Re: [9.3 bug fix] backends emit hundreds of messages when statistics file is inaccessible

Hello,

I've found a bug in PostgreSQL 9.3 beta 2 which is related to statistics
collection which emits excesssive amount of error messages. Please find
attached the patch to fix this. I confirmed this problem occurs in
PostgreSQL 9.2, too. Could you backport this?

[Problem]
If the directory specified by stats_temp_directory becomes inaccessible to
postgres, enormous amount of WARNING messages are output. For example, when
I set wrong permission on the directory by mistake while the database server
is running and then started psql, more than 600 messages were emitted in a
few seconds like this:

WARNING: could not open statistics file
"/work/maumau/stats_tmp/pgstat.stat": Permission denied
LOG: could not open temporary statistics file
"/work/maumau/stats_tmp/pgstat.tmp": Permission denied
WARNING: could not open statistics file
"/work/maumau/stats_tmp/pgstat.stat": Permission denied
WARNING: could not open statistics file
"/work/maumau/stats_tmp/pgstat.stat": Permission denied
WARNING: could not open statistics file
"/work/maumau/stats_tmp/pgstat.stat": Permission denied
...

Even when there's no client, these messages are output regularly. I guess
this is because autovacuum runs.

[Cause]
In backend_read_statsfile(), the backend loops PGSTAT_POLL_LOOP_COUNT
(=1000) times trying to open the statistics file. The backend emits a
WARNING message if it fails to open the file in every iteration of the loop.

[How to fix]
Emit the message upon the first failed attempt. For some diagnostics
purposes, emit the message with DEBUG2 level on the subsequent attempts.
DEBUG2 is arbitrary.

Regards
MauMau

"MauMau" <maumau307(at)gmail(dot)com> writes:
> I've found a bug in PostgreSQL 9.3 beta 2 which is related to statistics
> collection which emits excesssive amount of error messages. Please find
> attached the patch to fix this. I confirmed this problem occurs in
> PostgreSQL 9.2, too. Could you backport this?

It's not apparent that this is a good idea, let alone a bug fix.

> If the directory specified by stats_temp_directory becomes inaccessible to
> postgres, enormous amount of WARNING messages are output.

Well, yeah, because all of that functionality just broke. Not warning
about it doesn't seem like a good idea. AFAICT, your patch would result
in the situation not being remarked on anywhere except in the postmaster
log.

regards, tom lane

From: "Tom Lane" <tgl(at)sss(dot)pgh(dot)pa(dot)us>
> "MauMau" <maumau307(at)gmail(dot)com> writes:
>> If the directory specified by stats_temp_directory becomes inaccessible
>> to
>> postgres, enormous amount of WARNING messages are output.
>
> Well, yeah, because all of that functionality just broke. Not warning
> about it doesn't seem like a good idea. AFAICT, your patch would result
> in the situation not being remarked on anywhere except in the postmaster
> log.

No, my patch makes backend_read_statsfile_timestamp() emit just one warning
message instead of outputing the same message 1,000 times in one call. So
your concern does not exist. Is this OK?

Regards
MauMau