Re: Time delayed LR (WAS Re: logical replication restrictions)

On Fri, Jan 20, 2023 at 2:23 PM shveta malik <shveta(dot)malik(at)gmail(dot)com> wrote:
>
> On Fri, Jan 20, 2023 at 1:08 PM Peter Smith <smithpb2250(at)gmail(dot)com> wrote:
>
> > a) the message should say that this is the *remaining* time to left to wait.
> >
> > b) it might be convenient to know from the log what was the original
> > min_apply_delay value in the 1st place.
> >
> > For example, the logs might look something like this:
> >
> > DEBUG: time-delayed replication for txid 1234, min_apply_delay =
> > 160000 ms. Remaining wait time: 159972 ms
> > DEBUG: time-delayed replication for txid 1234, min_apply_delay =
> > 160000 ms. Remaining wait time: 142828 ms
> > DEBUG: time-delayed replication for txid 1234, min_apply_delay =
> > 160000 ms. Remaining wait time: 129994 ms
> > DEBUG: time-delayed replication for txid 1234, min_apply_delay =
> > 160000 ms. Remaining wait time: 110001 ms
> > ...
> >
>
> +1
> This will also help when min_apply_delay is set to a new value in
> between the current wait. Lets say, I started with min_apply_delay=5
> min, when the worker was half way through this, I changed
> min_apply_delay to 3 min or say 10min, I see the impact of that change
> i.e. new wait-time is adjusted, but log becomes confusing. So, please
> keep this scenario as well in mind while improving logging.
>

when we send-feedback during apply-delay after every
wal_receiver_status_interval , the log comes as:
023-01-19 17:12:56.000 IST [404795] DEBUG: sending feedback (force 1)
to recv 0/1570840, write 0/1570840, flush 0/1570840

Shall we have some info here to indicate that it is sent while waiting
for apply_delay to distinguish it from other such send-feedback logs?
It will
make apply_delay flow clear in logs.

thanks
Shveta