Deadlock in PostgreSQL 7.3.4

Hi,

In the meantime we were able to upgrade to PostgreSQL 7.3.4+Tom's patch
to datetime.c [see 'Postgresql 7.3.3 crashing on query' thread].

Now if the applications issues one delete statement concurrently on
two connections both block forever.

Please correct me if I am wrong, but should not one of the statements
succeed and the other simply fail ?

Aug 18 10:34:25 nut1 postgres[4934]: [44389] LOG:
query: delete from Calls where objID = 2268645

Aug 18 10:34:25 nut1 postgres[4933]: [44071] LOG:
query: delete from Calls where objID = 2268645

Architecture: i386, OS: Debian

And here the full info:

sd=> SELECT l.mode, l.granted, l.pid, l.transaction, d.datname, r.relname FROM pg_locks l, pg_database d, pg_class r WHERE d.oid=l.database AND r.oid=l.relation;
mode | granted | pid | transaction | datname | relname
------------------+---------+-------+-------------+---------+------------------------------
AccessShareLock | t | 26836 | | sd | pg_locks
AccessShareLock | t | 26836 | | sd | pg_class
AccessShareLock | t | 22486 | | sd | callactivities
AccessShareLock | t | 4935 | | sd | callactivities
AccessShareLock | t | 22487 | | sd | callactivities
AccessShareLock | t | 22486 | | sd | bppersons
AccessShareLock | t | 22487 | | sd | bppersons
AccessShareLock | t | 4935 | | sd | bppersons
AccessShareLock | t | 4935 | | sd | priorities
AccessShareLock | t | 22487 | | sd | priorities
AccessShareLock | t | 22486 | | sd | priorities
AccessShareLock | t | 22487 | | sd | callstates
AccessShareLock | t | 4935 | | sd | callstates
AccessShareLock | t | 22486 | | sd | callstates
AccessShareLock | t | 4935 | | sd | queues
AccessShareLock | t | 22487 | | sd | queues
AccessShareLock | t | 22486 | | sd | queues
AccessShareLock | t | 22486 | | sd | timezones
AccessShareLock | t | 4935 | | sd | timezones
AccessShareLock | t | 22487 | | sd | timezones
AccessShareLock | t | 22486 | | sd | calls
RowExclusiveLock | t | 4934 | | sd | calls
AccessShareLock | t | 4934 | | sd | calls
AccessShareLock | t | 4935 | | sd | calls
RowExclusiveLock | t | 4933 | | sd | calls
AccessShareLock | t | 4933 | | sd | calls
AccessShareLock | t | 22487 | | sd | calls
AccessShareLock | t | 22487 | | sd | bporganizations
AccessShareLock | t | 22486 | | sd | bporganizations
AccessShareLock | t | 4935 | | sd | bporganizations
AccessShareLock | t | 22487 | | sd | problemtypes
AccessShareLock | t | 22486 | | sd | problemtypes
AccessShareLock | t | 4935 | | sd | problemtypes
AccessShareLock | t | 4935 | | sd | contractelements
AccessShareLock | t | 22486 | | sd | contractelements
AccessShareLock | t | 22487 | | sd | contractelements
AccessShareLock | t | 4935 | | sd | contracts
AccessShareLock | t | 22487 | | sd | contracts
AccessShareLock | t | 22486 | | sd | contracts
AccessShareLock | t | 22487 | | sd | bpartners
AccessShareLock | t | 4935 | | sd | bpartners
AccessShareLock | t | 22486 | | sd | bpartners
AccessShareLock | t | 22487 | | sd | callcalculations
AccessShareLock | t | 22486 | | sd | callcalculations
AccessShareLock | t | 4935 | | sd | callcalculations
AccessShareLock | t | 22487 | | sd | chargingtypes
AccessShareLock | t | 22486 | | sd | chargingtypes
AccessShareLock | t | 4935 | | sd | chargingtypes
AccessShareLock | t | 22487 | | sd | dictpropertysethasproperties
AccessShareLock | t | 4935 | | sd | dictpropertysethasproperties
AccessShareLock | t | 22486 | | sd | dictpropertysethasproperties
AccessShareLock | t | 22487 | | sd | concretepropertysets
AccessShareLock | t | 4935 | | sd | concretepropertysets
AccessShareLock | t | 22486 | | sd | concretepropertysets
AccessShareLock | t | 22486 | | sd | concretepropertyvalues
AccessShareLock | t | 4935 | | sd | concretepropertyvalues
AccessShareLock | t | 22487 | | sd | concretepropertyvalues
AccessShareLock | t | 4935 | | sd | dictproperties
AccessShareLock | t | 22486 | | sd | dictproperties
AccessShareLock | t | 22487 | | sd | dictproperties
AccessShareLock | t | 4934 | | sd | calls_pkey
(61 rows)

