{"id":"IL-0313","org":"Decagon","date":"2026-08-05","docs":[],"title":{"en":"Decagon voice requests stalled for exactly 300 seconds behind self-managed PgBouncer and exhausted the SQLAlchemy pool","ko":"자체 운영 PgBouncer 로 옮기는 운영 카나리에서 일부 요청이 정확히 300초 멈추고 SQLAlchemy 커넥션 풀이 고갈됐다"},"domain":["database","gcp"],"impact":{"scope":"During the production canary, a small number of voice requests stalled mid-conversation for 300 seconds, and unrelated requests sharing the same connection pool failed with pool exhaustion","users":"unknown","region":"unknown"},"review":{"written_by":"session","reviewed_at":null,"reviewed_by":null},"lessons":{"en":"Decagon's lesson is that an infrastructure migration does not only change one's own systems but can also expose latent bugs elsewhere in the stack: the move to self-managed PgBouncer supplied the last condition for a long-standing edge case involving SQLAlchemy, PgBouncer, OpenSSL and the PostgreSQL wire protocol.","ko":"인프라 마이그레이션은 자기 시스템만 바꾸는 것이 아니라 스택의 다른 곳에 숨어 있던 버그를 드러낼 수 있다. 이번에는 자체 운영 PgBouncer 로 옮긴 일이 SQLAlchemy, PgBouncer, OpenSSL, PostgreSQL wire protocol 이 얽힌 오래된 예외 상황이 드러날 마지막 조건을 만들었다. 버그는 응답이 정확히 그 모양일 때는 늘 재현됐지만, 그런 응답 자체가 드물어 스테이징에서 나타나지 않았다."},"related":[],"sources":[{"url":"https://decagon.ai/blog/debugging-a-latent-pgbouncer-bug-across-four-layers","kind":"blog","archived":"https://web.archive.org/web/20261012211715/https://decagon.ai/blog/debugging-a-latent-pgbouncer-bug-across-four-layers"}],"summary":{"en":"Decagon sets the PostgreSQL application name to the current request path, and whenever the value changes Postgres sends it back to the client in a ParameterStatus packet. The stall needed three conditions: an application name longer than 41 bytes, which makes the ParameterStatus packet larger than 64 bytes; a query response of a size that makes that packet cross PgBouncer's 4096-byte read buffer; and both parts of the split packet in the same TLS record between Postgres and PgBouncer. The first two had existed for some time, and the migration to self-managed PgBouncer added the third. Because GCP's managed pooler also uses PgBouncer and the data path stayed the same, Decagon had expected a simple migration, and staging seemed to confirm it.\n\nPgBouncer's read loop waits for epoll() to report a readable socket, copies the data into its read buffer and parses PostgreSQL messages. With TLS, SSL_read() drains a whole TLS record from the kernel socket into OpenSSL's buffer and returns only as many plaintext bytes as requested, keeping the rest inside OpenSSL. In one reproduction Postgres sent a single 4,118-byte TLS record, PgBouncer read 4,096 bytes, and an 86-byte ParameterStatus packet crossed the boundary: PgBouncer saw 70 bytes, decided it needed more data and went back to epoll() without checking SSL_pending(), while the remaining 16 bytes sat in OpenSSL and nothing woke the connection. The query stayed blocked in cursor.execute() until Postgres killed the session after 300 seconds, so its connection stayed checked out of SQLAlchemy's process-level QueuePool. A few such connections shrank the pool, and unrelated requests sharing it failed with pool exhaustion.\n\nDecagon shortened the application name so the ParameterStatus packet stayed below PgBouncer's small-packet parsing threshold, which removed one condition and let the migration continue. Upstream, Decagon merged a small fix to PgBouncer's event loop that checks SSL_pending() before sleeping and keeps reading when OpenSSL already holds plaintext.","ko":"Decagon 은 GCP 의 관리형 커넥션 풀러도 PgBouncer 를 쓰므로 자체 운영 PgBouncer 로 옮기는 일이 간단할 것으로 보았고, 스테이징에서도 문제가 없어 보였다. 그런데 첫 운영 카나리에서 일부 음성 요청이 대화 도중 멈췄다가 정확히 300초 뒤 타임아웃됐고, 다른 요청은 SQLAlchemy 커넥션 풀 고갈로 실패했다. Postgres 쿼리 지연은 p95 1~3밀리초였고 PgBouncer 의 maxwait 는 0이었다. 타임라인을 맞춰 보니 Postgres 가 밀리초 안에 끝낸 쿼리를 애플리케이션이 300초 동안 기다리고 있었다. 팀은 응답 하나를 SQLAlchemy 의 QueuePool, PgBouncer 의 패킷 파서와 이벤트 루프, OpenSSL 의 TLS 레코드 버퍼, 리눅스 커널의 epoll() 네 계층에 걸쳐 따라갔다.\n\nDecagon 은 PostgreSQL 의 application name 값에 현재 요청 경로를 넣어 데이터베이스 작업을 엔드포인트별로 구분해 왔다. 이 값이 바뀔 때마다 Postgres 는 새 값을 ParameterStatus 패킷으로 클라이언트에 보낸다. 멈춤은 세 조건이 겹칠 때 났다. application name 이 41바이트보다 길어 ParameterStatus 패킷이 64바이트를 넘었고, 쿼리 응답의 크기가 좁은 범위에 들어 이 패킷이 PgBouncer 의 4096바이트 읽기 버퍼 경계에 걸쳤으며, 나뉜 패킷 두 부분이 Postgres 와 PgBouncer 사이의 같은 TLS 레코드에 실렸다. 앞의 두 조건은 전부터 있었고, 관리형 풀러에서 옮기며 바뀐 TLS 경로가 세 번째 조건을 만들었다.\n\nSSL_read() 는 TLS 레코드 하나를 커널 소켓에서 통째로 꺼내 OpenSSL 내부 버퍼에 두고, 호출한 쪽이 덜 읽으면 나머지 평문을 그 버퍼에 남긴다. 재현 사례 하나에서 Postgres 는 4,118바이트 TLS 레코드 하나를 보냈고, PgBouncer 는 평소대로 4,096바이트를 읽었으며, 86바이트 ParameterStatus 패킷이 버퍼 경계에 걸쳐 앞의 70바이트만 보였다. PgBouncer 는 데이터가 더 필요하다고 보고 SSL_pending() 을 확인하지 않은 채 epoll() 대기로 돌아갔다. 나머지 16바이트는 이미 OpenSSL 안에 있었으므로, 이 연결을 깨울 커널 이벤트는 오지 않았다. 멈춘 쿼리는 cursor.execute() 안에서 막혀 연결을 QueuePool 에 반환하지 못했고, Postgres 가 300초 뒤 세션을 끊을 때까지 연결을 잡고 있었다. 이렇게 묶인 연결 몇 개만으로 풀의 실제 크기가 줄었다. 같은 프로세스의 QueuePool 을 쓰는 상관없는 요청들은 줄을 서다 풀 고갈로 실패했다. 문제를 일으킨 요청과 피해를 본 요청은 대개 달랐다.\n\nDecagon 은 애플리케이션에서 application name 값을 줄여 ParameterStatus 패킷이 PgBouncer 의 작은 패킷 파싱 기준 아래에 머물게 했다. 세 조건 중 하나가 없어져 마이그레이션을 계속할 수 있었다. 이어서 PgBouncer 업스트림에 수정을 머지했다. 이 수정은 대기에 들어가기 전에 SSL_pending() 을 확인하고, OpenSSL 에 평문이 이미 있으면 계속 읽게 한다. 이 수정으로 패킷 크기나 응답 모양과 상관없이 교착이 없어진다."},"trigger":{"en":"The move from GCP's managed connection pooler to self-managed PgBouncer enabled a different TLS path between PgBouncer and Postgres, which supplied the last of three conditions needed to expose the bug.","ko":"Decagon 이 GCP 의 관리형 커넥션 풀러에서 자체 운영 PgBouncer 로 옮기면서 PgBouncer 와 Postgres 사이의 TLS 경로가 바뀌었다. 첫 운영 카나리에서 이 바뀐 경로 때문에, PgBouncer 에 숨어 있던 버그가 드러날 마지막 조건이 갖춰졌다."},"severity":"unknown","symptoms":["intermittent-timeouts","connection-pool-exhausted"],"timeline":{"detected_after":null,"resolved_after":null},"date_kind":"published","detection":{"en":"Sentry errors (\"SSL connection has been closed unexpectedly\") and SQLAlchemy connection-pool timeouts during the production canary, followed by a comparison of application spans with Postgres query timings.","ko":"운영 카나리 중 일부 음성 요청이 대화 도중 멈추고 정확히 300초 뒤 타임아웃됐다. Sentry 에 \"SSL connection has been closed unexpectedly\" 오류가 몇 건 찍혔고, 다른 요청은 SQLAlchemy 커넥션 풀 고갈로 실패했다."},"components":["database","database-proxy"],"root_cause":"software-bug","remediation":[{"text":{"en":"Shortened the application name parameter so the ParameterStatus packet stayed below PgBouncer's small-packet parsing threshold","ko":"애플리케이션에서 application name 값을 줄여 ParameterStatus 패킷이 PgBouncer 의 작은 패킷 파싱 기준 아래에 머물게 했고, 버그의 세 조건 중 하나를 없애 마이그레이션을 계속했다."}}],"action_items":[{"text":{"en":"Fix PgBouncer upstream so it checks SSL_pending() before going back to wait on epoll()","ko":"PgBouncer 업스트림에 이벤트 루프 버그의 수정을 머지했다. epoll() 대기로 돌아가기 전에 SSL_pending() 을 확인하고, OpenSSL 에 복호화된 바이트가 남아 있으면 계속 읽는다."}}],"contributing":["staging-not-representative","assumption-unverified"],"recurrence_of":null,"symptoms_text":{"en":"During the first production canary of Decagon's move from GCP's managed connection pooler to self-managed PgBouncer, a small number of voice requests stalled mid-conversation and timed out after exactly 300 seconds. Other requests failed much earlier because the SQLAlchemy connection pool was exhausted.\n\nSentry showed a handful of \"SSL connection has been closed unexpectedly\" errors, and the pool failures read \"sqlalchemy.exc.TimeoutError: QueuePool limit of size 2 overflow 20 reached, connection timed out, timeout 30.00\". The SSL errors appeared only after PostgreSQL's idle-in-transaction session timeout ended the stalled sessions, so they looked like isolated connection failures with no link to the pool errors.\n\nThe pool error suggested the application had simply run out of database connections, but the other signals did not fit a capacity problem: Postgres query latency stayed at 1–3 milliseconds at p95, and PgBouncer's maxwait, the time clients wait for a server connection, stayed at zero. Comparing timelines showed that Postgres finished the affected queries in milliseconds while the application spans stayed open for exactly 300 seconds before returning the expected rows. The stalled queries kept their connections checked out of the QueuePool, and other requests timed out after 30 seconds waiting for those connections.\n\nThe stall was rare. Only two backend endpoints set an application name long enough to cause it, and only a small share of their query responses had the size that exposed the bug, so it never showed in staging.","ko":"GCP 의 관리형 커넥션 풀러에서 자체 운영 PgBouncer 로 옮기는 첫 운영 카나리에서, 일부 음성 요청이 대화 도중 멈췄다가 정확히 300초 뒤 타임아웃됐다. 다른 요청은 그보다 훨씬 일찍 SQLAlchemy 커넥션 풀 고갈로 실패했다.\n\nSentry 에는 \"SSL connection has been closed unexpectedly\" 오류가 몇 건 찍혔다. 이 오류는 PostgreSQL 의 idle-in-transaction 세션 타임아웃이 멈춘 세션을 끊은 뒤에야 나왔기 때문에, 따로 떨어진 연결 실패처럼 보였다.\n\n풀 고갈로 실패한 요청에서는 다음 오류가 나왔다.\nsqlalchemy.exc.TimeoutError: QueuePool limit of size 2 overflow 20 reached, connection timed out, timeout 30.00\n\n처음에는 애플리케이션의 데이터베이스 연결이 모자란 것처럼 보였지만 다른 신호는 용량 문제와 맞지 않았다. Postgres 쿼리 지연은 p95 로 1~3밀리초였고, 클라이언트가 서버 연결을 기다린 시간인 PgBouncer 의 maxwait 는 0이었다.\n\n애플리케이션과 데이터베이스의 타임라인을 맞춰 보니 Postgres 는 해당 쿼리를 밀리초 안에 끝냈는데, 애플리케이션의 스팬은 정확히 300초 동안 열려 있다가 기대한 행을 받았다. 문제의 스택 트레이스는 모두 애플리케이션의 데이터베이스 호출을 가리켰다. 300초 동안 멈춘 요청이 QueuePool 의 연결을 잡고 있는 사이, 다른 요청이 그 연결을 빌리려고 기다리다 30초 뒤 타임아웃된 것이었다.\n\n스테이징에서는 이 문제가 나타나지 않았다. 버그 조건에 맞을 만큼 긴 application name 값을 만드는 엔드포인트가 백엔드 API 에 둘뿐이었고, 그 엔드포인트에서도 버퍼 경계에 걸리는 쿼리 응답은 아주 드물었다."},"updated_at":"2026-11-14T12:33:56.695665Z","url":"https://benchlet.com/incidentlib/app/cases/IL-0313","org_slug":"decagon"}