PostgreSQL Stories: From slow query to fast—via stats

SELECT e.id
FROM events e
JOIN postgres_dbs db ON (e.data ->> 'serviceId') = db.database_id
LIMIT 1;

• EXPLAIN: a command that returns the steps a database will take to execute a query.
• Join algorithms: the algorithms a database uses internally to join two sets of data. These algorithms include merge join, hash join, and nested loop join.
• PEV2: An open source tool that visualizes PostgreSQL execution plans.

A quick gut check

• It’s simple. The query joins two tables on a straightforward condition. It does not pull from dozens of tables nor re-aggregate data.
• It’s indexed. There’s a relevant index on each table in the query: The postgres_dbs table has a unique btree index defined over postgres_dbs(database_id). The events table has a multi-column btree index defined over ((data ->> 'serviceId'::text), "timestamp").
• It’s bounded. The LIMIT 1 ensures PostgreSQL won’t send back every event. The query will stop executing after one match.

Needles in a haystack

• The postgres_dbs table contained ~100k rows.
• The events table contained ~90M rows.
• Only up to ~10k rows in events (0.01% of events) were associated with a row in the postgres_dbs table.
  • Note: This was a rough count. We counted all events that had a prefix (dpg-) that indicated they were associated with postgres_dbs.

Query plan: using EXPLAIN

EXPLAIN
SELECT e.id
FROM events e
JOIN postgres_dbs db ON (e.data ->> 'serviceId') = db.database_id
LIMIT 1;

                                                         QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=0.98..4.39 rows=1 width=25)
   ->  Merge Join  (cost=0.98..306608988.86 rows=90103848 width=25)
         Merge Cond: ((events.data ->> 'serviceId'::text) = postgres_dbs.database_id)
         ->  Index Scan using events_service_id_timestamp_idx on events  (cost=0.57..305056170.48 rows=90103848 width=192)
         ->  Index Only Scan using postgres_dbs_database_id_key on postgres_dbs  (cost=0.42..200755.06 rows=101119 width=26)
(5 rows)

• The two most indented lines (Index Scan… and Index Only Scan…) are executed first. These two lines indicate the database will access the events and postgres_dbs tables with the indexes we mentioned above (events_service_id_timestamp_idx and postgres_dbs_database_id_key). The events will be scanned in order by serviceId, and the postgres_dbs in order by database_id.
• PostgreSQL will use a merge join to join the two datasets.
• The outer Limit […] rows=1 in the query plan indicates the merge join halts as soon as one row is joined.

Aside: What’s a merge join?

1. Initialize a pointer i at the beginning of one column.
2. Initialize a pointer j at the beginning of the second column.
3. Until either i and j exceed the bounds of their columns, repeat the following:
   1. If the values of the ith row and the jth row match, emit a joined row.
   2. Else, if the value of the ith row is “less than” the value of the jth row, advance the i pointer to the next row.
   3. Else, advance j.

Houston, we’re scanning too many rows…

• As noted above, only a small fraction of events (0.01%) are related to a postgres_db. The majority of events are related to other things—for instance cronjob runs, server builds, user logins, and other events on the Render platform.
• The serviceIds in the events table are prefixed based on the event type. For example, serviceIds for cron jobs start with crn-; serviceIds for PostgreSQL databases (represented by rows in postgres_dbs) start with dpg-; serviceIds for servers start with srv-; and so on.
• The index on the events table is sorted by serviceId.

• 79M of the 90M events (87% of events) appeared in alphabetical order before events associated with a PostgreSQL database. These included a large number of cron job events (with prefix crn-), which occur frequently.
• Of the remaining ~11M events:
  • ~10k events were associated with a PostgreSQL database.
  • ~10M events appeared in alphabetical order after PostgreSQL database events. These included server events (with prefix srv-).
  • ~600k events had a null serviceId. By default, NULLs are ordered after non-null content in PostgreSQL databases.

Manual fix 1: Skip earlier rows

SELECT e.id
FROM events e
JOIN postgres_dbs db ON (e.data ->> 'serviceId') = db.database_id
WHERE (e.data ->> 'serviceId') >= 'dpg-'
LIMIT 1;

Unchanged query plan

The “full” query yields a surprise

SELECT e.id
FROM events e
JOIN postgres_dbs db ON (e.data->>'serviceId') = db.database_id
WHERE (e.data ->> 'serviceId') >= 'dpg-';

• We expected all matches to return quickly. As you recall, there were only ~10k rows in the events table associated with a postgres_db row, and therefore at most 10k rows in the full result. That is a tiny number of rows for a computer in the 21st century.
• We expected the query plan to look similar. We expected the plan to also use a merge join. This time, we expected the merge join to keep joining records until we hit the end of the index on postgres_dbs.

Analyzing the “full” query

How the hash join works

1. First, the whole postgres_dbs table is scanned. Each row is inserted into a hash table keyed by the row’s database_id. This hash map is constructed in ~23ms.
   • Note: Since we're consuming the entire postgres_dbs table, a sequential scan isn’t alarming. Using an index may be slower: an index scan would select rows from the index and then fetch them from the table, which is more work than just scanning the table.
2. Then, the hash table is probed for a matching entry for each row in events.

Manual fix 2: Skip end rows

