timing-events-v1.diff

text/plain

Filename: timing-events-v1.diff
Type: text/plain
Part: 0
Message: Timing events WIP v1

Patch

Same data as JSON: GET /api/v1/attachments/:id/patch the parsed metadata as JSON — format, series position, per-file stats; never the diff bytes. API reference →
Format: unified
Series: patch v1
File+
contrib/pg_timing_events/Makefile 18 0
contrib/pg_timing_events/pg_timing_events--1.0.sql 43 0
contrib/pg_timing_events/pg_timing_events.c 716 0
contrib/pg_timing_events/pg_timing_events.control 5 0
contrib/pg_timing_events/pg_timing_events--unpackaged--1.0.sql 8 0
src/backend/access/transam/xlog.c 27 0
src/backend/utils/error/elog.c 6 0
src/include/utils/timing_event.h 20 0
src/tools/pgindent/typedefs.list 1 0
diff --git a/contrib/pg_timing_events/Makefile b/contrib/pg_timing_events/Makefile
new file mode 100644
index 0000000..3e7f1ab
--- /dev/null
+++ b/contrib/pg_timing_events/Makefile
@@ -0,0 +1,18 @@
+# contrib/pg_timing_events/Makefile
+
+MODULE_big = pg_timing_events
+OBJS = pg_timing_events.o
+
+EXTENSION = pg_timing_events
+DATA = pg_timing_events--1.0.sql pg_timing_events--unpackaged--1.0.sql
+
+ifdef USE_PGXS
+PG_CONFIG = pg_config
+PGXS := $(shell $(PG_CONFIG) --pgxs)
+include $(PGXS)
+else
+subdir = contrib/pg_timing_events
+top_builddir = ../..
+include $(top_builddir)/src/Makefile.global
+include $(top_srcdir)/contrib/contrib-global.mk
+endif
diff --git a/contrib/pg_timing_events/pg_timing_events--1.0.sql b/contrib/pg_timing_events/pg_timing_events--1.0.sql
new file mode 100644
index 0000000..ccf6372
--- /dev/null
+++ b/contrib/pg_timing_events/pg_timing_events--1.0.sql
@@ -0,0 +1,43 @@
+/* contrib/pg_timing_events/pg_timing_events--1.0.sql */
+
+-- complain if script is sourced in psql, rather than via CREATE EXTENSION
+\echo Use "CREATE EXTENSION pg_timing_events" to load this file. \quit
+
+-- Register functions.
+CREATE FUNCTION pg_timing_events_reset()
+RETURNS void
+AS 'MODULE_PATHNAME'
+LANGUAGE C;
+
+CREATE FUNCTION pg_timing_events(
+	OUT seq int8,
+    OUT event text
+--    OUT occured timestamp
+
+--    OUT userid oid,
+--    OUT dbid oid,
+--    OUT query text,
+--    OUT calls int8,
+--    OUT total_time float8,
+--    OUT rows int8,
+--    OUT shared_blks_hit int8,
+--    OUT shared_blks_read int8,
+--    OUT shared_blks_written int8,
+--    OUT local_blks_hit int8,
+--    OUT local_blks_read int8,
+--    OUT local_blks_written int8,
+--    OUT temp_blks_read int8,
+--    OUT temp_blks_written int8
+)
+RETURNS SETOF record
+AS 'MODULE_PATHNAME'
+LANGUAGE C;
+
+-- Register a view on the function for ease of use.
+CREATE VIEW pg_timing_events AS
+  SELECT * FROM pg_timing_events();
+
+GRANT SELECT ON pg_timing_events TO PUBLIC;
+
+-- Don't want this to be available to non-superusers.
+REVOKE ALL ON FUNCTION pg_timing_events_reset() FROM PUBLIC;
diff --git a/contrib/pg_timing_events/pg_timing_events--unpackaged--1.0.sql b/contrib/pg_timing_events/pg_timing_events--unpackaged--1.0.sql
new file mode 100644
index 0000000..0c9b1d8
--- /dev/null
+++ b/contrib/pg_timing_events/pg_timing_events--unpackaged--1.0.sql
@@ -0,0 +1,8 @@
+/* contrib/pg_timing_events/pg_timing_events--unpackaged--1.0.sql */
+
+-- complain if script is sourced in psql, rather than via CREATE EXTENSION
+\echo Use "CREATE EXTENSION pg_timing_events" to load this file. \quit
+
+ALTER EXTENSION pg_timing_events ADD function pg_timing_events_reset();
+ALTER EXTENSION pg_timing_events ADD function pg_timing_events();
+ALTER EXTENSION pg_timing_events ADD view pg_timing_events;
diff --git a/contrib/pg_timing_events/pg_timing_events.c b/contrib/pg_timing_events/pg_timing_events.c
new file mode 100644
index 0000000..d7558e6
--- /dev/null
+++ b/contrib/pg_timing_events/pg_timing_events.c
@@ -0,0 +1,716 @@
+/*-------------------------------------------------------------------------
+ *
+ * pg_timing_events.c
+ *		Track statement execution times across a whole database cluster.
+ *
+ * Note about locking issues: to create or delete an entry in the shared
+ * hashtable, one must hold pgte->lock exclusively.  Modifying any field
+ * in an entry requires the same.  To look up an entry, one must hold
+ * the lock shared.
+ *
+ * Portions copyright (c) 2012, Salesforce.com
+ * Portions copyright (c) 2008-2012, PostgreSQL Global Development Group
+ *
+ * IDENTIFICATION
+ *	  contrib/pg_timing_events/pg_timing_events.c
+ *
+ *-------------------------------------------------------------------------
+ */
+#include "postgres.h"
+
+#include <unistd.h>
+
+#include "access/hash.h"
+#include "catalog/pg_type.h"
+#include "executor/executor.h"
+#include "executor/instrument.h"
+#include "funcapi.h"
+#include "mb/pg_wchar.h"
+#include "miscadmin.h"
+#include "pgstat.h"
+#include "storage/fd.h"
+#include "storage/ipc.h"
+#include "storage/spin.h"
+#include "tcop/utility.h"
+#include "utils/builtins.h"
+#include "utils/hsearch.h"
+#include "utils/guc.h"
+#include "utils/memutils.h"
+#include "utils/timing_event.h"
+
+
+PG_MODULE_MAGIC;
+
+/* Location of stats file */
+#define PGTE_DUMP_FILE	"global/pg_timing_events.stat"
+
+/* This constant defines the magic number in the stats file header */
+static const uint32 PGTE_FILE_HEADER = 0x20100108;
+
+/*
+ * Statistics per statement
+ *
+ * NB: see the file read/write code before changing field order here.
+ */
+typedef struct pgteEntry
+{
+	/* TODO Remove key - it's just to cut down on compiler errors while refactoring to eliminate */
+	int key;  
+
+	Timestamp	entry_time;
+	char	*description;
+	int 		serial_num;
+
+	/* Old entries just to use as examples */
+	Oid			userid;			/* user OID */
+	Oid			dbid;			/* database OID */
+	int			encoding;		/* query encoding */
+	int			query_len;		/* # of valid bytes in query string */
+	const char *query_ptr;		/* query string proper */
+
+	slock_t		mutex;			/* protects the counters only */
+	char		query[1];		/* VARIABLE LENGTH ARRAY - MUST BE LAST */
+	/* Note: the allocated length of query[] is actually pgte->query_size */
+} pgteEntry;
+
+/*
+ * Global shared state
+ */
+typedef struct pgteSharedState
+{
+	LWLockId	lock;			/* protects queue lookup/modification */
+	int 		serial_num;
+	int			front;
+	unsigned char full;			/* really a boolean */
+	char		last_query[1024];
+	int			queue_size;
+	int			query_size;		/* max query length in bytes */
+} pgteSharedState;
+
+/*---- Local variables ----*/
+
+/* Saved hook values in case of unload */
+static shmem_startup_hook_type prev_shmem_startup_hook = NULL;
+static timing_event_hook_type prev_timing_event_hook = NULL;
+
+/* Links to shared memory state */
+static pgteSharedState *pgte = NULL;
+static pgteEntry *PGTE_queue = NULL;
+
+/*---- GUC variables ----*/
+
+static int	PGTE_max;			/* max # statements to track */
+static int	PGTE_track = 1;			/* tracking level */
+static bool PGTE_save;			/* whether to save stats across shutdown */
+
+
+/* TODO Add another GUC for disabling collection */
+#define PGTE_enabled() \
+	(PGTE_track == 1 )
+
+/*---- Function declarations ----*/
+
+void		_PG_init(void);
+void		_PG_fini(void);
+
+Datum		pg_timing_events_reset(PG_FUNCTION_ARGS);
+Datum		pg_timing_events(PG_FUNCTION_ARGS);
+
+PG_FUNCTION_INFO_V1(pg_timing_events_reset);
+PG_FUNCTION_INFO_V1(pg_timing_events);
+
+static void PGTE_shmem_startup(void);
+static void PGTE_shmem_shutdown(int code, Datum arg);
+static void PGTE_timing_event(const char *desc);
+static void PGTE_store(const char *query);
+static Size PGTE_memsize(void);
+static void entry_reset(void);
+
+
+/*
+ * Module load callback
+ */
+void
+_PG_init(void)
+{
+	/*
+	 * In order to create our shared memory area, we have to be loaded via
+	 * shared_preload_libraries.  If not, fall out without hooking into any of
+	 * the main system.  (We don't throw error here because it seems useful to
+	 * allow the pg_timing_events functions to be created even when the
+	 * module isn't active.  The functions must protect themselves against
+	 * being called then, however.)
+	 */
+	if (!process_shared_preload_libraries_in_progress)
+		return;
+
+	/*
+	 * Define (or redefine) custom GUC variables.
+	 */
+	DefineCustomIntVariable("pg_timing_events.max",
+	  "Sets the maximum number of events tracked by pg_timing_events.",
+							NULL,
+							&PGTE_max,
+							1000,
+							100,
+							INT_MAX,
+							PGC_POSTMASTER,
+							0,
+							NULL,
+							NULL,
+							NULL);
+
+	DefineCustomBoolVariable("pg_timing_events.save",
+			   "Save pg_timing_events statistics across server shutdowns.",
+							 NULL,
+							 &PGTE_save,
+							 true,
+							 PGC_SIGHUP,
+							 0,
+							 NULL,
+							 NULL,
+							 NULL);
+
+	EmitWarningsOnPlaceholders("pg_timing_events");
+
+	/*
+	 * Request additional shared resources.  (These are no-ops if we're not in
+	 * the postmaster process.)  We'll allocate or attach to the shared
+	 * resources in PGTE_shmem_startup().
+	 */
+	RequestAddinShmemSpace(PGTE_memsize());
+	RequestAddinLWLocks(1);
+
+	/*
+	 * Install hooks.
+	 */
+	prev_shmem_startup_hook = shmem_startup_hook;
+	shmem_startup_hook = PGTE_shmem_startup;
+
+	prev_timing_event_hook = timing_event_hook;
+	timing_event_hook = PGTE_timing_event;
+}
+
+/*
+ * Module unload callback
+ */
+void
+_PG_fini(void)
+{
+	/* Uninstall hooks. */
+	shmem_startup_hook = prev_shmem_startup_hook;
+	timing_event_hook = prev_timing_event_hook;
+
+}
+
+/*
+ * shmem_startup hook: allocate or attach to shared memory,
+ * then load any pre-existing statistics from file.
+ */
+static void
+PGTE_shmem_startup(void)
+{
+	bool		found;
+	FILE	   *file;
+	uint32		header;
+	int32		num;
+	int32		i;
+	int			query_size;
+	int			buffer_size;
+	char	   *buffer = NULL;
+
+	if (prev_shmem_startup_hook)
+		prev_shmem_startup_hook();
+
+	/* reset in case this is a restart within the postmaster */
+	pgte = NULL;
+
+	/*
+	 * Create or attach to the shared memory state, including hash table
+	 */
+	LWLockAcquire(AddinShmemInitLock, LW_EXCLUSIVE);
+
+	pgte = (pgteSharedState *) ShmemInitStruct("pg_timing_events",
+						   sizeof(pgteSharedState),
+						   &found);
+
+	if (!found)
+	{
+		/* First time through ... */
+		pgte->lock = LWLockAssign();
+		pgte->query_size = pgstat_track_activity_query_size;
+		pgte->front = -1;
+		pgte->full = 0;
+	}
+
+	/* Be sure everyone agrees on the table entry sizes */
+	query_size = pgte->query_size;
+	pgte->queue_size = PGTE_max;
+
+    PGTE_queue = (pgteEntry *)
+                    ShmemInitStruct("Timing Event Queue",
+                			PGTE_max * (Size) sizeof(pgteEntry *), &found);
+	if (!found)
+	{
+		/*
+		 * TODO If the queue logic is right, there should be no need
+		 * to initialize any of its elements here?
+		 */
+	}
+
+	LWLockRelease(AddinShmemInitLock);
+
+	/*
+	 * If we're in the postmaster (or a standalone backend...), set up a shmem
+	 * exit hook to dump the statistics to disk.
+	 */
+	if (!IsUnderPostmaster)
+		on_shmem_exit(PGTE_shmem_shutdown, (Datum) 0);
+
+	/*
+	 * Attempt to load old statistics from the dump file, if this is the first
+	 * time through and we weren't told not to.
+	 */
+	if (found || !PGTE_save)
+		return;
+
+	/*
+	 * TODO Below is the old pg_stat_statements reading code, but since we've
+	 * disabled writes we should never find a file to read yet for it to break
+	 * on.  Return anyway just to be safe.
+	 */
+	return;
+
+	/*
+	 * Note: we don't bother with locks here, because there should be no other
+	 * processes running when this code is reached.
+	 */
+	file = AllocateFile(PGTE_DUMP_FILE, PG_BINARY_R);
+	if (file == NULL)
+	{
+		if (errno == ENOENT)
+			return;				/* ignore not-found error */
+		goto error;
+	}
+
+	buffer_size = query_size;
+	buffer = (char *) palloc(buffer_size);
+
+	if (fread(&header, sizeof(uint32), 1, file) != 1 ||
+		header != PGTE_FILE_HEADER ||
+		fread(&num, sizeof(int32), 1, file) != 1)
+		goto error;
+
+	for (i = 0; i < num; i++)
+	{
+		pgteEntry	temp;
+/*
+		pgteEntry  *entry;
+*/
+		if (fread(&temp, offsetof(pgteEntry, mutex), 1, file) != 1)
+			goto error;
+
+		/* Encoding is the only field we can easily sanity-check */
+/*
+		if (!PG_VALID_BE_ENCODING(temp.key.encoding))
+			goto error;
+*/
+		/* Previous incarnation might have had a larger query_size */
+/*
+		if (temp.key.query_len >= buffer_size)
+		{
+			buffer = (char *) repalloc(buffer, temp.key.query_len + 1);
+			buffer_size = temp.key.query_len + 1;
+		}
+
+		if (fread(buffer, 1, temp.key.query_len, file) != temp.key.query_len)
+			goto error;
+		buffer[temp.key.query_len] = '\0';
+*/
+		/* Clip to available length if needed */
+/*
+		if (temp.key.query_len >= query_size)
+			temp.key.query_len = pg_encoding_mbcliplen(temp.key.encoding,
+													   buffer,
+													   temp.key.query_len,
+													   query_size - 1);
+		temp.key.query_ptr = buffer;
+*/
+		/* make the hashtable entry (discards old entries if too many) */
+/*
+		entry = entry_alloc(&temp);
+*/
+	}
+
+	pfree(buffer);
+	FreeFile(file);
+
+	/*
+	 * Remove the file so it's not included in backups/replication
+	 * slaves, etc. A new file will be written on next shutdown.
+	 */
+	unlink(PGTE_DUMP_FILE);
+
+	return;
+
+error:
+	ereport(LOG,
+			(errcode_for_file_access(),
+			 errmsg("could not read pg_stat_statement file \"%s\": %m",
+					PGTE_DUMP_FILE)));
+	if (buffer)
+		pfree(buffer);
+	if (file)
+		FreeFile(file);
+	/* If possible, throw away the bogus file; ignore any error */
+	unlink(PGTE_DUMP_FILE);
+}
+
+/*
+ * shmem_shutdown hook: Dump statistics into file.
+ *
+ * Note: we don't bother with acquiring lock, because there should be no
+ * other processes running when this is called.
+ */
+static void
+PGTE_shmem_shutdown(int code, Datum arg)
+{
+	FILE	   *file;
+
+/*
+	TODO Don't need to store state until code is rewritten
+	HASH_SEQ_STATUS hash_seq;
+	int32		num_entries;
+	pgteEntry  *entry;
+*/
+
+	/* Don't try to dump during a crash. */
+	if (code)
+		return;
+
+	/* Safety check ... shouldn't get here unless shmem is set up. */
+	if (!pgte || !PGTE_queue)
+		return;
+
+	/* Don't dump if told not to. */
+	if (!PGTE_save)
+		return;
+
+	/* TODO Cannot execute the below until it's corrected to write queue entries */
+	return;
+
+	file = AllocateFile(PGTE_DUMP_FILE ".tmp", PG_BINARY_W);
+	if (file == NULL)
+		goto error;
+
+	if (fwrite(&PGTE_FILE_HEADER, sizeof(uint32), 1, file) != 1)
+		goto error;
+
+/* TODO Replace with a queue iterator
+	num_entries = queue_get_num_entries(pgteSharedState);
+	if (fwrite(&num_entries, sizeof(int32), 1, file) != 1)
+		goto error;
+*/
+
+/*
+	hash_seq_init(&hash_seq, PGTE_hash);
+	while ((entry = hash_seq_search(&hash_seq)) != NULL)
+	{
+		int			len = entry->key.query_len;
+
+		if (fwrite(entry, offsetof(pgteEntry, mutex), 1, file) != 1 ||
+			fwrite(entry->query, 1, len, file) != len)
+			goto error;
+	}
+*/
+
+	if (FreeFile(file))
+	{
+		file = NULL;
+		goto error;
+	}
+
+	/*
+	 * Rename file into place, so we atomically replace the old one.
+	 */
+	if (rename(PGTE_DUMP_FILE ".tmp", PGTE_DUMP_FILE) != 0)
+		ereport(LOG,
+				(errcode_for_file_access(),
+				 errmsg("could not rename pg_stat_statement file \"%s\": %m",
+						PGTE_DUMP_FILE ".tmp")));
+
+	return;
+
+error:
+	ereport(LOG,
+			(errcode_for_file_access(),
+			 errmsg("could not write pg_stat_statement file \"%s\": %m",
+					PGTE_DUMP_FILE  ".tmp")));
+	if (file)
+		FreeFile(file);
+	unlink(PGTE_DUMP_FILE ".tmp");
+}
+
+/*
+ * Timing event hook: save the event
+ */
+static void
+PGTE_timing_event(const char *desc)
+{
+	if (PGTE_enabled())
+	{
+		PGTE_store(desc);
+	}
+}
+
+/*
+ * Store some statistics for a statement.
+ */
+static void
+PGTE_store(const char *query)
+{
+	Assert(query != NULL);
+
+	/* Safety check... */
+	if (!pgte || !PGTE_queue)
+		return;
+
+	/* Must acquire exclusive lock to add a new entry. */
+	LWLockAcquire(pgte->lock, LW_EXCLUSIVE);
+
+	pgte->front++;
+	if (pgte->front == PGTE_max)
+	{
+		pgte->front = 0;
+		/*
+		 * Noting that queue has filled is rundant but harmless on passes after
+		 * the first time it happens.
+		 */
+		pgte->full = 1;
+	}
+
+	/*  Using a plain strdup here results in junk events from the background writer */
+	PGTE_queue[pgte->front].description=MemoryContextStrdup(TopMemoryContext, query);
+	PGTE_queue[pgte->front].serial_num=pgte->serial_num;
+	pgte->serial_num++;
+
+	/*
+	 * TODO Cheat and save a copy in a static buffer.  This must be removed once the
+	 * memory is correctly moved to the output via the MemoryContextStrdup above
+	 * (or its replacement)
+	 */
+	strncpy(pgte->last_query,query,1023);
+
+	/* TODO Examples of how to grab some state data we'll need to add later
+	key.userid = GetUserId();
+	key.dbid = MyDatabaseId;
+	key.encoding = GetDatabaseEncoding();
+	key.query_len = strlen(query);
+	if (key.query_len >= pgte->query_size)
+		key.query_len = pg_encoding_mbcliplen(key.encoding,
+											  query,
+											  key.query_len,
+											  pgte->query_size - 1);
+	key.query_ptr = query;
+    */
+
+	LWLockRelease(pgte->lock);
+}
+
+/*
+ * Reset all statement statistics.
+ */
+Datum
+pg_timing_events_reset(PG_FUNCTION_ARGS)
+{
+	if (!pgte || !PGTE_queue)
+		ereport(ERROR,
+				(errcode(ERRCODE_OBJECT_NOT_IN_PREREQUISITE_STATE),
+				 errmsg("pg_timing_events must be loaded via shared_preload_libraries")));
+	entry_reset();
+	PG_RETURN_VOID();
+}
+
+#define pg_timing_events_COLS		2
+
+/*
+ * Retrieve statement statistics.
+ */
+Datum
+pg_timing_events(PG_FUNCTION_ARGS)
+{
+	ReturnSetInfo *rsinfo = (ReturnSetInfo *) fcinfo->resultinfo;
+	TupleDesc	tupdesc;
+	Tuplestorestate *tupstore;
+	MemoryContext per_query_ctx;
+	MemoryContext oldcontext;
+	/*
+	Oid			userid = GetUserId();
+	bool		is_superuser = superuser();
+	*/
+	int			count;
+	int			position;
+	int			offset;
+
+	if (!pgte || !PGTE_queue)
+		ereport(ERROR,
+				(errcode(ERRCODE_OBJECT_NOT_IN_PREREQUISITE_STATE),
+				 errmsg("pg_timing_events must be loaded via shared_preload_libraries")));
+
+	/* check to see if caller supports us returning a tuplestore */
+	if (rsinfo == NULL || !IsA(rsinfo, ReturnSetInfo))
+		ereport(ERROR,
+				(errcode(ERRCODE_FEATURE_NOT_SUPPORTED),
+				 errmsg("set-valued function called in context that cannot accept a set")));
+	if (!(rsinfo->allowedModes & SFRM_Materialize))
+		ereport(ERROR,
+				(errcode(ERRCODE_FEATURE_NOT_SUPPORTED),
+				 errmsg("materialize mode required, but it is not " \
+						"allowed in this context")));
+
+	/* Build a tuple descriptor for our result type */
+	if (get_call_result_type(fcinfo, NULL, &tupdesc) != TYPEFUNC_COMPOSITE)
+		elog(ERROR, "return type must be a row type");
+
+	per_query_ctx = rsinfo->econtext->ecxt_per_query_memory;
+	oldcontext = MemoryContextSwitchTo(per_query_ctx);
+
+	tupstore = tuplestore_begin_heap(true, false, work_mem);
+	rsinfo->returnMode = SFRM_Materialize;
+	rsinfo->setResult = tupstore;
+	rsinfo->setDesc = tupdesc;
+
+	MemoryContextSwitchTo(oldcontext);
+
+	/* TODO Fake data insertion, remove once real events are being stored */
+	/*PGTE_store("dummy data");*/
+
+	/*
+	 * We can co-exist with other readers, but will block concurrent additions
+	 */
+	LWLockAcquire(pgte->lock, LW_SHARED);
+
+	/*
+     * Determine start and how many active entries are in the queue.
+	 * Once the array holding the queue is full, the next position after
+	 * the front of the queue holds the oldest entry.  But before the queue
+	 * fills, the oldest entry is at position 0.
+	 */
+	if (pgte->full)
+	{
+		position=(pgte->front + 1) % PGTE_max;
+		count = PGTE_max;
+	}
+	else
+	{
+		position=0;
+		count = pgte->front + 1;
+	}
+
+	offset=0;  /* Just for debug printing, not navigation */
+
+	for (; count>0; count--)
+	{
+		Datum		values[pg_timing_events_COLS];
+		bool		nulls[pg_timing_events_COLS];
+		int			col = 0;
+		pgteEntry	*entry = &PGTE_queue[position];
+
+		memset(values, 0, sizeof(values));
+		memset(nulls, 0, sizeof(nulls));
+
+		/* printf("position[%d]='%s' (element %d)\n",offset,PGTE_queue[position].description,i); */
+
+		/*
+		 * TODO Quietly upcasting the temporary 32 bit serial_num to 64 bits.  
+		 * Eventually the serial number needs to be a true 64 bit value if
+		 * it is kept in the final design.
+		 */
+		values[col++] = Int64GetDatumFast(entry->serial_num);
+
+/* Debugging hack if we want to see how long the description string is */
+/*		values[col++] = Int64GetDatumFast(strlen(entry->description));*/
+
+/* Code that should work but doesn't yet */
+/*		values[col++] = CStringGetTextDatum(entry->description); */
+
+		values[col++] = CStringGetTextDatum(pgte->last_query);
+
+/*
+		values[col++] = ObjectIdGetDatum(entry->key.userid);
+		values[col++] = ObjectIdGetDatum(entry->key.dbid);
+*/
+
+/*
+		if (is_superuser || entry->userid == userid)
+		{
+			char	   *qstr;
+
+			qstr = (char *)
+				pg_do_encoding_conversion((unsigned char *) entry->query,
+										  entry->query_len,
+										  entry->encoding,
+										  GetDatabaseEncoding());
+			values[col++] = CStringGetTextDatum(qstr);
+			if (qstr != entry->query)
+				pfree(qstr);
+		}
+		else
+			values[col++] = CStringGetTextDatum("<insufficient privilege>");
+*/
+		Assert(col == pg_timing_events_COLS);
+
+		tuplestore_putvalues(tupstore, tupdesc, values, nulls);
+
+		/* Move to next queue position, wrapping around the array at the end */
+		position++;
+		if (position == PGTE_max)
+			position=0;
+		offset++;
+	}
+
+	LWLockRelease(pgte->lock);
+
+	/* clean up and return the tuplestore */
+	tuplestore_donestoring(tupstore);
+
+	return (Datum) 0;
+}
+
+/*
+ * Estimate shared memory space needed.
+ */
+static Size
+PGTE_memsize(void)
+{
+	Size		size;
+	Size		entrysize;
+
+	size = MAXALIGN(sizeof(pgteSharedState));
+	entrysize = offsetof(pgteEntry, query) +pgstat_track_activity_query_size;
+	size = add_size(size, hash_estimate_size(PGTE_max, entrysize));
+
+	return size;
+}
+
+/*
+ * Release all entries.
+ */
+static void
+entry_reset(void)
+{
+	pgteEntry  *entry;
+
+	LWLockAcquire(pgte->lock, LW_EXCLUSIVE);
+	entry=PGTE_queue;
+
+/* TODO Iterate over queue array
+	while ((entry = hash_seq_search(&hash_seq)) != NULL)
+	{
+		hash_search(PGTE_hash, &entry->key, HASH_REMOVE, NULL);
+	}
+*/
+
+	LWLockRelease(pgte->lock);
+
+}
diff --git a/contrib/pg_timing_events/pg_timing_events.control b/contrib/pg_timing_events/pg_timing_events.control
new file mode 100644
index 0000000..7db2d12
--- /dev/null
+++ b/contrib/pg_timing_events/pg_timing_events.control
@@ -0,0 +1,5 @@
+# pg_timing_events extension
+comment = 'track execution statistics of all SQL statements executed'
+default_version = '1.0'
+module_pathname = '$libdir/pg_timing_events'
+relocatable = true
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index bf76f6d..8abce9a 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -58,6 +58,7 @@
 #include "utils/relmapper.h"
 #include "utils/snapmgr.h"
 #include "utils/timestamp.h"
