Index: src/backend/commands/trigger.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/commands/trigger.c,v
retrieving revision 1.201
diff -c -r1.201 trigger.c
*** src/backend/commands/trigger.c	27 Apr 2006 00:33:41 -0000	1.201
--- src/backend/commands/trigger.c	9 May 2006 20:35:07 -0000
***************
*** 1306,1312 ****
  	 * one "tuple returned" (really the number of firings).
  	 */
  	if (instr)
! 		InstrStopNode(instr + tgindx, true);
  
  	return (HeapTuple) DatumGetPointer(result);
  }
--- 1306,1312 ----
  	 * one "tuple returned" (really the number of firings).
  	 */
  	if (instr)
! 		InstrStopNode(instr + tgindx, 1);
  
  	return (HeapTuple) DatumGetPointer(result);
  }
***************
*** 2154,2160 ****
  	 * one "tuple returned" (really the number of firings).
  	 */
  	if (instr)
! 		InstrStopNode(instr + tgindx, true);
  }
  
  
--- 2154,2160 ----
  	 * one "tuple returned" (really the number of firings).
  	 */
  	if (instr)
! 		InstrStopNode(instr + tgindx, 1);
  }
  
  
Index: src/backend/executor/execProcnode.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/execProcnode.c,v
retrieving revision 1.54
diff -c -r1.54 execProcnode.c
*** src/backend/executor/execProcnode.c	5 Mar 2006 15:58:26 -0000	1.54
--- src/backend/executor/execProcnode.c	9 May 2006 20:35:07 -0000
***************
*** 423,429 ****
  	}
  
  	if (node->instrument)
! 		InstrStopNode(node->instrument, !TupIsNull(result));
  
  	return result;
  }
--- 423,429 ----
  	}
  
  	if (node->instrument)
! 		InstrStopNode(node->instrument, TupIsNull(result) ? 0 : 1 );
  
  	return result;
  }
Index: src/backend/executor/instrument.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/instrument.c,v
retrieving revision 1.14
diff -c -r1.14 instrument.c
*** src/backend/executor/instrument.c	5 Mar 2006 15:58:26 -0000	1.14
--- src/backend/executor/instrument.c	9 May 2006 20:35:07 -0000
***************
*** 14,22 ****
--- 14,84 ----
  #include "postgres.h"
  
  #include <unistd.h>
+ #include <math.h>
  
  #include "executor/instrument.h"
  
+ /* This is the function that is used to determine the sampling intervals. In
+  * general, if the function is f(x), then for N tuples we will take on the
+  * order of integral(1/f(x), x=0..N) samples. Some examples follow, with the
+  * number of samples that would be collected over 1,000,000 tuples.
+ 
+   f(x) = x         =>   log2(N)                        20
+   f(x) = x^(1/2)   =>   2 * N^(1/2)                  2000
+   f(x) = x^(1/3)   =>   1.5 * N^(2/3)               15000
+   
+  * I've chosen the last one as it seems to provide a good compromise between
+  * low overhead but still getting a meaningful number of samples. However,
+  * not all machines have the cbrt() function so on those we substitute
+  * sqrt(). The difference is not very significant in the tests I made.
+ */ 
+ #ifdef HAVE_CBRT
+ #define SampleFunc cbrt
+ #else
+ #define SampleFunc sqrt
+ #endif
+ 
+ #define SAMPLE_THRESHOLD 50
+ 
+ static double SampleOverhead;
+ static bool SampleOverheadCalculated;
+ 
+ static void
+ CalculateSampleOverhead()
+ {
+ 	Instrumentation instr;
+ 	int i;
+ 	
+ 	/* We want to determine the sampling overhead, to correct
+ 	 * calculations later. This only needs to be done once per backend.
+ 	 * Is this the place? A wrong value here (due to a mistimed
+ 	 * task-switch) will cause bad calculations later.
+ 	 *
+ 	 * To minimize the risk we do it a few times and take the lowest.
+ 	 */
+ 	
+ 	SampleOverhead = 1.0e6;
+ 	
+ 	for( i = 0; i<5; i++ )
+ 	{
+ 		int j;
+ 		double overhead;
+ 		
+ 		memset( &instr, 0, sizeof(instr) );
+ 	
+ 		/* Loop SAMPLE_THRESHOLD times or 100 microseconds, whichever is faster */
+ 		for( j=0; j<SAMPLE_THRESHOLD && INSTR_TIME_GET_DOUBLE(instr.counter) < 100e-6; i++ )
+ 		{
+ 			InstrStartNode( &instr );
+ 			InstrStopNode( &instr, 1 );
+ 		}
+ 		overhead = INSTR_TIME_GET_DOUBLE(instr.counter) / instr.samplecount;
+ 		if( overhead < SampleOverhead )
+ 			SampleOverhead = overhead;
+ 	}
+ 		
+ 	SampleOverheadCalculated = true;
+ }
  
  /* Allocate new instrumentation structure(s) */
  Instrumentation *
