Why AWS RDS PostgreSQL suddenly consumed all free storage

Question

I've got a AWS RDS PostgreSQL (13.x). The DB had 100 GB storage of which around 30 GB was used. Suddenly, during one day all the free storage was eaten by PostgreSQL (so it seems) and even after adding another 100GB of storage, the free space was still consumed. There was no gigantic data load into the DB or something like that.

Please help me understand what has happened or point me to where I can learn about it to understand. This problem follows me all the time and doesn't allow me to sleep. ;-)

Thanks for any help!

What I've found out is one of tables, where we put time-based entries (explained in a moment) grew to 72 GB. I couldn't execute selects in the table in a reasonably finite time(it took 45 minutes for "select count(*)" to finish). After the crash there were 11M rows.

The table:

Db=> \d+ es.scheduled_events
                                                                       Table "es.scheduled_events"
       Column       |            Type             | Collation | Nullable |                        Default                        | Storage  | Stats target | Description
--------------------+-----------------------------+-----------+----------+-------------------------------------------------------+----------+--------------+-------------
 event_id           | bigint                      |           | not null | nextval('es.scheduled_events_event_id_seq'::regclass) | plain    |              |
 partition          | integer                     |           | not null | 0                                                     | plain    |              |
 transaction_id     | character varying(36)       |           | not null |                                                       | extended |              |
 created_at         | timestamp without time zone |           | not null |                                                       | plain    |              |
 schedule_id        | character varying(128)      |           | not null |                                                       | extended |              |
 effective_datetime | timestamp without time zone |           | not null |                                                       | plain    |              |
 processed          | boolean                     |           | not null | false                                                 | plain    |              |
 payload            | jsonb                       |           | not null |                                                       | extended |              |
Indexes:
    "scheduled_events_pkey" PRIMARY KEY, btree (event_id)
    "scheduled_events_by_processed_effective_datetime_idx" btree (processed, effective_datetime)
    "scheduled_events_by_schedule_idx" btree (schedule_id)
Access method: heap

The table stores events (rows) to be processed in the future, when their effective_datetime is in the past. Two connections constantly (every 500ms) process the table:

• select where processed = 'f' and effective_datetime <= now()
• each processed row (no matter if successfully or not) is marked processed = 't'
• if the processing fails, insert a new row with future date (in 2-3 days) for retry
• rows are never deleted.

The processing load in the table isn't the same all the time. 3 times a week (Mon, Wed, Fri) at 3 AM around 320k rows are ready for processing, the processing fails, and they are rescheduled (new rows are inserted) to the next retry day (the next of the Mon, Wed, Fri). On all other days there is almost nothing to process - less than 200 rows. In the image above the small rows, when the storage consumption was stable, were the days when the 320k events were processed. We basically add around 320k rows 3 times a week since the middle of March - around 30 times by the time of the failure.

Roughly sizes of rows in the table:

SELECT octet_length(t.*::text) as len FROM es.scheduled_events AS t
WHERE effective_datetime >= '2022-05-18' and effective_datetime < '2022-05-19' order by len desc limit 3;
 len
-----
 485
 484
 484

IIUC, the storage consumption is, roughly, 30 times 320k rows (480 bytes each) is roughly 5GB. Plus indices - let's say double the number - 10 GB grow since March. I know it is not precise, but nowhere near 72GB.

Here are some notes:

• Everything started to fall at 3 AM, when events scheduled for 3AM became ready for processing (around 320k rows)
• 2 connections were processing data from the table (as described above)
• Manual delete of old entries was deadlocking until I disconnected the app
• Adding 100GB only bought some time, because the storage was still consumed (pic below)
• Explain analyze select count(*) took 45 minutes
• Finally managed to deleted old rows (around 9 millions) to 2.4M rows
• Enabled the app
• Storage usage is back to stable.

Here's how the storage usage looked like:

• On 2022-05-18 at 3 AM it started to excessively consume the storage
• On 2022-05-19 I've added 100GB storage so it go up, but was still consumed
• Then I've eventually deleted the old data, which freed the space and the free space consumption have stopped.

I've found some query to calculate the size of temporary files:

SELECT datname, temp_files AS "Temporary files",
       temp_bytes AS "Size of temporary files",
       pg_size_pretty(temp_bytes) as "GB"
FROM pg_stat_database;
    datname      | Temporary files | Size of temporary files |   GB
