segfault on both Raspberry Pi B+ and 2 running Raspbian, Microsoft LifeCam Cinema Webcam

DrnSln commented 9 years ago

When setting the format = mjpeg in the hawkeye.conf file, hawkeye segfaults.

Hawkeye will start when switching format to yuv and properly display images captured from several cameras ( Ps3Eye, Microsoft Life Cam VX-800 and Microsoft LifeCam Cinema ).

Details :

# dmesg | tail -10

[ 3833.680384] usb 1-1.5: new high-speed USB device number 5 using dwc_otg
[ 3833.796657] usb 1-1.5: New USB device found, idVendor=045e, idProduct=075d
[ 3833.796681] usb 1-1.5: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 3833.796699] usb 1-1.5: Product: Microsoft\xffffffc2\xffffffae\xffffffae LifeCam Cinema(TM)
[ 3833.796716] usb 1-1.5: Manufacturer: Microsoft
[ 3833.798904] uvcvideo: Found UVC 1.00 device Microsoft\xffffffc2\xffffffae\xffffffae LifeCam Cinema(TM) (045e:075d)
[ 3833.805161] input: Microsoft\xffffffc2\xffffffae\xffffffae LifeCam Cinema(TM) as /devices/platform/bcm2708_usb/usb1/1-1/1-1.5/1-1.5:1.0/input/input1
[ 3838.920348] usb 1-1.5: 3:1: cannot get freq at ep 0x82
[ 3899.780427] uvcvideo: Failed to resubmit video URB (-1).

# cat /var/log/hawkeye.log

2015-05-14 12:52:41 DEBUG: Buffer mapped at address 0x76905000 for device /dev/video0.
2015-05-14 12:52:41 DEBUG: Buffer mapped at address 0x76743000 for device /dev/video0.
2015-05-14 12:52:41 DEBUG: Buffer mapped at address 0x76581000 for device /dev/video0.
2015-05-14 12:52:41 DEBUG: Buffer mapped at address 0x763bf000 for device /dev/video0.
2015-05-14 12:52:41 INFO: Starting capture on device /dev/video0.
2015-05-14 12:52:42 DEBUG: Current resolution is 1280x720 on device /dev/video0.
2015-05-14 12:52:42 DEBUG: /dev/video0: Supported format: YUV 4:2:2 (YUYV)
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 640x480
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 1280x720
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 960x544
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 800x448
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 640x360
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 424x240
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 352x288
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 320x240
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 800x600
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 176x144
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 160x120
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 1280x800
2015-05-14 12:52:42 DEBUG: /dev/video0: Supported format: MJPEG
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 640x480
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 1280x720
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 960x544
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 800x448
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 640x360
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 800x600
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 416x240
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 352x288
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 176x144
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 320x240
2015-05-14 12:52:42 DEBUG: /dev/video0: supported size: 160x120
2015-05-14 12:52:42 INFO: Starting server.
2015-05-14 12:52:42 DEBUG: getaddrinfo error for hostname '192.168.1.179': Address family for hostname not supported.
2015-05-14 12:52:42 INFO: Listening on 0.0.0.0 port 8000.

# strace hawkeye -c doc/hawkeye.conf