3936 ? S 0:00 postgres: stats buffer process
3937 ? S 0:00 postgres: stats collector process
4555 ? S 69:38 postgres: sd sd 10.2.2.6 idle
4556 ? S 0:07 postgres: sd sd 10.2.2.6 idle
4621 ? S 11:19 postgres: sd sd 10.2.2.6 idle
4632 ? S 10:08 postgres: sd sd 10.2.2.6 idle
4764 ? S 0:04 postgres: sd sd 10.2.1.5 idle
4933 ? S 5:20 postgres: sd sd 10.2.1.5 idle in transaction
4934 ? S 5:08 postgres: sd sd 10.2.1.5 DELETE waiting
4935 ? S 6:00 postgres: sd sd 10.2.1.5 idle in transaction
4936 ? S 4:54 postgres: sd sd 10.2.1.5 idle
4937 ? S 5:30 postgres: sd sd 10.2.1.5 idle
4938 ? S 6:17 postgres: sd sd 10.2.1.5 idle
4939 ? S 6:23 postgres: sd sd 10.2.1.5 idle
22486 ? S 1:40 postgres: sd sd 10.2.1.5 idle in transaction
22487 ? S 1:54 postgres: sd sd 10.2.1.5 idle in transaction
24211 pts/2 S 0:00 /usr/lib/postgresql/bin/psql -d sd
24218 ? S 0:00 postgres: sd sd [local] idle
26753 ? S 0:00 postgres: sd sd 10.2.1.5 idle

