On 2 Září 2011, 12:45, Magnus Hagander wrote:
> On Fri, Sep 2, 2011 at 11:01, Tomas Vondra <t...@fuzzy.cz> wrote:
>> What about logging it with a lower level, e.g. NOTICE instead of the
>> current LOG? If that's not a solution then a new GUC is needed I guess.
>
> I guess if it's at a DEBUG level it won't annoy anybody who doesn't
> need it. Not sure if NOTICE is low enough..
I've changed the level to NOTICE. I guess I could put that to info, but
the debug levels seem too low to me. Is there a rule of a thumb about
where to put messages?
Tomas
diff --git a/src/backend/storage/buffer/bufmgr.c
b/src/backend/storage/buffer/bufmgr.c
new file mode 100644
index 4c7cfb0..a9bdd89
*** a/src/backend/storage/buffer/bufmgr.c
--- b/src/backend/storage/buffer/bufmgr.c
*************** BufferSync(int flags)
*** 1175,1180 ****
--- 1175,1193 ----
int num_to_write;
int num_written;
int mask = BM_DIRTY;
+
+ int num_since_update;
+
+ long curr_secs,
+ total_secs;
+ int curr_usecs,
+ total_usecs;
+ float curr_time,
+ total_time;
+
+ TimestampTz startTimestamp, lastTimestamp;
+
+ int log_interval, check_interval;
/* Make sure we can handle the pin inside SyncOneBuffer */
ResourceOwnerEnlargeBuffers(CurrentResourceOwner);
*************** BufferSync(int flags)
*** 1238,1243 ****
--- 1251,1265 ----
buf_id = StrategySyncStart(NULL, NULL);
num_to_scan = NBuffers;
num_written = 0;
+ num_since_update = 0;
+
+ startTimestamp = GetCurrentTimestamp();
+ lastTimestamp = startTimestamp;
+
+ /* check the progress each 128 buffers or 10% */
+ log_interval = (int)round(num_to_write/10);
+ check_interval = ((log_interval < 128) && (log_interval > 0)) ?
log_interval : 128;
+
while (num_to_scan-- > 0)
{
volatile BufferDesc *bufHdr = &BufferDescriptors[buf_id];
*************** BufferSync(int flags)
*** 1261,1266 ****
--- 1283,1334 ----
TRACE_POSTGRESQL_BUFFER_SYNC_WRITTEN(buf_id);
BgWriterStats.m_buf_written_checkpoints++;
num_written++;
+ num_since_update++;
+
+ /*
+ * Every time we write enough buffers we check
the time since
+ * last log and whenever we reach 5 seconds or
10% of the buffers
+ * to write, we put a checkpoint status message.
+ *
+ * The log message contains info about total
number of buffers to
+ * write, how many buffers are already written,
average and current
+ * write speed and an estimate remaining time.
+ */
+ if ((log_checkpoints) && (num_written %
check_interval == 0)) {
+
+ TimestampDifference(lastTimestamp,
+ GetCurrentTimestamp(),
+ &curr_secs, &curr_usecs);
+
+ /* if at least 5 seconds elapsed since
the last log, log */
+ if ((curr_secs >= 5) ||
(num_since_update >= log_interval)) {
+
+
TimestampDifference(startTimestamp,
+ GetCurrentTimestamp(),
+ &total_secs,
&total_usecs);
+
+ curr_time = curr_secs +
(float)curr_usecs / 1000000;
+ total_time = total_secs +
(float)total_usecs / 1000000;
+
+ elog(NOTICE, "checkpoint
status: wrote %d buffers of %d (%.1f%%) in %.1f s; "
+ "average %.1f MB/s (%d
buffers, %ld.%03d s), "
+ "current %.1f MB/s (%d
buffers, %ld.%03d s), "
+ "remaining %.1f s",
+ num_written,
num_to_write, ((float) num_written * 100 / num_to_write),
+ total_time,
+ ((float)BLCKSZ *
num_written / 1024 / 1024 / total_time),
+ num_written,
total_secs, total_usecs/1000,
+ ((float)BLCKSZ *
num_since_update / 1024 / 1024 / curr_time),
+ num_since_update,
curr_secs, curr_usecs/1000,
+ (float)(num_to_write -
num_written) * total_time / (num_written));
+
+ /* reset the counter and
timestamp */
+ num_since_update = 0;
+ lastTimestamp =
GetCurrentTimestamp();
+
+ }
+
+ }
/*
* We know there are at most num_to_write
buffers with
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
