def testMetricsReporting(self):
"""Tests the subprocess creation by Popen in metrics.py."""
popen_mock = self._StartObjectPatch(subprocess, 'Popen')
# Set up the temp file for pickle dumping metrics into.
metrics_file = tempfile.NamedTemporaryFile()
metrics_file.close()
temp_file_mock = self._StartObjectPatch(tempfile, 'NamedTemporaryFile')
temp_file_mock.return_value = open(metrics_file.name, 'wb')
# If there are no metrics, Popen should not be called.
self.collector.ReportMetrics()
self.assertEqual(0, popen_mock.call_count)
_LogAllTestMetrics()
# Report the metrics and check Popen calls.
metrics.Shutdown()
call_list = popen_mock.call_args_list
self.assertEqual(1, len(call_list))
# Check to make sure that we have the proper PYTHONPATH in the subprocess.
args = call_list[0]
self.assertIn('PYTHONPATH', args[1]['env'])
# Ensure that we can access the same modules as the main process from
# PYTHONPATH.
missing_paths = (set(sys.path) -
set(args[1]['env']['PYTHONPATH'].split(os.pathsep)))
self.assertEqual(set(), missing_paths)
# Check that the metrics were correctly dumped into the temp file.
with open(metrics_file.name, 'rb') as metrics_file:
reported_metrics = pickle.load(metrics_file)
self.assertEqual(COMMAND_AND_ERROR_TEST_METRICS,
MetricListToTestMetricSet(reported_metrics))
def testExceptionCatchingDecorator(self):
"""Tests the exception catching decorator CaptureAndLogException."""
original_log_level = self.root_logger.getEffectiveLevel()
self.root_logger.setLevel(logging.DEBUG)
# Test that a wrapped function with an exception doesn't stop the process.
mock_exc_fn = mock.MagicMock(__name__='mock_exc_fn',
side_effect=Exception())
wrapped_fn = metrics.CaptureAndLogException(mock_exc_fn)
wrapped_fn()
self.assertEqual(1, mock_exc_fn.call_count)
with open(self.log_handler_file) as f:
log_output = f.read()
self.assertIn(
'Exception captured in mock_exc_fn during metrics '
'collection', log_output)
mock_err_fn = mock.MagicMock(__name__='mock_err_fn',
side_effect=TypeError())
wrapped_fn = metrics.CaptureAndLogException(mock_err_fn)
wrapped_fn()
self.assertEqual(1, mock_err_fn.call_count)
with open(self.log_handler_file) as f:
log_output = f.read()
self.assertIn(
'Exception captured in mock_err_fn during metrics '
'collection', log_output)
# Test that exceptions in the unprotected metrics functions are caught.
with mock.patch.object(MetricsCollector,
'GetCollector',
return_value='not a collector'):
# These calls should all fail, but the exceptions shouldn't propagate up.
metrics.Shutdown()
metrics.LogCommandParams()
metrics.LogRetryableError()
metrics.LogFatalError()
metrics.LogPerformanceSummary()
metrics.CheckAndMaybePromptForAnalyticsEnabling('invalid argument')
with open(self.log_handler_file) as f:
log_output = f.read()
self.assertIn(
'Exception captured in Shutdown during metrics collection',
log_output)
self.assertIn(
'Exception captured in LogCommandParams during metrics collection',
log_output)
self.assertIn(
'Exception captured in LogRetryableError during metrics collection',
log_output)
self.assertIn(
'Exception captured in LogFatalError during metrics collection',
log_output)
self.assertIn(
'Exception captured in LogPerformanceSummary during metrics '
'collection', log_output)
self.assertIn(
'Exception captured in CheckAndMaybePromptForAnalyticsEnabling '
'during metrics collection', log_output)
self.root_logger.setLevel(original_log_level)
def testExceptionCatchingDecorator(self):
"""Tests the exception catching decorator CaptureAndLogException."""
# A wrapped function with an exception should not stop the process.
mock_exc_fn = mock.MagicMock(__name__='mock_exc_fn',
side_effect=Exception())
wrapped_fn = metrics.CaptureAndLogException(mock_exc_fn)
wrapped_fn()
debug_messages = self.log_handler.messages['debug']
self.assertIn('Exception captured in mock_exc_fn during metrics collection',
debug_messages[0])
self.log_handler.reset()
self.assertEqual(1, mock_exc_fn.call_count)
mock_err_fn = mock.MagicMock(__name__='mock_err_fn',
side_effect=TypeError())
wrapped_fn = metrics.CaptureAndLogException(mock_err_fn)
wrapped_fn()
self.assertEqual(1, mock_err_fn.call_count)
debug_messages = self.log_handler.messages['debug']
self.assertIn('Exception captured in mock_err_fn during metrics collection',
debug_messages[0])
self.log_handler.reset()
# Test that exceptions in the unprotected metrics functions are caught.
with mock.patch.object(MetricsCollector, 'GetCollector',
return_value='not a collector'):
# These calls should all fail, but the exceptions shouldn't propagate up.
metrics.Shutdown()
metrics.LogCommandParams()
metrics.LogRetryableError()
metrics.LogFatalError()
metrics.LogPerformanceSummaryParams()
metrics.CheckAndMaybePromptForAnalyticsEnabling('invalid argument')
debug_messages = self.log_handler.messages['debug']
message_index = 0
for func_name in ('Shutdown', 'LogCommandParams', 'LogRetryableError',
'LogFatalError', 'LogPerformanceSummaryParams',
'CheckAndMaybePromptForAnalyticsEnabling'):
self.assertIn(
'Exception captured in %s during metrics collection' % func_name,
debug_messages[message_index])
message_index += 1
self.log_handler.reset()
def MultithreadedMainSignalHandler(signal_num, cur_stack_frame):
"""Final signal handler for multi-threaded main process."""
if signal_num == signal.SIGINT:
if logging.getLogger().isEnabledFor(logging.DEBUG):
stack_trace = ''.join(traceback.format_list(traceback.extract_stack()))
err = ('DEBUG: Caught CTRL-C (signal %d) - Exception stack trace:\n'
' %s' % (signal_num, re.sub('\\n', '\n ', stack_trace)))
try:
sys.stderr.write(err.encode(UTF8))
except UnicodeDecodeError:
# Can happen when outputting invalid Unicode filenames.
sys.stderr.write(err)
else:
sys.stderr.write('Caught CTRL-C (signal %d) - exiting\n' % signal_num)
metrics.LogFatalError(exception=ControlCException())
metrics.Shutdown()
KillProcess(os.getpid())