Gentoo Websites Logo
Go to: Gentoo Home Documentation Forums Lists Bugs Planet Store Wiki Get Gentoo!
Bug 544118 - sys-libs/uclibc-0.9.33.2-r14: setbuf(stdout,NULL) is not respected after a printf()
Summary: sys-libs/uclibc-0.9.33.2-r14: setbuf(stdout,NULL) is not respected after a pr...
Status: CONFIRMED
Alias: None
Product: Gentoo Linux
Classification: Unclassified
Component: [OLD] Core system (show other bugs)
Hardware: AMD64 Linux
: Normal normal (vote)
Assignee: Embedded Gentoo Team
URL:
Whiteboard:
Keywords:
Depends on:
Blocks: uclibc-porting
  Show dependency tree
 
Reported: 2015-03-22 16:46 UTC by René Rhéaume
Modified: 2017-01-14 18:47 UTC (History)
0 users

See Also:
Package list:
Runtime testing required: ---


Attachments
build log from Portage (build.log,21.49 KB, text/plain)
2015-03-22 16:47 UTC, René Rhéaume
Details
lib/ss/test.diff (test.diff,154 bytes, text/plain)
2015-03-22 16:48 UTC, René Rhéaume
Details
lib/ss/test_out (test_out,451 bytes, text/plain)
2015-03-22 16:49 UTC, René Rhéaume
Details
emeerge --info output (emerge-info.txt,5.35 KB, text/plain)
2015-03-22 16:49 UTC, René Rhéaume
Details
poc to test where stdout/stderr go (test-stdout-stderr.c,417 bytes, text/x-csrc)
2015-03-30 00:20 UTC, Anthony Basile
Details
Makefile for the test I ran (Makefile,535 bytes, text/plain)
2015-03-30 00:24 UTC, Anthony Basile
Details

Note You need to log in before you can comment on or make changes to this bug.
Description René Rhéaume 2015-03-22 16:46:56 UTC
e2fsprogs-libs fails early in its test suite on uclibc (at least). I will attach the build log and test results.

Reproducible: Always

Steps to Reproduce:
1. FEATURES="test" emerge -1 e2fsprogs-libs

Actual Results:  
 * ERROR: sys-libs/e2fsprogs-libs-1.42.12::gentoo failed (test phase):
 *   Make check failed. See above for details.


Expected Results:  
e2fsprogs-libs updated on system
Comment 1 René Rhéaume 2015-03-22 16:47:42 UTC
Created attachment 399474 [details]
build log from Portage
Comment 2 René Rhéaume 2015-03-22 16:48:34 UTC
Created attachment 399476 [details]
lib/ss/test.diff
Comment 3 René Rhéaume 2015-03-22 16:49:08 UTC
Created attachment 399478 [details]
lib/ss/test_out
Comment 4 René Rhéaume 2015-03-22 16:49:46 UTC
Created attachment 399480 [details]
emeerge --info output
Comment 5 Anthony Basile gentoo-dev 2015-03-27 13:16:07 UTC
Looks like you have uclibc-0.9.33.2-r4 which doesn't have the patch which adds fallocate64() which >=sys-fs/e2fsprogs-1.42.10 requires.  Hence your config.log has:

checking for fallocate... no
checking for fallocate64... no

I'm not sure, but it seems that this is at least related, if not a repeat of bug #516988. I didn't hit it via the tests on e2fsprogs-libs but directly when building sys-fs/e2fsprogs-1.42.10.  But I wouldn't be surprised if it messes up the tests too.

