2.5 Milestone 6 Issues

Try clearing browser cache?

I didn’t attempt to clear the browser cache no, I did however -

  • Force Reload
  • Try on three separate devices (Firefox browser, Android app and iphone app)
  • Check the browser console for errors (only warning about source map errors)

Moving back to M5 has indeed fixed the issue, so its something introduced since M5, I don’t know if its a UI issue or a symptom of something else.

That’s a really old and insecure Java version from 2015 :open_mouth:. You might want to update your Java version to something more recent.

1 Like

Just a heads up - I updated to m6 by accident today (happened to look at my computer and saw an update service box asking if I wanted to install updates so I hit yes) once it updated all my items were not responding and showed “uninitialized”. Turns out all my bindings and other add-ons where not installed. I reinstalled and all is well. If your items aren’t working might want to check that!

Thanks for pointing this out.
I had a bunch of more recent JREs installed, moved this machine to become my OH server, and did not notice that OH kept on accessing the 1.8.40 version from an old and otherwise unused JDK.
I updated to a current Java 8 (Zulu).
(This also seems to have fixe my problem with the Unifi binding)
Clemens

2 Likes

Since I updated to M6 I can see that my rules get reloaded at seemingly random intervals. This causes a spike in CPU and delays actions by openhab. I am on a Raspberry Pi 3B+. In my rule files I have sections like the following.

rule "System started Rule assistant"
when
        System started 
then
       	logInfo("System started Rule", "phone done")
end

The reason I have these sections it that it helps with the delay in rules firering the first time they get triggered. However, now I see that my rules started reloading. I see this happening at

  • 2019-12-03 02:10
  • 2019-12-03 04:11
  • 2019-12-03 06:11
  • 2019-12-03 08:12
  • 2019-12-03 10:12
  • 2019-12-03 12:13
  • 2019-12-03 14:13
  • 2019-12-03 16:01
  • 2019-12-03 18:14

All in all this makes openhab pretty unresponsive, as all rules get reloaded. This didn’t used to happen. The only point when rules were reloaded was on starting and stopping openhab.

Does anyone have an idea what is going on?

Is that all the rules or only the ones with the System started trigger?

All rules have the System started trigger. However, not all rules are reloaded. I have 55 rule files and if I counted correctly 47 get reloaded. I cannot find a connection between the rules that get reloaded or the rules that don’t.

I had a similair issue. Only a few items loaded in the sitemap. I did only a sudo apt-get upgrade. Afther i Started openhabian-config and did an upgrade system. And it whas fixed.

New to posting here, so my apologies ahead of time for the length, I wanted to provide as much insight possible ahead of time. Recently I had a hankering to tinker and recently upgraded my OH to 2.5 M6 from stable 2.4. Everything came up fine initially, and about an hour in all my devices went offline. I let it sit for the night. Woke up, things were back online, then within 60 minutes, went offline. I went to my pi, the console appeared locked. Couldn’t log in, hitting enter didn’t even bring up fresh login prompt. Rebooted the device. All came up well, everything online, able to be controlled, got ready for work and noticed the z-wave devices were offline, terminal seemed fine and had to get to work so I left it be. Since then I’ve been periodically checking on it and it appears the pi is staying up, but the openhab instance itself is having the issues. Essentially the services are dying off every couple of hours, staying offline for a couple hours and then back online for a couple hours. Sometimes, when this happens, it appears to be fully killing connectivity with the box. No SSH, but will respond to pings.

The last time I could ssh in I grabbed the events.log and openhab.log so I could upload snippets, but was wondering if there were other logs I should be grabbing for better visibility? I’ve sanitized the data below of what I saw.

Hardware from SSH summary banner:

###############  openhab  #####################################################
###############################################################################
        Ip = xx
   Release = Raspbian GNU/Linux 10 (buster)
    Kernel = Linux 4.19.75-v7+
  Platform = Raspberry Pi 3 Model B Plus Rev 1.3
    Uptime = 0 day(s). 9:12:16
 CPU Usage = 100% avg over 4 cpu(s) (4 core(s) x 1 socket(s))
  CPU Load = 1m: 5.29, 5m: 8.07, 15m: 6.74
    Memory = Free: 0.03GB (3%), Used: 0.92GB (97%), Total: 0.95GB
      Swap = Free: 0.01GB (19%), Used: 0.07GB (81%), Total: 0.09GB
      Root = Free: 25.03GB (89%), Used: 2.83GB (11%), Total: 29.07GB
   Updates = 0 apt updates available.
  Sessions = 1 session(s)
 Processes = 121 running processes of 32768 maximum processes
