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

Fix stack overflow when logging system encounters an error #8268

Merged
merged 1 commit into from Sep 7, 2020
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
1 change: 1 addition & 0 deletions changelog.d/8268.bugfix
@@ -0,0 +1 @@
Fix stack overflow when stderr is redirected to the logging system, and the logging system encounters an error.
25 changes: 23 additions & 2 deletions synapse/config/logger.py
Expand Up @@ -17,6 +17,7 @@
import logging.config
import os
import sys
import threading
from string import Template

import yaml
Expand All @@ -25,6 +26,7 @@
ILogObserver,
LogBeginner,
STDLibLogObserver,
eventAsText,
globalLogBeginner,
)

Expand Down Expand Up @@ -216,8 +218,9 @@ def factory(*args, **kwargs):
# system.
observer = STDLibLogObserver()

def _log(event):
threadlocal = threading.local()

def _log(event):
if "log_text" in event:
if event["log_text"].startswith("DNSDatagramProtocol starting on "):
return
Expand All @@ -228,7 +231,25 @@ def _log(event):
if event["log_text"].startswith("Timing out client"):
return

return observer(event)
# this is a workaround to make sure we don't get stack overflows when the
# logging system raises an error which is written to stderr which is redirected
# to the logging system, etc.
if getattr(threadlocal, "active", False):
# write the text of the event, if any, to the *real* stderr (which may
# be redirected to /dev/null, but there's not much we can do)
try:
event_text = eventAsText(event)
print("logging during logging: %s" % event_text, file=sys.__stderr__)
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this was meant to be "error during logging", but I'm not sure?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

well, we don't know for sure it was an error. It could have been any other log level.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hmm... "logging during logging" doesn't really make sense to me though. What's that trying to say?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

while we were writing some logging, more logging happened.

I'm open to better wording :)

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ah, I see what you're saying. Well...if nothing else that should be easy to find in the code-base if it ever comes up. 😄

except Exception:
# gah.
pass
return

try:
threadlocal.active = True
return observer(event)
finally:
threadlocal.active = False

logBeginner.beginLoggingTo([_log], redirectStandardIO=not config.no_redirect_stdio)
if not config.no_redirect_stdio:
Expand Down