From 62cd0de6cfbe7d2b7e966396d24bc337a962bdd7 Mon Sep 17 00:00:00 2001 From: Sam Saccone Date: Thu, 29 Jan 2026 13:41:41 -0800 Subject: [PATCH] Make git trace2 logging errors conditional on verbose mode. Add a verbose attribute to the EventLog class, defaulting to False. Error messages printed to sys.stderr within the EventLog.Write method are now guarded by this verbose flag. In main.py, set EventLog.verbose to True if the command-line --verbose option is used. This prevents trace2 logging failures from being printed to stderr unless verbose output is explicitly requested. PROMPT=convert all git trace2 logging print messages to verbose only logging BUG: b/479811034 Change-Id: I8757ee52117d766f2f3ec47856db64cc4f51143c Reviewed-on: https://gerrit-review.googlesource.com/c/git-repo/+/547542 Tested-by: Sam Saccone Reviewed-by: Julia Tuttle Reviewed-by: Gavin Mak --- git_trace2_event_log_base.py | 40 ++++++---- main.py | 4 +- tests/test_git_trace2_event_log.py | 124 +++++++++++++++++++++-------- tests/test_subcmds.py | 47 +++++++++++ 4 files changed, 162 insertions(+), 53 deletions(-) diff --git a/git_trace2_event_log_base.py b/git_trace2_event_log_base.py index 56db7a8f5..1a59fee8a 100644 --- a/git_trace2_event_log_base.py +++ b/git_trace2_event_log_base.py @@ -68,6 +68,7 @@ class BaseEventLog: global p_init_count p_init_count += 1 self._log = [] + self.verbose = False # Try to get session-id (sid) from environment (setup in repo launcher). KEY = "GIT_TRACE2_PARENT_SID" if env is None: @@ -309,10 +310,12 @@ class BaseEventLog: # ignore the attempt and continue to DGRAM below. Otherwise, # issue a warning. if err.errno != errno.EPROTOTYPE: - print( - f"repo: warning: git trace2 logging failed: {err}", - file=sys.stderr, - ) + if self.verbose: + print( + "repo: warning: git trace2 logging failed:", + f"{err}", + file=sys.stderr, + ) return None if socket_type == socket.SOCK_DGRAM or socket_type is None: try: @@ -322,18 +325,20 @@ class BaseEventLog: self._WriteLog(lambda bs: sock.sendto(bs, path)) return f"af_unix:dgram:{path}" except OSError as err: - print( - f"repo: warning: git trace2 logging failed: {err}", - file=sys.stderr, - ) + if self.verbose: + print( + f"repo: warning: git trace2 logging failed: {err}", + file=sys.stderr, + ) return None # Tried to open a socket but couldn't connect (SOCK_STREAM) or write # (SOCK_DGRAM). - print( - "repo: warning: git trace2 logging failed: could not write to " - "socket", - file=sys.stderr, - ) + if self.verbose: + print( + "repo: warning: git trace2 logging failed: could not" + "write to socket", + file=sys.stderr, + ) return None # Path is an absolute path @@ -348,9 +353,10 @@ class BaseEventLog: self._WriteLog(f.write) log_path = f.name except FileExistsError as err: - print( - "repo: warning: git trace2 logging failed: %r" % err, - file=sys.stderr, - ) + if self.verbose: + print( + "repo: warning: git trace2 logging failed: %r" % err, + file=sys.stderr, + ) return None return log_path diff --git a/main.py b/main.py index 424ad91ca..c55922255 100755 --- a/main.py +++ b/main.py @@ -337,6 +337,9 @@ class _Repo: ) return 1 + cmd.CommonValidateOptions(copts, cargs) + git_trace2_event_log.verbose = copts.verbose + if gopts.pager is not False and not isinstance(cmd, InteractiveCommand): config = cmd.client.globalConfig if gopts.pager: @@ -359,7 +362,6 @@ class _Repo: Execute the subcommand. """ nonlocal result - cmd.CommonValidateOptions(copts, cargs) cmd.ValidateOptions(copts, cargs) this_manifest_only = copts.this_manifest_only diff --git a/tests/test_git_trace2_event_log.py b/tests/test_git_trace2_event_log.py index bbeb45350..be2d09b07 100644 --- a/tests/test_git_trace2_event_log.py +++ b/tests/test_git_trace2_event_log.py @@ -14,6 +14,8 @@ """Unittests for the git_trace2_event_log.py module.""" +import contextlib +import io import json import os import socket @@ -65,13 +67,13 @@ class EventLogTestCase(unittest.TestCase): def setUp(self): """Load the event_log module every time.""" - self._event_log_module = None + self._event_log = None # By default we initialize with the expected case where # repo launches us (so GIT_TRACE2_PARENT_SID is set). env = { self.PARENT_SID_KEY: self.PARENT_SID_VALUE, } - self._event_log_module = git_trace2_event_log.EventLog(env=env) + self._event_log = git_trace2_event_log.EventLog(env=env) self._log_data = None def verifyCommonKeys( @@ -112,13 +114,13 @@ class EventLogTestCase(unittest.TestCase): def test_initial_state_with_parent_sid(self): """Test initial state when 'GIT_TRACE2_PARENT_SID' is set by parent.""" - self.assertRegex(self._event_log_module.full_sid, self.FULL_SID_REGEX) + self.assertRegex(self._event_log.full_sid, self.FULL_SID_REGEX) def test_initial_state_no_parent_sid(self): """Test initial state when 'GIT_TRACE2_PARENT_SID' is not set.""" # Setup an empty environment dict (no parent sid). - self._event_log_module = git_trace2_event_log.EventLog(env={}) - self.assertRegex(self._event_log_module.full_sid, self.SELF_SID_REGEX) + self._event_log = git_trace2_event_log.EventLog(env={}) + self.assertRegex(self._event_log.full_sid, self.SELF_SID_REGEX) def test_version_event(self): """Test 'version' event data is valid. @@ -130,7 +132,7 @@ class EventLogTestCase(unittest.TestCase): """ with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: - log_path = self._event_log_module.Write(path=tempdir) + log_path = self._event_log.Write(path=tempdir) self._log_data = self.readLog(log_path) # A log with no added events should only have the version entry. @@ -150,9 +152,9 @@ class EventLogTestCase(unittest.TestCase): """ - self._event_log_module.StartEvent([]) + self._event_log.StartEvent([]) with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: - log_path = self._event_log_module.Write(path=tempdir) + log_path = self._event_log.Write(path=tempdir) self._log_data = self.readLog(log_path) self.assertEqual(len(self._log_data), 2) @@ -172,9 +174,9 @@ class EventLogTestCase(unittest.TestCase): """ - self._event_log_module.ExitEvent(None) + self._event_log.ExitEvent(None) with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: - log_path = self._event_log_module.Write(path=tempdir) + log_path = self._event_log.Write(path=tempdir) self._log_data = self.readLog(log_path) self.assertEqual(len(self._log_data), 2) @@ -193,9 +195,9 @@ class EventLogTestCase(unittest.TestCase): """ - self._event_log_module.ExitEvent(2) + self._event_log.ExitEvent(2) with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: - log_path = self._event_log_module.Write(path=tempdir) + log_path = self._event_log.Write(path=tempdir) self._log_data = self.readLog(log_path) self.assertEqual(len(self._log_data), 2) @@ -213,11 +215,9 @@ class EventLogTestCase(unittest.TestCase): """ - self._event_log_module.CommandEvent( - name="repo", subcommands=["init", "this"] - ) + self._event_log.CommandEvent(name="repo", subcommands=["init", "this"]) with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: - log_path = self._event_log_module.Write(path=tempdir) + log_path = self._event_log.Write(path=tempdir) self._log_data = self.readLog(log_path) self.assertEqual(len(self._log_data), 2) @@ -241,10 +241,10 @@ class EventLogTestCase(unittest.TestCase): "repo.partialclone": "true", "repo.partialclonefilter": "blob:none", } - self._event_log_module.DefParamRepoEvents(config) + self._event_log.DefParamRepoEvents(config) with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: - log_path = self._event_log_module.Write(path=tempdir) + log_path = self._event_log.Write(path=tempdir) self._log_data = self.readLog(log_path) self.assertEqual(len(self._log_data), 3) @@ -268,10 +268,10 @@ class EventLogTestCase(unittest.TestCase): "git.foo": "bar", "git.core.foo2": "baz", } - self._event_log_module.DefParamRepoEvents(config) + self._event_log.DefParamRepoEvents(config) with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: - log_path = self._event_log_module.Write(path=tempdir) + log_path = self._event_log.Write(path=tempdir) self._log_data = self.readLog(log_path) self.assertEqual(len(self._log_data), 1) @@ -292,10 +292,10 @@ class EventLogTestCase(unittest.TestCase): "repo.syncstate.superproject.sys.argv": ["--", "sync", "protobuf"], } prefix_value = "prefix" - self._event_log_module.LogDataConfigEvents(config, prefix_value) + self._event_log.LogDataConfigEvents(config, prefix_value) with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: - log_path = self._event_log_module.Write(path=tempdir) + log_path = self._event_log.Write(path=tempdir) self._log_data = self.readLog(log_path) self.assertEqual(len(self._log_data), 5) @@ -311,7 +311,7 @@ class EventLogTestCase(unittest.TestCase): key = self.remove_prefix(key, f"{prefix_value}/") value = event["value"] self.assertEqual( - self._event_log_module.GetDataEventName(value), event["event"] + self._event_log.GetDataEventName(value), event["event"] ) self.assertTrue(key in config and value == config[key]) @@ -324,9 +324,9 @@ class EventLogTestCase(unittest.TestCase): """ msg = "invalid option: --cahced" fmt = "invalid option: %s" - self._event_log_module.ErrorEvent(msg, fmt) + self._event_log.ErrorEvent(msg, fmt) with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: - log_path = self._event_log_module.Write(path=tempdir) + log_path = self._event_log.Write(path=tempdir) self._log_data = self.readLog(log_path) self.assertEqual(len(self._log_data), 2) @@ -341,32 +341,32 @@ class EventLogTestCase(unittest.TestCase): def test_write_with_filename(self): """Test Write() with a path to a file exits with None.""" - self.assertIsNone(self._event_log_module.Write(path="path/to/file")) + self.assertIsNone(self._event_log.Write(path="path/to/file")) def test_write_with_git_config(self): """Test Write() uses the git config path when 'git config' call succeeds.""" with tempfile.TemporaryDirectory(prefix="event_log_tests") as tempdir: with mock.patch.object( - self._event_log_module, + self._event_log, "_GetEventTargetPath", return_value=tempdir, ): self.assertEqual( - os.path.dirname(self._event_log_module.Write()), tempdir + os.path.dirname(self._event_log.Write()), tempdir ) def test_write_no_git_config(self): """Test Write() with no git config variable present exits with None.""" with mock.patch.object( - self._event_log_module, "_GetEventTargetPath", return_value=None + self._event_log, "_GetEventTargetPath", return_value=None ): - self.assertIsNone(self._event_log_module.Write()) + self.assertIsNone(self._event_log.Write()) def test_write_non_string(self): """Test Write() with non-string type for |path| throws TypeError.""" with self.assertRaises(TypeError): - self._event_log_module.Write(path=1234) + self._event_log.Write(path=1234) @unittest.skipIf(not hasattr(socket, "AF_UNIX"), "Requires AF_UNIX sockets") def test_write_socket(self): @@ -389,10 +389,8 @@ class EventLogTestCase(unittest.TestCase): with server_ready: server_ready.wait(timeout=120) - self._event_log_module.StartEvent([]) - path = self._event_log_module.Write( - path=f"af_unix:{socket_path}" - ) + self._event_log.StartEvent([]) + path = self._event_log.Write(path=f"af_unix:{socket_path}") finally: server_thread.join(timeout=5) @@ -405,3 +403,59 @@ class EventLogTestCase(unittest.TestCase): # Check for 'start' event specific fields. self.assertIn("argv", start_event) self.assertIsInstance(start_event["argv"], list) + + +class EventLogVerboseTestCase(unittest.TestCase): + """TestCase for the EventLog module verbose logging.""" + + def setUp(self): + self._event_log = git_trace2_event_log.EventLog(env={}) + + def test_write_socket_error_no_verbose(self): + """Test Write() suppression of socket errors when not verbose.""" + self._event_log.verbose = False + with contextlib.redirect_stderr( + io.StringIO() + ) as mock_stderr, mock.patch("socket.socket", side_effect=OSError): + self._event_log.Write(path="af_unix:stream:/tmp/test_sock") + self.assertEqual(mock_stderr.getvalue(), "") + + def test_write_socket_error_verbose(self): + """Test Write() printing of socket errors when verbose.""" + self._event_log.verbose = True + with contextlib.redirect_stderr( + io.StringIO() + ) as mock_stderr, mock.patch( + "socket.socket", side_effect=OSError("Mock error") + ): + self._event_log.Write(path="af_unix:stream:/tmp/test_sock") + self.assertIn( + "git trace2 logging failed: Mock error", + mock_stderr.getvalue(), + ) + + def test_write_file_error_no_verbose(self): + """Test Write() suppression of file errors when not verbose.""" + self._event_log.verbose = False + with contextlib.redirect_stderr( + io.StringIO() + ) as mock_stderr, mock.patch( + "tempfile.NamedTemporaryFile", side_effect=FileExistsError + ): + self._event_log.Write(path="/tmp") + self.assertEqual(mock_stderr.getvalue(), "") + + def test_write_file_error_verbose(self): + """Test Write() printing of file errors when verbose.""" + self._event_log.verbose = True + with contextlib.redirect_stderr( + io.StringIO() + ) as mock_stderr, mock.patch( + "tempfile.NamedTemporaryFile", + side_effect=FileExistsError("Mock error"), + ): + self._event_log.Write(path="/tmp") + self.assertIn( + "git trace2 logging failed: FileExistsError", + mock_stderr.getvalue(), + ) diff --git a/tests/test_subcmds.py b/tests/test_subcmds.py index 0683f1dde..3382d822d 100644 --- a/tests/test_subcmds.py +++ b/tests/test_subcmds.py @@ -135,3 +135,50 @@ class AllCommands(unittest.TestCase): # Make sure we aren't popping the wrong stuff. assert optparse.Option.CHECK_METHODS.pop(0) is _check_dest + + def test_common_validate_options(self): + """Verify CommonValidateOptions sets up expected fields.""" + for name, cls in subcmds.all_commands.items(): + cmd = cls() + opts, args = cmd.OptionParser.parse_args([]) + + # Verify the fields don't exist yet. + self.assertFalse( + hasattr(opts, "verbose"), + msg=f"{name}: has verbose before validation", + ) + self.assertFalse( + hasattr(opts, "quiet"), + msg=f"{name}: has quiet before validation", + ) + + cmd.CommonValidateOptions(opts, args) + + # Verify the fields exist now. + self.assertTrue( + hasattr(opts, "verbose"), + msg=f"{name}: missing verbose after validation", + ) + self.assertTrue( + hasattr(opts, "quiet"), + msg=f"{name}: missing quiet after validation", + ) + self.assertTrue( + hasattr(opts, "outer_manifest"), + msg=f"{name}: missing outer_manifest after validation", + ) + + def test_attribute_error_repro(self): + """Confirm that accessing verbose before CommonValidateOptions fails.""" + from subcmds.sync import Sync + + cmd = Sync() + opts, args = cmd.OptionParser.parse_args([]) + + # This confirms that without the fix in main.py, an AttributeError + # would be raised because CommonValidateOptions hasn't been called yet. + with self.assertRaises(AttributeError): + _ = opts.verbose + + cmd.CommonValidateOptions(opts, args) + self.assertTrue(hasattr(opts, "verbose"))