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