PostgreSQL exceptionally slow parsing of extremely short queries

Question

I'm using Zend Framework (PHP) and postgresql as the session storage backend. Sometimes I'm getting tons of logs like this:

Mar  8 11:07:00 myhost postgres[79149]: [30640132-1] 0 LOG:  00000: duration: 1401.742 ms  parse pdo_stmt_00000005: SELECT "sessions".* FROM "php"."sessions" WHERE ((("sessions"."id" = '3d5tmqutaeuivtf8a1udfa5i04')))
Mar  8 11:07:00 myhost postgres[79150]: [30640151-1] 0 LOG:  00000: duration: 1400.083 ms  parse pdo_stmt_00000007: SELECT "sessions".* FROM "php"."sessions" WHERE ((("sessions"."id" = 'b2vh1r29vnqg1e3600ther40c3')))
Mar  8 11:07:00 myhost postgres[79152]: [30640135-1] 0 LOG:  00000: duration: 1401.261 ms  parse pdo_stmt_00000005: SELECT "sessions".* FROM "php"."sessions" WHERE ((("sessions"."id" = '3d5tmqutaeuivtf8a1udfa5i04')))
Mar  8 11:07:00 myhost postgres[79147]: [30640166-1] 0 LOG:  00000: duration: 1381.648 ms  parse pdo_stmt_00000009: SELECT "sessions".* FROM "php"."sessions" WHERE ((("sessions"."id" = '6uj0955g64mmd9i8ra1q5nbtd5')))

Table php.sessions has about 500-1000 rows at any moment.

It seems strange, as the execution of this statement was not logged as slow, but the parsing is almost "endless".

Any clue? Does anyone know of any postgres query parser speed issues?

Some tech background:

I'm using PostgreSQL 8.4.9 on CentOS 6.0, It's 2x 10Core Intel machine with 128 GB RAM. Cpu is was used only 20% - 25% at this very time. Disk reads/writes are extremely fast. log_min_statement = 500

Answer 1

This case appeared to be: lots of long idle'ing transactions, i.e. <IDLE> in transaction. We've managed to get rid of most of them. And the result is outstanding.

The main reason sadly occured to be flawed application logic. I mean that part of the transactions looked like:

• begin
• query
• query
• wait
• ... (lots of waiting)
• wait
• commit

As the row versioning subsystem has had to keep lots of old versions of the rows, the system has been becoming less and less responsive (each simple query has had to look for appropriate row versions).