search

QuantumEntangledAndy / neolink

An RTSP bridge to Reolink IP cameras
GNU Affero General Public License v3.0
297 stars 44 forks source link

neolink + powered camera - high CPU usage after some hours #61

Closed anthonws closed 11 months ago

anthonws commented 1 year ago

Setup

neolink docker logs:

(...)
[2023-04-15T11:11:54Z INFO  neolink::rtsp] Join Pause
[2023-04-15T11:12:04Z WARN  neolink::rtsp] tapas_hall: Retryable error: tapas_hall: Error while streaming
    Caused by:
        deadline has elapsed
[2023-04-15T11:13:00Z WARN  neolink::rtsp] tapas_hall: Retryable error: tapas_hall: Could not connect to camera
    Caused by:
        0: Failed to connect to camera tapas_hall at Address: 192.168.1.216:9000 on channel 0
        1: Cannot contact camera at given address
[2023-04-15T11:13:00Z INFO  neolink_core::bc_protocol] tapas_hall: TCP Discovery success at 192.168.1.216:9000
(...)

Frigate docker logs

2023-04-16 07:58:47.635806588  07:58:47.635 WRN [rtsp] error="source 0 error: dial tcp 192.168.1.10:8889: connect: connection refused" stream=tapas_balcony
2023-04-16 07:58:47.639060992  [2023-04-16 07:58:47] frigate.video                  ERROR   : tapas_balcony: Unable to read frames from ffmpeg process.
2023-04-16 07:58:47.639628721  [2023-04-16 07:58:47] frigate.video                  ERROR   : tapas_balcony: ffmpeg process is not running. exiting capture thread...
2023-04-16 07:58:50.071712983  192.168.25.9 - - [16/Apr/2023:07:58:50 +0000] "GET /api/stats HTTP/1.1" 200 2289 "-" "HomeAssistant/2023.4.4 aiohttp/3.8.4 Python/3.10" "-"
2023-04-16 07:58:57.636225154  [2023-04-16 07:58:57] watchdog.tapas_balcony         ERROR   : Ffmpeg process crashed unexpectedly for tapas_balcony.
2023-04-16 07:58:57.637464564  [2023-04-16 07:58:57] watchdog.tapas_balcony         ERROR   : The following ffmpeg logs include the last 100 lines prior to exit.
2023-04-16 07:58:57.637481849  [2023-04-16 07:58:57] ffmpeg.tapas_balcony.detect    ERROR   : [rtsp @ 0x55ceb1a54100] method DESCRIBE failed: 404 Not Found
2023-04-16 07:58:57.637484388  [2023-04-16 07:58:57] ffmpeg.tapas_balcony.detect    ERROR   : rtsp://127.0.0.1:8554/tapas_balcony: Server returned 404 Not Found
2023-04-16 07:58:57.674282953  07:58:57.673 ERR github.com/AlexxIT/go2rtc/cmd/streams/producer.go:53 > error="dial tcp 192.168.1.10:8889: connect: connection refused" url=rtsp://192.168.1.10:8889/tapas_balcony
2023-04-16 07:58:57.675132153  07:58:57.674 ERR github.com/AlexxIT/go2rtc/cmd/streams/producer.go:53 > error="dial tcp 192.168.1.10:8889: connect: connection refused" url=rtsp://192.168.1.10:8889/tapas_balcony
2023-04-16 07:58:57.675483306  07:58:57.675 WRN [rtsp] error="source 0 error: dial tcp 192.168.1.10:8889: connect: connection refused" stream=tapas_balcony
2023-04-16 07:58:57.682663332  [2023-04-16 07:58:57] frigate.video                  ERROR   : tapas_balcony: Unable to read frames from ffmpeg process.
2023-04-16 07:58:57.683063682  [2023-04-16 07:58:57] frigate.video                  ERROR   : tapas_balcony: ffmpeg process is not running. exiting capture thread...
2023-04-16 07:58:59.116699935  192.168.25.9 - - [16/Apr/2023:07:58:59 +0000] "GET /api/stats HTTP/1.1" 200 2288 "-" "HomeAssistant/2023.4.4 aiohttp/3.8.4 Python/3.10" "-"
2023-04-16 07:59:07.653010078  [2023-04-16 07:59:07] watchdog.tapas_balcony         ERROR   : Ffmpeg process crashed unexpectedly for tapas_balcony.
2023-04-16 07:59:07.656549542  [2023-04-16 07:59:07] watchdog.tapas_balcony         ERROR   : The following ffmpeg logs include the last 100 lines prior to exit.
2023-04-16 07:59:07.656556231  [2023-04-16 07:59:07] ffmpeg.tapas_balcony.detect    ERROR   : [rtsp @ 0x55c87c6d6100] method DESCRIBE failed: 404 Not Found
2023-04-16 07:59:07.656558614  [2023-04-16 07:59:07] ffmpeg.tapas_balcony.detect    ERROR   : rtsp://127.0.0.1:8554/tapas_balcony: Server returned 404 Not Found
2023-04-16 07:59:07.689685112  07:59:07.689 ERR github.com/AlexxIT/go2rtc/cmd/streams/producer.go:53 > error="dial tcp 192.168.1.10:8889: connect: connection refused" url=rtsp://192.168.1.10:8889/tapas_balcony
2023-04-16 07:59:07.690266545  07:59:07.690 ERR github.com/AlexxIT/go2rtc/cmd/streams/producer.go:53 > error="dial tcp 192.168.1.10:8889: connect: connection refused" url=rtsp://192.168.1.10:8889/tapas_balcony
2023-04-16 07:59:07.690402924  07:59:07.690 WRN [rtsp] error="source 0 error: dial tcp 192.168.1.10:8889: connect: connection refused" stream=tapas_balcony
2023-04-16 07:59:07.695709549  [2023-04-16 07:59:07] frigate.video                  ERROR   : tapas_balcony: Unable to read frames from ffmpeg process.
2023-04-16 07:59:07.696222426  [2023-04-16 07:59:07] frigate.video                  ERROR   : tapas_balcony: ffmpeg process is not running. exiting capture thread...
image

