On Windows, use QueryPerformanceCounter instead of gettimeofday for
authorTom Lane <tgl@sss.pgh.pa.us>
Sun, 20 Mar 2005 22:27:52 +0000 (22:27 +0000)
committerTom Lane <tgl@sss.pgh.pa.us>
Sun, 20 Mar 2005 22:27:52 +0000 (22:27 +0000)
EXPLAIN ANALYZE instrumentation.  Magnus Hagander

src/backend/commands/explain.c
src/backend/executor/instrument.c
src/include/executor/instrument.h

index 7a290e88363ccd5fc6fb34bf0b515e7dffbd9e88..02c9534cab8b562b7b93ab54fb3181596d88aff8 100644 (file)
@@ -7,7 +7,7 @@
  * Portions Copyright (c) 1994-5, Regents of the University of California
  *
  * 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,
                TupOutputState *tstate);
-static double elapsed_time(struct timeval * starttime);
+static double elapsed_time(instr_time * starttime);
 static void explain_outNode(StringInfo str,
                Plan *plan, PlanState *planstate,
                Plan *outer_plan,
@@ -212,12 +212,12 @@ void
 ExplainOnePlan(QueryDesc *queryDesc, ExplainStmt *stmt,
               TupOutputState *tstate)
 {
-   struct timeval starttime;
+   instr_time  starttime;
    double      totaltime = 0;
    ExplainState *es;
    StringInfo  str;
 
-   gettimeofday(&starttime, NULL);
+   INSTR_TIME_SET_CURRENT(starttime);
 
    /* If analyzing, we need to cope with queued triggers */
    if (stmt->analyze)
@@ -275,7 +275,7 @@ ExplainOnePlan(QueryDesc *queryDesc, ExplainStmt *stmt,
     * Close down the query and free resources; also run any queued
     * AFTER triggers.  Include time for this in the total runtime.
     */
-   gettimeofday(&starttime, NULL);
+   INSTR_TIME_SET_CURRENT(starttime);
 
    ExecutorEnd(queryDesc);
 
@@ -303,14 +303,15 @@ ExplainOnePlan(QueryDesc *queryDesc, ExplainStmt *stmt,
    pfree(es);
 }
 
-/* Compute elapsed time in seconds since given gettimeofday() timestamp */
+/* Compute elapsed time in seconds since given timestamp */
 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_usec -= starttime->tv_usec;
    while (endtime.tv_usec < 0)
@@ -318,8 +319,11 @@ elapsed_time(struct timeval * starttime)
        endtime.tv_usec += 1000000;
        endtime.tv_sec--;
    }
-   return (double) endtime.tv_sec +
-       (double) endtime.tv_usec / 1000000.0;
+#else  /* WIN32 */
+   endtime.QuadPart -= starttime->QuadPart;
+#endif
+
+   return INSTR_TIME_GET_DOUBLE(endtime);
 }
 
 /*
index 381e6ae4ef013b0244fb509b8855ca87247faa62..8b9b6abb935f8ed33346506d433149899a97305b 100644 (file)
@@ -7,7 +7,7 @@
  * Copyright (c) 2001-2005, PostgreSQL Global Development Group
  *
  * 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)
        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");
    else
-       gettimeofday(&instr->starttime, NULL);
+       INSTR_TIME_SET_CURRENT(instr->starttime);
 }
 
 /* Exit from a plan node */
 void
 InstrStopNode(Instrumentation *instr, bool returnedTuple)
 {
-   struct timeval endtime;
+   instr_time endtime;
 
    if (!instr)
        return;
 
-   if (instr->starttime.tv_sec == 0 && instr->starttime.tv_usec == 0)
+   if (INSTR_TIME_IS_ZERO(instr->starttime))
    {
        elog(DEBUG2, "InstrStopNode without start");
        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_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_sec++;
    }
+#else /* WIN32 */
+   instr->counter.QuadPart += (endtime.QuadPart - instr->starttime.QuadPart);
+#endif
 
-   instr->starttime.tv_sec = 0;
-   instr->starttime.tv_usec = 0;
+   INSTR_TIME_SET_ZERO(instr->starttime);
 
    /* 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;
+       instr->firsttuple = INSTR_TIME_GET_DOUBLE(instr->counter);
    }
 
    if (returnedTuple)
@@ -103,8 +105,7 @@ InstrEndLoop(Instrumentation *instr)
        return;
 
    /* Accumulate statistics */
-   totaltime = (double) instr->counter.tv_sec +
-       (double) instr->counter.tv_usec / 1000000.0;
+   totaltime = INSTR_TIME_GET_DOUBLE(instr->counter);
 
    instr->startup += instr->firsttuple;
    instr->total += totaltime;
@@ -113,10 +114,8 @@ InstrEndLoop(Instrumentation *instr)
 
    /* 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_TIME_SET_ZERO(instr->starttime);
+   INSTR_TIME_SET_ZERO(instr->counter);
    instr->firsttuple = 0;
    instr->tuplecount = 0;
 }
index 754655c1fd49cc4029b5ab436bba1bbf8bfd3629..8936c5cce23833b9494816815d8f58b845f71c7b 100644 (file)
@@ -6,7 +6,7 @@
  *
  * 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 $
  *
  *-------------------------------------------------------------------------
  */
 #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
 {
    /* Info about current plan cycle: */
    bool        running;        /* TRUE if we've completed first tuple */
-   struct timeval starttime;   /* Start time of current iteration of node */
-   struct timeval counter;     /* Accumulates runtime for this node */
+   instr_time  starttime;      /* Start time of current iteration of node */
+   instr_time  counter;        /* Accumulates runtime for this node */
    double      firsttuple;     /* Time for first tuple of this cycle */
    double      tuplecount;     /* Tuples so far this cycle */
    /* Accumulated statistics across all completed cycles: */