Log ErrorEvent for failing GitCommands
Change-Id: I270af7401cff310349e736bef87e9b381cc4d016
Reviewed-on: https://gerrit-review.googlesource.com/c/git-repo/+/385054
Reviewed-by: Gavin Mak <gavinmak@google.com>
Commit-Queue: Jason Chang <jasonnc@google.com>
Tested-by: Jason Chang <jasonnc@google.com>
diff --git a/git_trace2_event_log.py b/git_trace2_event_log.py
index f26f831..57edee4 100644
--- a/git_trace2_event_log.py
+++ b/git_trace2_event_log.py
@@ -1,47 +1,9 @@
-# Copyright (C) 2020 The Android Open Source Project
-#
-# Licensed under the Apache License, Version 2.0 (the "License");
-# you may not use this file except in compliance with the License.
-# You may obtain a copy of the License at
-#
-# http://www.apache.org/licenses/LICENSE-2.0
-#
-# Unless required by applicable law or agreed to in writing, software
-# distributed under the License is distributed on an "AS IS" BASIS,
-# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
-# See the License for the specific language governing permissions and
-# limitations under the License.
-
-"""Provide event logging in the git trace2 EVENT format.
-
-The git trace2 EVENT format is defined at:
-https://www.kernel.org/pub/software/scm/git/docs/technical/api-trace2.html#_event_format
-https://git-scm.com/docs/api-trace2#_the_event_format_target
-
- Usage:
-
- git_trace_log = EventLog()
- git_trace_log.StartEvent()
- ...
- git_trace_log.ExitEvent()
- git_trace_log.Write()
-"""
-
-
-import datetime
-import errno
-import json
-import os
-import socket
-import sys
-import tempfile
-import threading
-
-from git_command import GitCommand
+from git_command import GetEventTargetPath
from git_command import RepoSourceVersion
+from git_trace2_event_log_base import BaseEventLog
-class EventLog(object):
+class EventLog(BaseEventLog):
"""Event log that records events that occurred during a repo invocation.
Events are written to the log as a consecutive JSON entries, one per line.
@@ -58,318 +20,13 @@
https://git-scm.com/docs/api-trace2#_event_format
"""
- def __init__(self, env=None):
- """Initializes the event log."""
- self._log = []
- # Try to get session-id (sid) from environment (setup in repo launcher).
- KEY = "GIT_TRACE2_PARENT_SID"
- if env is None:
- env = os.environ
+ def __init__(self, **kwargs):
+ super().__init__(repo_source_version=RepoSourceVersion(), **kwargs)
- self.start = datetime.datetime.utcnow()
-
- # Save both our sid component and the complete sid.
- # We use our sid component (self._sid) as the unique filename prefix and
- # the full sid (self._full_sid) in the log itself.
- self._sid = "repo-%s-P%08x" % (
- self.start.strftime("%Y%m%dT%H%M%SZ"),
- os.getpid(),
- )
- parent_sid = env.get(KEY)
- # Append our sid component to the parent sid (if it exists).
- if parent_sid is not None:
- self._full_sid = parent_sid + "/" + self._sid
- else:
- self._full_sid = self._sid
-
- # Set/update the environment variable.
- # Environment handling across systems is messy.
- try:
- env[KEY] = self._full_sid
- except UnicodeEncodeError:
- env[KEY] = self._full_sid.encode()
-
- # Add a version event to front of the log.
- self._AddVersionEvent()
-
- @property
- def full_sid(self):
- return self._full_sid
-
- def _AddVersionEvent(self):
- """Adds a 'version' event at the beginning of current log."""
- version_event = self._CreateEventDict("version")
- version_event["evt"] = "2"
- version_event["exe"] = RepoSourceVersion()
- self._log.insert(0, version_event)
-
- def _CreateEventDict(self, event_name):
- """Returns a dictionary with common keys/values for git trace2 events.
-
- Args:
- event_name: The event name.
-
- Returns:
- Dictionary with the common event fields populated.
- """
- return {
- "event": event_name,
- "sid": self._full_sid,
- "thread": threading.current_thread().name,
- "time": datetime.datetime.utcnow().isoformat() + "Z",
- }
-
- def StartEvent(self):
- """Append a 'start' event to the current log."""
- start_event = self._CreateEventDict("start")
- start_event["argv"] = sys.argv
- self._log.append(start_event)
-
- def ExitEvent(self, result):
- """Append an 'exit' event to the current log.
-
- Args:
- result: Exit code of the event
- """
- exit_event = self._CreateEventDict("exit")
-
- # Consider 'None' success (consistent with event_log result handling).
- if result is None:
- result = 0
- exit_event["code"] = result
- time_delta = datetime.datetime.utcnow() - self.start
- exit_event["t_abs"] = time_delta.total_seconds()
- self._log.append(exit_event)
-
- def CommandEvent(self, name, subcommands):
- """Append a 'command' event to the current log.
-
- Args:
- name: Name of the primary command (ex: repo, git)
- subcommands: List of the sub-commands (ex: version, init, sync)
- """
- command_event = self._CreateEventDict("command")
- command_event["name"] = name
- command_event["subcommands"] = subcommands
- self._log.append(command_event)
-
- def LogConfigEvents(self, config, event_dict_name):
- """Append a |event_dict_name| event for each config key in |config|.
-
- Args:
- config: Configuration dictionary.
- event_dict_name: Name of the event dictionary for items to be logged
- under.
- """
- for param, value in config.items():
- event = self._CreateEventDict(event_dict_name)
- event["param"] = param
- event["value"] = value
- self._log.append(event)
-
- def DefParamRepoEvents(self, config):
- """Append 'def_param' events for repo config keys to the current log.
-
- This appends one event for each repo.* config key.
-
- Args:
- config: Repo configuration dictionary
- """
- # Only output the repo.* config parameters.
- repo_config = {k: v for k, v in config.items() if k.startswith("repo.")}
- self.LogConfigEvents(repo_config, "def_param")
-
- def GetDataEventName(self, value):
- """Returns 'data-json' if the value is an array else returns 'data'."""
- return "data-json" if value[0] == "[" and value[-1] == "]" else "data"
-
- def LogDataConfigEvents(self, config, prefix):
- """Append a 'data' event for each entry in |config| to the current log.
-
- For each keyX and valueX of the config, "key" field of the event is
- '|prefix|/keyX' and the "value" of the "key" field is valueX.
-
- Args:
- config: Configuration dictionary.
- prefix: Prefix for each key that is logged.
- """
- for key, value in config.items():
- event = self._CreateEventDict(self.GetDataEventName(value))
- event["key"] = f"{prefix}/{key}"
- event["value"] = value
- self._log.append(event)
-
- def ErrorEvent(self, msg, fmt=None):
- """Append a 'error' event to the current log."""
- error_event = self._CreateEventDict("error")
- if fmt is None:
- fmt = msg
- error_event["msg"] = f"RepoErrorEvent:{msg}"
- error_event["fmt"] = f"RepoErrorEvent:{fmt}"
- self._log.append(error_event)
-
- def _GetEventTargetPath(self):
- """Get the 'trace2.eventtarget' path from git configuration.
-
- Returns:
- path: git config's 'trace2.eventtarget' path if it exists, or None
- """
- path = None
- cmd = ["config", "--get", "trace2.eventtarget"]
- # TODO(https://crbug.com/gerrit/13706): Use GitConfig when it supports
- # system git config variables.
- p = GitCommand(
- None, cmd, capture_stdout=True, capture_stderr=True, bare=True
- )
- retval = p.Wait()
- if retval == 0:
- # Strip trailing carriage-return in path.
- path = p.stdout.rstrip("\n")
- elif retval != 1:
- # `git config --get` is documented to produce an exit status of `1`
- # if the requested variable is not present in the configuration.
- # Report any other return value as an error.
- print(
- "repo: error: 'git config --get' call failed with return code: "
- "%r, stderr: %r" % (retval, p.stderr),
- file=sys.stderr,
- )
- return path
-
- def _WriteLog(self, write_fn):
- """Writes the log out using a provided writer function.
-
- Generate compact JSON output for each item in the log, and write it
- using write_fn.
-
- Args:
- write_fn: A function that accepts byts and writes them to a
- destination.
- """
-
- for e in self._log:
- # Dump in compact encoding mode.
- # See 'Compact encoding' in Python docs:
- # https://docs.python.org/3/library/json.html#module-json
- write_fn(
- json.dumps(e, indent=None, separators=(",", ":")).encode(
- "utf-8"
- )
- + b"\n"
- )
-
- def Write(self, path=None):
- """Writes the log out to a file or socket.
-
- Log is only written if 'path' or 'git config --get trace2.eventtarget'
- provide a valid path (or socket) to write logs to.
-
- Logging filename format follows the git trace2 style of being a unique
- (exclusive writable) file.
-
- Args:
- path: Path to where logs should be written. The path may have a
- prefix of the form "af_unix:[{stream|dgram}:]", in which case
- the path is treated as a Unix domain socket. See
- https://git-scm.com/docs/api-trace2#_enabling_a_target for
- details.
-
- Returns:
- log_path: Path to the log file or socket if log is written,
- otherwise None
- """
- log_path = None
- # If no logging path is specified, get the path from
- # 'trace2.eventtarget'.
+ def Write(self, path=None, **kwargs):
if path is None:
path = self._GetEventTargetPath()
+ return super().Write(path=path, **kwargs)
- # If no logging path is specified, exit.
- if path is None:
- return None
-
- path_is_socket = False
- socket_type = None
- if isinstance(path, str):
- parts = path.split(":", 1)
- if parts[0] == "af_unix" and len(parts) == 2:
- path_is_socket = True
- path = parts[1]
- parts = path.split(":", 1)
- if parts[0] == "stream" and len(parts) == 2:
- socket_type = socket.SOCK_STREAM
- path = parts[1]
- elif parts[0] == "dgram" and len(parts) == 2:
- socket_type = socket.SOCK_DGRAM
- path = parts[1]
- else:
- # Get absolute path.
- path = os.path.abspath(os.path.expanduser(path))
- else:
- raise TypeError("path: str required but got %s." % type(path))
-
- # Git trace2 requires a directory to write log to.
-
- # TODO(https://crbug.com/gerrit/13706): Support file (append) mode also.
- if not (path_is_socket or os.path.isdir(path)):
- return None
-
- if path_is_socket:
- if socket_type == socket.SOCK_STREAM or socket_type is None:
- try:
- with socket.socket(
- socket.AF_UNIX, socket.SOCK_STREAM
- ) as sock:
- sock.connect(path)
- self._WriteLog(sock.sendall)
- return f"af_unix:stream:{path}"
- except OSError as err:
- # If we tried to connect to a DGRAM socket using STREAM,
- # 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,
- )
- return None
- if socket_type == socket.SOCK_DGRAM or socket_type is None:
- try:
- with socket.socket(
- socket.AF_UNIX, socket.SOCK_DGRAM
- ) as sock:
- 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,
- )
- 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,
- )
- return None
-
- # Path is an absolute path
- # Use NamedTemporaryFile to generate a unique filename as required by
- # git trace2.
- try:
- with tempfile.NamedTemporaryFile(
- mode="xb", prefix=self._sid, dir=path, delete=False
- ) as f:
- # TODO(https://crbug.com/gerrit/13706): Support writing events
- # as they occur.
- self._WriteLog(f.write)
- log_path = f.name
- except FileExistsError as err:
- print(
- "repo: warning: git trace2 logging failed: %r" % err,
- file=sys.stderr,
- )
- return None
- return log_path
+ def _GetEventTargetPath(self):
+ return GetEventTargetPath()