/*------------------------------------------------------------------------- * * instrument.c * functions for instrumentation of plan execution * * * Copyright (c) 2001-2010, PostgreSQL Global Development Group * * IDENTIFICATION * $PostgreSQL: pgsql/src/backend/executor/instrument.c,v 1.24 2010/01/02 16:57:41 momjian Exp $ * *------------------------------------------------------------------------- */ #include "postgres.h" #include #include "executor/instrument.h" BufferUsage pgBufferUsage; static void BufferUsageAccumDiff(BufferUsage *dst, const BufferUsage *add, const BufferUsage *sub); /* Allocate new instrumentation structure(s) */ Instrumentation * InstrAlloc(int n, int instrument_options) { Instrumentation *instr; /* timer is always required for now */ Assert(instrument_options & INSTRUMENT_TIMER); instr = palloc0(n * sizeof(Instrumentation)); if (instrument_options & INSTRUMENT_BUFFERS) { int i; for (i = 0; i < n; i++) instr[i].needs_bufusage = true; } return instr; } /* Entry to a plan node */ void 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"); /* initialize buffer usage per plan node */ if (instr->needs_bufusage) instr->bufusage_start = pgBufferUsage; } /* Exit from a plan node */ void InstrStopNode(Instrumentation *instr, double nTuples) { instr_time endtime; /* count the returned tuples */ instr->tuplecount += nTuples; if (INSTR_TIME_IS_ZERO(instr->starttime)) { elog(DEBUG2, "InstrStopNode called without start"); return; } INSTR_TIME_SET_CURRENT(endtime); INSTR_TIME_ACCUM_DIFF(instr->counter, endtime, instr->starttime); INSTR_TIME_SET_ZERO(instr->starttime); /* Adds delta of buffer usage to node's count. */ if (instr->needs_bufusage) BufferUsageAccumDiff(&instr->bufusage, &pgBufferUsage, &instr->bufusage_start); /* Is this the first tuple of this cycle? */ if (!instr->running) { instr->running = true; instr->firsttuple = INSTR_TIME_GET_DOUBLE(instr->counter); } } /* Finish a run cycle for a plan node */ void InstrEndLoop(Instrumentation *instr) { double totaltime; /* Skip if nothing has happened, or already shut down */ if (!instr->running) return; if (!INSTR_TIME_IS_ZERO(instr->starttime)) elog(DEBUG2, "InstrEndLoop called on running node"); /* Accumulate per-cycle statistics into totals */ 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) */ instr->running = false; INSTR_TIME_SET_ZERO(instr->starttime); INSTR_TIME_SET_ZERO(instr->counter); instr->firsttuple = 0; instr->tuplecount = 0; } static void BufferUsageAccumDiff(BufferUsage *dst, const BufferUsage *add, const BufferUsage *sub) { /* dst += add - sub */ dst->shared_blks_hit += add->shared_blks_hit - sub->shared_blks_hit; dst->shared_blks_read += add->shared_blks_read - sub->shared_blks_read; dst->shared_blks_written += add->shared_blks_written - sub->shared_blks_written; dst->local_blks_hit += add->local_blks_hit - sub->local_blks_hit; dst->local_blks_read += add->local_blks_read - sub->local_blks_read; dst->local_blks_written += add->local_blks_written - sub->local_blks_written; dst->temp_blks_read += add->temp_blks_read - sub->temp_blks_read; dst->temp_blks_written += add->temp_blks_written - sub->temp_blks_written; }