From 022f0faa388d1a1a26b64366c8d08b7772146cdc Mon Sep 17 00:00:00 2001 From: Taimoor Zaeem Date: Tue, 28 Jul 2026 04:07:49 +0500 Subject: [PATCH] add: make config log-level reloadable Closes #5113. Signed-off-by: Taimoor Zaeem --- CHANGELOG.md | 1 + docs/references/configuration.rst | 2 +- src/library/PostgREST/AppState.hs | 21 +++--- src/library/PostgREST/Logger.hs | 87 +++++++++++++------------ test/io/configs/sigusr2-settings.config | 3 + test/io/test_io.py | 37 +++++++++++ test/observability/Main.hs | 6 +- test/spec/Main.hs | 6 +- 8 files changed, 107 insertions(+), 56 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 15472f581..a2aaee54f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -16,6 +16,7 @@ All notable changes to this project will be documented in this file. From versio - Add GHC runtime metrics to the metrics endpoint by @mkleczek in #4862 - Support running the admin server on a unix socket by @wolfgangwalther in #5003 - Add config `server-reuseport` to allow starting multiple PostgREST instances using the same port on supported platforms by @mkleczek in #4703, #4694 +- Make config `log-level` reloadable by @taimoorzaeem in #5113 ### Fixed diff --git a/docs/references/configuration.rst b/docs/references/configuration.rst index 4cc32c871..67cd530c4 100644 --- a/docs/references/configuration.rst +++ b/docs/references/configuration.rst @@ -767,7 +767,7 @@ log-level =============== ================================= **Type** String **Default** error - **Reloadable** N + **Reloadable** Y **Environment** PGRST_LOG_LEVEL **In-Database** `n/a` =============== ================================= diff --git a/src/library/PostgREST/AppState.hs b/src/library/PostgREST/AppState.hs index 6896ad869..0a94ad3c2 100644 --- a/src/library/PostgREST/AppState.hs +++ b/src/library/PostgREST/AppState.hs @@ -39,7 +39,7 @@ import PostgREST.Version (prettyVersion) import Control.AutoUpdate (defaultUpdateSettings, mkAutoUpdate, updateAction) import Control.Concurrent.STM (newEmptyTMVarIO) -import Data.IORef (newIORef, readIORef) +import Data.IORef (IORef, newIORef, readIORef) import Data.Time.Clock (getCurrentTime) import PostgREST.AppState.Pool (destroy, initPool, usePool) import PostgREST.AppState.Reload (isSchemaCacheLoaded, readInDbConfig, @@ -54,26 +54,29 @@ import PostgREST.Debounce (makeDebouncer) import Protolude init :: AppConfig -> IO () -> IO AppState -init conf@AppConfig{configLogLevel, configDbPoolSize} appKiller = do - loggerState <- Logger.init +init conf@AppConfig{configDbPoolSize} appKiller = do + -- We need to create IORef first, so we can make its read action part of + -- loggerState. This is needed for log-level config reloading. + confRef <- newIORef conf + loggerState <- Logger.init (configLogLevel <$> readIORef confRef) metricsState <- Metrics.init configDbPoolSize - let observer = liftA2 (>>) (Logger.observationLogger loggerState configLogLevel) (Metrics.observationMetrics metricsState) + let observer = liftA2 (>>) (Logger.observationLogger loggerState) (Metrics.observationMetrics metricsState) observer $ AppStartObs prettyVersion pool <- initPool conf observer - initWithPool pool conf loggerState metricsState observer appKiller - -initWithPool :: SQL.Pool -> AppConfig -> Logger.LoggerState -> Metrics.MetricsState -> ObservationHandler -> IO () -> IO AppState -initWithPool pool conf loggerState metricsState observer appKiller = mdo + initWithPool pool confRef loggerState metricsState observer appKiller +initWithPool :: SQL.Pool -> IORef AppConfig -> Logger.LoggerState -> Metrics.MetricsState -> ObservationHandler -> IO () -> IO AppState +initWithPool pool confRef loggerState metricsState observer appKiller = mdo + conf <- readIORef confRef appState <- AppState pool <$> newIORef minimumPgVersion -- assume we're in a supported version when starting, this will be corrected on a later step <*> newIORef Nothing <*> newSchemaCacheStatus <*> newIORef False <*> makeDebouncer (retryingSchemaCacheLoad appState *> threadDelay 100000) -- 100ms cooldown - <*> newIORef conf + <*> pure confRef <*> mkAutoUpdate defaultUpdateSettings { updateAction = getCurrentTime } <*> pure appKiller <*> newIORef 0 diff --git a/src/library/PostgREST/Logger.hs b/src/library/PostgREST/Logger.hs index 70e3c905e..e178f717c 100644 --- a/src/library/PostgREST/Logger.hs +++ b/src/library/PostgREST/Logger.hs @@ -45,13 +45,14 @@ import Protolude data LoggerState = LoggerState { stateGetZTime :: IO ZonedTime -- ^ Time with time zone used for logs , stateLogDebouncePoolTimeout :: IO () -- ^ Logs with a debounce + , getLogLevel :: IO LogLevel -- ^ Get LogLevel from Config } -init :: IO LoggerState -init = mdo +init :: IO LogLevel -> IO LoggerState +init getLogLvl = mdo let oneSecond = 1_000_000 - loggerState = LoggerState zTime debouncePoolTimeout + loggerState = LoggerState zTime debouncePoolTimeout getLogLvl zTime <- mkAutoUpdate defaultUpdateSettings { updateAction = getZonedTime } debouncePoolTimeout <- makeDebouncer $ logWithZTime loggerState (observationMessages PoolAcqTimeoutObs) *> threadDelay (5 * oneSecond) @@ -66,47 +67,49 @@ shouldLogResponse logLevel = case logLevel of LogDebug -> const True -- All observations are logged except some that depend on the log-level -observationLogger :: LoggerState -> LogLevel -> ObservationHandler -observationLogger loggerState logLevel obs = case obs of - PoolAcqTimeoutObs -> do - when (logLevel >= LogError) $ - stateLogDebouncePoolTimeout loggerState - o@(QueryErrorCodeHighObs _) -> do - when (logLevel >= LogError) $ do +observationLogger :: LoggerState -> ObservationHandler +observationLogger loggerState obs = do + logLevel <- getLogLevel loggerState -- We need to do the IO action to read the "log-level" config value because it can be reloaded + case obs of + PoolAcqTimeoutObs -> do + when (logLevel >= LogError) $ + stateLogDebouncePoolTimeout loggerState + o@(QueryErrorCodeHighObs _) -> do + when (logLevel >= LogError) $ do + logWithZTime loggerState $ observationMessages o + o@SchemaCacheEmptyObs -> + when (logLevel >= LogError) $ do logWithZTime loggerState $ observationMessages o - o@SchemaCacheEmptyObs -> - when (logLevel >= LogError) $ do - logWithZTime loggerState $ observationMessages o - o@(HasqlPoolObs _) -> do - when (logLevel >= LogDebug) $ do + o@(HasqlPoolObs _) -> do + when (logLevel >= LogDebug) $ do + logWithZTime loggerState $ observationMessages o + o@(QueryObs _ status) -> do + when (shouldLogResponse logLevel status) $ + logWithZTime loggerState $ observationMessages o + o@PoolRequest -> + when (logLevel >= LogDebug) $ do + logWithZTime loggerState $ observationMessages o + o@PoolRequestFullfilled -> + when (logLevel >= LogDebug) $ do + logWithZTime loggerState $ observationMessages o + ResponseObs maybeRole req status contentLen -> + when (shouldLogResponse logLevel status) $ do + zTime <- stateGetZTime loggerState + putStr $ apacheFormat maybeRole (BS.pack $ formatZonedTime zTime) req status contentLen -- putStr prints to stdout + o@PoolFlushed -> + when (logLevel >= LogDebug) $ do + logWithZTime loggerState $ observationMessages o + o@JwtCacheEviction -> + when (logLevel >= LogDebug) $ do + logWithZTime loggerState $ observationMessages o + o@(JwtCacheLookup _) -> + when (logLevel >= LogDebug) $ do + logWithZTime loggerState $ observationMessages o + o@(WarpServerObs _) -> + when (logLevel >= LogDebug) $ do + logWithZTime loggerState $ observationMessages o + o -> logWithZTime loggerState $ observationMessages o - o@(QueryObs _ status) -> do - when (shouldLogResponse logLevel status) $ - logWithZTime loggerState $ observationMessages o - o@PoolRequest -> - when (logLevel >= LogDebug) $ do - logWithZTime loggerState $ observationMessages o - o@PoolRequestFullfilled -> - when (logLevel >= LogDebug) $ do - logWithZTime loggerState $ observationMessages o - ResponseObs maybeRole req status contentLen -> - when (shouldLogResponse logLevel status) $ do - zTime <- stateGetZTime loggerState - putStr $ apacheFormat maybeRole (BS.pack $ formatZonedTime zTime) req status contentLen -- putStr prints to stdout - o@PoolFlushed -> - when (logLevel >= LogDebug) $ do - logWithZTime loggerState $ observationMessages o - o@JwtCacheEviction -> - when (logLevel >= LogDebug) $ do - logWithZTime loggerState $ observationMessages o - o@(JwtCacheLookup _) -> - when (logLevel >= LogDebug) $ do - logWithZTime loggerState $ observationMessages o - o@(WarpServerObs _) -> - when (logLevel >= LogDebug) $ do - logWithZTime loggerState $ observationMessages o - o -> - logWithZTime loggerState $ observationMessages o logWithZTime :: LoggerState -> [Text] -> IO () logWithZTime loggerState txts = do diff --git a/test/io/configs/sigusr2-settings.config b/test/io/configs/sigusr2-settings.config index b3f842479..4bacedcdb 100644 --- a/test/io/configs/sigusr2-settings.config +++ b/test/io/configs/sigusr2-settings.config @@ -3,3 +3,6 @@ db-schemas = "public" app.settings.name_var = "John" jwt-secret = "invalidinvalidinvalidinvalidinvalid" + +# will be replaced in test +log-level = "error" diff --git a/test/io/test_io.py b/test/io/test_io.py index c273ba2a2..d51c2684d 100644 --- a/test/io/test_io.py +++ b/test/io/test_io.py @@ -1931,3 +1931,40 @@ def test_use_legacy_target_names(enabled, defaultenv): else: assert response.status_code == 400 assert not has_warning_log and not has_hint_log + + +def test_config_log_level_is_reloadable(tmp_path, defaultenv): + "Config log-level should be reloadable on SIGUSR2" + + config = (CONFIGSDIR / "sigusr2-settings.config").read_text() + configfile = tmp_path / "test.config" + configfile.write_text(config) + + # Delete the env variable for "log-level" so the config file value isn't overridden + del defaultenv["PGRST_LOG_LEVEL"] + + with run(configfile, env=defaultenv) as postgrest: + response = postgrest.session.get("/projects") + assert response.status_code == 200 + output = postgrest.read_stdout(nlines=5) + + # log-level = error, so this log line shouldn't be logged + assert not any( + "Trying to borrow a connection from pool" in line for line in output + ) + + # change setting + configfile.write_text( + config.replace('log-level = "error"', 'log-level = "debug"') + ) + # reload + postgrest.process.send_signal(signal.SIGUSR2) + + sleep_until_postgrest_config_reload() + + response = postgrest.session.get("/projects") + assert response.status_code == 200 + output = postgrest.read_stdout(nlines=5) + + # log-level = debug now, so this log line must be logged + assert any("Trying to borrow a connection from pool" in line for line in output) diff --git a/test/observability/Main.hs b/test/observability/Main.hs index a9b2c9cce..0eb483801 100644 --- a/test/observability/Main.hs +++ b/test/observability/Main.hs @@ -5,6 +5,7 @@ import qualified Hasql.Pool.Config as P import qualified Hasql.Transaction.Sessions as HT import Data.Function (id) +import Data.IORef (newIORef, readIORef) import PostgREST.App (postgrest) import qualified PostgREST.AppState as AppState @@ -48,14 +49,15 @@ main = do -- cached schema cache so most tests run fast baseSchemaCache <- loadSCache pool testCfg - loggerState <- Logger.init let initApp sCache config = do -- duplicate poolChan as a starting point + confRef <- newIORef config + loggerState <- Logger.init (configLogLevel <$> readIORef confRef) obsChan <- dupChan poolChan stateObsChan <- newObsChan obsChan - appState <- AppState.initWithPool pool config loggerState metricsState (Metrics.observationMetrics metricsState <> writeChan obsChan) mempty + appState <- AppState.initWithPool pool confRef loggerState metricsState (Metrics.observationMetrics metricsState <> writeChan obsChan) mempty AppState.putPgVersion appState actualPgVersion AppState.putSchemaCache appState (Just sCache) return (SpecState appState metricsState stateObsChan, postgrest appState (pure ())) diff --git a/test/spec/Main.hs b/test/spec/Main.hs index 17cf04637..e4207afd4 100644 --- a/test/spec/Main.hs +++ b/test/spec/Main.hs @@ -5,6 +5,7 @@ import qualified Hasql.Pool.Config as P import qualified Hasql.Transaction.Sessions as HT import Data.Function (id) +import Data.IORef (newIORef, readIORef) import Test.Hspec @@ -88,12 +89,13 @@ main = do -- cached schema cache so most tests run fast baseSchemaCache <- loadSCache pool baseCfg - loggerState <- Logger.init metricsState <- Metrics.init (configDbPoolSize baseCfg) let initApp sCache config = do - appState <- AppState.initWithPool pool config loggerState metricsState (Metrics.observationMetrics metricsState) mempty + confRef <- newIORef config + loggerState <- Logger.init (configLogLevel <$> readIORef confRef) + appState <- AppState.initWithPool pool confRef loggerState metricsState (Metrics.observationMetrics metricsState) mempty AppState.putPgVersion appState actualPgVersion AppState.putSchemaCache appState (Just sCache) return ((), postgrest appState (pure ()))