Can you try this before I jump into the code.  Upgrade to uclibc-0.9.33.2-r14.  Make sure you use your savedconfig so you don't break your system.  Then retest and report.
Comment 6 René Rhéaume 2015-03-28 01:20:44 UTC
(In reply to Anthony Basile from comment #5)
> Looks like you have uclibc-0.9.33.2-r4 which doesn't have the patch which
> adds fallocate64() which >=sys-fs/e2fsprogs-1.42.10 requires.  Hence your
> config.log has:
> 
> checking for fallocate... no
> checking for fallocate64... no

It is a bogus check in e2fsprogs-libs configure script. fallocate* are not used in the source code of e2fsprogs-libs (although fallocate* is used in e2fsprogs, and that is another story).
Comment 7 Anthony Basile gentoo-dev 2015-03-28 12:22:08 UTC
(In reply to René Rhéaume from comment #6)
> (In reply to Anthony Basile from comment #5)
> > Looks like you have uclibc-0.9.33.2-r4 which doesn't have the patch which
> > adds fallocate64() which >=sys-fs/e2fsprogs-1.42.10 requires.  Hence your
> > config.log has:
> > 
> > checking for fallocate... no
> > checking for fallocate64... no
> 
> It is a bogus check in e2fsprogs-libs configure script. fallocate* are not
> used in the source code of e2fsprogs-libs (although fallocate* is used in
> e2fsprogs, and that is another story).

Okay thanks.  I can see that since e2fsprogs and e2fsprogs-libs is really the same package.  Its one of those rare cases where we divide the executables from their library.

Did you test with -r14 though?  I'll try later and see.
Comment 8 Anthony Basile gentoo-dev 2015-03-29 22:26:34 UTC
(In reply to Anthony Basile from comment #7)
> Did you test with -r14 though?  I'll try later and see.

Okay I tested myself and this is a false positive.  The interesting line is in $(top_builddir)/lib/ss/Makefile and it reads:

-@(LD_LIBRARY_PATH=$(LIB) DYLD_LIBRARY_PATH=$(LIB) ./test_ss -f $(srcdir)/test_script > test_out 2>&1; exit 0)

This generates two outputs which are concatenated.  stdin gives:

amd64-uclibc-hardened-latest ss # ./test_ss -f ../../../e2fsprogs-libs-1.42.12/lib/ss/test_script 2>/dev/null
test_ss 1.0.  Type '?' for a list of commands.

test_icount: test
Hello, world!
Args: 
test_icount: test foo bar quux
Hello, world!
Args: 'foo', 'bar', 'quux'
test_icount: test bar quux
Hello, world!
Args: 'bar', 'quux'
test_icount: quux bar
test_icount: quux
test_icount: test quux
Hello, world!
Args: 'quux'
test_icount: quit
test_icount: test foo bar
Hello, world!
Args: 'foo', 'bar'

and stderr gives

amd64-uclibc-hardened-latest ss # ./test_ss -f ../../../e2fsprogs-libs-1.42.12/lib/ss/test_script >/dev/null
test_ss: Command not found quux
test_ss: Command not found quux

And when concatenated together we get

 # ./test_ss -f ../../../e2fsprogs-libs-1.42.12/lib/ss/test_script
test_ss 1.0.  Type '?' for a list of commands.

test_icount: test
Hello, world!
Args: 
test_icount: test foo bar quux
Hello, world!
Args: 'foo', 'bar', 'quux'
test_icount: test bar quux
Hello, world!
Args: 'bar', 'quux'
test_icount: quux bar
test_ss: Command not found quux
test_icount: quux
test_ss: Command not found quux
test_icount: test quux
Hello, world!
Args: 'quux'
test_icount: quit
test_icount: test foo bar
Hello, world!
Args: 'foo', 'bar'

which is identical to test_script_expected.  So why does the test fail?  If you take a look at test_out, it *doesn't* read as above!!!! Rather stderr's output is near the top:

amd64-uclibc-hardened-latest ss # head -n 6 test_out 
test_ss 1.0.  Type '?' for a list of commands.

test_ss: Command not found quux
test_ss: Command not found quux
test_icount: test
Hello, world!

So a failure occurs when the Makefile does

$(Q) if diff test_out $(srcdir)/test_script_expected > test.diff; then \
                true ; else echo "Regression test for ss library failed!"; exit 1 ; fi


To see this better, diff the two:


amd64-uclibc-hardened-latest ss # diff -Naur test_out ../../../e2fsprogs-libs-1.42.12/lib/ss/test_script_expected 
--- test_out	2015-03-29 21:52:12.701947827 +0000
+++ ../../../e2fsprogs-libs-1.42.12/lib/ss/test_script_expected	2011-01-14 18:07:50.000000000 +0000
@@ -1,7 +1,5 @@
 test_ss 1.0.  Type '?' for a list of commands.
 
-test_ss: Command not found quux
-test_ss: Command not found quux
 test_icount: test
 Hello, world!
 Args: 
@@ -12,7 +10,9 @@
 Hello, world!
 Args: 'bar', 'quux'
 test_icount: quux bar
+test_ss: Command not found quux
 test_icount: quux
+test_ss: Command not found quux
 test_icount: test quux
 Hello, world!
 Args: 'quux'

They are not the same.  So what's going on here?  Well this *may* be a bug in how uclibc treats stdout/stderr when the process has a controlling tty vs when it doesn't.  stdout is line-buffered when there is a ctty, meaning that as soon as it hits a newline, the libc buffer is flushed with a write syscall.  But stderr is unbuffered.  What does that mean when doing ./some_test > test.out 2>&1>  On uclibc you get stdout near first, while on glibc you get stdout/stderr intermixed.  So the test fails on uclibc but passes on glibc but for reasons other than intended.

Bottom line, this isn't a problem in libss.so or libcom_err.so which is what the test is testing.  But it may be a problem in how uclibc treats stdout/stderr.  I'll check what POSIX requires and write some reduced test.  Leave this bug open for now until I get this straight.
Comment 9 Anthony Basile gentoo-dev 2015-03-29 22:28:32 UTC
(In reply to Anthony Basile from comment #8)
> This generates two outputs which are concatenated.  stdin gives:
> 

That should read stdout.  (sorry i'm dyslexic sometimes)
Comment 10 Anthony Basile gentoo-dev 2015-03-29 22:30:50 UTC
(In reply to Anthony Basile from comment #8)
> (In reply to Anthony Basile from comment #7)
>  On uclibc you get stdout near first, while on
> glibc you get stdout/stderr intermixed. 

And here's another one ... that should read

On uclibc you get stderr first, while on glibc you get stdout/stderr intermixed.
Comment 11 Anthony Basile gentoo-dev 2015-03-30 00:20:53 UTC
Created attachment 400106 [details]
poc to test where stdout/stderr go
Comment 12 Anthony Basile gentoo-dev 2015-03-30 00:24:26 UTC
Created attachment 400108 [details]
Makefile for the test I ran

So I'm still not sure how test_ss does it buffering because I'm getting the same results in uclibc and glibc.  These are as expected given how stdout and stderr buffer.

amd64-uclibc-hardened-latest stdout-stderr # more out.*
::::::::::::::
out.flush.buf
::::::::::::::
stderr 1
stderr 2
stderr 3
stdout 1
stdout 2
stdout 3
::::::::::::::
out.flush.nobuf
::::::::::::::
stderr 1
stdout 1
stderr 2
stdout 2
stderr 3
stdout 3
::::::::::::::
out.noflush.buf
::::::::::::::
stderr 1
stderr 2
stderr 3
::::::::::::::
out.noflush.nobuf
::::::::::::::
stderr 1
stdout 1
stderr 2
stdout 2
stderr 3
stdout 3
Comment 13 Anthony Basile gentoo-dev 2015-03-30 00:28:52 UTC
Finally to see the line buffering kick in, you can run all four test-{,no}flush-{,no}buf from the command line in both uclibc and glibc and get:

# ./test-<any>
stderr 1
stdout 1
stderr 2
stdout 2
stderr 3
stdout 3


Again, as expected.
Comment 14 Anthony Basile gentoo-dev 2015-03-30 01:53:29 UTC
Okay I have reduced code showing the problem:

#include <stdio.h>
#include <stdlib.h>

int main() {
        printf("stdout 0\n");

        fflush(stdout);
        fflush(stderr);
        setbuf(stdout, NULL);
        setbuf(stderr, NULL);

        fprintf(stderr,"stderr 1\n");
        printf("stdout 1\n");
        fprintf(stderr,"stderr 2\n");
        printf("stdout 2\n");

        exit(0);
}

On a glibc system, running either `./test` or `./test > test_out 2>&1` yields

stdout 0
stderr 1
stdout 1
stderr 2
stdout 2

While on a uclibc system, running `./test` yields the above, yet `./test > test_out 2>&1` yields

stdout 0
stderr 1
stderr 2
stdout 1
stdout 2


So it looks like the first printf("stdout 0\n"); nullifies the setbuf(stdout,NULL).  If you comment it out, you restore the expected behavior.
Comment 15 Anthony Basile gentoo-dev 2015-04-21 21:24:10 UTC
Acutally according to `man 3 stderr` in NOTES, stderr is not buffered, so you don't need to fflush(stderr); setbuf(stderr, NULL);  The above code reduces to the following.  I've tested on uclibc-0.9.33.2-r14, 0.9.33.9999 and 9999 with the same result.

#include <stdio.h>
#include <stdlib.h>

int main() {
        printf("stdout 0\n");

        fflush(stdout);
        setbuf(stdout, NULL);

        fprintf(stderr,"stderr 1\n");
        printf("stdout 1\n");
        fprintf(stderr,"stderr 2\n");
        printf("stdout 2\n");

        exit(0);
}
Comment 16 René Rhéaume 2017-01-14 18:47:47 UTC
I continue to have the symptoms of the bug, this time with e2fsprogs-libs-1.43.3 and uclibc-ng 1.0.17. May look again after I updated to uclibc-ng 1.0.19 (not for the short term, I have around 130 package updates to babysit)