P33M
commented
10 years ago Is your webcam streaming video at the same time as audio when this occurs?
Closed Floppe closed 10 years ago
P33M
commented
10 years ago Is your webcam streaming video at the same time as audio when this occurs?
Floppe
commented
10 years ago Yes, I'm using mjpg-streamer which streams video to ZoneMinder.
However, I tested today not to start mjpg-streamer after boot and it still occurs.
P33M
commented
10 years ago There's nothing between those two commits either in our kernel patches or upstream changes that could cause this.
The messages you posted are rate-limited - typically only the first one is the actual message. Can you post the full dmesg buffer after the first ~3 seconds of pulseaudio activity?
Floppe
commented
10 years ago So I thought also, but no other messages. I've rebooted and ran pulseaudio for 4-5 seconds and this is what dmesg buffer holds.
pi@raspberrypi ~ $ dmesg
[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Initializing cgroup subsys cpu
[ 0.000000] Initializing cgroup subsys cpuacct
[ 0.000000] Linux version 3.10.29+ (dc4@dc4-arm-01) (gcc version 4.7.2 20120731 (prerelease) (crosstool-NG linaro-1.1
3.1+bzr2458 - Linaro GCC 2012.08) ) #636 PREEMPT Sun Feb 9 19:58:58 GMT 2014
[ 0.000000] CPU: ARMv6-compatible processor [410fb767] revision 7 (ARMv7), cr=00c5387d
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT nonaliasing instruction cache
[ 0.000000] Machine: BCM2708
[ 0.000000] cma: CMA: reserved 16 MiB at 1b000000
[ 0.000000] Memory policy: ECC disabled, Data cache writeback
[ 0.000000] On node 0 totalpages: 114688
[ 0.000000] free_area_init_node: node 0, pgdat c05cfe9c, node_mem_map c067c000
[ 0.000000] Normal zone: 896 pages used for memmap
[ 0.000000] Normal zone: 0 pages reserved
[ 0.000000] Normal zone: 114688 pages, LIFO batch:31
[ 0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1_32768
[ 0.000000] pcpu-alloc: [0] 0
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 113792
[ 0.000000] Kernel command line: dma.dmachans=0x7f35 bcm2708_fb.fbwidth=1184 bcm2708_fb.fbheight=624 bcm2708.boardrev =0xd bcm2708.serial=0x78e5960a smsc95xx.macaddr=B8:27:EB:E5:96:0A sdhci-bcm2708.emmc_clock_freq=250000000 vc_mem.mem_bas e=0x1ec00000 vc_mem.mem_size=0x20000000 dwc_otg.lpm_enable=0 console=ttyAMA0,115200 kgdboc=ttyAMA0,115200 console=tty1 root=/dev/mmcblk0p2 rootfstype=ext4 elevator=deadline rootwait
[ 0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[ 0.000000] Memory: 448MB = 448MB total
[ 0.000000] Memory: 431656k/431656k available, 27096k reserved, 0K highmem
[ 0.000000] Virtual kernel memory layout:
[ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
[ 0.000000] fixmap : 0xfff00000 - 0xfffe0000 ( 896 kB)
[ 0.000000] vmalloc : 0xdc800000 - 0xff000000 ( 552 MB)
[ 0.000000] lowmem : 0xc0000000 - 0xdc000000 ( 448 MB)
[ 0.000000] modules : 0xbf000000 - 0xc0000000 ( 16 MB)
[ 0.000000] .text : 0xc0008000 - 0xc05717b8 (5542 kB)
[ 0.000000] .init : 0xc0572000 - 0xc0596364 ( 145 kB)
[ 0.000000] .data : 0xc0598000 - 0xc05d09b0 ( 227 kB)
[ 0.000000] .bss : 0xc05d09b0 - 0xc067bba0 ( 685 kB)
[ 0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000] Preemptible hierarchical RCU implementation.
[ 0.000000] NR_IRQS:330
[ 0.000000] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 4294967ms
[ 0.000000] Switching to timer-based delay loop
[ 0.000000] Console: colour dummy device 80x30
[ 0.000000] console [tty1] enabled
[ 0.001171] Calibrating delay loop (skipped), value calculated using timer frequency.. 2.00 BogoMIPS (lpj=10000)
[ 0.001238] pid_max: default: 32768 minimum: 301
[ 0.001710] Mount-cache hash table entries: 512
[ 0.002518] Initializing cgroup subsys memory
[ 0.002629] Initializing cgroup subsys devices
[ 0.002670] Initializing cgroup subsys freezer
[ 0.002706] Initializing cgroup subsys blkio
[ 0.002868] CPU: Testing write buffer coherency: ok
[ 0.003340] Setting up static identity map for 0xc04062a8 - 0xc0406304
[ 0.005148] devtmpfs: initialized
[ 0.019594] NET: Registered protocol family 16
[ 0.025575] DMA: preallocated 4096 KiB pool for atomic coherent allocations
[ 0.026689] bcm2708.uart_clock = 0
[ 0.028499] hw-breakpoint: found 6 breakpoint and 1 watchpoint registers.
[ 0.028554] hw-breakpoint: maximum watchpoint size is 4 bytes.
[ 0.028594] mailbox: Broadcom VideoCore Mailbox driver
[ 0.028692] bcm2708_vcio: mailbox at f200b880
[ 0.028798] bcm_power: Broadcom power driver
[ 0.028839] bcm_power_open() -> 0
[ 0.028868] bcm_power_request(0, 8)
[ 0.529589] bcm_mailbox_read -> 00000080, 0
[ 0.529635] bcm_power_request -> 0
[ 0.529860] Serial: AMBA PL011 UART driver
[ 0.530007] dev:f1: ttyAMA0 at MMIO 0x20201000 (irq = 83) is a PL011 rev3
[ 0.872202] console [ttyAMA0] enabled
[ 0.898180] bio: create slab
ssl-umd
commented
10 years ago I can confirm a similar issue when trying to use a Turtle Beach Amigo II USB sound card with RPI
P33M
commented
10 years ago Please retest with latest firmware.
Isochronous transactions are now FIQ-accelerated which should make them more reliable.
Floppe
commented
10 years ago Cool, now it works again. Thanks!
Floppe
commented
10 years ago Well, some logging is still there. But I do not reopen as it seems to still work after almost a hour of testing.
[Thu May 8 13:40:26 2014] retire_capture_urb: 3 callbacks suppressed [Thu May 8 13:48:50 2014] retire_capture_urb: 3 callbacks suppressed [Thu May 8 13:50:14 2014] retire_capture_urb: 19 callbacks suppressed [Thu May 8 13:55:27 2014] retire_capture_urb: 2 callbacks suppressed [Thu May 8 14:05:14 2014] retire_capture_urb: 13 callbacks suppressed [Thu May 8 14:10:24 2014] retire_capture_urb: 7 callbacks suppressed [Thu May 8 14:20:19 2014] retire_capture_urb: 12 callbacks suppressed
jbeale1
commented
8 years ago The logging spew occurs for me when audio (not video) recording from PS3 Eye usb device, with the current RPi firmware as of July 2016. The audio recording does work, but I wish I could turn off this (apparently meaningless?) stream of messages that show up in 'dmesg'. See also https://www.raspberrypi.org/forums/viewtopic.php?f=28&t=154802 [ 37.360542] retire_capture_urb: 2 callbacks suppressed [ 42.704270] retire_capture_urb: 11 callbacks suppressed [ 49.814220] retire_capture_urb: 9 callbacks suppressed [ 55.164839] retire_capture_urb: 5 callbacks suppressed [ 61.429721] retire_capture_urb: 2 callbacks suppressed [ 67.853663] retire_capture_urb: 2 callbacks suppressed [ 73.419353] retire_capture_urb: 11 callbacks suppressed
mvduin
commented
7 years ago The problem is another instance (in the same file even!) of the problem described and fixed here: https://lkml.org/lkml/2014/5/2/156
The fix in this case would be
diff --git i/sound/usb/pcm.c w/sound/usb/pcm.c
index 44d178ee9177..a71a82c6c953 100644
--- i/sound/usb/pcm.c
+++ w/sound/usb/pcm.c
@@ -1279,8 +1279,8 @@ static void retire_capture_urb(struct snd_usb_substream *subs,
for (i = 0; i < urb->number_of_packets; i++) {
cp = (unsigned char *)urb->transfer_buffer + urb->iso_frame_desc[i].offset + subs->pkt_offset_adj;
- if (urb->iso_frame_desc[i].status && printk_ratelimit()) {
- dev_dbg(&subs->dev->dev, "frame %d active: %d\n",
+ if (urb->iso_frame_desc[i].status) {
+ dev_dbg_ratelimited(&subs->dev->dev, "frame %d active: %d\n",
i, urb->iso_frame_desc[i].status);
// continue;
}
popcornmix
commented
7 years ago @mvduin it would be best to report this upstream. We can cherry pick the fix from there.
dan-cristian
commented
6 years ago I get the same kernel message in my logs on a PI 3 device with Logitech C525 USB web cam. I start recording from the USB camera (audio & video) with ffmpeg via v4l (/dev/video0) and following messages starts to get logged in syslog. Quality wise the audio seems to drop from time to time.
Linux 4.9.59-v7+ #1047 SMP Sun Oct 29 12:19:23 GMT 2017 armv7l GNU/Linux
Jan 10 23:46:46 pidash kernel: [ 3.320463] Linux video capture interface: v2.00 Jan 10 23:46:46 pidash kernel: [ 3.507271] usb 1-1.4: set resolution quirk: cval->res = 384 Jan 10 23:46:46 pidash kernel: [ 3.513800] usbcore: registered new interface driver snd-usb-audio Jan 10 23:46:46 pidash kernel: [ 3.513821] uvcvideo: Found UVC 1.00 device HD Webcam C525 (046d:0826) Jan 10 23:46:46 pidash kernel: [ 3.526254] uvcvideo 1-1.4:1.2: Entity type for entity Extension 5 was not initialized! Jan 10 23:46:46 pidash kernel: [ 3.526274] uvcvideo 1-1.4:1.2: Entity type for entity Processing 2 was not initialized! Jan 10 23:46:46 pidash kernel: [ 3.526286] uvcvideo 1-1.4:1.2: Entity type for entity Camera 1 was not initialized! Jan 10 23:46:46 pidash kernel: [ 3.526297] uvcvideo 1-1.4:1.2: Entity type for entity Extension 6 was not initialized! Jan 10 23:46:46 pidash kernel: [ 3.526309] uvcvideo 1-1.4:1.2: Entity type for entity Extension 7 was not initialized! Jan 10 23:46:46 pidash kernel: [ 3.526320] uvcvideo 1-1.4:1.2: Entity type for entity Extension 8 was not initialized! Jan 10 23:46:46 pidash kernel: [ 3.527475] input: HD Webcam C525 as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.4/1-1.4:1.2/input/input1 Jan 10 23:46:46 pidash kernel: [ 3.527885] usbcore: registered new interface driver uvcvideo Jan 10 23:46:46 pidash kernel: [ 3.527890] USB Video Class driver (1.1.1) ... ... Jan 10 23:50:44 pidash kernel: [ 233.579381] retire_capture_urb: 2 callbacks suppressed Jan 10 23:50:49 pidash kernel: [ 238.603227] retire_capture_urb: 14 callbacks suppressed Jan 10 23:50:54 pidash kernel: [ 243.607226] retire_capture_urb: 302 callbacks suppressed Jan 10 23:50:59 pidash kernel: [ 248.619228] retire_capture_urb: 313 callbacks suppressed Jan 10 23:51:04 pidash kernel: [ 253.643226] retire_capture_urb: 286 callbacks suppressed Jan 10 23:51:09 pidash kernel: [ 258.647227] retire_capture_urb: 323 callbacks suppressed Jan 10 23:51:14 pidash kernel: [ 263.679245] retire_capture_urb: 272 callbacks suppressed Jan 10 23:51:39 pidash kernel: [ 288.799660] retire_capture_urb: 34 callbacks suppressed
I'm using a Webcam C310 with ZoneMinder to survey and the microphone is used by PulseAudio which is broadcasted all over the house. All was working perfectly until last summer until kernel was changed to 3.10 series.
Now when PulseAudio starts the kernel log spams which breaks both PulseAudio and ZoneMinder.
I've located which revision it last worked with. Don't know if this is an USB or sound module issue or is it PulseAudio which should adapt.
Hexxeh/rpi-firmware@8234d5148aded657760e9ecd622f324d140ae891 <- WORKS! pi@raspberrypi ~ $ lsusb Bus 001 Device 002: ID 0424:9512 Standard Microsystems Corp. Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp. Bus 001 Device 004: ID 0409:0059 NEC Corp. HighSpeed Hub Bus 001 Device 005: ID 046d:081b Logitech, Inc. Webcam C310 pi@raspberrypi ~ $ lsusb -t /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=dwc_otg/1p, 480M | Port 1: Dev 2, If 0, Class=hub, Driver=hub/3p, 480M | Port 1: Dev 3, If 0, Class=vend., Driver=smsc95xx, 480M | Port 2: Dev 4, If 0, Class=hub, Driver=hub/4p, 480M | Port 3: Dev 5, If 0, Class='bInterfaceClass 0x0e not yet handled', Driver=uvcvideo, 480M | Port 3: Dev 5, If 1, Class='bInterfaceClass 0x0e not yet handled', Driver=uvcvideo, 480M | Port 3: Dev 5, If 2, Class=audio, Driver=snd-usb-audio, 480M |__ Port 3: Dev 5, If 3, Class=audio, Driver=snd-usb-audio, 480M
Hexxeh/rpi-firmware@dc709fae6f7fca6d1062dd49ef3527b27439ca73 <- Breaks PulseAudio
pi@raspberrypi ~ $ lsusb Bus 001 Device 002: ID 0424:9512 Standard Microsystems Corp. Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp. Bus 001 Device 004: ID 0409:0059 NEC Corp. HighSpeed Hub Bus 001 Device 005: ID 046d:081b Logitech, Inc. Webcam C310 pi@raspberrypi ~ $ lsusb -t /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=dwc_otg/1p, 480M | Port 1: Dev 2, If 0, Class=hub, Driver=hub/3p, 480M | Port 1: Dev 3, If 0, Class=vend., Driver=smsc95xx, 480M | Port 2: Dev 4, If 0, Class=hub, Driver=hub/4p, 480M | Port 3: Dev 5, If 0, Class='bInterfaceClass 0x0e not yet handled', Driver=uvcvideo, 480M | Port 3: Dev 5, If 1, Class='bInterfaceClass 0x0e not yet handled', Driver=uvcvideo, 480M | Port 3: Dev 5, If 2, Class=audio, Driver=snd-usb-audio, 480M |__ Port 3: Dev 5, If 3, Class=audio, Driver=snd-usb-audio, 480M pi@raspberrypi ~ $ pulseaudio --start pi@raspberrypi ~ $ dmesg [ 433.496879] retire_capture_urb: 13 callbacks suppressed [ 438.591066] retire_capture_urb: 26 callbacks suppressed [ 443.719125] retire_capture_urb: 49 callbacks suppressed [ 448.846829] retire_capture_urb: 36 callbacks suppressed [ 453.995929] retire_capture_urb: 38 callbacks suppressed pi@raspberrypi ~ $ pulseaudio -k