Thread: Add wait event for log emission?
Hi, I just helped somebody debug a postgres performance problem that turned out to be not actually be postgres' fault. It turned out to be because postgres' stdout/stderr were piped to a program, and that program was slow. Whenever the pipe buffer filled up, postgres stopped making progress. That's not postgres' fault. But we make it too hard to debug such an issue. There's no way to figure this out from within postgres, one pretty much needs to look at stack traces. I think we should add a few wait events for log emission. I think it'd be good to have one wait event for each log destination. That's not perfect - we'd e.g. still not be able to debug where the logger process is stuck, due it not being in pg_stat_activity. But other processes reporting the wait event for writing to the logger process would be a pretty good hint. Greetings, Andres Freund
On Tue, Jun 13, 2023 at 09:58:54AM -0700, Andres Freund wrote: > I think we should add a few wait events for log emission. I think it'd be good > to have one wait event for each log destination. +1 -- Nathan Bossart Amazon Web Services: https://aws.amazon.com
On Tue, Jun 13, 2023 at 6:59 PM Andres Freund <andres@anarazel.de> wrote: > > Hi, > > I just helped somebody debug a postgres performance problem that turned out to > be not actually be postgres' fault. It turned out to be because postgres' > stdout/stderr were piped to a program, and that program was slow. Whenever the > pipe buffer filled up, postgres stopped making progress. > > That's not postgres' fault. But we make it too hard to debug such an > issue. There's no way to figure this out from within postgres, one pretty much > needs to look at stack traces. > > I think we should add a few wait events for log emission. I think it'd be good > to have one wait event for each log destination. > > That's not perfect - we'd e.g. still not be able to debug where the logger > process is stuck, due it not being in pg_stat_activity. But other processes > reporting the wait event for writing to the logger process would be a pretty > good hint. +1. Would it make sense to at the same time create a separate one for syslog, or just use the same? -- Magnus Hagander Me: https://www.hagander.net/ Work: https://www.redpill-linpro.com/
Hi, On 2023-06-13 20:55:19 +0200, Magnus Hagander wrote: > On Tue, Jun 13, 2023 at 6:59 PM Andres Freund <andres@anarazel.de> wrote: > > > > Hi, > > > > I just helped somebody debug a postgres performance problem that turned out to > > be not actually be postgres' fault. It turned out to be because postgres' > > stdout/stderr were piped to a program, and that program was slow. Whenever the > > pipe buffer filled up, postgres stopped making progress. > > > > That's not postgres' fault. But we make it too hard to debug such an > > issue. There's no way to figure this out from within postgres, one pretty much > > needs to look at stack traces. > > > > I think we should add a few wait events for log emission. I think it'd be good > > to have one wait event for each log destination. > > > > That's not perfect - we'd e.g. still not be able to debug where the logger > > process is stuck, due it not being in pg_stat_activity. But other processes > > reporting the wait event for writing to the logger process would be a pretty > > good hint. > > > +1. > > Would it make sense to at the same time create a separate one for > syslog, or just use the same? I think it should be a separate one for each of the log paths in send_message_to_server_log(). I don't think we gain anything by being stingy here - and it's not like we add one every other day. I do wonder if it'd be worth setting up a wait event around emit_log_hook - it's somewhat of a misuse of wait events, but might be useful nonetheless? Greetings, Andres Freund
At Tue, 13 Jun 2023 17:18:58 -0700, Andres Freund <andres@anarazel.de> wrote in > Hi, > > On 2023-06-13 20:55:19 +0200, Magnus Hagander wrote: > > On Tue, Jun 13, 2023 at 6:59 PM Andres Freund <andres@anarazel.de> wrote: > > > I think we should add a few wait events for log emission. I think it'd be good > > > to have one wait event for each log destination. > > > > > > That's not perfect - we'd e.g. still not be able to debug where the logger > > > process is stuck, due it not being in pg_stat_activity. But other processes > > > reporting the wait event for writing to the logger process would be a pretty > > > good hint. > > > > > > +1. > > > > Would it make sense to at the same time create a separate one for > > syslog, or just use the same? > > I think it should be a separate one for each of the log paths in > send_message_to_server_log(). I don't think we gain anything by being stingy > here - and it's not like we add one every other day. > > I do wonder if it'd be worth setting up a wait event around emit_log_hook - > it's somewhat of a misuse of wait events, but might be useful nonetheless? We are already doing something similar for archive_command. Given that the execution time of this hook is unpredictable, it seems resonable to me to do that there. Essentially, we are "waiting" for the hook-function to return. regards. -- Kyotaro Horiguchi NTT Open Source Software Center