...
gettimeofday({1431622631, 225111}, NULL) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3477, ...}) = 0
write(3, "2015-05-14 12:57:11 DEBUG: /dev/"..., 64) = 64
ioctl(4, VIDIOC_ENUM_FRAMESIZES, 0x7e937574) = 0
gettimeofday({1431622631, 225905}, NULL) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3477, ...}) = 0
write(3, "2015-05-14 12:57:11 DEBUG: /dev/"..., 64) = 64
ioctl(4, VIDIOC_ENUM_FRAMESIZES, 0x7e937574) = 0
gettimeofday({1431622631, 226695}, NULL) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3477, ...}) = 0
write(3, "2015-05-14 12:57:11 DEBUG: /dev/"..., 64) = 64
ioctl(4, VIDIOC_ENUM_FRAMESIZES, 0x7e937574) = 0
gettimeofday({1431622631, 227479}, NULL) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3477, ...}) = 0
write(3, "2015-05-14 12:57:11 DEBUG: /dev/"..., 64) = 64
ioctl(4, VIDIOC_ENUM_FRAMESIZES, 0x7e937574) = 0
gettimeofday({1431622631, 228274}, NULL) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3477, ...}) = 0
write(3, "2015-05-14 12:57:11 DEBUG: /dev/"..., 64) = 64
ioctl(4, VIDIOC_ENUM_FRAMESIZES, 0x7e937574) = -1 EINVAL (Invalid argument)
ioctl(4, VIDIOC_ENUM_FMT or VT_SETMODE, 0x7e937534) = -1 EINVAL (Invalid argument)
mmap2(NULL, 1867776, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7616e000
getuid32()                              = 0
getuid32()                              = 0
gettimeofday({1431622631, 229779}, NULL) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3477, ...}) = 0
write(3, "2015-05-14 12:57:11 INFO: Starti"..., 43) = 43
socket(PF_NETLINK, SOCK_RAW, 0)         = 5
bind(5, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 0
getsockname(5, {sa_family=AF_NETLINK, pid=2420, groups=00000000}, [12]) = 0
gettimeofday({1431622631, 231917}, NULL) = 0
sendto(5, "\24\0\0\0\26\0\1\3\347\323TU\0\0\0\0\0\0\0\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
recvmsg(5, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"L\0\0\0\24\0\2\0\347\323TUt\t\0\0\2\10\200\376\1\0\0\0\10\0\1\0\177\0\0\1"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 164
recvmsg(5, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"\24\0\0\0\3\0\2\0\347\323TUt\t\0\0\0\0\0\0\1\0\0\0\10\0\1\0\177\0\0\1"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 20
close(5)                                = 0
gettimeofday({1431622631, 233261}, NULL) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3477, ...}) = 0
write(3, "2015-05-14 12:57:11 DEBUG: getad"..., 118) = 118
socket(PF_NETLINK, SOCK_RAW, 0)         = 5
bind(5, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 0
getsockname(5, {sa_family=AF_NETLINK, pid=2420, groups=00000000}, [12]) = 0
gettimeofday({1431622631, 234441}, NULL) = 0
sendto(5, "\24\0\0\0\26\0\1\3\347\323TU\0\0\0\0\0\0\0\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
recvmsg(5, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"L\0\0\0\24\0\2\0\347\323TUt\t\0\0\2\10\200\376\1\0\0\0\10\0\1\0\177\0\0\1"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 164
recvmsg(5, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"\24\0\0\0\3\0\2\0\347\323TUt\t\0\0\0\0\0\0\1\0\0\0\10\0\1\0\177\0\0\1"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 20
close(5)                                = 0
socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 5
setsockopt(5, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
bind(5, {sa_family=AF_INET, sin_port=htons(8000), sin_addr=inet_addr("192.168.1.179")}, 16) = 0
gettimeofday({1431622631, 236193}, NULL) = 0
stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=3477, ...}) = 0
write(3, "2015-05-14 12:57:11 INFO: Listen"..., 58) = 58
listen(5, 5)                            = 0
gettimeofday({1431622631, 237099}, NULL) = 0
ioctl(4, VIDIOC_DQBUF, 0xde175c)        = 0
ioctl(4, VIDIOC_QBUF or VT_SETACTIVATE, 0xde175c) = 0
--- SIGSEGV (Segmentation fault) @ 0 (0) ---
+++ killed by SIGSEGV +++

DrnSln commented 9 years ago

After compiling hawkeye with debug symbols and ran it through gdb ( use handle SIGILL nostop noprint to not choke and fail with "in memcpy () from /usr/lib/arm-linux-gnueabihf/libcofi_rpi.so" ), I isolated the code causing the error to https://github.com/ipartola/hawkeye/blob/master/src/v4l2uvc.c#L398-400

Outputting the values before that memcpy with :

        printf("MEMCPY: dst %p | pos %p | dst + pos %p | ptcur %p | src_size %i | sizein %i | src_size - sizein %i \n", dst, pos, dst + pos, ptcur, src_size, sizein, src_size - sizein );
        memcpy(dst + pos, ptcur, src_size - sizein);
        pos += src_size - sizein;

Inserting a printf before the https://github.com/ipartola/hawkeye/blob/master/src/main.c#L122

printf("buf %p | sizeof(buf) %i | fb->vd->framebuffer %p | fb->vd->buf.bytesused %i\n", buf, sizeof(buf), fb->vd->framebuffer, fb->vd->buf.bytesused );

will output : buf 0x7ec9e5d0 | sizeof(buf) 1863680 | fb->vd->framebuffer 0x761b1008 | fb->vd->buf.bytesused 0

ipartola commented 9 years ago

@DrnSln Thanks, this is really helpful. I ran into the same issue, so that's what I'm trying to investigate, time-permitting. So looks like for whatever reason fb->vd->buf.bytesused is set to be 0.

This should be set in https://github.com/ipartola/hawkeye/blob/master/src/v4l2uvc.c#L414 and is actually used in https://github.com/ipartola/hawkeye/blob/master/src/v4l2uvc.c#L427. I wonder if something in the V4L2 API changed and I need to update the capture_frame() function.

ipartola commented 9 years ago

I just pushed a fix that I believe takes care of this. Basically, there was a race condition between capture_frame() and grab_frame() where capture_frame() would re-queue the buffer to the video device before grab_frame() was able to copy the data from it.

Now grab_frame() explicitly re-queues the buffer to the video device when it's done with it. This was likely an issue for YUV as well, but it's possible it just never hit the race condition. Version 0.3 should work fine.

Please verify that it works for you, and if so I'll close this issue.

DrnSln commented 9 years ago

I can confirm that your change fixed the issue, the streaming works great now !

Thank you very much !

ipartola / hawkeye

segfault on both Raspberry Pi B+ and 2 running Raspbian, Microsoft LifeCam Cinema Webcam #5