Aug 18 10:34:25 nut1 postgres[4934]: [44383-1] LOG: query: select objID, ID, CustCallID, SPCallID, cel_objid, con_objid, ccu_objid, csp_objid, csf_objid, fro_objid,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-2] to1_objid, to2_objid, CallerSLA, CallOpenTime, CallOpenTimeUTC, CallResponseTime, CallResponseTimeUTC, CallCloseTime,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-3] CallCloseTimeUTC, CallReceiveTime, CallReceiveTimeUTC, CallSendTime, CallSendTimeUTC, ProblemStartTime, ProblemStartTimeUTC,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-4] EndOfResponseTime, EndOfResponseTimeUTC, RemainingResponseMinutes, EndOfRecoveryTime, EndOfRecoveryTimeUTC,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-5] RemainingRecoveryMinutes, CallStateChangeTime, CallStateChangeTimeUTC, CallAcknowledgeTime, CallAcknowledgeTimeUTC,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-6] CallerShortName, CallerFirstName, CallerLastName, CallerTitle, CallerSalutation, CallerTel, CallerTel2, CallerMobileTel,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-7] CallerFax, CallerLocationZip, CallerLocationCity, CallerLocationStreet, CallerLocationCountry, CallerLocation, CallerEMail,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-8] CallerPIN, CallerDescription, CallerDepartment, CallerSign, MainCompManfacturer, MainCompType, MainCompModel, MainComponent,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-9] MainCompName, MainCompSerNr, MainCompInvNr, MainCompSerNrProv, MainCompOpSys, MainCompLocationZip, MainCompLocationCity,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-10] MainCompLocationStreet, MainCompLocationCountry, MainCompLocation, MainCompLocationTel, MainCompDescription,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-11] MainCompLocationName, pro_objid, pcu_objid, psp_objid, psf_objid, pgl_objid, sev_objid, fat_objid, cst_objid, pst_objid,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-12] cac_objid, ema_objid, InternalState, CallProvedFlag, ShortDescription, Description, Remarks, Diagnosis, edi_objid, EditTime,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-13] EditTimeUTC, csc_objid, css_objid, csu_objid, cal_objid, SubCompManfacturer, SubCompType, SubCompModel, SubComponent,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-14] SubCompName, SubCompSerNr, SubCompInvNr, SubCompSerNrProv, SubCompOpSys, SubCompLocationZip, SubCompLocationCity,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-15] SubCompLocationStreet, SubCompLocationCountry, SubCompLocation, SubCompLocationTel, SubCompDescription, SubCompLocationName,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-16] SysSpecField1, SysSpecField2, SysSpecField3, SysSpecField4, SysSpecField5, SysSpecField6, SysSpecField7, SysSpecField8,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-17] SysSpecField9, SysSpecField10, XML_Info, CHDShortName, CHDFirstName, CHDLastName, CHDTitle, CHDSalutation, CHDTel, CHDTel2,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-18] CHDMobileTel, CHDFax, CHDLocationZip, CHDLocationCity, CHDLocationStreet, CHDLocationCountry, CHDLocation, CHDEMail, CHDPIN,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-19] CHDDescription, CHDDepartment, CHDSign, CCPShortName, CCPFirstName, CCPLastName, CCPTitle, CCPSalutation, CCPTel, CCPTel2,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-20] CCPMobileTel, CCPFax, CCPLocationZip, CCPLocationCity, CCPLocationStreet, CCPLocationCountry, CCPLocation, CCPEMail, CCPPIN,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-21] CCPDescription, CCPDepartment, CCPSign, bpr_objid, SlaResponseMinutes, SlaRecoveryMinutes, TotalResponseMinutes,
Aug 18 10:34:25 nut1 postgres[4934]: [44383-22] TotalRecoveryMinutes, TotalAcknowledgeMinutes, Zone, unspsc, dev_objid, tzo_objid, isTestCall, que_objid, tec_objid from Calls
Aug 18 10:34:25 nut1 postgres[4934]: [44383-23] where ID = 2266388
Aug 18 10:34:25 nut1 postgres[4934]: [44384] LOG: duration: 0.007914 sec
Aug 18 10:34:25 nut1 postgres[4934]: [44385] LOG: query: select objID, ID, ShortName, Name, TZID, UTCRawOffset from TimeZones where objID = 1000040000
Aug 18 10:34:25 nut1 postgres[4934]: [44386] LOG: duration: 0.001898 sec
Aug 18 10:34:25 nut1 postgres[4934]: [44387] LOG: query: begin;
Aug 18 10:34:25 nut1 postgres[4934]: [44388] LOG: duration: 0.000117 sec
Aug 18 10:34:25 nut1 postgres[4934]: [44389] LOG: query: delete from Calls where objID = 2268645
Aug 18 10:39:18 nut1 postgres[4934]: [44390] LOG: duration: 292.649273 sec
Aug 18 10:39:18 nut1 postgres[4934]: [44391] LOG: pq_recvbuf: unexpected EOF on client connection