• We could rewrite the query with a materialized CTE that would first scan the relevant events and store them as a temporary table for a subsequent join. However, this is a heavy-handed approach. We're also likely to spill to shared memory and disk to store a large intermediate result set.
• We could introduce an ORDER BY <expression> to the query, and hope that the query planner opts to scan an index that is ordered by the same expression.
• We could be more explicit in telling PostgreSQL what our data distribution looks like. Earlier, we added a condition to skip the events that occur before a database-related event in an index scan. This leaves the tail of the index starting at database events, but still includes ~11M events that won't match the join condition.

SELECT e.id
FROM events e
JOIN postgres_dbs db ON (e.data ->> 'serviceId') = db.database_id
WHERE
    (e.data ->> 'serviceId') >= 'dpg-' AND
    (e.data ->> 'serviceId') <  'dph';

A statistics lesson

Aside: What are “statistics” in PostgreSQL?

• the number of rows in a table
• the physical size of a table or index
• the distribution of data in each column of a table

Querying our statistics

SELECT * FROM pg_stats WHERE tablename = 'events' AND attname = 'data';

-[ RECORD 1 ]----------------------------------------------------------------------------------------------------------
tablename         | events
attname           | data
null_frac         | 0
n_distinct        | -0.22765513
most_common_vals  | {
                  |   {"reason": {"nonZeroExit": 1}, "serviceId": "srv-bpo3bedifurfbl64o7tg"},
                  |   {"reason": {"nonZeroExit": 1}, "serviceId": "srv-bpo329difurfbl64o720"},
                  |   ...
                  | }
most_common_freqs | { 0.002282, 0.002010, ... }
histogram_bounds  | {
                  |   {"serviceId": "crn-bhsokgffhqe91l7vg0n0", "cronJobRunId": "crn-bhsokgffhqe91l7vg0n0-1551537300"},
                  |   {"serviceId": "crn-bhsokgffhqe91l7vg0n0", "cronJobRunId": "crn-bhsokgffhqe91l7vg0n0-1552037820"},
                  |   ...
                  | }

• null_frac: the ratio of null rows to the total number of rows. In the above output, the value 0 means there are no null rows.
• n_distinct: either the absolute number of distinct values in a column (indicated by a positive number), or the ratio of distinct values to the total number of rows (indicated by a negative number). In the above output, the value -0.22765513 means that 22.7% of rows contain a distinct value.
• most_common_vals and most_common_freqs: a list of the most common values. In the above output, we (unfortunately) see many events related to server and cronjob crashes.
• histogram_bounds: a sampling of every nth element when the column is sorted. These bounds break the rows of a column into groups of roughly the same size. These bounds can be used to estimate the cardinality of a result.

Ultimate fix: DIY stats

• Which columns are heavily correlated with one another (e.g., a postal code will always belong to a specific city)
• Which columns can predict the value of another (e.g., if a user id uniquely determines an email address, and vice versa)
• Statistics over expressions that are useful for you to filter or sort by (e.g., keeping a histogram of price * exchange_rate)

CREATE STATISTICS IF NOT EXISTS events_service_id
ON (data ->> 'serviceId'::text)
from events;

SELECT * FROM pg_stats_ext_exprs;

-[ RECORD 1 ]----------------------------------------------------------------------------------------------------------------
tablename         | events
statistics_name   | events_service_id
expr              | (data ->> 'serviceId'::text)
null_frac         | 0.0069796667
n_distinct        | 76228
most_common_vals  | {
                  |   crn-c7u453rs13jp86lgjg3g, crn-cf0rnjdv55c4kpmol3dg, crn-cf0aihdv55c708f13a1g, crn-cf0oell2qhu025k7u4p0,
                  |   ...,
                  |   srv-cf06b5u2ofe582arfj5g, srv-cevkofq254ubij4mgelg, srv-cevlocdv55cfcfun2p8g, srv-bptpnraps24ffc87hf5g
                  | }
most_common_freqs | {
                  |   0.0222010000, 0.0119753330, 0.0119540000, 0.0119480000,
                  |   ....,
                  |   0.0009033333, 0.0009000000, 0.0008976667, 0.0008960000
                  | }
histogram_bounds  | {
                  |   crn-bhm5trt334m912f601i0, crn-biv8696bo897vckjtlpg, crn-buncspffjtv9715thc00, crn-c1od9kegv2c20j2l50b0,
                  |   ...,
                  |   srv-cnj2njac7pgfeu8rc7q0, srv-cnj40mf88oc3nmb3g88g, srv-cnj4mlv88oc74520ihgg, srv-cogpale28t4943ck9b7g
                  | }

• null_frac: There is a non-zero proportion of NULL values.
• n_distinct: The number of distinct values is positive, which indicates an absolute count of distinct values.
• most_common_vals: The values here are serviceIds, which is what we want to filter by in our original query.

Final test and query plan

SELECT e.id
FROM events e
JOIN postgres_dbs db ON (e.data ->> 'serviceId') = db.database_id;

Tools for you

• Run EXPLAIN or EXPLAIN ANALYZE on a query. Remember that EXPLAIN ANALYZE actually executes the query.
• Use the PEV2 tool to visualize an EXPLAIN ANALYZE run.
• Explore the pg_stats view in your database.