Commit Graph
228 Commits
Author SHA1 Message Date
steve-chavez 70327cf869 test: negative pgrst_db_pool_available in metrics
Proves the failure on https://github.com/PostgREST/postgrest/issues/4622.

This doesn't require additional test infra, only nginx. Taking advantage
of the `stream {}` context which is also compatible with unix socket
besides TCP.
2026-05-17 12:58:58 -05:00
steve-chavez 02a1de2afe test: OPTIONS produce logs but not CORS preflight 2026-05-06 17:21:31 -05:00
steve-chavez 6b3ec5d9e0 test: empty db-anon-role lacks role in logs 2026-05-05 19:29:59 -05:00
steve-chavez 6804ce3cbe test: empty schema cache error has role in logs 2026-05-05 19:29:59 -05:00
steve-chavez 42e53e84e1 test: invalid rpc call contains role in logs 2026-05-05 19:29:59 -05:00
steve-chavez 8105375b64 test: expired JWT shows empty role in logs 2026-05-05 19:29:59 -05:00
Michał KłeczekandWolfgang Walther 85d91e5c0a add: Publish GHC runtime metrics to Prometheus metrics endpoint 2026-05-03 11:41:02 +00:00
Michal KleczekandGitHub 04a0e041e4 fix: Restore showing LISTEN pgrst in pg_stat_activity 2026-04-30 17:21:12 -05:00
Laurence Isla 41b86fffa5 fix: no longer retries the transaction on 40001 errors 2026-04-27 14:30:10 -05:00
Taimoor ZaeemandWolfgang Walther bf758698b3 fix: login with uppercase and mixed case role names
PostgREST failed when querying role settings where current
role name contained uppercase letters. This commit resolves
it by quoting the CURRENT_USER.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2026-04-27 09:19:26 +00:00
Michał KłeczekandSteve Chavez baebacf3db fix: shutdown should wait for in flight requests
Upgraded warp to 3.4.13 which fixed https://github.com/yesodweb/wai/issues/853
Changed interrupt handling so that instead of killing the main thread, listening sockets are closed which triggers warp graceful shutdown.
2026-04-20 16:19:13 -05:00
Wolfgang Walther 051b4799de chore(deps): update nixpkgs to latest nixpkgs-unstable
This allows building TemplateHaskell with GHC 9.6+ via iserv-proxy.
2026-04-19 13:16:55 +00:00
steve-chavez bcc8998e5e add: log schema cache queries' timings
This adds a new log line that shows each schema cache query time individually, only on
`log-level=debug`. Like so:

```
$ PGRST_LOG_LEVEL=debug postgrest-with-pg-17 -f test/spec/fixtures/load.sql postgrest-run

....
10/Apr/2026:21:48:45 -0500: Schema cache queried in 192.2 milliseconds
10/Apr/2026:21:48:45 -0500: tables: 72.027 ms, keydeps: 20.118 ms, rels: 6.189 ms, funcs: 35.010 ms, comprels: 4.319 ms, dreps: 1.614 ms, mhandlers: 7.419 ms, tzones: 43.025 ms
```

This helps debug specific schema cache queries being slow like on
https://github.com/PostgREST/postgrest/issues/4613#issuecomment-4210191065 and
https://github.com/PostgREST/postgrest/issues/3046#issuecomment-3469059948.
It also closes https://github.com/PostgREST/postgrest/issues/3215,
which main motivation was to find out which query is slow.

Implementation details
---------------------

To time each query inside a transaction in pure SQL, we do:

```sql
-- start timer
select set_config('pgrst.tmp_x', clock_timestamp()::text, false);
-- run the query
select <query>
-- end timer
select set_config('pgrst.tmp_x', (clock_timestamp() - current_setting('pgrst.tmp_x', false)::timestamptz)::text, false);

-- .... repeated for every query

-- at the end we capture all the timings with
select extract('milliseconds' from current_setting('pgrst.tmp_x', false)::interval), extract(..;
```

Considerations
--------------

Only added this on `log-level=debug` because while the queries are fast
and the data is valuable, it triples the amount of queries we run during schema cache refresh,
which could be troublesome on slow networks. It's possible to reduce the
amount of queries by starting and stopping timers in one statement, but
this would still double the amount of queries and makes the code messy,
doesn't seem worth it.

Also it would pollute pg_stat_statements, it's only required to debug certain
extreme cases anyway.
2026-04-16 13:10:24 -05:00
Michal KleczekandGitHub aca58c8571 fix: Flush pool as late as possible during schema cache reloading (#4645)
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).
2026-04-14 17:09:25 -05:00
steve-chavez 2fb2e86473 fix: remove red herring warp logs on default log-level
The logs added on e95e815483 are red
herrings under normal operation.

This moves them to `log-level=debug` and removes "error" from the
message prefix.

