franciscoreinolds
commented
11 months ago Now I think this is okay!
I tested it with the following lines:
Details
```sql Feb 10 23:26:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic analyze of table "db.public.table1" system usage: CPU: user: 0.77 s, system: 0.90 s, elapsed: 12.36 s Feb 10 23:26:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic analyze of table "db.public.table2" system usage: CPU: user: 0.19 s, system: 0.03 s, elapsed: 0.57 s Feb 10 23:26:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic analyze of table "db.public.table3" system usage: CPU: user: 0.11 s, system: 0.01 s, elapsed: 0.63 s Feb 10 23:26:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic analyze of table "db.public.table4" system usage: CPU: user: 0.56 s, system: 0.07 s, elapsed: 2.29 s Feb 10 23:26:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic analyze of table "db.public.table4" system usage: CPU: user: 0.56 s, system: 0.07 s, elapsed: 20.29 ```
And the result:
Hello 👋🏽
I thought this would be an interesting feature to add as one can have a decent average autovacuum duration, but some of them might be running too long and one wouldn't know it.
While trying to implement this feature, I stumbled upon the fact that the parsing for
autovacuum'ssystem usage: CPU: user: ...line is broken. I hadn't noticed it thus far, but have checked a report I generated a couple of days ago and it's also missing the longest vacuum duration:So, I fixed that, and begun implementing the chart.
To test my implementation, I generated a report from the following output:
Details
```sql Feb 10 23:06:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic vacuum of table "db.public.tablename": index scans: 1 pages: 0 removed, 1001527 remain, 0 skipped due to pins, 0 skipped frozen tuples: 1346603 removed, 15288094 remain, 224598 are dead but not yet removable, oldest xmin: 736 buffer usage: 1104110 hits, 2210831 misses, 1716564 dirtied avg read rate: 2.329 MB/s, avg write rate: 1.808 MB/s system usage: CPU: user: 46.90 s, system: 60.02 s, elapsed: 7417.28 Feb 10 23:08:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic vacuum of table "db.public.tablename": index scans: 1 pages: 0 removed, 1001527 remain, 0 skipped due to pins, 0 skipped frozen tuples: 1346603 removed, 15288094 remain, 224598 are dead but not yet removable, oldest xmin: 736 buffer usage: 1104110 hits, 2210831 misses, 1716564 dirtied avg read rate: 2.329 MB/s, avg write rate: 1.808 MB/s system usage: CPU: user: 46.90 s, system: 60.02 s, elapsed: 7417.28 Feb 10 23:10:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic vacuum of table "db.public.tablename": index scans: 1 pages: 0 removed, 1001527 remain, 0 skipped due to pins, 0 skipped frozen tuples: 1346603 removed, 15288094 remain, 224598 are dead but not yet removable, oldest xmin: 736 buffer usage: 1104110 hits, 2210831 misses, 1716564 dirtied avg read rate: 2.329 MB/s, avg write rate: 1.808 MB/s system usage: CPU: user: 46.90 s, system: 60.02 s, elapsed: 7417.28 Feb 10 23:12:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic vacuum of table "db.public.tablename": index scans: 1 pages: 0 removed, 1001527 remain, 0 skipped due to pins, 0 skipped frozen tuples: 1346603 removed, 15288094 remain, 224598 are dead but not yet removable, oldest xmin: 736 buffer usage: 1104110 hits, 2210831 misses, 1716564 dirtied avg read rate: 2.329 MB/s, avg write rate: 1.808 MB/s system usage: CPU: user: 46.90 s, system: 60.02 s, elapsed: 7417.28 Feb 10 23:14:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic vacuum of table "db.public.tablename": index scans: 1 pages: 0 removed, 1001527 remain, 0 skipped due to pins, 0 skipped frozen tuples: 1346603 removed, 15288094 remain, 224598 are dead but not yet removable, oldest xmin: 736 buffer usage: 1104110 hits, 2210831 misses, 1716564 dirtied avg read rate: 2.329 MB/s, avg write rate: 1.808 MB/s system usage: CPU: user: 46.90 s, system: 60.02 s, elapsed: 7417.28 Feb 10 23:16:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic vacuum of table "db.public.tablename": index scans: 1 pages: 0 removed, 1001527 remain, 0 skipped due to pins, 0 skipped frozen tuples: 1346603 removed, 15288094 remain, 224598 are dead but not yet removable, oldest xmin: 736 buffer usage: 1104110 hits, 2210831 misses, 1716564 dirtied avg read rate: 2.329 MB/s, avg write rate: 1.808 MB/s system usage: CPU: user: 46.90 s, system: 60.02 s, elapsed: 7417.28 Feb 10 23:18:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic vacuum of table "db.public.tablename": index scans: 1 pages: 0 removed, 1001527 remain, 0 skipped due to pins, 0 skipped frozen tuples: 1346603 removed, 15288094 remain, 224598 are dead but not yet removable, oldest xmin: 736 buffer usage: 1104110 hits, 2210831 misses, 1716564 dirtied avg read rate: 2.329 MB/s, avg write rate: 1.808 MB/s system usage: CPU: user: 46.90 s, system: 60.02 s, elapsed: 7417.28 Feb 10 23:20:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic vacuum of table "db.public.tablename": index scans: 1 pages: 0 removed, 1001527 remain, 0 skipped due to pins, 0 skipped frozen tuples: 1346603 removed, 15288094 remain, 224598 are dead but not yet removable, oldest xmin: 736 buffer usage: 1104110 hits, 2210831 misses, 1716564 dirtied avg read rate: 2.329 MB/s, avg write rate: 1.808 MB/s system usage: CPU: user: 46.90 s, system: 60.02 s, elapsed: 7417.28 Feb 10 23:22:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic vacuum of table "db.public.tablename": index scans: 1 pages: 0 removed, 1001527 remain, 0 skipped due to pins, 0 skipped frozen tuples: 1346603 removed, 15288094 remain, 224598 are dead but not yet removable, oldest xmin: 736 buffer usage: 1104110 hits, 2210831 misses, 1716564 dirtied avg read rate: 2.329 MB/s, avg write rate: 1.808 MB/s system usage: CPU: user: 46.90 s, system: 60.02 s, elapsed: 7417.28 Feb 10 23:24:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic vacuum of table "db.public.tablename": index scans: 1 pages: 0 removed, 1001527 remain, 0 skipped due to pins, 0 skipped frozen tuples: 1346603 removed, 15288094 remain, 224598 are dead but not yet removable, oldest xmin: 736 buffer usage: 1104110 hits, 2210831 misses, 1716564 dirtied avg read rate: 2.329 MB/s, avg write rate: 1.808 MB/s system usage: CPU: user: 46.90 s, system: 60.02 s, elapsed: 7417.28 Feb 10 23:26:30 test-pc postgres[10808]: [1-1] db=,user=,app=,client= LOG: automatic vacuum of table "db.public.tablename": index scans: 1 pages: 0 removed, 1001527 remain, 0 skipped due to pins, 0 skipped frozen tuples: 1346603 removed, 15288094 remain, 224598 are dead but not yet removable, oldest xmin: 736 buffer usage: 1104110 hits, 2210831 misses, 1716564 dirtied avg read rate: 2.329 MB/s, avg write rate: 1.808 MB/s system usage: CPU: user: 46.90 s, system: 60.02 s, elapsed: 7417.28 ```
The result (I know it's missing the
Key Values, I just wanted to get the biggest part out of the way) is:This seems decent enough, but I might be forgetting something, but I guess we can cross that bridge when we cross it.
Looking forward to hear from you, Gilles!