search

doitandbedone / ispyagentdvr-docker

GNU General Public License v3.0
119 stars 45 forks source link

Many disconnect and failure in ONVIF events #568

Closed titiviking closed 1 year ago

titiviking commented 1 year ago

Running iSpyAgent 4.5.4 on a docker, I'm facing many ONVIF issues for one of my cameras.

11:30:08 AM | Reconnect: Garden-Front: Reconnecting main in 2s -- | -- 11:30:15 AM | ONVIF Presets: Garden-Front: Presets not supported 11:30:15 AM | Error: ONVIF Presets: Garden-Front: Presets not supported 11:30:29 AM | SourcePlayingFinished: Garden-Front: Playing finished (DeviceLost) 11:30:29 AM | Reconnect: Garden-Front: Reconnecting in 2s 11:30:29 AM | open (record): Garden-Front: Trying UDP 11:30:32 AM | intervals: Garden-Front: Reconnecting 11:30:32 AM | intervals: Garden-Front: Reconnect Exit 11:30:33 AM | Discovery (GetServices): Garden-Front: ONVIF v1.0 11:30:33 AM | Discovery: Garden-Front: Using Media Version 1 11:30:33 AM | Discovery: Garden-Front: Media available at http://192.168.5.212/onvif/media_service 11:30:33 AM | Discovery: Garden-Front: PTZ available at http://192.168.5.212/onvif/ptz_service 11:30:33 AM | Discovery: Garden-Front: Events available at http://192.168.5.212/onvif/event_service 11:30:36 AM | ONVIF Presets: Garden-Front: Presets not supported 11:30:36 AM | Error: ONVIF Presets: Garden-Front: Presets not supported 11:30:39 AM | Start Stream: Garden-Front: Using software decoder 11:30:39 AM | ONVIF State Monitor: Garden-Front: Onvif event receiver state: Connecting to http://192.168.5.212/onvif/device_service... 11:30:39 AM | ONVIF Presets: Garden-Front: Presets not supported 11:30:39 AM | Error: ONVIF Presets: Garden-Front: Presets not supported 11:30:44 AM | ONVIF Received: 11:30:44 AM | ONVIF Received: 11:31:06 AM | Reconnect: Garden-Front: Reconnecting main in 2s 11:31:12 AM | ONVIF Presets: Garden-Front: Presets not supported 11:31:12 AM | Error: ONVIF Presets: Garden-Front: Presets not supported 11:31:44 AM | ONVIF State Monitor: Garden-Front: Onvif event receiver state: Connection error: The request channel timed out attempting to send after 00:00:15. Increase the timeout value passed to the call to Request or increase the SendTimeout value on the Binding. The time allotted to this operation may have been a portion of a longer timeout. 11:31:49 AM | ONVIF State Monitor: Garden-Front: Onvif event receiver state: Connecting to http://192.168.5.212/onvif/device_service... 11:31:50 AM | Reconnect: Garden-Front: Reconnecting main in 2s 11:31:52 AM | Reconnect: Garden-Front: Reconnecting main in 2s 11:31:52 AM | SourcePlayingFinished: Garden-Front: Playing finished (DeviceLost) 11:31:52 AM | Reconnect: Garden-Front: Reconnecting in 2s 11:31:54 AM | intervals: Garden-Front: Reconnecting 11:31:54 AM | intervals: Garden-Front: Reconnect Exit 11:31:59 AM | Discovery (GetServices): Garden-Front: ONVIF v1.0 11:31:59 AM | Discovery: Garden-Front: Using Media Version 1 11:31:59 AM | Discovery: Garden-Front: Media available at http://192.168.5.212/onvif/media_service 11:31:59 AM | Discovery: Garden-Front: PTZ available at http://192.168.5.212/onvif/ptz_service 11:31:59 AM | Discovery: Garden-Front: Events available at http://192.168.5.212/onvif/event_service 11:32:07 AM | ONVIF Presets: Garden-Front: Presets not supported 11:32:07 AM | Error: ONVIF Presets: Garden-Front: Presets not supported 11:32:15 AM | Start Stream: Garden-Front: Using software decoder 11:32:15 AM | ONVIF State Monitor: Garden-Front: Onvif event receiver state: Connecting to http://192.168.5.212/onvif/device_service... 11:32:16 AM | ONVIF Presets: Garden-Front: Presets not supported 11:32:16 AM | Error: ONVIF Presets: Garden-Front: Presets not supported 11:32:18 AM | ONVIF Received: 11:32:18 AM | ONVIF Received: 11:32:55 AM | Apply profile Disabled 11:33:03 AM | Apply profile Disabled 11:33:21 AM | Reconnect: Garden-Front: Reconnecting main in 2s 11:33:26 AM | ONVIF Presets: Garden-Front: Presets not supported 11:33:26 AM | Error: ONVIF Presets: Garden-Front: Presets not supported 11:34:38 AM | MQTT Init 11:34:38 AM | MQTT disconnected 11:34:38 AM | Connected to MQTT server 11:34:38 AM | Subscribed to ispyconnect/commands 11:35:11 AM | Downloader: Unzipping /agent/XML/Sources.zip 11:35:23 AM | Downloader: Unzipping /agent/XML/PTZ2.zip 11:35:52 AM | SourcePlayingFinished: Garden-Front: Playing finished (DeviceLost) 11:35:52 AM | Reconnect: Garden-Front: Reconnecting in 2s

