On Windows, use QueryPerformanceCounter instead of gettimeofday for
EXPLAIN ANALYZE instrumentation. Magnus Hagander
This commit is contained in:
parent
354049c709
commit
9e0dd84596
|
@ -7,7 +7,7 @@
|
||||||
* Portions Copyright (c) 1994-5, Regents of the University of California
|
* Portions Copyright (c) 1994-5, Regents of the University of California
|
||||||
*
|
*
|
||||||
* IDENTIFICATION
|
* IDENTIFICATION
|
||||||
* $PostgreSQL: pgsql/src/backend/commands/explain.c,v 1.129 2004/12/31 21:59:41 pgsql Exp $
|
* $PostgreSQL: pgsql/src/backend/commands/explain.c,v 1.130 2005/03/20 22:27:51 tgl Exp $
|
||||||
*
|
*
|
||||||
*-------------------------------------------------------------------------
|
*-------------------------------------------------------------------------
|
||||||
*/
|
*/
|
||||||
|
@ -46,7 +46,7 @@ typedef struct ExplainState
|
||||||
|
|
||||||
static void ExplainOneQuery(Query *query, ExplainStmt *stmt,
|
static void ExplainOneQuery(Query *query, ExplainStmt *stmt,
|
||||||
TupOutputState *tstate);
|
TupOutputState *tstate);
|
||||||
static double elapsed_time(struct timeval * starttime);
|
static double elapsed_time(instr_time * starttime);
|
||||||
static void explain_outNode(StringInfo str,
|
static void explain_outNode(StringInfo str,
|
||||||
Plan *plan, PlanState *planstate,
|
Plan *plan, PlanState *planstate,
|
||||||
Plan *outer_plan,
|
Plan *outer_plan,
|
||||||
|
@ -212,12 +212,12 @@ void
|
||||||
ExplainOnePlan(QueryDesc *queryDesc, ExplainStmt *stmt,
|
ExplainOnePlan(QueryDesc *queryDesc, ExplainStmt *stmt,
|
||||||
TupOutputState *tstate)
|
TupOutputState *tstate)
|
||||||
{
|
{
|
||||||
struct timeval starttime;
|
instr_time starttime;
|
||||||
double totaltime = 0;
|
double totaltime = 0;
|
||||||
ExplainState *es;
|
ExplainState *es;
|
||||||
StringInfo str;
|
StringInfo str;
|
||||||
|
|
||||||
gettimeofday(&starttime, NULL);
|
INSTR_TIME_SET_CURRENT(starttime);
|
||||||
|
|
||||||
/* If analyzing, we need to cope with queued triggers */
|
/* If analyzing, we need to cope with queued triggers */
|
||||||
if (stmt->analyze)
|
if (stmt->analyze)
|
||||||
|
@ -275,7 +275,7 @@ ExplainOnePlan(QueryDesc *queryDesc, ExplainStmt *stmt,
|
||||||
* Close down the query and free resources; also run any queued
|
* Close down the query and free resources; also run any queued
|
||||||
* AFTER triggers. Include time for this in the total runtime.
|
* AFTER triggers. Include time for this in the total runtime.
|
||||||
*/
|
*/
|
||||||
gettimeofday(&starttime, NULL);
|
INSTR_TIME_SET_CURRENT(starttime);
|
||||||
|
|
||||||
ExecutorEnd(queryDesc);
|
ExecutorEnd(queryDesc);
|
||||||
|
|
||||||
|
@ -303,14 +303,15 @@ ExplainOnePlan(QueryDesc *queryDesc, ExplainStmt *stmt,
|
||||||
pfree(es);
|
pfree(es);
|
||||||
}
|
}
|
||||||
|
|
||||||
/* Compute elapsed time in seconds since given gettimeofday() timestamp */
|
/* Compute elapsed time in seconds since given timestamp */
|
||||||
static double
|
static double
|
||||||
elapsed_time(struct timeval * starttime)
|
elapsed_time(instr_time * starttime)
|
||||||
{
|
{
|
||||||
struct timeval endtime;
|
instr_time endtime;
|
||||||
|
|
||||||
gettimeofday(&endtime, NULL);
|
INSTR_TIME_SET_CURRENT(endtime);
|
||||||
|
|
||||||
|
#ifndef WIN32
|
||||||
endtime.tv_sec -= starttime->tv_sec;
|
endtime.tv_sec -= starttime->tv_sec;
|
||||||
endtime.tv_usec -= starttime->tv_usec;
|
endtime.tv_usec -= starttime->tv_usec;
|
||||||
while (endtime.tv_usec < 0)
|
while (endtime.tv_usec < 0)
|
||||||
|
@ -318,8 +319,11 @@ elapsed_time(struct timeval * starttime)
|
||||||
endtime.tv_usec += 1000000;
|
endtime.tv_usec += 1000000;
|
||||||
endtime.tv_sec--;
|
endtime.tv_sec--;
|
||||||
}
|
}
|
||||||
return (double) endtime.tv_sec +
|
#else /* WIN32 */
|
||||||
(double) endtime.tv_usec / 1000000.0;
|
endtime.QuadPart -= starttime->QuadPart;
|
||||||
|
#endif
|
||||||
|
|
||||||
|
return INSTR_TIME_GET_DOUBLE(endtime);
|
||||||
}
|
}
|
||||||
|
|
||||||
/*
|
/*
|
||||||
|
|
|
@ -7,7 +7,7 @@
|
||||||
* Copyright (c) 2001-2005, PostgreSQL Global Development Group
|
* Copyright (c) 2001-2005, PostgreSQL Global Development Group
|
||||||
*
|
*
|
||||||
* IDENTIFICATION
|
* IDENTIFICATION
|
||||||
* $PostgreSQL: pgsql/src/backend/executor/instrument.c,v 1.9 2005/01/01 05:43:06 momjian Exp $
|
* $PostgreSQL: pgsql/src/backend/executor/instrument.c,v 1.10 2005/03/20 22:27:51 tgl Exp $
|
||||||
*
|
*
|
||||||
*-------------------------------------------------------------------------
|
*-------------------------------------------------------------------------
|
||||||
*/
|
*/
|
||||||
|
@ -36,29 +36,30 @@ InstrStartNode(Instrumentation *instr)
|
||||||
if (!instr)
|
if (!instr)
|
||||||
return;
|
return;
|
||||||
|
|
||||||
if (instr->starttime.tv_sec != 0 || instr->starttime.tv_usec != 0)
|
if (!INSTR_TIME_IS_ZERO(instr->starttime))
|
||||||
elog(DEBUG2, "InstrStartNode called twice in a row");
|
elog(DEBUG2, "InstrStartNode called twice in a row");
|
||||||
else
|
else
|
||||||
gettimeofday(&instr->starttime, NULL);
|
INSTR_TIME_SET_CURRENT(instr->starttime);
|
||||||
}
|
}
|
||||||
|
|
||||||
/* Exit from a plan node */
|
/* Exit from a plan node */
|
||||||
void
|
void
|
||||||
InstrStopNode(Instrumentation *instr, bool returnedTuple)
|
InstrStopNode(Instrumentation *instr, bool returnedTuple)
|
||||||
{
|
{
|
||||||
struct timeval endtime;
|
instr_time endtime;
|
||||||
|
|
||||||
if (!instr)
|
if (!instr)
|
||||||
return;
|
return;
|
||||||
|
|
||||||
if (instr->starttime.tv_sec == 0 && instr->starttime.tv_usec == 0)
|
if (INSTR_TIME_IS_ZERO(instr->starttime))
|
||||||
{
|
{
|
||||||
elog(DEBUG2, "InstrStopNode without start");
|
elog(DEBUG2, "InstrStopNode without start");
|
||||||
return;
|
return;
|
||||||
}
|
}
|
||||||
|
|
||||||
gettimeofday(&endtime, NULL);
|
INSTR_TIME_SET_CURRENT(endtime);
|
||||||
|
|
||||||
|
#ifndef WIN32
|
||||||
instr->counter.tv_sec += endtime.tv_sec - instr->starttime.tv_sec;
|
instr->counter.tv_sec += endtime.tv_sec - instr->starttime.tv_sec;
|
||||||
instr->counter.tv_usec += endtime.tv_usec - instr->starttime.tv_usec;
|
instr->counter.tv_usec += endtime.tv_usec - instr->starttime.tv_usec;
|
||||||
|
|
||||||
|
@ -73,16 +74,17 @@ InstrStopNode(Instrumentation *instr, bool returnedTuple)
|
||||||
instr->counter.tv_usec -= 1000000;
|
instr->counter.tv_usec -= 1000000;
|
||||||
instr->counter.tv_sec++;
|
instr->counter.tv_sec++;
|
||||||
}
|
}
|
||||||
|
#else /* WIN32 */
|
||||||
|
instr->counter.QuadPart += (endtime.QuadPart - instr->starttime.QuadPart);
|
||||||
|
#endif
|
||||||
|
|
||||||
instr->starttime.tv_sec = 0;
|
INSTR_TIME_SET_ZERO(instr->starttime);
|
||||||
instr->starttime.tv_usec = 0;
|
|
||||||
|
|
||||||
/* Is this the first tuple of this cycle? */
|
/* Is this the first tuple of this cycle? */
|
||||||
if (!instr->running)
|
if (!instr->running)
|
||||||
{
|
{
|
||||||
instr->running = true;
|
instr->running = true;
|
||||||
instr->firsttuple = (double) instr->counter.tv_sec +
|
instr->firsttuple = INSTR_TIME_GET_DOUBLE(instr->counter);
|
||||||
(double) instr->counter.tv_usec / 1000000.0;
|
|
||||||
}
|
}
|
||||||
|
|
||||||
if (returnedTuple)
|
if (returnedTuple)
|
||||||
|
@ -103,8 +105,7 @@ InstrEndLoop(Instrumentation *instr)
|
||||||
return;
|
return;
|
||||||
|
|
||||||
/* Accumulate statistics */
|
/* Accumulate statistics */
|
||||||
totaltime = (double) instr->counter.tv_sec +
|
totaltime = INSTR_TIME_GET_DOUBLE(instr->counter);
|
||||||
(double) instr->counter.tv_usec / 1000000.0;
|
|
||||||
|
|
||||||
instr->startup += instr->firsttuple;
|
instr->startup += instr->firsttuple;
|
||||||
instr->total += totaltime;
|
instr->total += totaltime;
|
||||||
|
@ -113,10 +114,8 @@ InstrEndLoop(Instrumentation *instr)
|
||||||
|
|
||||||
/* Reset for next cycle (if any) */
|
/* Reset for next cycle (if any) */
|
||||||
instr->running = false;
|
instr->running = false;
|
||||||
instr->starttime.tv_sec = 0;
|
INSTR_TIME_SET_ZERO(instr->starttime);
|
||||||
instr->starttime.tv_usec = 0;
|
INSTR_TIME_SET_ZERO(instr->counter);
|
||||||
instr->counter.tv_sec = 0;
|
|
||||||
instr->counter.tv_usec = 0;
|
|
||||||
instr->firsttuple = 0;
|
instr->firsttuple = 0;
|
||||||
instr->tuplecount = 0;
|
instr->tuplecount = 0;
|
||||||
}
|
}
|
||||||
|
|
|
@ -6,7 +6,7 @@
|
||||||
*
|
*
|
||||||
* Copyright (c) 2001-2005, PostgreSQL Global Development Group
|
* Copyright (c) 2001-2005, PostgreSQL Global Development Group
|
||||||
*
|
*
|
||||||
* $PostgreSQL: pgsql/src/include/executor/instrument.h,v 1.8 2005/01/01 05:43:09 momjian Exp $
|
* $PostgreSQL: pgsql/src/include/executor/instrument.h,v 1.9 2005/03/20 22:27:52 tgl Exp $
|
||||||
*
|
*
|
||||||
*-------------------------------------------------------------------------
|
*-------------------------------------------------------------------------
|
||||||
*/
|
*/
|
||||||
|
@ -16,12 +16,51 @@
|
||||||
#include <sys/time.h>
|
#include <sys/time.h>
|
||||||
|
|
||||||
|
|
||||||
|
/*
|
||||||
|
* gettimeofday() does not have sufficient resolution on Windows,
|
||||||
|
* so we must use QueryPerformanceCounter() instead. These macros
|
||||||
|
* also give some breathing room to use other high-precision-timing APIs
|
||||||
|
* on yet other platforms. (The macro-ization is not complete, however;
|
||||||
|
* see subtraction code in instrument.c and explain.c.)
|
||||||
|
*/
|
||||||
|
#ifndef WIN32
|
||||||
|
|
||||||
|
typedef struct timeval instr_time;
|
||||||
|
|
||||||
|
#define INSTR_TIME_IS_ZERO(t) ((t).tv_sec == 0 && (t).tv_usec == 0)
|
||||||
|
#define INSTR_TIME_SET_ZERO(t) ((t).tv_sec = 0, (t).tv_usec = 0)
|
||||||
|
#define INSTR_TIME_SET_CURRENT(t) gettimeofday(&(t), NULL)
|
||||||
|
#define INSTR_TIME_GET_DOUBLE(t) \
|
||||||
|
(((double) (t).tv_sec) + ((double) (t).tv_usec) / 1000000.0)
|
||||||
|
|
||||||
|
#else /* WIN32 */
|
||||||
|
|
||||||
|
typedef LARGE_INTEGER instr_time;
|
||||||
|
|
||||||
|
#define INSTR_TIME_IS_ZERO(t) ((t).QuadPart == 0)
|
||||||
|
#define INSTR_TIME_SET_ZERO(t) ((t).QuadPart = 0)
|
||||||
|
#define INSTR_TIME_SET_CURRENT(t) QueryPerformanceCounter(&(t))
|
||||||
|
#define INSTR_TIME_GET_DOUBLE(t) \
|
||||||
|
(((double) (t).QuadPart) / GetTimerFrequency())
|
||||||
|
|
||||||
|
static __inline__ double
|
||||||
|
GetTimerFrequency(void)
|
||||||
|
{
|
||||||
|
LARGE_INTEGER f;
|
||||||
|
|
||||||
|
QueryPerformanceFrequency(&f);
|
||||||
|
return (double) f.QuadPart;
|
||||||
|
}
|
||||||
|
|
||||||
|
#endif /* WIN32 */
|
||||||
|
|
||||||
|
|
||||||
typedef struct Instrumentation
|
typedef struct Instrumentation
|
||||||
{
|
{
|
||||||
/* Info about current plan cycle: */
|
/* Info about current plan cycle: */
|
||||||
bool running; /* TRUE if we've completed first tuple */
|
bool running; /* TRUE if we've completed first tuple */
|
||||||
struct timeval starttime; /* Start time of current iteration of node */
|
instr_time starttime; /* Start time of current iteration of node */
|
||||||
struct timeval counter; /* Accumulates runtime for this node */
|
instr_time counter; /* Accumulates runtime for this node */
|
||||||
double firsttuple; /* Time for first tuple of this cycle */
|
double firsttuple; /* Time for first tuple of this cycle */
|
||||||
double tuplecount; /* Tuples so far this cycle */
|
double tuplecount; /* Tuples so far this cycle */
|
||||||
/* Accumulated statistics across all completed cycles: */
|
/* Accumulated statistics across all completed cycles: */
|
||||||
|
|
Loading…
Reference in New Issue