JVM crash when hardware in use disconnected

[gchauvet]

Dear NRJavaSerial devs,

We have an issue with NRJavaSerial library who crash our JRE (1.6.31-33, compulsory). This issue occurs on physical or virtual serial port (same behaviour).

Below a full sample to the our issue:

import gnu.io.NRSerialPort;
import gnu.io.SerialPortEvent;
import gnu.io.SerialPortEventListener;
import java.io.IOException;
import java.util.concurrent.Callable;
import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;
import java.util.concurrent.Future;

public class MainApp {

    public static void main(String args[]) throws Exception {
        final String port = args[0];
        final int baudRate = Integer.valueOf(args[1]);
        final NRSerialPort serial = new NRSerialPort(port, baudRate);
        final ExecutorService executor = Executors.newSingleThreadExecutor();

        serial.connect();
        serial.getSerialPortInstance().notifyOnDSR(true);
        serial.getSerialPortInstance().notifyOnBreakInterrupt(true);
        serial.getSerialPortInstance().notifyOnFramingError(true);
        serial.getSerialPortInstance().notifyOnOverrunError(true);
        serial.getSerialPortInstance().notifyOnParityError(true);


        try {
            final Future<Void> task = executor.submit(new Callable<Void>() {
                @Override
                public Void call() throws Exception {
                    while (!Thread.currentThread().isInterrupted()) {
                        System.out.println(serial.getInputStream().read());
                    }
                    return null;
                }
            });

            serial.addEventListener(new SerialPortEventListener() {
                @Override
                public void serialEvent(SerialPortEvent ev) {
                    System.err.println("Receive code " + ev.getEventType());
                    serial.removeEventListener();
                    task.cancel(true);
                }
            });
            task.get();
        } catch (Exception ex) {
            throw new IOException(ex);
        } finally {
            serial.removeEventListener();
            executor.shutdownNow();
            serial.disconnect();
        }
    }

}

Now we test our hardware connected on a COM4 physical serial port:

C:\temp\SerialNotifier>java -cp serialnotifier-1.0.0.jar;nrjavaserial-3.11.0.jar
 MainApp COM4 9600
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
Receive code 4     (hardware disconnected)
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
-1
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x6ac47568, pid=11152, tid=9072

#
# JRE version: 6.0_31-b05
# Java VM: Java HotSpot(TM) Client VM (20.6-b01 mixed mode windows-x86 )
# Problematic frame:
# C  [libNRJavaSerial.dll+0x7568]
#
# An error report file with more information is saved as:
# C:\temp\SerialNotifier\hs_err_pid11152.log
#
# If you would like to submit a bug report, please visit:
#   http://java.sun.com/webapps/bugreport/crash.jsp
# The crash happened outside the Java Virtual Machine in native code.
# See problematic frame for where to report the bug.
#

C:\temp\SerialNotifier>

JVM crash report:

#
# A fatal error has been detected by the Java Runtime Environment:
#
#  EXCEPTION_ACCESS_VIOLATION (0xc0000005) at pc=0x6ac47568, pid=11152, tid=9072
#
# JRE version: 6.0_31-b05
# Java VM: Java HotSpot(TM) Client VM (20.6-b01 mixed mode windows-x86 )
# Problematic frame:
# C  [libNRJavaSerial.dll+0x7568]
#
# If you would like to submit a bug report, please visit:
#   http://java.sun.com/webapps/bugreport/crash.jsp
# The crash happened outside the Java Virtual Machine in native code.
# See problematic frame for where to report the bug.
#

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

Current thread (0x16f16400):  JavaThread "pool-1-thread-1" [_thread_in_native, id=9072, stack(0x17140000,0x17190000)]

siginfo: ExceptionCode=0xc0000005, writing address 0x1713fac0

Registers:
EAX=0x1713fab8, EBX=0x00000000, ECX=0x00000001, EDX=0x00471fd0
ESP=0x1718fa40, EBP=0x00000001, ESI=0x00000013, EDI=0x00000001
EIP=0x6ac47568, EFLAGS=0x00010297

Top of Stack: (sp=0x1718fa40)
0x1718fa40:   000003e8 1718faa0 00000001 6ac5413c
0x1718fa50:   1718fa60 471fd070 1713fab8 00000001
0x1718fa60:   1718fa78 6d881ff2 16f16400 16f16528
0x1718fa70:   16f17734 00000001 1718faf8 6ac476ae
0x1718fa80:   16f16528 1718fb04 00000001 1718faa0
0x1718fa90:   00000001 00000064 00912f03 00000064
0x1718faa0:   00000001 02b271a8 1718faa8 12bbc33a
0x1718fab0:   1718fae0 12bbd040 00000000 12bbc368 

