openHAB crashed twice in past week

After years of running various version of openHAB with nothing other than occasional minor problems and known glitches, I’ve had the entire service crash out twice within the past week. I’m not really sure what to do about the problem, since I can’t even see what binding or process is causing it. The most recent one happened just before 4am today, so it’s not related to any human interaction, and nor are there any scheduled things set to happen then, except those which happen every minute (such as updating electricity consumption, running a shell script to get a JSON of power prices, and loading weather from a rules file periodically written out by my local weather station software).

  • Platform information:
    • Hardware: Mac Mini 2.6GHz quad-core intel core i7, 16GB RAM
    • OS: Mac OS Catalina 10.15.7
    • Java Runtime Environment: see below
    • openHAB version: 3.2.0 release

What the process dumps to the command line is as follows, and I’ll also paste the contents of the err log referred to in that. Unfortunately I have to trim a large proportion of the error log for the character limit, so please tell me if there’s something I should extract from there to share specifically.

I’m quite worried that it now seems openHAB may crash randomly when it has never done so in the past. Any ideas?

#
# A fatal error has been detected by the Java Runtime Environment:
#
# SIGSEGV (0xb) at pc=0x000000010b70f818, pid=27833, tid=12547
#
# JRE version: OpenJDK Runtime Environment Zulu11.45+27-CA (11.0.10+9) (build 11.0.10+9-LTS)
# Java VM: OpenJDK 64-Bit Server VM Zulu11.45+27-CA (11.0.10+9-LTS, mixed mode, tiered, compressed oops, g1 gc, bsd-amd64)
# Problematic frame:
# V [libjvm.dylib+0x30f818] _ZN16G1ConcurrentMark19mark_in_next_bitmapEjP10HeapRegionP7oopDescm+0xb4
#
# No core dump will be written. 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/robin/openhab/userdata/hs_err_pid27833.log
#
# If you would like to submit a bug report, please visit:
# http://www.azulsystems.com/support/
#
/Users/robin/openhab/runtime/bin/karaf: line 177: 27833 Abort trap: 6 ${KARAF_EXEC} "${JAVA}" ${JAVA_OPTS} --add-reads=java.xml=java.logging --add-exports=java.base/org.apache.karaf.specs.locator=java.xml,ALL-UNNAMED --patch-module "java.base=${KARAF_HOME}/lib/endorsed/org.apache.karaf.specs.locator-4.3.4.jar" --patch-module "java.xml=${KARAF_HOME}/lib/endorsed/org.apache.karaf.specs.java.xml-4.3.4.jar" --add-opens java.base/java.security=ALL-UNNAMED --add-opens java.base/java.net=ALL-UNNAMED --add-opens java.base/java.lang=ALL-UNNAMED --add-opens java.base/java.util=ALL-UNNAMED --add-opens java.naming/javax.naming.spi=ALL-UNNAMED --add-opens java.rmi/sun.rmi.transport.tcp=ALL-UNNAMED --add-opens java.base/java.io=ALL-UNNAMED --add-opens java.base/java.lang.reflect=ALL-UNNAMED --add-opens java.base/java.text=ALL-UNNAMED --add-opens java.base/java.time=ALL-UNNAMED --add-opens java.desktop/java.awt.font=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.file=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.ftp=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.http=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.https=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.jar=ALL-UNNAMED --add-exports=java.base/sun.net.www.content.text=ALL-UNNAMED --add-exports=jdk.xml.dom/org.w3c.dom.html=ALL-UNNAMED --add-exports=jdk.naming.rmi/com.sun.jndi.url.rmi=ALL-UNNAMED --add-exports=java.rmi/sun.rmi.registry=ALL-UNNAMED --add-exports=java.security.sasl/com.sun.security.sasl=ALL-UNNAMED -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} "$@"
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x000000010b70f818, pid=27833, tid=12547
#
# JRE version: OpenJDK Runtime Environment Zulu11.45+27-CA (11.0.10+9) (build 11.0.10+9-LTS)
# Java VM: OpenJDK 64-Bit Server VM Zulu11.45+27-CA (11.0.10+9-LTS, mixed mode, tiered, compressed oops, g1 gc, bsd-amd64)
# Problematic frame:
# V  [libjvm.dylib+0x30f818]  _ZN16G1ConcurrentMark19mark_in_next_bitmapEjP10HeapRegionP7oopDescm+0xb4
#
# No core dump will be written. 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://www.azulsystems.com/support/
#

---------------  S U M M A R Y ------------

