fix: log connection pool events on log-level="debug" instead of "info"

CHANGELOG.md

@@ -12,7 +12,6 @@ This project adheres to [Semantic Versioning](http://semver.org/).
  - #3171, #3046, Log schema cache stats to stderr - @steve-chavez
  - #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
  - #1526, Add `/metrics` endpoint on admin server - @steve-chavez
    - Exposes connection pool metrics, schema cache metrics
@@ -23,6 +22,7 @@ This project adheres to [Semantic Versioning](http://semver.org/).
  - #3340, Log when the LISTEN channel gets a notification - @steve-chavez
  - #3184, Log full pg version to stderr on connection - @steve-chavez
  - #3242. Add config `db-hoisted-tx-settings` to apply only hoisted function settings - @taimoorzaeem
+ - #3214, #3229 Log connection pool events on log-level=debug - @steve-chavez, @laurenceisla
 
 ### Fixed
 

src/PostgREST/Logger.hs

@@ -83,7 +83,7 @@ observationLogger loggerState logLevel obs = case obs of
     when (logLevel >= LogError) $ do
       logWithZTime loggerState $ observationMessage o
   o@(HasqlPoolObs _) -> do
-    when (logLevel >= LogInfo) $ do
+    when (logLevel >= LogDebug) $ do
       logWithZTime loggerState $ observationMessage o
   o@(SchemaCacheLoadedObs _) -> do
     when (logLevel >= LogDebug) $ do

test/io/test_io.py

@@ -612,7 +612,7 @@ def test_pool_acquisition_timeout(level, defaultenv, metapostgrest):
 
         if level == "crit":
             assert len(output) == 0
-        elif level in ["info", "debug"]:
+        else:
             assert " 504 " in output[0]
             assert "Timed out acquiring connection from connection pool." in output[2]
 
@@ -871,7 +871,21 @@ def test_log_level(level, defaultenv):
                 output[1],
             )
             assert len(output) == 2
-        else:
+        elif level == "info":
+            assert re.match(
+                r'- - - \[.+\] "GET / HTTP/1.1" 500 - "" "python-requests/.+"',
+                output[0],
+            )
+            assert re.match(
+                r'- - postgrest_test_anonymous \[.+\] "GET / HTTP/1.1" 200 - "" "python-requests/.+"',
+                output[1],
+            )
+            assert re.match(
+                r'- - postgrest_test_anonymous \[.+\] "GET /unknown HTTP/1.1" 404 - "" "python-requests/.+"',
+                output[2],
+            )
+            assert len(output) == 3
+        elif level == "debug":
             assert re.match(
                 r'- - - \[.+\] "GET / HTTP/1.1" 500 - "" "python-requests/.+"',
                 output[0],
@@ -1164,9 +1178,9 @@ def test_log_postgrest_version(defaultenv):
     with run(env=defaultenv, no_startup_stdout=False) as postgrest:
         version = postgrest.session.head("/").headers["Server"].split("/")[1]
 
-        output = sorted(postgrest.read_stdout(nlines=5))
+        output = postgrest.read_stdout(nlines=1)
 
-        assert "Starting PostgREST %s..." % version in output[4]
+        assert "Starting PostgREST %s..." % version in output[0]
 
 
 def test_succeed_w_role_having_superuser_settings(defaultenv):
@@ -1456,7 +1470,7 @@ def test_db_error_logging_to_stderr(level, defaultenv, metapostgrest):
 
         if level == "crit":
             assert len(output) == 0
-        elif level in ["info", "debug"]:
+        elif level == "debug":
             assert " 500 " in output[0]
             assert "canceling statement due to statement timeout" in output[3]
         else: