1657425 - sentry errors while running `mach python-test`

Status: RESOLVED INVALID

(Firefox Build System :: General, defect)

Description

[Nathan Froyd [:froydnj]]

I ran mach python-test python/mozbuild/mozbuild/test/configure/test_toolchain_configure.py from my objdir, and got output that looked like:

--- Logging error ---
Traceback (most recent call last):
  File "/usr/lib/python3.6/logging/__init__.py", line 994, in emit
    msg = self.format(record)
  File "/usr/lib/python3.6/logging/__init__.py", line 840, in format
    return fmt.format(record)
  File "/home/froydnj/src/gecko/python/mach/mach/logging.py", line 67, in format
    return json.dumps([record.created, action, params])
  File "/usr/lib/python3.6/json/__init__.py", line 231, in dumps
    return _default_encoder.encode(obj)
  File "/usr/lib/python3.6/json/encoder.py", line 199, in encode
    chunks = self.iterencode(o, _one_shot=True)
  File "/usr/lib/python3.6/json/encoder.py", line 257, in iterencode
    return _iterencode(o, 0)
  File "/usr/lib/python3.6/json/encoder.py", line 180, in default
    o.__class__.__name__)
TypeError: Object of type 'bytes' is not JSON serializable
Call stack:
  File "/home/froydnj/src/gecko/mach", line 214, in <module>
    main(sys.argv[1:])
  File "/home/froydnj/src/gecko/mach", line 210, in main
    sys.exit(mach.run(args))
  File "/home/froydnj/src/gecko/python/mach/mach/main.py", line 371, in run
    return self._run(argv, sentry)
  File "/home/froydnj/src/gecko/python/mach/mach/main.py", line 480, in _run
    **vars(args.command_args))
  File "/home/froydnj/src/gecko/python/mach/mach/registrar.py", line 109, in _run_command_handler
    result = fn(**kwargs)
  File "/home/froydnj/src/gecko/python/mach_commands.py", line 128, in python_test
    return self.run_python_tests(*args, **kwargs)
  File "/home/froydnj/src/gecko/python/mach_commands.py", line 218, in run_python_tests
    return_code = on_test_finished(future.result())
  File "/home/froydnj/src/gecko/python/mach_commands.py", line 205, in on_test_finished
    self.log(logging.INFO, 'python-test', {'line': line.rstrip()}, '{line}')
  File "/home/froydnj/src/gecko/python/mach/mach/mixin/logging.py", line 54, in log
    extra={'action': action, 'params': params})
  File "/usr/lib/python3.6/logging/__init__.py", line 1374, in log
    self._log(level, msg, args, **kwargs)
  File "/usr/lib/python3.6/logging/__init__.py", line 1444, in _log
    self.handle(record)
  File "/usr/lib/python3.6/logging/__init__.py", line 1454, in handle
    self.callHandlers(record)
  File "/home/froydnj/src/gecko/third_party/python/sentry-sdk/sentry_sdk/integrations/logging.py", line 77, in sentry_patched_callhandlers
    return old_callhandlers(self, record)
Message: '{line}'
Arguments: ()
 4:06.89 b"\x1b[1m            'CC': 'gcc-7',\x1b[0m"

which is not helpful.

Comment 1

[Mitchell Hentges [:mhentges] 🦀]

This looks like the root error is from mach/logging.py:

...
  File "/home/froydnj/src/gecko/python/mach/mach/logging.py", line 67, in format
    return json.dumps([record.created, action, params])
...

However, Sentry is failing to log/report this error, which is cluttering the output with an additional failure.

I think that this should be resolved in two separate steps:

1. Resolve the underlying error in mach/logging.py so that mach python-test works
2. Determine why Sentry is choking when it attempts to log and resolve that issue separately

Comment 2

[Ricky Stewart]

Following up from our discussion on chat.mozilla.org, I can't reproduce this. I understand that you're not running on a recent, clean, m-c. Can you reproduce the issue if you update and stash your local changes?

Comment 3

[Ricky Stewart]

Getting this out of the queue until such a time that we have a repro at HEAD.

Comment 4

[Nathan Froyd [:froydnj]]

Yeah, this is probably some sort of not-updated tree + local changes. I'll reopen or file a new bug if it happens again.