Skip to content

Video capture from stk1160 device fails #620

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
hungerburg opened this issue Jun 17, 2014 · 33 comments
Closed

Video capture from stk1160 device fails #620

hungerburg opened this issue Jun 17, 2014 · 33 comments

Comments

@hungerburg
Copy link

The r-pi is a Model B made in UK running up to date raspbian. No monitor or keyboard attached, just logged in with ssh, still booted into graphical shell. Overclocking is set to 'modest'. The easycap is the only external USB device. The SDCard is a type 10. Below how to reproduce the error:

$ uname -a
Linux raspberrypi 3.12.21+ #689 PREEMPT Wed Jun 11 21:45:12 BST 2014 armv6l GNU/Linux
$ v4l2-ctl --set-standard=5
$ v4l2-ctl --get-fmt-video
Format Video Capture:
    Width/Height  : 720/576
    Pixel Format  : 'UYVY'
    Field         : Interlaced
    Bytes per Line: 1440
    Size Image    : 829440
    Colorspace    : Broadcast NTSC/PAL (SMPTE170M/ITU601)
$ avconv -v verbose -f video4linux2 -i /dev/video0 -b 5M -y /tmp/KK.flv
[…]
avconv version 0.8.10-6:0.8.10-1+rpi1, Copyright (c) 2000-2013 the Libav developers
[…]
[video4linux2 @ 0xcaa720] [4]Capabilities: 85000001
[video4linux2 @ 0xcaa720] Querying the device for the current frame size
[video4linux2 @ 0xcaa720] Setting frame size to 720x576
[video4linux2 @ 0xcaa720] The v4l2 frame is 828416 bytes, but 829440 bytes are expected
[…]
Press ctrl-c to stop encoding
[video4linux2 @ 0xcaa720] The v4l2 frame is 826906 bytes, but 829440 bytes are expected
frame=    0 fps=  0 q=0.0 Lsize=       0kB time=10000000000.00 bitrate=   0.0kbits/s    
video:0kB audio:0kB global headers:0kB muxing overhead nan%
$ dmesg
[…]
[81714.038072] usb 1-1.3.2: New device Syntek Semiconductor USB 2.0 Video Capture Controller @ 480 Mbps (05e1:0408, interface 0, class 0)
[…]
[81283.278685] stk1160: streaming started
[81283.431336] URB packet 0, status -63 [Buffer error (overrun)].
[81283.460993] stk1160: killing 8 urbs...
[…]

Capture stops at the first frame by itself. PAL or NTSC (smaller image size but higher framerate, so possibly not much bandwidth change) does not matter. It seems not connected to power draw; I get the same results with the easycap plugged into the pi or a powered hub.

The first value in the avconv output (bytes received) is only ever slightly below the second value (bytes expected), but its not always the same. There are two video4linux messages in avconv output but there is only one buffer overrun in dmesg. If the fault is bandwidth based, probably the device can be set to capture in another resolution?

Curiously, streaming video4linux to file works somehow, although the dump file is of different size each time:

$ sudo dmesg -c
$ v4l2-ctl --stream-mmap=3 --stream-count=100 --stream-to=/tmp/KK.dat
<<<<<<<<<<<<<<<<<<<<<<<<<< 25 fps
<<<<<<<<<<<<<<<<<<<<<<<< 23 fps
<<<<<<<<<<<<<<<<<<<<<<<<<< 25 fps
<<<<<<<<<<<<<<<<<<<<<<<<

$ du /tmp/KK.dat 
80732   /tmp/KK.dat
$ dmesg | grep -c overrun
9

I read a lot about grabbing video on the r-pi, some people seem to have success with the stk1160 module (I remember to have seen a picture from avplay when connected in xrdp before the rpi-update from 3.10 to 3.12), some seem to be lucky with the easycap driver.

Kind regards

Peter

@P33M
Copy link
Contributor

P33M commented Jun 17, 2014

When you say you get a frame before it stops, is the frame garbled or readable?

@hungerburg
Copy link
Author

The file captured from avconv command above (/tmp/KK.flv) is empty. I do not get to see how the (short) frame looks like.

@hungerburg
Copy link
Author

I gave it another try

$ v4l2-ctl --stream-mmap=8 --stream-count=2 --stream-to=KK.raw
$ avconv -f rawvideo -pix_fmt uyvy422 -s 720x576 -i KK.raw KK-%2d.jpg
$ ls KK*
KK-01.jpg
KK.raw

If I only order count 1 pictures, no jpeg will be produced. The picture is a mess, although it shows great promise ;) The camera (analog PAL b/w) was lying upside down. Part of the image is perfect: If avconv does de-interlace, would that explain why a single frame will produce no image? I suppose scanning starts at top left and proceeds to bottom left: somewhere some pixels in the even line are missing; see yourselves below:

Image of result

@P33M
Copy link
Contributor

P33M commented Jun 17, 2014

Can you post a lsusb -t?

@hungerburg
Copy link
Author

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/5p, 480M
        |__ Port 1: Dev 3, If 0, Class=vend., Driver=smsc95xx, 480M
        |__ Port 3: Dev 4, If 0, Class=hub, Driver=hub/4p, 480M
            |__ Port 3: Dev 5, If 0, Class=vend., Driver=stk1160, 480M
            |__ Port 3: Dev 5, If 1, Class=audio, Driver=snd-usb-audio, 480M
            |__ Port 3: Dev 5, If 2, Class=audio, Driver=snd-usb-audio, 480M

@P33M
Copy link
Contributor

P33M commented Jun 17, 2014

If you add the parameter dwc_otg.fiq_fsm_mask=0x3 to /boot/cmdline.txt (and reboot), is the capture different/improved/?

@hungerburg
Copy link
Author

No, the picture now is chopped in rectangular regions too and parts doubled. (The green bar I am used to, this happens with analogue equipment.) Several tries all the same. See below:

