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

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

Merged
merged 3 commits into from
Jun 21, 2021
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.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions changelog.d/10191.feature
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
Ensure that errors during startup are written to the logs and the console.
28 changes: 27 additions & 1 deletion synapse/app/_base.py
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,9 @@
from cryptography.utils import CryptographyDeprecationWarning
from typing_extensions import NoReturn

import twisted
from twisted.internet import defer, error, reactor
from twisted.logger import LoggingFile, LogLevel
from twisted.protocols.tls import TLSMemoryBIOFactory

import synapse
Expand Down Expand Up @@ -141,14 +143,38 @@ def run():

def quit_with_error(error_string: str) -> NoReturn:
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")
for line in message_lines:
sys.stderr.write(" %s\n" % (line.rstrip(),))
sys.stderr.write("*" * line_length + "\n")
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:
"""Register a callback with the reactor, to be called once it is running

Expand Down
22 changes: 17 additions & 5 deletions synapse/app/generic_worker.py
Original file line number Diff line number Diff line change
Expand Up @@ -32,7 +32,12 @@
SERVER_KEY_V2_PREFIX,
)
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.homeserver import HomeServerConfig
from synapse.config.logger import setup_logging
Expand Down Expand Up @@ -465,14 +470,21 @@ def start(config_options):

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
# streams. Will no-op if no streams can be written to by this worker.
hs.get_replication_streamer()
# 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.
hs.get_replication_streamer()
except Exception as e:
handle_startup_exception(e)

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)


Expand Down
16 changes: 9 additions & 7 deletions synapse/app/homeserver.py
Original file line number Diff line number Diff line change
Expand Up @@ -37,10 +37,11 @@
)
from synapse.app import _base
from synapse.app._base import (
handle_startup_exception,
listen_ssl,
listen_tcp,
max_request_body_size,
quit_with_error,
redirect_stdio_to_logs,
register_start,
)
from synapse.config._base import ConfigError
Expand Down Expand Up @@ -69,8 +70,6 @@
from synapse.rest.well_known import WellKnownResource
from synapse.server import HomeServer
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.module_loader import load_module
from synapse.util.versionstring import get_version_string
Expand Down Expand Up @@ -358,10 +357,8 @@ def setup(config_options):

try:
hs.setup()
except IncorrectDatabaseSetup as e:
quit_with_error(str(e))
except UpgradeDatabaseException as e:
quit_with_error("Failed to upgrade database: %s" % (e,))
except Exception as e:
handle_startup_exception(e)

async def do_acme() -> bool:
"""
Expand Down Expand Up @@ -500,6 +497,11 @@ def main():
# check base requirements
check_requirements()
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)


Expand Down
4 changes: 1 addition & 3 deletions synapse/config/logger.py
Original file line number Diff line number Diff line change
Expand Up @@ -259,9 +259,7 @@ def _log(event: dict) -> None:
finally:
threadlocal.active = False

logBeginner.beginLoggingTo([_log], redirectStandardIO=not config.no_redirect_stdio)
if not config.no_redirect_stdio:
print("Redirected stdout/stderr to logs")
logBeginner.beginLoggingTo([_log], redirectStandardIO=False)


def _load_logging_config(log_config_path: str) -> None:
Expand Down