Content-Type: text/plain; charset=UTF-8
Cc: Ray Stell <stellr@cns.vt.edu>, pgsql-admin <pgsql-admin@postgresql.org>,
	pgsql-hackers <pgsql-hackers@postgresql.org>
Subject: Re: command tag logging
From: alvherre <alvherre@commandprompt.com>
To: Tom Lane <tgl@sss.pgh.pa.us>
In-reply-to: <3713.1274978989@sss.pgh.pa.us>
References: <20100526210833.GA14469@cns.vt.edu>
	<1274908611-sup-6661@alvh.no-ip.org>
	<3713.1274978989@sss.pgh.pa.us>
Date: Thu, 27 May 2010 12:59:17 -0400
Message-Id: <1274979300-sup-5327@alvh.no-ip.org>
User-Agent: Sup/0.11
Content-Transfer-Encoding: 8bit

Excerpts from Tom Lane's message of jue may 27 12:49:49 -0400 2010:
> alvherre <alvherre@commandprompt.com> writes:
> > Excerpts from Ray Stell's message of mié may 26 17:08:33 -0400 2010:
> >> I just installed a compiled from src 8.3.11.  I usually include %i, command tag,
> >> in the log_line_prefix setting.  This causes some spewage I'd not seen before
> >> on connection received lines as if it is dumping the environment:
> 
> > Hmm, I bet it's the recent %.*s patch.
> 
> That is in the right place, isn't it.  That would suggest that
> get_ps_display() is returning a wrong length on Ray's machine.
> It works okay here, but since that's platform-specific code that
> hardly proves much.  Ray, what platform is this exactly?

FWIW it fails for me too (Debian running Linux 2.6.32).  Adding some
logging to stderr results in this:

psdisp (len 2130) is: “““/pgsql/install/83_rel/bin/postmaster”””
/pgsql/install/83_rel/bin/postmasterPGDATA=/pgsql/install/83_rel/dataORBIT_SOCKETDIR=/home/alvherre/tmp/orbit-alvherreSSH_AGENT_PID=2739GPG_AGENT_INFO=/tmp/gpg-aXAHSs/S.gpg-agent:2704:1SHELL=/bin/bashTERM=xtermXDG_SESSION_COOKIE=e50959452240490c59b0366b96665400-1274967349.87074-853952583HISTSIZE=10000TMPDIR=/home/alvherre/tmpGTK_RC_FILES=/etc/gtk/gtkrc:/home/alvherre/.gtkrc-1.2-gnome2WINDOWID=29360152GNOME_KEYRING_CONTROL=/home/alvherre/tmp/keyring-EUoSfgGTK_MODULES=canberra-gtk-moduleUSER=alvherrehttp_proxy=http://localhost:8118XTERM_SHELL=/bin/bashHISTFILESIZE=10000LD_LIBRARY_PATH=/pgsql/install/83_rel/libLS_COLORS=no=00:fi=00:di=01;35:ln=01;36:pi=40;33:so=01;35:bd=40;33;01:cd=40;33;01:or=01;05;37;41:mi=01;05;37;41:ex=01;32:*.cmd=01;32:*.exe=01;32:*.com=01;32:*.btm=01;32:*.bat=01;32:*.tar=01;31:*.tgz=01;31:*.tbz2=01;31:*.arc=01;31:*.arj=01;31:*.taz=01;31:*.lzh=01;31:*.lha=01;31:*.zip=01;31:*.z=01;31:*.Z=01;31:*.gz=01;31:*.bz2=01;31:*.bz=01;31:*.tz=01;31:*.rpm=01;31:*.jpg=01
 ;35:*.jpeg=01;35:*.gif=01;35:*.bmp=01;35:*.xbm=01;35:*.xpm=01;35:*.png=01;35:*.tif=01;35:*.tiff=01;35:SSH_AUTH_SOCK=/home/alvherre/tmp/keyring-EUoSfg/sshTMOUT=0USERNAME=alvherreSESSION_MANAGER=local/perhan:@/tmp/.ICE-unix/2689,unix/perhan:/tmp/.ICE-unix/2689PAGER=lessDESKTOP_SESSION=gnomePATH=/usr/local/bin:/usr/bin:/bin:/usr/bin/X11:/usr/games:/home/alvherre/bin:/sbin:/usr/sbinGDM_XSERVER_LOCATION=localPX_CONFIG_ORDER=envvarPWD=/home/alvherreEDITOR=vimLANG=es_CL.UTF-8GDM_LANG=es_CL.UTF-8TZ=America/SantiagoGDMSESSION=gnomeHISTIGNORE=ls:bg:fg:cd:exit:XTERM_VERSION=XTerm(256)XTERM_LOCALE=es_CL.UTF-8HISTCONTROL=ignorespace:erasedupsHOME=/home/alvherreSHLVL=1GNOME_DESKTOP_SESSION_ID=this-is-deprecatedno_proxy=localhost,127.0.0.0/8BASH_ENV=/home/alvherre/.bashrcLOGNAME=alvherreLESS=-XRM -x4VISUAL=vimXDG_DATA_DIRS=/usr/share/gnome:/usr/local/share/:/usr/share/:/usr/share/gdm/DBUS_SESSION_BUS_ADDRESS=unix:abstract=/tmp/dbus-TnbbC5PUiR,guid=833f76565b26a89543f6aa420000004f_PX_CONFIG
 _ORDER=WINDOWPATH=7DISPLAY=:0.0HOSTFILE=/home/alvherre/.hostsXAUTHORITY=/home/alvherre/.Xauthority LOG:  connection received: host=[local]


Maybe the problem is the PS_PADDING setting?

I patched as below -- obviously the \0 didn't make any difference (it
was the first thing I tried), because the length, as you say, is wrong.

*************** log_line_prefix(StringInfo buf)
*** 1615,1621 ****
--- 1615,1623 ----
                    int         displen;
  
                    psdisp = get_ps_display(&displen);
+                   fprintf(stderr, "psdisp (len %d) is: “““%s”””\n", displen, psdisp);
                    appendBinaryStringInfo(buf, psdisp, displen);
+                   appendStringInfoChar(buf, '\0');
                }
                break;
            case 'r':


-- 
Álvaro Herrera <alvherre@commandprompt.com>
The PostgreSQL Company - Command Prompt, Inc.
PostgreSQL Replication, Consulting, Custom Development, 24x7 support