***************
*** 25,31 ****
  	Instrumentation *instr = palloc0(n * sizeof(Instrumentation));
  
  	/* we don't need to do any initialization except zero 'em */
! 
  	return instr;
  }
  
--- 87,96 ----
  	Instrumentation *instr = palloc0(n * sizeof(Instrumentation));
  
  	/* we don't need to do any initialization except zero 'em */
! 	
! 	/* Calculate overhead, if not done yet */
! 	if( !SampleOverheadCalculated )
! 		CalculateSampleOverhead();
  	return instr;
  }
  
***************
*** 34,82 ****
  InstrStartNode(Instrumentation *instr)
  {
  	if (INSTR_TIME_IS_ZERO(instr->starttime))
! 		INSTR_TIME_SET_CURRENT(instr->starttime);
  	else
  		elog(DEBUG2, "InstrStartNode called twice in a row");
  }
  
  /* Exit from a plan node */
  void
! InstrStopNode(Instrumentation *instr, bool returnedTuple)
  {
  	instr_time	endtime;
  
  	/* count the returned tuples */
! 	if (returnedTuple)
! 		instr->tuplecount += 1;
  
! 	if (INSTR_TIME_IS_ZERO(instr->starttime))
  	{
! 		elog(DEBUG2, "InstrStopNode called without start");
! 		return;
! 	}
  
! 	INSTR_TIME_SET_CURRENT(endtime);
  
  #ifndef WIN32
! 	instr->counter.tv_sec += endtime.tv_sec - instr->starttime.tv_sec;
! 	instr->counter.tv_usec += endtime.tv_usec - instr->starttime.tv_usec;
  
! 	/* Normalize after each add to avoid overflow/underflow of tv_usec */
! 	while (instr->counter.tv_usec < 0)
! 	{
! 		instr->counter.tv_usec += 1000000;
! 		instr->counter.tv_sec--;
! 	}
! 	while (instr->counter.tv_usec >= 1000000)
! 	{
! 		instr->counter.tv_usec -= 1000000;
! 		instr->counter.tv_sec++;
! 	}
  #else							/* WIN32 */
! 	instr->counter.QuadPart += (endtime.QuadPart - instr->starttime.QuadPart);
  #endif
  
! 	INSTR_TIME_SET_ZERO(instr->starttime);
  
  	/* Is this the first tuple of this cycle? */
  	if (!instr->running)
--- 99,167 ----
  InstrStartNode(Instrumentation *instr)
  {
  	if (INSTR_TIME_IS_ZERO(instr->starttime))
! 	{
! 		/* We always sample the first SAMPLE_THRESHOLD tuples, so small nodes are always accurate */
! 		if (instr->tuplecount < SAMPLE_THRESHOLD)
! 			instr->sampling = true;
! 		else
! 		{
! 			/* Otherwise we go to sampling, see the comments on SampleFunc at the top of the file */
! 			if( instr->tuplecount > instr->nextsample )
! 			{
! 				instr->sampling = true;
! 				/* The doubling is so the random will average 1 over time */
! 				instr->nextsample += 2.0 * SampleFunc(instr->tuplecount) * (double)rand() / (double)RAND_MAX;
! 			}
! 		}
! 		if (instr->sampling)
! 			INSTR_TIME_SET_CURRENT(instr->starttime);
! 	}
  	else
  		elog(DEBUG2, "InstrStartNode called twice in a row");
  }
  
  /* Exit from a plan node */
  void
! InstrStopNode(Instrumentation *instr, double nTuples)
  {
  	instr_time	endtime;
  
  	/* count the returned tuples */
! 	instr->tuplecount += nTuples;
  
! 	if (instr->sampling)
  	{
! 		if (INSTR_TIME_IS_ZERO(instr->starttime))
! 		{
! 			elog(DEBUG2, "InstrStopNode called without start");
! 			return;
! 		}
  
! 		INSTR_TIME_SET_CURRENT(endtime);
  
  #ifndef WIN32
! 		instr->counter.tv_sec += endtime.tv_sec - instr->starttime.tv_sec;
! 		instr->counter.tv_usec += endtime.tv_usec - instr->starttime.tv_usec;
  
! 		/* Normalize after each add to avoid overflow/underflow of tv_usec */
! 		while (instr->counter.tv_usec < 0)
! 		{
! 			instr->counter.tv_usec += 1000000;
! 			instr->counter.tv_sec--;
! 		}
! 		while (instr->counter.tv_usec >= 1000000)
! 		{
! 			instr->counter.tv_usec -= 1000000;
! 			instr->counter.tv_sec++;
! 		}
  #else							/* WIN32 */
! 		instr->counter.QuadPart += (endtime.QuadPart - instr->starttime.QuadPart);
  #endif
  
! 		INSTR_TIME_SET_ZERO(instr->starttime);
! 		instr->samplecount += nTuples;
! 		instr->sampling = false;
! 	}
  
  	/* Is this the first tuple of this cycle? */
  	if (!instr->running)
***************
*** 86,102 ****
  	}
  }
  
- /* As above, but count multiple tuples returned at once */
- void
- InstrStopNodeMulti(Instrumentation *instr, double nTuples)
- {
- 	/* count the returned tuples */
- 	instr->tuplecount += nTuples;
- 
- 	/* delegate the rest */
- 	InstrStopNode(instr, false);
- }
- 
  /* Finish a run cycle for a plan node */
  void
  InstrEndLoop(Instrumentation *instr)
--- 171,176 ----
***************
*** 114,121 ****
  	totaltime = INSTR_TIME_GET_DOUBLE(instr->counter);
  
  	instr->startup += instr->firsttuple;
! 	instr->total += totaltime;
  	instr->ntuples += instr->tuplecount;
  	instr->nloops += 1;
  
  	/* Reset for next cycle (if any) */
--- 188,211 ----
  	totaltime = INSTR_TIME_GET_DOUBLE(instr->counter);
  
  	instr->startup += instr->firsttuple;
! 
! 	/* Here we take into account sampling effects. Doing it naively ends
! 	 * up assuming the sampling overhead applies to all tuples, even the
! 	 * ones we didn't measure. We've calculated an overhead, so we
! 	 * subtract that for all samples we didn't measure. The first tuple
! 	 * is also special cased, because it usually takes longer. */
! 
! 	if( instr->samplecount < instr->tuplecount )
! 	{
! 		double pertuple = (totaltime - instr->firsttuple) / (instr->samplecount - 1);
! 		instr->total += instr->firsttuple + (pertuple * (instr->samplecount - 1))
! 		                                  + ((pertuple - SampleOverhead) * (instr->tuplecount - instr->samplecount));
! 	}
! 	else
! 		instr->total += totaltime;
! 		
  	instr->ntuples += instr->tuplecount;
+ 	instr->nsamples += instr->samplecount;
  	instr->nloops += 1;
  
  	/* Reset for next cycle (if any) */
***************
*** 123,127 ****
--- 213,218 ----
  	INSTR_TIME_SET_ZERO(instr->starttime);
  	INSTR_TIME_SET_ZERO(instr->counter);
  	instr->firsttuple = 0;
+ 	instr->samplecount = 0;
  	instr->tuplecount = 0;
  }
Index: src/backend/executor/nodeBitmapAnd.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeBitmapAnd.c,v
retrieving revision 1.6
diff -c -r1.6 nodeBitmapAnd.c
*** src/backend/executor/nodeBitmapAnd.c	5 Mar 2006 15:58:26 -0000	1.6
--- src/backend/executor/nodeBitmapAnd.c	9 May 2006 20:35:07 -0000
***************
*** 163,169 ****
  
  	/* must provide our own instrumentation support */
  	if (node->ps.instrument)
! 		InstrStopNodeMulti(node->ps.instrument, 0 /* XXX */ );
  
  	return (Node *) result;
  }
--- 163,169 ----
  
  	/* must provide our own instrumentation support */
  	if (node->ps.instrument)
! 		InstrStopNode(node->ps.instrument, 0 /* XXX */ );
  
  	return (Node *) result;
  }
Index: src/backend/executor/nodeBitmapIndexscan.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeBitmapIndexscan.c,v
retrieving revision 1.17
diff -c -r1.17 nodeBitmapIndexscan.c
*** src/backend/executor/nodeBitmapIndexscan.c	5 Mar 2006 15:58:26 -0000	1.17
--- src/backend/executor/nodeBitmapIndexscan.c	9 May 2006 20:35:07 -0000
***************
*** 112,118 ****
  
  	/* must provide our own instrumentation support */
  	if (node->ss.ps.instrument)
! 		InstrStopNodeMulti(node->ss.ps.instrument, nTuples);
  
  	return (Node *) tbm;
  }