Fixes https://github.com/PostgREST/postgrest/issues/4799
2026-04-09 16:44:25 -05:00
Michał KłeczekandSteve Chavez c31aeecdcf test: add test_pool_acquisition_timeout_logs_are_debounced to io tests 2026-04-09 13:59:17 -05:00
Michał KłeczekandSteve Chavez ad907219be test(refactor): make debug output testing more robust
This change introduces a match_log function, that implements lenient matching of log output lines. Tests of log output are retrofited to use the function.
2026-04-09 10:41:29 -05:00
Taimoor ZaeemandSteve Chavez d6c338d588 add: config db-timezone-enabled for optional querying of timezones
To avoid repeated querying of `pg_timezone_names` every time schema
cache is reset, `Prefer: timezone` can be disabled by setting
`db-timezone-enabled = false`.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2026-04-01 12:48:38 -05:00
Michał KłeczekandSteve Chavez bd5de884fa test(io): add test_so_reuseport_zero_downtime_handover 2026-03-31 13:33:33 -05:00
Taimoor ZaeemandSteve Chavez 135b77d12b test(io): rename jwt-role-claim-key*.config dump files
These files were added to cover the config dumping of
string comparison operators in `JSPath`. Renaming and
adding a comment in these to make it clear.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2026-03-24 11:11:43 -05:00
steve-chavez 622c6d3f19 fix: not logging termination unix signals
Under container environments like ECS, it's hard to know when PostgREST
is being terminated.
2026-03-20 13:09:10 -05:00
Andrei DziahelandSteve Chavez 1f54e2accc add: add "Vary" header to responses
Co-authored-by: Steve Chavez <stevechavezast@gmail.com>
2026-03-16 09:55:20 -05:00
Michał KłeczekandSteve Chavez bee2ea6fa6 test(io): add test_graceful_shutdown_waits_for_in_flight_request 2026-03-12 15:24:46 -05:00
Taimoor ZaeemandSteve Chavez 5abacba0d8 fix(error): leaking table and function names when calculating hint
Increase similarity score to 0.75 from 0.33 for table and functions
error hint.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2026-03-06 16:03:21 -05:00
Michał KłeczekandSteve Chavez 2408cd332d refactor: get rid of redundant SchemaCacheSummaryObs
There is unnecessary coupling between observation messages and emited log entries. This causes schema loading logic to emit redundant events: SchemaCacheSummaryObs and SchemaCacheLoadedObs.

Logically - we want to emit a single event containing both summary and timing information. How it is logged is a different matter and should be decoupled.

This commit
* changes observationMessage function returning Text to observationMessages returning [Text] so that it is possible to return multiple (or zero) messages to log based on an observation event
* Removes SchemaCacheSummaryObs constructor from Observation type and adds summary text to SchemaCacheLoadedObs
2026-03-02 14:45:31 -05:00
Taimoor ZaeemandSteve Chavez 83dc082acf add: config client-error-verbosity to set error verbosity
Set error verbosity using this config. The verbosity can
be set to `verbose` or `minimal` for client error responses.

This only affects client side HTTP responses, server side logs
are not affected by this config.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2026-02-25 15:24:27 -05:00
Taimoor ZaeemandWolfgang Walther b977ffbb90 test(io): reset statement_timeout of anon role to correct value
Forgot to do this in bfb4f900e7.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2026-02-18 12:46:30 +00:00
Taimoor ZaeemandSteve Chavez bfb4f900e7 test(io): increase statement_timeout value of anonymous role
It is too low which leaves a small window of values to
use when testing other features.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2026-02-17 11:35:12 -05:00
steve-chavez e95e815483 fix: don't hide async exceptions in logs
Fixes #4646. Using the repro on #4646, this now produces the log:

```
11/Feb/2026:09:40:08 -0500: Warp server error: stack overflow
```