Command Line: -XX:-UsePerfData -Dlog4j2.formatMsgNoLookups=true -Dopenhab.home=/Users/robin/openhab -Dopenhab.conf=/Users/robin/openhab/conf -Dopenhab.runtime=/Users/robin/openhab/runtime -Dopenhab.userdata=/Users/robin/openhab/userdata -Dopenhab.logdir=/Users/robin/openhab/userdata/logs -Dfelix.cm.dir=/Users/robin/openhab/userdata/config -Djava.library.path=/Users/robin/openhab/userdata/tmp/lib -Djetty.host=0.0.0.0 -Djetty.http.compliance=RFC2616 -Dnashorn.args=--no-deprecation-warning -Dorg.apache.cxf.osgi.http.transport.disable=true -Dorg.ops4j.pax.web.listening.addresses=0.0.0.0 -Dorg.osgi.service.http.port=8080 -Dorg.osgi.service.http.port.secure=8443 -Djava.awt.headless=true -Dfile.encoding=UTF-8 -XX:+UseG1GC --add-reads=java.xml=java.logging --add-exports=java.base/org.apache.karaf.specs.locator=java.xml,ALL-UNNAMED --patch-module=java.base=/Users/robin/openhab/runtime/lib/endorsed/org.apache.karaf.specs.locator-4.3.4.jar --patch-module=java.xml=/Users/robin/openhab/runtime/lib/endorsed/org.apache.karaf.specs.java.xml-4.3.4.jar --add-opens=java.base/java.security=ALL-UNNAMED --add-opens=java.base/java.net=ALL-UNNAMED --add-opens=java.base/java.lang=ALL-UNNAMED --add-opens=java.base/java.util=ALL-UNNAMED --add-opens=java.naming/javax.naming.spi=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport.tcp=ALL-UNNAMED --add-opens=java.base/java.io=ALL-UNNAMED --add-opens=java.base/java.lang.reflect=ALL-UNNAMED --add-opens=java.base/java.text=ALL-UNNAMED --add-opens=java.base/java.time=ALL-UNNAMED --add-opens=java.desktop/java.awt.font=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.file=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.ftp=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.http=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.https=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.jar=ALL-UNNAMED --add-exports=java.base/sun.net.www.content.text=ALL-UNNAMED --add-exports=jdk.xml.dom/org.w3c.dom.html=ALL-UNNAMED --add-exports=jdk.naming.rmi/com.sun.jndi.url.rmi=ALL-UNNAMED --add-exports=java.rmi/sun.rmi.registry=ALL-UNNAMED --add-exports=java.security.sasl/com.sun.security.sasl=ALL-UNNAMED -Dkaraf.instances=/Users/robin/openhab/userdata/tmp/instances -Dkaraf.home=/Users/robin/openhab/runtime -Dkaraf.base=/Users/robin/openhab/userdata -Dkaraf.data=/Users/robin/openhab/userdata -Dkaraf.etc=/Users/robin/openhab/userdata/etc -Dkaraf.log=/Users/robin/openhab/userdata/logs -Dkaraf.restart.jvm.supported=true -Djava.io.tmpdir=/Users/robin/openhab/userdata/tmp -Djava.util.logging.config.file=/Users/robin/openhab/userdata/etc/java.util.logging.properties -Dkaraf.startLocalConsole=true -Dkaraf.startRemoteShell=true org.apache.karaf.main.Main

Host: Macmini6,2 x86_64 2600 MHz, 8 cores, 16G, Darwin 19.6.0
Time: Thu Feb 24 03:56:13 2022 AEDT elapsed time: 195450.018828 seconds (2d 6h 17m 30s)

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

Current thread (0x00007fc047042000):  ConcurrentGCThread "G1 Conc#0" [stack: 0x000070000da09000,0x000070000db09000] [id=12547]

Stack: [0x000070000da09000,0x000070000db09000],  sp=0x000070000db08c50,  free space=1023k
Native frames: (J=compiled Java code, A=aot compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.dylib+0x30f818]  _ZN16G1ConcurrentMark19mark_in_next_bitmapEjP10HeapRegionP7oopDescm+0xb4
V  [libjvm.dylib+0x310bbf]  _ZN8G1CMTask19make_reference_greyEP7oopDesc+0x43
V  [libjvm.dylib+0x310b79]  _ZN14G1CMOopClosure11do_oop_workIjEEvPT_+0x2d
V  [libjvm.dylib+0x3126da]  _ZN13ObjArrayKlass32oop_oop_iterate_elements_boundedIj14G1CMOopClosureEEvP15objArrayOopDescPT0_PvS6_+0x4a
V  [libjvm.dylib+0x31c6a7]  _ZN21G1CMObjArrayProcessor19process_array_sliceEP15objArrayOopDescP8HeapWordm+0x81
V  [libjvm.dylib+0x319653]  _ZN8G1CMTask23process_grey_task_entryILb1EEEv16G1TaskQueueEntry+0xe7
V  [libjvm.dylib+0x3141a2]  _ZN8G1CMTask17drain_local_queueEb+0x116
V  [libjvm.dylib+0x314069]  _ZN17G1CMBitMapClosure7do_addrEP8HeapWord+0x35
V  [libjvm.dylib+0x318daf]  _ZN10G1CMBitMap7iterateEP17G1CMBitMapClosure9MemRegion+0x1dd
V  [libjvm.dylib+0x3186d3]  _ZN8G1CMTask15do_marking_stepEdbb+0x1d1
V  [libjvm.dylib+0x319b4c]  _ZN25G1CMConcurrentMarkingTask4workEj+0xa6
V  [libjvm.dylib+0x7eb1a1]  _ZN10GangWorker4loopEv+0x43
V  [libjvm.dylib+0x776fe4]  _ZN6Thread8call_runEv+0x68
V  [libjvm.dylib+0x6244a7]  _ZL19thread_native_entryP6Thread+0x139
C  [libsystem_pthread.dylib+0x6109]  _pthread_start+0x94
C  [libsystem_pthread.dylib+0x1b8b]  thread_start+0xf


