Startup issues of OH:
a) sudo systemctl start openhab2.service
Does not start OH - status returns:
[10:23:45] openhabian@homer:~$ sudo systemctl status openhab2.service
â—Ź openhab2.service - openHAB2 instance, reachable at http://homer:8080
Loaded: loaded (/usr/lib/systemd/system/openhab2.service; enabled; vendor preset: enabled)
Drop-In: /etc/systemd/system/openhab2.service.d
└─override.conf
Active: inactive (dead)
Docs: https://www.openhab.org/docs/
https://community.openhab.org
b) sudo openhab-cli start
Does start OH in the console - but when I logout, OH will be shutdown (I don’t know this behaviour from thr karaf console)
After a reboot OH is not starting either.
Last openhab-log entry:
2020-09-20 10:04:11.463 [INFO ] [control.internal.WebSocketConnection] - Web Socket close 1006. Reason: Disconnected
2020-09-20 10:04:21.192 [WARN ] [core.thing.internal.ThingManagerImpl] - Disposing handler for thing 'zwave:serial_zstick:12345678-9012-3456-7890-123456789012' takes more than 5000ms.
2020-09-20 10:04:22.387 [INFO ] [b.core.service.AbstractActiveService] - FritzboxTr064 Refresh Service has been shut down
2020-09-20 10:04:23.761 [INFO ] [panel.internal.HABPanelDashboardTile] - Stopped HABPanel
2020-09-20 10:04:23.812 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Stopped Paper UI
2020-09-20 10:04:23.836 [INFO ] [.dashboard.internal.DashboardService] - Stopped Dashboard
^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^$
I would appreciate a hint what to check in this case.
I don’t see something suspicious in messages or syslog
EDIT:
If I start openhab in the console (sudo openhab-cli start) I don’t see openhab in “top” (just java):
And I don’t see the syslog in Browser (port 9001) is not available, but PaperUI works.
Furthermore I get in the colsole:
openhab> Experimental: JNI_OnUnload called.
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.116826] Internal error: Oops: 207 [#2] SMP ARM
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117361] Process mkswap (pid: 3249, stack limit = 0x0a38b0dc)
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117383] Stack: (0xd08a7aa8 to 0xd08a8000)
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117405] 7aa0: d386d320 d32e9008 00000000 de194b50 deac03b0 ddf1fdb0
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117435] 7ac0: c0621dfc d47d27a7 d08a7b18 00000000 c1204f88 d32e9008 d3efc600 d2e79e00
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117463] 7ae0: bf203400 d031a000 d08a7b4c d08a7af8 bf200998 bf1e405c c02a6450 c08a3610
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117492] 7b00: 00000001 d3b90580 00012244 d8f094e0 00000000 c1204f88 00000057 d47d27a7
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117520] 7b20: 00000008 d30b5a80 d2e79e00 00001000 00000000 00000000 00001000 00001000
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117549] 7b40: d08a7bac d08a7b50 bf201184 bf200660 00000001 d30b5a80 c020bc48 bf203198
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117577] 7b60: 00000000 00000000 00000000 c1204f88 d8f094e0 00001000 00000000 d47d27a7
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117606] 7b80: c020bbec c1204f88 d30b5a80 d08a7bb4 d3b90580 00000000 ffffffff d8f094e0
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117634] 7ba0: d08a7bec d08a7bb0 c0641110 bf200fdc c037d85c 00000000 00000000 00000000
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117662] 7bc0: 00000000 d47d27a7 c1204f88 d30b5a80 00000008 00000800 d08a7e60 00000000
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117691] 7be0: d08a7c5c d08a7bf0 c0641348 c064101c c1359964 c0638538 00000000 c1204f88
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117720] 7c00: d30b5a80 00001000 d8f094e0 00000000 00000000 d8f094e0 d08a7c5c d08a7c28
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117748] 7c20: c0638538 c063838c d08a7c33 d47d27a7 d08a7c5c d1b9a140 d30b5a80 00000801
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117776] 7c40: 00000800 d08a7e60 00000000 d8f094e0 d08a7c84 d08a7c60 c043f584 c0641300
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117805] 7c60: 00000001 d1b9a140 d1b9a140 00000800 d4820988 d08a7e60 d08a7cec d08a7c88
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117833] 7c80: c043f86c c043f3fc d08a7e60 d8f094e0 d08a7cd4 c0443e30 00001000 c1204f88
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117862] 7ca0: c043dbb0 d08a7e60 00000800 d4820988 000257ff 00000000 c0382c24 d47d27a7
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117890] 7cc0: 20000013 d4820988 00000000 d8f094e0 d08a7e60 c0443e30 d08a7e60 00000000
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117919] 7ce0: d08a7d24 d08a7cf0 c043fd6c c043f5c0 c043dbb0 d08a7d00 ffffffff d4820a90
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117947] 7d00: 00000000 d08a7d90 d4820a90 00000001 d08a7e60 00000000 d08a7d34 d08a7d28
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.117976] 7d20: c0443120 c043fc88 d08a7d4c d08a7d38 c03818d4 c0443108 d8f094e0 00000000
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118004] 7d40: d08a7dfc d08a7d50 c0382f3c c03818bc 00000002 c0c0db08 00000001 c1204f88
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118032] 7d60: c043e7cc c043d304 00000000 c12a4d90 c1204fb4 d4820a90 c03818b0 00000002
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118061] 7d80: d08a6010 ffffffff ffffffff c0440001 d8f094e0 d08a7ec0 d4820a90 00000c00
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118090] 7da0: d08a7e14 d08a7db0 c0376b58 c0384318 00000c00 00000c00 d8f094e0 05046553
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118118] 7dc0: c1204f88 d08a6030 00000c00 d47d27a7 00001000 d4820a90 c1204f88 d08a7e60
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118146] 7de0: 7fffffff 00000000 00000000 00000001 d08a7e34 d08a7e00 c03831dc c0382d00
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118175] 7e00: d08a7e00 d08a7e00 d08a7e08 d08a7e08 c0000000 d47d27a7 d08a7e14 d08a7e60
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118204] 7e20: d4820a90 d4820988 d08a7e44 d08a7e38 c04430d0 c0383184 d08a7e5c d08a7e48
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118232] 7e40: c0385210 c04430c4 d4820a90 c1204f88 d08a7ed4 d08a7e60 c037b0b0 c03851ec
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118260] 7e60: 7fffffff 00000000 00000000 00000000 ffffffff 7fffffff 00000001 00000000
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118288] 7e80: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118317] 7ea0: d08a7f2c d47d27a7 c03f87c8 ffffffff d4820a90 cfec3300 00000000 00000000
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118345] 7ec0: 00000000 00000076 d08a7f0c d08a7ed8 c037c544 c037afcc ffffffff 7fffffff
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118374] 7ee0: 00000001 00000000 00000000 ffffffff 7fffffff d4820988 c02011c4 d08a6000
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118402] 7f00: d08a7f34 d08a7f10 c0442adc c037c4f0 ffffffff 7fffffff d08a6000 cfec3300
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118430] 7f20: 00000000 00000000 d08a7f64 d08a7f38 c043704c c0442abc ffffffff 7fffffff
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118459] 7f40: 00000000 c041d0b8 cfec3300 cfec3300 00000000 00000076 d08a7f94 d08a7f68
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118487] 7f60: c0437104 c0436ff0 ffffffff 7fffffff 00000000 00000c00 b6f3d8f8 00000000
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118516] 7f80: 00000003 be9beef7 d08a7fa4 d08a7f98 c0437410 c04370c4 00000000 d08a7fa8
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118544] 7fa0: c0201000 c0437400 00000000 00000003 00000003 b6e60808 0000006c 00000000
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118572] 7fc0: 00000000 00000003 be9beef7 00000076 00000000 00000000 00000000 00033c98
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.118601] 7fe0: 00033dd0 be9be798 00012cf0 b6de68a4 60000010 00000003 00000000 00000000
Message from syslogd@homer at Sep 20 10:51:57 ...
kernel:[ 1043.120016] Code: e0844084 e1a04204 e0883004 e5939018 (e5991000)
Experimental: JNI_OnUnload called.
And even though OH seems to be running in the console (PaperUI still working).
I get the latest entry in events.log 20 minutes ago:
2020-09-20 10:53:06.469 [thome.event.ExtensionEvent] - Extension 'binding-icloud' has been uninstalled.
2020-09-20 10:53:12.378 [hingStatusInfoChangedEvent] - 'systeminfo:computer:homer' changed from ONLINE to UNINITIALIZED
2020-09-20 10:53:12.403 [hingStatusInfoChangedEvent] - 'systeminfo:computer:homer' changed from UNINITIALIZED to UNINITIALIZED (H$
2020-09-20 10:53:12.546 [thome.event.ExtensionEvent] - Extension 'binding-systeminfo' has been uninstalled.
2020-09-20 10:53:17.742 [thome.event.ExtensionEvent] - Extension 'binding-wol1' has been uninstalled.
and in openhab.log:
2020-09-20 10:51:48.153 [WARN ] [ig.xml.osgi.XmlDocumentBundleTracker] - The XML document '/ESH-INF/thing/yale/yrl256_1_78.xml' i$
com.thoughtworks.xstream.io.StreamException: : Exception in opening zip file: /var/lib/openhab2/cache/org.eclipse.osgi/265/0/bun$
at com.thoughtworks.xstream.io.xml.StaxDriver.createReader(StaxDriver.java:126) ~[bundleFile:?]
at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1115) ~[bundleFile:?]
at com.thoughtworks.xstream.XStream.fromXML(XStream.java:1062) ~[bundleFile:?]
at org.eclipse.smarthome.config.xml.util.XmlDocumentReader.readFromXML(XmlDocumentReader.java:85) ~[bundleFile:?]
at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.parseDocuments(XmlDocumentBundleTracker.java:411) [bund$
at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.processBundle(XmlDocumentBundleTracker.java:398) [bundl$
at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker.access$6(XmlDocumentBundleTracker.java:393) [bundleFile$
at org.eclipse.smarthome.config.xml.osgi.XmlDocumentBundleTracker$2.run(XmlDocumentBundleTracker.java:363) [bundleFile:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_265]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_265]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) $
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.$
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_265]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_265]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_265]
Caused by: java.io.IOException: Exception in opening zip file: /var/lib/openhab2/cache/org.eclipse.osgi/265/0/bundleFile
at org.eclipse.osgi.framework.util.SecureAction.getZipFile(SecureAction.java:321) ~[org.eclipse.osgi-3.12.100.jar:?]
at org.eclipse.osgi.storage.bundlefile.ZipBundleFile.basicOpen(ZipBundleFile.java:93) ~[org.eclipse.osgi-3.12.100.jar:?]
at org.eclipse.osgi.storage.bundlefile.ZipBundleFile.getZipFile(ZipBundleFile.java:106) ~[org.eclipse.osgi-3.12.100.jar:?]
at org.eclipse.osgi.storage.bundlefile.ZipBundleEntry.getInputStream(ZipBundleEntry.java:59) ~[org.eclipse.osgi-3.12.100.$
at org.eclipse.osgi.storage.url.BundleURLConnection.connect(BundleURLConnection.java:53) ~[org.eclipse.osgi-3.12.100.jar:$
at org.eclipse.osgi.storage.url.BundleURLConnection.getInputStream(BundleURLConnection.java:99) ~[org.eclipse.osgi-3.12.1$
at java.net.URL.openStream(URL.java:1068) ~[?:1.8.0_265]
at com.thoughtworks.xstream.io.xml.StaxDriver.createReader(StaxDriver.java:109) ~[bundleFile:?]
... 14 more
Caused by: java.io.FileNotFoundException: /var/lib/openhab2/cache/org.eclipse.osgi/265/0/bundleFile (No such file or directory)
at java.util.zip.ZipFile.open(Native Method) ~[?:1.8.0_265]
at java.util.zip.ZipFile.<init>(ZipFile.java:230) ~[?:1.8.0_265]
at java.util.zip.ZipFile.<init>(ZipFile.java:160) ~[?:1.8.0_265]
at java.util.zip.ZipFile.<init>(ZipFile.java:174) ~[?:1.8.0_265]
at org.eclipse.osgi.framework.util.SecureAction.getZipFile(SecureAction.java:304) ~[org.eclipse.osgi-3.12.100.jar:?]
at org.eclipse.osgi.storage.bundlefile.ZipBundleFile.basicOpen(ZipBundleFile.java:93) ~[org.eclipse.osgi-3.12.100.jar:?]
at org.eclipse.osgi.storage.bundlefile.ZipBundleFile.getZipFile(ZipBundleFile.java:106) ~[org.eclipse.osgi-3.12.100.jar:?]
at org.eclipse.osgi.storage.bundlefile.ZipBundleEntry.getInputStream(ZipBundleEntry.java:59) ~[org.eclipse.osgi-3.12.100.$
at org.eclipse.osgi.storage.url.BundleURLConnection.connect(BundleURLConnection.java:53) ~[org.eclipse.osgi-3.12.100.jar:$
at org.eclipse.osgi.storage.url.BundleURLConnection.getInputStream(BundleURLConnection.java:99) ~[org.eclipse.osgi-3.12.1$
at java.net.URL.openStream(URL.java:1068) ~[?:1.8.0_265]
at com.thoughtworks.xstream.io.xml.StaxDriver.createReader(StaxDriver.java:109) ~[bundleFile:?]
... 14 more
In the console I still can call bundles:list, but the logs don’t show any activity.
In messages I see a lot of ZRAM related stuff which does not look well (write error):
@mstormi Any idea about this?
Is it possible that the sd-card has an issue (almost brand new)
Sep 20 11:43:15 homer kernel: [ 4121.826231] zram: Added device: zram4
Sep 20 11:43:15 homer kernel: [ 4121.831178] zram4: detected capacity change from 0 to 629145600
Sep 20 11:43:15 homer kernel: [ 4121.831766] zram: Can't change algorithm for initialized device
Sep 20 11:43:15 homer zram-config[5823]: + continue
Sep 20 11:43:15 homer zram-config[5823]: + read -r line
Sep 20 11:43:15 homer zram-config[5823]: + case "$line" in
Sep 20 11:43:15 homer zram-config[5823]: + continue
Sep 20 11:43:15 homer zram-config[5823]: + read -r line
Sep 20 11:43:15 homer zram-config[5823]: + case "$line" in
Sep 20 11:43:15 homer zram-config[5823]: + continue
Sep 20 11:43:15 homer zram-config[5823]: + read -r line
Sep 20 11:43:15 homer zram-config[5823]: + case "$line" in
Sep 20 11:43:15 homer zram-config[5823]: + continue
Sep 20 11:43:15 homer zram-config[5823]: + read -r line
Sep 20 11:43:15 homer zram-config[5823]: + case "$line" in
Sep 20 11:43:15 homer zram-config[5823]: + continue
Sep 20 11:43:15 homer zram-config[5823]: + read -r line
Sep 20 11:43:15 homer zram-config[5823]: + case "$line" in
Sep 20 11:43:15 homer zram-config[5823]: + continue
Sep 20 11:43:15 homer zram-config[5823]: + read -r line
Sep 20 11:43:15 homer zram-config[5823]: + case "$line" in
Sep 20 11:43:15 homer zram-config[5823]: + set -- swap lz4 200M 600M 75 0 90
Sep 20 11:43:15 homer zram-config[5823]: + echo 'ztab create swap lz4 200M 600M 75 0 90 '
Sep 20 11:43:15 homer zram-config[5823]: + ZTAB_EMPTY=false
Sep 20 11:43:15 homer zram-config[5823]: + ZTYPE=swap
Sep 20 11:43:15 homer zram-config[5823]: + ALG=lz4
Sep 20 11:43:15 homer zram-config[5823]: + MEM_SIZE=200M
Sep 20 11:43:15 homer zram-config[5823]: + DISK_SIZE=600M
Sep 20 11:43:15 homer zram-config[5823]: + [[ -f /tmp/zram-device-list ]]
Sep 20 11:43:15 homer zram-config[5823]: + test -f /tmp/zram-device-list.new
Sep 20 11:43:15 homer zram-config[5823]: + case "$1" in
Sep 20 11:43:15 homer zram-config[5823]: + PRIORITY=75
Sep 20 11:43:15 homer zram-config[5823]: + PAGE_CLUSTER=0
Sep 20 11:43:15 homer zram-config[5823]: + SWAPPINESS=90
Sep 20 11:43:15 homer zram-config[5823]: + createZswap
Sep 20 11:43:15 homer zram-config[5823]: + createZdevice
Sep 20 11:43:15 homer zram-config[5823]: + [[ -d /sys/class/zram-control ]]
Sep 20 11:43:15 homer zram-config[5823]: ++ cat /sys/class/zram-control/hot_add
Sep 20 11:43:15 homer zram-config[5823]: + RAM_DEV=4
Sep 20 11:43:15 homer zram-config[5823]: + [[ -n 200M ]]
Sep 20 11:43:15 homer zram-config[5823]: + echo 200M
Sep 20 11:43:15 homer zram-config[5823]: + [[ -n 600M ]]
Sep 20 11:43:15 homer zram-config[5823]: + echo 600M
Sep 20 11:43:15 homer zram-config[5823]: + [[ -n lz4 ]]
Sep 20 11:43:15 homer zram-config[5823]: + echo lz4
Sep 20 11:43:15 homer zram-config[5823]: /usr/local/sbin/zram-config: line 30: echo: write error: Device or resource busy
Sep 20 11:43:15 homer zram-config[5823]: + echo 'zram4 created comp_algorithm=lz4 mem_limit=200M disksize=600M'
Sep 20 11:43:15 homer zram-config[5823]: + mkswap --label zram-config4 /dev/zram4
Sep 20 11:43:15 homer kernel: [ 4121.861232] 8<--- cut here ---
Sep 20 11:43:15 homer kernel: [ 4121.861272] Unable to handle kernel NULL pointer dereference at virtual address 00000000