Date: Wed, 10 Mar 2021 10:31:27 -0300
From: "'alvherre@alvh.no-ip.org'" <alvherre@alvh.no-ip.org>
To: "iwata.aya@fujitsu.com" <iwata.aya@fujitsu.com>
Cc: "tsunakawa.takay@fujitsu.com" <tsunakawa.takay@fujitsu.com>,
	'Tom Lane' <tgl@sss.pgh.pa.us>,
	"k.jamison@fujitsu.com" <k.jamison@fujitsu.com>,
	'Kyotaro Horiguchi' <horikyota.ntt@gmail.com>,
	"pgsql-hackers@lists.postgresql.org" <pgsql-hackers@lists.postgresql.org>
Subject: Re: libpq debug log
Message-ID: <20210310133127.GA18076@alvherre.pgsql>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="ZPt4rx8FFjLCG7dd"
Content-Disposition: inline
Content-Transfer-Encoding: 8bit
In-Reply-To: 
 <TY2PR01MB196364CF9E18269907460BC7EA919@TY2PR01MB1963.jpnprd01.prod.outlook.com>
User-Agent: Mutt/1.10.1 (2018-07-13)
Archived-At: 
 <https://www.postgresql.org/message-id/20210310133127.GA18076%40alvherre.pgsql>
Precedence: bulk


--ZPt4rx8FFjLCG7dd
Content-Type: text/plain; charset=iso-8859-1
Content-Disposition: inline
Content-Transfer-Encoding: 8bit

On 2021-Mar-10, iwata.aya@fujitsu.com wrote:

> Hi all,
> 
> Following all reviewer's advice, I have created a new patch.
> 
> In this patch, I add only two tracing entry points; I call pqTraceOutputMsg(PGconn conn, int msgCursor, PGCommSource commsource) in pqParseInput3 () and pqPutMsgEnd () to output log.
> The argument contains message first byte offset called msgCursor because it is simpler to specify the buffer pointer in the caller. 
> 
> In pqTraceOutputMsg(), the content common to all protocol messages (first timestamp, < or >, first 1 byte, and length) are output first and after that each protocol message contents is output. I referred to pqParseInput3 () , fe-exec.c and documentation page for that part.
> 
> This fix almost eliminates if(conn->Pfdebug) that was built into the code for other features.

This certainly looks much better!  Thanks for getting it done so
quickly.

I didn't review the code super closely.  I do see a compiler warning:

/pgsql/source/pipeline/src/interfaces/libpq/libpq-trace.c: In function 'pqTraceOutputNchar':
/pgsql/source/pipeline/src/interfaces/libpq/libpq-trace.c:373:2: warning: argument 1 null where non-null expected [-Wnonnull]
  memcpy(v, buf + *cursor, len);
  ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~

and then when I try to run the "libpq_pipeline" program from the other
thread, I get a crash with this backtrace:

Program received signal SIGSEGV, Segmentation fault.
__memmove_avx_unaligned_erms () at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:288
288	../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S: No existe el fichero o el directorio.
(gdb) bt
#0  __memmove_avx_unaligned_erms () at ../sysdeps/x86_64/multiarch/memmove-vec-unaligned-erms.S:288
#1  0x00007ffff7f9b50b in pqTraceOutputNchar (buf=buf@entry=0x555555564660 "P", 
    LogEnd=LogEnd@entry=42, cursor=cursor@entry=0x7fffffffdeb4, pfdebug=0x555555569320, len=1)
    at /pgsql/source/pipeline/src/interfaces/libpq/libpq-trace.c:373
#2  0x00007ffff7f9bc25 in pqTraceOutputMsg (conn=conn@entry=0x555555560260, msgCursor=<optimized out>, 
    commsource=commsource@entry=MSGDIR_FROM_FRONTEND)
    at /pgsql/source/pipeline/src/interfaces/libpq/libpq-trace.c:476
#3  0x00007ffff7f96280 in pqPutMsgEnd (conn=conn@entry=0x555555560260)
    at /pgsql/source/pipeline/src/interfaces/libpq/fe-misc.c:533
    ...

The attached patch fixes it, though I'm not sure that that's the final
form we want it to have (since we'd alloc and free repeatedly, making it
slow -- perhaps better to use a static, or ...? ).

-- 
Álvaro Herrera       Valdivia, Chile
Essentially, you're proposing Kevlar shoes as a solution for the problem
that you want to walk around carrying a loaded gun aimed at your foot.
(Tom Lane)

--ZPt4rx8FFjLCG7dd
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment; filename="fixsegv.patch"

diff --git a/src/interfaces/libpq/libpq-trace.c b/src/interfaces/libpq/libpq-trace.c
index ef294fa556..5d3b40a1d0 100644
--- a/src/interfaces/libpq/libpq-trace.c
+++ b/src/interfaces/libpq/libpq-trace.c
@@ -368,7 +368,15 @@ pqTraceOutputBinary(char *v, int length, FILE *pfdebug)
 static void
 pqTraceOutputNchar(char *buf, int LogEnd, int *cursor, FILE *pfdebug, int len)
 {
-	char	*v = '\0';
+	char	*v;
+
+	v = malloc(len);
+	if (v == NULL)
+	{
+		fprintf(pfdebug, "'..%d chars..'", len);
+		*cursor += len;
+		return;
+	}
 
 	memcpy(v, buf + *cursor, len);
 	*cursor += len;
@@ -377,6 +385,8 @@ pqTraceOutputNchar(char *buf, int LogEnd, int *cursor, FILE *pfdebug, int len)
 	pqTraceOutputBinary(v, len, pfdebug);
 	fprintf(pfdebug, "\'");
 
+	free(v);
+
 	if (*cursor < LogEnd)
 		fprintf(pfdebug, " ");
 	else

--ZPt4rx8FFjLCG7dd--