Repository navigation
Leftover debug log "status_changed_time" floods the log in pool_process_reporting.c #171
Description
Activity
The report/stats function is invoked periodically in our setup, so the log
appears roughly every ~15s (twice, once per backend).Every 15 seconds! I have never heard such a frequent call to show health_check_stats in wild.
Anyway, your claim is fair. The log level has not need to be LOG at all. However I think it's better to leave the line with the log level changed, say 'DEBUG5' because it will help developers once there's a problem with the function. What do you think?The report/stats function is invoked periodically in our setup, so the log
appears roughly every ~15s (twice, once per backend).Every 15 seconds! I have never heard such a frequent call to show health_check_stats in wild. Anyway, your claim is fair. The log level has not need to be LOG at all. However I think it's better to leave the line with the log level changed, say 'DEBUG5' because it will help developers once there's a problem with the function. What do you think?
Thanks for the quick response, and I agree — DEBUG5 is a better approach than removing it entirely. It keeps the diagnostic value for developers while no longer polluting the log under normal log_min_messages settings (e.g. warning). Please go ahead with lowering it to DEBUG5.
Regarding the frequency: in our setup the stats function is very likely being called by pgpool2_exporter (Prometheus exporter for Pgpool-II), which scrapes pgpool metrics periodically (our scrape interval matches the ~15s I observed). So it's not a manual SHOW, but the exporter polling the stats. That would explain the frequency you found unusual.
Thanks for confirmation. I will change the log level from LOG to DEBUG5, along with a change from errmsg to errmsg_internal, as it's the standard coding style to write a debug message in PostgreSQL.
Regarding the frequency: in our setup the stats function is very likely being called by pgpool2_exporter (Prometheus exporter for Pgpool-II), which scrapes pgpool metrics periodically (our scrape interval matches the ~15s I observed). So it's not a manual SHOW, but the exporter polling the stats. That would explain the frequency you found unusual.
Thanks for the detailed explanation.
I have pushed the change to all supported branches.
https://git.postgresql.org/gitweb/?p=pgpool2.git;a=commit;h=1a873669fea0f3f0dec37051c2417c66efe26e1d- added 6 commits that reference this issue
on Aug 31, 2026
I believe there is a leftover debug log statement in
src/utils/pool_process_reporting.c.In the function that builds the health check statistics report (the loop over
NUM_BACKENDSthat fillsPOOL_HEALTH_CHECK_STATS), there is this line:This emits a
LOG: status_changed_time <epoch>message for every backend eachtime the function is called. On a running system this shows up repeatedly in the
pgpool log (once per backend), e.g.:
Because it is emitted at LOG level, it keeps appearing in the server log file
even when
log_min_messages = warningis configured, which pollutes the log.The analogous code in
nodes_reporting()(SHOW pool_nodes) does the same"status last changed" handling but does NOT emit such a log line, which suggests
the
ereport(LOG, ...)above is a leftover debugging statement.This line is present in 4.7.2 and also still present on the current master
branch (src/utils/pool_process_reporting.c).
Proposed fix: simply remove that
ereport(LOG, ...)line./* status last changed */ t = bi->status_changed_time; - ereport(LOG, (errmsg("status_changed_time %lld", (long long) t))); strftime(stats[i].last_status_change, POOLCONFIG_MAXDATELEN, "%F %T", localtime(&t));Environment:
appears roughly every ~15s (twice, once per backend).
Thanks for maintaining pgpool-II.