Thread: Inconsitancies in pg_stat_bgwriter and pg_stat_database returned values

Hello, 

On one particular PG12.3 instance (same behaviour with PG12.4) we are experimenting occasional strange values in the
abovetables. 
 

For instance looping (10s. period) over this request: 

SELECT current_timestamp, checkpoints_timed, 
checkpoints_req, 
checkpoint_write_time, 
checkpoint_sync_time, 
buffers_checkpoint, 
buffers_clean, 
maxwritten_clean, 
buffers_backend, 
buffers_backend_fsync, 
buffers_alloc 
FROM pg_stat_bgwriter 

Gives: 

020-09-16 13:41:39.781609+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 
2020-09-16 13:41:49.815612+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 
2020-09-16 13:41:59.851812+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 
2020-09-16 13:42:09.89053+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 
2020-09-16 13:42:19.923291+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 
2020-09-16 13:42:29.959282+00,3291,227,1278516493,26327,66708986,1743379,16800,253585756,0,59080296 
2020-09-16 13:42:39.98198+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 
2020-09-16 13:42:50.028727+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 
2020-09-16 13:43:00.067928+00,3291,227,1278516493,26327,66709285,1743379,16800,253585756,0,59080296 
2020-09-16 13:43:10.090266+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 
2020-09-16 13:43:20.140272+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 
2020-09-16 13:43:30.170372+00,3291,227,1278516493,26327,66709585,1743379,16800,253585756,0,59080296 
2020-09-16 13:43:40.204747+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 
2020-09-16 13:43:50.239374+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 
2020-09-16 13:44:00.26905+00,3291,227,1278516493,26327,66709884,1743379,16800,253585756,0,59080296 
2020-09-16 13:44:10.314927+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 
2020-09-16 13:44:20.351091+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 
2020-09-16 13:44:30.408797+00,3291,227,1278516493,26327,66710184,1743379,16800,253585756,0,59080296 
2020-09-16 13:44:40.44833+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 
2020-09-16 13:44:50.484298+00,438,2,10095976,0,611207,870625,8695,612255,0,39028850 

One can see that some columns that are supposed to increase only are not always. For instance checkpoints_timed
suddenlyjumps from 438 to 3291, then back to 438. 
 

We experiment the same issue in pg_stat_database. 

Thanks

On Wed, 16 Sep 2020 17:06:45 +0200 (CEST)
RECHTÉ Marc <marc.rechte@meteo.fr> wrote:

> Hello,
>
> On one particular PG12.3 instance (same behaviour with PG12.4) we are
> experimenting occasional strange values in the above tables.
>
> For instance looping (10s. period) over this request:
>
> SELECT current_timestamp, checkpoints_timed,
> checkpoints_req,
> checkpoint_write_time,
> checkpoint_sync_time,
> buffers_checkpoint,
> buffers_clean,
> maxwritten_clean,
> buffers_backend,
> buffers_backend_fsync,
> buffers_alloc
> FROM pg_stat_bgwriter
>
> Gives:  [...]
>
> One can see that some columns that are supposed to increase only are not
> always. For instance checkpoints_timed suddenly jumps from 438 to 3291, then
> back to 438.
>
> We experiment the same issue in pg_stat_database.

The full row are different in your example, not just a few fields. It looks
like mixed values from different instance.

Could you share some more informations about the context and how to reproduce
it?

Regards,

On Wed, 16 Sep 2020 17:06:45 +0200 (CEST)
RECHTÉ Marc <marc.rechte@meteo.fr> wrote:

> Hello,
>
> On one particular PG12.3 instance (same behaviour with PG12.4) we are
> experimenting occasional strange values in the above tables.
>
> For instance looping (10s. period) over this request:
>
> SELECT current_timestamp, checkpoints_timed,
> checkpoints_req,
> checkpoint_write_time,
> checkpoint_sync_time,
> buffers_checkpoint,
> buffers_clean,
> maxwritten_clean,
> buffers_backend,
> buffers_backend_fsync,
> buffers_alloc
> FROM pg_stat_bgwriter
>
> Gives:  [...]
>
> One can see that some columns that are supposed to increase only are not
> always. For instance checkpoints_timed suddenly jumps from 438 to 3291, then
> back to 438.
>
> We experiment the same issue in pg_stat_database.


