nested logcontexts have broken

[richvdh]

Previously, we would include room id and event ids in the log lines when processing incoming federation transactions:

2021-04-01 01:08:19,924 - synapse.handlers.federation - 189 - INFO - PUT-2583944--!INnSqmMHFcPNCEaTfa:matrix.org-$pnWM__s9OmC8Y25UQ8sSVRumVbNIU3pbETOMb_Fqz-E-$n0wvuREXwL9vPEP0N0is0__BRJ_H7NHRFwqluGQ-OJs - handling received PDU: <FrozenEventV3 event_id='$n0wvuREXwL9vPEP0N0is0__BRJ_H7NHRFwqluGQ-OJs', type='m.room.message', state_key=None>

This has now broken, and we only log the request ID

2021-04-15 00:01:01,310 - synapse.handlers.federation - 201 - INFO - PUT-498746 - handling received PDU: <FrozenEventV3 event_id='$QR-j-dIXWBHyLpLHV7QOY3Zz-lI9B03wVAODrAKg700', type='m.room.message', state_key=None>

It looks like this broke in #9654.

Presumably relatedly, we are now logging Measure and runWithConnection blocks where we were not before:

2021-04-15 15:40:40,551 - synapse.storage.databases.main.event_push_actions - 718 - INFO - runWithConnection@7f9eb09ffc00 - Rotating notifications up to: 7788722
...
2021-04-15 15:40:45,592 - synapse.federation.sender.transaction_manager - 158 - INFO - Measure[_send_new_transaction]@7f9eb2660840 - TX [eggy.cc] {1618499443326} got 200 response

[clokep]

Presumably relatedly, we are now logging Measure and runWithConnection blocks where we were not before:

Do you mean that we log these at all or did the log line change? I'm not really sure what in there could have caused the lines to suddenly appear, but I'll double check!

[clokep]

Presumably relatedly, we are now logging Measure and runWithConnection blocks where we were not before:

Do you mean that we log these at all or did the log line change? I'm not really sure what in there could have caused the lines to suddenly appear, but I'll double check!

It seems that the Measure bit did not used to show and does now...will look more into this!

[clokep]

I can confirm that something in that branch regressed this behavior...