GNU bug report logs - #35762
When `test-driver` script + `check` testing framework are writing to same logfile = corrupted output

Previous Next

Package: automake;

Reported by: howaboutsynergy <at> protonmail.com

Date: Thu, 16 May 2019 14:32:01 UTC

Severity: normal

Done: Karl Berry <karl <at> freefriends.org>

Bug is archived. No further changes may be made.

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 35762 in the body.
You can then email your comments to 35762 AT debbugs.gnu.org in the normal way.

Toggle the display of automated, internal messages from the tracker.

View this report as an mbox folder, status mbox, maintainer mbox


Report forwarded to bug-automake <at> gnu.org:
bug#35762; Package automake. (Thu, 16 May 2019 14:32:01 GMT) Full text and rfc822 format available.

Acknowledgement sent to howaboutsynergy <at> protonmail.com:
New bug report received and forwarded. Copy sent to bug-automake <at> gnu.org. (Thu, 16 May 2019 14:32:02 GMT) Full text and rfc822 format available.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: howaboutsynergy <at> protonmail.com
To: "bug-automake <at> gnu.org" <bug-automake <at> gnu.org>
Subject: When `test-driver` script + `check` testing framework are writing to
 same logfile = corrupted output
Date: Thu, 16 May 2019 08:07:36 +0000
[Message part 1 (text/plain, inline)]
Hi. This isn't a bug, but just to inform you that `test-driver` redirecting stdout(and stderr) to the log file, coupled with  the test itself also writing to the same log file(for whatever reason), will result in them both using the same outfile (with different descriptors) thus corrupted output is the result.

For an example of what happens, see this comment: https://github.com/libcheck/check/issues/188#issuecomment-492794060 which I'll reproduce below for easy reading.

For exact reproduction steps with using `check` (the unit test framework for C) see the previous comment aka https://github.com/libcheck/check/issues/188#issuecomment-492782675

#include <stdio.h>
  

int main() {
  FILE *f=NULL;
  f = fopen("/tmp/a_out_.log", "w");
  if (NULL == f) {
    fprintf(stderr,"oopsie\n");
  } else {
    fprintf(stdout, "Something");
    fprintf(f," messy ");
    fprintf(f," jessy\n");
    fprintf(stdout, " or another\n");
    fprintf(f,"More stuff\n");
    fclose(f);                                                                                                                  

  }
}

$ gcc a.c && { ./a.out >/tmp/a_out_.log ; cat /tmp/a_out_.log ; }
Something or another
uff

That's basically what happens.

I'm on Arch Linux, and have the following versions:

local/autoconf 2.69-5 (base-devel)
    A GNU tool for automatically configuring source code
local/autoconf2.13 2.13-5
    A GNU tool for automatically configuring source code (Legacy 2.1x version)
local/automake 1.16.1-1 (base-devel)
    A GNU tool for automatically creating Makefiles

$ automake --version
automake (GNU automake) 1.16.1

$ autoconf --version
autoconf (GNU Autoconf) 2.69

$ make --version
GNU Make 4.2.1
Built for x86_64-pc-linux-gnu

  # test-driver - basic testsuite driver script.
  

  scriptversion=2018-03-07.03; # UTC

Thanks.
[publickey - howaboutsynergy@protonmail.com - 0x947B9B34.asc (application/pgp-keys, attachment)]
[signature.asc (application/pgp-signature, attachment)]

Information forwarded to bug-automake <at> gnu.org:
bug#35762; Package automake. (Thu, 16 May 2019 17:58:02 GMT) Full text and rfc822 format available.

Message #8 received at 35762 <at> debbugs.gnu.org (full text, mbox):

From: howaboutsynergy <at> protonmail.com
To: "35762 <at> debbugs.gnu.org" <35762 <at> debbugs.gnu.org>
Subject: (No Subject)
Date: Thu, 16 May 2019 17:40:39 +0000
[Message part 1 (text/plain, inline)]
A possible fix, or mitigation, based on the answer by John Bollinger[1] follows. I have tested this to work[2] even though it requires changes[2] in the program that created the test(s) executables and that program is 'check' - A unit testing framework for C [3].

[1] https://stackoverflow.com/a/56168216/11509478
[2] https://github.com/libcheck/check/issues/188#issuecomment-493161758
[3] https://github.com/libcheck/check

