Re: xact_start for walsender & logical decoding not updated

Hi,

On 2019-12-10 12:56:56 +0100, Tomas Vondra wrote:
> On Mon, Dec 09, 2019 at 04:04:40PM -0800, Andres Freund wrote:
> > On 2019-12-10 00:44:09 +0100, Tomas Vondra wrote:
> > > I think there's a minor bug in pg_stat_activity tracking of walsender
> > > processes. The issue is that xact_start is only updated at the very
> > > beginning when the walsender starts (so it's almost exactly equal to
> > > backend_start) and then just flips between NULL and that value.
> > >
> > > Reproducing this is trivial - just create a publication/subscription
> > > with the built-in logical replication, and run arbitrary workload.
> > > You'll see that the xact_start value never changes.
> > >
> > > I think the right fix is calling SetCurrentStatementStartTimestamp()
> > > right before StartTransactionCommand() in ReorderBufferCommit, per the
> > > attached patch.

> >
> > > diff --git a/src/backend/replication/logical/reorderbuffer.c b/src/backend/replication/logical/reorderbuffer.c
> > > index 53affeb877..5235fb31b8 100644
> > > --- a/src/backend/replication/logical/reorderbuffer.c
> > > +++ b/src/backend/replication/logical/reorderbuffer.c
> > > @@ -1554,7 +1554,10 @@ ReorderBufferCommit(ReorderBuffer *rb, TransactionId xid,
> > > if (using_subtxn)
> > > BeginInternalSubTransaction("replay");
> > > else
> > > + {
> > > + SetCurrentStatementStartTimestamp();
> > > StartTransactionCommand();
> > > + }
> >
> > I'm quite doubtful this is useful. To me this seems to do nothing but
> > add the overhead of timestamp computation - which isn't always that
> > cheap. I don't think you really can draw meaning from this?
> >
>
> I don't want to use this timestamp directly, but it does interfere with
> monitoring of long-running transactiosn looking at pg_stat_activity.
> With the current behavior, the walsender entries have ancient timestamps
> and produce random blips in monitoring. Of course, it's possible to edit
> the queries to skip entries with backend_type = walsender, but that's a
> bit inconvenient.

Oh, I'm not suggesting that we shouldn't fix this somehow, just that I'm
doubtful that that adding a lot of additional
SetCurrentStatementStartTimestamp() calls is the right thing. Besides
the overhead, it'd also just not be a meaningful value here - neither is
it an actual transaction, nor is it the right thing to be monitoring
when concerned about bloat or such.

It seems like it might be better to instead cause NULL to be returned
for the respective column in pg_stat_activity etc?

Greetings,

Andres Freund