search

QuantumEntangledAndy / neolink

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

Possible infinite loop in NeoReactor push notification... #272

Open dkerr64 opened 4 months ago

dkerr64 commented 4 months ago

I decided to catch up with many changes you have made and build the current version of Neolink. The first time I ran it, on my dev machine, it worked fine. When I moved the binary to my production machine, it ran but then just hung... never returned to command line. So I ran again with debug on...

[2024-06-15T03:26:01Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:26:01Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:26:01Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:26:01Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:26:01Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:26:01Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:26:01Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:26:01Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:26:01Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:26:01Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:26:01Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting

That goes on forever until I Ctrl-C.

So I decided that I would try and debug this morning, but unfortunately it is working just fine now... no changes to config file or anything. But looking in the code, I'm wondering how it is supposed to exit the loop it is in? I'm not skilled enough in Rust to tell if it is expected to exit the loop or not.

Thanks.

dkerr64 commented 4 months ago

Here is the command line and config...

/root/neolink image --config=/root/neolink.toml --file-path=/root/test.jpg driveway
bind = "0.0.0.0"

[[cameras]]
name = "driveway"
username = "admin"
password = "redacted"
uid = "9527redacted"
address = "192.168.12.177"
discovery = "local"
stream = "mainStream"
print_format = "Xml"
dkerr64 commented 4 months ago

And here is the INFO-level log when it works...

[2024-06-15T14:09:22Z INFO  neolink] Neolink 0.6.3-rc.2 (unknown commit) release
[2024-06-15T14:09:22Z INFO  neolink::utils] driveway: Connecting to camera at Address: 192.168.12.177, UID: 9527redacted
[2024-06-15T14:09:22Z INFO  neolink_core::bc_protocol] driveway: Trying TCP discovery
[2024-06-15T14:09:22Z INFO  neolink_core::bc_protocol] driveway: Trying local discovery
[2024-06-15T14:09:25Z INFO  neolink_core::bc_protocol] driveway: Local discovery success 9527redacted at 192.168.12.177:55645
[2024-06-15T14:09:25Z INFO  neolink::utils] driveway: Logging in
[2024-06-15T14:09:26Z INFO  neolink::utils] driveway: Connected and logged in
[2024-06-15T14:09:28Z INFO  neolink::common::camthread] driveway: Camera time is already set: 2024-06-15 10:09:32.0 +05:00:00
[2024-06-15T14:09:30Z INFO  neolink::common::neocam] driveway: Model Reolink Argus 3 Pro
[2024-06-15T14:09:30Z INFO  neolink::common::neocam] driveway: Firmware Version v3.0.0.973_22051000
dkerr64 commented 4 months ago

And when it failed...

root@utils:~# RUST_LOG=debug /root/neolink3 image --config=/root/neolink.toml --file-path=/root/test.jpg driveway
[2024-06-15T03:25:11Z INFO  neolink] Neolink 0.6.3-rc.2 (unknown commit) release
[2024-06-15T03:25:11Z INFO  neolink::utils] driveway: Connecting to camera at Address: 192.168.12.177, UID: 9527redacted
[2024-06-15T03:25:11Z DEBUG neolink::image] Using the snap command
[2024-06-15T03:25:11Z INFO  neolink_core::bc_protocol] driveway: Trying TCP discovery
[2024-06-15T03:25:13Z INFO  neolink_core::bc_protocol] driveway: Trying local discovery
[2024-06-15T03:25:13Z DEBUG neolink_core::bc_protocol::connection::discovery] Broadcasting to: [(255.255.255.255, 2015), (255.255.255.255, 2018), (192.168.17.255, 2015), (192.168.17.255, 2018), (192.168.12.255, 2015), (192.168.12.255, 2018)]
[2024-06-15T03:25:13Z DEBUG neolink_core::bc_protocol::connection::discovery] Also sending to [192.168.12.177:2018, 192.168.12.177:2015]
[2024-06-15T03:25:13Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 255.255.255.255:2015 with tid: 96
[2024-06-15T03:25:13Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 255.255.255.255:2018 with tid: 91
[2024-06-15T03:25:13Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 192.168.17.255:2015 with tid: 218
[2024-06-15T03:25:13Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 192.168.17.255:2018 with tid: 29
[2024-06-15T03:25:13Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 192.168.12.255:2015 with tid: 34
[2024-06-15T03:25:13Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 192.168.12.255:2018 with tid: 175
[2024-06-15T03:25:13Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 192.168.12.177:2018 with tid: 155
[2024-06-15T03:25:13Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 192.168.12.177:2015 with tid: 48
[2024-06-15T03:25:14Z DEBUG neolink::common::pushnoti] Push notification details are saved to Some("/root/.config/neolink/./neolink_token.toml")
[2024-06-15T03:25:14Z DEBUG neolink::common::pushnoti] Loaded push notification token
[2024-06-15T03:25:14Z DEBUG neolink::common::pushnoti] registration.fcm_token: cppyCG2tWbU:redacted-4Xl7m9yrCJ-TMmifH0YUuQvwjm6cthQKRfVWo6fidQuv6_C_VUSxFMKqIod1Iha3T5ORIJBB1
[2024-06-15T03:25:14Z DEBUG neolink::common::pushnoti] push notification UID: 780E4redacted
[2024-06-15T03:25:14Z DEBUG neolink::common::pushnoti] Push notification Listening
[2024-06-15T03:25:14Z DEBUG reqwest::connect] starting new connection: https://android.clients.google.com/
[2024-06-15T03:25:14Z DEBUG rustls::client::hs] No cached session for DnsName(DnsName(DnsName("mtalk.google.com")))
[2024-06-15T03:25:14Z DEBUG rustls::client::hs] Not resuming any session
[2024-06-15T03:25:14Z DEBUG rustls::client::hs] Using ciphersuite TLS13_AES_256_GCM_SHA384
[2024-06-15T03:25:14Z DEBUG rustls::client::tls13] Not resuming
[2024-06-15T03:25:14Z DEBUG rustls::client::tls13] TLS1.3 encrypted extensions: []
[2024-06-15T03:25:14Z DEBUG rustls::client::hs] ALPN protocol is None
[2024-06-15T03:25:14Z DEBUG rustls::client::tls13] Ticket saved
[2024-06-15T03:25:14Z DEBUG rustls::client::tls13] Ticket saved
[2024-06-15T03:25:14Z DEBUG fcm_push_listener::listener] Push message listener read tag 3 with payload size 62
[2024-06-15T03:25:14Z DEBUG fcm_push_listener::listener] Push message listener read tag 7 with payload size 10
[2024-06-15T03:25:15Z DEBUG neolink_core::bc_protocol::connection::discovery] Direct connect success at 192.168.12.255:2015 client: -901753292, device: 912
[2024-06-15T03:25:15Z DEBUG neolink_core::bc_protocol::connection::discovery] Returning direct connect: ConnectResult { addr: 192.168.12.177:19243, client_id: -901753292, camera_id: 912, sid: 0 }
[2024-06-15T03:25:15Z INFO  neolink_core::bc_protocol] driveway: Local discovery success 9527redacted at 192.168.12.177:19243
[2024-06-15T03:25:15Z INFO  neolink::utils] driveway: Logging in
[2024-06-15T03:25:16Z DEBUG neolink_core::bc_protocol::login] Populating abilities
[2024-06-15T03:25:16Z DEBUG neolink_core::bc_protocol::abilityinfo] Abilities: <AbilityInfo><userName>admin</userName><system><subModule><abilityValue>general_rw, norm_rw, version_ro, uid_ro, autoReboot_rw, restore_rw, reboot_rw, shutdown_rw, dst_rw, log_ro, performance_ro, upgrade_rw, export_rw, import_rw, bootPwd_rw</abilityValue></subModule></system><network><subModule><abilityValue>port_rw, dns_rw, email_rw, ipFilter_rw, localLink_rw, pppoe_rw, upnp_rw, wifi_rw, ntp_rw, netStatus_rw, ptop_rw, autontp_rw</abilityValue></subModule></network><alarm><subModule><abilityValue>rfAlarm_rw</abilityValue></subModule><subModule><channelId>0</channelId><abilityValue>motion_rw</abilityValue></subModule></alarm><image><subModule><channelId>0</channelId><abilityValue>ispBasic_rw, ispAdvance_rw, ledState_rw</abilityValue></subModule></image><video><subModule><channelId>0</channelId><abilityValue>osdName_rw, osdTime_rw, shelter_rw</abilityValue></subModule></video><security><subModule><abilityValue>user_rw, userOnline_rw, bootPwd_rw</abilityValue></subModule></security><PTZ><subModule><abilityValue>control_rw, preset_rw, cruise_rw, track_rw, decoder_rw, ptzInfo_ro</abilityValue></subModule></PTZ><streaming><subModule><channelId>0</channelId><abilityValue>preview_rw, compress_rw, snap_rw, rtsp_rw, streamTable_ro</abilityValue></subModule></streaming></AbilityInfo>
[2024-06-15T03:25:16Z INFO  neolink::utils] driveway: Connected and logged in
[2024-06-15T03:25:18Z INFO  neolink::common::camthread] driveway: Camera time is already set: 2024-06-14 23:25:21.0 +05:00:00
[2024-06-15T03:25:20Z INFO  neolink::common::neocam] driveway: Model Reolink Argus 3 Pro
[2024-06-15T03:25:20Z INFO  neolink::common::neocam] driveway: Firmware Version v3.0.0.973_22051000
[2024-06-15T03:25:21Z DEBUG neolink::common::instance] - Task Error: Send Error
[2024-06-15T03:25:21Z DEBUG neolink::common::mdthread] Error in MD task Restarting: Err(Camera is disconnecting)
root@utils:~# RUST_LOG=debug /root/neolink3 image --config=/root/neolink.toml --file-path=/root/test.jpg driveway
[2024-06-15T03:25:38Z INFO  neolink] Neolink 0.6.3-rc.2 (unknown commit) release
[2024-06-15T03:25:38Z INFO  neolink::utils] driveway: Connecting to camera at Address: 192.168.12.177, UID: 9527redacted
[2024-06-15T03:25:38Z DEBUG neolink::image] Using the snap command
[2024-06-15T03:25:38Z INFO  neolink_core::bc_protocol] driveway: Trying TCP discovery
[2024-06-15T03:25:38Z INFO  neolink_core::bc_protocol] driveway: Trying local discovery
[2024-06-15T03:25:38Z DEBUG neolink_core::bc_protocol::connection::discovery] Broadcasting to: [(255.255.255.255, 2015), (255.255.255.255, 2018), (192.168.17.255, 2015), (192.168.17.255, 2018), (192.168.12.255, 2015), (192.168.12.255, 2018)]
[2024-06-15T03:25:38Z DEBUG neolink_core::bc_protocol::connection::discovery] Also sending to [192.168.12.177:2018, 192.168.12.177:2015]
[2024-06-15T03:25:38Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 255.255.255.255:2015 with tid: 85
[2024-06-15T03:25:38Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 255.255.255.255:2018 with tid: 41
[2024-06-15T03:25:38Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 192.168.17.255:2015 with tid: 34
[2024-06-15T03:25:38Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 192.168.17.255:2018 with tid: 109
[2024-06-15T03:25:38Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 192.168.12.255:2015 with tid: 34
[2024-06-15T03:25:38Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 192.168.12.255:2018 with tid: 251
[2024-06-15T03:25:38Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 192.168.12.177:2018 with tid: 190
[2024-06-15T03:25:38Z DEBUG neolink_core::bc_protocol::connection::discovery] Trying a direct connect to: 192.168.12.177:2015 with tid: 10
[2024-06-15T03:25:40Z DEBUG neolink_core::bc_protocol::connection::discovery] Direct connect success at 192.168.12.177:2015 client: -1305555282, device: 944
[2024-06-15T03:25:40Z DEBUG neolink_core::bc_protocol::connection::discovery] Returning direct connect: ConnectResult { addr: 192.168.12.177:19243, client_id: -1305555282, camera_id: 944, sid: 0 }
[2024-06-15T03:25:40Z INFO  neolink_core::bc_protocol] driveway: Local discovery success 9527redacted at 192.168.12.177:19243
[2024-06-15T03:25:40Z INFO  neolink::utils] driveway: Logging in
[2024-06-15T03:25:41Z DEBUG neolink_core::bc_protocol::login] Populating abilities
[2024-06-15T03:25:41Z DEBUG neolink::common::pushnoti] Push notification details are saved to Some("/root/.config/neolink/./neolink_token.toml")
[2024-06-15T03:25:41Z DEBUG neolink::common::pushnoti] Loaded push notification token
[2024-06-15T03:25:41Z DEBUG neolink::common::pushnoti] registration.fcm_token: cppyCG2tWbU:redacted-4Xl7m9yrCJ-TMmifH0YUuQvwjm6cthQKRfVWo6fidQuv6_C_VUSxFMKqIod1Iha3T5ORIJBB1
[2024-06-15T03:25:41Z DEBUG neolink::common::pushnoti] push notification UID: 780E4redacted
[2024-06-15T03:25:41Z DEBUG neolink::common::pushnoti] Push notification Listening
[2024-06-15T03:25:41Z DEBUG reqwest::connect] starting new connection: https://android.clients.google.com/
[2024-06-15T03:25:41Z DEBUG neolink_core::bc_protocol::abilityinfo] Abilities: <AbilityInfo><userName>admin</userName><system><subModule><abilityValue>general_rw, norm_rw, version_ro, uid_ro, autoReboot_rw, restore_rw, reboot_rw, shutdown_rw, dst_rw, log_ro, performance_ro, upgrade_rw, export_rw, import_rw, bootPwd_rw</abilityValue></subModule></system><network><subModule><abilityValue>port_rw, dns_rw, email_rw, ipFilter_rw, localLink_rw, pppoe_rw, upnp_rw, wifi_rw, ntp_rw, netStatus_rw, ptop_rw, autontp_rw</abilityValue></subModule></network><alarm><subModule><abilityValue>rfAlarm_rw</abilityValue></subModule><subModule><channelId>0</channelId><abilityValue>motion_rw</abilityValue></subModule></alarm><image><subModule><channelId>0</channelId><abilityValue>ispBasic_rw, ispAdvance_rw, ledState_rw</abilityValue></subModule></image><video><subModule><channelId>0</channelId><abilityValue>osdName_rw, osdTime_rw, shelter_rw</abilityValue></subModule></video><security><subModule><abilityValue>user_rw, userOnline_rw, bootPwd_rw</abilityValue></subModule></security><PTZ><subModule><abilityValue>control_rw, preset_rw, cruise_rw, track_rw, decoder_rw, ptzInfo_ro</abilityValue></subModule></PTZ><streaming><subModule><channelId>0</channelId><abilityValue>preview_rw, compress_rw, snap_rw, rtsp_rw, streamTable_ro</abilityValue></subModule></streaming></AbilityInfo>
[2024-06-15T03:25:41Z INFO  neolink::utils] driveway: Connected and logged in
[2024-06-15T03:25:41Z DEBUG rustls::client::hs] No cached session for DnsName(DnsName(DnsName("mtalk.google.com")))
[2024-06-15T03:25:41Z DEBUG rustls::client::hs] Not resuming any session
[2024-06-15T03:25:41Z DEBUG rustls::client::hs] Using ciphersuite TLS13_AES_256_GCM_SHA384
[2024-06-15T03:25:41Z DEBUG rustls::client::tls13] Not resuming
[2024-06-15T03:25:41Z DEBUG rustls::client::tls13] TLS1.3 encrypted extensions: []
[2024-06-15T03:25:41Z DEBUG rustls::client::hs] ALPN protocol is None
[2024-06-15T03:25:41Z DEBUG rustls::client::tls13] Ticket saved
[2024-06-15T03:25:41Z DEBUG rustls::client::tls13] Ticket saved
[2024-06-15T03:25:42Z DEBUG fcm_push_listener::listener] Push message listener read tag 3 with payload size 62
[2024-06-15T03:25:42Z DEBUG fcm_push_listener::listener] Push message listener read tag 7 with payload size 10
[2024-06-15T03:25:44Z INFO  neolink::common::camthread] driveway: Camera time is already set: 2024-06-14 23:25:47.0 +05:00:00
[2024-06-15T03:25:46Z INFO  neolink::common::neocam] driveway: Model Reolink Argus 3 Pro
[2024-06-15T03:25:46Z INFO  neolink::common::neocam] driveway: Firmware Version v3.0.0.973_22051000
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
[2024-06-15T03:25:46Z DEBUG neolink::common::reactor] Push notifier reported normal shutdown. Restarting
dkerr64 commented 4 months ago

Something jumps out at me here.... what's with... 

[2024-06-15T03:25:41Z DEBUG reqwest::connect] starting new connection: https://android.clients.google.com/

Why is it trying to connect to something outside my local network?

QuantumEntangledAndy commented 4 months ago

Because of how push notifications work. Maybe google push notification and firebase messaging, can help you understand why we connect to https://android.clients.google.com/ for push notifications

This may actually be to do with upstream changes in googles push notifcation services (since we are using the REd version of it). I had a look at updating to the new method but I still need to find the vapid_key for reolink. Should be in the reolink android app code somewhere.

dkerr64 commented 4 months ago

How do I turn off push notifications... so it doesn't even try to connect to google?

QuantumEntangledAndy commented 4 months ago

It's in the readme push_notifications = false in every [[cameras]] section of the config

dkerr64 commented 4 months ago

Found it, thanks.

I also notice that capturing a still image has changed. When I was working with you, we had to capture it from the stream. Now it looks like you found a way to get it direct form the camera, which feels like a much better way to do it. But is there a way to specify the image size/resolution? It is coming in at 892x512 pixels, when camera full resolution is 2560x1440. Would be nice if we could request a snapshot of the full resolution.

QuantumEntangledAndy commented 4 months ago

Unfortunately not. The camera only has one command called Snap for getting a picture. There is a stream parameter and I always set it to MainStream but some cameras seem to just ignore that and always make snap pictures on SubStream. So if you want control you have to use from stream.