--- /tmp/test-driver	2018-09-18 15:06:54.000000000 +0200
+++ /usr/share/automake-1.16/test-driver	2019-05-16 17:58:09.690988983 +0200
@@ -104,7 +104,8 @@ trap "st=141; $do_exit" 13
 trap "st=143; $do_exit" 15

 # Test script is run here.
-"$@" >$log_file 2>&1
+echo -n "" >"$log_file"
+"$@" >>"$log_file" 2>&1
 estatus=$?

 if test $enable_hard_errors = no && test $estatus -eq 99; then


(the above patch is also attached)

Cheers.
[a.patch (text/x-patch, attachment)]
[publickey - howaboutsynergy@protonmail.com - 0x947B9B34.asc (application/pgp-keys, attachment)]
[signature.asc (application/pgp-signature, attachment)]

Information forwarded to bug-automake <at> gnu.org:
bug#35762; Package automake. (Thu, 16 May 2019 18:14:01 GMT) Full text and rfc822 format available.

Message #11 received at 35762 <at> debbugs.gnu.org (full text, mbox):

From: Eric Blake <eblake <at> redhat.com>
To: howaboutsynergy <at> protonmail.com,
 "35762 <at> debbugs.gnu.org" <35762 <at> debbugs.gnu.org>
Subject: Re: bug#35762: (No Subject)
Date: Thu, 16 May 2019 13:12:50 -0500
[Message part 1 (text/plain, inline)]
On 5/16/19 12:40 PM, howaboutsynergy <at> protonmail.com wrote:
> A possible fix, or mitigation, based on the answer by John Bollinger[1] follows. I have tested this to work[2] even though it requires changes[2] in the program that created the test(s) executables and that program is 'check' - A unit testing framework for C [3].
> 
> [1] https://stackoverflow.com/a/56168216/11509478
> [2] https://github.com/libcheck/check/issues/188#issuecomment-493161758
> [3] https://github.com/libcheck/check
> 
> --- /tmp/test-driver	2018-09-18 15:06:54.000000000 +0200
> +++ /usr/share/automake-1.16/test-driver	2019-05-16 17:58:09.690988983 +0200
> @@ -104,7 +104,8 @@ trap "st=141; $do_exit" 13
>  trap "st=143; $do_exit" 15
> 
>  # Test script is run here.
> -"$@" >$log_file 2>&1
> +echo -n "" >"$log_file"

'echo -n' is non-portable, but since all you are doing is using it to
create an empty file, it's simpler to just:

: >"$log_file"

> +"$@" >>"$log_file" 2>&1
>  estatus=$?
> 
>  if test $enable_hard_errors = no && test $estatus -eq 99; then
> 
> 
> (the above patch is also attached)
> 
> Cheers.
> 

-- 
Eric Blake, Principal Software Engineer
Red Hat, Inc.           +1-919-301-3226
Virtualization:  qemu.org | libvirt.org

[signature.asc (application/pgp-signature, attachment)]

Information forwarded to bug-automake <at> gnu.org:
bug#35762; Package automake. (Thu, 16 May 2019 18:48:01 GMT) Full text and rfc822 format available.

Message #14 received at 35762 <at> debbugs.gnu.org (full text, mbox):

From: howaboutsynergy <at> protonmail.com
To: "35762 <at> debbugs.gnu.org" <35762 <at> debbugs.gnu.org>
Subject: Re: bug#35762: (No Subject)
Date: Thu, 16 May 2019 18:25:57 +0000
[Message part 1 (text/plain, inline)]


Sent with ProtonMail Secure Email.

‐‐‐‐‐‐‐ Original Message ‐‐‐‐‐‐‐
On Thursday, May 16, 2019 8:12 PM, Eric Blake <eblake <at> redhat.com> wrote:

> On 5/16/19 12:40 PM, howaboutsynergy <at> protonmail.com wrote:
> 

