Message-ID: <34f2beb882d607b360dea53433f95a767d1cad8f.camel@cybertec.at>
Subject: Re: Autovacuum endless loop in heap_page_prune()?
From: Laurenz Albe <laurenz.albe@cybertec.at>
To: Peter <pmc@citylink.dinoex.sub.org>, pgsql-general@lists.postgresql.org
Date: Mon, 27 May 2024 11:25:47 +0200
In-Reply-To: <ZlHCxjfpxXyqS_wz@disp.intra.daemon.contact>
References: <ZlHCxjfpxXyqS_wz@disp.intra.daemon.contact>
Autocrypt: addr=laurenz.albe@cybertec.at; prefer-encrypt=mutual; keydata=mQINBGGDwAQBEADgbWy5cKXQld3N2mF+DFyiNFbi2oBl2T+XgxpPF8wTRw2D/u4bBKXP0SYSE/lA86jIVNWWU0gf1KODIkVvgJm2w4vH2VBV1b7ddVViGl1Iu+9zaRnv9wulhnH42KefepXnoean6UT1EzLM0opF/Ik0j+40TxdRtobkBprkQUyHDXWlHc2ffPs3SipyFEP9AVLf7ejRC46CXWDnsqjOBSMEW8Z4HiK/8RrPZBsKLts8dJxKF4pygOdJb0CWk8k/X1jbcfdxo+zOLjOMvJcSJ2pFdJmQHU+JufB3rePziqQ2S9Ur6sccr9XnTC1GVBWN4Lf5VHq+vf+bFJjVwg+2hrySZnAVfcOrxoqFLErr7ug1zN2nM1kcpgA4VWn4gxlJtYNYYq+9WxX5dtvnNANlG3ZCrRKQzl8lxtzoF6Zo7LUhEqPaHDwn7Rvs+IdbOn41lF5UDTJGqmC4gS/bZydW2Fy3YWm4aSaN9fgFf8D+PVkrlKAZB7gBLz1TyHjbcRf85cYF+GKKrDld5SzMB/V60VX3oP/Eo8ikFpyWaqiz1f9X7MBot3/PjJkY+wDzp3nmb19QEcOBuQiSQ4xds2r0HewbuHTAR68u8jNNMGmpm2j4x+g09Jd/WQDjqlTBZ/jEltH41fYCCPWMfljXTOOXu2eLNGdfi7ETZogtwjM9oTtSPQARAQABtCdMYXVyZW56IEFsYmUgPGxhdXJlbnouYWxiZUBjeWJlcnRlYy5hdD6JAk4EEwEIADgWIQR0CqhbZGGABqoaSbdi8bhXA2EdmAUCYYPABAIbAwULCQgHAgYVCgkICwIEFgIDAQIeAQIXgAAKCRBi8bhXA2EdmM/6EADK232JCwmBzhlj8h7U9CjG6kx0JHP3uJGv+XfsHtHAlmY/RCwF1BHMEsRlk
 bT5UrLvJ2jb99bA9QARzhFaxzyn0F/BUKzuIjRGNs/n6d5dNUFA0kOt8sX+TacmC GEyjEBCrVCm4ranBiUyePn9NhHNWnaex7pJyqvMLLdwW9BEMJx0Fqo+DN8ukbXmYRsmhEtd3ue+x/luYmOmJnaGtzInaY5aOJYbW9XqoRIZkZvOCgbi1FfvNmoqWa+3oVxTOgw9RafjJDyW0lTHzKGjbGI5ofMU98l+/hKJFYJqWUF6VpFJY5YIcN/1lf4ZICMwDl+MPIVo/tpq8L10seJL28nLlvw3K+cI+TVW8IW/qL/LyVoDofI3USeOORuYmhpWRhik8JXX6xf3v6GrRilJIPWNFIJbxm1ZblQiQnOw3IOW7T+8nAmPin1HKqM3VrOrJQ2VtShsefNBibNAsr1oFaqcDBkn3yGG8i6CTW+FyO4PZ+/EwNxMVgktxbYdy5AT1/lpXr5tB+phhLIyVfiBvrWs5EThxYMQ/L8Y85c3GMsAy1l/x4h3jqySIYy3SCU9+jc5UVuNnXljbvkEzJ+NLWJ6C1rACFWrMszgPdh5tCrlRY9PpmYll4JbCgb8BtxEIUmR+xr50/ZElEK5iml7Q00KUekCcDt+36PsyGFTXBzNOrkCDQRhg8AEARAAzOZ2tLHlI4rrhG411h6cdCFjBZxuljaFCxFyHn3m6wbGLqwBUWC5k8UrRqjHMz88KcTSaNO7XGAmCqPdWd2SeflPZRnNTbjsVpw7mLdffsBm4JX7kki2Pvk5h0NtYeidXT1PSpc2ri4DutYXuT9uD8RAm1wUDCE5HQNUihT/WH6opt+hskHW21uHao0+y822tG0QQcGMqdQR5Vxdxj89wiEPdqW+HpU/oOZIhrf2E7prduAppxixjHy/o1rcnoznnJvc8D3+YgI9O0LrBMij89dM55pRGbLovTR1oGR3U74sX774+0xmSzeIKwZfiMUz7Atlvfk5SHOsRUFPN2Ux9kaXiiBibQpHFxt7b
 lDrT4wxdLJ/XCdbPPAyl+lZtOLsaHEEZvYNyTXwZc35dVf3R4/oz20HoG6s7ct8e1 AQygj43XAERzty9SkWgxs8+grp1PrGx6FHVSYRqBM8dS/ZR6yRVwOwJXPyaSSqfIF21DkE4j1y4n+ItSewPGoRp8K/yWCikt6qlkVkO2ASNIiX04fAbtzwVOaNn8ZMRNqyvLc1fED4sr49onE4cAIcBLjcC3KL+w9DUGRQCdziROj5H2Yl/sXGPdMciUHo/Uz2rggc+2th3bQiMhrHWSsBpUkDQp0yWewemstPpPgBL3h2fHKaX8B9oH5Qu/H1IgrOuX8AEQEAAYkCNgQYAQgAIBYhBHQKqFtkYYAGqhpJt2LxuFcDYR2YBQJhg8AEAhsMAAoJEGLxuFcDYR2YuPwQAMkpGtR80pQ1gVsONhdkqj0H2eU66efP/gO3CoyaoIcvrpKYj7C2HipVSmkt1gpByL0X4AMQ/vKuknUz3wd28Ba+G1dCfbVs/Xiusq+SmpUj5rTwmYqdSjWMuCo1R6oS5hdJMdUUJYGMT0QkVlm1KnW8jkmCTl9GzjDxOAsN9O6/6lPzaGFtk9XF+34Bry/N4HKiJkqpC4+UTd0AprPfzJ2jdT64e1F0+W88X8y1bTTgNrHwK4mDiLnlE4SKRuEm54lNhJz//ar86Or5BErzNpM6TL7lk44QS06hwsMrEdKIy8J/SYJPjfzR8tIUnKscclVpOgjKaBqC+0iFiVaRqAgfOlIEiezX6kMh5Q2FIUfqs46qWhhXjRrdKOEoStYAaikdLu5ZXr7vfb0ZaDh+ZwTQtbSMFolyOkecwI81MCdbMfT/1TqIGTOdAj5as9fAakk0jb2pXgUYQ8X1DVTR8ahSDVEaw9VTmWiSvTxvguVJ1Mb7gG4Gmh6aviDTJhfXtH4rPUNXhDLqrTH8JkJjyKROOMakIF68Hjse5vUfUxreBEOtb5r1Coa2Fe7ncJayaSE7ryrDbFqpZ
 36UMAx4ulWMyqJajLNGY0DdG8qIsR5nxRhrnK/mrCidZ8F9/D3bWAl4rjtHlsztN59 +AnW5l0HsQcY9ntFL/zEBOaonjdJf
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable
User-Agent: Evolution 3.50.4 (3.50.4-1.fc39) 
MIME-Version: 1.0
Archived-At: <https://www.postgresql.org/message-id/34f2beb882d607b360dea53433f95a767d1cad8f.camel%40cybertec.at>
Precedence: bulk

