CODEWITHSUNDEEP
parsingpostgresqlloggingperformance
krawiec.a
krawiec.a

Reputation: 61

PostgreSQL exceptionally slow parsing of extremely short queries

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

Upvotes: 3

Views: 2940

Answers (2)

krawiec.a
krawiec.a

Reputation: 61

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).

Upvotes: 3

vyegorov
vyegorov

Reputation: 22895

I have similar situation on a test box in cases when:

  • CPU-heavy processes are run on the server;
  • Systems starts swapping out RAM onto disks for RAM-intensive processes.

PostgreSQL relies on 2 layers of data caches:

  1. shared pool, specified via shared_buffers;
  2. OS cache, specified via effective_cache_size, could you tell us what's your value here, please?

In order to understand what is really going on your system, you should monitor:

  • CPU usage;
  • RAM usage;
  • IO and swap volumes.

By monitor I mean not just looking at the current values, but rather using tools like sar, iostat, vmstat and alike, combined with, say, RRDtool for better data analysis. And then review produced reports for time period you observe unwanted delays in simple queries.

I have a feeling that you are having IO issues, but cannot tell more without looking at the system and reports.

I would recommend:

  1. Setup monitoring and review produced reports;
  2. Create a Standby database on a similar box in order to play around with different settings. (I assume you have proper database and WAL backups to do that.) I would look into: memory, autovacuum, checkpoints and WAL settings.
  3. Consider upgrading to the PostgreSQL 9.1, you're 2 major releases behind.

Upvotes: 0

Related Questions