1 /*-------------------------------------------------------------------------
2 *
3 * instrument.c
4 * functions for instrumentation of plan execution
5 *
6 *
7 * Copyright (c) 2001-2018, 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
20 BufferUsage pgBufferUsage;
21 static BufferUsage save_pgBufferUsage;
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) */
29 Instrumentation *
InstrAlloc(int n,int instrument_options)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
InstrInit(Instrumentation * instr,int instrument_options)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
InstrStartNode(Instrumentation * instr)63 InstrStartNode(Instrumentation *instr)
64 {
65 if (instr->need_timer)
66 {
67 if (INSTR_TIME_IS_ZERO(instr->starttime))
68 INSTR_TIME_SET_CURRENT(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)
75 instr->bufusage_start = pgBufferUsage;
76 }
77
78 /* Exit from a plan node */
79 void
InstrStopNode(Instrumentation * instr,double nTuples)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
96 INSTR_TIME_SET_ZERO(instr->starttime);
97 }
98
99 /* Add delta of buffer usage since entry to node's totals */
100 if (instr->need_bufusage)
101 BufferUsageAccumDiff(&instr->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
InstrEndLoop(Instrumentation * instr)114 InstrEndLoop(Instrumentation *instr)
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;
135 INSTR_TIME_SET_ZERO(instr->starttime);
136 INSTR_TIME_SET_ZERO(instr->counter);
137 instr->firsttuple = 0;
138 instr->tuplecount = 0;
139 }
140
141 /* aggregate instrumentation information */
142 void
InstrAggNode(Instrumentation * dst,Instrumentation * add)143 InstrAggNode(Instrumentation *dst, Instrumentation *add)
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->ntuples2 += add->ntuples2;
160 dst->nloops += add->nloops;
161 dst->nfiltered1 += add->nfiltered1;
162 dst->nfiltered2 += add->nfiltered2;
163
164 /* Add delta of buffer usage since entry to node's totals */
165 if (dst->need_bufusage)
166 BufferUsageAdd(&dst->bufusage, &add->bufusage);
167 }
168
169 /* note current values during parallel executor startup */
170 void
InstrStartParallelQuery(void)171 InstrStartParallelQuery(void)
172 {
173 save_pgBufferUsage = pgBufferUsage;
174 }
175
176 /* report usage after parallel executor shutdown */
177 void
InstrEndParallelQuery(BufferUsage * result)178 InstrEndParallelQuery(BufferUsage *result)
179 {
180 memset(result, 0, sizeof(BufferUsage));
181 BufferUsageAccumDiff(result, &pgBufferUsage, &save_pgBufferUsage);
182 }
183
184 /* accumulate work done by workers in leader's stats */
185 void
InstrAccumParallelQuery(BufferUsage * result)186 InstrAccumParallelQuery(BufferUsage *result)
187 {
188 BufferUsageAdd(&pgBufferUsage, result);
189 }
190
191 /* dst += add */
192 static void
BufferUsageAdd(BufferUsage * dst,const BufferUsage * add)193 BufferUsageAdd(BufferUsage *dst, const BufferUsage *add)
194 {
195 dst->shared_blks_hit += add->shared_blks_hit;
196 dst->shared_blks_read += add->shared_blks_read;
197 dst->shared_blks_dirtied += add->shared_blks_dirtied;
198 dst->shared_blks_written += add->shared_blks_written;
199 dst->local_blks_hit += add->local_blks_hit;
200 dst->local_blks_read += add->local_blks_read;
201 dst->local_blks_dirtied += add->local_blks_dirtied;
202 dst->local_blks_written += add->local_blks_written;
203 dst->temp_blks_read += add->temp_blks_read;
204 dst->temp_blks_written += add->temp_blks_written;
205 INSTR_TIME_ADD(dst->blk_read_time, add->blk_read_time);
206 INSTR_TIME_ADD(dst->blk_write_time, add->blk_write_time);
207 }
208
209 /* dst += add - sub */
210 static void
BufferUsageAccumDiff(BufferUsage * dst,const BufferUsage * add,const BufferUsage * sub)211 BufferUsageAccumDiff(BufferUsage *dst,
212 const BufferUsage *add,
213 const BufferUsage *sub)
214 {
215 dst->shared_blks_hit += add->shared_blks_hit - sub->shared_blks_hit;
216 dst->shared_blks_read += add->shared_blks_read - sub->shared_blks_read;
217 dst->shared_blks_dirtied += add->shared_blks_dirtied - sub->shared_blks_dirtied;
218 dst->shared_blks_written += add->shared_blks_written - sub->shared_blks_written;
219 dst->local_blks_hit += add->local_blks_hit - sub->local_blks_hit;
220 dst->local_blks_read += add->local_blks_read - sub->local_blks_read;
221 dst->local_blks_dirtied += add->local_blks_dirtied - sub->local_blks_dirtied;
222 dst->local_blks_written += add->local_blks_written - sub->local_blks_written;
223 dst->temp_blks_read += add->temp_blks_read - sub->temp_blks_read;
224 dst->temp_blks_written += add->temp_blks_written - sub->temp_blks_written;
225 INSTR_TIME_ACCUM_DIFF(dst->blk_read_time,
226 add->blk_read_time, sub->blk_read_time);
227 INSTR_TIME_ACCUM_DIFF(dst->blk_write_time,
228 add->blk_write_time, sub->blk_write_time);
229 }
230