Subject: SELECT FOR UPDATE performance is bad
From: Mario Splivalo <mario.splivalo@mobart.hr>
Reply-To: mario.splivalo@mobart.hr
To: Pgsql performance <pgsql-performance@postgresql.org>
Content-Type: text/plain
Organization: Mob-Art
Date: Tue, 18 Apr 2006 15:08:39 +0200
Message-Id: <1145365720.18469.35.camel@localhost.localdomain>
Mime-Version: 1.0
Content-Transfer-Encoding: 7bit

For the purpose of the application I need to establish some form of
serialization, therefore I use FOR UPDATE. The query, inside the
function, is like this:

pulitzer2=# explain analyze select id FROM messages JOIN
ticketing_codes_played ON id = message_id WHERE service_id = 1102 AND
receiving_time BETWEEN '2006-03-01' AND '2006-06-30' FOR UPDATE;

QUERY PLAN 
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Hash Join  (cost=32131.04..34281.86 rows=627 width=16) (actual
time=742.806..1491.864 rows=58005 loops=1)
   Hash Cond: ("outer".message_id = "inner".id)
   ->  Seq Scan on ticketing_codes_played  (cost=0.00..857.17 rows=57217
width=10) (actual time=0.024..209.331 rows=58005 loops=1)
   ->  Hash  (cost=32090.60..32090.60 rows=16177 width=10) (actual
time=742.601..742.601 rows=65596 loops=1)
         ->  Bitmap Heap Scan on messages  (cost=4153.51..32090.60
rows=16177 width=10) (actual time=160.555..489.459 rows=65596 loops=1)
               Recheck Cond: ((service_id = 1102) AND (receiving_time >=
'2006-03-01 00:00:00+01'::timestamp with time zone) AND (receiving_time
<= '2006-06-30 00:00:00+02'::timestamp with time zone))
               ->  BitmapAnd  (cost=4153.51..4153.51 rows=16177 width=0)
(actual time=156.900..156.900 rows=0 loops=1)
                     ->  Bitmap Index Scan on idx_service_id
(cost=0.00..469.31 rows=68945 width=0) (actual time=16.661..16.661
rows=66492 loops=1)
                           Index Cond: (service_id = 1102)
                     ->  Bitmap Index Scan on
idx_messages_receiving_time  (cost=0.00..3683.95 rows=346659 width=0)
(actual time=137.526..137.526 rows=360754 loops=1)
                           Index Cond: ((receiving_time >= '2006-03-01
00:00:00+01'::timestamp with time zone) AND (receiving_time <=
'2006-06-30 00:00:00+02'::timestamp with time zone))
 Total runtime: 6401.954 ms
(12 rows)


Now, this query takes between 8 and 30 seconds, wich is a lot, since
during the day we have almost 20 requests per minute. I notice that
during the execution of the above mentioned query i/o goes bezerk,
iostat tells me that load is around 60%. I tried playing with WAL
configuration parametars, even put the log on separate disk spindles, it
did nothing.

Shall I reconsider the need for the exact lock I developed, or there is
something more I could do to speed the things up?

	Mario
-- 
Mario Splivalo
Mob-Art
mario.splivalo@mobart.hr

"I can do it quick, I can do it cheap, I can do it well. Pick any two."