###############################################################################

Bindings Installed - none from market to my knowledge. All installed prior to upgrade as well:

Dresden Elektroniks -Deconz (conbeeII Zigbee stick) - David Graef
Harmony Hub - Dan Cunningham
Hue Bridge - Deutsche Telekom
Network Binding - Marc Mettke, David Graf
Onkyo binding - Paul Frank, Pauli Antilla
Plex Binding - Jeron Idserda
Sonos Binding - Karel Goderis
TP-Link Smart Home Binding - Hilbrand Bouwkamp, Christian Fischer
Z-Wave Binding - Chris Jackson

The box just came back to a connectable state, so I was looking for other ideas of logs to grab and review.

Logs I’ve grabbed:
/var/log/daemon.log
/var/log/kern.log
/var/log/syslog
/var/log/openhab2/events.log
/var/log/openhab2/openhab.log

Below are the snips that started appearing in the various logs after the upgrade, but after looking at kern.log it almost appears that Java itself is being killed off by the system due to exceeding memory usage. I just logged out and back in, when I started grabbing logs 1.5 hours ago, cpu was 42% over all 4 cores, I wasn’t smart enough to make note of memory consumption before exhausting my scroll back buffer. I grabbed sections from the most recent exhaustion state to coming back online.

daemon.log:

Dec  3 13:51:29 openhab karaf[30308]: java.lang.NullPointerException
Dec  3 13:51:29 openhab karaf[30308]: #011at org.openhab.binding.zwave.discovery.ZWaveDiscoveryService.deviceAdded(ZWaveDiscoveryService.java:196)
Dec  3 13:51:29 openhab karaf[30308]: #011at org.openhab.binding.zwave.discovery.ZWaveDiscoveryService.ZWaveIncomingEvent(ZWaveDiscoveryService.java:257)
Dec  3 13:51:29 openhab karaf[30308]: #011at org.openhab.binding.zwave.internal.protocol.ZWaveController.notifyEventListeners(ZWaveController.java:566)
Dec  3 13:51:29 openhab karaf[30308]: #011at org.openhab.binding.zwave.internal.protocol.ZWaveController$ZWaveInitNodeThread.run(ZWaveController.java:472)
Dec  3 14:35:20 openhab systemd-udevd[145]: ttyACM2: Worker [9599] processing SEQNUM=1420 is taking a long time
Dec  3 14:35:20 openhab systemd[1]: openhab2.service: Main process exited, code=killed, status=9/KILL
Dec  3 14:35:20 openhab systemd[1]: openhab2.service: Failed with result 'signal'.
Dec  3 14:35:20 openhab systemd-udevd[145]: ttyACM2: Worker [9599] processing SEQNUM=1420 killed
Dec  3 14:35:20 openhab systemd-udevd[145]: 1-1.3:1.1: Worker [9647] processing SEQNUM=1421 killed
Dec  3 14:35:20 openhab systemd-udevd[145]: 1-1.3:1.1: Worker [9647] processing SEQNUM=1421 is taking a long time
Dec  3 14:35:20 openhab systemd-udevd[145]: Worker [9599] terminated by signal 9 (KILL)
Dec  3 14:35:20 openhab systemd-udevd[145]: Worker [9647] terminated by signal 9 (KILL)
Dec  3 14:35:20 openhab systemd-udevd[145]: 1-1.3:1.1: Worker [9647] failed
Dec  3 14:35:26 openhab systemd[1]: openhab2.service: Service RestartSec=5s expired, scheduling restart.
Dec  3 14:35:26 openhab systemd[1]: openhab2.service: Scheduled restart job, restart counter is at 3.
Dec  3 14:35:26 openhab systemd[1]: Stopped openHAB 2 - empowering the smart home.
Dec  3 14:35:26 openhab systemd[1]: Started openHAB 2 - empowering the smart home.
Dec  3 14:35:28 openhab deCONZ[344]: This plugin does not support propagateSizeHints()
Dec  3 14:35:39 openhab karaf[9725]: org.ops4j.pax.url.wrap [org.ops4j.pax.url.commons.handler.HandlerActivator] DEBUG : Handler for protocols [wrap] started
Dec  3 14:37:00 openhab deCONZ[344]: This plugin does not support propagateSizeHints()
Dec  3 14:39:58 openhab rngd[407]: stats: bits received from HRNG source: 300064
Dec  3 14:39:58 openhab rngd[407]: stats: bits sent to kernel pool: 244096
Dec  3 14:39:58 openhab rngd[407]: stats: entropy added to kernel pool: 244096
Dec  3 14:39:58 openhab rngd[407]: stats: FIPS 140-2 successes: 15
Dec  3 14:39:58 openhab rngd[407]: stats: FIPS 140-2 failures: 0
Dec  3 14:39:58 openhab rngd[407]: stats: FIPS 140-2(2001-10-10) Monobit: 0
Dec  3 14:39:58 openhab rngd[407]: stats: FIPS 140-2(2001-10-10) Poker: 0
Dec  3 14:39:58 openhab rngd[407]: stats: FIPS 140-2(2001-10-10) Runs: 0
Dec  3 14:39:58 openhab rngd[407]: stats: FIPS 140-2(2001-10-10) Long run: 0
Dec  3 14:39:58 openhab rngd[407]: stats: FIPS 140-2(2001-10-10) Continuous run: 0
Dec  3 14:39:58 openhab rngd[407]: stats: HRNG source speed: (min=41.704; avg=152.782; max=887.703)Kibits/s
Dec  3 14:39:58 openhab rngd[407]: stats: FIPS tests speed: (min=14.623; avg=173.456; max=14619.199)Kibits/s
Dec  3 14:39:58 openhab rngd[407]: stats: Lowest ready-buffers level: 2
Dec  3 14:39:58 openhab rngd[407]: stats: Entropy starvations: 0
Dec  3 14:39:58 openhab rngd[407]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us

