On 29 June 2016 at 14:45, Kevin Grittner <kgrittn@gmail.com> wrote:
> Please monitor for the start of such an event and capture the full
> contents of pg_stat_activity and pg_locks during that 2 minute
> window.
I had already looked at that manually and found nothing unusual. To be more
thorough, I now had a batch file log the contents of pg_stat_activity and
pg_locks every 5 seconds.
During my test run, there was one offending query invocation, a simple
SELECT * FROM job WHERE field = $1
Of course the actual query specified the list of fields as it was generated
by Hibernate, but that is what it boils down to - no joins etc. The column on
which was queried is a VARCHAR(64) NOT NULL, not unique nor indexed (though
in practice most values are unique).
I can of course post the full output somewhere if you want (though it's more
than 1000 lines). In the meantime, here is what I can gather from the output
for these 2 minutes:
1) Looking at the logged pg_stat_activity data, there usually is only one
other query executing: the select * from pg_stat_activity itself. Sometimes
there's another query or a connection idle in transaction (which disappears
again in the next output from pg_stat_activity), but given the volume of
queries that's executed this seems expected.
2) Looking at pg_locks, the only locks that are consistently held throughout
those 2 minutes are these 5:
- the locks held by the slow query itself: an AccessShareLock on the job
table, and a virtualxid ExclusiveLock (the query does not happen within a
transaction).
- the advisory lock for the job this thread is processing
- locks held by the SELECT * FROM pg_locks query (a lock on the pg_locks
table and a virtualxid lock)
These 5 locks are of course all granted. Other locks change every 5 seconds,
and often no other locks are held at all.
Best regards,
Roel