Skip to content
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.

Sign up for GitHub

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

Jump to bottom

Camera streamer stops sending frames (octoprint multicam setup) #144

Open
damned-me opened this issue Mar 13, 2024 · 1 comment
Open

Camera streamer stops sending frames (octoprint multicam setup) #144

damned-me opened this issue Mar 13, 2024 · 1 comment

Comments

@damned-me
Copy link

I'm using camera-streamer on octopi to expose two webcams connected to a RPI4. Both webcams work correctly on other devices.

When connecting to the served ports with a GET /stream, I often get a 500 status code, as in the following response.

HTTP/1.1 500 Server Error
Content-Type: text/plain
Content-Length: 13

Server Error
No frames.

The service is up and running. A request to / demonstrates that the server correctly exposes the resource:

HTTP/1.1 200 OK
Content-Type: text/html
Content-Length: 2733
Access-Control-Allow-Origin: *

<!DOCTYPE html>

<html>
...
		<li>
			<a href="stream"><b>/stream</b></a> (MJPEG stream)</b><br>
			<br>
			<ul>
				<li>Get a live stream. Works everywhere, but consumes a ton of bandwidth.</li>
				<li>Uses resolution specified by <i>-camera-stream.height=</i>.</li>
			</ul>
		</li>
...
</body>
</html>

Note that the systemd process reports no errors when trying to connect

pi@octoprint:~ $ sudo systemctl status [email protected]
● [email protected] - camera-streamer endoscope
     Loaded: loaded (/etc/systemd/system/[email protected]; disabled; vendor preset: enabled)
    Drop-In: /etc/systemd/system/[email protected]
             └─override.conf
     Active: active (running) since Thu 2024-03-07 18:37:23 CET; 3h 8min ago
TriggeredBy: ● camera-streamer-usb-endoscope.path
    Process: 1114 ExecCondition=/bin/sh -c [ -e $DEVICE ] (code=exited, status=0/SUCCESS)
    Process: 1115 ExecCondition=/bin/sh -c ! ss -ltn src :$PORT | grep -q LISTEN (code=exited, status=0/SUCCESS)
   Main PID: 1118 (camera-streamer)
      Tasks: 19 (limit: 4915)
        CPU: 25.085s
     CGroup: /system.slice/system-camera\x2dstreamer\x2dusb.slice/[email protected]
             └─1118 /usr/bin/camera-streamer --http-port=8081 --camera-type=v4l2 --camera-path=/dev/v4l/by-id/usb-Generic_HD_camera-video-index0 --camera-format=YUYV --camera-width=1280 --camera-height=720 --camera-fps=15 --camera-nbufs=4 --http-listen=0.0.0.0

