deadlock in postgres on simple update query

Question

I'm working with postgres 9.1 and getting deadlock exception under excessive execution of a simple update method.

According to the logs the deadlock occurs due to execution of two identical updates at the same time.

update public.vm_action_info set last_on_demand_task_id=$1, version=version+1

How does two identical simple updates can deadlock each other ?

The error that I'm getting in the log

2013-08-18 11:00:24 IDT HINT:  See server log for query details.
2013-08-18 11:00:24 IDT STATEMENT:  update public.vm_action_info set last_on_demand_task_id=$1, version=version+1 where id=$2
2013-08-18 11:00:25 IDT ERROR:  deadlock detected
2013-08-18 11:00:25 IDT DETAIL:  Process 31533 waits for ShareLock on transaction 4228275; blocked by process 31530.
        Process 31530 waits for ExclusiveLock on tuple (0,68) of relation 70337 of database 69205; blocked by process 31533.
        Process 31533: update public.vm_action_info set last_on_demand_task_id=$1, version=version+1 where id=$2
        Process 31530: update public.vm_action_info set last_on_demand_task_id=$1, version=version+1 where id=$2
2013-08-18 11:00:25 IDT HINT:  See server log for query details.
2013-08-18 11:00:25 IDT STATEMENT:  update public.vm_action_info set last_on_demand_task_id=$1, version=version+1 where id=$2
2013-08-18 11:00:25 IDT ERROR:  deadlock detected
2013-08-18 11:00:25 IDT DETAIL:  Process 31530 waits for ExclusiveLock on tuple (0,68) of relation 70337 of database 69205; blocked by process 31876.
        Process 31876 waits for ShareLock on transaction 4228275; blocked by process 31530.
        Process 31530: update public.vm_action_info set last_on_demand_task_id=$1, version=version+1 where id=$2
        Process 31876: update public.vm_action_info set last_on_demand_task_id=$1, version=version+1 where id=$2

the schema is:

