Very slow startup after upgrade to 1.26.0

[richvdh]

@madduck reported that his synapse blocked during startup after upgrade to 1.26.0.

Debug logs are at https://paste.debian.net/plain/1183329. Additional logs (having restarted with synapse.storage.SQL set to DEBUG) are at https://paste.debian.net/plain/1183332.

Eventually it completed startup of its own accord.

Implication seems to be that the new to-device init code (introduced in #9044) is blocking, but oddly:

• the same query, run on postgres directly, completed in half a second (though this might be unrepresentative due to the results being cached)
• SELECT COUNT(*) FROM device_inbox WHERE stream_id >172426 - 1000; returns 222679, which is quite a lot, but not block-for-10-minutes level.

[richvdh]

As a general debugging point: if MultiWriterIdGenerator.__init__ and get_cache_dict included some logger.debug, this would be a lot less confusing to diagonose.

(I mention MultiWriterIdGenerator specifically, because StreamIdGenerator.__init__ does write debug, via _load_current_id, and it is quite helpful, and the inconsistency is extra confusing.)

[callahad]

I've spun out the request for more debugging into a standalone issue at #9443

[richvdh]

Seems like this only affected @madduck, so probably not worth spending time on