Re: Detoasting optionally to make Explain-Analyze less misleading
First of all thanks for bringing this Feature to PostgreSQL. From a regular-user perspective (not everyone is a Pro) it is very misleading that ANALYZE doesn't do what it suggests it does. To run the query into some kind of /dev/null type of destination is feasible and that is what people end up doing after they have fallen into the "de-toasting" trap. Having SERIALIZE is a great improvement for certain. When I said that SERIALIZE should be the default, then this came mostly out of very surprising subjective experiences in the past. Turning it on certainly alters some existing benchmarks and timings. That is destructive in a way and would destroy some existing work and measures. I lack the overall understanding of the consequences, so please don't follow this (emotional) advice. So thanks again! and this will really help a lot of people. The people actually bothering with EXPLAIN options are likely to explore the documentation and now have a hint about this pitfall. The EXPLAIN part of PostgreSQL "feels" a lot better now. I appreciate all of your work on this issue, which came up without being on some kind of plan and of course for the overall work on PostgreSQL. /Stepan On 4/10/24 15:57, Tom Lane wrote: Matthias van de Meent writes: Upthread at [0], Stepan mentioned that we should default to SERIALIZE when ANALYZE is enabled. I suspect a patch in that direction would primarily contain updates in the test plan outputs, but I've not yet worked on that. Does anyone else have a strong opinion for or against adding SERIALIZE to the default set of explain features enabled with ANALYZE? I am 100% dead set against that, because it would silently render EXPLAIN outputs from different versions quite non-comparable. regards, tom lane
Re: Detoasting optionally to make Explain-Analyze less misleading
Hi Matthias, thanks for picking it up. I still believe this is valuable to a lot of people out there. Thanks for dealing with my proposal. Matthias, Tom, Tomas everyone. Two (more or less) controversial remarks from side. 1. Actually serialization should be the default for "analyze" in explain, as current analyze doesn't detoast and thus distorts the result in extreme (but common) cases easily by many order of magnitude (see my original video on that one). So current "explain analyze" only works for some queries and since detoasting is really transparent, it is quite something to leave detoasting out of explain analyze. This surprises people all the time, since explain analyze suggests it "runs" the query more realistically. 2. The bandwidth I computed in one of the previous versions of the patch was certainly cluttering up the explain output and it is misleading yes, but then again it performs a calculation people will now do in their head. The "bandwidth" here is how much data your query gets out of backend by means of the query and the deserialization. So of course if you do id-lookups you get a single row and such querries do have a lower data-retrieval bandwidth compared to bulk querries. However having some measure of how fast data is delivered from the backend especially on larger joins is still a good indicator of one aspect of a query. Sorry for the remarks. Both are not really important, just restating my points here. I understand the objections and reasons that speak against both points and believe the current scope is just right. /Stepan On 26.02.24 20:30, Matthias van de Meent wrote: Hi, I've taken the liberty to update this patch, and register it in the commitfest app to not lose track of progress [0]. The attached v8 patch measures scratch memory allocations (with MEMORY option), total time spent in serialization (with TIMING on, measures are inclusive of unseparated memcpy to the message buffer), and a count of produced bytes plus the output format used (text or binary). It's a light rework of the earlier 0007 patch, I've reused tests and some infrastructure, while the implementation details and comments have been updated significantly. I think we can bikeshed on format and names, but overall I think the patch is in a very decent shape. Stepan, thank you for your earlier work, and feel free to check it out or pick it up again if you want to; else I'll try to get this done. Kind regards, Matthias van de Meent [0] https://commitfest.postgresql.org/47/4852/
Re: Detoasting optionally to make Explain-Analyze less misleading
Hi Thomas, indeed by doing less the code also becomes trivial and ExplainPropertyInteger can be used as a oneliner. My intention was to actually get the realistic payload-bytes from the wire-protocol counted by the serialization option. I am also adding the protocol bits and the length of the data that is generated by serialization output-functions. So it should (hopefully) be the real numbers. Attached is a new revision of the patch that prints kB (floor'ed by integer-division by 1024). Maybe that is also misleading and bytes would be nicer (though harder to read). The output is now as follows: db1=# explain (analyze, serialize) select * from test; QUERY PLAN --- Seq Scan on test (cost=0.00..22.00 rows=1200 width=40) (actual time=0.014..0.017 rows=1 loops=1) Planning Time: 0.245 ms Execution Time: 292.983 ms Serialized Bytes: 77039 kB (4 rows) Definately a lot nicer and controlled by ExplainPropertyInteger in terms of formatting. The main motivation was to actually get a correct feeling for the execution time. Actually counting the bytes gives an impression of what would go over the wire. Only the big numbers matter here of course. Regards, Stepan On 02.11.23 20:32, Tomas Vondra wrote: On 11/2/23 20:09, stepan rutz wrote: Hi Thomas, you are right of course. Thanks! I have attached a new version of the patch that supports the syntax like suggested. The previous patch was insonsistent in style indeed. explain (analyze, serialize) and explain (analyze, serialize binary) That doesn't make too much of a difference for most scenarios I am certain. However the the seralize option itself does. Mostly because it performs the detoasting and that was a trap for me in the past with just plain analyze. Eg this scenario really is not too far fetched in a world where people have large JSONB values. db1=# create table test(id bigint, val text); db1=# insert into test(val) select string_agg(s::text, ',') from (select generate_series(1, 10_000_000) as s) as a1; now we have a cell that has roughly 80Mb in it. A large detoasting that will happen in reallife but in explain(analyze). and then... db1=# explain (analyze) select * from test; QUERY PLAN --- Seq Scan on test (cost=0.00..22.00 rows=1200 width=40) (actual time=0.018..0.020 rows=1 loops=1) Planning Time: 0.085 ms Execution Time: 0.044 ms (3 rows) db1=# explain (analyze, serialize) select * from test; QUERY PLAN --- Seq Scan on test (cost=0.00..22.00 rows=1200 width=40) (actual time=0.023..0.027 rows=1 loops=1) Planning Time: 0.077 ms Execution Time: 303.281 ms Serialized Bytes: 7953 Bytes. Mode Text. Bandwidth 248.068 MB/sec (4 rows) db1=# So the explain(analyze) does not process the ~80 MB in 0.044ms in any way of course. Honestly, I see absolutely no point in printing this. I have little idea what to do with the "bytes". We have to transfer this over network, but surely there's other data not included in this sum, right? But the bandwidth seems pretty bogus/useless, as it's calculated from execution time, which includes everything else, not just serialization. So what does it say? It certainly does not include the network transfer. IMO we should either print nothing or just the bytes. I don't see the point in printing the mode, which is determined by the command. Actually I could print the serialized bytes using 1. grouping-separators (eg 78_888_953) or 2. in the way pg_size_pretty does it. If doing it the pg_size_pretty way I am uncertain if it would be ok to query the actual pg_size_pretty function via its (certainly frozen) oid of 3166 and do OidFunctionCall1(3166...) to invoke it. Otherwise I'd say it would be nice if the code from that function would be made available as a utility function for all c-code. Any suggestions on this topic? I'm rather skeptical about this proposal, mostly because it makes it harder to process the explain output in scripts etc. But more importantly, it's a completely separate matter from what this patch does, so if you want to pursue this, I suggest you start a separate thread. If you want to introduce separators, surely this is not the only place that should do it (e.g. why not to do that for "rows" or "cost" estimates)? BTW if you really want to print amount of memory, maybe print it in kilobytes, like every other place in explain.c? Also, explain generally prints stuff in "key: value" style (in text format). regards diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index f1d71bc
Re: Detoasting optionally to make Explain-Analyze less misleading
Hi Thomas,
you are right of course. Thanks!
I have attached a new version of the patch that supports the syntax like
suggested. The previous patch was insonsistent in style indeed.
explain (analyze, serialize)
and
explain (analyze, serialize binary)
That doesn't make too much of a difference for most scenarios I am
certain. However the the seralize option itself does. Mostly because it
performs the detoasting and that was a trap for me in the past with just
plain analyze.
Eg this scenario really is not too far fetched in a world where people
have large JSONB values.
db1=# create table test(id bigint, val text);
db1=# insert into test(val) select string_agg(s::text, ',') from (select
generate_series(1, 10_000_000) as s) as a1;
now we have a cell that has roughly 80Mb in it. A large detoasting that
will happen in reallife but in explain(analyze).
and then...
db1=# explain (analyze) select * from test;
QUERY PLAN
---
Seq Scan on test (cost=0.00..22.00 rows=1200 width=40) (actual
time=0.018..0.020 rows=1 loops=1)
Planning Time: 0.085 ms
Execution Time: 0.044 ms
(3 rows)
db1=# explain (analyze, serialize) select * from test;
QUERY PLAN
---
Seq Scan on test (cost=0.00..22.00 rows=1200 width=40) (actual
time=0.023..0.027 rows=1 loops=1)
Planning Time: 0.077 ms
Execution Time: 303.281 ms
Serialized Bytes: 7953 Bytes. Mode Text. Bandwidth 248.068 MB/sec
(4 rows)
db1=#
So the explain(analyze) does not process the ~80 MB in 0.044ms in any
way of course.
Actually I could print the serialized bytes using 1. grouping-separators
(eg 78_888_953) or 2. in the way pg_size_pretty does it.
If doing it the pg_size_pretty way I am uncertain if it would be ok to
query the actual pg_size_pretty function via its (certainly frozen) oid
of 3166 and do OidFunctionCall1(3166...) to invoke it. Otherwise I'd say
it would be nice if the code from that function would be made available
as a utility function for all c-code. Any suggestions on this topic?
Regards,
/Stepan
On 02.11.23 18:49, Tomas Vondra wrote:
Hi,
On 9/15/23 22:09, stepan rutz wrote:
Hi,
please see a revised version yesterday's mail. The patch attached now
provides the following:
EXPLAIN(ANALYZE,SERIALIZE)
and
EXPLAIN(ANALYZE,SERIALIZEBINARY)
I haven't looked at the patch in detail yet, but this option name looks
a bit strange/inconsistent. Either it should be SERIALIZE_BINARY (to
match other multi-word options), or maybe there should be just SERIALIZE
with a parameter to determine text/binary (like FORMAT, for example).
So we'd do either
EXPLAIN (SERIALIZE)
EXPLAIN (SERIALIZE TEXT)
to get serialization to text (which I guess 99% of people will do), or
EXPLAIN (SERIALIZE BINARY)
to get binary.
regards
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index f1d71bc54e..bb75ac0b73 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -26,6 +26,7 @@
#include "nodes/nodeFuncs.h"
#include "parser/analyze.h"
#include "parser/parsetree.h"
+#include "mb/pg_wchar.h"
#include "rewrite/rewriteHandler.h"
#include "storage/bufmgr.h"
#include "tcop/tcopprot.h"
@@ -33,6 +34,7 @@
#include "utils/guc_tables.h"
#include "utils/json.h"
#include "utils/lsyscache.h"
+#include "utils/numeric.h"
#include "utils/rel.h"
#include "utils/ruleutils.h"
#include "utils/snapmgr.h"
@@ -47,7 +49,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
@@ -154,7 +155,8 @@ static void ExplainJSONLineEnding(ExplainState *es);
static void ExplainYAMLLineStarting(ExplainState *es);
static void escape_yaml(StringInfo buf, const char *str);
-
+static DestReceiver *CreateSerializeDestReceiver(int16 format);
+static uint64 GetNumberOfSerializedBytes(DestReceiver *dest);
/*
* ExplainQuery -
@@ -192,6 +194,23 @@ 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, "serialize") == 0)
+ {
+ es->serialize = true;
+ /* optionally check for BINARY as argument */
+ if (opt->arg)
+ {
+char *p = defGetString(opt);
+if (strcmp(p, "binary") == 0)
+ es->serialize = es->serializebinary = true;
+else
+ er
Re: Detoasting optionally to make Explain-Analyze less misleading
Hi, please see a revised version yesterday's mail. The patch attached now provides the following: EXPLAIN(ANALYZE,SERIALIZE) and EXPLAIN(ANALYZE,SERIALIZEBINARY) and timing output. Both options perform the serialization during analyze and provide an additional output in the plan like this: template1=# explain (analyze,serialize) select * from t12 limit 1; QUERY PLAN --- ... Serialized Bytes: 36 bytes Execution Time: 0.035 ms (5 rows) or also this template1=# explain (analyze,serialize) select * from t1; QUERY PLAN - Seq Scan on t1 (cost=0.00..1.02 rows=2 width=19) (actual time=0.101..0.111 rows=5 loops=1) Planning Time: 0.850 ms Serialized Bytes: 85777978 bytes Execution Time: 354.284 ms (4 rows) Its tempting to divide Serialized-Bytes by Execution-Time to get an idea of the serialization bandwidth. This is /dev/null serialization though. The results are length-counted and then discarded. Since detoasting happens implicitly during serialization, the number of bytes becomes huge in this case and accounts for the detoasted lengths as well. I tried to get the number of bytes send for the protocol's messages and the attribute headers correctly. For the actual values I am quite sure I get the correct measures, as one can really tell by sending more values across. Null is 4 bytes on the wire interestingly. I didn't know that, but it makes sense, since its using the same prefix length-field as all values do. I have checked the JBDC driver and it uses binary and text formats depending on an attribute's type oid. So having the SERIALIZEBINARY option is not accurate, as in reality both formats can be occur for the same tuple. Please provide some feedback on the new patch and let me know if this makes sense. In general this kind of option for EXPLAIN is a good thing for sure. Greetings, Stepan On 14.09.23 21:27, stepan rutz wrote: Hi Tom, Hi Matthias, you are right of course. I have looked at the code from printtup.c and made a new version of the patch. Thanks for the MemoryContextReset hint too (@Matthias) This time is called EXPLAIN(ANALYZE,SERIALIZE) (hey, it also sounds nicer phonetically) If the option SERIALIZE is active, the output functions are called and they perform the detoasting, which I have even checked. So things are better this way, however I hardcoded the output option "Text" (format=0). In printtup.c there is an incoming array which applies Text (format=0) or Binary (format=1) for each column individually. I am not sure whether this is even needed. I left in the if-statement from printtup.c which calls the binary output method of a given type. The result of the output is ignored and apparently free'd because of the memory-context-reset at the end. Please also note, that I added a call to DestReceiver's rDestroy hook, which was missing from explain.c before altogether. Feedback is appreciated. /Stepan On 12.09.23 17:26, Tom Lane wrote: Matthias van de Meent writes: 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. +1, that was my immediate reaction to the proposal as well. Some output functions are far from cheap. Doing only the detoast part seems like it's still misleading. Do we need to go as far as offering both text-output and binary-output options? regards, tom lane diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 8570b14f62..9090e0f114 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -26,6 +26,7 @@ #include "nodes/nodeFuncs.h" #include "parser/analyze.h" #include "parser/parsetree.h" +#include "mb/pg_wchar.h" #include "rewrite/rewriteHandler.h" #include "storage/bufmgr.h" #include "tcop/tcopprot.h" @@ -47,7 +48,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 @@ -154,7 +154,8 @@ static void ExplainJSONLineEnding(ExplainState *es); static void ExplainYAMLLineStarting(ExplainState *es); static void escape_yaml(StringI
Re: Detoasting optionally to make Explain-Analyze less misleading
Hi Tom, Hi Matthias,
you are right of course. I have looked at the code from printtup.c and
made a new version of the patch.
Thanks for the MemoryContextReset hint too (@Matthias)
This time is called EXPLAIN(ANALYZE,SERIALIZE) (hey, it also sounds
nicer phonetically)
If the option SERIALIZE is active, the output functions are called and
they perform the detoasting, which I have even checked.
So things are better this way, however I hardcoded the output option
"Text" (format=0). In printtup.c there is an incoming array which
applies Text (format=0) or Binary (format=1) for each column
individually. I am not sure whether this is even needed. I left in the
if-statement from printtup.c which calls the binary output method of a
given type. The result of the output is ignored and apparently free'd
because of the memory-context-reset at the end.
Please also note, that I added a call to DestReceiver's rDestroy hook,
which was missing from explain.c before altogether.
Feedback is appreciated.
/Stepan
On 12.09.23 17:26, Tom Lane wrote:
Matthias van de Meent writes:
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.
+1, that was my immediate reaction to the proposal as well. Some
output functions are far from cheap. Doing only the detoast part
seems like it's still misleading.
Do we need to go as far as offering both text-output and binary-output
options?
regards, tom lane
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 8570b14f62..dc52019a3e 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 *CreateSerializeDestReceiver(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, "serialize") == 0)
+ es->serialize = 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 serialize is used with EXPLAIN ANALYZE */
+ if (es->serialize && !es->analyze)
+ ereport(ERROR,
+(errcode(ERRCODE_INVALID_PARAMETER_VALUE),
+ errmsg("EXPLAIN option SERIALIZE requires ANALYZE")));
+
/* check that GENERIC_PLAN is not used with EXPLAIN ANALYZE */
if (es->generic && es->analyze)
ereport(ERROR,
@@ -565,9 +574,16 @@ 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 serialize during explain, we need to send the
+ * tuples to a receiver that performs the serializing
+ * which includes detoasting and the conversion of the attributes
+ * into the protocol receiving format. The latter can also be costly
+ * for some types
*/
if (into)
dest = CreateIntoRelDestReceiver(into);
+ else if (es->analyze && es->serialize)
+ dest = CreateSerializeDestReceiver();
else
dest = None_Receiver;
@@ -606,6 +622,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();
}
@@ -5052,3 +5071,193 @@ escape_yaml(StringInfo buf, const char *str)
{
escape_json(buf, str);
}
+
+
+/* Serializing 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.
+ *
+ * Also the output/send functions of some
Re: Detoasting optionally to make Explain-Analyze less misleading
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 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 us
Detoasting optionally to make Explain-Analyze less misleading
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.
Attached is a patch for addressing the issue in form of adding another
parameter to explain. I don't know if that is a good idea, but I got
some feedback that a solution to this problem would be appreciated by
some people out there. It would also be nice to reflect the detoasting
in the "buffers" option of explain as well. The change for detoasting is
only a few lines though.
So the idea was to allow this
EXPLAIN (ANALYZE, DETOAST) SELECT * FROM sometable;
and perform the detoasting step additionally during the explain. This
just gives a more realistic runtime and by playing around with the
parameter and comparing the execution-times of the query one even gets
an impression about the detoasting cost involved in a query. Since the
parameter is purely optional, it would not affect any existing measures.
It is not uncommon that the runtime of explain-analyze is way
unrealistic in the real world, where people use PostgreSQL to store
larger and larger documents inside tables and not using Large-Objects.
Here is a video of the effect (in an exagerated form):
https://www.stepanrutz.com/short_detoast_subtitles.mp4
It would be great to get some feedback on the subject and how to address
this, maybe in totally different ways.
Greetings from cologne, Stepan
Stepan Rutz - IT Consultant, Cologne Germany, stepan.rutz AT gmx.de
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 8570b14f62..50859e6a1e 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -47,6 +47,8 @@ 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;
+/* Forward decl for detoasting analyze */
+static const DestReceiver detoastAnalyzeDR;
/* OR-able flags for ExplainXMLTag() */
#define X_OPENING 0
@@ -192,6 +194,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 +248,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 +575,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 =
else
dest = None_Receiver;
@@ -5052,3 +5066,98 @@ 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.
+ */
+
+/* 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, DestRecei
