2.5 Milestone 6 Issues

Bruce_Osborne · December 2, 2019, 11:10am

I just updated one system from M5 to M6 using openHABian and noticed this error. I will open a GitHub issue.

2019-12-02 06:07:40.545 [ERROR] [org.apache.felix.scr                ] - bundle org.apache.felix.scr:2.1.16 (43)Circular reference detected trying to get service {org.eclipse.smarthome.core.items.MetadataProvider}={service.id=244, service.bundleid=183, service.scope=bundle, component.name=org.eclipse.smarthome.core.semantics.internal.SemanticsMetadataProvider, component.id=90}

 stack of references: ServiceReference: {org.eclipse.smarthome.core.items.MetadataProvider}={service.id=244, service.bundleid=183, service.scope=bundle, component.name=org.eclipse.smarthome.core.semantics.internal.SemanticsMetadataProvider, component.id=90}

ServiceReference: {org.eclipse.smarthome.core.items.ItemRegistry}={service.id=243, service.bundleid=133, service.scope=bundle, component.name=org.eclipse.smarthome.core.internal.items.ItemRegistryImpl, component.id=144}

ServiceReference: {org.eclipse.smarthome.core.items.MetadataRegistry}={service.id=242, service.bundleid=133, service.scope=bundle, component.name=org.eclipse.smarthome.core.internal.items.MetadataRegistryImpl, component.id=148}

It seems to have settled down after a restart but this still appears to be a bug that could cause issues later on in development.

gitMiguel · December 2, 2019, 11:24am

I’f I remember correctly then bindings installed from marketplace won’t resolve runtime dependencies in the same way like bindings in the official release. It’s more a feature than a bug. That’s why you have to trigger the feature installation manually.

Bruce_Osborne · December 2, 2019, 11:28am

The only binding I have installed on that test system is Z-Wave. It was a clean M5 install initially.

gitMiguel · December 2, 2019, 11:50am

Sorry Bruce for the confusion. I replied to your earlier post:

cmar · December 2, 2019, 5:10pm

Is this of interest?

                      2.5.0.M6
                               Milestone Build

Hit '<tab>' for a list of available commands
and '[cmd] --help' for help on a specific command.
Hit '<ctrl-d>' or type 'system:shutdown' or 'logout' to shutdown openHAB.

