Re: how could select id=xx so slow?

I didn't set log_min_duration_statement in the postgresql.conf, but execute

dbapi_con.cursor().execute("SET log_min_duration_statement to 30")

for every connection.

OK, same effect: You're only logging slow statements.

It's not at all surprising that BEGIN doesn't appear when a log_min_duration_statement is set. It's an incredibly fast operation. What's amazing is that it appears even once - that means your database must be in serious performance trouble, as BEGIN should take tenths of a millisecond on an unloaded system. For example my quick test here:

LOG:  statement: BEGIN;
LOG:  duration: 0.193 ms

... which is actually a lot slower than I expected, but hardly slow statement material.

The frequent appearance of slow (multi-second) COMMIT statements in your slow statement logs suggests there's enough load on your database that there's real contention for disk, and/or that checkpoints are stalling transactions.


First, you need to set log_min_messages = 'info' to allow Pg to complain about things like checkpoint frequency.

Now temporarily set log_checkpoints = on to record when checkpoints happen and how long they take. Most likely you'll find you need to tune checkpoint behaviour. Some information, albeit old, on that is here:

  http://www.westnet.com/~gsmith/content/postgresql/chkp-bgw-83.htm

Basically you might want to try increasing your checkpoint_completion_target and making the bgwriter more aggressive - assuming that your performance issues are in fact checkpoint related.

It's also possible that they're just overall load, especially if you have lots and lots (hundreds) of connections to the database all trying to do work at once without any kind of admission control or pooling/queuing. In that case, introducing a connection pool like PgBouncer may help.

--
Craig Ringer