1# Copyright 2014 The Chromium OS Authors. All rights reserved.
2# Use of this source code is governed by a BSD-style license that can be
3# found in the LICENSE file.
4
5import errno, glob, logging, os, re, struct, sys, time
6
7from autotest_lib.client.bin import test
8from autotest_lib.client.bin import utils
9from autotest_lib.client.common_lib import error
10from autotest_lib.client.common_lib import utils as common_utils
11from autotest_lib.client.common_lib.cros import chrome
12from autotest_lib.client.cros import cros_logging
13from autotest_lib.client.cros.graphics import graphics_utils
14
15# Kernel 3.8 to 3.14 has cur_delay_info, 3.18+ has frequency_info.
16CLOCK_PATHS = [
17    '/sys/kernel/debug/dri/0/i915_frequency_info',
18    '/sys/kernel/debug/dri/0/i915_cur_delayinfo'
19]
20# Kernel 3.8 has i915_fbc, kernel > 3.8 i915_fbc_status.
21FBC_PATHS = [
22    '/sys/kernel/debug/dri/0/i915_fbc',
23    '/sys/kernel/debug/dri/0/i915_fbc_status'
24]
25GEM_OBJECTS_PATHS = ['/sys/kernel/debug/dri/0/i915_gem_objects']
26GEM_PATHS = ['/sys/kernel/debug/dri/0/i915_gem_active']
27PSR_PATHS = ['/sys/kernel/debug/dri/0/i915_edp_psr_status']
28RC6_PATHS = ['/sys/kernel/debug/dri/0/i915_drpc_info']
29
30
31class graphics_Idle(graphics_utils.GraphicsTest):
32    """Class for graphics_Idle.  See 'control' for details."""
33    version = 1
34    _gpu_type = None
35    _cpu_type = None
36    _board = None
37
38    def run_once(self, arc_mode=None):
39        # If we are in arc_mode, do not report failures to perf dashboard.
40        if arc_mode:
41            self._test_failure_report_enable = False
42
43        self.add_failures('graphics_Idle')
44        with chrome.Chrome(
45                logged_in=True,
46                arc_mode=arc_mode) as cr:
47            # The New Tab Page contains the Google doodle which can cause
48            # arbitrary side effects. Hide it by going to a neutral page.
49            if not cr.browser.tabs:
50                cr.browser.tabs.New()
51            tab = cr.browser.tabs[0]
52            tab.Navigate('chrome://version')
53            # Try to protect against runaway previous tests.
54            if not utils.wait_for_idle_cpu(60.0, 0.1):
55                logging.warning('Could not get idle CPU before running tests.')
56            self._gpu_type = utils.get_gpu_family()
57            self._cpu_type = utils.get_cpu_soc_family()
58            self._board = utils.get_board()
59            errors = ''
60            errors += self.verify_graphics_dvfs()
61            errors += self.verify_graphics_fbc()
62            errors += self.verify_graphics_psr()
63            errors += self.verify_graphics_gem_idle()
64            errors += self.verify_graphics_i915_min_clock()
65            errors += self.verify_graphics_rc6()
66            errors += self.verify_lvds_downclock()
67            errors += self.verify_short_blanking()
68            if errors:
69                raise error.TestFail('Failed: %s' % errors)
70        self.remove_failures('graphics_Idle')
71
72    def get_valid_path(self, paths):
73        for path in paths:
74            if os.path.exists(path):
75                return path
76        logging.error('Error: %s not found.', ' '.join(paths))
77        return None
78
79    def handle_error(self, message, path=None):
80        logging.error('Error: %s', message)
81        # For debugging show the content of the file.
82        if path is not None:
83            with open(path, 'r') as text_file:
84                logging.info('Content of %s\n%s', path, text_file.read())
85        # Dump the output of 'top'.
86        utils.log_process_activity()
87        return message
88
89    def verify_lvds_downclock(self):
90        """On systems which support LVDS downclock, checks the kernel log for
91        a message that an LVDS downclock mode has been added."""
92        logging.info('Running verify_lvds_downclock')
93        board = utils.get_board()
94        if not (board == 'alex' or board == 'lumpy' or board == 'stout'):
95            return ''
96        # Get the downclock message from the logs.
97        reader = cros_logging.LogReader()
98        reader.set_start_by_reboot(-1)
99        if not reader.can_find('Adding LVDS downclock mode'):
100            return self.handle_error('LVDS downclock quirk not applied. ')
101        return ''
102
103    def verify_short_blanking(self):
104        """On baytrail systems with a known panel, checks the kernel log for a
105        message that a short blanking mode has been added."""
106        logging.info('Running verify_short_blanking')
107        if self._gpu_type != 'baytrail' or utils.has_no_monitor():
108            return ''
109
110        # Open the EDID to find the panel model.
111        param_path = '/sys/class/drm/card0-eDP-1/edid'
112        if not os.path.exists(param_path):
113            logging.error('Error: %s not found.', param_path)
114            return self.handle_error(
115                'Short blanking not added (no EDID found). ')
116
117        with open(param_path, 'r') as edp_edid_file:
118            edp_edid_file.seek(8)
119            data = edp_edid_file.read(2)
120            manufacturer = int(struct.unpack('<H', data)[0])
121            data = edp_edid_file.read(2)
122            product_code = int(struct.unpack('<H', data)[0])
123        # This is not the panel we are looking for (AUO B116XTN02.2)
124        if manufacturer != 0xaf06 or product_code != 0x225c:
125            return ''
126        # Get the downclock message from the logs.
127        reader = cros_logging.LogReader()
128        reader.set_start_by_reboot(-1)
129        if not reader.can_find('Modified preferred into a short blanking mode'):
130            return self.handle_error('Short blanking not added. ')
131        return ''
132
133    def verify_graphics_rc6(self):
134        """ On systems which support RC6 (non atom), check that we are able to
135        get into rc6; idle before doing so, and retry every second for 20
136        seconds."""
137        logging.info('Running verify_graphics_rc6')
138        # TODO(ihf): Implement on baytrail/braswell using residency counters.
139        # But note the format changed since SNB, so this will be complex.
140        if (utils.get_cpu_soc_family() == 'x86_64' and
141                self._gpu_type != 'pinetrail' and
142                self._gpu_type != 'baytrail' and self._gpu_type != 'braswell'):
143            tries = 0
144            found = False
145            param_path = self.get_valid_path(RC6_PATHS)
146            if not param_path:
147                return 'RC6_PATHS not found.'
148            while found == False and tries < 20:
149                time.sleep(1)
150                with open(param_path, 'r') as drpc_info_file:
151                    for line in drpc_info_file:
152                        match = re.search(r'Current RC state: (.*)', line)
153                        if match and match.group(1) == 'RC6':
154                            found = True
155                            break
156                tries += 1
157            if not found:
158                return self.handle_error('Error: did not see the GPU in RC6.',
159                                         param_path)
160        return ''
161
162    def verify_graphics_i915_min_clock(self):
163        """ On i915 systems, check that we get into the lowest clock frequency;
164        idle before doing so, and retry every second for 20 seconds."""
165        logging.info('Running verify_graphics_i915_min_clock')
166
167        # TODO(benzh): enable once crbug.com/719040 is fixed.
168        if self._gpu_type == 'baytrail' and utils.count_cpus() == 4:
169            logging.info('Waived min clock check due to crbug.com/719040')
170            return ''
171
172        if (utils.get_cpu_soc_family() == 'x86_64' and
173                self._gpu_type != 'pinetrail'):
174            tries = 0
175            found = False
176            param_path = self.get_valid_path(CLOCK_PATHS)
177            if not param_path:
178                return 'CLOCK_PATHS not found.'
179            while not found and tries < 80:
180                time.sleep(0.25)
181
182                with open(param_path, 'r') as delayinfo_file:
183                    for line in delayinfo_file:
184                        # This file has a different format depending on the
185                        # board, so we parse both. Also, it would be tedious
186                        # to add the minimum clock for each board, so instead
187                        # we use 650MHz which is the max of the minimum clocks.
188                        match = re.search(r'CAGF: (.*)MHz', line)
189                        if match and int(match.group(1)) <= 650:
190                            found = True
191                            break
192
193                        match = re.search(r'current GPU freq: (.*) MHz', line)
194                        if match and int(match.group(1)) <= 650:
195                            found = True
196                            break
197
198                tries += 1
199
200            if not found:
201                return self.handle_error('Did not see the min i915 clock. ',
202                                         param_path)
203
204        return ''
205
206    def get_devfreq_path(self, dev_path):
207        """ Return the path of the devfreq device for a device (if it has one).
208        """
209        g = glob.glob(dev_path + "/devfreq/*")
210
211        if len(g) != 1:
212            raise RuntimeError("Device '" + dev_path + "' has no devfreq device")
213
214        return g[0]
215
216    def verify_graphics_dvfs(self):
217        """ On systems which support DVFS, check that we get into the lowest
218        clock frequency; idle before doing so, and retry every second for 20
219        seconds."""
220        logging.info('Running verify_graphics_dvfs')
221
222        exynos_node = '/sys/devices/11800000.mali/'
223        rk3288_node = '/sys/devices/ffa30000.gpu/'
224        rk3288_419_node = '/sys/devices/platform/ffa30000.gpu/'
225        rk3399_node = '/sys/devices/platform/ff9a0000.gpu/'
226        mt8173_node = '/sys/devices/soc/13000000.mfgsys-gpu/'
227        mt8173_419_node = '/sys/devices/platform/soc/13000000.mfgsys-gpu/'
228        mt8183_node = '/sys/devices/platform/soc/13040000.mali/'
229        mt8192_node = '/sys/devices/platform/soc/13000000.mali/'
230
231        if self._cpu_type == 'exynos5':
232            if os.path.isdir(exynos_node):
233                node = exynos_node
234                use_devfreq = False
235                enable_node = 'dvfs'
236                enable_value = 'on'
237            else:
238                logging.error('Error: unknown exynos SoC.')
239                return self.handle_error('Unknown exynos SoC.')
240        elif self._cpu_type.startswith('rockchip'):
241            if os.path.isdir(rk3288_node):
242                node = rk3288_node
243                use_devfreq = False
244                enable_node = 'dvfs_enable'
245                enable_value = '1'
246            elif os.path.isdir(rk3288_419_node):
247                node = rk3288_419_node
248                use_devfreq = True
249            elif os.path.isdir(rk3399_node):
250                node = rk3399_node
251                use_devfreq = True
252            else:
253                logging.error('Error: unknown rockchip SoC.')
254                return self.handle_error('Unknown rockchip SoC.')
255        elif self._cpu_type == 'mediatek':
256            if os.path.isdir(mt8173_node):
257                node = mt8173_node
258                use_devfreq = True
259            elif os.path.isdir(mt8173_419_node):
260                node = mt8173_419_node
261                use_devfreq = True
262            elif os.path.isdir(mt8183_node):
263                node = mt8183_node
264                use_devfreq = True
265            elif os.path.isdir(mt8192_node):
266                node = mt8192_node
267                use_devfreq = True
268            else:
269                logging.error('Error: unknown mediatek SoC.')
270                return self.handle_error('Unknown mediatek SoC.')
271        else:
272            return ''
273
274        if use_devfreq:
275            node = self.get_devfreq_path(node)
276            governor_path = utils.locate_file('governor', node)
277            clock_path = utils.locate_file('cur_freq', node)
278
279            governor = utils.read_one_line(governor_path)
280            logging.info('DVFS governor = %s', governor)
281            if not governor == 'simple_ondemand':
282                logging.error('Error: DVFS governor is not simple_ondemand.')
283                return self.handle_error('Governor is wrong.')
284        else:
285            clock_path = utils.locate_file('clock', node)
286            enable_path = utils.locate_file(enable_node, node)
287
288            enable = utils.read_one_line(enable_path)
289            logging.info('DVFS enable = %s', enable)
290            if not enable == enable_value:
291                return self.handle_error('DVFS is not enabled. ')
292
293        freqs_path = utils.locate_file('available_frequencies', node)
294
295        # available_frequencies are always sorted in ascending order
296        # each line may contain one or multiple integers separated by spaces
297        min_freq = int(utils.read_one_line(freqs_path).split()[0])
298
299        # daisy_* (exynos5250) boards set idle frequency to 266000000
300        # See: crbug.com/467401 and crosbug.com/p/19710
301        if self._board.startswith('daisy'):
302            min_freq = 266000000
303
304        logging.info('Expecting idle DVFS clock = %u', min_freq)
305        tries = 0
306        found = False
307        while not found and tries < 80:
308            time.sleep(0.25)
309            clock = int(utils.read_one_line(clock_path))
310            if clock <= min_freq:
311                logging.info('Found idle DVFS clock = %u', clock)
312                found = True
313                break
314
315            tries += 1
316        if not found:
317            logging.error('Error: DVFS clock (%u) > min (%u)', clock, min_freq)
318            return self.handle_error('Did not see the min DVFS clock. ',
319                                     clock_path)
320        return ''
321
322    def verify_graphics_fbc(self):
323        """ On systems which support FBC, check that we can get into FBC;
324        idle before doing so, and retry every second for 20 seconds."""
325        logging.info('Running verify_graphics_fbc')
326
327        # Link's FBC is disabled (crbug.com/338588).
328        # TODO(marcheu): remove this when/if we fix this bug.
329        board = utils.get_board()
330        if board == 'link':
331            return ''
332
333        # Machines which don't have a monitor can't get FBC.
334        if utils.has_no_monitor():
335            return ''
336
337        if (self._gpu_type == 'haswell' or self._gpu_type == 'ivybridge' or
338                self._gpu_type == 'sandybridge'):
339            tries = 0
340            found = False
341            param_path = self.get_valid_path(FBC_PATHS)
342            if not param_path:
343                return 'FBC_PATHS not found.'
344            while not found and tries < 20:
345                time.sleep(1)
346                with open(param_path, 'r') as fbc_info_file:
347                    for line in fbc_info_file:
348                        if re.search('FBC enabled', line):
349                            found = True
350                            break
351
352                tries += 1
353            if not found:
354                return self.handle_error('Did not see FBC enabled. ',
355                                         param_path)
356        return ''
357
358    def verify_graphics_psr(self):
359        """ On systems which support PSR, check that we can get into PSR;
360        idle before doing so, and retry every second for 20 seconds."""
361        logging.info('Running verify_graphics_psr')
362
363        if utils.get_cpu_soc_family() != 'x86_64':
364            return ''
365        tries = 0
366        found = False
367        param_path = self.get_valid_path(PSR_PATHS)
368        if not param_path:
369            logging.warning("PSR_PATHS not found.")
370            return ''
371        kernel_version = utils.get_kernel_version()[0:4].rstrip(".")
372        logging.info('Kernel version: %s', kernel_version)
373        # First check if PSR is enabled on the device so
374        # we can watch for the active values
375        with open(param_path, 'r') as psr_info_file:
376            match = None
377            try:
378                for line in psr_info_file:
379                    match = re.search(r'Enabled: yes', line)
380                    if match:
381                        logging.info('PSR enabled')
382                        break
383                if not match:
384                    logging.warning('PSR not enabled')
385                    return ''
386            except IOError as e:
387                num, strerror = e.args
388                # Newer kernels might report ENODEV when PSR not available.
389                if num == errno.ENODEV:
390                    logging.warning('PSR not enabled')
391                    return ''
392                else:
393                    logging.error('While accessing %s', param_path)
394                    logging.error(e)
395                    return self.handle_error('Unexpected PSR read failure. ')
396        while not found and tries < 20:
397            time.sleep(1)
398            with open(param_path, 'r') as psr_info_file:
399                for line in psr_info_file:
400                    # Kernels 4.4 and up
401                    if common_utils.compare_versions(kernel_version, '4.4') != -1:
402                        match = re.search(r'PSR status: .* \[SRDENT', line)
403                        if match:
404                            found = True
405                            logging.info('Found active with kernel >= 4.4')
406                            break
407                    # 3.18 kernel
408                    elif kernel_version == '3.18':
409                        match = re.search(r'Performance_Counter: 0', line)
410                        if match:
411                            found = True
412                            logging.info('Found active with 3.18 kernel')
413                            break
414                    # Older kernels (up to 3.14)
415                    else:
416                        match = re.search(r'Performance_Counter: ([\d])+', line)
417                        if match and int(match.group(1)) > 0:
418                            found = True
419                            logging.info('Found active with kernel <= 3.14')
420                            break
421
422            tries += 1
423        if not found:
424            return self.handle_error('Did not see PSR activity. ', param_path)
425        return ''
426
427    def verify_graphics_gem_idle(self):
428        """ On systems which have i915, check that we can get all gem objects
429        to become idle (i.e. the i915_gem_active list or i915_gem_objects
430        client/process gem object counts need to go to 0);
431        idle before doing so, and retry every second for 20 seconds."""
432        logging.info('Running verify_graphics_gem_idle')
433        if utils.get_cpu_soc_family() == 'x86_64':
434            tries = 0
435            found = False
436            per_process_check = False
437
438            gem_path = self.get_valid_path(GEM_PATHS)
439            if not gem_path:
440                gem_path = self.get_valid_path(GEM_OBJECTS_PATHS)
441                if gem_path:
442                    per_process_check = True
443                else:
444                    return 'GEM_PATHS not found.'
445
446            # Checks 4.4 and later kernels
447            if per_process_check:
448                while not found and tries < 240:
449                    time.sleep(0.25)
450                    gem_objects_idle = False
451                    gem_active_search = False
452                    with open(gem_path, 'r') as gem_file:
453                        for line in gem_file:
454                            if gem_active_search:
455                                if re.search('\(0 active,', line):
456                                    gem_objects_idle = True
457                                else:
458                                    gem_objects_idle = False
459                                    break
460                            elif line == '\n':
461                                gem_active_search = True
462                        if gem_objects_idle:
463                            found = True
464                    tries += 1
465
466            # Checks pre 4.4 kernels
467            else:
468                while not found and tries < 240:
469                    time.sleep(0.25)
470                    with open(gem_path, 'r') as gem_file:
471                        for line in gem_file:
472                            if re.search('Total 0 objects', line):
473                                found = True
474                                break
475                    tries += 1
476            if not found:
477                return self.handle_error('Did not reach 0 gem actives. ',
478                                         gem_path)
479        return ''
480