element-hq / element-hq/synapse
Closing scope `Scope<xxx matrix.org synchrotron.write_bytes_to_request>` which is not the currently-active one
- Dominant language
- Python
- Stars
- 4.6k
- Forks
- 600
- Avg merge
- 5d 22h
- Merged PRs (30d)
- 51
Description
We're seeing millions of instances of:
```
Closing scope Scope<3383a8e8423cb969:6132fe74719247d5:0:0 matrix.org synchrotron.write_bytes_to_request> which is not the currently-active one None
```
on matrix.org, which appears to be raised by any log line that logs at the `ERROR` level. The sheer volume of exceptions being sent to sentry was causing 25% CPU usage alone.
This appears to be related to https://github.com/element-hq/synapse/pull/18804 (cc @MadLittleMods), which instrumented `write_bytes_to_request` and went out in 1.138.0. To stop the immediate spam, @erikjohnston added the following patch:
```
diff --git a/synapse/logging/scopecontextmanager.py b/synapse/logging/scopecontextmanager.py
index feaadc4d87..f896de3c50 100644
--- a/synapse/logging/scopecontextmanager.py
+++ b/synapse/logging/scopecontextmanager.py
@@ -146,7 +146,7 @@ class _LogContextScope(Scope):
def close(self) -> None:
active_scope = self.manager.active
if active_scope is not self:
- logger.error(
+ logger.warning(
"Closing scope %s which is not the currently-active one %s",
self,
active_scope,
```
but this still needs a proper fix.
Contributor guide
Assessment
This issue has not been assessed yet.