Commit Graph
41 Commits
Author SHA1 Message Date
Taimoor Zaeemandsteve-chavez ae65768569 fix(admin): log admin server exceptions and close admin socket
Admin server was crashing silently and requests hang indefinitely.
With this fix, we are now logging the admin server exceptions and also
close the socket afterwards so admin request don't hang.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2026-06-29 13:13:16 -05:00
Michał KłeczekandTaimoor Zaeem 80ea1f4a1b refactor: make Observation Logger and Listener modules more cohesive
Observation module exports observationMessage and isDbListenerBug functions. The first one is used only in Logger module and the second one - only in Listener.

This change moves observationMessage function to Logger module and isDbListenerBug function to Listener module, making all three modules more cohesive and lessening dependencies.
It also gives the compiler more opportunities for intra-module inlining and optimization.
2026-05-07 00:36:36 +05:00
Laurence IslaandTaimoor Zaeem 0502488b70 fix: call pg_notification_queue_usage() automatically when the LISTEN channel bug is detected (#4858)
There's a PostgreSQL bug that doesn't let any listener to register in the DB:
https://www.postgresql.org/message-id/flat/CAK98qZ3wZLE-RZJN_Y%2BTFjiTRPPFPBwNBpBi5K5CU8hUHkzDpw%40mail.gmail.com
The only workaround is to advance the async notification queue tail,
which can be done by executing:  "SELECT pg_notification_queue_usage();".
Before we just logged a HINT with this suggestion, but now we call that function directly
and then let the listener to automatically recover.

No automated tests were added here as it would be too complex and this is a PostgreSQL bug. But this was manually tested following the steps on https://github.com/PostgREST/postgrest/pull/4581#issuecomment-3690610592
2026-05-04 22:08:06 +05:00
Michał KłeczekandTaimoor Zaeem df87ce46ed add: log pool flushes
Emit a dedicated PoolFlushed observation when the DB pool is released during schema cache reload.
2026-04-16 11:18:44 +05:00
steve-chavez fb31654277 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-10 18:16:19 -05:00
Michał KłeczekandSteve Chavez b9c8562641 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-04-06 11:11:16 -05:00
Michał KłeczekandSteve Chavez 34a767a5cc 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-04-06 11:11:16 -05:00
Laurence IslaandSteve Chavez 250747aadc add(logs): Include a HINT when the LISTEN channel breaks due to a Postgres bug
The HINT shows a SQL command that solves the issue.
2026-04-03 16:36:55 -05:00
Michal KleczekandSteve Chavez afb95a5268 refactor(test): provide means to validate metrics and observations
Some helpers are provided for introspecting metrics already (used in JWT cache tests). This change provides facilities to additionally validate emited Observation events.
A new Spec module is also implemented, adding basic tests of schema cache reloading - their main goal is to excercise the new infrastructure.
2026-04-02 13:34:38 -05:00
steve-chavez 1856434a74 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:38:40 -05:00
steve-chavez 94350fdde6 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
```

(cherry picked from commit e95e815483)
2026-02-12 20:11:44 -05:00
Michal Kleczekandsteve-chavez 16c767134c fix: listener running with exception masked after first failure 2026-01-29 13:22:46 -05:00
Michal KleczekandSteve Chavez 5796f86100 fix: ensure Listener connections are released
retryingListen function potentially leaks database connections. This patch ensures the connections are released in case of listen/notify errors.

(cherry picked from commit 00c7cb1a22)
2026-01-28 18:26:15 -05:00
steve-chavez 4d35eb02e7 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.

(cherry picked from commit 013f078bc4)
2025-12-18 18:18:09 -05: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
steve-chavez cddfb6cf5e fix: not logging OpenAPI queries
Closes https://github.com/PostgREST/postgrest/issues/4226.

This requires moving query generation to the top App.hs module.

At this point is also simple to log the transaction variables + the
pre-request function call but this is not done here to reduce scope.
2025-09-10 09:04:12 -05:00
Taimoor ZaeemandSteve Chavez 41b6ebea58 refactor: deduplicate host resolution logic and observations
Replaces the "API server listening on unix socket" with simpler
"API server listening on " observation. This allows refactoring
redundant code.

Signed-off-by: Taimoor Zaeem <taimoorzaeem@gmail.com>
2025-09-01 15:00:20 -05:00
Laurence Isla bf90f95443 fix: logging the Haskell type instead of the listener error message directly
Previously: Just "connection error..."
Now: connection error...
2025-08-22 19:27:38 +00:00
Michal KleczekandGitHub 77ff11de95 feat: JWT cache implementation based on sieve algorithm (#4084)
Changes:

1. Refactoring and some cleanup of JWT handling code:
* Instead of caching AuthResult cache decoded claims (which signature was verified). Validating claims and determining role is done after cache lookup
* Cleaned up API so that usage of it is simplified: lookupJwtCache cache key >>= parseClaims configJwtAud time
* Handling of JwtCacheState initialization and updates of configuration is encapsulated in Auth.JwtCache module

2. Generic high performance (hopefully) scalable, dynamically resizeable cache implementation based on stm, stm-hamt and sieve algorithm. It also integrates with PostgREST measurements infrastructure providing usage stats (ie. hit ratio, evictions count)
2025-07-29 18:51:41 -05:00
Taimoor ZaeemandGitHub ea9d4f49b2 fix: log db-schemas and db-extra-search-path in schema cache load error (#4108) 2025-05-30 10:13:19 -05:00
Taimoor ZaeemandGitHub c9a625ced6 feat: Log PoolRequest and PoolRequestFullfilled observations (#3925) 2025-02-28 12:01:10 -05:00
Laurence IslaandGitHub 9c880c082a feat: allow logging the SQL query to stderr
- Logs the main SQL query when `log-query=main-query`.
- Only logs at the current `log-level`.
2025-02-18 19:17:26 -05:00
steve-chavez 80a4edbd2d chore: add comments on the Observation module 2024-11-15 16:11:26 -05:00
steve-chavez 7e99babec7 feat: log pool maximum size
It's important for observability to have an historic trace of the pool
size. Currently we expose it on the metrics endpoint, but not all
deployments use it.

This logs the pool size after the successful connection log to make it
more visible:

<timestamp>: Connection Pool initialized with a maximum size of 4 connections
2024-10-02 22:47:22 -05:00
steve-chavez 87dddd66d2 fix: clarify "listening" logs
It's not immediately clear on which port the API server is listening.
Also it's not clear that the "pgrst" channel is for database
notifications.

Goes from:

<timestamp>: Admin server listening on 0.0.0.0:3001
<timestamp>: Listening on 0.0.0.0:3000
<timestamp>: Listening for notifications on the "pgrst" channel

To:

<timestamp>: Admin server listening on 0.0.0.0:3001
<timestamp>: API server listening on 0.0.0.0:3000
<timestamp>: Listening for database notifications on the "pgrst" channel
2024-10-02 22:47:22 -05:00
Andrei DziahelandGitHub 46537879ae feat: Add resolved host to "Listening on ..." messages (#3560)
This adds resolved host's IP to "Listening on ..." messages emitted when
app and admin servers start.
2024-08-01 11:31:35 -05:00
steve-chavez 6be59066df fix: schema cache retrying without backoff
Fixes https://github.com/PostgREST/postgrest/issues/3523.

Now if there's a failure when obtaining the pg version OR schema cache,
we do the same retrying process. This way we don't add two retries.

Refactors and renames the "connectionWorker" to "schemaCacheLoader".
This makes more sense since what we really want is the schema cache,
the version is the pre-requisite for ensuring our
schema cache queries work.

Additionally, we no longer log ` Attempting to connect to the database...`
at startup unnecessarily. This is only logged whenever there's a retry attempt.
2024-07-10 21:14:24 -05:00
steve-chavez 30ca64d849 docs: improve observability 2024-05-24 18:05:45 -05:00
Laurence IslaandGitHub aea563bd82 fix: remove verbosity from some error logs
Error logs starting with "An error occured..." are replaced with "Failed to..."
2024-05-21 16:44:28 -05:00
steve-chavez 3cf565614d fix: listener retries with exponential backoff
Also corrects the admin ready response which now considers the listener
state.
2024-05-19 20:48:59 -05:00
steve-chavez 756aad7827 fix: listener silent fail on replica
Update hasql-notifications to include the fix on
https://github.com/diogob/hasql-notifications/issues/24.

Which now reveals the following error:

```
$ postgrest-with-postgresql-16 --replica -f test/spec/fixtures/load.sql postgrest-run

17/May/2024:18:35:38 -0500: Successfully connected to PostgreSQL 16.2 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 13.2.0, 64-bit
17/May/2024:18:35:38 -0500: Could not listen for notifications on the "pgrst" channel. ERROR:  cannot execute LISTEN during recovery
17/May/2024:18:35:38 -0500: Retrying listening for notifications...
```

This is still not good because the LISTEN channel will be retried
forever without a backoff.
2024-05-18 23:33:04 -05:00
steve-chavez 33b6ba8199 refactor: move checkIsFatal logic to usePool
The fatal logic is now inside `usePool`. It centralizes the
logic which is better for Locality of Behavior.

Removes:

- The need to do checkIsFatal on other parts of the code
- SCFatalFail/ConnFatalFail states which are no longer needed.
2024-05-16 17:40:25 -05:00
steve-chavez 653c7955b2 feat: connection pool metrics in admin server 2024-04-23 19:08:37 -05:00
steve-chavez 1bf0c54dd6 feat: log connection pool events on log-level=info 2024-04-15 18:31:51 -05:00
steve-chavez 2de32fc108 refactor: observation handler to AppConfig
With this:

- Is no longer necessary to pass observer as an argument
  to every function that needs observations.
- We can invoke the observer on every function that uses AppConfig.
  However it'd be better to just call the observer in the upper modules
  (like on App.hs).
2024-04-12 14:29:39 -05:00
steve-chavez ee8b3ef8fe fix: log on LISTEN notification 2024-03-19 13:22:51 +03:30
steve-chavez 86e15dbb77 fix: upgrade hasql-notifications to show error 2024-03-13 11:14:11 -05:00
Steve ChavezandGitHub 00f5780415 fix: don't hide error on LISTEN channel failure (#3323) 2024-03-11 19:56:35 -05:00
steve-chavez 3a3601cbeb feat: log schema cache load time 2024-02-21 18:16:37 -05:00
Steve ChavezandGitHub 7c6c056e92 refactor: make observation messages pure (#3250)
removes the observation messages from the Logger
2024-02-20 18:42:38 -05:00
Steve ChavezandGitHub 6d506df6f3 refactor: add observation module (#3232) 2024-02-20 12:29:33 -05:00