siginfo: si_signo: 11 (SIGSEGV), si_code: 1 (SEGV_MAPERR), si_addr: 0x0000000000000058

Register to memory mapping:

RAX=0x000000010bda0b30: _ZN8Universe13_narrow_klassE+0 in /Library/Java/JavaVirtualMachines/zulu-11.jdk/Contents/Home/lib/server/libjvm.dylib at 0x000000010b400000
RBX=0x0000000000091a79 is an unknown value
RCX=0x0842108421084203 is an unknown value
RDX=0x0000000040000001 is an unknown value
RSP=0x000070000db08c50 points into unknown readable memory: 0x0000000000000000 | 00 00 00 00 00 00 00 00
RBP=0x000070000db08c70 points into unknown readable memory: 0x000070000db08cb0 | b0 8c b0 0d 00 70 00 00
RSI=0x00000001282893c8 points into unknown readable memory: 0x0842108461084210 | 10 42 08 61 84 10 42 08
RDI=0x0000000000000050 is an unknown value
R8 =0x0 is NULL
R9 =0x000000010bd799a0: _ZN28OopOopIterateBoundedDispatchI14G1CMOopClosureE6_tableE+0 in /Library/Java/JavaVirtualMachines/zulu-11.jdk/Contents/Home/lib/server/libjvm.dylib at 0x000000010b400000
R10=0x0 is NULL
R11=0x0000000000000202 is an unknown value
R12=0x00000006d234f2f0 is pointing into object: biweekly.util.com.google.ical.values.DateTimeValueImpl 
{0x00000006d234f2e8} - klass: 'biweekly/util/com/google/ical/values/DateTimeValueImpl'
R13=0x0000000002460000 is an unknown value
R14=0x0 is NULL
R15=0x00007fc047030600 points into unknown readable memory: 0x00007fc047041000 | 00 10 04 47 c0 7f 00 00


Registers:
RAX=0x000000010bda0b30, RBX=0x0000000000091a79, RCX=0x0842108421084203, RDX=0x0000000040000001
RSP=0x000070000db08c50, RBP=0x000070000db08c70, RSI=0x00000001282893c8, RDI=0x0000000000000050
R8 =0x0000000000000000, R9 =0x000000010bd799a0, R10=0x0000000000000000, R11=0x0000000000000202
R12=0x00000006d234f2f0, R13=0x0000000002460000, R14=0x0000000000000000, R15=0x00007fc047030600
RIP=0x000000010b70f818, EFLAGS=0x0000000000010206, ERR=0x0000000000000004
  TRAPNO=0x000000000000000e

Top of Stack: (sp=0x000070000db08c50)
0x000070000db08c50:   0000000000000000 00007fc047815db8
[trimmed]
0x000070000db08e40:   00007fc047815ef0 00007fc04780bbd0 

Instructions: (pc=0x000000010b70f818)
0x000000010b70f718:   8b 86 b0 00 00 00 49 3b 86 98 00 00 00 75 13 49
[trimmed]
0x000000010b70f908:   8b 86 78 02 00 00 48 89 45 80 0f 10 40 10 0f 11 


Stack slot to memory mapping:
stack at sp + 0 slots: 0x0 is NULL
stack at sp + 1 slots: 0x00007fc047815db8 points into unknown readable memory: 0x00007fc047815db0 | b0 5d 81 47 c0 7f 00 00
stack at sp + 2 slots: 0x00000006d234f2f0 is pointing into object: biweekly.util.com.google.ical.values.DateTimeValueImpl 
{0x00000006d234f2e8} - klass: 'biweekly/util/com/google/ical/values/DateTimeValueImpl'
stack at sp + 3 slots: 0x00007fc047815db0 points into unknown readable memory: 0x000000010bd53590 | 90 35 d5 0b 01 00 00 00
stack at sp + 4 slots: 0x000070000db08cb0 points into unknown readable memory: 0x000070000db08cc0 | c0 8c b0 0d 00 70 00 00
stack at sp + 5 slots: 0x000000010b710bbf: _ZN8G1CMTask19make_reference_greyEP7oopDesc+0x43 in /Library/Java/JavaVirtualMachines/zulu-11.jdk/Contents/Home/lib/server/libjvm.dylib at 0x000000010b400000
stack at sp + 6 slots: 0x000070000db08cb0 points into unknown readable memory: 0x000070000db08cc0 | c0 8c b0 0d 00 70 00 00
stack at sp + 7 slots: 0x000000010b70f8a2: _ZN16G1ConcurrentMark19mark_in_next_bitmapEjP10HeapRegionP7oopDescm+0x13e in /Library/Java/JavaVirtualMachines/zulu-11.jdk/Contents/Home/lib/server/libjvm.dylib at 0x000000010b400000


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

Threads class SMR info:
_java_thread_list=0x00007fc04bef61c0, length=355, elements={
0x00007fc048008800, 0x00007fc049823000, 0x00007fc049826000, 0x00007fc047080000,
[trimmed for character limit
0x00007fc0449b6800, 0x00007fc044dac800, 0x00007fc044953800
}

Java Threads: ( => current thread )
  0x00007fc048008800 JavaThread "main" [_thread_blocked, id=7939, stack(0x000070000d700000,0x000070000d800000)]
  0x00007fc049823000 JavaThread "Reference Handler" daemon [_thread_blocked, id=19203, stack(0x000070000de15000,0x000070000df15000)]
  0x00007fc049826000 JavaThread "Finalizer" daemon [_thread_blocked, id=14595, stack(0x000070000df18000,0x000070000e018000)]
  0x00007fc047080000 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=17155, stack(0x000070000e121000,0x000070000e221000)]
  0x00007fc049827800 JavaThread "Service Thread" daemon [_thread_blocked, id=22275, stack(0x000070000e224000,0x000070000e324000)]
