summaryrefslogtreecommitdiffstats
path: root/git_trace2_event_log.py
diff options
context:
space:
mode:
authorGavin Mak <gavinmak@google.com>2023-03-11 06:46:20 +0000
committerLUCI <gerrit-scoped@luci-project-accounts.iam.gserviceaccount.com>2023-03-22 17:46:28 +0000
commitea2e330e43c182dc16b0111ebc69ee5a71ee4ce1 (patch)
treedc33ba0e56825b3e007d0589891756724725a465 /git_trace2_event_log.py
parent1604cf255f8c1786a23388db6d5277ac7949a24a (diff)
downloadgit-repo-ea2e330e43c182dc16b0111ebc69ee5a71ee4ce1.tar.gz
Format codebase with black and check formatting in CQ
Apply rules set by https://gerrit-review.googlesource.com/c/git-repo/+/362954/ across the codebase and fix any lingering errors caught by flake8. Also check black formatting in run_tests (and CQ). Bug: b/267675342 Change-Id: I972d77649dac351150dcfeb1cd1ad0ea2efc1956 Reviewed-on: https://gerrit-review.googlesource.com/c/git-repo/+/363474 Reviewed-by: Mike Frysinger <vapier@google.com> Tested-by: Gavin Mak <gavinmak@google.com> Commit-Queue: Gavin Mak <gavinmak@google.com>
Diffstat (limited to 'git_trace2_event_log.py')
-rw-r--r--git_trace2_event_log.py595
1 files changed, 317 insertions, 278 deletions
diff --git a/git_trace2_event_log.py b/git_trace2_event_log.py
index 2edab0e1..d90e9039 100644
--- a/git_trace2_event_log.py
+++ b/git_trace2_event_log.py
@@ -41,291 +41,330 @@ from git_command import GitCommand, RepoSourceVersion
41 41
42 42
43class EventLog(object): 43class EventLog(object):
44 """Event log that records events that occurred during a repo invocation. 44 """Event log that records events that occurred during a repo invocation.
45
46 Events are written to the log as a consecutive JSON entries, one per line.
47 Entries follow the git trace2 EVENT format.
48
49 Each entry contains the following common keys:
50 - event: The event name
51 - sid: session-id - Unique string to allow process instance to be identified.
52 - thread: The thread name.
53 - time: is the UTC time of the event.
54
55 Valid 'event' names and event specific fields are documented here:
56 https://git-scm.com/docs/api-trace2#_event_format
57 """
58
59 def __init__(self, env=None):
60 """Initializes the event log."""
61 self._log = []
62 # Try to get session-id (sid) from environment (setup in repo launcher).
63 KEY = 'GIT_TRACE2_PARENT_SID'
64 if env is None:
65 env = os.environ
66
67 now = datetime.datetime.utcnow()
68
69 # Save both our sid component and the complete sid.
70 # We use our sid component (self._sid) as the unique filename prefix and
71 # the full sid (self._full_sid) in the log itself.
72 self._sid = 'repo-%s-P%08x' % (now.strftime('%Y%m%dT%H%M%SZ'), os.getpid())
73 parent_sid = env.get(KEY)
74 # Append our sid component to the parent sid (if it exists).
75 if parent_sid is not None:
76 self._full_sid = parent_sid + '/' + self._sid
77 else:
78 self._full_sid = self._sid
79
80 # Set/update the environment variable.
81 # Environment handling across systems is messy.
82 try:
83 env[KEY] = self._full_sid
84 except UnicodeEncodeError:
85 env[KEY] = self._full_sid.encode()
86
87 # Add a version event to front of the log.
88 self._AddVersionEvent()
89
90 @property
91 def full_sid(self):
92 return self._full_sid
93
94 def _AddVersionEvent(self):
95 """Adds a 'version' event at the beginning of current log."""
96 version_event = self._CreateEventDict('version')
97 version_event['evt'] = "2"
98 version_event['exe'] = RepoSourceVersion()
99 self._log.insert(0, version_event)
100
101 def _CreateEventDict(self, event_name):
102 """Returns a dictionary with the common keys/values for git trace2 events.
103
104 Args:
105 event_name: The event name.
106
107 Returns:
108 Dictionary with the common event fields populated.
109 """
110 return {
111 'event': event_name,
112 'sid': self._full_sid,
113 'thread': threading.current_thread().name,
114 'time': datetime.datetime.utcnow().isoformat() + 'Z',
115 }
116
117 def StartEvent(self):
118 """Append a 'start' event to the current log."""
119 start_event = self._CreateEventDict('start')
120 start_event['argv'] = sys.argv
121 self._log.append(start_event)
122
123 def ExitEvent(self, result):
124 """Append an 'exit' event to the current log.
125
126 Args:
127 result: Exit code of the event
128 """
129 exit_event = self._CreateEventDict('exit')
130
131 # Consider 'None' success (consistent with event_log result handling).
132 if result is None:
133 result = 0
134 exit_event['code'] = result
135 self._log.append(exit_event)
136
137 def CommandEvent(self, name, subcommands):
138 """Append a 'command' event to the current log.
139
140 Args:
141 name: Name of the primary command (ex: repo, git)
142 subcommands: List of the sub-commands (ex: version, init, sync)
143 """
144 command_event = self._CreateEventDict('command')
145 command_event['name'] = name
146 command_event['subcommands'] = subcommands
147 self._log.append(command_event)
148 45
149 def LogConfigEvents(self, config, event_dict_name): 46 Events are written to the log as a consecutive JSON entries, one per line.
150 """Append a |event_dict_name| event for each config key in |config|. 47 Entries follow the git trace2 EVENT format.
151 48
152 Args: 49 Each entry contains the following common keys:
153 config: Configuration dictionary. 50 - event: The event name
154 event_dict_name: Name of the event dictionary for items to be logged under. 51 - sid: session-id - Unique string to allow process instance to be
155 """ 52 identified.
156 for param, value in config.items(): 53 - thread: The thread name.
157 event = self._CreateEventDict(event_dict_name) 54 - time: is the UTC time of the event.
158 event['param'] = param
159 event['value'] = value
160 self._log.append(event)
161
162 def DefParamRepoEvents(self, config):
163 """Append a 'def_param' event for each repo.* config key to the current log.
164 55
165 Args: 56 Valid 'event' names and event specific fields are documented here:
166 config: Repo configuration dictionary 57 https://git-scm.com/docs/api-trace2#_event_format
167 """ 58 """
168 # Only output the repo.* config parameters.
169 repo_config = {k: v for k, v in config.items() if k.startswith('repo.')}
170 self.LogConfigEvents(repo_config, 'def_param')
171
172 def GetDataEventName(self, value):
173 """Returns 'data-json' if the value is an array else returns 'data'."""
174 return 'data-json' if value[0] == '[' and value[-1] == ']' else 'data'
175 59
176 def LogDataConfigEvents(self, config, prefix): 60 def __init__(self, env=None):
177 """Append a 'data' event for each config key/value in |config| to the current log. 61 """Initializes the event log."""
178 62 self._log = []
179 For each keyX and valueX of the config, "key" field of the event is '|prefix|/keyX' 63 # Try to get session-id (sid) from environment (setup in repo launcher).
180 and the "value" of the "key" field is valueX. 64 KEY = "GIT_TRACE2_PARENT_SID"
181 65 if env is None:
182 Args: 66 env = os.environ
183 config: Configuration dictionary. 67
184 prefix: Prefix for each key that is logged. 68 now = datetime.datetime.utcnow()
185 """ 69
186 for key, value in config.items(): 70 # Save both our sid component and the complete sid.
187 event = self._CreateEventDict(self.GetDataEventName(value)) 71 # We use our sid component (self._sid) as the unique filename prefix and
188 event['key'] = f'{prefix}/{key}' 72 # the full sid (self._full_sid) in the log itself.
189 event['value'] = value 73 self._sid = "repo-%s-P%08x" % (
190 self._log.append(event) 74 now.strftime("%Y%m%dT%H%M%SZ"),
191 75 os.getpid(),
192 def ErrorEvent(self, msg, fmt): 76 )
193 """Append a 'error' event to the current log.""" 77 parent_sid = env.get(KEY)
194 error_event = self._CreateEventDict('error') 78 # Append our sid component to the parent sid (if it exists).
195 error_event['msg'] = msg 79 if parent_sid is not None:
196 error_event['fmt'] = fmt 80 self._full_sid = parent_sid + "/" + self._sid
197 self._log.append(error_event) 81 else:
198 82 self._full_sid = self._sid
199 def _GetEventTargetPath(self): 83
200 """Get the 'trace2.eventtarget' path from git configuration. 84 # Set/update the environment variable.
201 85 # Environment handling across systems is messy.
202 Returns: 86 try:
203 path: git config's 'trace2.eventtarget' path if it exists, or None 87 env[KEY] = self._full_sid
204 """ 88 except UnicodeEncodeError:
205 path = None 89 env[KEY] = self._full_sid.encode()
206 cmd = ['config', '--get', 'trace2.eventtarget'] 90
207 # TODO(https://crbug.com/gerrit/13706): Use GitConfig when it supports 91 # Add a version event to front of the log.
208 # system git config variables. 92 self._AddVersionEvent()
209 p = GitCommand(None, cmd, capture_stdout=True, capture_stderr=True, 93
210 bare=True) 94 @property
211 retval = p.Wait() 95 def full_sid(self):
212 if retval == 0: 96 return self._full_sid
213 # Strip trailing carriage-return in path. 97
214 path = p.stdout.rstrip('\n') 98 def _AddVersionEvent(self):
215 elif retval != 1: 99 """Adds a 'version' event at the beginning of current log."""
216 # `git config --get` is documented to produce an exit status of `1` if 100 version_event = self._CreateEventDict("version")
217 # the requested variable is not present in the configuration. Report any 101 version_event["evt"] = "2"
218 # other return value as an error. 102 version_event["exe"] = RepoSourceVersion()
219 print("repo: error: 'git config --get' call failed with return code: %r, stderr: %r" % ( 103 self._log.insert(0, version_event)
220 retval, p.stderr), file=sys.stderr) 104
221 return path 105 def _CreateEventDict(self, event_name):
222 106 """Returns a dictionary with common keys/values for git trace2 events.
223 def _WriteLog(self, write_fn): 107
224 """Writes the log out using a provided writer function. 108 Args:
225 109 event_name: The event name.
226 Generate compact JSON output for each item in the log, and write it using 110
227 write_fn. 111 Returns:
228 112 Dictionary with the common event fields populated.
229 Args: 113 """
230 write_fn: A function that accepts byts and writes them to a destination. 114 return {
231 """ 115 "event": event_name,
232 116 "sid": self._full_sid,
233 for e in self._log: 117 "thread": threading.current_thread().name,
234 # Dump in compact encoding mode. 118 "time": datetime.datetime.utcnow().isoformat() + "Z",
235 # See 'Compact encoding' in Python docs: 119 }
236 # https://docs.python.org/3/library/json.html#module-json 120
237 write_fn(json.dumps(e, indent=None, separators=(',', ':')).encode('utf-8') + b'\n') 121 def StartEvent(self):
238 122 """Append a 'start' event to the current log."""
239 def Write(self, path=None): 123 start_event = self._CreateEventDict("start")
240 """Writes the log out to a file or socket. 124 start_event["argv"] = sys.argv
241 125 self._log.append(start_event)
242 Log is only written if 'path' or 'git config --get trace2.eventtarget' 126
243 provide a valid path (or socket) to write logs to. 127 def ExitEvent(self, result):
128 """Append an 'exit' event to the current log.
129
130 Args:
131 result: Exit code of the event
132 """
133 exit_event = self._CreateEventDict("exit")
134
135 # Consider 'None' success (consistent with event_log result handling).
136 if result is None:
137 result = 0
138 exit_event["code"] = result
139 self._log.append(exit_event)
140
141 def CommandEvent(self, name, subcommands):
142 """Append a 'command' event to the current log.
143
144 Args:
145 name: Name of the primary command (ex: repo, git)
146 subcommands: List of the sub-commands (ex: version, init, sync)
147 """
148 command_event = self._CreateEventDict("command")
149 command_event["name"] = name
150 command_event["subcommands"] = subcommands
151 self._log.append(command_event)
152
153 def LogConfigEvents(self, config, event_dict_name):
154 """Append a |event_dict_name| event for each config key in |config|.
155
156 Args:
157 config: Configuration dictionary.
158 event_dict_name: Name of the event dictionary for items to be logged
159 under.
160 """
161 for param, value in config.items():
162 event = self._CreateEventDict(event_dict_name)
163 event["param"] = param
164 event["value"] = value
165 self._log.append(event)
166
167 def DefParamRepoEvents(self, config):
168 """Append 'def_param' events for repo config keys to the current log.
169
170 This appends one event for each repo.* config key.
171
172 Args:
173 config: Repo configuration dictionary
174 """
175 # Only output the repo.* config parameters.
176 repo_config = {k: v for k, v in config.items() if k.startswith("repo.")}
177 self.LogConfigEvents(repo_config, "def_param")
178
179 def GetDataEventName(self, value):
180 """Returns 'data-json' if the value is an array else returns 'data'."""
181 return "data-json" if value[0] == "[" and value[-1] == "]" else "data"
182
183 def LogDataConfigEvents(self, config, prefix):
184 """Append a 'data' event for each entry in |config| to the current log.
185
186 For each keyX and valueX of the config, "key" field of the event is
187 '|prefix|/keyX' and the "value" of the "key" field is valueX.
188
189 Args:
190 config: Configuration dictionary.
191 prefix: Prefix for each key that is logged.
192 """
193 for key, value in config.items():
194 event = self._CreateEventDict(self.GetDataEventName(value))
195 event["key"] = f"{prefix}/{key}"
196 event["value"] = value
197 self._log.append(event)
198
199 def ErrorEvent(self, msg, fmt):
200 """Append a 'error' event to the current log."""
201 error_event = self._CreateEventDict("error")
202 error_event["msg"] = msg
203 error_event["fmt"] = fmt
204 self._log.append(error_event)
205
206 def _GetEventTargetPath(self):
207 """Get the 'trace2.eventtarget' path from git configuration.
208
209 Returns:
210 path: git config's 'trace2.eventtarget' path if it exists, or None
211 """
212 path = None
213 cmd = ["config", "--get", "trace2.eventtarget"]
214 # TODO(https://crbug.com/gerrit/13706): Use GitConfig when it supports
215 # system git config variables.
216 p = GitCommand(
217 None, cmd, capture_stdout=True, capture_stderr=True, bare=True
218 )
219 retval = p.Wait()
220 if retval == 0:
221 # Strip trailing carriage-return in path.
222 path = p.stdout.rstrip("\n")
223 elif retval != 1:
224 # `git config --get` is documented to produce an exit status of `1`
225 # if the requested variable is not present in the configuration.
226 # Report any other return value as an error.
227 print(
228 "repo: error: 'git config --get' call failed with return code: "
229 "%r, stderr: %r" % (retval, p.stderr),
230 file=sys.stderr,
231 )
232 return path
233
234 def _WriteLog(self, write_fn):
235 """Writes the log out using a provided writer function.
236
237 Generate compact JSON output for each item in the log, and write it
238 using write_fn.
239
240 Args:
241 write_fn: A function that accepts byts and writes them to a
242 destination.
243 """
244
245 for e in self._log:
246 # Dump in compact encoding mode.
247 # See 'Compact encoding' in Python docs:
248 # https://docs.python.org/3/library/json.html#module-json
249 write_fn(
250 json.dumps(e, indent=None, separators=(",", ":")).encode(
251 "utf-8"
252 )
253 + b"\n"
254 )
255
256 def Write(self, path=None):
257 """Writes the log out to a file or socket.
258
259 Log is only written if 'path' or 'git config --get trace2.eventtarget'
260 provide a valid path (or socket) to write logs to.
261
262 Logging filename format follows the git trace2 style of being a unique
263 (exclusive writable) file.
264
265 Args:
266 path: Path to where logs should be written. The path may have a
267 prefix of the form "af_unix:[{stream|dgram}:]", in which case
268 the path is treated as a Unix domain socket. See
269 https://git-scm.com/docs/api-trace2#_enabling_a_target for
270 details.
271
272 Returns:
273 log_path: Path to the log file or socket if log is written,
274 otherwise None
275 """
276 log_path = None
277 # If no logging path is specified, get the path from
278 # 'trace2.eventtarget'.
279 if path is None:
280 path = self._GetEventTargetPath()
281
282 # If no logging path is specified, exit.
283 if path is None:
284 return None
244 285
245 Logging filename format follows the git trace2 style of being a unique 286 path_is_socket = False
246 (exclusive writable) file. 287 socket_type = None
288 if isinstance(path, str):
289 parts = path.split(":", 1)
290 if parts[0] == "af_unix" and len(parts) == 2:
291 path_is_socket = True
292 path = parts[1]
293 parts = path.split(":", 1)
294 if parts[0] == "stream" and len(parts) == 2:
295 socket_type = socket.SOCK_STREAM
296 path = parts[1]
297 elif parts[0] == "dgram" and len(parts) == 2:
298 socket_type = socket.SOCK_DGRAM
299 path = parts[1]
300 else:
301 # Get absolute path.
302 path = os.path.abspath(os.path.expanduser(path))
303 else:
304 raise TypeError("path: str required but got %s." % type(path))
305
306 # Git trace2 requires a directory to write log to.
307
308 # TODO(https://crbug.com/gerrit/13706): Support file (append) mode also.
309 if not (path_is_socket or os.path.isdir(path)):
310 return None
247 311
248 Args: 312 if path_is_socket:
249 path: Path to where logs should be written. The path may have a prefix of 313 if socket_type == socket.SOCK_STREAM or socket_type is None:
250 the form "af_unix:[{stream|dgram}:]", in which case the path is 314 try:
251 treated as a Unix domain socket. See 315 with socket.socket(
252 https://git-scm.com/docs/api-trace2#_enabling_a_target for details. 316 socket.AF_UNIX, socket.SOCK_STREAM
317 ) as sock:
318 sock.connect(path)
319 self._WriteLog(sock.sendall)
320 return f"af_unix:stream:{path}"
321 except OSError as err:
322 # If we tried to connect to a DGRAM socket using STREAM,
323 # ignore the attempt and continue to DGRAM below. Otherwise,
324 # issue a warning.
325 if err.errno != errno.EPROTOTYPE:
326 print(
327 f"repo: warning: git trace2 logging failed: {err}",
328 file=sys.stderr,
329 )
330 return None
331 if socket_type == socket.SOCK_DGRAM or socket_type is None:
332 try:
333 with socket.socket(
334 socket.AF_UNIX, socket.SOCK_DGRAM
335 ) as sock:
336 self._WriteLog(lambda bs: sock.sendto(bs, path))
337 return f"af_unix:dgram:{path}"
338 except OSError as err:
339 print(
340 f"repo: warning: git trace2 logging failed: {err}",
341 file=sys.stderr,
342 )
343 return None
344 # Tried to open a socket but couldn't connect (SOCK_STREAM) or write
345 # (SOCK_DGRAM).
346 print(
347 "repo: warning: git trace2 logging failed: could not write to "
348 "socket",
349 file=sys.stderr,
350 )
351 return None
253 352
254 Returns: 353 # Path is an absolute path
255 log_path: Path to the log file or socket if log is written, otherwise None 354 # Use NamedTemporaryFile to generate a unique filename as required by
256 """ 355 # git trace2.
257 log_path = None
258 # If no logging path is specified, get the path from 'trace2.eventtarget'.
259 if path is None:
260 path = self._GetEventTargetPath()
261
262 # If no logging path is specified, exit.
263 if path is None:
264 return None
265
266 path_is_socket = False
267 socket_type = None
268 if isinstance(path, str):
269 parts = path.split(':', 1)
270 if parts[0] == 'af_unix' and len(parts) == 2:
271 path_is_socket = True
272 path = parts[1]
273 parts = path.split(':', 1)
274 if parts[0] == 'stream' and len(parts) == 2:
275 socket_type = socket.SOCK_STREAM
276 path = parts[1]
277 elif parts[0] == 'dgram' and len(parts) == 2:
278 socket_type = socket.SOCK_DGRAM
279 path = parts[1]
280 else:
281 # Get absolute path.
282 path = os.path.abspath(os.path.expanduser(path))
283 else:
284 raise TypeError('path: str required but got %s.' % type(path))
285
286 # Git trace2 requires a directory to write log to.
287
288 # TODO(https://crbug.com/gerrit/13706): Support file (append) mode also.
289 if not (path_is_socket or os.path.isdir(path)):
290 return None
291
292 if path_is_socket:
293 if socket_type == socket.SOCK_STREAM or socket_type is None:
294 try: 356 try:
295 with socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) as sock: 357 with tempfile.NamedTemporaryFile(
296 sock.connect(path) 358 mode="xb", prefix=self._sid, dir=path, delete=False
297 self._WriteLog(sock.sendall) 359 ) as f:
298 return f'af_unix:stream:{path}' 360 # TODO(https://crbug.com/gerrit/13706): Support writing events
299 except OSError as err: 361 # as they occur.
300 # If we tried to connect to a DGRAM socket using STREAM, ignore the 362 self._WriteLog(f.write)
301 # attempt and continue to DGRAM below. Otherwise, issue a warning. 363 log_path = f.name
302 if err.errno != errno.EPROTOTYPE: 364 except FileExistsError as err:
303 print(f'repo: warning: git trace2 logging failed: {err}', file=sys.stderr) 365 print(
366 "repo: warning: git trace2 logging failed: %r" % err,
367 file=sys.stderr,
368 )
304 return None 369 return None
305 if socket_type == socket.SOCK_DGRAM or socket_type is None: 370 return log_path
306 try:
307 with socket.socket(socket.AF_UNIX, socket.SOCK_DGRAM) as sock:
308 self._WriteLog(lambda bs: sock.sendto(bs, path))
309 return f'af_unix:dgram:{path}'
310 except OSError as err:
311 print(f'repo: warning: git trace2 logging failed: {err}', file=sys.stderr)
312 return None
313 # Tried to open a socket but couldn't connect (SOCK_STREAM) or write
314 # (SOCK_DGRAM).
315 print('repo: warning: git trace2 logging failed: could not write to socket', file=sys.stderr)
316 return None
317
318 # Path is an absolute path
319 # Use NamedTemporaryFile to generate a unique filename as required by git trace2.
320 try:
321 with tempfile.NamedTemporaryFile(mode='xb', prefix=self._sid, dir=path,
322 delete=False) as f:
323 # TODO(https://crbug.com/gerrit/13706): Support writing events as they
324 # occur.
325 self._WriteLog(f.write)
326 log_path = f.name
327 except FileExistsError as err:
328 print('repo: warning: git trace2 logging failed: %r' % err,
329 file=sys.stderr)
330 return None
331 return log_path