4.10-RELEASE-p3 i386 problem with /dev/dsp

[Roman Neuhauser]

Hello,

I have a machine with FreeBSD 4.10-RELEASE-p3 i386 (450MHz P3/Celeron)
that has been running just fine, but after ~ 120 days something
happened to /dev/dsp, and I can no longer play mp3s. A restart would
most probably fix it, but I'd like to know if it's possible to determine
(and fix) the issue on a running system. Yes, I'm fond of my uptime
("up 133 days, 20:04", including an X session), but I'd also like to know if
this is recoverable or requires the windows-style bandaid.

Short: playing mp3s brings mpg321 into a tight loop of failing writes
to /dev/dsp, producing no sound.

ktrace/kdump shows mpg321 successfully opening

 * /usr/local/lib/libid3tag.so.2
 * /usr/local/lib/libmad.so.2
 * /usr/local/lib/libao.so.3
 * /usr/local/lib/ao/plugins-2/liboss.so
 * /dev/dsp
 * the mp3 file

and failing on (neither exists):

 * /etc/malloc.conf
 * /etc/libao.conf
 * ~/.libao
 * /dev/sound/dsp

 67469 mpg321   1116837907.243643 NAMI  "/mnt/tmp/test.mp3"
 67469 mpg321   1116837907.243704 RET   open 3
    ...
 67469 mpg321   1116837907.251698 CALL  open(0x80580a0,0x1,0xbfbfefc0)
 67469 mpg321   1116837907.251751 NAMI  "/dev/dsp"
 67469 mpg321   1116837907.270293 RET   open 4
 67469 mpg321   1116837907.270325 CALL  ioctl(0x4,SNDCTL_DSP_GETBLKSIZE,0x8058088)
 67469 mpg321   1116837907.270354 RET   ioctl 0
 67469 mpg321   1116837907.270369 CALL  ioctl(0x4,SNDCTL_DSP_STEREO,0xbfbfeff8)
 67469 mpg321   1116837907.276986 RET   ioctl 0
 67469 mpg321   1116837907.277012 CALL  ioctl(0x4,SNDCTL_DSP_SETFMT,0xbfbfeff8)
 67469 mpg321   1116837907.283655 RET   ioctl 0
 67469 mpg321   1116837907.283682 CALL  ioctl(0x4,SNDCTL_DSP_SPEED,0xbfbfeff8)
 67469 mpg321   1116837907.288238 RET   ioctl 0
 67469 mpg321   1116837907.288274 CALL  sigaction(0x2,0xbfbff048,0xbfbff030)
 67469 mpg321   1116837907.288292 RET   sigaction 0
 67469 mpg321   1116837907.288777 CALL  write(0x4,0x8051f80,0x80)
 67469 mpg321   1116837907.288817 GIO   fd 4 wrote 128 bytes
    ... (mpg321 writes 128B chunks into fd 4) 
 67469 mpg321   1116837907.400663 RET   write 128/0x80
 67469 mpg321   1116837907.400680 CALL  write(0x4,0x8052580,0x80)
 67469 mpg321   1116837908.390910 GIO   fd 4 wrote 0 bytes
       ""
 67469 mpg321   1116837908.390942 RET   write 0
 67469 mpg321   1116837908.392573 CALL  write(0x4,0x8051f80,0x80)
 67469 mpg321   1116837908.392614 RET   write -1 errno 22 Invalid argument
 67469 mpg321   1116837908.394192 CALL  write(0x4,0x8051f80,0x80)
 67469 mpg321   1116837908.394231 RET   write -1 errno 22 Invalid argument
    ... (MANY such failed writes)
 67469 mpg321   1116837919.779634 CALL  write(0x4,0x8051f80,0x80)
 67469 mpg321   1116837919.779673 RET   write -1 errno 22 Invalid argument
 67469 mpg321   1116837919.779789 CALL  write(0x2,0xbfbfea88,0x34)
 67469 mpg321   1116837919.779837 GIO   fd 2 wrote 52 bytes
       "
    [2:54] Decoding of test.mp3 finished.
       " 

mpg321 eats more and more CPU as it runs, peaking at about 85% just before dying.
time says: 10.77s user 0.18s system 84% cpu 13.026 total

-- 
How many Vietnam vets does it take to screw in a light bulb?
You don't know, man.  You don't KNOW.
Cause you weren't THERE.             http://bash.org/?255991