Re: PostgreSQL XID exceeded crash.

Mario Lopez <mario@xxxxxxxxx> · Mon, 04 Sep 2006 16:42:20 +0200

Hola Alvaro,

The process that are being reaped are postgresql child processes, more 
precisely the process that is attending my queryes...

Here I have another log that has the %p %i and %x in that order but I 
see no clear difference.

Thanks.

Alvaro Herrera escribió:
Mario Lopez wrote:

Hi Alvaro,

Ok, maybe is not a crash  but this issue makes postgresql reap all of 
it's child processes and restart operations, after this error I get in 
pg_restore this message:

pg_restore: [archivador (bd)] Error durante PROCESAMIENTO DE TABLA DE 
CONTENIDOS:
pg_restore: [archivador (bd)] Error en entrada de la tabla de contenidos 
1893; 0 1615776 TABLE DATA xxxxx postgres
pg_restore: [archivador (bd)] could not execute query: server closed the 
connection unexpectedly
       This probably means the server terminated abnormally
       before or while processing the request.
   Command was: INSERT INTO xxxxx VALUES (1755298, 2, 117, 28, 1155, 
52457, 1, 1, '', '', '', '', NULL);
pg_restore: [archivador (bd)] could not execute query: sin resultado 
desde el servidor

I have a attached a log from the XID exhausted resources till it reaps 
all of it's child processes, which ends in a crash from pg_restore or 
any application using this table.

The actual problem is shown in these lines:

DEBUG:  00000: reaping dead processes
UBICACION:  reaper, postmaster.c:2021
DEBUG:  00000: proceso de servidor (PID 31622) termino con codigo de salida 255
UBICACION:  LogChildExit, postmaster.c:2419
LOG:  00000: proceso de servidor (PID 31622) termino con codigo de salida 255

What you need to find out is why is this process is terminating with
code 255.  What is it anyway?  If you added %p to log_line_prefix we
could have a better idea of what is it and what is it doing.

