Thread: lock contention, need profiling idea
I see lots of similar log message at a certain time in a day on Postgresql 9,.1:
LOG: process 18855 still waiting for ShareLock on transaction 2856146023 after 1001.209 ms
STATEMENT: UPDATE table1 SET time = $1 WHERE id = $2
The table1 size is 17 G.
What could be the reason for this lock contention?
autovacuum?
Please give some idea.
Thanks.
On Tue, Jul 1, 2014 at 7:36 AM, AI Rumman <rummandba@gmail.com> wrote:
-- I see lots of similar log message at a certain time in a day on Postgresql 9,.1:LOG: process 18855 still waiting for ShareLock on transaction 2856146023 after 1001.209 msSTATEMENT: UPDATE table1 SET time = $1 WHERE id = $2The table1 size is 17 G.What could be the reason for this lock contention?autovacuum?
This may be a CREATE INDEX query taking some time, perhaps combined with an old prepared transaction still holding a lock? Perhaps a cron job running behind that you are not aware of?
You should have a look at pg_stat_activity, pg_prepared_xacts and pg_locks to get more information about the transactions running and the locks being taken.
Michael
There was no CREATE INDEX command running on the host.
On Mon, Jun 30, 2014 at 5:06 PM, Michael Paquier <michael.paquier@gmail.com> wrote:
--On Tue, Jul 1, 2014 at 7:36 AM, AI Rumman <rummandba@gmail.com> wrote:I see lots of similar log message at a certain time in a day on Postgresql 9,.1:LOG: process 18855 still waiting for ShareLock on transaction 2856146023 after 1001.209 msSTATEMENT: UPDATE table1 SET time = $1 WHERE id = $2The table1 size is 17 G.What could be the reason for this lock contention?autovacuum?This may be a CREATE INDEX query taking some time, perhaps combined with an old prepared transaction still holding a lock? Perhaps a cron job running behind that you are not aware of?You should have a look at pg_stat_activity, pg_prepared_xacts and pg_locks to get more information about the transactions running and the locks being taken.
Michael
On Mon, Jun 30, 2014 at 5:36 PM, AI Rumman <rummandba@gmail.com> wrote: > I see lots of similar log message at a certain time in a day on Postgresql > 9,.1: > > LOG: process 18855 still waiting for ShareLock on transaction 2856146023 > after 1001.209 ms > STATEMENT: UPDATE table1 SET time = $1 WHERE id = $2 > > The table1 size is 17 G. > > What could be the reason for this lock contention? > autovacuum? > > Please give some idea. Query pg_stat_activity and pg_locks on intervals and you'll get to the bottom of this. merlin
On Mon, Jun 30, 2014 at 5:06 PM, Michael Paquier <michael.paquier@gmail.com> wrote: > On Tue, Jul 1, 2014 at 7:36 AM, AI Rumman <rummandba@gmail.com> wrote: >> >> I see lots of similar log message at a certain time in a day on Postgresql >> 9,.1: >> >> LOG: process 18855 still waiting for ShareLock on transaction 2856146023 >> after 1001.209 ms >> STATEMENT: UPDATE table1 SET time = $1 WHERE id = $2 >> >> The table1 size is 17 G. >> >> What could be the reason for this lock contention? >> autovacuum? > > This may be a CREATE INDEX query taking some time, perhaps combined with an > old prepared transaction still holding a lock? Perhaps a cron job running > behind that you are not aware of? Wouldn't that be waiting on the table, not the transaction? I think transaction lock waits are (almost?) always due to tuples, so "FOR UPDATE", UPDATE, etc. > You should have a look at pg_stat_activity, pg_prepared_xacts and pg_locks > to get more information about the transactions running and the locks being > taken. In 9.4, the log message will also include info on the blocking process, not just the blocked process, for lock waits. But until then, pg_stat_activity and pg_locks are the best bet. Unless you can afford to turn log_statement to 'all' and dig through the resulting mess. Cheers, Jeff
On Tue, Jul 1, 2014 at 2:28 PM, Jeff Janes <jeff.janes@gmail.com> wrote: >> You should have a look at pg_stat_activity, pg_prepared_xacts and pg_locks >> to get more information about the transactions running and the locks being >> taken. > > In 9.4, the log message will also include info on the blocking > process, not just the blocked process, for lock waits. > > But until then, pg_stat_activity and pg_locks are the best bet. > Unless you can afford to turn log_statement to 'all' and dig through > the resulting mess. log_min_duration_statement might be a middle ground -- set it to 1 second plus. on most applications this should cut out most of the chaff. merlin