Re: Improving log capture of TAP tests with IPC::Run

On Wed, Jul 8, 2015 at 6:10 AM, Heikki Linnakangas <hlinnaka(at)iki(dot)fi> wrote:
> On 06/25/2015 07:14 AM, Michael Paquier wrote:
>>
>> After looking at the issues with the TAP test suite that hamster faced
>> a couple of days ago, which is what has been discussed on this thread:
>> http://www.postgresql.org/message-id/13002.1434307025@sss.pgh.pa.us
>>
>> I have developed a patch to improve log capture of the TAP tests by
>> being able to collect stderr and stdout output of each command run in
>> the tests by using more extensively IPC::Run::run (instead of system()
>> that is not able to help much) that has already been sent on the
>> thread above.
>
>
> This is a massive improvement to the usability of TAP tests. They are
> practically impossible to debug currently. Thanks for working on this!
>
> The patch redirects the output of all "system_or_bail" commands to a log
> file. That's a good start, but I wish we could get *everything* in the same
> log file. That includes also:
>
> * stdout and stderr of *all* commands. Including all the commands run with
> command_ok/command_fails.

That makes sense. I have switched command_ok, command_exit_is and
command_fails to show up their output instead of having them sent to
void.

> * the command line of commands being executed. It's difficult to follow the
> log when you don't know which output corresponds to which command.

OK, I have added some stuff for that. Let me know your thoughts. Each
command started is printed in the log file before starting with a
message mentioning what is the type of test used.

> * whenever a test case is reported as success/fail.

Just to be sure, does this concern the "ok/not ok" messages printed
out by each test run? Or is it a custom message that you have in mind?

> Looking at the manual page of Test::More, it looks like you could change
> where the perl script's STDOUT and STDERR point to, because Test::More takes
> a copy of them (when? at program startup I guess..). That would be much more
> convenient than decorating every run call with ">> logfile".

Hm. There are two types of logs we want to capture:
1) stdout and stderr from the subprocesses kicked by IPC::Run::run
2) Status messages written in the log file by the process running the tests.
Perhaps we could redirect the output of stdout and stderr but I think
that this is going to need an fd open from the beginning of the test
until the end, with something like that:
open my $test_logfile_fd, '>>', $test_logfile;
*STDOUT = $test_logfile_fd;
*STDERR = $test_logfile_fd;

While that would work on OSX and Linux for sure, I suspect that this
will not on Windows where two concurrent processes cannot write to the
same file. Also, the output can be correctly captured by just
appending that to a couple of places:
[ '>>', $test_logfile, '2>&1']
And this solution proves to work as well on Windows...
--
Michael