Hello,
I'm having an issue where a process in Postgres is crashing and cause the server to go into recovery mode.
I'm getting the following errors in the log.
2020-02-03 14:12:57.473 EST [11992] [0]WARNING: 57P02: terminating connection because of crash of another server process
2020-02-03 14:12:57.473 EST [11992] [0]DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2020-02-03 14:12:57.473 EST [11992] [0]HINT: In a moment you should be able to reconnect to the database and repeat your command.
2020-02-03 14:12:57.473 EST [11992] [0]CONTEXT: while locking tuple (4101,2) in relation "containers"
SQL statement "UPDATE containers
SET type_uid = COALESCE(declared_type_uid, type_uid),
carton_type_uid = COALESCE(declared_carton_type_uid, carton_type_uid),
status_uid = COALESCE(declared_status_uid, status_uid),
order_uid = COALESCE(in_order_uid, order_uid),
wave_uid = COALESCE(in_wave_uid, wave_uid),
length = COALESCE(in_length, carton_length, length),
width = COALESCE(in_width, carton_width, width),
height = COALESCE(in_height, carton_height, height),
weight = COALESCE(in_weight, weight),
weight_minimum = COALESCE(in_weight_minimum, weight_minimum),
weight_maximum = COALESCE(in_weight_maximum, weight_maximum),
weight_expected = COALESCE(in_weight_expected, weight_expected),
first_seen_decision_point_id = COALESCE(first_seen_decision_point_id, in_last_seen_decision_point_id),
first_seen_datetime = COALESCE(first_seen_datetime, last_seen_date_time),
last_seen_decision_point_id = COALESCE(in_last_seen_decision_point_id, last_seen_decision_point_id),
last_seen_datetime = COALESCE(last_seen_date_time, last_seen_datetime),
recirculation_count = COALESCE(in_recirculation_count, recirculation_count),
project_flags = COALESCE(in_project_flags, project_flags),
passed_weight_check = COALESCE(in_passed_weight_check, passed_weight_check)
WHERE uid = in_uid"
PL/pgSQL function containers_add_update(integer,integer,integer,integer,integer,integer,double precision,double precision,double precision,double precision,double precision,double precision,double precision,integer,timestamp without time zone,character varying,bigint,boolean) line 60 at SQL statement
2020-02-03 14:12:57.473 EST [11992] [0]LOCATION: quickdie, postgres.c:2717
2020-02-03 14:12:57.473 EST [12260] [0]WARNING: 57P02: terminating connection because of crash of another server process
2020-02-03 14:12:57.473 EST [12260] [0]DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2020-02-03 14:12:57.473 EST [12260] [0]HINT: In a moment you should be able to reconnect to the database and repeat your command.
2020-02-03 14:12:57.473 EST [12260] [0]LOCATION: quickdie, postgres.c:2717
2020-02-03 14:12:57.476 EST [24552] [0]WARNING: 57P02: terminating connection because of crash of another server process
2020-02-03 14:12:57.476 EST [24552] [0]DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2020-02-03 14:12:57.476 EST [24552] [0]HINT: In a moment you should be able to reconnect to the database and repeat your command.
2020-02-03 14:12:57.476 EST [24552] [0]LOCATION: quickdie, postgres.c:2717
2020-02-03 14:12:57.479 EST [23844] [0]WARNING: 57P02: terminating connection because of crash of another server process
2020-02-03 14:12:57.479 EST [23844] [0]DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2020-02-03 14:12:57.479 EST [23844] [0]HINT: In a moment you should be able to reconnect to the database and repeat your command.
2020-02-03 14:12:57.479 EST [23844] [0]LOCATION: quickdie, postgres.c:2717
2020-02-03 14:12:57.586 EST [25992] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:57.586 EST [25992] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:57.587 EST [19428] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:57.587 EST [19428] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:57.627 EST [24968] [0]LOG: 00000: all server processes terminated; reinitializing
2020-02-03 14:12:57.627 EST [24968] [0]LOCATION: PostmasterStateMachine, postmaster.c:3912
2020-02-03 14:12:57.697 EST [16620] [0]LOG: 00000: database system was interrupted; last known up at 2020-02-03 14:12:53 EST
2020-02-03 14:12:57.697 EST [16620] [0]LOCATION: StartupXLOG, xlog.c:6277
2020-02-03 14:12:57.707 EST [13736] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:57.707 EST [13736] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:57.826 EST [21712] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:57.826 EST [21712] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:57.903 EST [6596] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:57.903 EST [6596] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:57.936 EST [20988] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:57.936 EST [20988] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:57.997 EST [16772] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:57.997 EST [16772] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.054 EST [11116] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.054 EST [11116] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.112 EST [24912] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.112 EST [24912] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.174 EST [25152] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.174 EST [25152] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.237 EST [3184] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.237 EST [3184] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.305 EST [22284] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.305 EST [22284] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.349 EST [18136] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.349 EST [18136] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.368 EST [13096] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.368 EST [13096] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.435 EST [20696] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.435 EST [20696] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.498 EST [13808] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.498 EST [13808] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.685 EST [16620] [0]LOG: 00000: database system was not properly shut down; automatic recovery in progress
2020-02-03 14:12:58.685 EST [16620] [0]LOCATION: StartupXLOG, xlog.c:6774
2020-02-03 14:12:58.692 EST [16620] [0]LOG: 00000: redo starts at 10/A6064FE8
2020-02-03 14:12:58.692 EST [16620] [0]LOCATION: StartupXLOG, xlog.c:7045
2020-02-03 14:12:58.965 EST [19264] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.965 EST [19264] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:59.866 EST [23180] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:59.866 EST [23180] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:13:01.211 EST [23624] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:13:01.211 EST [23624] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:13:03.160 EST [22964] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:13:03.160 EST [22964] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:13:06.052 EST [17252] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:13:06.052 EST [17252] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:13:10.383 EST [24704] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:13:10.383 EST [24704] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:13:16.831 EST [25028] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:13:16.831 EST [25028] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:13:26.488 EST [14852] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:13:26.488 EST [14852] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:13:32.772 EST [16620] [0]LOG: 00000: invalid record length at 10/C9B33770: wanted 24, got 0
2020-02-03 14:13:32.772 EST [16620] [0]LOCATION: ReadRecord, xlog.c:4284
2020-02-03 14:13:32.772 EST [16620] [0]LOG: 00000: redo done at 10/C9B33730
2020-02-03 14:13:32.772 EST [16620] [0]LOCATION: StartupXLOG, xlog.c:7307
2020-02-03 14:13:34.152 EST [24968] [0]LOG: 00000: database system is ready to accept connections
2020-02-03 14:12:57.473 EST [11992] [0]DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2020-02-03 14:12:57.473 EST [11992] [0]HINT: In a moment you should be able to reconnect to the database and repeat your command.
2020-02-03 14:12:57.473 EST [11992] [0]CONTEXT: while locking tuple (4101,2) in relation "containers"
SQL statement "UPDATE containers
SET type_uid = COALESCE(declared_type_uid, type_uid),
carton_type_uid = COALESCE(declared_carton_type_uid, carton_type_uid),
status_uid = COALESCE(declared_status_uid, status_uid),
order_uid = COALESCE(in_order_uid, order_uid),
wave_uid = COALESCE(in_wave_uid, wave_uid),
length = COALESCE(in_length, carton_length, length),
width = COALESCE(in_width, carton_width, width),
height = COALESCE(in_height, carton_height, height),
weight = COALESCE(in_weight, weight),
weight_minimum = COALESCE(in_weight_minimum, weight_minimum),
weight_maximum = COALESCE(in_weight_maximum, weight_maximum),
weight_expected = COALESCE(in_weight_expected, weight_expected),
first_seen_decision_point_id = COALESCE(first_seen_decision_point_id, in_last_seen_decision_point_id),
first_seen_datetime = COALESCE(first_seen_datetime, last_seen_date_time),
last_seen_decision_point_id = COALESCE(in_last_seen_decision_point_id, last_seen_decision_point_id),
last_seen_datetime = COALESCE(last_seen_date_time, last_seen_datetime),
recirculation_count = COALESCE(in_recirculation_count, recirculation_count),
project_flags = COALESCE(in_project_flags, project_flags),
passed_weight_check = COALESCE(in_passed_weight_check, passed_weight_check)
WHERE uid = in_uid"
PL/pgSQL function containers_add_update(integer,integer,integer,integer,integer,integer,double precision,double precision,double precision,double precision,double precision,double precision,double precision,integer,timestamp without time zone,character varying,bigint,boolean) line 60 at SQL statement
2020-02-03 14:12:57.473 EST [11992] [0]LOCATION: quickdie, postgres.c:2717
2020-02-03 14:12:57.473 EST [12260] [0]WARNING: 57P02: terminating connection because of crash of another server process
2020-02-03 14:12:57.473 EST [12260] [0]DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2020-02-03 14:12:57.473 EST [12260] [0]HINT: In a moment you should be able to reconnect to the database and repeat your command.
2020-02-03 14:12:57.473 EST [12260] [0]LOCATION: quickdie, postgres.c:2717
2020-02-03 14:12:57.476 EST [24552] [0]WARNING: 57P02: terminating connection because of crash of another server process
2020-02-03 14:12:57.476 EST [24552] [0]DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2020-02-03 14:12:57.476 EST [24552] [0]HINT: In a moment you should be able to reconnect to the database and repeat your command.
2020-02-03 14:12:57.476 EST [24552] [0]LOCATION: quickdie, postgres.c:2717
2020-02-03 14:12:57.479 EST [23844] [0]WARNING: 57P02: terminating connection because of crash of another server process
2020-02-03 14:12:57.479 EST [23844] [0]DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory.
2020-02-03 14:12:57.479 EST [23844] [0]HINT: In a moment you should be able to reconnect to the database and repeat your command.
2020-02-03 14:12:57.479 EST [23844] [0]LOCATION: quickdie, postgres.c:2717
2020-02-03 14:12:57.586 EST [25992] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:57.586 EST [25992] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:57.587 EST [19428] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:57.587 EST [19428] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:57.627 EST [24968] [0]LOG: 00000: all server processes terminated; reinitializing
2020-02-03 14:12:57.627 EST [24968] [0]LOCATION: PostmasterStateMachine, postmaster.c:3912
2020-02-03 14:12:57.697 EST [16620] [0]LOG: 00000: database system was interrupted; last known up at 2020-02-03 14:12:53 EST
2020-02-03 14:12:57.697 EST [16620] [0]LOCATION: StartupXLOG, xlog.c:6277
2020-02-03 14:12:57.707 EST [13736] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:57.707 EST [13736] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:57.826 EST [21712] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:57.826 EST [21712] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:57.903 EST [6596] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:57.903 EST [6596] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:57.936 EST [20988] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:57.936 EST [20988] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:57.997 EST [16772] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:57.997 EST [16772] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.054 EST [11116] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.054 EST [11116] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.112 EST [24912] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.112 EST [24912] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.174 EST [25152] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.174 EST [25152] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.237 EST [3184] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.237 EST [3184] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.305 EST [22284] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.305 EST [22284] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.349 EST [18136] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.349 EST [18136] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.368 EST [13096] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.368 EST [13096] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.435 EST [20696] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.435 EST [20696] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.498 EST [13808] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.498 EST [13808] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:58.685 EST [16620] [0]LOG: 00000: database system was not properly shut down; automatic recovery in progress
2020-02-03 14:12:58.685 EST [16620] [0]LOCATION: StartupXLOG, xlog.c:6774
2020-02-03 14:12:58.692 EST [16620] [0]LOG: 00000: redo starts at 10/A6064FE8
2020-02-03 14:12:58.692 EST [16620] [0]LOCATION: StartupXLOG, xlog.c:7045
2020-02-03 14:12:58.965 EST [19264] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:58.965 EST [19264] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:12:59.866 EST [23180] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:12:59.866 EST [23180] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:13:01.211 EST [23624] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:13:01.211 EST [23624] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:13:03.160 EST [22964] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:13:03.160 EST [22964] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:13:06.052 EST [17252] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:13:06.052 EST [17252] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:13:10.383 EST [24704] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:13:10.383 EST [24704] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:13:16.831 EST [25028] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:13:16.831 EST [25028] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:13:26.488 EST [14852] [0]FATAL: 57P03: the database system is in recovery mode
2020-02-03 14:13:26.488 EST [14852] [0]LOCATION: ProcessStartupPacket, postmaster.c:2275
2020-02-03 14:13:32.772 EST [16620] [0]LOG: 00000: invalid record length at 10/C9B33770: wanted 24, got 0
2020-02-03 14:13:32.772 EST [16620] [0]LOCATION: ReadRecord, xlog.c:4284
2020-02-03 14:13:32.772 EST [16620] [0]LOG: 00000: redo done at 10/C9B33730
2020-02-03 14:13:32.772 EST [16620] [0]LOCATION: StartupXLOG, xlog.c:7307
2020-02-03 14:13:34.152 EST [24968] [0]LOG: 00000: database system is ready to accept connections
This happened when I was using a function to remove part of a comma delimited string while updating a row. The update could potentially touch every row in the table. The issue above occurred when a different update function was being executed on the same table.
If I use the following lock this issue seems to be resolved. However, I'm not sure why the above issue occurred.
LOCK TABLE containers IN SHARE ROW EXCLUSIVE MODE;
Does anyone have any ideas?
Thanks,
Doug