On Sat, 2024-05-25 at 12:51 +0200, Peter wrote:
> =C2=A0I just found Autovacuum run for 6 hours on a 8 GB table, VACUUM que=
ry
> doesnt cancel, cluster doesn't stop, autovacuum worker is not
> killable, truss shows no activity, after kill -6 this backtrace:
>=20
> * thread #1, name =3D 'postgres', stop reason =3D signal SIGABRT
> =C2=A0 * frame #0: 0x0000000000548063 postgres`HeapTupleSatisfiesVacuumHo=
rizon + 531
> =C2=A0=C2=A0=C2=A0 frame #1: 0x000000000054aed9 postgres`heap_page_prune =
+ 537
> =C2=A0=C2=A0=C2=A0 frame #2: 0x000000000054e38a postgres`heap_vacuum_rel =
+ 3626
> =C2=A0=C2=A0=C2=A0 frame #3: 0x00000000006af382 postgres`vacuum_rel + 626
> =C2=A0=C2=A0=C2=A0 frame #4: 0x00000000006aeeeb postgres`vacuum + 1611
> =C2=A0=C2=A0=C2=A0 frame #5: 0x00000000007b4664 postgres`do_autovacuum + =
4292
> =C2=A0=C2=A0=C2=A0 frame #6: 0x00000000007b2342 postgres`AutoVacWorkerMai=
n + 866
> =C2=A0=C2=A0=C2=A0 frame #7: 0x00000000007b1f97 postgres`StartAutoVacWork=
er + 39
> =C2=A0=C2=A0=C2=A0 frame #8: 0x00000000007ba0df postgres`sigusr1_handler =
+ 783
> =C2=A0=C2=A0=C2=A0 frame #9: 0x00000008220da627 libthr.so.3`___lldb_unnam=
ed_symbol683 + 215
> =C2=A0=C2=A0=C2=A0 frame #10: 0x00000008220d9b1a libthr.so.3`___lldb_unna=
med_symbol664 + 314
> =C2=A0=C2=A0=C2=A0 frame #11: 0x00007ffffffff913
> =C2=A0=C2=A0=C2=A0 frame #12: 0x00000000007bba25 postgres`ServerLoop + 15=
41
> =C2=A0=C2=A0=C2=A0 frame #13: 0x00000000007b9467 postgres`PostmasterMain =
+ 3207
> =C2=A0=C2=A0=C2=A0 frame #14: 0x000000000071a566 postgres`main + 758
> =C2=A0=C2=A0=C2=A0 frame #15: 0x00000000004f9995 postgres`_start + 261
>=20
> After restart, no problems reported yet.
>=20
> Storyline:
> this is the file-list table of my backup/archive system, contains ~50
> mio records. Recently I found a flaw in the backup system, so that some
> old records weren't removed. I wrote a script to do this, that script
> did run first at 04:15 and reported it had now removed a lot of old
> data. I looked into pgadmin4 and it reported 9 mio dead tuples.

This smells of index corruption.

I have seen cases where a corrupted index sends VACUUM into an endless loop
so that it does not react to query cancellation.

Check the index with the "bt_index_check()" function from the "amcheck"
extension.  If that reports a problem, rebuild the index.

Of course, as always, try to figure out how that could happen.
Apart from hardware problems, one frequent cause is upgrading glibc
(if the index on a string column or expression).

Yours,
Laurenz Albe