Updated patch cleans up two diff mistakes made when backing out the progress report feature. The tip-off I screwed up should have been the absurdly high write rate shown. The usleep was accidentally deleted, so it was running without cost limits even applying. Here's a good one instead:

LOG: automatic vacuum of table "pgbench.public.pgbench_accounts": index scans: 1
    pages: 0 removed, 163935 remain
    tuples: 2000000 removed, 2928356 remain
buffer usage: 117393 hits, 123351 misses, 102684 dirtied, 2.168 MiB/s write rate
    system usage: CPU 2.54s/6.27u sec elapsed 369.99 sec

--
Greg Smith   2ndQuadrant US    g...@2ndquadrant.com   Baltimore, MD
PostgreSQL Training, Services, and 24x7 Support  www.2ndQuadrant.us

diff --git a/src/backend/commands/vacuum.c b/src/backend/commands/vacuum.c
index 889737e..c9890b4 100644
*** a/src/backend/commands/vacuum.c
--- b/src/backend/commands/vacuum.c
*************** vacuum(VacuumStmt *vacstmt, Oid relid, b
*** 214,219 ****
--- 214,222 ----
  
  		VacuumCostActive = (VacuumCostDelay > 0);
  		VacuumCostBalance = 0;
+ 		VacuumPageHit = 0;
+ 		VacuumPageMiss = 0;
+ 		VacuumPageDirty = 0;
  
  		/*
  		 * Loop to process each selected relation.
diff --git a/src/backend/commands/vacuumlazy.c b/src/backend/commands/vacuumlazy.c
index b5547c5..a41f1cd 100644
*** a/src/backend/commands/vacuumlazy.c
--- b/src/backend/commands/vacuumlazy.c
*************** lazy_vacuum_rel(Relation onerel, VacuumS
*** 151,165 ****
  	int			nindexes;
  	BlockNumber possibly_freeable;
  	PGRUsage	ru0;
! 	TimestampTz starttime = 0;
  	bool		scan_all;
  	TransactionId freezeTableLimit;
  
  	/* measure elapsed time iff autovacuum logging requires it */
  	if (IsAutoVacuumWorkerProcess() && Log_autovacuum_min_duration >= 0)
  	{
  		pg_rusage_init(&ru0);
! 		if (Log_autovacuum_min_duration > 0)
  			starttime = GetCurrentTimestamp();
  	}
  
--- 151,168 ----
  	int			nindexes;
  	BlockNumber possibly_freeable;
  	PGRUsage	ru0;
! 	TimestampTz starttime = 0, endtime;
  	bool		scan_all;
  	TransactionId freezeTableLimit;
+ 	long		secs;
+ 	int			usecs;
+ 	double		write_rate;
  
  	/* measure elapsed time iff autovacuum logging requires it */
  	if (IsAutoVacuumWorkerProcess() && Log_autovacuum_min_duration >= 0)
  	{
  		pg_rusage_init(&ru0);
! 		if (Log_autovacuum_min_duration > 0 || VacuumCostActive)
  			starttime = GetCurrentTimestamp();
  	}
  
*************** lazy_vacuum_rel(Relation onerel, VacuumS
*** 225,247 ****
  	/* and log the action if appropriate */
  	if (IsAutoVacuumWorkerProcess() && Log_autovacuum_min_duration >= 0)
  	{
  		if (Log_autovacuum_min_duration == 0 ||
! 			TimestampDifferenceExceeds(starttime, GetCurrentTimestamp(),
  									   Log_autovacuum_min_duration))
! 			ereport(LOG,
! 					(errmsg("automatic vacuum of table \"%s.%s.%s\": index scans: %d\n"
! 							"pages: %d removed, %d remain\n"
! 							"tuples: %.0f removed, %.0f remain\n"
! 							"system usage: %s",
! 							get_database_name(MyDatabaseId),
! 							get_namespace_name(RelationGetNamespace(onerel)),
! 							RelationGetRelationName(onerel),
! 							vacrelstats->num_index_scans,
! 							vacrelstats->pages_removed,
! 							vacrelstats->rel_pages,
! 							vacrelstats->tuples_deleted,
! 							vacrelstats->new_rel_tuples,
! 							pg_rusage_show(&ru0))));
  	}
  }
  
--- 228,282 ----
  	/* and log the action if appropriate */
  	if (IsAutoVacuumWorkerProcess() && Log_autovacuum_min_duration >= 0)
  	{
+ 		endtime = GetCurrentTimestamp();
  		if (Log_autovacuum_min_duration == 0 ||
! 			TimestampDifferenceExceeds(starttime, endtime,
  									   Log_autovacuum_min_duration))
! 		{
! 			if (VacuumCostActive)
! 			{
! 				TimestampDifference(starttime, endtime, &secs, &usecs);
! 				write_rate = 0;
! 				if ((secs > 0) || (usecs > 0))
! 					write_rate = (double) BLCKSZ * VacuumPageDirty / (1024 * 1024) /
! 						(secs + usecs / 1000000.0);
! 
! 				ereport(LOG,
! 						(errmsg("automatic vacuum of table \"%s.%s.%s\": index scans: %d\n"
! 								"pages: %d removed, %d remain\n"
! 								"tuples: %.0f removed, %.0f remain\n"
! 								"buffer usage: %d hits, %d misses, %d dirtied, %.3f MiB/s write rate\n"
! 								"system usage: %s",
! 								get_database_name(MyDatabaseId),
! 								get_namespace_name(RelationGetNamespace(onerel)),
! 								RelationGetRelationName(onerel),
! 								vacrelstats->num_index_scans,
! 								vacrelstats->pages_removed,
! 								vacrelstats->rel_pages,
! 								vacrelstats->tuples_deleted,
! 								vacrelstats->new_rel_tuples,
! 								VacuumPageHit,
! 								VacuumPageMiss,
! 								VacuumPageDirty,
! 								write_rate,
! 								pg_rusage_show(&ru0))));
! 			}
! 			else
! 				ereport(LOG,
! 						(errmsg("automatic vacuum of table \"%s.%s.%s\": index scans: %d\n"
! 								"pages: %d removed, %d remain\n"
! 								"tuples: %.0f removed, %.0f remain\n"
! 								"system usage: %s",
! 								get_database_name(MyDatabaseId),
! 								get_namespace_name(RelationGetNamespace(onerel)),
! 								RelationGetRelationName(onerel),
! 								vacrelstats->num_index_scans,
! 								vacrelstats->pages_removed,
! 								vacrelstats->rel_pages,
! 								vacrelstats->tuples_deleted,
! 								vacrelstats->new_rel_tuples,
! 								pg_rusage_show(&ru0))));
! 		}
  	}
  }
  
