[IPcamera] Doorbird Camera Things going offline / not getting back online

Add-ons Bindings
, ,
1

Hi there,

My Doorbrid device Things connected via IPcamera binding are getting offline from time to time. It seems to be working sometimes for a few days and sometimes only one day or so. Since the devices are doorbells it is hard to assess properly since they are not in action regularly and / or all the time.

Error description:
The Things are going offline and the following error is shown in Main UI:
ipcam_error_offline

The IP and PORT are correct and nothing has been changed in the setup. When pausing the Things and re-activating them after a few seconds, they’re getting back online and working properly.

As discussed with @matt1, I set the binding to log level TRACE in order to check what happens. Please find the relevant logs between the time when the Things were definetely working (Mail with a snapshot was send) and the time were it was definetly not working anymore (Mail with broken picture only was send):

Working properly, proved by detected motion snapshot:

2022-03-13 19:48:07.039 [INFO ] [.model.script.DoorbirdHaustuer_IPcam] - Motion detected at Haustuer

then tons of those messages:

2022-03-13 19:48:08.258 [TRACE] [era.internal.handler.IpCameraHandler] - HTTP Result back from camera is 	:--ioboundary
Content-Type: text/plain

doorbell:L

--ioboundary
Content-Type: text/plain

motionsensor:L

not sure whether this is relevant in this case or not, but to be 100% safe let me share the following error also:

2022-03-14 03:20:51.521 [ERROR] [io.openhabcloud.internal.CloudClient] - Error during communication
2022-03-14 03:20:51.521 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = XXX, base URL = http://localhost:8080)
2022-03-14 03:20:52.990 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = XXX, base URL = http://localhost:8080)

I am posting this, since before and after this log, there where a lot of errors from http binding. It seems somewhen in the night, the http binding failed somehow.

However, the first WARN log from IPcamera binding was > half an hour later. The connection was closed by remotehost:

2022-03-14 04:08:24.379 [WARN ] [era.internal.handler.IpCameraHandler] - !!!! Camera possibly closed the channel on the binding, cause reported is: Eine vorhandene Verbindung wurde vom Remotehost geschlossen

In the morning, there was a DEBUG message. When I remember correctly, I’ve seen those messages also when the binding was working. So I guess it is also not related to the offline issue:

2022-03-14 07:20:32.125 [DEBUG] [hab.binding.ipcamera.internal.Ffmpeg] - [mp4 @ 000001caecccc040] Non-monotonous DTS in output stream 0:0; previous: 0, current: -7636; changing to 1. This may result in incorrect timestamps in the output file.
2022-03-14 07:20:32.328 [DEBUG] [hab.binding.ipcamera.internal.Ffmpeg] - [mp4 @ 000001a7c97a00c0] Timestamps are unset in a packet for stream 0. This is deprecated and will stop working in the future. Fix your code to set the timestamps properly

Then a motion event happend, and the snapshot sent by Mail was a grey dot only:

2022-03-14 08:14:04.039 [INFO ] [re.model.script.DoorbirdPforte_IPcam] - Motion detected at Pforte

I guess the time of interest is 04:08:24.379 when the connection is closed. What exactly does this mean? Or is it somehow standard but the connection should be established again and does not?

When it’s helpfull I can of course share the whole log file by PM also.

Regards,
Sascha

2

I think the best approach is to look at this as two things.

  1. What causes the camera to go offline?
  2. Why does the camera not come back online automatically? This is what should happen.

So try to get some TRACE level log output with all other cameras PAUSED so they dont make confusing log lines when the issue is already occurred, and we can hopefully get an answer to point number 2. This may be enough to work out a theory as to why it happens in the first place so we don’t need to get log output when point 1 occurs.

From memory you have multiple Doorbird cameras, does this happen with them all or just 1 of them?

3

I have two Doorbird Doorbells (different versions) and both are going offline.

The TRACE logs are shown above, can you see any hint already?

If required I can pause one of the devices, but I fear this will just increase the time frame leading me recognizing that the the Thing is offline as there are less events. As you can see in the logs above the last working snapshot comes from a different device than the first not working one.
I (hopefully) shared all logs related to the issue. However, if it will be helpfull for you, I can send you the whole log file also. Then you maybe can better check what happens when exactly. Or in worst-case if I missed something to share. Just let me know.

Thanks!

4

Do you see the camera in the TRACE logs trying to re-connect every 60 seconds by trying to fetch a snapshot?
Can you provide the JSON of the cameras settings so I can see if you have over ridden any default settings?

5

Assuming the cameras went offline at this time:

2022-03-14 04:08:24.379 [WARN ] [era.internal.handler.IpCameraHandler] - !!!! Camera possibly closed the channel on the binding, cause reported is: Eine vorhandene Verbindung wurde vom Remotehost geschlossen

There are no regular logs after that anymore. Also not this one (which appears before roughly every 10seconds):

2022-03-14 02:08:22.747 [TRACE] [era.internal.handler.IpCameraHandler] - HTTP Result back from camera is 	:--ioboundary
Content-Type: text/plain

doorbell:L

--ioboundary
Content-Type: text/plain

motionsensor:L

:

The next logs appear just when an event occurs (motion, …). So if my understanding is correctly there is no re-connection trial.

I’ve send you the log file from yesterday evening until today morning in a PM. Roughly at 08:26 I paused the Things and re-activated them. I did not check the exact time, this is just an assumption based on the logs.

I know the TRACE log is really heavy, but maybe a total overview is more helpfull. As starting point you can check the hour and minutes from my logs posted above. Additionally I’ve added a few remarks. Just CTRL+F for “remark”.

I’ve also send the JSON data - please let me know if this is what you need since I am not 100% sure.

Thanks!

6

