PostgreSQL Source Code  git master
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-2019, 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 a 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 &&
67  elog(ERROR, "InstrStartNode called twice in a row");
68 
69  /* save buffer usage totals at node entry, if needed */
70  if (instr->need_bufusage)
72 }
73 
74 /* Exit from a plan node */
75 void
76 InstrStopNode(Instrumentation *instr, double nTuples)
77 {
78  instr_time endtime;
79 
80  /* count the returned tuples */
81  instr->tuplecount += nTuples;
82 
83  /* let's update the time only if the timer was requested */
84  if (instr->need_timer)
85  {
86  if (INSTR_TIME_IS_ZERO(instr->starttime))
87  elog(ERROR, "InstrStopNode called without start");
88 
89  INSTR_TIME_SET_CURRENT(endtime);
90  INSTR_TIME_ACCUM_DIFF(instr->counter, endtime, instr->starttime);
91 
93  }
94 
95  /* Add delta of buffer usage since entry to node's totals */
96  if (instr->need_bufusage)
98  &pgBufferUsage, &instr->bufusage_start);
99 
100  /* Is this the first tuple of this cycle? */
101  if (!instr->running)
102  {
103  instr->running = true;
104  instr->firsttuple = INSTR_TIME_GET_DOUBLE(instr->counter);
105  }
106 }
107 
108 /* Finish a run cycle for a plan node */
109 void
111 {
112  double totaltime;
113 
114  /* Skip if nothing has happened, or already shut down */
115  if (!instr->running)
116  return;
117 
118  if (!INSTR_TIME_IS_ZERO(instr->starttime))
119  elog(ERROR, "InstrEndLoop called on running node");
120 
121  /* Accumulate per-cycle statistics into totals */
122  totaltime = INSTR_TIME_GET_DOUBLE(instr->counter);
123 
124  instr->startup += instr->firsttuple;
125  instr->total += totaltime;
126  instr->ntuples += instr->tuplecount;
127  instr->nloops += 1;
128 
129  /* Reset for next cycle (if any) */
130  instr->running = false;
133  instr->firsttuple = 0;
134  instr->tuplecount = 0;
135 }
136 
137 /* aggregate instrumentation information */
138 void
140 {
141  if (!dst->running && add->running)
142  {
143  dst->running = true;
144  dst->firsttuple = add->firsttuple;
145  }
146  else if (dst->running && add->running && dst->firsttuple > add->firsttuple)
147  dst->firsttuple = add->firsttuple;
148 
149  INSTR_TIME_ADD(dst->counter, add->counter);
150 
151  dst->tuplecount += add->tuplecount;
152  dst->startup += add->startup;
153  dst->total += add->total;
154  dst->ntuples += add->ntuples;
155  dst->ntuples2 += add->ntuples2;
156  dst->nloops += add->nloops;
157  dst->nfiltered1 += add->nfiltered1;
158  dst->nfiltered2 += add->nfiltered2;
159 
160  /* Add delta of buffer usage since entry to node's totals */
161  if (dst->need_bufusage)
162  BufferUsageAdd(&dst->bufusage, &add->bufusage);
163 }
164 
165 /* note current values during parallel executor startup */
166 void
168 {
169  save_pgBufferUsage = pgBufferUsage;
170 }
171 
172 /* report usage after parallel executor shutdown */
173 void
175 {
176  memset(result, 0, sizeof(BufferUsage));
177  BufferUsageAccumDiff(result, &pgBufferUsage, &save_pgBufferUsage);
178 }
179 
180 /* accumulate work done by workers in leader's stats */
181 void
183 {
184  BufferUsageAdd(&pgBufferUsage, result);
185 }
186 
187 /* dst += add */
188 static void
190 {
191  dst->shared_blks_hit += add->shared_blks_hit;
192  dst->shared_blks_read += add->shared_blks_read;
195  dst->local_blks_hit += add->local_blks_hit;
196  dst->local_blks_read += add->local_blks_read;
199  dst->temp_blks_read += add->temp_blks_read;
203 }
204 
205 /* dst += add - sub */
206 static void
208  const BufferUsage *add,
209  const BufferUsage *sub)
210 {
211  dst->shared_blks_hit += add->shared_blks_hit - sub->shared_blks_hit;
215  dst->local_blks_hit += add->local_blks_hit - sub->local_blks_hit;
216  dst->local_blks_read += add->local_blks_read - sub->local_blks_read;
219  dst->temp_blks_read += add->temp_blks_read - sub->temp_blks_read;
222  add->blk_read_time, sub->blk_read_time);
224  add->blk_write_time, sub->blk_write_time);
225 }
double nfiltered1
Definition: instrument.h:62
void InstrStopNode(Instrumentation *instr, double nTuples)
Definition: instrument.c:76
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:139
struct timeval instr_time
Definition: instr_time.h:150
long shared_blks_read
Definition: instrument.h:22
double startup
Definition: instrument.h:57
void InstrEndParallelQuery(BufferUsage *result)
Definition: instrument.c:174
#define INSTR_TIME_ACCUM_DIFF(x, y, z)
Definition: instr_time.h:182
Instrumentation * InstrAlloc(int n, int instrument_options)
Definition: instrument.c:30
static BufferUsage save_pgBufferUsage
Definition: instrument.c:21
#define INSTR_TIME_SET_ZERO(t)
Definition: instr_time.h:154
#define INSTR_TIME_GET_DOUBLE(t)
Definition: instr_time.h:199
long temp_blks_written
Definition: instrument.h:30
#define INSTR_TIME_IS_ZERO(t)
Definition: instr_time.h:152
void InstrEndLoop(Instrumentation *instr)
Definition: instrument.c:110
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:63
void InstrStartNode(Instrumentation *instr)
Definition: instrument.c:63
#define INSTR_TIME_ADD(x, y)
Definition: instr_time.h:158
instr_time starttime
Definition: instrument.h:51
long shared_blks_dirtied
Definition: instrument.h:23
void InstrAccumParallelQuery(BufferUsage *result)
Definition: instrument.c:182
static void BufferUsageAccumDiff(BufferUsage *dst, const BufferUsage *add, const BufferUsage *sub)
Definition: instrument.c:207
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:167
void InstrInit(Instrumentation *instr, int instrument_options)
Definition: instrument.c:54
void * palloc0(Size size)
Definition: mcxt.c:980
BufferUsage bufusage
Definition: instrument.h:64
instr_time counter
Definition: instrument.h:52
#define INSTR_TIME_SET_CURRENT_LAZY(t)
Definition: instr_time.h:253
instr_time blk_write_time
Definition: instrument.h:32
double ntuples2
Definition: instrument.h:60
#define INSTR_TIME_SET_CURRENT(t)
Definition: instr_time.h:156
long shared_blks_hit
Definition: instrument.h:21
long local_blks_written
Definition: instrument.h:28
#define elog(elevel,...)
Definition: elog.h:226
int i
static void BufferUsageAdd(BufferUsage *dst, const BufferUsage *add)
Definition: instrument.c:189
BufferUsage pgBufferUsage
Definition: instrument.c:20