Concise summary query for pg_stat_statements

February 4, 2013

PostgreSQL 9.2 made the pg_stat_statements module a heck of a lot more useful now that it does query normalization. See the documentation for how to set the module up, as it is totally worth it if you are trying to track down the slow database queries in your application.

This is my goto query for finding statements worth optimizing. In the months I’ve been giving this a go, I’ve been able to quickly pinpoint the queries causing the most delay in returning data without being overwhelmed by one-off reporting queries.

SELECT rolname,
	calls,
	round(total_time::numeric, 1) AS total,
	round((total_time / calls)::numeric, 3) AS per_call,
	rows,
	regexp_replace(query, '[ \t\n]+', ' ', 'g') AS query_text
FROM pg_stat_statements
JOIN pg_roles r ON r.oid = userid
WHERE calls > 100
AND rolname NOT LIKE '%backup'
ORDER BY total_time / calls DESC
LIMIT 15;

The beauty of this query:

Query text is normalized by coalescing whitespace
Total time and per-call time are immediately obvious
Don’t show uncommon queries that may skew the results
Shows how to exclude things from a backup-type user if you have one

So it doesn’t overwhelm the width of this blog, I’ve posted a small sample snippet below of what you can expect to see. This particular snippet comes from the Archweb production database.

 rolname | calls |  total  | per_call |  rows  |                                                         query_text                                                          
---------+-------+---------+----------+--------+-----------------------------------------------------------------------------------------------------------------------------
 archweb |   502 | 33855.9 |   67.442 |    502 | SELECT COUNT(*) FROM "packages" INNER JOIN "repos" ON ("packages"."repo_id" = "repos"."id") WHERE ("repos"."staging" =  ...
 archweb |   314 | 17271.0 |   55.003 |   5904 | SELECT "packages"."id", "packages"."repo_id", "packages"."arch_id", "packages"."pkgname", "packages"."pkgbase", "packag ...
 archweb |   298 |  5742.4 |   19.270 |    298 | SELECT COUNT(*) FROM "packages" INNER JOIN "repos" ON ("packages"."repo_id" = "repos"."id") WHERE "repos"."staging" = ? ...
 archweb |   114 |  2040.7 |   17.901 |     52 | SELECT "packages_update"."id", "packages_update"."package_id", "packages_update"."repo_id", "packages_update"."arch_id" ...
 archweb |   300 |  1882.5 |    6.275 |  27000 | SELECT "packages"."id", "packages"."repo_id", "packages"."arch_id", "packages"."pkgname", "packages"."pkgbase", "packag ...
 archweb |   287 |  1462.2 |    5.095 | 164563 | SELECT "package_files"."id", "package_files"."pkg_id", "package_files"."is_directory", "package_files"."directory", "pa ...
 archweb |   163 |   403.9 |    2.478 |   8150 | SELECT "packages"."id", "packages"."repo_id", "packages"."arch_id", "packages"."pkgname", "packages"."pkgbase", "packag ...
 archweb |   796 |  1442.5 |    1.812 |   9124 | SELECT "packages_depend"."id", "packages_depend"."name", "packages_depend"."version", "packages_depend"."pkg_id", "pack ...
 archweb |   380 |   488.8 |    1.286 |   1474 | SELECT DISTINCT "packages"."pkgname" FROM "packages" WHERE "packages"."pkgname"::text LIKE ? ORDER BY "packages"."pkgna ...
 archweb |  1026 |  1029.4 |    1.003 |  62586 | SELECT "auth_user"."id", "auth_user"."username", "auth_user"."first_name", "auth_user"."last_name", "auth_user"."email" ...
 archweb |   145 |   113.2 |    0.781 |    396 | SELECT "packages_depend"."id", "packages_depend"."name", "packages_depend"."version", "packages_depend"."pkg_id", "pack ...
 archweb |   110 |    84.4 |    0.767 |   5500 | SELECT DISTINCT "mirrors_mirrorurl"."country" FROM "mirrors_mirrorurl" INNER JOIN "mirrors_mirror" ON ("mirrors_mirroru ...
 archweb |   251 |   172.3 |    0.686 |    251 | SELECT "releng_release"."id", "releng_release"."release_date", "releng_release"."version", "releng_release"."kernel_ver ...
 archweb |   137 |    86.8 |    0.634 |    182 | SELECT DISTINCT "packages"."id", "packages"."repo_id", "packages"."arch_id", "packages"."pkgname", "packages"."pkgbase" ...
 archweb |   969 |   347.5 |    0.359 |    998 | SELECT "packages"."id", "packages"."repo_id", "packages"."arch_id", "packages"."pkgname", "packages"."pkgbase", "packag ...

My rule of thumb is somewhat as follows:

Queries over 100 ms/call are worth checking the EXPLAIN and EXPLAIN ANALYZE results for. Sometimes you’ll see it is doing a full sequential scan; indexes are your friend. Other times the fix is much more involved; see this optimization of required by lookup as an example that required adding a custom UNION ALL clause to a Django queryset.
Queries under 100 ms/call sometimes have room for optimization, but the fix isn’t always obvious.
Anything < 5 ms/call is usually not worth touching, unless you notice it seems to be called way too much (you’ll want to sort by calls or total instead). In that case, optimize it in the application.

toofishes.net

Concise summary query for pg_stat_statements

Tags

See Also