summaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorJason Chang <jasonnc@google.com>2023-09-01 16:07:34 -0700
committerLUCI <gerrit-scoped@luci-project-accounts.iam.gserviceaccount.com>2023-09-06 18:22:33 +0000
commitf19b310f15e03e92075e7409c9d7f0956acc007d (patch)
tree554ef8c4dcf5aab828a9f74e3568e6dffee17eab
parent712e62b9b07f690abbb40e089a17f4ddec6ba952 (diff)
downloadgit-repo-f19b310f15e03e92075e7409c9d7f0956acc007d.tar.gz
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>
-rw-r--r--git_command.py120
-rw-r--r--git_trace2_event_log.py361
-rw-r--r--git_trace2_event_log_base.py352
3 files changed, 470 insertions, 363 deletions
diff --git a/git_command.py b/git_command.py
index a5cf514b..71b464c6 100644
--- a/git_command.py
+++ b/git_command.py
@@ -13,6 +13,7 @@
13# limitations under the License. 13# limitations under the License.
14 14
15import functools 15import functools
16import json
16import os 17import os
17import subprocess 18import subprocess
18import sys 19import sys
@@ -21,6 +22,7 @@ from typing import Any, Optional
21from error import GitError 22from error import GitError
22from error import RepoExitError 23from error import RepoExitError
23from git_refs import HEAD 24from git_refs import HEAD
25from git_trace2_event_log_base import BaseEventLog
24import platform_utils 26import platform_utils
25from repo_trace import IsTrace 27from repo_trace import IsTrace
26from repo_trace import REPO_TRACE 28from repo_trace import REPO_TRACE
@@ -45,6 +47,7 @@ GIT_DIR = "GIT_DIR"
45LAST_GITDIR = None 47LAST_GITDIR = None
46LAST_CWD = None 48LAST_CWD = None
47DEFAULT_GIT_FAIL_MESSAGE = "git command failure" 49DEFAULT_GIT_FAIL_MESSAGE = "git command failure"
50ERROR_EVENT_LOGGING_PREFIX = "RepoGitCommandError"
48# Common line length limit 51# Common line length limit
49GIT_ERROR_STDOUT_LINES = 1 52GIT_ERROR_STDOUT_LINES = 1
50GIT_ERROR_STDERR_LINES = 1 53GIT_ERROR_STDERR_LINES = 1
@@ -67,7 +70,7 @@ class _GitCall(object):
67 def fun(*cmdv): 70 def fun(*cmdv):
68 command = [name] 71 command = [name]
69 command.extend(cmdv) 72 command.extend(cmdv)
70 return GitCommand(None, command).Wait() == 0 73 return GitCommand(None, command, add_event_log=False).Wait() == 0
71 74
72 return fun 75 return fun
73 76
@@ -105,6 +108,41 @@ def RepoSourceVersion():
105 return ver 108 return ver
106 109
107 110
111@functools.lru_cache(maxsize=None)
112def GetEventTargetPath():
113 """Get the 'trace2.eventtarget' path from git configuration.
114
115 Returns:
116 path: git config's 'trace2.eventtarget' path if it exists, or None
117 """
118 path = None
119 cmd = ["config", "--get", "trace2.eventtarget"]
120 # TODO(https://crbug.com/gerrit/13706): Use GitConfig when it supports
121 # system git config variables.
122 p = GitCommand(
123 None,
124 cmd,
125 capture_stdout=True,
126 capture_stderr=True,
127 bare=True,
128 add_event_log=False,
129 )
130 retval = p.Wait()
131 if retval == 0:
132 # Strip trailing carriage-return in path.
133 path = p.stdout.rstrip("\n")
134 elif retval != 1:
135 # `git config --get` is documented to produce an exit status of `1`
136 # if the requested variable is not present in the configuration.
137 # Report any other return value as an error.
138 print(
139 "repo: error: 'git config --get' call failed with return code: "
140 "%r, stderr: %r" % (retval, p.stderr),
141 file=sys.stderr,
142 )
143 return path
144
145
108class UserAgent(object): 146class UserAgent(object):
109 """Mange User-Agent settings when talking to external services 147 """Mange User-Agent settings when talking to external services
110 148
@@ -247,6 +285,7 @@ class GitCommand(object):
247 gitdir=None, 285 gitdir=None,
248 objdir=None, 286 objdir=None,
249 verify_command=False, 287 verify_command=False,
288 add_event_log=True,
250 ): 289 ):
251 if project: 290 if project:
252 if not cwd: 291 if not cwd:
@@ -276,11 +315,12 @@ class GitCommand(object):
276 command = [GIT] 315 command = [GIT]
277 if bare: 316 if bare:
278 cwd = None 317 cwd = None
279 command.append(cmdv[0]) 318 command_name = cmdv[0]
319 command.append(command_name)
280 # Need to use the --progress flag for fetch/clone so output will be 320 # Need to use the --progress flag for fetch/clone so output will be
281 # displayed as by default git only does progress output if stderr is a 321 # displayed as by default git only does progress output if stderr is a
282 # TTY. 322 # TTY.
283 if sys.stderr.isatty() and cmdv[0] in ("fetch", "clone"): 323 if sys.stderr.isatty() and command_name in ("fetch", "clone"):
284 if "--progress" not in cmdv and "--quiet" not in cmdv: 324 if "--progress" not in cmdv and "--quiet" not in cmdv:
285 command.append("--progress") 325 command.append("--progress")
286 command.extend(cmdv[1:]) 326 command.extend(cmdv[1:])
@@ -293,6 +333,55 @@ class GitCommand(object):
293 else (subprocess.PIPE if capture_stderr else None) 333 else (subprocess.PIPE if capture_stderr else None)
294 ) 334 )
295 335
336 event_log = (
337 BaseEventLog(env=env, add_init_count=True)
338 if add_event_log
339 else None
340 )
341
342 try:
343 self._RunCommand(
344 command,
345 env,
346 stdin=stdin,
347 stdout=stdout,
348 stderr=stderr,
349 ssh_proxy=ssh_proxy,
350 cwd=cwd,
351 input=input,
352 )
353 self.VerifyCommand()
354 except GitCommandError as e:
355 if event_log is not None:
356 error_info = json.dumps(
357 {
358 "ErrorType": type(e).__name__,
359 "Project": e.project,
360 "CommandName": command_name,
361 "Message": str(e),
362 "ReturnCode": str(e.git_rc)
363 if e.git_rc is not None
364 else None,
365 }
366 )
367 event_log.ErrorEvent(
368 f"{ERROR_EVENT_LOGGING_PREFIX}:{error_info}"
369 )
370 event_log.Write(GetEventTargetPath())
371 if isinstance(e, GitPopenCommandError):
372 raise
373
374 def _RunCommand(
375 self,
376 command,
377 env,
378 stdin=None,
379 stdout=None,
380 stderr=None,
381 ssh_proxy=None,
382 cwd=None,
383 input=None,
384 ):
296 dbg = "" 385 dbg = ""
297 if IsTrace(): 386 if IsTrace():
298 global LAST_CWD 387 global LAST_CWD
@@ -346,10 +435,10 @@ class GitCommand(object):
346 stderr=stderr, 435 stderr=stderr,
347 ) 436 )
348 except Exception as e: 437 except Exception as e:
349 raise GitCommandError( 438 raise GitPopenCommandError(
350 message="%s: %s" % (command[1], e), 439 message="%s: %s" % (command[1], e),
351 project=project.name if project else None, 440 project=self.project.name if self.project else None,
352 command_args=cmdv, 441 command_args=self.cmdv,
353 ) 442 )
354 443
355 if ssh_proxy: 444 if ssh_proxy:
@@ -383,16 +472,14 @@ class GitCommand(object):
383 env.pop(key, None) 472 env.pop(key, None)
384 return env 473 return env
385 474
386 def Wait(self): 475 def VerifyCommand(self):
387 if not self.verify_command or self.rc == 0: 476 if self.rc == 0:
388 return self.rc 477 return None
389
390 stdout = ( 478 stdout = (
391 "\n".join(self.stdout.split("\n")[:GIT_ERROR_STDOUT_LINES]) 479 "\n".join(self.stdout.split("\n")[:GIT_ERROR_STDOUT_LINES])
392 if self.stdout 480 if self.stdout
393 else None 481 else None
394 ) 482 )
395
396 stderr = ( 483 stderr = (
397 "\n".join(self.stderr.split("\n")[:GIT_ERROR_STDERR_LINES]) 484 "\n".join(self.stderr.split("\n")[:GIT_ERROR_STDERR_LINES])
398 if self.stderr 485 if self.stderr
@@ -407,6 +494,11 @@ class GitCommand(object):
407 git_stderr=stderr, 494 git_stderr=stderr,
408 ) 495 )
409 496
497 def Wait(self):
498 if self.verify_command:
499 self.VerifyCommand()
500 return self.rc
501
410 502
411class GitRequireError(RepoExitError): 503class GitRequireError(RepoExitError):
412 """Error raised when git version is unavailable or invalid.""" 504 """Error raised when git version is unavailable or invalid."""
@@ -449,3 +541,9 @@ class GitCommandError(GitError):
449{self.git_stdout} 541{self.git_stdout}
450 Stderr: 542 Stderr:
451{self.git_stderr}""" 543{self.git_stderr}"""
544
545
546class GitPopenCommandError(GitError):
547 """
548 Error raised when subprocess.Popen fails for a GitCommand
549 """
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 @@
1# Copyright (C) 2020 The Android Open Source Project 1from git_command import GetEventTargetPath
2#
3# Licensed under the Apache License, Version 2.0 (the "License");
4# you may not use this file except in compliance with the License.
5# You may obtain a copy of the License at
6#
7# http://www.apache.org/licenses/LICENSE-2.0
8#
9# Unless required by applicable law or agreed to in writing, software
10# distributed under the License is distributed on an "AS IS" BASIS,
11# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12# See the License for the specific language governing permissions and
13# limitations under the License.
14
15"""Provide event logging in the git trace2 EVENT format.
16
17The git trace2 EVENT format is defined at:
18https://www.kernel.org/pub/software/scm/git/docs/technical/api-trace2.html#_event_format
19https://git-scm.com/docs/api-trace2#_the_event_format_target
20
21 Usage:
22
23 git_trace_log = EventLog()
24 git_trace_log.StartEvent()
25 ...
26 git_trace_log.ExitEvent()
27 git_trace_log.Write()
28"""
29
30
31import datetime
32import errno
33import json
34import os
35import socket
36import sys
37import tempfile
38import threading
39
40from git_command import GitCommand
41from git_command import RepoSourceVersion 2from git_command import RepoSourceVersion
3from git_trace2_event_log_base import BaseEventLog
42 4
43 5
44class EventLog(object): 6class EventLog(BaseEventLog):
45 """Event log that records events that occurred during a repo invocation. 7 """Event log that records events that occurred during a repo invocation.
46 8
47 Events are written to the log as a consecutive JSON entries, one per line. 9 Events are written to the log as a consecutive JSON entries, one per line.
@@ -58,318 +20,13 @@ class EventLog(object):
58 https://git-scm.com/docs/api-trace2#_event_format 20 https://git-scm.com/docs/api-trace2#_event_format
59 """ 21 """
60 22
61 def __init__(self, env=None): 23 def __init__(self, **kwargs):
62 """Initializes the event log.""" 24 super().__init__(repo_source_version=RepoSourceVersion(), **kwargs)
63 self._log = []
64 # Try to get session-id (sid) from environment (setup in repo launcher).
65 KEY = "GIT_TRACE2_PARENT_SID"
66 if env is None:
67 env = os.environ
68
69 self.start = datetime.datetime.utcnow()
70
71 # Save both our sid component and the complete sid.
72 # We use our sid component (self._sid) as the unique filename prefix and
73 # the full sid (self._full_sid) in the log itself.
74 self._sid = "repo-%s-P%08x" % (
75 self.start.strftime("%Y%m%dT%H%M%SZ"),
76 os.getpid(),
77 )
78 parent_sid = env.get(KEY)
79 # Append our sid component to the parent sid (if it exists).
80 if parent_sid is not None:
81 self._full_sid = parent_sid + "/" + self._sid
82 else:
83 self._full_sid = self._sid
84
85 # Set/update the environment variable.
86 # Environment handling across systems is messy.
87 try:
88 env[KEY] = self._full_sid
89 except UnicodeEncodeError:
90 env[KEY] = self._full_sid.encode()
91
92 # Add a version event to front of the log.
93 self._AddVersionEvent()
94
95 @property
96 def full_sid(self):
97 return self._full_sid
98
99 def _AddVersionEvent(self):
100 """Adds a 'version' event at the beginning of current log."""
101 version_event = self._CreateEventDict("version")
102 version_event["evt"] = "2"
103 version_event["exe"] = RepoSourceVersion()
104 self._log.insert(0, version_event)
105
106 def _CreateEventDict(self, event_name):
107 """Returns a dictionary with common keys/values for git trace2 events.
108
109 Args:
110 event_name: The event name.
111
112 Returns:
113 Dictionary with the common event fields populated.
114 """
115 return {
116 "event": event_name,
117 "sid": self._full_sid,
118 "thread": threading.current_thread().name,
119 "time": datetime.datetime.utcnow().isoformat() + "Z",
120 }
121
122 def StartEvent(self):
123 """Append a 'start' event to the current log."""
124 start_event = self._CreateEventDict("start")
125 start_event["argv"] = sys.argv
126 self._log.append(start_event)
127
128 def ExitEvent(self, result):
129 """Append an 'exit' event to the current log.
130
131 Args:
132 result: Exit code of the event
133 """
134 exit_event = self._CreateEventDict("exit")
135
136 # Consider 'None' success (consistent with event_log result handling).
137 if result is None:
138 result = 0
139 exit_event["code"] = result
140 time_delta = datetime.datetime.utcnow() - self.start
141 exit_event["t_abs"] = time_delta.total_seconds()
142 self._log.append(exit_event)
143
144 def CommandEvent(self, name, subcommands):
145 """Append a 'command' event to the current log.
146
147 Args:
148 name: Name of the primary command (ex: repo, git)
149 subcommands: List of the sub-commands (ex: version, init, sync)
150 """
151 command_event = self._CreateEventDict("command")
152 command_event["name"] = name
153 command_event["subcommands"] = subcommands
154 self._log.append(command_event)
155
156 def LogConfigEvents(self, config, event_dict_name):
157 """Append a |event_dict_name| event for each config key in |config|.
158
159 Args:
160 config: Configuration dictionary.
161 event_dict_name: Name of the event dictionary for items to be logged
162 under.
163 """
164 for param, value in config.items():
165 event = self._CreateEventDict(event_dict_name)
166 event["param"] = param
167 event["value"] = value
168 self._log.append(event)
169
170 def DefParamRepoEvents(self, config):
171 """Append 'def_param' events for repo config keys to the current log.
172 25
173 This appends one event for each repo.* config key. 26 def Write(self, path=None, **kwargs):
174
175 Args:
176 config: Repo configuration dictionary
177 """
178 # Only output the repo.* config parameters.
179 repo_config = {k: v for k, v in config.items() if k.startswith("repo.")}
180 self.LogConfigEvents(repo_config, "def_param")
181
182 def GetDataEventName(self, value):
183 """Returns 'data-json' if the value is an array else returns 'data'."""
184 return "data-json" if value[0] == "[" and value[-1] == "]" else "data"
185
186 def LogDataConfigEvents(self, config, prefix):
187 """Append a 'data' event for each entry in |config| to the current log.
188
189 For each keyX and valueX of the config, "key" field of the event is
190 '|prefix|/keyX' and the "value" of the "key" field is valueX.
191
192 Args:
193 config: Configuration dictionary.
194 prefix: Prefix for each key that is logged.
195 """
196 for key, value in config.items():
197 event = self._CreateEventDict(self.GetDataEventName(value))
198 event["key"] = f"{prefix}/{key}"
199 event["value"] = value
200 self._log.append(event)
201
202 def ErrorEvent(self, msg, fmt=None):
203 """Append a 'error' event to the current log."""
204 error_event = self._CreateEventDict("error")
205 if fmt is None:
206 fmt = msg
207 error_event["msg"] = f"RepoErrorEvent:{msg}"
208 error_event["fmt"] = f"RepoErrorEvent:{fmt}"
209 self._log.append(error_event)
210
211 def _GetEventTargetPath(self):
212 """Get the 'trace2.eventtarget' path from git configuration.
213
214 Returns:
215 path: git config's 'trace2.eventtarget' path if it exists, or None
216 """
217 path = None
218 cmd = ["config", "--get", "trace2.eventtarget"]
219 # TODO(https://crbug.com/gerrit/13706): Use GitConfig when it supports
220 # system git config variables.
221 p = GitCommand(
222 None, cmd, capture_stdout=True, capture_stderr=True, bare=True
223 )
224 retval = p.Wait()
225 if retval == 0:
226 # Strip trailing carriage-return in path.
227 path = p.stdout.rstrip("\n")
228 elif retval != 1:
229 # `git config --get` is documented to produce an exit status of `1`
230 # if the requested variable is not present in the configuration.
231 # Report any other return value as an error.
232 print(
233 "repo: error: 'git config --get' call failed with return code: "
234 "%r, stderr: %r" % (retval, p.stderr),
235 file=sys.stderr,
236 )
237 return path
238
239 def _WriteLog(self, write_fn):
240 """Writes the log out using a provided writer function.
241
242 Generate compact JSON output for each item in the log, and write it
243 using write_fn.
244
245 Args:
246 write_fn: A function that accepts byts and writes them to a
247 destination.
248 """
249
250 for e in self._log:
251 # Dump in compact encoding mode.
252 # See 'Compact encoding' in Python docs:
253 # https://docs.python.org/3/library/json.html#module-json
254 write_fn(
255 json.dumps(e, indent=None, separators=(",", ":")).encode(
256 "utf-8"
257 )
258 + b"\n"
259 )
260
261 def Write(self, path=None):
262 """Writes the log out to a file or socket.
263
264 Log is only written if 'path' or 'git config --get trace2.eventtarget'
265 provide a valid path (or socket) to write logs to.
266
267 Logging filename format follows the git trace2 style of being a unique
268 (exclusive writable) file.
269
270 Args:
271 path: Path to where logs should be written. The path may have a
272 prefix of the form "af_unix:[{stream|dgram}:]", in which case
273 the path is treated as a Unix domain socket. See
274 https://git-scm.com/docs/api-trace2#_enabling_a_target for
275 details.
276
277 Returns:
278 log_path: Path to the log file or socket if log is written,
279 otherwise None
280 """
281 log_path = None
282 # If no logging path is specified, get the path from
283 # 'trace2.eventtarget'.
284 if path is None: 27 if path is None:
285 path = self._GetEventTargetPath() 28 path = self._GetEventTargetPath()
29 return super().Write(path=path, **kwargs)
286 30
287 # If no logging path is specified, exit. 31 def _GetEventTargetPath(self):
288 if path is None: 32 return GetEventTargetPath()
289 return None
290
291 path_is_socket = False
292 socket_type = None
293 if isinstance(path, str):
294 parts = path.split(":", 1)
295 if parts[0] == "af_unix" and len(parts) == 2:
296 path_is_socket = True
297 path = parts[1]
298 parts = path.split(":", 1)
299 if parts[0] == "stream" and len(parts) == 2:
300 socket_type = socket.SOCK_STREAM
301 path = parts[1]
302 elif parts[0] == "dgram" and len(parts) == 2:
303 socket_type = socket.SOCK_DGRAM
304 path = parts[1]
305 else:
306 # Get absolute path.
307 path = os.path.abspath(os.path.expanduser(path))
308 else:
309 raise TypeError("path: str required but got %s." % type(path))
310
311 # Git trace2 requires a directory to write log to.
312
313 # TODO(https://crbug.com/gerrit/13706): Support file (append) mode also.
314 if not (path_is_socket or os.path.isdir(path)):
315 return None
316
317 if path_is_socket:
318 if socket_type == socket.SOCK_STREAM or socket_type is None:
319 try:
320 with socket.socket(
321 socket.AF_UNIX, socket.SOCK_STREAM
322 ) as sock:
323 sock.connect(path)
324 self._WriteLog(sock.sendall)
325 return f"af_unix:stream:{path}"
326 except OSError as err:
327 # If we tried to connect to a DGRAM socket using STREAM,
328 # ignore the attempt and continue to DGRAM below. Otherwise,
329 # issue a warning.
330 if err.errno != errno.EPROTOTYPE:
331 print(
332 f"repo: warning: git trace2 logging failed: {err}",
333 file=sys.stderr,
334 )
335 return None
336 if socket_type == socket.SOCK_DGRAM or socket_type is None:
337 try:
338 with socket.socket(
339 socket.AF_UNIX, socket.SOCK_DGRAM
340 ) as sock:
341 self._WriteLog(lambda bs: sock.sendto(bs, path))
342 return f"af_unix:dgram:{path}"
343 except OSError as err:
344 print(
345 f"repo: warning: git trace2 logging failed: {err}",
346 file=sys.stderr,
347 )
348 return None
349 # Tried to open a socket but couldn't connect (SOCK_STREAM) or write
350 # (SOCK_DGRAM).
351 print(
352 "repo: warning: git trace2 logging failed: could not write to "
353 "socket",
354 file=sys.stderr,
355 )
356 return None
357
358 # Path is an absolute path
359 # Use NamedTemporaryFile to generate a unique filename as required by
360 # git trace2.
361 try:
362 with tempfile.NamedTemporaryFile(
363 mode="xb", prefix=self._sid, dir=path, delete=False
364 ) as f:
365 # TODO(https://crbug.com/gerrit/13706): Support writing events
366 # as they occur.
367 self._WriteLog(f.write)
368 log_path = f.name
369 except FileExistsError as err:
370 print(
371 "repo: warning: git trace2 logging failed: %r" % err,
372 file=sys.stderr,
373 )
374 return None
375 return log_path
diff --git a/git_trace2_event_log_base.py b/git_trace2_event_log_base.py
new file mode 100644
index 00000000..a111668a
--- /dev/null
+++ b/git_trace2_event_log_base.py
@@ -0,0 +1,352 @@
1# Copyright (C) 2020 The Android Open Source Project
2#
3# Licensed under the Apache License, Version 2.0 (the "License");
4# you may not use this file except in compliance with the License.
5# You may obtain a copy of the License at
6#
7# http://www.apache.org/licenses/LICENSE-2.0
8#
9# Unless required by applicable law or agreed to in writing, software
10# distributed under the License is distributed on an "AS IS" BASIS,
11# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12# See the License for the specific language governing permissions and
13# limitations under the License.
14
15"""Provide event logging in the git trace2 EVENT format.
16
17The git trace2 EVENT format is defined at:
18https://www.kernel.org/pub/software/scm/git/docs/technical/api-trace2.html#_event_format
19https://git-scm.com/docs/api-trace2#_the_event_format_target
20
21 Usage:
22
23 git_trace_log = EventLog()
24 git_trace_log.StartEvent()
25 ...
26 git_trace_log.ExitEvent()
27 git_trace_log.Write()
28"""
29
30
31import datetime
32import errno
33import json
34import os
35import socket
36import sys
37import tempfile
38import threading
39
40
41# BaseEventLog __init__ Counter that is consistent within the same process
42p_init_count = 0
43
44
45class BaseEventLog(object):
46 """Event log that records events that occurred during a repo invocation.
47
48 Events are written to the log as a consecutive JSON entries, one per line.
49 Entries follow the git trace2 EVENT format.
50
51 Each entry contains the following common keys:
52 - event: The event name
53 - sid: session-id - Unique string to allow process instance to be
54 identified.
55 - thread: The thread name.
56 - time: is the UTC time of the event.
57
58 Valid 'event' names and event specific fields are documented here:
59 https://git-scm.com/docs/api-trace2#_event_format
60 """
61
62 def __init__(
63 self, env=None, repo_source_version=None, add_init_count=False
64 ):
65 """Initializes the event log."""
66 global p_init_count
67 p_init_count += 1
68 self._log = []
69 # Try to get session-id (sid) from environment (setup in repo launcher).
70 KEY = "GIT_TRACE2_PARENT_SID"
71 if env is None:
72 env = os.environ
73
74 self.start = datetime.datetime.utcnow()
75
76 # Save both our sid component and the complete sid.
77 # We use our sid component (self._sid) as the unique filename prefix and
78 # the full sid (self._full_sid) in the log itself.
79 self._sid = "repo-%s-P%08x" % (
80 self.start.strftime("%Y%m%dT%H%M%SZ"),
81 os.getpid(),
82 )
83
84 if add_init_count:
85 self._sid = f"{self._sid}-{p_init_count}"
86
87 parent_sid = env.get(KEY)
88 # Append our sid component to the parent sid (if it exists).
89 if parent_sid is not None:
90 self._full_sid = parent_sid + "/" + self._sid
91 else:
92 self._full_sid = self._sid
93
94 # Set/update the environment variable.
95 # Environment handling across systems is messy.
96 try:
97 env[KEY] = self._full_sid
98 except UnicodeEncodeError:
99 env[KEY] = self._full_sid.encode()
100
101 if repo_source_version is not None:
102 # Add a version event to front of the log.
103 self._AddVersionEvent(repo_source_version)
104
105 @property
106 def full_sid(self):
107 return self._full_sid
108
109 def _AddVersionEvent(self, repo_source_version):
110 """Adds a 'version' event at the beginning of current log."""
111 version_event = self._CreateEventDict("version")
112 version_event["evt"] = "2"
113 version_event["exe"] = repo_source_version
114 self._log.insert(0, version_event)
115
116 def _CreateEventDict(self, event_name):
117 """Returns a dictionary with common keys/values for git trace2 events.
118
119 Args:
120 event_name: The event name.
121
122 Returns:
123 Dictionary with the common event fields populated.
124 """
125 return {
126 "event": event_name,
127 "sid": self._full_sid,
128 "thread": threading.current_thread().name,
129 "time": datetime.datetime.utcnow().isoformat() + "Z",
130 }
131
132 def StartEvent(self):
133 """Append a 'start' event to the current log."""
134 start_event = self._CreateEventDict("start")
135 start_event["argv"] = sys.argv
136 self._log.append(start_event)
137
138 def ExitEvent(self, result):
139 """Append an 'exit' event to the current log.
140
141 Args:
142 result: Exit code of the event
143 """
144 exit_event = self._CreateEventDict("exit")
145
146 # Consider 'None' success (consistent with event_log result handling).
147 if result is None:
148 result = 0
149 exit_event["code"] = result
150 time_delta = datetime.datetime.utcnow() - self.start
151 exit_event["t_abs"] = time_delta.total_seconds()
152 self._log.append(exit_event)
153
154 def CommandEvent(self, name, subcommands):
155 """Append a 'command' event to the current log.
156
157 Args:
158 name: Name of the primary command (ex: repo, git)
159 subcommands: List of the sub-commands (ex: version, init, sync)
160 """
161 command_event = self._CreateEventDict("command")
162 command_event["name"] = name
163 command_event["subcommands"] = subcommands
164 self._log.append(command_event)
165
166 def LogConfigEvents(self, config, event_dict_name):
167 """Append a |event_dict_name| event for each config key in |config|.
168
169 Args:
170 config: Configuration dictionary.
171 event_dict_name: Name of the event dictionary for items to be logged
172 under.
173 """
174 for param, value in config.items():
175 event = self._CreateEventDict(event_dict_name)
176 event["param"] = param
177 event["value"] = value
178 self._log.append(event)
179
180 def DefParamRepoEvents(self, config):
181 """Append 'def_param' events for repo config keys to the current log.
182
183 This appends one event for each repo.* config key.
184
185 Args:
186 config: Repo configuration dictionary
187 """
188 # Only output the repo.* config parameters.
189 repo_config = {k: v for k, v in config.items() if k.startswith("repo.")}
190 self.LogConfigEvents(repo_config, "def_param")
191
192 def GetDataEventName(self, value):
193 """Returns 'data-json' if the value is an array else returns 'data'."""
194 return "data-json" if value[0] == "[" and value[-1] == "]" else "data"
195
196 def LogDataConfigEvents(self, config, prefix):
197 """Append a 'data' event for each entry in |config| to the current log.
198
199 For each keyX and valueX of the config, "key" field of the event is
200 '|prefix|/keyX' and the "value" of the "key" field is valueX.
201
202 Args:
203 config: Configuration dictionary.
204 prefix: Prefix for each key that is logged.
205 """
206 for key, value in config.items():
207 event = self._CreateEventDict(self.GetDataEventName(value))
208 event["key"] = f"{prefix}/{key}"
209 event["value"] = value
210 self._log.append(event)
211
212 def ErrorEvent(self, msg, fmt=None):
213 """Append a 'error' event to the current log."""
214 error_event = self._CreateEventDict("error")
215 if fmt is None:
216 fmt = msg
217 error_event["msg"] = f"RepoErrorEvent:{msg}"
218 error_event["fmt"] = f"RepoErrorEvent:{fmt}"
219 self._log.append(error_event)
220
221 def _WriteLog(self, write_fn):
222 """Writes the log out using a provided writer function.
223
224 Generate compact JSON output for each item in the log, and write it
225 using write_fn.
226
227 Args:
228 write_fn: A function that accepts byts and writes them to a
229 destination.
230 """
231
232 for e in self._log:
233 # Dump in compact encoding mode.
234 # See 'Compact encoding' in Python docs:
235 # https://docs.python.org/3/library/json.html#module-json
236 write_fn(
237 json.dumps(e, indent=None, separators=(",", ":")).encode(
238 "utf-8"
239 )
240 + b"\n"
241 )
242
243 def Write(self, path=None):
244 """Writes the log out to a file or socket.
245
246 Log is only written if 'path' or 'git config --get trace2.eventtarget'
247 provide a valid path (or socket) to write logs to.
248
249 Logging filename format follows the git trace2 style of being a unique
250 (exclusive writable) file.
251
252 Args:
253 path: Path to where logs should be written. The path may have a
254 prefix of the form "af_unix:[{stream|dgram}:]", in which case
255 the path is treated as a Unix domain socket. See
256 https://git-scm.com/docs/api-trace2#_enabling_a_target for
257 details.
258
259 Returns:
260 log_path: Path to the log file or socket if log is written,
261 otherwise None
262 """
263 log_path = None
264 # If no logging path is specified, exit.
265 if path is None:
266 return None
267
268 path_is_socket = False
269 socket_type = None
270 if isinstance(path, str):
271 parts = path.split(":", 1)
272 if parts[0] == "af_unix" and len(parts) == 2:
273 path_is_socket = True
274 path = parts[1]
275 parts = path.split(":", 1)
276 if parts[0] == "stream" and len(parts) == 2:
277 socket_type = socket.SOCK_STREAM
278 path = parts[1]
279 elif parts[0] == "dgram" and len(parts) == 2:
280 socket_type = socket.SOCK_DGRAM
281 path = parts[1]
282 else:
283 # Get absolute path.
284 path = os.path.abspath(os.path.expanduser(path))
285 else:
286 raise TypeError("path: str required but got %s." % type(path))
287
288 # Git trace2 requires a directory to write log to.
289
290 # TODO(https://crbug.com/gerrit/13706): Support file (append) mode also.
291 if not (path_is_socket or os.path.isdir(path)):
292 return None
293
294 if path_is_socket:
295 if socket_type == socket.SOCK_STREAM or socket_type is None:
296 try:
297 with socket.socket(
298 socket.AF_UNIX, socket.SOCK_STREAM
299 ) as sock:
300 sock.connect(path)
301 self._WriteLog(sock.sendall)
302 return f"af_unix:stream:{path}"
303 except OSError as err:
304 # If we tried to connect to a DGRAM socket using STREAM,
305 # ignore the attempt and continue to DGRAM below. Otherwise,
306 # issue a warning.
307 if err.errno != errno.EPROTOTYPE:
308 print(
309 f"repo: warning: git trace2 logging failed: {err}",
310 file=sys.stderr,
311 )
312 return None
313 if socket_type == socket.SOCK_DGRAM or socket_type is None:
314 try:
315 with socket.socket(
316 socket.AF_UNIX, socket.SOCK_DGRAM
317 ) as sock:
318 self._WriteLog(lambda bs: sock.sendto(bs, path))
319 return f"af_unix:dgram:{path}"
320 except OSError as err:
321 print(
322 f"repo: warning: git trace2 logging failed: {err}",
323 file=sys.stderr,
324 )
325 return None
326 # Tried to open a socket but couldn't connect (SOCK_STREAM) or write
327 # (SOCK_DGRAM).
328 print(
329 "repo: warning: git trace2 logging failed: could not write to "
330 "socket",
331 file=sys.stderr,
332 )
333 return None
334
335 # Path is an absolute path
336 # Use NamedTemporaryFile to generate a unique filename as required by
337 # git trace2.
338 try:
339 with tempfile.NamedTemporaryFile(
340 mode="xb", prefix=self._sid, dir=path, delete=False
341 ) as f:
342 # TODO(https://crbug.com/gerrit/13706): Support writing events
343 # as they occur.
344 self._WriteLog(f.write)
345 log_path = f.name
346 except FileExistsError as err:
347 print(
348 "repo: warning: git trace2 logging failed: %r" % err,
349 file=sys.stderr,
350 )
351 return None
352 return log_path