From 1de333e0ecd95463c1758f62b3510aab1e394440 Mon Sep 17 00:00:00 2001 From: steve-chavez Date: Mon, 22 Apr 2024 16:18:08 -0500 Subject: [PATCH] feat: add log-level=debug --- CHANGELOG.md | 1 + docs/references/configuration.rst | 2 ++ src/PostgREST/CLI.hs | 2 +- src/PostgREST/Config.hs | 4 +++- src/PostgREST/Logger.hs | 10 +++++++--- test/io/test_io.py | 10 +++++----- 6 files changed, 19 insertions(+), 10 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 21cf719eb4..601efd4c08 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -14,6 +14,7 @@ This project adheres to [Semantic Versioning](http://semver.org/). - #3210, Dump schema cache through admin API - @taimoorzaeem - #2676, Performance improvement on bulk json inserts, around 10% increase on requests per second by removing `json_typeof` from write queries - @steve-chavez - #3214, Log connection pool events on log-level=info - @steve-chavez + - #3435, Add log-level=debug, for development purposes - @steve-chavez ### Fixed diff --git a/docs/references/configuration.rst b/docs/references/configuration.rst index 2067f38be5..8c347dadf7 100644 --- a/docs/references/configuration.rst +++ b/docs/references/configuration.rst @@ -680,6 +680,8 @@ log-level # All the "warn" level events plus all requests (every status code) are logged log-level = "info" + # All the above plus events for development purposes are logged + log-level = "debug" Because currently there's no buffering for logging, the levels with minimal logging(``crit/error``) will increase throughput. diff --git a/src/PostgREST/CLI.hs b/src/PostgREST/CLI.hs index bf33509a28..9550bc3f18 100644 --- a/src/PostgREST/CLI.hs +++ b/src/PostgREST/CLI.hs @@ -203,7 +203,7 @@ exampleConfigFile = |## Enables and set JWT Cache max lifetime, disables caching with 0 |# jwt-cache-max-lifetime = 0 | - |## Logging level, the admitted values are: crit, error, warn and info. + |## Logging level, the admitted values are: crit, error, warn, info and debug. |log-level = "error" | |## Determine if the OpenAPI output should follow or ignore role privileges or be disabled entirely. diff --git a/src/PostgREST/Config.hs b/src/PostgREST/Config.hs index 6d4de526da..e13cbf4997 100644 --- a/src/PostgREST/Config.hs +++ b/src/PostgREST/Config.hs @@ -114,7 +114,7 @@ data AppConfig = AppConfig , configInternalSCSleep :: Maybe Int32 } -data LogLevel = LogCrit | LogError | LogWarn | LogInfo +data LogLevel = LogCrit | LogError | LogWarn | LogInfo | LogDebug deriving (Eq, Ord) dumpLogLevel :: LogLevel -> Text @@ -123,6 +123,7 @@ dumpLogLevel = \case LogError -> "error" LogWarn -> "warn" LogInfo -> "info" + LogDebug -> "debug" data OpenAPIMode = OAFollowPriv | OAIgnorePriv | OADisabled deriving Eq @@ -338,6 +339,7 @@ parser optPath env dbSettings roleSettings roleIsolationLvl = Just "error" -> pure LogError Just "warn" -> pure LogWarn Just "info" -> pure LogInfo + Just "debug" -> pure LogDebug Just _ -> fail "Invalid logging level. Check your configuration." parseTxEnd :: C.Key -> ((Bool, Bool) -> Bool) -> C.Parser C.Config Bool diff --git a/src/PostgREST/Logger.hs b/src/PostgREST/Logger.hs index 55ab16a6c3..1a4145c52f 100644 --- a/src/PostgREST/Logger.hs +++ b/src/PostgREST/Logger.hs @@ -56,10 +56,11 @@ logWithDebounce loggerState action = do middleware :: LogLevel -> (Wai.Request -> Maybe BS.ByteString) -> Wai.Middleware middleware logLevel getAuthRole = case logLevel of - LogInfo -> requestLogger (const True) - LogWarn -> requestLogger (>= status400) - LogError -> requestLogger (>= status500) LogCrit -> requestLogger (const False) + LogError -> requestLogger (>= status500) + LogWarn -> requestLogger (>= status400) + LogInfo -> requestLogger (const True) + LogDebug -> requestLogger (const True) where requestLogger filterStatus = unsafePerformIO $ Wai.mkRequestLogger Wai.defaultRequestLoggerSettings @@ -84,6 +85,9 @@ observationLogger loggerState logLevel obs = case obs of o@(HasqlPoolObs _) -> do when (logLevel >= LogInfo) $ do logWithZTime loggerState $ observationMessage o + o@(SchemaCacheLoadedObs _) -> do + when (logLevel >= LogDebug) $ do + logWithZTime loggerState $ observationMessage o o -> logWithZTime loggerState $ observationMessage o diff --git a/test/io/test_io.py b/test/io/test_io.py index 9b229341be..0ee692a8c6 100644 --- a/test/io/test_io.py +++ b/test/io/test_io.py @@ -575,7 +575,7 @@ def sleep(i=i): assert delta > 1 and delta < 1.5 -@pytest.mark.parametrize("level", ["crit", "error", "warn", "info"]) +@pytest.mark.parametrize("level", ["crit", "error", "warn", "info", "debug"]) def test_pool_acquisition_timeout(level, defaultenv, metapostgrest): "Verify that PGRST_DB_POOL_ACQUISITION_TIMEOUT times out when the pool is empty" @@ -597,7 +597,7 @@ def test_pool_acquisition_timeout(level, defaultenv, metapostgrest): if level == "crit": assert len(output) == 0 - elif level == "info": + elif level in ["info", "debug"]: assert " 504 " in output[0] assert "Timed out acquiring connection from connection pool." in output[2] @@ -772,7 +772,7 @@ def test_admin_works_with_host_special_values(specialhostvalue, defaultenv): assert response.status_code == 200 -@pytest.mark.parametrize("level", ["crit", "error", "warn", "info"]) +@pytest.mark.parametrize("level", ["crit", "error", "warn", "info", "debug"]) def test_log_level(level, defaultenv): "log_level should filter request logging" @@ -1358,7 +1358,7 @@ def test_no_preflight_request_with_CORS_config_should_not_return_header(defaulte assert "Access-Control-Allow-Origin" not in response.headers -@pytest.mark.parametrize("level", ["crit", "error", "warn", "info"]) +@pytest.mark.parametrize("level", ["crit", "error", "warn", "info", "debug"]) def test_db_error_logging_to_stderr(level, defaultenv, metapostgrest): "verify that DB errors are logged to stderr" @@ -1381,7 +1381,7 @@ def test_db_error_logging_to_stderr(level, defaultenv, metapostgrest): if level == "crit": assert len(output) == 0 - elif level == "info": + elif level in ["info", "debug"]: assert " 500 " in output[0] assert "canceling statement due to statement timeout" in output[3] else: