Hi, My application runs many concurrent sessions with the same transaction code starting with an update statement. I would expect locking and serialization of those transactions. But I get unexpected deadlocks. As opposed to *http://momjian.us/main/writings/pgsql/locking.pdf <http://momjian.us/main/writings/pgsql/locking.pdf>* page 84 (waits for ShareLock on transaction only) my case looks different:
ERROR: deadlock detected DETAIL: Process 6973 waits for ShareLock on transaction 318396117; blocked by process 11039. ^^^^^^^^^^^^^^ Process 11039 waits for ExclusiveLock on tuple (4,9) of relation 16416 of database 16417; blocked by process 6973. ^^^^^^^^^^^^^^ Process 6973: update AELDATA set LOCK_COLUMN = 1 where (SBO_GRP = '000015') Process 11039: update AELDATA set LOCK_COLUMN = 1 where (SBO_GRP = '000015') Is this an expected behaviour, or maybe a bug? Thanks, Andrej ---------------------------details case is reproducible via my application. I was unable to reproduce it via psql sessions (locking worked fine). I was unable to reproduce it via shell for loop with psql sessions running same transactions (100 loops in 10 terminal windows). postgres version: PostgreSQL 9.3.4 on x86_64-unknown-linux-gnu, compiled by gcc (GCC) 4.4.7 20120313 (Red Hat 4.4.7-4), 64-bit postgres log: 2014-09-22 22:21:54 CEST:yy@xx1:[6973] LOG: duration: 0.021 ms execute S_2: ROLLBACK 2014-09-22 22:21:54 CEST:yy@xx1:[11039] LOG: duration: 7.965 ms execute S_3: COMMIT 2014-09-22 22:21:54 CEST:yy@xx1:[6973] LOG: duration: 0.015 ms bind S_1: BEGIN 2014-09-22 22:21:54 CEST:yy@xx1:[6973] LOG: duration: 0.008 ms execute S_1: BEGIN 2014-09-22 22:21:54 CEST:yy@xx1:[6973] LOG: duration: 0.122 ms parse <unnamed>: select * from AELDATA_READ_VIEW where (SBO_GRP = '000015') 2014-09-22 22:21:54 CEST:yy@xx1:[6973] LOG: duration: 0.317 ms bind <unnamed>: select * from AELDATA_READ_VIEW where (SBO_GRP = '000015') 2014-09-22 22:21:54 CEST:yy@xx1:[6973] LOG: duration: 0.041 ms execute <unnamed>: select * from AELDATA_READ_VIEW where (SBO_GRP = '000015') 2014-09-22 22:21:54 CEST:yy@xx1:[6973] LOG: duration: 0.017 ms bind S_2: ROLLBACK 2014-09-22 22:21:54 CEST:yy@xx1:[6973] LOG: duration: 0.022 ms execute S_2: ROLLBACK 2014-09-22 22:21:54 CEST:yy@xx1:[11039] LOG: duration: 0.017 ms bind S_1: BEGIN 2014-09-22 22:21:54 CEST:yy@xx1:[11039] LOG: duration: 0.010 ms execute S_1: BEGIN 2014-09-22 22:21:54 CEST:yy@xx1:[11039] LOG: duration: 0.083 ms parse <unnamed>: update AELDATA set LOCK_COLUMN = 1 where (SBO_GRP = '000015') 2014-09-22 22:21:54 CEST:yy@xx1:[6973] LOG: duration: 0.016 ms bind S_1: BEGIN 2014-09-22 22:21:54 CEST:yy@xx1:[6973] LOG: duration: 0.013 ms execute S_1: BEGIN 2014-09-22 22:21:54 CEST:yy@xx1:[11039] LOG: duration: 0.174 ms bind <unnamed>: update AELDATA set LOCK_COLUMN = 1 where (SBO_GRP = '000015') 2014-09-22 22:21:54 CEST:yy@xx1:[6973] LOG: duration: 0.096 ms parse <unnamed>: update AELDATA set LOCK_COLUMN = 1 where (SBO_GRP = '000015') 2014-09-22 22:21:54 CEST:yy@xx1:[6973] LOG: duration: 0.152 ms bind <unnamed>: update AELDATA set LOCK_COLUMN = 1 where (SBO_GRP = '000015') 2014-09-22 22:21:55 CEST:yy@xx1:[6973] LOG: process 6973 detected deadlock while waiting for ShareLock on transaction 318396117 after 1000.060 ms 2014-09-22 22:21:55 CEST:yy@xx1:[6973] STATEMENT: update AELDATA set LOCK_COLUMN = 1 where (SBO_GRP = '000015') 2014-09-22 22:21:55 CEST:yy@xx1:[11039] LOG: process 11039 still waiting for ExclusiveLock on tuple (4,9) of relation 16416 of database 16417 after 1000.038 ms 2014-09-22 22:21:55 CEST:yy@xx1:[11039] STATEMENT: update AELDATA set LOCK_COLUMN = 1 where (SBO_GRP = '000015') 2014-09-22 22:21:55 CEST:yy@xx1:[6973] ERROR: deadlock detected 2014-09-22 22:21:55 CEST:yy@xx1:[6973] DETAIL: Process 6973 waits for ShareLock on transaction 318396117; blocked by process 11039. Process 11039 waits for ExclusiveLock on tuple (4,9) of relation 16416 of database 16417; blocked by process 6973. Process 6973: update AELDATA set LOCK_COLUMN = 1 where (SBO_GRP = '000015') Process 11039: update AELDATA set LOCK_COLUMN = 1 where (SBO_GRP = '000015') 2014-09-22 22:21:55 CEST:yy@xx1:[6973] HINT: See server log for query details. 2014-09-22 22:21:55 CEST:yy@xx1:[6973] STATEMENT: update AELDATA set LOCK_COLUMN = 1 where (SBO_GRP = '000015') 2014-09-22 22:21:55 CEST:yy@xx1:[11039] LOG: process 11039 acquired ExclusiveLock on tuple (4,9) of relation 16416 of database 16417 after 1000.224 ms 2014-09-22 22:21:55 CEST:yy@xx1:[11039] STATEMENT: update AELDATA set LOCK_COLUMN = 1 where (SBO_GRP = '000015') 2014-09-22 22:21:55 CEST:yy@xx1:[11039] LOG: duration: 1004.543 ms execute <unnamed>: update AELDATA set LOCK_COLUMN = 1 where (SBO_GRP = '000015') 2014-09-22 22:21:55 CEST:yy@xx1:[11039] LOG: duration: 0.084 ms parse <unnamed>: select AEL_ID, SBO_GRP, LOCK_KEY from AELDATA where (SBO_GRP = '000015') 2014-09-22 22:21:55 CEST:yy@xx1:[11039] LOG: duration: 0.128 ms bind <unnamed>: select AEL_ID, SBO_GRP, LOCK_KEY from AELDATA where (SBO_GRP = '000015') 2014-09-22 22:21:55 CEST:yy@xx1:[11039] LOG: duration: 0.048 ms execute <unnamed>: select AEL_ID, SBO_GRP, LOCK_KEY from AELDATA where (SBO_GRP = '000015') 2014-09-22 22:21:55 CEST:yy@xx1:[11039] LOG: duration: 0.122 ms parse <unnamed>: select NUM_OF_SBO, AEL_ID, SBO_GRP, SBO_KEY, STATE, PROGRESS, LOCK_KEY from AEL_XT_DATA_VIEW where (AEL_ID = 15 and EN_NAME = 'H103') 2014-09-22 22:21:55 CEST:yy@xx1:[11039] LOG: duration: 0.356 ms bind <unnamed>: select NUM_OF_SBO, AEL_ID, SBO_GRP, SBO_KEY, STATE, PROGRESS, LOCK_KEY from AEL_XT_DATA_VIEW where (AEL_ID = 15 and EN_NAME = 'H103') 2014-09-22 22:21:55 CEST:yy@xx1:[11039] LOG: duration: 0.073 ms execute <unnamed>: select NUM_OF_SBO, AEL_ID, SBO_GRP, SBO_KEY, STATE, PROGRESS, LOCK_KEY from AEL_XT_DATA_VIEW where (AEL_ID = 15 and EN_NAME = 'H103') 2014-09-22 22:21:55 CEST:yy@xx1:[11039] LOG: duration: 0.096 ms parse <unnamed>: update AEL_XT_DATA set NUM_OF_SBO = 31121, STATE = 0, PROGRESS = 0, LOCK_KEY = null where (AEL_ID = 15 and EN_NAME = 'H103') 2014-09-22 22:21:55 CEST:yy@xx1:[11039] LOG: duration: 0.199 ms bind <unnamed>: update AEL_XT_DATA set NUM_OF_SBO = 31121, STATE = 0, PROGRESS = 0, LOCK_KEY = null where (AEL_ID = 15 and EN_NAME = 'H103') 2014-09-22 22:21:55 CEST:yy@xx1:[11039] LOG: duration: 0.092 ms execute <unnamed>: update AEL_XT_DATA set NUM_OF_SBO = 31121, STATE = 0, PROGRESS = 0, LOCK_KEY = null where (AEL_ID = 15 and EN_NAME = 'H103') 2014-09-22 22:21:55 CEST:yy@xx1:[11039] LOG: duration: 0.011 ms bind S_3: COMMIT 2014-09-22 22:21:55 CEST:yy@xx1:[11039] LOG: duration: 7.775 ms execute S_3: COMMIT 2014-09-22 22:21:55 CEST:yy@xx1:[6973] LOG: duration: 0.014 ms bind S_2: ROLLBACK 2014-09-22 22:21:55 CEST:yy@xx1:[6973] LOG: duration: 0.014 ms execute S_2: ROLLBACK affected data structures: xx1=> \d aeldata Table "public.aeldata" Column | Type | Modifiers ----------------+------------------------+----------- ael_id | numeric(10,0) | not null sbo_grp | character varying(6) | not null ael_name | character varying(30) | not null remark | character varying(200) | mc_id | numeric(4,0) | owner | character varying(30) | lock_key | numeric(10,0) | lock_column | numeric(1,0) | default_ael | numeric(1,0) | Indexes: "aeldata_pkey" PRIMARY KEY, btree (ael_id) "default_ael_uk" UNIQUE CONSTRAINT, btree (default_ael) "uk_ael_name" UNIQUE CONSTRAINT, btree (ael_name) "uk_sbo_grp" UNIQUE CONSTRAINT, btree (sbo_grp) "idx_aeldata_mcid" btree (mc_id) Foreign-key constraints: "ael_mc_id_fk" FOREIGN KEY (mc_id) REFERENCES mcdata(mc_id) Referenced by: TABLE "alarm_table" CONSTRAINT "alarm_table_ael_fk" FOREIGN KEY (ael_id) REFERENCES aeldata(ael_id) TABLE "ul_bulk_operation_data" CONSTRAINT "bulk_operation_data_ael_id_fk" FOREIGN KEY (ael_id) REFERENCES aeldata(ael_id) TABLE "ul_job_data" CONSTRAINT "fkey_ael_id" FOREIGN KEY (ael_id) REFERENCES aeldata(ael_id) TABLE "ael_groups" CONSTRAINT "fkey_lg_ael_id" FOREIGN KEY (ael_id) REFERENCES aeldata(ael_id) TABLE "ael_esd" CONSTRAINT "ael_esd_fk" FOREIGN KEY (ael_id) REFERENCES aeldata(ael_id) TABLE "ael_que" CONSTRAINT "ael_que_aelid_fk" FOREIGN KEY (ael_id) REFERENCES aeldata(ael_id) TABLE "ael_awai" CONSTRAINT "ael_awai_aelid_fk" FOREIGN KEY (ael_id) REFERENCES aeldata(ael_id) TABLE "ael_xt_data" CONSTRAINT "ael_id_key" FOREIGN KEY (ael_id) REFERENCES aeldata(ael_id) TABLE "ael_noacc" CONSTRAINT "ael_noacc_ael_fk" FOREIGN KEY (ael_id) REFERENCES aeldata(ael_id) ON DELETE CASCADE TABLE "ael_traffic" CONSTRAINT "ael_traffic_ael_fk" FOREIGN KEY (ael_id) REFERENCES aeldata(ael_id) ON DELETE CASCADE TABLE "ul_recs" CONSTRAINT "ul_recs_ael_fk" FOREIGN KEY (ael_id) REFERENCES aeldata(ael_id) xx1=> \d+ ael_xt_data_view View "public.ael_xt_data_view" Column | Type | Modifiers | Storage | Description -------------+-------------------------+-----------+----------+------------- sbo_grp | character varying(6) | | extended | ael_name | character varying(30) | | extended | en_name | character varying(40) | | extended | sbo_key | character varying(20) | | extended | num_of_sbo | numeric | | main | ael_en_lock | numeric(10,0) | | main | ael_state | numeric(3,0) | | main | job_id | character varying(32) | | extended | state | numeric(1,0) | | main | progress | numeric(1,0) | | main | lock_key | numeric(10,0) | | main | ael_id | numeric(10,0) | | main | View definition: SELECT aeldata.sbo_grp, aeldata.ael_name, ael_xt_data.en_name, ael_xt_data.sbo_key, ael_xt_data.num_of_sbo, ael_xt_data.ael_en_lock, ael_xt_data.ael_state, ael_xt_data.job_id, ael_xt_data.state, ael_xt_data.progress, ael_xt_data.lock_key, ael_xt_data.ael_id FROM ael_xt_data, aeldata WHERE aeldata.ael_id = ael_xt_data.ael_id; Rules: ael_xt_data_view_ir AS ON INSERT TO ael_xt_data_view DO INSTEAD INSERT INTO ael_xt_data (en_name, sbo_key, ael_id, num_of_sbo, ael_en_lock, ael_state, job_id) VALUES (new.en_name, new.sbo_key, gf_proc.get_aelid_sbo(new.sbo_grp), new.num_of_sbo, new.ael_en_lock, new.ael_state, new.job_id) ael_xt_data_view_ud AS ON DELETE TO ael_xt_data_view DO INSTEAD DELETE FROM ael_xt_data WHERE ael_xt_data.ael_id = gf_proc.get_aelid_sbo(old.sbo_grp) AND ael_xt_data.en_name::text = old.en_name::text ael_xt_data_view_ur AS ON UPDATE TO ael_xt_data_view DO INSTEAD UPDATE ael_xt_data SET en_name = new.en_name, sbo_key = new.sbo_key, ael_id = gf_proc.get_aelid_sbo(new.sbo_grp), num_of_sbo = new.num_of_sbo, ael_en_lock = new.ael_en_lock, ael_state = new.ael_state, job_id = new.job_id WHERE ael_xt_data.ael_id = gf_proc.get_aelid_sbo(old.sbo_grp) AND ael_xt_data.en_name::text = old.en_name::text xx1=> \d ael_xt_data Table "public.ael_xt_data" Column | Type | Modifiers -------------+-------------------------+-------------- ael_id | numeric(10,0) | not null en_name | character varying(40) | not null sbo_key | character varying(20) | num_of_sbo | numeric | ael_en_lock | numeric(10,0) | ael_state | numeric(3,0) | default (-8) job_id | character varying(32) | state | numeric(1,0) | progress | numeric(1,0) | lock_key | numeric(10,0) | Indexes: "ael_xt_data_key" PRIMARY KEY, btree (ael_id, en_name) "idx_aelxtdata_nename" btree (en_name) Foreign-key constraints: "ael_ad_en_name" FOREIGN KEY (en_name) REFERENCES en_names(en_name) "ael_id_key" FOREIGN KEY (ael_id) REFERENCES aeldata(ael_id)