Hi Matthias,
thanks for your feedback.
I wasn't sure on the memory-contexts. I was actually also unsure on
whether the array
TupleTableSlot.tts_isnull
is also set up correctly by the previous call to slot_getallattrs(slot).
This would allow to get rid of even more code from this patch, which is
in the loop and determines whether a field is null or not. I switched to
using tts_isnull from TupleTableSlot now, seems to be ok and the docs
say it is save to use.
Also I reuse the MemoryContext throughout the livetime of the receiver.
Not sure if that makes a difference. One more thing I noticed. During
explain.c the DestReceiver's destroy callback was never invoked. I added
a line to do that, however I am unsure whether this is the right place
or a good idea in the first place. This potentially affects plain
analyze calls as well, though seems to behave nicely. Even when I
explain (analyze) select * into ....
This is the call I am talking about, which was missing from explain.c
dest->rDestroy(dest);
Attached a new patch. Hoping for feedback,
Greetings, Stepan
On 12.09.23 14:25, Matthias van de Meent wrote:
On Tue, 12 Sept 2023 at 12:56, stepan rutz<stepan.r...@gmx.de> wrote:
Hi,
I have fallen into this trap and others have too. If you run
EXPLAIN(ANALYZE) no de-toasting happens. This makes query-runtimes
differ a lot. The bigger point is that the average user expects more
from EXPLAIN(ANALYZE) than what it provides. This can be suprising. You
can force detoasting during explain with explicit calls to length(), but
that is tedious. Those of us who are forced to work using java stacks,
orms and still store mostly documents fall into this trap sooner or
later. I have already received some good feedback on this one, so this
is an issue that bother quite a few people out there.
Yes, the lack of being able to see the impact of detoasting (amongst
others) in EXPLAIN (ANALYZE) can hide performance issues.
It would be great to get some feedback on the subject and how to address
this, maybe in totally different ways.
Hmm, maybe we should measure the overhead of serializing the tuples instead.
The difference between your patch and "serializing the tuples, but not
sending them" is that serializing also does the detoasting, but also
includes any time spent in the serialization functions of the type. So
an option "SERIALIZE" which measures all the time the server spent on
the query (except the final step of sending the bytes to the client)
would likely be more useful than "just" detoasting.
0001_explain_analyze_and_detoast.patch
I notice that this patch creates and destroys a memory context for
every tuple that the DestReceiver receives. I think that's quite
wasteful, as you should be able to create only one memory context and
reset it before (or after) each processed tuple. That also reduces the
differences in measurements between EXPLAIN and normal query
processing of the tuples - after all, we don't create new memory
contexts for every tuple in the normal DestRemote receiver either,
right?
Kind regards,
Matthias van de Meent
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 8570b14f62..95a09dd4cb 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -47,7 +47,6 @@ ExplainOneQuery_hook_type ExplainOneQuery_hook = NULL;
/* Hook for plugins to get control in explain_get_index_name() */
explain_get_index_name_hook_type explain_get_index_name_hook = NULL;
-
/* OR-able flags for ExplainXMLTag() */
#define X_OPENING 0
#define X_CLOSING 1
@@ -155,6 +154,8 @@ static void ExplainYAMLLineStarting(ExplainState *es);
static void escape_yaml(StringInfo buf, const char *str);
+static DestReceiver *CreateDetoastDestReceiver(void);
+
/*
* ExplainQuery -
@@ -192,6 +193,8 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt,
es->settings = defGetBoolean(opt);
else if (strcmp(opt->defname, "generic_plan") == 0)
es->generic = defGetBoolean(opt);
+ else if (strcmp(opt->defname, "detoast") == 0)
+ es->detoast = defGetBoolean(opt);
else if (strcmp(opt->defname, "timing") == 0)
{
timing_set = true;
@@ -244,6 +247,12 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt,
(errcode(ERRCODE_INVALID_PARAMETER_VALUE),
errmsg("EXPLAIN option TIMING requires ANALYZE")));
+ /* check that detoast is used with EXPLAIN ANALYZE */
+ if (es->detoast && !es->analyze)
+ ereport(ERROR,
+ (errcode(ERRCODE_INVALID_PARAMETER_VALUE),
+ errmsg("EXPLAIN option DETOAST requires ANALYZE")));
+
/* check that GENERIC_PLAN is not used with EXPLAIN ANALYZE */
if (es->generic && es->analyze)
ereport(ERROR,
@@ -565,9 +574,13 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
/*
* Normally we discard the query's output, but if explaining CREATE TABLE
* AS, we'd better use the appropriate tuple receiver.
+ * Also if we choose to detoast during explain, we need to send the
+ * tuples to a receiver that performs the detoasting
*/
if (into)
dest = CreateIntoRelDestReceiver(into);
+ else if (es->analyze && es->detoast)
+ dest = CreateDetoastDestReceiver();
else
dest = None_Receiver;
@@ -606,6 +619,9 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
/* run cleanup too */
ExecutorFinish(queryDesc);
+ /* call the dest receiver's destroy method even during explain */
+ dest->rDestroy(dest);
+
/* We can't run ExecutorEnd 'till we're done printing the stats... */
totaltime += elapsed_time(&starttime);
}
@@ -5052,3 +5068,116 @@ escape_yaml(StringInfo buf, const char *str)
{
escape_json(buf, str);
}
+
+
+/* ----------------
+ * detoasting DestReceiver functions
+ * ----------------
+ */
+/* the idea is that running EXPLAIN (ANALYZE) sometimes gives results that
+ * are way unrealistic, since during explain there is no detoasting of
+ * values. That means you get no idea what your actual query time is going
+ * to be, nor what the actual overhead of detoasting is.
+ *
+ * if you run EXPLAIN (ANAYLZE, DETOAST) then you get an impression of
+ * what is actually happening when you use postgresql as a document-database
+ * or have large values for some other reason.
+ */
+
+typedef struct
+{
+ DestReceiver destRecevier; /* receiver for the tuples, that just detoasts */
+ MemoryContext memoryContext; /* used throughout the detoasting analysis run */
+ MemoryContext oldMemoryContext; /* restore to old when done */
+} DetoastDestReceiver;
+
+
+
+/* this method receives the tuples/records during explain (analyze, detoast)
+ * and detoasts them.
+ * this method is otherwise not called and its purpose is to detoast to
+ * make analyze optionally more realistic
+ */
+static bool
+detoastAnalyzeReceive(TupleTableSlot *slot, DestReceiver *self)
+{
+ DetoastDestReceiver *receiver = (DetoastDestReceiver*) self;
+ int i;
+ bool shouldFree = true;
+ TupleDesc tupdesc;
+ HeapTuple tuple;
+
+ receiver->oldMemoryContext = MemoryContextSwitchTo(receiver->memoryContext);
+ tupdesc = slot->tts_tupleDescriptor;
+ tuple = ExecFetchSlotHeapTuple(slot, true, &shouldFree);
+
+ /* fill all of the slot's attributes, we can now use slot->tts_values
+ * and its tts_isnull array which should be long enough even if added
+ * a null-column to the table */
+ slot_getallattrs(slot);
+
+ /* iterate over all attributes of the tuple and potentially detoast them */
+ for (i = 0; i < tupdesc->natts; i++)
+ {
+ Form_pg_attribute attr;
+ char storage;
+
+ attr = TupleDescAttr(tupdesc, i);
+ storage = attr->attstorage;
+ if (!slot->tts_isnull[i] && (storage == 'e' || storage == 'x' || storage == 'm')) {
+ Datum datum = slot->tts_values[i];
+ /* here simple detoast the attribute's value, making
+ * the explain (analyze) slower, but also more realistic
+ * the above storage makes sure, that datum is actually
+ * a struct varlena pointer */
+ pg_detoast_datum_packed((struct varlena *)datum);
+ }
+ }
+ if (shouldFree)
+ pfree(tuple);
+ MemoryContextSwitchTo(receiver->oldMemoryContext);
+ return true;
+}
+
+static void
+detoastAnalyzeStartup(DestReceiver *self, int operation, TupleDesc typeinfo)
+{
+ DetoastDestReceiver *receiver = (DetoastDestReceiver*) self;
+ /* memory context for our work */
+ receiver->memoryContext = AllocSetContextCreate(CurrentMemoryContext,
+ "DetoastTupleReceive", ALLOCSET_DEFAULT_SIZES);
+}
+
+static void
+detoastAnalyzeCleanup(DestReceiver *self)
+{
+ DetoastDestReceiver *receiver = (DetoastDestReceiver*) self;
+ MemoryContextDelete(receiver->memoryContext);
+}
+
+static void
+detoastAnalyzeDestroy(DestReceiver *self)
+{
+ pfree(self);
+}
+
+static DestReceiver *CreateDetoastDestReceiver(void)
+{
+ DetoastDestReceiver *self = (DetoastDestReceiver*) palloc0(sizeof(DetoastDestReceiver));
+
+ self->destRecevier.receiveSlot = detoastAnalyzeReceive;
+ self->destRecevier.rStartup = detoastAnalyzeStartup;
+ self->destRecevier.rShutdown = detoastAnalyzeCleanup;
+ self->destRecevier.rDestroy = detoastAnalyzeDestroy;
+ self->destRecevier.mydest = DestNone;
+ return (DestReceiver *) self;
+}
+
+
+/*
+static const DestReceiver detoastAnalyzeDR = {
+ detoastAnalyzeReceive, detoastAnalyzeStartup, detoastAnalyzeCleanup, detoastAnalyzeDestroy,
+ DestNone
+};
+
+*/
\ No newline at end of file
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index 3d3e632a0c..011dffb890 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -47,6 +47,8 @@ typedef struct ExplainState
bool summary; /* print total planning and execution timing */
bool settings; /* print modified settings */
bool generic; /* generate a generic plan */
+ bool detoast; /* detoast all toasted values, only applicable
+ when "analyze" is active. */
ExplainFormat format; /* output format */
/* state for output formatting --- not reset for each new plan tree */
int indent; /* current indentation level */
diff --git a/src/test/regress/expected/explain.out b/src/test/regress/expected/explain.out
index 1aca77491b..eef68d1eca 100644
--- a/src/test/regress/expected/explain.out
+++ b/src/test/regress/expected/explain.out
@@ -559,3 +559,23 @@ select explain_filter('explain (verbose) select * from int8_tbl i8');
Query Identifier: N
(3 rows)
+-- Test detoast is accepted as a parameter to explain
+-- seems hard to test the expected longer runtime of detoasting
+-- since one needs to setup enough data to make such a test stable
+-- also timing are filtered out by explain_filter anyway
+create table test_detoast(id bigserial, val text);
+select explain_filter('explain (analyze,detoast) select * from test_detoast');
+ explain_filter
+------------------------------------------------------------------------------------------------
+ Seq Scan on test_detoast (cost=N.N..N.N rows=N width=N) (actual time=N.N..N.N rows=N loops=N)
+ Planning Time: N.N ms
+ Execution Time: N.N ms
+(3 rows)
+
+drop table test_detoast;
+-- Test detoast is _not_ accepted as a parameter to explain unless analyze is specified
+create table test_detoast(id bigserial, val text);
+select explain_filter('explain (detoast) select * from test_detoast');
+ERROR: EXPLAIN option DETOAST requires ANALYZE
+CONTEXT: PL/pgSQL function explain_filter(text) line 5 at FOR over EXECUTE statement
+drop table test_detoast;
diff --git a/src/test/regress/sql/explain.sql b/src/test/regress/sql/explain.sql
index b6b7beab27..43047f9cce 100644
--- a/src/test/regress/sql/explain.sql
+++ b/src/test/regress/sql/explain.sql
@@ -154,3 +154,18 @@ select explain_filter('explain (verbose) select * from t1 where pg_temp.mysin(f1
-- Test compute_query_id
set compute_query_id = on;
select explain_filter('explain (verbose) select * from int8_tbl i8');
+
+-- Test detoast is accepted as a parameter to explain
+-- seems hard to test the expected longer runtime of detoasting
+-- since one needs to setup enough data to make such a test stable
+-- also timing are filtered out by explain_filter anyway
+create table test_detoast(id bigserial, val text);
+select explain_filter('explain (analyze,detoast) select * from test_detoast');
+drop table test_detoast;
+
+-- Test detoast is _not_ accepted as a parameter to explain unless analyze is specified
+create table test_detoast(id bigserial, val text);
+select explain_filter('explain (detoast) select * from test_detoast');
+drop table test_detoast;
+
+
