2001-09-18 03:59:07 +02:00
|
|
|
/*-------------------------------------------------------------------------
|
|
|
|
*
|
|
|
|
* instrument.c
|
2001-10-25 07:50:21 +02:00
|
|
|
* functions for instrumentation of plan execution
|
2001-09-18 03:59:07 +02:00
|
|
|
*
|
|
|
|
*
|
2012-01-02 00:01:58 +01:00
|
|
|
* Copyright (c) 2001-2012, PostgreSQL Global Development Group
|
2001-09-18 03:59:07 +02:00
|
|
|
*
|
|
|
|
* IDENTIFICATION
|
2010-09-20 22:08:53 +02:00
|
|
|
* src/backend/executor/instrument.c
|
2001-09-18 03:59:07 +02:00
|
|
|
*
|
|
|
|
*-------------------------------------------------------------------------
|
|
|
|
*/
|
|
|
|
#include "postgres.h"
|
|
|
|
|
2006-05-30 21:24:25 +02:00
|
|
|
#include <unistd.h>
|
2001-09-18 03:59:07 +02:00
|
|
|
|
|
|
|
#include "executor/instrument.h"
|
|
|
|
|
2010-02-26 03:01:40 +01:00
|
|
|
BufferUsage pgBufferUsage;
|
2009-12-15 05:57:48 +01:00
|
|
|
|
|
|
|
static void BufferUsageAccumDiff(BufferUsage *dst,
|
2010-02-26 03:01:40 +01:00
|
|
|
const BufferUsage *add, const BufferUsage *sub);
|
2006-05-30 16:01:58 +02:00
|
|
|
|
2011-09-22 17:29:18 +02:00
|
|
|
|
2005-03-25 22:58:00 +01:00
|
|
|
/* Allocate new instrumentation structure(s) */
|
2001-09-18 03:59:07 +02:00
|
|
|
Instrumentation *
|
2009-12-15 05:57:48 +01:00
|
|
|
InstrAlloc(int n, int instrument_options)
|
2001-09-18 03:59:07 +02:00
|
|
|
{
|
2009-12-15 05:57:48 +01:00
|
|
|
Instrumentation *instr;
|
|
|
|
|
2011-09-22 17:29:18 +02:00
|
|
|
/* initialize all fields to zeroes, then modify as needed */
|
2009-12-15 05:57:48 +01:00
|
|
|
instr = palloc0(n * sizeof(Instrumentation));
|
2012-02-07 17:23:04 +01:00
|
|
|
if (instrument_options & (INSTRUMENT_BUFFERS | INSTRUMENT_TIMER))
|
2009-12-15 05:57:48 +01:00
|
|
|
{
|
2010-02-26 03:01:40 +01:00
|
|
|
int i;
|
2012-02-07 17:23:04 +01:00
|
|
|
bool need_buffers = instrument_options & INSTRUMENT_BUFFERS;
|
|
|
|
bool need_timer = instrument_options & INSTRUMENT_TIMER;
|
2009-12-15 05:57:48 +01:00
|
|
|
|
|
|
|
for (i = 0; i < n; i++)
|
2012-02-07 17:23:04 +01:00
|
|
|
{
|
|
|
|
instr[i].need_bufusage = need_buffers;
|
|
|
|
instr[i].need_timer = need_timer;
|
|
|
|
}
|
2009-12-15 05:57:48 +01:00
|
|
|
}
|
2006-05-30 21:24:25 +02:00
|
|
|
|
2001-09-18 03:59:07 +02:00
|
|
|
return instr;
|
|
|
|
}
|
|
|
|
|
|
|
|
/* Entry to a plan node */
|
|
|
|
void
|
|
|
|
InstrStartNode(Instrumentation *instr)
|
|
|
|
{
|
2012-02-07 17:23:04 +01:00
|
|
|
if (instr->need_timer && INSTR_TIME_IS_ZERO(instr->starttime))
|
2006-06-09 21:30:56 +02:00
|
|
|
INSTR_TIME_SET_CURRENT(instr->starttime);
|
2005-04-16 22:07:35 +02:00
|
|
|
else
|
|
|
|
elog(DEBUG2, "InstrStartNode called twice in a row");
|
2009-12-15 05:57:48 +01:00
|
|
|
|
2011-09-22 17:29:18 +02:00
|
|
|
/* save buffer usage totals at node entry, if needed */
|
|
|
|
if (instr->need_bufusage)
|
2009-12-15 05:57:48 +01:00
|
|
|
instr->bufusage_start = pgBufferUsage;
|
2001-09-18 03:59:07 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
/* Exit from a plan node */
|
|
|
|
void
|
2006-05-30 16:01:58 +02:00
|
|
|
InstrStopNode(Instrumentation *instr, double nTuples)
|
2001-09-18 03:59:07 +02:00
|
|
|
{
|
2006-06-09 21:30:56 +02:00
|
|
|
instr_time endtime;
|
|
|
|
|
|
|
|
/* count the returned tuples */
|
2006-05-30 16:01:58 +02:00
|
|
|
instr->tuplecount += nTuples;
|
2001-09-18 03:59:07 +02:00
|
|
|
|
2012-02-07 17:23:04 +01:00
|
|
|
/* let's update the time only if the timer was requested */
|
|
|
|
if (instr->need_timer)
|
2001-09-18 03:59:07 +02:00
|
|
|
{
|
2006-06-07 20:49:03 +02:00
|
|
|
|
2012-02-07 17:23:04 +01:00
|
|
|
if (INSTR_TIME_IS_ZERO(instr->starttime))
|
|
|
|
{
|
|
|
|
elog(DEBUG2, "InstrStopNode called without start");
|
|
|
|
return;
|
|
|
|
}
|
2001-09-18 03:59:07 +02:00
|
|
|
|
2012-02-07 17:23:04 +01:00
|
|
|
INSTR_TIME_SET_CURRENT(endtime);
|
|
|
|
INSTR_TIME_ACCUM_DIFF(instr->counter, endtime, instr->starttime);
|
|
|
|
|
|
|
|
INSTR_TIME_SET_ZERO(instr->starttime);
|
|
|
|
|
|
|
|
}
|
2001-09-18 03:59:07 +02:00
|
|
|
|
2011-09-22 17:29:18 +02:00
|
|
|
/* Add delta of buffer usage since entry to node's totals */
|
|
|
|
if (instr->need_bufusage)
|
2009-12-15 05:57:48 +01:00
|
|
|
BufferUsageAccumDiff(&instr->bufusage,
|
2010-02-26 03:01:40 +01:00
|
|
|
&pgBufferUsage, &instr->bufusage_start);
|
2009-12-15 05:57:48 +01:00
|
|
|
|
2001-09-18 03:59:07 +02:00
|
|
|
/* Is this the first tuple of this cycle? */
|
|
|
|
if (!instr->running)
|
|
|
|
{
|
|
|
|
instr->running = true;
|
2005-03-20 23:27:52 +01:00
|
|
|
instr->firsttuple = INSTR_TIME_GET_DOUBLE(instr->counter);
|
2001-09-18 03:59:07 +02:00
|
|
|
}
|
2005-04-16 22:07:35 +02:00
|
|
|
}
|
2001-09-18 03:59:07 +02:00
|
|
|
|
|
|
|
/* Finish a run cycle for a plan node */
|
2001-10-25 07:50:21 +02:00
|
|
|
void
|
2001-09-18 03:59:07 +02:00
|
|
|
InstrEndLoop(Instrumentation *instr)
|
|
|
|
{
|
2001-10-25 07:50:21 +02:00
|
|
|
double totaltime;
|
2001-09-18 03:59:07 +02:00
|
|
|
|
|
|
|
/* Skip if nothing has happened, or already shut down */
|
|
|
|
if (!instr->running)
|
|
|
|
return;
|
|
|
|
|
2005-04-16 22:07:35 +02:00
|
|
|
if (!INSTR_TIME_IS_ZERO(instr->starttime))
|
|
|
|
elog(DEBUG2, "InstrEndLoop called on running node");
|
|
|
|
|
2006-06-09 21:30:56 +02:00
|
|
|
/* Accumulate per-cycle statistics into totals */
|
2005-03-20 23:27:52 +01:00
|
|
|
totaltime = INSTR_TIME_GET_DOUBLE(instr->counter);
|
2001-09-18 03:59:07 +02:00
|
|
|
|
2006-05-30 21:24:25 +02:00
|
|
|
instr->startup += instr->firsttuple;
|
|
|
|
instr->total += totaltime;
|
2001-09-18 03:59:07 +02:00
|
|
|
instr->ntuples += instr->tuplecount;
|
|
|
|
instr->nloops += 1;
|
|
|
|
|
|
|
|
/* Reset for next cycle (if any) */
|
|
|
|
instr->running = false;
|
2005-03-20 23:27:52 +01:00
|
|
|
INSTR_TIME_SET_ZERO(instr->starttime);
|
|
|
|
INSTR_TIME_SET_ZERO(instr->counter);
|
2001-09-18 03:59:07 +02:00
|
|
|
instr->firsttuple = 0;
|
|
|
|
instr->tuplecount = 0;
|
|
|
|
}
|
2009-12-15 05:57:48 +01:00
|
|
|
|
2011-09-22 17:29:18 +02:00
|
|
|
/* dst += add - sub */
|
2009-12-15 05:57:48 +01:00
|
|
|
static void
|
|
|
|
BufferUsageAccumDiff(BufferUsage *dst,
|
|
|
|
const BufferUsage *add,
|
|
|
|
const BufferUsage *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;
|
|
|
|
}
|