Any idea how I can fix those reconnects and enable the ONVIF events properly ?

ispysoftware commented 1 year ago

Usually means your camera needs a reboot

titiviking commented 1 year ago

I've done that, but I still get quite a bit of disconnects...

2:14:07 AM | Error: Garden-Front:Reader: Garden-Front: AV_READ_FRAME:Immediate exit requested
-- | --
2:14:07 AM | Reconnect: Garden-Front: Reconnecting main in 2s
2:14:14 AM | ONVIF Presets: Garden-Front: Presets not supported
2:14:14 AM | Error: ONVIF Presets: Garden-Front: Presets not supported
2:14:29 AM | open (record): Garden-Front: Trying UDP
2:14:29 AM | MainSourceError: Garden-Front: rtsp://admin:L208733E@192.168.5.212:554/cam/realmonitor?channel=1&subtype=0&unicast=true&proto=Onvif:Reader: Garden-Front: OPEN_INPUT:Invalid data found when processing input
2:14:29 AM | Error: MainSourceError: Garden-Front: rtsp://admin:L208733E@192.168.5.212:554/cam/realmonitor?channel=1&subtype=0&unicast=true&proto=Onvif:Reader: Garden-Front: OPEN_INPUT:Invalid data found when processing input
2:14:29 AM | Reconnect: Garden-Front: Reconnecting main in 5s
2:14:39 AM | ONVIF Presets: Garden-Front: Presets not supported
2:14:39 AM | Error: ONVIF Presets: Garden-Front: Presets not supported
2:14:54 AM | open (record): Garden-Front: Trying TCP
2:14:54 AM | MainSourceError: Garden-Front: rtsp://admin:L208733E@192.168.5.212:554/cam/realmonitor?channel=1&subtype=0&unicast=true&proto=Onvif:Reader: Garden-Front: OPEN_INPUT:Invalid data found when processing input
2:14:54 AM | Error: MainSourceError: Garden-Front: rtsp://admin:L208733E@192.168.5.212:554/cam/realmonitor?channel=1&subtype=0&unicast=true&proto=Onvif:Reader: Garden-Front: OPEN_INPUT:Invalid data found when processing input
2:14:54 AM | Reconnect: Garden-Front: Reconnecting main in 10s
2:15:08 AM | ONVIF Presets: Garden-Front: Presets not supported
2:15:08 AM | Error: ONVIF Presets: Garden-Front: Presets not supported
2:15:23 AM | open (record): Garden-Front: Trying UDP
2:15:23 AM | MainSourceError: Garden-Front: rtsp://admin:L208733E@192.168.5.212:554/cam/realmonitor?channel=1&subtype=0&unicast=true&proto=Onvif:Reader: Garden-Front: OPEN_INPUT:Operation not permitted
2:15:23 AM | Error: MainSourceError: Garden-Front: rtsp://admin:L208733E@192.168.5.212:554/cam/realmonitor?channel=1&subtype=0&unicast=true&proto=Onvif:Reader: Garden-Front: OPEN_INPUT:Operation not permitted
2:15:23 AM | Reconnect: Garden-Front: Reconnecting main in 30s
2:15:57 AM | ONVIF Presets: Garden-Front: Presets not supported
2:15:57 AM | Error: ONVIF Presets: Garden-Front: Presets not supported
2:16:12 AM | open (record): Garden-Front: Trying TCP
2:16:12 AM | MainSourceError: Garden-Front: rtsp://admin:L208733E@192.168.5.212:554/cam/realmonitor?channel=1&subtype=0&unicast=true&proto=Onvif:Reader: Garden-Front: OPEN_INPUT:Invalid data found when processing input
2:16:12 AM | Error: MainSourceError: Garden-Front: rtsp://admin:L208733E@192.168.5.212:554/cam/realmonitor?channel=1&subtype=0&unicast=true&proto=Onvif:Reader: Garden-Front: OPEN_INPUT:Invalid data found when processing input
2:16:12 AM | Reconnect: Garden-Front: Reconnecting main in 30s
2:16:45 AM | ONVIF Presets: Garden-Front: Presets not supported
2:16:45 AM | Error: ONVIF Presets: Garden-Front: Presets not supported

