Many disconnect and failure in ONVIF events
titiviking opened this issue · 9 comments
titiviking commented
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: <tt:Source xmlns:tt="http://www.onvif.org/ver10/schema"><tt:SimpleItem Name="Source" Value="VideoSource000"></tt:SimpleItem></tt:Source><tt:Data xmlns:tt="http://www.onvif.org/ver10/schema"><tt:SimpleItem Name="State" Value="false"></tt:SimpleItem></tt:Data> |
| 11:30:44 AM | ONVIF Received: <tt:Source xmlns:tt="http://www.onvif.org/ver10/schema"><tt:SimpleItem Name="Source" Value="VideoSource000"></tt:SimpleItem></tt:Source><tt:Data xmlns:tt="http://www.onvif.org/ver10/schema"><tt:SimpleItem Name="State" Value="false"></tt:SimpleItem></tt:Data> |
| 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: <tt:Source xmlns:tt="http://www.onvif.org/ver10/schema"><tt:SimpleItem Name="Source" Value="VideoSource000"></tt:SimpleItem></tt:Source><tt:Data xmlns:tt="http://www.onvif.org/ver10/schema"><tt:SimpleItem Name="State" Value="false"></tt:SimpleItem></tt:Data> |
| 11:32:18 AM | ONVIF Received: <tt:Source xmlns:tt="http://www.onvif.org/ver10/schema"><tt:SimpleItem Name="Source" Value="VideoSource000"></tt:SimpleItem></tt:Source><tt:Data xmlns:tt="http://www.onvif.org/ver10/schema"><tt:SimpleItem Name="State" Value="false"></tt:SimpleItem></tt:Data> |
| 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
Usually means your camera needs a reboot
titiviking commented
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
what makes you think mqtt is disconnecting?
titiviking commented
7:48:42 AM | MQTT disconnected
7:48:47 AM | Connecting MQTT
7:48:47 AM | Connected to MQTT server
ispysoftware commented
oh right i didn't see that
you could try decreasing the check interval in mqtt settings
titiviking commented
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
no it's just debug saying that a push notification (ios/ android) hasn't been sent
titiviking commented
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
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..