Aug 18 10:34:25 nut1 postgres[4933]: [44067-1] LOG: query: select objID, ID, CustCallID, SPCallID, cel_objid, con_objid, ccu_objid, csp_objid, csf_objid, fro_objid,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-2] to1_objid, to2_objid, CallerSLA, CallOpenTime, CallOpenTimeUTC, CallResponseTime, CallResponseTimeUTC, CallCloseTime,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-3] CallCloseTimeUTC, CallReceiveTime, CallReceiveTimeUTC, CallSendTime, CallSendTimeUTC, ProblemStartTime, ProblemStartTimeUTC,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-4] EndOfResponseTime, EndOfResponseTimeUTC, RemainingResponseMinutes, EndOfRecoveryTime, EndOfRecoveryTimeUTC,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-5] RemainingRecoveryMinutes, CallStateChangeTime, CallStateChangeTimeUTC, CallAcknowledgeTime, CallAcknowledgeTimeUTC,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-6] CallerShortName, CallerFirstName, CallerLastName, CallerTitle, CallerSalutation, CallerTel, CallerTel2, CallerMobileTel,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-7] CallerFax, CallerLocationZip, CallerLocationCity, CallerLocationStreet, CallerLocationCountry, CallerLocation, CallerEMail,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-8] CallerPIN, CallerDescription, CallerDepartment, CallerSign, MainCompManfacturer, MainCompType, MainCompModel, MainComponent,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-9] MainCompName, MainCompSerNr, MainCompInvNr, MainCompSerNrProv, MainCompOpSys, MainCompLocationZip, MainCompLocationCity,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-10] MainCompLocationStreet, MainCompLocationCountry, MainCompLocation, MainCompLocationTel, MainCompDescription,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-11] MainCompLocationName, pro_objid, pcu_objid, psp_objid, psf_objid, pgl_objid, sev_objid, fat_objid, cst_objid, pst_objid,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-12] cac_objid, ema_objid, InternalState, CallProvedFlag, ShortDescription, Description, Remarks, Diagnosis, edi_objid, EditTime,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-13] EditTimeUTC, csc_objid, css_objid, csu_objid, cal_objid, SubCompManfacturer, SubCompType, SubCompModel, SubComponent,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-14] SubCompName, SubCompSerNr, SubCompInvNr, SubCompSerNrProv, SubCompOpSys, SubCompLocationZip, SubCompLocationCity,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-15] SubCompLocationStreet, SubCompLocationCountry, SubCompLocation, SubCompLocationTel, SubCompDescription, SubCompLocationName,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-16] SysSpecField1, SysSpecField2, SysSpecField3, SysSpecField4, SysSpecField5, SysSpecField6, SysSpecField7, SysSpecField8,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-17] SysSpecField9, SysSpecField10, XML_Info, CHDShortName, CHDFirstName, CHDLastName, CHDTitle, CHDSalutation, CHDTel, CHDTel2,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-18] CHDMobileTel, CHDFax, CHDLocationZip, CHDLocationCity, CHDLocationStreet, CHDLocationCountry, CHDLocation, CHDEMail, CHDPIN,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-19] CHDDescription, CHDDepartment, CHDSign, CCPShortName, CCPFirstName, CCPLastName, CCPTitle, CCPSalutation, CCPTel, CCPTel2,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-20] CCPMobileTel, CCPFax, CCPLocationZip, CCPLocationCity, CCPLocationStreet, CCPLocationCountry, CCPLocation, CCPEMail, CCPPIN,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-21] CCPDescription, CCPDepartment, CCPSign, bpr_objid, SlaResponseMinutes, SlaRecoveryMinutes, TotalResponseMinutes,
Aug 18 10:34:25 nut1 postgres[4933]: [44067-22] TotalRecoveryMinutes, TotalAcknowledgeMinutes, Zone, unspsc, dev_objid, tzo_objid, isTestCall, que_objid, tec_objid from Calls
Aug 18 10:34:25 nut1 postgres[4933]: [44067-23] where ID = 2265302
Aug 18 10:34:25 nut1 postgres[4933]: [44068] LOG: duration: 0.008038 sec
Aug 18 10:34:25 nut1 postgres[4933]: [44069] LOG: query: begin;
Aug 18 10:34:25 nut1 postgres[4933]: [44070] LOG: duration: 0.000121 sec
Aug 18 10:34:25 nut1 postgres[4933]: [44071] LOG: query: delete from Calls where objID = 2268645
Aug 18 10:34:25 nut1 postgres[4933]: [44072] LOG: duration: 0.000675 sec
Aug 18 10:39:18 nut1 postgres[4933]: [44073] LOG: pq_recvbuf: unexpected EOF on client connection

-Philipp
--
: Dipl-Ing Philipp Reisner Tel +43-1-8178292-50 :
: LINBIT Information Technologies GmbH Fax +43-1-8178292-82 :
: Schönbrunnerstr 244, 1120 Vienna, Austria http://www.linbit.com :