Mar 07 21:38:57 octoprint sh[1118]: util/http/http.c: HTTP8081/7: Client disconnected 192.168.1.187.
Mar 07 21:44:07 octoprint sh[1118]: util/http/http.c: HTTP8081/8: Client connected 192.168.1.187 (fd=12).
Mar 07 21:44:07 octoprint sh[1118]: util/http/http.c: HTTP8081/8: Request 'GET' '/stream' ''
Mar 07 21:44:09 octoprint sh[1118]: util/http/http.c: HTTP8081/8: Client disconnected 192.168.1.187.
Mar 07 21:45:06 octoprint sh[1118]: util/http/http.c: HTTP8081/9: Client connected 192.168.1.187 (fd=13).
Mar 07 21:45:06 octoprint sh[1118]: util/http/http.c: HTTP8081/9: Request 'GET' '/stream' ''
Mar 07 21:45:08 octoprint sh[1118]: util/http/http.c: HTTP8081/9: Client disconnected 192.168.1.187.
Mar 07 21:46:02 octoprint sh[1118]: util/http/http.c: HTTP8081/0: Client connected 192.168.1.187 (fd=4).
Mar 07 21:46:02 octoprint sh[1118]: util/http/http.c: HTTP8081/0: Request 'GET' '/stream' ''
Mar 07 21:46:04 octoprint sh[1118]: util/httpMar 07 21:20:51 octoprint sh[645]: device/links.c: SNAPSHOT:capture:mplane:buf0: Capture image is outdated. Skipped. Now: 9950728676, vs 9830550890.
Mar 07 21:20:52 octoprint sh[645]: util/http/http.c: HTTP8080/4: Client disconnected 192.168.1.10.
Mar 07 21:22:52 octoprint sh[645]: util/http/http.c: HTTP8080/7: Client connected 192.168.1.10 (fd=11).
Mar 07 21:22:52 octoprint sh[645]: util/http/http.c: HTTP8080/7: Request 'GET' '/snapshot' ''
Mar 07 21:22:52 octoprint sh[645]: util/http/http.c: HTTP8080/7: Client disconnected 192.168.1.10.
Mar 07 21:24:52 octoprint sh[645]: util/http/http.c: HTTP8080/5: Client connected 192.168.1.10 (fd=9).
Mar 07 21:24:52 octoprint sh[645]: util/http/http.c: HTTP8080/5: Request 'GET' '/snapshot' ''
Mar 07 21:24:52 octoprint sh[645]: util/http/http.c: HTTP8080/5: Client disconnected 192.168.1.10.
Mar 07 21:26:52 octoprint sh[645]: util/http/http.c: HTTP8080/6: Client connected 192.168.1.10 (fd=10).
Mar 07 21:26:52 octoprint sh[645]: util/http/http.c: HTTP8080/6: Request 'GET' '/snapshot' ''
Mar 07 21:26:52 octoprint sh[645]: util/http/http.c: HTTP8080/6: Client disconnected 192.168.1.10.
Mar 07 21:28:53 octoprint sh[645]: util/http/http.c: HTTP8080/8: Client connected 192.168.1.10 (fd=12).
Mar 07 21:28:53 octoprint sh[645]: util/http/http.c: HTTP8080/8: Request 'GET' '/snapshot' ''
Mar 07 21:28:53 octoprint sh[645]: util/http/http.c: HTTP8080/8: Client disconnected 192.168.1.10.
Mar 07 21:30:53 octoprint sh[645]: util/http/http.c: HTTP8080/9: Client connected 192.168.1.10 (fd=13).
Mar 07 21:30:53 octoprint sh[645]: util/http/http.c: HTTP8080/9: Request 'GET' '/snapshot' ''/http.c: HTTP8081/0: Client disconnected 192.168.1.187.
lines 1-24/24 (END)

Follows the output of journalctl -u camera-streamer\* that includes the run reported in the aforementioned output, also attaching a more comprehensive version of logs here.

