From owner-freebsd-stable Fri Mar 19 8:41:52 1999 Delivered-To: freebsd-stable@freebsd.org Received: from freed.libdns.qc.ca (derby.JSP.UMontreal.CA [132.204.45.26]) by hub.freebsd.org (Postfix) with ESMTP id 20AA4154D9; Fri, 19 Mar 1999 08:40:56 -0800 (PST) (envelope-from spidey@libdns.qc.ca) Received: from localhost (spidey@localhost) by freed.libdns.qc.ca (8.9.2/8.9.2) with SMTP id LAA02026; Fri, 19 Mar 1999 11:39:54 -0500 (EST) (envelope-from spidey@libdns.qc.ca) X-Authentication-Warning: freed.libdns.qc.ca: spidey owned process doing -bs Date: Fri, 19 Mar 1999 11:39:53 -0500 (EST) From: Spidey Reply-To: Spidey To: Munehiro Matsuda Cc: kaj@raditex.se, freebsd-questions@FreeBSD.ORG, freebsd-stable@FreeBSD.ORG Subject: Re: Problems with SB16 PnP and FBSD-stable (fwd) In-Reply-To: <19990319171536Q.haro@tk.kubota.co.jp> Message-ID: MIME-Version: 1.0 Content-Type: TEXT/PLAIN; charset=US-ASCII Sender: owner-freebsd-stable@FreeBSD.ORG Precedence: bulk X-Loop: FreeBSD.ORG Ok. Done. This is a mess... There's a *lot* of output... Anyways. I'll try to figure out what to send out here... I hope that this won't enrage other people on the lists... In the booting process: ch_bits dev 0 ch 0 val 90 old 0xc0 r 48 p 0 bit 5 off 3 ch_bits dev 0 ch 1 val 90 old 0xc0 r 49 p 0 bit 5 off 3 ch_bits dev 1 ch 0 val 75 old 0x80 r 70 p 0 bit 4 off 4 ch_bits dev 1 ch 1 val 75 old 0x80 r 71 p 0 bit 4 off 4 ch_bits dev 2 ch 0 val 75 old 0x80 r 68 p 0 bit 4 off 4 ch_bits dev 2 ch 1 val 75 old 0x80 r 69 p 0 bit 4 off 4 ch_bits dev 3 ch 0 val 75 old 0xc0 r 52 p 0 bit 5 off 3 ch_bits dev 3 ch 1 val 75 old 0xc0 r 53 p 0 bit 5 off 3 ch_bits dev 4 ch 0 val 75 old 0xc0 r 50 p 0 bit 5 off 3 ch_bits dev 4 ch 1 val 75 old 0xc0 r 51 p 0 bit 5 off 3 ch_bits dev 5 ch 0 val 75 old 0xa0 r 59 p 0 bit 2 off 6 ch_bits dev 6 ch 0 val 75 old 0x00 r 56 p 0 bit 5 off 3 ch_bits dev 6 ch 1 val 75 old 0x00 r 57 p 0 bit 5 off 3 ch_bits dev 7 ch 0 val 16 old 0x00 r 58 p 0 bit 5 off 3 ch_bits dev 8 ch 0 val 75 old 0x00 r 54 p 0 bit 5 off 3 ch_bits dev 8 ch 1 val 75 old 0x00 r 55 p 0 bit 5 off 3 ch_bits dev 12 ch 0 val 75 old 0x00 r 63 p 0 bit 2 off 6 ch_bits dev 12 ch 1 val 75 old 0x00 r 64 p 0 bit 2 off 6 ch_bits dev 13 ch 0 val 75 old 0x00 r 65 p 0 bit 2 off 6 ch_bits dev 13 ch 1 val 75 old 0x00 r 66 p 0 bit 2 off 6 pcm1 (SB16pnp sn 0xffffffff) at 0x220-0x22f irq 10 drq 1 flags 0x10 on isa I guess that pcm is guessing which sound card it is there... Next, I try cp *.au /dev/audio : open snd1 subdev 4 flags 0x00000402 mode 0x00002000 1 : open sb16: play_fmt 1, rec_fmt 0, swap 0 reset dbuf for chan 0 reset dbuf for chan 1 write snd1 subdev 4 flag 0x00000001 dsp_write_body: prepare 65280 bytes out of 247879 wrintr: bsz change from 0 to 2000, rp 0 rl 65280 wrintr: dl 0 -> 2000 dsp_write_body: prepare 0 bytes out of 182599 dsp_write_body: l=0, (fl 0) sleeping dsp_write_body: prepare 4000 bytes out of 182599 dsp_write_body: prepare 0 bytes out of 178599 dsp_write_body: l=0, (fl 0) sleeping dsp_write_body: prepare 0 bytes out of 178599 dsp_write_body: l=0, (fl 0) sleeping dsp_write_body: prepare 0 bytes out of 178599 dsp_write_body: l=0, (fl 0) sleeping dsp_write_body: prepare 0 bytes out of 178599 dsp_write_body: l=0, (fl 0) sleeping dsp_write_body: prepare 0 bytes out of 178599 dsp_write_body: l=0, (fl 0) sleeping dsp_write_body: prepare 0 bytes out of 178599 dsp_write_body: l=0, (fl 0) sleeping dsp_write_body: prepare 0 bytes out of 178599 dsp_write_body: l=0, (fl 0) sleeping dsp_write_body: prepare 0 bytes out of 178599 dsp_write_body: l=0, (fl 0) sleeping dsp_write_body: prepare 0 bytes out of 178599 dsp_write_body: l=0, (fl 0) sleeping SND_CB_XXX: reason 0x204 dsp_wrabort: stopped, 65276 bytes left reset dbuf for chan 1 close snd1 subdev 4 snd_flush d->flags 0x00000441 reset dbuf for chan 0 reset dbuf for chan 1 It plays the few first seconds (about 1 or 2 s), and then it just sends: dsp_write_body: prepare 0 bytes out of 178599 dsp_write_body: l=0, (fl 0) sleeping then I interrupt it: SND_CB_XXX: reason 0x204 And it closes: dsp_wrabort: stopped, 65276 bytes left reset dbuf for chan 1 close snd1 subdev 4 snd_flush d->flags 0x00000441 reset dbuf for chan 0 reset dbuf for chan 1 This is nice :) It's seems that the message: write snd1 subdev 4 flag 0x00000001 dsp_write_body: prepare 65280 bytes out of 247879 wrintr: bsz change from 0 to 2000, rp 0 rl 65280 wrintr: dl 0 -> 2000 dsp_write_body: prepare 0 bytes out of 182599 dsp_write_body: l=0, (fl 0) sleeping dsp_write_body: prepare 4000 bytes out of 182599 dsp_write_body: prepare 0 bytes out of 178599 dsp_write_body: l=0, (fl 0) sleeping dsp_write_body: prepare 0 bytes out of 178599 dsp_write_body: l=0, (fl 0) sleeping is verbose enough. I see that it tries to send 65280 bytes out of 247879. The file is indeed 247879 bytes. -rw-r--r-- 1 spidey wheel 247879 Oct 17 07:28 crus228m.au But why is it only sending 65280 bytes, and then 0 bytes out of 182599??? This is a nonsense!!! And what is 'l=0, (fl 0) sleeping'? Anyways.. I'll try now a mp3. Ouah... Now there's even more output... Ok. $ mpg123 sureshot.mp3 dmesg can't even hold enough of it!!! Anyways, from syslogd: (some messages are repeated 2 or 3 times, so I cut some of it...) Mar 19 11:14:42 freed /kernel: open snd1 subdev 3 flags 0x00000002 mode 0x00002000 SoundBlaster 16 4.13>1 : open sb16: play_fmt 8, rec_fmt 0, swap 0 reset dbuf for chan 0 (now the program, mpg123, tells me the standard: "Playing MPEG stream from sureshot.mp3 ...") reset dbuf for chan 0 reset dbuf for chan 0 reset dbuf for chan 1 (MPEG 1.0 layer III, 128 kbit/s, 44100 Hz joint-stereo) reset dbuf for chan 1 reset dbuf for chan 1 for chan 1 for chan 1 for chan 1 reset dbuf for chan 0 reset dbuf for chan 0 reset dbuf for chan 0 sb16: play_fmt 128, rec_fmt 0, swap 0 sb16: play_fmt 128, rec_fmt 0, swap 0 sb16: play_fmt 128, rec_fmt 0, swap 0 reset dbuf for chan 1 reset dbuf for chan 1 reset dbuf for chan 1 reset dbuf for chan 0 reset dbuf for chan 0 reset dbuf for chan 0 [...] sb16: play_fmt 2, rec_fmt 0, swap 0 sb16: play_fmt 2, rec_fmt 0, swap 0 sb16: play_fmt 2, rec_fmt 0, swap 0 reset dbuf for chan 1 reset dbuf for chan 1 reset dbuf for chan 1 reset dbuf for chan 0 reset dbuf for chan 0 reset dbuf for chan 0 [...] Now these messages repeat *a lot* of times after. With the number '2' changing like this: sb16: play_fmt 2, rec_fmt 0, swap 0 sb16: play_fmt 1, rec_fmt 0, swap 0 sb16: play_fmt 16, rec_fmt 0, swap 1 sb16: play_fmt 8, rec_fmt 0, swap 0 sb16: play_fmt 64, rec_fmt 0, swap 0 Now these are splattering all my Xterms since I'm root... so I interrupt it. But it keeps going on!!! About the same messages for a long time! say, a few seconds, but they show up real fast. About 4-5 'cycles' per second, a cycle being: Mar 19 11:14:50 freed /kernel: sb16: play_fmt 128, rec_fmt 0, swap 0 Mar 19 11:14:50 freed /kernel: sb16: play_fmt 128, rec_fmt 0, swap 0 Mar 19 11:14:50 freed /kernel: sb16: play_fmt 128, rec_fmt 0, swap 0 Mar 19 11:14:50 freed /kernel: reset dbuf for chan 0 Mar 19 11:14:50 freed /kernel: reset dbuf for chan 0 Mar 19 11:14:50 freed /kernel: reset dbuf for chan 0 Mar 19 11:14:50 freed /kernel: reset dbuf for chan 1 Mar 19 11:14:50 freed /kernel: reset dbuf for chan 1 Mar 19 11:14:50 freed /kernel: reset dbuf for chan 1 And somehow, somewhere, my interrupt request is heard, and then: Mar 19 11:14:58 freed /kernel: close snd1 subdev 3 Mar 19 11:14:58 freed /kernel: close snd1 subdev 3 Mar 19 11:14:58 freed /kernel: close snd1 subdev 3 Mar 19 11:14:58 freed /kernel: snd_flush d->flags 0x00000141 Mar 19 11:14:58 freed /kernel: snd_flush d->flags 0x00000141 Mar 19 11:14:58 freed /kernel: snd_flush d->flags 0x00000141 Mar 19 11:14:58 freed /kernel: reset dbuf for chan 0 Mar 19 11:14:58 freed /kernel: reset dbuf for chan 0 Mar 19 11:14:58 freed /kernel: reset dbuf for chan 0 Mar 19 11:14:58 freed /kernel: reset dbuf for chan 1 Mar 19 11:14:58 freed /kernel: reset dbuf for chan 1 Mar 19 11:14:58 freed /kernel: reset dbuf for chan 1 Mar 19 11:14:58 freed /kernel: open snd1 subdev 3 flags 0x00000002 mode 0x00002000 Mar 19 11:14:58 freed /kernel: open snd1 subdev 3 flags 0x00000002 mode 0x00002000 Mar 19 11:14:58 freed /kernel: open snd1 subdev 3 flags 0x00000002 mode 0x00002000 Mar 19 11:14:59 freed /kernel: SoundBlaster 16 4.13>1 : open Mar 19 11:14:59 freed /kernel: SoundBlaster 16 4.13>1 : open Mar 19 11:14:59 freed /kernel: SoundBlaster 16 4.13>1 : open Mar 19 11:14:59 freed /kernel: sb16: play_fmt 8, rec_fmt 0, swap 0 Mar 19 11:14:59 freed /kernel: sb16: play_fmt 8, rec_fmt 0, swap 0 Mar 19 11:14:59 freed /kernel: sb16: play_fmt 8, rec_fmt 0, swap 0 Mar 19 11:14:59 freed /kernel: reset dbuf for chan 0 Mar 19 11:14:59 freed /kernel: reset dbuf for chan 0 Mar 19 11:14:59 freed /kernel: reset dbuf for chan 0 Mar 19 11:14:59 freed /kernel: Mar 19 11:14:59 freed /kernel: Mar 19 11:14:59 freed /kernel: Mar 19 11:14:59 freed /kernel: reset dbuf for chan 1 Mar 19 11:14:59 freed /kernel: reset dbuf for chan 1 Mar 19 11:14:59 freed /kernel: reset dbuf for chan 1 Mar 19 11:14:59 freed /kernel: dsp reset Mar 19 11:14:59 freed /kernel: dsp reset Mar 19 11:14:59 freed /kernel: dsp reset There, I don't understand, there messages were like the ones when I played the music... but it's supposed to be closing.. anyways. Keeps going on like this for a while: Mar 19 11:14:59 freed /kernel: sb16: play_fmt 16, rec_fmt 0, swap 1 Mar 19 11:14:59 freed /kernel: sb16: play_fmt 16, rec_fmt 0, swap 1 Mar 19 11:14:59 freed /kernel: sb16: play_fmt 16, rec_fmt 0, swap 1 Mar 19 11:14:59 freed /kernel: reset dbuf for chan 1 Mar 19 11:14:59 freed /kernel: reset dbuf for chan 1 Mar 19 11:14:59 freed /kernel: reset dbuf for chan 1 Mar 19 11:15:00 freed /kernel: reset dbuf for chan 0 Mar 19 11:15:00 freed /kernel: reset dbuf for chan 0 Mar 19 11:15:00 freed /kernel: reset dbuf for chan 0 Mar 19 11:15:00 freed /kernel: close snd1 subdev 3 Mar 19 11:15:00 freed /kernel: close snd1 subdev 3 Mar 19 11:15:00 freed /kernel: close snd1 subdev 3 Mar 19 11:15:00 freed /kernel: snd_flush d->flags 0x00000141 Mar 19 11:15:00 freed /kernel: snd_flush d->flags 0x00000141 Mar 19 11:15:00 freed /kernel: snd_flush d->flags 0x00000141 re-opening and closing itself: Mar 19 11:15:00 freed /kernel: open snd1 subdev 3 flags 0x00000002 mode 0x00002000 Mar 19 11:15:00 freed /kernel: open snd1 subdev 3 flags 0x00000002 mode 0x00002000 Mar 19 11:15:00 freed /kernel: open snd1 subdev 3 flags 0x00000002 mode 0x00002000 Mar 19 11:15:00 freed /kernel: SoundBlaster 16 4.13>1 : open Mar 19 11:15:00 freed /kernel: SoundBlaster 16 4.13>1 : open Mar 19 11:15:00 freed /kernel: SoundBlaster 16 4.13>1 : open Mar 19 11:15:00 freed /kernel: sb16: play_fmt 8, rec_fmt 0, swap 0 Mar 19 11:15:00 freed /kernel: sb16: play_fmt 8, rec_fmt 0, swap 0 Mar 19 11:15:00 freed /kernel: sb16: play_fmt 8, rec_fmt 0, swap 0 here, something interesting. It's seems it's trying to play something after all... Mar 19 11:15:01 freed /kernel: write snd1 subdev 3 flag 0x00000001 Mar 19 11:15:01 freed /kernel: write snd1 subdev 3 flag 0x00000001 Mar 19 11:15:01 freed /kernel: write snd1 subdev 3 flag 0x00000001 Mar 19 11:15:01 freed /kernel: dsp_write_body: prepare 16384 bytes out of 16384 Mar 19 11:15:01 freed /kernel: dsp_write_body: prepare 16384 bytes out of 16384 Mar 19 11:15:01 freed /kernel: dsp_write_body: prepare 16384 bytes out of 16384 Mar 19 11:15:01 freed /kernel: wrintr: bsz change from 0 to 16320, rp 0 rl 16384 Mar 19 11:15:01 freed /kernel: wrintr: bsz change from 0 to 16320, rp 0 rl 16384 Mar 19 11:15:01 freed /kernel: wrintr: bsz change from 0 to 16320, rp 0 rl 16384 Mar 19 11:15:01 freed /kernel: wrintr: dl 0 - Mar 19 11:15:01 freed /kernel: wrintr: dl 0 - Mar 19 11:15:01 freed /kernel: wrintr: dl 0 -Mar 19 11:15:01 freed /kernel: > 16320 Mar 19 11:15:01 freed /kernel: > 16320 Mar 19 11:15:01 freed /kernel: write snd1 subdev 3 flag 0x00000001 Mar 19 11:15:01 freed /kernel: write snd1 subdev 3 flag 0x00000001 Mar 19 11:15:01 freed /kernel: write snd1 subdev 3 flag 0x00000001 Mar 19 11:15:01 freed /kernel: dsp_write_body: prepare 256 bytes out of 16384 Mar 19 11:15:01 freed /kernel: dsp_write_body: prepare 256 bytes out of 16384 Mar 19 11:15:01 freed /kernel: dsp_write_body: prepare 256 bytes out of 16384 Mar 19 11:15:01 freed /kernel: dsp_write_body: prepare 512 bytes out of 16128 Mar 19 11:15:01 freed /kernel: dsp_write_body: prepare 512 bytes out of 16128 Mar 19 11:15:01 freed /kernel: dsp_write_body: prepare 512 bytes out of 16128 Mar 19 11:15:02 freed /kernel: dsp_write_body: prepare 1024 bytes out of 15616 Mar 19 11:15:02 freed /kernel: dsp_write_body: prepare 1024 bytes out of 15616 Mar 19 11:15:02 freed /kernel: dsp_write_body: prepare 1024 bytes out of 15616 Mar 19 11:15:02 freed /kernel: dsp_write_body: prepare 2048 bytes out of 14592 Mar 19 11:15:02 freed /kernel: dsp_write_body: prepare 2048 bytes out of 14592 Mar 19 11:15:02 freed /kernel: dsp_write_body: prepare 2048 bytes out of 14592 Mar 19 11:15:02 freed /kernel: dsp_write_body: prepare 4096 bytes out of 12544 Mar 19 11:15:02 freed /kernel: dsp_write_body: prepare 4096 bytes out of 12544 I get some messages that look a little like the ones when I tried to play audio: Mar 19 11:15:04 freed /kernel: dsp_write_body: prepare 0 bytes out of 384 Mar 19 11:15:04 freed /kernel: dsp_write_body: prepare 0 bytes out of 384 Mar 19 11:15:04 freed /kernel: dsp_write_body: prepare 0 bytes out of 384 Mar 19 11:15:04 freed /kernel: dsp_write_body: l=0, (fl 0) sleeping Mar 19 11:15:04 freed /kernel: dsp_write_body: l=0, (fl 0) sleeping Mar 19 11:15:04 freed /kernel: dsp_write_body: l=0, (fl 0) sleeping Mar 19 11:15:05 freed /kernel: dsp_write_body: l=0, (fl 0) sleeping [...] Mar 19 11:15:05 freed /kernel: SND_CB_XXX: reason 0x204 Mar 19 11:15:05 freed /kernel: SND_CB_XXX: reason 0x204 Mar 19 11:15:05 freed /kernel: SND_CB_XXX: reason 0x204 Mar 19 11:15:05 freed /kernel: dsp_wrabort: stopped, 65268 bytes left [the last lines are worth it:] Mar 19 11:15:05 freed /kernel: dsp_wrabort: stopped, 65268 bytes left Mar 19 11:15:05 freed /kernel: dsp_wrabort: stopped, 65268 bytes left Mar 19 11:15:05 freed /kernel: reset dbuf for chan 1 Mar 19 11:15:05 freed /kernel: reset dbuf for chan 1 Mar 19 11:15:05 freed /kernel: reset dbuf for chan 1 Mar 19 11:15:06 freed /kernel: write snd1 subdev 3 flag 0x00000001 Mar 19 11:15:06 freed /kernel: write snd1 subdev 3 flag 0x00000001 Mar 19 11:15:06 freed /kernel: write snd1 subdev 3 flag 0x00000001 Mar 19 11:15:06 freed /kernel: dsp_write_body: prepare 3072 bytes out of 3072 Mar 19 11:15:06 freed /kernel: dsp_write_body: prepare 3072 bytes out of 3072 Mar 19 11:15:06 freed /kernel: dsp_write_body: prepare 3072 bytes out of 3072 Mar 19 11:15:06 freed /kernel: wrintr: bsz change from 0 to 3072, rp 0 rl 3072 Mar 19 11:15:06 freed /kernel: wrintr: bsz change from 0 to 3072, rp 0 rl 3072 Mar 19 11:15:06 freed /kernel: wrintr: bsz change from 0 to 3072, rp 0 rl 3072 Mar 19 11:15:06 freed /kernel: wrintr: dl 0 -> 3072 Mar 19 11:15:06 freed /kernel: wrintr: dl 0 -> 3072 Mar 19 11:15:06 freed /kernel: wrintr: dl 0 -> 3072 Mar 19 11:15:06 freed /kernel: close snd1 subdev 3 Mar 19 11:15:06 freed /kernel: close snd1 subdev 3 Mar 19 11:15:06 freed /kernel: close snd1 subdev 3 Mar 19 11:15:06 freed /kernel: snd_flush d->flags 0x00000141 Mar 19 11:15:06 freed /kernel: snd_flush d->flags 0x00000141 Mar 19 11:15:06 freed /kernel: snd_flush d->flags 0x00000141 Mar 19 11:15:06 freed /kernel: reset dbuf for chan 0 Mar 19 11:15:06 freed /kernel: reset dbuf for chan 0 Mar 19 11:15:06 freed /kernel: reset dbuf for chan 0 Mar 19 11:15:06 freed /kernel: snd_sync: now rl : fl 0 : 65280 Mar 19 11:15:06 freed /kernel: snd_sync: now rl : fl 0 : 65280 Mar 19 11:15:06 freed /kernel: snd_sync: now rl : fl 0 : 65280 Mar 19 11:15:06 freed /kernel: snd_sync: now rl : fl 0 : 65280 Mar 19 11:15:06 freed /kernel: tsleep returns 4 Mar 19 11:15:06 freed /kernel: snd_sync: now rl : fl 0 : 65280 Mar 19 11:15:06 freed /kernel: tsleep returns 4 Mar 19 11:15:06 freed /kernel: snd_sync: now rl : fl 0 : 65280 Mar 19 11:15:06 freed /kernel: tsleep returns 4 The tsleep returns 4 normally appear *without* the debug enabled.. Anyways. I just can't figure out what's going on. Maybe it's the card that is scrapped. But then how could the horrible windows startup sound play when I boot on my other partition?? This is really weird. This is not a consequence of me misconfiguring, no? Some other guy told me that irq 10 for the SB16 is very unsual, however my modem (PnP too) is on irq 5, and I don't know if I'd like to play with this... Anyways, I always used irq 10 for SB in FreeBSD, and never had such problems. May I recall that all this started when I moved to -stable from 3.0R, so this is either that: 1- the source code changed 2- my configuration changed (this is obvious that my config changed because some drivers were removed and added, but it seems to me that for the pnp/pcm part, *nothing* changed! 3- my hardware changed, which is unprobable since it is working in windoze. I cutted the rest of your mail... 'hope you don't mind. (anyways, this is long enough this way!!!) Thanks for everything When a man lies he murders some part of the world These are the pale deaths which men miscall their lives All this I can witness any longer Cannot the kingdom of salvation take me home To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-stable" in the body of the message