MQTT "motion" always returns "off"

tr1plus commented 1 year ago

Describe the bug When using neolink in MQTT mode, the "motion" topic neolink/<cam>/status/motion always returns "off", even when the official client shows motion

To Reproduce Steps to reproduce the behavior. Example:

Create this configuration file:

bind = "0.0.0.0"

[[cameras]]
name = "tuin"
username = "admin"
password = "123456"
address = "192.168.1.79"
uid = "xxx"
discover = "local"
mqtt.broker_addr = "192.168.1.25"
mqtt.port = 1883
mqtt.credentials = ["xxx", "xxx"]
mqtt.discovery.topic = "homeassistant"
mqtt.discovery.features = ["ir", "motion", "battery"]

Launch Neolink
Ensure reolink camera sees motion
Check MQTT topic and observe new messages are coming in with payload "off"

I have a lot of "off" payload, no "on" payload

I have done a capture while generating motion in front of my camera. I tried checking if I could find anything in the packets, but I'm not even sure how to start decoding these packages + my knowledge of the RUST language is non-existant. mqtt-motion.zip

Expected behavior When motion is occuring I expect the payload to be "on", when motion stops it should return to "off".

Versions NVR software: N/A Neolink software: the new firmware branch with login issue resolution Reolink camera model and firmware: argus eco; Camera reports firmware version v3.0.0.1981_23040606

tr1plus commented 1 year ago

[2023-08-20T15:26:50Z INFO  neolink::rtsp] tuin: Motion Pause
[2023-08-20T15:56:16Z INFO  neolink::rtsp] tuin: Motion Resume
[2023-08-20T15:56:16Z WARN  neolink::rtsp] tuin: Retryable error: tuin: Error updating pause state

    Caused by:
        0: Error while processing motion messages
        1: IO Error: Custom { kind: Other, error: DroppedConnection }
        2: Dropped connection

[2023-08-20T15:56:50Z INFO  neolink::rtsp] tuin: Motion Pause
[2023-08-20T16:26:22Z INFO  neolink::rtsp] tuin: Motion Resume
[2023-08-20T16:26:22Z WARN  neolink::rtsp] tuin: Retryable error: tuin: Error updating pause state

    Caused by:
        0: Error while processing motion messages
        1: IO Error: Custom { kind: Other, error: DroppedConnection }
        2: Dropped connection

[2023-08-20T16:26:25Z INFO  neolink::rtsp] tuin: Buffers prepared
[2023-08-20T16:26:56Z INFO  neolink::rtsp] tuin: Motion Pause
[2023-08-20T16:47:15Z INFO  neolink::rtsp] tuin: Motion Resume
[2023-08-20T16:47:15Z INFO  neolink::rtsp::states::streaming] tuin: Starting video stream Main Stream (Clear)
[2023-08-20T16:47:15Z INFO  neolink::rtsp::states::streaming] tuin: Starting video stream Sub Stream (Fluent)
[2023-08-20T16:47:40Z INFO  neolink::rtsp] tuin: Join Pause
[2023-08-20T16:47:40Z WARN  neolink::rtsp] tuin: Retryable error: Camera join error: Io(Custom { kind: Other, error: DroppedConnection })
[2023-08-20T16:47:40Z INFO  neolink_core::bc_protocol] tuin: Trying TCP discovery
[2023-08-20T16:47:40Z INFO  neolink_core::bc_protocol] tuin: Trying local discovery
[2023-08-20T16:47:40Z INFO  neolink_core::bc_protocol] tuin: Local discovery success xxx at 192.168.1.79:40760
[2023-08-20T16:47:43Z WARN  neolink::rtsp] tuin: Retryable error: tuin: Could not login to camera

    Caused by:
        0: IO Error: Custom { kind: Other, error: DroppedConnection }
        1: Dropped connection

[2023-08-20T17:15:27Z INFO  neolink::rtsp] tuin: Motion Pause
[2023-08-20T17:15:28Z INFO  neolink::rtsp] tuin: Motion Resume
[2023-08-20T17:15:28Z INFO  neolink::rtsp::states::streaming] tuin: Starting video stream Main Stream (Clear)
[2023-08-20T17:15:28Z INFO  neolink::rtsp::states::streaming] tuin: Starting video stream Sub Stream (Fluent)
[2023-08-20T17:16:19Z INFO  neolink::rtsp] tuin: Motion Pause
[2023-08-20T17:18:00Z INFO  neolink::rtsp] tuin: Motion Resume
[2023-08-20T17:18:00Z WARN  neolink::rtsp] tuin: Retryable error: tuin: Error updating pause state

    Caused by:
        0: Error while processing motion messages
        1: IO Error: Custom { kind: Other, error: DroppedConnection }
        2: Dropped connection