----- Mail original -----
De: "Jehan-Guillaume de Rorthais" <jgdr@dalibo.com>
À: "RECHTÉ Marc" <marc.rechte@meteo.fr>
Cc: pgsql-bugs@lists.postgresql.org
Envoyé: Mercredi 16 Septembre 2020 17:31:24
Objet: Re: Inconsitancies in pg_stat_bgwriter and pg_stat_database returned values

The full row are different in your example, not just a few fields. It looks
like mixed values from different instance.

Could you share some more informations about the context and how to reproduce
it?

Regards,

Hello

Thanks a lot, you got it right: there are 2 instances on this machine and they are both configured with:

stats_temp_directory = '/dev/shm'

We some time ago tried, stats_temp_directory = '/dev/shm/instance', but PostgreSQL ignored the subdirectory part and
keptcreating the temp file at the FS root. 
As this is a temporary FS, one cannot in advance create the instance subdirectory as it is wiped out between reboots.

Best regards

On Thu, 17 Sep 2020 08:38:10 +0200 (CEST)
RECHTÉ Marc <marc.rechte@meteo.fr> wrote:
[...]
> The full row are different in your example, not just a few fields. It looks
> like mixed values from different instance.
>
> Could you share some more informations about the context and how to reproduce
> it?
>
> Regards,
>
> Hello
>
> Thanks a lot, you got it right: there are 2 instances on this machine and
> they are both configured with:
>
> stats_temp_directory = '/dev/shm'
>
> We some time ago tried, stats_temp_directory = '/dev/shm/instance', but
> PostgreSQL ignored the subdirectory part and kept creating the temp file at
> the FS root. As this is a temporary FS, one cannot in advance create the
> instance subdirectory as it is wiped out between reboots.

Use "/var/run/postgresql/instance_name" and setup systemd tmpfiles to create
the folder automatically. Eg.:

  cat <<EOF > /etc/tmpfiles.d/postgresql-stats.conf
  # Directory for PostgreSQL temp stat files
  d /var/run/postgresql/stats-instance_name 0700 postgres postgres - -
  EOF

You can add as many folders as you need.

To take this file in consideration immediately without rebooting the server,
run the following command:

 systemd-tmpfiles --create /etc/tmpfiles.d/postgresql-stats.conf

Regards,

----- Mail original -----
De: "Jehan-Guillaume de Rorthais" <jgdr@dalibo.com>
À: "RECHTÉ Marc" <marc.rechte@meteo.fr>
Cc: pgsql-bugs@lists.postgresql.org
Envoyé: Jeudi 17 Septembre 2020 09:39:44
Objet: Re: Inconsitancies in pg_stat_bgwriter and pg_stat_database returned values

On Thu, 17 Sep 2020 08:38:10 +0200 (CEST)
RECHTÉ Marc <marc.rechte@meteo.fr> wrote:
[...]
> The full row are different in your example, not just a few fields. It looks
> like mixed values from different instance.
>
> Could you share some more informations about the context and how to reproduce
> it?
>
> Regards,
>
> Hello
>
> Thanks a lot, you got it right: there are 2 instances on this machine and
> they are both configured with:
>
> stats_temp_directory = '/dev/shm'
>
> We some time ago tried, stats_temp_directory = '/dev/shm/instance', but
> PostgreSQL ignored the subdirectory part and kept creating the temp file at
> the FS root. As this is a temporary FS, one cannot in advance create the
> instance subdirectory as it is wiped out between reboots.

Use "/var/run/postgresql/instance_name" and setup systemd tmpfiles to create
the folder automatically. Eg.:

  cat <<EOF > /etc/tmpfiles.d/postgresql-stats.conf
  # Directory for PostgreSQL temp stat files
  d /var/run/postgresql/stats-instance_name 0700 postgres postgres - -
  EOF

You can add as many folders as you need.

To take this file in consideration immediately without rebooting the server,
run the following command:

 systemd-tmpfiles --create /etc/tmpfiles.d/postgresql-stats.conf

Regards,


I applied your suggestions. Thanks again.

Marc.