/* * ExecutorEnd hook: log results if needed */ static void explain_ExecutorEnd(QueryDesc *queryDesc) { if (queryDesc->totaltime && (nesting_level == 0) && collect) { double seconds; /* * Make sure stats accumulation is done. (Note: it's okay if several * levels of hook all do this.) */ InstrEndLoop(queryDesc->totaltime); /* Log plan if duration is exceeded. */ seconds = queryDesc->totaltime->total; buffer_add_query(seconds, queryDesc->sourceText); } if (prev_ExecutorEnd) prev_ExecutorEnd(queryDesc); else standard_ExecutorEnd(queryDesc); }
/* * ExecutorEnd hook: log results if needed */ static void explain_ExecutorEnd(QueryDesc *queryDesc) { if (queryDesc->totaltime && auto_explain_enabled()) { double msec; /* * Make sure stats accumulation is done. (Note: it's okay if several * levels of hook all do this.) */ InstrEndLoop(queryDesc->totaltime); /* Log plan if duration is exceeded. */ msec = queryDesc->totaltime->total * 1000.0; if (msec >= auto_explain_log_min_duration) { ExplainState es; ExplainInitState(&es); es.analyze = (queryDesc->instrument_options && auto_explain_log_analyze); es.verbose = auto_explain_log_verbose; es.buffers = (es.analyze && auto_explain_log_buffers); es.format = auto_explain_log_format; ExplainBeginOutput(&es); ExplainQueryText(&es, queryDesc); ExplainPrintPlan(&es, queryDesc); ExplainEndOutput(&es); /* Remove last line break */ if (es.str->len > 0 && es.str->data[es.str->len - 1] == '\n') es.str->data[--es.str->len] = '\0'; /* * Note: we rely on the existing logging of context or * debug_query_string to identify just which statement is being * reported. This isn't ideal but trying to do it here would * often result in duplication. */ ereport(LOG, (errmsg("duration: %.3f ms plan:\n%s", msec, es.str->data), errhidestmt(true))); pfree(es.str->data); } } if (prev_ExecutorEnd) prev_ExecutorEnd(queryDesc); else standard_ExecutorEnd(queryDesc); }
/* * ExecutorEnd hook: log results if needed */ static void explain_ExecutorEnd(QueryDesc *queryDesc) { if (queryDesc->totaltime && (nesting_level == 0) && query_histogram_enabled()) { float seconds; /* * Make sure stats accumulation is done. (Note: it's okay if several * levels of hook all do this.) */ InstrEndLoop(queryDesc->totaltime); /* Log plan if duration is exceeded. */ seconds = queryDesc->totaltime->total; /* is the histogram static or dynamic? */ if (! default_histogram_dynamic) { /* in case of static histogram, it's quite simple - check the number * of bins and a sample rate - then lock the segment, add the query * and unlock it again */ if ((default_histogram_bins > 0) && (rand() % 100 < default_histogram_sample_pct)) { LWLockAcquire(shared_histogram_info->lock, LW_EXCLUSIVE); query_hist_add_query(seconds); LWLockRelease(shared_histogram_info->lock); } } else { /* when the histogram is dynamic, we have to lock it first, as we * will access the sample_pct in the histogram */ LWLockAcquire(shared_histogram_info->lock, LW_SHARED); if ((shared_histogram_info->bins > 0) && (rand() % 100 < shared_histogram_info->sample_pct)) { LWLockRelease(shared_histogram_info->lock); LWLockAcquire(shared_histogram_info->lock, LW_EXCLUSIVE); query_hist_add_query(seconds); } LWLockRelease(shared_histogram_info->lock); } } if (prev_ExecutorEnd) prev_ExecutorEnd(queryDesc); else standard_ExecutorEnd(queryDesc); }
static void new_executor_end(QueryDesc *queryDesc) { double query_duration; int tuple_count; char buffer[BUF_SIZE]; //Assert(queryDesc != NULL); if (pg_query_statsd_enabled() && queryDesc->totaltime) { InstrEndLoop(queryDesc->totaltime); query_duration = queryDesc->totaltime->total * 1000; tuple_count = queryDesc->totaltime->ntuples; snprintf(buffer, BUF_SIZE, "query:%.3f|ms\ntuples:%d|c", query_duration, tuple_count); sendto(sockfd, buffer, strlen(buffer), 0, serverinfo->ai_addr, serverinfo->ai_addrlen); } prev_ExecutorEnd(queryDesc); }
/* * ExecutorEnd hook: store results if needed */ static void pgss_ExecutorEnd(QueryDesc *queryDesc) { if (queryDesc->totaltime && pgss_enabled()) { /* * Make sure stats accumulation is done. (Note: it's okay if several * levels of hook all do this.) */ InstrEndLoop(queryDesc->totaltime); pgss_store(queryDesc->sourceText, queryDesc->totaltime->total, queryDesc->estate->es_processed, &queryDesc->totaltime->bufusage); } if (prev_ExecutorEnd) prev_ExecutorEnd(queryDesc); else standard_ExecutorEnd(queryDesc); }
/* * ExecutorEnd hook: log results if needed */ static void explain_ExecutorEnd(QueryDesc *queryDesc) { if (queryDesc->totaltime && auto_explain_enabled() && current_query_sampled) { double msec; /* * Make sure stats accumulation is done. (Note: it's okay if several * levels of hook all do this.) */ InstrEndLoop(queryDesc->totaltime); /* Log plan if duration is exceeded. */ msec = queryDesc->totaltime->total * 1000.0; if (msec >= auto_explain_log_min_duration) { ExplainState *es = NewExplainState(); es->analyze = (queryDesc->instrument_options && auto_explain_log_analyze); es->verbose = auto_explain_log_verbose; es->buffers = (es->analyze && auto_explain_log_buffers); es->timing = (es->analyze && auto_explain_log_timing); es->summary = es->analyze; es->format = auto_explain_log_format; ExplainBeginOutput(es); ExplainQueryText(es, queryDesc); ExplainPrintPlan(es, queryDesc); if (es->analyze && auto_explain_log_triggers) ExplainPrintTriggers(es, queryDesc); if (es->costs) ExplainPrintJITSummary(es, queryDesc); ExplainEndOutput(es); /* Remove last line break */ if (es->str->len > 0 && es->str->data[es->str->len - 1] == '\n') es->str->data[--es->str->len] = '\0'; /* Fix JSON to output an object */ if (auto_explain_log_format == EXPLAIN_FORMAT_JSON) { es->str->data[0] = '{'; es->str->data[es->str->len - 1] = '}'; } /* * Note: we rely on the existing logging of context or * debug_query_string to identify just which statement is being * reported. This isn't ideal but trying to do it here would * often result in duplication. */ ereport(auto_explain_log_level, (errmsg("duration: %.3f ms plan:\n%s", msec, es->str->data), errhidestmt(true))); pfree(es->str->data); } } if (prev_ExecutorEnd) prev_ExecutorEnd(queryDesc); else standard_ExecutorEnd(queryDesc); }
static void grab_ExecutorEnd(QueryDesc * queryDesc) { Datum values[10]; bool nulls[10] = {false, false, false, false, false, false, false, false, false, false}; Relation dump_heap; RangeVar *dump_table_rv; HeapTuple tuple; Oid namespaceId; /* lookup schema */ namespaceId = GetSysCacheOid1(NAMESPACENAME, CStringGetDatum(EXTENSION_SCHEMA)); if (OidIsValid(namespaceId)) { /* lookup table */ if (OidIsValid(get_relname_relid(EXTENSION_LOG_TABLE, namespaceId))) { /* get table heap */ dump_table_rv = makeRangeVar(EXTENSION_SCHEMA, EXTENSION_LOG_TABLE, -1); dump_heap = heap_openrv(dump_table_rv, RowExclusiveLock); /* transaction info */ values[0] = Int32GetDatum(GetCurrentTransactionId()); values[1] = Int32GetDatum(GetCurrentCommandId(false)); values[2] = Int32GetDatum(MyProcPid); values[3] = Int32GetDatum(GetUserId()); /* query timing */ if (queryDesc->totaltime != NULL) { InstrEndLoop(queryDesc->totaltime); values[4] = TimestampGetDatum( TimestampTzPlusMilliseconds(GetCurrentTimestamp(), (queryDesc->totaltime->total * -1000.0))); values[5] = Float8GetDatum(queryDesc->totaltime->total); } else { nulls[4] = true; nulls[5] = true; } /* query command type */ values[6] = Int32GetDatum(queryDesc->operation); /* query text */ values[7] = CStringGetDatum( cstring_to_text(queryDesc->sourceText)); /* query params */ if (queryDesc->params != NULL) { int numParams = queryDesc->params->numParams; Oid out_func_oid, ptype; Datum pvalue; bool isvarlena; FmgrInfo *out_functions; bool arr_nulls[numParams]; size_t arr_nelems = (size_t) numParams; Datum *arr_val_elems = palloc(sizeof(Datum) * arr_nelems); Datum *arr_typ_elems = palloc(sizeof(Datum) * arr_nelems); char elem_val_byval, elem_val_align, elem_typ_byval, elem_typ_align; int16 elem_val_len, elem_typ_len; int elem_dims[1], elem_lbs[1]; int paramno; /* init */ out_functions = (FmgrInfo *) palloc( (numParams) * sizeof(FmgrInfo)); get_typlenbyvalalign(TEXTOID, &elem_val_len, &elem_val_byval, &elem_val_align); get_typlenbyvalalign(REGTYPEOID, &elem_typ_len, &elem_typ_byval, &elem_typ_align); elem_dims[0] = arr_nelems; elem_lbs[0] = 1; for (paramno = 0; paramno < numParams; paramno++) { pvalue = queryDesc->params->params[paramno].value; ptype = queryDesc->params->params[paramno].ptype; getTypeOutputInfo(ptype, &out_func_oid, &isvarlena); fmgr_info(out_func_oid, &out_functions[paramno]); arr_typ_elems[paramno] = ptype; arr_nulls[paramno] = true; if (!queryDesc->params->params[paramno].isnull) { arr_nulls[paramno] = false; arr_val_elems[paramno] = PointerGetDatum( cstring_to_text( OutputFunctionCall(&out_functions[paramno], pvalue))); } } values[8] = PointerGetDatum( construct_md_array( arr_val_elems, arr_nulls, 1, elem_dims, elem_lbs, TEXTOID, elem_val_len, elem_val_byval, elem_val_align)); values[9] = PointerGetDatum( construct_array( arr_typ_elems, arr_nelems, REGTYPEOID, elem_typ_len, elem_typ_byval, elem_typ_align)); pfree(out_functions); pfree(arr_val_elems); } else { nulls[8] = true; nulls[9] = true; } /* insert */ tuple = heap_form_tuple(dump_heap->rd_att, values, nulls); simple_heap_insert(dump_heap, tuple); heap_close(dump_heap, RowExclusiveLock); } } if (prev_ExecutorEnd) prev_ExecutorEnd(queryDesc); else standard_ExecutorEnd(queryDesc); }