Instructions: (pc=0x6ac47568)
0x6ac47548:   75 c6 c7 04 24 e8 03 00 00 e8 4a 16 00 00 39 5c
0x6ac47558:   24 50 7f be 8d 74 26 00 8b 44 24 18 8b 4c 24 1c
0x6ac47568:   89 48 08 83 c4 2c 89 d8 5b 5e 5f 5d c3 e8 0e ac
0x6ac47578:   00 00 83 38 04 74 06 90 e8 03 ac 00 00 8b 44 24 


Register to memory mapping:

EAX=0x1713fab8 is an unknown value
EBX=0x00000000 is an unknown value
ECX=0x00000001 is an unknown value
EDX=0x00471fd0 is an unknown value
ESP=0x1718fa40 is pointing into the stack for thread: 0x16f16400
EBP=0x00000001 is an unknown value
ESI=0x00000013 is an unknown value
EDI=0x00000001 is an unknown value


Stack: [0x17140000,0x17190000],  sp=0x1718fa40,  free space=318k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
C  [libNRJavaSerial.dll+0x7568]  Java_gnu_io_RXTXPort_nativeSetEndOfInputChar+0x1e8

Java frames: (J=compiled Java code, j=interpreted, Vv=VM code)
j  gnu.io.RXTXPort.readByte()I+0
j  gnu.io.RXTXPort$SerialInputStream.read()I+61
j  MainApp$1.call()Ljava/lang/Void;+19
j  MainApp$1.call()Ljava/lang/Object;+1
j  java.util.concurrent.FutureTask$Sync.innerRun()V+30
j  java.util.concurrent.FutureTask.run()V+4
j  java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Ljava/lang/Runnable;)V+59
j  java.util.concurrent.ThreadPoolExecutor$Worker.run()V+28
j  java.lang.Thread.run()V+11
v  ~StubRoutines::call_stub

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

Java Threads: ( => current thread )
=>0x16f16400 JavaThread "pool-1-thread-1" [_thread_in_native, id=9072, stack(0x17140000,0x17190000)]
  0x16b60c00 JavaThread "Low Memory Detector" daemon [_thread_blocked, id=7528, stack(0x16db0000,0x16e00000)]
  0x16b5c800 JavaThread "C1 CompilerThread0" daemon [_thread_blocked, id=9412, stack(0x16d60000,0x16db0000)]
  0x16b59400 JavaThread "Attach Listener" daemon [_thread_blocked, id=2420, stack(0x16d10000,0x16d60000)]
  0x16b57c00 JavaThread "Signal Dispatcher" daemon [_thread_blocked, id=2488, stack(0x16cc0000,0x16d10000)]
  0x16b4a400 JavaThread "Finalizer" daemon [_thread_blocked, id=9100, stack(0x16c70000,0x16cc0000)]
  0x16b45800 JavaThread "Reference Handler" daemon [_thread_blocked, id=4556, stack(0x16c20000,0x16c70000)]
  0x002b6800 JavaThread "main" [_thread_blocked, id=9144, stack(0x008c0000,0x00910000)]

Other Threads:
  0x16b41c00 VMThread [stack: 0x16bd0000,0x16c20000] [id=4680]
  0x16b6b800 WatcherThread [stack: 0x16e00000,0x16e50000] [id=7728]

VM state:not at safepoint (normal execution)

VM Mutex/Monitor currently owned by a thread: None

Heap
 def new generation   total 4928K, used 2228K [0x02990000, 0x02ee0000, 0x07ee0000)
  eden space 4416K,  38% used [0x02990000, 0x02b3d0a8, 0x02de0000)
  from space 512K, 100% used [0x02de0000, 0x02e60000, 0x02e60000)
  to   space 512K,   0% used [0x02e60000, 0x02e60000, 0x02ee0000)
 tenured generation   total 10944K, used 4431K [0x07ee0000, 0x08990000, 0x12990000)
   the space 10944K,  40% used [0x07ee0000, 0x08333c28, 0x08333e00, 0x08990000)
 compacting perm gen  total 12288K, used 2273K [0x12990000, 0x13590000, 0x16990000)
   the space 12288K,  18% used [0x12990000, 0x12bc8748, 0x12bc8800, 0x13590000)
No shared spaces configured.

Code Cache  [0x00910000, 0x009a8000, 0x02910000)
 total_blobs=180 nmethods=51 adapters=66 free_code_cache=32941376 largest_free_block=0

