Search Postgresql Archives

deadlock of lock-waits (on transaction and on tuple) using same update statement

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



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 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)


[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
[Index of Archives]     [Postgresql Jobs]     [Postgresql Admin]     [Postgresql Performance]     [Linux Clusters]     [PHP Home]     [PHP on Windows]     [Kernel Newbies]     [PHP Classes]     [PHP Books]     [PHP Databases]     [Postgresql & PHP]     [Yosemite]
  Powered by Linux