Duplicate timestamp in _trial_temp/test.log log formatting

[MadLittleMods]

Currently, the log lines in _trial_temp/test.log seem way too verbose and duplicate the timestamp for some reason. It's the exact same time in both places but one with timezone offset and one with millisecond precision.

_trial_temp/test.log

2023-05-17 22:51:36-0500 [-] 2023-05-17 22:51:36,889 - synapse.server - 338 - INFO - sentinel - Finished setting up.

This is in contrast to my own homeserver.log which uses the same logging format as what the tests seem to use but only has the asctime as expected,

synapse/tests/test_utils/logging_setup.py

Lines 43 to 46 in 41b9def

	log_format = (
	"%(asctime)s - %(name)s - %(lineno)d - "
	"%(levelname)s - %(request)s - %(message)s"
	)

If you remove %(asctime)s - from the test logging setup, the logs in _trial_temp/test.log still end up with a timestamp 🤔:

2023-05-18 00:41:35-0500 [-] synapse.server - 338 - INFO - sentinel - Finished setting up.

Definition of done

• Remove duplicate timestamps from _trial_temp/test.log log formatting

[reivilibre]

May be worth checking whether it's part of Trial itself

[MadLittleMods]

It looks like this is from the Twisted logger: twisted/twisted -> src/twisted/logger/_format.py#L362-L374

It doesn't seem that Twisted really supports changing the format unless you override the emit method:

• https://docs.twisted.org/en/latest/api/twisted.logger.html
• https://stackoverflow.com/questions/3700955/how-to-format-twisted-logs
• https://stackoverflow.com/questions/59930732/can-the-twisted-logger-log-in-utc

The easiest thing to do is probably just remove %(asctime)s - from our format