[CASSANDRA-14059] Root logging formatter broken in dtests

• Type: Bug
• Status: Resolved
• Priority: Low
• Resolution: Fixed
• Component/s: Test/dtest/python
• Severity: Low
• Assignee: Joel Knighton
• Reporter: Joel Knighton

Authors

Joel Knighton

Reviewers

Stefan Podkowinski

• Created: 18/Nov/17 00:26
• Updated: 16/Apr/19 09:29
• Resolved: 05/Dec/17 03:13

Description

Since the ccm dependency in dtest was bumped to 3.1.0 in 7cc06a086f89ed76499837558ff263d84337acba, when dtests are run with --nologcapture, errors of the following form are printed:

Traceback (most recent call last):
  File "/usr/lib64/python2.7/logging/__init__.py", line 861, in emit
    msg = self.format(record)
  File "/usr/lib64/python2.7/logging/__init__.py", line 734, in format
    return fmt.format(record)
  File "/usr/lib64/python2.7/logging/__init__.py", line 469, in format
    s = self._fmt % record.__dict__
KeyError: 'current_test'
Logged from file dtest.py, line 485

This is because CCM no longer installs a basic root logger configuration, which is probably a more correct behavior than what it did prior to this change. Now, dtest installs its own basic root logger configuration which writes to 'dtest.log' using the formatter '%(asctime)s,%(msecs)d %(name)s %(current_test)s %(levelname)s %(message)s'. This means that anything logging a message must provide the current_test key in its extras map. The dtest debug and warning functions do this, but logging from dependencies doesn't, producing these KeyError s.