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 RunNamedCommand(self, command_name, args=None, headers=None, debug=0, trace_token=None, parallel_operations=False, skip_update_check=False, logging_filters=None, do_shutdown=True, perf_trace_token=None, user_project=None, collect_analytics=False): """Runs the named command. Used by gsutil main, commands built atop other commands, and tests. Args: command_name: The name of the command being run. args: Command-line args (arg0 = actual arg, not command name ala bash). headers: Dictionary containing optional HTTP headers to pass to boto. debug: Debug level to pass in to boto connection (range 0..3). trace_token: Trace token to pass to the underlying API. parallel_operations: Should command operations be executed in parallel? skip_update_check: Set to True to disable checking for gsutil updates. logging_filters: Optional list of logging.Filters to apply to this command's logger. do_shutdown: Stop all parallelism framework workers iff this is True. perf_trace_token: Performance measurement trace token to pass to the underlying API. user_project: The project to bill this request to. collect_analytics: Set to True to collect an analytics metric logging this command. Raises: CommandException: if errors encountered. Returns: Return value(s) from Command that was run. """ command_changed_to_update = False if (not skip_update_check and self.MaybeCheckForAndOfferSoftwareUpdate( command_name, debug)): command_name = 'update' command_changed_to_update = True args = ['-n'] # Check for opt-in analytics. if system_util.IsRunningInteractively() and collect_analytics: metrics.CheckAndMaybePromptForAnalyticsEnabling() if not args: args = [] # Include api_version header in all commands. api_version = boto.config.get_value('GSUtil', 'default_api_version', '1') if not headers: headers = {} headers['x-goog-api-version'] = api_version if command_name not in self.command_map: close_matches = difflib.get_close_matches(command_name, self.command_map.keys(), n=1) if close_matches: # Instead of suggesting a deprecated command alias, suggest the new # name for that command. translated_command_name = (OLD_ALIAS_MAP.get( close_matches[0], close_matches)[0]) print >> sys.stderr, 'Did you mean this?' print >> sys.stderr, '\t%s' % translated_command_name elif command_name == 'update' and gslib.IS_PACKAGE_INSTALL: sys.stderr.write( 'Update command is not supported for package installs; ' 'please instead update using your package manager.') raise CommandException('Invalid command "%s".' % command_name) if '--help' in args: new_args = [command_name] original_command_class = self.command_map[command_name] subcommands = original_command_class.help_spec.subcommand_help_text.keys( ) for arg in args: if arg in subcommands: new_args.append(arg) break # Take the first match and throw away the rest. args = new_args command_name = 'help' HandleArgCoding(args) HandleHeaderCoding(headers) command_class = self.command_map[command_name] command_inst = command_class(self, args, headers, debug, trace_token, parallel_operations, self.bucket_storage_uri_class, self.gsutil_api_class_map_factory, logging_filters, command_alias_used=command_name, perf_trace_token=perf_trace_token, user_project=user_project) # Log the command name, command alias, and sub-options after being parsed by # RunCommand and the command constructor. For commands with subcommands and # suboptions, we need to log the suboptions again within the command itself # because the command constructor will not parse the suboptions fully. if collect_analytics: metrics.LogCommandParams(command_name=command_inst.command_name, sub_opts=command_inst.sub_opts, command_alias=command_name) return_code = command_inst.RunCommand() if CheckMultiprocessingAvailableAndInit().is_available and do_shutdown: ShutDownGsutil() if GetFailureCount() > 0: return_code = 1 if command_changed_to_update: # If the command changed to update, the user's original command was # not executed. return_code = 1 print '\n'.join( textwrap.wrap( 'Update was successful. Exiting with code 1 as the original command ' 'issued prior to the update was not executed and should be re-run.' )) return return_code