[trimmed]
  0x00007fc0449b6800 JavaThread "presenceDetectionARP_192.168.11.105 utun0" [_thread_blocked, id=134827, stack(0x000070001b494000,0x000070001b594000)]
  0x00007fc044dac800 JavaThread "presenceDetectionICMP_192.168.11.105" [_thread_blocked, id=308539, stack(0x000070001ccdc000,0x000070001cddc000)]
  0x00007fc044953800 JavaThread "OH-file-processing-1637" daemon [_thread_blocked, id=57839, stack(0x0000700020186000,0x0000700020286000)]

Other Threads:
  0x00007fc04981b800 VMThread "VM Thread" [stack: 0x000070000dd12000,0x000070000de12000] [id=19715]
  0x00007fc04b008800 WatcherThread [stack: 0x000070000e733000,0x000070000e833000] [id=24067]
  0x00007fc048028800 GCTaskThread "GC Thread#0" [stack: 0x000070000d803000,0x000070000d903000] [id=11267]
[trimmed]
  0x00007fc0469c6000 ConcurrentGCThread "G1 Refine#3" [stack: 0x000070000f151000,0x000070000f251000] [id=39939]
  0x00007fc04805b800 ConcurrentGCThread "G1 Young RemSet Sampling" [stack: 0x000070000dc0f000,0x000070000dd0f000] [id=20739]

Threads with active compile tasks:

VM state:not at safepoint (normal execution)

VM Mutex/Monitor currently owned by a thread: None

Heap address: 0x00000006c0000000, size: 4096 MB, Compressed Oops mode: Zero based, Oop shift amount: 3
Narrow klass base: 0x0000000000000000, Narrow klass shift: 3
Compressed class space size: 1073741824 Address: 0x00000007c0000000

Heap:
 garbage-first heap   total 651264K, used 308475K [0x00000006c0000000, 0x00000007c0000000)
  region size 1024K, 11 young (11264K), 3 survivors (3072K)
 Metaspace       used 150019K, capacity 163299K, committed 165404K, reserved 1193984K
  class space    used 16605K, capacity 20576K, committed 21168K, reserved 1048576K
Heap Regions: E=young(eden), S=young(survivor), O=old, HS=humongous(starts), HC=humongous(continues), CS=collection set, F=free, A=archive, TAMS=top-at-mark-start (previous, next)
|   0|0x00000006c0000000, 0x00000006c0100000, 0x00000006c0100000|100%| O|  |TAMS 0x00000006c0100000, 0x00000006c0100000| Untracked 
|   1|0x00000006c0100000, 0x00000006c0200000, 0x00000006c0200000|100%| O|  |TAMS 0x00000006c0200000, 0x00000006c0200000| Untracked 
|   2|0x00000006c0200000, 0x00000006c0300000, 0x00000006c0300000|100%| O|  |TAMS 0x00000006c0300000, 0x00000006c0300000| Untracked 
|   3|0x00000006c0300000, 0x00000006c0400000, 0x00000006c0400000|100%| O|  |TAMS 0x00000006c0400000, 0x00000006c0400000| Untracked 
|   4|0x00000006c0400000, 0x00000006c0500000, 0x00000006c0500000|100%| O|  |TAMS 0x00000006c0500000, 0x00000006c0500000| Untracked 
|   5|0x00000006c0500000, 0x00000006c0600000, 0x00000006c0600000|100%| O|  |TAMS 0x00000006c0600000, 0x00000006c0600000| Untracked 
[ heap trimmed for character limit ]
| 634|0x00000006e7a00000, 0x00000006e7b00000, 0x00000006e7b00000|100%| E|CS|TAMS 0x00000006e7a00000, 0x00000006e7a00000| Complete 
| 635|0x00000006e7b00000, 0x00000006e7c00000, 0x00000006e7c00000|100%| E|CS|TAMS 0x00000006e7b00000, 0x00000006e7b00000| Complete 

Card table byte_map: [0x000000010cc11000,0x000000010d411000] _byte_map_base: 0x0000000109611000

Marking Bits (Prev, Next): (CMBitMap*) 0x00007fc047030650, (CMBitMap*) 0x00007fc047030618
 Prev Bits: [0x000000012bdfc000, 0x000000012fdfc000)
 Next Bits: [0x0000000127dfc000, 0x000000012bdfc000)

Polling page: 0x000000010a3fe000

Metaspace:

Usage:
  Non-class:    139.38 MB capacity,   130.29 MB ( 93%) used,     8.62 MB (  6%) free+waste,   486.44 KB ( <1%) overhead. 
      Class:     20.09 MB capacity,    16.22 MB ( 81%) used,     3.65 MB ( 18%) free+waste,   234.38 KB (  1%) overhead. 
       Both:    159.47 MB capacity,   146.50 MB ( 92%) used,    12.26 MB (  8%) free+waste,   720.81 KB ( <1%) overhead. 

