Logspam and possible Hang if "Exception: stream events has fallen behind"

[mtippmann]

Description

Synapse produces huge loglines if Exception: stream events has fallen behind is happening.

Steps to reproduce

• not sure how to reproduce it reliable

• Debian Package on Debian Testing

• Setup with workers (all known workers are setup)

Version information

• Homeserver: bau-ha.us

• Version: 0.99.5.1

• Install method: Debian-Testing with matrix.org Repo / Python3

• Platform: Linux, Debian 10 Testing - inside LXD-Container, dedicated Server, nginx Frontend-Proxy that does SSL-Termination.

2019-05-26 10:19:53,132 - synapse.metrics.background_process_metrics - 203 - ERROR - replication_notifier-27921- Background process 'replication_notifier' threw an exception
Traceback (most recent call last):
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/storage/_base.py", line 527, in runWithConnection
    defer.returnValue(result)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1362, in returnValue
    raise _DefGen_Return(val)
twisted.internet.defer._DefGen_Return: [(2114403, '!sOTlIPQBOAvFaUMZtB:irc.snt.utwente.nl', 'm.room.member', '@_tweaker
[ megabytes of the addresses ] 
114410, '!yhqiEdqNjyPbxtUjzm:matrix.org', 'm.room.member', '@203520:matrix.org', '$15016146426123107wBGQG:matrix.org')]

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/replication/tcp/streams/events.py", line 141, in update_function
    defer.returnValue(all_updates)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1362, in returnValue
    raise _DefGen_Return(val)
twisted.internet.defer._DefGen_Return: <generator object merge at 0x7f4827bd6480>

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/replication/tcp/protocol.py", line 479, in subscribe_to_stream
    stream_name, token,
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/python/failure.py", line 512, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/util/metrics.py", line 63, in measured_func
    r = yield func(self, *args, **kwargs)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/replication/tcp/streams/_base.py", line 204, in get_updates_since
    raise Exception("stream %s has fallen behind" % (self.NAME))
Exception: stream events has fallen behind
2019-05-26 10:20:07,664 - synapse.replication.tcp.protocol - 247 - WARNING - replication-REPLICATE-events-4506- [synapse.app.synchrotron-bhlPO] Closing connection
2019-05-26 10:20:08,933 - synapse.metrics.background_process_metrics - 203 - ERROR - replication_notifier-27934- Background process 'replication_notifier' threw an exception
Traceback (most recent call last):
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)

[mtippmann]

worker_log_config: /etc/matrix-synapse/log.yaml and log_config point to the same file (stock log config with levels adjusted to WARNING - every worker has a section

worker_listeners:
 - type: metrics
   port: 9005
   bind_addresses:
     - '0.0.0.0'

port is different for each worker, homeserver also has a listener.

[mtippmann]

Update: This is not related to metrics.

[mtippmann]

closing this as duplicate of #4388