mycontroller-org / mycontroller-v1-legacy

The Open Source Controller
http://www.MyController.org
Apache License 2.0
148 stars 89 forks source link

Core dump Java JRE #204

Closed WimVerhaert closed 8 years ago

WimVerhaert commented 8 years ago

Hi,

Since this weekend I am getting a core dump of my java JRE. Started happening after adding an extra sensor...

Running on a rasp: Linux raspberrypi_1 4.1.16+ #833 Wed Jan 27 14:29:11 GMT 2016 armv6l GNU/Linux coreJVM.txt

Hope this info helps to troubleshoot,....

jkandasa commented 8 years ago

@WimVerhaert What is the gateway type? and did you upgrade your system recently? Can you also send version information of MyController.org and mycontroller/log/mycontroller.log? You can email me.

WimVerhaert commented 8 years ago

Gateway type is Serial using PiGatewaySerial from NRF24, is connected directly on the rasp. I did not upgrade in the last few months, java -version java version "1.8.0" Java(TM) SE Runtime Environment (build 1.8.0-b132) Java HotSpot(TM) Client VM (build 25.0-b70, mixed mode)

Mycontroller = 0.03-alpha1-SNAPSHOT db 1.01.05-SNAPSHOT

mycontroller.zip

jkandasa commented 8 years ago

I believe MyController may face problem with PiGatewaySerial. Can you change serial port driver to jSerialComm in MyController gateway serial port settings? Reload gateway required when we do change on gateway settings.

WimVerhaert commented 8 years ago

No luck,... This time

