I have a performance riddle, hoping someone can point me in a
helpful direction. We have a pg 8.1.2 cluster using
Apache::Sessions and experiencing simple UPDATEs taking
sometimes 30+ seconds to do a very simply update, no foreign
keys, no triggers:
Table "public.sessions"
Column | Type | Modifiers
-----------+---------------+-----------
id | character(32) | not null
a_session | text |
Indexes:
"sessions_pkey" PRIMARY KEY, btree (id)
This is on an HP ia64 11.23 box with what appears to be gobs of
surplus CPU, I/O (it's on a SAN), and RAM, pretty high query
volume from 180 concurrent client connections.
Wondering if it is a locking issue, I set up logging to capture
existing locks every 10s with this query:
SELECT now(), dbu.usename as locker, l.mode as locktype, CASE
l.granted WHEN true THEN 'granted' ELSE 'pending' END as status,
pg_stat_get_backend_pid(S.backendid)
as pid, l.transaction as xid, db.datname||'.'||n.nspname||'.'||
r.relname as relation, case l.mode when 'AccessShareLock' then 1
when 'RowShareLock' then 2 when 'Row
ExclusiveLock' then 3 when 'ShareUpdateExclusiveLock' then 4 when
'ShareLock' then 5 when 'ShareRowExclusiveLock' then 6 when
'ExclusiveLock' then 7 else 100 end as
exclusivity, pg_stat_get_backend_activity(S.backendid) as query
FROM pg_user dbu,
(SELECT pg_stat_get_backend_idset() AS backendid) AS S,
pg_database db, pg_locks l, pg_class r, pg_namespace n
WHERE db.oid = pg_stat_get_backend_dbid(S.backendid)
AND dbu.usesysid = pg_stat_get_backend_userid(S.backendid)
AND l.pid = pg_stat_get_backend_pid(S.backendid)
AND l.relation = r.oid
AND l.database = db.oid
AND r.relnamespace = n.oid
ORDER BY exclusivity DESC, db.datname, n.nspname, r.relname,
l.mode;"
I see what appear to be many single transactions holding
RowExclusiveLocks for sometimes 40-50 seconds while their query
shows "<IDLE> in transaction".
2006-03-25 20:04:01.063873-08 | www | RowExclusiveLock | granted
| 17192 | 270205914 | db1.public.sessions | 3 | <IDLE>
in transaction
2006-03-25 20:04:11.128632-08 | www | RowExclusiveLock | granted
| 17192 | 270205914 | db1.public.sessions | 3
| <IDLE> in transaction
2006-03-25 20:04:21.215896-08 | www | RowExclusiveLock | granted
| 17192 | 270205914 | db1.public.sessions | 3
| <IDLE> in transaction
I'm thinking that means the client is simply tweaking a row and
then failing to commit the change for 40-50 seconds. Is that
consistent? Is there something else obvious here to explain the
delays? Does this sound like a browser stop button issue where
they may be aborting the query that has the lock, and then
issuing another that waits on the first? Other suggestions?
Thanks,
Ed