I've enabled RUST_LOG = debug and am awaiting to see if it reproduces.

QuantumEntangledAndy commented 1 year ago

Interesting. Are you familiar with how to compile with rust and profiling? Running a flamegraph might help get to the bottom of this.

I'm currently tracking an issue with some of the threads locking and not being able to send further stream data. Maybe there's a relation

anthonws commented 1 year ago

If you can give me some pointers, I will manage to do it.

QuantumEntangledAndy commented 1 year ago

Ok since you seem good with docker we will try it in there. Hopefully profiling works in a container.

Start with this base image

docker.io/rust:slim-buster

It contains the rust tool chain

Install the following packages

apt-get update && \
        apt-get install -y --no-install-recommends \
          build-essential \
          libgstrtspserver-1.0-dev \
          libgstreamer1.0-dev \
          libgtk2.0-dev \
          libglib2.0-dev \
        gstreamer1.0-tools \
        gstreamer1.0-x \
        gstreamer1.0-plugins-base \
        gstreamer1.0-plugins-good \
        gstreamer1.0-plugins-bad \
       git

Clone the repo

git clone https://github.com/QuantumEntangledAndy/neolink

Now let's build it to make sure things work

cd neolink
cargo build

If that works let's install the flamegraph. (This step might need work to install other things I'm not sure)

cargo install flamegraph

Now we run neolink in the flamegraph program

cargo flamegraph --bin neolink -- rtsp --config=yourconfig.toml

It should now build and profile to create a flamegraph called flamegraph.svg in the cwd.

That graph should let us know what's going on. But I've never run a flame graph for more than 30 mins so not sure how it will behave long term

anthonws commented 1 year ago

Will come back as soon as possible (might be more towards mid of the week).

Thanks!

jsapede commented 1 year ago

Woulnt be of great help in coding but observed same thing with same config all on proxmox Large CPU usage for neolink émerges when frigate act as détection and overload the cpu (i use cpu détection with hwaccel passtrhough). Easily observable on proxmox frontend Since last nigh i put all détections off, and no problem appeared for the last 8 hours

QuantumEntangledAndy commented 1 year ago

I'm not sure what you mean by détections is this something to do with Frigate?

jsapede commented 1 year ago

frigate uses image processing for motion / person detection, with or without hardware acceleration.

on my system i have a proxmox with 2 LXC containers :

when motion detection is enabled on frigate, it consumes al ot CPU and i suppose that image processing is slowed, and frames are skipped. Strangely (?) at the same time, even if neolink is inside a separated container it suddenly overload CPU usage, leading to errors / disconnexion, same type of errors reported here.

if frigate detection is turned off, CPU charge keeps low and there's no problem with neolink. However using neolink without the ability to post process the rtsp is quite useless.

it looks like that neolink overloads when frigate is not able anymore to process the rtsp flow issuing from neolink

such reaction is not observed on all other containers i have. They are slowed because of frigate CPU charge on the whole proxmox but they do not overaload themselves.

QuantumEntangledAndy commented 1 year ago

Ah so your client is not pulling the frames and the buffer overflows. I am actually working on fixing the buffers at the moment by listening to the need/enough data signals from gatreamer. Maybe that will help.

QuantumEntangledAndy commented 1 year ago

Could you test with this build https://github.com/QuantumEntangledAndy/neolink/actions/runs/4721352049 it has various imporvments to try to address buffers and cpu usage

