On Sun, Mar 03, 2019 at 12:13:29PM +0100, Sebastien Marie wrote: > On Sat, Mar 02, 2019 at 04:00:19PM +0000, Visa Hankala wrote: > > On Sat, Mar 02, 2019 at 04:37:04PM +0100, Sebastien Marie wrote: > > > Thread 1 (thread 469200): > > > #0 sched_yield () at -:3 > > > #1 0x00000a8c0609d9c5 in _libc__spinlock (lock=Variable "lock" is not > > > available.) at /usr/src/lib/libc/thread/rthread.c:50 > > > #2 0x00000a8c060702be in _thread_flockfile (fp=0x7f7ffffcfaa8) at > > > /usr/src/lib/libc/thread/rthread_file.c:180 > > > #3 0x00000a8c0609e11a in _libc_fflush (fp=0x7f7ffffcfaa8) at > > > /usr/src/lib/libc/stdio/fflush.c:46 > > > #4 0x00000a8c0606c89a in _libc_vdprintf (fd=Variable "fd" is not > > > available.) at /usr/src/lib/libc/stdio/vdprintf.c:72 > > > #5 0x00000a8c060a7f63 in _libc__rthread_debug (level=Variable "level" is > > > not available.) at /usr/src/lib/libc/thread/rthread_debug.c:23 > > > #6 0x00000a8c060410c5 in _rthread_mutex_timedlock (mutexp=Variable > > > "mutexp" is not available.) at > > > /usr/src/lib/libc/thread/rthread_mutex.c:163 > > > #7 0x00000a8c060bc482 in malloc (size=56) at > > > /usr/src/lib/libc/stdlib/malloc.c:1253 > > > #8 0x00000a8c060703e4 in _thread_flockfile (fp=0x7f7ffffd02b8) at > > > /usr/src/lib/libc/thread/rthread_file.c:156 > > > #9 0x00000a8c0609e11a in _libc_fflush (fp=0x7f7ffffd02b8) at > > > /usr/src/lib/libc/stdio/fflush.c:46 > > > #10 0x00000a8c0606c89a in _libc_vdprintf (fd=Variable "fd" is not > > > available.) at /usr/src/lib/libc/stdio/vdprintf.c:72 > > > #11 0x00000a8c060a7f63 in _libc__rthread_debug (level=Variable "level" is > > > not available.) at /usr/src/lib/libc/thread/rthread_debug.c:23 > > > #12 0x00000a8c3c2792b6 in _rthread_reaper () at > > > /data/openbsd/src/lib/librthread/rthread.c:260 > > > #13 0x00000a8c3c279229 in pthread_join (thread=Variable "thread" is not > > > available.) at /data/openbsd/src/lib/librthread/rthread.c:319 > > > #14 0x00000a8993d1a705 in main (argc=1, argv=0x7f7ffffd0ab8) at test.c:86 > > > > This does not look good. The thread is recursing with hash_lock of > > rthread_file.c. Apparently triggered by the debug output routine. > > does it makes sens to call __sflush() instead of fflush() in vdprintf() ? > > the FILE variable used by vdprintf() is "home made" on the stack, using > a buffer on the stack too. And as fflush() only enclose __sflush() > with FILE locking, I don't see the gain to use fflush() here. > > at each call of vdprintf(), the FILE variable is a fresh variable on the > stack, so there is no possible concurrent access on the variable address. > > and for what I understand of find_lock() and do_lock() in > libc/thread/rthread_file.c, the lock mecanism is based on FILE address, > and not on the descriptor used, so locking a stack variable seems > unnecessary.
Using __sflush() instead of fflush() is a good choice in vdprintf(). As you have noted, there is no need to do locking in the routine. OK visa@ > The point where I am unsure is it doesn't correct the underline problem > if any: why calling _thread_flockfile() could dead-lock. but it makes > vdprintf() to avoid this unnecessary code path. The debug print routine should preferably be free of locking. That makes it easier to change the implementation of libc's internal locking. In fact, _thread_flockfile() might now be able to use a pthread mutex. I have to check that. _thread_flockfile() is used for locking FILE instances, so the lack of reentrancy should not be a problem in this case. The FILE routines generally are not signal-safe. And calling _thread_flockfile() as a consequence of lock debug printing is a bad thing anyway.
