Subject: Re: Set log_lock_waits=on by default

From: Michael Banck <[email-masked]>
Date: Thu, 18 Jul 2024 12:25:55 +0200

Hi,

this patch is still on the table, though for v18 now.

Nathan mentioned up-thread that he was hesitant to commit this without
further discussion. Laurenz, Stephen and I are +1 on this, but when it 
comes to committers having chimed in only Tom did so far and was -1.

Are there any others who have an opinion on this?

On Tue, Feb 06, 2024 at 12:29:10PM -0500, Tom Lane wrote:
> Nathan Bossart <[email-masked]> writes:
> > It looks like there are two ideas:
> 
> > * Separate log_lock_waits from deadlock_timeout.  It looks like this idea
> >   has a decent amount of support, but I didn't see any patch for it so far.
> 
> I think the support comes from people who have not actually looked at
> the code.  The reason they are not separate is that the same timeout
> service routine does both things.  To pull them apart, you would have
> to (1) detangle that code and (2) incur the overhead of two timeout
> events queued for every lock wait.  It's not clear to me that it's
> worth it.  In some sense, deadlock_timeout is exactly the length of
> time after which you want to get concerned.
> 
> >   IMHO this is arguably a prerequisite for setting log_lock_waits on by
> >   default, as we could then easily set it higher by default to help address
> >   concerns about introducing too much noise in the logs.
> 
> Well, that's the question --- would it be sane to enable
> log_lock_waits by default if we don't separate them?

I think it would be, I have not seen people change the value of
deadlock_timeout so far, and I think 1s is a reasonable long time for a
default lock wait to be reported.
 
> > * Set log_lock_waits on by default.  The folks on this thread seem to
> >   support this idea, but given the lively discussion for enabling
> >   log_checkpoints by default [0], I'm hesitant to commit something like
> >   this without further community discussion.
> 
> I was, and remain, of the opinion that that was a bad idea that
> we'll eventually revert, just like we previously got rid of most
> inessential log chatter in the default configuration.

I somewhat agree here in the sense that log_checkpoints is really only
useful for heavily-used servers, but this is a digression and due to the
fact that log_checkpoints emits log lines periodically while
log_lock_waits only emits them for application conflicts (and arguably
application bugs), I do not think those would be in the "issential log
chatter" group similar to how all SQL errors are not in that group
either.

Michael

---

From: Laurenz Albe <[email-masked]>
Date: Fri, 19 Jul 2024 11:54:42 +0200

> Are there any others who have an opinion on this?

If we want to tally up, there were also +1 votes from Christoph Berg,
Shinya Kato, Nikolay Samokhvalov, Jeremy Schneider and Frédéric Yhuel.

The major criticism is Tom's that it might unduly increase the log volume.

I'm not trying to rush things, but I see little point in kicking a trivial
patch like this through many commitfests.  If no committer wants to step
up and commit this, it should be rejected.

Yours,
Laurenz Albe

---

From: Christoph Berg <[email-masked]>
Date: Fri, 19 Jul 2024 15:24:24 +0200

Re: Laurenz Albe
> up and commit this, it should be rejected.

That would be a pity, I still think log_lock_waits=on by default would
be a good thing.

I have not seen any server yet where normal, legitimate operation
would routinely trigger the message. (If it did, people should likely
have used SKIP LOCKED or NOWAIT instead.) It would only increase the
log volume on systems that have a problem.

Christoph

---

From: Robert Haas <[email-masked]>
Date: Fri, 19 Jul 2024 10:14:14 -0400

> log volume on systems that have a problem.

I've definitely seen systems where this setting would have generated
regular output, because I see a lot of systems that are chronically
overloaded. I think waits of more than 1 second for tuple locks could
be pretty routine on some servers -- or XID or VXID locks. So I'm more
cautious about this than most people on this thread: log_checkpoints
won't generate more than a few lines of output per checkpoint
interval, and a checkpoint cycle will be on the order of minutes, so
it's really never that much volume. On the other hand, in theory, this
setting can generate arbitrarily many messages.

That's why I originally proposed separating deadlock_timeout from
log_lock_waits, because I think 1s might actually end up being kind of
noisy for some people. On the other hand, I take Tom's point that
separating those things would be hard to code and, probably more
importantly, require a second timer.

