diff --git a/synapse/config/logger.py b/synapse/config/logger.py
index dd775a97e8..13d6f6a3ea 100644
--- a/synapse/config/logger.py
+++ b/synapse/config/logger.py
@@ -17,6 +17,7 @@ import logging
import logging.config
import os
import sys
+import threading
from string import Template
import yaml
@@ -25,6 +26,7 @@ from twisted.logger import (
ILogObserver,
LogBeginner,
STDLibLogObserver,
+ eventAsText,
globalLogBeginner,
)
@@ -55,24 +57,33 @@ formatters:
format: '%(asctime)s - %(name)s - %(lineno)d - %(levelname)s - \
%(request)s - %(message)s'
-filters:
- context:
- (): synapse.logging.context.LoggingContextFilter
- request: ""
-
handlers:
file:
- class: logging.handlers.RotatingFileHandler
+ class: logging.handlers.TimedRotatingFileHandler
formatter: precise
filename: ${log_file}
- maxBytes: 104857600
- backupCount: 10
- filters: [context]
+ when: midnight
+ backupCount: 3 # Does not include the current log file.
encoding: utf8
+
+ # Default to buffering writes to log file for efficiency. This means that
+ # will be a delay for INFO/DEBUG logs to get written, but WARNING/ERROR
+ # logs will still be flushed immediately.
+ buffer:
+ class: logging.handlers.MemoryHandler
+ target: file
+ # The capacity is the number of log lines that are buffered before
+ # being written to disk. Increasing this will lead to better
+ # performance, at the expensive of it taking longer for log lines to
+ # be written to disk.
+ capacity: 10
+ flushLevel: 30 # Flush for WARNING logs as well
+
+ # A handler that writes logs to stderr. Unused by default, but can be used
+ # instead of "buffer" and "file" in the logger handlers.
console:
class: logging.StreamHandler
formatter: precise
- filters: [context]
loggers:
synapse.storage.SQL:
@@ -80,9 +91,24 @@ loggers:
# information such as access tokens.
level: INFO
+ twisted:
+ # We send the twisted logging directly to the file handler,
+ # to work around https://github.com/matrix-org/synapse/issues/3471
+ # when using "buffer" logger. Use "console" to log to stderr instead.
+ handlers: [file]
+ propagate: false
+
root:
level: INFO
- handlers: [file, console]
+
+ # Write logs to the `buffer` handler, which will buffer them together in memory,
+ # then write them to a file.
+ #
+ # Replace "buffer" with "console" to log to stderr instead. (Note that you'll
+ # also need to update the configuation for the `twisted` logger above, in
+ # this case.)
+ #
+ handlers: [buffer]
disable_existing_loggers: false
"""
@@ -168,17 +194,33 @@ def _setup_stdlib_logging(config, log_config, logBeginner: LogBeginner):
handler = logging.StreamHandler()
handler.setFormatter(formatter)
- handler.addFilter(LoggingContextFilter(request=""))
logger.addHandler(handler)
else:
logging.config.dictConfig(log_config)
+ # We add a log record factory that runs all messages through the
+ # LoggingContextFilter so that we get the context *at the time we log*
+ # rather than when we write to a handler. This can be done in config using
+ # filter options, but care must when using e.g. MemoryHandler to buffer
+ # writes.
+
+ log_filter = LoggingContextFilter(request="")
+ old_factory = logging.getLogRecordFactory()
+
+ def factory(*args, **kwargs):
+ record = old_factory(*args, **kwargs)
+ log_filter.filter(record)
+ return record
+
+ logging.setLogRecordFactory(factory)
+
# Route Twisted's native logging through to the standard library logging
# 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
@@ -189,7 +231,25 @@ def _setup_stdlib_logging(config, log_config, logBeginner: LogBeginner):
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__)
+ 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:
|
