got a little progress with GIF - thank You for the guidance!
added getActions("ipcamera", "ipcamera:onvif:Darzs").recordGIF("ipcamera",5) in the rules as reaction to test switch change from habpanel.
Interesting that with preroll>0 it was not making the actual gif. As i changed preroll=0, the /ipcamera.gif was showing up (and I also saw 10snapshot images and the .gif file in output folder). tried making longer gif and shorter postroll, but not sure if it worked out for me. With preroll specifid, pollTime is set by default and I do not need to add it? Will keep reading:)
it looks like, with ipcamera thing enabled, it still hangs my openhab (this is having rtsp auth set to basic and http to none and with the /ipcamera.jpg and /snapshots.mjpeg working fine)
2020-09-22 08:40:13.610 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.CommunicationManager@744f26' takes more than 5000ms.
2020-09-22 08:40:27.856 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@ea47c9' takes more than 5000ms.
2020-09-22 08:41:53.087 [WARN ] [era.internal.handler.IpCameraHandler] - !!!! Camera possibly closed the channel on the binding, cause reported is: Java heap space
Try uninstalling the binding, and using the jar file from this link, placing it in the addons folder. This build has a fix for the gif recording and it also uses uppercase on the headers. If you can try it with digest turned on that would be great.
hohoho, digest auth mode and your latest build - and /ipcamera and /snapshots are working now!!!
Here is also the log file. ipcamera_20200922_capitalletters.log (431.3 KB)
the system still hangs out of memory after some 5-8minutes
With gif’s - my feeling is, with preroll>0 it’s still not generating the file. As soon as I change preroll=0, save the things file, change the test switch - the file shows up in folder and is available after little later
Then it is confirmed your camera is breaking http convension by not treating headers as case insensitive. I believe in the future this will become very important as they must be all lowercase with HTTP/2 which is being released. Report this to your camera support to pass onto their firmware development.
I will need to look into your second issue which is asking for the gif repeatedly when it does not exist. That may be a bug as it should handle it gracefully. Have not tested this yet.
My guess is your not using the feature correctly as it was recently was changed from a aswirch to aN action. How are you starting the file to be recorded and please see the example in the docs.
I will definetly submit a ticket/report it to UniView team. Well, at least try to.
For gif - I am pretty sure I may have some config issues and appologies if so. I was trying to follow the doc, so I have a test switch to simulate the pir event.
And then the rule which, when test switch changed, calls action:
getActions(“ipcamera”, “ipcamera:onvif:Darzs”).recordGIF(“ipcamera”,6)
I have noticed that sometimes it complains the rule is not a ipcamera instance or something similar, if you reboot openHAB that fixes it. I have not looked at your logs but please put them back to INFO level now the issue with auth is solved.
EDIT:
looked at your log and it appears the ONVIF events are talking way too often. Can you try giving the camera the wrong ONVIF port so it fails to talk with onvif? If you manually supply the URLs it should still work minus the events and hopefully that solves the OOME and will narrow down where to look.
I have not had a chance to play around w ipcamera settings yet, but I got a suspicioysly fast response from uniview with a newer fw version - will be eager to try.
Happy to downgrade log level. That TRACE was driving me crazy even if turned on only for experiments:) I wonder if onvif event load is due to misfiring human&motion detection or smtg else - will also try to disable both at camera and see if it gets rid of them
with the new firmware and 0922 binding (I guess, not beeing able to check if new fw changed header handling).
turned off all events I could on camera side, but not touching onvif port in .things yet.
with gifPreroll=1 and gifPostroll=15 (do I read it correctly postroll is not doing anything anymore?)
the getAction call creates this in the log
Recording ipcamera.gif for 6 seconds.
but nothing else happens; no file created in output folder nor RecordingGIF changing back from 6.
changed gifPreroll=0 and saved .things file (the second ‘refreshing model’ occurrence).
getAction called, recording gif appears in logs, followed by ffmpeg call.
.gif file created in output folder (no snapshot files).
If I understand it correctly - significantly less onvif events reported. But the openhab noticably slows down over 5+ minutes (.things save reported in log with delay, same as test switch change//getAction call)
looks like now gif’s not beeing created w neither preroll=0 nor =1 … but it s because ffmpeg url not detected from onvif (whic hmeans it was not using snapshot, right?)
2020-09-23 23:58:00.373 [DEBUG] [era.internal.handler.IpCameraHandler] - File server for camera at 192.168.60.250 has started on port 54321 for all NIC's.
2020-09-23 23:58:00.535 [DEBUG] [amera.internal.onvif.OnvifConnection] - Camera is not reachable on ONVIF port:888 or the port may be wrong.
2020-09-23 23:58:04.336 [WARN ] [.server.impl.connections.HttpSession] - Unrecognized request for /pair-verify
2020-09-23 23:58:04.444 [DEBUG] [era.internal.handler.IpCameraHandler] - About to connect to the IP Camera using the ONVIF PORT at IP:192.168.60.250:888
2020-09-23 23:58:04.480 [DEBUG] [amera.internal.onvif.OnvifConnection] - Camera is not reachable on ONVIF port:888 or the port may be wrong.
2020-09-23 23:58:07.351 [DEBUG] [amera.internal.onvif.OnvifConnection] - Camera is not reachable on ONVIF port:888 or the port may be wrong.
...
2020-09-23 23:58:57.195 [INFO ] [se.smarthome.model.script.Buuda sign] - Test update to ON
2020-09-23 23:58:57.208 [DEBUG] [ng.ipcamera.internal.IpCameraActions] - Recording ipcamera.gif for 6 seconds.
2020-09-23 23:59:07.109 [DEBUG] [era.internal.handler.IpCameraHandler] - About to connect to the IP Camera using the ONVIF PORT at IP:192.168.60.250:888
2020-09-23 23:59:07.199 [DEBUG] [amera.internal.onvif.OnvifConnection] - Camera is not reachable on ONVIF port:888 or the port may be wrong.
...
2020-09-24 00:00:12.224 [INFO ] [el.core.internal.ModelRepositoryImpl] - Refreshing model 'ipcamera.things'
2020-09-24 00:00:15.790 [DEBUG] [era.internal.handler.IpCameraHandler] - File server for camera at 192.168.60.250 has started on port 54321 for all NIC's.
2020-09-24 00:00:15.862 [DEBUG] [amera.internal.onvif.OnvifConnection] - Camera is not reachable on ONVIF port:888 or the port may be wrong.
2020-09-24 00:00:19.816 [DEBUG] [era.internal.handler.IpCameraHandler] - About to connect to the IP Camera using the ONVIF PORT at IP:192.168.60.250:888
...
2020-09-24 00:00:25.849 [WARN ] [era.internal.handler.IpCameraHandler] - The camera tried to use a FFmpeg feature when no valid input for FFmpeg is provided.
...
2020-09-24 00:00:38.638 [INFO ] [se.smarthome.model.script.Buuda sign] - Test update to OFF
2020-09-24 00:00:38.648 [DEBUG] [ng.ipcamera.internal.IpCameraActions] - Recording ipcamera.gif for 6 seconds.
2020-09-24 00:00:40.727 [DEBUG] [ipcamera.internal.MyNettyAuthHandler] - Camera reported stale=true which normally means the NONCE has expired.
2020-09-24 00:00:43.847 [WARN ] [era.internal.handler.IpCameraHandler] - The camera tried to use a FFmpeg feature when no valid input for FFmpeg is provided.
2020-09-24 00:00:46.328 [DEBUG] [amera.internal.onvif.OnvifConnection] - Camera is not reachable on ONVIF port:888 or the port may be wrong.
With the wrong onvif port, not seeing the Selector.select() returned prematurely 512 times in a row; rebuilding Selector io.netty.channel.nio.SelectedSelectionKeySetSelector@1e73c9f. warnings anymore and not feeling it becoming slower.
EDIT: nope, wrong observation (wishful thinking). Some dozen minutes later
2020-09-24 00:13:25.144 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.config.discovery.internal.AutomaticInboxProcessor@3c7892' takes more than 5000ms.
2020-09-24 00:14:46.577 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@120d1b7' takes more than 5000ms.
2020-09-24 00:14:24.730 [WARN ] [t.mqtt.internal.MqttBrokerConnection] - MQTT connection to 'mqtt' was lost: Connection lost : ReasonCode 32109 : Cause : null
2020-09-24 00:14:22.232 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = b1a93b6e-c9cf-4079-86e1-fb39eeeac023, base URL = http://localhost:8080)
2020-09-24 00:14:17.515 [WARN ] [netty.util.concurrent.DefaultPromise] - An exception was thrown by org.openhab.binding.ipcamera.internal.handler.IpCameraHandler$2.operationComplete()
java.lang.OutOfMemoryError: Java heap space
Can you remove the binding and test to see if the OOME still occurs? It may not be the binding that causes it, but since the binding needs a lot of ram it could be the first to try and use ram when it has run out.
If you provide the snapshot and ffmpeg input URLs manually to the binding it should work with the wrong Onvif port set. You will lose event and PTZ features but the rest can work.
I can leave the binding as is, just commenting out my ipcamera .thing, restart and the OOME is gone. Running overnight w/out any symptoms.
The Unrecognized request for /pair-verify - interesting that I do not recall seeing it ever before (checked the log files since last week and don’t have it; could be just one-of)
Miio - nope, do not have it.
Only other little weird behavior I’m observing on my system - openhab cloud disconnect ~every two hours. But, I guess, it should not impact the OOME happening after fresh restart, as long as the disconnect has not taken place
2020-09-24 06:08:23.020 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = b1a93b6e-c9cf-4079-86e1-fb39eeeac023, base URL = http://localhost:8080)
2020-09-24 06:08:24.254 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = b1a93b6e-c9cf-4079-86e1-fb39eeeac023, base URL = http://localhost:8080)
2020-09-24 06:08:41.471 [INFO ] [control.internal.WebSocketConnection] - Web Socket close 1006. Reason: Disconnected
2020-09-24 06:08:41.471 [INFO ] [control.internal.WebSocketConnection] - Web Socket error
org.eclipse.jetty.io.EofException: null
yesssss, added ffmpegInput="rtsp://192.168.60.250/media/video1"` and looks like it is creating gif as well. On first attempt I had a feeling with gifPreroll=1 it is never generating the file in output folder, but maybe I was just too impatient, dunno. After I changed gifPreroll=0; checked it is working; gifPreroll=2; was working with snapshot images; restarted openhab and still is working with Preroll=2.
Could it be bug with how/when the preroll images are added? In my case the generated gif has this sequence of :seconds in frames
:32
:31
:31
:33
:34
:35
:36
:37
Re gif from snapshot bug, I don’t know I would need to look when I have some time as I only do 5 second recordings. It is possible that the camera takes longer to reply to some requests then others and this means the pictures come back in a different order. You did state (do i remember correct?) once your camera was not taking a consistent time to reply with a snapshot and that may be the cause.
Regarding OOME we need to solve this one first as you can not trust a system that this has occurred on. Forget other issues until you no longer run out of heap space…
The only time I has seen this is when using the image channel, do not use the image channel.
How did you setup the PI3? Did you use openhabian or do it yourself? What is your heap size?
See this post on how to check and increase the heap size.
gif - yeah, it could be some delays in snapshot request responses. sounds very likely, indeed.
(meanwhile I tested the new camera fw with 0917 version of binding - and it was still not working, so no header cases fix, I presume. I wonder, for uniview devs, what’s the easiest way how I can showcase it w/out the openhab? If I make https://gitlab.com/gnuwget/wget2 and it is not downloading and regular wget is downloading the snapshot from camera - that should be enough?)
I believe I’m not using image channel, but will re-check my items file that I do not have it there from some early experiments.
OOME - Thank You so much for guidance and linked post … I will have at least few commands to try out. What is interesting - with onvif off and direct snapshot and ffmpeg links, I’m not seeing signifcant slowdown after few minutes, not even mentioning OOM. Will leave it running and see if it pops up again.
On one occasion during today I had a feeling I’m seeing “20channels open” and a “Selector.select() returned prematurely 512 times” message again around the same time as ptp link was reporting beeing down for a second or less … could that be related - camera not responding/leaving something leaking?
re PI3 setup - that was loooong ago. I believe it was openabian, definetly not me manually.
JVM
Java Virtual Machine OpenJDK Client VM version 25.265-b11
Version 1.8.0_265
Vendor Azul Systems, Inc.
Pid 7809
Uptime 1 hour 32 minutes
Process CPU time 18 minutes
Process CPU load 0.00
System CPU load 0.07
Open file descriptors 448
Max file descriptors 102,642
Total compile time 2 minutes
Threads
Live threads 276
Daemon threads 152
Peak 288
Total started 4776
Memory
Current heap size 229,640 kbytes
Maximum heap size 241,536 kbytes
Committed heap size 241,536 kbytes
Pending objects 0
Garbage collector Name = 'Copy', Collections = 189, Time = 8.859 seconds
Garbage collector Name = 'MarkSweepCompact', Collections = 110, Time = 3 minutes
Classes
Current classes loaded 21,621
Total classes loaded 22,396
Total classes unloaded 775
Operating system
Name Linux version 4.19.66-v7+
Architecture arm
Processors 4
8h later and no signs of OOME so far.
Have had few “Selector.select() returned prematurely 512 times” logs during the time, but just few.
Have to admit have not uses ipcamera features extensively during the day - there were no pir/motion events that woulf cause gif creation. Just a ocasional habpanel widget use and maybe m3u8 stream to chromecast.
Eager to see what happens overnight:)
I only get 1 a week and never see issues when that occurs. It is possible this occurs if the camera is busy in the middle of opening a channel up, but since I don’t see it often enough I cant run tests here to confirm. Ignore this if it is not happening very often.
After you have increased the heap size, either it will fix the issue if the heap was too small or it may simply take longer for the OOME to occur. You can use the shell:info command to see if the threads are going out of control or if the heap size keeps growing and never shrinks back when ‘garbage collection’ occurs. Hopefully it was just a case of you needing more heap space.
What is interesting - that I did not increase the heap size yet.
so overnight have 5 or 6 “selector.select()” errors spread across the log. But other than that, can’t feel any degradation.
No idea yet how to read the threads information and how much is “too much” can see a little increase comparing to yday after rstart, but maybe thats normal? will see in evening again.
Threads
Live threads 331
Daemon threads 148
Peak 355
Total started 55148
12 more hours … Threads look the same.
Spotted ~40 .ts files created in ffmpegOutput folder … timing feels related with habpanel’s clickable camera widget usage?
Threads
Live threads 331
Daemon threads 151
Peak 355
Total started 89094
Memory
Current heap size 221,868 kbytes
Maximum heap size 241,536 kbytes
Committed heap size 241,536 kbytes
Pending objects 0
Garbage collector Name = 'Copy', Collections = 767, Time = 5 minutes
Garbage collector Name = 'MarkSweepCompact', Collections = 2102, Time = 1 hour 12 minutes
Classes
Current classes loaded 22,960
Total classes loaded 29,609
Total classes unloaded 6,649
Can just confirm not seeing any signs of OOM after few days (have not touched the heap size yet).
Yesterday also turned on onvif on binding side (fixed onvif port), still all event detection off at camera side. No slow down overnight.
can see a little increase comparing to yday after rstart, but maybe thats normal? will see in evening again.