NetBSD Problem Report #52175

From martin@aprisoft.de  Tue Apr 18 07:37:14 2017
Return-Path: <martin@aprisoft.de>
Received: from mail.netbsd.org (mail.netbsd.org [199.233.217.200])
	(using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits))
	(Client CN "mail.netbsd.org", Issuer "Postmaster NetBSD.org" (verified OK))
	by mollari.NetBSD.org (Postfix) with ESMTPS id 6E84A7A170
	for <gnats-bugs@gnats.NetBSD.org>; Tue, 18 Apr 2017 07:37:14 +0000 (UTC)
Message-Id: <20170418073701.7ED355CC761@emmas.aprisoft.de>
Date: Tue, 18 Apr 2017 09:37:01 +0200 (CEST)
From: martin@NetBSD.org
Reply-To: martin@NetBSD.org
To: gnats-bugs@NetBSD.org
Subject: audio sometimes stutters
X-Send-Pr-Version: 3.95

>Number:         52175
>Category:       kern
>Synopsis:       audio sometimes stutters
>Confidential:   no
>Severity:       critical
>Priority:       high
>Responsible:    kern-bug-people
>State:          closed
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Tue Apr 18 07:40:00 +0000 2017
>Closed-Date:    Tue May 23 17:39:43 +0000 2017
>Last-Modified:  Tue May 23 17:39:43 +0000 2017
>Originator:     Martin Husemann
>Release:        NetBSD 7.99.70
>Organization:
The NetBSD Foundation, Inc.
>Environment:
System: NetBSD whoever-brings-the-night.aprisoft.de 7.99.70 NetBSD 7.99.70 (WHOEVER) #112: Mon Apr 17 20:30:18 CEST 2017 martin@martins.aprisoft.de:/ssd/src/sys/arch/sparc64/compile/WHOEVER sparc64
Architecture: sparc64
Machine: sparc64
>Description:

Most audio fallout has been resolved, but I still see this issue on one machine.

It happens randomly, even when the machine is otherwise mostly idle.
Sometimes playback with:

	mpg123 -o oss -q -r 48000 -b 8192

goes into "stutter" mode. This is the only audio user in my system, no mixing
involved. When in that mode, I can pause the player, wait for audio to drain,
continue the player and it will continue stuttering.

When I kill the player and restart it, everything is fine (usually).
This effect happens (no hard statistics) on like 5% of the play backs.

>How-To-Repeat:

No idea, does not seem to happen for me on a lot slower machines - in case it
is something hardware specific, here is the full dmesg:

Copyright (c) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003, 2004, 2005,
    2006, 2007, 2008, 2009, 2010, 2011, 2012, 2013, 2014, 2015, 2016, 2017
    The NetBSD Foundation, Inc.  All rights reserved.
Copyright (c) 1982, 1986, 1989, 1991, 1993
    The Regents of the University of California.  All rights reserved.

NetBSD 7.99.70 (WHOEVER) #112: Mon Apr 17 20:30:18 CEST 2017
	martin@martins.aprisoft.de:/ssd/src/sys/arch/sparc64/compile/WHOEVER