Events.log:

2019-12-03 13:56:56.313 [hingStatusInfoChangedEvent] - 'zwave:device:fa47f277:node19' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to UNINITIALIZED
2019-12-03 13:56:56.391 [hingStatusInfoChangedEvent] - 'zwave:device:fa47f277:node19' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2019-12-03 13:56:56.405 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:fa47f277' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to UNINITIALIZED
2019-12-03 13:56:56.650 [hingStatusInfoChangedEvent] - 'hue:bridge:00212E04EB0A' changed from ONLINE to OFFLINE: Hue bridge connection lost.
2019-12-03 13:56:56.654 [hingStatusInfoChangedEvent] - 'hue:0010:a2e9ba13' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2019-12-03 13:56:56.658 [hingStatusInfoChangedEvent] - 'hue:0010:d0e6fe92' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2019-12-03 13:56:56.661 [hingStatusInfoChangedEvent] - 'hue:bridge:00212E04EB0A' changed from OFFLINE: Hue bridge connection lost. to ONLINE
2019-12-03 13:56:56.673 [hingStatusInfoChangedEvent] - 'hue:0010:d0e6fe92' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2019-12-03 13:56:56.739 [hingStatusInfoChangedEvent] - 'hue:0010:a2e9ba13' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2019-12-03 13:57:02.695 [hingStatusInfoChangedEvent] - 'hue:bridge:00212E04EB0A' changed from ONLINE to OFFLINE: Hue bridge connection lost.
2019-12-03 13:57:02.814 [hingStatusInfoChangedEvent] - 'zwave:serial_zstick:fa47f277' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2019-12-03 13:57:02.816 [hingStatusInfoChangedEvent] - 'hue:0010:a2e9ba13' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2019-12-03 13:57:02.818 [hingStatusInfoChangedEvent] - 'hue:bridge:00212E04EB0A' changed from OFFLINE: Hue bridge connection lost. to ONLINE
2019-12-03 13:57:02.821 [hingStatusInfoChangedEvent] - 'hue:0010:a2e9ba13' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2019-12-03 13:57:02.823 [hingStatusInfoChangedEvent] - 'hue:0010:d0e6fe92' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2019-12-03 13:57:02.829 [hingStatusInfoChangedEvent] - 'hue:0010:d0e6fe92' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2019-12-03 13:57:08.013 [hingStatusInfoChangedEvent] - 'hue:0010:d0e6fe92' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2019-12-03 13:57:08.114 [hingStatusInfoChangedEvent] - 'hue:0010:a2e9ba13' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2019-12-03 13:57:08.116 [hingStatusInfoChangedEvent] - 'hue:bridge:00212E04EB0A' changed from ONLINE to OFFLINE: Hue bridge connection lost.
2019-12-03 13:57:08.548 [hingStatusInfoChangedEvent] - 'hue:bridge:00212E04EB0A' changed from OFFLINE: Hue bridge connection lost. to ONLINE
2019-12-03 13:57:08.552 [hingStatusInfoChangedEvent] - 'hue:0010:d0e6fe92' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2019-12-03 13:57:08.555 [hingStatusInfoChangedEvent] - 'hue:0010:a2e9ba13' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2019-12-03 13:57:34.425 [hingStatusInfoChangedEvent] - 'hue:bridge:00212E04EB0A' changed from ONLINE to OFFLINE: Hue bridge connection lost.
2019-12-03 13:57:34.481 [hingStatusInfoChangedEvent] - 'hue:0010:a2e9ba13' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2019-12-03 13:57:34.483 [hingStatusInfoChangedEvent] - 'hue:0010:d0e6fe92' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2019-12-03 13:57:35.869 [hingStatusInfoChangedEvent] - 'hue:bridge:00212E04EB0A' changed from OFFLINE: Hue bridge connection lost. to ONLINE
2019-12-03 13:57:36.008 [hingStatusInfoChangedEvent] - 'hue:0010:d0e6fe92' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2019-12-03 13:57:36.010 [hingStatusInfoChangedEvent] - 'hue:0010:a2e9ba13' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2019-12-03 13:57:42.930 [hingStatusInfoChangedEvent] - 'hue:bridge:00212E04EB0A' changed from ONLINE to OFFLINE: Hue bridge connection lost.
2019-12-03 13:57:44.838 [hingStatusInfoChangedEvent] - 'hue:0010:d0e6fe92' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2019-12-03 13:57:44.863 [hingStatusInfoChangedEvent] - 'hue:bridge:00212E04EB0A' changed from OFFLINE: Hue bridge connection lost. to ONLINE
2019-12-03 13:57:44.865 [hingStatusInfoChangedEvent] - 'hue:0010:a2e9ba13' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2019-12-03 13:57:44.868 [hingStatusInfoChangedEvent] - 'hue:0010:a2e9ba13' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2019-12-03 13:57:44.871 [hingStatusInfoChangedEvent] - 'hue:0010:d0e6fe92' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2019-12-03 13:57:50.785 [hingStatusInfoChangedEvent] - 'hue:bridge:00212E04EB0A' changed from ONLINE to OFFLINE: Hue bridge connection lost.
2019-12-03 13:57:51.924 [hingStatusInfoChangedEvent] - 'hue:0010:d0e6fe92' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2019-12-03 13:57:55.784 [hingStatusInfoChangedEvent] - 'hue:bridge:00212E04EB0A' changed from OFFLINE: Hue bridge connection lost. to ONLINE
2019-12-03 13:57:58.342 [hingStatusInfoChangedEvent] - 'hue:0010:d0e6fe92' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2019-12-03 13:57:59.906 [hingStatusInfoChangedEvent] - 'hue:0010:a2e9ba13' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2019-12-03 13:58:02.770 [hingStatusInfoChangedEvent] - 'hue:0010:a2e9ba13' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2019-12-03 13:58:02.845 [hingStatusInfoChangedEvent] - 'hue:bridge:00212E04EB0A' changed from ONLINE to OFFLINE: Hue bridge connection lost.
2019-12-03 14:36:18.027 [hingStatusInfoChangedEvent] - 'onkyo:onkyoUnsupported:150bd628-a5d2-448e-a6b4-8d407ed91b7d' changed from UNINITIALIZED to INITIALIZING
2019-12-03 14:36:18.216 [hingStatusInfoChangedEvent] - 'onkyo:onkyoUnsupported:150bd628-a5d2-448e-a6b4-8d407ed91b7d' changed from INITIALIZING to ONLINE
2019-12-03 14:36:18.646 [hingStatusInfoChangedEvent] - 'sonos:CONNECT:RINCON_949F3E2022F801400' changed from UNINITIALIZED to INITIALIZING
2019-12-03 14:36:18.666 [hingStatusInfoChangedEvent] - 'harmonyhub:hub:LivingRoom' changed from UNINITIALIZED to INITIALIZING
2019-12-03 14:36:18.751 [hingStatusInfoChangedEvent] - 'harmonyhub:hub:LivingRoom' changed from INITIALIZING to UNKNOWN
2019-12-03 14:36:18.821 [hingStatusInfoChangedEvent] - 'harmonyhub:hub:MediaRoom' changed from UNINITIALIZED to INITIALIZING
2019-12-03 14:36:18.858 [hingStatusInfoChangedEvent] - 'harmonyhub:device:LivingRoom:49338255' changed from UNINITIALIZED to INITIALIZING
2019-12-03 14:36:18.914 [hingStatusInfoChangedEvent] - 'harmonyhub:hub:MediaRoom' changed from INITIALIZING to UNKNOWN
2019-12-03 14:36:18.935 [hingStatusInfoChangedEvent] - 'harmonyhub:device:MediaRoom:49214592' changed from UNINITIALIZED to INITIALIZING
2019-12-03 14:36:19.009 [hingStatusInfoChangedEvent] - 'sonos:CONNECT:RINCON_949F3E2022F801400' changed from INITIALIZING to ONLINE