I'm not strongly opposed to just turning this on by default. It's not
like we can't change our minds, and it's also not like individual
customers can't change the default. I think Tom has entirely the wrong
idea about what a typical log file on a production server looks like.
In every case I've seen, it's full of application generated errors
that will never be fixed, connection logging, statement logging, and
other stuff that is there just in case but will normally be ignored.
Finding the messages that indicate real database problems is typically
quite difficult, even if they're all enabled. If they're disabled by
default, well then the useless crap is the ONLY thing you find in the
log file, and when the customer has a problem, the first thing you
have to do is tell them to turn on all the GUCs that log the actually
important stuff and wait until the problem recurs.

I have yet to run into a customer who was thrilled about receiving that message.

-- 
Robert Haas
EDB: http://www.enterprisedb.com

---

From: Greg Sabino Mullane <[email-masked]>
Date: Fri, 19 Jul 2024 10:28:24 -0400

> Are there any others who have an opinion on this?

Big +1 to having it on by default. It's already one of the first things I
turn on by default on any system I come across. The log spam is minimal,
compared to all the other stuff that ends up in there. And unlike most of
that stuff, this is output you generally want and need, when problems start
occurring.

Cheers,
Greg

---

From: Jelte Fennema-Nio <[email-masked]>
Date: Fri, 19 Jul 2024 16:29:30 +0200

Late to the party, but +1 from me on this default change also

---

From: Laurenz Albe <[email-masked]>
Date: Tue, 08 Apr 2025 16:32:49 +0200

> up and commit this, it should be rejected.

Well, it didn't make v18.

But this patch got enough votes in favor that I am not going to withdraw it.

Yours,
Laurenz Albe

---

From: Shinya Kato <[email-masked]>
Date: Thu, 4 Sep 2025 14:12:25 +0900

Hi,

> But this patch got enough votes in favor that I am not going to withdraw it.

Thank you for discussing it.

diff --git a/src/backend/utils/misc/guc_tables.c
b/src/backend/utils/misc/guc_tables.c
index f7c9882f7c..1f3d56e6ee 100644
--- a/src/backend/utils/misc/guc_tables.c
+++ b/src/backend/utils/misc/guc_tables.c
@@ -1519,7 +1519,7 @@ struct config_bool ConfigureNamesBool[] =
  NULL
  },
  &log_lock_waits,