diff --git a/src/backend/storage/buffer/bufmgr.c b/src/backend/storage/buffer/bufmgr.c
index 4c7cfb0..d62adbc 100644
*** a/src/backend/storage/buffer/bufmgr.c
--- b/src/backend/storage/buffer/bufmgr.c
*************** ReadBuffer_common(SMgrRelation smgr, cha
*** 341,347 ****
--- 341,350 ----
  			*hit = true;
  
  			if (VacuumCostActive)
+ 			{
+ 				VacuumPageHit++;
  				VacuumCostBalance += VacuumCostPageHit;
+ 			}
  
  			TRACE_POSTGRESQL_BUFFER_READ_DONE(forkNum, blockNum,
  											  smgr->smgr_rnode.node.spcNode,
*************** ReadBuffer_common(SMgrRelation smgr, cha
*** 471,477 ****
--- 474,483 ----
  	}
  
  	if (VacuumCostActive)
+ 	{
+ 		VacuumPageMiss++;
  		VacuumCostBalance += VacuumCostPageMiss;
+ 	}
  
  	TRACE_POSTGRESQL_BUFFER_READ_DONE(forkNum, blockNum,
  									  smgr->smgr_rnode.node.spcNode,
*************** MarkBufferDirty(Buffer buffer)
*** 974,980 ****
--- 980,989 ----
  	 * If the buffer was not dirty already, do vacuum cost accounting.
  	 */
  	if (!(bufHdr->flags & BM_DIRTY) && VacuumCostActive)
+ 	{
+ 		VacuumPageDirty++;
  		VacuumCostBalance += VacuumCostPageDirty;
+ 	}
  
  	bufHdr->flags |= (BM_DIRTY | BM_JUST_DIRTIED);
  
*************** SetBufferCommitInfoNeedsSave(Buffer buff
*** 2299,2305 ****
--- 2308,2317 ----
  		LockBufHdr(bufHdr);
  		Assert(bufHdr->refcount > 0);
  		if (!(bufHdr->flags & BM_DIRTY) && VacuumCostActive)
+ 		{
+ 			VacuumPageDirty++;
  			VacuumCostBalance += VacuumCostPageDirty;
+ 		}
  		bufHdr->flags |= (BM_DIRTY | BM_JUST_DIRTIED);
  		UnlockBufHdr(bufHdr);
  	}
diff --git a/src/backend/utils/init/globals.c b/src/backend/utils/init/globals.c
index c4c4154..9ce64e6 100644
*** a/src/backend/utils/init/globals.c
--- b/src/backend/utils/init/globals.c
*************** int			VacuumCostPageDirty = 20;
*** 115,120 ****
--- 115,124 ----
  int			VacuumCostLimit = 200;
  int			VacuumCostDelay = 0;
  
+ int			VacuumPageHit = 0;
+ int			VacuumPageMiss = 0;
+ int			VacuumPageDirty = 0;
+ 
  int			VacuumCostBalance = 0;		/* working state for vacuum */
  bool		VacuumCostActive = false;
  
diff --git a/src/include/miscadmin.h b/src/include/miscadmin.h
index 9d19417..4ee08fe 100644
*** a/src/include/miscadmin.h
--- b/src/include/miscadmin.h
*************** extern int	VacuumCostPageDirty;
*** 230,235 ****
--- 230,239 ----
  extern int	VacuumCostLimit;
  extern int	VacuumCostDelay;
  
+ extern int	VacuumPageHit;
+ extern int	VacuumPageMiss;
+ extern int	VacuumPageDirty;
+ 
  extern int	VacuumCostBalance;
  extern bool VacuumCostActive;
  
-- 
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers

Reply via email to