checkpoint-stats-update-v2.diff

text/plain

Filename: checkpoint-stats-update-v2.diff
Type: text/plain
Part: 0
Message: Re: PATCH: regular logging of checkpoint progress
diff --git a/src/backend/storage/buffer/bufmgr.c b/src/backend/storage/buffer/bufmgr.c
new file mode 100644
index 4c7cfb0..e60d304
*** 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 (checkpoint_update_limit),
+ 				 * we log a checkpoint status message and update the bgwriter
+ 				 * stats (so that the pg_stat_bgwriter table may be updated).
+ 				 * 
+ 				 * 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(LOG, "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