Hi @matt1, did you find any hint meanwhile? Is there anything I can do in order to support you (send further logs, try anything,…?)?

7

Correct, something must have gone wrong and stopped the thread that keeps trying to reconnect. Does it detect online and offline correctly and automatically if you disconnect the cable or power to the camera?

I would need to know more details as to what causes the original problem in the first place, the good news is that when the error occurs you will probably find the TRACE logs will stop making it easy to find what happen last before it had an error.

8

The Thing goes OFFLINE instantly when the Doorbird is powered off. Main UI shows the same error:
ipcam_error_offline

But: it stays OFFLINE and does not come back to ONLINE automatically when the device has been restarted! When I disable the Thing in Main UI, wait a few seconds and enable - it’s working again. So same behaviour than the issue described above - but sort of manually, not automatically.

The TRACE logs do not stop in this case (manual stop) and the only entry is following which repeats every few seconds:

2022-04-04 12:58:45.367 [TRACE] [era.internal.handler.IpCameraHandler] - HTTP Result back from camera is 	:--ioboundary
Content-Type: text/plain

doorbell:L

--ioboundary
Content-Type: text/plain

motionsensor:L

:

There is no other log and no difference whether the thing is ONLINE or OFFLINE (powered off manually).

I’ve sent you full TRACE log a few weeks ago, did you have a look at it? To be honest I checked the logs a few times meanwhile, I cannot find anything obivious - at least it’s not ovious for me as beginner.

I’ll keep TRACE log, any other log-messages by a rule are disabled, so I can send you a further log when the error appears again. Should be in 1-2 days.

Edit: I am just wondering… I have two Doorbird devices, so maybe the above mentioned logs belong to the second one (which was not powered off)! That means, it is likely that the TRACE log stops in this case also (for the device which was powered off).

9

Please find an update from my side - TRACE logs from yesterday:

The logs are ending at 2022-04-05 03:27:12.491 ==> this is the time were the second or both (1) cameras went OFFLINE!

Starting from this time to earlier, the following logs appear:

  1. periodic message every 20 seconds (2):
2022-04-05 03:26:52.492 [TRACE] [era.internal.handler.IpCameraHandler] - HTTP Result back from camera is 	:--ioboundary
Content-Type: text/plain

doorbell:L

--ioboundary
Content-Type: text/plain

motionsensor:L

:
  1. At 03:00:59.063 the following message appears the last time (before 03:00h - every 20 seconds, and ONLY for camera 19216817886, not for the second one 19216817834) (2):
2022-04-05 03:00:59.063 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler IpCameraHandler of thing ipcamera:doorbird:19216817886 tried updating channel doorBell although the handler was already disposed.
2022-04-05 03:00:59.063 [WARN ] [.core.thing.binding.BaseThingHandler] - Handler IpCameraHandler of thing ipcamera:doorbird:19216817886 tried updating channel motionAlarm although the handler was already disposed.
  1. Approx. 100 of the following messages appear at 22:14:35:
2022-04-04 22:14:35.725 [DEBUG] [camera.internal.servlet.StreamOutput] - FIFO buffer has run out of space:Queue full

That’s it. As already mentioned I can’t detect any hint for the issue. Especially since the logs just end witout any error. And all logs which seems to appear like an error are far earlier and so often that I don’t think they have something to do with the Things getting offline.

Hopefully you will find something and / or have another idea what I could try @matt1
I’ll send you the whole logs via PM. I recommend to CTRL+F for ‘2022-04-05 03:27:12.491’ - scrolling up = the time before the Thing went offline / scrolling down = logs when Things were manually disabled (==> many java / http errors) and enabled (trace logs continue) in Main UI,

REMARKS:

(1) Maybe it makes sense to add the Thing-ID or anything else specific for each camera to the following periodic log in order to make it clear to which camera this log belogs:

2022-04-05 03:27:12.491 [TRACE] [era.internal.handler.IpCameraHandler] - HTTP Result back from camera is 	:--ioboundary
Content-Type: text/plain

doorbell:L

--ioboundary
Content-Type: text/plain

motionsensor:L

:

(2) looking at the afternoon logs, they’re appearing more often than every 20 seconds, so I guess at the time mentioned above one of the cameras was already offline. The second one went offline at 03:27:12.491.

Edit 2022-04-08:
This night the cameras became offline again. Here are the logs of the time one or both cameras appear offline at 03:18:28.275. The next log entry is from 05:11:24.412 - there is nothing in between those two:

2022-04-08 03:18:28.275 [TRACE] [era.internal.handler.IpCameraHandler] - HTTP Result back from camera is 	:--ioboundary
Content-Type: text/plain

doorbell:L

--ioboundary
Content-Type: text/plain

motionsensor:L

:

2022-04-08 05:11:24.412 [WARN ] [era.internal.handler.IpCameraHandler] - !!!! Camera possibly closed the channel on the binding, cause reported is: Eine vorhandene Verbindung wurde vom Remotehost geschlossen

At 05:28 I disabled / enabled the things manually. TRACE logs are availabe of this procedure if it’s requested?

10

Ok then please try the build here with a change that may help.
Index of /openhab/IpCameraBinding/ (pcmus.com)

First lets fix the issue of it not detecting online and offline correctly, it may be the same issue for both problems but it will be quicker to reproduce unplugging a cable and putting it back in.

You will need to install the Telstick binding, and uninstall the merged ipcamera binding before you unzipped that to your addons folder.

1 Like
11

Thanks for the build - it works for the offline / online status when powering off / on the camera. Let’s see whether the actual problem is solved also. I will give you a feedback within the next days.

12

After several days now, I can confirm that the updated version of the binding solved the original issue - the Doorbird things stay online (getting back online when were offline due to some reason). Thanks for your support @matt1!