Image of result, dwc_otg.fiq_fsm_mask=0x3

With the other one and Gimp filter deinterlace I could get a good picture, but maybe that was only luck?

@P33M
Copy link
Contributor

P33M commented Jun 17, 2014

With the FIQ accelerating the transactions (mask |= 0x4) it seems the transfer is far more reliable. I think the driver (or userspace program) may not be expecting corrupt frames and ends up throwing them away.

Does guvcview (gui-based webcam/v4l viewer) work with it?

@hungerburg
Copy link
Author

The graphical viewer fails to start. I rather not strace it. Beware that this is from an xrdp session (so puts extra stress on the network and therefore usb):

$ guvcview -f uyvy -s 720x576 -w 0 -c 1
[…]
video device: /dev/video0 
Init. stk1160 (location: usb-bcm2708_usb-1.3.3)
{ pixelformat = 'UYVY', description = '16 bpp YUY2, 4:2:2, packed' }
VIDIOC_ENUM_FRAMESIZES - Error enumerating frame sizes: Inappropriate ioctl for device
  Unable to enumerate frame sizes.
: Inappropriate ioctl for device
{ pixelformat = 'RGB3', description = 'RGB3' }
{ ?GSPCA? : width = 720, height = 576 }
fmtind:2 fsizeind: 1
{ pixelformat = 'BGR3', description = 'BGR3' }
{ ?GSPCA? : width = 720, height = 576 }
fmtind:3 fsizeind: 1
{ pixelformat = 'YU12', description = 'YU12' }
{ ?GSPCA? : width = 720, height = 576 }
fmtind:4 fsizeind: 1
{ pixelformat = 'YV12', description = 'YV12' }
{ ?GSPCA? : width = 720, height = 576 }
fmtind:5 fsizeind: 1
vid:05e1 
pid:0408 
driver:stk1160
checking format: 1498831189
Unable to set 1/25 fps
VIDIOC_S_PARM error: Inappropriate ioctl for device
fps is set to 1/25
drawing controls

control type: 0x00000006 not supported
Segmentation fault

Don't you think, that the v4l2-ctl command captures raw bits as they come from the device, that the stream has no frame marks, and that the userspace avconv program just splits at byte counts (w×h×d), as far as I understand -- which would imply, that the doubling of area above would be the next frame(s). Curiously, dmesg is littered with [Buffer error (overrun)] entries, not /underrun/.

@hungerburg
Copy link
Author

PS:‌ There must be frame markers somewhere at least in driver space, how else would avconv capture know how many bytes to expect in a frame; the v4l2-ctl seems not to care though. Such markers may even be present in the stream-dump: the avconv file conversion reports errors, though gives no specifics.

@hungerburg
Copy link
Author

Will the Model B+ make a difference in this regard or is this still handicapped on high throughput?

@P33M
Copy link
Contributor

P33M commented Jul 14, 2014

