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>

1 files changed, 9 insertions, 352 deletions

diff --git a/git_trace2_event_log.py b/git_trace2_event_log.py
index f26f8311..57edee4d 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 @@ class EventLog(object):
     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
-
-        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.
+    def __init__(self, **kwargs):
+        super().__init__(repo_source_version=RepoSourceVersion(), **kwargs)
 
-        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()