CREATE TABLE vm_action_info(
  id integer NOT NULL,
  version integer NOT NULL DEFAULT 0,
  vm_info_id integer NOT NULL,
 last_exit_code integer,
  bundle_action_id integer NOT NULL,
  last_result_change_time numeric NOT NULL,
  last_completed_vm_task_id integer,
  last_on_demand_task_id bigint,
  CONSTRAINT vm_action_info_pkey PRIMARY KEY (id ),
  CONSTRAINT vm_action_info_bundle_action_id_fk FOREIGN KEY (bundle_action_id)
      REFERENCES bundle_action (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE CASCADE,
  CONSTRAINT vm_discovery_info_fk FOREIGN KEY (vm_info_id)
      REFERENCES vm_info (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE CASCADE,
  CONSTRAINT vm_task_last_on_demand_task_fk FOREIGN KEY (last_on_demand_task_id)
      REFERENCES vm_task (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE NO ACTION,

  CONSTRAINT vm_task_last_task_fk FOREIGN KEY (last_completed_vm_task_id)
      REFERENCES vm_task (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE NO ACTION
)
WITH (OIDS=FALSE);

ALTER TABLE vm_action_info
  OWNER TO vadm;

-- Index: vm_action_info_vm_info_id_index

-- DROP INDEX vm_action_info_vm_info_id_index;

CREATE INDEX vm_action_info_vm_info_id_index
  ON vm_action_info
  USING btree (vm_info_id );

CREATE TABLE vm_task
(
  id integer NOT NULL,
  version integer NOT NULL DEFAULT 0,
  vm_action_info_id integer NOT NULL,
  creation_time numeric NOT NULL DEFAULT 0,
  task_state text NOT NULL,
  triggered_by text NOT NULL,
  bundle_param_revision bigint NOT NULL DEFAULT 0,
  execution_time bigint,
  expiration_time bigint,
  username text,
  completion_time bigint,
  completion_status text,
  completion_error text,
  CONSTRAINT vm_task_pkey PRIMARY KEY (id ),
  CONSTRAINT vm_action_info_fk FOREIGN KEY (vm_action_info_id)
  REFERENCES vm_action_info (id) MATCH SIMPLE
  ON UPDATE NO ACTION ON DELETE CASCADE
)
 WITH (
OIDS=FALSE
);
ALTER TABLE vm_task
  OWNER TO vadm;

-- Index: vm_task_creation_time_index

-- DROP INDEX vm_task_creation_time_index     ;

CREATE INDEX vm_task_creation_time_index
  ON vm_task
  USING btree
 (creation_time );

Answer 1

My guess is that the source of the problem is a circular foreign key reference in your tables.

TABLE vm_action_info
==> FOREIGN KEY (last_completed_vm_task_id) REFERENCES vm_task (id)

TABLE vm_task
==> FOREIGN KEY (vm_action_info_id) REFERENCES vm_action_info (id)

The transaction consists of two steps:

1. add a new entry to task table
2. updates corresponding entry in vm_action_info the vm_task table.

When two transactions are going to update the same record in the vm_action_info table at the same time, this will finish with a deadlock.

Look at simple test case:

CREATE TABLE vm_task
(
  id integer NOT NULL,
  version integer NOT NULL DEFAULT 0,
  vm_action_info_id integer NOT NULL,
  CONSTRAINT vm_task_pkey PRIMARY KEY (id )
)
 WITH ( OIDS=FALSE );

 insert into vm_task values 
 ( 0, 0, 0 ), ( 1, 1, 1 ), ( 2, 2, 2 );

CREATE TABLE vm_action_info(
  id integer NOT NULL,
  version integer NOT NULL DEFAULT 0,
  last_on_demand_task_id bigint,
  CONSTRAINT vm_action_info_pkey PRIMARY KEY (id )
)
WITH (OIDS=FALSE);
insert into vm_action_info values 
 ( 0, 0, 0 ), ( 1, 1, 1 ), ( 2, 2, 2 );

alter table vm_task
add  CONSTRAINT vm_action_info_fk FOREIGN KEY (vm_action_info_id)
  REFERENCES vm_action_info (id) MATCH SIMPLE
  ON UPDATE NO ACTION ON DELETE CASCADE
  ;
Alter table vm_action_info
 add CONSTRAINT vm_task_last_on_demand_task_fk FOREIGN KEY (last_on_demand_task_id)
      REFERENCES vm_task (id) MATCH SIMPLE
      ON UPDATE NO ACTION ON DELETE NO ACTION
      ;

In session 1 we add a record to vm_task that reference to id=2 in vm_action_info

session1=> begin;
BEGIN
session1=> insert into vm_task values( 100, 0, 2 );
INSERT 0 1
session1=>

At the same time in session 2 an another transaction begins:

session2=> begin;
BEGIN
session2=> insert into vm_task values( 200, 0, 2 );
INSERT 0 1
session2=>

Then the 1st transaction performs the update:

session1=> update vm_action_info set last_on_demand_task_id=100, version=version+1
session1=> where id=2;

but this command hangs and is waiting for a lock.....

then the 2nd session performs the update ........

session2=> update vm_action_info set last_on_demand_task_id=200, version=version+1 where id=2;
BŁĄD:  wykryto zakleszczenie
SZCZEGÓŁY:  Proces 9384 oczekuje na ExclusiveLock na krotka (0,5) relacji 33083 bazy danych 16393; zablokowany przez 380
8.
Proces 3808 oczekuje na ShareLock na transakcja 976; zablokowany przez 9384.
PODPOWIEDŹ:  Przejrzyj dziennik serwera by znaleźć szczegóły zapytania.
session2=>

Deadlock detected !!!

This is because both INSERTs into vm_task place a shared lock on row id=2 in the vm_action_info table due to the foreign key reference. Then the first update tries to place a write lock on this row and hangs because the row is locked by another (second) transaction. Then the second update tries to lock the same record in write mode, but it is locked in shared mode by the first transaction. And this cause a deadlock.

I think that this can be avoided if you place a write lock on record in vm_action_info, the whole transaction has to consist of 5 steps:

 begin;
 select * from vm_action_info where id=2 for update;
 insert into vm_task values( 100, 0, 2 );
 update vm_action_info set last_on_demand_task_id=100, 
         version=version+1 where id=2;
 commit;

Answer 2

It may just be that your system was exceptionally busy. You say you've only seen this with "excessive execution" of the query.

What appears to be the situation is this:

pid=31530 wants to lock tuple (0,68) on rel 70337 (vm_action_info I suspect) for update
    it is waiting behind pid=31533, pid=31876
pid=31533 is waiting behind transaction 4228275
pid=31876 is waiting behind transaction 4228275

So - we have what seems to be four transactions all updating this row at the same time. Transaction 4228275 hasn't committed or rolled back yet and is holding the others up. Two of them have been waiting for deadlock_timeout seconds otherwise we'd not see the timeout. Timout expires, deadlock detector takes a look, sees a bunch of intertwined transactions and cancels one of them. Might not strictly be a deadlock, but I'm not sure if the detector is smart enough to figure that out.

Try one of:

1. Reduce the rate of updates
2. Get a faster server
3. Increase deadlock_timeout

Probably #3 is the simplest :-) Might want to set log_lock_waits too so you can see if/when your system is under this sort of strain.