search

stephendade / Rpanion-server

Web-based configurator for companion computers of MAVLink vehicles
https://www.docs.rpanion.com/software/rpanion-server
GNU General Public License v3.0
146 stars 62 forks source link

RTP streaming lost, not sure if the encoding process is exit #223

Closed lida2003 closed 1 month ago

lida2003 commented 6 months ago

I have discovered an issue with the RTP stream, which cannot be restored after the RTP stream is disconnected, regardless of the data flow or network link conditions. From the ssh top, it appears that the process is gone.

stephendade commented 6 months ago

Do you have a Rpanion-server logfile? It should show any errors encountered by the video streaming system

lida2003 commented 6 months ago

I didn't find any useful info, since app.log seems stop working since 2024-02-14.

This is all I got: app.log

stephendade commented 6 months ago

Which RPi model, OS version (bullseye?) and camera are you using? Could you try lower resolution/fps and see if that makes it more stable?

Try deleting the app.log and see if Rpanion-server creates a new one.

EDIT: Also try upgrading the latest QGC version, if you haven't already

lida2003 commented 6 months ago

Which RPi model, OS version (bullseye?) 

$ lsb_release -a
No LSB modules are available.
Distributor ID: Debian
Description:    Debian GNU/Linux 11 (bullseye)
Release:        11
Codename:       bullseye

and camera are you using?

OV5647

Could you try lower resolution/fps and see if that makes it more stable?

720P@30FPS, 1100Kbps

Try deleting the app.log and see if Rpanion-server creates a new one.

Ah,,, I saw extra two log files, but the webpage didn't see those extra log file.

Well all the messages I don't know what to look at :(

app1.log

app2.log

~/Rpanion-server/logs $ ls -al
total 10496
drwxr-xr-x  2 daniel daniel    4096 May  9 02:26 .
drwxr-xr-x 16 daniel daniel    4096 May  7 22:50 ..
-rw-r--r--  1 daniel daniel 5245972 May  9 02:26 app1.log
-rw-r--r--  1 daniel daniel  232497 May 12 22:56 app2.log
-rw-r--r--  1 daniel daniel 5243141 Feb 14 00:01 app.log

EDIT: Also try upgrading the latest QGC version, if you haven't already

v4.4.0 release candidate 1 my test go with this version on laptop.

I didn't find/notice on 4.3.0 apk version.

lida2003 commented 6 months ago

