PostgreSQL Source Code  git master
 All Data Structures Namespaces Files Functions Variables Typedefs Enumerations Enumerator Macros
instrument.c
Go to the documentation of this file.
1 /*-------------------------------------------------------------------------
2  *
3  * instrument.c
4  * functions for instrumentation of plan execution
5  *
6  *
7  * Copyright (c) 2001-2017, PostgreSQL Global Development Group
8  *
9  * IDENTIFICATION
10  * src/backend/executor/instrument.c
11  *
12  *-------------------------------------------------------------------------
13  */
14 #include "postgres.h"
15 
16 #include <unistd.h>
17 
18 #include "executor/instrument.h"
19 
22 
23 static void BufferUsageAdd(BufferUsage *dst, const BufferUsage *add);
24 static void BufferUsageAccumDiff(BufferUsage *dst,
25  const BufferUsage *add, const BufferUsage *sub);
26 
27 
28 /* Allocate new instrumentation structure(s) */
30 InstrAlloc(int n, int instrument_options)
31 {
32  Instrumentation *instr;
33 
34  /* initialize all fields to zeroes, then modify as needed */
35  instr = palloc0(n * sizeof(Instrumentation));
36  if (instrument_options & (INSTRUMENT_BUFFERS | INSTRUMENT_TIMER))
37  {
38  bool need_buffers = (instrument_options & INSTRUMENT_BUFFERS) != 0;
39  bool need_timer = (instrument_options & INSTRUMENT_TIMER) != 0;
40  int i;
41 
42  for (i = 0; i < n; i++)
43  {
44  instr[i].need_bufusage = need_buffers;
45  instr[i].need_timer = need_timer;
46  }
47  }
48 
49  return instr;
50 }
51 
52 /* Initialize an pre-allocated instrumentation structure. */
53 void
54 InstrInit(Instrumentation *instr, int instrument_options)
55 {
56  memset(instr, 0, sizeof(Instrumentation));
57  instr->need_bufusage = (instrument_options & INSTRUMENT_BUFFERS) != 0;
58  instr->need_timer = (instrument_options & INSTRUMENT_TIMER) != 0;
59 }
60 
61 /* Entry to a plan node */
62 void
64 {
65  if (instr->need_timer)
66  {
67  if (INSTR_TIME_IS_ZERO(instr->starttime))
69  else
70  elog(ERROR, "InstrStartNode called twice in a row");
71  }
72 
73  /* save buffer usage totals at node entry, if needed */
74  if (instr->need_bufusage)
76 }
77 
78 /* Exit from a plan node */
79 void
80 InstrStopNode(Instrumentation *instr, double nTuples)
81 {
82  instr_time endtime;
83 
84  /* count the returned tuples */
85  instr->tuplecount += nTuples;
86 
87  /* let's update the time only if the timer was requested */
88  if (instr->need_timer)
89  {
90  if (INSTR_TIME_IS_ZERO(instr->starttime))
91  elog(ERROR, "InstrStopNode called without start");
92 
93  INSTR_TIME_SET_CURRENT(endtime);
94  INSTR_TIME_ACCUM_DIFF(instr->counter, endtime, instr->starttime);
95 
97  }
98 
99  /* Add delta of buffer usage since entry to node's totals */
100  if (instr->need_bufusage)
102  &pgBufferUsage, &instr->bufusage_start);
103 
104  /* Is this the first tuple of this cycle? */
105  if (!instr->running)
106  {
107  instr->running = true;
108  instr->firsttuple = INSTR_TIME_GET_DOUBLE(instr->counter);
109  }
110 }
111 
112 /* Finish a run cycle for a plan node */
113 void
115 {
116  double totaltime;
117 
118  /* Skip if nothing has happened, or already shut down */
119  if (!instr->running)
120  return;
121 
122  if (!INSTR_TIME_IS_ZERO(instr->starttime))
123  elog(ERROR, "InstrEndLoop called on running node");
124 
125  /* Accumulate per-cycle statistics into totals */
126  totaltime = INSTR_TIME_GET_DOUBLE(instr->counter);
127 
128  instr->startup += instr->firsttuple;
129  instr->total += totaltime;
130  instr->ntuples += instr->tuplecount;
131  instr->nloops += 1;
132 
133  /* Reset for next cycle (if any) */
134  instr->running = false;
137  instr->firsttuple = 0;
138  instr->tuplecount = 0;
139 }
140 
141 /* aggregate instrumentation information */
142 void
144 {
145  if (!dst->running && add->running)
146  {
147  dst->running = true;
148  dst->firsttuple = add->firsttuple;
149  }
150  else if (dst->running && add->running && dst->firsttuple > add->firsttuple)
151  dst->firsttuple = add->firsttuple;
152 
153  INSTR_TIME_ADD(dst->counter, add->counter);
154 
155  dst->tuplecount += add->tuplecount;
156  dst->startup += add->startup;
157  dst->total += add->total;
158  dst->ntuples += add->ntuples;
159  dst->nloops += add->nloops;
160  dst->nfiltered1 += add->nfiltered1;
161  dst->nfiltered2 += add->nfiltered2;
162 
163  /* Add delta of buffer usage since entry to node's totals */
164  if (dst->need_bufusage)
165  BufferUsageAdd(&dst->bufusage, &add->bufusage);
166 }
167 
168 /* note current values during parallel executor startup */
169 void
171 {
172  save_pgBufferUsage = pgBufferUsage;
173 }
174 
175 /* report usage after parallel executor shutdown */
176 void
178 {
179  memset(result, 0, sizeof(BufferUsage));
180  BufferUsageAccumDiff(result, &pgBufferUsage, &save_pgBufferUsage);
181 }
182 
183 /* accumulate work done by workers in leader's stats */
184 void
186 {
187  BufferUsageAdd(&pgBufferUsage, result);
188 }
189 
190 /* dst += add */
191 static void
193 {
194  dst->shared_blks_hit += add->shared_blks_hit;
195  dst->shared_blks_read += add->shared_blks_read;
198  dst->local_blks_hit += add->local_blks_hit;
199  dst->local_blks_read += add->local_blks_read;
202  dst->temp_blks_read += add->temp_blks_read;
206 }
207 
208 /* dst += add - sub */
209 static void
211  const BufferUsage *add,
212  const BufferUsage *sub)
213 {
214  dst->shared_blks_hit += add->shared_blks_hit - sub->shared_blks_hit;
218  dst->local_blks_hit += add->local_blks_hit - sub->local_blks_hit;
219  dst->local_blks_read += add->local_blks_read - sub->local_blks_read;
222  dst->temp_blks_read += add->temp_blks_read - sub->temp_blks_read;
225  add->blk_read_time, sub->blk_read_time);
227  add->blk_write_time, sub->blk_write_time);
228 }
double nfiltered1
Definition: instrument.h:61
void InstrStopNode(Instrumentation *instr, double nTuples)
Definition: instrument.c:80
bool need_bufusage
Definition: instrument.h:48
long local_blks_hit
Definition: instrument.h:25
long local_blks_dirtied
Definition: instrument.h:27
long local_blks_read
Definition: instrument.h:26
instr_time blk_read_time
Definition: instrument.h:31
void InstrAggNode(Instrumentation *dst, Instrumentation *add)
Definition: instrument.c:143
struct timeval instr_time
Definition: instr_time.h:147
long shared_blks_read
Definition: instrument.h:22
double startup
Definition: instrument.h:57
void InstrEndParallelQuery(BufferUsage *result)
Definition: instrument.c:177
#define INSTR_TIME_ACCUM_DIFF(x, y, z)
Definition: instr_time.h:179
Instrumentation * InstrAlloc(int n, int instrument_options)
Definition: instrument.c:30
static BufferUsage save_pgBufferUsage
Definition: instrument.c:21
return result
Definition: formatting.c:1633
#define INSTR_TIME_SET_ZERO(t)
Definition: instr_time.h:151
#define INSTR_TIME_GET_DOUBLE(t)
Definition: instr_time.h:196
long temp_blks_written
Definition: instrument.h:30
#define INSTR_TIME_IS_ZERO(t)
Definition: instr_time.h:149
void InstrEndLoop(Instrumentation *instr)
Definition: instrument.c:114
long shared_blks_written
Definition: instrument.h:24
BufferUsage bufusage_start
Definition: instrument.h:55
#define ERROR
Definition: elog.h:43
double firsttuple
Definition: instrument.h:53
double nfiltered2
Definition: instrument.h:62
void InstrStartNode(Instrumentation *instr)
Definition: instrument.c:63
#define INSTR_TIME_ADD(x, y)
Definition: instr_time.h:155
instr_time starttime
Definition: instrument.h:51
long shared_blks_dirtied
Definition: instrument.h:23
void InstrAccumParallelQuery(BufferUsage *result)
Definition: instrument.c:185
static void BufferUsageAccumDiff(BufferUsage *dst, const BufferUsage *add, const BufferUsage *sub)
Definition: instrument.c:210
double ntuples
Definition: instrument.h:59
long temp_blks_read
Definition: instrument.h:29
double tuplecount
Definition: instrument.h:54
void InstrStartParallelQuery(void)
Definition: instrument.c:170
void InstrInit(Instrumentation *instr, int instrument_options)
Definition: instrument.c:54
void * palloc0(Size size)
Definition: mcxt.c:878
BufferUsage bufusage
Definition: instrument.h:63
instr_time counter
Definition: instrument.h:52
instr_time blk_write_time
Definition: instrument.h:32
#define INSTR_TIME_SET_CURRENT(t)
Definition: instr_time.h:153
long shared_blks_hit
Definition: instrument.h:21
long local_blks_written
Definition: instrument.h:28
int i
#define elog
Definition: elog.h:219
static void BufferUsageAdd(BufferUsage *dst, const BufferUsage *add)
Definition: instrument.c:192
BufferUsage pgBufferUsage
Definition: instrument.c:20