openhab> [CodeBlob (0x0000000113563e10)]
Framesize: 0
BufferBlob (0x0000000113563e10) used for StubRoutines (2)
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (sharedRuntime.cpp:834), pid=75928, tid=110811
#  fatal error: exception happened outside interpreter, nmethods and vtable stubs at pc 0x0000000113566acf
#
# JRE version: Java(TM) SE Runtime Environment (8.0_40-b25) (build 1.8.0_40-b25)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (25.40-b25 mixed mode bsd-amd64 compressed oops)
# Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#
# An error report file with more information is saved as:
# /Users/martin/Documents/HomeAutomation/openhab-2.1.0/userdata/hs_err_pid75928.log
#
# If you would like to submit a bug report, please visit:
#   http://bugreport.java.com/bugreport/crash.jsp
#
/Users/martin/OH/runtime/bin/karaf: line 175: 75928 Abort trap: 6           ${KARAF_EXEC} "${JAVA}" ${JAVA_OPTS} -Djava.endorsed.dirs="${JAVA_ENDORSED_DIRS}" -Djava.ext.dirs="${JAVA_EXT_DIRS}" -Dkaraf.instances="${KARAF_DATA}/tmp/instances" -Dkaraf.home="${KARAF_HOME}" -Dkaraf.base="${KARAF_BASE}" -Dkaraf.data="${KARAF_DATA}" -Dkaraf.etc="${KARAF_ETC}" -Dkaraf.log="${OPENHAB_LOGDIR}" -Dkaraf.restart.jvm.supported=true -Djava.io.tmpdir="${KARAF_DATA}/tmp" -Djava.util.logging.config.file="${KARAF_BASE}/etc/java.util.logging.properties" ${KARAF_SYSTEM_OPTS} ${KARAF_OPTS} ${OPTS} -classpath "${CLASSPATH}" ${MAIN} "$@"[hs_err_pid75928.log|attachment](upload://9W0Pnzpt1RZVD3UynDHMkX8d0K9.log) (101.2 KB) 
```[hs_err_pid75928.log|attachment](upload://9W0Pnzpt1RZVD3UynDHMkX8d0K9.log) (101.2 KB)

mstormi · December 5, 2019, 11:16am

14 posts were split to a new topic: Things lost (JSONDB gone) on upgrade

cmar · December 2, 2019, 9:19pm

My problem form earlier today reappeared.

Second crash of openhab (2.5.M6) only 53 min after having started it freshly after the reported crash earlier today. Similar error message. As I had to recreate my account (my last posts were from a few years ago) I can’t upload the error_pid file, but below is an excerpt.
Updated to M6 yesterday. running on OS X Mojave.

 A fatal error has been detected by the Java Runtime Environment:
#
#  Internal Error (sharedRuntime.cpp:834), pid=80390, tid=82443
#  fatal error: exception happened outside interpreter, nmethods and vtable stubs at pc 0x000000010ae96acf
#
# JRE version: Java(TM) SE Runtime Environment (8.0_40-b25) (build 1.8.0_40-b25)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (25.40-b25 mixed mode bsd-amd64 compressed oops)
# Failed to write core dump. Core dumps have been disabled. To enable core dumping, try "ulimit -c unlimited" before starting Java again
#
# If you would like to submit a bug report, please visit:
#   http://bugreport.java.com/bugreport/crash.jsp
#

---------------  T H R E A D  ---------------

Current thread (0x00007ff747aba800):  JavaThread "HttpClient@1529fbf8-1916" [_thread_in_Java, id=82443, stack(0x000070000456a000,0x000070000466a000)]

Stack: [0x000070000456a000,0x000070000466a000],  sp=0x0000700004667920,  free space=1014k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.dylib+0x58e7ba]
V  [libjvm.dylib+0x1e03af]
V  [libjvm.dylib+0x4c924b]
V  [libjvm.dylib+0x46fd67]
V  [libjvm.dylib+0x46c147]
C  [libsystem_platform.dylib+0x4b5d]  _sigtramp+0x1d
C  0x00007000046681e8
J 22893 C2 com.sun.crypto.provider.GCTR.doFinal([BII[BI)I (130 bytes) @ 0x000000010c2c42e8 [0x000000010c2c3f40+0x3a8]


---------------  P R O C E S S  ---------------

Java Threads: ( => current thread )
  0x00007ff745f91800 JavaThread "upnp-async-815" [_thread_blocked, id=104787, stack(0x000070000c6ea000,0x000070000c7ea000)]
  0x00007ff7350b7800 JavaThread "upnp-async-814" [_thread_blocked, id=101559, stack(0x000070000c5e7000,0x000070000c6e7000)]
  0x00007ff7350b6800 JavaThread "upnp-async-813" [_thread_blocked, id=100619, stack(0x000070000c4e4000,0x000070000c5e4000)]
  0x00007ff73514e800 JavaThread "upnp-async-812" [_thread_blocked, id=131431, stack(0x000070000c3e1000,0x000070000c4e1000)]
  0x00007ff735161800 JavaThread "upnp-async-811" [_thread_blocked, id=80007, stack(0x000070000c1db000,0x000070000c2db000)]

  0x00007ff773842800 JavaThread "upnp-async-810" [_thread_blocked, id=132163, stack(0x000070000aea2000,0x000070000afa2000)]
  0x00007ff746391000 JavaThread "upnp-main-264" [_thread_blocked, id=130855, stack(0x000070000ad9f000,0x000070000ae9f000)]
  0x00007ff744922800 JavaThread "upnp-main-263" [_thread_blocked, id=164931, stack(0x000070000a68a000,0x000070000a78a000)]
  0x00007ff746151000 JavaThread "upnp-async-809" [_thread_blocked, id=175911, stack(0x000070000a27e000,0x000070000a37e000)]
  0x00007ff744848800 JavaThread "OH-discovery-109" daemon [_thread_blocked, id=77091, stack(0x00007000067d0000,0x00007000068d0000)]
  0x00007ff741084000 JavaThread "OH-common-67" daemon [_thread_blocked, id=132435, stack(0x000070000d005000,0x000070000d105000)]
  0x00007ff745f88000 JavaThread "pool-78-thread-1" [_thread_blocked, id=71303, stack(0x000070000cf02000,0x000070000d002000)]
  0x00007ff747f99000 JavaThread "OH-homematicGateway-127" daemon [_thread_blocked, id=118607, stack(0x0000700004c7f000,0x0000700004d7f000)]
  0x00007ff744872800 JavaThread "OH-scheduler-67" daemon [_thread_blocked, id=105051, stack(0x000070000ac9c000,0x000070000ad9c000)]
  0x00007ff73515d800 JavaThread "HttpClient@1529fbf8-2067" [_thread_blocked, id=133923, stack(0x000070000ab99000,0x000070000ac99000)]
  0x00007ff744c8e800 JavaThread "HttpClient@1529fbf8-2066" [_thread_blocked, id=101131, stack(0x0000700009e72000,0x0000700009f72000)]
  0x00007ff7352e2000 JavaThread "OH-homematicGateway-126" daemon [_thread_blocked, id=82995, stack(0x00007000061be000,0x00007000062be000)]
  0x00007ff744a58000 JavaThread "OH-discovery-108" daemon [_thread_blocked, id=134183, stack(0x00007000057a0000,0x00007000058a0000)]
  0x00007ff745f17800 JavaThread "items-114" [_thread_blocked, id=128619, stack(0x00007000060bb000,0x00007000061bb000)]
  0x00007ff744918000 JavaThread "pool-77-thread-1" [_thread_blocked, id=166151, stack(0x000070000cbf9000,0x000070000ccf9000)]
  0x00007ff744956000 JavaThread "pool-76-thread-1" [_thread_blocked, id=61471, stack(0x000070000cdff000,0x000070000ceff000)]
  0x00007ff745f55800 JavaThread "OH-common-64" daemon [_thread_blocked, id=80867, stack(0x0000700009454000,0x0000700009554000)]
  0x00007ff735150800 JavaThread "jupnp-jetty-client-2014" daemon [_thread_blocked, id=104115, stack(0x0000700009d6f000,0x0000700009e6f000)]
  0x00007ff744a62800 JavaThread "jupnp-jetty-client-2013" daemon [_thread_in_native, id=138887, stack(0x0000700006de2000,0x0000700006ee2000)]
  0x00007ff7460b7800 JavaThread "qtp1263082990-2010" [_thread_blocked, id=102163, stack(0x000070000bfd5000,0x000070000c0d5000)]
  0x00007ff744855800 JavaThread "qtp1263082990-2005" [_thread_in_native, id=165535, stack(0x000070000caf6000,0x000070000cbf6000)]
  0x00007ff747e1f800 JavaThread "qtp1263082990-2004" [_thread_blocked, id=137539, stack(0x000070000c9f3000,0x000070000caf3000)]
  0x00007ff745834000 JavaThread "qtp1263082990-2003" [_thread_blocked, id=140519, stack(0x000070000c8f0000,0x000070000c9f0000)]
  0x00007ff744f80000 JavaThread "qtp1263082990-2002" [_thread_blocked, id=117019, stack(0x000070000c7ed000,0x000070000c8ed000)]
  0x00007ff747c24000 JavaThread "items-113" [_thread_blocked, id=90515, stack(0x0000700006bdc000,0x0000700006cdc000)]
  0x00007ff744959000 JavaThread "OH-scheduler-63" daemon [_thread_blocked, id=47799, stack(0x0000700006ad9000,0x0000700006bd9000)]
=>0x00007ff747aba800 JavaThread "HttpClient@1529fbf8-1916" [_thread_in_Java, id=82443, stack(0x000070000456a000,0x000070000466a000)]
  0x00007ff745dbf000 JavaThread "jupnp-jetty-client-1879" daemon [_thread_in_native, id=118791, stack(0x000070000a381000,0x000070000a481000)]
  0x00007ff73515f800 JavaThread "items-112" [_thread_blocked, id=217963, stack(0x000070000bed2000,0x000070000bfd2000)]
  0x00007ff74499a800 JavaThread "HttpClient@1529fbf8-1777" [_thread_blocked, id=115551, stack(0x00007000068d3000,0x00007000069d3000)]
  0x00007ff745b3b800 JavaThread "items-110" [_thread_blocked, id=102483, stack(0x00007000064c7000,0x00007000065c7000)]
  0x00007ff773ba3800 JavaThread "jupnp-jetty-client-1570" daemon [_thread_in_native, id=90647, stack(0x0000700008d3f000,0x0000700008e3f000)]
  0x00007ff744857800 JavaThread "qtp2084260425-1423" [_thread_blocked, id=149303, stack(0x000070000518e000,0x000070000528e000)]
  0x00007ff745b38800 JavaThread "pool-2-thread-1" [_thread_blocked, id=172823, stack(0x0000700009351000,0x0000700009451000)]
  0x00007ff744fdd000 JavaThread "jupnp-jetty-client-796" daemon [_thread_in_native, id=131083, stack(0x000070000bdcf000,0x000070000becf000)]
  0x00007ff745dc3800 JavaThread "HttpClient@1529fbf8-744" [_thread_in_native, id=165163, stack(0x000070000aa96000,0x000070000ab96000)]
 0x00007ff745ccf000 JavaThread "HttpClient@1529fbf8-504" [_thread_in_native, id=169735, stack(0x000070000bccc000,0x000070000bdcc000)]
  0x00007ff744a1d800 JavaThread "HttpClient@1529fbf8-503" [_thread_in_native, id=122383, stack(0x000070000afa5000,0x000070000b0a5000)]
  0x00007ff74585a800 JavaThread "qtp1263082990-475" [_thread_in_native, id=141323, stack(0x000070000862a000,0x000070000872a000)]
  0x00007ff7449e8800 JavaThread "qtp1263082990-474" [_thread_blocked, id=51723, stack(0x00007000074f7000,0x00007000075f7000)]
  0x00007ff747bfe800 JavaThread "qtp1263082990-471" [_thread_in_native, id=35347, stack(0x00007000066cd000,0x00007000067cd000)]
  0x00007ff74486f800 JavaThread "Thread-116" daemon [_thread_blocked, id=64263, stack(0x0000700004467000,0x0000700004567000)]
  0x00007ff747e32000 JavaThread "Thread-114" daemon [_thread_in_native, id=131591, stack(0x0000700004a79000,0x0000700004b79000)]
  0x00007ff744a13800 JavaThread "OH-homematicGateway-3" daemon [_thread_blocked, id=31239, stack(0x0000700004976000,0x0000700004a76000)]
  0x00007ff741048800 JavaThread "OH-homematicGateway-2" daemon [_thread_blocked, id=148487, stack(0x000070000c2de000,0x000070000c3de000)]
  0x00007ff791180800 JavaThread "nioEventLoopGroup-2-1" [_thread_in_native, id=217607, stack(0x0000700014f7f000,0x000070001507f000)]
  0x00007ff747939000 JavaThread "JmDNS(192-168-1-59.local.).State.Timer" [_thread_blocked, id=218115, stack(0x0000700014d79000,0x0000700014e79000)]
  0x00007ff747b0b000 JavaThread "JmDNS(192-168-1-59.local.).Timer" daemon [_thread_blocked, id=175107, stack(0x0000700014c76000,0x0000700014d76000)]
  0x00007ff747a92800 JavaThread "SocketListener(192-168-1-59.local.)" daemon [_thread_in_native, id=174595, stack(0x0000700014b73000,0x0000700014c73000)]
  0x00007ff744f54800 JavaThread "Timer-13" daemon [_thread_blocked, id=152323, stack(0x0000700014a70000,0x0000700014b70000)]
  0x00007ff7415f6800 JavaThread "Timer-12" daemon [_thread_blocked, id=153091, stack(0x000070001496d000,0x0000700014a6d000)]
  0x00007ff7443fe800 JavaThread "Refresh Thread: Equinox Container: 17681a7d-af5e-48aa-82b4-cb04ac225a89" daemon [_thread_blocked, id=120583, stack(0x000070000c0d8000,0x000070000c1d8000)]
  0x00007ff732289000 JavaThread "items-4" [_thread_blocked, id=70407, stack(0x0000700009048000,0x0000700009148000)]
  0x00007ff740410000 JavaThread "OkHttp ConnectionPool" daemon [_thread_blocked, id=138243, stack(0x00007000113ce000,0x00007000114ce000)]
  0x00007ff7425a6000 JavaThread "pool-23-thread-1" [_thread_blocked, id=166659, stack(0x00007000112cb000,0x00007000113cb000)]
  0x00007ff790f01000 JavaThread "qtp2084260425-327" [_thread_in_native, id=137731, stack(0x00007000111c8000,0x00007000112c8000)]
  0x00007ff7323f5800 JavaThread "qtp2084260425-326" [_thread_in_native, id=167171, stack(0x00007000110c5000,0x00007000111c5000)]
  0x00007ff743327000 JavaThread "Connector-Scheduler-1c9bbb2c" [_thread_blocked, id=167939, stack(0x0000700010ebf000,0x0000700010fbf000)]
  0x00007ff731b0c000 JavaThread "qtp2084260425-323" [_thread_blocked, id=137219, stack(0x0000700010dbc000,0x0000700010ebc000)]
  0x00007ff731afd000 JavaThread "qtp2084260425-322-acceptor-0@e4b94c5-ServerConnector@1c9bbb2c{HTTP/1.1,[http/1.1]}{192.168.1.56:9125}" [_thread_in_native, id=136963, stack(0x0000700010cb9000,0x0000700010db9000)]
  0x00007ff7317d5800 JavaThread "qtp2084260425-321" [_thread_in_native, id=168707, stack(0x0000700010bb6000,0x0000700010cb6000)]
  0x00007ff731a34000 JavaThread "qtp2084260425-320" [_thread_in_native, id=136195, stack(0x0000700010ab3000,0x0000700010bb3000)]
  0x00007ff7a0e85800 JavaThread "qtp2084260425-319" [_thread_in_native, id=135939, stack(0x00007000109b0000,0x0000700010ab0000)]
  0x00007ff74375b000 JavaThread "qtp2084260425-318" [_thread_in_native, id=169475, stack(0x00007000108ad000,0x00007000109ad000)]
  0x00007ff734386800 JavaThread "ESH-httpClient-common-308" daemon [_thread_in_native, id=172547, stack(0x000070000fe8f000,0x000070000ff8f000)]
  0x00007ff74151f000 JavaThread "ESH-httpClient-common-303" daemon [_thread_in_native, id=174083, stack(0x000070000f980000,0x000070000fa80000)]
  0x00007ff732246800 JavaThread "OH-thingHandler-5" daemon [_thread_in_native, id=108035, stack(0x000070000f26b000,0x000070000f36b000)]
  0x00007ff77280c800 JavaThread "HttpClient@1529fbf8-294" [_thread_in_native, id=112131, stack(0x000070000f065000,0x000070000f165000)]
  0x00007ff747a51800 JavaThread "OH-thingHandler-4" daemon [_thread_blocked, id=112387, stack(0x000070000ef62000,0x000070000f062000)]

.... [ and so forth ]

  0x00007ff7b0800000 JavaThread "main" [_thread_blocked, id=9219, stack(0x0000700000ec8000,0x0000700000fc8000)]

Other Threads:
  0x00007ff7b0833800 VMThread [stack: 0x0000700002916000,0x0000700002a16000] [id=22531]
  0x00007ff791001000 WatcherThread [stack: 0x000070000353a000,0x000070000363a000] [id=26883]

VM state:not at safepoint (normal execution)

VM Mutex/Monitor currently owned by a thread: None

Heap:
 garbage-first heap   total 524288K, used 337888K [0x00000005c0000000, 0x00000005c0200800, 0x00000007c0000000)
  region size 2048K, 128 young (262144K), 14 survivors (28672K)
 Metaspace       used 103589K, capacity 117180K, committed 117324K, reserved 1150976K
  class space    used 12476K, capacity 15893K, committed 15948K, reserved 1048576K

Heap Regions: (Y=young(eden), SU=young(survivor), HS=humongous(starts), HC=humongous(continues), CS=collection set, F=free, TS=gc time stamp, PTAMS=previous top-at-mark-start, NTAMS=next top-at-mark-start)
AC   0  O    TS     0 PTAMS 0x00000005c0200000 NTAMS 0x00000005c0200000 space 2048K, 100% used [0x00000005c0000000, 0x00000005c0200000)
AC   0  O    TS     0 PTAMS 0x00000005c0400000 NTAMS 0x00000005c0400000 space 2048K, 100% used [0x00000005c0200000, 0x00000005c0400000)
AC   0  O    TS     0 PTAMS 0x00000005c0600000 NTAMS 0x00000005c0600000 space 2048K, 100% used [0x00000005c0400000, 0x00000005c0600000)
AC   0  O    TS     0 PTAMS 0x00000005c0800000 NTAMS 0x00000005c0800000 space 2048K, 100% used [0x00000005c0600000, 0x00000005c0800000)
AC   0  O    TS     0 PTAMS 0x00000005c0a00000 NTAMS 0x00000005c0a00000 space 2048K, 100% used [0x00000005c0800000, 0x00000005c0a00000)
AC   0  O    TS     0 PTAMS 0x00000005c0c00000 NTAMS 0x00000005c0c00000 space 2048K, 100% used [0x00000005c0a00000, 0x00000005c0c00000)
AC   0  O    TS     0 PTAMS 0x00000005c0e00000 NTAMS 0x00000005c0e00000 space 2048K, 100% used [0x00000005c0c00000, 0x00000005c0e00000)
AC   0  O    TS     0 PTAMS 0x00000005c1000000 NTAMS 0x00000005c1000000 space 2048K, 100% used [0x00000005c0e00000, 0x00000005c1000000)
AC   0  O    TS     0 PTAMS 0x00000005c1200000 NTAMS 0x00000005c1200000 space 2048K, 100% used [0x00000005c1000000, 0x00000005c1200000)
.... several hundred lines omitted ....
ava_command: org.apache.karaf.main.Main
java_class_path (initial): /Users/martin/OH/runtime/lib/boot/org.apache.karaf.diagnostic.boot-4.2.7.jar:/Users/martin/OH/runtime/lib/boot/org.apache.karaf.jaas.boot-4.2.7.jar:/Users/martin/OH/runtime/lib/boot/org.apache.karaf.main-4.2.7.jar:/Users/martin/OH/runtime/lib/boot/org.apache.karaf.specs.activator-4.2.7.jar:/Users/martin/OH/runtime/lib/boot/osgi.core-6.0.0.jar
Launcher Type: SUN_STANDARD

Environment Variables:
PATH=/usr/local/sbin:/usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/bin:/opt/X11/bin:/usr/texbin
LD_LIBRARY_PATH=/Users/martin/OH/userdata/lib:/Users/martin/OH/runtime/lib
SHELL=/bin/bash
DISPLAY=/private/tmp/com.apple.launchd.xkIpt67VgL/org.macosforge.xquartz:0

Signal Handlers:
SIGSEGV: [libjvm.dylib+0x58ef95], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_ONSTACK|SA_RESTART|SA_SIGINFO
SIGBUS: [libjvm.dylib+0x58ef95], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGFPE: [libjvm.dylib+0x46c118], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGPIPE: [libjvm.dylib+0x46c118], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGXFSZ: [libjvm.dylib+0x46c118], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGILL: [libjvm.dylib+0x46c118], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGUSR1: SIG_DFL, sa_mask[0]=11011111011111100000000111000110, sa_flags=none
SIGUSR2: [libjvm.dylib+0x46bc36], sa_mask[0]=00000000000000000000000000000000, sa_flags=SA_RESTART|SA_SIGINFO
SIGHUP: [libjvm.dylib+0x46a209], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGINT: [libjvm.dylib+0x46a209], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGTERM: [libjvm.dylib+0x46a209], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGQUIT: [libjvm.dylib+0x46a209], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO


---------------  S Y S T E M  ---------------

OS:Bsduname:Darwin 18.7.0 Darwin Kernel Version 18.7.0: Tue Aug 20 16:57:14 PDT 2019; root:xnu-4903.271.2~2/RELEASE_X86_64 x86_64
rlimit: STACK 8192k, CORE 0k, NPROC 2837, NOFILE 10240, AS infinity
load average:2,69 2,50 2,25

CPU:total 12 (6 cores per cpu, 2 threads per core) family 6 model 62 stepping 4, cmov, cx8, fxsr, mmx, sse, sse2, sse3, ssse3, sse4.1, sse4.2, popcnt, avx, aes, clmul, erms, ht, tsc, tscinvbit

Memory: 4k page, physical 33554432k(2319448k free)

/proc/meminfo:


vm_info: Java HotSpot(TM) 64-Bit Server VM (25.40-b25) for bsd-amd64 JRE (1.8.0_40-b25), built on Feb 10 2015 21:07:25 by "java_re" with gcc 4.2.1 (Based on Apple Inc. build 5658) (LLVM build 2336.11.00)

time: Mon Dec  2 18:53:49 2019
elapsed time: 3214 seconds (0d 0h 53m 34s)

Any ideas? Been running OH for years now, never had it crash on me. Most recent change (beside the update to M6) is the inclusion of the Unifi Binding and switching on debugging for it.

Clemens

Bruce_Osborne · December 2, 2019, 9:23pm

Try without the Unifi binding? It might be a worthwhile debugging step since that was a recent change.

Jonny0stars · December 2, 2019, 9:54pm

I’ve got an odd issue between milestone 5 and milestone 6, the basicUI is mostly missing, I’ve got several nested groups, one for each room, some basic items like sliders appear, however colour wheels/pickers do not, instead showing a blank page, the label structure remains but they’re not populated with any items. I can’t see any errors in the log, though I’ve not tried debug/verbose yet.

I have a global colour wheel in a frame that appears on the main page, altering its value now gives me errors in the console -

2019-12-02 21:36:34.651 [WARN ] [rest.core.internal.item.ItemResource] - Received HTTP POST request at 'items/gColor' with an invalid status value '331,91,100'.

Things I’ve tried

Remove/clear cache
Restart
Uninstall/Reinstall via apt (running on rpi3 on raspbian)

I’ll try jumping back to M5 to see if the problem goes away and report back

Bruce_Osborne · December 2, 2019, 9:58pm

Try clearing browser cache?

Jonny0stars · December 2, 2019, 10:26pm

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.

wborn · December 2, 2019, 10:45pm

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

Hotrodwinston · December 3, 2019, 3:51am

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!

cmar · December 3, 2019, 10:02am

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

mark_leonard_tuil · December 3, 2019, 6:01pm

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?

vzorglub · December 3, 2019, 6:07pm

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

mark_leonard_tuil · December 3, 2019, 6:39pm

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.

Mordor · December 3, 2019, 8:18pm

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.

to_so · December 3, 2019, 9:56pm

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.

Bruce_Osborne · December 3, 2019, 10:38pm

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