On Mon, Mar 23, 2020 at 3:00 PM Andres Freund <andres@xxxxxxxxxxx> wrote: > > Hi, > > On 2020-03-23 20:47:25 +0100, Julien Rouhaud wrote: > > > - relfrozenxid, age(relfrozenxid) for the oldest table in the oldest database > > > SELECT oid::regclass, age(relfrozenxid), relfrozenxid FROM pg_class WHERE relfrozenxid <> 0 ORDER BY age(relfrozenxid) DESC LIMIT 1; > > > > The vm has been trashed since, and I don't have that level of detail available > > in the gathered stats unfortunately (and the available information I have is a > > little bit messy, sorry for that). > > > > > - Oldest backend xmin > > > SELECT pid, backend_xmin, age(backend_xmin) FROM pg_stat_activity WHERE backend_xmin <> 0 ORDER BY age(backend_xmin) DESC LIMIT 3; > > > - oldest replication xmin: > > > SELECT pid, backend_xmin, age(backend_xmin) FROM pg_stat_replication WHERE backend_xmin <> 0 ORDER BY age(backend_xmin) DESC LIMIT 3; > > > - oldest slot xmin: > > > SELECT slot_name, xmin, age(xmin), catalog_xmin, age(catalog_xmin) FROM pg_replication_slots WHERE xmin <> 0 OR catalog_xmin <> 0 ORDER BY greatest(age(xmin), age(catalog_xmin)) DESC LIMIT 3; > > > - oldest prepared transaction (unfortunately xmin not available) > > > SELECT gid, database, transaction FROM pg_prepared_xacts ORDER BY age(transaction) LIMIT 3; > > > > I have output from this query: https://github.com/OPMDG/check_pgactivity/blob/oldest_xmin/check_pgactivity#L5669-L5732 > > (which may be dumb). Here are the non-null rows after 8AM GMT+1: > > Could you share what the config of the server was? > > > > > > The same bench was run against pg11 many times and never triggered this issue. > > > > So far our best guess is a side effect of 2aa6e331ead7. > > > > > > In that case you'd likely see DEBUG1 output, right? Did you try running > > > with that? > > > > That's unfortunately not an option, as while the issue is reproducible, it > > happens after roughly 16h with an average of 6.5ktps, and we definitely don't > > have enough disk space for that amount of logs. We'll try next time with a > > recompiled version with the DEBUG1 promoted to WARNING, and maybe other elog. > > You wouldn't need to run it with DEBUG1 the whole time, you could just > change the config and reload config once you hit the issue. > > > > > > Michael and I have been trying to reproduce this issue locally (drastically > > > > reducing the various freeze_age parameters) for hours, but no luck for now. > > > > > > Have you considered using gdb to investigate? > > > > Not for now, because it's hard to be around for the ~ 90min interval the system > > stays alive after atuvacuum get stuck, especially since it's a weekend bench. > > > > > > This is using a vanilla pg 12.1, with some OLTP workload. The only possibly > > > > relevant configuration changes are quite aggressive autovacuum settings on some > > > > tables (no delay, analyze/vacuum threshold to 1k and analyze/vacuum scale > > > > factor to 0, for both heap and toast). > > > > > > That, uh, is not an insignificant set of changes for an autovac > > > scheduling issues. > > > > > > It sounds like what might be happening is that you have something > > > holding back the "oldest needed transaction" horizon. Before > > > 2aa6e331ead7, if the xmin horizon hasn't increased, there'd be repeated > > > vacuums unable to increase the horizon, but afterwards they'll all > > > immediately exit without any messages. > > > > The xmin horizon is increasing AFAICS. Grepping the autovacuum logs, I can see > > for the 08:00 AM UTC - 08:59 AM UTC interval the oldest xmin going from > > 200069684 to 210363848. E.g.: > > Which database is this on? > > > > [...] > > 266603:2020-03-14 08:49:59.927 UTC LOG: automatic aggressive vacuum to prevent wraparound of table "pg_toast.pg_toast_27683": index scans: 0 > > 266604- pages: 0 removed, 0 remain, 0 skipped due to pins, 0 skipped frozen > > 266605- tuples: 0 removed, 0 remain, 0 are dead but not yet removable, oldest xmin: 209635921 > > 266606- buffer usage: 25 hits, 1 misses, 1 dirtied > > 266607- avg read rate: 15.440 MB/s, avg write rate: 15.440 MB/s > > 266608- system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s > > 266609:2020-03-14 08:49:59.929 UTC LOG: automatic aggressive vacuum to prevent wraparound of table "pg_toast.pg_toast_27694": index scans: 0 > > 266610- pages: 0 removed, 0 remain, 0 skipped due to pins, 0 skipped frozen > > 266611- tuples: 0 removed, 0 remain, 0 are dead but not yet removable, oldest xmin: 209635934 > > 266612- buffer usage: 25 hits, 1 misses, 1 dirtied > > 266613- avg read rate: 21.058 MB/s, avg write rate: 21.058 MB/s > > 266614- system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s > > 266615:2020-03-14 08:49:59.931 UTC LOG: automatic aggressive vacuum to prevent wraparound of table "pg_toast.pg_toast_24845": index scans: 0 > > 266616- pages: 0 removed, 0 remain, 0 skipped due to pins, 0 skipped frozen > > 266617- tuples: 0 removed, 0 remain, 0 are dead but not yet removable, oldest xmin: 209635934 > > 266618- buffer usage: 25 hits, 1 misses, 2 dirtied > > 266619- avg read rate: 8.005 MB/s, avg write rate: 16.009 MB/s > > 266620- system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s > > 266621:2020-03-14 08:49:59.945 UTC LOG: automatic aggressive vacuum to prevent wraparound of table "pg_toast.pg_toast_27712": index scans: 0 > > 266622- pages: 0 removed, 0 remain, 0 skipped due to pins, 0 skipped frozen > > 266623- tuples: 0 removed, 0 remain, 0 are dead but not yet removable, oldest xmin: 209635953 > > [...] > > Do you have any non-toast ones? This is occurring in our environment right now (started about 30 min ago). Here 's the latest logs (grepped by vacuum): Mar 23 20:54:16 cowtn postgres[15569]: [12-1] 2020-03-23 20:54:16.542 GMT [15569] LOG: automatic vacuum of table "feedi.production.tita": index scans: 1 Mar 23 20:54:27 cowtn postgres[15654]: [8-1] 2020-03-23 20:54:27.964 GMT [15654] LOG: automatic vacuum of table "feedi.production.distributed_virtual_schedule": index scans: 1 Mar 23 20:54:29 cowtn postgres[15654]: [10-1] 2020-03-23 20:54:29.103 GMT [15654] LOG: automatic vacuum of table "feedi.production.tita": index scans: 1 Mar 23 20:54:29 cowtn postgres[15654]: [12-1] 2020-03-23 20:54:29.284 GMT [15654] LOG: automatic vacuum of table "feedi.pg_toast.pg_toast_2619": index scans: 1 Mar 23 20:54:44 cowtn postgres[15759]: [8-1] 2020-03-23 20:54:44.005 GMT [15759] LOG: automatic vacuum of table "feedi.production.flightplans": index scans: 1 Mar 23 20:54:45 cowtn postgres[15759]: [11-1] 2020-03-23 20:54:45.979 GMT [15759] LOG: automatic vacuum of table "feedi.production.tita": index scans: 1 Mar 23 20:54:54 cowtn postgres[15814]: [7-1] 2020-03-23 20:54:54.367 GMT [15814] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_statistic": index scans: 0 Mar 23 20:54:54 cowtn postgres[15814]: [8-1] 2020-03-23 20:54:54.378 GMT [15814] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_type": index scans: 0 Mar 23 20:54:54 cowtn postgres[15814]: [9-1] 2020-03-23 20:54:54.389 GMT [15814] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_foreign_server": index scans: 0 Mar 23 20:54:54 cowtn postgres[15814]: [10-1] 2020-03-23 20:54:54.410 GMT [15814] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_statistic_ext_data": index scans: 0 Mar 23 20:54:54 cowtn postgres[15814]: [11-1] 2020-03-23 20:54:54.420 GMT [15814] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_user_mapping": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [7-1] 2020-03-23 20:55:09.194 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_attribute": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [8-1] 2020-03-23 20:55:09.205 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_proc": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [9-1] 2020-03-23 20:55:09.216 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_class": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [10-1] 2020-03-23 20:55:09.227 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_attrdef": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [11-1] 2020-03-23 20:55:09.239 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_constraint": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [12-1] 2020-03-23 20:55:09.250 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_inherits": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [13-1] 2020-03-23 20:55:09.260 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_index": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [14-1] 2020-03-23 20:55:09.272 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_operator": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [15-1] 2020-03-23 20:55:09.283 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_opfamily": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [16-1] 2020-03-23 20:55:09.294 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_opclass": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [17-1] 2020-03-23 20:55:09.305 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_am": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [18-1] 2020-03-23 20:55:09.317 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_amop": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [19-1] 2020-03-23 20:55:09.328 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_amproc": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [20-1] 2020-03-23 20:55:09.339 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_language": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [21-1] 2020-03-23 20:55:09.349 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_largeobject_metadata": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [22-1] 2020-03-23 20:55:09.360 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_aggregate": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [23-1] 2020-03-23 20:55:09.371 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_largeobject": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [24-1] 2020-03-23 20:55:09.382 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_statistic_ext": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [25-1] 2020-03-23 20:55:09.393 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_rewrite": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [26-1] 2020-03-23 20:55:09.404 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_trigger": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [27-1] 2020-03-23 20:55:09.415 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_event_trigger": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [28-1] 2020-03-23 20:55:09.426 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_description": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [29-1] 2020-03-23 20:55:09.437 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_cast": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [30-1] 2020-03-23 20:55:09.448 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_enum": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [31-1] 2020-03-23 20:55:09.459 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_namespace": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [32-1] 2020-03-23 20:55:09.470 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_conversion": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [33-1] 2020-03-23 20:55:09.481 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_depend": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [34-1] 2020-03-23 20:55:09.502 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_db_role_setting": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [35-1] 2020-03-23 20:55:09.524 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_pltemplate": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [36-1] 2020-03-23 20:55:09.545 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_shdepend": index scans: 1 Mar 23 20:55:09 cowtn postgres[15890]: [37-1] 2020-03-23 20:55:09.556 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_shdescription": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [38-1] 2020-03-23 20:55:09.567 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_ts_config": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [39-1] 2020-03-23 20:55:09.578 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_ts_config_map": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [40-1] 2020-03-23 20:55:09.589 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_ts_dict": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [41-1] 2020-03-23 20:55:09.600 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_ts_parser": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [42-1] 2020-03-23 20:55:09.611 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_ts_template": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [43-1] 2020-03-23 20:55:09.622 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_extension": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [44-1] 2020-03-23 20:55:09.633 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_foreign_data_wrapper": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [45-1] 2020-03-23 20:55:09.643 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_foreign_table": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [46-1] 2020-03-23 20:55:09.654 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_policy": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [47-1] 2020-03-23 20:55:09.675 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_default_acl": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [48-1] 2020-03-23 20:55:09.686 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_init_privs": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [49-1] 2020-03-23 20:55:09.696 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_seclabel": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [50-1] 2020-03-23 20:55:09.719 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_collation": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [51-1] 2020-03-23 20:55:09.729 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_partitioned_table": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [52-1] 2020-03-23 20:55:09.740 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_range": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [53-1] 2020-03-23 20:55:09.751 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_transform": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [54-1] 2020-03-23 20:55:09.762 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_sequence": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [55-1] 2020-03-23 20:55:09.772 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_publication": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [56-1] 2020-03-23 20:55:09.783 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_publication_rel": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [57-1] 2020-03-23 20:55:09.794 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_catalog.pg_subscription_rel": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [58-1] 2020-03-23 20:55:09.805 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.information_schema.sql_packages": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [59-1] 2020-03-23 20:55:09.816 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.information_schema.sql_features": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [60-1] 2020-03-23 20:55:09.827 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.information_schema.sql_implementation_info": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [61-1] 2020-03-23 20:55:09.838 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.information_schema.sql_parts": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [62-1] 2020-03-23 20:55:09.849 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.information_schema.sql_languages": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [63-1] 2020-03-23 20:55:09.859 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.information_schema.sql_sizing": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [64-1] 2020-03-23 20:55:09.870 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.information_schema.sql_sizing_profiles": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [65-1] 2020-03-23 20:55:09.880 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_2600": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [66-1] 2020-03-23 20:55:09.891 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_2604": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [67-1] 2020-03-23 20:55:09.902 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_3456": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [68-1] 2020-03-23 20:55:09.912 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_2606": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [69-1] 2020-03-23 20:55:09.923 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_826": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [70-1] 2020-03-23 20:55:09.933 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_2609": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [71-1] 2020-03-23 20:55:09.944 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_3466": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [72-1] 2020-03-23 20:55:09.955 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_3079": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [73-1] 2020-03-23 20:55:09.965 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_2328": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [74-1] 2020-03-23 20:55:09.976 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_1417": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [75-1] 2020-03-23 20:55:09.987 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_3118": index scans: 0 Mar 23 20:55:09 cowtn postgres[15890]: [76-1] 2020-03-23 20:55:09.997 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_3394": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [77-1] 2020-03-23 20:55:10.008 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_2612": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [78-1] 2020-03-23 20:55:10.018 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_2615": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [79-1] 2020-03-23 20:55:10.029 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_3350": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [80-1] 2020-03-23 20:55:10.040 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_3256": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [81-1] 2020-03-23 20:55:10.050 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_1255": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [82-1] 2020-03-23 20:55:10.062 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_2618": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [83-1] 2020-03-23 20:55:10.072 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_3596": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [84-1] 2020-03-23 20:55:10.083 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_2619": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [85-1] 2020-03-23 20:55:10.094 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_3381": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [86-1] 2020-03-23 20:55:10.105 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_3429": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [87-1] 2020-03-23 20:55:10.115 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_2620": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [88-1] 2020-03-23 20:55:10.126 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_3600": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [89-1] 2020-03-23 20:55:10.137 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_1247": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [90-1] 2020-03-23 20:55:10.147 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_1418": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [91-1] 2020-03-23 20:55:10.158 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_1260": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [92-1] 2020-03-23 20:55:10.169 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_1262": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [93-1] 2020-03-23 20:55:10.179 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_2964": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [94-1] 2020-03-23 20:55:10.190 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_1136": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [95-1] 2020-03-23 20:55:10.201 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_6000": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [96-1] 2020-03-23 20:55:10.211 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_2396": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [97-1] 2020-03-23 20:55:10.222 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_3592": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [98-1] 2020-03-23 20:55:10.232 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_6100": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [99-1] 2020-03-23 20:55:10.243 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_1213": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [100-1] 2020-03-23 20:55:10.254 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_13267": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [101-1] 2020-03-23 20:55:10.264 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_13272": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [102-1] 2020-03-23 20:55:10.275 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_13287": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [103-1] 2020-03-23 20:55:10.286 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_13277": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [104-1] 2020-03-23 20:55:10.296 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_13282": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [105-1] 2020-03-23 20:55:10.307 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_13292": index scans: 0 Mar 23 20:55:10 cowtn postgres[15890]: [106-1] 2020-03-23 20:55:10.317 GMT [15890] LOG: automatic aggressive vacuum to prevent wraparound of table "postgres.pg_toast.pg_toast_13297": index scans: 0 > > > > > I wonder if what might be happening is that we're somehow missed/failed > > > to update relfrozenxid and/or datfrozenxid. If you manually vacuum some > > > table in the oldest database, but that is *NOT* the oldest table itself, > > > does the problem "resolve" itself? postgres=# SELECT datname , age(datfrozenxid) , current_setting('autovacuum_freeze_max_age') FROM pg_database; datname | age | current_setting -----------+-----------+----------------- postgres | 202375735 | 200000000 template1 | 202345459 | 200000000 template0 | 132459914 | 200000000 feedi | 132459914 | 200000000 (4 rows) > > > > I'll also add pg_class snapshot for next time we run the bench. I'm not sure > > if we'll be able to catch the 1h45 interval when the system stays alive > > after the issue though. > > Could you just script something to stop the benchmark once the disk is > 90% full or so? > > Did you see any errors / fatals around the time autovacuum stopped > working? There are no ERROR or FATAL messages around the time -- (or at all). Since this is occurring right now, what else would be useful to capture? You'd asked about a GDB -- do you want that of the main process or the autovac worker? > > Greetings, > > Andres Freund