moskovskiy82 commented 1 year ago

Could you test with this build https://github.com/QuantumEntangledAndy/neolink/actions/runs/4721352049 it has various imporvments to try to address buffers and cpu usage

Would love to test it as well as with @jsapede running frigate and see a CPU usage of over 167% on xeon v2 8core As i am quite new to docker can you emphasize how to switch to new build in docker compose?

moskovskiy82 commented 1 year ago

@jsapede mind sharing your frigate config? Can't get main stream to work on my B800

QuantumEntangledAndy commented 1 year ago

I believe that specific build was already merged into master. Are you seeing issues with current master?

jsapede commented 1 year ago

IMG_20230424_054006

As you Can sée i observed a cpu overload in saturday. Unfortunately i didnt kept the logs and restarted the lxc but part of the problem i had was on frigate side because of permanent transcodig / restreaming. Actually, i turned off this feature and it works a lot better.

However there was a CPU overloard on this saturday, dunno the origin. Strangely neolink even at 100% CPU, provided stream to the frigate without any problem.

QuantumEntangledAndy commented 1 year ago

I've got some more buffer fixes coming soon. Just needs a final set of tests. Maybe it will help more.

QuantumEntangledAndy commented 1 year ago

Those fixes I mentioned are in perhaps you could try the latest build and see if it helps with frigate

Lacoste313 commented 1 year ago

i have the same issue with 0.5.8.

i just try to update to v0.5.9 or v0.5.10 but my stream not working on this version.

neolink    | [2023-05-17T10:43:09Z INFO  neolink] Neolink b9fd2f75fffaa0f3890d1008061ad908b0500b1b release
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp] Starting RTSP Server at XXX
neolink    | [2023-05-17T10:43:14Z INFO  neolink_core::bc_protocol] Cuisine: Trying TCP discovery
neolink    | [2023-05-17T10:43:14Z INFO  neolink_core::bc_protocol] Entree: Trying TCP discovery
neolink    | [2023-05-17T10:43:14Z INFO  neolink_core::bc_protocol] Jardin: Trying TCP discovery
neolink    | [2023-05-17T10:43:14Z INFO  neolink_core::bc_protocol] Salon: Trying TCP discovery
neolink    | [2023-05-17T10:43:14Z INFO  neolink_core::bc_protocol] Buanderie: Trying TCP discovery
neolink    | [2023-05-17T10:43:14Z INFO  neolink_core::bc_protocol] Salon: TCP Discovery success at XXX
neolink    | [2023-05-17T10:43:14Z INFO  neolink_core::bc_protocol] Entree: TCP Discovery success at XXX
neolink    | [2023-05-17T10:43:14Z INFO  neolink_core::bc_protocol] Cuisine: TCP Discovery success at XXX
neolink    | [2023-05-17T10:43:14Z INFO  neolink_core::bc_protocol] Jardin: TCP Discovery success at XXX
neolink    | [2023-05-17T10:43:14Z INFO  neolink_core::bc_protocol] Buanderie: TCP Discovery success at XXX
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::loggedin] Cuisine: Camera time is already set: 2023-05-17 12:43:12.0 -01:00:00
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::loggedin] Cuisine: Camera reports firmware version v3.0.0.183_21012800
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::streaming] Cuisine: Starting video stream Sub Stream (Fluent)
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::streaming] Cuisine: Starting video stream Main Stream (Clear)
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::loggedin] Entree: Camera time is already set: 2023-05-17 12:43:13.0 -01:00:00
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::loggedin] Entree: Camera reports firmware version v3.0.0.183_21012800
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::streaming] Entree: Starting video stream Main Stream (Clear)
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::streaming] Entree: Starting video stream Sub Stream (Fluent)
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::loggedin] Salon: Camera time is already set: 2023-05-17 12:43:13.0 -01:00:00
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::loggedin] Buanderie: Camera time is already set: 2023-05-17 12:43:14.0 -01:00:00
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::loggedin] Salon: Camera reports firmware version v3.0.0.183_21012800
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::streaming] Salon: Starting video stream Sub Stream (Fluent)
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::streaming] Salon: Starting video stream Main Stream (Clear)
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::loggedin] Jardin: Camera time is already set: 2023-05-17 12:43:14.0 -01:00:00
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::loggedin] Buanderie: Camera reports firmware version v3.0.0.183_21012800
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::streaming] Buanderie: Starting video stream Sub Stream (Fluent)
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::streaming] Buanderie: Starting video stream Main Stream (Clear)
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::loggedin] Jardin: Camera reports firmware version v3.0.0.142_20121803
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::streaming] Jardin: Starting video stream Main Stream (Clear)
neolink    | [2023-05-17T10:43:14Z INFO  neolink::rtsp::states::streaming] Jardin: Starting video stream Sub Stream (Fluent)
neolink    | [2023-05-17T10:43:23Z INFO  neolink::rtsp::gst::server] Removing Session Media
neolink    | [2023-05-17T10:43:23Z INFO  neolink::rtsp::gst::server] Removing Session Media
neolink    | [2023-05-17T10:43:23Z INFO  neolink::rtsp::gst::server] Removing Session Media
neolink    | [2023-05-17T10:43:23Z INFO  neolink::rtsp] Entree: Buffers prepared
neolink    | [2023-05-17T10:43:23Z INFO  neolink::rtsp] Salon: Buffers prepared
neolink    | [2023-05-17T10:43:23Z INFO  neolink::rtsp::gst::server] Removing Session Media
neolink    | [2023-05-17T10:43:24Z INFO  neolink::rtsp] Cuisine: Buffers prepared
neolink    | [2023-05-17T10:43:24Z INFO  neolink::rtsp::gst::server] Removing Session Media
neolink    | [2023-05-17T10:43:24Z INFO  neolink::rtsp] Buanderie: Buffers prepared
neolink    | [2023-05-17T10:43:24Z INFO  neolink::rtsp::gst::server] Removing Session Media
neolink    | [2023-05-17T10:43:24Z INFO  neolink::rtsp] Jardin: Buffers prepared
neolink    |
neolink    | (neolink:7): GStreamer-WARNING **: 12:43:52.779: free_priv_data: object finalizing but still has 1 parents (object:0x7fb15c7f1ea0)
neolink    |
neolink    | (neolink:7): GStreamer-CRITICAL **: 12:43:52.779: gst_mini_object_unref: assertion 'mini_object != NULL' failed
neolink    |
neolink    | (neolink:7): GStreamer-WARNING **: 12:43:52.817: free_priv_data: object finalizing but still has 1 parents (object:0x7fb12001dc60)
neolink    |
neolink    | (neolink:7): GStreamer-CRITICAL **: 12:43:52.818: gst_mini_object_unref: assertion 'mini_object != NULL' failed
neolink    |
neolink    | (neolink:7): GStreamer-WARNING **: 12:44:32.897: free_priv_data: object finalizing but still has 1 parents (object:0x7fb174678d80)
neolink    |
neolink    | (neolink:7): GStreamer-WARNING **: 12:44:32.897: free_priv_data: object finalizing but still has 1 parents (object:0x7fb174537a20)
neolink    |
neolink    | (neolink:7): GStreamer-WARNING **: 12:44:55.659: free_priv_data: object finalizing but still has 1 parents (object:0x7fb104046ea0)
neolink    |
neolink    | (neolink:7): GStreamer-WARNING **: 12:44:55.659: free_priv_data: object finalizing but still has 1 parents (object:0x7fb10412f5a0)
neolink    |
neolink    | (neolink:7): GStreamer-WARNING **: 12:44:55.697: free_priv_data: object finalizing but still has 1 parents (object:0x7fb10403f5a0)

