Skip to content
This repository has been archived by the owner on Apr 26, 2024. It is now read-only.

notifier using 100% cpu, reporting "Could not find event None" #5102

Closed
richvdh opened this issue Apr 26, 2019 · 2 comments
Closed

notifier using 100% cpu, reporting "Could not find event None" #5102

richvdh opened this issue Apr 26, 2019 · 2 comments
Labels
z-bug (Deprecated Label) z-p2 (Deprecated Label)

Comments

@richvdh
Copy link
Member

richvdh commented Apr 26, 2019

For the last few hours synapse has been pinning my CPU, with almost all of the cpu usage coming from notify_new_event

In the logs I see many:

2019-04-26 06:18:26,267 - synapse.metrics.background_process_metrics - 203 - ERROR - presence.notify_new_event-13001- Background process 'presence.notify_new_event' threw an exception
Capture point (most recent call last):
  File "/usr/lib/python3.5/runpy.py", line 184, in _run_module_as_main
    "__main__", mod_spec)
  File "/usr/lib/python3.5/runpy.py", line 85, in _run_code
    exec(code, run_globals)
  File "/opt/synapse/synapse/synapse/app/homeserver.py", line 661, in <module>
    main()
  File "/opt/synapse/synapse/synapse/app/homeserver.py", line 657, in main
    run(hs)
  File "/opt/synapse/synapse/synapse/app/homeserver.py", line 648, in run
    logger=logger,
  File "/opt/synapse/synapse/synapse/app/_base.py", line 143, in start_reactor
    run()
  File "/opt/synapse/synapse/synapse/app/_base.py", line 127, in run
    reactor.run()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/base.py", line 1267, in run
    self.mainLoop()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/base.py", line 1276, in mainLoop
    self.runUntilCurrent()
  File "/opt/synapse/synapse/synapse/metrics/__init__.py", line 347, in f
    ret = func(*args, **kwargs)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/base.py", line 875, in runUntilCurrent
    f(*a, **kw)
  File "/opt/synapse/synapse/synapse/storage/events_worker.py", line 349, in fire
    d.callback([res[i] for i in ids if i in res])
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 460, in callback
    self._startRunCallbacks(result)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks
    self._runCallbacks()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1475, in gotResult
    _inlineCallbacks(r, g, status)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1461, in _inlineCallbacks
    status.deferred.callback(e.value)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 460, in callback
    self._startRunCallbacks(result)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks
    self._runCallbacks()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1475, in gotResult
    _inlineCallbacks(r, g, status)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1461, in _inlineCallbacks
    status.deferred.callback(e.value)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 460, in callback
    self._startRunCallbacks(result)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks
    self._runCallbacks()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1475, in gotResult
    _inlineCallbacks(r, g, status)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1464, in _inlineCallbacks
    status.deferred.errback()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 501, in errback
    self._startRunCallbacks(fail)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks
    self._runCallbacks()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1475, in gotResult
    _inlineCallbacks(r, g, status)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1464, in _inlineCallbacks
    status.deferred.errback()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 501, in errback
    self._startRunCallbacks(fail)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks
    self._runCallbacks()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1475, in gotResult
    _inlineCallbacks(r, g, status)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1464, in _inlineCallbacks
    status.deferred.errback()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 501, in errback
    self._startRunCallbacks(fail)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks
    self._runCallbacks()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1475, in gotResult
    _inlineCallbacks(r, g, status)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1464, in _inlineCallbacks
    status.deferred.errback()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 501, in errback
    self._startRunCallbacks(fail)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks
    self._runCallbacks()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1475, in gotResult
    _inlineCallbacks(r, g, status)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
    return g.throw(self.type, self.value, self.tb)
Traceback (most recent call last):
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/opt/synapse/synapse/synapse/storage/events_worker.py", line 419, in _enqueue_events
    defer.returnValue({e.event.event_id: e for e in res if e})
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1362, in returnValue
    raise _DefGen_Return(val)
twisted.internet.defer._DefGen_Return: {}

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/opt/synapse/synapse/synapse/storage/events_worker.py", line 263, in _get_events
    defer.returnValue(events)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1362, in returnValue
    raise _DefGen_Return(val)
twisted.internet.defer._DefGen_Return: []

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/synapse/synapse/synapse/metrics/background_process_metrics.py", line 201, in run
    yield func(*args, **kwargs)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/opt/synapse/synapse/synapse/handlers/presence.py", line 790, in _process_presence
    yield self._unsafe_process()
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/opt/synapse/synapse/synapse/handlers/presence.py", line 805, in _unsafe_process
    yield self._handle_state_delta(deltas)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1416, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/python/failure.py", line 491, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/opt/synapse/synapse/synapse/handlers/presence.py", line 831, in _handle_state_delta
    event = yield self.store.get_event(event_id)
  File "/opt/synapse/env3/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/opt/synapse/synapse/synapse/storage/events_worker.py", line 120, in get_event
    raise NotFoundError("Could not find event %s" % (event_id,))
synapse.api.errors.NotFoundError: 404: Could not find event None
@richvdh
Copy link
Member Author

richvdh commented Apr 26, 2019

This seems to have been introduced by #4942

richvdh added a commit that referenced this issue Apr 26, 2019
@richvdh
Fix infinite loop in presence handler
bd0d45c 
Fixes #5102
@richvdh richvdh mentioned this issue Apr 26, 2019
Merged
@neilisfragile neilisfragile added z-bug (Deprecated Label) z-p2 (Deprecated Label) labels Apr 30, 2019
@richvdh
Copy link
Member Author

richvdh commented May 1, 2019

fixed by #5103

@richvdh richvdh closed this as completed May 1, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
z-bug (Deprecated Label) z-p2 (Deprecated Label)
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@neilisfragile @richvdh