| # 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, RepoSourceVersion |
| |
| |
| class EventLog(object): |
| """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. |
| Entries follow the git trace2 EVENT format. |
| |
| Each entry contains the following common keys: |
| - event: The event name |
| - sid: session-id - Unique string to allow process instance to be identified. |
| - thread: The thread name. |
| - time: is the UTC time of the event. |
| |
| Valid 'event' names and event specific fields are documented here: |
| 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 |
| |
| now = 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' % (now.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 the 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 |
| 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 a 'def_param' event for each repo.* config key to the current log. |
| |
| 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 config key/value 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): |
| """Append a 'error' event to the current log.""" |
| error_event = self._CreateEventDict('error') |
| error_event['msg'] = msg |
| error_event['fmt'] = 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'. |
| if path is None: |
| path = self._GetEventTargetPath() |
| |
| # 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 |