Almost like clockwork 30 minutes after a "pause" event is triggered it goes into error

QuantumEntangledAndy commented 1 year ago

I've got one more change that I have but at this point I'm not sure there's anything I can do. My camera can stream for hours now without issue until something happens to the network or the battery does. Since your own cutout is regular there may be a hard coded cutoff for some battery cameras.

Half hour of wireshark packets might be a bit much but if you could get that for me I will have another look.

QuantumEntangledAndy commented 1 year ago

Is it 30min after video pause by any chance? Maybe it will disconnect if no video is read for that long. If so I could make it pull a frame or two every 20 mins.

QuantumEntangledAndy commented 1 year ago

This is the current build I'm working on, maybe you can see if these last few changes help

QuantumEntangledAndy commented 1 year ago

Actually could you try this build. I am wondering if this is to do with the pause state not sending any packets. I know from the mqtt code that battery cameras will drop us if we dont exchamge bc messages for too long. So I copied over the ping code of mqtt. Lets see if that helps

tr1plus commented 1 year ago

30-min.zip

pw still 123456

C:\Users\Gebruiker\Downloads\neolink_new_new>.\neolink rtsp --config neolink.toml
[2023-08-21T09:03:07Z INFO  neolink] Neolink 48892344b87a6f560ec22fd52e64f99d6131f475 release
[2023-08-21T09:03:15Z INFO  neolink::rtsp] Starting RTSP Server at 0.0.0.0:8554
[2023-08-21T09:03:15Z INFO  neolink_core::bc_protocol] tuin: Trying TCP discovery
[2023-08-21T09:03:18Z INFO  neolink_core::bc_protocol] tuin: Trying local discovery
[2023-08-21T09:03:20Z INFO  neolink_core::bc_protocol] tuin: Local discovery success xxx at 192.168.1.79:40760
[2023-08-21T09:03:22Z INFO  neolink::rtsp::states::loggedin] tuin: Camera time is already set: 2023-08-21 11:03:33.0 -01:00:00
[2023-08-21T09:03:22Z INFO  neolink::rtsp::states::loggedin] tuin: Camera reports firmware version v3.0.0.1981_23040606
[2023-08-21T09:03:22Z INFO  neolink::rtsp::states::streaming] tuin: Starting video stream Main Stream (Clear)
[2023-08-21T09:03:22Z INFO  neolink::rtsp::states::streaming] tuin: Starting video stream Sub Stream (Fluent)
[2023-08-21T09:03:30Z INFO  neolink::rtsp] tuin: Buffers prepared
[2023-08-21T09:04:01Z INFO  neolink::rtsp] tuin: Motion Pause
[2023-08-21T09:33:42Z INFO  neolink::rtsp] tuin: Motion Resume
[2023-08-21T09:33:42Z WARN  neolink::rtsp] tuin: Retryable error: tuin: Error updating pause state

    Caused by:
        0: Error while processing motion messages
        1: IO Error: Custom { kind: Other, error: DroppedConnection }
        2: Dropped connection
[2023-08-21T09:33:42Z INFO  neolink_core::bc_protocol] tuin: Trying TCP discovery
[2023-08-21T09:33:45Z INFO  neolink_core::bc_protocol] tuin: Trying local discovery
[2023-08-21T09:33:47Z INFO  neolink_core::bc_protocol] tuin: Local discovery success xxx at 192.168.1.79:40760
[2023-08-21T09:33:48Z INFO  neolink::rtsp::states::loggedin] tuin: Camera time is already set: 2023-08-21 11:33:49.0 -01:00:00
[2023-08-21T09:33:49Z INFO  neolink::rtsp::states::loggedin] tuin: Camera reports firmware version v3.0.0.1981_23040606
[2023-08-21T09:33:49Z INFO  neolink::rtsp::states::streaming] tuin: Starting video stream Main Stream (Clear)
[2023-08-21T09:33:49Z INFO  neolink::rtsp::states::streaming] tuin: Starting video stream Sub Stream (Fluent)
[2023-08-21T09:33:49Z INFO  neolink::rtsp] tuin: Buffers prepared
[2023-08-21T09:34:20Z INFO  neolink::rtsp] tuin: Motion Pause

still every 30 min after a motion pause, both on windows & docker(linux).

QuantumEntangledAndy commented 1 year ago

Looks like the pings aren't sending during the pause state. I will try to find out why

tr1plus commented 1 year ago

