1# Copyright (c) 2010 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 logging, os
6from autotest_lib.client.bin import utils
7from autotest_lib.client.common_lib import error
8from autotest_lib.client.cros import cros_ui, upstart
9from autotest_lib.client.cros.crash import user_crash_test
10
11
12_COLLECTION_ERROR_SIGNATURE = 'crash_reporter-user-collection'
13_CORE2MD_PATH = '/usr/bin/core2md'
14_LEAVE_CORE_PATH = '/root/.leave_core'
15_MAX_CRASH_DIRECTORY_SIZE = 32
16
17
18class logging_UserCrash(user_crash_test.UserCrashTest):
19    """Verifies crash reporting for user processes."""
20    version = 1
21
22
23    def _test_reporter_startup(self):
24        """Test that the core_pattern is set up by crash reporter."""
25        # Turn off crash filtering so we see the original setting.
26        self.disable_crash_filtering()
27        output = utils.read_file(self._CORE_PATTERN).rstrip()
28        expected_core_pattern = ('|%s --user=%%P:%%s:%%u:%%e' %
29                                 self._CRASH_REPORTER_PATH)
30        if output != expected_core_pattern:
31            raise error.TestFail('core pattern should have been %s, not %s' %
32                                 (expected_core_pattern, output))
33
34        self._log_reader.set_start_by_reboot(-1)
35
36        if not self._log_reader.can_find('Enabling user crash handling'):
37            raise error.TestFail(
38                'user space crash handling was not started during last boot')
39
40
41    def _test_reporter_shutdown(self):
42        """Test the crash_reporter shutdown code works."""
43        self._log_reader.set_start_by_current()
44        utils.system('%s --clean_shutdown' % self._CRASH_REPORTER_PATH)
45        output = utils.read_file(self._CORE_PATTERN).rstrip()
46        if output != 'core':
47            raise error.TestFail('core pattern should have been core, not %s' %
48                                 output)
49
50
51    def _test_no_crash(self):
52        """Test a program linked against libcrash_dumper can exit normally."""
53        self._log_reader.set_start_by_current()
54        result = self._run_crasher_process_and_analyze(username='root',
55                                                       cause_crash=False)
56        if (result['crashed'] or
57            result['crash_reporter_caught'] or
58            result['returncode'] != 0):
59            raise error.TestFail('Normal exit of program with dumper failed')
60
61
62    def _test_chronos_crasher(self):
63        """Test a user space crash when running as chronos is handled."""
64        self._check_crashing_process('chronos')
65
66
67    def _test_chronos_crasher_no_consent(self):
68        """Test that without consent no files are stored."""
69        results = self._check_crashing_process('chronos', consent=False)
70
71
72    def _test_root_crasher(self):
73        """Test a user space crash when running as root is handled."""
74        self._check_crashing_process('root')
75
76
77    def _test_root_crasher_no_consent(self):
78        """Test that without consent no files are stored."""
79        results = self._check_crashing_process('root', consent=False)
80
81
82    def _check_filter_crasher(self, should_receive):
83        self._log_reader.set_start_by_current()
84        crasher_basename = os.path.basename(self._crasher_path)
85        utils.system(self._crasher_path, ignore_status=True);
86        if should_receive:
87            to_find = 'Received crash notification for ' + crasher_basename
88        else:
89            to_find = 'Ignoring crash from ' + crasher_basename
90        utils.poll_for_condition(
91            lambda: self._log_reader.can_find(to_find),
92            timeout=10,
93            exception=error.TestError(
94              'Timeout waiting for: ' + to_find + ' in ' +
95              self._log_reader.get_logs()))
96
97
98    def _test_crash_filtering(self):
99        """Test that crash filtering (a feature needed for testing) works."""
100        crasher_basename = os.path.basename(self._crasher_path)
101        self._log_reader.set_start_by_current()
102
103        self.enable_crash_filtering('none')
104        self._check_filter_crasher(False)
105
106        self.enable_crash_filtering('sleep')
107        self._check_filter_crasher(False)
108
109        self.disable_crash_filtering()
110        self._check_filter_crasher(True)
111
112
113    def _test_max_enqueued_crashes(self):
114        """Test that _MAX_CRASH_DIRECTORY_SIZE is enforced."""
115        self._log_reader.set_start_by_current()
116        username = 'root'
117
118        crash_dir = self._get_crash_dir(username)
119        full_message = ('Crash directory %s already full with %d pending '
120                        'reports' % (crash_dir, _MAX_CRASH_DIRECTORY_SIZE))
121
122        # Fill up the queue.
123        for i in range(0, _MAX_CRASH_DIRECTORY_SIZE):
124          result = self._run_crasher_process(username)
125          if not result['crashed']:
126            raise error.TestFail('failure while setting up queue: %d' %
127                                 result['returncode'])
128          if self._log_reader.can_find(full_message):
129            raise error.TestFail('unexpected full message: ' + full_message)
130
131        crash_dir_size = len(os.listdir(crash_dir))
132        # For debugging
133        utils.system('ls -l %s' % crash_dir)
134        logging.info('Crash directory had %d entries', crash_dir_size)
135
136        # Crash a bunch more times, but make sure no new reports
137        # are enqueued.
138        for i in range(0, 10):
139          self._log_reader.set_start_by_current()
140          result = self._run_crasher_process(username)
141          logging.info('New log messages: %s', self._log_reader.get_logs())
142          if not result['crashed']:
143            raise error.TestFail('failure after setting up queue: %d' %
144                                 result['returncode'])
145          utils.poll_for_condition(
146              lambda: self._log_reader.can_find(full_message),
147              timeout=20,
148              exception=error.TestFail('expected full message: ' +
149                                       full_message))
150          if crash_dir_size != len(os.listdir(crash_dir)):
151            utils.system('ls -l %s' % crash_dir)
152            raise error.TestFail('expected no new files (now %d were %d)',
153                                 len(os.listdir(crash_dir)),
154                                 crash_dir_size)
155
156
157    def _check_collection_failure(self, test_option, failure_string):
158        # Add parameter to core_pattern.
159        old_core_pattern = utils.read_file(self._CORE_PATTERN)[:-1]
160        try:
161            utils.system('echo "%s %s" > %s' % (old_core_pattern, test_option,
162                                                self._CORE_PATTERN))
163            result = self._run_crasher_process_and_analyze('root',
164                                                           consent=True)
165            self._check_crashed_and_caught(result)
166            if not self._log_reader.can_find(failure_string):
167                raise error.TestFail('Did not find fail string in log %s' %
168                                     failure_string)
169            if result['minidump']:
170                raise error.TestFail('failed collection resulted in minidump')
171            if not result['log']:
172                raise error.TestFail('failed collection had no log')
173            log_contents = utils.read_file(result['log'])
174            logging.debug('Log contents were: %s', log_contents)
175            if not failure_string in log_contents:
176                raise error.TestFail('Expected logged error '
177                                     '\"%s\" was \"%s\"' %
178                                     (failure_string, log_contents))
179            # Verify we are generating appropriate diagnostic output.
180            if ((not '===ps output===' in log_contents) or
181                (not '===meminfo===' in log_contents)):
182                raise error.TestFail('Expected full logs, got: ' + log_contents)
183            self._check_generated_report_sending(result['meta'],
184                                                 result['log'],
185                                                 'root',
186                                                 result['basename'],
187                                                 'log',
188                                                 _COLLECTION_ERROR_SIGNATURE)
189        finally:
190            utils.system('echo "%s" > %s' % (old_core_pattern,
191                                             self._CORE_PATTERN))
192
193
194    def _test_core2md_failure(self):
195        self._check_collection_failure('--core2md_failure',
196                                       'Problem during %s [result=1]: Usage:' %
197                                       _CORE2MD_PATH)
198
199
200    def _test_internal_directory_failure(self):
201        self._check_collection_failure('--directory_failure',
202                                       'Purposefully failing to create')
203
204
205    def _test_crash_logs_creation(self):
206        # Copy and rename crasher to trigger crash_reporter_logs.conf rule.
207        logs_triggering_crasher = os.path.join(os.path.dirname(self.bindir),
208                                               'crash_log_test')
209        result = self._run_crasher_process_and_analyze(
210            'root', crasher_path=logs_triggering_crasher)
211        self._check_crashed_and_caught(result)
212        contents = utils.read_file(result['log'])
213        if contents != 'hello world\n':
214            raise error.TestFail('Crash log contents unexpected: %s' % contents)
215        if not ('log=' + result['log']) in utils.read_file(result['meta']):
216            raise error.TestFail('Meta file does not reference log')
217
218
219    def _test_crash_log_infinite_recursion(self):
220        # Copy and rename crasher to trigger crash_reporter_logs.conf rule.
221        recursion_triggering_crasher = os.path.join(
222            os.path.dirname(self.bindir), 'crash_log_recursion_test')
223        # The configuration file hardcodes this path, so make sure it's still
224        # the same.
225        if (recursion_triggering_crasher !=
226            '/usr/local/autotest/tests/crash_log_recursion_test'):
227          raise error.TestError('Path to recursion test changed')
228        # Simply completing this command means that we avoided
229        # infinite recursion.
230        result = self._run_crasher_process(
231            'root', crasher_path=recursion_triggering_crasher)
232
233
234    def _check_core_file_persisting(self, expect_persist):
235        self._log_reader.set_start_by_current()
236
237        result = self._run_crasher_process('root')
238
239        if not result['crashed']:
240            raise error.TestFail('crasher did not crash')
241
242        crash_contents = os.listdir(self._get_crash_dir('root'))
243
244        logging.debug('Contents of crash directory: %s', crash_contents)
245        logging.debug('Log messages: %s', self._log_reader.get_logs())
246
247        if expect_persist:
248            if not self._log_reader.can_find('Leaving core file at'):
249                raise error.TestFail('Missing log message')
250            expected_core_files = 1
251        else:
252            if self._log_reader.can_find('Leaving core file at'):
253                raise error.TestFail('Unexpected log message')
254            expected_core_files = 0
255
256        dmp_files = 0
257        core_files = 0
258        for filename in crash_contents:
259            if filename.endswith('.dmp'):
260                dmp_files += 1
261            if filename.endswith('.core'):
262                core_files += 1
263
264        if dmp_files != 1:
265            raise error.TestFail('Should have been exactly 1 dmp file')
266        if core_files != expected_core_files:
267            raise error.TestFail('Should have been exactly %d core files' %
268                                 expected_core_files)
269
270
271    def _test_core_file_removed_in_production(self):
272        """Test that core files do not stick around for production builds."""
273        # Avoid remounting / rw by instead creating a tmpfs in /root and
274        # populating it with everything but the
275        utils.system('tar -cvz -C /root -f /tmp/root.tgz .')
276        utils.system('mount -t tmpfs tmpfs /root')
277        try:
278            utils.system('tar -xvz -C /root -f /tmp/root.tgz .')
279            os.remove(_LEAVE_CORE_PATH)
280            if os.path.exists(_LEAVE_CORE_PATH):
281                raise error.TestFail('.leave_core file did not disappear')
282            self._check_core_file_persisting(False)
283        finally:
284            os.system('umount /root')
285
286
287    def initialize(self):
288        user_crash_test.UserCrashTest.initialize(self)
289
290        # If the device has a GUI, return the device to the sign-in screen, as
291        # some tests will fail inside a user session.
292        if upstart.has_service('ui'):
293            cros_ui.restart()
294
295
296    # TODO(kmixter): Test crashing a process as ntp or some other
297    # non-root, non-chronos user.
298
299    def run_once(self):
300        self._prepare_crasher()
301        self._populate_symbols()
302
303        # Run the test once without re-initializing
304        # to catch problems with the default crash reporting setup
305        self.run_crash_tests(['reporter_startup'],
306                              initialize_crash_reporter=False,
307                              must_run_all=False)
308
309        self.run_crash_tests(['reporter_startup',
310                              'reporter_shutdown',
311                              'no_crash',
312                              'chronos_crasher',
313                              'chronos_crasher_no_consent',
314                              'root_crasher',
315                              'root_crasher_no_consent',
316                              'crash_filtering',
317                              'max_enqueued_crashes',
318                              'core2md_failure',
319                              'internal_directory_failure',
320                              'crash_logs_creation',
321                              'crash_log_infinite_recursion',
322                              'core_file_removed_in_production'],
323                              initialize_crash_reporter=True)
324