It'm NOT sure if it's OK for 720P to report not enough memory (from app2.log) v4l2bufferpool gstv4l2bufferpool.c:814:gst_v4l2_buffer_pool_start:<v4l2h264enc0:pool0:src>�[00m Uncertain or not enough buffers, enabling copy threshold 

2024-05-09 10:01:27 info [server/index.js]: [object Object],[object Object]
2024-05-09 10:01:33 info [server/networkManager.js]: getConnections() got: 5
2024-05-09 10:01:33 info [server/networkManager.js]: getAdapters() adding wlan0,wifi,connected
2024-05-09 10:01:33 info [server/networkManager.js]: getAdapters() adding usb0,ethernet,connected
2024-05-09 10:01:33 info [server/networkManager.js]: getAdapters() adding zt44xhvvrc,tun,connected (externally)
2024-05-09 10:01:33 info [server/networkManager.js]: getAdapters() adding eth0,ethernet,unavailable
2024-05-09 10:10:33 info [server/index.js]: [{"value": "/base/soc/i2c0mux/i2c@1/ov5647@36", "label": "CSI Port Camera (ov5647)", "caps": [{"value": "1920x1080xx-raw", "label": "1920x1080", "height": 1080, "width": 1920, "format": "video/x-raw", "fpsmax": "30", "fps": []}, {"value": "1640x922xx-raw", "label": "1640x922", "height": 922, "width": 1640, "format": "video/x-raw", "fpsmax": "40", "fps": []}, {"value": "1280x720xx-raw", "label": "1280x720", "height": 720, "width": 1280, "format": "video/x-raw", "fpsmax": "60", "fps": []}, {"value": "640x480xx-raw", "label": "640x480", "height": 480, "width": 640, "format": "video/x-raw", "fpsmax": "90", "fps": []}]}, {"value": "testsrc", "label": "Test Source", "caps": [{"value": "1920x1080xx-raw", "label": "1920x1080", "height": 1080, "width": 1920, "format": "video/x-raw", "fpsmax": "30", "fps": []}, {"value": "1280x720xx-raw", "label": "1280x720", "height": 720, "width": 1280, "format": "video/x-raw", "fpsmax": "30", "fps": []}, {"value": "640x480xx-raw", "label": "640x480", "height": 480, "width": 640, "format": "video/x-raw", "fpsmax": "30", "fps": []}]}]

2024-05-09 10:10:33 info [server/index.js]: [object Object],[object Object]
2024-05-09 10:11:17 info [server/index.js]: Started Video Streaming of /base/soc/i2c0mux/i2c@1/ov5647@36
2024-05-09 10:11:18 error [server/index.js]: startStopStreaming() err  0:00:00.308678750  1250     0x3f1bf330 WARN                    v4l2 gstv4l2object.c:4403:gst_v4l2_object_probe_caps:<v4l2h264enc0:src> Failed to probe pixel aspect ratio with VIDIOC_CROPCAP: Invalid argument

2024-05-09 10:11:18 error [server/index.js]: startStopStreaming() err  [0:13:28.607088417] [1250]  INFO Camera camera_manager.cpp:297 libcamera v0.0.5+83-bde9b04f

2024-05-09 10:11:18 error [server/index.js]: startStopStreaming() err  [0:13:28.735936984] [1251]  INFO RPI vc4.cpp:437 Registered camera /base/soc/i2c0mux/i2c@1/ov5647@36 to Unicam device /dev/media3 and ISP device /dev/media0

2024-05-09 10:11:18 error [server/index.js]: startStopStreaming() err  0:00:00.449229488  1250     0x3f163120 FIXME                default gstutils.c:4025:gst_pad_create_stream_id_internal:<libcamerasrc0:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id

2024-05-09 10:11:18 error [server/index.js]: startStopStreaming() err  [0:13:28.768923259] [1256]  INFO Camera camera.cpp:1033 configuring streams: (0) 1280x720-NV12

2024-05-09 10:11:18 error [server/index.js]: startStopStreaming() err  [0:13:28.770590192] [1251]  INFO RPI vc4.cpp:565 Sensor: /base/soc/i2c0mux/i2c@1/ov5647@36 - Selected sensor format: 1920x1080-SGBRG10_1X10 - Selected unicam format: 1920x1080-pGAA

2024-05-09 10:11:18 error [server/index.js]: startStopStreaming() err  [0:13:28.936212205] [1251]  INFO V4L2 v4l2_videodevice.cpp:1820 /dev/video0[20:cap]: Zero sequence expected for first frame (got 1)

2024-05-09 10:11:19 error [server/index.js]: startStopStreaming() err  0:00:01.024506946  1250     0x3f1630c0 WARN          v4l2bufferpool gstv4l2bufferpool.c:814:gst_v4l2_buffer_pool_start:<v4l2h264enc0:pool0:src> Uncertain or not enough buffers, enabling copy threshold

2024-05-09 10:11:27 info [server/index.js]: Reset Video Settings
2024-05-09 10:11:27 info [server/index.js]: startStopStreaming() close null
2024-05-09 10:11:27 info [server/index.js]: Reset Video Settings
2024-05-09 10:19:49 info [server/index.js]: Started Video Streaming of /base/soc/i2c0mux/i2c@1/ov5647@36
2024-05-09 10:19:50 error [server/index.js]: startStopStreaming() err  0:00:00.309389172  1304     0x36826730 WARN                    v4l2 gstv4l2object.c:4403:gst_v4l2_object_probe_caps:<v4l2h264enc0:src> Failed to probe pixel aspect ratio with VIDIOC_CROPCAP: Invalid argument

2024-05-09 10:19:50 error [server/index.js]: startStopStreaming() err  [0:22:00.972390308] [1304]  INFO Camera camera_manager.cpp:297 libcamera v0.0.5+83-bde9b04f

2024-05-09 10:19:50 error [server/index.js]: startStopStreaming() err  [0:22:01.104438526] [1305]  INFO RPI vc4.cpp:437 Registered camera /base/soc/i2c0mux/i2c@1/ov5647@36 to Unicam device /dev/media3 and ISP device /dev/media0

2024-05-09 10:19:50 error [server/index.js]: startStopStreaming() err  0:00:00.453378186  1304     0x367ca120 FIXME                default gstutils.c:4025:gst_pad_create_stream_id_internal:<libcamerasrc0:src> Creating random stream-id, consider implementing a deterministic way of creating a stream-id

2024-05-09 10:19:50 error [server/index.js]: startStopStreaming() err  [0:22:01.135548657] [1310]  INFO Camera camera.cpp:1033 configuring streams: (0) 1280x720-NV12

2024-05-09 10:19:50 error [server/index.js]: startStopStreaming() err  [0:22:01.137269284] [1305]  INFO RPI vc4.cpp:565 Sensor: /base/soc/i2c0mux/i2c@1/ov5647@36 - Selected sensor format: 1920x1080-SGBRG10_1X10 - Selected unicam format: 1920x1080-pGAA

2024-05-09 10:19:51 error [server/index.js]: startStopStreaming() err  0:00:01.040026126  1304     0x367ca0c0 WARN          v4l2bufferpool gstv4l2bufferpool.c:814:gst_v4l2_buffer_pool_start:<v4l2h264enc0:pool0:src> Uncertain or not enough buffers, enabling copy threshold
stephendade commented 6 months ago

From your log:

2024-05-09 10:11:27 info [server/index.js]: Reset Video Settings 2024-05-09 10:11:27 info [server/index.js]: startStopStreaming() close null

That is Rpanion-server deliberately closing the stream. Are you running latest master?

Does the stream stop when you access or refresh the video page? I did fix that bug a few months ago...

EDIT: I'd be interested if you see the same behaviour with a USB camera (or Test Camera source)

lida2003 commented 6 months ago

From your log:

2024-05-09 10:11:27 info [server/index.js]: Reset Video Settings 2024-05-09 10:11:27 info [server/index.js]: startStopStreaming() close null

That is Rpanion-server deliberately closing the stream.

As the process is not exist any more (as the above video shows). But the web GUI still indicating the process is running. When I restart the video, I have to stop first, then it might be something like "close null"

Well, I'm NOT sure if the log is correct, as the I didn't remember the time(UTC+8) of those tests.

Are you running latest master?

It's VPN fixed version(2cf0809432db19cb88f4291b570195ac4add902d).

Does the stream stop when you access or refresh the video page? I did fix that bug a few months ago...

I think GUI and process is not sync when the process is exited it self.

EDIT: I'd be interested if you see the same behaviour with a USB camera (or Test Camera source)

Well, I didn't see this issue anymore. And I have know how to find/delete the log. Will report back if the phenomenon occurs again.

EDIT: The real issue, I think is this part: 720P@30FPS "Uncertain or not enough buffers, enabling copy threshold"

2024-05-09 10:19:49 info [server/index.js]: Started Video Streaming of /base/soc/i2c0mux/i2c@1/ov5647@36
2024-05-09 10:19:50 error [server/index.js]: startStopStreaming() err  0:00:00.309389172 �[33m 1304�[00m     0x36826730 �[33;01mWARN   �[00m �[00m                v4l2 gstv4l2object.c:4403:gst_v4l2_object_probe_caps:<v4l2h264enc0:src>�[00m Failed to probe pixel aspect ratio with VIDIOC_CROPCAP: Invalid argument

2024-05-09 10:19:50 error [server/index.js]: startStopStreaming() err  [0:22:00.972390308] [1304] �[1;32m INFO �[1;37mCamera �[1;34mcamera_manager.cpp:297 �[0mlibcamera v0.0.5+83-bde9b04f

2024-05-09 10:19:50 error [server/index.js]: startStopStreaming() err  [0:22:01.104438526] [1305] �[1;32m INFO �[1;37mRPI �[1;34mvc4.cpp:437 �[0mRegistered camera /base/soc/i2c0mux/i2c@1/ov5647@36 to Unicam device /dev/media3 and ISP device /dev/media0

2024-05-09 10:19:50 error [server/index.js]: startStopStreaming() err  0:00:00.453378186 �[33m 1304�[00m     0x367ca120 �[32;01mFIXME  �[00m �[00;04m             default gstutils.c:4025:gst_pad_create_stream_id_internal:<libcamerasrc0:src>�[00m Creating random stream-id, consider implementing a deterministic way of creating a stream-id

2024-05-09 10:19:50 error [server/index.js]: startStopStreaming() err  [0:22:01.135548657] [1310] �[1;32m INFO �[1;37mCamera �[1;34mcamera.cpp:1033 �[0mconfiguring streams: (0) 1280x720-NV12

2024-05-09 10:19:50 error [server/index.js]: startStopStreaming() err  [0:22:01.137269284] [1305] �[1;32m INFO �[1;37mRPI �[1;34mvc4.cpp:565 �[0mSensor: /base/soc/i2c0mux/i2c@1/ov5647@36 - Selected sensor format: 1920x1080-SGBRG10_1X10 - Selected unicam format: 1920x1080-pGAA

2024-05-09 10:19:51 error [server/index.js]: startStopStreaming() err  0:00:01.040026126 �[33m 1304�[00m     0x367ca0c0 �[33;01mWARN   �[00m �[00m      v4l2bufferpool gstv4l2bufferpool.c:814:gst_v4l2_buffer_pool_start:<v4l2h264enc0:pool0:src>�[00m Uncertain or not enough buffers, enabling copy threshold
lida2003 commented 5 months ago

Please check last video lost message. The log is downloaed lively from Pi, which suggested following steps:

  1. battery on
  2. QGC drive
  3. check https://github.com/stephendade/Rpanion-server/issues/225 issue with different bitrate
  4. last bitrate settings: 3000Kbps
  5. Then move the rover around within hand
  6. Suddenly video link lost, BUT mavlink is OK
  7. over 5mins, pulling log, write comments, video link still not recover

Lucky day, I have two logs:

Detailed log: app1.log

Detailed log: app.log

--- EDIT: Add version info

$ git log -n 1
commit 2cf0809432db19cb88f4291b570195ac4add902d (HEAD -> master, origin/master, origin/HEAD)
Author: Stephen Dade <stephen_dade@hotmail.com>
Date:   Tue May 7 21:11:50 2024 +1000

    VPN: Better Zerotier online detection
stephendade commented 5 months ago

That's interesting. Definitely a streaming failure in there.

Thanks for the logs. I'll look into it.

stephendade commented 5 months ago

Quite interesting. It appears to show the videoflip element (rotation) receiving a bad buffer at some point in the stream. According to https://forums.raspberrypi.com/viewtopic.php?t=93560, I should maybe change to I420 format.

Give #232 a go and see if that works for you.

lida2003 commented 5 months ago

I used below version quite a while, and didn't see video lost.

I think all is OK right now, just let's wait for a while. Let's say 1~2week long time test. @stephendade I'll keep you noticed when I got any issue or OK.

But it didn't improve https://github.com/stephendade/Rpanion-server/issues/225 .

https://www.bilibili.com/video/BV1fw4m1i7mq/

$ lsb_release -a
No LSB modules are available.
Distributor ID: Debian
Description:    Debian GNU/Linux 11 (bullseye)
Release:        11
Codename:       bullseye

$ git log -n 1
commit daba5a36bc361e8ddc4afe8c368b665898251d01 (HEAD -> I420Pi, origin/I420Pi)
Author: Stephen Dade <stephen_dade@hotmail.com>
Date:   Thu Jun 6 20:41:51 2024 +1000

    Video: Change to I420 format for Pi cam

PS: I have re-installed with ./RasPi2-3-4-5-deploy.sh, as I used gh pr checkout 232 instead of previous http protocol, which caused the system is upgraded. I'm NOT sure the issue is system related, just keep a note with this (as link shows " glibc detected gst-launch-1.0: free(): invalid pointer: 0x003ff0c0 ***").

lida2003 commented 5 months ago 
2024-06-07 01:04:07 error [server/index.js]: uncaughtException: Unexpected end of JSON input
SyntaxError: Unexpected end of JSON input
    at JSON.parse (<anonymous>)
    at /home/daniel/Rpanion-server/server/videostream.js:78:29
    at ChildProcess.exithandler (node:child_process:430:5)
    at ChildProcess.emit (node:events:519:28)
    at maybeClose (node:internal/child_process:1105:16)
    at Socket.<anonymous> (node:internal/child_process:457:11)
    at Socket.emit (node:events:519:28)
    at Pipe.<anonymous> (node:net:338:12)

Detailed app.log

图片

lida2003 commented 5 months ago

Well, fixed #234 . Trying now... please wait for the feedback.