From 92719076187304759ba309840c436f5a77858df1 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Micha=C5=82=20K=C5=82eczek?= Date: Wed, 25 Feb 2026 19:54:31 +0100 Subject: [PATCH 1/2] fix: Flush pool as late as possible during schema cache reloading retryingSchemaCacheLoad flushes the pool upon every retry before it starts reloading the schema. This is too early as schema reloading might take some time during which new connections might be acquired. The consequence is that: * upon successful schema cache reload we might have some connections created with the old schema cache * we close connections upon each retry and under load we will keep closing and re-opening connections until schema cache load succeeds This change is to make sure we flush the pool only after successful schema cache querying but before loading (so that connections acquired during loading wait for it and do not interfere with timing the loading process). --- CHANGELOG.md | 4 ++++ src/PostgREST/AppState.hs | 6 ++++-- test/io/test_io.py | 8 ++++---- test/observability/Observation/SchemaCacheSpec.hs | 6 ++---- 4 files changed, 14 insertions(+), 10 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index ea36f2edb2..4afe37d1eb 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -15,6 +15,10 @@ All notable changes to this project will be documented in this file. From versio - Add config `db-timezone-enabled` for optional querying of timezones by @taimoorzaeem in #4751 - Log when the pool is released during schema cache reload on `log-level=debug` by @mkleczek in #4668 +### Fixed + +- Pool should be flushed not before but after schema cache reloading by @mkleczek in #4645 + ### Changed - All responses now include a `Vary` header by @develop7 in #4609 diff --git a/src/PostgREST/AppState.hs b/src/PostgREST/AppState.hs index e8424fb728..4d96ed70fa 100644 --- a/src/PostgREST/AppState.hs +++ b/src/PostgREST/AppState.hs @@ -302,8 +302,6 @@ retryingSchemaCacheLoad appState@AppState{stateObserver=observer, stateMainThrea let delay = fromMaybe 0 rsPreviousDelay `div` oneSecondInUs observer $ ConnectionRetryObs delay - flushPool appState - (,) <$> qPgVersion <*> (qInDbConfig *> qSchemaCache) ) where @@ -352,6 +350,10 @@ retryingSchemaCacheLoad appState@AppState{stateObserver=observer, stateMainThrea -- IORef on putSchemaCache. This is why schema cache status is marked as pending here to signal the Admin server (using isPending) that we're on a recovery state. markSchemaCachePending appState putSchemaCache appState $ Just sCache + -- Flush the pool after loading the schema cache to reset any stale session cache entries + -- We do it after successfully querying the schema cache + -- and after marking sCacheStatus as pending, + flushPool appState observer $ SchemaCacheQueriedObs resultTime observer . uncurry SchemaCacheLoadedObs =<< timeItT (evaluate $ showSummary sCache) markSchemaCacheLoaded appState diff --git a/test/io/test_io.py b/test/io/test_io.py index 86310cd4be..b0f4aef583 100644 --- a/test/io/test_io.py +++ b/test/io/test_io.py @@ -841,7 +841,7 @@ def test_log_level(level, defaultenv): response = postgrest.session.get("/") assert response.status_code == 200 - output = postgrest.read_stdout(nlines=7) + output = postgrest.read_stdout(nlines=9) if level == "crit": assert len(output) == 0 @@ -879,7 +879,7 @@ def test_log_level(level, defaultenv): r'- - postgrest_test_anonymous \[.+\] "GET / HTTP/1.1" 200 \d+ "" "python-requests/.+"', ], ) - assert len(output) == 7 + assert len(output) == 9 assert any("Connection" and "is available" in line for line in output) assert any("Connection" and "is used" in line for line in output) @@ -1507,7 +1507,7 @@ def test_db_error_logging_to_stderr(level, defaultenv, metapostgrest): assert response.status_code == 500 # ensure the message appears on the logs - output = postgrest.read_stdout(nlines=6) + output = postgrest.read_stdout(nlines=8) if level == "crit": assert len(output) == 0 @@ -1724,7 +1724,7 @@ def test_log_pool_req_observation(level, defaultenv): if level == "debug": output = postgrest.read_stdout(nlines=7) - assert len(output) == 6 + assert len(output) == 7 match_log(output, [pool_req, pool_req_fullfill]) elif level == "info": output = postgrest.read_stdout(nlines=4) diff --git a/test/observability/Observation/SchemaCacheSpec.hs b/test/observability/Observation/SchemaCacheSpec.hs index e3260271b8..318c2dba6b 100644 --- a/test/observability/Observation/SchemaCacheSpec.hs +++ b/test/observability/Observation/SchemaCacheSpec.hs @@ -27,7 +27,7 @@ spec = describe "Server started with metrics enabled" $ do waitFor (1 * sec) "SchemaCacheLoadedObs" $ \x -> [ o | o@SchemaCacheLoadedObs{} <- pure x ] - it "Should flush pool multiple times when schema reloading retries" $ do + it "Should flush pool once when schema reloading retries" $ do SpecState{specAppState = appState, specObsChan} <- getState let waitFor = waitForObs specObsChan @@ -36,16 +36,14 @@ spec = describe "Server started with metrics enabled" $ do AppState.putConfig appState $ cfg { configDbSchemas = pure "bad_schema" } AppState.schemaCacheLoader appState - waitFor (1 * sec) "PoolFlushed 1" $ \x -> [ o | o@PoolFlushed <- pure x ] waitFor (1 * sec) "SchemaCacheErrorObs" $ \x -> [ o | o@SchemaCacheErrorObs{} <- pure x ] -- Restore configuration AppState.putConfig appState cfg -- Wait for 2 seconds so that retry can happen - waitFor (2 * sec) "PoolFlushed 2" $ \x -> [ o | o@PoolFlushed <- pure x ] + waitFor (2 * sec) "PoolFlushed" $ \x -> [ o | o@PoolFlushed <- pure x ] waitFor (1 * sec) "SchemaCacheQueriedObs" $ \x -> [ o | o@SchemaCacheQueriedObs{} <- pure x ] waitFor (1 * sec) "SchemaCacheLoadedObs" $ \x -> [ o | o@SchemaCacheLoadedObs{} <- pure x ] - where sec = 1000000 From 817eb8fdbf9652a790a70f3d3c94e1093322e411 Mon Sep 17 00:00:00 2001 From: Steve Chavez Date: Tue, 14 Apr 2026 16:56:14 -0500 Subject: [PATCH 2/2] chore: add comment and clear changelog Co-authored-by: Steve Chavez --- CHANGELOG.md | 2 +- src/PostgREST/AppState.hs | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 4afe37d1eb..43807eb014 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -17,7 +17,7 @@ All notable changes to this project will be documented in this file. From versio ### Fixed -- Pool should be flushed not before but after schema cache reloading by @mkleczek in #4645 +- Fix unnecessary connection pool flushes during schema cache reloading by @mkleczek in #4645 ### Changed diff --git a/src/PostgREST/AppState.hs b/src/PostgREST/AppState.hs index 4d96ed70fa..55ee2de1db 100644 --- a/src/PostgREST/AppState.hs +++ b/src/PostgREST/AppState.hs @@ -351,7 +351,7 @@ retryingSchemaCacheLoad appState@AppState{stateObserver=observer, stateMainThrea markSchemaCachePending appState putSchemaCache appState $ Just sCache -- Flush the pool after loading the schema cache to reset any stale session cache entries - -- We do it after successfully querying the schema cache + -- We do it after successfully querying the schema cache (because this can fail and during retries we would flush the pool repeatedly unnecessarily) -- and after marking sCacheStatus as pending, flushPool appState observer $ SchemaCacheQueriedObs resultTime