[Mon May 23 16:21:22 CEST 2016] IO error: javax.net.ssl.SSLException: Connection has been shutdown: javax.net.ssl.SSLHandshakeException: Remote host closed connection during handshake in processing a request from /81.246.118.4:8443 / sun.security.ssl.SSLSocketImpl
2016-05-23 16:31:43,644 ERROR [Thread-246] [org.mycontroller.standalone.gateway.serialport.SerialDataListenerjSerialComm:88] Exception,
java.lang.NegativeArraySizeException: null
        at org.mycontroller.standalone.gateway.serialport.SerialDataListenerjSerialComm.serialEvent(SerialDataListenerjSerialComm.java:58) ~[mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at com.fazecast.jSerialComm.SerialPort$SerialPortEventListener.waitForSerialEvent(SerialPort.java:913) [mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at com.fazecast.jSerialComm.SerialPort$SerialPortEventListener$1.run(SerialPort.java:861) [mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at java.lang.Thread.run(Thread.java:744) [na:1.8.0]
[Mon May 23 16:31:53 CEST 2016] IO error: javax.net.ssl.SSLException: Connection has been shutdown: javax.net.ssl.SSLHandshakeException: Remote host closed connection during handshake in processing a request from /81.246.118.4:8443 / sun.security.ssl.SSLSocketImpl
...
2016-05-23 16:51:42,718 ERROR [Thread-4] [org.mycontroller.standalone.message.MessageUtils:44] Message send failed! Message:[GatewayId:1, Data:1;255;3;0;18;1464015102699
, SubData:null, IsTxMessage:true]
org.mycontroller.standalone.gateway.GatewayException: Gateway not available! Gateway:[Gateway(id=1, enabled=true, name=Serial-gateway, type=SERIAL, networkType=MY_SENSORS, timestamp=null, state=DOWN, statusMessage=ERROR: null, statusSince=1464013903542, variable1=jSerialComm, variable2=/dev/ttyUSB20, variable3=115200, variable4=3600, variable5=jSerialComm, variable6=null, variable7=null, variable8=null, variable9=null, variable10=null)]
        at org.mycontroller.standalone.gateway.serialport.SerialPortMonitoringThread.write(SerialPortMonitoringThread.java:133) ~[mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.gateway.serialport.MYCSerialPort.write(MYCSerialPort.java:44) ~[mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.message.MessageUtils.sendMessgaeToGateway(MessageUtils.java:38) ~[mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.mysensors.MySensorsMessageEngine.executeMessage(MySensorsMessageEngine.java:102) [mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.message.MessageMonitorThread.processRawMessage(MessageMonitorThread.java:68) [mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.message.MessageMonitorThread.run(MessageMonitorThread.java:107) [mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at java.lang.Thread.run(Thread.java:744) [na:1.8.0]
2016-05-23 16:51:42,907 ERROR [Thread-4] [org.mycontroller.standalone.message.MessageUtils:44] Message send failed! Message:[GatewayId:1, Data:2;255;3;0;18;1464015102700
, SubData:null, IsTxMessage:true]
org.mycontroller.standalone.gateway.GatewayException: Gateway not available! Gateway:[Gateway(id=1, enabled=true, name=Serial-gateway, type=SERIAL, networkType=MY_SENSORS, timestamp=null, state=DOWN, statusMessage=ERROR: null, statusSince=1464013903542, variable1=jSerialComm, variable2=/dev/ttyUSB20, variable3=115200, variable4=3600, variable5=jSerialComm, variable6=null, variable7=null, variable8=null, variable9=null, variable10=null)]
        at org.mycontroller.standalone.gateway.serialport.SerialPortMonitoringThread.write(SerialPortMonitoringThread.java:133) ~[mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.gateway.serialport.MYCSerialPort.write(MYCSerialPort.java:44) ~[mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.message.MessageUtils.sendMessgaeToGateway(MessageUtils.java:38) ~[mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.mysensors.MySensorsMessageEngine.executeMessage(MySensorsMessageEngine.java:102) [mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.message.MessageMonitorThread.processRawMessage(MessageMonitorThread.java:68) [mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.message.MessageMonitorThread.run(MessageMonitorThread.java:107) [mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at java.lang.Thread.run(Thread.java:744) [na:1.8.0]
2016-05-23 16:51:43,100 ERROR [Thread-4] [org.mycontroller.standalone.message.MessageUtils:44] Message send failed! Message:[GatewayId:1, Data:5;255;3;0;18;1464015102701
, SubData:null, IsTxMessage:true]
org.mycontroller.standalone.gateway.GatewayException: Gateway not available! Gateway:[Gateway(id=1, enabled=true, name=Serial-gateway, type=SERIAL, networkType=MY_SENSORS, timestamp=null, state=DOWN, statusMessage=ERROR: null, statusSince=1464013903542, variable1=jSerialComm, variable2=/dev/ttyUSB20, variable3=115200, variable4=3600, variable5=jSerialComm, variable6=null, variable7=null, variable8=null, variable9=null, variable10=null)]
        at org.mycontroller.standalone.gateway.serialport.SerialPortMonitoringThread.write(SerialPortMonitoringThread.java:133) ~[mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.gateway.serialport.MYCSerialPort.write(MYCSerialPort.java:44) ~[mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.message.MessageUtils.sendMessgaeToGateway(MessageUtils.java:38) ~[mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.mysensors.MySensorsMessageEngine.executeMessage(MySensorsMessageEngine.java:102) [mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.message.MessageMonitorThread.processRawMessage(MessageMonitorThread.java:68) [mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.message.MessageMonitorThread.run(MessageMonitorThread.java:107) [mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at java.lang.Thread.run(Thread.java:744) [na:1.8.0]
2016-05-23 16:51:43,150 ERROR [Thread-4] [org.mycontroller.standalone.message.MessageUtils:44] Message send failed! Message:[GatewayId:1, Data:255;255;3;0;18;1464015102702
, SubData:null, IsTxMessage:true]
org.mycontroller.standalone.gateway.GatewayException: Gateway not available! Gateway:[Gateway(id=1, enabled=true, name=Serial-gateway, type=SERIAL, networkType=MY_SENSORS, timestamp=null, state=DOWN, statusMessage=ERROR: null, statusSince=1464013903542, variable1=jSerialComm, variable2=/dev/ttyUSB20, variable3=115200, variable4=3600, variable5=jSerialComm, variable6=null, variable7=null, variable8=null, variable9=null, variable10=null)]
        at org.mycontroller.standalone.gateway.serialport.SerialPortMonitoringThread.write(SerialPortMonitoringThread.java:133) ~[mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.gateway.serialport.MYCSerialPort.write(MYCSerialPort.java:44) ~[mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.message.MessageUtils.sendMessgaeToGateway(MessageUtils.java:38) ~[mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.mysensors.MySensorsMessageEngine.executeMessage(MySensorsMessageEngine.java:102) [mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.message.MessageMonitorThread.processRawMessage(MessageMonitorThread.java:68) [mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at org.mycontroller.standalone.message.MessageMonitorThread.run(MessageMonitorThread.java:107) [mycontroller-standalone-0.0.3-alpha1-SNAPSHOT-single.jar:na]
        at java.lang.Thread.run(Thread.java:744) [na:1.8.0]
jkandasa commented 8 years ago

@WimVerhaert looks like some issue with serial port. In recenet version fixed some issues related to serial port. Is it possible for you to try with latest version of MyController? If you are ok, please start email or chat, I will guide you to migrate.

WimVerhaert commented 8 years ago

After upgrade I got a Migration Exception:

2016-05-24 09:35:04,578 ERROR [main] [org.mycontroller.standalone.db.DataBaseUtils:116] Migration exception,
org.flywaydb.core.api.FlywayException: Validate failed. Migration Description mismatch for migration 1.01.05
-> Applied to database : SNAPSHOT
-> Resolved locally    : 0 0 3 alpha1
        at org.flywaydb.core.Flyway.doValidate(Flyway.java:1108) ~[mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
        at org.flywaydb.core.Flyway.access$300(Flyway.java:62) ~[mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
        at org.flywaydb.core.Flyway$1.execute(Flyway.java:1012) ~[mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
        at org.flywaydb.core.Flyway$1.execute(Flyway.java:1006) ~[mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
        at org.flywaydb.core.Flyway.execute(Flyway.java:1418) ~[mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
        at org.flywaydb.core.Flyway.migrate(Flyway.java:1006) ~[mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
        at org.mycontroller.standalone.db.DataBaseUtils.loadDatabase(DataBaseUtils.java:114) ~[mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
        at org.mycontroller.standalone.StartApp.startServices(StartApp.java:240) [mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
        at org.mycontroller.standalone.StartApp.startMycontroller(StartApp.java:104) [mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
        at org.mycontroller.standalone.StartApp.main(StartApp.java:91) [mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
2016-05-24 09:35:21,526 INFO [main] [org.mycontroller.standalone.db.DataBaseUtils:149] Number of migrations done:0
2016-05-24 09:35:21,680 INFO [main] [org.mycontroller.standalone.db.DataBaseUtils:150] Application information: [Version:0.0.3.Alpha2-SNAPSHOT, Database version:1.01.05 - SNAPSHOT]
2016-05-24 09:35:29,883 ERROR [main] [org.mycontroller.standalone.StartApp:93] Unable to start application, refer error log,
java.lang.NullPointerException: null
        at org.mycontroller.standalone.db.dao.GatewayDaoImpl.getAll(GatewayDaoImpl.java:77) ~[mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
        at org.mycontroller.standalone.db.dao.GatewayDaoImpl.getAllEnabled(GatewayDaoImpl.java:46) ~[mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
        at org.mycontroller.standalone.gateway.GatewayUtils.loadAllGateways(GatewayUtils.java:198) ~[mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
        at org.mycontroller.standalone.StartApp.startServices(StartApp.java:262) ~[mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
        at org.mycontroller.standalone.StartApp.startMycontroller(StartApp.java:104) ~[mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
        at org.mycontroller.standalone.StartApp.main(StartApp.java:91) ~[mycontroller-dist-standalone-0.0.3.Alpha2-SNAPSHOT-single.jar:0.0.3.Alpha2-SNAPSHOT]
Exception in thread "MyController.org Shutdown-Hook" java.lang.NullPointerException
        at Acme.Serve.Serve.stopBackground(Serve.java:684)
        at org.jboss.resteasy.plugins.server.tjws.TJWSServletServer.stop(TJWSServletServer.java:184)
        at org.mycontroller.standalone.StartApp.stopHTTPWebServer(StartApp.java:213)
        at org.mycontroller.standalone.StartApp.stopServices(StartApp.java:282)
        at org.mycontroller.standalone.AppShutdownHook$1.run(AppShutdownHook.java:34)
jkandasa commented 8 years ago

@WimVerhaert I hope everything alright now. Please close this issue if you do not face JVM core dump error.

WimVerhaert commented 8 years ago

I have not had a core recently,... will close for now

WimVerhaert commented 8 years ago

Still getting a sporadic core,...

#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGILL (0x4) at pc=0xb6de79dc, pid=1224, tid=2907919456
#
# JRE version: Java(TM) SE Runtime Environment (8.0-b132) (build 1.8.0-b132)
# Java VM: Java HotSpot(TM) Client VM (25.0-b70 mixed mode linux-arm )
# Problematic frame:
# C  [libc.so.6+0x789dc]  strncpy+0x0
#
# 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.sun.com/bugreport/crash.jsp
#

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

Current thread (0xb615b0f0):  VMThread [stack: 0xad4b6000,0xad536000] [id=1232]

siginfo:si_signo=SIGILL: si_errno=0, si_code=1 (ILL_ILLOPC), si_addr=0xb6de79dc

Registers:
  r0  = 0xad534190
  r1  = 0xb68cf0c8
  r2  = 0x000007cf
  r3  = 0x0000000e
  r4  = 0xad534190
  r5  = 0xb68cf0c8
  r6  = 0x000007cf
  r7  = 0xad53418c
  r8  = 0x00000001
  r9  = 0x00000000
  r10 = 0xad534970
  fp  = 0xad53417c
  r12 = 0xb690a3d8
  sp  = 0xad534158
  lr  = 0xb6791bb8
  pc  = 0xb6de79dc
  cpsr = 0x20000010

Top of Stack: (sp=0xad534158)
0xad534158:   ad534940 00000051 ad534978 b610b138
0xad534168:   00000000 b610b074 b690a0e0 b610b020
0xad534178:   ad534968 b6791d3c 00000001 ad53418c
0xad534188:   ad534970 00000001 696d6d6f 64657474
0xad534198:   38353220 2c4b3038 73657220 65767265
0xad5341a8:   35322064 4b343039 0000000a 00000000
0xad5341b8:   00000000 b6db1c68 b6db1c68 ad534284
0xad5341c8:   b6e884d8 b6e884d8 00000000 00000000 

Instructions: (pc=0xb6de79dc)
0xb6de79bc:   1afffff5 e0640003 e8bd07f0 e12fff1e
0xb6de79cc:   e2022003 e1a01006 e1a00005 eaffffe1
0xb6de79dc:   e3520003 e92d01f0 e2408001 9a000029
0xb6de79ec:   e1a0c001 e1a03008 e2814004 e1a07122 

Register to memory mapping:

  r0  = 0xad534190
0xad534190 is an unknown value

  r1  = 0xb68cf0c8
0xb68cf0c8: <offset 0x51b0c8> in /usr/lib/jvm/jdk-8-oracle-arm-vfp-hflt/jre/lib/arm/client/libjvm.so at 0xb63b4000

  r2  = 0x000007cf
0x000007cf is an unknown value

  r3  = 0x0000000e
0x0000000e is an unknown value

  r4  = 0xad534190
0xad534190 is an unknown value

  r5  = 0xb68cf0c8
0xb68cf0c8: <offset 0x51b0c8> in /usr/lib/jvm/jdk-8-oracle-arm-vfp-hflt/jre/lib/arm/client/libjvm.so at 0xb63b4000

  r6  = 0x000007cf
0x000007cf is an unknown value

  r7  = 0xad53418c
0xad53418c is an unknown value

  r8  = 0x00000001
0x00000001 is an unknown value

  r9  = 0x00000000
0x00000000 is an unknown value

  r10 = 0xad534970
0xad534970 is an unknown value

  fp  = 0xad53417c
0xad53417c is an unknown value

  r12 = 0xb690a3d8
0xb690a3d8: <offset 0x5563d8> in /usr/lib/jvm/jdk-8-oracle-arm-vfp-hflt/jre/lib/arm/client/libjvm.so at 0xb63b4000

  sp  = 0xad534158
0xad534158 is an unknown value

  lr  = 0xb6791bb8
0xb6791bb8: <offset 0x3ddbb8> in /usr/lib/jvm/jdk-8-oracle-arm-vfp-hflt/jre/lib/arm/client/libjvm.so at 0xb63b4000

  pc  = 0xb6de79dc
0xb6de79dc: strncpy+0 in /lib/arm-linux-gnueabihf/libc.so.6 at 0xb6d6f000

Stack: [0xad4b6000,0xad536000],  sp=0xad534158,  free space=504k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
C  [libc.so.6+0x789dc]  strncpy+0x0
jkandasa commented 8 years ago

@WimVerhaert Can you add small configuration to generate heap dump on crash?

Modify bin/start.sh line number 59 as follows, -XX:+HeapDumpOnOutOfMemoryError

$_java ${HEAP_MIN} ${HEAP_MAX} -XX:+HeapDumpOnOutOfMemoryError -Dlogback.configurationFile=${CONF_LOG_FILE} -Dmc.conf.file=${CONF_PROPERTIES_FILE} -cp "../lib/*" org.mycontroller.standalone.StartApp >> ../logs/mycontroller.log 2>&1 &

Send me the dump file, when you get

jkandasa commented 8 years ago

@WimVerhaert Did you get core dump on crash?

jkandasa commented 8 years ago

@WimVerhaert We can close this issue, if we cannot reproduce this issue.