Also just a thought - why isn't the camera having connection issues with the client pause (on_client)

it also pauses everything during that, and it can keep "living" like this for a very long time (at least >30min)

QuantumEntangledAndy commented 1 year ago

It may be because when client pause is on and not motion pause then we are not waiting for any bc messages. It will likely not seem like any error until we ask it to start again. To test you can try this. Client pause -> 40 mins -> Try and resume

QuantumEntangledAndy commented 1 year ago

Next test build

tr1plus commented 1 year ago

The error message is a bit different :p

[2023-08-21T12:36:30Z INFO  neolink::rtsp] tuin: Motion Pause
[2023-08-21T13:06:02Z INFO  neolink::rtsp] tuin: Motion Resume
[2023-08-21T13:06:02Z WARN  neolink::rtsp] tuin: Retryable error: tuin: Error updating pause state

    Caused by:
        0: Error while processing motion messages
        1: Send Error
[2023-08-21T13:06:02Z INFO  neolink_core::bc_protocol] tuin: Trying TCP discovery
[2023-08-21T13:06:02Z INFO  neolink_core::bc_protocol] tuin: Trying local discovery

QuantumEntangledAndy commented 1 year ago

Yes but ultimately the same issue. The connection was dropped when we were not listening and when we went to send the start message it fails

tr1plus commented 1 year ago

and when we went to send the start message it fails

But at this point it auto fails. It doesn't start again because of motion. So I don't think we want to send the start message here since there is no point (no motion and no request from neolink side to start it)

I could be miss understanding, just letting you know the situation :)

QuantumEntangledAndy commented 1 year ago

Oh sorry I thought you were doing the client test. Misread that.

QuantumEntangledAndy commented 1 year ago

Can I have some more context for that error message then

QuantumEntangledAndy commented 1 year ago

Was it after 30 mins what's the full log etc

QuantumEntangledAndy commented 1 year ago

Could you also get a wireshark of this. It's getting late in my time zone so it would be helpful to have that so I have something to analyse in the morning

tr1plus commented 1 year ago

Can I have some more context for that error message then

Same as before using on_motion:

Start neolink
observe neolink does motion pause tuin: Motion Pause
Wait ~30minutes

Error appears & re-starts neolink

[2023-08-21T13:06:02Z WARN  neolink::rtsp] tuin: Retryable error: tuin: Error updating pause state

Caused by:
    0: Error while processing motion messages
    1: Send Error
[2023-08-21T13:06:02Z INFO  neolink_core::bc_protocol] tuin: Trying TCP discovery
[2023-08-21T13:06:02Z INFO  neolink_core::bc_protocol] tuin: Trying local discovery

I'll try to get another wireshark for your this evening. Testing steps are/will be exactly the same as the previous wireshark I shared.

tr1plus commented 1 year ago

P.S. what I find weird is that it tries to tuin: Motion Resume - I'm 99% sure no motion event would have been triggered at this stage, and its always 'exactly' (give or take a few seconds) 30 minutes after the pause. (seems to be 18 or 19 seconds less than 30 minutes, so 29 minutes and ~41 seconds)

tr1plus commented 1 year ago

It may be because when client pause is on and not motion pause then we are not waiting for any bc messages. It will likely not seem like any error until we ask it to start again. To test you can try this. Client pause -> 40 mins -> Try and resume

confirmed - it fails but is less battery intensive because it doesn't actually "stream" every 30 minutes and is only triggered when a client actually connects :)

[2023-08-21T13:09:14Z INFO  neolink::rtsp] tuin: Client Pause:: Main
[2023-08-21T13:09:14Z INFO  neolink::rtsp] tuin: Client Pause:: Sub
[2023-08-21T14:59:23Z INFO  neolink::rtsp] tuin: Client Resume:: Main
[2023-08-21T14:59:23Z INFO  neolink::rtsp::states::streaming] tuin: Starting video stream Main Stream (Clear)
[2023-08-21T14:59:23Z INFO  neolink::rtsp] tuin: Join Pause
[2023-08-21T14:59:23Z WARN  neolink::rtsp] tuin: Retryable error: Camera join error: Io(Custom { kind: Other, error: DroppedConnection })
[2023-08-21T14:59:23Z INFO  neolink_core::bc_protocol] tuin: Trying TCP discovery
[2023-08-21T14:59:24Z INFO  neolink_core::bc_protocol] tuin: Trying local discovery

tr1plus commented 1 year ago

New wireshark with latest build & motion pause:

  [cameras.pause]
  on_motion = true
  mode = "none"
  timeout = 30.0