events.log:

Dec  3 14:26:36 openhab kernel: [28092.636452] cdc_acm 1-1.3:1.0: ttyACM1: USB ACM device
Dec  3 14:35:18 openhab kernel: [28618.057702] pidof invoked oom-killer: gfp_mask=0x6000c0(GFP_KERNEL), nodemask=(null), order=0, oom_score_adj=0
Dec  3 14:35:19 openhab kernel: [28618.057713] pidof cpuset=/ mems_allowed=0
Dec  3 14:35:19 openhab kernel: [28618.057739] CPU: 3 PID: 9619 Comm: pidof Tainted: G         C        4.19.75-v7+ #1270
Dec  3 14:35:19 openhab kernel: [28618.057742] Hardware name: BCM2835
Dec  3 14:35:19 openhab kernel: [28618.057772] [<80111fcc>] (unwind_backtrace) from [<8010d544>] (show_stack+0x20/0x24)
Dec  3 14:35:19 openhab kernel: [28618.057788] [<8010d544>] (show_stack) from [<80819bc0>] (dump_stack+0xd4/0x118)
Dec  3 14:35:19 openhab kernel: [28618.057806] [<80819bc0>] (dump_stack) from [<8023cfe0>] (dump_header+0x80/0x250)
Dec  3 14:35:19 openhab kernel: [28618.057820] [<8023cfe0>] (dump_header) from [<8023c358>] (oom_kill_process+0x358/0x3a8)
Dec  3 14:35:19 openhab kernel: [28618.057833] [<8023c358>] (oom_kill_process) from [<8023cc88>] (out_of_memory+0x134/0x36c)
Dec  3 14:35:19 openhab kernel: [28618.057847] [<8023cc88>] (out_of_memory) from [<802430e0>] (__alloc_pages_nodemask+0x1024/0x1178)
Dec  3 14:35:19 openhab kernel: [28618.057857] [<802430e0>] (__alloc_pages_nodemask) from [<80243258>] (__get_free_pages+0x24/0x70)
Dec  3 14:35:19 openhab kernel: [28618.057871] [<80243258>] (__get_free_pages) from [<80320184>] (proc_pid_readlink+0x8c/0x134)
Dec  3 14:35:19 openhab kernel: [28618.057887] [<80320184>] (proc_pid_readlink) from [<802bdbfc>] (vfs_readlink+0x11c/0x124)
Dec  3 14:35:19 openhab kernel: [28618.057902] [<802bdbfc>] (vfs_readlink) from [<802b0cbc>] (do_readlinkat+0xc0/0x11c)
Dec  3 14:35:19 openhab kernel: [28618.057915] [<802b0cbc>] (do_readlinkat) from [<802b105c>] (sys_readlink+0x2c/0x30)
Dec  3 14:35:19 openhab kernel: [28618.057928] [<802b105c>] (sys_readlink) from [<80101000>] (ret_fast_syscall+0x0/0x28)

