Subject: [PATCH 0/1] cygwin test failures due to printf

From: Ramsay Jones <[email-masked]>
Date: Sat, 15 Dec 2012 19:08:42 +0000

Hi Junio,

Sorry for being a bit tardy on this; I noticed these test failures
on cygwin close to the start of this cycle, just before I went
into hospital, but have only just got around to looking into it...

In particular, the following tests fail: t0021, t0030, t1410, t3032,
t3304, t3404 and t4132. [The list of failing tests is not actually
all that interesting, because the fault is not actually with the
tests!]

These failures are provoked by commit 7bc0911d ("test-lib: Fix say_color ()
not to interpret \a\b\c in the message", 11-10-2012).

If we look at t0021 as a representative, then:

    $ ./t0021-conversion.sh
    ok 1 - setup
    ok 2 - check
    ok 3 - expanded_in_repo
          5 [sig] sh 2388 C:\cygwin\bin\sh.exe: *** fatal error - called with threadlist_ix -1
    ./test-lib.sh: line 207:  2388 Hangup                  \
        ( TERM=$ORIGINAL_TERM; export TERM; case "$1" in
        error)
            tput bold; tput setaf 1
        ;;
        skip)
            tput bold; tput setaf 4
        ;;
        warn)
            tput bold; tput setaf 3
        ;;
        pass)
            tput setaf 2
        ;;
        info)
            tput setaf 3
        ;;
        *)
            test -n "$quiet" && return
        ;;
    esac; shift; printf "%s" "$*"; tput sgr0; echo )
    ok 4 - filter shell-escaped filenames
    ok 5 - required filter success
    ok 6 - required filter smudge failure
    ok 7 - required filter clean failure
    # passed all 7 test(s)
    1..7
    $ 

We see that the "--color" version of say_color(), despite the bash builtin
printf function crashing the shell (sh.exe is actually bash for me), passes
just fine. Note that the message passed to say_color() is printed before
the shell is aborted (via SIGHUP), but that the "tput sgr0; echo" has been
skipped. This results in the occasional line of output in the wrong colour.

This has been happening for several years and, given that there are no
adverse consequences (ignoring the additional error message spew), I have
been happy to ignore this problem. :D

Note that the "--no-color" version of say_color() did not have this problem
since it used echo, rather than printf, until commit 7bc0911d ... 

    $ ./t0021-conversion.sh --no-color
    ok 1 - setup
    ok 2 - check
    ok 3 - expanded_in_repo
          6 [sig] sh 2740 C:\cygwin\bin\sh.exe: *** fatal error - called with threadlist_ix -1
    Hangup
    $ 

Note that, unlike the "--color" version of say_color(), the printf call is
not contained within a sub-shell. Indeed, a simple solution to this problem
would be to execute the body of the function from within a "(...)" sub-shell.
This actually works, since the extra error message spew does not cause a
TAP syntax error to confuse 'prove'. However, I would never suggest this
as a solution, given that it already takes over 3 hours to run the tests...

Also, note that another solution is to call the external version of printf
(e.g. via /usr/bin/printf) but, again, I would not suggest adding to the
fork-exec load by replacing a call to a shell builtin with an external
program...

Note that:

    $ cygcheck /bin/sh.exe
    C:/cygwin/bin/sh.exe
      C:/cygwin/bin\cygwin1.dll
        C:\WINDOWS\system32\ADVAPI32.DLL
          C:\WINDOWS\system32\KERNEL32.dll
            C:\WINDOWS\system32\ntdll.dll
          C:\WINDOWS\system32\RPCRT4.dll
            C:\WINDOWS\system32\Secur32.dll
      C:/cygwin/bin\cygintl-8.dll
        C:/cygwin/bin\cygiconv-2.dll
      C:/cygwin/bin\cygreadline6.dll
        C:/cygwin/bin\cygncurses-8.dll
        C:\WINDOWS\system32\USER32.dll
          C:\WINDOWS\system32\GDI32.dll
    $ 

    $ strings /bin/cygwin1.dll | grep 'called with'
    called with threadlist_ix %d
    called with invalid value %d
    openlog called with (%s, %d, %d)
    $

So, the error message is coming from the cygwin dll (no surprise there).
I have a fairly recent source snapshot of cygwin, but this message or the
code that uses it is not present. In order to debug this further, I would
need to find the source code for the version I am using (1.5.22). This does
not excite me too much. ;-)

As a simpler solution, the patch which follows allows me to customize
the function used to do the output. This allows me to revert to using
echo and, as a bonus, fixes the "--color" version of say_color() at the
same time.

I admit that I find this solution a bit ugly, but it has (at least) two
virtues:
   1. it works!
   2. it's not as ugly as some other solutions I had tried. :-P

ATB,
Ramsay Jones