diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c index 55ab2da299b..cc03458fcba 100644 --- a/src/backend/tcop/postgres.c +++ b/src/backend/tcop/postgres.c @@ -873,6 +873,19 @@ pg_rewrite_query(Query *query) return querytree_list; } +#define NANOSEC_PER_SEC 1000000000 + +#include + +/* Returns difference between t1 and t2 in nanoseconds */ +static int64 +get_clock_diff(struct timespec *t1, struct timespec *t2) +{ + int64 nanosec = (t1->tv_sec - t2->tv_sec) * NANOSEC_PER_SEC; + nanosec += (t1->tv_nsec - t2->tv_nsec); + + return nanosec; +} /* * Generate a plan for a single already-rewritten query. @@ -883,6 +896,8 @@ pg_plan_query(Query *querytree, const char *query_string, int cursorOptions, ParamListInfo boundParams) { PlannedStmt *plan; + struct timespec start, end; + int64 jumbletime; /* Utility commands have no plans. */ if (querytree->commandType == CMD_UTILITY) @@ -896,6 +911,12 @@ pg_plan_query(Query *querytree, const char *query_string, int cursorOptions, if (log_planner_stats) ResetUsage(); + clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &start); + JumbleQuery(querytree); + clock_gettime(CLOCK_PROCESS_CPUTIME_ID, &end); + jumbletime = get_clock_diff(&end, &start); + elog(NOTICE, "QueryJumble in %ld nanoseconds", jumbletime); + /* call the optimizer */ plan = planner(querytree, query_string, cursorOptions, boundParams);