Buffering `printf` outputs between different threads in Linux
Asked Answered
N

2

0

Here is my code:

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

pthread_t ntid;void
printids(const char *s) {
  printf("%s \n", s);
}

void *
thr_fn(void *arg)   {
  printids("new thread: ");
  return((void *)0);
}

int
main(void)  {
  pthread_create(&ntid, NULL, thr_fn, NULL);
  printids("main thread:");
}

I'm running it on Red Hat Enterprise Linux Workstation release 6.5 .
Here is my compiling command

gcc -ansi -g -std=c99 -Wall -DLINUX -D_GNU_SOURCE threadid.c -o threadid -pthread -lrt -lbsd

Here is the output:

main thread:
new thread:
new thread:

Why "new thread" has been printed twice? I doubt this may related to buffering mechanism in Linux. But after I added fflush(stdout) and fsync(1) in the end of each function. The output is almost the same.

If you run the program several times. The output differs:

main thread:
new thread:

or

main thread:
new thread:
new thread:

Or

main thread:

Niggardly answered 14/8, 2017 at 7:7 Comment(14)
What do you mean with "almost the same"? If there are differences, what are they?Apoenzyme
This doesn't compile. Please make it a minimal reproducible example. I don't think the doubled output can be caused by the lines you provide here.Lovmilla
adding a declaration for ntid and a pthread_join() gives exactly the expected output, btw.Lovmilla
Cannot reproduce (after having added a pthread_t ntid definition).Bunche
Did you actually try the code you posted here (which is at least complete now after the edit)? It gives the expected output, nothing is printed twice. It might not print new thread: at all as you don't do a pthread_join(), so the program could end before the new thread had a chance to run. But it's impossible this is printed twice.Lovmilla
You can run it multiple times. @StephanLechnerNiggardly
Gave it about 20 tries; at least no double output of new thread:.Bunche
I can expect a scenario where only main thread gets printed, because you don't wait for the created thread. But I cannot reproduce double new thread.Tubercular
By the way, there's only one buffer per process. The worst that could happen is that the output from the main and child threads become intermingled, but you should not get duplication. Duplication similar to what you show can happen when creating a child process though, but should not happen with threads.Apoenzyme
@Someprogrammerdude I believe you are referring to the buffer associated with stdout from the operating system, but the libc implementation could have a per thread output buffer.Tubercular
@AjayBrahmakshatriya No I mean the C standard I/O buffering used by printf. And no matter if it's implemented using one buffer per process, or one per thread, this duplication should not happen. Especially if it's one buffer per thread.Apoenzyme
@Someprogrammerdude what do you think about the scenario I mentioned in my answer below? I agree the case I mentioned would be a bug in the implementation of libc, but could be possible.Tubercular
Can you post the output from ldd threadid? If you're linking in some library with a non-thread-safe stdout stream, that could explain your inconsistent results.Tactic
linux-vdso.so.1 => (0x00007fff6efff000) librt.so.1 => /lib64/librt.so.1 (0x0000003f77c00000) libpthread.so.0 => /lib64/libpthread.so.0 (0x0000003f77400000) libc.so.6 => /lib64/libc.so.6 (0x0000003f76c00000) /lib64/ld-linux-x86-64.so.2 (0x0000003f76400000) @AndrewHenleNiggardly
T
5

Most libc libraries do buffer the output as you mentioned. And at the end of the program (when the main thread exits), they flush all the buffers and exit.

There is a slight possibility that your new thread has flushed the output but before it could update the state of the buffer, the main program exited and the cleanup code flushed the same buffer again. Since these buffers are local to the thread I am sure they won't have concurrency mechanism. But because of this rare case it might get messed up.

You can try

err = pthread_create(&ntid, NULL, thr_fn, NULL);
printids("main thread:");
pthread_join(ntid, NULL);

At the end of the main function and check if the problem is solved.

This will cause your main function to wait till the new thread is finished (including the flushing operation it does).

Tubercular answered 14/8, 2017 at 7:39 Comment(5)
Given Linux's conflation of threads and processes (they're similar, but different), I suspect that this is the cause of the trouble when the main thread exits without waiting for the child thread to complete.Zara
@JonathanLeffler: I disagree. GLIBC does have internal locking for multithreading, as the various interfaces (including fflush()) are marked MT-Safe. I believe the underlying cause is the fact that return from main() in Linux immediately kills all threads (both that and exit() actually invoke the exit_group() syscall). Simply put, I don't believe the newly started thread(s) always get(s) to run before it is killed.Mcqueen
@NominalAnimal how can we explain the duplication? (if it indeed is happening, I cannot reproduce).Tubercular
@NominalAnimal and I agree that the implementation of fflush must be having locks but on the side that it deals with the stdout fd. Are there locks for updating the per thread buffer states?Tubercular
@AjayBrahmakshatriya: The locks are per stream, not per thread, and the final flush at end of process has an explicit lock. Unless the OP has a C library compiled for !_IO_MTSAFE_IO, or OP is using _unlocked() versions of the I/O functions, I don't see any way you could get a duplicate output using only one thread (in addition to the main one).Mcqueen
A
2

Double output is possible on glibc-based linux systems due to a nasty bug in glibc: if the FILE lock is already held at the time exit tries to flush, the lock is simply ignored and the buffer access is performed with no synchronization. This would be a great test case to report to glibc to pressure them to fix it, if you can reproduce it reliably.

Armilla answered 14/8, 2017 at 11:25 Comment(1)
Looks like there are even more threading bugs in glibc's exit handling: sourceware.org/bugzilla/show_bug.cgi?id=14333Tactic

© 2022 - 2024 — McMap. All rights reserved.