main and sub are no available. (frigate or vlc)

i downgrade to 0.5.8 and all work fine again, exept the cpu overload after time (2-3day in my case, i need to reboot)

QuantumEntangledAndy commented 1 year ago

What exactly do you see with the error? Perhaps you could open a seperate issue and we could discuss it in detail.

QuantumEntangledAndy commented 1 year ago

Also triple backticks for logs please

Log log Log log

QuantumEntangledAndy commented 1 year ago

Also, also if you can please try the build from #82 it has some bug fixes in it

anthonws commented 1 year ago

Hey Andy,

My apologies but I haven't been able to have the time to do the tests you suggested. Will try to do them this weekend.

Nevertheless, one of my biggest gripes, still solely using a non-battery camera, was Frigate ffmep memory and CPU run away... I simply had to limit each container available CPU and memory, to prevent overheating of my NUCs CPU and being unable to also even access the server remotely.

Yesterday I enabled the second neolink container I have, that I just use for the battery powered camera, in order to test the new commits/versions.

The picture below shows the impact, even of a limited 0.5 CPU (NUC has a 4 core CPU) and 1GB of RAM per container. Please note that I don't have a way to show which neolink process is actually the responsible for each spike (Zabbix is doing a summary of both processes CPU and memory consumption).

image

On the battery powered camera container, I can see a constant warning about max bitrate.

