Bug 209599

Summary:

[PATCHES] FreeBSD fix for JDK-6244515 : Unsafe operations that access invalid memory are not handled gracefully - java/openjdk8 and java/openjdk7

Product:

Ports & Packages

Reporter:

Andrew Smith <iamasmith.home>

Component:

Individual Port(s)

Assignee:

freebsd-java (Nobody) <java>

Status:

Closed FIXED

Severity:

Affects Only Me

CC:

glewis, iamasmith.home, openjdk

Priority:

---

Flags:

bugzilla: maintainer-feedback? (java)

Version:

Latest

Hardware:

amd64

OS:

Any

Attachments:

Description	Flags
hs_err_pid57712.log	none
hs_err_pid57787.log	none
java/openjdk8 patch	none
java/openjdk7 patch	none

Description Andrew Smith 2016-05-18 08:37:58 UTC

Whilst investigating a stability problem that occurs periodically if we attempt to utilise OpenJDK 8 with Tomcat (resulting in various SIGSEGV and SIGBUS errors), I decided to build everything afresh from current sources and perform run the test suite.

System information on JDK build test machine.

10.3-RELEASE FreeBSD
root@testbuild1:~ # freebsd-version
10.3-RELEASE

portsnap sources fetched and installed on 16th May
root@testbuild1:~ # ls -l /var/db/portsnap/
total 4504
-rw-r--r--  1 root  wheel  2255587 May 16 09:59 INDEX
drwxr-xr-x  2 root  wheel  2237952 May 16 09:59 files
-rw-r--r--  1 root  wheel      451 May 16 09:56 pub.ssl
-rw-r--r--  1 root  wheel      272 May 16 09:56 serverlist
-rw-r--r--  1 root  wheel      272 May 16 09:56 serverlist_full
-rw-r--r--  1 root  wheel       40 May 16 09:56 serverlist_tried
-rw-r--r--  1 root  wheel      681 May 16 09:59 tINDEX
-rw-r--r--  1 root  wheel       85 May 16 09:59 tag
root@testbuild1:~ # 

Build process cycle run as follows..

# Selected all build configurations up front for the whole depdency set using postmaster
# Every option with the exception of turning on TEST for OpenJDK8 was set to default.
portmaster -n java/openjdk8
# Build actual port so that the build area was not cleaned (as is the case when using postmaster).
cd /usr/ports/java/openjdk8
make clean install

2 of the tests fail when running the regression tests and error logs can be collected as follows..

/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/output.txt

and to locate the stashed error reports in the test hierarchy..

root@testbuild1:~ # cd /usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core
root@testbuild1:/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core # find . -name 'hs_*'
./JTwork/java/nio/MappedByteBuffer/Truncate/hs_err_pid57787.log
./JTwork/sun/misc/CopyMemory/hs_err_pid57712.log

The logs always show SIGSEGV errors from the same locations with the failure signal being triggered during calles to sun.misc.Unsafe methods..

Stack: [0x00007fffde0e0000,0x00007fffde1e0000],  sp=0x00007fffde1df080,  free space=1020k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0x8d3ced]  JVM_handle_bsd_signal+0x120c2d
j  sun.misc.Unsafe.putByte(Ljava/lang/Object;JB)V+0
j  CopyMemory.set(Lsun/misc/Unsafe;JIII)V+23
j  CopyMemory.testSetRawMemory(Lsun/misc/Unsafe;)V+32
j  CopyMemory.main([Ljava/lang/String;)V+9

Stack: [0x00007fffdf1f1000,0x00007fffdf2f1000],  sp=0x00007fffdf2f0860,  free space=1022k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0x8d8d0a]  JVM_handle_bsd_signal+0x125c4a
j  sun.misc.Unsafe.getByte(J)B+0
j  java.nio.MappedByteBuffer.load()Ljava/nio/MappedByteBuffer;+85
j  Truncate$2.call()Ljava/lang/Void;+4

Cores in this initial run are pretty useless and I am now rebuilding with FASTDEBUG in the hope of getting enough symbolic information for them to be particularly useful, however, one observation is that the MappedByteBuffer core always results in the stack being unavailable...

