Sample Header Ad - 728x90

Auto-vacuum shows different behaviour in two similar situations. I am unable to understand why?

0 votes
0 answers
16 views
I have a insert-only table event on PostgreSQL-12 where I am having a high volume of inserts per sec (~2000 per sec). I regularly faced an issue when anti-wraparound auto-vacuum was running on this table and ALTER query was getting blocked. I am surprised to see that once I saw that auto-vacuum job got cancelled after deadlock timeout even though it was anti-wraparound. **Logs when autovacuum did not get cancelled**
autovacuum not cancelled

sqlstate=00000 application_name=,user=,db=,client= LOG:  automatic vacuum to prevent wraparound of table "my_db.public.event_spl_1740300900": index scans: 0
#011pages: 0 removed, 16591962 remain, 0 skipped due to pins, 16300723 skipped frozen
#011tuples: 0 removed, 1244397113 remain, 0 are dead but not yet removable, oldest xmin: 1410720248
#011buffer usage: 2361602 hits, 6947399 misses, 291262 dirtied
#011avg read rate: 3.879 MB/s, avg write rate: 0.163 MB/s
#011system usage: CPU: user: 83.69 s, system: 135.74 s, elapsed: 13990.91 s
sqlstate=00000 application_name=[unknown],user=bpuser,db=my_db,client=172.16.6.1 LOG:  process 113323 acquired AccessExclusiveLock on relation 181282787 of database 180669275 after 5823314.224 ms
**Logs when autovacuum got cancelled**
autovacuum cancelled (happened later in time)

sqlstate=00000 application_name=,user=,db=,client= LOG:  automatic vacuum to prevent wraparound of table "my_db.public.event_spl_1740300900": index scans: 0
#011pages: 0 removed, 74793286 remain, 0 skipped due to pins, 74587702 skipped frozen
#011tuples: 0 removed, 5609496590 remain, 0 are dead but not yet removable, oldest xmin: 1616127756
#011buffer usage: 436546 hits, 7 misses, 205186 dirtied
#011avg read rate: 0.000 MB/s, avg write rate: 1.179 MB/s
#011system usage: CPU: user: 9.24 s, system: 3.22 s, elapsed: 1359.75 s
sqlstate=57014 application_name=,user=,db=,client= ERROR:  canceling autovacuum task
sqlstate=00000 application_name=[unknown],user=bpuser,db=my_db,client=172.16.6.1 LOG:  process 100214 acquired AccessExclusiveLock on relation 181282787 of database 180669275 after 1000.650 ms
sqlstate=00000 application_name=[unknown],user=bpuser,db=my_db,client=172.16.6.1 STATEMENT:  ALTER TABLE event ALTER pkey SET DEFAULT (1742745300)
sqlstate=00000 application_name=[unknown],user=bpuser,db=my_db,client=172.16.6.1 LOG:  duration: 1126.377 ms  execute : ALTER TABLE event ALTER pkey SET DEFAULT (1742745300)
What could be the difference between these two scenarios?
Asked by Yashodhan Agnihotri (11 rep)
Mar 26, 2025, 07:20 AM
Last activity: Mar 26, 2025, 10:20 PM