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 1pmFZJ-0007pc-Da for pgsql-hackers@arkaria.postgresql.org; Tue, 11 Apr 2023 15:06:01 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1pmFZH-0004Fc-2d for pgsql-hackers@arkaria.postgresql.org; Tue, 11 Apr 2023 15:05:59 +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 1pmFZG-0004FT-MP for pgsql-hackers@lists.postgresql.org; Tue, 11 Apr 2023 15:05:58 +0000 Received: from mail-oi1-x234.google.com ([2607:f8b0:4864:20::234]) by magus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 (Exim 4.94.2) (envelope-from ) id 1pmFZD-002Fkw-CF for pgsql-hackers@postgresql.org; Tue, 11 Apr 2023 15:05:58 +0000 Received: by mail-oi1-x234.google.com with SMTP id w13so26217053oik.2 for ; Tue, 11 Apr 2023 08:05:54 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; t=1681225553; h=content-transfer-encoding:cc:to:subject:message-id:date:from :in-reply-to:references:mime-version:from:to:cc:subject:date :message-id:reply-to; bh=4u1/pC8BQl4otGVah2tJz1/zoXSKlth4TBq2cIcMDpU=; b=Sr8l6VHxbkNcLalXvgd3ULxARVF3n9N6yGUdMRgM0TqJb3KEW9VxQdwRF3dBcm0CWB QvIIV5XWFnX9QtwfEeggpovTtc4HwxoOIpC3nYu9nFaf03p1Jjzb2mw17mkBu9ZbDqua fEsV87rEWA9lOMhpMIPCUoPi8zSv4xuuYAuX2CiwJ2QdxHEplFYxr2uWieqrSiDfcrJ4 G8dfOQ8+x8UrNOd/uuEtUC0he0L6vn8xEtn2uRjU8LHNkzslPOdvdXdx8nr+dPQof1Nu i7xj3LdnY1ekFacnGEADdot8ygxc2Ly1HWJMMT7OI07frkYPk69zISnllGNgdMVxxMzM HAiQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; t=1681225553; h=content-transfer-encoding:cc:to:subject:message-id:date:from :in-reply-to:references:mime-version:x-gm-message-state:from:to:cc :subject:date:message-id:reply-to; bh=4u1/pC8BQl4otGVah2tJz1/zoXSKlth4TBq2cIcMDpU=; b=nMLDUvTHnCCSPG/DN3n+Nry+6ibTCvW4mapqa6531UTbl++S46NdyllR9/w9tZAz5K 67NFUYw2vEPKRcU759E00z15Pb5+5xMJZPEnURj2BhvahZVSho0Y4hrhbKXkJYuz8YUA QxEIMjvSQ/wHxsicxbxC9psSGGSxRjD092YGf6ZLxpH8vDfBPnnhoHmBBCR65oU0/s/f MPiJj/2S+butMWGTd689PUPQOEMagP463L+7K6/SGt0Y/Ch/u5ODt2usuhQSKbPbHMT9 1cvWm6QU8EjgDEIkfp0jsmHdc6pqRRxhc8pTpcXsBtcYM941kiTvEQbZoRVZzVXpXTkD hZkA== X-Gm-Message-State: AAQBX9dobu5n7M+jiiynXS21/WSnoeVRcYHKt9gOWJT5mQnoNsJTbVKQ X4GcJ6Wo1py5aN709AE1qpL60s9BUoOxqIY9Wv4= X-Google-Smtp-Source: AKy350aB4rLTsfDRLpiJDLwz11H9tzQqHW+RZSgHMJ/Ynp9MPeDF5ZKxCsXODoYIaigMWqNf4psdT4boG713XBLpsKg= X-Received: by 2002:a05:6808:210:b0:383:fcba:70e6 with SMTP id l16-20020a056808021000b00383fcba70e6mr2316330oie.1.1681225553104; Tue, 11 Apr 2023 08:05:53 -0700 (PDT) MIME-Version: 1.0 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> <23D2F3D0-90C2-428A-817F-1E16194DDC2D@yesql.se> In-Reply-To: <23D2F3D0-90C2-428A-817F-1E16194DDC2D@yesql.se> From: Masahiko Sawada Date: Wed, 12 Apr 2023 00:05:16 +0900 Message-ID: Subject: Re: Should vacuum process config file reload more often To: Daniel Gustafsson Cc: Melanie Plageman , Robert Haas , Andres Freund , Tom Lane , Kyotaro Horiguchi , PostgreSQL Hackers , Amit Kapila Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk On Fri, Apr 7, 2023 at 10:23=E2=80=AFPM Daniel Gustafsson = wrote: > > > On 7 Apr 2023, at 15:07, Melanie Plageman w= rote: > > 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; > >> > >> 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) > > > > Thanks for coming up with the case you thought of with storage param fo= r > > cost delay =3D 0. In that case we wouldn't print the message initially = and > > we should fix that. > > > > 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. > > > > 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. > > For debugging purposes, I think it could also be important information that the cost values are not changed. Personally, I prefer to log the current state rather than deciding for ourselves which events are important. If always logging these values in DEBUG2 had been distracting, we might want to lower it to DEBUG3. > > 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(). I'm not really sure it's a good idea to change the log messages and events depending on elevel. Do you know we have any precedents ? > > > > I'd even argue that, potentially, having the cost-delay related > > parameters printed at the beginning of vacuuming could be interesting t= o > > regular VACUUM as well (even though it doesn't benefit from config > > reload while in progress). > > > > 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 lea= st > 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 whe= n > > it would be a problem, but it felt a bit off. > > Considering how uncommon DEBUG2 will be in production, I think conditioni= ng > taking a lock on it makes sense. The comment of message_level_is_interesting() says: * This is useful to short-circuit any expensive preparatory work that * might be needed for a logging message. Which can apply to taking a lwlock, I think. > > >> 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: > >> > >> /* > >> * If any of the cost delay parameters has been set individuall= y for > >> * this table, disable the balancing algorithm. > >> */ > >> tab->at_dobalance =3D > >> !(avopts && (avopts->vacuum_cost_limit > 0 || > >> avopts->vacuum_cost_delay > 0)); > >> > >> The initial values of both avopts->vacuum_cost_limit and > >> avopts->vacuum_cost_delay are -1. I think we should use ">=3D 0" inste= ad > >> 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. > > > > 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. Thanks for checking! > > > > Definitely seems worth fixing as it kind of defeats the purpose of the > > original commit. I wish I had noticed before! > > > > Your fix has: > > !(avopts && (avopts->vacuum_cost_limit >=3D 0 || > > avopts->vacuum_cost_delay >=3D 0)); > > > > And though delay is required to be >=3D 0 > > avopts->vacuum_cost_delay >=3D 0 > > > > Limit does not. It can just be > 0. > > > > postgres=3D# create table foo (a int) with (autovacuum_vacuum_cost_limi= t =3D 0); > > ERROR: value 0 out of bounds for option "autovacuum_vacuum_cost_limit" > > DETAIL: Valid values are between "1" and "10000". > > > > 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 whol= e > > thing is quite confusing). > > +1 +1. I misunderstood the initial value of autovacuum_vacuum_cost_limit relop= tion. Regards, --=20 Masahiko Sawada Amazon Web Services: https://aws.amazon.com