openhab.log: The section about the z-wave controller starting and stopping appears throughout the log post-upgrade and was not in there previously to my knowledge.

2019-12-03 13:56:34.695 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null
2019-12-03 13:56:40.898 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'
2019-12-03 13:56:45.523 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2019-12-03 13:56:45.537 [WARN ] [core.thing.internal.ThingManagerImpl] - Initializing handler for thing 'zwave:serial_zstick:fa47f277' takes more than 5000ms.
2019-12-03 13:56:47.307 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2019-12-03 13:56:47.311 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2019-12-03 13:56:59.882 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Stopped ZWave serial handler
2019-12-03 13:57:20.259 [ERROR] [core.karaf.internal.FeatureInstaller] - Failed installing 'openhab-misc-restdocs'
2019-12-03 14:35:50.145 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'America/Chicago'.
2019-12-03 14:35:50.215 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to 'xxx,xxx'.
2019-12-03 14:35:50.231 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'en_US'.

syslog: Snipped what I think might be just the important parts.

Dec  3 14:35:19 openhab kernel: [28618.058157] Tasks state (memory values in pages):
Dec  3 14:35:19 openhab kernel: [28618.058161] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
Dec  3 14:35:19 openhab kernel: [28618.058538] [  30308]   110 30308   303802   215046  1159168    13126             0 java
Dec  3 14:35:19 openhab kernel: [28618.058768] Out of memory: Kill process 30308 (java) score 829 or sacrifice child
Dec  3 14:35:19 openhab kernel: [28618.060141] Killed process 30308 (java) total-vm:1215208kB, anon-rss:860184kB, file-rss:0kB, shmem-rss:0kB
Dec  3 14:35:19 openhab kernel: [28618.428709] oom_reaper: reaped process 30308 (java), now anon-rss:0kB, file-rss:0kB, shmem-rss:0kB
Dec  3 14:35:20 openhab systemd-udevd[145]: ttyACM2: Worker [9599] processing SEQNUM=1420 is taking a long time
Dec  3 14:35:20 openhab systemd[1]: openhab2.service: Main process exited, code=killed, status=9/KILL
Dec  3 14:35:20 openhab CRON[9638]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Dec  3 14:35:20 openhab systemd[1]: openhab2.service: Failed with result 'signal'.
Dec  3 14:35:20 openhab systemd-udevd[145]: ttyACM2: Worker [9599] processing SEQNUM=1420 killed
Dec  3 14:35:20 openhab systemd-udevd[145]: 1-1.3:1.1: Worker [9647] processing SEQNUM=1421 killed
Dec  3 14:35:20 openhab systemd-udevd[145]: 1-1.3:1.1: Worker [9647] processing SEQNUM=1421 is taking a long time
Dec  3 14:35:20 openhab systemd-udevd[145]: Worker [9599] terminated by signal 9 (KILL)
Dec  3 14:35:20 openhab CRON[9643]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Dec  3 14:35:20 openhab systemd-udevd[145]: Worker [9647] terminated by signal 9 (KILL)
Dec  3 14:35:20 openhab CRON[9644]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Dec  3 14:35:20 openhab systemd-udevd[145]: 1-1.3:1.1: Worker [9647] failed
Dec  3 14:35:20 openhab CRON[9645]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Dec  3 14:35:20 openhab CRON[9646]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Dec  3 14:35:20 openhab mtp-probe: checking bus 1, device 18: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3"
Dec  3 14:35:20 openhab mtp-probe: bus: 1, device: 18 was not an MTP device
Dec  3 14:35:20 openhab mtp-probe: checking bus 1, device 18: "/sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3"
Dec  3 14:35:20 openhab mtp-probe: bus: 1, device: 18 was not an MTP device