Virtual space:
  Non-class space:      142.00 MB reserved,     140.86 MB (>99%) committed 
      Class space:        1.00 GB reserved,      20.67 MB (  2%) committed 
             Both:        1.14 GB reserved,     161.53 MB ( 14%) committed 

Chunk freelists:
   Non-Class:  1.33 MB
       Class:  512.00 KB
        Both:  1.83 MB

MaxMetaspaceSize: unlimited
CompressedClassSpaceSize: 1.00 GB

CodeHeap 'non-profiled nmethods': size=120032Kb used=41800Kb max_used=41933Kb free=78231Kb
 bounds [0x00000001208c4000, 0x00000001231c4000, 0x0000000127dfc000]
CodeHeap 'profiled nmethods': size=120028Kb used=58055Kb max_used=58948Kb free=61972Kb
 bounds [0x000000011938d000, 0x000000011ce9d000, 0x00000001208c4000]
CodeHeap 'non-nmethods': size=5700Kb used=1468Kb max_used=1535Kb free=4231Kb
 bounds [0x0000000118dfc000, 0x000000011906c000, 0x000000011938d000]
 total_blobs=30022 nmethods=29024 adapters=907
 compilation: enabled
              stopped_count=0, restarted_count=0
 full_count=0

Compilation events (20 events):
Event: 194516.535 Thread 0x00007fc04680b800 40226       3       sun.security.ssl.SSLAlgorithmConstraints::<init> (30 bytes)
[trimmed]
org.jupnp.model.meta.StateVariableTypeDetails::validate (235 bytes)
Event: 195075.495 Thread 0x00007fc049828800 nmethod 40235 0x00000001225bb310 code [0x00000001225bb520, 0x00000001225bbca0]

GC Heap History (20 events):
Event: 194892.688 GC heap before
{Heap before GC invocations=2791 (full 0):
 garbage-first heap   total 651264K, used 572906K [0x00000006c0000000, 0x00000007c0000000)
  region size 1024K, 294 young (301056K), 6 survivors (6144K)
 Metaspace       used 150023K, capacity 163305K, committed 165404K, reserved 1193984K
  class space    used 16605K, capacity 20577K, committed 21168K, reserved 1048576K
}
Event: 194892.700 GC heap after
{Heap after GC invocations=2792 (full 0):
 garbage-first heap   total 651264K, used 291363K [0x00000006c0000000, 0x00000007c0000000)
  region size 1024K, 18 young (18432K), 18 survivors (18432K)
 Metaspace       used 150023K, capacity 163305K, committed 165404K, reserved 1193984K
  class space    used 16605K, capacity 20577K, committed 21168K, reserved 1048576K
}
[trimmed]
Event: 195449.905 GC heap after
{Heap after GC invocations=2804 (full 0):
 garbage-first heap   total 651264K, used 301307K [0x00000006c0000000, 0x00000007c0000000)
  region size 1024K, 3 young (3072K), 3 survivors (3072K)
 Metaspace       used 150019K, capacity 163299K, committed 165404K, reserved 1193984K
  class space    used 16605K, capacity 20576K, committed 21168K, reserved 1048576K
}

Deoptimization events (20 events):
Event: 190157.691 Thread 0x00007fc04855b000 DEOPT PACKING pc=0x00000001230bc634 sp=0x0000700019b45880
Event: 190157.691 Thread 0x00007fc04855b000 DEOPT UNPACKING pc=0x0000000118e228a5 sp=0x0000700019b45838 mode 2
[trimmed]
Event: 190488.945 Thread 0x00007fc04ab3a000 DEOPT UNPACKING pc=0x0000000118e226ba sp=0x0000700016fc3d88 mode 0

Classes redefined (0 events):
No events

Internal exceptions (20 events):
Event: 195402.398 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d99a8c08}: Receive timed out> (0x00000006d99a8c08) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195405.400 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d99a91a8}: Receive timed out> (0x00000006d99a91a8) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195409.396 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d959f010}: Receive timed out> (0x00000006d959f010) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195412.403 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d959f5b0}: Receive timed out> (0x00000006d959f5b0) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195415.408 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d959fb50}: Receive timed out> (0x00000006d959fb50) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195419.398 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d92a9f60}: Receive timed out> (0x00000006d92a9f60) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195421.480 Thread 0x00007fc047581000 Exception <a 'java/net/SocketTimeoutException'{0x00000006d9074350}: Read timed out> (0x00000006d9074350) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195422.408 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d92aa298}: Receive timed out> (0x00000006d92aa298) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195425.412 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d8d81758}: Receive timed out> (0x00000006d8d81758) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195428.019 Thread 0x00007fc05168e800 Exception <a 'java/net/ConnectException'{0x00000006d8a126a0}> (0x00000006d8a126a0) thrown at [./src/hotspot/share/prims/jni.cpp, line 615]
Event: 195429.398 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d8dbc7b8}: Receive timed out> (0x00000006d8dbc7b8) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195432.404 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d8dbcd58}: Receive timed out> (0x00000006d8dbcd58) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195435.411 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d8dbd2f8}: Receive timed out> (0x00000006d8dbd2f8) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195436.390 Thread 0x00007fc047581000 Exception <a 'java/net/SocketTimeoutException'{0x00000006d86495b0}: Read timed out> (0x00000006d86495b0) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195437.553 Thread 0x00007fc047581000 Exception <a 'java/net/SocketTimeoutException'{0x00000006d854f2f8}: Read timed out> (0x00000006d854f2f8) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195439.139 Thread 0x00007fc047581000 Exception <a 'java/net/SocketTimeoutException'{0x00000006d8440720}: Read timed out> (0x00000006d8440720) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195439.396 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d8654c38}: Receive timed out> (0x00000006d8654c38) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195442.400 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d86551d8}: Receive timed out> (0x00000006d86551d8) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195445.403 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d8655778}: Receive timed out> (0x00000006d8655778) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]
Event: 195449.392 Thread 0x00007fc052129800 Exception <a 'java/net/SocketTimeoutException'{0x00000006d7d34058}: Receive timed out> (0x00000006d7d34058) thrown at [./src/hotspot/share/prims/jni.cpp, line 636]

