v1-0001-libpq-trace-log.patch

diff --git a/src/interfaces/libpq/fe-connect.c b/src/interfaces/libpq/fe-connect.c
index d001bc5..6bdf2df 100644
--- a/src/interfaces/libpq/fe-connect.c
+++ b/src/interfaces/libpq/fe-connect.c
@@ -325,6 +325,15 @@ static const internalPQconninfoOption PQconninfoOptions[] = {
 		"Target-Session-Attrs", "", 11, /* sizeof("read-write") = 11 */
 	offsetof(struct pg_conn, target_session_attrs)},
 
+	/* libpq trace log options */
+	{"logdir", "PGLOGDIR", NULL, NULL,
+		"Logdir", "", MAXPGPATH - 4,
+	offsetof(struct pg_conn, logdir)},
+
+	{"logsize", "PGLOGSIZE", NULL, NULL,
+		"Logsize", "", 5,
+	offsetof(struct pg_conn, logsize_str)},
+
 	/* Terminating entry --- MUST BE LAST */
 	{NULL, NULL, NULL, NULL,
 	NULL, NULL, 0}
@@ -1128,6 +1137,19 @@ connectOptions2(PGconn *conn)
 	}
 
 	/*
+	 * If both size and directory of trace log was given,
+	 * initialize a trace log.
+	 */
+	if (conn->logsize_str && conn->logsize_str[0] != '\0')
+		conn->logsize = atoi(conn->logsize_str);
+
+	if (conn->logdir != NULL && conn->logsize > 0 && conn->logsize < 2048)
+	{
+		conn->logsize = conn->logsize * 1024 * 1024;
+		initTraceLog(conn);
+	}
+
+	/*
 	 * If password was not given, try to look it up in password file.  Note
 	 * that the result might be different for each host/port pair.
 	 */
@@ -3687,6 +3709,14 @@ freePGconn(PGconn *conn)
 	termPQExpBuffer(&conn->errorMessage);
 	termPQExpBuffer(&conn->workBuffer);
 
+	/* clean up libpq trace log structures */
+	if (conn->logsize_str)
+		free(conn->logsize_str);
+	if (conn->logdir)
+		free(conn->logdir);
+	if (conn->traceDebug)
+		fclose(conn->traceDebug);
+
 	free(conn);
 
 #ifdef WIN32
@@ -3722,6 +3752,8 @@ sendTerminateConn(PGconn *conn)
 	 */
 	if (conn->sock != PGINVALID_SOCKET && conn->status == CONNECTION_OK)
 	{
+		if (conn->Pfdebug || conn->traceDebug)
+			traceLog_fprintf(conn, true, "Send connection terminate message to backend: ");
 		/*
 		 * Try to send "close connection" message to backend. Ignore any
 		 * error.
@@ -4124,6 +4156,9 @@ int
 pqPacketSend(PGconn *conn, char pack_type,
 			 const void *buf, size_t buf_len)
 {
+	if (conn->Pfdebug || conn->traceDebug)
+		traceLog_fprintf(conn, true, "Send connection start message to backend: ");
+
 	/* Start the message. */
 	if (pqPutMsgStart(pack_type, true, conn))
 		return STATUS_ERROR;
diff --git a/src/interfaces/libpq/fe-exec.c b/src/interfaces/libpq/fe-exec.c
index 6aed8c8..d326e66 100644
--- a/src/interfaces/libpq/fe-exec.c
+++ b/src/interfaces/libpq/fe-exec.c
@@ -879,7 +879,7 @@ pqInternalNotice(const PGNoticeHooks *hooks, const char *fmt,...)
 	res->errMsg = (char *) pqResultAlloc(res, strlen(msgBuf) + 2, false);
 	if (res->errMsg)
 	{
-		sprintf(res->errMsg, "%s\n", msgBuf);
+		sprintf(res->errMsg, "NOTICE: %s\n", msgBuf);
 
 		/*
 		 * Pass to receiver, then free it.
@@ -991,9 +991,9 @@ pqSaveParameterStatus(PGconn *conn, const char *name, const char *value)
 	pgParameterStatus *pstatus;
 	pgParameterStatus *prev;
 
-	if (conn->Pfdebug)
-		fprintf(conn->Pfdebug, "pqSaveParameterStatus: '%s' = '%s'\n",
-				name, value);
+	if (conn->Pfdebug || conn->traceDebug)
+		traceLog_fprintf(conn, false, "pqSaveParameterStatus: '%s' = '%s'\n",
+						 name, value);
 
 	/*
 	 * Forget any old information about the parameter
@@ -1219,6 +1219,9 @@ PQsendQuery(PGconn *conn, const char *query)
 		return 0;
 	}
 
+	if (conn->traceDebug)
+		traceLog_fprintf(conn, false, "Query: %s \n",query);
+
 	/* construct the outgoing Query message */
 	if (pqPutMsgStart('Q', false, conn) < 0 ||
 		pqPuts(query, conn) < 0 ||
@@ -1337,6 +1340,9 @@ PQsendPrepare(PGconn *conn,
 		return 0;
 	}
 
+	if (conn->traceDebug)
+		traceLog_fprintf(conn, false, "Statement name: %s, Query: %s \n",stmtName, query);
+
 	/* construct the Parse message */
 	if (pqPutMsgStart('P', false, conn) < 0 ||
 		pqPuts(stmtName, conn) < 0 ||
@@ -1507,6 +1513,9 @@ PQsendQueryGuts(PGconn *conn,
 
 	if (command)
 	{
+		if (conn->traceDebug)
+			traceLog_fprintf(conn, false, "Statement name: %s, Command: %s \n",stmtName, command);
+
 		/* construct the Parse message */
 		if (pqPutMsgStart('P', false, conn) < 0 ||
 			pqPuts(stmtName, conn) < 0 ||
@@ -1820,6 +1829,7 @@ PQgetResult(PGconn *conn)
 
 		/* Parse it. */
 		parseInput(conn);
+
 	}
 
 	/* Return the appropriate thing. */
@@ -2006,6 +2016,9 @@ PQexecStart(PGconn *conn)
 {
 	PGresult   *result;
 
+	if (conn->traceDebug)
+		traceLog_fprintf(conn, true, "Start :");
+
 	if (!conn)
 		return false;
 
@@ -2120,6 +2133,9 @@ PQexecFinish(PGconn *conn)
 			break;
 	}
 
+	if (conn->traceDebug)
+		traceLog_fprintf(conn, true, "End :");
+
 	return lastResult;
 }
 
@@ -2218,6 +2234,9 @@ PQsendDescribe(PGconn *conn, char desc_type, const char *desc_target)
 		return 0;
 	}
 
+	if (conn->traceDebug)
+		traceLog_fprintf(conn, false, "Describe type: %c, target: %s \n",desc_type, desc_target);
+
 	/* construct the Describe message */
 	if (pqPutMsgStart('D', false, conn) < 0 ||
 		pqPutc(desc_type, conn) < 0 ||
diff --git a/src/interfaces/libpq/fe-misc.c b/src/interfaces/libpq/fe-misc.c
index 46ece1a..fcf7c8e 100644
--- a/src/interfaces/libpq/fe-misc.c
+++ b/src/interfaces/libpq/fe-misc.c
@@ -35,6 +35,7 @@
 
 #ifdef WIN32
 #include "win32.h"
+#include <windows.h>
 #else
 #include <unistd.h>
 #include <sys/time.h>
@@ -45,6 +46,7 @@
 #endif
 #ifdef HAVE_SYS_SELECT_H
 #include <sys/select.h>
+#include <sys/timeb.h>
 #endif
 
 #include "libpq-fe.h"
@@ -60,6 +62,168 @@ static int pqSocketCheck(PGconn *conn, int forRead, int forWrite,
 			  time_t end_time);
 static int	pqSocketPoll(int sock, int forRead, int forWrite, time_t end_time);
 
+static void getTraceLogFilename(PGconn *conn,char* filename);
+static void traceLog_fputnbytes(PGconn *conn, const char *head, const char *str, size_t n);
+static void fputnbytes(FILE *f, const char *str, size_t n);
+static void getCurrentTime(char* currenttime,int type);
+#define	TRACELOG_TIME_SIZE	28
+
+/*
+ * getCurrentTime: get current time for trace log output
+ *
+ * type=0 currenttime formate %Y-%m-%d_%H%M%S
+ * type=1 currenttime formate %Y/%m/%d %H:%M:%S.%Milliseconds
+ */
+static void
+getCurrentTime(char* currenttime,int type)
+{
+#ifdef WIN32
+	SYSTEMTIME localTime;
+	GetLocalTime(&localTime);
+	if(type==0)
+		snprintf(currenttime,TRACELOG_TIME_SIZE,"%4d-%02d-%02d_%02d%02d%02d",
+				localTime.wYear,localTime.wMonth,localTime.wDay,
+				localTime.wHour,localTime.wMinute,localTime.wSecond);
+	else if(type==1)
+		snprintf(currenttime,TRACELOG_TIME_SIZE,"%4d/%02d/%02d %02d:%02d:%02d.%03d",
+				localTime.wYear,localTime.wMonth,localTime.wDay,
+				localTime.wHour,localTime.wMinute,localTime.wSecond,
+				localTime.wMilliseconds);
+#else
+	struct timeb localTime;
+	struct tm *tm;
+	ftime(&localTime);
+	tm = localtime(&localTime.time);
+	if(type == 0)
+		snprintf(currenttime, TRACELOG_TIME_SIZE,"%4d-%02d-%02d_%02d%02d%02d",
+				1900+ tm->tm_year,1 + tm->tm_mon, tm->tm_mday,
+				tm->tm_hour, tm->tm_min, tm->tm_sec);
+	else if(type==1)
+		snprintf(currenttime, TRACELOG_TIME_SIZE,"%4d/%02d/%02d %02d:%02d:%02d.%03d",
+				1900+ tm->tm_year,1 + tm->tm_mon, tm->tm_mday,
+				tm->tm_hour, tm->tm_min, tm->tm_sec, localTime.millitm);
+#endif
+}
+
+/*
+ * getTraceLogFilename: build trace log file name
+ * The name is libpq-%ProcessID-%Y-%m-%d_%H%M%S.log.
+ */
+static void
+getTraceLogFilename(PGconn *conn,char* filename)
+{
+	char		currenttime[TRACELOG_TIME_SIZE];    /* %Y-%m-%d_%H%M%S */
+	getCurrentTime(currenttime,0);
+
+#ifdef WIN32
+	snprintf(filename, MAXPGPATH, "%s\\libpq-%d-%s.log", conn->logdir,getpid(),currenttime);
+#else
+	snprintf(filename, MAXPGPATH, "%s/libpq-%d-%s.log", conn->logdir,getpid(),currenttime);
+#endif
+}
+
+/*
+ * initTraceLog: initialize a trace log file
+ */
+void
+initTraceLog(PGconn *conn)
+{
+	char		logfilename[MAXPGPATH];
+	getTraceLogFilename(conn,logfilename);
+	conn->traceDebug=fopen(logfilename,"w");
+}
+
+/*
+ * traceLog_fprintf: output trace log to file
+ * If PQtrace() is called, PQtrace() is output followed by libpq trace log.
+ */
+void
+traceLog_fprintf(PGconn *conn, bool addTime, const char *fmt,...)
+{
+	char		logfilename[MAXPGPATH];
+	char		msgBuf[MAXPGPATH];
+	va_list		args;
+	int			ret;
+	char		currenttime[TRACELOG_TIME_SIZE];
+
+	va_start(args, fmt);
+	vsnprintf(msgBuf, sizeof(msgBuf), fmt, args);
+	msgBuf[sizeof(msgBuf) - 1] = '\0';
+	va_end(args);
+
+	if(conn->Pfdebug)
+	{
+		fprintf(conn->Pfdebug, "%s", msgBuf);
+	}
+	else if(conn->traceDebug)
+	{
+		if((int)ftell(conn->traceDebug) >= conn->logsize)
+		{
+			fclose(conn->traceDebug);
+			getTraceLogFilename(conn,logfilename);
+			conn->traceDebug = fopen(logfilename,"w");
+			if(conn->traceDebug == NULL)
+				return;
+		}
+
+		/* Select trace log message style */
+		if(addTime)
+		{
+			getCurrentTime(currenttime,1);
+			ret = fprintf(conn->traceDebug, "%s  %s\n", msgBuf, currenttime);
+		}
+		else
+		{
+			ret = fprintf(conn->traceDebug, "%s",msgBuf);
+		}
+
+		if(ret < 0)
+		{
+			fclose(conn->traceDebug);
+			conn->traceDebug = NULL;
+			return;
+		}
+		fflush(conn->traceDebug);
+	}
+}
+/*
+ * traceLog_fputnbytes: output trace log to file using fputnbytes()
+ */
+static void
+traceLog_fputnbytes(PGconn *conn,const char *head, const char *str, size_t n)
+{
+	char		logfilename[MAXPGPATH];
+	int			ret;
+
+	if (conn->Pfdebug)
+	{
+		fprintf(conn->Pfdebug, "%s", head);
+		fputnbytes(conn->Pfdebug,str, n);
+		fprintf(conn->Pfdebug, "\n");
+	}
+	else if(conn->traceDebug)
+	{
+		if((int)ftell(conn->traceDebug) >= conn->logsize)
+		{
+			fclose(conn->traceDebug);
+			getTraceLogFilename(conn,logfilename);
+			conn->traceDebug = fopen(logfilename,"w");
+			if(conn->traceDebug == NULL)
+				return;
+		}
+		ret = fprintf(conn->traceDebug, "%s", head);
+		if(ret < 0)
+		{
+			fclose(conn->traceDebug);
+			conn->traceDebug = NULL;
+			return;
+		}
+		fputnbytes(conn->traceDebug,str,n);
+		fprintf(conn->traceDebug,"\n");
+		fflush(conn->traceDebug);
+	}
+}
+
 /*
  * PQlibVersion: return the libpq version number
  */
@@ -98,8 +262,8 @@ pqGetc(char *result, PGconn *conn)
 
 	*result = conn->inBuffer[conn->inCursor++];
 
-	if (conn->Pfdebug)
-		fprintf(conn->Pfdebug, "From backend> %c\n", *result);
+	if(conn->Pfdebug||conn->traceDebug)
+		traceLog_fprintf(conn, false, "From backend> %c\n", *result);
 
 	return 0;
 }
@@ -114,8 +278,8 @@ pqPutc(char c, PGconn *conn)
 	if (pqPutMsgBytes(&c, 1, conn))
 		return EOF;
 
-	if (conn->Pfdebug)
-		fprintf(conn->Pfdebug, "To backend> %c\n", c);
+	if(conn->Pfdebug||conn->traceDebug)
+		traceLog_fprintf(conn, false, "To backend> %c\n", c);
 
 	return 0;
 }
@@ -152,9 +316,9 @@ pqGets_internal(PQExpBuffer buf, PGconn *conn, bool resetbuffer)
 
 	conn->inCursor = ++inCursor;
 
-	if (conn->Pfdebug)
-		fprintf(conn->Pfdebug, "From backend> \"%s\"\n",
-				buf->data);
+	if(conn->Pfdebug||conn->traceDebug)
+		traceLog_fprintf(conn, false, "From backend> \"%s\"\n",
+						buf->data);
 
 	return 0;
 }
@@ -181,8 +345,8 @@ pqPuts(const char *s, PGconn *conn)
 	if (pqPutMsgBytes(s, strlen(s) + 1, conn))
 		return EOF;
 
-	if (conn->Pfdebug)
-		fprintf(conn->Pfdebug, "To backend> \"%s\"\n", s);
+	if(conn->Pfdebug||conn->traceDebug)
+		traceLog_fprintf(conn, false, "To backend> \"%s\"\n", s);
 
 	return 0;
 }
@@ -194,6 +358,7 @@ pqPuts(const char *s, PGconn *conn)
 int
 pqGetnchar(char *s, size_t len, PGconn *conn)
 {
+	char		buf[100];
 	if (len > (size_t) (conn->inEnd - conn->inCursor))
 		return EOF;
 
@@ -202,11 +367,10 @@ pqGetnchar(char *s, size_t len, PGconn *conn)
 
 	conn->inCursor += len;
 
-	if (conn->Pfdebug)
+	if(conn->Pfdebug||conn->traceDebug)
 	{
-		fprintf(conn->Pfdebug, "From backend (%lu)> ", (unsigned long) len);
-		fputnbytes(conn->Pfdebug, s, len);
-		fprintf(conn->Pfdebug, "\n");
+		sprintf(buf, "From backend (%lu)> ", (unsigned long) len);
+		traceLog_fputnbytes(conn,buf,s, len);
 	}
 
 	return 0;
@@ -228,7 +392,7 @@ pqSkipnchar(size_t len, PGconn *conn)
 
 	if (conn->Pfdebug)
 	{
-		fprintf(conn->Pfdebug, "From backend (%lu)> ", (unsigned long) len);
+		fprintf(conn->Pfdebug, "(pqSkipnchar)From backend (%lu)> ", (unsigned long) len);
 		fputnbytes(conn->Pfdebug, conn->inBuffer + conn->inCursor, len);
 		fprintf(conn->Pfdebug, "\n");
 	}
@@ -245,14 +409,14 @@ pqSkipnchar(size_t len, PGconn *conn)
 int
 pqPutnchar(const char *s, size_t len, PGconn *conn)
 {
+	char		buf[100];
 	if (pqPutMsgBytes(s, len, conn))
 		return EOF;
 
-	if (conn->Pfdebug)
+	if(conn->Pfdebug||conn->traceDebug)
 	{
-		fprintf(conn->Pfdebug, "To backend> ");
-		fputnbytes(conn->Pfdebug, s, len);
-		fprintf(conn->Pfdebug, "\n");
+		sprintf(buf,"To backend (%lu)> ", (unsigned long) len);
+		traceLog_fputnbytes(conn,buf,s,len);
 	}
 
 	return 0;
@@ -292,8 +456,8 @@ pqGetInt(int *result, size_t bytes, PGconn *conn)
 			return EOF;
 	}
 
-	if (conn->Pfdebug)
-		fprintf(conn->Pfdebug, "From backend (#%lu)> %d\n", (unsigned long) bytes, *result);
+	if(conn->Pfdebug||conn->traceDebug)
+		traceLog_fprintf(conn, false, "From backend (#%lu)> %d\n", (unsigned long) bytes, *result);
 
 	return 0;
 }
@@ -328,8 +492,8 @@ pqPutInt(int value, size_t bytes, PGconn *conn)
 			return EOF;
 	}
 
-	if (conn->Pfdebug)
-		fprintf(conn->Pfdebug, "To backend (%lu#)> %d\n", (unsigned long) bytes, value);
+	if(conn->Pfdebug||conn->traceDebug)
+		traceLog_fprintf(conn, false, "To backend (%lu#)> %d\n", (unsigned long) bytes, value);
 
 	return 0;
 }
@@ -548,9 +712,9 @@ pqPutMsgStart(char msg_type, bool force_len, PGconn *conn)
 	conn->outMsgEnd = endPos;
 	/* length word, if needed, will be filled in by pqPutMsgEnd */
 
-	if (conn->Pfdebug)
-		fprintf(conn->Pfdebug, "To backend> Msg %c\n",
-				msg_type ? msg_type : ' ');
+	if(conn->Pfdebug||conn->traceDebug)
+		traceLog_fprintf(conn, false, "To backend> Msg %c\n",
+						msg_type ? msg_type : ' ');
 
 	return 0;
 }
@@ -586,9 +750,9 @@ pqPutMsgBytes(const void *buf, size_t len, PGconn *conn)
 int
 pqPutMsgEnd(PGconn *conn)
 {
-	if (conn->Pfdebug)
-		fprintf(conn->Pfdebug, "To backend> Msg complete, length %u\n",
-				conn->outMsgEnd - conn->outCount);
+	if(conn->Pfdebug||conn->traceDebug)
+		traceLog_fprintf(conn, false, "To backend> Msg complete, length %u\n",
+						conn->outMsgEnd - conn->outCount);
 
 	/* Fill in length word if needed */
 	if (conn->outMsgStart >= 0)
@@ -677,9 +841,16 @@ pqReadData(PGconn *conn)
 	}
 
 	/* OK, try to read some data */
