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

Commit

Permalink
Reload the pyo3-log config when the Python logging config changes. (#…
Browse files Browse the repository at this point in the history
…14976)

Since pyo3-log is initialized very early in the Python start-up
it caches the state of the loggers before they're fully initialized
(and thus are essentially disabled). Whenever we reload the
logging configuration we now also tell pyo3-log to discard
any cached logging configuration it has; it will refetch the
current logging configuration from Python at the next point
it logs.

This fixes Rust log lines not appearing in the homeserver logs.
  • Loading branch information
clokep authored Feb 3, 2023
1 parent da05b70 commit 8e9fc28
Show file tree
Hide file tree
Showing 5 changed files with 44 additions and 20 deletions.
1 change: 1 addition & 0 deletions changelog.d/14976.bugfix
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
Fix a bug introduced in Synapse 1.68.0 where logging from the Rust module was not properly logged.
17 changes: 15 additions & 2 deletions rust/src/lib.rs
Original file line number Diff line number Diff line change
@@ -1,7 +1,13 @@
use lazy_static::lazy_static;
use pyo3::prelude::*;
use pyo3_log::ResetHandle;

pub mod push;

lazy_static! {
static ref LOGGING_HANDLE: ResetHandle = pyo3_log::init();
}

/// Returns the hash of all the rust source files at the time it was compiled.
///
/// Used by python to detect if the rust library is outdated.
Expand All @@ -17,13 +23,20 @@ fn sum_as_string(a: usize, b: usize) -> PyResult<String> {
Ok((a + b).to_string())
}

/// Reset the cached logging configuration of pyo3-log to pick up any changes
/// in the Python logging configuration.
///
#[pyfunction]
fn reset_logging_config() {
LOGGING_HANDLE.reset();
}

/// The entry point for defining the Python module.
#[pymodule]
fn synapse_rust(py: Python<'_>, m: &PyModule) -> PyResult<()> {
pyo3_log::init();

m.add_function(wrap_pyfunction!(sum_as_string, m)?)?;
m.add_function(wrap_pyfunction!(get_rust_file_digest, m)?)?;
m.add_function(wrap_pyfunction!(reset_logging_config, m)?)?;

push::register_module(py, m)?;

Expand Down
1 change: 1 addition & 0 deletions stubs/synapse/synapse_rust/__init__.pyi
Original file line number Diff line number Diff line change
@@ -1,2 +1,3 @@
def sum_as_string(a: int, b: int) -> str: ...
def get_rust_file_digest() -> str: ...
def reset_logging_config() -> None: ...
42 changes: 24 additions & 18 deletions synapse/config/logger.py
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@

from synapse.logging.context import LoggingContextFilter
from synapse.logging.filter import MetadataFilter
from synapse.synapse_rust import reset_logging_config
from synapse.types import JsonDict

from ..util import SYNAPSE_VERSION
Expand Down Expand Up @@ -200,24 +201,6 @@ def _setup_stdlib_logging(
"""
Set up Python standard library logging.
"""
if log_config_path is None:
log_format = (
"%(asctime)s - %(name)s - %(lineno)d - %(levelname)s - %(request)s"
" - %(message)s"
)

logger = logging.getLogger("")
logger.setLevel(logging.INFO)
logging.getLogger("synapse.storage.SQL").setLevel(logging.INFO)

formatter = logging.Formatter(log_format)

handler = logging.StreamHandler()
handler.setFormatter(formatter)
logger.addHandler(handler)
else:
# Load the logging configuration.
_load_logging_config(log_config_path)

# We add a log record factory that runs all messages through the
# LoggingContextFilter so that we get the context *at the time we log*
Expand All @@ -237,6 +220,26 @@ def factory(*args: Any, **kwargs: Any) -> logging.LogRecord:

logging.setLogRecordFactory(factory)

# Configure the logger with the initial configuration.
if log_config_path is None:
log_format = (
"%(asctime)s - %(name)s - %(lineno)d - %(levelname)s - %(request)s"
" - %(message)s"
)

logger = logging.getLogger("")
logger.setLevel(logging.INFO)
logging.getLogger("synapse.storage.SQL").setLevel(logging.INFO)

formatter = logging.Formatter(log_format)

handler = logging.StreamHandler()
handler.setFormatter(formatter)
logger.addHandler(handler)
else:
# Load the logging configuration.
_load_logging_config(log_config_path)

# Route Twisted's native logging through to the standard library logging
# system.
observer = STDLibLogObserver()
Expand Down Expand Up @@ -294,6 +297,9 @@ def _load_logging_config(log_config_path: str) -> None:

logging.config.dictConfig(log_config)

# Blow away the pyo3-log cache so that it reloads the configuration.
reset_logging_config()


def _reload_logging_config(log_config_path: Optional[str]) -> None:
"""
Expand Down
3 changes: 3 additions & 0 deletions tests/test_utils/logging_setup.py
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@
import twisted.logger

from synapse.logging.context import LoggingContextFilter
from synapse.synapse_rust import reset_logging_config


class ToTwistedHandler(logging.Handler):
Expand Down Expand Up @@ -52,3 +53,5 @@ def setup_logging():

log_level = os.environ.get("SYNAPSE_TEST_LOG_LEVEL", "ERROR")
root_logger.setLevel(log_level)

reset_logging_config()

0 comments on commit 8e9fc28

Please sign in to comment.