Mar 07 18:37:22 octoprint systemd[1]: [email protected]: Scheduled restart job, restart counter is at 1.
Mar 07 18:37:22 octoprint systemd[1]: Stopped camera-streamer endoscope.
Mar 07 18:37:22 octoprint systemd[1]: Starting camera-streamer endoscope...
Mar 07 18:37:23 octoprint systemd[1]: Started camera-streamer endoscope.
Mar 07 18:37:23 octoprint sh[1118]: util/http/http.c: ?: HTTP listening on 0.0.0.0:8081.
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device.c: CAMERA: Device path=/dev/v4l/by-id/usb-Generic_HD_camera-video-index0 fd=14 opened
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device_options.c: CAMERA: The 'horizontal_flip=0' was failed to find.
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device_options.c: CAMERA: The 'vertical_flip=0' was failed to find.
Mar 07 18:37:23 octoprint sh[1118]: device/camera/camera_input.c: CAMERA: Disabling DMA since device uses USB (which is likely not working properly).
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/buffer_list.c: CAMERA:capture: Requested resolution=1280x720 is unavailable. Got 640x480. Accepted
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: CAMERA:capture: Using: 640x480/YUYV, buffers=2, bytesperline=1280, sizeimage=0.6MiB
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: CAMERA:capture: Opened 2 buffers. Memory used: 1.2 MiB
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device.c: SNAPSHOT: Device path=/dev/video31 fd=17 opened
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: SNAPSHOT:output:mplane: Using: 640x480/YUYV, buffers=2, bytesperline=1280, sizeimage=0.6MiB
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: SNAPSHOT:output:mplane: Opened 2 buffers. Memory used: 1.2 MiB
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: SNAPSHOT:capture:mplane: Using: 640x480/JPEG, buffers=2, bytesperline=0, sizeimage=4.0MiB
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: SNAPSHOT:capture:mplane: Opened 2 buffers. Memory used: 8.0 MiB
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device.c: VIDEO: Device path=/dev/video11 fd=22 opened
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: VIDEO:output:mplane: Using: 640x480/YUYV, buffers=2, bytesperline=1280, sizeimage=0.6MiB
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: VIDEO:output:mplane: Opened 2 buffers. Memory used: 1.2 MiB
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: VIDEO:capture:mplane: Using: 640x480/H264, buffers=2, bytesperline=0, sizeimage=0.5MiB
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: VIDEO:capture:mplane: Opened 2 buffers. Memory used: 1.0 MiB
Mar 07 18:37:23 octoprint sh[1118]: device/device.c: CAMERA: Setting frame interval_us=0 for FPS=15
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device_options.c: CAMERA: The 'AfTrigger=1' was failed to find.
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device_options.c: SNAPSHOT: Configuring option 'Compression Quality' (009d0903) = 80
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device_options.c: VIDEO: Configuring option 'Repeat Sequence Header' (009909e2) = 1
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device_options.c: VIDEO: Configuring option 'Video Bitrate Mode' (009909ce) = 0
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device_options.c: VIDEO: Configuring option 'Video Bitrate' (009909cf) = 2000000
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device_options.c: VIDEO: Configuring option 'Repeat Sequence Header' (009909e2) = 5000000
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device_options.c: VIDEO: Configuring option 'H264 I-Frame Period' (00990a66) = 30
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device_options.c: VIDEO: Configuring option 'H264 Level' (00990a67) = 11
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device_options.c: VIDEO: Configuring option 'H264 Profile' (00990a6b) = 4
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device_options.c: VIDEO: Configuring option 'H264 Minimum QP Value' (00990a61) = 16
Mar 07 18:37:23 octoprint sh[1118]: device/v4l2/device_options.c: VIDEO: Configuring option 'H264 Maximum QP Value' (00990a62) = 32
Mar 07 18:37:23 octoprint sh[1118]: device/links.c: ?: Link 0: CAMERA:capture[640x480/YUYV/2] => [SNAPSHOT:output:mplane[640x480/YUYV/2], VIDEO:output:mplane[640x480/YUYV/2]]
Mar 07 18:37:23 octoprint sh[1118]: device/links.c: ?: Link 1: SNAPSHOT:capture:mplane[640x480/JPEG/2] => [SNAPSHOT-CAPTURE, STREAM-CAPTURE]
Mar 07 18:37:23 octoprint sh[1118]: device/links.c: ?: Link 2: VIDEO:capture:mplane[640x480/H264/2] => [VIDEO-CAPTURE]
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: CAMERA:capture: Streaming started... Was 0 of 2 enqueud
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: SNAPSHOT:output:mplane: Streaming started... Was 0 of 2 enqueud
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: VIDEO:output:mplane: Streaming started... Was 0 of 2 enqueud
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: SNAPSHOT:capture:mplane: Streaming started... Was 0 of 2 enqueud
Mar 07 18:37:23 octoprint sh[1118]: device/buffer_list.c: VIDEO:capture:mplane: Streaming started... Was 0 of 2 enqueud
Mar 07 18:37:27 octoprint sh[645]: util/http/http.c: HTTP8080/9: Client connected 192.168.1.10 (fd=13).
Mar 07 18:37:29 octoprint sh[645]: util/http/http.c: HTTP8080/9: Request 'GET' '/snapshot' ''
...
Mar 07 21:36:54 octoprint sh[645]: util/http/http.c: HTTP8080/2: Request 'GET' '/snapshot' ''
Mar 07 21:36:54 octoprint sh[645]: util/http/http.c: HTTP8080/2: Client disconnected 192.168.1.10.
Mar 07 21:38:54 octoprint sh[645]: util/http/http.c: HTTP8080/3: Client connected 192.168.1.10 (fd=7).
Mar 07 21:38:54 octoprint sh[645]: util/http/http.c: HTTP8080/3: Request 'GET' '/snapshot' ''
Mar 07 21:38:54 octoprint sh[645]: device/links.c: SNAPSHOT:capture:mplane:buf0: Capture image is outdated. Skipped. Now: 11033195947, vs 10913060413.
Mar 07 21:38:54 octoprint sh[645]: util/http/http.c: HTTP8080/3: Client disconnected 192.168.1.10.
Mar 07 21:38:55 octoprint sh[1118]: util/http/http.c: HTTP8081/7: Client connected 192.168.1.187 (fd=11).
Mar 07 21:38:55 octoprint sh[1118]: util/http/http.c: HTTP8081/7: Request 'GET' '/stream' ''
Mar 07 21:38:55 octoprint sh[1118]: device/links.c: CAMERA:capture: Stale detected. Restarting streaming...
Mar 07 21:38:55 octoprint sh[1118]: device/buffer_list.c: CAMERA:capture: Streaming stopped... Was 0 of 2 enqueud
Mar 07 21:38:55 octoprint sh[1118]: device/buffer_list.c: CAMERA:capture: Streaming started... Was 0 of 2 enqueud
Mar 07 21:38:57 octoprint sh[1118]: util/http/http.c: HTTP8081/7: Client disconnected 192.168.1.187.
Mar 07 21:40:54 octoprint sh[645]: util/http/http.c: HTTP8080/4: Client connected 192.168.1.10 (fd=8).
Mar 07 21:40:54 octoprint sh[645]: util/http/http.c: HTTP8080/4: Request 'GET' '/snapshot' ''
Mar 07 21:40:54 octoprint sh[645]: util/http/http.c: HTTP8080/4: Client disconnected 192.168.1.10.
Mar 07 21:42:54 octoprint sh[645]: util/http/http.c: HTTP8080/7: Client connected 192.168.1.10 (fd=11).
Mar 07 21:42:54 octoprint sh[645]: util/http/http.c: HTTP8080/7: Request 'GET' '/snapshot' ''
Mar 07 21:42:54 octoprint sh[645]: device/links.c: SNAPSHOT:capture:mplane:buf0: Capture image is outdated. Skipped. Now: 11273686025, vs 11153548900.
Mar 07 21:42:54 octoprint sh[645]: util/http/http.c: HTTP8080/7: Client disconnected 192.168.1.10.2