Events (20 events):
Event: 195446.309 Protecting memory [0x00007000172d1000,0x00007000172d5000] with protection modes 3
Event: 195446.309 Thread 0x00007fc052773000 Thread exited: 0x00007fc052773000
Event: 195447.273 Thread 0x00007fc046c6b800 Thread added: 0x00007fc046c6b800
Event: 195447.273 Protecting memory [0x00007000172d1000,0x00007000172d5000] with protection modes 0
Event: 195447.273 Thread 0x00007fc044a0c000 Thread added: 0x00007fc044a0c000
Event: 195447.273 Protecting memory [0x000070001a567000,0x000070001a56b000] with protection modes 0
Event: 195447.273 Thread 0x00007fc0449b6800 Thread added: 0x00007fc0449b6800
Event: 195447.273 Protecting memory [0x000070001b494000,0x000070001b498000] with protection modes 0
Event: 195447.273 Thread 0x00007fc044dac800 Thread added: 0x00007fc044dac800
Event: 195447.273 Protecting memory [0x000070001ccdc000,0x000070001cce0000] with protection modes 0
Event: 195448.884 Thread 0x00007fc044953800 Thread added: 0x00007fc044953800
Event: 195448.884 Protecting memory [0x0000700020186000,0x000070002018a000] with protection modes 0
Event: 195449.896 Executing VM operation: RevokeBias
Event: 195449.897 Executing VM operation: RevokeBias done
Event: 195449.898 Executing VM operation: G1CollectForAllocation
Event: 195449.905 Executing VM operation: G1CollectForAllocation done
Event: 195449.938 Executing VM operation: RevokeBias
Event: 195449.938 Protecting memory [0x00007000222e9000,0x00007000222ed000] with protection modes 3
Event: 195449.938 Thread 0x00007fc052775000 Thread exited: 0x00007fc052775000
Event: 195449.939 Executing VM operation: RevokeBias done


Dynamic libraries:
0x00007fff33819000 	/System/Library/Frameworks/Cocoa.framework/Versions/A/Cocoa
0x00007fff40e7b000 	/System/Library/Frameworks/Security.framework/Versions/A/Security
0x00007fff3277f000 	
[ list of dylibs snipped for character limit]
0x00007fff4d951000 	/System/Library/PrivateFrameworks/CoreServicesInternal.framework/Versions/A/CoreServicesInternal
0x00007fff50dd3000 	/System/Library/PrivateFrameworks/FontServices.framework/libTrueTypeScaler.dylib


