LCOV - code coverage report
Current view: top level - src/backend/executor - instrument.c (source / functions) Hit Total Coverage
Test: PostgreSQL 13devel Lines: 100 107 93.5 %
Date: 2019-11-22 07:06:56 Functions: 11 11 100.0 %
Legend: Lines: hit not hit

          Line data    Source code
       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             : 
      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 *
      30        4180 : InstrAlloc(int n, int instrument_options)
      31             : {
      32             :     Instrumentation *instr;
      33             : 
      34             :     /* initialize all fields to zeroes, then modify as needed */
      35        4180 :     instr = palloc0(n * sizeof(Instrumentation));
      36        4180 :     if (instrument_options & (INSTRUMENT_BUFFERS | INSTRUMENT_TIMER))
      37             :     {
      38        1756 :         bool        need_buffers = (instrument_options & INSTRUMENT_BUFFERS) != 0;
      39        1756 :         bool        need_timer = (instrument_options & INSTRUMENT_TIMER) != 0;
      40             :         int         i;
      41             : 
      42        3512 :         for (i = 0; i < n; i++)
      43             :         {
      44        1756 :             instr[i].need_bufusage = need_buffers;
      45        1756 :             instr[i].need_timer = need_timer;
      46             :         }
      47             :     }
      48             : 
      49        4180 :     return instr;
      50             : }
      51             : 
      52             : /* Initialize a pre-allocated instrumentation structure. */
      53             : void
      54        1004 : InstrInit(Instrumentation *instr, int instrument_options)
      55             : {
      56        1004 :     memset(instr, 0, sizeof(Instrumentation));
      57        1004 :     instr->need_bufusage = (instrument_options & INSTRUMENT_BUFFERS) != 0;
      58        1004 :     instr->need_timer = (instrument_options & INSTRUMENT_TIMER) != 0;
      59        1004 : }
      60             : 
      61             : /* Entry to a plan node */
      62             : void
      63     8066520 : InstrStartNode(Instrumentation *instr)
      64             : {
      65    20708272 :     if (instr->need_timer &&
      66    12641752 :         !INSTR_TIME_SET_CURRENT_LAZY(instr->starttime))
      67           0 :         elog(ERROR, "InstrStartNode called twice in a row");
      68             : 
      69             :     /* save buffer usage totals at node entry, if needed */
      70     8066520 :     if (instr->need_bufusage)
      71         336 :         instr->bufusage_start = pgBufferUsage;
      72     8066520 : }
      73             : 
      74             : /* Exit from a plan node */
      75             : void
      76     8066512 : InstrStopNode(Instrumentation *instr, double nTuples)
      77             : {
      78             :     instr_time  endtime;
      79             : 
      80             :     /* count the returned tuples */
      81     8066512 :     instr->tuplecount += nTuples;
      82             : 
      83             :     /* let's update the time only if the timer was requested */
      84     8066512 :     if (instr->need_timer)
      85             :     {
      86     6320876 :         if (INSTR_TIME_IS_ZERO(instr->starttime))
      87           0 :             elog(ERROR, "InstrStopNode called without start");
      88             : 
      89     6320876 :         INSTR_TIME_SET_CURRENT(endtime);
      90     6320876 :         INSTR_TIME_ACCUM_DIFF(instr->counter, endtime, instr->starttime);
      91             : 
      92     6320876 :         INSTR_TIME_SET_ZERO(instr->starttime);
      93             :     }
      94             : 
      95             :     /* Add delta of buffer usage since entry to node's totals */
      96     8066512 :     if (instr->need_bufusage)
      97         336 :         BufferUsageAccumDiff(&instr->bufusage,
      98         336 :                              &pgBufferUsage, &instr->bufusage_start);
      99             : 
     100             :     /* Is this the first tuple of this cycle? */
     101     8066512 :     if (!instr->running)
     102             :     {
     103        5528 :         instr->running = true;
     104        5528 :         instr->firsttuple = INSTR_TIME_GET_DOUBLE(instr->counter);
     105             :     }
     106     8066512 : }
     107             : 
     108             : /* Finish a run cycle for a plan node */
     109             : void
     110        6676 : InstrEndLoop(Instrumentation *instr)
     111             : {
     112             :     double      totaltime;
     113             : 
     114             :     /* Skip if nothing has happened, or already shut down */
     115        6676 :     if (!instr->running)
     116        1148 :         return;
     117             : 
     118        5528 :     if (!INSTR_TIME_IS_ZERO(instr->starttime))
     119           0 :         elog(ERROR, "InstrEndLoop called on running node");
     120             : 
     121             :     /* Accumulate per-cycle statistics into totals */
     122        5528 :     totaltime = INSTR_TIME_GET_DOUBLE(instr->counter);
     123             : 
     124        5528 :     instr->startup += instr->firsttuple;
     125        5528 :     instr->total += totaltime;
     126        5528 :     instr->ntuples += instr->tuplecount;
     127        5528 :     instr->nloops += 1;
     128             : 
     129             :     /* Reset for next cycle (if any) */
     130        5528 :     instr->running = false;
     131        5528 :     INSTR_TIME_SET_ZERO(instr->starttime);
     132        5528 :     INSTR_TIME_SET_ZERO(instr->counter);
     133        5528 :     instr->firsttuple = 0;
     134        5528 :     instr->tuplecount = 0;
     135             : }
     136             : 
     137             : /* aggregate instrumentation information */
     138             : void
     139        2472 : InstrAggNode(Instrumentation *dst, Instrumentation *add)
     140             : {
     141        2472 :     if (!dst->running && add->running)
     142             :     {
     143           0 :         dst->running = true;
     144           0 :         dst->firsttuple = add->firsttuple;
     145             :     }
     146        2472 :     else if (dst->running && add->running && dst->firsttuple > add->firsttuple)
     147           0 :         dst->firsttuple = add->firsttuple;
     148             : 
     149        2472 :     INSTR_TIME_ADD(dst->counter, add->counter);
     150             : 
     151        2472 :     dst->tuplecount += add->tuplecount;
     152        2472 :     dst->startup += add->startup;
     153        2472 :     dst->total += add->total;
     154        2472 :     dst->ntuples += add->ntuples;
     155        2472 :     dst->ntuples2 += add->ntuples2;
     156        2472 :     dst->nloops += add->nloops;
     157        2472 :     dst->nfiltered1 += add->nfiltered1;
     158        2472 :     dst->nfiltered2 += add->nfiltered2;
     159             : 
     160             :     /* Add delta of buffer usage since entry to node's totals */
     161        2472 :     if (dst->need_bufusage)
     162           0 :         BufferUsageAdd(&dst->bufusage, &add->bufusage);
     163        2472 : }
     164             : 
     165             : /* note current values during parallel executor startup */
     166             : void
     167        1436 : InstrStartParallelQuery(void)
     168             : {
     169        1436 :     save_pgBufferUsage = pgBufferUsage;
     170        1436 : }
     171             : 
     172             : /* report usage after parallel executor shutdown */
     173             : void
     174        1432 : InstrEndParallelQuery(BufferUsage *result)
     175             : {
     176        1432 :     memset(result, 0, sizeof(BufferUsage));
     177        1432 :     BufferUsageAccumDiff(result, &pgBufferUsage, &save_pgBufferUsage);
     178        1432 : }
     179             : 
     180             : /* accumulate work done by workers in leader's stats */
     181             : void
     182        1432 : InstrAccumParallelQuery(BufferUsage *result)
     183             : {
     184        1432 :     BufferUsageAdd(&pgBufferUsage, result);
     185        1432 : }
     186             : 
     187             : /* dst += add */
     188             : static void
     189        1432 : BufferUsageAdd(BufferUsage *dst, const BufferUsage *add)
     190             : {
     191        1432 :     dst->shared_blks_hit += add->shared_blks_hit;
     192        1432 :     dst->shared_blks_read += add->shared_blks_read;
     193        1432 :     dst->shared_blks_dirtied += add->shared_blks_dirtied;
     194        1432 :     dst->shared_blks_written += add->shared_blks_written;
     195        1432 :     dst->local_blks_hit += add->local_blks_hit;
     196        1432 :     dst->local_blks_read += add->local_blks_read;
     197        1432 :     dst->local_blks_dirtied += add->local_blks_dirtied;
     198        1432 :     dst->local_blks_written += add->local_blks_written;
     199        1432 :     dst->temp_blks_read += add->temp_blks_read;
     200        1432 :     dst->temp_blks_written += add->temp_blks_written;
     201        1432 :     INSTR_TIME_ADD(dst->blk_read_time, add->blk_read_time);
     202        1432 :     INSTR_TIME_ADD(dst->blk_write_time, add->blk_write_time);
     203        1432 : }
     204             : 
     205             : /* dst += add - sub */
     206             : static void
     207        1768 : BufferUsageAccumDiff(BufferUsage *dst,
     208             :                      const BufferUsage *add,
     209             :                      const BufferUsage *sub)
     210             : {
     211        1768 :     dst->shared_blks_hit += add->shared_blks_hit - sub->shared_blks_hit;
     212        1768 :     dst->shared_blks_read += add->shared_blks_read - sub->shared_blks_read;
     213        1768 :     dst->shared_blks_dirtied += add->shared_blks_dirtied - sub->shared_blks_dirtied;
     214        1768 :     dst->shared_blks_written += add->shared_blks_written - sub->shared_blks_written;
     215        1768 :     dst->local_blks_hit += add->local_blks_hit - sub->local_blks_hit;
     216        1768 :     dst->local_blks_read += add->local_blks_read - sub->local_blks_read;
     217        1768 :     dst->local_blks_dirtied += add->local_blks_dirtied - sub->local_blks_dirtied;
     218        1768 :     dst->local_blks_written += add->local_blks_written - sub->local_blks_written;
     219        1768 :     dst->temp_blks_read += add->temp_blks_read - sub->temp_blks_read;
     220        1768 :     dst->temp_blks_written += add->temp_blks_written - sub->temp_blks_written;
     221        1768 :     INSTR_TIME_ACCUM_DIFF(dst->blk_read_time,
     222             :                           add->blk_read_time, sub->blk_read_time);
     223        1768 :     INSTR_TIME_ACCUM_DIFF(dst->blk_write_time,
     224             :                           add->blk_write_time, sub->blk_write_time);
     225        1768 : }

Generated by: LCOV version 1.13