While investigating some performance issues I have been looking at slow
queries logged to the postgresql.log file. A strange thing that I have
seen is a series of apparently very slow queries that just select from a
sequence. It is as if access to a sequence is blocked for many sessions and
then released as I get log entries like this appearing:
LOG: duration: 23702.553 ms execute <unnamed>: /* dynamic native SQL
query */ select nextval ('my_sequence') as nextval
LOG: duration: 23673.068 ms execute <unnamed>: /* dynamic native SQL
query */ select nextval ('my_sequence') as nextval
LOG: duration: 23632.729 ms execute <unnamed>: /* dynamic native SQL
query */ select nextval ('my_sequence') as nextval
....(Many similar lines)....
LOG: duration: 3055.057 ms execute <unnamed>: /* dynamic native SQL query
*/ select nextval ('my_sequence') as nextval
LOG: duration: 2377.621 ms execute <unnamed>: /* dynamic native SQL query
*/ select nextval ('my_sequence') as nextval
LOG: duration: 743.732 ms execute <unnamed>: /* dynamic native SQL query
*/ select nextval ('my_sequence') as nextval
The code is being executed via Hibernate, but using
Session.createSQLQuery(), so the SQL above appears in the source as above
(minus the comment) and not as part of any ORM magic. We are using
Postgresql 9.0.
This seems very strange to me. What could cause a sequence to be locked for
such a long time?
The sequence in question has cache set at 1. Would setting this higher make
any difference?
Thanks
Chris