VM Arguments:
jvm_args: -XX:-UsePerfData -Dlog4j2.formatMsgNoLookups=true -Dopenhab.home=/Users/robin/openhab -Dopenhab.conf=/Users/robin/openhab/conf -Dopenhab.runtime=/Users/robin/openhab/runtime -Dopenhab.userdata=/Users/robin/openhab/userdata -Dopenhab.logdir=/Users/robin/openhab/userdata/logs -Dfelix.cm.dir=/Users/robin/openhab/userdata/config -Djava.library.path=/Users/robin/openhab/userdata/tmp/lib -Djetty.host=0.0.0.0 -Djetty.http.compliance=RFC2616 -Dnashorn.args=--no-deprecation-warning -Dorg.apache.cxf.osgi.http.transport.disable=true -Dorg.ops4j.pax.web.listening.addresses=0.0.0.0 -Dorg.osgi.service.http.port=8080 -Dorg.osgi.service.http.port.secure=8443 -Djava.awt.headless=true -Dfile.encoding=UTF-8 -XX:+UseG1GC --add-reads=java.xml=java.logging --add-exports=java.base/org.apache.karaf.specs.locator=java.xml,ALL-UNNAMED --patch-module=java.base=/Users/robin/openhab/runtime/lib/endorsed/org.apache.karaf.specs.locator-4.3.4.jar --patch-module=java.xml=/Users/robin/openhab/runtime/lib/endorsed/org.apache.karaf.specs.java.xml-4.3.4.jar --add-opens=java.base/java.security=ALL-UNNAMED --add-opens=java.base/java.net=ALL-UNNAMED --add-opens=java.base/java.lang=ALL-UNNAMED --add-opens=java.base/java.util=ALL-UNNAMED --add-opens=java.naming/javax.naming.spi=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport.tcp=ALL-UNNAMED --add-opens=java.base/java.io=ALL-UNNAMED --add-opens=java.base/java.lang.reflect=ALL-UNNAMED --add-opens=java.base/java.text=ALL-UNNAMED --add-opens=java.base/java.time=ALL-UNNAMED --add-opens=java.desktop/java.awt.font=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.file=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.ftp=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.http=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.https=ALL-UNNAMED --add-exports=java.base/sun.net.www.protocol.jar=ALL-UNNAMED --add-exports=java.base/sun.net.www.content.text=ALL-UNNAMED --add-exports=jdk.xml.dom/org.w3c.dom.html=ALL-UNNAMED --add-exports=jdk.naming.rmi/com.sun.jndi.url.rmi=ALL-UNNAMED --add-exports=java.rmi/sun.rmi.registry=ALL-UNNAMED --add-exports=java.security.sasl/com.sun.security.sasl=ALL-UNNAMED -Dkaraf.instances=/Users/robin/openhab/userdata/tmp/instances -Dkaraf.home=/Users/robin/openhab/runtime -Dkaraf.base=/Users/robin/openhab/userdata -Dkaraf.data=/Users/robin/openhab/userdata -Dkaraf.etc=/Users/robin/openhab/userdata/etc -Dkaraf.log=/Users/robin/openhab/userdata/logs -Dkaraf.restart.jvm.supported=true -Djava.io.tmpdir=/Users/robin/openhab/userdata/tmp -Djava.util.logging.config.file=/Users/robin/openhab/userdata/etc/java.util.logging.properties -Dkaraf.startLocalConsole=true -Dkaraf.startRemoteShell=true 
java_command: org.apache.karaf.main.Main
java_class_path (initial): /Users/robin/openhab/runtime/lib/boot/org.apache.karaf.diagnostic.boot-4.3.4.jar:/Users/robin/openhab/runtime/lib/boot/org.apache.karaf.jaas.boot-4.3.4.jar:/Users/robin/openhab/runtime/lib/boot/org.apache.karaf.main-4.3.4.jar:/Users/robin/openhab/runtime/lib/boot/org.apache.karaf.specs.activator-4.3.4.jar:/Users/robin/openhab/runtime/lib/boot/osgi.core-7.0.0.jar:/Users/robin/openhab/runtime/lib/jdk9plus/istack-commons-runtime-3.0.10.jar:/Users/robin/openhab/runtime/lib/jdk9plus/jakarta.xml.bind-api-2.3.3.jar:/Users/robin/openhab/runtime/lib/jdk9plus/javax.annotation-api-1.3.2.jar:/Users/robin/openhab/runtime/lib/jdk9plus/jaxb-runtime-2.3.3.jar:/Users/robin/openhab/runtime/lib/jdk9plus/org.apache.servicemix.specs.activation-api-1.2.1-1.2.1_3.jar:/Users/robin/openhab/runtime/lib/jdk9plus/txw2-2.3.3.jar
Launcher Type: SUN_STANDARD

[Global flags]
     intx CICompilerCount                          = 4                                         {product} {ergonomic}
     uint ConcGCThreads                            = 2                                         {product} {ergonomic}
     uint G1ConcRefinementThreads                  = 8                                         {product} {ergonomic}
   size_t G1HeapRegionSize                         = 1048576                                   {product} {ergonomic}
    uintx GCDrainStackTargetSize                   = 64                                        {product} {ergonomic}
   size_t InitialHeapSize                          = 268435456                                 {product} {ergonomic}
   size_t MarkStackSize                            = 4194304                                   {product} {ergonomic}
   size_t MaxHeapSize                              = 4294967296                                {product} {ergonomic}
   size_t MaxNewSize                               = 2576351232                                {product} {ergonomic}
   size_t MinHeapDeltaBytes                        = 1048576                                   {product} {ergonomic}
    uintx NonNMethodCodeHeapSize                   = 5836300                                {pd product} {ergonomic}
    uintx NonProfiledCodeHeapSize                  = 122910970                              {pd product} {ergonomic}
    uintx ProfiledCodeHeapSize                     = 122910970                              {pd product} {ergonomic}
    uintx ReservedCodeCacheSize                    = 251658240                              {pd product} {ergonomic}
     bool SegmentedCodeCache                       = true                                      {product} {ergonomic}
     bool UseCompressedClassPointers               = true                                 {lp64_product} {ergonomic}
     bool UseCompressedOops                        = true                                 {lp64_product} {ergonomic}
     bool UseG1GC                                  = true                                      {product} {command line}
     bool UsePerfData                              = false                                     {product} {command line}

Logging:
Log output configuration:
 #0: stdout all=warning uptime,level,tags
 #1: stderr all=off uptime,level,tags

Environment Variables:
PATH=/Users/robin/bin:.:/usr/local/mysql/bin:/usr/local/sbin:/usr/local/bin:/usr/bin:/bin:/usr/sbin:/sbin:/opt/X11/bin:/Applications/Wireshark.app/Contents/MacOS
LD_LIBRARY_PATH=/Users/robin/openhab/userdata/lib:/Users/robin/openhab/runtime/lib
SHELL=/bin/bash
DISPLAY=/private/tmp/com.apple.launchd.BHAxD4vDus/org.macosforge.xquartz:0
LANG=en_AU.UTF-8

