|
|
|
|
/*-------------------------------------------------------------------------
|
|
|
|
|
*
|
|
|
|
|
* instrument.c
|
|
|
|
|
* functions for instrumentation of plan execution
|
|
|
|
|
*
|
|
|
|
|
*
|
|
|
|
|
* Copyright (c) 2001, PostgreSQL Global Development Group
|
|
|
|
|
*
|
|
|
|
|
* IDENTIFICATION
|
Commit to match discussed elog() changes. Only update is that LOG is
now just below FATAL in server_min_messages. Added more text to
highlight ordering difference between it and client_min_messages.
---------------------------------------------------------------------------
REALLYFATAL => PANIC
STOP => PANIC
New INFO level the prints to client by default
New LOG level the prints to server log by default
Cause VACUUM information to print only to the client
NOTICE => INFO where purely information messages are sent
DEBUG => LOG for purely server status messages
DEBUG removed, kept as backward compatible
DEBUG5, DEBUG4, DEBUG3, DEBUG2, DEBUG1 added
DebugLvl removed in favor of new DEBUG[1-5] symbols
New server_min_messages GUC parameter with values:
DEBUG[5-1], INFO, NOTICE, ERROR, LOG, FATAL, PANIC
New client_min_messages GUC parameter with values:
DEBUG[5-1], LOG, INFO, NOTICE, ERROR, FATAL, PANIC
Server startup now logged with LOG instead of DEBUG
Remove debug_level GUC parameter
elog() numbers now start at 10
Add test to print error message if older elog() values are passed to elog()
Bootstrap mode now has a -d that requires an argument, like postmaster
24 years ago
|
|
|
* $Header: /cvsroot/pgsql/src/backend/executor/instrument.c,v 1.3 2002/03/02 21:39:25 momjian Exp $
|
|
|
|
|
*
|
|
|
|
|
*-------------------------------------------------------------------------
|
|
|
|
|
*/
|
|
|
|
|
#include "postgres.h"
|
|
|
|
|
|
|
|
|
|
#include <unistd.h>
|
|
|
|
|
|
|
|
|
|
#include "executor/instrument.h"
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
/* Allocate new instrumentation structure */
|
|
|
|
|
Instrumentation *
|
|
|
|
|
InstrAlloc(void)
|
|
|
|
|
{
|
|
|
|
|
Instrumentation *instr = palloc(sizeof(Instrumentation));
|
|
|
|
|
|
|
|
|
|
memset(instr, 0, sizeof(Instrumentation));
|
|
|
|
|
|
|
|
|
|
return instr;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
/* Entry to a plan node */
|
|
|
|
|
void
|
|
|
|
|
InstrStartNode(Instrumentation *instr)
|
|
|
|
|
{
|
|
|
|
|
if (!instr)
|
|
|
|
|
return;
|
|
|
|
|
|
|
|
|
|
if (instr->starttime.tv_sec != 0 || instr->starttime.tv_usec != 0)
|
Commit to match discussed elog() changes. Only update is that LOG is
now just below FATAL in server_min_messages. Added more text to
highlight ordering difference between it and client_min_messages.
---------------------------------------------------------------------------
REALLYFATAL => PANIC
STOP => PANIC
New INFO level the prints to client by default
New LOG level the prints to server log by default
Cause VACUUM information to print only to the client
NOTICE => INFO where purely information messages are sent
DEBUG => LOG for purely server status messages
DEBUG removed, kept as backward compatible
DEBUG5, DEBUG4, DEBUG3, DEBUG2, DEBUG1 added
DebugLvl removed in favor of new DEBUG[1-5] symbols
New server_min_messages GUC parameter with values:
DEBUG[5-1], INFO, NOTICE, ERROR, LOG, FATAL, PANIC
New client_min_messages GUC parameter with values:
DEBUG[5-1], LOG, INFO, NOTICE, ERROR, FATAL, PANIC
Server startup now logged with LOG instead of DEBUG
Remove debug_level GUC parameter
elog() numbers now start at 10
Add test to print error message if older elog() values are passed to elog()
Bootstrap mode now has a -d that requires an argument, like postmaster
24 years ago
|
|
|
elog(LOG, "InstrStartTimer called twice in a row");
|
|
|
|
|
else
|
|
|
|
|
gettimeofday(&instr->starttime, NULL);
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
/* Exit from a plan node */
|
|
|
|
|
void
|
|
|
|
|
InstrStopNode(Instrumentation *instr, bool returnedTuple)
|
|
|
|
|
{
|
|
|
|
|
struct timeval endtime;
|
|
|
|
|
|
|
|
|
|
if (!instr)
|
|
|
|
|
return;
|
|
|
|
|
|
|
|
|
|
if (instr->starttime.tv_sec == 0 && instr->starttime.tv_usec == 0)
|
|
|
|
|
{
|
Commit to match discussed elog() changes. Only update is that LOG is
now just below FATAL in server_min_messages. Added more text to
highlight ordering difference between it and client_min_messages.
---------------------------------------------------------------------------
REALLYFATAL => PANIC
STOP => PANIC
New INFO level the prints to client by default
New LOG level the prints to server log by default
Cause VACUUM information to print only to the client
NOTICE => INFO where purely information messages are sent
DEBUG => LOG for purely server status messages
DEBUG removed, kept as backward compatible
DEBUG5, DEBUG4, DEBUG3, DEBUG2, DEBUG1 added
DebugLvl removed in favor of new DEBUG[1-5] symbols
New server_min_messages GUC parameter with values:
DEBUG[5-1], INFO, NOTICE, ERROR, LOG, FATAL, PANIC
New client_min_messages GUC parameter with values:
DEBUG[5-1], LOG, INFO, NOTICE, ERROR, FATAL, PANIC
Server startup now logged with LOG instead of DEBUG
Remove debug_level GUC parameter
elog() numbers now start at 10
Add test to print error message if older elog() values are passed to elog()
Bootstrap mode now has a -d that requires an argument, like postmaster
24 years ago
|
|
|
elog(LOG, "InstrStopNode without start");
|
|
|
|
|
return;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
gettimeofday(&endtime, NULL);
|
|
|
|
|
|
|
|
|
|
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->starttime.tv_sec = 0;
|
|
|
|
|
instr->starttime.tv_usec = 0;
|
|
|
|
|
|
|
|
|
|
/* Is this the first tuple of this cycle? */
|
|
|
|
|
if (!instr->running)
|
|
|
|
|
{
|
|
|
|
|
instr->running = true;
|
|
|
|
|
instr->firsttuple = (double) instr->counter.tv_sec +
|
|
|
|
|
(double) instr->counter.tv_usec / 1000000.0;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
if (returnedTuple)
|
|
|
|
|
instr->tuplecount += 1;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
/* Finish a run cycle for a plan node */
|
|
|
|
|
void
|
|
|
|
|
InstrEndLoop(Instrumentation *instr)
|
|
|
|
|
{
|
|
|
|
|
double totaltime;
|
|
|
|
|
|
|
|
|
|
if (!instr)
|
|
|
|
|
return;
|
|
|
|
|
|
|
|
|
|
/* Skip if nothing has happened, or already shut down */
|
|
|
|
|
if (!instr->running)
|
|
|
|
|
return;
|
|
|
|
|
|
|
|
|
|
/* Accumulate statistics */
|
|
|
|
|
totaltime = (double) instr->counter.tv_sec +
|
|
|
|
|
(double) instr->counter.tv_usec / 1000000.0;
|
|
|
|
|
|
|
|
|
|
instr->startup += instr->firsttuple;
|
|
|
|
|
instr->total += totaltime;
|
|
|
|
|
instr->ntuples += instr->tuplecount;
|
|
|
|
|
instr->nloops += 1;
|
|
|
|
|
|
|
|
|
|
/* Reset for next cycle (if any) */
|
|
|
|
|
instr->running = false;
|
|
|
|
|
instr->starttime.tv_sec = 0;
|
|
|
|
|
instr->starttime.tv_usec = 0;
|
|
|
|
|
instr->counter.tv_sec = 0;
|
|
|
|
|
instr->counter.tv_usec = 0;
|
|
|
|
|
instr->firsttuple = 0;
|
|
|
|
|
instr->tuplecount = 0;
|
|
|
|
|
}
|