-----------------+-----------------+-------------------------+---------
 template0       |               0 |                       0 | 0 bytes
 template1       |               0 |                       0 | 0 bytes
 postgres        |               0 |                       0 | 0 bytes
 MyDb            |           10707 |            217424405880 | 202 GB
 rdsadmin        |               0 |                       0 | 0 bytes

After a few days after the crash I've found some super complicated query to calculate bloat:

\set bloat 'SELECT tablename as table_name, ROUND(CASE WHEN otta=0 THEN 0.0 ELSE sml.relpages/otta::numeric END,1) AS table_bloat, CASE WHEN relpages < otta THEN ''0'' ELSE pg_size_pretty((bs*(sml.relpages-otta)::bigint)::bigint) END AS table_waste, iname as index_name, ROUND(CASE WHEN iotta=0 OR ipages=0 THEN 0.0 ELSE ipages/iotta::numeric END,1) AS index_bloat, CASE WHEN ipages < iotta THEN ''0'' ELSE pg_size_pretty((bs*(ipages-iotta))::bigint) END AS index_waste FROM ( SELECT schemaname, tablename, cc.reltuples, cc.relpages, bs, CEIL((cc.reltuples*((datahdr+ma- (CASE WHEN datahdr%ma=0 THEN ma ELSE datahdr%ma END))+nullhdr2+4))/(bs-20::float)) AS otta, COALESCE(c2.relname,''?'') AS iname, COALESCE(c2.reltuples,0) AS ituples, COALESCE(c2.relpages,0) AS ipages, COALESCE(CEIL((c2.reltuples*(datahdr-12))/(bs-20::float)),0) AS iotta FROM ( SELECT ma,bs,schemaname,tablename, (datawidth+(hdr+ma-(case when hdr%ma=0 THEN ma ELSE hdr%ma END)))::numeric AS datahdr, (maxfracsum*(nullhdr+ma-(case when nullhdr%ma=0 THEN ma ELSE nullhdr%ma END))) AS nullhdr2 FROM ( SELECT schemaname, tablename, hdr, ma, bs, SUM((1-null_frac)*avg_width) AS datawidth, MAX(null_frac) AS maxfracsum, hdr+( SELECT 1+count(*)/8 FROM pg_stats s2 WHERE null_frac<>0 AND s2.schemaname = s.schemaname AND s2.tablename = s.tablename) AS nullhdr FROM pg_stats s, ( SELECT (SELECT current_setting(''block_size'')::numeric) AS bs, CASE WHEN substring(v,12,3) IN (''8.0'',''8.1'',''8.2'') THEN 27 ELSE 23 END AS hdr, CASE WHEN v ~ ''mingw32'' THEN 8 ELSE 4 END AS ma FROM (SELECT version() AS v) AS foo) AS constants GROUP BY 1,2,3,4,5) AS foo) AS rs JOIN pg_class cc ON cc.relname = rs.tablename JOIN pg_namespace nn ON cc.relnamespace = nn.oid AND nn.nspname = rs.schemaname AND nn.nspname <> ''information_schema'' LEFT JOIN pg_index i ON indrelid = cc.oid LEFT JOIN pg_class c2 ON c2.oid = i.indexrelid) AS sml ORDER BY CASE WHEN relpages < otta THEN 0 ELSE bs*(sml.relpages-otta)::bigint END DESC;'

MyDB=> :bloat
      table_name  | table_bloat | table_waste |                      index_name                      | index_bloat | index_waste
------------------+-------------+-------------+------------------------------------------------------+-------------+-------------
 scheduled_events |        12.1 | 20 GB       | scheduled_events_by_processed_effective_datetime_idx |         3.5 | 2502 MB
 scheduled_events |        12.1 | 20 GB       | scheduled_events_pkey                                |         0.5 | 0
 scheduled_events |        12.1 | 20 GB       | scheduled_events_by_schedule_idx                     |         3.7 | 2701 MB

I'm not sure if it's helpful but here's Transaction Logs Disk Usage from the period.

I've got a snapshot of the database, so can provide more information if needed.

Answer 1

Do take a look into the size of log files stored in the RDS instance. I faced such an issue where our DB size was 250GB but it autoscaled up to 1TB as we were logging all queries (log_statement) and the retention period of these log files was 3 days. Then we tuned the parameters log_statement and rds.log_retention_period to reduce and clear log files from the RDS instance. Got it backed up daily in CloudWatch.