root@testbuild1:/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core # gdb -c ./JTwork/java/nio/MappedByteBuffer/Truncate/java.core
GNU gdb 6.1.1 [FreeBSD]
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "amd64-marcel-freebsd".
Core was generated by `java'.
Program terminated with signal 6, Aborted.
#0  0x0000000800f2635a in ?? ()
(gdb) info stack
#0  0x0000000800f2635a in ?? ()
Cannot access memory at address 0x7fffdf2efc48
(gdb)

Comment 1 Andrew Smith 2016-05-18 08:42:14 UTC

Sections from output.txt (which is too large to post)..


....
--------------------------------------------------
TEST: java/nio/MappedByteBuffer/Force.java
  build: 0.174 seconds
  compile: 0.174 seconds
  main: 0.891 seconds
TEST RESULT: Passed. Execution successful
--------------------------------------------------
TEST: java/nio/MappedByteBuffer/Truncate.java
JDK under test: (/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/images/j2sdk-image)
openjdk version "1.8.0_77"
OpenJDK Runtime Environment (build 1.8.0_77-b03)
OpenJDK 64-Bit Server VM (build 25.77-b03, mixed mode)


ACTION: build -- Passed. Build successful
REASON: Named class compiled on demand
TIME:   0.171 seconds
messages:
command: build Truncate
reason: Named class compiled on demand
elapsed time (seconds): 0.171

ACTION: compile -- Passed. Compilation successful
REASON: .class file out of date or does not exist
TIME:   0.17 seconds
messages:
command: compile -XDignore.symbol.file=true /usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer/Truncate.java
reason: .class file out of date or does not exist
elapsed time (seconds): 0.17
rerun:
HOME=/usr/ports/java/openjdk8/work \
LANG=C \
LC_ALL=C \
PATH=/bin:/usr/bin \
    /usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/images/j2sdk-image/bin/javac \
        -J-ea \
        -J-esa \
        -J-Xmx512m \
        -J-Dtest.vm.opts='-ea -esa -Xmx512m' \
        -J-Dtest.class.path.prefix=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/JTwork/classes/0/java/nio/MappedByteBuffer:/usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer \
        -J-Dtest.jdk=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/images/j2sdk-image \
        -J-Dtest.timeout.factor=4.0 \
        -J-Dtest.src.path=/usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer \
        -J-Dtest.compiler.opts= \
        -J-Dcompile.jdk=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/images/j2sdk-image \
        -J-Dtest.classes=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/JTwork/classes/0/java/nio/MappedByteBuffer \
        -J-Dtest.class.path=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/JTwork/classes/0/java/nio/MappedByteBuffer \
        -J-Dtest.java.opts= \
        -J-Dtest.src=/usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer \
        -J-Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m' \
        -d /usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/JTwork/classes/0/java/nio/MappedByteBuffer -classpath /usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/JTwork/classes/0/java/nio/MappedByteBuffer:/usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer:/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/images/j2sdk-image/lib/tools.jar -sourcepath /usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer -XDignore.symbol.file=true /usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer/Truncate.java

ACTION: main -- Failed. Unexpected exit from test [exit code: 134]
REASON: User specified action: run main/othervm Truncate
TIME:   0.572 seconds
messages:
command: main Truncate
reason: User specified action: run main/othervm Truncate
elapsed time (seconds): 0.572
STDOUT:
#
# A fatal error has been detected by the Java Runtime Environment:
#
#  SIGSEGV (0xb) at pc=0x00000008024d8d0a, pid=57787, tid=100433
#
# JRE version: OpenJDK Runtime Environment (8.0_77-b03) (build 1.8.0_77-b03)
# Java VM: OpenJDK 64-Bit Server VM (25.77-b03 mixed mode bsd-amd64 compressed oops)
# Problematic frame:
# V  [libjvm.so+0x8d8d0a]  JVM_handle_bsd_signal+0x125c4a
#
# Core dump written. Default location: /usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/JTwork/scratch/0/java.core
#
# An error report file with more information is saved as:
# /usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/JTwork/scratch/0/hs_err_pid57787.log
#
# If you would like to submit a bug report, please visit:
#   http://bugreport.java.com/bugreport/crash.jsp
#
STDERR:
rerun:
HOME=/usr/ports/java/openjdk8/work \
LANG=C \
LC_ALL=C \
PATH=/bin:/usr/bin \
CLASSPATH=/usr/ports/java/openjdk8/work/jtreg/lib/javatest.jar:/usr/ports/java/openjdk8/work/jtreg/lib/jtreg.jar:/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/JTwork/classes/0/java/nio/MappedByteBuffer:/usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer:/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/images/j2sdk-image/lib/tools.jar \
    /usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/images/j2sdk-image/bin/java \
        -Dtest.vm.opts='-ea -esa -Xmx512m' \
        -Dtest.class.path.prefix=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/JTwork/classes/0/java/nio/MappedByteBuffer:/usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer \
        -Dtest.jdk=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/images/j2sdk-image \
        -Dtest.timeout.factor=4.0 \
        -Dtest.src.path=/usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer \
        -Dtest.compiler.opts= \
        -Dcompile.jdk=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/images/j2sdk-image \
        -Dtest.classes=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/JTwork/classes/0/java/nio/MappedByteBuffer \
        -Dtest.class.path=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/JTwork/classes/0/java/nio/MappedByteBuffer \
        -Dtest.java.opts= \
        -Dtest.src=/usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer \
        -Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m' \
        -ea -esa -Xmx512m \
        com.sun.javatest.regtest.MainWrapper /usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/JTwork/classes/0/java/nio/MappedByteBuffer/Truncate.jta

TEST RESULT: Failed. Unexpected exit from test [exit code: 134]
--------------------------------------------------
TEST: java/nio/MappedByteBuffer/ZeroMap.java
  build: 0.149 seconds
  compile: 0.149 seconds
  main: 0.977 seconds
TEST RESULT: Passed. Execution successful
--------------------------------------------------
.....



....
--------------------------------------------------
TEST: sun/misc/Version/Version.java
  compile: 0.16 seconds
  build: 0.001 seconds
  main: 0.22 seconds
TEST RESULT: Passed. Execution successful
--------------------------------------------------
Agent[6].stdout: #
Agent[6].stdout: # A fatal error has been detected by the Java Runtime Environment:
Agent[6].stdout: #
Agent[6].stdout: #  SIGSEGV (0xb) at pc=0x00000008024d3ced, pid=57712, tid=100802
Agent[6].stdout: #
Agent[6].stdout: # JRE version: OpenJDK Runtime Environment (8.0_77-b03) (build 1.8.0_77-b03)
Agent[6].stdout: # Java VM: OpenJDK 64-Bit Server VM (25.77-b03 mixed mode bsd-amd64 compressed oops)
Agent[6].stdout: # Problematic frame:
Agent[6].stdout: # V  [libjvm.so+0x8d3ced]  JVM_handle_bsd_signal+0x120c2d
Agent[6].stdout: #
Agent[6].stdout: # Core dump written. Default location: /usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/JTwork/scratch/0/java.core
Agent[6].stdout: #
Agent[6].stdout: # An error report file with more information is saved as:
Agent[6].stdout: # /usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-release/testoutput/jdk_core/JTwork/scratch/0/hs_err_pid57712.log
Agent[6].stdout: #
Agent[6].stdout: # If you would like to submit a bug report, please visit:
Agent[6].stdout: #   http://bugreport.java.com/bugreport/crash.jsp
Agent[6].stdout: #
TEST: jdk/lambda/FDTest.java
  build: 0.004 seconds
  testng: 75.952 seconds
TEST RESULT: Passed. Execution successful
--------------------------------------------------
....

Comment 2 Andrew Smith 2016-05-18 08:43:04 UTC

Created attachment 170425 [details]
hs_err_pid57712.log

Comment 3 Andrew Smith 2016-05-18 08:43:29 UTC

Created attachment 170426 [details]
hs_err_pid57787.log

Comment 4 Andrew Smith 2016-05-18 08:51:56 UTC

Noting the sun.misc.Unsafe class implementation is through the various java.lang.reflect.* classes which in turn interface directly with Hotspot internal methods so although the provided stack trace reaches this far the likely cause when resolved is within Hotspot code.

Comment 5 Andrew Smith 2016-05-18 12:22:38 UTC

Confirmed to happen on uniprocessor systems as well as multiprocessor.

Comment 6 Andrew Smith 2016-05-19 12:15:05 UTC

Following a few false starts without being able to get gdb to unwind the stack trace I decided to invoke the test directly with -XX:+ShowMessageBoxOnError so I could hop into gdb directly.

It's identified Unsafe_GetNativeByte as the cause of the SIGSEGV but this is somewhat obfuscated by it being macro generated.

Just thought I had better test this with PCH turned off before I proceed so next report will be results of that.

/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-slowdebug/images/j2sdk-image/bin/javac -J-ea -J-esa -J-Xmx512m -J-Dtest.vm.opts='-ea -esa -Xmx512m'  -J-Dtest.class.path.prefix=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-slowdebug/testoutput/jdk_core/JTwork/classes/1/java/nio/MappedByteBuffer:/usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer  -J-Dtest.jdk=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-slowdebug/images/j2sdk-image  -J-Dtest.timeout.factor=4.0 -J-Dtest.src.path=/usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer  -J-Dtest.compiler.opts=  -J-Dcompile.jdk=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-slowdebug/images/j2sdk-image  -J-Dtest.classes=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-slowdebug/testoutput/jdk_core/JTwork/classes/1/java/nio/MappedByteBuffer  -J-Dtest.class.path=/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-slowdebug/testoutput/jdk_core/JTwork/classes/1/java/nio/MappedByteBuffer -J-Dtest.java.opts=  -J-Dtest.src=/usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer -J-Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m' -d  /usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-slowdebug/testoutput/jdk_core/JTwork/classes/1/java/nio/MappedByteBuffer -classpath /usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-slowdebug/testoutput/jdk_core/JTwork/classes/1/java/nio/MappedByteBuffer:/usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer:/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-slowdebug/images/j2sdk-image/lib/tools.jar -sourcepath /usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer -XDignore.symbol.file=true /usr/ports/java/openjdk8/work/openjdk/jdk/test/java/nio/MappedByteBuffer/Truncate.java

root@testbuild1:/usr/ports/java/openjdk8/work/openjdk/build/bsd-x86_64-normal-server-slowdebug/testoutput/jdk_core/JTwork/classes/1/java/nio/MappedByteBuffer # java -XX:+ShowMessageBoxOnError -cp . Truncate
==============================================================================
Unexpected Error
------------------------------------------------------------------------------
SIGSEGV (0xb) at pc=0x0000000802a01fab, pid=88015, tid=100683

Do you want to debug the problem?

To debug, run 'gdb /usr/local/openjdk8/bin/java 88015'; then switch to thread 100683 (0x000000000001894b)
Enter 'yes' to launch gdb automatically (PATH must include gdb)
Otherwise, press RETURN to abort...
==============================================================================
yes
GNU gdb 6.1.1 [FreeBSD]
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "amd64-marcel-freebsd"...(no debugging symbols found)...
Attaching to program: /usr/local/openjdk8/bin/java, process 88015
Reading symbols from /usr/local/openjdk8/bin/../lib/amd64/jli/libjli.so...done.
Loaded symbols for /usr/local/openjdk8/bin/../lib/amd64/jli/libjli.so
Reading symbols from /lib/libz.so.6...done.
Loaded symbols for /lib/libz.so.6
Reading symbols from /lib/libthr.so.3...done.
[New Thread 803ce6000 (LWP 100683/java)]
[New Thread 803ce5800 (LWP 100865/java)]
[New Thread 803ce5400 (LWP 100864/java)]
[New Thread 803ce5000 (LWP 100863/java)]
[New Thread 803ce4c00 (LWP 100862/java)]
[New Thread 803ce4800 (LWP 100861/java)]
[New Thread 803ce4400 (LWP 100860/java)]
[New Thread 803ce3c00 (LWP 100857/java)]
[New Thread 803ce3800 (LWP 100747/java)]
[New Thread 803ce3400 (LWP 100405/java)]
[New Thread 803ce3000 (LWP 100401/java)]
[New Thread 803ce2c00 (LWP 100348/java)]
[New Thread 803ce2800 (LWP 100122/java)]
[New Thread 803ce2400 (LWP 100090/java)]
[New Thread 801806800 (LWP 100070/java)]
[New Thread 801806400 (LWP 100286/java)]
Loaded symbols for /lib/libthr.so.3
Reading symbols from /lib/libc.so.7...done.
Loaded symbols for /lib/libc.so.7
Reading symbols from /usr/local/openjdk8/jre/lib/amd64/server/libjvm.so...Reading symbols from /usr/local/openjdk8/jre/lib/amd64/server/libjvm.debuginfo...done.
done.
Loaded symbols for /usr/local/openjdk8/jre/lib/amd64/server/libjvm.so
Reading symbols from /lib/libm.so.5...done.
Loaded symbols for /lib/libm.so.5
Reading symbols from /usr/lib/libc++.so.1...done.
Loaded symbols for /usr/lib/libc++.so.1
Reading symbols from /lib/libcxxrt.so.1...done.
Loaded symbols for /lib/libcxxrt.so.1
Reading symbols from /lib/libgcc_s.so.1...done.
Loaded symbols for /lib/libgcc_s.so.1
Reading symbols from /usr/local/openjdk8/jre/lib/amd64/libverify.so...Reading symbols from /usr/local/openjdk8/jre/lib/amd64/libverify.debuginfo...done.
done.
Loaded symbols for /usr/local/openjdk8/jre/lib/amd64/libverify.so
Reading symbols from /usr/local/openjdk8/jre/lib/amd64/libjava.so...Reading symbols from /usr/local/openjdk8/jre/lib/amd64/libjava.debuginfo...done.
done.
Loaded symbols for /usr/local/openjdk8/jre/lib/amd64/libjava.so
Reading symbols from /usr/local/openjdk8/jre/lib/amd64/libzip.so...Reading symbols from /usr/local/openjdk8/jre/lib/amd64/libzip.debuginfo...done.
done.
Loaded symbols for /usr/local/openjdk8/jre/lib/amd64/libzip.so
Reading symbols from /usr/local/openjdk8/jre/lib/amd64/libnet.so...Reading symbols from /usr/local/openjdk8/jre/lib/amd64/libnet.debuginfo...done.
done.
Loaded symbols for /usr/local/openjdk8/jre/lib/amd64/libnet.so
Reading symbols from /usr/local/openjdk8/jre/lib/amd64/libnio.so...Reading symbols from /usr/local/openjdk8/jre/lib/amd64/libnio.debuginfo...done.
done.
Loaded symbols for /usr/local/openjdk8/jre/lib/amd64/libnio.so
Reading symbols from /libexec/ld-elf.so.1...done.
Loaded symbols for /libexec/ld-elf.so.1
[Switching to Thread 803ce6000 (LWP 100683/java)]
0x0000000800f479b8 in _wait4 () from /lib/libc.so.7
(gdb) bt
#0  0x0000000800f479b8 in _wait4 () from /lib/libc.so.7
#1  0x0000000800c521cc in pthread_suspend_all_np () from /lib/libthr.so.3
#2  0x0000000802848d88 in os::fork_and_exec (cmd=0x803192850 "gdb /usr/local/openjdk8/bin/java 88015") at /usr/ports/java/openjdk8/work/openjdk/hotspot/src/os/bsd/vm/os_bsd.cpp:4878
#3  0x0000000802a3e297 in VMError::show_message_box (this=0x7fffdf0ed8d8, buf=0x803192850 "gdb /usr/local/openjdk8/bin/java 88015", buflen=2000) at /usr/ports/java/openjdk8/work/openjdk/hotspot/src/os/bsd/vm/vmError_bsd.cpp:80
#4  0x0000000802a3d085 in VMError::report_and_die (this=0x7fffdf0ed8d8) at /usr/ports/java/openjdk8/work/openjdk/hotspot/src/share/vm/utilities/vmError.cpp:881
#5  0x000000080284a704 in JVM_handle_bsd_signal (sig=11, info=0x7fffdf0ee230, ucVoid=0x7fffdf0edec0, abort_if_unrecognized=1) at /usr/ports/java/openjdk8/work/openjdk/hotspot/src/os_cpu/bsd_x86/vm/os_bsd_x86.cpp:731
#6  0x0000000802844e77 in signalHandler (sig=11, info=0x7fffdf0ee230, uc=0x7fffdf0edec0) at /usr/ports/java/openjdk8/work/openjdk/hotspot/src/os/bsd/vm/os_bsd.cpp:3207
#7  0x0000000800c54b37 in pthread_sigmask () from /lib/libthr.so.3
#8  0x0000000800c5422c in pthread_getspecific () from /lib/libthr.so.3
#9  <signal handler called>
#10 0x0000000802a01fab in Unsafe_GetNativeByte (env=0x8c9b0da20, unsafe=0x7fffdf0ee568, addr=34366722048) at /usr/ports/java/openjdk8/work/openjdk/hotspot/src/share/vm/prims/unsafe.cpp:539
#11 0x000000080467b162 in ?? ()
#12 0x00000000000003d8 in ?? ()
#13 0x00000008c9b0d800 in ?? ()
#14 0x00007fffdf0ee5b8 in ?? ()
#15 0x00007fffdf0ee4f8 in ?? ()
#16 0x0000000000000000 in ?? ()
(gdb) frame 10
#10 0x0000000802a01fab in Unsafe_GetNativeByte (env=0x8c9b0da20, unsafe=0x7fffdf0ee568, addr=34366722048) at /usr/ports/java/openjdk8/work/openjdk/hotspot/src/share/vm/prims/unsafe.cpp:539
539	DEFINE_GETSETNATIVE(jbyte, Byte, signed char)
Current language:  auto; currently c++
(gdb) list
534	  t->set_doing_unsafe_access(false); \
535	UNSAFE_END \
536	 \
537	// END DEFINE_GETSETNATIVE.
538	
539	DEFINE_GETSETNATIVE(jbyte, Byte, signed char)
540	DEFINE_GETSETNATIVE(jshort, Short, signed short);
541	DEFINE_GETSETNATIVE(jchar, Char, unsigned short);
542	DEFINE_GETSETNATIVE(jint, Int, jint);
543	// no long -- handled specially
(gdb) frame 9
#9  <signal handler called>
(gdb) list
544	DEFINE_GETSETNATIVE(jfloat, Float, float);
545	DEFINE_GETSETNATIVE(jdouble, Double, double);
546	
547	#undef DEFINE_GETSETNATIVE
548	
549	UNSAFE_ENTRY(jlong, Unsafe_GetNativeLong(JNIEnv *env, jobject unsafe, jlong addr))
550	  UnsafeWrapper("Unsafe_GetNativeLong");
551	  JavaThread* t = JavaThread::current();
552	  // We do it this way to avoid problems with access to heap using 64
553	  // bit loads, as jlong in heap could be not 64-bit aligned, and on
(gdb)

Comment 7 Andrew Smith 2016-05-19 13:40:18 UTC

turning off PCH makes no difference, the fault still occurs.

Interestingly with slow debug only the MappedByteBuffer.Truncate test throws the exception.

Looking at the disassembly of the region of code...

0x0000000802a01f8b <Unsafe_GetNativeByte+347>:	callq  0x801f04550 <_ZN10JavaThread7currentEv>
0x0000000802a01f90 <Unsafe_GetNativeByte+352>:	mov    $0x1,%esi
0x0000000802a01f95 <Unsafe_GetNativeByte+357>:	mov    %rax,-0x60(%rbp)
0x0000000802a01f99 <Unsafe_GetNativeByte+361>:	mov    -0x60(%rbp),%rdi
0x0000000802a01f9d <Unsafe_GetNativeByte+365>:	callq  0x802a09fe0 <_ZN10JavaThread23set_doing_unsafe_accessEb>
0x0000000802a01fa2 <Unsafe_GetNativeByte+370>:	mov    $0x0,%esi
0x0000000802a01fa7 <Unsafe_GetNativeByte+375>:	mov    -0x58(%rbp),%rax
0x0000000802a01fab <Unsafe_GetNativeByte+379>:	mov    (%rax),%cl             # SIGSEGV is HERE
0x0000000802a01fad <Unsafe_GetNativeByte+381>:	mov    %cl,-0x61(%rbp)
0x0000000802a01fb0 <Unsafe_GetNativeByte+384>:	mov    -0x60(%rbp),%rdi
0x0000000802a01fb4 <Unsafe_GetNativeByte+388>:	callq  0x802a09fe0 <_ZN10JavaThread23set_doing_unsafe_accessEb>
0x0000000802a01fb9 <Unsafe_GetNativeByte+393>:	lea    -0x48(%rbp),%rdi
0x0000000802a01fbd <Unsafe_GetNativeByte+397>:	mov    -0x61(%rbp),%cl

This pretty much maps to here in unsafe.cpp

#define DEFINE_GETSETNATIVE(java_type, Type, native_type) \
 \
UNSAFE_ENTRY(java_type, Unsafe_GetNative##Type(JNIEnv *env, jobject unsafe, jlong addr)) \
  UnsafeWrapper("Unsafe_GetNative"#Type); \
  void* p = addr_from_java(addr); \
  JavaThread* t = JavaThread::current(); \
  t->set_doing_unsafe_access(true); \
  java_type x = *(volatile native_type*)p; \ # So, here in our macro
  t->set_doing_unsafe_access(false); \
  return x; \
UNSAFE_END \
 \
UNSAFE_ENTRY(void, Unsafe_SetNative##Type(JNIEnv *env, jobject unsafe, jlong addr, java_type x)) \
  UnsafeWrapper("Unsafe_SetNative"#Type); \
  JavaThread* t = JavaThread::current(); \
  t->set_doing_unsafe_access(true); \
  void* p = addr_from_java(addr); \
  *(volatile native_type*)p = x; \
  t->set_doing_unsafe_access(false); \
UNSAFE_END \
 \
// END DEFINE_GETSETNATIVE.

DEFINE_GETSETNATIVE(jbyte, Byte, signed char)
DEFINE_GETSETNATIVE(jshort, Short, signed short);
DEFINE_GETSETNATIVE(jchar, Char, unsigned short);
DEFINE_GETSETNATIVE(jint, Int, jint);
// no long -- handled specially
DEFINE_GETSETNATIVE(jfloat, Float, float);
DEFINE_GETSETNATIVE(jdouble, Double, double);

As far as I can see this looks OK and I suspect this is more about the caller than this particular function.

Unfortunately from frame 11 onwards we look to be in the murky region of hotspot compiled code and gdb is isn't really much help following that piece.

Comment 8 Andrew Smith 2016-05-19 13:42:17 UTC

i.e.

(gdb) frame 11
#11 0x000000080467b162 in ?? ()
(gdb) disassem
No function contains program counter for selected frame.

Comment 9 Andrew Smith 2016-05-19 16:07:59 UTC

Went at this form the other end as I had visibility of the native code.

Examining the stack from earlier we have the use of the load method to look at.

Stack: [0x00007fffdf1f1000,0x00007fffdf2f1000],  sp=0x00007fffdf2f0860,  free space=1022k
Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code)
V  [libjvm.so+0x8d8d0a]  JVM_handle_bsd_signal+0x125c4a
j  sun.misc.Unsafe.getByte(J)B+0
j  java.nio.MappedByteBuffer.load()Ljava/nio/MappedByteBuffer;+85
j  Truncate$2.call()Ljava/lang/Void;+4
j  Truncate$2.call()Ljava/lang/Object;+1
j  Truncate$3.run()V+4
j  java.lang.Thread.run()V+11
v  ~StubRoutines::call_stub
V  [libjvm.so+0x59d83b]  AsyncGetCallTrace+0xcab7b
V  [libjvm.so+0x59c283]  AsyncGetCallTrace+0xc95c3
V  [libjvm.so+0x59c4bc]  AsyncGetCallTrace+0xc97fc
V  [libjvm.so+0x608c3e]  JVM_StartThread+0x36e
V  [libjvm.so+0x8b1600]  JVM_handle_bsd_signal+0xfe540
V  [libjvm.so+0x7ad3af]  JVM_FindSignal+0x19a4ff
C  [libthr.so.3+0x8855]  operator->+0x805
C  0x0000000000000000

    public final MappedByteBuffer load() {
        checkMapped();
        if ((address == 0) || (capacity() == 0))
            return this;
        long offset = mappingOffset();
        long length = mappingLength(offset);
        load0(mappingAddress(offset), length);

        // Read a byte from each page to bring it into memory. A checksum
        // is computed as we go along to prevent the compiler from otherwise
        // considering the loop as dead code.
        Unsafe unsafe = Unsafe.getUnsafe();
        int ps = Bits.pageSize();
        int count = Bits.pageCount(length);
        long a = mappingAddress(offset);
        byte x = 0;
        for (int i=0; i<count; i++) {
            x ^= unsafe.getByte(a);
            a += ps;
        }
        if (unused != 0)
            unused = x;

        return this;
    }

Unsafe, it seems is used to demand page the file in.

Looking at other unit tests we can see .load works OK, however, in this test the file is truncated an then we attempt to demand page it in (this works based on the length known by the MappedByteBuffer and here's where it fails.


        try {
            fc.truncate(TRUNCATED_FILE_SIZE);
            truncated = true;
        } catch (IOException ioe) {
            // probably on Windows where a file cannot be truncated when
            // there is a file mapping.
            truncated = false;
        }
        if (truncated) {
            // Test 1: access region that is no longer accessible
            execute(new Callable<Void>() {
                public Void call() {
                    mbb.get((int)TRUNCATED_FILE_SIZE + 1);
                    mbb.put((int)TRUNCATED_FILE_SIZE + 2, (byte)123);
                    return null;
                }
            });
            // Test 2: load buffer into memory
            execute(new Callable<Void>() {
                public Void call() throws IOException {
                    mbb.load();
                    return null;
                }
            });
        }
        fc.close();
    }

    // Runs the given task in its own thread. If operating correcting the
    // the thread will terminate with an InternalError as the mapped buffer
    // is inaccessible.
    static void execute(final Callable<?> c) {
        Runnable r = new Runnable() {
            public void run() {
                try {
                    Object ignore = c.call();
                } catch (Exception ignore) {
                }
            }
        };

Noting what it mentions in the execute wrapper.. there is an expectation that InternalError is raised but we are receiving a SIGSEGV.

Comment 10 openjdk 2016-05-19 18:01:50 UTC

That's really interesting.  It seems that if MappedByteBuffer is using Unsafe operations to load a truncated file into memory that a SEGV would be expected.  I wonder how this generates an internal error on other Operating Systems.  I saw a comment in the test that windows throws an error when you try to truncate a file that has an open MappedByteBuffer, maybe FreeBSD should as well.



        try {
            fc.truncate(TRUNCATED_FILE_SIZE);
            truncated = true;
        } catch (IOException ioe) {
            // probably on Windows where a file cannot be truncated when
            // there is a file mapping.
            truncated = false;
        }

Comment 11 Andrew Smith 2016-05-19 22:39:23 UTC

exactly.. I suspect I will be spending a lot of tomorrow examining this

Comment 12 Andrew Smith 2016-05-20 08:51:56 UTC

Reported as a bug that didn't effect Solaris or Windows but did effect Linux at the time. (Bug ID referenced in the unit test  code)

http://bugs.java.com/bugdatabase/view_bug.do?bug_id=6934977

The useful bit is right at the end.

"
EVALUATION

The issue here is that the load method is touching each page in a native method rather rather than using the Unsafe API. This means the sig handler doesn't know to unwind the stack."

Noting also that I ran this unit test under FreeBSD OpenJDK7 independently and it also produces a SIGSEGV.

Comment 13 Andrew Smith 2016-05-20 12:15:27 UTC

I have a patch that has passed initial testing and will post this as soon as I have run a full regression test doing both fastdebug and release builds along with my observations.

Comment 14 Andrew Smith 2016-05-20 15:31:59 UTC

Created attachment 170507 [details]
java/openjdk8 patch

Drop into /usr/ports/java/openjdk8/files and build port

Comment 15 Andrew Smith 2016-05-20 15:34:35 UTC

Created attachment 170508 [details]
java/openjdk7 patch

Drop into /usr/ports/java/openjdk7/files and make the port.

This, if accepted, shoudld be merged into patch-bsd since that file already contains changes to hotspot/src/os_cpu/bsd_x86/vm/os_bsd_x86.cpp. Sent this way so that one can conveniently add/remove it.

Comment 16 Andrew Smith 2016-05-20 15:38:18 UTC

The patches attached simply add in SIGSEGV as a possible signal that needs to be handled as the exception whilst using sun.misc.Unsafe functions.

The original implementation had handlers for SIGBUS only and with this change the handlers now raise the appropriate java exception rather than fatally killing the vm.

root@testbuild1:~ # /usr/local/openjdk8/bin/java -cp . Truncate
java.lang.InternalError: a fault occurred in a recent unsafe memory access operation in compiled Java code
	at java.nio.MappedByteBuffer.load(MappedByteBuffer.java:175)
	at Truncate$2.call(Truncate.java:70)
	at Truncate$2.call(Truncate.java:68)
	at Truncate$3.run(Truncate.java:85)
	at java.lang.Thread.run(Thread.java:745)
root@testbuild1:~ # /usr/local/openjdk7/bin/java -cp . Truncate
java.lang.InternalError: a fault occurred in a recent unsafe memory access operation in compiled Java code
	at java.nio.MappedByteBuffer.load(MappedByteBuffer.java:175)
	at Truncate$2.call(Truncate.java:70)
	at Truncate$2.call(Truncate.java:68)
	at Truncate$3.run(Truncate.java:85)
	at java.lang.Thread.run(Thread.java:745)
root@testbuild1:~ #

Comment 17 Andrew Smith 2016-05-20 17:07:15 UTC

Changed the title a lot I know but this bug is the closest.

Comment 18 openjdk 2016-05-24 05:47:19 UTC

+1
Good work tracking that down.  I'm not a Freebsd committer, so I can't sponsor these patches into the Freebsd ports tree.  However, if you've already agreed to, or are willing and capable of agreeing to Oracle's OCA, I'll sponsor getting the patch into the bsd-port openjdk repository.

http://openjdk.java.net/contribute/

Comment 19 Andrew Smith 2016-05-25 07:43:12 UTC

Awaiting feedback from my company on signing up to the OCA.

It may be that they would be happy for me to individually sign the OCA and allow me to submit such patches as my own work but it needs to go by legal.

There's a bunch of stuff in the OCA about surrendering rights on patentable material etc. which I'm sure only applies to the contributions made but it's the sort of thing that brings out legal teams in a rash.

As far as these changes go, this it Hotspot and a body of GPL work so the patches should be made available anyway and I would be happy for any other committer to add this to either the bad-port upstream or to the patch set here.

Comment 20 commit-hook freebsd_committer

2016-06-12 21:54:40 UTC

A commit references this bug:

Author: glewis
Date: Sun Jun 12 21:53:49 UTC 2016
New revision: 416825
URL: https://svnweb.freebsd.org/changeset/ports/416825

Log:
  Handle unsafe operations that access invalid memory more gracefully

  PR:		209599
  Submitted by:	Andrew Smith <iamasmith.home@gmail.com>

Changes:
  head/java/openjdk8/files/patch-hotspot-src-os_cpu-bsd_x86-vm-os_bsd_x86.cpp

Comment 21 commit-hook freebsd_committer

2016-06-13 04:58:09 UTC

A commit references this bug:

Author: glewis
Date: Mon Jun 13 04:57:28 UTC 2016
New revision: 416828
URL: https://svnweb.freebsd.org/changeset/ports/416828

Log:
  . Handle unsafe operations that access invalid memory more gracefully.
  . Bump PORTREVISION for this fix.

  PR:		209599
  Submitted by:	Andrew Smith <iamasmith.home@gmail.com>

Changes:
  head/java/openjdk7/Makefile
  head/java/openjdk7/files/patch-hotspot-src-os_cpu-bsd_x86-vm-os_bsd_x86.cpp

Comment 22 Greg Lewis freebsd_committer

2016-06-13 05:05:56 UTC

Andrew, thanks for working on this and for the patches.  I'd love to upstream this, so please let me know if you have success with getting the OCA signed either personally or at a company level.

Comment 23 Andrew Smith 2016-06-13 07:25:25 UTC

I'll get a copy of the OCA signed personally I think as everybody here says that's probably the best way to proceed.

Comment 24 Andrew Smith 2016-06-13 08:25:01 UTC

Form emailed in, I'll update this PR when my name appears on the list.

Comment 25 Andrew Smith 2016-06-22 13:38:49 UTC

My OCA has been processed and I now appear on the OCA web page as 'Andrew Smith - OpenJDK' and am happy for you to sponsor these changes should you wish.

-Andy

Comment 26 Greg Lewis freebsd_committer

2016-07-27 01:38:06 UTC

Pushed upstream, will be in the next generated patchset.  Thanks Andrew!