| Summary: | Raspberry Pi audio stops working after a few hours | ||
|---|---|---|---|
| Product: | Base System | Reporter: | Harry NEWTON <hn> |
| Component: | arm | Assignee: | freebsd-arm (Nobody) <freebsd-arm> |
| Status: | New --- | ||
| Severity: | Affects Only Me | ||
| Priority: | --- | ||
| Version: | 12.1-STABLE | ||
| Hardware: | Any | ||
| OS: | Any | ||
| See Also: |
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=248710 https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=129604 https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=208678 https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=205979 https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=213687 https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=217434 |
||
Machine doesn't hang: but not audio out. Example message from play: In:0.00% 00:00:00.00 [00:02:41.44] Out:0 [ | ] Clip:0 play FAIL sox: `default' Error writing to device: Invalid argument (In reply to Harry NEWTON from comment #1) But after a series of attempted plays failing, last attempt caused hang. No messages in /var/log/messages. See also 248710 which is the same bug, on different RPI model and with different version of FreeBSD. |
Sound [through jack] works fine for a while then stops working after a few hours. Reboot fixes, but problem recurs. Firmware [pkg install rpi-firmware] updated. Raspberry Pi Model B Revision 2.0 / FreeBSD rpi-b 12.1-STABLE FreeBSD 12.1-STABLE r361761 RPI-B arm # cat /var/log/messages Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (hardware) timeout=42 b[40000/4000/2] bs[8192/4096/2] limit=0 Jul 14 20:45:59 rpi-b kernel: sndbuf_remalloc(): b=0xc170a700 65536 -> 4096 [512] Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (virtual) timeout=42 b[0/0/0] bs[512/64/8] limit=341 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (hardware) timeout=42 b[40000/4000/2] bs[8192/4096/2] limit=0 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (virtual) timeout=42 b[0/0/0] bs[512/64/8] limit=341 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (hardware) timeout=42 b[40000/4000/2] bs[8192/4096/2] limit=0 Jul 14 20:45:59 rpi-b kernel: sndbuf_remalloc(): b=0xc170a700 4096 [512] NOCHANGE Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (virtual) timeout=42 b[0/0/0] bs[1024/128/8] limit=682 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (hardware) timeout=42 b[40000/4000/2] bs[8192/4096/2] limit=0 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (virtual) timeout=42 b[0/0/0] bs[1024/128/8] limit=682 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_setspeed(): Setting speed 0 failed, falling back to 8000 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (hardware) timeout=42 b[40000/4000/2] bs[8192/4096/2] limit=0 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (virtual) timeout=42 b[0/0/0] bs[1024/128/8] limit=682 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (hardware) timeout=42 b[40000/4000/2] bs[8192/4096/2] limit=0 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (virtual) timeout=42 b[0/0/0] bs[1024/128/8] limit=682 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (hardware) timeout=42 b[40000/4000/2] bs[8192/4096/2] limit=0 Jul 14 20:45:59 rpi-b kernel: sndbuf_remalloc(): b=0xc170a700 4096 [1024] NOCHANGE Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (virtual) timeout=42 b[0/0/0] bs[512/64/8] limit=341 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (hardware) timeout=42 b[40000/4000/2] bs[8192/4096/2] limit=0 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (virtual) timeout=42 b[0/0/0] bs[512/64/8] limit=341 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (hardware) timeout=42 b[40000/4000/2] bs[8192/4096/2] limit=0 Jul 14 20:45:59 rpi-b kernel: sndbuf_remalloc(): b=0xc170a700 4096 [512] NOCHANGE Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (virtual) timeout=42 b[0/0/0] bs[2048/256/8] limit=1365 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (hardware) timeout=42 b[40000/4000/2] bs[8192/4096/2] limit=0 Jul 14 20:45:59 rpi-b kernel: sndbuf_remalloc(): b=0xc170a700 4096 [2048] NOCHANGE Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (virtual) timeout=42 b[0/0/0] bs[4096/512/8] limit=2730 Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (hardware) timeout=42 b[40000/4000/2] bs[8192/4096/2] limit=0 Jul 14 20:45:59 rpi-b kernel: sndbuf_remalloc(): b=0xc170a700 4096 -> 16384 [16384] Jul 14 20:45:59 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (virtual) timeout=42 b[0/0/0] bs[16384/2048/8] limit=16384 Jul 14 20:46:00 rpi-b kernel: pcm0: chn_start(): PCMDIR_PLAY (virtual) threshold i=4096 j=4 Jul 14 20:46:00 rpi-b kernel: pcm0: chn_start(): VCHAN PARENT starting! (PCMDIR_PLAY/running) (ready=8192 force=1 i=1 j=0 intrtimeout=42 latency=208ms) Jul 14 20:46:00 rpi-b kernel: pcm0: WARNING: PCMDIR_PLAY DMA completion too fast/slow ! hwptr=0, old=0 delta=0 amt=0 ready=8192 free=31808 Jul 14 20:46:00 rpi-b kernel: pcm0: chn_trigger() pcm0:play:dsp0.p0: calling go=0x00000001 , prev=0xffffffff Jul 14 20:46:00 rpi-b kernel: pcm0: chn_trigger() pcm0:virtual:dsp0.vp0: calling go=0x00000001 , prev=0xffffffff Jul 14 20:46:05 rpi-b kernel: pcm0: chn_write(): pcm0:virtual:dsp0.vp0: play interrupt timeout, channel dead Jul 14 20:46:05 rpi-b kernel: pcm0: chn_trigger() pcm0:play:dsp0.p0: calling go=0xffffffff , prev=0x00000001 Jul 14 20:46:05 rpi-b kernel: pcm0: chn_trigger() pcm0:virtual:dsp0.vp0: calling go=0xffffffff , prev=0x00000001 Jul 14 20:46:05 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (hardware) timeout=42 b[40000/4000/2] bs[8192/4096/2] limit=0 Jul 14 20:46:05 rpi-b kernel: pcm0: chn_resizebuf(): PCMDIR_PLAY (virtual) timeout=42 b[0/0/0] bs[16384/2048/8] limit=16384 # sysctl -a | grep -i dev.pcm dev.pcm.0.starved: 0 dev.pcm.0.freebuffer: 40000 dev.pcm.0.underruns: 6 dev.pcm.0.retrieved: 0 dev.pcm.0.submitted: 40000 dev.pcm.0.callbacks: 136300 dev.pcm.0.dest: 0 dev.pcm.0.bitperfect: 0 dev.pcm.0.buffersize: 0 dev.pcm.0.play.vchanformat: s16le:2.0 dev.pcm.0.play.vchanrate: 48000 dev.pcm.0.play.vchanmode: fixed dev.pcm.0.play.vchans: 1 dev.pcm.0.%parent: vchiq0 dev.pcm.0.%pnpinfo: dev.pcm.0.%location: dev.pcm.0.%driver: pcm dev.pcm.0.%desc: VCHIQ audio dev.pcm.%parent: # sysctl hw.snd hw.snd.maxautovchans: 16 hw.snd.default_unit: 0 hw.snd.version: 2009061500/armv6 hw.snd.default_auto: 1 hw.snd.verbose: 4 hw.snd.vpc_mixer_bypass: 1 hw.snd.feeder_rate_quality: 1 hw.snd.feeder_rate_round: 25 hw.snd.feeder_rate_max: 2016000 hw.snd.feeder_rate_min: 1 hw.snd.feeder_rate_polyphase_max: 183040 hw.snd.feeder_rate_presets: 100:8:0.85 100:36:0.92 100:164:0.97 hw.snd.feeder_eq_exact_rate: 0 hw.snd.feeder_eq_presets: PEQ:16000,0.2500,62,0.2500:-9,9,1.0:44100,48000,88200,96000,176400,192000 hw.snd.basename_clone: 1 hw.snd.compat_linux_mmap: 0 hw.snd.syncdelay: -1 hw.snd.usefrags: 0 hw.snd.vpc_reset: 0 hw.snd.vpc_0db: 45 hw.snd.vpc_autoreset: 1 hw.snd.timeout: 5 hw.snd.latency_profile: 1 hw.snd.latency: 2 hw.snd.report_soft_matrix: 1 hw.snd.report_soft_formats: 1 # cat /dev/sndstat FreeBSD Audio Driver (32bit 2009061500/armv6) Installed devices: pcm0: <VCHIQ audio> at VCHIQ (1p:1v/0r:0v) default snddev flags=0x2a3<SIMPLEX,AUTOVCHAN,BUSY,REGISTERED,VPC> [pcm0:play:dsp0.p0]: spd 48000, fmt 0x00200010, flags 0x00002100, 0x00000004 interrupts 1, underruns 0, feed 0, ready 0 [b:40000/4000/2|bs:8192/4096/2] channel flags=0x2100<BUSY,HAS_VCHAN> {userland} -> feeder_mixer(0x00200010) -> {hardware} pcm0:play:dsp0.p0[pcm0:virtual:dsp0.vp0]: spd 48000, fmt 0x00201000/0x00200010, flags 0x10000000, 0x00000023 interrupts 0, underruns 0, feed 0, ready 0 [b:0/0/0|bs:16384/2048/8] channel flags=0x10000000<VIRTUAL> {userland} -> feeder_root(0x00201000) -> feeder_format(0x00201000 -> 0x00200010) -> feeder_volume(0x00200010) -> {hardware} No devices installed from userspace. File Versions: $FreeBSD: stable/12/sys/dev/sound/pcm/feeder_chain.c 326255 2017-11-27 14:52:40Z pfg $ $FreeBSD: stable/12/sys/dev/sound/pcm/feeder_eq.c 326255 2017-11-27 14:52:40Z pfg $ $FreeBSD: stable/12/sys/dev/sound/pcm/feeder_format.c 326255 2017-11-27 14:52:40Z pfg $ $FreeBSD: stable/12/sys/dev/sound/pcm/feeder_matrix.c 326255 2017-11-27 14:52:40Z pfg $ $FreeBSD: stable/12/sys/dev/sound/pcm/feeder_mixer.c 326255 2017-11-27 14:52:40Z pfg $ $FreeBSD: stable/12/sys/dev/sound/pcm/feeder_rate.c 326255 2017-11-27 14:52:40Z pfg $ $FreeBSD: stable/12/sys/dev/sound/pcm/feeder_volume.c 326255 2017-11-27 14:52:40Z pfg $ $FreeBSD: stable/12/sys/dev/sound/pcm/mixer.c 359885 2020-04-13 16:31:13Z hselasky $ $FreeBSD: stable/12/sys/dev/sound/pcm/sndstat.c 326255 2017-11-27 14:52:40Z pfg $ $FreeBSD: stable/12/sys/dev/sound/pcm/sound.c 358877 2020-03-11 08:24:50Z hselasky $ $FreeBSD: stable/12/sys/dev/sound/pcm/vchan.c 326255 2017-11-27 14:52:40Z pfg $ $FreeBSD: stable/12/sys/dev/sound/pcm/ac97.c 326255 2017-11-27 14:52:40Z pfg $ $FreeBSD: stable/12/sys/dev/sound/pcm/ac97_patch.c 326255 2017-11-27 14:52:40Z pfg $ $FreeBSD: stable/12/sys/dev/sound/pcm/buffer.c 326255 2017-11-27 14:52:40Z pfg $ $FreeBSD: stable/12/sys/dev/sound/pcm/channel.c 326255 2017-11-27 14:52:40Z pfg $ $FreeBSD: stable/12/sys/dev/sound/pcm/dsp.c 361174 2020-05-18 09:07:14Z hselasky $ $FreeBSD: stable/12/sys/arm/broadcom/bcm2835/bcm2835_audio.c 310636 2016-12-27 19:08:08Z gonzo $ $FreeBSD: stable/12/sys/dev/sound/pcm/feeder.c 326255 2017-11-27 14:52:40Z pfg $ #