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