Ensure that errors during startup are written to the logs and the console. (#10191)

* Defer stdio redirection until we are about to start the reactor

* Catch and handle exceptions during startup
This commit is contained in:
Richard van der Hoff 2021-06-21 11:41:25 +01:00 committed by GitHub
parent 7c536d0fef
commit 107c06081f
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
5 changed files with 55 additions and 16 deletions

View File

@ -0,0 +1 @@
Ensure that errors during startup are written to the logs and the console.

View File

@ -26,7 +26,9 @@ from typing import Awaitable, Callable, Iterable
from cryptography.utils import CryptographyDeprecationWarning from cryptography.utils import CryptographyDeprecationWarning
from typing_extensions import NoReturn from typing_extensions import NoReturn
import twisted
from twisted.internet import defer, error, reactor from twisted.internet import defer, error, reactor
from twisted.logger import LoggingFile, LogLevel
from twisted.protocols.tls import TLSMemoryBIOFactory from twisted.protocols.tls import TLSMemoryBIOFactory
import synapse import synapse
@ -139,7 +141,7 @@ def start_reactor(
def quit_with_error(error_string: str) -> NoReturn: def quit_with_error(error_string: str) -> NoReturn:
message_lines = error_string.split("\n") message_lines = error_string.split("\n")
line_length = max(len(line) for line in message_lines if len(line) < 80) + 2 line_length = min(max(len(line) for line in message_lines), 80) + 2
sys.stderr.write("*" * line_length + "\n") sys.stderr.write("*" * line_length + "\n")
for line in message_lines: for line in message_lines:
sys.stderr.write(" %s\n" % (line.rstrip(),)) sys.stderr.write(" %s\n" % (line.rstrip(),))
@ -147,6 +149,30 @@ def quit_with_error(error_string: str) -> NoReturn:
sys.exit(1) sys.exit(1)
def handle_startup_exception(e: Exception) -> NoReturn:
# Exceptions that occur between setting up the logging and forking or starting
# the reactor are written to the logs, followed by a summary to stderr.
logger.exception("Exception during startup")
quit_with_error(
f"Error during initialisation:\n {e}\nThere may be more information in the logs."
)
def redirect_stdio_to_logs() -> None:
streams = [("stdout", LogLevel.info), ("stderr", LogLevel.error)]
for (stream, level) in streams:
oldStream = getattr(sys, stream)
loggingFile = LoggingFile(
logger=twisted.logger.Logger(namespace=stream),
level=level,
encoding=getattr(oldStream, "encoding", None),
)
setattr(sys, stream, loggingFile)
print("Redirected stdout/stderr to logs")
def register_start(cb: Callable[..., Awaitable], *args, **kwargs) -> None: def register_start(cb: Callable[..., Awaitable], *args, **kwargs) -> None:
"""Register a callback with the reactor, to be called once it is running """Register a callback with the reactor, to be called once it is running

View File

@ -32,7 +32,12 @@ from synapse.api.urls import (
SERVER_KEY_V2_PREFIX, SERVER_KEY_V2_PREFIX,
) )
from synapse.app import _base from synapse.app import _base
from synapse.app._base import max_request_body_size, register_start from synapse.app._base import (
handle_startup_exception,
max_request_body_size,
redirect_stdio_to_logs,
register_start,
)
from synapse.config._base import ConfigError from synapse.config._base import ConfigError
from synapse.config.homeserver import HomeServerConfig from synapse.config.homeserver import HomeServerConfig
from synapse.config.logger import setup_logging from synapse.config.logger import setup_logging
@ -469,14 +474,21 @@ def start(config_options):
setup_logging(hs, config, use_worker_options=True) setup_logging(hs, config, use_worker_options=True)
hs.setup() try:
hs.setup()
# Ensure the replication streamer is always started in case we write to any # Ensure the replication streamer is always started in case we write to any
# streams. Will no-op if no streams can be written to by this worker. # streams. Will no-op if no streams can be written to by this worker.
hs.get_replication_streamer() hs.get_replication_streamer()
except Exception as e:
handle_startup_exception(e)
register_start(_base.start, hs) register_start(_base.start, hs)
# redirect stdio to the logs, if configured.
if not hs.config.no_redirect_stdio:
redirect_stdio_to_logs()
_base.start_worker_reactor("synapse-generic-worker", config) _base.start_worker_reactor("synapse-generic-worker", config)

View File

@ -37,10 +37,11 @@ from synapse.api.urls import (
) )
from synapse.app import _base from synapse.app import _base
from synapse.app._base import ( from synapse.app._base import (
handle_startup_exception,
listen_ssl, listen_ssl,
listen_tcp, listen_tcp,
max_request_body_size, max_request_body_size,
quit_with_error, redirect_stdio_to_logs,
register_start, register_start,
) )
from synapse.config._base import ConfigError from synapse.config._base import ConfigError
@ -69,8 +70,6 @@ from synapse.rest.synapse.client import build_synapse_client_resource_tree
from synapse.rest.well_known import WellKnownResource from synapse.rest.well_known import WellKnownResource
from synapse.server import HomeServer from synapse.server import HomeServer
from synapse.storage import DataStore from synapse.storage import DataStore
from synapse.storage.engines import IncorrectDatabaseSetup
from synapse.storage.prepare_database import UpgradeDatabaseException
from synapse.util.httpresourcetree import create_resource_tree from synapse.util.httpresourcetree import create_resource_tree
from synapse.util.module_loader import load_module from synapse.util.module_loader import load_module
from synapse.util.versionstring import get_version_string from synapse.util.versionstring import get_version_string
@ -362,10 +361,8 @@ def setup(config_options):
try: try:
hs.setup() hs.setup()
except IncorrectDatabaseSetup as e: except Exception as e:
quit_with_error(str(e)) handle_startup_exception(e)
except UpgradeDatabaseException as e:
quit_with_error("Failed to upgrade database: %s" % (e,))
async def start(): async def start():
# Load the OIDC provider metadatas, if OIDC is enabled. # Load the OIDC provider metadatas, if OIDC is enabled.
@ -456,6 +453,11 @@ def main():
# check base requirements # check base requirements
check_requirements() check_requirements()
hs = setup(sys.argv[1:]) hs = setup(sys.argv[1:])
# redirect stdio to the logs, if configured.
if not hs.config.no_redirect_stdio:
redirect_stdio_to_logs()
run(hs) run(hs)

View File

@ -259,9 +259,7 @@ def _setup_stdlib_logging(config, log_config_path, logBeginner: LogBeginner) ->
finally: finally:
threadlocal.active = False threadlocal.active = False
logBeginner.beginLoggingTo([_log], redirectStandardIO=not config.no_redirect_stdio) logBeginner.beginLoggingTo([_log], redirectStandardIO=False)
if not config.no_redirect_stdio:
print("Redirected stdout/stderr to logs")
def _load_logging_config(log_config_path: str) -> None: def _load_logging_config(log_config_path: str) -> None: