Re: May be BUG. Periodic burst growth of the checkpoint_req counter on replica.

Hello!

Thank you very much for your feedback and essential remarks.

On 07.09.2022 10:39, Kyotaro Horiguchi wrote:
> 
> It lets XLogPageRead run the same check with what CreateRestartPoint
> does, so it basically works (it is forgetting a lock, though. The
> reason for omitting the lock in CreateRestartPoint is that it knows
> checkopinter is the only updator of the shared variable.). I'm not
> sure I like that for the code duplication.
> 
> I'm not sure we need to fix that but if we do that, I would impletent
> IsNewCheckPointWALRecs() using XLogCtl->RedoRecPtr and
> XLogCtl->lastCheckPoint.redo instead since they are protected by the
> same lock, and they work more correct way, that is, that can avoid
> restartpoint requests while the last checkpoint is running.  And I
> would rename it as RestartPointAvailable() or something like that.

Corrected patch is attached (v2-0001-Fix-burst-checkpoint_req-growth.patch).
The access to Controlfile was removed so lwlock seems to be not needed.
Some logic duplication is still present and and i'm not quite sure if
it's possible to get rid of it. Would be glad to any suggestions.

> Or I might want to add XLogRestartpointNeeded(readSegNo) to reduce the
> required number of info_lck by reading XLogCtl members at once.

If we place this check into the XLogCheckpointNeeded() this will lead to a double
take of info_lck in XLogPageRead() when the restartpoint request is forming.
As it's done now taking of info_lck will be more rarely.
It seems i probably didn't understand your idea, please clarify it for me.

> Depends on how we see the counter value. I think this can be annoying
> but not a bug. CreateRestartPoint already handles that case. 

Yes! It is in fact annoying as docs says that checkpoint_req counts
"the number of requested checkpoints that have been performed".
But really checkpoints_req counts both the number of checkpoints requests
and restartpoint ones which may not be performed and resources are not spent.
The second frightening factor is the several times faster growth
of the checkpoints_timed counter on the replica vs primary due to scheduling
replays in 15 second if an attempt to create the restartpoint failed.

Here is a patch that leaves all logic as is, but adds a stats about
restartpoints. (v1-0001-Add-restartpoint-stats.patch)
.
For instance, for the same period on primary with this patch:
# SELECT CURRENT_TIME; select * from pg_stat_bgwriter \gx
     current_time
--------------------
  00:19:15.794561+03
(1 row)

-[ RECORD 1 ]---------+-----------------------------
checkpoints_timed     | 4
checkpoints_req       | 10
restartpoints_timed   | 0
restartpoints_req     | 0
restartpoints_done    | 0

On replica:
# SELECT CURRENT_TIME; select * from pg_stat_bgwriter \gx
     current_time
--------------------
  00:19:11.363009+03
(1 row)

-[ RECORD 1 ]---------+------------------------------
checkpoints_timed     | 0
checkpoints_req       | 0
restartpoints_timed   | 42
restartpoints_req     | 67
restartpoints_done    | 10

Only the counters checkpoints_timed, checkpoints_req and restartpoints_done give
the indication of resource-intensive operations.
Without this patch, the user would see on the replica something like this:

checkpoints_timed     | 42
checkpoints_req       | 109


With best regards,

-- 
Anton A. Melnikov
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company