[2023-05-19T10:34:13Z INFO  neolink] Neolink 2a8c713ee023883554693496d6c5bdad9db258fa release
[2023-05-19T10:34:13Z INFO  neolink::rtsp] Starting RTSP Server at 0.0.0.0:8889
[2023-05-19T10:34:13Z INFO  neolink_core::bc_protocol] tapas_balcony: Trying TCP discovery
[2023-05-19T10:34:13Z INFO  neolink_core::bc_protocol] tapas_balcony: Trying local discovery
[2023-05-19T10:34:13Z INFO  neolink_core::bc_protocol] tapas_balcony: Local discovery success CAMERA_ID at 192.168.1.106:41636
[2023-05-19T10:34:14Z INFO  neolink::rtsp::states::loggedin] tapas_balcony: Camera time is already set: 2023-05-19 12:34:17.0 -01:00:00
[2023-05-19T10:34:14Z INFO  neolink::rtsp::states::loggedin] tapas_balcony: Camera reports firmware version 0323_712_572_477
[2023-05-19T10:34:14Z INFO  neolink::rtsp::states::streaming] tapas_balcony: Starting video stream Sub Stream (Fluent)
[2023-05-19T10:34:27Z INFO  neolink::rtsp] tapas_balcony: Buffers prepared
[2023-05-19T10:34:27Z INFO  neolink::rtsp] Client Pause
[2023-05-19T10:34:39Z WARN  neolink::rtsp::gst::sender] Buffer exhausted. Not enough data from Camera. Pausing RTSP until refilled.
[2023-05-19T10:34:39Z INFO  neolink::rtsp::gst::sender] Try reducing your Max Bitrate using the offical app
[2023-05-19T10:34:59Z WARN  neolink::rtsp::gst::sender] Buffer exhausted. Not enough data from Camera. Pausing RTSP until refilled.
[2023-05-19T10:34:59Z INFO  neolink::rtsp::gst::sender] Try reducing your Max Bitrate using the offical app
[2023-05-19T10:35:19Z WARN  neolink::rtsp::gst::sender] Buffer exhausted. Not enough data from Camera. Pausing RTSP until refilled.

Frigate logs show a slew of errors on trying to read the RTSP buffer from the camera:

2023-05-19 10:32:37.090556578  [2023-05-19 10:32:37] ffmpeg.tapas_balcony.detect    ERROR   : [mp4 @ 0x557ccf5ca580] Packet duration: 3934724669 / dts: 3934970095 is out of range
2023-05-19 10:32:37.090558794  [2023-05-19 10:32:37] ffmpeg.tapas_balcony.detect    ERROR   : [mp4 @ 0x557ccf5ca580] pts has no value
2023-05-19 10:32:37.090561210  [2023-05-19 10:32:37] ffmpeg.tapas_balcony.detect    ERROR   : [out_1_0 @ 0x557ccf5762c0] 100 buffers queued in out_1_0, something may be wrong.
2023-05-19 10:32:37.090563390  [2023-05-19 10:32:37] ffmpeg.tapas_balcony.detect    ERROR   : [out_1_0 @ 0x557ccf5762c0] 1000 buffers queued in out_1_0, something may be wrong.
2023-05-19 10:33:07.298235007  [2023-05-19 10:33:07] watchdog.tapas_balcony         INFO    : tapas_balcony exceeded fps limit. Exiting ffmpeg...
2023-05-19 10:33:07.298246900  [2023-05-19 10:33:07] watchdog.tapas_balcony         INFO    : Waiting for ffmpeg to exit gracefully...
2023-05-19 10:33:16.043121948  [2023-05-19 10:33:15] frigate.video                  ERROR   : tapas_balcony: Unable to read frames from ffmpeg process.
2023-05-19 10:33:16.043643380  [2023-05-19 10:33:16] frigate.video                  ERROR   : tapas_balcony: ffmpeg process is not running. exiting capture thread...
2023-05-19 10:33:19.256123558  [2023-05-19 10:33:19] frigate.record                 WARNING : Failed to probe corrupt segment /tmp/cache/tapas_balcony-20230519103256.mp4: 0 - b'[mov,mp4,m4a,3gp,3g2,mj2 @ 0x55e89d6d96c0] moov atom not found\n/tmp/cache/tapas_balcony-20230519103256.mp4: Invalid data found when processing input\n'
2023-05-19 10:33:19.256457545  [2023-05-19 10:33:19] frigate.record                 WARNING : Discarding a corrupt recording segment: /tmp/cache/tapas_balcony-20230519103256.mp4
2023-05-19 10:33:26.003132080  [2023-05-19 10:33:25] watchdog.tapas_balcony         ERROR   : Ffmpeg process crashed unexpectedly for tapas_balcony.
2023-05-19 10:33:26.003139874  [2023-05-19 10:33:25] watchdog.tapas_balcony         ERROR   : The following ffmpeg logs include the last 100 lines prior to exit.
2023-05-19 10:33:26.003142145  [2023-05-19 10:33:25] ffmpeg.tapas_balcony.detect    ERROR   : [rtsp @ 0x55d64b694100] RTP: PT=60: bad cseq 59f6 expected=3430
2023-05-19 10:33:26.004738222  [2023-05-19 10:33:25] ffmpeg.tapas_balcony.detect    ERROR   : [segment @ 0x55d64b7a6ec0] Timestamps are unset in a packet for stream 0. This is deprecated and will stop working in the future. Fix your code to set the timestamps properly
2023-05-19 10:33:26.004948500  [2023-05-19 10:33:25] ffmpeg.tapas_balcony.detect    ERROR   : [mp4 @ 0x55d64b6d6940] Packet duration: 2580864440 / dts: 2581092081 is out of range
2023-05-19 10:33:26.005295829  [2023-05-19 10:33:25] ffmpeg.tapas_balcony.detect    ERROR   : [mp4 @ 0x55d64b6d6940] pts has no value
2023-05-19 10:33:26.005504251  [2023-05-19 10:33:25] ffmpeg.tapas_balcony.detect    ERROR   : [segment @ 0x55d64b7a6ec0] Non-monotonous DTS in output stream 0:0; previous: 2581092081, current: 2581092081; changing to 2581092082. This may result in incorrect timestamps in the output file.
2023-05-19 10:33:26.014509060  [2023-05-19 10:33:25] ffmpeg.tapas_balcony.detect    ERROR   : [mp4 @ 0x55d64b6d6940] Packet duration: 2580864440 / dts: 2581092082 is out of range
2023-05-19 10:33:26.014516151  [2023-05-19 10:33:25] ffmpeg.tapas_balcony.detect    ERROR   : [mp4 @ 0x55d64b6d6940] pts has no value
2023-05-19 10:33:26.014518511  [2023-05-19 10:33:25] ffmpeg.tapas_balcony.detect    ERROR   : [out_1_0 @ 0x55d64b779240] 100 buffers queued in out_1_0, something may be wrong.
2023-05-19 10:33:26.014520753  [2023-05-19 10:33:25] ffmpeg.tapas_balcony.detect    ERROR   : [out_1_0 @ 0x55d64b779240] 1000 buffers queued in out_1_0, something may be wrong.
2023-05-19 10:33:56.101327153  [2023-05-19 10:33:56] watchdog.tapas_balcony         INFO    : tapas_balcony exceeded fps limit. Exiting ffmpeg...
2023-05-19 10:33:56.101334398  [2023-05-19 10:33:56] watchdog.tapas_balcony         INFO    : Waiting for ffmpeg to exit gracefully...
2023-05-19 10:34:04.516498496  [2023-05-19 10:34:04] frigate.record                 WARNING : Failed to probe corrupt segment /tmp/cache/tapas_balcony-20230519103340.mp4: 0 - b'[mov,mp4,m4a,3gp,3g2,mj2 @ 0x55791b0506c0] moov atom not found\n/tmp/cache/tapas_balcony-20230519103340.mp4: Invalid data found when processing input\n'
2023-05-19 10:34:04.517397488  [2023-05-19 10:34:04] frigate.record                 WARNING : Discarding a corrupt recording segment: /tmp/cache/tapas_balcony-20230519103340.mp4
2023-05-19 10:34:04.620071204  [2023-05-19 10:34:04] frigate.video                  ERROR   : tapas_balcony: Unable to read frames from ffmpeg process.
2023-05-19 10:34:04.620313682  [2023-05-19 10:34:04] frigate.video                  ERROR   : tapas_balcony: ffmpeg process is not running. exiting capture thread...
2023-05-19 10:34:14.534700819  [2023-05-19 10:34:14] watchdog.tapas_balcony         ERROR   : Ffmpeg process crashed unexpectedly for tapas_balcony.
2023-05-19 10:34:14.534989098  [2023-05-19 10:34:14] watchdog.tapas_balcony         ERROR   : The following ffmpeg logs include the last 100 lines prior to exit.
2023-05-19 10:34:14.535637215  [2023-05-19 10:34:14] ffmpeg.tapas_balcony.detect    ERROR   : [segment @ 0x5570bb123140] Timestamps are unset in a packet for stream 0. This is deprecated and will stop working in the future. Fix your code to set the timestamps properly
2023-05-19 10:34:14.536422789  [2023-05-19 10:34:14] ffmpeg.tapas_balcony.detect    ERROR   : [segment @ 0x5570bb123140] Non-monotonous DTS in output stream 0:0; previous: 0, current: 0; changing to 1. This may result in incorrect timestamps in the output file.
2023-05-19 10:34:14.536618816  [2023-05-19 10:34:14] ffmpeg.tapas_balcony.detect    ERROR   : [rtsp @ 0x5570bb107100] RTP: PT=60: bad cseq 6063 expected=2598
2023-05-19 10:34:14.537463358  [2023-05-19 10:34:14] ffmpeg.tapas_balcony.detect    ERROR   : [segment @ 0x5570bb123140] Non-monotonous DTS in output stream 0:0; previous: 245433, current: -830103483316929823; changing to 245434. This may result in incorrect timestamps in the output file.
2023-05-19 10:34:14.537608346  [2023-05-19 10:34:14] ffmpeg.tapas_balcony.detect    ERROR   : [mp4 @ 0x5570bb146a80] Packet duration: 2922002246 / dts: 2922247680 is out of range
2023-05-19 10:34:14.538080953  [2023-05-19 10:34:14] ffmpeg.tapas_balcony.detect    ERROR   : [mp4 @ 0x5570bb146a80] pts has no value
2023-05-19 10:34:14.538184057  [2023-05-19 10:34:14] ffmpeg.tapas_balcony.detect    ERROR   : [mp4 @ 0x5570bb146a80] Packet duration: 2922020384 / dts: 2922265819 is out of range
2023-05-19 10:34:14.538390683  [2023-05-19 10:34:14] ffmpeg.tapas_balcony.detect    ERROR   : [mp4 @ 0x5570bb146a80] pts has no value
2023-05-19 10:34:14.538394016  [2023-05-19 10:34:14] ffmpeg.tapas_balcony.detect    ERROR   : [out_1_0 @ 0x5570bb1c4c40] 100 buffers queued in out_1_0, something may be wrong.
2023-05-19 10:34:14.538525119  [2023-05-19 10:34:14] ffmpeg.tapas_balcony.detect    ERROR   : [out_1_0 @ 0x5570bb1c4c40] 1000 buffers queued in out_1_0, something may be wrong.
2023-05-19 10:34:14.636215175  [2023-05-19 10:34:14] frigate.video                  ERROR   : tapas_balcony: Unable to read frames from ffmpeg process.
2023-05-19 10:34:14.636651747  [2023-05-19 10:34:14] frigate.video                  ERROR   : tapas_balcony: ffmpeg process is not running. exiting capture thread...
2023-05-19 10:34:24.587112781  [2023-05-19 10:34:24] watchdog.tapas_balcony         ERROR   : Ffmpeg process crashed unexpectedly for tapas_balcony.

