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 5 import logging, os 6 from autotest_lib.client.bin import utils 7 from autotest_lib.client.common_lib import error 8 from autotest_lib.client.cros import cros_ui, upstart 9 from 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 18 class 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 that the crasher 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 result['basename'], 186 'log', 187 _COLLECTION_ERROR_SIGNATURE) 188 finally: 189 utils.system('echo "%s" > %s' % (old_core_pattern, 190 self._CORE_PATTERN)) 191 192 193 def _test_core2md_failure(self): 194 self._check_collection_failure('--core2md_failure', 195 'Problem during %s [result=1]: Usage:' % 196 _CORE2MD_PATH) 197 198 199 def _test_internal_directory_failure(self): 200 self._check_collection_failure('--directory_failure', 201 'Purposefully failing to create') 202 203 204 def _test_crash_logs_creation(self): 205 # Copy and rename crasher to trigger crash_reporter_logs.conf rule. 206 logs_triggering_crasher = os.path.join(os.path.dirname(self.bindir), 207 'crash_log_test') 208 result = self._run_crasher_process_and_analyze( 209 'root', crasher_path=logs_triggering_crasher) 210 self._check_crashed_and_caught(result) 211 contents = utils.read_file(result['log']) 212 if contents != 'hello world\n': 213 raise error.TestFail('Crash log contents unexpected: %s' % contents) 214 if not ('log=' + result['log']) in utils.read_file(result['meta']): 215 raise error.TestFail('Meta file does not reference log') 216 217 218 def _test_crash_log_infinite_recursion(self): 219 # Copy and rename crasher to trigger crash_reporter_logs.conf rule. 220 recursion_triggering_crasher = os.path.join( 221 os.path.dirname(self.bindir), 'crash_log_recursion_test') 222 # The configuration file hardcodes this path, so make sure it's still 223 # the same. 224 if (recursion_triggering_crasher != 225 '/usr/local/autotest/tests/crash_log_recursion_test'): 226 raise error.TestError('Path to recursion test changed') 227 # Simply completing this command means that we avoided 228 # infinite recursion. 229 result = self._run_crasher_process( 230 'root', crasher_path=recursion_triggering_crasher) 231 232 233 def _check_core_file_persisting(self, expect_persist): 234 self._log_reader.set_start_by_current() 235 236 result = self._run_crasher_process('root') 237 238 if not result['crashed']: 239 raise error.TestFail('crasher did not crash') 240 241 crash_contents = os.listdir(self._get_crash_dir('root')) 242 243 logging.debug('Contents of crash directory: %s', crash_contents) 244 logging.debug('Log messages: %s', self._log_reader.get_logs()) 245 246 if expect_persist: 247 if not self._log_reader.can_find('Leaving core file at'): 248 raise error.TestFail('Missing log message') 249 expected_core_files = 1 250 else: 251 if self._log_reader.can_find('Leaving core file at'): 252 raise error.TestFail('Unexpected log message') 253 expected_core_files = 0 254 255 dmp_files = 0 256 core_files = 0 257 for filename in crash_contents: 258 if filename.endswith('.dmp'): 259 dmp_files += 1 260 if filename.endswith('.core'): 261 core_files += 1 262 263 if dmp_files != 1: 264 raise error.TestFail('Should have been exactly 1 dmp file') 265 if core_files != expected_core_files: 266 raise error.TestFail('Should have been exactly %d core files' % 267 expected_core_files) 268 269 270 def _test_core_file_removed_in_production(self): 271 """Test that core files do not stick around for production builds.""" 272 # Avoid remounting / rw by instead creating a tmpfs in /root and 273 # populating it with everything but the 274 utils.system('tar -cvz -C /root -f /tmp/root.tgz .') 275 utils.system('mount -t tmpfs tmpfs /root') 276 try: 277 utils.system('tar -xvz -C /root -f /tmp/root.tgz .') 278 os.remove(_LEAVE_CORE_PATH) 279 if os.path.exists(_LEAVE_CORE_PATH): 280 raise error.TestFail('.leave_core file did not disappear') 281 self._check_core_file_persisting(False) 282 finally: 283 os.system('umount /root') 284 285 286 def initialize(self): 287 user_crash_test.UserCrashTest.initialize(self) 288 289 # If the device has a GUI, return the device to the sign-in screen, as 290 # some tests will fail inside a user session. 291 if upstart.has_service('ui'): 292 cros_ui.restart() 293 294 295 # TODO(kmixter): Test crashing a process as ntp or some other 296 # non-root, non-chronos user. 297 298 def run_once(self): 299 self._prepare_crasher() 300 self._populate_symbols() 301 302 # Run the test once without re-initializing 303 # to catch problems with the default crash reporting setup 304 self.run_crash_tests(['reporter_startup'], 305 initialize_crash_reporter=False, 306 must_run_all=False) 307 308 self.run_crash_tests(['reporter_startup', 309 'reporter_shutdown', 310 'no_crash', 311 'chronos_crasher', 312 'chronos_crasher_no_consent', 313 'root_crasher', 314 'root_crasher_no_consent', 315 'crash_filtering', 316 'max_enqueued_crashes', 317 'core2md_failure', 318 'internal_directory_failure', 319 'crash_logs_creation', 320 'crash_log_infinite_recursion', 321 'core_file_removed_in_production'], 322 initialize_crash_reporter=True) 323