- false,
+ true,
  NULL, NULL, NULL
  },
  {

Due to 635998965 [0], you need to change guc_parameters.dat instead of
guc_tables.c.

[0] https://git.postgresql.org/gitweb/?p=postgresql.git;a=commit;h=63599896545c7869f7dd28cd593e8b548983d613

--
Best regards,
Shinya Kato
NTT OSS Center

---

From: Laurenz Albe <[email-masked]>
Date: Sun, 07 Sep 2025 23:46:32 +0200

> Due to 635998965 [0], you need to change guc_parameters.dat instead of

Thanks for pointing that out to me!
Here is an updated patch.

Yours,
Laurenz Albe
From aa04f6cf6e7c89f1107ffc6eb661da65082459fe Mon Sep 17 00:00:00 2001
From: Laurenz Albe <[email-masked]>
Date: Sun, 7 Sep 2025 23:44:38 +0200
Subject: [PATCH v2] Default to log_lock_waits=on

If someone is stuck behind a lock for more than a second,
that is almost always a problem that is worth a log entry.

Author: Laurenz Albe <[email-masked]>
Reviewed-By: Michael Banck <[email-masked]>
Reviewed-By: Robert Haas <[email-masked]>
Reviewed-By: Christoph Berg <[email-masked]>
Reviewed-By: Stephen Frost <[email-masked]>
Discussion: https://postgr.es/m/b8b8502915e50f44deb111bc0b43a99e2733e117.camel%40cybertec.at
---
 doc/src/sgml/config.sgml                      | 2 +-
 src/backend/storage/lmgr/proc.c               | 2 +-
 src/backend/utils/misc/guc_parameters.dat     | 2 +-
 src/backend/utils/misc/postgresql.conf.sample | 2 +-
 4 files changed, 4 insertions(+), 4 deletions(-)

diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml
index 2a3685f474a..3c33d5d0fbc 100644
--- a/doc/src/sgml/config.sgml
+++ b/doc/src/sgml/config.sgml
@@ -7929,7 +7929,7 @@ log_line_prefix = '%m [%p] %q%u@%d/%a '
         Controls whether a log message is produced when a session waits
         longer than <xref linkend="guc-deadlock-timeout"/> to acquire a
         lock.  This is useful in determining if lock waits are causing
-        poor performance.  The default is <literal>off</literal>.
+        poor performance.  The default is <literal>on</literal>.
         Only superusers and users with the appropriate <literal>SET</literal>
         privilege can change this setting.
        </para>
diff --git a/src/backend/storage/lmgr/proc.c b/src/backend/storage/lmgr/proc.c
index e9ef0fbfe32..96f29aafc39 100644
--- a/src/backend/storage/lmgr/proc.c
+++ b/src/backend/storage/lmgr/proc.c
@@ -60,7 +60,7 @@ int			LockTimeout = 0;
 int			IdleInTransactionSessionTimeout = 0;
 int			TransactionTimeout = 0;
 int			IdleSessionTimeout = 0;
-bool		log_lock_waits = false;
+bool		log_lock_waits = true;
 
 /* Pointer to this process's PGPROC struct, if any */
 PGPROC	   *MyProc = NULL;
diff --git a/src/backend/utils/misc/guc_parameters.dat b/src/backend/utils/misc/guc_parameters.dat
index 0da01627cfe..6bc6be13d2a 100644
--- a/src/backend/utils/misc/guc_parameters.dat
+++ b/src/backend/utils/misc/guc_parameters.dat
@@ -566,7 +566,7 @@
 { name => 'log_lock_waits', type => 'bool', context => 'PGC_SUSET', group => 'LOGGING_WHAT',
   short_desc => 'Logs long lock waits.',
   variable => 'log_lock_waits',
-  boot_val => 'false',
+  boot_val => 'true',
 },
 
 { name => 'log_lock_failures', type => 'bool', context => 'PGC_SUSET', group => 'LOGGING_WHAT',
diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample
index 26c08693564..c36fcb9ab61 100644
--- a/src/backend/utils/misc/postgresql.conf.sample
+++ b/src/backend/utils/misc/postgresql.conf.sample
@@ -624,7 +624,7 @@
 					#        processes
 					#   %% = '%'
 					# e.g. '<%u%%%d> '
-#log_lock_waits = off			# log lock waits >= deadlock_timeout
+#log_lock_waits = on			# log lock waits >= deadlock_timeout
 #log_lock_failures = off		# log lock failures
 #log_recovery_conflict_waits = off	# log standby recovery conflict waits
 					# >= deadlock_timeout
-- 
2.51.0

---

From: Chao Li <[email-masked]>
Date: Mon, 8 Sep 2025 10:38:07 +0800

> On Sep 8, 2025, at 05:46, Laurenz Albe <[email-masked]> wrote:
> 
> <v2-0001-Default-to-log_lock_waits-on.patch>

I am hesitate to support this change. I agree log_lock_waits is a powerful tool, but it’s more like a diagnostic tool. On a high-concurrency system with many tractions running at the same time, it may quickly fill up log files and make it difficult to find other errors. So, we usually only turn it on when needed, and turn it off once debugging is done.

But v2 code looks good to me.

Best regards,
--
Chao Li (Evan)
HighGo Software Co., Ltd.
https://www.highgo.com/

---

From: Laurenz Albe <[email-masked]>
Date: Mon, 08 Sep 2025 09:03:24 +0200

On Mon, 2025-09-08 at 10:38 +0800, Chao Li wrote:
> I am hesitate to support this change. I agree log_lock_waits is a powerful tool,
> but it’s more like a diagnostic tool. On a high-concurrency system with many tractions
> running at the same time, it may quickly fill up log files and make it difficult
> to find other errors. So, we usually only turn it on when needed, and turn it off
> once debugging is done.

You still can do that - only the default changed.

I think that if your log fills up with messages indicating that sessions are stuck
behind a lock for more than one second, and it is a high concurrency system, you
have got a severe problem that you want to know about.

What I argue is that while log_lock_waits=on is not the correct setting for
everybody, it is the correct setting for the vast majority of databases.

Yours,
Laurenz Albe

---

From: Peter Eisentraut <[email-masked]>
Date: Fri, 12 Sep 2025 08:06:02 +0200

> Here is an updated patch.

committed

---

From: Laurenz Albe <[email-masked]>
Date: Fri, 12 Sep 2025 09:01:54 +0200

> committed

Thank you!

Laurenz Albe