Postgres connection failures

Hi,

I’m developing an application using Postgres and when doing a transaction with a bunch of INSERT statements, the connection to the server (on localhost) often suddenly dies. Trying to diagnose the problem, I’ve increased log levels and I’ve run a tcpdump session to find out what’s going on, can someone spot something strange or point me in a direction to continue debugging?

The symptom I notice is that the Postgres server (9.1 from Ubuntu repo) closes the connection, sometimes by sending a TCP FIN, sometimes by sending a TCP RST, but I’m not sure why this happens. The (node.js / node-postgres-pure) client doesn’t report any error message that could have been received from the server; it only complains that the connection unexpectedly closed during query execution.

Log message around the time the connections stops. I’ve looked up some lines in the code on GitHub, but I can’t figure out what’s going on yet. Queries are large, but that doesn’t seem to be a problem, as a lot of those have been added before.

2014-04-04 15:16:33 CEST DEBUG: 00000: parse <unnamed>: INSERT INTO xx (xx
xx, xx, xx, xx, xx) VALUES ($1, $2, $3, $4, $5), ($1, $2, $6, $7,
$8), ($1, $2, $9, $10, $11), ($1, $2, $12, $13, $14), ($1, $2, $15, $16, $17),
($1, $2, $18, $19, $20), ($1, $2, $21, $22, $23), ($1, $2, $24, $25, $26), ($1,
(… cut …)
2014-04-04 15:16:33 CEST LOCATION: exec_parse_message, postgres.c:1146
2014-04-04 15:16:33 CEST DEBUG: 00000: StartTransactionCommand
2014-04-04 15:16:33 CEST LOCATION: start_xact_command, postgres.c:2426
2014-04-04 15:16:33 CEST DEBUG: 00000: bind <unnamed> to <unnamed>
2014-04-04 15:16:33 CEST LOCATION: exec_bind_message, postgres.c:1429
2014-04-04 15:16:33 CEST DEBUG: 00000: ProcessQuery
2014-04-04 15:16:33 CEST LOCATION: ProcessQuery, pquery.c:170
2014-04-04 15:16:34 CEST DEBUG: 00000: shmem_exit(0): 7 callbacks to make
2014-04-04 15:16:34 CEST LOCATION: shmem_exit, ipc.c:211
2014-04-04 15:16:34 CEST DEBUG: 00000: proc_exit(0): 4 callbacks to make
2014-04-04 15:16:34 CEST LOCATION: proc_exit_prepare, ipc.c:183
2014-04-04 15:16:34 CEST LOG: 00000: disconnection: session time: 0:01:04.287 u
ser=postgres database=dev host=127.0.0.1 port=57848
2014-04-04 15:16:34 CEST LOCATION: log_disconnections, postgres.c:4375
2014-04-04 15:16:34 CEST DEBUG: 00000: exit(0)
2014-04-04 15:16:34 CEST LOCATION: proc_exit, ipc.c:135
2014-04-04 15:16:34 CEST DEBUG: 00000: shmem_exit(-1): 0 callbacks to make
2014-04-04 15:16:34 CEST LOCATION: shmem_exit, ipc.c:211
2014-04-04 15:16:34 CEST DEBUG: 00000: proc_exit(-1): 0 callbacks to make
2014-04-04 15:16:34 CEST LOCATION: proc_exit_prepare, ipc.c:183
2014-04-04 15:16:34 CEST DEBUG: 00000: reaping dead processes
2014-04-04 15:16:34 CEST LOCATION: reaper, postmaster.c:2360
2014-04-04 15:16:34 CEST DEBUG: 00000: server process (PID 20677) exited with e
xit code 0
2014-04-04 15:16:34 CEST LOCATION: LogChildExit, postmaster.c:2873
2014-04-04 15:16:37 CEST DEBUG: 00000: attempting to remove WAL segments older
than log file 000000010000003C00000071
2014-04-04 15:16:37 CEST LOCATION: RemoveOldXlogFiles, xlog.c:3364
2014-04-04 15:16:37 CEST DEBUG: 00000: recycled transaction log file "000000010
000003C00000071"
2014-04-04 15:16:37 CEST LOCATION: RemoveOldXlogFiles, xlog.c:3414
2014-04-04 15:16:37 CEST DEBUG: 00000: recycled transaction log file "000000010
000003C0000006F"
2014-04-04 15:16:37 CEST LOCATION: RemoveOldXlogFiles, xlog.c:3414
2014-04-04 15:16:37 CEST DEBUG: 00000: recycled transaction log file "000000010000003C00000070"
2014-04-04 15:16:37 CEST LOCATION: RemoveOldXlogFiles, xlog.c:3414

/Mark