+#include "utils/timing_event.h"
 #include "pg_trace.h"
 
 
@@ -6730,6 +6731,7 @@ LogCheckpointEnd(bool restartpoint)
 				longest_usecs,
 				average_usecs;
 	uint64		average_sync_time;
+	StringInfoData timing_descr;
 
 	CheckpointStats.ckpt_end_t = GetCurrentTimestamp();
 
@@ -6774,6 +6776,31 @@ LogCheckpointEnd(bool restartpoint)
 	average_secs = (long) (average_sync_time / 1000000);
 	average_usecs = average_sync_time - (uint64) average_secs *1000000;
 
+	if (timing_event_hook)
+	{
+		initStringInfo(&timing_descr);
+		appendStringInfo(&timing_descr,
+			"check/restartpoint complete: wrote %d buffers (%.1f%%); "
+			 "%d transaction log file(s) added, %d removed, %d recycled; "
+			 "write=%ld.%03d s, sync=%ld.%03d s, total=%ld.%03d s; "
+			 "sync files=%d, longest=%ld.%03d s, average=%ld.%03d s",
+			 CheckpointStats.ckpt_bufs_written,
+			 (double) CheckpointStats.ckpt_bufs_written * 100 / NBuffers,
+			 CheckpointStats.ckpt_segs_added,
+			 CheckpointStats.ckpt_segs_removed,
+			 CheckpointStats.ckpt_segs_recycled,
+			 write_secs, write_usecs / 1000,
+			 sync_secs, sync_usecs / 1000,
+			 total_secs, total_usecs / 1000,
+			 CheckpointStats.ckpt_sync_rels,
+			 longest_secs, longest_usecs / 1000,
+			 average_secs, average_usecs / 1000);
+
+		elog(LOG,"Timing event message:  %s",timing_descr.data);
+
+		(*timing_event_hook) (timing_descr.data);
+	}
+
 	if (restartpoint)
 		elog(LOG, "restartpoint complete: wrote %d buffers (%.1f%%); "
 			 "%d transaction log file(s) added, %d removed, %d recycled; "
diff --git a/src/backend/utils/error/elog.c b/src/backend/utils/error/elog.c
index 68b7ab3..1deb31c 100644
--- a/src/backend/utils/error/elog.c
+++ b/src/backend/utils/error/elog.c
@@ -77,6 +77,7 @@
 #include "utils/guc.h"
 #include "utils/memutils.h"
 #include "utils/ps_status.h"
+#include "utils/timing_event.h"
 
 
 #undef _
@@ -104,6 +105,11 @@ extern bool redirection_done;
  */
 emit_log_hook_type emit_log_hook = NULL;
 
+/*
+ * Hook for notifing a timing event happened.
+ */
+timing_event_hook_type timing_event_hook = NULL;
+
 /* GUC parameters */
 int			Log_error_verbosity = PGERROR_VERBOSE;
 char	   *Log_line_prefix = NULL;		/* format for extra log line info */
diff --git a/src/include/utils/timing_event.h b/src/include/utils/timing_event.h
new file mode 100644
index 0000000..7c516f7
--- /dev/null
+++ b/src/include/utils/timing_event.h
@@ -0,0 +1,20 @@
+/*-------------------------------------------------------------------------
+ *
+ * timing_event.h
+ *	  Timing event definitions.
+ *
+ * Portions Copyright (c) 1996-2012, PostgreSQL Global Development Group
+ * Portions Copyright (c) 1994, Regents of the University of California
+ *
+ * src/include/utils/timing_event.h
+ *
+ *-------------------------------------------------------------------------
+ */
+#ifndef TIMEEVENT_H
+#define TIMEEVENT_H
+
+/* Hook for sending timing event messages */
+typedef void (*timing_event_hook_type) (const char *event_text);
+extern PGDLLIMPORT timing_event_hook_type timing_event_hook;
+
+#endif   /* TIMEEVENT_H */
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list
index a831a1e..9c8356f 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -2234,6 +2234,7 @@ timeKEY
 time_t
 timerCA
 timezone_extra
+timing_event_hook_type
 tlist_vinfo
 transferMode
 trgm