--- 112,118 ----
  
  	/* must provide our own instrumentation support */
  	if (node->ss.ps.instrument)
! 		InstrStopNode(node->ss.ps.instrument, nTuples);
  
  	return (Node *) tbm;
  }
Index: src/backend/executor/nodeBitmapOr.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeBitmapOr.c,v
retrieving revision 1.5
diff -c -r1.5 nodeBitmapOr.c
*** src/backend/executor/nodeBitmapOr.c	5 Mar 2006 15:58:26 -0000	1.5
--- src/backend/executor/nodeBitmapOr.c	9 May 2006 20:35:07 -0000
***************
*** 179,185 ****
  
  	/* must provide our own instrumentation support */
  	if (node->ps.instrument)
! 		InstrStopNodeMulti(node->ps.instrument, 0 /* XXX */ );
  
  	return (Node *) result;
  }
--- 179,185 ----
  
  	/* must provide our own instrumentation support */
  	if (node->ps.instrument)
! 		InstrStopNode(node->ps.instrument, 0 /* XXX */ );
  
  	return (Node *) result;
  }
Index: src/backend/executor/nodeHash.c
===================================================================
RCS file: /projects/cvsroot/pgsql/src/backend/executor/nodeHash.c,v
retrieving revision 1.101
diff -c -r1.101 nodeHash.c
*** src/backend/executor/nodeHash.c	5 Mar 2006 15:58:26 -0000	1.101
--- src/backend/executor/nodeHash.c	9 May 2006 20:35:07 -0000
***************
*** 97,103 ****
  
  	/* must provide our own instrumentation support */
  	if (node->ps.instrument)
! 		InstrStopNodeMulti(node->ps.instrument, hashtable->totalTuples);
  
  	/*
  	 * We do not return the hash table directly because it's not a subtype of
--- 97,103 ----
  
  	/* must provide our own instrumentation support */
  	if (node->ps.instrument)
! 		InstrStopNode(node->ps.instrument, hashtable->totalTuples);
  
  	/*
  	 * We do not return the hash table directly because it's not a subtype of
Index: src/include/executor/instrument.h
===================================================================
RCS file: /projects/cvsroot/pgsql/src/include/executor/instrument.h,v
retrieving revision 1.13
diff -c -r1.13 instrument.h
*** src/include/executor/instrument.h	5 Mar 2006 15:58:56 -0000	1.13
--- src/include/executor/instrument.h	9 May 2006 20:35:09 -0000
***************
*** 61,77 ****
  	instr_time	counter;		/* Accumulated runtime for this node */
  	double		firsttuple;		/* Time for first tuple of this cycle */
  	double		tuplecount;		/* Tuples emitted so far this cycle */
  	/* Accumulated statistics across all completed cycles: */
  	double		startup;		/* Total startup time (in seconds) */
  	double		total;			/* Total total time (in seconds) */
  	double		ntuples;		/* Total tuples produced */
  	double		nloops;			/* # of run cycles for this node */
  } Instrumentation;
  
  extern Instrumentation *InstrAlloc(int n);
  extern void InstrStartNode(Instrumentation *instr);
! extern void InstrStopNode(Instrumentation *instr, bool returnedTuple);
! extern void InstrStopNodeMulti(Instrumentation *instr, double nTuples);
  extern void InstrEndLoop(Instrumentation *instr);
  
  #endif   /* INSTRUMENT_H */
--- 61,81 ----
  	instr_time	counter;		/* Accumulated runtime for this node */
  	double		firsttuple;		/* Time for first tuple of this cycle */
  	double		tuplecount;		/* Tuples emitted so far this cycle */
+ 	double		samplecount;		/* Samples collected this cycle */
  	/* Accumulated statistics across all completed cycles: */
  	double		startup;		/* Total startup time (in seconds) */
  	double		total;			/* Total total time (in seconds) */
  	double		ntuples;		/* Total tuples produced */
  	double		nloops;			/* # of run cycles for this node */
+ 	double		nsamples;		/* # of samples taken */
+ 	/* Tracking for sampling */
+ 	bool		sampling;		/* Are we sampling this iteration */
+ 	double		nextsample;		/* The next tuplecount we're going to sample */
  } Instrumentation;
  
  extern Instrumentation *InstrAlloc(int n);
  extern void InstrStartNode(Instrumentation *instr);
! extern void InstrStopNode(Instrumentation *instr, double nTuples);
  extern void InstrEndLoop(Instrumentation *instr);
  
  #endif   /* INSTRUMENT_H */