This configuration used to work at alternate intervals, sometimes the cameras would work correctly but suddently stops, without a clear reason or the occurring of a particular event. Currently, restarting the unit or rebooting the system won't fix the issue.

Some fixes I've already tried are:

  • Restarted webcams and camera streamer in multiple ways (systemctl restart camera-streamer, sudo camera-streamer-control restart, etc...)
  • Read realtime log journalctl -fu camera-streamer\* looking for errors or warnings
  • Rebooting the RPI sudo shutdown now -r
  • Switching USB ports (currently using USB 3.0 ports for both devices)
  • Switching net interface (wlan0, eth0). Currently using connection trough Ethernet cable
  • Powering the RPI with different power supplies (from 15W to 65W)

I'm opening this issue after a post on the octoprint forum, more information can be found there. I may be switching to the "old" camera stack proposed by the octoprint mainline but, even if I didn't debug the program directly, I would be happy to provide valuable information for the resolution of the problem.

Thanks
@damned-me
Copy link
Author

damned-me commented Mar 17, 2024 •
edited
Loading

I wanted to add some information and so I did a quick debug run with gdb (using the following command: /usr/bin/camera-streamer --http-port=8081 --camera-type=v4l2 --camera-path=/dev/video0 --camera-format=YUYV --camera-width=1280 --camera-height=720 --camera-fps=15 --camera-nbufs=4 --http-listen=0.0.0.0) and found this stack trace:

