+ {
+ 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 *
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;
}
InstrStartNode(Instrumentation *instr)
{
if (INSTR_TIME_IS_ZERO(instr->starttime))
- INSTR_TIME_SET_CURRENT(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, bool returnedTuple)
+InstrStopNode(Instrumentation *instr, double nTuples)
{
instr_time endtime;
/* count the returned tuples */
- if (returnedTuple)
- instr->tuplecount += 1;
+ instr->tuplecount += nTuples;
- if (INSTR_TIME_IS_ZERO(instr->starttime))
+ if (instr->sampling)
{
- elog(DEBUG2, "InstrStopNode called without start");
- return;
- }
+ if (INSTR_TIME_IS_ZERO(instr->starttime))
+ {
+ elog(DEBUG2, "InstrStopNode called without start");
+ return;
+ }
- INSTR_TIME_SET_CURRENT(endtime);
+ 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++;
- }
+ 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);
+ instr->counter.QuadPart += (endtime.QuadPart - instr->starttime.QuadPart);
#endif
- INSTR_TIME_SET_ZERO(instr->starttime);
+ INSTR_TIME_SET_ZERO(instr->starttime);
+ instr->samplecount += nTuples;
+ instr->sampling = false;
+ }
/* Is this the first tuple of this cycle? */
if (!instr->running)
}
}
-/* 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)
totaltime = INSTR_TIME_GET_DOUBLE(instr->counter);
instr->startup += instr->firsttuple;
- instr->total += totaltime;
+
+ /* 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) */
INSTR_TIME_SET_ZERO(instr->starttime);
INSTR_TIME_SET_ZERO(instr->counter);
instr->firsttuple = 0;
+ instr->samplecount = 0;
instr->tuplecount = 0;
}
projects / postgresql.git / commitdiff