Hi, this is the 7th patch to make instrumentation work.
Explain analyze shows the following result by the previous patch set .
| Aggregate (cost=820.25..820.26 rows=1 width=8) (actual
time=4324.676..4324.676
| rows=1 loops=1)
| -> Append (cost=0.00..791.00 rows=11701 width=4) (actual
time=0.910..3663.8
|82 rows=4000000 loops=1)
| -> Foreign Scan on ft10 (cost=100.00..197.75 rows=2925 width=4)
| (never executed)
| -> Foreign Scan on ft20 (cost=100.00..197.75 rows=2925 width=4)
| (never executed)
| -> Foreign Scan on ft30 (cost=100.00..197.75 rows=2925 width=4)
| (never executed)
| -> Foreign Scan on ft40 (cost=100.00..197.75 rows=2925 width=4)
| (never executed)
| -> Seq Scan on pf0 (cost=0.00..0.00 rows=1 width=4)
| (actual time=0.004..0.004 rows=0 loops=1)
The current instrument stuff assumes that requested tuple always
returns a tuple or the end of tuple comes. This async framework
has two point of executing underneath nodes. ExecAsyncRequest and
ExecAsyncEventLoop. So I'm not sure if this is appropriate but
anyway it seems to show sane numbers.
| Aggregate (cost=820.25..820.26 rows=1 width=8) (actual
time=4571.205..4571.206
| rows=1 loops=1)
| -> Append (cost=0.00..791.00 rows=11701 width=4) (actual
time=1.362..3893.1
|14 rows=4000000 loops=1)
| -> Foreign Scan on ft10 (cost=100.00..197.75 rows=2925 width=4)
| (actual time=1.056..770.863 rows=1000000 loops=1)
| -> Foreign Scan on ft20 (cost=100.00..197.75 rows=2925 width=4)
| (actual time=0.461..767.840 rows=1000000 loops=1)
| -> Foreign Scan on ft30 (cost=100.00..197.75 rows=2925 width=4)
| (actual time=0.474..782.547 rows=1000000 loops=1)
| -> Foreign Scan on ft40 (cost=100.00..197.75 rows=2925 width=4)
| (actual time=0.156..765.920 rows=1000000 loops=1)
| -> Seq Scan on pf0 (cost=0.00..0.00 rows=1 width=4) (never executed)
regards,
--
Kyotaro Horiguchi
NTT Open Source Software Center
>From 35c60a46f49aab72d492c798ff7eb8fc0e672250 Mon Sep 17 00:00:00 2001
From: Kyotaro Horiguchi <horiguchi.kyot...@lab.ntt.co.jp>
Date: Tue, 25 Oct 2016 19:04:04 +0900
Subject: [PATCH 7/7] Add instrumentation to async execution
Make explain analyze give sane result when async execution has taken
place.
---
src/backend/executor/execAsync.c | 19 +++++++++++++++++++
src/backend/executor/instrument.c | 2 +-
2 files changed, 20 insertions(+), 1 deletion(-)
diff --git a/src/backend/executor/execAsync.c b/src/backend/executor/execAsync.c
index 40e3f67..588ba18 100644
--- a/src/backend/executor/execAsync.c
+++ b/src/backend/executor/execAsync.c
@@ -46,6 +46,9 @@ ExecAsyncRequest(EState *estate, PlanState *requestor, int request_index,
PendingAsyncRequest *areq = NULL;
int nasync = estate->es_num_pending_async;
+ if (requestee->instrument)
+ InstrStartNode(requestee->instrument);
+
/*
* If the number of pending asynchronous nodes exceeds the number of
* available slots in the es_pending_async array, expand the array.
@@ -121,11 +124,17 @@ ExecAsyncRequest(EState *estate, PlanState *requestor, int request_index,
if (areq->state == ASYNC_COMPLETE)
{
Assert(areq->result == NULL || IsA(areq->result, TupleTableSlot));
+
ExecAsyncResponse(estate, areq);
+ if (areq->requestee->instrument)
+ InstrStopNode(requestee->instrument,
+ TupIsNull((TupleTableSlot*)areq->result) ? 0.0 : 1.0);
return;
}
+ if (areq->requestee->instrument)
+ InstrStopNode(requestee->instrument, 0);
/* No result available now, make this node pending */
estate->es_num_pending_async++;
}
@@ -193,6 +202,9 @@ ExecAsyncEventLoop(EState *estate, PlanState *requestor, long timeout)
{
PendingAsyncRequest *areq = estate->es_pending_async[i];
+ if (areq->requestee->instrument)
+ InstrStartNode(areq->requestee->instrument);
+
/* Skip it if not pending. */
if (areq->state == ASYNC_CALLBACK_PENDING)
{
@@ -211,7 +223,14 @@ ExecAsyncEventLoop(EState *estate, PlanState *requestor, long timeout)
if (requestor == areq->requestor)
requestor_done = true;
ExecAsyncResponse(estate, areq);
+
+ if (areq->requestee->instrument)
+ InstrStopNode(areq->requestee->instrument,
+ TupIsNull((TupleTableSlot*)areq->result) ?
+ 0.0 : 1.0);
}
+ else if (areq->requestee->instrument)
+ InstrStopNode(areq->requestee->instrument, 0);
}
/* If any node completed, compact the array. */
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index 2614bf4..6a22a15 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -102,7 +102,7 @@ InstrStopNode(Instrumentation *instr, double nTuples)
&pgBufferUsage, &instr->bufusage_start);
/* Is this the first tuple of this cycle? */
- if (!instr->running)
+ if (!instr->running && nTuples > 0)
{
instr->running = true;
instr->firsttuple = INSTR_TIME_GET_DOUBLE(instr->counter);
--
2.9.2
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