As for the non-battery powered camera container, there are very few errors/logs:

[2023-05-19T02:56:35Z INFO  neolink] Neolink 2a8c713ee023883554693496d6c5bdad9db258fa release
[2023-05-19T02:56:35Z INFO  neolink::rtsp] Starting RTSP Server at 0.0.0.0:8888
[2023-05-19T02:56:35Z INFO  neolink_core::bc_protocol] tapas_hall: Trying TCP discovery
[2023-05-19T02:56:35Z INFO  neolink_core::bc_protocol] tapas_hall: TCP Discovery success at 192.168.1.216:9000
[2023-05-19T02:56:35Z INFO  neolink::rtsp::states::loggedin] tapas_hall: Camera time is already set: 2023-05-19 4:56:35.0 -01:00:00
[2023-05-19T02:56:35Z INFO  neolink::rtsp::states::loggedin] tapas_hall: Camera reports firmware version v3.0.0.716_21112404
[2023-05-19T02:56:35Z INFO  neolink::rtsp::states::streaming] tapas_hall: Starting video stream Main Stream (Clear)
[2023-05-19T02:56:35Z INFO  neolink::rtsp::states::streaming] tapas_hall: Starting video stream Sub Stream (Fluent)
[2023-05-19T02:56:45Z INFO  neolink::rtsp] tapas_hall: Buffers prepared
(neolink:7): GStreamer-WARNING **: 06:33:36.204: free_priv_data: object finalizing but still has 1 parents (object:0x7fde256167e0)
(neolink:7): GStreamer-WARNING **: 06:33:36.204: free_priv_data: object finalizing but still has 1 parents (object:0x7fde256d1a20)
(neolink:7): GStreamer-WARNING **: 07:43:20.184: free_priv_data: object finalizing but still has 1 parents (object:0x7fde30f68900)
(neolink:7): GStreamer-CRITICAL **: 07:43:20.187: gst_mini_object_unref: assertion 'mini_object != NULL' failed
(neolink:7): GStreamer-CRITICAL **: 08:35:03.299: gst_mini_object_unref: assertion 'mini_object != NULL' failed
(neolink:7): GStreamer-WARNING **: 08:51:28.164: free_priv_data: object finalizing but still has 1 parents (object:0x7fde44083900)
(neolink:7): GStreamer-WARNING **: 08:51:28.164: free_priv_data: object finalizing but still has 1 parents (object:0x7fde4408cea0)
(neolink:7): GStreamer-WARNING **: 08:55:55.724: free_priv_data: object finalizing but still has 1 parents (object:0x7fde38094d80)
(neolink:7): GStreamer-WARNING **: 08:55:55.724: free_priv_data: object finalizing but still has 1 parents (object:0x7fde3807fea0)
(neolink:7): GStreamer-CRITICAL **: 09:09:17.566: gst_mini_object_unref: assertion 'mini_object != NULL' failed
(neolink:7): GStreamer-CRITICAL **: 09:13:37.886: gst_mini_object_unref: assertion 'mini_object != NULL' failed
(neolink:7): GStreamer-CRITICAL **: 09:39:15.565: gst_mini_object_unref: assertion 'mini_object != NULL' failed
(neolink:7): GStreamer-WARNING **: 10:00:15.808: free_priv_data: object finalizing but still has 1 parents (object:0x7fde1419dea0)
(neolink:7): GStreamer-WARNING **: 10:18:37.138: free_priv_data: object finalizing but still has 1 parents (object:0x7fde243f9d80)
(neolink:7): GStreamer-CRITICAL **: 10:18:37.139: gst_mini_object_unref: assertion 'mini_object != NULL' failed
(neolink:7): GStreamer-WARNING **: 10:21:57.603: free_priv_data: object finalizing but still has 1 parents (object:0x7fde243f8480)
(neolink:7): GStreamer-CRITICAL **: 10:21:57.604: gst_mini_object_unref: assertion 'mini_object != NULL' failed