Dynamic libraries:
0x00400000 - 0x00425000     C:\Windows\system32\java.exe
0x7c900000 - 0x7c9af000     C:\Windows\system32\ntdll.dll
0x7c800000 - 0x7c8f6000     C:\Windows\system32\kernel32.dll
0x77dd0000 - 0x77e6b000     C:\Windows\system32\ADVAPI32.dll
0x77e70000 - 0x77f02000     C:\Windows\system32\RPCRT4.dll
0x77fe0000 - 0x77ff1000     C:\Windows\system32\Secur32.dll
0x7c340000 - 0x7c396000     C:\Program Files\Java\jre6\bin\msvcr71.dll
0x6d7f0000 - 0x6da9f000     C:\Program Files\Java\jre6\bin\client\jvm.dll
0x7e410000 - 0x7e4a1000     C:\Windows\system32\USER32.dll
0x77f10000 - 0x77f59000     C:\Windows\system32\GDI32.dll
0x76b40000 - 0x76b6d000     C:\Windows\system32\WINMM.dll
0x76390000 - 0x763ad000     C:\Windows\system32\IMM32.DLL
0x6d7a0000 - 0x6d7ac000     C:\Program Files\Java\jre6\bin\verify.dll
0x6d320000 - 0x6d33f000     C:\Program Files\Java\jre6\bin\java.dll
0x6d7e0000 - 0x6d7ef000     C:\Program Files\Java\jre6\bin\zip.dll
0x6ac40000 - 0x6ac66000     C:\Documents and Settings\Administrator\Local Settings\Temp\libNRJavaSerial_Administrateur_0\libNRJavaSerial.dll
0x77c10000 - 0x77c68000     C:\Windows\system32\msvcrt.dll
0x76bf0000 - 0x76bfb000     C:\Windows\system32\PSAPI.DLL

VM Arguments:
java_command: MainApp COM4 9600
Launcher Type: SUN_STANDARD

Environment Variables:
PATH=C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\system32\WindowsPowerShell\v1.0;C:\httpd\Php\extras\wso2-wsf-php-bin-2.0.0-win32\wsf_c\lib\;C:\httpd\Php\extras\bindlib-cvs-vc8\lib\;C:\httpd\Php\extras\iconv-1.9.2.win32\bin\;C:\httpd\Php\extras\libxml2-2.7.6.win32\bin\;C:\httpd\Php\extras\openssl-0.9.8a.win32\bin\;c:\Program Files\Panda Security\WaAgent\Common;C:\Program Files\Skype\Phone\
USERNAME=Administrateur
OS=Windows_NT
PROCESSOR_IDENTIFIER=x86 Family 6 Model 28 Stepping 2, GenuineIntel



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

OS: Windows XP Build 2600 Service Pack 3

CPU:total 2 (1 cores per cpu, 2 threads per core) family 6 model 28 stepping 2, cmov, cx8, fxsr, mmx, sse, sse2, sse3, ssse3, ht

Memory: 4k page, physical 2087020k(1352620k free), swap 2957980k(2166384k free)

vm_info: Java HotSpot(TM) Client VM (20.6-b01) for windows-x86 JRE (1.6.0_31-b05), built on Feb  3 2012 18:44:09 by "java_re" with MS VC++ 7.1 (VS2003)

time: Tue Feb 23 09:47:21 2016
elapsed time: 14 seconds

[gchauvet]

Note: same issue in a non threaded execution way

[jason-s]

The crash-JVM-upon-USB-disconnect is has been an issue with RXTX for years (I ran into it in 2009 and 2010) and has never been properly addressed to my knowledge. It's the reason why I stopped using RXTX completely and migrated to PureJavaComm which does not have this issue.

• http://marc.info/?l=rxtx&m=128896796230399&w=2
• http://stackoverflow.com/questions/2142918/java-serial-i-o-handling-usb-serial-connection-disconnection-in-a-robust-manner

I hope someone is able to fix this issue.

[madhephaestus]

The work around i have used for a long time for this is:

• cache a copy of the data streams. don't just call get stream each time.
• when you detect the disconnect, set the stream to null and disconnect
• the read method will fail with a catchable exception when it tries to read from the null stream.

I have a consumer serial device i ship with this lib, and the use case of pulling it before disconnecting was a primary concern. I have never dived into the JNI to attempt to put this robustness into the place where the error occurs, but this workaround provides the expected results for my application.

[jason-s]

when you detect the disconnect, set the stream to null and disconnect

It's been several years since I was working with RXTX or NRJavaSerial, but from what I remember, this was possible in certain cases and not possible in others -- again, see http://marc.info/?l=rxtx&m=128896796230399&w=2. Low data rates (NOT baud rates -- you can have a 4.375Mbaud connection and only send a few hundred bytes per second if you want) made it easier to catch and recover; high data rates made it harder. There was a guy on the RXTX mailing list (Mariusz) that claimed he could always workaround the disconnect crash issue, but he was using low data rates and I was using high data rates. I was able to reproduce his method on low data rates, but unfortunately never got around to exploring in detail before I left my previous job along with my sample code.

[gchauvet]

Using PureJavaComm solve my issue 👍
But I've small differences : timeout threshold works like Linux. I define it at 500ms as describe here

[madhephaestus]

this issue resolved as part of #75