From: Andrew Dunstan <andrew.dunstan@2ndquadrant.com>
Subject: Re: BUG #15804: Assertion failure when using logging_collector with
 EXEC_BACKEND
To: Tom Lane <tgl@sss.pgh.pa.us>, Michael Paquier <michael@paquier.xyz>
Cc: Andres Freund <andres@anarazel.de>,
 Peter Eisentraut <peter.eisentraut@2ndquadrant.com>,
 Yuli Khodorkovskiy <yuli.khodorkovskiy@crunchydata.com>,
 pgsql-bugs@lists.postgresql.org
References: <20190516021903.GB1415@paquier.xyz>
 <28927.1557977558@sss.pgh.pa.us> <20190516035617.GC1415@paquier.xyz>
 <20190516043618.GD1415@paquier.xyz> <31437.1557982294@sss.pgh.pa.us>
 <20190516060628.GE1415@paquier.xyz> <20190517042536.GM20887@paquier.xyz>
 <20190517202443.gw4zdfkpwgsjdel6@alap3.anarazel.de>
 <20190518093522.GA19212@paquier.xyz> <28565.1558196308@sss.pgh.pa.us>
 <20190519004344.GA3653@paquier.xyz> <22995.1558278322@sss.pgh.pa.us>
 <27719.1558282181@sss.pgh.pa.us>
Openpgp: preference=signencrypt
Autocrypt: addr=andrew.dunstan@2ndQuadrant.com; prefer-encrypt=mutual;
 keydata=
 xsBNBE7KWFkBCAClridxur2AIc7eW2AR7izbfp3EnNefie2HbLF0izW5Ik5UjX2HBXBx4syI
 gY6b0ugohXrr274+baoAlvSbq6cAoQuEVrk5IZFzt20b1Xkx65FwGSEj526yiKLocqkJceSq
 Xr9xcA5SGY+FZv441chh5SU92v4q6z+6LPpoHOh97ptAVXZYNTtU0LevyvD5lja0TzbvJm6C
 eFXitJfnm1pLEr0DGJCR/iUOl/N62Kh4855zZC7NHIjQHPOvV5Stz/l5ilDhvGVk+xkXFPys
 SjZoUr1rXhYLpiyi5sR0X9FHXT0KnGuz1F5ERO7ZTLSSQ6fJwPj6gOk9K+vvoKvoeql5ABEB
 AAHNL0FuZHJldyBEdW5zdGFuIDxhbmRyZXcuZHVuc3RhbkAybmRRdWFkcmFudC5jb20+wsCY
 BBMBAgBCAhsDBgsJCAcDAgYVCAIJCgsEFgIDAQIeAQIXgAUJDyV6hBYhBOQ+WEYd/Hy/RGkV
 pZn6f8tZ/DuBBQJcH/EVAhkBAAoJEJn6f8tZ/DuB7BEH/iDWZEbVft2m2MT6SPjARzTupt/l
 xLLZ/Cl6n2US2hov5+fBbnR5xvECk/YCOfG9ICvKNlpFjceqNLRKStd8cmndnI+kDw91uNM2
 hpL4aJMeW65XCHvqXlOLSwv5chBpXz9NG7FMaJ+q+59sWEWjcTNmjXgkEHn53y+1pc7nSLDe
 cr5ZI1aB3nGXRm1SoDY5PYZkUKMykW+YBZwgcs/Q5tRaE+siN7DKbz8E628+PerwAkmHPVXN
 MdJFD6gs4S0gDFA8IxcyIwZU2v4By+brzcJ9Se3FK5BYxBDHtaYZxgSrJAvOUOrLIZPQTQfL
 TtnVs3C3JTfrxCH1ceHtnA6dRuTOwE0ETspYWQEIANGc4zQULOxhbqO2dyD51YhqCNRmm9oK
 Waqf+wmW4tpDe/VVcxAnNizd4LWCHfzpb5cHAtGkOPePMfzWVf6nvdF7d3eglbtf59+zG7O7
 llV0xSSoFiieQBsrGvqDInXYX/4mRRXMtyhM353/tixC9RWLs1oofyYmCPPXXY7h9R7en3B8
 BoVrRFcdzlIY/NFNhFGW/9dkEiGjgna2Rk6e15kln4ZvFBWUg23p93w/pqXcxY6+k/8TEk+C
 4R+M6w7o2PLGOjdZ+kPiUcw5H85zf/yZJwQXzisXaNduwWB6Vads9YC9dj6kPR1c4VGRqAaY
 L++LAEOqrlvm2TvqQqZRtnEAEQEAAcLAZQQYAQIADwIbDAUCXA6fpAUJDyV6xAAKCRCZ+n/L
 Wfw7geU4B/9vFFsVmWxerDWgNjyiK80zIPmlw/iwdUlU6FIu0JWLMg4093kvxBs7RMZV9hBq
 n3ekBvD4IvFsVLJrw9qzSI2FH3UeYy5WXpEs01Ppia60NOlvRDqXbryzuvfe+iYo6bVP3Ikr
 TPTNYL/BePUTD2DPvSI82SbGTyzuA7SJv6NRqqQDMIy1fU6KyQFLmQJp/QJyhKWzm9jWh8ee
 w8jVaoMY0Kbq5N7RqisEx1Lu/Iw646UphdYzQNymf+kbiU5Kf4I6DhzV8w9sie1Bo1juNj3I
 c5/fFJsmxljbnaDbXPcnFsur1Oo9mIHFakgWgOBMuxoWfjONiLjjLh/9+ZIqSSLX
