search

QuantumEntangledAndy / neolink

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

Error when streaming from Argus 3 pro [was using UID discovery], Deserialization error #36

Closed dkerr64 closed 1 year ago

dkerr64 commented 1 year ago

My wired Reolink is working fine (RLC-520). However the Argus 3 Pro is not. I suspect it is to do with UID discovery as that is the only way to connect to this camera.

After streaming starts the debug log shows continuous start to parse "Extension" messages which within 15 seconds ends with an error. Before it errors out I am able to connect to the rstp stream with VLC, but it terminates shortly after the error.

Streaming from the camera seems to stop (tcpdump sees no traffic) but neolink is still doing something as CPU continues to run at 25% (4 core, so 100% on one core/thread?)

Monitoring tcpdump, I notice an incoming packet from 20.231.199.129 which is the relay server returned by Reolink. It appears that neolink is not expecting that because it expects traffic only from the camera's local IP address.

Here is tail end of the log.

[2023-02-24T01:50:39Z DEBUG neolink_core::bc::xml] Struct: start to parse "Extension"
[2023-02-24T01:50:39Z DEBUG yaserde::de] Fetched StartElement(Extension, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"}, [version -> 1.1])
[2023-02-24T01:50:39Z DEBUG yaserde::de] Fetched StartElement(checkPos, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T01:50:39Z DEBUG yaserde::de] Fetched Characters(0)
[2023-02-24T01:50:39Z DEBUG yaserde::de] Fetched EndElement(checkPos)
[2023-02-24T01:50:39Z DEBUG yaserde::de] Fetched StartElement(checkValue, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T01:50:39Z DEBUG yaserde::de] Fetched Characters(1667510576)
[2023-02-24T01:50:39Z DEBUG yaserde::de] Fetched EndElement(checkValue)
[2023-02-24T01:50:39Z DEBUG neolink_core::bc::xml] Struct: start to parse "Extension"
[2023-02-24T01:50:39Z DEBUG yaserde::de] Fetched StartElement(Extension, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"}, [version -> 1.1])
[2023-02-24T01:50:39Z DEBUG yaserde::de] Fetched StartElement(checkPos, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T01:50:39Z DEBUG yaserde::de] Fetched Characters(0)
[2023-02-24T01:50:39Z DEBUG yaserde::de] Fetched EndElement(checkPos)
[2023-02-24T01:50:39Z DEBUG yaserde::de] Fetched StartElement(checkValue, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T01:50:39Z DEBUG yaserde::de] Fetched Characters(1667510576)
[2023-02-24T01:50:39Z DEBUG yaserde::de] Fetched EndElement(checkValue)
[2023-02-24T01:50:40Z DEBUG neolink_core::bc::xml] Struct: start to parse "Extension"
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched StartElement(Extension, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"}, [version -> 1.1])
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched StartElement(checkPos, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched Characters(0)
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched EndElement(checkPos)
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched StartElement(checkValue, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched Characters(1667510576)
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched EndElement(checkValue)
[2023-02-24T01:50:40Z DEBUG neolink_core::bc::xml] Struct: start to parse "Extension"
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched StartElement(Extension, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"}, [version -> 1.1])
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched StartElement(checkPos, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched Characters(0)
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched EndElement(checkPos)
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched StartElement(checkValue, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched Characters(1651979568)
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched EndElement(checkValue)
[2023-02-24T01:50:40Z DEBUG neolink_core::bc::xml] Struct: start to parse "Extension"
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched StartElement(Extension, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"}, [version -> 1.1])
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched StartElement(checkPos, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched Characters(0)
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched EndElement(checkPos)
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched StartElement(checkValue, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched Characters(1651979568)
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched EndElement(checkValue)
[2023-02-24T01:50:40Z DEBUG neolink_core::bcudp::xml] Struct: start to parse "P2P"
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched StartElement(P2P, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T01:50:40Z DEBUG neolink_core::bcudp::xml] Struct: start to parse "D2C_DISC"
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched StartElement(D2C_DISC, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched StartElement(cid, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched Characters(-221156607)
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched EndElement(cid)
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched StartElement(did, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched Characters(432)
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched EndElement(did)
[2023-02-24T01:50:40Z DEBUG yaserde::de] Fetched EndElement(D2C_DISC)
[2023-02-24T01:50:40Z ERROR neolink_core::bc_protocol::connection::bcconn] Deserialization error: Io(Custom { kind: Other, error: CameraTerminate })
^C

And the tcpdump...

root@neolink:~# tcpdump -n -i eth0 host 192.168.21.38 or host 20.231.199.129
tcpdump: verbose output suppressed, use -v[v]... for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes
20:50:28.442523 IP 192.168.21.171.53961 > 20.231.199.129.58200: UDP, length 297
20:50:28.442523 IP 192.168.21.171.53571 > 20.231.199.129.58200: UDP, length 296
20:50:28.477575 IP 20.231.199.129.58200 > 192.168.21.171.53961: UDP, length 204
20:50:28.477663 IP 20.231.199.129.58200 > 192.168.21.171.53571: UDP, length 203
20:50:28.480283 IP 192.168.21.171.53571 > 192.168.21.38.43563: UDP, length 158
20:50:28.981678 IP 192.168.21.171.53571 > 192.168.21.38.43563: UDP, length 158
20:50:28.986979 IP 20.231.199.129.58200 > 192.168.21.171.53961: UDP, length 204
20:50:28.987302 IP 20.231.199.129.58200 > 192.168.21.171.53571: UDP, length 203
20:50:29.482878 IP 192.168.21.171.53571 > 192.168.21.38.43563: UDP, length 158
20:50:29.494597 IP 20.231.199.129.58200 > 192.168.21.171.53961: UDP, length 204
20:50:29.494787 IP 20.231.199.129.58200 > 192.168.21.171.53571: UDP, length 203
20:50:29.983991 IP 192.168.21.171.53571 > 192.168.21.38.43563: UDP, length 158
20:50:30.485206 IP 192.168.21.171.53571 > 192.168.21.38.43563: UDP, length 158
20:50:30.852897 IP 192.168.21.38.43563 > 192.168.21.171.53961: UDP, length 128
20:50:30.852928 IP 192.168.21.38.43563 > 192.168.21.171.53571: UDP, length 144
20:50:30.854628 IP 192.168.21.171.53961 > 192.168.21.38.43563: UDP, length 173
20:50:30.855857 IP 192.168.21.171.53571 > 20.231.199.129.58200: UDP, length 173
20:50:30.890895 IP 192.168.21.38.43563 > 192.168.21.171.53961: UDP, length 143
20:50:30.892861 IP 192.168.21.171.53961 > 20.231.199.129.58200: UDP, length 174
20:50:30.896164 IP 20.231.199.129.58200 > 192.168.21.171.53961: UDP, length 275
20:50:30.905783 IP 192.168.21.171.53571 > 20.231.199.129.58200: UDP, length 173
20:50:30.942981 IP 192.168.21.171.53961 > 20.231.199.129.58200: UDP, length 174
20:50:30.956164 IP 192.168.21.171.53571 > 20.231.199.129.58200: UDP, length 173
20:50:30.992432 IP 192.168.21.171.53961 > 20.231.199.129.58200: UDP, length 174
20:50:31.005636 IP 192.168.21.171.53571 > 20.231.199.129.58200: UDP, length 173
20:50:31.043028 IP 192.168.21.171.53961 > 20.231.199.129.58200: UDP, length 174
20:50:31.056284 IP 192.168.21.171.53571 > 20.231.199.129.58200: UDP, length 173
20:50:31.057486 IP 192.168.21.171.53571 > 192.168.21.38.43563: UDP, length 156
20:50:31.092786 IP 192.168.21.171.53961 > 20.231.199.129.58200: UDP, length 174
20:50:31.093999 IP 192.168.21.171.53961 > 192.168.21.38.43563: UDP, length 157
20:50:31.107433 IP 192.168.21.171.53571 > 192.168.21.38.43563: UDP, length 156
20:50:31.143701 IP 192.168.21.171.53961 > 192.168.21.38.43563: UDP, length 157
20:50:31.158009 IP 192.168.21.171.53571 > 192.168.21.38.43563: UDP, length 156
20:50:31.193417 IP 192.168.21.171.53961 > 192.168.21.38.43563: UDP, length 157
.
.
[deleted a whole lot of traffic]
.
.
20:50:40.458935 IP 192.168.21.38.43563 > 192.168.21.171.53571: UDP, length 1030
20:50:40.459357 IP 192.168.21.171.53571 > 192.168.21.38.43563: UDP, length 28
20:50:40.460005 IP 192.168.21.38.43563 > 192.168.21.171.53571: UDP, length 1030
20:50:40.460092 IP 192.168.21.38.43563 > 192.168.21.171.53571: UDP, length 1030
20:50:40.460092 IP 192.168.21.38.43563 > 192.168.21.171.53571: UDP, length 1030
20:50:40.461647 IP 192.168.21.38.43563 > 192.168.21.171.53571: UDP, length 616
20:50:40.461740 IP 192.168.21.38.43563 > 192.168.21.171.53571: UDP, length 28
20:50:40.470271 IP 192.168.21.171.53571 > 192.168.21.38.43563: UDP, length 28
20:50:40.476416 IP 192.168.21.38.43563 > 192.168.21.171.53571: UDP, length 28
20:50:40.479463 IP 192.168.21.171.53571 > 192.168.21.38.43563: UDP, length 28
20:50:40.489647 IP 192.168.21.171.53571 > 192.168.21.38.43563: UDP, length 28
20:50:40.499686 IP 192.168.21.171.53571 > 192.168.21.38.43563: UDP, length 28
20:50:40.509836 IP 192.168.21.38.43563 > 192.168.21.171.53571: UDP, length 28
20:50:40.509902 IP 192.168.21.171.53571 > 192.168.21.38.43563: UDP, length 28
20:50:40.513898 IP 192.168.21.38.43563 > 192.168.21.171.53571: UDP, length 93
20:50:40.521009 IP 192.168.21.38.43563 > 192.168.21.171.53571: UDP, length 28
20:50:40.563842 IP 20.231.199.129.58200 > 192.168.21.171.53571: UDP, length 72
20:50:41.023999 IP 20.231.199.129.58200 > 192.168.21.171.53961: UDP, length 72
20:50:41.024024 IP 192.168.21.171 > 20.231.199.129: ICMP 192.168.21.171 udp port 53961 unreachable, length 108
20:50:41.044879 IP 192.168.21.38.43563 > 192.168.21.171.53571: UDP, length 93

Error message in neolink coincides with receipt of the packet from 20.231.199.129

QuantumEntangledAndy commented 1 year ago

Lets try disabling relay for the moment. Can you add

[[cameras]]
...other cam stuff...
discovery = "local"

to your config. It will disable the remote and relay discovery

dkerr64 commented 1 year ago

Doesn't work. The battery powered cameras do not respond to broadcasts. Or if they do it takes longer than the timeout. I believe that the only way to establish a connection to one of these cameras is with the remote discovery.

david@neolink:~$ RUST_LOG=trace ~/github/neolink/target/debug/neolink image --config=/home/david/neolink.toml --file-path=/home/david/image2.jpeg driveway
[2023-02-24T02:33:46Z INFO  neolink] Neolink 0.5.2 (unknown commit) debug
[2023-02-24T02:33:46Z INFO  neolink::utils] driveway: Connecting to camera at UID: <redacted>
[2023-02-24T02:33:46Z DEBUG neolink_core::bc_protocol] Trying uid <redacted>
[2023-02-24T02:33:46Z DEBUG neolink_core::bc_protocol] Starting Local discovery
[2023-02-24T02:33:46Z TRACE mio::poll] registering event source with poller: token=Token(0), interests=READABLE | WRITABLE
[2023-02-24T02:33:46Z DEBUG neolink_core::bc_protocol::connection::discovery] Broadcasting to: [(255.255.255.255, 2015), (255.255.255.255, 2018), (192.168.21.255, 2015), (192.168.21.255, 2018), (192.168.17.255, 2015), (192.168.17.255, 2018)]
[2023-02-24T02:33:49Z TRACE mio::poll] deregistering event source from poller
[2023-02-24T02:33:49Z DEBUG neolink_core::bc_protocol] Discovery Error: DiscoveryTimeout
Error: Failed to connect to the camera, check credentials and network

Caused by:
    0: Failed to connect to camera driveway at UID: <redacted> on channel 0
    1: Timed out while waiting for camera reply
QuantumEntangledAndy commented 1 year ago

Oh then let's try the next level up discovery = "remote"

dkerr64 commented 1 year ago

Update... timeout is too short. I tried again with tcpdump monitoring and the camera does respond eventually. It can take a few broadcast attempts (restarting neolink several times).

QuantumEntangledAndy commented 1 year ago

Ok I'll bump that up then or maybe repeat more than 5 times

QuantumEntangledAndy commented 1 year ago

Which branch are you working on? feature/jpeg if so I'll add it to that

dkerr64 commented 1 year ago

remote discovery has the same problem, packet arrives from relay server and neolink errors.

21:42:04.844735 IP 192.168.21.171.53653 > 192.168.21.38.43563: UDP, length 28
21:42:04.844748 IP 192.168.21.171.53653 > 192.168.21.38.43563: UDP, length 28
21:42:04.844755 IP 192.168.21.171.53653 > 192.168.21.38.43563: UDP, length 28
21:42:04.844780 IP 192.168.21.38.43563 > 192.168.21.171.53653: UDP, length 28
21:42:04.883539 IP 20.231.199.129.58200 > 192.168.21.171.53653: UDP, length 72
21:42:05.332007 IP 192.168.21.38.43563 > 192.168.21.171.53653: UDP, length 93
dkerr64 commented 1 year ago

Which branch are you working on? feature/jpeg if so I'll add it to that

Yes I am working in that branch now. Bump it up really high please, to get us past this problem. Let's say 60 seconds. And keep broadcasting until then.

Thanks

QuantumEntangledAndy commented 1 year ago

We broadcast every 0.5s for 2.5 seconds I've bump it up to every 0.5s for 60s now but that might be too long for production

dkerr64 commented 1 year ago

We broadcast every 0.5s for 2.5 seconds I've bump it up to every 0.5s for 60s now but that might be too long for production

Yes agree. But for production really need to fix the underlying problem of error on the unexpected packet.

dkerr64 commented 1 year ago

Humm. That didn't fix it. Local discovery now works, but we still error out and this time there is no incoming packet from the relay server. I have to stop for the night now.

[2023-02-24T02:52:46Z DEBUG neolink_core::bc::xml] Struct: start to parse "Extension"
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched StartElement(Extension, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"}, [version -> 1.1])
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched StartElement(checkPos, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched Characters(0)
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched EndElement(checkPos)
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched StartElement(checkValue, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched Characters(1651979568)
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched EndElement(checkValue)
[2023-02-24T02:52:46Z DEBUG neolink_core::bc::xml] Struct: start to parse "Extension"
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched StartElement(Extension, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"}, [version -> 1.1])
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched StartElement(checkPos, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched Characters(0)
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched EndElement(checkPos)
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched StartElement(checkValue, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched Characters(1651979568)
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched EndElement(checkValue)
[2023-02-24T02:52:46Z DEBUG neolink_core::bcudp::xml] Struct: start to parse "P2P"
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched StartElement(P2P, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T02:52:46Z DEBUG neolink_core::bcudp::xml] Struct: start to parse "D2C_DISC"
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched StartElement(D2C_DISC, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched StartElement(cid, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched Characters(-891741286)
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched EndElement(cid)
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched StartElement(did, {"": "", "xml": "http://www.w3.org/XML/1998/namespace", "xmlns": "http://www.w3.org/2000/xmlns/"})
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched Characters(160)
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched EndElement(did)
[2023-02-24T02:52:46Z DEBUG yaserde::de] Fetched EndElement(D2C_DISC)
[2023-02-24T02:52:46Z ERROR neolink_core::bc_protocol::connection::bcconn] Deserialization error: Io(Custom { kind: Other, error: CameraTerminate })
21:52:46.283667 IP 192.168.21.171.53911 > 192.168.21.38.43563: UDP, length 28
21:52:46.293402 IP 192.168.21.171.53911 > 192.168.21.38.43563: UDP, length 28
21:52:46.294792 IP 192.168.21.38.43563 > 192.168.21.171.53911: UDP, length 182
21:52:46.294793 IP 192.168.21.38.43563 > 192.168.21.171.53911: UDP, length 28
21:52:46.294830 IP 192.168.21.171.53911 > 192.168.21.38.43563: UDP, length 28
21:52:46.294936 IP 192.168.21.38.43563 > 192.168.21.171.53911: UDP, length 1030
21:52:46.294952 IP 192.168.21.38.43563 > 192.168.21.171.53911: UDP, length 1030
21:52:46.294952 IP 192.168.21.38.43563 > 192.168.21.171.53911: UDP, length 1030
21:52:46.306841 IP 192.168.21.38.43563 > 192.168.21.171.53911: UDP, length 1030
21:52:46.306878 IP 192.168.21.171.53911 > 192.168.21.38.43563: UDP, length 28
21:52:46.306887 IP 192.168.21.171.53911 > 192.168.21.38.43563: UDP, length 28
21:52:46.306893 IP 192.168.21.171.53911 > 192.168.21.38.43563: UDP, length 28
21:52:46.306898 IP 192.168.21.171.53911 > 192.168.21.38.43563: UDP, length 28
21:52:46.306903 IP 192.168.21.171.53911 > 192.168.21.38.43563: UDP, length 28
21:52:46.306926 IP 192.168.21.38.43563 > 192.168.21.171.53911: UDP, length 1030
21:52:46.306927 IP 192.168.21.38.43563 > 192.168.21.171.53911: UDP, length 1030
21:52:46.307019 IP 192.168.21.38.43563 > 192.168.21.171.53911: UDP, length 888
21:52:46.307020 IP 192.168.21.38.43563 > 192.168.21.171.53911: UDP, length 28
21:52:46.307020 IP 192.168.21.38.43563 > 192.168.21.171.53911: UDP, length 93
21:52:46.307021 IP 192.168.21.38.43563 > 192.168.21.171.53911: UDP, length 28
dkerr64 commented 1 year ago

Btw... the constant logging of start to parse Extension and P2P and D2C_DISC only happens with this camera (Argus 3 Pro). The log is quiet when streaming from the RLC-520 wired camera.

QuantumEntangledAndy commented 1 year ago

The D2C_DISC is a disconnect message from the camera. Are you testing with just local or remote? I asked because I had issues in my tests where the camera would send a D2C_DISC to me and try to swap to the relay if I started a relay and local together without terminating relay correctly

dkerr64 commented 1 year ago

All local.

QuantumEntangledAndy commented 1 year ago

Could you send the pcap it would be helpful to see the steps in wireshark

Hoppersusa commented 1 year ago

Gents, just to add to this I see the Deserialization error on the Argus Eco, Pro 2 and Pro 3 cameras. The issue is not limited to the Pro 3. I was lucky enough for it to complete on one of my Pro 3's and it is very cool! If I can help troubleshoot please let me know.

dkerr64 commented 1 year ago

Could you send the pcap it would be helpful to see the steps in wireshark

Archive 2.zip Attached.

QuantumEntangledAndy commented 1 year ago

@dkerr64 Pushed an update to feature/jpeg that seems to be helping can you confirm?

dkerr64 commented 1 year ago

I think your push is incomplete, missing keepalive module, so it is not building.

QuantumEntangledAndy commented 1 year ago

Ah I see, sorry about that. Since my usual editor (Atom) is no longer being updated I've swapped to something else but the new editor dosen't manage git nearly as well so I'm doing it more manually. Anyways should be pushed

dkerr64 commented 1 year ago

Now we are building and things have improved a lot. There are still errors like that below, and the VLC player is logging a lot of warnings. Those should probably be new/separate issues. But this bug is now fixed.

[2023-02-26T02:32:26Z INFO  neolink::rtsp::states] driveway: Connecting to camera at UID: <redacted>
[2023-02-26T02:32:26Z INFO  neolink::rtsp::states] driveway: Logging in
[2023-02-26T02:32:27Z INFO  neolink::rtsp::states] driveway: Successfully logged in
[2023-02-26T02:32:27Z INFO  neolink::rtsp::states] driveway: Camera time is already set: 2023-02-25 21:32:35 -5
[2023-02-26T02:32:28Z INFO  neolink::rtsp::states] driveway: Camera reports firmware version v3.0.0.973_22051000
[2023-02-26T02:32:28Z INFO  neolink::rtsp::states] driveway: Starting stream
[2023-02-26T02:32:28Z INFO  neolink::rtsp::states::streaming] driveway: Starting video stream Main Stream (Clear)
[2023-02-26T02:32:28Z INFO  neolink::rtsp::states] driveway: Successfully started streaming
[2023-02-26T02:33:29Z WARN  neolink::rtsp] driveway: Retryable error: Camera has unexpectanely stopped the streaming state: On stream: Main

    Caused by:
        Nom Parsing error: Nom Error: VerboseError { errors: [([2E, 2B, 18, B, B9,
.
.
.
(many pages of data followed by...
.
.
.
E3, 97, 68], Context("Failed to match any known bcmedia"))] }
[2023-02-26T02:33:29Z INFO  neolink::rtsp::states] driveway: Connecting to camera at UID: <redacted>
[2023-02-26T02:33:29Z INFO  neolink::rtsp::states] driveway: Logging in
[2023-02-26T02:33:30Z INFO  neolink::rtsp::states] driveway: Successfully logged in
[2023-02-26T02:33:30Z INFO  neolink::rtsp::states] driveway: Camera time is already set: 2023-02-25 21:33:38 -5
[2023-02-26T02:33:30Z INFO  neolink::rtsp::states] driveway: Camera reports firmware version v3.0.0.973_22051000
[2023-02-26T02:33:30Z INFO  neolink::rtsp::states] driveway: Starting stream
[2023-02-26T02:33:30Z INFO  neolink::rtsp::states::streaming] driveway: Starting video stream Main Stream (Clear)
[2023-02-26T02:33:30Z INFO  neolink::rtsp::states] driveway: Successfully started streaming
dkerr64 commented 1 year ago

Maybe I spoke too soon. Deserialization error still exists. Note in this case the IP address was discovered by relay not local. Was not running with debug so don't know if a message was received from the relay server.

david@neolink:~/github/neolink$ ~/github/neolink/target/debug/neolink rtsp --config=/home/david/neolink.toml
[2023-02-26T02:58:29Z INFO  neolink] Neolink 0.5.2 (unknown commit) debug
[2023-02-26T02:58:29Z WARN  neolink::rtsp::gst] Missing the gstreamer plugin `x264 (gst-plugins-ugly)` for `x264enc` element. Required to paused certain cameras
[2023-02-26T02:58:29Z WARN  neolink::rtsp::gst] Missing the gstreamer plugin `libav (gst-libav)` for `avdec_h264` element. Required to paused certain cameras
[2023-02-26T02:58:29Z WARN  neolink::rtsp::gst] Missing the gstreamer plugin `libav (gst-libav)` for `avdec_h265` element. Required to paused certain cameras
[2023-02-26T02:58:29Z INFO  neolink::rtsp] Starting RTSP Server at 0.0.0.0:8554
[2023-02-26T02:58:29Z INFO  neolink::rtsp::states] driveway: Connecting to camera at UID: <redacted>
[2023-02-26T02:58:34Z INFO  neolink_core::bc_protocol] Relay success <redacted> at 192.168.21.38:34892
[2023-02-26T02:58:34Z INFO  neolink::rtsp::states] driveway: Logging in
[2023-02-26T02:58:46Z ERROR neolink_core::bc_protocol::connection::bcconn] Deserialization error: Io(Custom { kind: Other, error: RelayTerminate })
^C
david@neolink:~/github/neolink$
QuantumEntangledAndy commented 1 year ago

I've added the UDP keep alive messages so that the camera doesn't drop us for inactivity. However now you are getting a disconnect from the Relay instead of the camera.... I've got to find our what the offical client dose to placate the relay

QuantumEntangledAndy commented 1 year ago

Hopefully this is addressed in #40. I did some tests were I stopped discovery methods one at a time until I could replicate your issue then reworked the discoverer to better match the offical client. It seems to now be working for my Argus2E

QuantumEntangledAndy commented 1 year ago

If you could test it would be appreciated

dkerr64 commented 1 year ago

So far I am not seeing the deserialization error. I am still seeing the problem reported in #38 so it may be necessary to get past that one before we know for sure that this is fixed.

QuantumEntangledAndy commented 1 year ago

38 should be addressed in feature/passdown but I sometimes still see this. I think it happens when we connect via relay but then the camera decides it can actually connect via map instead and drop us in favour of establishing a map

dkerr64 commented 1 year ago

See comments in #38. This deserialization is probably fixed.

Hoppersusa commented 1 year ago

With 0.5.4rc I am not hitting the deserialization issue so far. Thank you for addressing that so quickly. I did want to highlight that as soon as gstreamer is invoked/started even without the pause feature enabled I see 100% CPU utilization. The pause feature is not working in this release but I think that is expected. Is there additional information I can provide to help? I have the trace output below.
5.4.nopause.zip

QuantumEntangledAndy commented 1 year ago

Think this is all fixed now so closing. Please make a new issue against the latest neolink if you get something similar