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(StringInfo buf, const char *str); - +static DestReceiver *CreateSerializeDestReceiver(int16 format); +static uint64 GetNumberOfSerializedBytes(DestReceiver *dest); /* * ExplainQuery - @@ -192,6 +193,12 @@ 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, "serializebinary") == 0) + { + es->serialize = es->serializebinary = defGetBoolean(opt); + } else if (strcmp(opt->defname, "timing") == 0) { timing_set = true; @@ -244,6 +251,17 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt, (errcode(ERRCODE_INVALID_PARAMETER_VALUE), errmsg("EXPLAIN option TIMING requires ANALYZE"))); + /* check that serializebinary is used with EXPLAIN ANALYZE */ + if (es->serializebinary && !es->analyze) + ereport(ERROR, + (errcode(ERRCODE_INVALID_PARAMETER_VALUE), + errmsg("EXPLAIN option SERIALIZEBINARY requires ANALYZE"))); + /* check that serialize is used with EXPLAIN ANALYZE */ + else 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, @@ -535,6 +553,7 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, double totaltime = 0; int eflags; int instrument_option = 0; + uint64 bytesSend = 0; Assert(plannedstmt->commandType != CMD_UTILITY); @@ -565,9 +584,15 @@ 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 dest-receiver that performs serializing + * into the protocol receiving format. this implicitly also detoasts + * values. */ if (into) dest = CreateIntoRelDestReceiver(into); + else if (es->analyze && es->serialize) + dest = CreateSerializeDestReceiver(es->serializebinary ? 1 : 0); else dest = None_Receiver; @@ -606,6 +631,15 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, /* run cleanup too */ ExecutorFinish(queryDesc); + if (es->serialize) + { + bytesSend = GetNumberOfSerializedBytes(dest); + } + + + /* 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); } @@ -643,6 +677,11 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, if (es->costs) ExplainPrintJITSummary(es, queryDesc); + if (es->analyze && es->serialize) + { + ExplainPropertyUInteger("Serialized Bytes", "bytes", bytesSend, es); + } + /* * Close down the query and free resources. Include time for this in the * total execution time (although it should be pretty minimal). @@ -5052,3 +5091,239 @@ escape_yaml(StringInfo buf, const char *str) { escape_json(buf, str); } + + +/* Serializing DestReceiver functions + * + * EXPLAIN (ANALYZE) sometimes gives results that unrealistic. + * During EXPLAIN(ANALYZE) 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. + * + * EXPLAIN (ANAYLZE, SERIALIZE) will perform detoasting implicitly and + * will also do count the number of bytes being send to the client but + * will not actually send them. SERIALIZE uses text format for all + * attributes. + * + * EXPLAIN (ANAYLZE, SERIALIZEBINARY) serializes using binary format. + */ + +/* an attribute info cached for each column */ +typedef struct +{ /* Per-attribute information */ + Oid typoutput; /* Oid for the type's text output fn */ + Oid typsend; /* Oid for the type's binary output fn */ + bool typisvarlena; /* is it varlena (ie possibly toastable)? */ + int16 format; /* format code for this column */ + FmgrInfo finfo; /* Precomputed call info for output fn */ +} SerializeAttrInfo; + +typedef struct +{ + /* receiver for the tuples, that just serializes */ + DestReceiver destRecevier; + MemoryContext memoryContext; + MemoryContext oldMemoryContext; /* restore to old when done */ + int16 format; /* text of binary */ + TupleDesc attrinfo; + int nattrs; + uint64 bytesSend; /* Num of bytes over the wire */ + SerializeAttrInfo *infos; /* Cached info about each attr */ +} SerializeDestReceiver; + +/* + * Get the lookup info that the row-callback of the receiver needs. this code + * is similar to the code from printup.c except that it doesn't do any actual + * output. + */ +static void +serialize_prepare_info(SerializeDestReceiver *receiver, TupleDesc typeinfo, + int nattrs) +{ + int i; + + /* get rid of any old data */ + if (receiver->infos) + pfree(receiver->infos); + receiver->infos = NULL; + + receiver->attrinfo = typeinfo; + receiver->nattrs = nattrs; + if (nattrs <= 0) + return; + + receiver->infos = (SerializeAttrInfo *) palloc0( + nattrs * sizeof(SerializeAttrInfo)); + for (i = 0; i < nattrs; i++) + { + SerializeAttrInfo *info = &(receiver->infos[i]); + Form_pg_attribute attr = TupleDescAttr(typeinfo, i); + info->format = receiver->format; + if (info->format == 0) + { + getTypeOutputInfo(attr->atttypid, + &info->typoutput, + &info->typisvarlena); + fmgr_info(info->typoutput, &info->finfo); + } + else if (info->format == 1) + { + getTypeBinaryOutputInfo(attr->atttypid, + &info->typsend, + &info->typisvarlena); + fmgr_info(info->typsend, &info->finfo); + } + else + ereport(ERROR, + (errcode(ERRCODE_INVALID_PARAMETER_VALUE), + errmsg("unsupported format code: %d", info->format))); + } +} + + + +/* this method receives the tuples/records during explain (analyze, serialize) + * and serializes them. + * this method is otherwise not called and its purpose is to serialize to + * make analyze optionally more realistic. serialization includes detoasting + * and invoking the type's output (or send) function, which is what happens + * when you actually run the query. both steps cost time and thus + * analyze can be very misleading if those two steps are omitted. + */ +static bool +serializeAnalyzeReceive(TupleTableSlot *slot, DestReceiver *self) +{ + int i; + TupleDesc tupdesc; + SerializeDestReceiver *receiver = (SerializeDestReceiver*) self; + + tupdesc = slot->tts_tupleDescriptor; + /* Cache attribute infos and function oid if outdated */ + if (receiver->attrinfo != tupdesc || receiver->nattrs != tupdesc->natts) + { + serialize_prepare_info(receiver, tupdesc, tupdesc->natts); + } + + /* 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); + + receiver->oldMemoryContext = MemoryContextSwitchTo( + receiver->memoryContext); + + /* Iterate over all attributes of the tuple and invoke the output func + * (or send function in case of a binary format). completely ignore the + * result. MemoryContext is free'd via reset at the end of the this + * per-tuple callback anyhow. + * NOTE: when invoking the output function detoasting is implicitly + * performed when needed. This adds major overhead to plain + * explain-analyze and this is what is desired here. + */ + + receiver->bytesSend += 3; /* protocol message type and attribute-count */ + for (i = 0; i < tupdesc->natts; i++) + { + SerializeAttrInfo *info = &(receiver->infos[i]); + Datum attr = slot->tts_values[i]; + if (slot->tts_isnull[i]) + { + receiver->bytesSend += 4; /* null is send as -1 length */ + } + else + { + if (info->format == 0) + { + /* Text output, ignore the result but count it */ + char* output = OutputFunctionCall(&info->finfo, attr); + size_t outputlen = strlen(output); + /* convert from server encoding to client encoding if needed */ + char *converted = pg_server_to_client(output, outputlen); + if (converted != output) + { + /* converted encoding, get new length */ + outputlen = strlen(converted); + pfree(converted); + } + /* append length that would have gone over the wire, 4 + * the number of preceding bytes that contain the length */ + receiver->bytesSend += 4 + outputlen; + } + else + { + /* Binary output, ignore the result but count it + * length is included in varsize */ + bytea* bytes = SendFunctionCall(&info->finfo, attr); + uint64 n = VARSIZE(bytes); + receiver->bytesSend += n; + } + } + } + MemoryContextSwitchTo(receiver->oldMemoryContext); + MemoryContextReset(receiver->memoryContext); + return true; +} + +static void +serializeAnalyzeStartup(DestReceiver *self, int operation, TupleDesc typeinfo) +{ + SerializeDestReceiver *receiver = (SerializeDestReceiver*) self; + int i; + /* memory context for our work */ + receiver->memoryContext = AllocSetContextCreate(CurrentMemoryContext, + "SerializeTupleReceive", ALLOCSET_DEFAULT_SIZES); + + /* account for the attribute headers for send bytes */ + receiver->bytesSend += 3; /* protocol message type and attribute-count */ + for (i = 0; i < typeinfo->natts; ++i) + { + Form_pg_attribute att = TupleDescAttr(typeinfo, i); + char* name = NameStr(att->attname); + size_t namelen = strlen(name); + /* convert from server encoding to client encoding if needed */ + char *converted = pg_server_to_client(name, namelen); + if (converted != name) + { + namelen = strlen(converted); + pfree(converted); + } + /* see printtup.h why we add 18 bytes here. These are the infos + * needed for each attribute plus the attributes's name */ + receiver->bytesSend += namelen + 1 + 18; + } +} + +static void +serializeAnalyzeCleanup(DestReceiver *self) +{ + SerializeDestReceiver *receiver = (SerializeDestReceiver*) self; + MemoryContextDelete(receiver->memoryContext); +} + +static void +serializeAnalyzeDestroy(DestReceiver *self) +{ + pfree(self); +} + +/* format is either 0 (text) or 1 (binary) */ +static DestReceiver *CreateSerializeDestReceiver(int16 format) +{ + /* Attention must palloc0 (like calloc) here. + * infos and nattrs are expected to be 0 or NULL initially */ + SerializeDestReceiver *self = (SerializeDestReceiver*) palloc0( + sizeof(SerializeDestReceiver)); + self->destRecevier.receiveSlot = serializeAnalyzeReceive; + self->destRecevier.rStartup = serializeAnalyzeStartup; + self->destRecevier.rShutdown = serializeAnalyzeCleanup; + self->destRecevier.rDestroy = serializeAnalyzeDestroy; + self->destRecevier.mydest = DestNone; + self->format = format; + return (DestReceiver *) self; +} + +static uint64 GetNumberOfSerializedBytes(DestReceiver *dest) +{ + SerializeDestReceiver *receiver = (SerializeDestReceiver*) dest; + return receiver->bytesSend; +} diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h index 3d3e632a0c..777c7578cc 100644 --- a/src/include/commands/explain.h +++ b/src/include/commands/explain.h @@ -47,6 +47,16 @@ typedef struct ExplainState bool summary; /* print total planning and execution timing */ bool settings; /* print modified settings */ bool generic; /* generate a generic plan */ + bool serialize; /* serialize all values, only applicable + * when "analyze" is active. serializing + * invokes the type's output function in + * the same way printtup.c does then tuples + * are send to the client. this includes + * detoasting of toasted values and makes + * EXPLAIN(ANALYZE,SERIALIZE) return realistic + * (longer runtimes */ + bool serializebinary;/* serialize in binary format */ + 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..76e8932a7c 100644 --- a/src/test/regress/expected/explain.out +++ b/src/test/regress/expected/explain.out @@ -559,3 +559,40 @@ select explain_filter('explain (verbose) select * from int8_tbl i8'); Query Identifier: N (3 rows) +-- Test that SERIALIZE is accepted as a parameter to explain +-- timings are filtered out by explain_filter +create table test_serialize(id bigserial, val text); +select explain_filter('explain (analyze,serialize) select * from test_serialize'); + explain_filter +-------------------------------------------------------------------------------------------------- + Seq Scan on test_serialize (cost=N.N..N.N rows=N width=N) (actual time=N.N..N.N rows=N loops=N) + Planning Time: N.N ms + Serialized Bytes: N bytes + Execution Time: N.N ms +(4 rows) + +drop table test_serialize; +-- Test that SERIALIZEBINARY is accepted as a parameter to explain +create table test_serialize(id bigserial, val text); +select explain_filter('explain (analyze,serializebinary) select * from test_serialize'); + explain_filter +-------------------------------------------------------------------------------------------------- + Seq Scan on test_serialize (cost=N.N..N.N rows=N width=N) (actual time=N.N..N.N rows=N loops=N) + Planning Time: N.N ms + Serialized Bytes: N bytes + Execution Time: N.N ms +(4 rows) + +drop table test_serialize; +-- Test SERIALIZE is _not_ accepted as a parameter to explain unless ANALYZE is specified +create table test_serialize(id bigserial, val text); +select explain_filter('explain (serialize) select * from test_serialize'); +ERROR: EXPLAIN option SERIALIZE requires ANALYZE +CONTEXT: PL/pgSQL function explain_filter(text) line 5 at FOR over EXECUTE statement +drop table test_serialize; +-- Test SERIALIZEBINARY is _not_ accepted as a parameter to explain unless ANALYZE is specified +create table test_serialize(id bigserial, val text); +select explain_filter('explain (serializebinary) select * from test_serialize'); +ERROR: EXPLAIN option SERIALIZEBINARY requires ANALYZE +CONTEXT: PL/pgSQL function explain_filter(text) line 5 at FOR over EXECUTE statement +drop table test_serialize; diff --git a/src/test/regress/sql/explain.sql b/src/test/regress/sql/explain.sql index b6b7beab27..bdabc0c36e 100644 --- a/src/test/regress/sql/explain.sql +++ b/src/test/regress/sql/explain.sql @@ -154,3 +154,26 @@ 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 that SERIALIZE is accepted as a parameter to explain +-- timings are filtered out by explain_filter +create table test_serialize(id bigserial, val text); +select explain_filter('explain (analyze,serialize) select * from test_serialize'); +drop table test_serialize; + +-- Test that SERIALIZEBINARY is accepted as a parameter to explain +create table test_serialize(id bigserial, val text); +select explain_filter('explain (analyze,serializebinary) select * from test_serialize'); +drop table test_serialize; + +-- Test SERIALIZE is _not_ accepted as a parameter to explain unless ANALYZE is specified +create table test_serialize(id bigserial, val text); +select explain_filter('explain (serialize) select * from test_serialize'); +drop table test_serialize; + +-- Test SERIALIZEBINARY is _not_ accepted as a parameter to explain unless ANALYZE is specified +create table test_serialize(id bigserial, val text); +select explain_filter('explain (serializebinary) select * from test_serialize'); +drop table test_serialize; + +