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

lida2003 · 2024-05-08T01:19:05Z

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.

The text was updated successfully, but these errors were encountered:

stephendade · 2024-05-08T10:39:35Z

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

lida2003 · 2024-05-08T11:17:55Z

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 · 2024-05-12T05:57:12Z

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 · 2024-05-12T22:11:15Z

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 · 2024-05-14T21:23:58Z

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 �[33m 1250�[00m     0x3f1bf330 �[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:11:18 error [server/index.js]: startStopStreaming() err  [0:13:28.607088417] [1250] �[1;32m INFO �[1;37mCamera �[1;34mcamera_manager.cpp:297 �[0mlibcamera v0.0.5+83-bde9b04f

2024-05-09 10:11:18 error [server/index.js]: startStopStreaming() err  [0:13:28.735936984] [1251] �[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:11:18 error [server/index.js]: startStopStreaming() err  0:00:00.449229488 �[33m 1250�[00m     0x3f163120 �[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:11:18 error [server/index.js]: startStopStreaming() err  [0:13:28.768923259] [1256] �[1;32m INFO �[1;37mCamera �[1;34mcamera.cpp:1033 �[0mconfiguring streams: (0) 1280x720-NV12

2024-05-09 10:11:18 error [server/index.js]: startStopStreaming() err  [0:13:28.770590192] [1251] �[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:11:18 error [server/index.js]: startStopStreaming() err  [0:13:28.936212205] [1251] �[1;32m INFO �[1;37mV4L2 �[1;34mv4l2_videodevice.cpp:1820 �[0;32m/dev/video0[20:cap]: �[0mZero sequence expected for first frame (got 1)

2024-05-09 10:11:19 error [server/index.js]: startStopStreaming() err  0:00:01.024506946 �[33m 1250�[00m     0x3f1630c0 �[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

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 �[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

stephendade · 2024-05-15T10:32:16Z

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 · 2024-05-15T11:06:20Z

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(2cf0809).

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 · 2024-06-05T07:48:39Z

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

battery on
QGC drive
check 4G LTE networks results in significant screen freezing and stuttering #225 issue with different bitrate
last bitrate settings: 3000Kbps
Then move the rover around within hand
Suddenly video link lost, BUT mavlink is OK
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 <[email protected]>
Date:   Tue May 7 21:11:50 2024 +1000

    VPN: Better Zerotier online detection

stephendade · 2024-06-05T10:21:31Z

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

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

stephendade · 2024-06-06T10:43:28Z

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 · 2024-06-07T00:11:27Z

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 #225 .

high bitrate will have more mosaic when moving, still image is OK
high bitrate will increase latency, below 2000kbps(aroudn 15000) is acceptable on Rover(maybe around 150~200ms lantency)

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 <[email protected]>
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 · 2024-06-07T02:37:28Z

Issue1: Reboot Rpanion meet trouble in branch-I420Pi

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

Issue2: Can't find the camera, but it's there!!! (opened a new issue: Video: Camera didn't show on WebGUI sometimes #233)

lida2003 · 2024-06-27T02:53:04Z

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

lida2003 mentioned this issue Jun 7, 2024

Video: Camera didn't show on WebGUI sometimes #233

Closed

stephendade closed this as completed Oct 10, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

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

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

lida2003 commented May 8, 2024

stephendade commented May 8, 2024

lida2003 commented May 8, 2024

stephendade commented May 12, 2024 •

edited

Loading

lida2003 commented May 12, 2024

lida2003 commented May 14, 2024 •

edited

Loading

stephendade commented May 15, 2024 •

edited

Loading

lida2003 commented May 15, 2024 •

edited

Loading

lida2003 commented Jun 5, 2024 •

edited

Loading

stephendade commented Jun 5, 2024

stephendade commented Jun 6, 2024

lida2003 commented Jun 7, 2024 •

edited

Loading

lida2003 commented Jun 7, 2024 •

edited

Loading

lida2003 commented Jun 27, 2024

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

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

Comments

lida2003 commented May 8, 2024

stephendade commented May 8, 2024

lida2003 commented May 8, 2024

stephendade commented May 12, 2024 • edited Loading

lida2003 commented May 12, 2024

lida2003 commented May 14, 2024 • edited Loading

stephendade commented May 15, 2024 • edited Loading

lida2003 commented May 15, 2024 • edited Loading

lida2003 commented Jun 5, 2024 • edited Loading

stephendade commented Jun 5, 2024

stephendade commented Jun 6, 2024

lida2003 commented Jun 7, 2024 • edited Loading

lida2003 commented Jun 7, 2024 • edited Loading

lida2003 commented Jun 27, 2024

stephendade commented May 12, 2024 •

edited

Loading

lida2003 commented May 14, 2024 •

edited

Loading

stephendade commented May 15, 2024 •

edited

Loading

lida2003 commented May 15, 2024 •

edited

Loading

lida2003 commented Jun 5, 2024 •

edited

Loading

lida2003 commented Jun 7, 2024 •

edited

Loading

lida2003 commented Jun 7, 2024 •

edited

Loading