On 01/17/2012 11:13 AM, Joel Jacobson wrote:
> Since you only care about the parentfuncid in one level, it looks like
> you will only be able to get a total call graph of all possible
> function calls, and not each unique call graph per transaction.
True, for my purposes (function dependencies and performance analysis)
the global graph is sufficient.
> Also, why remove the parent oid when uploading the statistics to the
> collector?
> It would be nice to have the statistics for each function per parent,
> to see where you have a bottleneck which might only be occurring in a
> function when called from a specific parent.
I guess I was just lazy at the time I wrote it. But it shouldn't be too
much of an effort to store the global call graph in statistics
collector. Unique call graphs would be somewhat more complicated I
guess.
>> There is a patch for this and we do use it in production for occasional
>> troubleshooting and dependency analysis. Can't attach immediately
>> though -- it has some extra cruft in it that needs to be cleaned up.
>
> I would highly appreciate a patch, don't worry about cleaning up, I
> can do that, unless it's some code you can't share for other reasons.
>
Patch attached. It was developed against 9.1, but also applies to
HEAD but gives some fuzz and offsets.
It adds 2 GUC variables: log_function_calls and log_usage_stats. The
first just output function statistics to log (with no parent info).
With log_usage_stats enabled, it also outputs detailed function usage
plus relation usage. So you basically get output such as:
# select * from pgq.get_consumer_info();
LOG: duration: 11.153 ms statement: select * from pgq.get_consumer_info();
LOG: function call: pgq.get_consumer_info(0) calls=1 time=9726
self_time=536
LOG: USAGE STATISTICS
DETAIL: ! object access stats:
! F 1892464226 0 pgq.get_consumer_info(0) calls=1 time=9726 self_time=536
! F 1892464228 1892464226 pgq.get_consumer_info(2) calls=1 time=9190
self_time=9190
! r 167558000 pgq.queue: blks_read=28 blks_hit=28
! r 167557988 pgq.consumer: blks_read=56 blks_hit=56
! r 167558021 pgq.subscription: blks_read=54 blks_hit=50
! r 167558050 pgq.tick: blks_read=103 blks_hit=102
! i 1892464189 pgq.queue_pkey: scans=1 tup_ret=37 tup_fetch=37
blks_read=2 blks_hit=2
! i 167557995 pgq.consumer_pkey: scans=56 tup_ret=56 tup_fetch=56
blks_read=57 blks_hit=56
! i 1892464195 pgq.subscription_pkey: scans=37 tup_ret=156 tup_fetch=56
blks_read=127 blks_hit=123
! i 167558058 pgq.tick_pkey: scans=112 tup_ret=103 tup_fetch=103
blks_read=367 blks_hit=366
> funcid->parentfuncid might be sufficient for performance
> optimizations, but to automatically generate directional graphs of all
> unique call graphs in run-time, you would need all the unique pairs of
> funcid->parentfuncid as a singel column, probably a sorted array of
> oids[][], example: [[1,2],[1,3],[2,4],[2,5]] if the call craph would
> be {1->2, 1->3, 2->4, 2->5}.
>
Hmm, array would probably work, although I wonder if there is a
more elegant solution ...
regards,
Martin
diff --git a/src/backend/postmaster/pgstat.c b/src/backend/postmaster/pgstat.c
index 5ed6e83..2e66020 100644
--- a/src/backend/postmaster/pgstat.c
+++ b/src/backend/postmaster/pgstat.c
@@ -42,6 +42,7 @@
#include "access/twophase_rmgr.h"
#include "access/xact.h"
#include "catalog/pg_database.h"
+#include "catalog/pg_namespace.h"
#include "catalog/pg_proc.h"
#include "libpq/ip.h"
#include "libpq/libpq.h"
@@ -63,7 +64,8 @@
#include "utils/ps_status.h"
#include "utils/rel.h"
#include "utils/tqual.h"
-
+#include "utils/syscache.h"
+#include "utils/lsyscache.h"
/* ----------
* Paths for the statistics files (relative to installation's $PGDATA).
@@ -113,6 +115,12 @@ bool pgstat_track_counts = false;
int pgstat_track_functions = TRACK_FUNC_OFF;
int pgstat_track_activity_query_size = 1024;
+/*
+ * Last function call parent. InvalidOid is used to indicate
+ * top-level functions.
+ */
+Oid current_function_parent = InvalidOid;
+
/* ----------
* Built from GUC parameter
* ----------
@@ -258,8 +266,11 @@ static void pgstat_read_current_status(void);
static void pgstat_send_tabstat(PgStat_MsgTabstat *tsmsg);
static void pgstat_send_funcstats(void);
static HTAB *pgstat_collect_oids(Oid catalogid);
+static void pgstat_report_functions(void);
+static void pgstat_report_usage(void);
static PgStat_TableStatus *get_tabstat_entry(Oid rel_id, bool isshared);
+static PgStat_TableStatus *new_tsa_entry(TabStatusArray *entry, Oid rel_id, bool isshared);
static void pgstat_setup_memcxt(void);
@@ -697,6 +708,12 @@ pgstat_report_stat(bool force)
last_report = now;
/*
+ * First report function calls and object usage.
+ */
+ pgstat_report_functions();
+ pgstat_report_usage();
+
+ /*
* Scan through the TabStatusArray struct(s) to find tables that actually
* have counts, and build messages to send. We have to separate shared
* relations from regular ones because the databaseid field in the message
@@ -804,9 +821,6 @@ pgstat_send_tabstat(PgStat_MsgTabstat *tsmsg)
static void
pgstat_send_funcstats(void)
{
- /* we assume this inits to all zeroes: */
- static const PgStat_FunctionCounts all_zeroes;
-
PgStat_MsgFuncstat msg;
PgStat_BackendFunctionEntry *entry;
HASH_SEQ_STATUS fstat;
@@ -818,37 +832,31 @@ pgstat_send_funcstats(void)
msg.m_databaseid = MyDatabaseId;
msg.m_nentries = 0;
+ /*
+ * Pack the function stats into message structures and send
+ * them to the collector. Don't bother merging the stats for
+ * the same function with different parents -- just send the
+ * entries individually and let the collector sum it up.
+ */
hash_seq_init(&fstat, pgStatFunctions);
- while ((entry = (PgStat_BackendFunctionEntry *) hash_seq_search(&fstat)) != NULL)
+ while ((entry = hash_seq_search(&fstat)) != NULL)
{
- PgStat_FunctionEntry *m_ent;
+ msg.m_entry[msg.m_nentries].f_id = entry->f_key.f_id;
+ msg.m_entry[msg.m_nentries].f_counts = entry->counts;
- /* Skip it if no counts accumulated since last time */
- if (memcmp(&entry->f_counts, &all_zeroes,
- sizeof(PgStat_FunctionCounts)) == 0)
- continue;
-
- /* need to convert format of time accumulators */
- m_ent = &msg.m_entry[msg.m_nentries];
- m_ent->f_id = entry->f_id;
- m_ent->f_numcalls = entry->f_counts.f_numcalls;
- m_ent->f_time = INSTR_TIME_GET_MICROSEC(entry->f_counts.f_time);
- m_ent->f_time_self = INSTR_TIME_GET_MICROSEC(entry->f_counts.f_time_self);
-
- if (++msg.m_nentries >= PGSTAT_NUM_FUNCENTRIES)
- {
- pgstat_send(&msg, offsetof(PgStat_MsgFuncstat, m_entry[0]) +
- msg.m_nentries * sizeof(PgStat_FunctionEntry));
- msg.m_nentries = 0;
- }
+ memset(&entry->counts, 0, sizeof(PgStat_FunctionCounts));
- /* reset the entry's counts */
- MemSet(&entry->f_counts, 0, sizeof(PgStat_FunctionCounts));
+ if (++msg.m_nentries >= PGSTAT_NUM_FUNCENTRIES)
+ {
+ pgstat_send(&msg, offsetof(PgStat_MsgFuncstat, m_entry[0]) +
+ msg.m_nentries * sizeof(PgStat_MsgFunctionEntry));
+ msg.m_nentries = 0;
+ }
}
if (msg.m_nentries > 0)
pgstat_send(&msg, offsetof(PgStat_MsgFuncstat, m_entry[0]) +
- msg.m_nentries * sizeof(PgStat_FunctionEntry));
+ msg.m_nentries * sizeof(PgStat_MsgFunctionEntry));
have_function_stats = false;
}
@@ -1079,6 +1087,163 @@ pgstat_collect_oids(Oid catalogid)
/* ----------
+ * pgstat_report_functions() -
+ *
+ * Report top-level function calls to system log.
+ * ----------
+ */
+static void
+pgstat_report_functions(void)
+{
+ PgStat_BackendFunctionEntry *entry;
+ HASH_SEQ_STATUS fstat;
+
+ if (!log_function_calls || IsAutoVacuumWorkerProcess())
+ return;
+
+ /*
+ * Go through the functions that have stats. Dump only the
+ * top-level calls.
+ */
+ if (pgStatFunctions != NULL)
+ {
+ hash_seq_init(&fstat, pgStatFunctions);
+ while ((entry = hash_seq_search(&fstat)) != NULL)
+ {
+ /* log top-level function calls if so requested */
+ if (entry->counts.f_numcalls > 0 && !OidIsValid(entry->f_key.f_parent))
+ elog(LOG, "function call: %s.%s(%d) calls=" UINT64_FORMAT
+ " time=" UINT64_FORMAT " self_time=" UINT64_FORMAT,
+ entry->f_schema,
+ entry->f_name,
+ entry->f_nargs,
+ entry->counts.f_numcalls,
+ INSTR_TIME_GET_MICROSEC(entry->counts.f_time),
+ INSTR_TIME_GET_MICROSEC(entry->counts.f_time_self));
+ }
+ }
+}
+
+/* ----------
+ * pgstat_report_usage() -
+ *
+ * Report relation and function usage for the client. The report is
+ * formatted similarly to log_executor_stats.
+ * ----------
+ */
+static void
+pgstat_report_usage(void)
+{
+ static const PgStat_TableCounts tc_all_zeroes;
+ PgStat_BackendFunctionEntry *entry;
+ HASH_SEQ_STATUS fstat;
+ TabStatusArray *tsa;
+ StringInfoData str;
+ bool log_usage = false;
+ int i;
+
+ if (!log_usage_stats || IsAutoVacuumWorkerProcess())
+ return;
+
+ initStringInfo(&str);
+ appendStringInfo(&str, "! object access stats:\n");
+
+ /*
+ * Go through the functions that have stats. We produce as many
+ * detail rows as necessary to list all the invocations by different
+ * parents of the function. This is verbose, but allows for more
+ * fine-grained performance analysis later.
+ */
+ if (pgStatFunctions != NULL)
+ {
+ hash_seq_init(&fstat, pgStatFunctions);
+ while ((entry = hash_seq_search(&fstat)) != NULL)
+ {
+ if (!entry->counts.f_numcalls > 0)
+ /* nothing to do */
+ continue;
+
+ appendStringInfo(&str, "! F %u %u %s.%s(%d) calls=" UINT64_FORMAT
+ " time=" UINT64_FORMAT
+ " self_time=" UINT64_FORMAT "\n",
+ entry->f_key.f_id,
+ entry->f_key.f_parent,
+ entry->f_schema,
+ entry->f_name,
+ entry->f_nargs,
+ entry->counts.f_numcalls,
+ INSTR_TIME_GET_MICROSEC(entry->counts.f_time),
+ INSTR_TIME_GET_MICROSEC(entry->counts.f_time_self));
+
+ log_usage = true;
+ }
+ }
+
+ /*
+ * Now the tables. Here we actually report any relations that have
+ * stats counters, use relkind to distinguish.
+ */
+ if (log_usage_stats && pgStatTabList->tsa_used > 0)
+ {
+ for (tsa = pgStatTabList; tsa != NULL; tsa = tsa->tsa_next)
+ {
+ for (i = 0; i < tsa->tsa_used; i++)
+ {
+ PgStat_TableStatus *entry = &tsa->tsa_entries[i];
+ PgStat_TableCounts *tc = &entry->t_counts;
+
+ if (entry->t_system)
+ /* Don't report system tables */
+ continue;
+ if (memcmp(tc, &tc_all_zeroes, sizeof(*tc)) == 0)
+ /* All zeroes, nothing to report */
+ continue;
+
+#define REPORT_TC_COUNTER(field,label) \
+ if (tc->field) \
+ appendStringInfo(&str, " %s=" UINT64_FORMAT, (label), tc->field)
+
+ appendStringInfo(&str, "! %c %u %s.%s:",
+ entry->t_relkind,
+ entry->t_id,
+ entry->t_schema,
+ entry->t_name);
+
+ REPORT_TC_COUNTER(t_numscans, "scans");
+ REPORT_TC_COUNTER(t_tuples_returned, "tup_ret");
+ REPORT_TC_COUNTER(t_tuples_fetched, "tup_fetch");
+ REPORT_TC_COUNTER(t_tuples_inserted, "n_tup_ins");
+ REPORT_TC_COUNTER(t_tuples_updated, "n_tup_upd");
+ REPORT_TC_COUNTER(t_tuples_deleted, "n_tup_del");
+ REPORT_TC_COUNTER(t_tuples_hot_updated, "n_tup_hot_upd");
+ REPORT_TC_COUNTER(t_delta_live_tuples, "n_delta_live_tuples");
+ REPORT_TC_COUNTER(t_delta_dead_tuples, "n_delta_dead_tuples");
+ REPORT_TC_COUNTER(t_changed_tuples, "n_changed_tuples");
+ REPORT_TC_COUNTER(t_blocks_fetched, "blks_read");
+ REPORT_TC_COUNTER(t_blocks_hit, "blks_hit");
+
+ appendStringInfo(&str, "\n");
+ log_usage = true;
+ }
+ }
+ }
+
+ /*
+ * Found something to report - spit it out.
+ */
+ if (log_usage)
+ {
+ str.data[--str.len] = '\0';
+ ereport(LOG,
+ (errmsg_internal("%s", "USAGE STATISTICS"),
+ errdetail("%s", str.data)));
+ }
+
+ pfree(str.data);
+}
+
+
+/* ----------
* pgstat_drop_database() -
*
* Tell the collector that we just dropped a database.
@@ -1380,8 +1545,10 @@ void
pgstat_init_function_usage(FunctionCallInfoData *fcinfo,
PgStat_FunctionCallUsage *fcu)
{
- PgStat_BackendFunctionEntry *htabent;
bool found;
+ Oid funcid;
+ MemoryContext oldcontext;
+ FunctionStatKey key;
if (pgstat_track_functions <= fcinfo->flinfo->fn_stats)
{
@@ -1390,15 +1557,19 @@ pgstat_init_function_usage(FunctionCallInfoData *fcinfo,
return;
}
+ memset(&fcu->counts, 0, sizeof(fcu->counts));
+ funcid = fcinfo->flinfo->fn_oid;
+ oldcontext = MemoryContextSwitchTo(TopMemoryContext);
+
if (!pgStatFunctions)
{
/* First time through - initialize function stat table */
HASHCTL hash_ctl;
memset(&hash_ctl, 0, sizeof(hash_ctl));
- hash_ctl.keysize = sizeof(Oid);
+ hash_ctl.keysize = sizeof(key);
hash_ctl.entrysize = sizeof(PgStat_BackendFunctionEntry);
- hash_ctl.hash = oid_hash;
+ hash_ctl.hash = tag_hash;
pgStatFunctions = hash_create("Function stat entries",
PGSTAT_FUNCTION_HASH_SIZE,
&hash_ctl,
@@ -1406,21 +1577,45 @@ pgstat_init_function_usage(FunctionCallInfoData *fcinfo,
}
/* Get the stats entry for this function, create if necessary */
- htabent = hash_search(pgStatFunctions, &fcinfo->flinfo->fn_oid,
- HASH_ENTER, &found);
+ key.f_id = funcid;
+ key.f_parent = current_function_parent;
+ fcu->fs = hash_search(pgStatFunctions, &key, HASH_ENTER, &found);
+
if (!found)
- MemSet(&htabent->f_counts, 0, sizeof(PgStat_FunctionCounts));
+ {
+ Form_pg_proc functup;
+ HeapTuple tp;
- fcu->fs = &htabent->f_counts;
+ tp = SearchSysCache(PROCOID, ObjectIdGetDatum(funcid), 0, 0, 0);
+ if (!HeapTupleIsValid(tp))
+ ereport(ERROR,
+ (errcode(ERRCODE_UNDEFINED_OBJECT),
+ errmsg("function \"%u\" does not exist", funcid)));
+
+ functup = (Form_pg_proc) GETSTRUCT(tp);
+
+ memset(fcu->fs, 0, sizeof(*fcu->fs));
+ fcu->fs->f_key = key;
+ fcu->fs->f_name = pstrdup(NameStr(functup->proname));
+ fcu->fs->f_schema = get_namespace_name(functup->pronamespace);
+ fcu->fs->f_nargs = functup->pronargs;
+
+ ReleaseSysCache(tp);
+ }
+
+ /* Make this function the current */
+ current_function_parent = funcid;
/* save stats for this function, later used to compensate for recursion */
- fcu->save_f_time = htabent->f_counts.f_time;
+ fcu->save_counts = fcu->fs->counts;
/* save current backend-wide total time */
fcu->save_total = total_func_time;
/* get clock time as of function start */
INSTR_TIME_SET_CURRENT(fcu->f_start);
+
+ MemoryContextSwitchTo(oldcontext);
}
/*
@@ -1452,13 +1647,12 @@ find_funcstat_entry(Oid func_id)
void
pgstat_end_function_usage(PgStat_FunctionCallUsage *fcu, bool finalize)
{
- PgStat_FunctionCounts *fs = fcu->fs;
instr_time f_total;
instr_time f_others;
instr_time f_self;
/* stats not wanted? */
- if (fs == NULL)
+ if (fcu->fs == NULL)
return;
/* total elapsed time in this function call */
@@ -1481,13 +1675,17 @@ pgstat_end_function_usage(PgStat_FunctionCallUsage *fcu, bool finalize)
* similar kluge for self time, since that already excludes any recursive
* calls.)
*/
- INSTR_TIME_ADD(f_total, fcu->save_f_time);
+ INSTR_TIME_ADD(f_total, fcu->save_counts.f_time);
/* update counters in function stats table */
if (finalize)
- fs->f_numcalls++;
- fs->f_time = f_total;
- INSTR_TIME_ADD(fs->f_time_self, f_self);
+ fcu->fs->counts.f_numcalls++;
+
+ fcu->fs->counts.f_time = f_total;
+ INSTR_TIME_ADD(fcu->fs->counts.f_time_self, f_self);
+
+ /* restore the previous parent */
+ current_function_parent = fcu->fs->f_key.f_parent;
/* indicate that we have something to send */
have_function_stats = true;
@@ -1542,6 +1740,60 @@ pgstat_initstats(Relation rel)
}
/*
+ * new_tsa_entry - fill in PgStat_TableStatus structure.
+ */
+PgStat_TableStatus *
+new_tsa_entry(TabStatusArray *tsa, Oid rel_id, bool isshared)
+{
+ HeapTuple tp;
+ MemoryContext oldcontext;
+ Form_pg_class reltup;
+
+ PgStat_TableStatus *entry = &tsa->tsa_entries[tsa->tsa_used++];
+ entry->t_id = rel_id;
+ entry->t_shared = isshared;
+ entry->t_name = NULL;
+ entry->t_schema = NULL;
+ entry->t_relkind = ' ';
+
+ if (rel_id < FirstNormalObjectId)
+ {
+ /*
+ * Skip name lookups for system tables. As a sideeffect this also
+ * takes care of the cases where pgstat_initstats is called without
+ * a transaction (e.g. autovacuum launcher or pg_hba role check).
+ */
+ entry->t_system = TRUE;
+ return entry;
+ }
+
+ tp = SearchSysCache(RELOID, ObjectIdGetDatum(rel_id), 0, 0, 0);
+
+ if (!HeapTupleIsValid(tp))
+ ereport(ERROR,
+ (errcode(ERRCODE_UNDEFINED_OBJECT),
+ errmsg("relation \"%u\" does not exist", rel_id)));
+
+ oldcontext = MemoryContextSwitchTo(TopMemoryContext);
+ reltup = (Form_pg_class) GETSTRUCT(tp);
+
+ entry->t_name = pstrdup(NameStr(reltup->relname));
+ entry->t_relkind = reltup->relkind;
+
+ /* Additional check for system objects */
+ if (reltup->relnamespace == PG_CATALOG_NAMESPACE
+ || reltup->relnamespace == PG_TOAST_NAMESPACE)
+ entry->t_system = TRUE;
+ else
+ entry->t_schema = get_namespace_name(reltup->relnamespace);
+
+ MemoryContextSwitchTo(oldcontext);
+ ReleaseSysCache(tp);
+
+ return entry;
+}
+
+/*
* get_tabstat_entry - find or create a PgStat_TableStatus entry for rel
*/
static PgStat_TableStatus *
@@ -1572,10 +1824,7 @@ get_tabstat_entry(Oid rel_id, bool isshared)
* let's use this one. We assume the entry was already zeroed,
* either at creation or after last use.
*/
- entry = &tsa->tsa_entries[tsa->tsa_used++];
- entry->t_id = rel_id;
- entry->t_shared = isshared;
- return entry;
+ return new_tsa_entry(tsa, rel_id, isshared);
}
}
@@ -1589,13 +1838,7 @@ get_tabstat_entry(Oid rel_id, bool isshared)
else
pgStatTabList = tsa;
- /*
- * Use the first entry of the new TabStatusArray.
- */
- entry = &tsa->tsa_entries[tsa->tsa_used++];
- entry->t_id = rel_id;
- entry->t_shared = isshared;
- return entry;
+ return new_tsa_entry(tsa, rel_id, isshared);
}
/*
@@ -4349,18 +4592,18 @@ pgstat_recv_funcstat(PgStat_MsgFuncstat *msg, int len)
* If it's a new function entry, initialize counters to the values
* we just got.
*/
- funcentry->f_numcalls = funcmsg->f_numcalls;
- funcentry->f_time = funcmsg->f_time;
- funcentry->f_time_self = funcmsg->f_time_self;
+ funcentry->f_numcalls = funcmsg->f_counts.f_numcalls;
+ funcentry->f_time = funcmsg->f_counts.f_time;
+ funcentry->f_time_self = funcmsg->f_counts.f_time_self;
}
else
{
/*
* Otherwise add the values to the existing entry.
*/
- funcentry->f_numcalls += funcmsg->f_numcalls;
- funcentry->f_time += funcmsg->f_time;
- funcentry->f_time_self += funcmsg->f_time_self;
+ funcentry->f_numcalls += funcmsg->f_counts.f_numcalls;
+ INSTR_TIME_ADD(funcentry->f_time, funcmsg->f_counts.f_time);
+ INSTR_TIME_ADD(funcentry->f_time_self, funcmsg->f_counts.f_time_self);
}
}
}
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index a07661f..b7c102f 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -3783,6 +3783,11 @@ PostgresMain(int argc, char *argv[], const char *username)
debug_query_string = NULL;
/*
+ * Reset the current function parent.
+ */
+ current_function_parent = InvalidOid;
+
+ /*
* Abort the current transaction in order to recover.
*/
AbortCurrentTransaction();
diff --git a/src/backend/utils/adt/pgstatfuncs.c b/src/backend/utils/adt/pgstatfuncs.c
index f811245..a245a31 100644
--- a/src/backend/utils/adt/pgstatfuncs.c
+++ b/src/backend/utils/adt/pgstatfuncs.c
@@ -438,7 +438,7 @@ pg_stat_get_function_time(PG_FUNCTION_ARGS)
if ((funcentry = pgstat_fetch_stat_funcentry(funcid)) == NULL)
PG_RETURN_NULL();
- PG_RETURN_INT64(funcentry->f_time);
+ PG_RETURN_INT64(INSTR_TIME_GET_MICROSEC(funcentry->f_time));
}
Datum
@@ -449,7 +449,7 @@ pg_stat_get_function_self_time(PG_FUNCTION_ARGS)
if ((funcentry = pgstat_fetch_stat_funcentry(funcid)) == NULL)
PG_RETURN_NULL();
- PG_RETURN_INT64(funcentry->f_time_self);
+ PG_RETURN_INT64(INSTR_TIME_GET_MICROSEC(funcentry->f_time_self));
}
Datum
@@ -1487,7 +1487,7 @@ pg_stat_get_xact_function_calls(PG_FUNCTION_ARGS)
if ((funcentry = find_funcstat_entry(funcid)) == NULL)
PG_RETURN_NULL();
- PG_RETURN_INT64(funcentry->f_counts.f_numcalls);
+ PG_RETURN_INT64(funcentry->counts.f_numcalls);
}
Datum
@@ -1498,7 +1498,7 @@ pg_stat_get_xact_function_time(PG_FUNCTION_ARGS)
if ((funcentry = find_funcstat_entry(funcid)) == NULL)
PG_RETURN_NULL();
- PG_RETURN_INT64(INSTR_TIME_GET_MICROSEC(funcentry->f_counts.f_time));
+ PG_RETURN_INT64(INSTR_TIME_GET_MICROSEC(funcentry->counts.f_time));
}
Datum
@@ -1509,7 +1509,7 @@ pg_stat_get_xact_function_self_time(PG_FUNCTION_ARGS)
if ((funcentry = find_funcstat_entry(funcid)) == NULL)
PG_RETURN_NULL();
- PG_RETURN_INT64(INSTR_TIME_GET_MICROSEC(funcentry->f_counts.f_time_self));
+ PG_RETURN_INT64(INSTR_TIME_GET_MICROSEC(funcentry->counts.f_time_self));
}
diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c
index 92391ed..7f1dfea 100644
--- a/src/backend/utils/misc/guc.c
+++ b/src/backend/utils/misc/guc.c
@@ -412,6 +412,9 @@ bool log_statement_stats = false; /* this is sort of all three
* above together */
bool log_btree_build_stats = false;
+bool log_usage_stats = false;
+bool log_function_calls = false;
+
bool check_function_bodies = true;
bool default_with_oids = false;
bool SQL_inheritance = true;
@@ -976,6 +979,22 @@ static struct config_bool ConfigureNamesBool[] =
false,
check_log_stats, NULL, NULL
},
+ {
+ {"log_usage_stats", PGC_SUSET, STATS_MONITORING,
+ gettext_noop("Writes table and function access statistics to the server log."),
+ NULL
+ },
+ &log_usage_stats,
+ false, NULL, NULL
+ },
+ {
+ {"log_function_calls", PGC_SUSET, STATS_MONITORING,
+ gettext_noop("Writes top level function call stats to the server log."),
+ NULL
+ },
+ &log_function_calls,
+ false, NULL, NULL
+ },
#ifdef BTREE_BUILD_STATS
{
{"log_btree_build_stats", PGC_SUSET, DEVELOPER_OPTIONS,
diff --git a/src/include/pgstat.h b/src/include/pgstat.h
index f04be95..1eca1f2 100644
--- a/src/include/pgstat.h
+++ b/src/include/pgstat.h
@@ -134,6 +134,10 @@ typedef struct PgStat_TableStatus
{
Oid t_id; /* table's OID */
bool t_shared; /* is it a shared catalog? */
+ bool t_system; /* is it a system table? */
+ char t_relkind; /* table, index, ... */
+ char *t_schema;
+ char *t_name;
struct PgStat_TableXactStatus *trans; /* lowest subxact's counts */
PgStat_TableCounts t_counts; /* event counts to be sent */
} PgStat_TableStatus;
@@ -395,13 +399,35 @@ typedef struct PgStat_FunctionCounts
} PgStat_FunctionCounts;
/* ----------
- * PgStat_BackendFunctionEntry Entry in backend's per-function hash table
+ * PgStat_MsgFunctionEntry Per-function info in a stat message.
* ----------
*/
-typedef struct PgStat_BackendFunctionEntry
+typedef struct PgStat_MsgFunctionEntry
{
Oid f_id;
PgStat_FunctionCounts f_counts;
+} PgStat_MsgFunctionEntry;
+
+/* Hash key for the function stats */
+typedef struct FunctionStatKey
+{
+ Oid f_id;
+ Oid f_parent;
+} FunctionStatKey;
+
+/* ----------
+ * PgStat_BackendFunctionEntry Entry in backend's per-function hash table
+ * ----------
+ */
+typedef struct PgStat_BackendFunctionEntry
+{
+ FunctionStatKey f_key;
+ int f_nargs;
+ char *f_schema;
+ char *f_name;
+
+ PgStat_FunctionCounts counts;
+
} PgStat_BackendFunctionEntry;
/* ----------
@@ -411,9 +437,7 @@ typedef struct PgStat_BackendFunctionEntry
typedef struct PgStat_FunctionEntry
{
Oid f_id;
- PgStat_Counter f_numcalls;
- PgStat_Counter f_time; /* times in microseconds */
- PgStat_Counter f_time_self;
+ PgStat_FunctionCounts f_counts;
} PgStat_FunctionEntry;
/* ----------
@@ -566,8 +590,8 @@ typedef struct PgStat_StatFuncEntry
PgStat_Counter f_numcalls;
- PgStat_Counter f_time; /* times in microseconds */
- PgStat_Counter f_time_self;
+ instr_time f_time; /* times in microseconds */
+ instr_time f_time_self;
} PgStat_StatFuncEntry;
@@ -647,9 +671,9 @@ typedef struct PgStat_FunctionCallUsage
{
/* Link to function's hashtable entry (must still be there at exit!) */
/* NULL means we are not tracking the current function call */
- PgStat_FunctionCounts *fs;
- /* Total time previously charged to function, as of function start */
- instr_time save_f_time;
+ PgStat_BackendFunctionEntry *fs;
+ PgStat_FunctionCounts counts;
+ PgStat_FunctionCounts save_counts;
/* Backend-wide total time as of function start */
instr_time save_total;
/* system clock as of function start */
@@ -669,6 +693,11 @@ extern char *pgstat_stat_tmpname;
extern char *pgstat_stat_filename;
/*
+ * The current function call parent for dependency tracking.
+ */
+extern Oid current_function_parent;
+
+/*
* BgWriter statistics counters are updated directly by bgwriter and bufmgr
*/
extern PgStat_MsgBgWriter BgWriterStats;
diff --git a/src/include/utils/guc.h b/src/include/utils/guc.h
index ee52cd7..310ec08 100644
--- a/src/include/utils/guc.h
+++ b/src/include/utils/guc.h
@@ -198,6 +198,8 @@ extern bool log_planner_stats;
extern bool log_executor_stats;
extern bool log_statement_stats;
extern bool log_btree_build_stats;
+extern bool log_usage_stats;
+extern bool log_function_calls;
extern PGDLLIMPORT bool check_function_bodies;
extern bool default_with_oids;
--
Sent via pgsql-hackers mailing list ([email protected])
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