total memory = 8192 MB
avail memory = 8025 MB
timecounter: Timecounters tick every 10.000 msec
Kernelized RAIDframe activated
running cgd selftest aes-xts-256 aes-xts-512 done
mainbus0 (root): SUNW,Sun-Blade-2500-S (Sun Blade 2500): hostid 83cd9ff1
cpu0 at mainbus0: SUNW,UltraSPARC-IIIi @ 1600 MHz, CPU id 0
cpu0: manuf 3e, impl 16, mask 34
cpu0: system tick frequency 12 MHz
cpu0: 32K instruction (32 b/l), 64K data (32 b/l), 1024K external (64 b/l)
cpu1 at mainbus0: SUNW,UltraSPARC-IIIi @ 1600 MHz, CPU id 1
cpu1: manuf 3e, impl 16, mask 34
cpu1: system tick frequency 12 MHz
cpu1: 32K instruction (32 b/l), 64K data (32 b/l), 1024K external (64 b/l)
memory-controller at mainbus0 not configured
memory-controller at mainbus0 not configured
schizo0 at mainbus0: addr 4000e600000: Tomatillo, version 4, ign 700, bus A 0 to 0
schizo0:  pci0 at schizo0
pci0: i/o space, memory space enabled
bge0 at pci0 dev 3 function 0: Broadcom BCM5703 Gigabit Ethernet
bge0: interrupting at ivec 371c
bge0: HW config 00000000, 00000000, 00000000, 00000000 00000000
bge0: ASIC BCM5702/5703 A2 (0x1002), Ethernet address 00:03:ba:cd:9f:f1
brgphy0 at bge0 phy 1: BCM5703 1000BASE-T media interface, rev. 2
brgphy0: 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT, 1000baseT-FDX, auto
siisata0 at pci0 dev 2 function 0module_autoload: trying to load `pciverbose' before root is mounted
module_autoload: trying to load `pciverbose' before root is mounted
: vendor 1095 product 3124 (rev. 0x02)
siisata0: interrupting at ivec 700
siisata0: SiI3124, 3.0Gb/s
siisata0: 32-bit 66MHz PCI
atabus0 at siisata0 channel 0
atabus1 at siisata0 channel 1
atabus2 at siisata0 channel 2
atabus3 at siisata0 channel 3
ppm at mainbus0 not configured
schizo1 at mainbus0: addr 4000ef00000: Tomatillo, version 4, ign 740, bus B 0 to 0
schizo1:  pci1 at schizo1
pci1: i/o space, memory space enabled
mpt0 at pci1 dev 4 function 0module_autoload: trying to load `pciverbose' before root is mounted
module_autoload: trying to load `pciverbose' before root is mounted
: vendor 1000 product 0030 (rev. 0x07)
mpt0: applying 1030 quirk
mpt0: interrupting at ivec 1f69
scsibus0 at mpt0: 16 targets, 8 luns per target
mpt1 at pci1 dev 4 function 1module_autoload: trying to load `pciverbose' before root is mounted
module_autoload: trying to load `pciverbose' before root is mounted
: vendor 1000 product 0030 (rev. 0x07)
mpt1: applying 1030 quirk
mpt1: interrupting at ivec 1f68
scsibus1 at mpt1: 16 targets, 8 luns per target
schizo2 at mainbus0: addr 4000f600000: Tomatillo, version 4, ign 780, bus A 0 to 1
schizo2:  pci2 at schizo2
pci2: i/o space, memory space enabled
ebus0 at pci2 dev 7 function 0
module_autoload: trying to load `pciverbose' before root is mounted
module_autoload: trying to load `pciverbose' before root is mounted
ebus0: vendor 10b9 product 1533, revision 0x00
flashprom at ebus0 addr 0-fffff not configured
rtc0 at ebus0 addr 70-71: mc146818 compatible time-of-day clock: m5823
pcfiic0 at ebus0 addr 320-321 ipl 2e
iic0 at pcfiic0: I2C bus
i2c-bridge at iic0 addr 0x09 not configured
gpio at iic0 addr 0x18 not configured
hardware-monitor at iic0 addr 0x29 not configured
dbcool0 at iic0 addr 0x2c
dbcool0: ADM1031 dBCool(tm) Controller (rev 0x0083)
dbcool1 at iic0 addr 0x2e
dbcool1: ADM1031 dBCool(tm) Controller (rev 0x0083)
gpio at iic0 addr 0x37 not configured
gpio at iic0 addr 0x4e not configured
seeprom0 at iic0 addr 0x50: audio-card-fru-prom: size 8192
seeprom1 at iic0 addr 0x51: motherboard-fru-prom: size 8192
seeprom2 at iic0 addr 0x54: scsi-backplane-fru-prom: size 8192
spdmem0 at iic0 addr 0x5b
spdmem0: DDR SDRAM (registered), data ECC, 1GB, 286MHz (PC-2300)
spdmem0: 13 rows, 11 cols, 2 ranks, 4 banks/chip, 7.0ns cycle time
spdmem0: tAA-tRCD-tRP-tRAS: 1-3-3-7
spdmem0: voltage SSTL 2.5V, refresh time 7.8us (self-refreshing)
spdmem1 at iic0 addr 0x5c
spdmem1: DDR SDRAM (registered), data ECC, 1GB, 286MHz (PC-2300)
spdmem1: 13 rows, 11 cols, 2 ranks, 4 banks/chip, 7.0ns cycle time
spdmem1: tAA-tRCD-tRP-tRAS: 1-3-3-7
spdmem1: voltage SSTL 2.5V, refresh time 7.8us (self-refreshing)
spdmem2 at iic0 addr 0x5d
spdmem2: DDR SDRAM (registered), data ECC, 1GB, 286MHz (PC-2300)
spdmem2: 13 rows, 11 cols, 2 ranks, 4 banks/chip, 7.0ns cycle time
spdmem2: tAA-tRCD-tRP-tRAS: 1-3-3-7
spdmem2: voltage SSTL 2.5V, refresh time 7.8us (self-refreshing)
spdmem3 at iic0 addr 0x5e
spdmem3: DDR SDRAM (registered), data ECC, 1GB, 286MHz (PC-2300)
spdmem3: 13 rows, 11 cols, 2 ranks, 4 banks/chip, 7.0ns cycle time
spdmem3: tAA-tRCD-tRP-tRAS: 1-3-3-7
spdmem3: voltage SSTL 2.5V, refresh time 7.8us (self-refreshing)
spdmem4 at iic0 addr 0x63
spdmem4: DDR SDRAM (registered), data ECC, 1GB, 286MHz (PC-2300)
spdmem4: 13 rows, 11 cols, 2 ranks, 4 banks/chip, 7.0ns cycle time
spdmem4: tAA-tRCD-tRP-tRAS: 1-3-3-7
spdmem4: voltage SSTL 2.5V, refresh time 7.8us (self-refreshing)
spdmem5 at iic0 addr 0x64
spdmem5: DDR SDRAM (registered), data ECC, 1GB, 286MHz (PC-2300)
spdmem5: 13 rows, 11 cols, 2 ranks, 4 banks/chip, 7.0ns cycle time
spdmem5: tAA-tRCD-tRP-tRAS: 1-3-3-7
spdmem5: voltage SSTL 2.5V, refresh time 7.8us (self-refreshing)
spdmem6 at iic0 addr 0x65
spdmem6: DDR SDRAM (registered), data ECC, 1GB, 286MHz (PC-2300)
spdmem6: 13 rows, 11 cols, 2 ranks, 4 banks/chip, 7.0ns cycle time
spdmem6: tAA-tRCD-tRP-tRAS: 1-3-3-7
spdmem6: voltage SSTL 2.5V, refresh time 7.8us (self-refreshing)
spdmem7 at iic0 addr 0x66
spdmem7: DDR SDRAM (registered), data ECC, 1GB, 286MHz (PC-2300)
spdmem7: 13 rows, 11 cols, 2 ranks, 4 banks/chip, 7.0ns cycle time
spdmem7: tAA-tRCD-tRP-tRAS: 1-3-3-7
spdmem7: voltage SSTL 2.5V, refresh time 7.8us (self-refreshing)
clock-generator at iic0 addr 0x69 not configured
power at ebus0 addr 800-82f ipl 20 not configured
com0 at ebus0 addr 3f8-3ff ipl 2c: ns16550a, working fifo
com1 at ebus0 addr 2e8-2ef ipl 2c: ns16550a, working fifo
dma at ebus0 addr 0-ffff not configured
alipm0 at pci2 dev 6 function 0: 223KHz clock
iic1 at alipm0: I2C bus
card-reader at iic1 addr 0x20 not configured
autri0 at pci2 dev 8 function 0module_autoload: trying to load `pciverbose' before root is mounted
module_autoload: trying to load `pciverbose' before root is mounted
: vendor 10b9 product 5451 (rev. 0x02)
autri0: interrupting at ivec 7a4
autri0: ac97: Analog Devices AD1881A codec; headphone, Analog Devices Phat Stereo
audio0 at autri0: full duplex, playback, capture, mmap, independent
autri0: Virtual format configured - Format SLINEAR, precision 16, channels 2, frequency 48000
midi0 at autri0: 4DWAVE MIDI UART
ohci0 at pci2 dev 10 function 0module_autoload: trying to load `pciverbose' before root is mounted
module_autoload: trying to load `pciverbose' before root is mounted
: vendor 10b9 product 5237 (rev. 0x03)
ohci0: interrupting at ivec 7a7
module_autoload: trying to load `pciverbose' before root is mounted
ohci0: OHCI version 1.0, legacy support
usb0 at ohci0: USB revision 1.0
ohci1 at pci2 dev 11 function 0module_autoload: trying to load `pciverbose' before root is mounted
module_autoload: trying to load `pciverbose' before root is mounted
: vendor 10b9 product 5237 (rev. 0x03)
ohci1: interrupting at ivec 7a6
module_autoload: trying to load `pciverbose' before root is mounted
ohci1: OHCI version 1.0, legacy support
usb1 at ohci1: USB revision 1.0
aceride0 at pci2 dev 13 function 0: Acer Labs M5229 UDMA IDE Controller (rev. 0xc4)
aceride0: bus-master DMA support present
aceride0: using PIO transfers above 137GB as workaround for 48bit DMA access bug, expect reduced performance
aceride0: primary channel configured to native-PCI mode
aceride0: using ivec 1f98 for native-PCI interrupt
atabus4 at aceride0 channel 0
aceride0: secondary channel configured to native-PCI mode
atabus5 at aceride0 channel 1
ppb0 at pci2 dev 4 function 0module_autoload: trying to load `pciverbose' before root is mounted
module_autoload: trying to load `pciverbose' before root is mounted
: vendor 104c product ac23 (rev. 0x02)
pci3 at ppb0 bus 1
pci3: i/o space, memory space enabled
ohci2 at pci3 dev 8 function 0module_autoload: trying to load `pciverbose' before root is mounted
module_autoload: trying to load `pciverbose' before root is mounted
: vendor 1033 product 0035 (rev. 0x43)
ohci2: interrupting at ivec 794
module_autoload: trying to load `pciverbose' before root is mounted
ohci2: OHCI version 1.0
usb2 at ohci2: USB revision 1.0
ohci3 at pci3 dev 8 function 1module_autoload: trying to load `pciverbose' before root is mounted
module_autoload: trying to load `pciverbose' before root is mounted
: vendor 1033 product 0035 (rev. 0x43)
ohci3: interrupting at ivec 795
module_autoload: trying to load `pciverbose' before root is mounted
ohci3: OHCI version 1.0
usb3 at ohci3: USB revision 1.0
ehci0 at pci3 dev 8 function 2module_autoload: trying to load `pciverbose' before root is mounted
module_autoload: trying to load `pciverbose' before root is mounted
: vendor 1033 product 00e0 (rev. 0x04)
ehci0: interrupting at ivec 796
module_autoload: trying to load `pciverbose' before root is mounted
ehci0: EHCI version 1.0
ehci0: companion controllers, 3 ports each: ohci2 ohci3
usb4 at ehci0: USB revision 2.0
fwohci0 at pci3 dev 11 function 0module_autoload: trying to load `pciverbose' before root is mounted
module_autoload: trying to load `pciverbose' before root is mounted
: vendor 104c product 8024 (rev. 0x00)
fwohci0: interrupting at ivec 797
fwohci0: OHCI version 1.10 (ROM=1)
fwohci0: No. of Isochronous channels is 4.
fwohci0: EUI64 00:05:16:00:00:41:f8:4a
fwohci0: Phy 1394a available S400, 3 ports.
fwohci0: Link S400, max_rec 2048 bytes.
ieee1394if0 at fwohci0: IEEE1394 bus
fwip0 at ieee1394if0: IP over IEEE1394
fwohci0: Initiate bus reset
ppm at mainbus0 not configured
schizo3 at mainbus0: addr 4000ff00000: Tomatillo, version 4, ign 7c0, bus B 0 to 0
schizo3:  pci4 at schizo3
pci4: i/o space, memory space enabled
radeonfb0 at pci4 dev 2 function 0module_autoload: trying to load `pciverbose' before root is mounted
module_autoload: trying to load `pciverbose' before root is mounted
: vendor 1002 product 5159 (rev. 0x00)
radeonfb0: Video BIOS not present
radeonfb0: No video BIOS, using default clocks
radeonfb0: refclk = 27.000 MHz, refdiv = 12 minpll = 125000, maxpll = 400000
no data for est. mode 640x480x67
radeonfb0: 64 MB aperture at 0x08000000, 64 KB registers at 0x00100000
radeonfb0: display 0: initial virtual resolution 1280x1024 at 8 bpp
radeonfb0: using 32 MB per display
radeonfb0: port 0: physical 1280x1024 60Hz
radeonfb0: port 1: physical 1280x1024 75Hz
wsdisplay0 at radeonfb0 kbdmux 1: console (fb, vt100 emulation)
wsmux1: connecting to wsdisplay0
wsdisplay0: screen 1-3 added (fb, vt100 emulation)
drm at radeonfb0 not configured
i2c at mainbus0 not configured
pcons at mainbus0 not configured
fwohci0: BUS reset
fwohci0: node_id=0xc800ffc0, gen=1, CYCLEMASTER mode
ieee1394if0: 1 nodes, maxhop <= 0 cable IRM irm(0) (me)
ieee1394if0: bus manager 0
timecounter: Timecounter "clockinterrupt" frequency 100 Hz quality 0
timecounter: Timecounter "tick-counter" frequency 1600000000 Hz quality 100
timecounter: Timecounter "stick-counter" frequency 12000000 Hz quality 200
No counter-timer -- using %stick at 12MHz as system clock.
scsibus0: waiting 2 seconds for devices to settle...
scsibus1: waiting 2 seconds for devices to settle...
uhub0 at usb0: vendor 10b9 (0x10b9) OHCI root hub (0000), class 9/0, rev 1.00/1.00, addr 1
uhub0: 2 ports with 2 removable, self powered
uhub1 at usb1: vendor 10b9 (0x10b9) OHCI root hub (0000), class 9/0, rev 1.00/1.00, addr 1
uhub1: 2 ports with 2 removable, self powered
uhub2 at usb2: vendor 1033 (0x1033) OHCI root hub (0000), class 9/0, rev 1.00/1.00, addr 1
uhub2: 3 ports with 3 removable, self powered
uhub3 at usb3: vendor 1033 (0x1033) OHCI root hub (0000), class 9/0, rev 1.00/1.00, addr 1
uhub3: 2 ports with 2 removable, self powered
uhub4 at usb4: vendor 1033 (0x1033) EHCI root hub (0000), class 9/0, rev 2.00/1.00, addr 1
uhub4: 5 ports with 5 removable, self powered
siisata0 port 3: device present, speed: 3.0Gb/s
wd0 at atabus3 drive 0
wd0: <Samsung SSD 850 PRO 256GB>
wd0: drive supports 1-sector PIO transfers, LBA48 addressing
wd0: 238 GB, 496149 cyl, 16 head, 63 sec, 512 bytes/sect x 500118192 sectors
wd0: GPT GUID: 7787bb2e-19c7-46df-a243-f98c2feb8eab
dk0 at wd0: "sb2k5swap", 93008640 blocks at 36, type: swap
dk1 at wd0: "sb2k5root", 407109480 blocks at 93008676, type: ffs
wd0: drive supports PIO mode 4, DMA mode 2, Ultra-DMA mode 6 (Ultra/133)
wd0(siisata0:3:0): using PIO mode 4, DMA mode 2, Ultra-DMA mode 6 (Ultra/133) (using DMA)
ehci0: handing over full speed device on port 5 to ohci3
uhidev0 at uhub1 port 1 configuration 1 interface 0
uhidev0: Microsoft (0x45e) Microsoft IntelliMouse M-BM-. with IntelliEye (0x25), rev 1.10/1.07, addr 2, iclass 3/1
ums0 at uhidev0: 3 buttons and Z dir
wsmouse0 at ums0 mux 0
uplcom0 at uhub2 port 3
uplcom0: Prolific Technology Inc. (0x67b) USB 2.0 To COM Device (0x2303), rev 1.10/3.00, addr 2
ucom0 at uplcom0
wd1 at atabus4 drive 0
wd1: <SINTECHI HighSpeed SD to CF Adapter V1.0>
wd1: drive supports 1-sector PIO transfers, LBA addressing
wd1: 3796 MB, 7712 cyl, 16 head, 63 sec, 512 bytes/sect x 7774208 sectors
dk2 at wd1: "sb2.5kboot/a", 7774208 blocks at 0, type: ffs
wd1: drive supports PIO mode 4, DMA mode 2, Ultra-DMA mode 5 (Ultra/100)
wd1(aceride0:0:0): using PIO mode 4, Ultra-DMA mode 5 (Ultra/100) (using DMA)
atapibus0 at atabus5: 2 targets
cd0 at atapibus0 drive 0: <JLMS XJ-HD166S, , D3S4> cdrom removable
cd0: drive supports PIO mode 4, DMA mode 2, Ultra-DMA mode 2 (Ultra/33)
cd0(aceride0:1:0): using PIO mode 4, Ultra-DMA mode 2 (Ultra/33) (using DMA)
module_autoload: trying to load `usbverbose' before root is mounted
module_autoload: trying to load `usbverbose' before root is mounted
uhub5 at uhub1 port 2module_autoload: trying to load `usbverbose' before root is mounted
module_autoload: trying to load `usbverbose' before root is mounted
: vendor 0430 (0x430) product 100e (0x100e), class 9/0, rev 2.00/1.04, addr 3
uhub5: 4 ports with 3 removable, bus powered
module_autoload: trying to load `usbverbose' before root is mounted
uhidev1 at uhub5 port 4 configuration 1 interface 0
module_autoload: trying to load `usbverbose' before root is mounted
uhidev1: vendor 0430 (0x430) Sun USB Keyboard (0xa2), rev 2.00/1.04, addr 4, iclass 3/1
ukbd0 at uhidev1: 8 modifier keys, 6 key codes
wskbd1 at ukbd0: console keyboard, using wsdisplay0
wd1: transfer error, downgrading to Ultra-DMA mode 4
wd1(aceride0:0:0): using PIO mode 4, Ultra-DMA mode 4 (Ultra/66) (using DMA)
wd1c: error reading fsbn 32 of 32-33 (wd1 bn 32; cn 0 tn 0 sn 32), retrying
wd1: (aborted command, interface CRC error)
wd1: soft error (corrected)
WARNING: 2 errors while detecting hardware; check system log.
root on dk0 dumps on dk0
root file system type: ffs
kern.module.path=/stand/sparc64/7.99.70/modules
wsdisplay0: screen 4 added (fb, vt100 emulation)


>Fix:
n/a

>Release-Note:

>Audit-Trail:
From: Manuel Bouyer <bouyer@antioche.eu.org>
To: gnats-bugs@netbsd.org
Cc: kern-bug-people@netbsd.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Subject: Re: kern/52175: audio sometimes stutters
Date: Tue, 25 Apr 2017 22:17:35 +0200

 On Tue, Apr 18, 2017 at 07:40:00AM +0000, martin@NetBSD.org wrote:
 > Most audio fallout has been resolved, but I still see this issue on one machine.
 > 
 > It happens randomly, even when the machine is otherwise mostly idle.
 > Sometimes playback with:
 > 
 > 	mpg123 -o oss -q -r 48000 -b 8192
 > 
 > goes into "stutter" mode. This is the only audio user in my system, no mixing
 > involved. When in that mode, I can pause the player, wait for audio to drain,
 > continue the player and it will continue stuttering.
 > 
 > When I kill the player and restart it, everything is fine (usually).
 > This effect happens (no hard statistics) on like 5% of the play backs.

 I'm also hearing problems on a allwinner A20 (920Mhz ARM cortex-A7),
 which seems related to ossaudio. When playing a file with mplayer
 (which, I believe, uses ossaudio), there is stops and clicks
 in the output. Playing the same file with audioplay is as perfect
 as it can be. The file is:
 RIFF (little-endian) data, WAVE audio, Microsoft PCM, 16 bit, mono 44100 Hz

 Also, playing a sound from opencpn (which uses portaudio2, which uses
 ossaudio). It hangs. ktrace shows what looks like an endless loop writing
 the same 64k data block again and again (the file itself is less than 128KB,
 but larger files shows the same behavior), at a very low rate.
 I don't hear anything on output but maybe that's because the file
 is played at a very low rate.

 All this is with a netbsd-7 userland, but with an updated libossaudio.

 Any idea what I could look at ?

 -- 
 Manuel Bouyer <bouyer@antioche.eu.org>
      NetBSD: 26 ans d'experience feront toujours la difference
 --

From: Manuel Bouyer <bouyer@antioche.eu.org>
To: gnats-bugs@netbsd.org
Cc: kern-bug-people@netbsd.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Subject: Re: kern/52175: audio sometimes stutters
Date: Tue, 25 Apr 2017 22:20:07 +0200

 On Tue, Apr 25, 2017 at 10:17:35PM +0200, Manuel Bouyer wrote:
 > [...]
 > I'm also hearing problems on a allwinner A20 (920Mhz ARM cortex-A7),
 > which seems related to ossaudio. When playing a file with mplayer
 > (which, I believe, uses ossaudio), there is stops and clicks
 > in the output. Playing the same file with audioplay is as perfect
 > as it can be. The file is:
 > RIFF (little-endian) data, WAVE audio, Microsoft PCM, 16 bit, mono 44100 Hz
 > 
 > Also, playing a sound from opencpn (which uses portaudio2, which uses
 > ossaudio). It hangs. ktrace shows what looks like an endless loop writing
 > the same 64k data block again and again (the file itself is less than 128KB,
 > but larger files shows the same behavior), at a very low rate.
 > I don't hear anything on output but maybe that's because the file
 > is played at a very low rate.

 Note that the hardware can only do 48Khz, 16 or 24 bits.

 -- 
 Manuel Bouyer <bouyer@antioche.eu.org>
      NetBSD: 26 ans d'experience feront toujours la difference
 --

From: Manuel Bouyer <bouyer@antioche.eu.org>
To: gnats-bugs@netbsd.org
Cc: kern-bug-people@netbsd.org, gnats-admin@netbsd.org, netbsd-bugs@netbsd.org
Subject: Re: kern/52175: audio sometimes stutters
Date: Wed, 26 Apr 2017 12:03:36 +0200

 On Tue, Apr 25, 2017 at 10:17:35PM +0200, Manuel Bouyer wrote:
 > [...]
 > Also, playing a sound from opencpn (which uses portaudio2, which uses
 > ossaudio). It hangs. ktrace shows what looks like an endless loop writing
 > the same 64k data block again and again (the file itself is less than 128KB,
 > but larger files shows the same behavior), at a very low rate.
 > I don't hear anything on output but maybe that's because the file
 > is played at a very low rate.

 Here is what I see with AUDIO_DEBUG=1 when opencpn opens the device to
 play the file (the file is:
 RIFF (little-endian) data, WAVE audio, Microsoft PCM, 16 bit, mono 22050 Hz
 )

 audio_open: flags=0x6 sc=0xbfaef808 hdl=0xbfd54688
 audio_initbufs: mode=0x5
 audio_init_ringbuffer: MI blksize=9600
 audio_init_ringbuffer: final blksize=9600
 audio_init_ringbuffer: MI blksize=9600
 audio_init_ringbuffer: final blksize=9600
 audio_init_ringbuffer: MI blksize=9600
 audio_init_ringbuffer: final blksize=9600
 audio_init_ringbuffer: MI blksize=9600
 audio_init_ringbuffer: final blksize=9600
 audiosetinfo sc=0xbfaef808 ai=0xbd1c5b20
 audiosetinfo p rate 8000 p encoding 1 p precision 8 p channels 1 np 4
 audiosetinfo() Setting record params: enc=1 1ch 8/8bit 8000Hz
 audiosetinfo() Setting play params: enc=1 1ch 8/8bit 8000Hz
 audio_setup_pfilters: HW-buffer=0xbf86e1d4 pustream=0xbf86e034
 [0] enc=1 1ch 8/8bit 8000Hz
 [1] enc=6 1ch 16/16bit 8000Hz
 [HW] enc=6 2ch 16/16bit 48000Hz
 audio_setup_rfilters: HW-buffer=0xbf86e238 pustream=0xbf86e2e4
 [HW] enc=6 2ch 16/16bit 48000Hz
 [0] enc=6 1ch 16/16bit 8000Hz
 [1] enc=1 1ch 8/8bit 8000Hz
 audiosetinfo: filter setup is completed.
 audio_calc_blksize: record blksize=9600
 audio_calc_blksize: play blksize=9600
 audio_initbufs: mode=0x5
 audio_init_ringbuffer: MI blksize=9600
 audio_init_ringbuffer: final blksize=9600
 audio_init_ringbuffer: MI blksize=9600
 audio_init_ringbuffer: final blksize=9600
 audio_calcwater: plow=49152 phigh=65536 rlow=0 rhigh=55936
 audiostartp: start=0xc0f94000 used=0(hi=65536 blk=9600) mmapped=0
 audiostartp: wakeup and return
 audio_calcwater: plow=49152 phigh=65536 rlow=0 rhigh=55936
 audio_open: done sc_mode = 0x5
 audio_ioctl(4,'f',126)
 audio_ioctl(4,'f',126) result 0
 audio_ioctl(32,'A',28)
 AUDIO_GETENC
 audio_ioctl(32,'A',28) result 0
 audio_ioctl(32,'A',28)
 AUDIO_GETENC
 audio_ioctl(32,'A',28) result 0
 audio_ioctl(32,'A',28)
 AUDIO_GETENC
 audio_ioctl(32,'A',28) result 0
 audio_ioctl(32,'A',28)
 AUDIO_GETENC
 audio_ioctl(32,'A',28) result 0
 audio_ioctl(32,'A',28)
 AUDIO_GETENC
 audio_ioctl(32,'A',28) result 0
 audio_ioctl(32,'A',28)
 AUDIO_GETENC
 audio_ioctl(32,'A',28) result 0
 audio_ioctl(32,'A',28)
 AUDIO_GETENC
 audio_ioctl(32,'A',28) result 22
 audio_ioctl(136,'A',22)
 AUDIO_SETINFO mode=0x5
 audiosetinfo sc=0xbfaef808 ai=0xba310838
 audiosetinfo np 0
 audio_ioctl(136,'A',22) result 0
 audio_ioctl(136,'A',35)
 AUDIO_GETBUFINFO
 audio_ioctl(136,'A',35) result 0
 audio_ioctl(136,'A',22)
 AUDIO_SETINFO mode=0x5
 audiosetinfo sc=0xbfaef808 ai=0xba310838
 audiosetinfo p encoding 6 p precision 16 np 2
 audiosetinfo() Setting record params: enc=6 1ch 16/16bit 8000Hz
 audiosetinfo() Setting play params: enc=6 1ch 16/16bit 8000Hz
 audio_setup_pfilters: HW-buffer=0xbf86e1d4 pustream=0xbf86e034
 [0] enc=6 1ch 16/16bit 8000Hz
 [HW] enc=6 2ch 16/16bit 48000Hz
 audio_setup_rfilters: HW-buffer=0xbf86e238 pustream=0xbf86e2b4
 [HW] enc=6 2ch 16/16bit 48000Hz
 [0] enc=6 1ch 16/16bit 8000Hz
 audiosetinfo: filter setup is completed.
 audio_calc_blksize: record blksize=9600
 audio_calc_blksize: play blksize=9600
 audio_initbufs: mode=0x5
 audio_init_ringbuffer: MI blksize=9600
 audio_init_ringbuffer: final blksize=9600
 audio_init_ringbuffer: MI blksize=9600
 audio_init_ringbuffer: final blksize=9600
 audio_calcwater: plow=49152 phigh=65536 rlow=0 rhigh=55936
 audio_ioctl(136,'A',22) result 0
 audio_ioctl(136,'A',35)
 AUDIO_GETBUFINFO
 audio_ioctl(136,'A',35) result 0
 audio_ioctl(136,'A',22)
 AUDIO_SETINFO mode=0x5
 audiosetinfo sc=0xbfaef808 ai=0xba310838
 audiosetinfo p channels 1 np 1
 audiosetinfo() Setting play params: enc=6 1ch 16/16bit 8000Hz
 audio_setup_pfilters: HW-buffer=0xbf86e1d4 pustream=0xbf86e034
 [0] enc=6 1ch 16/16bit 8000Hz
 [HW] enc=6 2ch 16/16bit 48000Hz
 audiosetinfo: filter setup is completed.
 audio_calc_blksize: record blksize=9600
 audio_calc_blksize: play blksize=9600
 audio_initbufs: mode=0x5
 audio_init_ringbuffer: MI blksize=9600
 audio_init_ringbuffer: final blksize=9600
 audio_init_ringbuffer: MI blksize=9600
 audio_init_ringbuffer: final blksize=9600
 audio_ioctl(136,'A',22) result 0
 audio_ioctl(136,'A',22)
 AUDIO_SETINFO mode=0x5
 audiosetinfo sc=0xbfaef808 ai=0xba310838
 audiosetinfo np 0
 audiosetinfo() Setting record params: enc=6 1ch 16/16bit 8000Hz
 audio_setup_rfilters: HW-buffer=0xbf86e238 pustream=0xbf86e2b4
 [HW] enc=6 2ch 16/16bit 48000Hz
 [0] enc=6 1ch 16/16bit 8000Hz
 audiosetinfo: filter setup is completed.
 audio_calc_blksize: record blksize=9600
 audio_calc_blksize: play blksize=9600
 audio_initbufs: mode=0x5
 audio_init_ringbuffer: MI blksize=9600
 audio_init_ringbuffer: final blksize=9600
 audio_init_ringbuffer: MI blksize=9600
 audio_init_ringbuffer: final blksize=9600
 audio_ioctl(136,'A',22) result 0
 audio_ioctl(136,'A',35)
 AUDIO_GETBUFINFO
 audio_ioctl(136,'A',35) result 0
 audio_ioctl(136,'A',22)
 AUDIO_SETINFO mode=0x5
 audiosetinfo sc=0xbfaef808 ai=0xba310838
 audiosetinfo p rate 22050 np 1
 audiosetinfo() Setting record params: enc=6 1ch 16/16bit 22050Hz
 audiosetinfo() Setting play params: enc=6 1ch 16/16bit 22050Hz
 audio_setup_pfilters: HW-buffer=0xbf86e1d4 pustream=0xbf86e034
 [0] enc=6 1ch 16/16bit 22050Hz
 [HW] enc=6 2ch 16/16bit 48000Hz
 audio_setup_rfilters: HW-buffer=0xbf86e238 pustream=0xbf86e2b4
 [HW] enc=6 2ch 16/16bit 48000Hz
 [0] enc=6 1ch 16/16bit 22050Hz
 audiosetinfo: filter setup is completed.
 audio_calc_blksize: record blksize=9600
 audio_calc_blksize: play blksize=9600
 audio_initbufs: mode=0x5
 audio_init_ringbuffer: MI blksize=9600
 audio_init_ringbuffer: final blksize=9600
 audio_init_ringbuffer: MI blksize=9600
 audio_init_ringbuffer: final blksize=9600
 audio_ioctl(136,'A',22) result 0
 audio_ioctl(136,'A',35)
 AUDIO_GETBUFINFO
 audio_ioctl(136,'A',35) result 0
 audio_ioctl(136,'A',35)
 AUDIO_GETBUFINFO
 audio_ioctl(136,'A',35) result 0
 audio_ioctl(136,'A',22)
 AUDIO_SETINFO mode=0x5
 audiosetinfo sc=0xbfaef808 ai=0xba310838
 audiosetinfo np 0
 audio_ioctl(136,'A',22) result 0
 audio_ioctl(136,'A',35)
 AUDIO_GETBUFINFO
 audio_ioctl(136,'A',35) result 0
 audio_ioctl(136,'A',35)
 AUDIO_GETBUFINFO
 audio_ioctl(136,'A',35) result 0
 audio_ioctl(136,'A',22)
 AUDIO_SETINFO mode=0x5
 audiosetinfo sc=0xbfaef808 ai=0xba310838
 audiosetinfo np 0
 audio_ioctl(136,'A',22) result 0
 audio_ioctl(136,'A',35)
 AUDIO_GETBUFINFO
 audio_ioctl(136,'A',35) result 0
 audio_ioctl(4,'f',126)
 audio_ioctl(4,'f',126) result 0
 audiostartp: start=0xc0f94000 used=19200(hi=65536 blk=9600) mmapped=0
 mix_write: call trigger_output

 -- 
 Manuel Bouyer <bouyer@antioche.eu.org>
      NetBSD: 26 ans d'experience feront toujours la difference
 --

From: "Nathanial Sloss" <nat@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc: 
Subject: PR/52175 CVS commit: src/sys/dev
Date: Tue, 2 May 2017 06:37:12 +0000

 Module Name:	src
 Committed By:	nat
 Date:		Tue May  2 06:37:12 UTC 2017

 Modified Files:
 	src/sys/dev: audio.c

 Log Message:
 More debuging output - if mix or hw ring inserts silence.

 This is to help identify the cause of PR kern/52175.


 To generate a diff of this commit:
 cvs rdiff -u -r1.330 -r1.331 src/sys/dev/audio.c

 Please note that diffs are not public domain; they are subject to the
 copyright notices on the relevant files.

From: "Nathanial Sloss" <nat@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc: 
Subject: PR/52175 CVS commit: src/sys/dev
Date: Fri, 5 May 2017 00:38:50 +0000

 Module Name:	src
 Committed By:	nat
 Date:		Fri May  5 00:38:50 UTC 2017

 Modified Files:
 	src/sys/dev: audio.c

 Log Message:
 Bounds checking inside the mixing of the audio block.

 Addresses PR kern/52175.


 To generate a diff of this commit:
 cvs rdiff -u -r1.332 -r1.333 src/sys/dev/audio.c

 Please note that diffs are not public domain; they are subject to the
 copyright notices on the relevant files.

From: "Nathanial Sloss" <nat@netbsd.org>
To: gnats-bugs@gnats.NetBSD.org
Cc: 
Subject: PR/52175 CVS commit: src/sys/dev
Date: Fri, 12 May 2017 04:15:40 +0000

 Module Name:	src
 Committed By:	nat
 Date:		Fri May 12 04:15:40 UTC 2017

 Modified Files:
 	src/sys/dev: audio.c

 Log Message:
 Blksize is now calculated on sc_pustream/sc_rustream.
 Don't allow hw ring buffer to be saturated and data overwritten.

 It should help PR kern/52175.


 To generate a diff of this commit:
 cvs rdiff -u -r1.341 -r1.342 src/sys/dev/audio.c

 Please note that diffs are not public domain; they are subject to the
 copyright notices on the relevant files.

State-Changed-From-To: open->closed
State-Changed-By: martin@NetBSD.org
State-Changed-When: Tue, 23 May 2017 17:39:43 +0000
State-Changed-Why:
This does not happen any more in .72


>Unformatted:

NetBSD Home
NetBSD PR Database Search

(Contact us) $NetBSD: query-full-pr,v 1.39 2013/11/01 18:47:49 spz Exp $
$NetBSD: gnats_config.sh,v 1.8 2006/05/07 09:23:38 tsutsui Exp $
Copyright © 1994-2014 The NetBSD Foundation, Inc. ALL RIGHTS RESERVED.