Merge bitcoin/bitcoin#32676: test: apply microsecond precision to test framework logging

ed179e0a6528c39b3bca76365f256716f917e19b test: apply microsecond precision to test framework logging (Martin Zumsande)

Pull request description:

  When analyzing functional test logs (produced with `combine_logs.py`), entries sometimes sort slightly out of order because even though python prints 6 digits for microsecond precision, it fills up the last 3 digits with zeroes. For example, it may look like a message was received by the test framework before it was sent by the node.

  Change this to actually use microsecond precision - this should make combined logs a little bit easier to analyze.

ACKs for top commit:
  davidgumberg:
    Tested ACK ed179e0a65
  achow101:
    ACK ed179e0a6528c39b3bca76365f256716f917e19b
  maflcko:
    review ACK ed179e0a6528c39b3bca76365f256716f917e19b 🗳
  janb84:
    ACK ed179e0a6528c39b3bca76365f256716f917e19b

Tree-SHA512: 55cdb5024e8e910c5a5ce741ce512eb88f4f82f11f378ba0fe7a5a2b1c97d2e7b540bdf5603c76aab837d35798610b165f087fbeb7c9dc90aaad890bf4d0323d

test/functional/test_framework/test_framework.py

@@ -7,6 +7,7 @@
 import configparser
 from enum import Enum
 import argparse
+from datetime import datetime, timezone
 import logging
 import os
 import platform
@@ -837,9 +838,16 @@ class BitcoinTestFramework(metaclass=BitcoinTestMetaClass):
         # User can provide log level as a number or string (eg DEBUG). loglevel was caught as a string, so try to convert it to an int
         ll = int(self.options.loglevel) if self.options.loglevel.isdigit() else self.options.loglevel.upper()
         ch.setLevel(ll)
+
         # Format logs the same as bitcoind's debug.log with microprecision (so log files can be concatenated and sorted)
-        formatter = logging.Formatter(fmt='%(asctime)s.%(msecs)03d000Z %(name)s (%(levelname)s): %(message)s', datefmt='%Y-%m-%dT%H:%M:%S')
-        formatter.converter = time.gmtime
+        class MicrosecondFormatter(logging.Formatter):
+            def formatTime(self, record, _=None):
+                dt = datetime.fromtimestamp(record.created, timezone.utc)
+                return dt.strftime('%Y-%m-%dT%H:%M:%S.%f')
+
+        formatter = MicrosecondFormatter(
+            fmt='%(asctime)sZ %(name)s (%(levelname)s): %(message)s',
+        )
         fh.setFormatter(formatter)
         ch.setFormatter(formatter)
         # add the handlers to the logger