PID:3559 CMD_TAG:INSERT XID:273990712 DEBUG:  00000: name: unnamed; blockState:       STARTED; state: INPROGR, xid/subid/cid: 273990712/1/0, nestlvl: 1, children: <>
PID:3559 CMD_TAG:INSERT XID:273990712 UBICACIÓN:  ShowTransactionStateRec, xact.c:3955
PID:3559 CMD_TAG:idle XID:0 DEBUG:  00000: StartTransactionCommand
PID:3559 CMD_TAG:idle XID:0 UBICACIÓN:  start_xact_command, postgres.c:1983
PID:3559 CMD_TAG:idle XID:273990713 DEBUG:  00000: StartTransaction
PID:3559 CMD_TAG:idle XID:273990713 UBICACIÓN:  ShowTransactionState, xact.c:3930
PID:3559 CMD_TAG:idle XID:273990713 DEBUG:  00000: name: unnamed; blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 273990713/1/0, nestlvl: 1, children: <>
PID:3559 CMD_TAG:idle XID:273990713 UBICACIÓN:  ShowTransactionStateRec, xact.c:3955
PID:3559 CMD_TAG:INSERT XID:273990713 DEBUG:  00000: ProcessQuery
PID:3559 CMD_TAG:INSERT XID:273990713 UBICACIÓN:  ProcessQuery, pquery.c:128
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3524 CMD_TAG: XID: DEBUG:  00000: proceso de servidor (PID 3559) terminó con código de salida 255
PID:3524 CMD_TAG: XID: UBICACIÓN:  LogChildExit, postmaster.c:2419
PID:3524 CMD_TAG: XID: LOG:  00000: proceso de servidor (PID 3559) terminó con código de salida 255
PID:3524 CMD_TAG: XID: UBICACIÓN:  LogChildExit, postmaster.c:2419
PID:3524 CMD_TAG: XID: LOG:  00000: terminando todos los otros procesos de servidor activos
PID:3524 CMD_TAG: XID: UBICACIÓN:  HandleChildCrash, postmaster.c:2309
PID:3524 CMD_TAG: XID: DEBUG:  00000: sending SIGQUIT to process 3526
PID:3524 CMD_TAG: XID: UBICACIÓN:  HandleChildCrash, postmaster.c:2362
PID:3524 CMD_TAG: XID: DEBUG:  00000: sending SIGQUIT to process 3527
PID:3524 CMD_TAG: XID: UBICACIÓN:  HandleChildCrash, postmaster.c:2396
PID:3524 CMD_TAG: XID: LOG:  00000: todos los procesos fueron terminados; reinicializando
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2209
PID:3524 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3524 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3524 CMD_TAG: XID: DEBUG:  00000: invoking IpcMemoryCreate(size=110387200)
PID:3524 CMD_TAG: XID: UBICACIÓN:  CreateSharedMemoryAndSemaphores, ipci.c:99
PID:3612 CMD_TAG: XID: LOG:  00000: el sistema de bases de datos fue interrumpido en 2006-09-04 16:08:06 CEST
PID:3612 CMD_TAG: XID: UBICACIÓN:  StartupXLOG, xlog.c:4373
PID:3612 CMD_TAG: XID: LOG:  00000: el registro de checkpoint está en 1/9307E6A0
PID:3612 CMD_TAG: XID: UBICACIÓN:  StartupXLOG, xlog.c:4441
PID:3612 CMD_TAG: XID: LOG:  00000: registro de redo en 1/93000058; registro de undo en 0/0; apagado FALSE
PID:3612 CMD_TAG: XID: UBICACIÓN:  StartupXLOG, xlog.c:4468
PID:3612 CMD_TAG: XID: LOG:  00000: siguiente ID de transacción: 273975270; siguiente OID: 12298416
PID:3612 CMD_TAG: XID: UBICACIÓN:  StartupXLOG, xlog.c:4471
PID:3612 CMD_TAG: XID: LOG:  00000: siguiente MultiXactId: 5; siguiente MultiXactOffset: 10
PID:3612 CMD_TAG: XID: UBICACIÓN:  StartupXLOG, xlog.c:4474
PID:3612 CMD_TAG: XID: LOG:  00000: el sistema de bases de datos no fue apagado apropiadamente; se está efectuando la recuperación automática
PID:3612 CMD_TAG: XID: UBICACIÓN:  StartupXLOG, xlog.c:4531
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3612 CMD_TAG: XID: LOG:  00000: redo comienza en 1/93000058
PID:3612 CMD_TAG: XID: UBICACIÓN:  StartupXLOG, xlog.c:4568
PID:3612 CMD_TAG: XID: LOG:  00000: registro de longitud cero en 1/9323006C
PID:3612 CMD_TAG: XID: UBICACIÓN:  ReadRecord, xlog.c:2763
PID:3612 CMD_TAG: XID: LOG:  00000: redo listo en 1/93230044
PID:3612 CMD_TAG: XID: UBICACIÓN:  StartupXLOG, xlog.c:4626
PID:3612 CMD_TAG: XID: DEBUG:  00000: el archivo de registro de transacciones «000000010000000100000092» ha sido reciclado
PID:3612 CMD_TAG: XID: UBICACIÓN:  MoveOfflineLogs, xlog.c:2407
PID:3612 CMD_TAG: XID: DEBUG:  00000: el archivo de registro de transacciones «000000010000000100000090» ha sido reciclado
PID:3612 CMD_TAG: XID: UBICACIÓN:  MoveOfflineLogs, xlog.c:2407
PID:3612 CMD_TAG: XID: DEBUG:  00000: el archivo de registro de transacciones «000000010000000100000091» ha sido reciclado
PID:3612 CMD_TAG: XID: UBICACIÓN:  MoveOfflineLogs, xlog.c:2407
PID:3612 CMD_TAG: XID: LOG:  00000: el sistema de bases de datos está listo
PID:3612 CMD_TAG: XID: UBICACIÓN:  StartupXLOG, xlog.c:4820
PID:3612 CMD_TAG: XID: LOG:  00000: el límite para el reciclaje de ID de transacciones es 2147484146, limitado por base de datos «postgres»
PID:3612 CMD_TAG: XID: UBICACIÓN:  SetTransactionIdLimit, varsup.c:234
PID:3612 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3612 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3612 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3612 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3612 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3612 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3650 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3650 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3650 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3650 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3650 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3650 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3675 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3675 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3675 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3675 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3675 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3675 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3700 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3700 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3700 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3700 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3700 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3700 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3725 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3725 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3725 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3725 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3725 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3725 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3750 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3750 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3750 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3750 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3750 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3750 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3775 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3775 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3775 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3775 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3775 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3775 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3800 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3800 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3800 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3800 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3800 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3800 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3826 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3826 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3826 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3826 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3826 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3826 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3853 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3853 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3853 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3853 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3853 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3853 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3878 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3878 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3878 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3878 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3878 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3878 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3903 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3903 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3903 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3903 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3903 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3903 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3928 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3928 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3928 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3928 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3928 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3928 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3953 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3953 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3953 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3953 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3953 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3953 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:3979 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:3979 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:3979 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:3979 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:3979 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:3979 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:4004 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:4004 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:4004 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:4004 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:4004 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:4004 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:4029 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:4029 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:4029 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:4029 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:4029 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:4029 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021
PID:4054 CMD_TAG: XID: DEBUG:  00000: proc_exit(0)
PID:4054 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:95
PID:4054 CMD_TAG: XID: DEBUG:  00000: shmem_exit(0)
PID:4054 CMD_TAG: XID: UBICACIÓN:  shmem_exit, ipc.c:126
PID:4054 CMD_TAG: XID: DEBUG:  00000: exit(0)
PID:4054 CMD_TAG: XID: UBICACIÓN:  proc_exit, ipc.c:113
PID:3524 CMD_TAG: XID: DEBUG:  00000: reaping dead processes
PID:3524 CMD_TAG: XID: UBICACIÓN:  reaper, postmaster.c:2021