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-2020, 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 
24 
25 static void BufferUsageAdd(BufferUsage *dst, const BufferUsage *add);
26 static void WalUsageAdd(WalUsage *dst, WalUsage *add);
27 
28 
29 /* Allocate new instrumentation structure(s) */
31 InstrAlloc(int n, int instrument_options)
32 {
33  Instrumentation *instr;
34 
35  /* initialize all fields to zeroes, then modify as needed */
36  instr = palloc0(n * sizeof(Instrumentation));
37  if (instrument_options & (INSTRUMENT_BUFFERS | INSTRUMENT_TIMER | INSTRUMENT_WAL))
38  {
39  bool need_buffers = (instrument_options & INSTRUMENT_BUFFERS) != 0;
40  bool need_wal = (instrument_options & INSTRUMENT_WAL) != 0;
41  bool need_timer = (instrument_options & INSTRUMENT_TIMER) != 0;
42  int i;
43 
44  for (i = 0; i < n; i++)
45  {
46  instr[i].need_bufusage = need_buffers;
47  instr[i].need_walusage = need_wal;
48  instr[i].need_timer = need_timer;
49  }
50  }
51 
52  return instr;
53 }
54 
55 /* Initialize a pre-allocated instrumentation structure. */
56 void
57 InstrInit(Instrumentation *instr, int instrument_options)
58 {
59  memset(instr, 0, sizeof(Instrumentation));
60  instr->need_bufusage = (instrument_options & INSTRUMENT_BUFFERS) != 0;
61  instr->need_walusage = (instrument_options & INSTRUMENT_WAL) != 0;
62  instr->need_timer = (instrument_options & INSTRUMENT_TIMER) != 0;
63 }
64 
65 /* Entry to a plan node */
66 void
68 {
69  if (instr->need_timer &&
71  elog(ERROR, "InstrStartNode called twice in a row");
72 
73  /* save buffer usage totals at node entry, if needed */
74  if (instr->need_bufusage)
76 
77  if (instr->need_walusage)
78  instr->walusage_start = pgWalUsage;
79 }
80 
81 /* Exit from a plan node */
82 void
83 InstrStopNode(Instrumentation *instr, double nTuples)
84 {
85  instr_time endtime;
86 
87  /* count the returned tuples */
88  instr->tuplecount += nTuples;
89 
90  /* let's update the time only if the timer was requested */
91  if (instr->need_timer)
92  {
93  if (INSTR_TIME_IS_ZERO(instr->starttime))
94  elog(ERROR, "InstrStopNode called without start");
95 
96  INSTR_TIME_SET_CURRENT(endtime);
97  INSTR_TIME_ACCUM_DIFF(instr->counter, endtime, instr->starttime);
98 
100  }
101 
102  /* Add delta of buffer usage since entry to node's totals */
103  if (instr->need_bufusage)
105  &pgBufferUsage, &instr->bufusage_start);
106 
107  if (instr->need_walusage)
108  WalUsageAccumDiff(&instr->walusage,
109  &pgWalUsage, &instr->walusage_start);
110 
111  /* Is this the first tuple of this cycle? */
112  if (!instr->running)
113  {
114  instr->running = true;
115  instr->firsttuple = INSTR_TIME_GET_DOUBLE(instr->counter);
116  }
117 }
118 
119 /* Finish a run cycle for a plan node */
120 void
122 {
123  double totaltime;
124 
125  /* Skip if nothing has happened, or already shut down */
126  if (!instr->running)
127  return;
128 
129  if (!INSTR_TIME_IS_ZERO(instr->starttime))
130  elog(ERROR, "InstrEndLoop called on running node");
131 
132  /* Accumulate per-cycle statistics into totals */
133  totaltime = INSTR_TIME_GET_DOUBLE(instr->counter);
134 
135  instr->startup += instr->firsttuple;
136  instr->total += totaltime;
137  instr->ntuples += instr->tuplecount;
138  instr->nloops += 1;
139 
140  /* Reset for next cycle (if any) */
141  instr->running = false;
144  instr->firsttuple = 0;
145  instr->tuplecount = 0;
146 }
147 
148 /* aggregate instrumentation information */
149 void
151 {
152  if (!dst->running && add->running)
153  {
154  dst->running = true;
155  dst->firsttuple = add->firsttuple;
156  }
157  else if (dst->running && add->running && dst->firsttuple > add->firsttuple)
158  dst->firsttuple = add->firsttuple;
159 
160  INSTR_TIME_ADD(dst->counter, add->counter);
161 
162  dst->tuplecount += add->tuplecount;
163  dst->startup += add->startup;
164  dst->total += add->total;
165  dst->ntuples += add->ntuples;
166  dst->ntuples2 += add->ntuples2;
167  dst->nloops += add->nloops;
168  dst->nfiltered1 += add->nfiltered1;
169  dst->nfiltered2 += add->nfiltered2;
170 
171  /* Add delta of buffer usage since entry to node's totals */
172  if (dst->need_bufusage)
173  BufferUsageAdd(&dst->bufusage, &add->bufusage);
174 
175  if (dst->need_walusage)
176  WalUsageAdd(&dst->walusage, &add->walusage);
177 }
178 
179 /* note current values during parallel executor startup */
180 void
182 {
183  save_pgBufferUsage = pgBufferUsage;
184  save_pgWalUsage = pgWalUsage;
185 }
186 
187 /* report usage after parallel executor shutdown */
188 void
190 {
191  memset(bufusage, 0, sizeof(BufferUsage));
192  BufferUsageAccumDiff(bufusage, &pgBufferUsage, &save_pgBufferUsage);
193  memset(walusage, 0, sizeof(WalUsage));
194  WalUsageAccumDiff(walusage, &pgWalUsage, &save_pgWalUsage);
195 }
196 
197 /* accumulate work done by workers in leader's stats */
198 void
200 {
201  BufferUsageAdd(&pgBufferUsage, bufusage);
202  WalUsageAdd(&pgWalUsage, walusage);
203 }
204 
205 /* dst += add */
206 static void
208 {
209  dst->shared_blks_hit += add->shared_blks_hit;
210  dst->shared_blks_read += add->shared_blks_read;
213  dst->local_blks_hit += add->local_blks_hit;
214  dst->local_blks_read += add->local_blks_read;
217  dst->temp_blks_read += add->temp_blks_read;
221 }
222 
223 /* dst += add - sub */
224 void
226  const BufferUsage *add,
227  const BufferUsage *sub)
228 {
229  dst->shared_blks_hit += add->shared_blks_hit - sub->shared_blks_hit;
233  dst->local_blks_hit += add->local_blks_hit - sub->local_blks_hit;
234  dst->local_blks_read += add->local_blks_read - sub->local_blks_read;
237  dst->temp_blks_read += add->temp_blks_read - sub->temp_blks_read;
240  add->blk_read_time, sub->blk_read_time);
242  add->blk_write_time, sub->blk_write_time);
243 }
244 
245 /* helper functions for WAL usage accumulation */
246 static void
248 {
249  dst->wal_bytes += add->wal_bytes;
250  dst->wal_records += add->wal_records;
251  dst->wal_fpi += add->wal_fpi;
252 }
253 
254 void
255 WalUsageAccumDiff(WalUsage *dst, const WalUsage *add, const WalUsage *sub)
256 {
257  dst->wal_bytes += add->wal_bytes - sub->wal_bytes;
258  dst->wal_records += add->wal_records - sub->wal_records;
259  dst->wal_fpi += add->wal_fpi - sub->wal_fpi;
260 }
double nfiltered1
Definition: instrument.h:72
void InstrStopNode(Instrumentation *instr, double nTuples)
Definition: instrument.c:83
bool need_bufusage
Definition: instrument.h:56
long local_blks_hit
Definition: instrument.h:25
long local_blks_dirtied
Definition: instrument.h:27
long local_blks_read
Definition: instrument.h:26
WalUsage walusage
Definition: instrument.h:75
instr_time blk_read_time
Definition: instrument.h:31
void InstrAggNode(Instrumentation *dst, Instrumentation *add)
Definition: instrument.c:150
WalUsage pgWalUsage
Definition: instrument.c:22
struct timeval instr_time
Definition: instr_time.h:150
long shared_blks_read
Definition: instrument.h:22
double startup
Definition: instrument.h:67
void WalUsageAccumDiff(WalUsage *dst, const WalUsage *add, const WalUsage *sub)
Definition: instrument.c:255
#define INSTR_TIME_ACCUM_DIFF(x, y, z)
Definition: instr_time.h:182
Instrumentation * InstrAlloc(int n, int instrument_options)
Definition: instrument.c:31
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
void InstrEndParallelQuery(BufferUsage *bufusage, WalUsage *walusage)
Definition: instrument.c:189
#define INSTR_TIME_IS_ZERO(t)
Definition: instr_time.h:152
void BufferUsageAccumDiff(BufferUsage *dst, const BufferUsage *add, const BufferUsage *sub)
Definition: instrument.c:225
void InstrEndLoop(Instrumentation *instr)
Definition: instrument.c:121
long shared_blks_written
Definition: instrument.h:24
BufferUsage bufusage_start
Definition: instrument.h:64
#define ERROR
Definition: elog.h:43
static void WalUsageAdd(WalUsage *dst, WalUsage *add)
Definition: instrument.c:247
double firsttuple
Definition: instrument.h:62
double nfiltered2
Definition: instrument.h:73
void InstrStartNode(Instrumentation *instr)
Definition: instrument.c:67
long wal_records
Definition: instrument.h:37
#define INSTR_TIME_ADD(x, y)
Definition: instr_time.h:158
instr_time starttime
Definition: instrument.h:60
long shared_blks_dirtied
Definition: instrument.h:23
double ntuples
Definition: instrument.h:69
long temp_blks_read
Definition: instrument.h:29
void InstrAccumParallelQuery(BufferUsage *bufusage, WalUsage *walusage)
Definition: instrument.c:199
WalUsage walusage_start
Definition: instrument.h:65
double tuplecount
Definition: instrument.h:63
void InstrStartParallelQuery(void)
Definition: instrument.c:181
void InstrInit(Instrumentation *instr, int instrument_options)
Definition: instrument.c:57
void * palloc0(Size size)
Definition: mcxt.c:981
BufferUsage bufusage
Definition: instrument.h:74
instr_time counter
Definition: instrument.h:61
#define INSTR_TIME_SET_CURRENT_LAZY(t)
Definition: instr_time.h:253
instr_time blk_write_time
Definition: instrument.h:32
long wal_fpi
Definition: instrument.h:38
double ntuples2
Definition: instrument.h:70
#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:214
int i
bool need_walusage
Definition: instrument.h:57
uint64 wal_bytes
Definition: instrument.h:39
static void BufferUsageAdd(BufferUsage *dst, const BufferUsage *add)
Definition: instrument.c:207
BufferUsage pgBufferUsage
Definition: instrument.c:20
static WalUsage save_pgWalUsage
Definition: instrument.c:23