diff options
author | Josh Steadmon <steadmon@google.com> | 2022-03-08 10:24:43 -0800 |
---|---|---|
committer | Josh Steadmon <steadmon@google.com> | 2022-03-16 17:33:07 +0000 |
commit | 244c9a71a689743acea97c6a07ff4dfce4dc6dab (patch) | |
tree | 2a52943292478722db03174e577f05ab4ffc1eb7 | |
parent | b308db1e2a982ae4158cb6fedd23d3d547bd09b0 (diff) | |
download | git-repo-244c9a71a689743acea97c6a07ff4dfce4dc6dab.tar.gz |
trace: allow writing traces to a socket
Git can write trace2 events to a Unix domain socket [1]. This can be
specified via Git's `trace2.eventTarget` config option, which we read to
determine where to log our own trace2 events. Currently, if the Git
config specifies a socket as the trace2 target, we fail to log any
traces.
Fix this by adding support for writing to a Unix domain socket,
following the same specification that Git supports.
[1]: https://git-scm.com/docs/api-trace2#_enabling_a_target
Change-Id: I928bc22ba04fba603a9132eb055141845fa48ab2
Reviewed-on: https://gerrit-review.googlesource.com/c/git-repo/+/332339
Reviewed-by: Raman Tenneti <rtenneti@google.com>
Reviewed-by: Mike Frysinger <vapier@google.com>
Tested-by: Josh Steadmon <steadmon@google.com>
-rw-r--r-- | git_trace2_event_log.py | 86 | ||||
-rw-r--r-- | tests/test_git_trace2_event_log.py | 62 |
2 files changed, 134 insertions, 14 deletions
diff --git a/git_trace2_event_log.py b/git_trace2_event_log.py index 0e5e9089..7426aba9 100644 --- a/git_trace2_event_log.py +++ b/git_trace2_event_log.py | |||
@@ -29,8 +29,10 @@ https://git-scm.com/docs/api-trace2#_the_event_format_target | |||
29 | 29 | ||
30 | 30 | ||
31 | import datetime | 31 | import datetime |
32 | import errno | ||
32 | import json | 33 | import json |
33 | import os | 34 | import os |
35 | import socket | ||
34 | import sys | 36 | import sys |
35 | import tempfile | 37 | import tempfile |
36 | import threading | 38 | import threading |
@@ -218,20 +220,39 @@ class EventLog(object): | |||
218 | retval, p.stderr), file=sys.stderr) | 220 | retval, p.stderr), file=sys.stderr) |
219 | return path | 221 | return path |
220 | 222 | ||
223 | def _WriteLog(self, write_fn): | ||
224 | """Writes the log out using a provided writer function. | ||
225 | |||
226 | Generate compact JSON output for each item in the log, and write it using | ||
227 | write_fn. | ||
228 | |||
229 | Args: | ||
230 | write_fn: A function that accepts byts and writes them to a destination. | ||
231 | """ | ||
232 | |||
233 | for e in self._log: | ||
234 | # Dump in compact encoding mode. | ||
235 | # See 'Compact encoding' in Python docs: | ||
236 | # https://docs.python.org/3/library/json.html#module-json | ||
237 | write_fn(json.dumps(e, indent=None, separators=(',', ':')).encode('utf-8') + b'\n') | ||
238 | |||
221 | def Write(self, path=None): | 239 | def Write(self, path=None): |
222 | """Writes the log out to a file. | 240 | """Writes the log out to a file or socket. |
223 | 241 | ||
224 | Log is only written if 'path' or 'git config --get trace2.eventtarget' | 242 | Log is only written if 'path' or 'git config --get trace2.eventtarget' |
225 | provide a valid path to write logs to. | 243 | provide a valid path (or socket) to write logs to. |
226 | 244 | ||
227 | Logging filename format follows the git trace2 style of being a unique | 245 | Logging filename format follows the git trace2 style of being a unique |
228 | (exclusive writable) file. | 246 | (exclusive writable) file. |
229 | 247 | ||
230 | Args: | 248 | Args: |
231 | path: Path to where logs should be written. | 249 | path: Path to where logs should be written. The path may have a prefix of |
250 | the form "af_unix:[{stream|dgram}:]", in which case the path is | ||
251 | treated as a Unix domain socket. See | ||
252 | https://git-scm.com/docs/api-trace2#_enabling_a_target for details. | ||
232 | 253 | ||
233 | Returns: | 254 | Returns: |
234 | log_path: Path to the log file if log is written, otherwise None | 255 | log_path: Path to the log file or socket if log is written, otherwise None |
235 | """ | 256 | """ |
236 | log_path = None | 257 | log_path = None |
237 | # If no logging path is specified, get the path from 'trace2.eventtarget'. | 258 | # If no logging path is specified, get the path from 'trace2.eventtarget'. |
@@ -242,29 +263,66 @@ class EventLog(object): | |||
242 | if path is None: | 263 | if path is None: |
243 | return None | 264 | return None |
244 | 265 | ||
266 | path_is_socket = False | ||
267 | socket_type = None | ||
245 | if isinstance(path, str): | 268 | if isinstance(path, str): |
246 | # Get absolute path. | 269 | parts = path.split(':', 1) |
247 | path = os.path.abspath(os.path.expanduser(path)) | 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)) | ||
248 | else: | 283 | else: |
249 | raise TypeError('path: str required but got %s.' % type(path)) | 284 | raise TypeError('path: str required but got %s.' % type(path)) |
250 | 285 | ||
251 | # Git trace2 requires a directory to write log to. | 286 | # Git trace2 requires a directory to write log to. |
252 | 287 | ||
253 | # TODO(https://crbug.com/gerrit/13706): Support file (append) mode also. | 288 | # TODO(https://crbug.com/gerrit/13706): Support file (append) mode also. |
254 | if not os.path.isdir(path): | 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: | ||
295 | with socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) as sock: | ||
296 | sock.connect(path) | ||
297 | self._WriteLog(sock.sendall) | ||
298 | return f'af_unix:stream:{path}' | ||
299 | except OSError as err: | ||
300 | # If we tried to connect to a DGRAM socket using STREAM, ignore the | ||
301 | # attempt and continue to DGRAM below. Otherwise, issue a warning. | ||
302 | if err.errno != errno.EPROTOTYPE: | ||
303 | print(f'repo: warning: git trace2 logging failed: {err}', file=sys.stderr) | ||
304 | return None | ||
305 | if socket_type == socket.SOCK_DGRAM or socket_type is None: | ||
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) | ||
255 | return None | 316 | return None |
317 | |||
318 | # Path is an absolute path | ||
256 | # Use NamedTemporaryFile to generate a unique filename as required by git trace2. | 319 | # Use NamedTemporaryFile to generate a unique filename as required by git trace2. |
257 | try: | 320 | try: |
258 | with tempfile.NamedTemporaryFile(mode='x', prefix=self._sid, dir=path, | 321 | with tempfile.NamedTemporaryFile(mode='xb', prefix=self._sid, dir=path, |
259 | delete=False) as f: | 322 | delete=False) as f: |
260 | # TODO(https://crbug.com/gerrit/13706): Support writing events as they | 323 | # TODO(https://crbug.com/gerrit/13706): Support writing events as they |
261 | # occur. | 324 | # occur. |
262 | for e in self._log: | 325 | self._WriteLog(f.write) |
263 | # Dump in compact encoding mode. | ||
264 | # See 'Compact encoding' in Python docs: | ||
265 | # https://docs.python.org/3/library/json.html#module-json | ||
266 | json.dump(e, f, indent=None, separators=(',', ':')) | ||
267 | f.write('\n') | ||
268 | log_path = f.name | 326 | log_path = f.name |
269 | except FileExistsError as err: | 327 | except FileExistsError as err: |
270 | print('repo: warning: git trace2 logging failed: %r' % err, | 328 | print('repo: warning: git trace2 logging failed: %r' % err, |
diff --git a/tests/test_git_trace2_event_log.py b/tests/test_git_trace2_event_log.py index 89dcfb92..0623d32e 100644 --- a/tests/test_git_trace2_event_log.py +++ b/tests/test_git_trace2_event_log.py | |||
@@ -16,11 +16,42 @@ | |||
16 | 16 | ||
17 | import json | 17 | import json |
18 | import os | 18 | import os |
19 | import socket | ||
19 | import tempfile | 20 | import tempfile |
21 | import threading | ||
20 | import unittest | 22 | import unittest |
21 | from unittest import mock | 23 | from unittest import mock |
22 | 24 | ||
23 | import git_trace2_event_log | 25 | import git_trace2_event_log |
26 | import platform_utils | ||
27 | |||
28 | |||
29 | def serverLoggingThread(socket_path, server_ready, received_traces): | ||
30 | """Helper function to receive logs over a Unix domain socket. | ||
31 | |||
32 | Appends received messages on the provided socket and appends to received_traces. | ||
33 | |||
34 | Args: | ||
35 | socket_path: path to a Unix domain socket on which to listen for traces | ||
36 | server_ready: a threading.Condition used to signal to the caller that this thread is ready to | ||
37 | accept connections | ||
38 | received_traces: a list to which received traces will be appended (after decoding to a utf-8 | ||
39 | string). | ||
40 | """ | ||
41 | platform_utils.remove(socket_path, missing_ok=True) | ||
42 | data = b'' | ||
43 | with socket.socket(socket.AF_UNIX, socket.SOCK_STREAM) as sock: | ||
44 | sock.bind(socket_path) | ||
45 | sock.listen(0) | ||
46 | with server_ready: | ||
47 | server_ready.notify() | ||
48 | with sock.accept()[0] as conn: | ||
49 | while True: | ||
50 | recved = conn.recv(4096) | ||
51 | if not recved: | ||
52 | break | ||
53 | data += recved | ||
54 | received_traces.extend(data.decode('utf-8').splitlines()) | ||
24 | 55 | ||
25 | 56 | ||
26 | class EventLogTestCase(unittest.TestCase): | 57 | class EventLogTestCase(unittest.TestCase): |
@@ -324,6 +355,37 @@ class EventLogTestCase(unittest.TestCase): | |||
324 | with self.assertRaises(TypeError): | 355 | with self.assertRaises(TypeError): |
325 | self._event_log_module.Write(path=1234) | 356 | self._event_log_module.Write(path=1234) |
326 | 357 | ||
358 | def test_write_socket(self): | ||
359 | """Test Write() with Unix domain socket for |path| and validate received traces.""" | ||
360 | received_traces = [] | ||
361 | with tempfile.TemporaryDirectory(prefix='test_server_sockets') as tempdir: | ||
362 | socket_path = os.path.join(tempdir, "server.sock") | ||
363 | server_ready = threading.Condition() | ||
364 | # Start "server" listening on Unix domain socket at socket_path. | ||
365 | try: | ||
366 | server_thread = threading.Thread( | ||
367 | target=serverLoggingThread, | ||
368 | args=(socket_path, server_ready, received_traces)) | ||
369 | server_thread.start() | ||
370 | |||
371 | with server_ready: | ||
372 | server_ready.wait() | ||
373 | |||
374 | self._event_log_module.StartEvent() | ||
375 | path = self._event_log_module.Write(path=f'af_unix:{socket_path}') | ||
376 | finally: | ||
377 | server_thread.join(timeout=5) | ||
378 | |||
379 | self.assertEqual(path, f'af_unix:stream:{socket_path}') | ||
380 | self.assertEqual(len(received_traces), 2) | ||
381 | version_event = json.loads(received_traces[0]) | ||
382 | start_event = json.loads(received_traces[1]) | ||
383 | self.verifyCommonKeys(version_event, expected_event_name='version') | ||
384 | self.verifyCommonKeys(start_event, expected_event_name='start') | ||
385 | # Check for 'start' event specific fields. | ||
386 | self.assertIn('argv', start_event) | ||
387 | self.assertIsInstance(start_event['argv'], list) | ||
388 | |||
327 | 389 | ||
328 | if __name__ == '__main__': | 390 | if __name__ == '__main__': |
329 | unittest.main() | 391 | unittest.main() |