Advanced pg_stat_statements: Filtering, Regression Testing & more

Advanced pg_stat_statements: Filtering, Regression Testing & more

Talk on how we use pg_stat_statements at https://pganalyze.com/.

Lessons learned and introducing our pg_query library for parsing SQL queries.

27b304f67c0cadfa2f37a19f01af8f89?s=128

Lukas Fittl

March 26, 2015
Tweet

Transcript

  1. 4.

    Intro userid | 10 dbid | 1397527 query | SELECT

    * FROM x WHERE y = ? calls | 5 total_time | 15.249 rows | 0 shared_blks_hit | 451 shared_blks_read | 41 shared_blks_dirtied | 26 shared_blks_written | 0 local_blks_hit | 0 local_blks_read | 0 local_blks_dirtied | 0 local_blks_written | 0 temp_blks_read | 0 temp_blks_written | 0 blk_read_time | 0 blk_write_time | 0 pg_stat_statements
  2. 9.

    Intro SELECT * FROM pg_stat_statements LIMIT 1; userid | 10

    dbid | 17025 queryid | 1720234670 query | SELECT * FROM x WHERE y = ? calls | 14 total_time | 0.151 rows | 28 shared_blks_hit | 14 shared_blks_read | 0 shared_blks_dirtied | 0 shared_blks_written | 0 local_blks_hit | 0 local_blks_read | 0 local_blks_dirtied | 0 local_blks_written | 0 temp_blks_read | 0 temp_blks_written | 0 blk_read_time | 0 blk_write_time | 0
  3. 10.

    Intro queryid | 1720234670 query | SELECT * FROM x

    WHERE y = ? calls | 5 total_time | 15.249 Query + No. of Calls + Avg Time
  4. 11.

    Intro shared_blks_hit | 2447215 shared_blks_read | 55335 Avg. Shared Buffer

    Hit Rate: 97% hit_rate = shared_blks_hit / (shared_blks_hit + shared_blks_read)
  5. 15.

    Truncation (pre 9.4) SELECT "postgres_settings".* FROM "postgres_settings" WHERE "postgres_settings"."database_id" =

    $1 AND "postgres_settings"."invalidated_at_snapshot_id" IS NULL AND (id not in (70288,70289,70290,70291,70292,70293,70294,70295,70296,70297,70298 ,70299,70300,70301,70302,70303,70304,70305,70306,70307,70308,70309 ,70310,70311,70312,70313,70314,70315,70316,70317,70318,70319,70320 ,70321,70322,70323,70324,70325,70326,70327,99059,99060,70330,70331 ,70332,70333,70334,70335,70336,70337,70338,99061,70340,70341,70342 ,70343,70344,70345,70346,70347,70348,70349,70350,70351,70352,70353 ,70354,70355,70356,70357,70358,70359,70360,99062,70362,70363,70364 ,70365,70366,70367,70368,70369,70370,70371,70372,70373,70374,70375 ,70376,70377,70378,70379,70380,70381,70382,70383,70384,70385,70386 ,99063,99064,99065,99066,99067,70392,70393,70394,70395,70396,70397 ,70398,70399,70400,70401,70402,70403,70404,70405,99068,70407,70408 ,70409,70410,70411,70412,70413,70414,70415,70416,70417,99069,70419 ,70420,70421,99070,70423,70424,70425,70426,70427,70428, Improving Data Quality
  6. 16.

    Improving Data Quality Race Condition during pg_stat_statements_reset() -[ RECORD 1

    ]———+-------------------------------- query | SELECT * FROM x WHERE y = ? calls | 5 total_time | 15.249 -[ RECORD 2 ]———+-------------------------------- query | SELECT * FROM z WHERE a = 123 calls | 50 total_time | 104.19
  7. 18.

    Fingerprinting SELECT a, b FROM x SELECT b, a FROM

    x != SELECT a AS b SELECT a AS c == y IN (?, ?, ?) y IN (?, ?) != Problematic: Improving Data Quality DEALLOCATE p141 DEALLOCATE p150 !=
  8. 19.

    PostgreSQL 9.4 Improving Data Quality query | SELECT * FROM

    x WHERE y = ? query | SELECT * FROM x WHERE y = ? queryid | 2515120125
  9. 20.

    PostgreSQL 9.5 Improving Data Quality min_time | 0.25110 max_time |

    51.2103 mean_time | 10.2421 stddev_time | …
  10. 22.

    pg_stat_plans Improving Data Quality Unmaintained pg_s_s variant that differentiates between

    query plans. Don’t use it before this bug is fixed: https://github.com/2ndQuadrant/pg_stat_plans/issues/39
  11. 25.

    pg_query {“schema”: {“n_live_tup”: 75, "relpages": 1, "reltuples": 75.0,…}, “queries”: [{..},

    {..}]} Snapshot Monitoring Setup Production Database Collector {“schema”: {“n_live_tup”: 75, "relpages": 1, "reltuples": 75.0,…}, “queries”: [{..}, {..}]} Monitoring Database Parse Fingerprint Normalize Extract Tables
  12. 26.

    pg_query queries id | 7053479 database_id | 1 received_query |

    SELECT * FROM x WHERE y = ? normalized_query | SELECT * FROM x WHERE y = ? created_at | 2014-06-27 16:20:08.334705 updated_at | 2014-06-27 16:20:08.334705 parse_tree | [{"SELECT":{...}] parse_error | parse_warnings | statement_types | {SELECT} truncated | f fingerprint | 00704f1fd8442b7c17821cb8a61856c3d61b330e
  13. 27.

    pg_query query_snapshots id | 170661585 query_id | 7053479 calls |

    29 total_time | 94.38 rows | 29 snapshot_id | 3386118 id | 3386118 database_id | 408 collected_at | 2014-09-09 20:10:01 submitter | pganalyze-collector 0.6.1 query_source | pg_stat_statements snapshots
  14. 30.

    pg_query EXPLAIN (PARSETREE TRUE) SELECT * FROM x WHERE y

    = 1 ({SELECT :distinctClause <> :intoClause <> :targetList ( {RESTARGET :name <> :indirection <> :val {COLUMNREF :fields ({A_STAR}) :location 7} :location 7}) :fromClause ( {RANGEVAR :schemaname <> :relname x :inhOpt 2 :relpersistence p :alias <> :location 14}) :whereClause {AEXPR :name (“=") :lexpr {COLUMNREF :fields ("y") :location 22} :rexpr {PARAMREF :number 0 :location 26} :location 24} Unfortunately doesn’t exist.
  15. 32.

    pg_query tree = raw_parser(query_str); str = nodeToString(tree); printf(str); ({SELECT :distinctClause

    <> :intoClause <> :targetList ( {RESTARGET :name <> :indirection <> :val {COLUMNREF :fields ({A_STAR}) :location 7} :location 7}) :fromClause ( {RANGEVAR :schemaname <> :relname x :inhOpt 2 :relpersistence p :alias <> :location 14}) :whereClause {AEXPR :name (“=") :lexpr {COLUMNREF :fields ("y") :location 22} :rexpr {PARAMREF :number 0 :location 26} :location 24}
  16. 35.

    pg_query ({SELECT :distinctClause <> :intoClause <> :targetList ( {RESTARGET :name

    <> :indirection <> :val {COLUMNREF :fields ({A_STAR}) :location 7} :location 7}) :fromClause ( {RANGEVAR :schemaname <> :relname x :inhOpt 2 :relpersistence p :alias <> :location 14}) :whereClause {AEXPR :name (“=") :lexpr {COLUMNREF :fields ("y") :location 22} :rexpr {PARAMREF :number 0 :location 26} :location 24} :groupClause <> :havingClause <> :windowClause <> :valuesLists <> :sortClause <> :limitOffset <> :limitCount <> :lockingClause <> :withClause <> PgQuery._raw_parse( “SELECT * FROM x WHERE y = 1”)
  17. 36.

    pg_query WARNING: 01000: could not dump unrecognized node type: 754

    PgQuery._raw_parse(“CREATE SCHEMA foo”) nodeToString is incomplete :(
  18. 38.

    pg_query PgQuery._raw_parse( “SELECT * FROM x WHERE y = 1”)

    [{"SELECT": { "targetList": [{ "RESTARGET": { "val": { "COLUMNREF": { "fields": [{"A_STAR": {}}], "location": 7 } }, "location": 7 } } ], "fromClause": [ { "RANGEVAR": { "relname": "x", "inhOpt": 2, "relpersistence": "p", "location": 14 } } ], "whereClause": { "AEXPR": { "name": [ "=" ], "lexpr": {
  19. 40.

    EXPLAIN SELECT * FROM x WHERE y = 1 QUERY

    PLAN --------------------------------------------------------------------- Index Scan using idx_for_y on x (cost=0.15..8.17 rows=1 width=140) Index Cond: (id = 1) Parse Analyze Plan pg_query
  20. 41.

    EXPLAIN SELECT * FROM x WHERE y = ? ERROR:

    syntax error at or near ";" LINE 1: EXPLAIN SELECT * FROM x WHERE y = ?; Parse Analyze Plan pg_query
  21. 42.

    EXPLAIN SELECT * FROM x WHERE y = ? EXPLAIN

    SELECT * FROM x WHERE y = $1 ERROR: there is no parameter $1 LINE 1: EXPLAIN SELECT * FROM x WHERE y = $1; Parse Analyze Plan pg_query
  22. 44.

    pg_query Downside: Breaks ? operator in some cases Real fix:

    Don’t use ? as a replacement character.
  23. 46.

    pg_query > require ‘pg_query’ > q1 = PgQuery.parse(‘SELECT a, b

    FROM x’) > q1.fingerprint [“c72f1bc9feda72c0b4ba030eea90b4fed3ac8e86”] > q2 = PgQuery.parse(‘SELECT b, a FROM x’) > q2.fingerprint [“c72f1bc9feda72c0b4ba030eea90b4fed3ac8e86”]
  24. 54.

    pg_qtop Simple top-like tool that shows pg_stat_statements data Filtering &

    Regression Testing https://github.com/lfittl/pg_qtop
  25. 55.

    Filtering & Regression Testing AVG | QUERY -------------------------------------------------------------------------------- 10.7ms |

    SELECT oid, typname, typelem, typdelim, typinput FROM pg_type 3.0ms | SET time zone 'UTC' 0.4ms | SELECT a.attname, format_type(a.atttypid, a.atttypmod), pg_get_expr(d.adbin, d.adrelid), a.attnotnull, a.atttypid, a.atttypmod FROM pg_attribute a LEFT JOIN pg_attrdef d ON a.attrelid = d.adrelid AND a.attnum = d.adnum WHERE a.attrelid = ?::regclass AND a.attnum > ? AND NOT a.attisdropped ORDER BY a.attnum 0.2ms | SELECT pg_stat_statements_reset() 0.1ms | SELECT query, calls, total_time FROM pg_stat_statements 0.1ms | SELECT attr.attname FROM pg_attribute attr INNER JOIN pg_constraint cons ON attr.attrelid = cons.conrelid AND attr.attnum = cons.conkey[?] WHERE cons.contype = ? AND cons.conrelid = ?: :regclass 0.0ms | SELECT COUNT(*) FROM pg_class c LEFT JOIN pg_namespace n ON n.oid = c.relnamespace WHERE c.relkind in (?,?) AND c.relname = ? AND n.nspname = ANY (current_schemas(?)) 0.0ms | SELECT * FROM posts JOIN users ON (posts.author_id = users.id) WHERE users.login = ?; 0.0ms | SET client_min_messages TO 'panic' 0.0ms | set client_encoding to 'UTF8' 0.0ms | SHOW client_min_messages 0.0ms | SELECT * FROM ad_reels WHERE id = ?; 0.0ms | SELECT * FROM posts WHERE guid = ?; 0.0ms | SELECT ? 0.0ms | SET client_min_messages TO 'warning' 0.0ms | SET standard_conforming_strings = on 0.0ms | SELECT "posts".* FROM "posts" ORDER BY "posts"."id" DESC LIMIT ? 0.0ms | SHOW TIME ZONE pg_qtop -d testdb
  26. 56.

    Filtering & Regression Testing AVG | QUERY -------------------------------------------------------------------------------- 0.0ms |

    SELECT * FROM posts JOIN users ON (posts.author_id = users.id) WHERE users.login = ?; 0.0ms | SELECT * FROM posts WHERE guid = ?; 0.0ms | SELECT "posts".* FROM "posts" ORDER BY "posts"."id" DESC LIMIT ? pg_qtop -d testdb -t posts
  27. 57.

    Filtering & Regression Testing AVG | CALLS | HIT RATE

    | QUERY -------------------------------------------------------------------------------- 0.1ms | 1 | 100.0 | SELECT * FROM users; 0.1ms | 1 | - | SELECT * FROM databases; 0.0ms | 1 | - | SELECT * FROM invoices; 0.0ms | 1 | - | SELECT * FROM query_snapshots; pg_qtop -d testdb -s select
  28. 60.

    Which query plans are affected by removal of an index?

    How would execution plans be affected by an upgrade to 9.X? Filtering & Regression Testing
  29. 62.

    "n_live_tup": 75, "relpages": 1, "reltuples": 75.0, “stanumbers1": [..], "stavalues1": “{..}”,

    … Schema Dump + Table Level Statistics Local Test Database Testing Setup Production Database EXPLAIN SELECT FROM x WHERE y = ? Filtering & Regression Testing
  30. 63.

    EXPLAIN SELECT * FROM x WHERE y = ? EXPLAIN

    SELECT * FROM x WHERE y = $1 ERROR: there is no parameter $1 LINE 1: EXPLAIN SELECT * FROM x WHERE y = $1; Parse Analyze Plan Filtering & Regression Testing
  31. 64.

    y = $1 ERROR: there is no parameter $0 LINE

    1: EXPLAIN SELECT * FROM x WHERE y = $0; Filtering & Regression Testing
  32. 65.

    y = $1 y = NULL QUERY PLAN ---------------------------------------------------------------- Result

    (cost=0.00..21.60 rows=1 width=40) One-Time Filter: NULL::boolean -> Seq Scan on x (cost=0.00..21.60 rows=1 width=40) ERROR: there is no parameter $0 LINE 1: EXPLAIN SELECT * FROM x WHERE y = $0; Filtering & Regression Testing
  33. 66.

    y = $1 y = NULL QUERY PLAN ---------------------------------------------------------------- Result

    (cost=0.00..21.60 rows=1 width=40) One-Time Filter: NULL::boolean -> Seq Scan on x (cost=0.00..21.60 rows=1 width=40) y = (SELECT null) ERROR: failed to find conversion function from unknown to integer ERROR: there is no parameter $0 LINE 1: EXPLAIN SELECT * FROM x WHERE y = $0; Filtering & Regression Testing
  34. 67.

    y = $1 y = NULL QUERY PLAN ---------------------------------------------------------------- Result

    (cost=0.00..21.60 rows=1 width=40) One-Time Filter: NULL::boolean -> Seq Scan on x (cost=0.00..21.60 rows=1 width=40) y = (SELECT null) ERROR: failed to find conversion function from unknown to integer y = (SELECT null::integer) QUERY PLAN ---------------------------------------------------------------------- Index Scan using idx_for_y on x (cost=0.16..8.18 rows=1 width=144) Index Cond: (y = $0) InitPlan 1 (returns $0) -> Result (cost=0.00..0.01 rows=1 width=0) ERROR: there is no parameter $0 LINE 1: EXPLAIN SELECT * FROM x WHERE y = $0; Filtering & Regression Testing
  35. 68.

    Finding out the type y = $1 ERROR: there is

    no parameter $1 LINE 1: EXPLAIN SELECT * FROM x WHERE y = $1; PREPARE tmp AS SELECT * FROM x WHERE y = $1; SELECT unnest(parameter_types) AS data_type FROM pg_prepared_statements WHERE name = ‘tmp’; DEALLOCATE tmp; data_type ----------- integer pg_prepared_statements Filtering & Regression Testing
  36. 69.

    EXPLAIN SELECT * FROM x WHERE y = ? EXPLAIN

    SELECT * FROM x WHERE y = $0 EXPLAIN SELECT * FROM x WHERE y = ((SELECT null::integer)::integer) QUERY PLAN --------------------------------------------------------------------- Index Scan using idx_for_y on x (cost=0.16..8.18 rows=1 width=144) Index Cond: (y = $0) InitPlan 1 (returns $0) -> Result (cost=0.00..0.01 rows=1 width=0) Parse Analyze Plan Filtering & Regression Testing
  37. 74.

    Proposal for outfuncs.c: Generate automatically from struct definitions, cutting 3000

    hand-written lines down to 1000. Add JSON output support. Closing
  38. 75.

    Proposal: Consider adding a way to get a parsetree more

    easily. Via SQL / shared library / helper tool. Closing
  39. 76.

    Proposal for pg_s_s: Instead of ? use $0 as replacement

    character - making the output parseable again. Closing
  40. 77.

    Future idea: Annotation plugins for web frameworks, as well as

    parsing of PL/pgSQL methods. “Where is that query called from?” Closing