Leftover debug log "status_changed_time" floods the log in pool_process_reporting.c

[seoktai-chun]

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_BACKENDS that fills POOL_HEALTH_CHECK_STATS), there is this line:

/* status last changed */
t = bi->status_changed_time;
ereport(LOG, (errmsg("status_changed_time %lld", (long long) t)));   /* <-- this line */
strftime(stats[i].last_status_change, POOLCONFIG_MAXDATELEN, "%F %T", localtime(&t));

This emits a LOG: status_changed_time <epoch> message for every backend each
time the function is called. On a running system this shows up repeatedly in the
pgpool log (once per backend), e.g.:

2026-08-28 12:06:46.015: [unknown] pid 217627: LOG:  status_changed_time 1787886194
2026-08-28 12:06:46.015: [unknown] pid 217627: LOG:  status_changed_time 1787886194

Because it is emitted at LOG level, it keeps appearing in the server log file
even when log_min_messages = warning is 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:

• Pgpool-II 4.7.2, streaming replication mode
• PostgreSQL 17.9, 2 backend nodes
• The report/stats function is invoked periodically in our setup, so the log
  appears roughly every ~15s (twice, once per backend).

Thanks for maintaining pgpool-II.

[tatsuo-ishii]

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?

[seoktai-chun]

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.

[tatsuo-ishii]

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.

[tatsuo-ishii]

I have pushed the change to all supported branches.
https://git.postgresql.org/gitweb/?p=pgpool2.git;a=commit;h=1a873669fea0f3f0dec37051c2417c66efe26e1d