fix: reloading the Schema Cache unnecessarily on a PGRST002 error

When 503 errors happen if the Schema Cache is empty,
it should not retrigger the connection worker since
there's no Schema Cache loaded yet.

Author: laurenceisla

CHANGELOG.md

@@ -12,6 +12,7 @@ This project adheres to [Semantic Versioning](http://semver.org/).
 - Fix not logging transaction variables and db-pre-request function when `log-query=main-query` is enabled by @steve-chavez in #3934
 - Fix loading utf-8 config files with `ASCII` locale set in #4386
 - Fix not logging the JSON message to stderr on a `PGRST002` error by @laurenceisla in #4129
+- Fix reloading the Schema Cache unnecessarily on a `PGRST002` error by @laurenceisla in #4367
 
 ### Added
 

src/PostgREST/App.hs

@@ -109,10 +109,14 @@ postgrest logLevel appState connWorker =
             runExceptT $ postgrestResponse appState appConf maybeSchemaCache authResult req
 
         response <- either Error.errorResponseFor identity <$> eitherResponse
-        -- Launch the connWorker when the connection is down.  The postgrest
+        -- Launch the connWorker when the connection is down. The postgrest
         -- function can respond successfully (with a stale schema cache) before
-        -- the connWorker is done.
-        when (isServiceUnavailable response) connWorker
+        -- the connWorker is done. However, when there's an empty schema cache
+        -- postgrest responds with the error `PGRST002`; this means that the schema
+        -- cache is still loading, so we don't launch the connWorker here because
+        -- it would duplicate the loading process, e.g. https://github.com/PostgREST/postgrest/issues/3704
+        -- TODO: this process may be unnecessary when the Listener is enabled. Revisit once https://github.com/PostgREST/postgrest/issues/1766 is done
+        when (isServiceUnavailable response && isJust maybeSchemaCache) connWorker
         resp <- do
           delay <- AppState.getNextDelay appState
           return $ addRetryHint delay response

test/io/test_io.py

@@ -1892,6 +1892,28 @@ def test_log_error_when_empty_schema_cache_on_startup_to_stderr(defaultenv):
         assert any(log_err_message in line for line in output_start)
 
 
+def test_no_double_schema_cache_reload_on_empty_schema(defaultenv):
+    "Should only load the schema cache once on a 503 error when there's an empty schema cache on startup"
+
+    env = {
+        **defaultenv,
+        "PGRST_INTERNAL_SCHEMA_CACHE_QUERY_SLEEP": "300",
+    }
+
+    with run(env=env, port=freeport(), wait_for_readiness=False) as postgrest:
+        postgrest.wait_until_scache_starts_loading()
+
+        response = postgrest.session.get("/projects")
+        assert response.status_code == 503
+
+        # Should wait enough time to load the schema cache twice to guarantee that the test is valid
+        time.sleep(1)
+
+        response = postgrest.admin.get("/metrics")
+        assert response.status_code == 200
+        assert 'pgrst_schema_cache_loads_total{status="SUCCESS"} 1.0' in response.text
+
+
 @pytest.mark.parametrize("level", ["crit", "error", "warn", "info", "debug"])
 def test_log_pool_req_observation(level, defaultenv):
     "PostgREST should log PoolRequest and PoolRequestFullfilled observation when log-level=debug"