#1164

Transaction mode: backend killed by FATAL 08P01 invalid frontend message type 109, then handed to an unrelated client

Opencrimbleopened 2mo ago

What happens

In transaction mode, a Postgres backend behind the pooler dies with a frontend protocol violation. Because the backend is multiplexed, the client holding it at that moment has done nothing wrong and sees its socket close mid-write.

The sequence is identical on every reproduction:

  1. Postgres: FATAL 08P01 invalid frontend message type 109
  2. Supavisor: DbHandler: Session terminated by server while checked out by a client
  3. The application, 94 to 97 ms later: write CONNECTION_CLOSED <region>.pooler.supabase.com:6543
  4. Later in the same window, on a different session: Supavisor ClientHandler: (ECLIENTSOCKETCLOSED) Client socket closed while state was busy (proxy) against Postgres incomplete message from client, the same 08P01 class

Message type 109 is ASCII m, which the frontend protocol has no message type for. That reads as a truncated or interleaved message reaching the backend rather than as anything either end sent deliberately.

It happens on roughly one end-to-end test run in three, over five days.

Environment

  • Supavisor in transaction mode, port 6543, region eu-west-2, default_pool_size and max_client_conn at platform defaults
  • Client: postgres.js 3.4.9 on Node v22.22.2, max: 10, idle_timeout: 20, prepare: false
  • Project ref withheld here deliberately. Happy to send it, and the three affected session IDs, to anyone at Supabase who wants them.

Three reproductions

#Window (UTC)Postgres FATALSupavisorClient error
12026-08-26 18:20 to 18:2418:24:15.07018:24:15.091 (twice)18:24:15.165
22026-08-26 22:06 to 22:1122:10:25.59922:10:25.62122:10:25.696
32026-08-26 22:2322:23:47.167same window+94 ms

All three are in that project's postgres_logs and supavisor_logs.

What we have ruled out, by measurement rather than by argument

We spent five days on this and every timing-based explanation we had turned out to be a coincidence of two log lines. What survives:

  • Our client does not truncate a message at the JavaScript layer. We instrumented net.Socket.writableLength at destroy time for every socket to port 6543, which is bytes accepted from the application and not yet handed to the kernel. On two separate failing runs, each with four write CONNECTION_CLOSED, no socket was destroyed with bytes still buffered. The instrument prints an arming line at startup, so the zero is a reading rather than silence.
  • Nothing on our side holds a connection. Our one place that holds a transaction across an await is bounded at 30 s and logs when it fires; it did not fire on a failing run. The role carries idle_in_transaction_session_timeout=60s.
  • idle_timeout is not involved. We turned it off on a branch and reproduced the identical FATAL. On that run the connection that died had been open 2 m 31 s with nothing on our side closing anything, which also rules out the pooler closing an idle client connection on its own clock.
  • Not exhaustion. About 13 connections of a 60 cap, zero idle in transaction at rest.
  • Not the ordinary 42501 refusal that sometimes precedes it. On one run the refusal and the FATAL were on the same session; on the next they were on different sessions, and the gap was 5.6 s once and 15.2 s the next time.

The question

Can Supavisor in transaction mode interleave or truncate a frontend message when handing a backend between clients?

We are happy to reproduce on demand, add any client-side instrumentation you suggest, or hand over the project ref and session IDs privately.

Activity

1
crimble2mo ago

Filed #1172, which may be the same fault seen from closer in. Same pooler, same Session terminated by server while checked out by a client line, but the observable there is a backend returned to the pool with a transaction still open and the reply never relayed (25P03) rather than the 08P01 crash reported here. It carries a self-contained reproduction that does not need our stack, pg_stat_activity read while wedged, and an instrumented postgres.js showing the reply never arrives.

Whether the two are one fault is not established.