console output (again no actual motion triggered in front of camera)

C:\Users\Gebruiker\Downloads\neolink_new_new>.\neolink rtsp --config neolink.toml
[2023-08-21T17:32:35Z INFO  neolink] Neolink 0768bcf959515cc297d2c21a1a963e8c9ec7a031 release
[2023-08-21T17:32:35Z INFO  neolink::rtsp] Starting RTSP Server at 0.0.0.0:8554
[2023-08-21T17:32:35Z INFO  neolink_core::bc_protocol] tuin: Trying TCP discovery
[2023-08-21T17:32:38Z INFO  neolink_core::bc_protocol] tuin: Trying local discovery
[2023-08-21T17:32:40Z INFO  neolink_core::bc_protocol] tuin: Local discovery success xxx at 192.168.1.79:24742
[2023-08-21T17:32:42Z INFO  neolink::rtsp::states::loggedin] tuin: Camera time is already set: 2023-08-21 19:32:42.0 -01:00:00
[2023-08-21T17:32:42Z INFO  neolink::rtsp::states::loggedin] tuin: Camera reports firmware version v3.0.0.1981_23040606
[2023-08-21T17:32:42Z INFO  neolink::rtsp::states::streaming] tuin: Starting video stream Main Stream (Clear)
[2023-08-21T17:32:42Z INFO  neolink::rtsp::states::streaming] tuin: Starting video stream Sub Stream (Fluent)
[2023-08-21T17:32:50Z INFO  neolink::rtsp] tuin: Buffers prepared
[2023-08-21T17:33:21Z INFO  neolink::rtsp] tuin: Motion Pause
[2023-08-21T18:02:51Z INFO  neolink::rtsp] tuin: Motion Resume
[2023-08-21T18:02:51Z WARN  neolink::rtsp] tuin: Retryable error: tuin: Error updating pause state

    Caused by:
        0: Error while processing motion messages
        1: IO Error: Custom { kind: Other, error: DroppedConnection }
        2: Dropped connection
[2023-08-21T18:02:51Z INFO  neolink_core::bc_protocol] tuin: Trying TCP discovery
[2023-08-21T18:02:54Z INFO  neolink_core::bc_protocol] tuin: Trying local discovery
[2023-08-21T18:02:55Z INFO  neolink_core::bc_protocol] tuin: Local discovery success xxx at 192.168.1.79:24742
[2023-08-21T18:02:57Z INFO  neolink::rtsp::states::loggedin] tuin: Camera time is already set: 2023-08-21 20:02:58.0 -01:00:00
[2023-08-21T18:02:57Z INFO  neolink::rtsp::states::loggedin] tuin: Camera reports firmware version v3.0.0.1981_23040606
[2023-08-21T18:02:57Z INFO  neolink::rtsp::states::streaming] tuin: Starting video stream Main Stream (Clear)
[2023-08-21T18:02:57Z INFO  neolink::rtsp::states::streaming] tuin: Starting video stream Sub Stream (Fluent)
[2023-08-21T18:02:57Z INFO  neolink::rtsp] tuin: Buffers prepared
[2023-08-21T18:03:28Z INFO  neolink::rtsp] tuin: Motion Pause

30-min-new.zip

QuantumEntangledAndy commented 1 year ago

It's not actually Motion resume per say, its just this code:

v = async {
                // Wait for motion start
                let mut motion = camera.listen_on_motion().await?;
                motion.await_start(Duration::ZERO).await
            }, if motion_pause && shared.get_config().pause.on_motion => {
                info!("{}: Motion Resume", name);
                v.with_context(|| "Error while processing motion messages")?;
                Ok(StreamChange::MotionStart)
            },

We print Motion Resume before we check for Ok or Err

QuantumEntangledAndy commented 1 year ago

Ok so packets seem 100%. Ack packets are being sent, Ping is being sent, Keep alive is being replied to. It's just at 30mins the camera stops sending messages.

Can you try connecting with the offical client for 30mins and have a wireshark dump?

Maybe also see if you can connect for 30+ mins without pause

tr1plus commented 1 year ago

So I started streaming live view via the official reolink app:

After EVERY ~5 minutes it gives this message(I think it starts counting down from 30 seconds):

I kept clicking "cancel" a few times but then missed 1 prompt (started around 9:36 am and ended at 9:57). So this is about 20 min of captured data: Since the file size is too big(so I assume the official client sends many more packages as neolink), I uploaded it on one of my domains: https://triplusnet.be/client%20-%2020min.zip

