Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1pkm3n-00017j-3n for pgsql-hackers@arkaria.postgresql.org; Fri, 07 Apr 2023 13:23:23 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1pkm3l-0007ll-Eg for pgsql-hackers@arkaria.postgresql.org; Fri, 07 Apr 2023 13:23:21 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1pkm3l-0007lc-40 for pgsql-hackers@lists.postgresql.org; Fri, 07 Apr 2023 13:23:21 +0000 Received: from smtp.outgoing.loopia.se ([93.188.3.37]) by magus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1pkm3g-001Rrp-K1 for pgsql-hackers@postgresql.org; Fri, 07 Apr 2023 13:23:20 +0000 Received: from s807.loopia.se (localhost [127.0.0.1]) by s807.loopia.se (Postfix) with ESMTP id 8B04D2F5FAFA for ; Fri, 7 Apr 2023 15:23:15 +0200 (CEST) Received: from s899.loopia.se (unknown [172.22.191.6]) by s807.loopia.se (Postfix) with ESMTP id 72DC02E28242; Fri, 7 Apr 2023 15:23:15 +0200 (CEST) Received: from s472.loopia.se (unknown [172.22.191.5]) by s899.loopia.se (Postfix) with ESMTP id 6DB2F2C8BA50; Fri, 7 Apr 2023 15:23:15 +0200 (CEST) X-Virus-Scanned: amavisd-new at amavis.loopia.se X-Spam-Flag: NO X-Spam-Score: -1 X-Spam-Level: X-Spam-Status: No, score=-1 tagged_above=-999 required=6.2 tests=[ALL_TRUSTED=-1] autolearn=disabled Received: from s979.loopia.se ([172.22.191.5]) by s472.loopia.se (s472.loopia.se [172.22.190.12]) (amavisd-new, port 10024) with LMTP id p_abMNQ3q4a7; Fri, 7 Apr 2023 15:23:14 +0200 (CEST) X-Loopia-Auth: user X-Loopia-User: daniel@yesql.se X-Loopia-Originating-IP: 89.255.232.193 Received: from smtpclient.apple (customer-89-255-232-193.stosn.net [89.255.232.193]) (Authenticated sender: daniel@yesql.se) by s979.loopia.se (Postfix) with ESMTPSA id 587CF10BC34C; Fri, 7 Apr 2023 15:23:14 +0200 (CEST) Content-Type: text/plain; charset=utf-8 Mime-Version: 1.0 (Mac OS X Mail 16.0 \(3696.120.41.1.2\)) Subject: Re: Should vacuum process config file reload more often From: Daniel Gustafsson In-Reply-To: Date: Fri, 7 Apr 2023 15:23:13 +0200 Cc: Masahiko Sawada , Robert Haas , Andres Freund , Tom Lane , Kyotaro Horiguchi , PostgreSQL Hackers , Amit Kapila Content-Transfer-Encoding: quoted-printable Message-Id: <23D2F3D0-90C2-428A-817F-1E16194DDC2D@yesql.se> References: <20230329.132155.629765142788133576.horikyota.ntt@gmail.com> <20230329.173456.1185961934810139447.horikyota.ntt@gmail.com> <935191FB-083B-4060-89FC-466F61FAA391@yesql.se> <1252075.1680547394@sss.pgh.pa.us> <20230403190837.qubpnwugfe2k2g46@awork3.anarazel.de> <7E06F879-7E20-4A6A-862F-CA72CDC9A323@yesql.se> <5028847C-937A-4CC2-B127-AFF5F9FB79C5@yesql.se> <2B703533-102A-47E5-A4F7-C6A68C09BB27@yesql.se> To: Melanie Plageman X-Mailer: Apple Mail (2.3696.120.41.1.2) List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk > On 7 Apr 2023, at 15:07, Melanie Plageman = wrote: > On Fri, Apr 7, 2023 at 2:53=E2=80=AFAM Masahiko Sawada = wrote: >> + /* Only log updates to cost-related variables */ >> + if (vacuum_cost_delay =3D=3D original_cost_delay && >> + vacuum_cost_limit =3D=3D original_cost_limit) >> + return; >>=20 >> IIUC by default, we log not only before starting the vacuum but also >> when changing cost-related variables. Which is good, I think, because >> logging the initial values would also be helpful for investigation. >> However, I think that we don't log the initial vacuum cost values >> depending on the values. For example, if the >> autovacuum_vacuum_cost_delay storage option is set to 0, we don't log >> the initial values. I think that instead of comparing old and new >> values, we can write the log only if >> message_level_is_interesting(DEBUG2) is true. That way, we don't need >> to acquire the lwlock unnecessarily. And the code looks cleaner to = me. >> I've attached the patch (use_message_level_is_interesting.patch) >=20 > Thanks for coming up with the case you thought of with storage param = for > cost delay =3D 0. In that case we wouldn't print the message initially = and > we should fix that. >=20 > I disagree, however, that we should condition it only on > message_level_is_interesting(). I think we should keep the logging frequency as committed, but condition = taking the lock on message_level_is_interesting(). > Actually, outside of printing initial values when the autovacuum = worker > first starts (before vacuuming all tables), I don't think we should = log > these values except when they are being updated. Autovacuum workers > could vacuum tons of small tables and having this print out at least > once per table (which I know is how it is on master) would be > distracting. Also, you could be reloading the config to update some > other GUCs and be oblivious to an ongoing autovacuum and get these > messages printed out, which I would also find distracting. >=20 > You will have to stare very hard at the logs to tell if your changes = to > vacuum cost delay and limit took effect when you reload config. I = think > with our changes to update the values more often, we should take the > opportunity to make this logging more useful by making it happen only > when the values are changed. >=20 > I would be open to elevating the log level to DEBUG1 for logging only > updates and, perhaps, having an option if you set log level to DEBUG2, > for example, to always log these values in VacuumUpdateCosts(). >=20 > I'd even argue that, potentially, having the cost-delay related > parameters printed at the beginning of vacuuming could be interesting = to > regular VACUUM as well (even though it doesn't benefit from config > reload while in progress). >=20 > To fix the issue you mentioned and ensure the logging is printed when > autovacuum workers start up before vacuuming tables, we could either > initialize vacuum_cost_delay and vacuum_cost_limit to something = invalid > that will always be different than what they are set to in > VacuumUpdateCosts() (not sure if this poses a problem for VACUUM using > these values since they are set to the defaults for VACUUM). Or, we > could duplicate this logging message in do_autovacuum(). Duplicating logging, maybe with a slightly tailored message, seem the = least bad option. > Finally, one other point about message_level_is_interesting(). I liked > the idea of using it a lot, since log level DEBUG2 will not be the > common case. I thought of it but hesitated because all other users of > message_level_is_interesting() are avoiding some memory allocation or > string copying -- not avoiding take a lock. Making this conditioned on > log level made me a bit uncomfortable. I can't think of a situation = when > it would be a problem, but it felt a bit off. Considering how uncommon DEBUG2 will be in production, I think = conditioning taking a lock on it makes sense. >> Also, while testing the autovacuum delay with relopt >> autovacuum_vacuum_cost_delay =3D 0, I realized that even if we set >> autovacuum_vacuum_cost_delay =3D 0 to a table, wi_dobalance is set to >> true. wi_dobalance comes from the following expression: >>=20 >> /* >> * If any of the cost delay parameters has been set = individually for >> * this table, disable the balancing algorithm. >> */ >> tab->at_dobalance =3D >> !(avopts && (avopts->vacuum_cost_limit > 0 || >> avopts->vacuum_cost_delay > 0)); >>=20 >> The initial values of both avopts->vacuum_cost_limit and >> avopts->vacuum_cost_delay are -1. I think we should use ">=3D 0" = instead >> of "> 0". Otherwise, we include the autovacuum worker working on a >> table whose autovacuum_vacuum_cost_delay is 0 to the balancing >> algorithm. Probably this behavior has existed also on back branches >> but I haven't checked it yet. >=20 > Thank you for catching this. Indeed this exists in master since > 1021bd6a89b which was backpatched. I checked and it is true all the = way > back through REL_11_STABLE. >=20 > Definitely seems worth fixing as it kind of defeats the purpose of the > original commit. I wish I had noticed before! >=20 > Your fix has: > !(avopts && (avopts->vacuum_cost_limit >=3D 0 || > avopts->vacuum_cost_delay >=3D 0)); >=20 > And though delay is required to be >=3D 0 > avopts->vacuum_cost_delay >=3D 0 >=20 > Limit does not. It can just be > 0. >=20 > postgres=3D# create table foo (a int) with = (autovacuum_vacuum_cost_limit =3D 0); > ERROR: value 0 out of bounds for option = "autovacuum_vacuum_cost_limit" > DETAIL: Valid values are between "1" and "10000". >=20 > Though >=3D is also fine, the rest of the code in all versions always > checks if limit > 0 and delay >=3D 0 since 0 is a valid value for = delay > and not for limit. Probably best we keep it consistent (though the = whole > thing is quite confusing). +1 -- Daniel Gustafsson