> > A possible fix, or mitigation, based on the answer by John Bollinger[1] follows. I have tested this to work[2] even though it requires changes[2] in the program that created the test(s) executables and that program is 'check' - A unit testing framework for C [3].
> > [1] https://stackoverflow.com/a/56168216/11509478
> > [2] https://github.com/libcheck/check/issues/188#issuecomment-493161758
> > [3] https://github.com/libcheck/check
> > --- /tmp/test-driver 2018-09-18 15:06:54.000000000 +0200
> > +++ /usr/share/automake-1.16/test-driver 2019-05-16 17:58:09.690988983 +0200
> > @@ -104,7 +104,8 @@ trap "st=141; $do_exit" 13
> > trap "st=143; $do_exit" 15
> > 

> > Test script is run here.
> > 

> > =========================
> > 

> > -"$@" >$log_file 2>&1
> > +echo -n "" >"$log_file"
> 

> 'echo -n' is non-portable, but since all you are doing is using it to
> create an empty file, it's simpler to just:
> 

> : >"$log_file"
Very cool! Thank you very much! I'll use that in my local automake rebuild.
Where can I find more information about ":" ? it seems kinda tough to search for.

PS: Sorry for any dups, I previously pressed Reply instead of Reply All. My mistake:)

> 

> > +"$@" >>"$log_file" 2>&1
> > estatus=$?
> > if test $enable_hard_errors = no && test $estatus -eq 99; then
> > (the above patch is also attached)
> > Cheers.
> 

> --
> 

> Eric Blake, Principal Software Engineer
> Red Hat, Inc. +1-919-301-3226
> Virtualization: qemu.org | libvirt.org

[publickey - howaboutsynergy@protonmail.com - 0x947B9B34.asc (application/pgp-keys, attachment)]
[signature.asc (application/pgp-signature, attachment)]

Information forwarded to bug-automake <at> gnu.org:
bug#35762; Package automake. (Thu, 16 May 2019 19:23:02 GMT) Full text and rfc822 format available.

Message #17 received at 35762 <at> debbugs.gnu.org (full text, mbox):

From: Nick Bowler <nbowler <at> draconx.ca>
To: howaboutsynergy <at> protonmail.com
Cc: "35762 <at> debbugs.gnu.org" <35762 <at> debbugs.gnu.org>
Subject: Re: bug#35762: (No Subject)
Date: Thu, 16 May 2019 15:22:50 -0400
On 2019-05-16, howaboutsynergy <at> protonmail.com
<howaboutsynergy <at> protonmail.com> wrote:
> On Thursday, May 16, 2019 8:12 PM, Eric Blake <eblake <at> redhat.com> wrote:
[...]
>> : >"$log_file"
> Very cool! Thank you very much! I'll use that in my local automake
> rebuild.  Where can I find more information about ":" ? it seems kinda
> tough to search for.

The relevant standards are a good place to start:

  https://pubs.opengroup.org/onlinepubs/9699919799/utilities/V3_chap02.html#colon

Cheers,
  Nick




Information forwarded to bug-automake <at> gnu.org:
bug#35762; Package automake. (Tue, 24 Nov 2020 02:07:02 GMT) Full text and rfc822 format available.

Message #20 received at 35762 <at> debbugs.gnu.org (full text, mbox):

From: Karl Berry <karl <at> freefriends.org>
To: 35762 <at> debbugs.gnu.org
Subject: Re: bug#35762: (No Subject)
Date: Mon, 23 Nov 2020 19:06:51 -0700
   : >"$log_file"
   "$@" >>"$log_file" 2>&1

I committed this change to test-driver, so it'll (finally) be in the
next release. (Sorry for the long-delayed response.)

(I was tempted to make the script exit unsuccessfully if either of the
commands failed (e.g., add  || exit 1  or some such), but I was too scared.)

Thanks for the report,
Karl




Reply sent to Karl Berry <karl <at> freefriends.org>:
You have taken responsibility. (Tue, 24 Nov 2020 02:07:03 GMT) Full text and rfc822 format available.

Notification sent to howaboutsynergy <at> protonmail.com:
bug acknowledged by developer. (Tue, 24 Nov 2020 02:07:03 GMT) Full text and rfc822 format available.

bug archived. Request was from Debbugs Internal Request <help-debbugs <at> gnu.org> to internal_control <at> debbugs.gnu.org. (Tue, 22 Dec 2020 12:24:09 GMT) Full text and rfc822 format available.

This bug report was last modified 3 years and 97 days ago.

Previous Next


GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.