stored procedure stats in collector - Mailing list pgsql-patches
| From | Martin Pihlak |
|---|---|
| Subject | stored procedure stats in collector |
| Date | |
| Msg-id | 47E69BD0.6070403@gmail.com Whole thread Raw |
| Responses |
Re: stored procedure stats in collector
|
| List | pgsql-patches |
Attached is a patch that enables tracking function calls through the stats subsystem. Original discussion: http://archives.postgresql.org/pgsql-hackers/2007-07/msg00377.php Introduces new guc variable - track_functions. Possible values are: none - no collection, default pl - tracks procedural language functions all - tracks procedural, SQL and C (not internal) functions The results are visible from pg_stat_get_function_* functions and pg_stat_user_functions view. regards, Martin *** ./doc/src/sgml/config.sgml.orig 2008-03-22 20:15:30.000000000 +0200 --- ./doc/src/sgml/config.sgml 2008-03-23 15:00:27.000000000 +0200 *************** *** 3322,3327 **** --- 3322,3343 ---- </listitem> </varlistentry> + <varlistentry id="guc-track-functions" xreflabel="track_functions"> + <term><varname>track_functions</varname> (<type>string</type>)</term> + <indexterm> + <primary><varname>track_functions</> configuration parameter</primary> + </indexterm> + <listitem> + <para> + Enables tracking of time and cpu usage of stored procedures. Specify + <literal>pl</literal> to count only procedural language functions, + <literal>all</literal> to also track SQL and C language functions. The + default is <literal>none</literal>. Only superusers can change this + setting. + </para> + </listitem> + </varlistentry> + <varlistentry id="guc-update-process-title" xreflabel="update_process_title"> <term><varname>update_process_title</varname> (<type>boolean</type>)</term> <indexterm> *** ./doc/src/sgml/monitoring.sgml.orig 2008-03-23 13:20:25.000000000 +0200 --- ./doc/src/sgml/monitoring.sgml 2008-03-23 14:55:28.000000000 +0200 *************** *** 151,156 **** --- 151,161 ---- </para> <para> + The parameter <xref linkend="guc-track-functions"> enables tracking of + stored procedure usage. + </para> + + <para> Normally these parameters are set in <filename>postgresql.conf</> so that they apply to all server processes, but it is possible to turn them on or off in individual sessions using the <xref *************** *** 370,375 **** --- 375,390 ---- <entry>Same as <structname>pg_statio_all_sequences</>, except that only user sequences are shown.</entry> </row> + + <row> + <entry><structname>pg_stat_user_functions</></entry> + <entry>For all called functions, function OID, schema, name, number + of calls, total time, total cpu, self time and cpu. Self time is the + amount of time spent in the function itself, total time includes the + time spent in child functions. Time values in milliseconds. + </entry> + </row> + </tbody> </tgroup> </table> *************** *** 655,660 **** --- 670,733 ---- </row> <row> + <entry><literal><function>pg_stat_get_function_calls</function>(<type>oid</type>)</literal></entry> + <entry><type>bigint</type></entry> + <entry> + Number of times the function has been called. + </entry> + </row> + + <row> + <entry><literal><function>pg_stat_get_function_rtime</function>(<type>oid</type>)</literal></entry> + <entry><type>bigint</type></entry> + <entry> + Total wall clock time spent in the function. In microseconds, includes + the time spent by child functions. + </entry> + </row> + + <row> + <entry><literal><function>pg_stat_get_function_stime</function>(<type>oid</type>)</literal></entry> + <entry><type>bigint</type></entry> + <entry> + Total system mode CPU time spent in the function. + </entry> + </row> + + <row> + <entry><literal><function>pg_stat_get_function_utime</function>(<type>oid</type>)</literal></entry> + <entry><type>bigint</type></entry> + <entry> + Total user mode CPU time spent in the function. + </entry> + </row> + + <row> + <entry><literal><function>pg_stat_get_function_self_rtime</function>(<type>oid</type>)</literal></entry> + <entry><type>bigint</type></entry> + <entry> + Time spent by only this function. Time spent in child functions + is excluded. + </entry> + </row> + + <row> + <entry><literal><function>pg_stat_get_function_self_stime</function>(<type>oid</type>)</literal></entry> + <entry><type>bigint</type></entry> + <entry> + System mode CPU spent by this function. + </entry> + </row> + + <row> + <entry><literal><function>pg_stat_get_function_self_utime</function>(<type>oid</type>)</literal></entry> + <entry><type>bigint</type></entry> + <entry> + User mode CPU spent by this function. + </entry> + </row> + + <row> <entry><literal><function>pg_stat_get_backend_idset</function>()</literal></entry> <entry><type>setof integer</type></entry> <entry> *** ./src/backend/catalog/system_views.sql.orig 2008-03-20 10:13:23.000000000 +0200 --- ./src/backend/catalog/system_views.sql 2008-03-22 16:27:38.000000000 +0200 *************** *** 376,381 **** --- 376,395 ---- pg_stat_get_db_tuples_deleted(D.oid) AS tup_deleted FROM pg_database D; + CREATE OR REPLACE VIEW pg_stat_user_functions AS + SELECT + P.oid AS funcid, + N.nspname AS schemaname, + P.proname AS funcname, + pg_stat_get_function_calls(P.oid) AS calls, + pg_stat_get_function_rtime(P.oid)/1000 AS total_time, + (pg_stat_get_function_utime(P.oid) + pg_stat_get_function_stime(P.oid)) /1000 AS total_cpu, + pg_stat_get_function_self_rtime(P.oid)/1000 AS self_time, + (pg_stat_get_function_self_utime(P.oid) + pg_stat_get_function_self_stime(P.oid)) /1000 AS self_cpu + FROM pg_proc P LEFT JOIN pg_namespace N ON (N.oid = P.pronamespace) + WHERE + pg_stat_get_function_calls(P.oid) IS NOT NULL; + CREATE VIEW pg_stat_bgwriter AS SELECT pg_stat_get_bgwriter_timed_checkpoints() AS checkpoints_timed, *** ./src/backend/commands/trigger.c.orig 2008-03-20 10:15:41.000000000 +0200 --- ./src/backend/commands/trigger.c 2008-03-23 18:42:39.000000000 +0200 *************** *** 13,18 **** --- 13,19 ---- */ #include "postgres.h" + #include "pgstat.h" #include "access/genam.h" #include "access/heapam.h" #include "access/xact.h" *************** *** 1541,1546 **** --- 1542,1548 ---- MemoryContext per_tuple_context) { FunctionCallInfoData fcinfo; + PgStat_FunctionCallUsage fcusage; Datum result; MemoryContext oldContext; *************** *** 1574,1580 **** --- 1576,1584 ---- */ InitFunctionCallInfoData(fcinfo, finfo, 0, (Node *) trigdata, NULL); + pgstat_init_function_usage(&fcinfo, &fcusage); result = FunctionCallInvoke(&fcinfo); + pgstat_update_function_usage(&fcusage, TRUE); MemoryContextSwitchTo(oldContext); *** ./src/backend/commands/vacuum.c.orig 2008-03-21 19:26:48.000000000 +0200 --- ./src/backend/commands/vacuum.c 2008-03-22 11:21:08.000000000 +0200 *************** *** 319,325 **** * in autovacuum --- autovacuum.c does this for itself. */ if (vacstmt->vacuum && !IsAutoVacuumWorkerProcess()) ! pgstat_vacuum_tabstat(); /* * Create special memory context for cross-transaction storage. --- 319,325 ---- * in autovacuum --- autovacuum.c does this for itself. */ if (vacstmt->vacuum && !IsAutoVacuumWorkerProcess()) ! pgstat_vacuum_stat(); /* * Create special memory context for cross-transaction storage. *** ./src/backend/executor/execQual.c.orig 2008-03-20 10:18:39.000000000 +0200 --- ./src/backend/executor/execQual.c 2008-03-23 18:43:00.000000000 +0200 *************** *** 36,41 **** --- 36,42 ---- #include "postgres.h" + #include "pgstat.h" #include "access/heapam.h" #include "access/nbtree.h" #include "catalog/pg_type.h" *************** *** 1148,1153 **** --- 1149,1155 ---- List *arguments = fcache->args; Datum result; FunctionCallInfoData fcinfo; + PgStat_FunctionCallUsage fcusage; ReturnSetInfo rsinfo; /* for functions returning sets */ ExprDoneCond argDone; bool hasSetArg; *************** *** 1206,1211 **** --- 1208,1215 ---- rsinfo.setDesc = NULL; } + pgstat_init_function_usage(&fcinfo, &fcusage); + /* * now return the value gotten by calling the function manager, passing * the function the evaluated parameter values. *************** *** 1316,1321 **** --- 1320,1326 ---- * argument. */ } + pgstat_update_function_usage(&fcusage, *isDone == ExprEndResult); } else { *************** *** 1350,1355 **** --- 1355,1361 ---- fcinfo.isnull = false; result = FunctionCallInvoke(&fcinfo); *isNull = fcinfo.isnull; + pgstat_update_function_usage(&fcusage, TRUE); } return result; *************** *** 1370,1375 **** --- 1376,1382 ---- ListCell *arg; Datum result; FunctionCallInfoData fcinfo; + PgStat_FunctionCallUsage fcusage; int i; /* Guard against stack overflow due to overly complex expressions */ *************** *** 1392,1397 **** --- 1399,1405 ---- } InitFunctionCallInfoData(fcinfo, &(fcache->func), i, NULL, NULL); + pgstat_init_function_usage(&fcinfo, &fcusage); /* * If function is strict, and there are any NULL arguments, skip calling *************** *** 1412,1417 **** --- 1420,1427 ---- result = FunctionCallInvoke(&fcinfo); *isNull = fcinfo.isnull; + pgstat_update_function_usage(&fcusage, TRUE); + return result; } *************** *** 1435,1440 **** --- 1445,1451 ---- bool returnsTuple; bool returnsSet = false; FunctionCallInfoData fcinfo; + PgStat_FunctionCallUsage fcusage; ReturnSetInfo rsinfo; HeapTupleData tmptup; MemoryContext callerContext; *************** *** 1535,1540 **** --- 1546,1553 ---- direct_function_call = false; } + pgstat_init_function_usage(&fcinfo, &fcusage); + /* * Switch to short-lived context for calling the function or expression. */ *************** *** 1685,1690 **** --- 1698,1705 ---- first_time = false; } + pgstat_update_function_usage(&fcusage, TRUE); + no_function_result: /* *** ./src/backend/postmaster/autovacuum.c.orig 2008-03-21 19:26:40.000000000 +0200 --- ./src/backend/postmaster/autovacuum.c 2008-03-22 11:21:24.000000000 +0200 *************** *** 1855,1861 **** * want to do this exactly once per DB-processing cycle, even if we find * nothing worth vacuuming in the database. */ ! pgstat_vacuum_tabstat(); /* * Find the pg_database entry and select the default freeze_min_age. We --- 1855,1861 ---- * want to do this exactly once per DB-processing cycle, even if we find * nothing worth vacuuming in the database. */ ! pgstat_vacuum_stat(); /* * Find the pg_database entry and select the default freeze_min_age. We *** ./src/backend/postmaster/pgstat.c.orig 2008-03-20 10:29:52.000000000 +0200 --- ./src/backend/postmaster/pgstat.c 2008-03-23 18:43:33.000000000 +0200 *************** *** 42,47 **** --- 42,48 ---- #include "access/twophase_rmgr.h" #include "access/xact.h" #include "catalog/pg_database.h" + #include "catalog/pg_proc.h" #include "libpq/ip.h" #include "libpq/libpq.h" #include "libpq/pqsignal.h" *************** *** 88,93 **** --- 89,95 ---- */ #define PGSTAT_DB_HASH_SIZE 16 #define PGSTAT_TAB_HASH_SIZE 512 + #define PGSTAT_FUNCTION_HASH_SIZE 512 /* ---------- *************** *** 96,101 **** --- 98,104 ---- */ bool pgstat_track_activities = false; bool pgstat_track_counts = false; + int pgstat_track_functions = 0; /* * BgWriter global statistics counters (unused in other processes). *************** *** 138,143 **** --- 141,150 ---- static TabStatusArray *pgStatTabList = NULL; + /* Function stat entries */ + HTAB *pgStatFunctions = NULL; + + /* * Tuple insertion/deletion counts for an open transaction can't be propagated * into PgStat_TableStatus counters until we know if it is going to commit *************** *** 184,189 **** --- 191,200 ---- static volatile bool need_exit = false; static volatile bool need_statwrite = false; + /* Helper variables for function self time calculations. */ + static uint64 total_stime = 0; + static uint64 total_utime = 0; + static uint64 total_rtime = 0; /* ---------- * Local function forward declarations *************** *** 205,210 **** --- 216,222 ---- 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 PgStat_TableStatus *get_tabstat_entry(Oid rel_id, bool isshared); *************** *** 216,221 **** --- 228,235 ---- static void pgstat_recv_tabstat(PgStat_MsgTabstat *msg, int len); static void pgstat_recv_tabpurge(PgStat_MsgTabpurge *msg, int len); + static void pgstat_recv_funcstat(PgStat_MsgFuncstat *msg, int len); + static void pgstat_recv_funcpurge(PgStat_MsgFuncpurge *msg, int len); static void pgstat_recv_dropdb(PgStat_MsgDropdb *msg, int len); static void pgstat_recv_resetcounter(PgStat_MsgResetcounter *msg, int len); static void pgstat_recv_autovac(PgStat_MsgAutovacStart *msg, int len); *************** *** 600,615 **** /* ---------- ! * pgstat_report_tabstat() - * * Called from tcop/postgres.c to send the so far collected per-table ! * access statistics to the collector. Note that this is called only ! * when not within a transaction, so it is fair to use transaction stop ! * time as an approximation of current time. * ---------- */ void ! pgstat_report_tabstat(bool force) { /* we assume this inits to all zeroes: */ static const PgStat_TableCounts all_zeroes; --- 614,629 ---- /* ---------- ! * pgstat_report_stat() - * * Called from tcop/postgres.c to send the so far collected per-table ! * and function access statistics to the collector. Note that this is ! * called only when not within a transaction, so it is fair to use ! * transaction stop time as an approximation of current time. * ---------- */ void ! pgstat_report_stat(bool force) { /* we assume this inits to all zeroes: */ static const PgStat_TableCounts all_zeroes; *************** *** 695,704 **** pgstat_send_tabstat(®ular_msg); if (shared_msg.m_nentries > 0) pgstat_send_tabstat(&shared_msg); } /* ! * Subroutine for pgstat_report_tabstat: finish and send a tabstat message */ static void pgstat_send_tabstat(PgStat_MsgTabstat *tsmsg) --- 709,721 ---- pgstat_send_tabstat(®ular_msg); if (shared_msg.m_nentries > 0) pgstat_send_tabstat(&shared_msg); + + /* Now, send the functions */ + pgstat_send_funcstats(); } /* ! * Subroutine for pgstat_report_stat: finish and send a tabstat message */ static void pgstat_send_tabstat(PgStat_MsgTabstat *tsmsg) *************** *** 735,755 **** pgstat_send(tsmsg, len); } /* ---------- ! * pgstat_vacuum_tabstat() - * * Will tell the collector about objects he can get rid of. * ---------- */ void ! pgstat_vacuum_tabstat(void) { HTAB *htab; PgStat_MsgTabpurge msg; HASH_SEQ_STATUS hstat; PgStat_StatDBEntry *dbentry; PgStat_StatTabEntry *tabentry; int len; if (pgStatSock < 0) --- 752,812 ---- pgstat_send(tsmsg, len); } + /* + * Subroutine for pgstat_report_stat: populate and send a function stat message. + */ + void + pgstat_send_funcstats(void) + { + PgStat_MsgFuncstat msg; + PgStat_FunctionEntry *entry; + HASH_SEQ_STATUS fstat; + + if (pgStatFunctions == NULL) + return; + + pgstat_setheader(&msg.m_hdr, PGSTAT_MTYPE_FUNCSTAT); + msg.m_databaseid = MyDatabaseId; + msg.m_nentries = 0; + + hash_seq_init(&fstat, pgStatFunctions); + while ((entry = (PgStat_FunctionEntry *)hash_seq_search(&fstat)) != NULL) + { + msg.m_entry[msg.m_nentries] = *entry; + + /* clear the entry, but retain Oid */ + memset(entry, 0, sizeof(PgStat_FunctionEntry)); + entry->f_id = msg.m_entry[msg.m_nentries].f_id; + + 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; + } + } + + if (msg.m_nentries > 0) + pgstat_send(&msg, offsetof(PgStat_MsgFuncstat, m_entry[0]) + + msg.m_nentries * sizeof(PgStat_FunctionEntry)); + } /* ---------- ! * pgstat_vacuum_stat() - * * Will tell the collector about objects he can get rid of. * ---------- */ void ! pgstat_vacuum_stat(void) { HTAB *htab; PgStat_MsgTabpurge msg; + PgStat_MsgFuncpurge f_msg; HASH_SEQ_STATUS hstat; PgStat_StatDBEntry *dbentry; PgStat_StatTabEntry *tabentry; + PgStat_StatFuncEntry *funcentry; int len; if (pgStatSock < 0) *************** *** 854,861 **** /* Clean up */ hash_destroy(htab); - } /* ---------- * pgstat_collect_oids() - --- 911,965 ---- /* Clean up */ hash_destroy(htab); + /* + * Done with the tables, now repeat the above steps for functions. + */ + htab = pgstat_collect_oids(ProcedureRelationId); + + pgstat_setheader(&f_msg.m_hdr, PGSTAT_MTYPE_FUNCPURGE); + f_msg.m_nentries = 0; + f_msg.m_databaseid = MyDatabaseId; + + /* + * Check for all functions listed in stats hashtable if they still exist. + */ + hash_seq_init(&hstat, dbentry->functions); + while ((funcentry = (PgStat_StatFuncEntry *) hash_seq_search(&hstat)) != NULL) + { + Oid funcid = funcentry->functionid; + + CHECK_FOR_INTERRUPTS(); + + if (hash_search(htab, (void *) &funcid, HASH_FIND, NULL) != NULL) + /* still exists, move on */ + continue; + + f_msg.m_functionid[f_msg.m_nentries++] = funcid; + + /* + * If the message is full, send it out and reinitialize to empty + */ + if (f_msg.m_nentries >= PGSTAT_NUM_TABPURGE) + { + len = offsetof(PgStat_MsgFuncpurge, m_functionid[0]) + +f_msg.m_nentries * sizeof(Oid); + + pgstat_send(&f_msg, len); + f_msg.m_nentries = 0; + } + } + + if (f_msg.m_nentries > 0) + { + len = offsetof(PgStat_MsgFuncpurge, m_functionid[0]) + +f_msg.m_nentries * sizeof(Oid); + + pgstat_send(&f_msg, len); + } + + hash_destroy(htab); + } /* ---------- * pgstat_collect_oids() - *************** *** 905,911 **** * * Tell the collector that we just dropped a database. * (If the message gets lost, we will still clean the dead DB eventually ! * via future invocations of pgstat_vacuum_tabstat().) * ---------- */ void --- 1009,1015 ---- * * Tell the collector that we just dropped a database. * (If the message gets lost, we will still clean the dead DB eventually ! * via future invocations of pgstat_vacuum_stat().) * ---------- */ void *************** *** 927,936 **** * * Tell the collector that we just dropped a relation. * (If the message gets lost, we will still clean the dead entry eventually ! * via future invocations of pgstat_vacuum_tabstat().) * * Currently not used for lack of any good place to call it; we rely ! * entirely on pgstat_vacuum_tabstat() to clean out stats for dead rels. * ---------- */ #ifdef NOT_USED --- 1031,1040 ---- * * Tell the collector that we just dropped a relation. * (If the message gets lost, we will still clean the dead entry eventually ! * via future invocations of pgstat_vacuum_stat().) * * Currently not used for lack of any good place to call it; we rely ! * entirely on pgstat_vacuum_stat() to clean out stats for dead rels. * ---------- */ #ifdef NOT_USED *************** *** 1073,1078 **** --- 1177,1294 ---- pgstat_send(&msg, sizeof(msg)); } + /* + * Initialize function call usage structures. Called by the executor before + * invoking a function. + */ + void + pgstat_init_function_usage(FunctionCallInfoData *fcinfo, PgStat_FunctionCallUsage *fcu) + { + HASHCTL hash_ctl; + bool found; + + fcu->fn_oid = InvalidOid; + + if (!pgstat_track_functions || !fcinfo->flinfo) { + /* We are not collecting or we don't have oid of the function (got rewritten?)*/ + return; + } + + if (!fcinfo->flinfo->fn_stats) { + /* stats not needed */ + return; + } + + gettimeofday(&fcu->t_start, NULL); + getrusage(RUSAGE_SELF, &fcu->r_start); + fcu->rtime_us = fcu->self_rtime = 0; + fcu->utime_us = fcu->self_utime = 0; + fcu->stime_us = fcu->self_stime = 0; + fcu->fn_oid = fcinfo->flinfo->fn_oid; + + if (!pgStatFunctions) { + /* First time - initialize function stat table */ + memset(&hash_ctl, 0, sizeof(hash_ctl)); + hash_ctl.keysize = sizeof(Oid); + hash_ctl.entrysize = sizeof(PgStat_FunctionEntry); + hash_ctl.hash = oid_hash; + pgStatFunctions = hash_create("Function stat entries", + PGSTAT_FUNCTION_HASH_SIZE, + &hash_ctl, + HASH_ELEM | HASH_FUNCTION ); + } + + /* get the stats entry for this function, create if necessary */ + fcu->fs = hash_search(pgStatFunctions, &fcu->fn_oid, HASH_ENTER, &found); + if (!found) { + memset(fcu->fs, 0, sizeof(PgStat_FunctionEntry)); + fcu->fs->f_id = fcu->fn_oid; + } + + /* save stats for this function, later used to compensate for recursion */ + fcu->save_fs = *fcu->fs; + + /* save totals for 'self' calculation */ + fcu->save_stime = total_stime; + fcu->save_utime = total_utime; + fcu->save_rtime = total_rtime; + } + + /* + * Calculate function call usage and update stat counters. Called by the + * executor when its done with the function. Might be called several times + * by set returning functions, last invocation should then have finalize + * set to TRUE. + */ + void + pgstat_update_function_usage(PgStat_FunctionCallUsage *fcu, bool finalize) + { + struct timeval t1; + struct rusage r1; + + if (!pgstat_track_functions || fcu->fn_oid == InvalidOid) + return; + + getrusage(RUSAGE_SELF, &r1); + gettimeofday(&t1, NULL); + + /* total elapsed */ + fcu->utime_us += r1.ru_utime.tv_sec*1000000 + r1.ru_utime.tv_usec - + (fcu->r_start.ru_utime.tv_sec*1000000 + fcu->r_start.ru_utime.tv_usec); + fcu->stime_us += r1.ru_stime.tv_sec*1000000 + r1.ru_stime.tv_usec - + (fcu->r_start.ru_stime.tv_sec*1000000 + fcu->r_start.ru_stime.tv_usec); + fcu->rtime_us += t1.tv_sec*1000000 + t1.tv_usec - + (fcu->t_start.tv_sec*1000000 + fcu->t_start.tv_usec); + + /* extract self usage */ + fcu->self_stime = (fcu->save_stime + fcu->stime_us) - total_stime; + fcu->self_utime = (fcu->save_utime + fcu->utime_us) - total_utime; + fcu->self_rtime = (fcu->save_rtime + fcu->rtime_us) - total_rtime; + + /* subtract recursive calls of myself */ + fcu->utime_us -= fcu->fs->f_utime - fcu->save_fs.f_utime; + fcu->stime_us -= fcu->fs->f_stime - fcu->save_fs.f_stime; + fcu->rtime_us -= fcu->fs->f_rtime - fcu->save_fs.f_rtime; + + elog(DEBUG5, "pgstat_update_function_usage: rtime start=%llu end=%llu\n", fcu->save_fs.f_rtime, fcu->fs->f_rtime); + + total_stime += fcu->self_stime; + total_utime += fcu->self_utime; + total_rtime += fcu->self_rtime; + + if (finalize) + pgstat_count_function_calls(fcu->fs); + + /* update the calculated values in function stats table */ + pgstat_count_function_rtime(fcu->fs, fcu->rtime_us, fcu->self_rtime); + pgstat_count_function_utime(fcu->fs, fcu->utime_us, fcu->self_utime); + pgstat_count_function_stime(fcu->fs, fcu->stime_us, fcu->self_stime); + + elog(DEBUG5, "pgstat_update_function_usage %u %s: real=%llu user=%llu sys=%llu us [self %llu %llu %llu us]", + fcu->fn_oid, finalize ? "final" : "contemporary", + fcu->rtime_us, fcu->utime_us, fcu->stime_us, + fcu->self_rtime, fcu->self_utime, fcu->self_stime); + } /* ---------- * pgstat_initstats() - *************** *** 1661,1666 **** --- 1877,1909 ---- return NULL; } + /* ---------- + * pgstat_fetch_stat_funcentry() - + * + * Support function for the SQL-callable pgstat* functions. Returns + * the collected statistics for one function or NULL. + * ---------- + */ + PgStat_StatFuncEntry * + pgstat_fetch_stat_funcentry(Oid func_id) + { + PgStat_StatDBEntry *dbentry; + PgStat_StatFuncEntry *funcentry = NULL; + + /* load the stats file if needed */ + backend_read_statsfile(); + + /* Lookup our database, then find the requested function. */ + dbentry = pgstat_fetch_stat_dbentry(MyDatabaseId); + if (dbentry != NULL && dbentry->functions != NULL) + { + funcentry = (PgStat_StatFuncEntry *) hash_search(dbentry->functions, + (void *) &func_id, + HASH_FIND, NULL); + } + + return funcentry; + } /* ---------- * pgstat_fetch_stat_beentry() - *************** *** 1861,1867 **** { volatile PgBackendStatus *beentry = MyBEEntry; ! pgstat_report_tabstat(true); /* * Clear my status entry, following the protocol of bumping st_changecount --- 2104,2110 ---- { volatile PgBackendStatus *beentry = MyBEEntry; ! pgstat_report_stat(true); /* * Clear my status entry, following the protocol of bumping st_changecount *************** *** 2343,2348 **** --- 2586,2599 ---- pgstat_recv_tabpurge((PgStat_MsgTabpurge *) &msg, len); break; + case PGSTAT_MTYPE_FUNCSTAT: + pgstat_recv_funcstat((PgStat_MsgFuncstat *) &msg, len); + break; + + case PGSTAT_MTYPE_FUNCPURGE: + pgstat_recv_funcpurge((PgStat_MsgFuncpurge *) &msg, len); + break; + case PGSTAT_MTYPE_DROPDB: pgstat_recv_dropdb((PgStat_MsgDropdb *) &msg, len); break; *************** *** 2446,2451 **** --- 2697,2703 ---- HASHCTL hash_ctl; result->tables = NULL; + result->functions = NULL; result->n_xact_commit = 0; result->n_xact_rollback = 0; result->n_blocks_fetched = 0; *************** *** 2465,2470 **** --- 2717,2728 ---- PGSTAT_TAB_HASH_SIZE, &hash_ctl, HASH_ELEM | HASH_FUNCTION); + + hash_ctl.entrysize = sizeof(PgStat_FunctionEntry); + result->functions = hash_create("Per-database function", + PGSTAT_TAB_HASH_SIZE, + &hash_ctl, + HASH_ELEM | HASH_FUNCTION); } return result; *************** *** 2482,2489 **** --- 2740,2749 ---- { HASH_SEQ_STATUS hstat; HASH_SEQ_STATUS tstat; + HASH_SEQ_STATUS fstat; PgStat_StatDBEntry *dbentry; PgStat_StatTabEntry *tabentry; + PgStat_StatFuncEntry *funcentry; FILE *fpout; int32 format_id; *************** *** 2536,2541 **** --- 2796,2814 ---- } /* + * Walk through the database's function stats table. + */ + hash_seq_init(&fstat, dbentry->functions); + while ((funcentry = (PgStat_StatFuncEntry *) hash_seq_search(&fstat)) != NULL) + { + if (funcentry->numcalls > 0) + { + fputc('F', fpout); + fwrite(funcentry, sizeof(PgStat_StatFuncEntry), 1, fpout); + } + } + + /* * Mark the end of this DB */ fputc('d', fpout); *************** *** 2590,2598 **** --- 2863,2874 ---- PgStat_StatDBEntry dbbuf; PgStat_StatTabEntry *tabentry; PgStat_StatTabEntry tabbuf; + PgStat_StatFuncEntry funcbuf; + PgStat_StatFuncEntry *funcentry; HASHCTL hash_ctl; HTAB *dbhash; HTAB *tabhash = NULL; + HTAB *funchash = NULL; FILE *fpin; int32 format_id; bool found; *************** *** 2686,2691 **** --- 2962,2968 ---- memcpy(dbentry, &dbbuf, sizeof(PgStat_StatDBEntry)); dbentry->tables = NULL; + dbentry->functions = NULL; /* * Don't collect tables if not the requested DB (or the *************** *** 2708,2718 **** --- 2985,3001 ---- &hash_ctl, HASH_ELEM | HASH_FUNCTION | HASH_CONTEXT); + hash_ctl.entrysize = sizeof(PgStat_FunctionEntry); + dbentry->functions = hash_create("Per-database function", + PGSTAT_FUNCTION_HASH_SIZE, + &hash_ctl, + HASH_ELEM | HASH_FUNCTION | HASH_CONTEXT); /* * Arrange that following 'T's add entries to this database's * tables hash table. */ tabhash = dbentry->tables; + funchash = dbentry->functions; break; /* *************** *** 2720,2725 **** --- 3003,3009 ---- */ case 'd': tabhash = NULL; + funchash = NULL; break; /* *************** *** 2755,2760 **** --- 3039,3076 ---- break; /* + * 'F' A PgStat_FunctionEntry follows + */ + case 'F': + if (fread(&funcbuf, 1, sizeof(PgStat_StatFuncEntry), + fpin) != sizeof(PgStat_StatFuncEntry)) + { + ereport(pgStatRunningInCollector ? LOG : WARNING, + (errmsg("corrupted pgstat.stat file"))); + goto done; + } + + /* + * Skip if table belongs to a not requested database. + */ + if (funchash == NULL) + break; + + funcentry = (PgStat_StatFuncEntry *) hash_search(funchash, + (void *) &funcbuf.functionid, + HASH_ENTER, &found); + + if (found) + { + ereport(pgStatRunningInCollector ? LOG : WARNING, + (errmsg("corrupted pgstat.stat file"))); + goto done; + } + + memcpy(funcentry, &funcbuf, sizeof(funcbuf)); + break; + + /* * 'E' The EOF marker of a complete stats file. */ case 'E': *************** *** 2962,2967 **** --- 3278,3367 ---- } } + /* ---------- + * pgstat_recv_funcstat() - + * + * Count what the backend has done. + * ---------- + */ + static void + pgstat_recv_funcstat(PgStat_MsgFuncstat *msg, int len) + { + PgStat_FunctionEntry *funcmsg = &(msg->m_entry[0]); + PgStat_StatDBEntry *dbentry; + PgStat_StatFuncEntry *funcentry; + int i; + bool found; + + dbentry = pgstat_get_db_entry(msg->m_databaseid, true); + + /* + * Process all function entries in the message. + */ + for (i = 0; i < msg->m_nentries; i++) + { + funcentry = (PgStat_StatFuncEntry *) hash_search(dbentry->functions, + (void *) &(funcmsg[i].f_id), + HASH_ENTER, &found); + + if (!found) + { + /* + * If it's a new function entry, initialize counters to the values we + * just got. + */ + funcentry->numcalls = funcmsg[i].f_numcalls; + funcentry->utime = funcmsg[i].f_utime; + funcentry->stime = funcmsg[i].f_stime; + funcentry->rtime = funcmsg[i].f_rtime; + funcentry->utime_self = funcmsg[i].f_utime_self; + funcentry->stime_self = funcmsg[i].f_stime_self; + funcentry->rtime_self = funcmsg[i].f_rtime_self; + } + else + { + /* + * Otherwise add the values to the existing entry. + */ + funcentry->numcalls += funcmsg[i].f_numcalls; + funcentry->utime += funcmsg[i].f_utime; + funcentry->stime += funcmsg[i].f_stime; + funcentry->rtime += funcmsg[i].f_rtime; + funcentry->utime_self += funcmsg[i].f_utime_self; + funcentry->stime_self += funcmsg[i].f_stime_self; + funcentry->rtime_self += funcmsg[i].f_rtime_self; + } + } + + } + + /* ---------- + * pgstat_recv_funcpurge() - + * + * Arrange for dead function removal. + * ---------- + */ + static void + pgstat_recv_funcpurge(PgStat_MsgFuncpurge *msg, int len) + { + PgStat_StatDBEntry *dbentry; + int i; + + dbentry = pgstat_get_db_entry(msg->m_databaseid, false); + + if (!dbentry || !dbentry->tables) + return; + + /* + * Process all function entries in the message. + */ + for (i = 0; i < msg->m_nentries; i++) + { + (void) hash_search(dbentry->functions, + (void *) &(msg->m_functionid[i]), + HASH_REMOVE, NULL); + } + } /* ---------- * pgstat_recv_dropdb() - *************** *** 2986,2991 **** --- 3386,3393 ---- { if (dbentry->tables != NULL) hash_destroy(dbentry->tables); + if (dbentry->functions != NULL) + hash_destroy(dbentry->functions); if (hash_search(pgStatDBHash, (void *) &(dbentry->databaseid), *************** *** 3023,3030 **** --- 3425,3435 ---- */ if (dbentry->tables != NULL) hash_destroy(dbentry->tables); + if (dbentry->functions != NULL) + hash_destroy(dbentry->functions); dbentry->tables = NULL; + dbentry->functions = NULL; dbentry->n_xact_commit = 0; dbentry->n_xact_rollback = 0; dbentry->n_blocks_fetched = 0; *************** *** 3038,3043 **** --- 3443,3454 ---- PGSTAT_TAB_HASH_SIZE, &hash_ctl, HASH_ELEM | HASH_FUNCTION); + + hash_ctl.entrysize = sizeof(PgStat_FunctionEntry); + dbentry->functions = hash_create("Per-database function", + PGSTAT_FUNCTION_HASH_SIZE, + &hash_ctl, + HASH_ELEM | HASH_FUNCTION); } /* ---------- *************** *** 3170,3172 **** --- 3581,3584 ---- globalStats.buf_written_backend += msg->m_buf_written_backend; globalStats.buf_alloc += msg->m_buf_alloc; } + *** ./src/backend/tcop/postgres.c.orig 2008-03-20 10:46:13.000000000 +0200 --- ./src/backend/tcop/postgres.c 2008-03-22 11:39:41.000000000 +0200 *************** *** 3488,3494 **** } else { ! pgstat_report_tabstat(false); set_ps_display("idle", false); pgstat_report_activity("<IDLE>"); --- 3488,3494 ---- } else { ! pgstat_report_stat(false); set_ps_display("idle", false); pgstat_report_activity("<IDLE>"); *** ./src/backend/utils/adt/pgstatfuncs.c.orig 2008-03-20 10:47:44.000000000 +0200 --- ./src/backend/utils/adt/pgstatfuncs.c 2008-03-20 10:51:10.000000000 +0200 *************** *** 38,43 **** --- 38,51 ---- extern Datum pg_stat_get_last_analyze_time(PG_FUNCTION_ARGS); extern Datum pg_stat_get_last_autoanalyze_time(PG_FUNCTION_ARGS); + extern Datum pg_stat_get_function_calls(PG_FUNCTION_ARGS); + extern Datum pg_stat_get_function_utime(PG_FUNCTION_ARGS); + extern Datum pg_stat_get_function_stime(PG_FUNCTION_ARGS); + extern Datum pg_stat_get_function_rtime(PG_FUNCTION_ARGS); + extern Datum pg_stat_get_function_self_utime(PG_FUNCTION_ARGS); + extern Datum pg_stat_get_function_self_stime(PG_FUNCTION_ARGS); + extern Datum pg_stat_get_function_self_rtime(PG_FUNCTION_ARGS); + extern Datum pg_stat_get_backend_idset(PG_FUNCTION_ARGS); extern Datum pg_backend_pid(PG_FUNCTION_ARGS); extern Datum pg_stat_get_backend_pid(PG_FUNCTION_ARGS); *************** *** 324,329 **** --- 332,420 ---- } Datum + pg_stat_get_function_calls(PG_FUNCTION_ARGS) + { + Oid funcid = PG_GETARG_OID(0); + PgStat_StatFuncEntry *funcentry; + + if ((funcentry = pgstat_fetch_stat_funcentry(funcid)) == NULL) + PG_RETURN_NULL(); + PG_RETURN_INT64(funcentry->numcalls); + } + + Datum + pg_stat_get_function_utime(PG_FUNCTION_ARGS) + { + Oid funcid = PG_GETARG_OID(0); + PgStat_StatFuncEntry *funcentry; + + if ((funcentry = pgstat_fetch_stat_funcentry(funcid)) == NULL) + PG_RETURN_NULL(); + + PG_RETURN_INT64(funcentry->utime); + } + + Datum + pg_stat_get_function_stime(PG_FUNCTION_ARGS) + { + Oid funcid = PG_GETARG_OID(0); + PgStat_StatFuncEntry *funcentry; + + if ((funcentry = pgstat_fetch_stat_funcentry(funcid)) == NULL) + PG_RETURN_NULL(); + + PG_RETURN_INT64(funcentry->stime); + } + + Datum + pg_stat_get_function_rtime(PG_FUNCTION_ARGS) + { + Oid funcid = PG_GETARG_OID(0); + PgStat_StatFuncEntry *funcentry; + + if ((funcentry = pgstat_fetch_stat_funcentry(funcid)) == NULL) + PG_RETURN_NULL(); + + PG_RETURN_INT64(funcentry->rtime); + } + + Datum + pg_stat_get_function_self_utime(PG_FUNCTION_ARGS) + { + Oid funcid = PG_GETARG_OID(0); + PgStat_StatFuncEntry *funcentry; + + if ((funcentry = pgstat_fetch_stat_funcentry(funcid)) == NULL) + PG_RETURN_NULL(); + + PG_RETURN_INT64(funcentry->utime_self); + } + + Datum + pg_stat_get_function_self_stime(PG_FUNCTION_ARGS) + { + Oid funcid = PG_GETARG_OID(0); + PgStat_StatFuncEntry *funcentry; + + if ((funcentry = pgstat_fetch_stat_funcentry(funcid)) == NULL) + PG_RETURN_NULL(); + + PG_RETURN_INT64(funcentry->stime_self); + } + + Datum + pg_stat_get_function_self_rtime(PG_FUNCTION_ARGS) + { + Oid funcid = PG_GETARG_OID(0); + PgStat_StatFuncEntry *funcentry; + + if ((funcentry = pgstat_fetch_stat_funcentry(funcid)) == NULL) + PG_RETURN_NULL(); + + PG_RETURN_INT64(funcentry->rtime_self); + } + + Datum pg_stat_get_backend_idset(PG_FUNCTION_ARGS) { FuncCallContext *funcctx; *** ./src/backend/utils/fmgr/fmgr.c.orig 2008-03-20 10:51:21.000000000 +0200 --- ./src/backend/utils/fmgr/fmgr.c 2008-03-22 19:38:04.000000000 +0200 *************** *** 27,32 **** --- 27,33 ---- #include "utils/guc.h" #include "utils/lsyscache.h" #include "utils/syscache.h" + #include "pgstat.h" /* *************** *** 189,194 **** --- 190,196 ---- finfo->fn_extra = NULL; finfo->fn_mcxt = mcxt; finfo->fn_expr = NULL; /* caller may set this later */ + finfo->fn_stats = false; if ((fbp = fmgr_isbuiltin(functionId)) != NULL) { *************** *** 215,220 **** --- 217,236 ---- finfo->fn_strict = procedureStruct->proisstrict; finfo->fn_retset = procedureStruct->proretset; + /* check if we need stats for the function */ + switch (procedureStruct->prolang) { + case INTERNALlanguageId: + finfo->fn_stats = false; + break; + case ClanguageId: + case SQLlanguageId: + finfo->fn_stats = (pgstat_track_functions == TRACK_FUNC_ALL); + break; + default: + finfo->fn_stats = (pgstat_track_functions != TRACK_FUNC_OFF); + break; + } + /* * If it has prosecdef set, or non-null proconfig, use * fmgr_security_definer call handler. *** ./src/backend/utils/misc/guc.c.orig 2008-03-20 10:54:29.000000000 +0200 --- ./src/backend/utils/misc/guc.c 2008-03-23 14:56:59.000000000 +0200 *************** *** 208,213 **** --- 208,220 ---- {NULL, 0} }; + static const struct config_enum_entry track_function_options [] = { + {"none", TRACK_FUNC_OFF}, + {"pl", TRACK_FUNC_PL}, + {"all", TRACK_FUNC_ALL}, + {NULL, 0} + }; + /* * GUC option variables that are exported from this module */ *************** *** 2488,2493 **** --- 2495,2508 ---- LOGSTMT_NONE, log_statement_options, NULL, NULL }, + { + {"track_functions", PGC_USERSET, STATS_COLLECTOR, + gettext_noop("Collects function-level statistics on database activity."), + gettext_noop("Valid values are: pl, all and none.") + }, + &pgstat_track_functions, + TRACK_FUNC_OFF, track_function_options, NULL, NULL + }, *** ./src/backend/utils/misc/postgresql.conf.sample.orig 2008-03-20 11:00:32.000000000 +0200 --- ./src/backend/utils/misc/postgresql.conf.sample 2008-03-23 14:57:25.000000000 +0200 *************** *** 362,367 **** --- 362,368 ---- #track_activities = on #track_counts = on + #track_functions = none # none, pl, all #update_process_title = on *** ./src/include/catalog/pg_proc.h.orig 2008-03-20 11:01:01.000000000 +0200 --- ./src/include/catalog/pg_proc.h 2008-03-20 15:21:34.000000000 +0200 *************** *** 2949,2954 **** --- 2949,2969 ---- DATA(insert OID = 2859 ( pg_stat_get_buf_alloc PGNSP PGUID 12 1 0 f f t f s 0 20 "" _null_ _null_ _null_ pg_stat_get_buf_alloc- _null_ _null_ )); DESCR("statistics: number of buffer allocations"); + DATA(insert OID = 2978 ( pg_stat_get_function_calls PGNSP PGUID 12 1 0 f f t f s 1 20 "26" _null_ _null_ _null_ pg_stat_get_function_calls- _null_ _null_ )); + DESCR("Statistics: Number of function calls"); + DATA(insert OID = 2979 ( pg_stat_get_function_utime PGNSP PGUID 12 1 0 f f t f s 1 20 "26" _null_ _null_ _null_ pg_stat_get_function_utime- _null_ _null_ )); + DESCR("Statistics: User mode cpu usage of function"); + DATA(insert OID = 2980 ( pg_stat_get_function_stime PGNSP PGUID 12 1 0 f f t f s 1 20 "26" _null_ _null_ _null_ pg_stat_get_function_stime- _null_ _null_ )); + DESCR("Statistics: System mode cpu usage of function"); + DATA(insert OID = 2981 ( pg_stat_get_function_rtime PGNSP PGUID 12 1 0 f f t f s 1 20 "26" _null_ _null_ _null_ pg_stat_get_function_rtime- _null_ _null_ )); + DESCR("Statistics: Execution time of function"); + DATA(insert OID = 2982 ( pg_stat_get_function_self_utime PGNSP PGUID 12 1 0 f f t f s 1 20 "26" _null_ _null_ _null_ pg_stat_get_function_self_utime- _null_ _null_ )); + DESCR("Statistics: Self user mode cpu usage of function"); + DATA(insert OID = 2983 ( pg_stat_get_function_self_stime PGNSP PGUID 12 1 0 f f t f s 1 20 "26" _null_ _null_ _null_ pg_stat_get_function_self_stime- _null_ _null_ )); + DESCR("Statistics: Self system mode cpu usage of function"); + DATA(insert OID = 2984 ( pg_stat_get_function_self_rtime PGNSP PGUID 12 1 0 f f t f s 1 20 "26" _null_ _null_ _null_ pg_stat_get_function_self_rtime- _null_ _null_ )); + DESCR("Statistics: Self execution time of function"); + DATA(insert OID = 2230 ( pg_stat_clear_snapshot PGNSP PGUID 12 1 0 f f f f v 0 2278 "" _null_ _null_ _null_ pg_stat_clear_snapshot - _null_ _null_ )); DESCR("statistics: discard current transaction's statistics snapshot"); DATA(insert OID = 2274 ( pg_stat_reset PGNSP PGUID 12 1 0 f f f f v 0 2278 "" _null_ _null_ _null_ pg_stat_reset - _null_ _null_ )); *** ./src/include/fmgr.h.orig 2008-03-20 11:05:48.000000000 +0200 --- ./src/include/fmgr.h 2008-03-20 11:06:20.000000000 +0200 *************** *** 50,55 **** --- 50,56 ---- bool fn_strict; /* function is "strict" (NULL in => NULL out) */ bool fn_retset; /* function returns a set */ void *fn_extra; /* extra space for use by handler */ + bool fn_stats; /* collect function call stats */ MemoryContext fn_mcxt; /* memory context to store fn_extra in */ fmNodePtr fn_expr; /* expression parse tree for call, or NULL */ } FmgrInfo; *** ./src/include/pgstat.h.orig 2008-03-20 11:06:43.000000000 +0200 --- ./src/include/pgstat.h 2008-03-23 18:44:09.000000000 +0200 *************** *** 16,21 **** --- 16,30 ---- #include "utils/rel.h" #include "utils/timestamp.h" + #ifdef HAVE_SYS_RESOURCE_H + #include <sys/time.h> + #include <sys/resource.h> + #endif + + #ifndef HAVE_GETRUSAGE + #include "rusagestub.h" + #endif + /* ---------- * The types of backend -> collector messages *************** *** 31,39 **** PGSTAT_MTYPE_AUTOVAC_START, PGSTAT_MTYPE_VACUUM, PGSTAT_MTYPE_ANALYZE, ! PGSTAT_MTYPE_BGWRITER } StatMsgType; /* ---------- * The data type used for counters. * ---------- --- 40,56 ---- PGSTAT_MTYPE_AUTOVAC_START, PGSTAT_MTYPE_VACUUM, PGSTAT_MTYPE_ANALYZE, ! PGSTAT_MTYPE_BGWRITER, ! PGSTAT_MTYPE_FUNCSTAT, ! PGSTAT_MTYPE_FUNCPURGE } StatMsgType; + typedef enum { + TRACK_FUNC_OFF, + TRACK_FUNC_PL, + TRACK_FUNC_ALL + } TrackFunctionsLevel; + /* ---------- * The data type used for counters. * ---------- *************** *** 173,178 **** --- 190,214 ---- } PgStat_TableEntry; /* ---------- + * PgStat_FunctionEntry Per-function info in a MsgFuncstat + * + */ + typedef struct PgStat_FunctionEntry + { + Oid f_id; + + PgStat_Counter f_numcalls; + + PgStat_Counter f_utime; + PgStat_Counter f_stime; + PgStat_Counter f_rtime; + + PgStat_Counter f_utime_self; + PgStat_Counter f_stime_self; + PgStat_Counter f_rtime_self; + } PgStat_FunctionEntry; + + /* ---------- * PgStat_MsgTabstat Sent by the backend to report table * and buffer access statistics. * ---------- *************** *** 211,216 **** --- 247,286 ---- /* ---------- + * PgStat_MsgFuncstat Sent by the backend to report function + * access statistics. + * ---------- + */ + #define PGSTAT_NUM_FUNCENTRIES \ + ((PGSTAT_MSG_PAYLOAD - sizeof(Oid) - 3 * sizeof(int)) \ + / sizeof(PgStat_FunctionEntry)) + + typedef struct PgStat_MsgFuncstat + { + PgStat_MsgHdr m_hdr; + Oid m_databaseid; + int m_nentries; + PgStat_FunctionEntry m_entry[PGSTAT_NUM_FUNCENTRIES]; + } PgStat_MsgFuncstat; + + /* ---------- + * PgStat_MsgFuncpurge Sent by the backend to tell the collector + * about dead functions. + * ---------- + */ + #define PGSTAT_NUM_FUNCPURGE \ + ((PGSTAT_MSG_PAYLOAD - sizeof(Oid) - sizeof(int)) \ + / sizeof(Oid)) + + typedef struct PgStat_MsgFuncpurge + { + PgStat_MsgHdr m_hdr; + Oid m_databaseid; + int m_nentries; + Oid m_functionid[PGSTAT_NUM_FUNCPURGE]; + } PgStat_MsgFuncpurge; + + /* ---------- * PgStat_MsgDropdb Sent by the backend to tell the collector * about a dropped database * ---------- *************** *** 309,314 **** --- 379,386 ---- PgStat_MsgDummy msg_dummy; PgStat_MsgTabstat msg_tabstat; PgStat_MsgTabpurge msg_tabpurge; + PgStat_MsgFuncstat msg_funcstat; + PgStat_MsgFuncpurge msg_funcpurge; PgStat_MsgDropdb msg_dropdb; PgStat_MsgResetcounter msg_resetcounter; PgStat_MsgAutovacStart msg_autovacuum; *************** *** 347,356 **** TimestampTz last_autovac_time; /* ! * tables must be last in the struct, because we don't write the pointer ! * out to the stats file. */ HTAB *tables; } PgStat_StatDBEntry; --- 419,429 ---- TimestampTz last_autovac_time; /* ! * tables and functions must be last in the struct, because we don't ! * write the pointer out to the stats file. */ HTAB *tables; + HTAB *functions; } PgStat_StatDBEntry; *************** *** 385,390 **** --- 458,481 ---- TimestampTz autovac_analyze_timestamp; /* autovacuum initiated */ } PgStat_StatTabEntry; + /* ---------- + * PgStat_StatFuncEntry The collector's data per function + * ---------- + */ + typedef struct PgStat_StatFuncEntry + { + Oid functionid; + + PgStat_Counter numcalls; + + PgStat_Counter utime; + PgStat_Counter stime; + PgStat_Counter rtime; + PgStat_Counter utime_self; + PgStat_Counter stime_self; + PgStat_Counter rtime_self; + } PgStat_StatFuncEntry ; + /* * Global statistics kept in the stats collector *************** *** 451,456 **** --- 542,568 ---- char st_activity[PGBE_ACTIVITY_SIZE]; } PgBackendStatus; + /* + * Function call cpu and time usage. + */ + typedef struct PgStat_FunctionCallUsage + { + Oid fn_oid; + struct rusage r_start; + struct timeval t_start; + uint64 rtime_us; + uint64 utime_us; + uint64 stime_us; + uint64 self_stime; + uint64 self_utime; + uint64 self_rtime; + PgStat_FunctionEntry *fs; + PgStat_FunctionEntry save_fs; + uint64 save_stime; + uint64 save_utime; + uint64 save_rtime; + } PgStat_FunctionCallUsage; + /* ---------- * GUC parameters *************** *** 458,463 **** --- 570,577 ---- */ extern bool pgstat_track_activities; extern bool pgstat_track_counts; + extern int pgstat_track_functions; + /* * BgWriter statistics counters are updated directly by bgwriter and bufmgr *************** *** 476,481 **** --- 590,601 ---- extern void pgstat_reset_all(void); extern void allow_immediate_pgstat_restart(void); + /* + * function call stats + */ + extern void pgstat_init_function_usage(FunctionCallInfoData *fcinfo, PgStat_FunctionCallUsage *fcu); + extern void pgstat_update_function_usage(PgStat_FunctionCallUsage *fcu, bool finalize); + #ifdef EXEC_BACKEND extern void PgstatCollectorMain(int argc, char *argv[]); #endif *************** *** 487,494 **** */ extern void pgstat_ping(void); ! extern void pgstat_report_tabstat(bool force); ! extern void pgstat_vacuum_tabstat(void); extern void pgstat_drop_database(Oid databaseid); extern void pgstat_clear_snapshot(void); --- 607,614 ---- */ extern void pgstat_ping(void); ! extern void pgstat_report_stat(bool force); ! extern void pgstat_vacuum_stat(void); extern void pgstat_drop_database(Oid databaseid); extern void pgstat_clear_snapshot(void); *************** *** 547,552 **** --- 667,698 ---- if (pgstat_track_counts && (rel)->pgstat_info != NULL) \ (rel)->pgstat_info->t_counts.t_blocks_hit++; \ } while (0) + #define pgstat_count_function_calls(s) \ + do { \ + if (pgstat_track_functions && s != NULL) \ + s->f_numcalls++; \ + } while (0) + #define pgstat_count_function_rtime(s, n, self) \ + do { \ + if (pgstat_track_functions && s != NULL) { \ + s->f_rtime += (n); \ + s->f_rtime_self += (self); \ + } \ + } while (0) + #define pgstat_count_function_utime(s, n, self) \ + do { \ + if (pgstat_track_functions && s != NULL) { \ + s->f_utime += (n); \ + s->f_utime_self += (self); \ + } \ + } while (0) + #define pgstat_count_function_stime(s, n, self) \ + do { \ + if (pgstat_track_functions && s != NULL) { \ + s->f_stime += (n); \ + s->f_stime_self += (self); \ + } \ + } while (0) extern void pgstat_count_heap_insert(Relation rel); extern void pgstat_count_heap_update(Relation rel, bool hot); *************** *** 574,579 **** --- 720,726 ---- extern PgStat_StatDBEntry *pgstat_fetch_stat_dbentry(Oid dbid); extern PgStat_StatTabEntry *pgstat_fetch_stat_tabentry(Oid relid); extern PgBackendStatus *pgstat_fetch_stat_beentry(int beid); + extern PgStat_StatFuncEntry *pgstat_fetch_stat_funcentry(Oid funcid); extern int pgstat_fetch_stat_numbackends(void); extern PgStat_GlobalStats *pgstat_fetch_global(void); *** ./src/test/regress/expected/rules.out.orig 2008-03-20 19:46:37.000000000 +0200 --- ./src/test/regress/expected/rules.out 2008-03-22 16:38:25.000000000 +0200 *************** *** 1296,1301 **** --- 1296,1302 ---- pg_stat_database | SELECT d.oid AS datid, d.datname, pg_stat_get_db_numbackends(d.oid) AS numbackends, pg_stat_get_db_xact_commit(d.oid)AS xact_commit, pg_stat_get_db_xact_rollback(d.oid) AS xact_rollback, (pg_stat_get_db_blocks_fetched(d.oid)- pg_stat_get_db_blocks_hit(d.oid)) AS blks_read, pg_stat_get_db_blocks_hit(d.oid) ASblks_hit, pg_stat_get_db_tuples_returned(d.oid) AS tup_returned, pg_stat_get_db_tuples_fetched(d.oid) AS tup_fetched, pg_stat_get_db_tuples_inserted(d.oid)AS tup_inserted, pg_stat_get_db_tuples_updated(d.oid) AS tup_updated, pg_stat_get_db_tuples_deleted(d.oid)AS tup_deleted FROM pg_database d; pg_stat_sys_indexes | SELECT pg_stat_all_indexes.relid, pg_stat_all_indexes.indexrelid, pg_stat_all_indexes.schemaname,pg_stat_all_indexes.relname, pg_stat_all_indexes.indexrelname, pg_stat_all_indexes.idx_scan,pg_stat_all_indexes.idx_tup_read, pg_stat_all_indexes.idx_tup_fetch FROM pg_stat_all_indexesWHERE ((pg_stat_all_indexes.schemaname = ANY (ARRAY['pg_catalog'::name, 'information_schema'::name]))OR (pg_stat_all_indexes.schemaname ~ '^pg_toast'::text)); pg_stat_sys_tables | SELECT pg_stat_all_tables.relid, pg_stat_all_tables.schemaname, pg_stat_all_tables.relname,pg_stat_all_tables.seq_scan, pg_stat_all_tables.seq_tup_read, pg_stat_all_tables.idx_scan, pg_stat_all_tables.idx_tup_fetch,pg_stat_all_tables.n_tup_ins, pg_stat_all_tables.n_tup_upd, pg_stat_all_tables.n_tup_del,pg_stat_all_tables.n_tup_hot_upd, pg_stat_all_tables.n_live_tup, pg_stat_all_tables.n_dead_tup,pg_stat_all_tables.last_vacuum, pg_stat_all_tables.last_autovacuum, pg_stat_all_tables.last_analyze,pg_stat_all_tables.last_autoanalyze FROM pg_stat_all_tables WHERE ((pg_stat_all_tables.schemaname= ANY (ARRAY['pg_catalog'::name, 'information_schema'::name])) OR (pg_stat_all_tables.schemaname~ '^pg_toast'::text)); + pg_stat_user_functions | SELECT p.oid AS funcid, n.nspname AS schemaname, p.proname AS funcname, pg_stat_get_function_calls(p.oid)AS calls, (pg_stat_get_function_rtime(p.oid) / 1000) AS total_time, ((pg_stat_get_function_utime(p.oid)+ pg_stat_get_function_stime(p.oid)) / 1000) AS total_cpu, (pg_stat_get_function_self_rtime(p.oid)/ 1000) AS self_time, ((pg_stat_get_function_self_utime(p.oid) + pg_stat_get_function_self_stime(p.oid))/ 1000) AS self_cpu FROM (pg_proc p LEFT JOIN pg_namespace n ON ((n.oid = p.pronamespace)))WHERE (pg_stat_get_function_calls(p.oid) IS NOT NULL); pg_stat_user_indexes | SELECT pg_stat_all_indexes.relid, pg_stat_all_indexes.indexrelid, pg_stat_all_indexes.schemaname,pg_stat_all_indexes.relname, pg_stat_all_indexes.indexrelname, pg_stat_all_indexes.idx_scan,pg_stat_all_indexes.idx_tup_read, pg_stat_all_indexes.idx_tup_fetch FROM pg_stat_all_indexesWHERE ((pg_stat_all_indexes.schemaname <> ALL (ARRAY['pg_catalog'::name, 'information_schema'::name]))AND (pg_stat_all_indexes.schemaname !~ '^pg_toast'::text)); pg_stat_user_tables | SELECT pg_stat_all_tables.relid, pg_stat_all_tables.schemaname, pg_stat_all_tables.relname,pg_stat_all_tables.seq_scan, pg_stat_all_tables.seq_tup_read, pg_stat_all_tables.idx_scan, pg_stat_all_tables.idx_tup_fetch,pg_stat_all_tables.n_tup_ins, pg_stat_all_tables.n_tup_upd, pg_stat_all_tables.n_tup_del,pg_stat_all_tables.n_tup_hot_upd, pg_stat_all_tables.n_live_tup, pg_stat_all_tables.n_dead_tup,pg_stat_all_tables.last_vacuum, pg_stat_all_tables.last_autovacuum, pg_stat_all_tables.last_analyze,pg_stat_all_tables.last_autoanalyze FROM pg_stat_all_tables WHERE ((pg_stat_all_tables.schemaname<> ALL (ARRAY['pg_catalog'::name, 'information_schema'::name])) AND (pg_stat_all_tables.schemaname!~ '^pg_toast'::text)); pg_statio_all_indexes | SELECT c.oid AS relid, i.oid AS indexrelid, n.nspname AS schemaname, c.relname, i.relname ASindexrelname, (pg_stat_get_blocks_fetched(i.oid) - pg_stat_get_blocks_hit(i.oid)) AS idx_blks_read, pg_stat_get_blocks_hit(i.oid)AS idx_blks_hit FROM (((pg_class c JOIN pg_index x ON ((c.oid = x.indrelid))) JOIN pg_classi ON ((i.oid = x.indexrelid))) LEFT JOIN pg_namespace n ON ((n.oid = c.relnamespace))) WHERE (c.relkind = ANY (ARRAY['r'::"char",'t'::"char"])); *************** *** 1327,1333 **** shoelace_obsolete | SELECT shoelace.sl_name, shoelace.sl_avail, shoelace.sl_color, shoelace.sl_len, shoelace.sl_unit,shoelace.sl_len_cm FROM shoelace WHERE (NOT (EXISTS (SELECT shoe.shoename FROM shoe WHERE (shoe.slcolor= shoelace.sl_color)))); street | SELECT r.name, r.thepath, c.cname FROM ONLY road r, real_city c WHERE (c.outline ## r.thepath); toyemp | SELECT emp.name, emp.age, emp.location, (12 * emp.salary) AS annualsal FROM emp; ! (49 rows) SELECT tablename, rulename, definition FROM pg_rules ORDER BY tablename, rulename; --- 1328,1334 ---- shoelace_obsolete | SELECT shoelace.sl_name, shoelace.sl_avail, shoelace.sl_color, shoelace.sl_len, shoelace.sl_unit,shoelace.sl_len_cm FROM shoelace WHERE (NOT (EXISTS (SELECT shoe.shoename FROM shoe WHERE (shoe.slcolor= shoelace.sl_color)))); street | SELECT r.name, r.thepath, c.cname FROM ONLY road r, real_city c WHERE (c.outline ## r.thepath); toyemp | SELECT emp.name, emp.age, emp.location, (12 * emp.salary) AS annualsal FROM emp; ! (50 rows) SELECT tablename, rulename, definition FROM pg_rules ORDER BY tablename, rulename;
pgsql-patches by date: