Re: TODO item: list prepared queries

[Bruce Momjian <pgman(at)candle(dot)pha(dot)pa(dot)us>]

Tom Lane wrote:
> Neil Conway <neilc(at)samurai(dot)com> writes:
> > One minor irritation is that the query string of prepared statements
> > created via SQL has "PREPARE ... AS" prefixed to it, whereas statements
> > prepared via the FE-BE protocol do not. This should probably be fixed,
> 
> That's debatable.  Earlier today, I was busy being annoyed all over
> again with the way that Bruce set up Parse/Bind/Execute logging to
> deliberately obscure the difference between a SQL PREPARE command and a
> protocol-level Parse operation.  I think it's a good thing to be able to
> tell which level a prepared statement came from.  Yeah, much of the time
> you may not care, but when you do care it's important.

I have applied the following patch to CVS HEAD to mark client-side
prepare/bind/execute statements with "[client]" so they can be easily
distinguished from SQL commands.  I hesitate to apply this logging
change to 8.1.X.

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman(at)candle(dot)pha(dot)pa(dot)us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073

Index: src/backend/tcop/postgres.c
===================================================================
RCS file: /cvsroot/pgsql/src/backend/tcop/postgres.c,v
retrieving revision 1.471
diff -c -c -r1.471 postgres.c
*** src/backend/tcop/postgres.c	14 Dec 2005 17:06:27 -0000	1.471
--- src/backend/tcop/postgres.c	30 Dec 2005 22:27:51 -0000
***************
*** 1146,1152 ****
  
  	if (log_statement == LOGSTMT_ALL)
  		ereport(LOG,
! 				(errmsg("statement: PREPARE %s AS %s",
  						(*stmt_name != '\0') ? stmt_name : "<unnamed>",
  						query_string)));
  
--- 1146,1152 ----
  
  	if (log_statement == LOGSTMT_ALL)
  		ereport(LOG,
! 				(errmsg("statement: [client] PREPARE %s AS %s",
  						(*stmt_name != '\0') ? stmt_name : "<unnamed>",
  						query_string)));
  
***************
*** 1449,1455 ****
  	/* We need to output the parameter values someday */
  	if (log_statement == LOGSTMT_ALL)
  		ereport(LOG,
! 				(errmsg("statement: <BIND> %s", portal_name)));
  
  	/*
  	 * Fetch parameters, if any, and store in the portal's memory context.
--- 1449,1455 ----
  	/* We need to output the parameter values someday */
  	if (log_statement == LOGSTMT_ALL)
  		ereport(LOG,
! 				(errmsg("statement: [client] <BIND> %s", portal_name)));
  
  	/*
  	 * Fetch parameters, if any, and store in the portal's memory context.
***************
*** 1712,1718 ****
  	if (log_statement == LOGSTMT_ALL)
  		/* We have the portal, so output the source query. */
  		ereport(LOG,
! 				(errmsg("statement: %sEXECUTE %s  [PREPARE:  %s]",
  						(execute_is_fetch) ? "FETCH from " : "",
  						(*portal_name != '\0') ? portal_name : "<unnamed>",
  						portal->sourceText ? portal->sourceText : "")));
--- 1712,1718 ----
  	if (log_statement == LOGSTMT_ALL)
  		/* We have the portal, so output the source query. */
  		ereport(LOG,
! 				(errmsg("statement: [client] %sEXECUTE %s  [PREPARE:  %s]",
  						(execute_is_fetch) ? "FETCH from " : "",
  						(*portal_name != '\0') ? portal_name : "<unnamed>",
  						portal->sourceText ? portal->sourceText : "")));
***************
*** 1821,1827 ****
  			(save_log_min_duration_statement > 0 &&
  			 usecs >= save_log_min_duration_statement * 1000))
  			ereport(LOG,
! 					(errmsg("duration: %ld.%03ld ms  statement: %sEXECUTE %s  [PREPARE:  %s]",
  							(long) ((stop_t.tv_sec - start_t.tv_sec) * 1000 +
  								  (stop_t.tv_usec - start_t.tv_usec) / 1000),
  							(long) (stop_t.tv_usec - start_t.tv_usec) % 1000,
--- 1821,1827 ----
  			(save_log_min_duration_statement > 0 &&
  			 usecs >= save_log_min_duration_statement * 1000))
  			ereport(LOG,
! 					(errmsg("duration: %ld.%03ld ms  statement: [client] %sEXECUTE %s  [PREPARE:  %s]",
  							(long) ((stop_t.tv_sec - start_t.tv_sec) * 1000 +
  								  (stop_t.tv_usec - start_t.tv_usec) / 1000),
  							(long) (stop_t.tv_usec - start_t.tv_usec) % 1000,