Any information or tips, I would greatly appreciate. I’m sorry if this was too long or too much information.

Have you run out of space on the SD card? What is the output of sudo df -hl ?

My SSH session is currently clunky due to the system performance. Currently myopenhab is showing the system back down.
the SD Card is 32GB with the following stats:

##      Swap = Free: 0.01GB (19%), Used: 0.07GB (81%), Total: 0.09GB
##      Root = Free: 25.03GB (89%), Used: 2.83GB (11%), Total: 29.07GB
1 Like

I upgraded from 2.5 Milestone 3 to Milestone 6 and experiencing issues with the Astro Binding. Events are not triggered on expected time but instead these are all triggered at once on midnight. I also noticed that if I for example change the Offset of one of the event not being triggered earlier the day, it is getting triggered directly after the update.

The installation is running on a docker container (amd x64, milestone tag), migrated via:

  • New container created (clean start)
  • Restore backup via restore script

2019-12-04 00:00:35.780 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:morningNight#event triggered END
2019-12-04 00:00:35.780 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:morningNight#event triggered END
2019-12-04 00:00:35.782 [vent.ChannelTriggeredEvent] - astro:sun:local:morningNight#event triggered END
2019-12-04 00:00:35.782 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:astroDawn#event triggered START
2019-12-04 00:00:35.785 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:astroDawn#event triggered START
2019-12-04 00:00:35.785 [vent.ChannelTriggeredEvent] - astro:sun:local:astroDawn#event triggered START
2019-12-04 00:00:35.786 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:nauticDawn#event triggered START
2019-12-04 00:00:35.787 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:astroDawn#event triggered END
2019-12-04 00:00:35.788 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:nauticDawn#event triggered START
2019-12-04 00:00:35.788 [vent.ChannelTriggeredEvent] - astro:sun:local:astroDawn#event triggered END
2019-12-04 00:00:35.789 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:astroDawn#event triggered END
2019-12-04 00:00:35.789 [vent.ChannelTriggeredEvent] - astro:sun:local:nauticDawn#event triggered START
2019-12-04 00:00:35.791 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:civilDawn#event triggered START
2019-12-04 00:00:35.792 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:nauticDawn#event triggered END
2019-12-04 00:00:35.792 [vent.ChannelTriggeredEvent] - astro:sun:local:nauticDawn#event triggered END
2019-12-04 00:00:35.794 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:civilDawn#event triggered START
2019-12-04 00:00:35.795 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:nauticDawn#event triggered END
2019-12-04 00:00:35.797 [vent.ChannelTriggeredEvent] - astro:sun:local:civilDawn#event triggered START
2019-12-04 00:00:35.798 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:daylight#event triggered START
2019-12-04 00:00:35.799 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:civilDawn#event triggered END
2019-12-04 00:00:35.800 [vent.ChannelTriggeredEvent] - astro:sun:local:rise#event triggered START
2019-12-04 00:00:35.800 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:civilDawn#event triggered END
2019-12-04 00:00:35.801 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:rise#event triggered START
2019-12-04 00:00:35.802 [vent.ChannelTriggeredEvent] - astro:sun:local:civilDawn#event triggered END
2019-12-04 00:00:35.802 [vent.ChannelTriggeredEvent] - astro:sun:local:rise#event triggered END
2019-12-04 00:00:35.803 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:daylight#event triggered START
2019-12-04 00:00:35.804 [vent.ChannelTriggeredEvent] - astro:sun:local:daylight#event triggered START
2019-12-04 00:00:35.806 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:rise#event triggered END
2019-12-04 00:00:35.807 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:rise#event triggered START
2019-12-04 00:00:35.807 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:rise#event triggered END
2019-12-04 00:00:35.809 [vent.ChannelTriggeredEvent] - astro:sun:local:noon#event triggered START
2019-12-04 00:00:35.809 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:noon#event triggered START
2019-12-04 00:00:35.810 [vent.ChannelTriggeredEvent] - astro:sun:local:noon#event triggered END
2019-12-04 00:00:35.811 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:noon#event triggered END
2019-12-04 00:00:35.811 [vent.ChannelTriggeredEvent] - astro:moon:3d92b296:rise#event triggered START
2019-12-04 00:00:35.812 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:set#event triggered START
2019-12-04 00:00:35.812 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:set#event triggered END
2019-12-04 00:00:35.814 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:daylight#event triggered END
2019-12-04 00:00:35.814 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:daylight#event triggered END
2019-12-04 00:00:35.815 [vent.ChannelTriggeredEvent] - astro:sun:local:daylight#event triggered END
2019-12-04 00:00:35.815 [vent.ChannelTriggeredEvent] - astro:sun:local:set#event triggered START
2019-12-04 00:00:35.816 [vent.ChannelTriggeredEvent] - astro:sun:local:set#event triggered END
2019-12-04 00:00:35.819 [vent.ChannelTriggeredEvent] - astro:sun:local:civilDusk#event triggered START
2019-12-04 00:00:35.820 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:civilDusk#event triggered START
2019-12-04 00:00:35.823 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:civilDusk#event triggered START
2019-12-04 00:00:35.826 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:set#event triggered START
2019-12-04 00:00:35.827 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:civilDusk#event triggered END
2019-12-04 00:00:35.827 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:nauticDusk#event triggered START
2019-12-04 00:00:35.828 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:nauticDusk#event triggered START
2019-12-04 00:00:35.828 [vent.ChannelTriggeredEvent] - astro:sun:local:nauticDusk#event triggered START
2019-12-04 00:00:35.829 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:civilDusk#event triggered END
2019-12-04 00:00:35.829 [vent.ChannelTriggeredEvent] - astro:sun:local:civilDusk#event triggered END
2019-12-04 00:00:35.830 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:set#event triggered END
2019-12-04 00:00:35.830 [vent.ChannelTriggeredEvent] - astro:sun:local:astroDusk#event triggered START
2019-12-04 00:00:35.831 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:nauticDusk#event triggered END
2019-12-04 00:00:35.831 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:nauticDusk#event triggered END
2019-12-04 00:00:35.832 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:astroDusk#event triggered START
2019-12-04 00:00:35.832 [vent.ChannelTriggeredEvent] - astro:sun:local:nauticDusk#event triggered END
2019-12-04 00:00:35.833 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:astroDusk#event triggered START
2019-12-04 00:00:35.833 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:night#event triggered START
2019-12-04 00:00:35.833 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:night#event triggered START
2019-12-04 00:00:35.834 [vent.ChannelTriggeredEvent] - astro:sun:local:astroDusk#event triggered END
2019-12-04 00:00:35.834 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:eveningNight#event triggered START
2019-12-04 00:00:35.835 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:eveningNight#event triggered START
2019-12-04 00:00:35.835 [vent.ChannelTriggeredEvent] - astro:sun:local:night#event triggered START
2019-12-04 00:00:35.836 [vent.ChannelTriggeredEvent] - astro:sun:f40304f7:astroDusk#event triggered END
2019-12-04 00:00:35.836 [vent.ChannelTriggeredEvent] - astro:sun:local:eveningNight#event triggered START
2019-12-04 00:00:35.837 [vent.ChannelTriggeredEvent] - astro:sun:34f9d149:astroDusk#event triggered END
2019-12-04 00:00:35.838 [vent.ChannelTriggeredEvent] - astro:moon:3d92b296:set#event triggered END