The same OTG hardware is present on the Model B+ (it's the same SOC), so no difference.

I purchased a "random" easycap device a couple of weeks ago and it appears to be a usbtv007 clone. I will see if I can replicate the issue.

@sassmann
Copy link
Contributor

I have a similar capture device, also experiencing buffer overruns.

[   33.223976] stk1160: registers to NTSC like standard
[   33.384628] stk1160: queue_setup: buffer count 8, each 691200 bytes
[   33.413614] stk1160: setting alternate 5
[   33.413645] stk1160: minimum isoc packet size: 3072 (alt=5)
[   33.413656] stk1160: setting alt 5 with wMaxPacketSize=3072
[   33.431748] stk1160: allocating urbs...
[   33.438841] stk1160: cannot alloc 196608 bytes for tx[15] buffer
[   33.438865] stk1160: 14 urbs allocated. Trying to continue...
[   33.471129] stk1160: streaming started
[   33.543973] URB packet 0, status -63 [Buffer error (overrun)].
[   33.649337] URB packet 12, status -63 [Buffer error (overrun)].
[   33.649369] URB packet 13, status -63 [Buffer error (overrun)].

I get this when I try to capture video with hyperion-v4l or mplayer

root@pi ~ # hyperion-v4l2 -v NTSC
V4L2 width=720 height=480
V4L2 pixel format=UYVY
V4L2 grabber signal threshold set to: {0,0,0}
Connecting to Hyperion: 127.0.0.1:19445
V4L2 grabber started
Frame too small: 680974 != 691200
Frame too small: 690032 != 691200
Frame too small: 671394 != 691200
Frame too small: 690052 != 691200

Already tried several settings of dwc_otg.fiq_fsm_mask

dwc_otg.fiq_fsm_mask=0x1
Frame too small: 555638 != 691200
Frame too small: 597436 != 691200
Frame too small: 584364 != 691200
dwc_otg.fiq_fsm_mask=0x3
Frame too small: 595770 != 691200
Frame too small: 594286 != 691200
Frame too small: 563024 != 691200
dwc_otg.fiq_fsm_mask=0x4
Frame too small: 690654 != 691200
Frame too small: 689886 != 691200
Frame too small: 676092 != 691200
dwc_otg.fiq_fsm_mask=0x7
Frame too small: 690020 != 691200
Frame too small: 687680 != 691200
Frame too small: 688510 != 691200

So it seems with 0x4 and 0x7 it's almost there.
Here's some info about the setup

root@pi ~ # uname -a
Linux pi 3.12.26+ #704 PREEMPT Wed Aug 20 22:35:11 BST 2014 armv6l GNU/Linux
root@pi ~ # lsusb | grep STK1160
Bus 001 Device 005: ID 05e1:0408 Syntek Semiconductor Co., Ltd STK1160 Video Capture Device
root@pi ~ # 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=HID, Driver=usbhid, 12M
        |__ Port 2: Dev 4, If 1, Class=HID, Driver=usbhid, 12M
        |__ Port 2: Dev 4, If 2, Class=HID, Driver=usbhid, 12M
        |__ Port 3: Dev 5, If 0, Class=vend., Driver=stk1160, 480M
        |__ Port 3: Dev 5, If 1, Class=audio, Driver=snd-usb-audio, 480M
        |__ Port 3: Dev 5, If 2, Class=audio, Driver=snd-usb-audio, 480M

Any recommendations on what else to try? Thanks!

@knowncolor
Copy link

I'm certainly no expert on this topic but I've spent a couple of days trying to figure this out and wasn't able to get anywhere. I have the STK1160 and the best picture I can get is stable about 50% of the time, and flickers horribly and looks like the images above the rest of the time (seem to coincide with the "Frame too small" messages).

There are some rumors that it's related to the USB bus on the Pi - great info here, http://easycap.blogspot.co.uk/2013/03/raspberry-pi-and-easycap-devices.html. I have ordered another capture card, the Fushicai as discussed here... http://raspberry-at-home.com/video-grabber-for-raspberry-pi/.

@npp1993
Copy link

npp1993 commented Aug 3, 2015

@knowncolor ,have you had any luck with this issue? I've gotten an STK1160 to capture video on the 3.6.11+ kernel on a B+. However, I just got a Pi 2 and and my previous code doesn't work. In fact, I can't even replicate the results on this thread here--avconv doesn't even grab a frame. Did the Fushicai card work for you?

@knowncolor
Copy link

@npp1993 I was unable to resolve the flickering. In the end I ordered a new capture device from Lightberry and it works great and with minimal set up. https://lightberry.eu/shop/shop/easycap-video-grabber/

@6by9
Copy link
Contributor

6by9 commented Jan 29, 2016

Sorry for bumping an old issue, but I've hit a similar thing on a totally different project and thought I'd report what has been found there. Feel free to ignore!

My device is actually a UVC device, but stk1160 seems to be similar. On URB completion it does a memcpy of the video frame from USB buffer into the V4L2 buffer, and then returns the URB. Our processor was being slightly too slow in doing that memcpy and was running out of URBs to fill, so USB packets got dropped and the frame was reported as being of fewer bytes than expected. The buffers V4L2 presents to userspace do not have V4L2_BUF_FLAG_ERROR set in the flags field, but the bytesused field is < fmt.sizeimage.
Increase the number of URBs in circulation and the issue goes away. I should say that our UVC device is incredibly bursty in nature, whereas I don't know how much buffering these video capture devices have.

Seeing as people here are getting short buffers reported, and the images attached look like there is stale data in buffers, it sounded plausibly relevant.

Anyone with one of these devices feel like rebuilding the kernel with STK1160_NUM_BUFS and/or STK1160_MIN_BUFS set higher?

@ghost
Copy link

ghost commented Jan 29, 2016

@6by9 Very excited to hear a potentially positive update on this thread! I've not been looking at this issue for some time as I was able to find a different capture device that works, but I spent a lot of time on this in the past and know lots of people were having the same issue.

@6by9
Copy link
Contributor

6by9 commented Jan 29, 2016

@tramonex-james Don't count chickens yet.
I don't have any of these video capture devices so can't try it. I'm just reporting a similar type issue on a totally different platform. I don't know of enough detail on the USB controller side to know if this is applicable to Pi - some information I've seen say that the interrupt rate on Pi is stupidly high vs a more sensible controller.

@P33M would probably be the one to know if this is a total red herring.

@Karmek
Copy link

Karmek commented Mar 13, 2016

Same issue here. I just wanted to use my old STK1160 USB-Video grabber card, which worked flawlessly before. When i try to capture data from /dev/video0 i get the following error(s):

[video4linux2 @ 0x1faa1e0] The v4l2 frame is 690276 bytes, but 691200 bytes are expected

Occasionally the driver works for a couple of seconds/minutes but usually it fails right away. It seems to be independent of the chosen resolution or bitrate.
Below you will find the full output and some extra information. Hope this helps fixing the issue:

avconv -v verbose -f video4linux2 -i /dev/video0 -s 640x480 -b 5000K -y /home/pi/KK.flv
avconv version 11.4-6:11.4-1deb8u1+rpi1, Copyright (c) 2000-2014 the Libav developers
built on Jun 16 2015 05:32:34 with gcc 4.9.2 (Raspbian 4.9.2-10)
configuration: --arch=arm --enable-pthreads --enable-runtime-cpudetect --extra-version='6:11.4-1
deb8u1+rpi1' --libdir=/usr/lib/arm-linux-gnueabihf --prefix=/usr --disable-yasm --disable-avserver --disable-armv6t2 --disable-neon --enable-bzlib --enable-libdc1394 --enable-libfreetype --enable-frei0r --enable-gnutls --enable-libgsm --enable-libmp3lame --enable-librtmp --enable-libopencv --enable-libopenjpeg --enable-libopus --enable-libpulse --enable-libschroedinger --enable-libspeex --enable-libtheora --enable-vaapi --enable-vdpau --enable-libvorbis --enable-libvpx --enable-zlib --enable-gpl --enable-swscale --enable-libcdio --enable-x11grab --enable-libx264 --enable-libxvid --shlibdir=/usr/lib/arm-linux-gnueabihf --enable-shared --disable-static
avcodec configuration: --arch=arm --enable-pthreads --enable-runtime-cpudetect --extra-version='6:11.4-1~deb8u1+rpi1' --libdir=/usr/lib/arm-linux-gnueabihf --prefix=/usr --disable-yasm --disable-avserver --disable-armv6t2 --disable-neon --enable-bzlib --enable-libdc1394 --enable-libfreetype --enable-frei0r --enable-gnutls --enable-libgsm --enable-libmp3lame --enable-librtmp --enable-libopencv --enable-libopenjpeg --enable-libopus --enable-libpulse --enable-libschroedinger --enable-libspeex --enable-libtheora --enable-vaapi --enable-vdpau --enable-libvorbis --enable-libvpx --enable-zlib --enable-gpl --enable-swscale --enable-libcdio --enable-x11grab --enable-libx264 --enable-libxvid --shlibdir=/usr/lib/arm-linux-gnueabihf --enable-shared --disable-static --enable-libopencore-amrnb --enable-version3 --enable-libopencore-amrwb --enable-version3 --enable-libvo-aacenc --enable-version3 --enable-libvo-amrwbenc --enable-version3
libavutil 54. 3. 0 / 54. 3. 0
libavcodec 56. 1. 0 / 56. 1. 0
libavformat 56. 1. 0 / 56. 1. 0
libavdevice 55. 0. 0 / 55. 0. 0
libavfilter 5. 0. 0 / 5. 0. 0
libavresample 2. 1. 0 / 2. 1. 0
libswscale 3. 0. 0 / 3. 0. 0
[video4linux2 @ 0x1711e0] [4]Capabilities: 85200001
[video4linux2 @ 0x1711e0] Querying the device for the current frame size
[video4linux2 @ 0x1711e0] Setting frame size to 720x480
[video4linux2 @ 0x1711e0] Estimating duration from bitrate, this may be inaccurate
Input #0, video4linux2, from '/dev/video0':
Duration: N/A, start: 981.866725, bitrate: 165722 kb/s
Stream #0.0: Video: rawvideo, uyvy422, 720x480, 165722 kb/s, 29.97 fps, 1000k tbn
[buffer @ 0x167ec0] w:720 h:480 pixfmt:uyvy422
[buffersink @ 0x168640] auto-inserting filter 'auto-inserted fifo 0' between the filter 'format' and the filter 'output stream 0:0'
[scale @ 0x1637a0] w:720 h:480 fmt:uyvy422 -> w:640 h:480 fmt:yuv420p flags:0x4
Output #0, flv, to '/home/pi/KK.flv':
Metadata:
encoder : Lavf56.1.0
Stream #0.0: Video: flv, yuv420p, 640x480, q=2-31, 5000 kb/s, 1k tbn, 1000k tbc
Metadata:
encoder : Lavc56.1.0 flv
Stream mapping:
Stream #0:0 -> #0:0 (rawvideo (native) -> flv1 (flv))
Press ctrl-c to stop encoding
The v4l2 frame is 689656 bytes, but 691200 bytes are expected 631.6kbits/s
/dev/video0: Invalid data found when processing input
No more output streams to write to, finishing.
frame= 16 fps= 16 q=31.0 Lsize= 34kB time=0.50 bitrate= 552.5kbits/s
video:34kB audio:0kB other streams:0kB global headers:0kB muxing overhead: 1.294998%
Input file #0 (/dev/video0):
Input stream #0:0 (video): 16 packets read (11059200 bytes); 16 frames decoded;
Total: 16 packets (11059200 bytes) demuxed
Output file #0 (/home/pi/KK.flv):
Output stream #0:0 (video): 16 frames encoded; 16 packets muxed (34363 bytes);
Total: 16 packets (34363 bytes) muxed
[video4linux2 @ 0x1711e0] Some buffers are still owned by the caller on close.

uname -a
Linux theke2 4.1.18-v7+ #846 SMP Thu Feb 25 14:22:53 GMT 2016 armv7l GNU/Linux

lsb_release -a
No LSB modules are available.
Distributor ID: Raspbian
Description: Raspbian GNU/Linux 8.0 (jessie)
Release: 8.0
Codename: jessie

dmesg
[ 1009.775647] stk1160: queue_setup: buffer count 32, each 691200 bytes
[ 1009.800345] stk1160: setting alternate 5
[ 1009.800363] stk1160: minimum isoc packet size: 3072 (alt=5)
[ 1009.800371] stk1160: setting alt 5 with wMaxPacketSize=3072
[ 1009.800722] stk1160: allocating urbs...
[ 1009.804897] stk1160: cannot alloc 196608 bytes for tx[12] buffer
[ 1009.804912] stk1160: 11 urbs allocated. Trying to continue...
[ 1009.805212] stk1160: streaming started
[ 1010.162713] stk1160: killing 11 urbs...
[ 1010.162774] stk1160: all urbs killed
[ 1010.162782] stk1160: freeing 11 urb buffers...
[ 1010.163205] stk1160: all urb buffers freed
[ 1010.163214] stk1160: setting alternate 0
[ 1010.163715] stk1160: buffer [9a845000/10] aborted
[ 1010.163726] stk1160: buffer [9a845800/11] aborted
[ 1010.163734] stk1160: buffer [9a846000/12] aborted
[ 1010.163742] stk1160: buffer [9a846800/13] aborted
[ 1010.163749] stk1160: buffer [9a847000/14] aborted
[ 1010.163756] stk1160: buffer [9a847800/15] aborted
[ 1010.163764] stk1160: buffer [9a5bc000/16] aborted
[ 1010.163771] stk1160: buffer [9a5bc800/17] aborted
[ 1010.163779] stk1160: buffer [9a5bd000/18] aborted
[ 1010.163786] stk1160: buffer [9a5bd800/19] aborted
[ 1010.163793] stk1160: buffer [9a5be000/20] aborted
[ 1010.163801] stk1160: buffer [9a5be800/21] aborted
[ 1010.163808] stk1160: buffer [9a5bf000/22] aborted
[ 1010.163816] stk1160: buffer [9a5bf800/23] aborted
[ 1010.163823] stk1160: buffer [9a314000/24] aborted
[ 1010.163831] stk1160: buffer [9a314800/25] aborted
[ 1010.163838] stk1160: buffer [9a315000/26] aborted
[ 1010.163845] stk1160: buffer [9a315800/27] aborted
[ 1010.163853] stk1160: buffer [9a316000/28] aborted
[ 1010.163860] stk1160: buffer [9a316800/29] aborted
[ 1010.163867] stk1160: buffer [9a317000/30] aborted
[ 1010.163875] stk1160: buffer [9a317800/31] aborted
[ 1010.163883] stk1160: buffer [9985f000/0] aborted
[ 1010.163890] stk1160: buffer [9985f800/1] aborted
[ 1010.163897] stk1160: buffer [9985ec00/2] aborted
[ 1010.163905] stk1160: buffer [9a844800/9] aborted
[ 1010.163910] stk1160: streaming stopped

@Ruffio
Copy link

Ruffio commented Aug 10, 2016

@hungerburg has this issue been resolved? If yes, then please close this issue.

@mmodler
Copy link

mmodler commented Aug 12, 2016

I still get broken frames with stk1160 on raspbian lite with kernel 4.4.

Any ideas on this? Might reducing the frame size solve/reduce the issue? I think it can hardly be hardware related due to the old legacy stk1160 driver worked fine?

@hungerburg
Copy link
Author

@Ruffio Sorry, no success -- Just installed a stock 2016-05-27-raspbian-jessie-lite.img -- which has everything on board -- and got no good capture; Below the same commands as above; on the desktop, the same commands yield fine pictures.

pi@raspberrypi:~ $ uname -a
Linux raspberrypi 4.4.11+ #888 Mon May 23 20:02:58 BST 2016 armv6l GNU/Linux
pi@raspberrypi:~ $ v4l2-ctl --set-standard=5
Standard set to 000000ff
pi@raspberrypi:~ $ v4l2-ctl --get-fmt-video
Format Video Capture:
    Width/Height  : 720/576
    Pixel Format  : 'UYVY'
    Field         : Interlaced
    Bytes per Line: 1440
    Size Image    : 829440
    Colorspace    : Broadcast NTSC/PAL (SMPTE170M/ITU601)
    Flags         : 
pi@raspberrypi:~ $ v4l2-ctl --stream-mmap=3 --stream-count=100 --stream-to=/tmp/KK.dat
pi@raspberrypi:~ $ dmesg |tail
[  678.180794] stk1160: cannot alloc 196608 bytes for tx[10] buffer
[  678.180831] stk1160: 9 urbs allocated. Trying to continue...
[  678.625128] print_err_status: 2 callbacks suppressed
[  678.625166] URB packet 0, status -63 [Buffer error (overrun)].
[  679.805726] URB packet 0, status -63 [Buffer error (overrun)].
[  680.064868] URB packet 0, status -63 [Buffer error (overrun)].
[  680.177758] URB packet 0, status -63 [Buffer error (overrun)].
[  681.326203] URB packet 0, status -63 [Buffer error (overrun)].
[  682.046421] URB packet 0, status -63 [Buffer error (overrun)].
[  682.095133] URB packet 0, status -63 [Buffer error (overrun)].

On my desktop I extract the frames:
ffmpeg -f rawvideo -pix_fmt uyvy422 -s 720x576 -i KK.dat KK-%2d.jpg

That is what it looks like
kk-01

If you close the issue, I do not mind, the Pi may be just too weak for uncompressed video, but there are good alternatives and only few want to use legacy hardware…

@mmodler
Copy link

mmodler commented Aug 13, 2016

The issue touches me with a current Pi 3 and hyperion ambilight. I used a fushicai grabber first, but it gives oversaturated colors and a driver which has no v4l2-ctl commands to adjust anyting. Now i use a stk1160 grabber which has good colors (with chroma=off) but the frame issue leads to blue led flashlights from time to time.

I don't know any other grabber hardware for hyperion ambilight, so i think many users are affected by it. I would greatly appreciate any hint or work on this topic!

I don't have enough knowledge to undersand if the commits made to the driver in kernel > 4.4 can solve the issue...

@sassmann
Copy link
Contributor

I'm also still facing the issue with stk1160 openelec
OpenELEC:~ # uname -a
Linux OpenELEC 4.4.8 #1 Sun May 1 15:22:48 CEST 2016 armv6l GNU/Linux
OpenELEC:~ # dmesg
[ 25.453391] stk1160: cannot alloc 196608 bytes for tx[13] buffer
[ 25.453421] stk1160: 12 urbs allocated. Trying to continue...
[...]
[ 490.554096] URB packet 0, status -63 [Buffer error (overrun)].
[ 491.992929] URB packet 0, status -63 [Buffer error (overrun)].
[ 496.624565] URB packet 0, status -63 [Buffer error (overrun)].

@habeIchVergessen
Copy link

on a 64-bit kernel (opensuse leap 42.2) on raspi 3 doesn't occurre the tx buffer allocation error.
main difference is kmem_cache size of 256 MB vs. 128 MB on any 32-bit kernel (64-bit use 8k instead of 4k on 32-bit).

@sassmann
Copy link
Contributor

Thanks for the comment habeIchVergessen. That made me think about how to workaround that limit and I realized that by allocating some contiguous memory at boot kmalloc may draw from that pool and thus the allocation succeeds.
tl;dr add cma=32M to the kernel cmdline on 32bit kernel.

@Vaskyy
Copy link

Vaskyy commented Feb 20, 2017

@sassmann u almost saved my life dude!!
THIS was the answer!!

my stats:
osmc@Herbert:~$ uname -a Linux Herbert 4.4.27-7-osmc #1 SMP PREEMPT Tue Jan 24 03:38:31 UTC 2017 armv7l GNU/Linux

running hyperion on the same device
`
osmc@Herbert:~$ sudo service thirdtry status

  • thirdtry.service - Hyperion Systemd service
    Loaded: loaded (/etc/systemd/system/thirdtry.service; enabled)
    Active: active (running) since Mon 2017-02-20 03:47:54 CET; 10min ago
    Process: 394 ExecStartPre=/bin/sleep 10 (code=exited, status=0/SUCCESS)
    Main PID: 521 (hyperiond)
    CGroup: /system.slice/thirdtry.service
    `-521 /usr/bin/hyperiond /etc/hyperion/hyperion.config.json

Feb 20 03:50:14 Herbert hyperiond[521]: BLACKBORDER INFO: threshold set to 0 (0)
Feb 20 03:50:14 Herbert hyperiond[521]: BLACKBORDER INFO: mode:default
Feb 20 03:50:14 Herbert hyperiond[521]: EFFECTENGINE INFO: effect finished
Feb 20 03:50:15 Herbert hyperiond[521]: EFFECTENGINE INFO: run effect Rainbow swirl fast on channel 0
Feb 20 03:50:15 Herbert hyperiond[521]: BLACKBORDER INFO: threshold set to 0 (0)
Feb 20 03:50:15 Herbert hyperiond[521]: BLACKBORDER INFO: mode:default
Feb 20 03:50:15 Herbert hyperiond[521]: EFFECTENGINE INFO: effect finished
Feb 20 03:50:18 Herbert hyperiond[521]: EFFECTENGINE INFO: effect finished
Feb 20 03:50:18 Herbert hyperiond[521]: V4L2GRABBER INFO: started
Feb 20 03:50:48 Herbert hyperiond[521]: JSONSERVER INFO: Connection closed
`

(Yeah i know the service name is another.. this is cause i made 2 another startup scripts to kill the first hyperion startup (cause it caused everytime flickering on the led's) and the second starts it 10 seconds later again. Then it runs smoothly and has no flickering)

And after that all, everytime i started to change colors or turned on an effect, the amilight (think the grabber) didn't seem to work anymore after i turned back to it)

dmesg gave me similar logs like u:
[ 678.180794] stk1160: cannot alloc 196608 bytes for tx[10] buffer
[ 678.180831] stk1160: 9 urbs allocated. Trying to continue...

After this log everytime the grabber stopped working.
Now after i read your post i figured out how to increase CMA at my OSMC Pi

First look if this Setting is on "y"
osmc@Herbert:~$ zgrep DMA_CMA /boot/config-4.4.27-7-osmc CONFIG_DMA_CMA=y

Second add the following in /boot/cmdline.txt
cma=32M

Reboot

After that the dmesg shows:
[ 0.000000] Memory: 716416K/770048K available (8022K kernel code, 440K rwdata, 1872K rodata, 1792K init, 764K bss, 20864K reserved, 32768K cma-reserved)

So we got 32768K cma-reserved!

And now the urbs allocated message is gone and i can change colors, effects and anything else, and turn the ambilight back on for watching a movie, as often as i want! :)

Im sorry for my bad english.. but its very late in the night, and im very tired, and very excited that we could figured that out together :D

@hungerburg
Copy link
Author

hungerburg commented Feb 20, 2017

@Vaskyy Indeed, setting cma=32 in cmdline.txt makes the alloc messages disappear; still no good pictures from the cam, this time though the first one is good :) Do you still see these messages in dmesg?
URB packet 0, status -63 [Buffer error (overrun)].

@sassmann
Copy link
Contributor

To be clear, I'm still experiencing the buffer errors from time to time, so it's only a partial fix.

@Vaskyy
Copy link

Vaskyy commented Feb 21, 2017

yeah, unfortunately i see them too :(
and indeed my screenshots are bad too :/

So, no one is getting rid of this on stk1160 ?

@P33M
Copy link
Contributor

P33M commented May 4, 2017

Closing USB issues as OP has not updated the thread. Further comments by the OP stating that the issue is still present on latest rpi-update kernel will lead to a review.

@P33M P33M closed this as completed May 4, 2017
@cacheflood
Copy link

cacheflood commented Aug 6, 2019

Still issues with rpi3:

19_08_06_04_45
19_08_06_18:39

I have replaced cables, tried different psu:s on cams and rpi,different cameras, 2 digizers...
Tried also rpi1 and with that almost all images were corrupted.

Can this be some timing (resources) issue or something? when I take smaller image with multiple frames on it (f.e 240x200) there is no problems. but if image size is as on examples, I start to get interlacing.

popcornmix pushed a commit that referenced this issue Jul 20, 2020
[ Upstream commit 2a762e9 ]

There are two types of the lower interface of rmnet that are VND
and BRIDGE.
Each lower interface can have only one type either VND or BRIDGE.
But, there is a case, which uses both lower interface types.
Due to this unexpected behavior, lower interface leak occurs.

Test commands:
    ip link add dummy0 type dummy
    ip link add dummy1 type dummy
    ip link add rmnet0 link dummy0 type rmnet mux_id 1
    ip link set dummy1 master rmnet0
    ip link add rmnet1 link dummy1 type rmnet mux_id 2
    ip link del rmnet0

The dummy1 was attached as BRIDGE interface of rmnet0.
Then, it also was attached as VND interface of rmnet1.
This is unexpected behavior and there is no code for handling this case.
So that below splat occurs when the rmnet0 interface is deleted.

Splat looks like:
[   53.254112][    C1] WARNING: CPU: 1 PID: 1192 at net/core/dev.c:8992 rollback_registered_many+0x986/0xcf0
[   53.254117][    C1] Modules linked in: rmnet dummy openvswitch nsh nf_conncount nf_nat nf_conntrack nf_defrag_ipv6 nfx
[   53.254182][    C1] CPU: 1 PID: 1192 Comm: ip Not tainted 5.8.0-rc1+ #620
[   53.254188][    C1] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[   53.254192][    C1] RIP: 0010:rollback_registered_many+0x986/0xcf0
[   53.254200][    C1] Code: 41 8b 4e cc 45 31 c0 31 d2 4c 89 ee 48 89 df e8 e0 47 ff ff 85 c0 0f 84 cd fc ff ff 0f 0b e5
[   53.254205][    C1] RSP: 0018:ffff888050a5f2e0 EFLAGS: 00010287
[   53.254214][    C1] RAX: ffff88805756d658 RBX: ffff88804d99c000 RCX: ffffffff8329d323
[   53.254219][    C1] RDX: 1ffffffff0be6410 RSI: 0000000000000008 RDI: ffffffff85f32080
[   53.254223][    C1] RBP: dffffc0000000000 R08: fffffbfff0be6411 R09: fffffbfff0be6411
[   53.254228][    C1] R10: ffffffff85f32087 R11: 0000000000000001 R12: ffff888050a5f480
[   53.254233][    C1] R13: ffff88804d99c0b8 R14: ffff888050a5f400 R15: ffff8880548ebe40
[   53.254238][    C1] FS:  00007f6b86b370c0(0000) GS:ffff88806c200000(0000) knlGS:0000000000000000
[   53.254243][    C1] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   53.254248][    C1] CR2: 0000562c62438758 CR3: 000000003f600005 CR4: 00000000000606e0
[   53.254253][    C1] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[   53.254257][    C1] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[   53.254261][    C1] Call Trace:
[   53.254266][    C1]  ? lockdep_hardirqs_on_prepare+0x379/0x540
[   53.254270][    C1]  ? netif_set_real_num_tx_queues+0x780/0x780
[   53.254275][    C1]  ? rmnet_unregister_real_device+0x56/0x90 [rmnet]
[   53.254279][    C1]  ? __kasan_slab_free+0x126/0x150
[   53.254283][    C1]  ? kfree+0xdc/0x320
[   53.254288][    C1]  ? rmnet_unregister_real_device+0x56/0x90 [rmnet]
[   53.254293][    C1]  unregister_netdevice_many.part.135+0x13/0x1b0
[   53.254297][    C1]  rtnl_delete_link+0xbc/0x100
[   53.254301][    C1]  ? rtnl_af_register+0xc0/0xc0
[   53.254305][    C1]  rtnl_dellink+0x2dc/0x840
[   53.254309][    C1]  ? find_held_lock+0x39/0x1d0
[   53.254314][    C1]  ? valid_fdb_dump_strict+0x620/0x620
[   53.254318][    C1]  ? rtnetlink_rcv_msg+0x457/0x890
[   53.254322][    C1]  ? lock_contended+0xd20/0xd20
[   53.254326][    C1]  rtnetlink_rcv_msg+0x4a8/0x890
[ ... ]
[   73.813696][ T1192] unregister_netdevice: waiting for rmnet0 to become free. Usage count = 1

Fixes: 037f9cd ("net: rmnet: use upper/lower device infrastructure")
Signed-off-by: Taehee Yoo <[email protected]>
Signed-off-by: David S. Miller <[email protected]>
Signed-off-by: Sasha Levin <[email protected]>
popcornmix pushed a commit that referenced this issue Aug 12, 2020
commit 2a762e9 upstream.

There are two types of the lower interface of rmnet that are VND
and BRIDGE.
Each lower interface can have only one type either VND or BRIDGE.
But, there is a case, which uses both lower interface types.
Due to this unexpected behavior, lower interface leak occurs.

Test commands:
    ip link add dummy0 type dummy
    ip link add dummy1 type dummy
    ip link add rmnet0 link dummy0 type rmnet mux_id 1
    ip link set dummy1 master rmnet0
    ip link add rmnet1 link dummy1 type rmnet mux_id 2
    ip link del rmnet0

The dummy1 was attached as BRIDGE interface of rmnet0.
Then, it also was attached as VND interface of rmnet1.
This is unexpected behavior and there is no code for handling this case.
So that below splat occurs when the rmnet0 interface is deleted.

Splat looks like:
[   53.254112][    C1] WARNING: CPU: 1 PID: 1192 at net/core/dev.c:8992 rollback_registered_many+0x986/0xcf0
[   53.254117][    C1] Modules linked in: rmnet dummy openvswitch nsh nf_conncount nf_nat nf_conntrack nf_defrag_ipv6 nfx
[   53.254182][    C1] CPU: 1 PID: 1192 Comm: ip Not tainted 5.8.0-rc1+ #620
[   53.254188][    C1] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[   53.254192][    C1] RIP: 0010:rollback_registered_many+0x986/0xcf0
[   53.254200][    C1] Code: 41 8b 4e cc 45 31 c0 31 d2 4c 89 ee 48 89 df e8 e0 47 ff ff 85 c0 0f 84 cd fc ff ff 0f 0b e5
[   53.254205][    C1] RSP: 0018:ffff888050a5f2e0 EFLAGS: 00010287
[   53.254214][    C1] RAX: ffff88805756d658 RBX: ffff88804d99c000 RCX: ffffffff8329d323
[   53.254219][    C1] RDX: 1ffffffff0be6410 RSI: 0000000000000008 RDI: ffffffff85f32080
[   53.254223][    C1] RBP: dffffc0000000000 R08: fffffbfff0be6411 R09: fffffbfff0be6411
[   53.254228][    C1] R10: ffffffff85f32087 R11: 0000000000000001 R12: ffff888050a5f480
[   53.254233][    C1] R13: ffff88804d99c0b8 R14: ffff888050a5f400 R15: ffff8880548ebe40
[   53.254238][    C1] FS:  00007f6b86b370c0(0000) GS:ffff88806c200000(0000) knlGS:0000000000000000
[   53.254243][    C1] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   53.254248][    C1] CR2: 0000562c62438758 CR3: 000000003f600005 CR4: 00000000000606e0
[   53.254253][    C1] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[   53.254257][    C1] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[   53.254261][    C1] Call Trace:
[   53.254266][    C1]  ? lockdep_hardirqs_on_prepare+0x379/0x540
[   53.254270][    C1]  ? netif_set_real_num_tx_queues+0x780/0x780
[   53.254275][    C1]  ? rmnet_unregister_real_device+0x56/0x90 [rmnet]
[   53.254279][    C1]  ? __kasan_slab_free+0x126/0x150
[   53.254283][    C1]  ? kfree+0xdc/0x320
[   53.254288][    C1]  ? rmnet_unregister_real_device+0x56/0x90 [rmnet]
[   53.254293][    C1]  unregister_netdevice_many.part.135+0x13/0x1b0
[   53.254297][    C1]  rtnl_delete_link+0xbc/0x100
[   53.254301][    C1]  ? rtnl_af_register+0xc0/0xc0
[   53.254305][    C1]  rtnl_dellink+0x2dc/0x840
[   53.254309][    C1]  ? find_held_lock+0x39/0x1d0
[   53.254314][    C1]  ? valid_fdb_dump_strict+0x620/0x620
[   53.254318][    C1]  ? rtnetlink_rcv_msg+0x457/0x890
[   53.254322][    C1]  ? lock_contended+0xd20/0xd20
[   53.254326][    C1]  rtnetlink_rcv_msg+0x4a8/0x890
[ ... ]
[   73.813696][ T1192] unregister_netdevice: waiting for rmnet0 to become free. Usage count = 1

Fixes: 037f9cd ("net: rmnet: use upper/lower device infrastructure")
Signed-off-by: Taehee Yoo <[email protected]>
Signed-off-by: David S. Miller <[email protected]>
Signed-off-by: Greg Kroah-Hartman <[email protected]>
margro pushed a commit to margro/linux that referenced this issue May 28, 2023
commit 2a762e9 upstream.

There are two types of the lower interface of rmnet that are VND
and BRIDGE.
Each lower interface can have only one type either VND or BRIDGE.
But, there is a case, which uses both lower interface types.
Due to this unexpected behavior, lower interface leak occurs.

Test commands:
    ip link add dummy0 type dummy
    ip link add dummy1 type dummy
    ip link add rmnet0 link dummy0 type rmnet mux_id 1
    ip link set dummy1 master rmnet0
    ip link add rmnet1 link dummy1 type rmnet mux_id 2
    ip link del rmnet0

The dummy1 was attached as BRIDGE interface of rmnet0.
Then, it also was attached as VND interface of rmnet1.
This is unexpected behavior and there is no code for handling this case.
So that below splat occurs when the rmnet0 interface is deleted.

Splat looks like:
[   53.254112][    C1] WARNING: CPU: 1 PID: 1192 at net/core/dev.c:8992 rollback_registered_many+0x986/0xcf0
[   53.254117][    C1] Modules linked in: rmnet dummy openvswitch nsh nf_conncount nf_nat nf_conntrack nf_defrag_ipv6 nfx
[   53.254182][    C1] CPU: 1 PID: 1192 Comm: ip Not tainted 5.8.0-rc1+ raspberrypi#620
[   53.254188][    C1] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
[   53.254192][    C1] RIP: 0010:rollback_registered_many+0x986/0xcf0
[   53.254200][    C1] Code: 41 8b 4e cc 45 31 c0 31 d2 4c 89 ee 48 89 df e8 e0 47 ff ff 85 c0 0f 84 cd fc ff ff 0f 0b e5
[   53.254205][    C1] RSP: 0018:ffff888050a5f2e0 EFLAGS: 00010287
[   53.254214][    C1] RAX: ffff88805756d658 RBX: ffff88804d99c000 RCX: ffffffff8329d323
[   53.254219][    C1] RDX: 1ffffffff0be6410 RSI: 0000000000000008 RDI: ffffffff85f32080
[   53.254223][    C1] RBP: dffffc0000000000 R08: fffffbfff0be6411 R09: fffffbfff0be6411
[   53.254228][    C1] R10: ffffffff85f32087 R11: 0000000000000001 R12: ffff888050a5f480
[   53.254233][    C1] R13: ffff88804d99c0b8 R14: ffff888050a5f400 R15: ffff8880548ebe40
[   53.254238][    C1] FS:  00007f6b86b370c0(0000) GS:ffff88806c200000(0000) knlGS:0000000000000000
[   53.254243][    C1] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   53.254248][    C1] CR2: 0000562c62438758 CR3: 000000003f600005 CR4: 00000000000606e0
[   53.254253][    C1] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[   53.254257][    C1] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[   53.254261][    C1] Call Trace:
[   53.254266][    C1]  ? lockdep_hardirqs_on_prepare+0x379/0x540
[   53.254270][    C1]  ? netif_set_real_num_tx_queues+0x780/0x780
[   53.254275][    C1]  ? rmnet_unregister_real_device+0x56/0x90 [rmnet]
[   53.254279][    C1]  ? __kasan_slab_free+0x126/0x150
[   53.254283][    C1]  ? kfree+0xdc/0x320
[   53.254288][    C1]  ? rmnet_unregister_real_device+0x56/0x90 [rmnet]
[   53.254293][    C1]  unregister_netdevice_many.part.135+0x13/0x1b0
[   53.254297][    C1]  rtnl_delete_link+0xbc/0x100
[   53.254301][    C1]  ? rtnl_af_register+0xc0/0xc0
[   53.254305][    C1]  rtnl_dellink+0x2dc/0x840
[   53.254309][    C1]  ? find_held_lock+0x39/0x1d0
[   53.254314][    C1]  ? valid_fdb_dump_strict+0x620/0x620
[   53.254318][    C1]  ? rtnetlink_rcv_msg+0x457/0x890
[   53.254322][    C1]  ? lock_contended+0xd20/0xd20
[   53.254326][    C1]  rtnetlink_rcv_msg+0x4a8/0x890
[ ... ]
[   73.813696][ T1192] unregister_netdevice: waiting for rmnet0 to become free. Usage count = 1

Fixes: 037f9cd ("net: rmnet: use upper/lower device infrastructure")
Signed-off-by: Taehee Yoo <[email protected]>
Signed-off-by: David S. Miller <[email protected]>
Signed-off-by: Greg Kroah-Hartman <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests