Index: backend/commands/explain.c =================================================================== --- backend/commands/explain.c (revision 28901) +++ backend/commands/explain.c (working copy) @@ -378,8 +378,16 @@ appendStringInfo(buf, " on %s", RelationGetRelationName(rInfo->ri_RelationDesc)); - appendStringInfo(buf, ": time=%.3f calls=%.0f\n", - 1000.0 * instr->total, instr->ntuples); + appendStringInfo(buf, ": time=%.3f calls=%.0f read_shared=%ld(%ld) read_local=%ld(%ld) flush=%ld local_flush=%ld file_read=%ld file_write=%ld\n", + 1000.0 * instr->total, instr->ntuples, + instr->ReadBufferCount, + instr->BufferHitCount, + instr->ReadLocalBufferCount, + instr->LocalBufferHitCount, + instr->BufferFlushCount, + instr->LocalBufferFlushCount, + instr->BufFileReadCount, + instr->BufFileWriteCount); } } @@ -740,11 +748,19 @@ { double nloops = planstate->instrument->nloops; - appendStringInfo(str, " (actual time=%.3f..%.3f rows=%.0f loops=%.0f)", + appendStringInfo(str, " (actual time=%.3f..%.3f rows=%.0f loops=%.0f read_shared=%ld(%ld) read_local=%ld(%ld) flush=%ld local_flush=%ld file_read=%ld file_write=%ld)", 1000.0 * planstate->instrument->startup / nloops, 1000.0 * planstate->instrument->total / nloops, planstate->instrument->ntuples / nloops, - planstate->instrument->nloops); + planstate->instrument->nloops, + planstate->instrument->ReadBufferCount, + planstate->instrument->BufferHitCount, + planstate->instrument->ReadLocalBufferCount, + planstate->instrument->LocalBufferHitCount, + planstate->instrument->BufferFlushCount, + planstate->instrument->LocalBufferFlushCount, + planstate->instrument->BufFileReadCount, + planstate->instrument->BufFileWriteCount); } else if (es->printAnalyze) appendStringInfo(str, " (never executed)"); Index: backend/executor/instrument.c =================================================================== --- backend/executor/instrument.c (revision 28901) +++ backend/executor/instrument.c (working copy) @@ -34,7 +34,10 @@ InstrStartNode(Instrumentation *instr) { if (INSTR_TIME_IS_ZERO(instr->starttime)) + { INSTR_TIME_SET_CURRENT(instr->starttime); + INSTR_ADD_BUFFER_COUNTERS(instr, -); + } else elog(DEBUG2, "InstrStartNode called twice in a row"); } @@ -56,6 +59,7 @@ INSTR_TIME_SET_CURRENT(endtime); INSTR_TIME_ACCUM_DIFF(instr->counter, endtime, instr->starttime); + INSTR_ADD_BUFFER_COUNTERS(instr, +); INSTR_TIME_SET_ZERO(instr->starttime); Index: include/executor/instrument.h =================================================================== --- include/executor/instrument.h (revision 28901) +++ include/executor/instrument.h (working copy) @@ -14,8 +14,22 @@ #define INSTRUMENT_H #include "portability/instr_time.h" +#include "storage/buf_internals.h" +#define INSTR_ADD_BUFFER_COUNTERS_2(i, sign) +#define INSTR_ADD_BUFFER_COUNTERS_2(i, sign) \ + do { \ + i->ReadBufferCount sign##= ReadBufferCount; \ + i->ReadLocalBufferCount sign##= ReadLocalBufferCount; \ + i->BufferHitCount sign##= BufferHitCount; \ + i->LocalBufferHitCount sign##= LocalBufferHitCount; \ + i->BufferFlushCount sign##= BufferFlushCount; \ + i->LocalBufferFlushCount sign##= LocalBufferFlushCount; \ + i->BufFileReadCount sign##= BufFileReadCount; \ + i->BufFileWriteCount sign##= BufFileWriteCount; \ + } while(0); + typedef struct Instrumentation { /* Info about current plan cycle: */ @@ -29,6 +43,14 @@ double total; /* Total total time (in seconds) */ double ntuples; /* Total tuples produced */ double nloops; /* # of run cycles for this node */ + long int ReadBufferCount; /* # of buffers read */ + long int ReadLocalBufferCount; /* # of local buffers read */ + long int BufferHitCount; /* # of buffer hits */ + long int LocalBufferHitCount; /* # of local buffer hits */ + long int BufferFlushCount; /* # of buffers flushed */ + long int LocalBufferFlushCount; /* # of local buffers flushed */ + long int BufFileReadCount; /* # of direct writes (temp) */ + long int BufFileWriteCount; /* # of direct writes (temp) */ } Instrumentation; extern Instrumentation *InstrAlloc(int n);