When:
```
$ curl localhost:3000/
curl: (52) Empty reply from server
```
2026-02-12 19:43:50 -05:00
Taimoor ZaeemandSteve Chavez aaaf7e96bd test(io): set client_min_messages to warning in SQL fixtures
To suppress unwanted "NOTICE: ..." messages which pollute the log.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2026-02-04 09:20:03 -05:00
Taimoor ZaeemandSteve Chavez 37fc0a211b test(io): refactor SQL fixtures
- Move privileges and grants to privileges.sql
- Move schema, tables and functions to schema.sql
- Move global database settings to database.sql

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2026-02-04 09:20:03 -05:00
Taimoor ZaeemandSteve Chavez c35eb7a6c2 test(io): move role fixtures to roles.sql
Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2026-02-02 17:38:32 -05:00
Michał KłeczekandSteve Chavez 21b8c3458a add: Log pg version details of listener connection
Follow-up to #4617 adding more information to log entry produced upon successful listener connection establishement.
2026-01-27 15:44:05 -05:00
Michał KłeczekandSteve Chavez 5356f4e973 add: Log actual host and port of listener connection
Diagnosing problems with listener channel notifications not being handled properly by PostgREST connected to read replicas is difficult. Issues might be related to lost connections and listener not being connected to the right host after failover or database server restarts.
This patch adds logging of actual host:port used by libpq connection opened by the listener. It should make it easier to find out if PostgREST is connected to the right host.
2026-01-27 11:00:30 -05:00
Taimoor ZaeemandGitHub fe0386e9c4 add: string slicing operator for jwt-role-claim-key (#4603) 2026-01-24 05:40:21 -05:00
Michał KłeczekandSteve Chavez 886df84e87 test: Fix flakiness of test_second_request_for_non_existent_table_should_be_quick
Changed divider in assertion (response.elapsed.total_seconds() < first_duration / divider) to 2 (from 10).
2026-01-13 11:37:50 +07:00
Michał KłeczekandSteve Chavez e592d568c6 fix: Performance and high memory usage of relation hint calculation
* Calculation of hint message when requested relation is not present in schema cache requires creation of a FuzzySet (to use fuzzy search to find candidate tables). For schemas with many tables it is costly.
This patch introduces dbTablesFuzzyIndex in SchemaCache to memoize the FuzzySet creation.

* Additionally, because of FuzzySet large memory requirements, this patch introduces a limit of 500 relations per schema, above which FuzzySet is not created and hint calculation disabled.
2026-01-03 07:56:12 +08:00
steve-chavez 013f078bc4 fix: inaccurate Server-Timing durations
The transaction duration was notably off, doing:

```
curl localhost:3000/rpc/sleep?seconds=5 -i
```

Shows `46.1` for the `transaction;dur`, with this fix we obtain
`5007.3`.

Fixes https://github.com/PostgREST/postgrest/issues/4522

This also fixes inaccurate "schema cache queried" logs,
see https://github.com/PostgREST/postgrest/issues/4551.
2025-12-18 17:35:18 -05:00
Taimoor ZaeemandSteve Chavez abad47ff1b add: log error when db-schemas config contain restricted schemas
We don't allow accessing schemas "pg_catalog" and "information_schema".
Instead of silently failing requests on these schemas, this now adds
logging an error on startup when these schemas are found in `db-schemas`
config.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2025-12-11 14:28:08 -05:00
Taimoor ZaeemandSteve Chavez 50eec773bf test(io): fix freeport function to prevent failures
Sometimes, a healthcheck related test fails as occurred in
https://github.com/PostgREST/postgrest/actions/runs/19771357953/job/56655949002.
This happens due to freeport function accidently picking up a used port.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2025-11-29 18:17:00 -05:00
Taimoor ZaeemandSteve Chavez 35de13eebd test(io): move fixtures to fixtures/ directory
Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2025-11-27 17:08:03 -05:00
Taimoor ZaeemandSteve Chavez c561a3749c test(io): move authentication related tests to test_auth.py
The `test_io.py` module is too bloated (2100+ lines). To
logically group related tests, as a first step, this commit
separates authentication related IO tests into `test_auth.py`
module.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2025-11-21 13:21:15 -05:00
Taimoor ZaeemandSteve Chavez 379eaec8e0 test(io): remove stale jwt cache test
Removes a test related to jwt cache which is stale
since #4084.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2025-11-19 11:17:18 -05:00
Taimoor ZaeemandWolfgang Walther 462798dc2d nix: shorten postgrest-with-postgresql-xx scripts
Renames these scripts to `postgrest-with-pg-xx`. The renaming
helps reduce the length of temporary filenames. This is needed
to ensure that socket file names remain under the maximum
allowed length of 107 chars.

Closes #4461.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2025-11-18 09:40:16 +00:00
Taimoor ZaeemandSteve Chavez 91abcd49e1 test(io): move resource embedding tests to test_io.py
- Adds fixtures to `test/io/fixtures.sql` to test resource
  embedding related queries.

- Moves the resource embedding related tests that no longer
  require big schema from `test_big_schema.py` to `test_io.py`.

Closes #4417.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2025-11-11 13:43:10 -05:00
Taimoor ZaeemandSteve Chavez 58efc2680e fix: server-host !6 incorrectly binds to IPv4 address
Updates streaming-commons to version 0.2.3.1. This resolves #3202.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2025-11-02 12:24:14 -05:00
Taimoor ZaeemandSteve Chavez a688878236 fix: db-pre-config function failing with pg reserved words
When db-pre-config is accidentally set to a pg reserved word
like "true", it fails with a confusing error. The function
names should be properly quoted to avoid such errors. This commit
resolves this by quoting the pre-config function name.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2025-10-29 16:54:24 -05:00
steve-chavez 0f7ac1bc39 test: schema cache load max duration
Test to ensure no regression happens after https://github.com/PostgREST/postgrest/pull/4396
2025-10-21 14:10:14 -05:00
Laurence Isla ea5db2a09a 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.
2025-10-20 18:42:56 +00:00
Laurence Isla c88ddfe18d fix: not logging the JSON message on a PGRST002 error
It happens right after the configuration is loaded and before
the schema cache is queried.
2025-10-20 18:42:56 +00:00