Tom, et. al.,
From: Greg Williamson <gwilliamson39@xxxxxxxxx>
To: Tom Lane <tgl@xxxxxxxxxxxxx>
Cc: "pgsql-admin@xxxxxxxxxxxxxx" <pgsql-admin@xxxxxxxxxxxxxx>
Sent: Thursday, August 9, 2012 5:35 PM
Subject: Re: Question about ALTER TABLE DROP CONSTRAINT on 9.1 -- psql crashes
Tom -->>
><...>
>> WTF? That should certainly not happen. Have you perhaps got a script
>> that runs around sending SIGTERM to backends that it thinks are blocking
>> something? Does anything show up in the postmaster log when this
>> happens?
>
> No, we have processes that kill IDLE IN TRANSACTIONs ruthlessly, but nothing that kills any other processes. There is an outside chance that this ran at just the> same time that a cronjob ran the REINDEX command for the table (unlikely but I am going to shut off the cronjob and try this again).>> It does not log an ERROR to the log file; I can wade intio the log and see what else it says but it will take a little while (about 800 megs per hour) to answer that.
>
> Thanks, and I'll report back soon.This was as all run as user postgres, unlike everything else so here is everyhting in the logsw:2012-08-09 16:50:25.398 PDT,"postgres","gusher",13873,"[local]",50244cc1.3631,2,"authentication",2012-08-09 16:50:25 PDT,19/61906190,0,LOG,00000,"connection authorized: user=postgres database=gusher",,,,,,,,,""2012-08-09 16:50:41.206 PDT,"postgres","gusher",13873,"[local]",50244cc1.3631,3,"SELECT",2012-08-09 16:50:25 PDT,19/0,0,LOG,00000,"duration: 3.437 ms statement: SELECT c.oid,2012-08-09 16:50:41.212 PDT,"postgres","gusher",13873,"[local]",50244cc1.3631,4,"SELECT",2012-08-09 16:50:25 PDT,19/0,0,LOG,00000,"duration: 4.461 ms statement: SELECT a.attname,2012-08-09 16:50:59.238 PDT,"postgres","gusher",13873,"[local]",50244cc1.3631,5,"ALTER TABLE",2012-08-09 16:50:25 PDT,19/61906197,1518480799,LOG,00000,"duration: 4.612 ms statement: ALTER TABLE ourcodes ADD CONSTRAINT ourcodes_pkey PRIMARY KEY (id);",,,,,,,,,"psql"2012-08-09 16:51:01.808 PDT,"postgres","gusher",13873,"[local]",50244cc1.3631,6,"idle in transaction",2012-08-09 16:50:25 PDT,19/61906197,1518480799,FATAL,57P01,"terminating connection due to administrator command",,,,,,,,,"psql"2012-08-09 16:51:01.859 PDT,"postgres","gusher",13873,"[local]",50244cc1.3631,7,"idle in transaction",2012-08-09 16:50:25 PDT,,0,LOG,00000,"disconnection: session time: 0:00:36.458 user=postgres database=gusher host=[local]",,,,,,,,,"psql"2012-08-09 16:51:02.309 PDT,"postgres","gusher",14000,"[local]",50244ce6.36b0,2,"authentication",2012-08-09 16:51:02 PDT,19/61906206,0,LOG,00000,"connection authorized: user=postgres database=gusher",,,,,,,,,""2012-08-09 16:51:18.551 PDT,"postgres","gusher",14000,"[local]",50244ce6.36b0,3,"SELECT",2012-08-09 16:51:02 PDT,19/0,0,LOG,00000,"duration: 3.979 ms statement: SELECT a.attname,2012-08-09 16:51:18.556 PDT,"postgres","gusher",14000,"[local]",50244ce6.36b0,4,"SELECT",2012-08-09 16:51:02 PDT,19/0,0,LOG,00000,"duration: 5.255 ms statement: SELECT c2.relname, i.indisprimary, i.indisunique, i.indisclustered, i.indisvalid, pg_catalog.pg_get_indexdef(i.indexrelid, 0, true),2012-08-09 16:59:34.443 PDT,"postgres","gusher",14000,"[local]",50244ce6.36b0,5,"idle",2012-08-09 16:51:02 PDT,,0,LOG,00000,"disconnection: session time: 0:08:32.135 user=postgres database=gusher host=[local]",,,,,,,,,"psql"Every minute on the minute there is a cronjob that kills IDLE IN CONNECTION procs older than 3 seconds ... possibly that process killed the process I was running, but to me the user it seemed as if the COMMIT came before the disconnect.We have had some issues on this box so I probably won't test this much more today; I'll post more if I can get a reproducible case.Thanks,Greg