Message-ID: <16df9d01-8b03-2664-a18c-16c40186f5ab@2ndQuadrant.com>
Date: Sun, 19 May 2019 12:42:27 -0400
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:60.0) Gecko/20100101
 Thunderbird/60.6.1
MIME-Version: 1.0
In-Reply-To: <27719.1558282181@sss.pgh.pa.us>
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: quoted-printable
Content-Language: en-MW
Precedence: bulk


On 5/19/19 12:09 PM, Tom Lane wrote:
> I went back to take a closer look at why the existing regression tests
> failed to detect this problem.  As Michael already noted,
> src/bin/pg_ctl/t/004_logrotate.pl does try to exercise the logging
> collector, and we do have a couple of Windows machines that run the
> TAP tests, so how'd it escape notice?
>
> The answer indeed seems to be that it *was* noticed, but Andrew failed
> to realize what he was seeing:
>
> Author: Andrew Dunstan <andrew@dunslane.net>
> Branch: master [d611175e5] 2019-03-03 18:19:44 -0500
>
>     Don't do pg_ctl logrotate test on Windows
>    =20
>     The test crashes and burns quite badly, for some reason, but even i=
f it
>     didn't it wouldn't work, since Windows doesn't let you rename a fil=
e
>     held by a running process.
>
> But even when we do run it, it fails to detect any problem, because
> it's only testing for the existence of a log file not whether anything
> ever gets written into it.  As it happens, SysLogger_Start() creates
> the initial log file right in the postmaster (to validate the logging
> parameters), so as 004_logrotate.pl is constituted it fails to prove
> that the syslogger process got launched at all.  That's why it
> "passes" even when the syslogger is crashing instantly on launch.
>
> Given the current unpleasantness, I think it's quite important that
> we fix 004_logrotate.pl so that it (a) poses an end-to-end test
> and (b) works on Windows.  I think (a) could be managed by having
> the test execute guaranteed-to-fail SQL commands ("select 1/0" or
> the like) and making it look into the log file to verify that the
> expected error messages appear there.  (b) is a little harder in
> view of Andrew's point that we can't just summarily rename or unlink
> the log file.  But I don't much like using a fixed log file name
> in the test anyway.  I propose that we let it use the default logfile
> pattern (postgresql-%Y-%m-%d_%H%M%S.log), and that we just sleep for a
> couple of seconds before requesting rotation, and that we verify that
> the file name actually changed.  We can avoid difficult issues of
> guessing what file name got used by having the test script look into
> "current_logfiles" to get the name --- which is another feature that
> there's exactly zero test coverage of right now, so that seems like
> a win all around.
>


Worth a try.


cheers


andrew


--=20
Andrew Dunstan                https://www.2ndQuadrant.com
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services