Is it expected that in 2.5 you need to install the BasicUI to be able to see icons in the Android app?

On my 2.4 system I only have PaperUI installed and I am able to see icons on my phone, but with 2.5 M6 I didn’t get any icons until I installed BasicUI.

Broadlink Binding not work on latest 2.5 M6
Fall back to M5 then all error gone and work properly

2019-12-03 09:41:57.714 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method ‘ThingHandler.handleCommand()’ on ‘org.openhab.binding.broadlink.handler.BroadlinkRemoteHandler@d99458’: bundleContext

java.lang.NoSuchFieldError: bundleContext

at org.openhab.binding.broadlink.handler.BroadlinkRemoteHandler.lookupCode(BroadlinkRemoteHandler.java:110) ~[?:?]

at org.openhab.binding.broadlink.handler.BroadlinkRemoteHandler.handleCommand(BroadlinkRemoteHandler.java:87) ~[?:?]

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_222]

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_222]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_222]

at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_222]

at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]

at org.eclipse.smarthome.core.internal.common.InvocationHandlerSync.invoke(InvocationHandlerSync.java:59) [bundleFile:?]

at com.sun.proxy.$Proxy409.handleCommand(Unknown Source) [?:?]

at org.eclipse.smarthome.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:74) [bundleFile:?]

at org.eclipse.smarthome.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem(SystemDefaultProfile.java:48) [bundleFile:?]

at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_222]

at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_222]

at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_222]

at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_222]

at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]

at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]

at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_222]

at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]

at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]

at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]

Same here, broadlink binding stopped working.
The problem is described also here Broadlink binding for RMx, A1, SPx and MP. Any interest?

Please open a GirHub issue so the developers can correct the issues.

I had a similar issue last night (see here)

The issue seemed to resolve itself when I edited my .items file. Whilst glad it started to work, I wasn’t exactly filled with confidence that it won’t happen again.

The binding is not in the official repo of openHAB, so if an issue would be created it should be on the repo of the binding, but I don’t know where that is.

If I suspect my issue to be related to Java blowing up, is that considered openhab-core? I just want to make sure I’m being useful and putting items in the correct area, versus being a hindrance and putting chaff in the way.