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() |
