From 53e47cdd799963951c371ea8158996be3b6e603a Mon Sep 17 00:00:00 2001 From: Tom Lane Date: Mon, 3 Oct 2005 22:55:56 +0000 Subject: [PATCH] Add a trace_sort option to help with measuring resource usage of external sort operations. Per recent discussion. Simon Riggs and Tom Lane. --- doc/src/sgml/config.sgml | 17 ++++++- src/backend/utils/misc/guc.c | 17 ++++++- src/backend/utils/sort/tuplesort.c | 82 +++++++++++++++++++++++++++++- src/include/pg_config_manual.h | 12 +++-- 4 files changed, 121 insertions(+), 7 deletions(-) diff --git a/doc/src/sgml/config.sgml b/doc/src/sgml/config.sgml index d239654b47..710605ca70 100644 --- a/doc/src/sgml/config.sgml +++ b/doc/src/sgml/config.sgml @@ -1,5 +1,5 @@ Run-time Configuration @@ -4071,6 +4071,21 @@ plruby.use_strict = true # generates error: unknown class name + + trace_sort (boolean) + + trace_sort configuration parameter + + + + If on, emit information about resource usage during sort operations. + This option is only available if the TRACE_SORT macro + was defined when PostgreSQL was compiled. + (However, TRACE_SORT is currently defined by default.) + + + + trace_locks (boolean) trace_lwlocks (boolean) diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c index 1315afff0c..d9932e0517 100644 --- a/src/backend/utils/misc/guc.c +++ b/src/backend/utils/misc/guc.c @@ -10,7 +10,7 @@ * Written by Peter Eisentraut . * * IDENTIFICATION - * $PostgreSQL: pgsql/src/backend/utils/misc/guc.c,v 1.289 2005/09/24 22:54:39 tgl Exp $ + * $PostgreSQL: pgsql/src/backend/utils/misc/guc.c,v 1.290 2005/10/03 22:55:51 tgl Exp $ * *-------------------------------------------------------------------- */ @@ -92,6 +92,9 @@ extern int CommitDelay; extern int CommitSiblings; extern char *default_tablespace; extern bool fullPageWrites; +#ifdef TRACE_SORT +extern bool trace_sort; +#endif static const char *assign_log_destination(const char *value, bool doit, GucSource source); @@ -891,6 +894,18 @@ static struct config_bool ConfigureNamesBool[] = false, NULL, NULL }, +#ifdef TRACE_SORT + { + {"trace_sort", PGC_USERSET, DEVELOPER_OPTIONS, + gettext_noop("Emit information about resource usage in sorting."), + NULL, + GUC_NOT_IN_SAMPLE + }, + &trace_sort, + false, NULL, NULL + }, +#endif + #ifdef WAL_DEBUG { {"wal_debug", PGC_SUSET, DEVELOPER_OPTIONS, diff --git a/src/backend/utils/sort/tuplesort.c b/src/backend/utils/sort/tuplesort.c index 3ec1cf127f..53f2b546f4 100644 --- a/src/backend/utils/sort/tuplesort.c +++ b/src/backend/utils/sort/tuplesort.c @@ -78,7 +78,7 @@ * Portions Copyright (c) 1994, Regents of the University of California * * IDENTIFICATION - * $PostgreSQL: pgsql/src/backend/utils/sort/tuplesort.c,v 1.50 2005/09/23 15:36:57 tgl Exp $ + * $PostgreSQL: pgsql/src/backend/utils/sort/tuplesort.c,v 1.51 2005/10/03 22:55:54 tgl Exp $ * *------------------------------------------------------------------------- */ @@ -95,10 +95,17 @@ #include "utils/logtape.h" #include "utils/lsyscache.h" #include "utils/memutils.h" +#include "utils/pg_rusage.h" #include "utils/syscache.h" #include "utils/tuplesort.h" +/* GUC variable */ +#ifdef TRACE_SORT +bool trace_sort = false; +#endif + + /* * Possible states of a Tuplesort object. These denote the states that * persist between calls of Tuplesort routines. @@ -283,6 +290,13 @@ struct Tuplesortstate /* we need typelen and byval in order to know how to copy the Datums. */ int datumTypeLen; bool datumTypeByVal; + + /* + * Resource snapshot for time of sort start. + */ +#ifdef TRACE_SORT + PGRUsage ru_start; +#endif }; #define COMPARETUP(state,a,b) ((*(state)->comparetup) (state, a, b)) @@ -422,6 +436,11 @@ tuplesort_begin_common(int workMem, bool randomAccess) state = (Tuplesortstate *) palloc0(sizeof(Tuplesortstate)); +#ifdef TRACE_SORT + if (trace_sort) + pg_rusage_init(&state->ru_start); +#endif + state->status = TSS_INITIAL; state->randomAccess = randomAccess; state->availMem = workMem * 1024L; @@ -456,6 +475,13 @@ tuplesort_begin_heap(TupleDesc tupDesc, AssertArg(nkeys > 0); +#ifdef TRACE_SORT + if (trace_sort) + elog(NOTICE, + "begin tuple sort: nkeys = %d, workMem = %d, randomAccess = %c", + nkeys, workMem, randomAccess ? 't' : 'f'); +#endif + state->comparetup = comparetup_heap; state->copytup = copytup_heap; state->writetup = writetup_heap; @@ -499,6 +525,14 @@ tuplesort_begin_index(Relation indexRel, { Tuplesortstate *state = tuplesort_begin_common(workMem, randomAccess); +#ifdef TRACE_SORT + if (trace_sort) + elog(NOTICE, + "begin index sort: unique = %c, workMem = %d, randomAccess = %c", + enforceUnique ? 't' : 'f', + workMem, randomAccess ? 't' : 'f'); +#endif + state->comparetup = comparetup_index; state->copytup = copytup_index; state->writetup = writetup_index; @@ -522,6 +556,13 @@ tuplesort_begin_datum(Oid datumType, int16 typlen; bool typbyval; +#ifdef TRACE_SORT + if (trace_sort) + elog(NOTICE, + "begin datum sort: workMem = %d, randomAccess = %c", + workMem, randomAccess ? 't' : 'f'); +#endif + state->comparetup = comparetup_datum; state->copytup = copytup_datum; state->writetup = writetup_datum; @@ -573,6 +614,12 @@ tuplesort_end(Tuplesortstate *state) if (state->sortFnKinds) pfree(state->sortFnKinds); +#ifdef TRACE_SORT + if (trace_sort) + elog(NOTICE, "sort ended: %s", + pg_rusage_show(&state->ru_start)); +#endif + pfree(state); } @@ -712,6 +759,12 @@ puttuple_common(Tuplesortstate *state, void *tuple) void tuplesort_performsort(Tuplesortstate *state) { +#ifdef TRACE_SORT + if (trace_sort) + elog(NOTICE, "performsort starting: %s", + pg_rusage_show(&state->ru_start)); +#endif + switch (state->status) { case TSS_INITIAL: @@ -751,6 +804,13 @@ tuplesort_performsort(Tuplesortstate *state) elog(ERROR, "invalid tuplesort state"); break; } + +#ifdef TRACE_SORT + if (trace_sort) + elog(NOTICE, "performsort done%s: %s", + (state->status == TSS_FINALMERGE) ? " (except final merge)" : "", + pg_rusage_show(&state->ru_start)); +#endif } /* @@ -986,6 +1046,12 @@ inittapes(Tuplesortstate *state) int ntuples, j; +#ifdef TRACE_SORT + if (trace_sort) + elog(NOTICE, "switching to external sort: %s", + pg_rusage_show(&state->ru_start)); +#endif + state->tapeset = LogicalTapeSetCreate(MAXTAPES); /* @@ -1243,6 +1309,12 @@ mergeonerun(Tuplesortstate *state) */ markrunend(state, destTape); state->tp_runs[TAPERANGE]++; + +#ifdef TRACE_SORT + if (trace_sort) + elog(NOTICE, "finished merge step: %s", + pg_rusage_show(&state->ru_start)); +#endif } /* @@ -1456,6 +1528,14 @@ dumptuples(Tuplesortstate *state, bool alltuples) state->tp_runs[state->destTape]++; state->tp_dummy[state->destTape]--; /* per Alg D step D2 */ +#ifdef TRACE_SORT + if (trace_sort) + elog(NOTICE, "finished writing%s run %d: %s", + (state->memtupcount == 0) ? " final" : "", + state->currentRun, + pg_rusage_show(&state->ru_start)); +#endif + /* * Done if heap is empty, else prepare for new run. */ diff --git a/src/include/pg_config_manual.h b/src/include/pg_config_manual.h index b36714b87b..bf82771d45 100644 --- a/src/include/pg_config_manual.h +++ b/src/include/pg_config_manual.h @@ -6,7 +6,7 @@ * for developers. If you edit any of these, be sure to do a *full* * rebuild (and an initdb if noted). * - * $PostgreSQL: pgsql/src/include/pg_config_manual.h,v 1.16 2005/03/29 03:01:32 tgl Exp $ + * $PostgreSQL: pgsql/src/include/pg_config_manual.h,v 1.17 2005/10/03 22:55:56 tgl Exp $ *------------------------------------------------------------------------ */ @@ -229,11 +229,15 @@ */ /* #define WAL_DEBUG */ +/* + * Enable tracing of resource consumption during sort operations; + * see also the trace_sort GUC var. For 8.1 this is enabled by default. + */ +#define TRACE_SORT 1 + /* * Other debug #defines (documentation, anyone?) */ -/* #define IPORTAL_DEBUG */ -/* #define HEAPDEBUGALL */ +/* #define HEAPDEBUGALL */ /* #define ACLDEBUG */ /* #define RTDEBUG */ -/* #define GISTDEBUG */ -- 2.40.0