(gdb) b http_500
Breakpoint 1 at 0x37960: file util/http/http_methods.c, line 75.
(gdb) c
Continuing.
util/http/http.c: HTTP8081/0: Client connected 192.168.1.187 (fd=4).
util/http/http.c: HTTP8081/0: Request 'GET' '/stream' ''
[Switching to Thread 0xae639ac0 (LWP 3298)]

Thread 2 "camera-streamer" hit Breakpoint 1, http_500 (stream=0xa7c005f8, data=0x0) at util/http/http_methods.c:75
75      util/http/http_methods.c: No such file or directory.
(gdb) backtrace
#0  http_500 (stream=0xa7c005f8, data=0x0) at util/http/http_methods.c:75
#1  0x0002e380 in http_stream (worker=0x2fb380, stream=0xa7c005f8) at output/http_jpeg.c:96
#2  0x0003718c in http_process (worker=0x2fb380, stream=0xa7c005f8) at util/http/http.c:194
#3  0x0003732c in http_client (worker=0x2fb380) at util/http/http.c:221
#4  0x00037428 in http_worker (worker=0x2fb380) at util/http/http.c:243
#5  0xb6f84310 in start_thread (arg=0xae639ac0) at pthread_create.c:477
#6  0xb4e7b5c8 in ?? () at ../sysdeps/unix/sysv/linux/arm/clone.S:73 from /lib/arm-linux-gnueabihf/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)

meaning that the function buffer_lock_write_loop at http_jpeg.c:93 returns 0

I noted, breaking on buffer_lock.c:141, that the function can hit goto error with frames set to zero, which means that if the function fails to get the lock it exit with a return value equal to 0. Thus hitting the if(n == 0) in http_jpeg.c:91.

(gdb) c
Continuing.
util/http/http.c: HTTP8081/1: Client disconnected 192.168.1.10.
util/http/http.c: HTTP8081/0: Client connected 192.168.1.187 (fd=4).
util/http/http.c: HTTP8081/0: Request 'GET' '/stream' ''
[Switching to Thread 0xae639ac0 (LWP 3919)]

Thread 2 "camera-streamer" hit Breakpoint 5, buffer_lock_write_loop (buf_lock=0x2b3350 <stream_lock>, nframes=0, timeout_ms=0,
    fn=0x2e24c <http_stream_buf_part>, data=0xa7c005f8) at device/buffer_lock.c:141
141     in device/buffer_lock.c
(gdb) backtrace
#0  buffer_lock_write_loop (buf_lock=0x2b3350 <stream_lock>, nframes=0, timeout_ms=0, fn=0x2e24c <http_stream_buf_part>, data=0xa7c005f8)
    at device/buffer_lock.c:141
#1  0x0002e364 in http_stream (worker=0x2fb380, stream=0xa7c005f8) at output/http_jpeg.c:93
#2  0x0003718c in http_process (worker=0x2fb380, stream=0xa7c005f8) at util/http/http.c:194
#3  0x0003732c in http_client (worker=0x2fb380) at util/http/http.c:221
#4  0x00037428 in http_worker (worker=0x2fb380) at util/http/http.c:243
#5  0xb6f84310 in start_thread (arg=0xae639ac0) at pthread_create.c:477
#6  0xb4e7b5c8 in ?? () at ../sysdeps/unix/sysv/linux/arm/clone.S:73 from /lib/arm-linux-gnueabihf/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb) i locals
buf = 0x0
ret = -1259606884
counter = 0
frames = 0
deadline_ms = 4943263440
frame_stop_ms = 4941263443
(gdb)

I wonder if this could be a concurrency related issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@damned-me