Structured logging

With this applied, logs use logfmt when run on a non-TTY stdout:

timestamp="2023-04-26 12:54:25" event="Running on http://0.0.0.0:38119 (CTRL + C to quit)" level=info logger=http.server
timestamp="2023-04-26 12:54:25" event="Running on http://0.0.0.0:38119 (CTRL + C to quit)" level=info logger=http.server
timestamp="2023-04-26 12:54:26" event="    worker data: Worker(port=6050, hostarch='armv8l', ip='127.0.0.1', meta={'sandbox': 'chroot', 'linux': OrderedDict([('version', '4.19.0-14'), ('flavor', 'arm64')]), 'hardware': OrderedDict([('cpu', None), ('processors', '8')])}, workerid='worker:1')" level=info func_name=worker_ping logger=obs_proxy.repserver
timestamp="2023-04-26 12:54:26" event="    armv8l:worker:1 unknown on 6050" level=info func_name=worker_ping logger=obs_proxy.repserver
timestamp="2023-04-26 12:54:26" event="127.0.0.1:59130 POST /worker 1.1 200 2 16924" level=info logger=http.server
timestamp="2023-04-26 12:54:26" event="127.0.0.1:59130 POST /worker 1.1 200 2 16924" level=info logger=http.server
timestamp="2023-04-26 12:54:26" event="Proxying http://127.0.0.1:42881/foo/repserver/worker:1/putjob" level=info func_name=putjob logger=obs_proxy.repserver
timestamp="2023-04-26 12:54:26" event="Connected to ws://127.0.0.1:42881/foo/worker/worker:1/events using WebSockets, authenticated with a token" level=info func_name=wsclient logger=obs_proxy.wsclient
timestamp="2023-04-26 12:54:26" event="<<< #() [worker_ping] {worker:1}" level=info logger=root
timestamp="2023-04-26 12:54:26" event="127.0.0.1:59130 POST /repserver/worker:1/putjob?jobid=62d106cb98d80ec44b18691e6bb5b487 1.1 200 2 77631" level=info logger=http.server
timestamp="2023-04-26 12:54:26" event="127.0.0.1:59130 POST /repserver/worker:1/putjob?jobid=62d106cb98d80ec44b18691e6bb5b487 1.1 200 2 77631" level=info logger=http.server
timestamp="2023-04-26 12:54:27" event="Caught an exception" level=error exc_info func_name=wsclient logger=obs_proxy.wsclient
timestamp="2023-04-26 12:54:27" event="Waiting for 4 seconds before reconnecting" level=info func_name=wsclient logger=obs_proxy.wsclient
timestamp="2023-04-26 12:54:27" event="Received a signal, will terminate" level=info func_name=_signal_handler logger=__main__
timestamp="2023-04-26 12:54:28" event=Terminating. level=info func_name=_terminate logger=__main__

or like this (with colours) when run interactively:

2023-04-26 12:57:29 [info     ] Running on http://0.0.0.0:6050 (CTRL + C to quit) [http.server] 
2023-04-26 12:58:09 [info     ] (o) worker:1 online            [obs_proxy.server] func_name=worker_events_ws
2023-04-26 12:58:09 [info     ] ... awaiting                   [obs_proxy.server] func_name=recv
2023-04-26 12:58:09 [info     ] 127.0.0.1:46354 GET /worker/worker:1/events 1.1 101 - 2950 [http.server] 
2023-04-26 12:58:09 [info     ] 127.0.0.1:46354 GET /worker/worker:1/events 1.1 101 - 2950 [http.server] 
2023-04-26 12:58:09 [info     ] >>>                            [obs_proxy.server] func_name=recv id=() kind=call method=worker_ping state=idle worker={'port': 6262, 'hostarch': 'x86_64', 'ip': '127.0.0.1', 'meta': {'sandbox': 'chroot', 'linux': {'version': '5.16.0-1', 'flavor': 'amd64'}, 'hardware': {'cpu': {'flag': ['fpu', 'vme', 'de', 'pse', 'tsc', 'msr', 'pae', 'mce', 'cx8', 'apic', 'sep', 'mtrr', 'pge', 'mca', 'cmov', 'pat', 'pse36', 'clflush', 'dts', 'acpi', 'mmx', 'fxsr', 'sse', 'sse2', 'ss', 'ht', 'tm', 'pbe', 'syscall', 'nx', 'pdpe1gb', 'rdtscp', 'lm', 'constant_tsc', 'art', 'arch_perfmon', 'pebs', 'bts', 'rep_good', 'nopl', 'xtopology', 'nonstop_tsc', 'cpuid', 'aperfmperf', 'pni', 'pclmulqdq', 'dtes64', 'monitor', 'ds_cpl', 'vmx', 'smx', 'est', 'tm2', 'ssse3', 'sdbg', 'fma', 'cx16', 'xtpr', 'pdcm', 'pcid', 'sse4_1', 'sse4_2', 'x2apic', 'movbe', 'popcnt', 'tsc_deadline_timer', 'aes', 'xsave', 'avx', 'f16c', 'rdrand', 'lahf_lm', 'abm', '3dnowprefetch', 'cpuid_fault', 'epb', 'invpcid_single', 'ssbd', 'ibrs', 'ibpb', 'stibp', 'ibrs_enhanced', 'tpr_shadow', 'vnmi', 'flexpriority', 'ept', 'vpid', 'ept_ad', 'fsgsbase', 'tsc_adjust', 'sgx', 'bmi1', 'avx2', 'smep', 'bmi2', 'erms', 'invpcid', 'mpx', 'rdseed', 'adx', 'smap', 'clflushopt', 'intel_pt', 'xsaveopt', 'xsavec', 'xgetbv1', 'xsaves', 'dtherm', 'ida', 'arat', 'pln', 'pts', 'hwp', 'hwp_notify', 'hwp_act_window', 'hwp_epp', 'md_clear', 'flush_l1d', 'arch_capabilities']}, 'processors': '8'}}, 'workerid': 'worker:1'} worker_id=worker:1
2023-04-26 12:58:09 [info     ] updating worker state          [obs_proxy.server] arch=x86_64 func_name=post_worker_state port=6011 state=idle workerid=worker:1
2023-04-26 12:58:12 [error    ] update failed                  [obs_proxy.server] error=ConnectError('All connection attempts failed') func_name=post_worker_state
2023-04-26 12:58:12 [error    ] <x- #() [{'code': -32000, 'message': 'Server error', 'data': {'type': 'ConnectError', 'args': ('All connection attempts failed',), 'message': 'All connection attempts failed', 'url': 'http://172.27.0.2:5252/worker?state=idle&arch=x86_64&port=6011&workerid=worker%3A1'}}] [root] 
2023-04-26 12:58:12 [info     ] ... awaiting                   [obs_proxy.server] func_name=recv