When the reolink client is not streaming, no packages are being sent: (so Either we are connected (and streaming) or not connected at all. There is no way to simulate a non-streaming connection via the official app I think)

I will try to get a full 30 minutes capture, but I need to be on top of the messages to click "cancel" :p

QuantumEntangledAndy commented 1 year ago

Oh that's painful. Maybe an auto clicker could help. If it's too much effort I understand.

QuantumEntangledAndy commented 1 year ago

How's the test without pause? Does that stay connected?

tr1plus commented 1 year ago

Oh that's painful. Maybe an auto clicker could help. If it's too much effort I understand.

I'll manage, it's 6 clicks in a 30 seconds window, should be fine. Work is slow currently ;)

How's the test without pause? Does that stay connected?

What do you mean with this? I have done an on_client test --> Do you want me to do a test without any pause section in the config?

It may be because when client pause is on and not motion pause then we are not waiting for any bc messages. It will likely not seem like any error until we ask it to start again. To test you can try this. Client pause -> 40 mins -> Try and resume

confirmed - it fails but is less battery intensive because it doesn't actually "stream" every 30 minutes and is only triggered when a client actually connects :)
[2023-08-21T13:09:14Z INFO  neolink::rtsp] tuin: Client Pause:: Main
[2023-08-21T13:09:14Z INFO  neolink::rtsp] tuin: Client Pause:: Sub
[2023-08-21T14:59:23Z INFO  neolink::rtsp] tuin: Client Resume:: Main
[2023-08-21T14:59:23Z INFO  neolink::rtsp::states::streaming] tuin: Starting video stream Main Stream (Clear)
[2023-08-21T14:59:23Z INFO  neolink::rtsp] tuin: Join Pause
[2023-08-21T14:59:23Z WARN  neolink::rtsp] tuin: Retryable error: Camera join error: Io(Custom { kind: Other, error: DroppedConnection })
[2023-08-21T14:59:23Z INFO  neolink_core::bc_protocol] tuin: Trying TCP discovery
[2023-08-21T14:59:24Z INFO  neolink_core::bc_protocol] tuin: Trying local discovery

QuantumEntangledAndy commented 1 year ago

I mean on_client and on_motion set to false so that the stream is active. What I want to see is if the camera keeps the connection if there is a stream running

tr1plus commented 1 year ago

started at ~10:09 kept clicking 'cancel' to prevent stream from dying.

And lo and behold - the official client also stopped and re-started after 30 minutes!

So it's standard behaviour I guess? No prompt to stop this from happening!

Here is the wireshark, but I think it is as expected: https://triplusnet.be/official_client_30_MIN.zip

personal opinion - and I know it might be a lot of work: I think the main "issue" in that case is that a more graceful disconnect/reconnect should be built in. Both on_client and on_motion have "issues for me"

on_client: I connect a client to neolink once motion is triggered, but because neolink has "died" in the meantime, it takes ~20-30 seconds to re-start the stream so I lose those 30 seconds in my recording
on_motion: because the stream starts up again every 30 minutes it records/streams every 30 minutes for a few seconds which drains the battery fast (during the night)

proposed:

on_client: can you build in some kind of auto restart every ~10minutes, unless a client is connected in the moment?
on_motion: when neolink has to restart with "on_motion", immediately pause the stream (never send a frame) so motion detection doesn't happen.

Again --> Just a proposal, not sure how feasible these are :)

tr1plus commented 1 year ago

I mean on_client and on_motion set to false so that the stream is active. What I want to see is if the camera keeps the connection if there is a stream running

is this still required based on the fact the official client also disconnects? Guess it's a battery powered camera thing

QuantumEntangledAndy commented 1 year ago

no not required, since it seems to be a camera issue.

on_motion I think I just need to carry thorough the previous motion state rather than a full restart of the state across reset boundaries

on_client I think it would be better to have something report connection errors and force a restart when that occurs. That way camera that don't need a restart wont have this auto reconnect and pause should come back too.

This is a major rework of the restrart loop though....

tr1plus commented 1 year ago

I am aware :) But I think we (and mostly you ;)) at least understand what is happening now, so that's some progress I suppose.

For now my set-up with on_client works (so a mail is sent from the camera on motion to a smtp 2 mqtt service that sets my camera to recording). Only downside is indeed that for 20 seconds I get a static image until neolink has finished restarting.

Can't you start a second connection/thread to the camera in the background at 25 minutes so we have a new running connection, and then do some kind of handover?

Just brainstorming

QuantumEntangledAndy / neolink

MQTT "motion" always returns "off" #129

And lo and behold - the official client also stopped and re-started after 30 minutes!