+
+	if (conn->traceDebug)
+		traceLog_fprintf(conn, true, "Start receiving message from backend:");
 retry3:
 	nread = pqsecure_read(conn, conn->inBuffer + conn->inEnd,
 						  conn->inBufSize - conn->inEnd);
+
+	if (conn->traceDebug)
+		traceLog_fprintf(conn, true, "End receiving message from backend:");
+
 	if (nread < 0)
 	{
 		if (SOCK_ERRNO == EINTR)
@@ -767,9 +938,16 @@ retry3:
 	 * Still not sure that it's EOF, because some data could have just
 	 * arrived.
 	 */
+
+	if (conn->traceDebug)
+		traceLog_fprintf(conn, true, "Start receiving message from backend:");
 retry4:
 	nread = pqsecure_read(conn, conn->inBuffer + conn->inEnd,
 						  conn->inBufSize - conn->inEnd);
+
+	if (conn->traceDebug)
+		traceLog_fprintf(conn, true, "End receiving message from backend:");
+
 	if (nread < 0)
 	{
 		if (SOCK_ERRNO == EINTR)
@@ -846,6 +1024,9 @@ pqSendSome(PGconn *conn, int len)
 	{
 		int			sent;
 
+	if (conn->traceDebug)
+		traceLog_fprintf(conn, true, "Start sending message to backend:");
+
 #ifndef WIN32
 		sent = pqsecure_write(conn, ptr, len);
 #else
@@ -858,6 +1039,9 @@ pqSendSome(PGconn *conn, int len)
 		sent = pqsecure_write(conn, ptr, Min(len, 65536));
 #endif
 
+	if (conn->traceDebug)
+		traceLog_fprintf(conn, true, "End sending message to backend:");
+
 		if (sent < 0)
 		{
 			/* Anything except EAGAIN/EWOULDBLOCK/EINTR is trouble */
diff --git a/src/interfaces/libpq/libpq-int.h b/src/interfaces/libpq/libpq-int.h
index 975ab33..2aa8a51 100644
--- a/src/interfaces/libpq/libpq-int.h
+++ b/src/interfaces/libpq/libpq-int.h
@@ -499,6 +499,11 @@ struct pg_conn
 
 	/* Buffer for receiving various parts of messages */
 	PQExpBufferData workBuffer; /* expansible string */
+
+	char	   *logsize_str;		/* Trace log maximum size (string) */
+	int			logsize;		/* Trace log maximum size */
+	char	   *logdir;			/* Trace log directory to save log */
+	FILE	   *traceDebug;			/* Trace log file to write trace info */
 };
 
 /* PGcancel stores all data necessary to cancel a connection. A copy of this
@@ -665,6 +670,10 @@ extern void pq_reset_sigpipe(sigset_t *osigset, bool sigpipe_pending,
 				 bool got_epipe);
 #endif
 
+/* libpq trace log  */
+extern void initTraceLog(PGconn *conn);
+extern void traceLog_fprintf(PGconn *conn, bool addTime, const char *fmt,...) pg_attribute_printf(3, 4);
+
 /* === SSL === */
 
 /*