I also face many MQTT disconnects:

7:27:12 AM | Push blocked (Send:False, Enabled:True, Connected: False)
-- | --
7:27:12 AM | Processing MQTT (home/Security/Motion/Living)
7:27:55 AM | Processing MQTT (home/Security/Motion/Living)
7:27:59 AM | Processing MQTT (home/Security/Motion/Living)
7:28:16 AM | Push blocked (Send:False, Enabled:True, Connected: False)
7:28:16 AM | Processing MQTT (home/Security/Motion/Living)
7:33:41 AM | Push blocked (Send:False, Enabled:True, Connected: False)
7:33:41 AM | Processing MQTT (home/Security/Motion/Living)
7:34:32 AM | Processing MQTT (home/Security/Motion/Living)
7:36:36 AM | Push blocked (Send:False, Enabled:True, Connected: False)
7:36:36 AM | Processing MQTT (home/Security/Motion/Living)
7:36:40 AM | Processing MQTT (home/Security/Motion/Living)
7:39:02 AM | Push blocked (Send:False, Enabled:True, Connected: False)
7:39:02 AM | Processing MQTT (home/Security/Motion/Living)
7:39:21 AM | Processing MQTT (home/Security/Motion/Living)
7:40:16 AM | Push blocked (Send:False, Enabled:True, Connected: False)
7:40:16 AM | Processing MQTT (home/Security/Motion/Living)
7:41:03 AM | Processing MQTT (home/Security/Motion/Living)
7:41:24 AM | Push blocked (Send:False, Enabled:True, Connected: False)
7:41:24 AM | Processing MQTT (home/Security/Motion/Living)
7:43:41 AM | Apply profile Disabled
7:46:38 AM | Apply profile Disabled
7:48:42 AM | MQTT disconnected
7:48:47 AM | Connecting MQTT
7:48:47 AM | Connected to MQTT server

The iSpyAgent is running on a docker that runs on my NAS. My NAS is not showing any signs or warnings of disconnects, so I don't think it's a networking issue.

ispysoftware commented 1 year ago

what makes you think mqtt is disconnecting?

titiviking commented 1 year ago 
7:48:42 AM | MQTT disconnected
7:48:47 AM | Connecting MQTT
7:48:47 AM | Connected to MQTT server
ispysoftware commented 1 year ago

oh right i didn't see that you could try decreasing the check interval in mqtt settings

titiviking commented 1 year ago

How about those entries: 7:40:16 AM | Push blocked (Send:False, Enabled:True, Connected: False)

does it mean that the push to MQTT is blocked and therefore the event is not published? or does it has a differnet meaning in the iSpyAgent implementation ?

ispysoftware commented 1 year ago

no it's just debug saying that a push notification (ios/ android) hasn't been sent

titiviking commented 1 year ago

I've performed a reboot again over the week and kept an eye out on the logs... I still keep on seeing many ONVIF disconnects... The camera app does not show disconnects and the feed keeps on going, even when iSpyAgent detects a connection failure...

Any idea what I could look at? I've checked my network, but I don't see packet loss or interference happening.

ispysoftware commented 1 year ago

Usually this means the camera app is connecting to a different endpoint and the ONVIF implementation on it is buggy. You can try scanning the camera for alternate feeds using the wizard.

If this was a bug in Agent's ONVIF code then everyone would be seeing the same thing..