Re: unbounded sleep on [fifoow] while open a named pipe: is it a feature?

On Fri, Jan 28, 2011 at 12:43:38PM +0300, Sergey Kandaurov wrote:
> Hi.
> 
> That's FreeBSD 8.1-RELEASE i386 (w/o debug).
> 
> It's observed for bash processes which end up in unbounded sleep
> in [fifoow] wchan while executing the next script:
> 
> %%%
> #!/usr/local/bin/bash
> 
> LOG_FACILITY="local7.notice"
> LOG_TOPIC_OUT="$TAG-output[$$]"
> LOG_TOPIC_ERR="$TAG-error[$$]"
> 
> cd $WORK_DIR
> 
> exec  > >(logger -p "$LOG_FACILITY" -t "$LOG_TOPIC_OUT" )
> exec 2> >(logger -p "$LOG_FACILITY" -t "$LOG_TOPIC_ERR" )
> eval exec $1
> %%%
> 
> It's used to call $1 and redirect its stdout and stderr streams
> to different files. Bash implements this functionality by creating
> on every execution a new named pipe stored at /var/tmp/ directory.
> This script is used to run periodically from cron(8). Note, that bash
> has a misfeature to not delete those named pipes. With a high creation
> frequency of named pipes (several per minute) it eventually ends
> up with a large number [~137000] of existing named pipes, when it
> was found that a number [~44] of bash processes sleep on [fifoow],
> which is guessed to be likely caused by the number of fifo pipes created.
> 
> For example, this one sleeps for about 1.5 days:
>  1001 78809 78803   0  50  0  4564  1952 fifoow Is    ??    0:00.00
> /usr/local/bin/bash ./logger_wrapper.sh ./sync_overlords.pl
> 
> # procstat -f 78809
> [...]
> 78809 bash                1 f - -w------   1       0 -   /var/tmp/sh-np-[random]
> [...]
> 
> # procstat -kk 78809
>   PID    TID COMM             TDNAME           KSTACK
> 78809 100733 bash             -                mi_switch+0x12a
> sleepq_switch+0xcc sleepq_catch_signals+0x5b sleepq_wait_sig+0x18
> _sleep+0x28c fifo_open+0x718 VOP_OPEN_APV+0x42 vn_open_cred+0x52b
> vn_open+0x3b kern_openat+0x125 kern_open+0x35 open+0x30 syscall+0x2d3
> Xint0x80_syscall+0x20
fifoow means that pipe is opened for writing while no readers exists.