I am using the fluent subStream in Frigate Go2RTC server.

I will try to conduct the performance tests you asked previously and will also try to get some logs with debug enabled.

Cheers, anthonws.

QuantumEntangledAndy commented 1 year ago

Does your neolink config use both main and sub stream? I ask because buffer exhaustion usually happens on main stream and rarely on sub stream. But at the moment unless you specify stream = subStream it will always pull from both.

Also does the log about frigate crashing stop after the message "buffers prepared" from neolink.

Before the buffers are prepared the video only lasts for 500 frames then stops which causes those error messages in my frigate too but can be safely ignored once the buffer is ready.

anthonws commented 1 year ago
  1. No. Only subStream.

Config:

bind = "0.0.0.0"
bind_port = 8889

[[cameras]]
name = "tapas_balcony"
username = "admin"
password = "PASS"
uid = "CAMERA_ID"
stream = "subStream"
  [cameras.pause]
  on_motion = true
  on_client = true
  mode = "none"
  timeout = 2.1
  1. I do not know. Will have to test and look at the logs SxS. Will let you know once I have some time to look at it.
QuantumEntangledAndy commented 1 year ago

The PTS warning is interesting. Currently I set the DTS instead but I can set the PTS if ffmpeg prefers it.

QuantumEntangledAndy commented 1 year ago

What's your frigate config? Maybe I can replicate it and see if I can get these ffmpeg message too.

anthonws commented 1 year ago

Here you go!

Thanks!!

mqtt:
  host: 192.168.25.9
  port: 1883
  topic_prefix: frigate_tapas
  client_id: frigate_tapas

detectors:
  ov:
    type: openvino
    device: AUTO
    model:
      path: /openvino-model/ssdlite_mobilenet_v2.xml

model:
  width: 300
  height: 300
  input_tensor: nhwc
  input_pixel_format: bgr
  labelmap_path: /openvino-model/coco_91cl_bkgr.txt

go2rtc:
  streams:
    tapas_balcony: rtsp://192.168.1.10:8889/tapas_balcony
    tapas_hall: rtsp://192.168.1.10:8888/tapas_hall

cameras:
  tapas_hall:
    ffmpeg:
      inputs:
        - path: rtsp://127.0.0.1:8554/tapas_hall
          input_args: preset-rtsp-restream
          roles:
            - record 
            - detect 
    detect:
      width: 1280
      height: 720
  tapas_balcony:
    ffmpeg:
      inputs:
        - path: rtsp://127.0.0.1:8554/tapas_balcony
          input_args: preset-rtsp-restream
          roles:
            - record 
            - detect 
    detect:
      width: 1280
      height: 720 

record:
  enabled: True
  events:
    retain:
      default: 5 

birdseye:
  # Optional: Enable birdseye view (default: shown below)
  enabled: false

ffmpeg:
  hwaccel_args: preset-vaapi
  #hwaccel_args: -hwaccel vaapi -hwaccel_device /dev/dri/renderD128 -hwaccel_output_format yuv420p

environment_vars: 
  LIBVA_DRIVER_NAME: i965
anthonws commented 11 months ago

Fixed :) Never had any CPU perf or memory run away behaviors.

QuantumEntangledAndy commented 11 months ago

Oh good. I'm still getting a small memory increase over time that looking at allocations in the profiler seems to suggest that the gstreamer buffer is growing too big so I see what I can with that in the next release