Re: How can i be certain autovacuum is causing reuse if table still grows

On Tue, Aug 4, 2020 at 5:03 AM Guillaume Lelarge <guillaume(at)lelarge(dot)info>
wrote:

> Le lun. 3 août 2020 à 23:36, Sidney Aloisio Ferreira Pryor <
> sidney(at)tjrj(dot)jus(dot)br> a écrit :
>
>> Hi Keith, how are you?
>> Hope you are very fine.
>>
>> As i promissed we ran vacuum full on that table on a test environment
>> similar to production and it took 11 hours to complete.
>> It reduced the original table segment from 2.3TB to 100GB as below (note
>> that it is still growing...).
>> So we are now proposing to our Direction a maintenance window to vacuum
>> full production.
>>
>> Original:
>> table_schema | table_name | total_size | data_size |
>> external_size
>>
>> --------------+---------------------+------------+-----------+---------------
>> public | flip_pagina_edicao | 4578 GB | 2880 GB | 1699 GB
>>
>> Copy of Orginal (after vacuum full):
>> table_schema | table_name | total_size | data_size |
>> external_size
>>
>> --------------+---------------------+------------+-----------+---------------
>> public | flip_pagina_edicao | 180 GB | 100 GB | 80 GB
>>
>>
>> In meantime if you could please help us understand some curious facts
>> below about vacuum verbose (not full).
>> I am running on production another vacuum verbose (not full) because that
>> first one stucked on the same indexes for 3 days.
>> But now is on a 3rd sequential scan of all indexes of that table followed
>> by a scan on the table itself.
>> It is not finishing even completing scans.
>>
>> 1) Why it is scanning again and not finishing vacuum?
>>
>>
> Your maintenance_work_mem parameter value is probably too low.
>
> 2) I noticed that on all scans it is taking 12 hours only on an index on
>> a bpchar(1) column (character(1) DEFAULT 'N'::bpchar).
>> All other indexes and even the table it self are running too much faster,
>> can you guess a reason for this?
>>
>> CREATE INDEX ocrindex
>> ON public.flip_pagina_edicao
>> USING btree
>> (ocr COLLATE pg_catalog."default");
>>
>>
> Not used, so not in cache? or much bigger than the other ones?
>
> 3) And is repeatly scanning 11.184.520 or 521 or 528 row versions.
>> Why does it not end and scans again the same amount of row versions?
>>
>>
> Well, VACUUM is a multi-steps operation. It first scans the table and puts
> every tid that needs to be deleted in memory. Once done, il will scan
> indexes. But if there's more TID than memory can hold, it will have to do
> multiple scans of the table and the indexes. It seems clear in your case
> that, when VACUUM finds 11184520 TID, memory is full. By the way, memory is
> limited by a parameter named maintenance_work_mem. So what is its current
> value?
>
> flip=# vacuum verbose flip_pagina_edicao;
>> INFO: vacuuming "public.flip_pagina_edicao"
>> INFO: scanned index "id_caderno" to remove 11184520 row versions
>> DETAIL: CPU 155.34s/540.40u sec elapsed 1101.49 sec
>> INFO: scanned index "ordem_index" to remove 11184520 row versions
>> DETAIL: CPU 253.35s/870.77u sec elapsed 1962.36 sec
>> INFO: scanned index "primary00024" to remove 11184520 row versions
>> DETAIL: CPU 134.10s/478.79u sec elapsed 922.02 sec
>> INFO: scanned index "ordem" to remove 11184520 row versions
>> DETAIL: CPU 265.16s/932.90u sec elapsed 1878.20 sec
>> INFO: scanned index "flip_pagina_edicao_pkey" to remove 11184520 row
>> versions
>> DETAIL: CPU 149.51s/523.42u sec elapsed 949.68 sec
>> INFO: scanned index "flip_flippagedic_idcaderno" to remove 11184520 row
>> versions
>> DETAIL: CPU 460.19s/1171.75u sec elapsed 2696.89 sec
>> INFO: scanned index "nomepdfindex" to remove 11184520 row versions
>> DETAIL: CPU 598.88s/1286.84u sec elapsed 3543.26 sec
>> INFO: scanned index "ocrindex" to remove 11184520 row versions
>> DETAIL: CPU 25657.30s/18907.82u sec elapsed 46652.49 sec
>> INFO: scanned index "idr_documento_index" to remove 11184520 row versions
>> DETAIL: CPU 321.96s/968.75u sec elapsed 2004.91 sec
>> INFO: "flip_pagina_edicao": removed 11184520 row versions in 3762529
>> pages
>> DETAIL: CPU 165.65s/95.06u sec elapsed 647.49 sec
>> INFO: scanned index "id_caderno" to remove 11184521 row versions
>> DETAIL: CPU 175.89s/461.26u sec elapsed 1098.74 sec
>> INFO: scanned index "ordem_index" to remove 11184521 row versions
>> DETAIL: CPU 301.57s/887.26u sec elapsed 2052.44 sec
>> INFO: scanned index "primary00024" to remove 11184521 row versions
>> DETAIL: CPU 150.12s/461.92u sec elapsed 947.74 sec
>> INFO: scanned index "ordem" to remove 11184521 row versions
>> DETAIL: CPU 286.29s/896.03u sec elapsed 1954.21 sec
>> INFO: scanned index "flip_pagina_edicao_pkey" to remove 11184521 row
>> versions
>> DETAIL: CPU 140.75s/423.38u sec elapsed 901.04 sec
>> INFO: scanned index "flip_flippagedic_idcaderno" to remove 11184521 row
>> versions
>> DETAIL: CPU 455.24s/1043.27u sec elapsed 2551.54 sec
>> INFO: scanned index "nomepdfindex" to remove 11184521 row versions
>> DETAIL: CPU 644.78s/1163.80u sec elapsed 3469.67 sec
>> INFO: scanned index "ocrindex" to remove 11184521 row versions
>> DETAIL: CPU 25951.95s/18712.36u sec elapsed 49880.37 sec
>> INFO: scanned index "idr_documento_index" to remove 11184521 row versions
>> DETAIL: CPU 274.05s/710.37u sec elapsed 1799.98 sec
>> INFO: "flip_pagina_edicao": removed 11184521 row versions in 2358457
>> pages
>> DETAIL: CPU 68.83s/36.81u sec elapsed 353.40 sec
>> INFO: scanned index "id_caderno" to remove 11184528 row versions
>> DETAIL: CPU 156.47s/372.75u sec elapsed 1022.31 sec
>> INFO: scanned index "ordem_index" to remove 11184528 row versions
>> DETAIL: CPU 257.13s/669.86u sec elapsed 2057.05 sec
>> INFO: scanned index "primary00024" to remove 11184528 row versions
>> DETAIL: CPU 116.29s/319.86u sec elapsed 842.55 sec
>> INFO: scanned index "ordem" to remove 11184528 row versions
>> DETAIL: CPU 232.78s/562.22u sec elapsed 2676.35 sec
>> INFO: scanned index "flip_pagina_edicao_pkey" to remove 11184528 row
>> versions
>> DETAIL: CPU 91.21s/241.00u sec elapsed 875.27 sec
>> INFO: scanned index "flip_flippagedic_idcaderno" to remove 11184528 row
>> versions
>> DETAIL: CPU 285.71s/585.63u sec elapsed 2593.08 sec
>> INFO: scanned index "nomepdfindex" to remove 11184528 row versions
>> DETAIL: CPU 413.55s/692.77u sec elapsed 3843.78 sec
>>
>> Thank you.
>> Sidney Pryor.
>>
>>
>> --
> Guillaume.
>

Guillaume answered most of your questions (thanks!).

Since this shrunk the size of your table so dramatically, the best thing
going forward after fixing things would be to tune this table specifically
until you find the point where vacuum is running often enough to clean up
enough space for future updates/deletes to just use that space instead of
allocating more. For reference again

https://www.keithf4.com/per-table-autovacuum-tuning/

There will likely always be a certain level of bloat, but that's not a bad
thing as long as it doesn't continually keep growing over time. So I'd
recommend running something like pg_bloat_check on this table maybe once a
week, or even once a day, during off-peak hours to keep an eye on it. It
may take a while to narrow down the sweet spot of how and when to get
autovacuum to run and keep the free space in balance with future writes.
And if you have particularly heavy periods of writes, it may require
manually scheduling vacuums around those times as well.

--
Keith Fiske
Senior Database Engineer
Crunchy Data - http://crunchydata.com