[nas] (resend) hard hang in libaoss.so
Paul Fox
pgf at foxharp.boston.ma.us
Wed Jul 3 07:03:54 MDT 2013
[ i sent this from the wrong address last night, so i assume
it won't make it to the list. if it's waiting moderation, kill it. ]
i just reread david woodfall's problem reports from april -- i'd forgotten
that he also reported a futex() issue. so perhaps the problem i
describe below isn't purely libaoss's fault, but is merely exacerbated
by its presence.
paul
> To: Abramo Bagnara <abramo at alsa-project.org>,
> Jaroslav Kysela <perex at perex.cz>
> cc: nas at radscan.com
>
> From: Paul Fox <pgf at laptop.org>
> Subject: hard hang in libaoss.so
>
> hi -- you're both listed as authors in the libaoss code. the links to
> the alsa bug tracker on alsa-project.org seem to be broken, so i'm
> hoping that you can help me, or at least redirect me. :-)
>
> i use an old audio program called NAS (http://radscan.com/nas.html, or
> "apt-get install nas"), whose main function is to provide remote audio
> services to client programs. the nasd server has several audio driver
> interfaces (mostly for obsolete OSes -- HPux, SunOS), including an OSS
> driver for linux. unfortunately no one has ever written an alsa
> driver interface for nasd.
>
> using the NAS server with the OSS driver is rock-solid. but in order
> to share my alsa devices properly with other clients (e.g., with
> dmix), i've started running nasd under aoss.
>
> when run under aoss, nasd hangs fairly easily.
>
> if i enable alsa_oss_debug in libaoss, and strace the resulting
> process, my strace logs always end like this:
>
> ....
> 1625 ioctl(6, 0x4122, 0x1614b3) = 0
> 1625 ioctl(6, 0x4122, 0xbfbb0988) = 0
> 1625 ioctl(6, 0x4122, 0xb7888600) = 0
> 1625 poll([{fd=5, events=POLLIN|POLLERR|POLLNVAL}], 1, -1) = 1 ([{fd=5, revents=POLLIN}])
> 1625 ioctl(6, 0x4122, 0x1800) = 0
> 1625 ioctl(6, 0x4122, 0xbfbb08b8) = 0
> 1625 ioctl(6, 0x4122, 0x1800) = 0
> 1625 ioctl(6, 0x4122, 0x1614b3) = 0
> 1625 ioctl(6, 0x4122, 0x4505a) = 0
> 1625 ioctl(6, 0x4122, 0xb7888600) = 0
> 1625 ioctl(6, 0x4122, 0xbfbb08a8) = 0
> 1625 write(2, "write(4, 0x842d1f8, 4096) -> 4096\n", 34) = 34
> 1625 rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 8) = 0
> 1625 setitimer(ITIMER_REAL, {it_interval={0, 32000}, it_value={0, 320}}, {it_interval={0, 0}, it_value={0, 0}}) = 0
> 1625 sigreturn() = ? (mask now [])
> 1625 select(128, [0 1 9], NULL, NULL, NULL) = ? ERESTARTNOHAND (To be restarted)
> 1625 --- SIGALRM (Alarm clock) @ 0 (0) ---
> 1625 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, {it_interval={0, 32000}, it_value={0, 26345}}) = 0
> 1625 rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 8) = 0
> 1625 gettimeofday({1372812517, 715097}, NULL) = 0
> 1625 kill(1625, SIGUSR1) = 0
> 1625 --- SIGUSR1 (User defined signal 1) @ 0 (0) ---
> 1625 rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 8) = 0
> 1625 rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 8) = 0
> 1625 rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 8) = 0
> 1625 rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 8) = 0
> 1625 ioctl(6, 0x4122, 0x1614b3) = 0
> 1625 ioctl(6, 0x4122, 0xbfbb0948) = 0
> 1625 ioctl(6, 0x4122, 0xb7888600) = 0
> 1625 ioctl(6, 0x4122, 0xbfbb08a8) = 0
> 1625 ioctl(6, 0x4122, 0xbfbb07d8) = 0
> 1625 semop(32768, {{0, 0, 0}, {0, 1, SEM_UNDO}}, 2) = 0
> 1625 semop(32768, {{0, -1, SEM_UNDO|IPC_NOWAIT}}, 1) = 0
> 1625 ioctl(6, 0x4122, 0xbfbb08a8) = 0
> 1625 ioctl(6, 0x4122, 0xbfbb07d8) = 0
> 1625 semop(32768, {{0, 0, 0}, {0, 1, SEM_UNDO}}, 2) = 0
> 1625 semop(32768, {{0, -1, SEM_UNDO|IPC_NOWAIT}}, 1) = 0
> 1625 read(5, "\1\0\0\0\214\230\0\0\357\230u\2\2\0\0\0", 64) = 16
> 1625 ioctl(6, 0x4122, 0x2) = 0
> 1625 ioctl(6, 0x4122, 0xbfbb0988) = 0
> 1625 ioctl(6, 0x4122, 0xb7888600) = 0
> 1625 poll([{fd=5, events=POLLIN|POLLERR|POLLNVAL}], 1, -1) = 1 ([{fd=5, revents=POLLIN}])
> 1625 ioctl(6, 0x4122, 0x1800) = 0
> 1625 ioctl(6, 0x4122, 0xbfbb08b8) = 0
> 1625 ioctl(6, 0x4122, 0x1800) = 0
> 1625 ioctl(6, 0x4122, 0x1614b3) = 0
> 1625 ioctl(6, 0x4122, 0x4505a) = 0
> 1625 ioctl(6, 0x4122, 0xb7888600) = 0
> 1625 ioctl(6, 0x4122, 0xbfbb08a8) = 0
> 1625 write(2, "write(4, 0x842d1f8, 3080) -> 3080\n", 34) = 34
> 1625 rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 8) = 0
> 1625 rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 8) = 0
> 1625 rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 8) = 0
> 1625 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, {it_interval={0, 0}, it_value={0, 0}}) = 0
> 1625 rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 8) = 0
> 1625 write(2, "ioctl(4, SNDCTL_DSP_SETFRAGMENT, 0xbfbb0bec[3000b])\n", 52) = 52
> 1625 open("/usr/lib/alsa-lib/libasound_module_rate_speexrate.so", O_RDONLY) = -1 ENOENT (No such file or directory)
> 1625 ioctl(5, TIOCSTI, 0xbfbb06e0) = 0
> 1625 write(2, "ioctl(4, SNDCTL_DSP_SYNC)\n", 26) = 26
> 1625 ioctl(5, 0x54a1, 0x200000b9) = 0
> 1625 ioctl(5, TIOCSTI, 0xbfbb0a20) = 0
> 1625 open("/usr/lib/alsa-lib/libasound_module_rate_speexrate.so", O_RDONLY) = -1 ENOENT (No such file or directory)
> 1625 ioctl(5, TIOCSTI, 0xbfbb0710) = 0
> 1625 write(2, "ioctl(4, SNDCTL_DSP_SPEED, 0x806256c[5000]) -> [5000]\n", 54) = 54
> 1625 rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 8) = 0
> 1625 setitimer(ITIMER_REAL, {it_interval={0, 102000}, it_value={0, 1020}}, {it_interval={0, 0}, it_value={0, 0}}) = 0
> 1625 rt_sigprocmask(SIG_BLOCK, [ALRM], NULL, 8) = 0
> 1625 rt_sigprocmask(SIG_UNBLOCK, [ALRM], NULL, 8) = 0
> 1625 write(2, "ioctl(4, SNDCTL_DSP_SYNC)\n", 26) = 26
> 1625 ioctl(5, 0x54a1, 0x469ee6) = 0
> 1625 ioctl(5, TIOCSTI, 0xbfbb0a40) = 0
> 1625 open("/usr/lib/alsa-lib/libasound_module_rate_speexrate.so", O_RDONLY) = -1 ENOENT (No such file or directory)
> 1625 --- SIGALRM (Alarm clock) @ 0 (0) ---
> 1625 setitimer(ITIMER_REAL, {it_interval={0, 0}, it_value={0, 0}}, {it_interval={0, 102000}, it_value={0, 93202}}) = 0
> 1625 write(2, "ioctl(4, ioctl(4, SNDCTL_DSP_SYNC)\n", 35) = 35
> 1625 futex(0xb7730d2c, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
> 1625 +++ killed by SIGKILL +++
>
>
> the process always hangs in the futex call, and requires kill -9 to
> clean it up.
>
> what's very interesting is the write(2,...) just above futex(), which
> comes from lib_oss_pcm_ioctl() -- note the repeated "ioctl(4, ioctl(4
> ". i see no direct path through lib_oss_pcm_ioctl() that could cause
> that.
>
> i'm not very familiar with any of the code involved (nasd, libaoss, or
> alsa), so i won't go much further without some advice, but it seems as
> if the hang might be the result of a recursive locking attempt. nasd
> does make liberal use of SIGALRM and SIGUSR1, which could complicate
> things.
>
> anyway, i'm very willing to continue debugging, but would appreciate
> any advice or tips you can provide. i suppose the first step is to
> understand where futex() is called.
>
> many thanks in advance...
>
> paul
=---------------------
paul fox, pgf at laptop.org
=---------------------
paul fox, pgf at foxharp.boston.ma.us
More information about the nas
mailing list