Skip to content

Commit d681d53

Browse files
committed
fix: Limit concurrent schema cache loads
Triggering schema cache reload immediately upon receival of notification by the listener leads to thundering herd problem in PostgREST cluster. This change adds limiting of number of concurrent schema cache loading queries using advisory locks.
1 parent b66bc15 commit d681d53

3 files changed

Lines changed: 158 additions & 8 deletions

File tree

CHANGELOG.md

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -38,6 +38,7 @@ All notable changes to this project will be documented in this file. From versio
3838

3939
- Fix unnecessary connection pool flushes during schema cache reloading by @mkleczek in #4645
4040
- Fix race condition in pool_available metric causing negative values during network instability by @mkleczek in #4622
41+
- Limit concurrent schema cache loads by @mkleczek in #4643
4142

4243
## [14.9] - 2026-04-10
4344

src/PostgREST/AppState.hs

Lines changed: 67 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,9 @@
1-
{-# LANGUAGE LambdaCase #-}
2-
{-# LANGUAGE NamedFieldPuns #-}
3-
{-# LANGUAGE RecordWildCards #-}
4-
{-# LANGUAGE RecursiveDo #-}
1+
{-# LANGUAGE LambdaCase #-}
2+
{-# LANGUAGE NamedFieldPuns #-}
3+
{-# LANGUAGE QuasiQuotes #-}
4+
{-# LANGUAGE RecordWildCards #-}
5+
{-# LANGUAGE RecursiveDo #-}
6+
{-# LANGUAGE TypeApplications #-}
57

68
module PostgREST.AppState
79
( AppState
@@ -33,7 +35,8 @@ import qualified Data.ByteString.Char8 as BS
3335
import Data.Either.Combinators (whenLeft)
3436
import qualified Hasql.Pool as SQL
3537
import qualified Hasql.Pool.Config as SQL
36-
import qualified Hasql.Session as SQL
38+
import qualified Hasql.Session as SQL hiding (statement)
39+
import qualified Hasql.Transaction as SQL hiding (sql)
3740
import qualified Hasql.Transaction.Sessions as SQL
3841
import qualified Network.HTTP.Types.Status as HTTP
3942
import qualified PostgREST.Auth.JwtCache as JwtCache
@@ -63,11 +66,17 @@ import PostgREST.Config.Database (queryDbSettings,
6366
import PostgREST.Config.PgVersion (PgVersion (..),
6467
minimumPgVersion)
6568
import PostgREST.Debounce (makeDebouncer)
69+
import PostgREST.Metrics (MetricsState (connTrack))
6670
import PostgREST.SchemaCache (SchemaCache (..),
6771
querySchemaCache,
6872
showSummary)
6973
import PostgREST.SchemaCache.Identifiers (quoteQi)
7074

75+
import qualified Hasql.Decoders as HD
76+
import qualified Hasql.Encoders as HE
77+
import qualified Hasql.Statement as SQL
78+
import NeatInterpolation (trimming)
79+
7180
import Protolude
7281

7382
data AppState = AppState
@@ -296,7 +305,7 @@ getObserver = stateObserver
296305
-- + Because connections cache the pg catalog(see #2620)
297306
-- + For rapid recovery. Otherwise, the pool idle or lifetime timeout would have to be reached for new healthy connections to be acquired.
298307
retryingSchemaCacheLoad :: AppState -> IO ()
299-
retryingSchemaCacheLoad appState@AppState{stateObserver=observer, stateMainThreadId=mainThreadId} =
308+
retryingSchemaCacheLoad appState@AppState{stateObserver=observer, stateMainThreadId=mainThreadId, stateMetrics} =
300309
void $ retrying retryPolicy shouldRetry (\RetryStatus{rsIterNumber, rsPreviousDelay} -> do
301310
when (rsIterNumber > 0) $ do
302311
let delay = fromMaybe 0 rsPreviousDelay `div` oneSecondInUs
@@ -335,9 +344,23 @@ retryingSchemaCacheLoad appState@AppState{stateObserver=observer, stateMainThrea
335344
qSchemaCache :: IO (Maybe SchemaCache)
336345
qSchemaCache = do
337346
conf@AppConfig{..} <- getConfig appState
347+
-- Throttle concurrent schema cache loads, guarded by advisory locks.
348+
-- This is to prevent thundering herd problem on startup or when many PostgREST
349+
-- instances receive "reload schema" notifications at the same time
350+
-- See get_lock_sql for details of the algorithm.
351+
-- Here we calculate the number of open connections passed to the query.
352+
Metrics.ConnStats connected inUse <- Metrics.connectionCounts $ connTrack stateMetrics
353+
-- Determine whether schema cache loading will create a new session
354+
let
355+
-- if all connections in use but pool not full - schema cache loading will create session
356+
scLoadingSessions = if connected <= inUse && inUse < configDbPoolSize then 1 else 0
357+
withTxLock = SQL.statement
358+
(fromIntegral $ connected + scLoadingSessions)
359+
(SQL.Statement get_lock_sql get_lock_params HD.noResult configDbPreparedStatements)
360+
338361
(resultTime, result) <-
339362
let transaction = if configDbPreparedStatements then SQL.transaction else SQL.unpreparedTransaction in
340-
timeItT $ usePool appState (transaction SQL.ReadCommitted SQL.Read $ querySchemaCache conf)
363+
timeItT $ usePool appState (transaction SQL.ReadCommitted SQL.Read $ withTxLock *> querySchemaCache conf)
341364
case result of
342365
Left e -> do
343366
markSchemaCachePending appState
@@ -359,6 +382,43 @@ retryingSchemaCacheLoad appState@AppState{stateObserver=observer, stateMainThrea
359382
observer $ SchemaCacheLoadedObs loadTime summary
360383
markSchemaCacheLoaded appState
361384
return $ Just sCache
385+
where
386+
-- Recursive query that tries acquiring locks in order
387+
-- and waits for randomly selected lock if no attempt succeeded.
388+
-- It has a single parameter: this node open connection count.
389+
-- It is used to estimate the number of nodes
390+
-- by counting the number of active sessions for current session_user
391+
-- and dividing it by this node open connections.
392+
-- Assuming load is uniform among cluster nodes, all should have
393+
-- statistically the same number of open connections.
394+
-- Once the number of nodes is known we calculate the number
395+
-- of locks as ceil(log(2, number_of_nodes))
396+
get_lock_sql = encodeUtf8 [trimming|
397+
WITH RECURSIVE attempts AS (
398+
SELECT 1 AS lock_number, pg_try_advisory_xact_lock(lock_id, 1) AS success FROM parameters
399+
UNION ALL
400+
SELECT next_lock_number AS lock_number, pg_try_advisory_xact_lock(lock_id, next_lock_number) AS success
401+
FROM
402+
parameters CROSS JOIN LATERAL (
403+
SELECT lock_number + 1 AS next_lock_number FROM attempts
404+
WHERE NOT success AND lock_number < locks_count
405+
ORDER BY lock_number DESC
406+
LIMIT 1
407+
) AS previous_attempt
408+
),
409+
counts AS (
410+
SELECT round(log(2, round(count(*)::double precision/$$1)::numeric))::int AS locks_count
411+
FROM
412+
pg_stat_activity WHERE usename = SESSION_USER
413+
),
414+
parameters AS (
415+
SELECT locks_count, 50168275 AS lock_id FROM counts WHERE locks_count > 0
416+
)
417+
SELECT pg_advisory_xact_lock(lock_id, floor(random() * locks_count)::int + 1)
418+
FROM
419+
parameters WHERE NOT EXISTS (SELECT 1 FROM attempts WHERE success) |]
420+
421+
get_lock_params = HE.param (HE.nonNullable HE.int4)
362422

363423
shouldRetry :: RetryStatus -> (Maybe PgVersion, Maybe SchemaCache) -> IO Bool
364424
shouldRetry _ (pgVer, sCache) = do

test/io/test_io.py

Lines changed: 90 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
"Unit tests for Input/Ouput of PostgREST seen as a black box."
22

3+
import contextlib
34
import os
45
import re
56
import signal
@@ -18,6 +19,7 @@
1819
sleep_until_postgrest_full_reload,
1920
sleep_until_postgrest_scache_reload,
2021
wait_until_exit,
22+
wait_until_status_code,
2123
)
2224

2325

@@ -1218,6 +1220,93 @@ def test_schema_cache_concurrent_notifications(slow_schema_cache_env):
12181220
assert response.status_code == 200
12191221

12201222

1223+
@pytest.mark.parametrize(
1224+
"instance_count, expected_concurrency", [(2, 2), (4, 3), (6, 4), (8, 4), (16, 5)]
1225+
)
1226+
def test_schema_cache_reload_throttled_with_advisory_locks(
1227+
instance_count, expected_concurrency, slow_schema_cache_env
1228+
):
1229+
"schema cache reloads should be throttled across instances"
1230+
1231+
internal_sleep_ms = int(
1232+
slow_schema_cache_env["PGRST_INTERNAL_SCHEMA_CACHE_QUERY_SLEEP"]
1233+
)
1234+
lock_wait_threshold_ms = internal_sleep_ms * 2
1235+
query_log_pattern = re.compile(r"Schema cache queried in ([\d.]+) milliseconds")
1236+
1237+
def read_available_output_lines(postgrest):
1238+
try:
1239+
output = postgrest.process.stdout.read()
1240+
except BlockingIOError:
1241+
return []
1242+
1243+
if not output:
1244+
return []
1245+
return output.decode().splitlines()
1246+
1247+
with contextlib.ExitStack() as stack:
1248+
instances = [
1249+
stack.enter_context(
1250+
run(
1251+
env=slow_schema_cache_env,
1252+
wait_for_readiness=False,
1253+
wait_max_seconds=10,
1254+
)
1255+
)
1256+
for _ in range(instance_count)
1257+
]
1258+
1259+
for postgrest in instances:
1260+
wait_until_status_code(
1261+
postgrest.admin.baseurl + "/ready", max_seconds=10, status_code=200
1262+
)
1263+
1264+
# Drop startup logs so only reload logs are parsed.
1265+
for postgrest in instances:
1266+
read_available_output_lines(postgrest)
1267+
1268+
response = instances[0].session.get("/rpc/notify_pgrst")
1269+
assert response.status_code == 204
1270+
1271+
# Wait long enough for the lock-throttled cache reloads to finish.
1272+
time.sleep((internal_sleep_ms / 1000) * 2)
1273+
1274+
reload_durations_ms = []
1275+
for postgrest in instances:
1276+
output_lines = []
1277+
for _ in range(instance_count * 2):
1278+
output_lines.extend(read_available_output_lines(postgrest))
1279+
if any(query_log_pattern.search(line) for line in output_lines):
1280+
break
1281+
time.sleep(0.2)
1282+
1283+
durations = []
1284+
for line in output_lines:
1285+
match = query_log_pattern.search(line)
1286+
if match:
1287+
durations.append(float(match.group(1)))
1288+
1289+
assert durations
1290+
reload_durations_ms.append(max(durations))
1291+
1292+
assert len(reload_durations_ms) == instance_count
1293+
1294+
# expected_concurrency instances should have
1295+
# reload_durations_ms <= lock_wait_threshold_ms
1296+
# the rest should wait
1297+
assert (
1298+
instance_count
1299+
- len(
1300+
[
1301+
duration
1302+
for duration in reload_durations_ms
1303+
if duration > lock_wait_threshold_ms
1304+
]
1305+
)
1306+
== expected_concurrency
1307+
)
1308+
1309+
12211310
def test_schema_cache_query_sleep_logs(defaultenv):
12221311
"""Schema cache sleep should be reflected in the logged query duration."""
12231312

@@ -1887,7 +1976,7 @@ def test_requests_with_resource_embedding_wait_for_schema_cache_reload(defaulten
18871976
env = {
18881977
**defaultenv,
18891978
"PGRST_DB_POOL": "2",
1890-
"PGRST_INTERNAL_SCHEMA_CACHE_RELATIONSHIP_LOAD_SLEEP": "5100",
1979+
"PGRST_INTERNAL_SCHEMA_CACHE_RELATIONSHIP_LOAD_SLEEP": "5200",
18911980
}
18921981

18931982
with run(env=env, wait_max_seconds=30) as postgrest:

0 commit comments

Comments
 (0)