Signal Handlers:
SIGSEGV: [libjvm.dylib+0x7c38f0], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_ONSTACK|SA_RESTART|SA_SIGINFO
SIGBUS: [libjvm.dylib+0x7c38f0], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGFPE: [libjvm.dylib+0x7c38f0], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGPIPE: [libjvm.dylib+0x6266b8], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGXFSZ: [libjvm.dylib+0x6266b8], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGILL: [libjvm.dylib+0x7c38f0], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGUSR2: [libjvm.dylib+0x626c9d], sa_mask[0]=00000000000000000000000000000000, sa_flags=SA_RESTART|SA_SIGINFO
SIGHUP: [libjvm.dylib+0x625757], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGINT: [libjvm.dylib+0x625757], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGTERM: [libjvm.dylib+0x625757], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGQUIT: [libjvm.dylib+0x625757], sa_mask[0]=11111111011111110111111111111111, sa_flags=SA_RESTART|SA_SIGINFO


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

OS:uname:Darwin 19.6.0 Darwin Kernel Version 19.6.0: Thu Jan 13 01:26:33 PST 2022; root:xnu-6153.141.51~3/RELEASE_X86_64 x86_64
OS uptime: 5 days 6:14 hours
rlimit (soft/hard): STACK 8192k/65532k , CORE 0k/infinity , NPROC 2784/4176 , NOFILE 10240/200000 , AS infinity/infinity , CPU infinity/infinity , DATA infinity/infinity , FSIZE infinity/infinity , MEMLOCK infinity/infinity , RSS infinity/infinity
load average:1.91 1.98 1.92

CPU:total 8 (initial active 8) (4 cores per cpu, 2 threads per core) family 6 model 58 stepping 9 microcode 0x21, cmov, cx8, fxsr, mmx, sse, sse2, sse3, ssse3, sse4.1, sse4.2, popcnt, avx, aes, clmul, erms, ht, tsc, tscinvbit, tscinv

Memory: 4k page, physical 16777216k(779716k free), swap 1048576k(1002240k free)

vm_info: OpenJDK 64-Bit Server VM (11.0.10+9-LTS) for bsd-amd64 JRE (Zulu11.45+27-CA) (11.0.10+9-LTS), built on Dec 30 2020 12:39:54 by "zulu_re" with gcc 4.2.1 Compatible Apple LLVM 9.1.0 (clang-902.0.39.2)

END.

What -xmx value are you giving it? I’m picking it might have run out of heap space.

I have been tracking mine and seen it using more and more. I run in docker, and have a mem limit on it, and see it get restarted. Normally after adding items, things it seems to consume more.

May not be the actual issue, but I’d probably start there.

Umm… sorry, but I don’t know? I’ve never “given” it a -xmx value AFAIK. I just run it using start.sh. How would I go about checking or changing the -xmx value?

OK, I think I’ve found at least part of an answer to your question, although I’m not yet sure how I’d change it (if indeed it needs changing). Here’s my shell:info output


openhab> shell:info                                                                                                                                                                          
Karaf
  Karaf version               4.3.4
  Karaf home                  /Users/robin/openhab/runtime
  Karaf base                  /Users/robin/openhab/userdata
  OSGi Framework              org.eclipse.osgi-3.16.300.v20210525-1715

JVM
  Java Virtual Machine        OpenJDK 64-Bit Server VM version 11.0.10+9-LTS
  Version                     11.0.10
  Vendor                      Azul Systems, Inc.
  Pid                         5274
  Uptime                      1 hour 21 minutes
  Process CPU time            5 minutes
  Process CPU load            0.00
  System CPU load             0.00
  Open file descriptors       448
  Max file descriptors        10,240
  Total compile time          2 minutes
Threads
  Live threads                301
  Daemon threads              179
  Peak                        368
  Total started               6854
Memory
  Current heap size           184,720 kbytes
  Maximum heap size           4,194,304 kbytes
  Committed heap size         378,880 kbytes
  Pending objects             0
  Garbage collector           Name = 'G1 Young Generation', Collections = 99, Time = 0.766 seconds
  Garbage collector           Name = 'G1 Old Generation', Collections = 0, Time = 0.000 seconds
Classes
  Current classes loaded      22,418
  Total classes loaded        22,919
  Total classes unloaded      501
Operating system
  Name                        Mac OS X version 10.15.7
  Architecture                x86_64
  Processors                  8

This is a crash in JVM itself, particularly in piece of code that tries to reclaim memory (garbage collector). openHAB has little to do with this crash directly, it is essentially a bug in JVM.

I would first advice to check if there is newer zulu11 java available and update to that.

Thanks for that - I’ve now updated to:

openjdk version "11.0.14.1" 2022-02-08 LTS
OpenJDK Runtime Environment Zulu11.54+25-CA (build 11.0.14.1+1-LTS)
OpenJDK 64-Bit Server VM Zulu11.54+25-CA (build 11.0.14.1+1-LTS, mixed mode)

which is a fair bit newer than the version I was running. Here’s hoping that solves it! On the bright side, the crashes are so uncommon it will be hard to know for sure… but I guess if it runs for many weeks without crashing, then that will be a positive indication at least.

1 Like