JDK-8146263 : tools/pack200/Pack200Test.java failed intermittently with "Unexpected exit from test [exit code: -1073740940]"
  • Type: Bug
  • Component: hotspot
  • Sub-Component: runtime
  • Affected Version: 9
  • Priority: P2
  • Status: Closed
  • Resolution: Cannot Reproduce
  • OS: windows
  • CPU: generic
  • Submitted: 2015-12-29
  • Updated: 2016-09-23
  • Resolved: 2016-07-14
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 9
9 b126Resolved
Related Reports
Relates :  
JDK-8148813 - Windows os::check_heap needs more information
Relates :  
JDK-8146587 - Mark tools/pack200/Pack200Test.java as intermittently failing
Relates :  
JDK-8147876 - ciTypeFlow::is_dominated_by() writes outside dominated array
Relates :  
JDK-8163146 - Remove os::check_heap on Windows
Description
This happened 10 times in jdk 9 b97 same binaries run. It is windows only.

Please refer to the output below:
----------System.out:(9/642)*----------
--listing C:\\Users\\aurora\\sandbox_keepme\\results\\run_52\\testoutput\\tier2\\JTwork\\scratch\\0\\.---
C:\\Users\\aurora\\sandbox_keepme\\jdk\\bin\\jimage.exe extract C:\\Users\\aurora\\sandbox_keepme\\jdk\\lib\\modules\\bootmodules.jimage --dir out 
--listing C:\\Users\\aurora\\sandbox_keepme\\results\\run_52\\testoutput\\tier2\\JTwork\\scratch\\0\\.---
d out
C:\\Users\\aurora\\sandbox_keepme\\jdk\\bin\\jar.exe cf rt.jar -C out . 
[rt.jar, C:\\Users\\aurora\\sandbox_keepme\\testbase\\jdk\\test\\tools\\pack200\\pack200-verifier\\data\\golden.jar]
Packing [rt.jar]
  Info: memory diff = 3804K
  Unpacking using java unpacker
----------System.err:(0/0)----------
----------rerun:(22/3409)*----------
PATH='C:\\cygwin\\usr\\local\\bin;C:\\cygwin\\bin;C:\\Program Files (x86)\\Common Files\\Intel\\Shared Libraries\\redist\\intel64\\compiler;C:\\Program Files (x86)\\Common Files\\Intel\\Shared Libraries\\redist\\ia32\\compiler;C:\\jdk7u51\\bin;C:\\Windows\\System32;C:\\Windows\\system32;C:\\Windows;C:\\Windows\\System32\\Wbem;C:\\Windows\\System32\\WindowsPowerShell\\v1.0;C:\\ACTIVE~1\\BIN;C:\\AIME\\BIN;C:\\Program Files\\Microsoft Platform SDK\\bin\\win64\\x86\\AMD64;C:\\Program Files\\Microsoft Platform SDK\\Bin\\win64\\AMD64;C:\\Program Files\\Microsoft Platform SDK\\Bin;C:\\Program Files\\Microsoft Platform SDK\\Bin\\Winnt;C:\\PROGRAM FILES\\TERATERM;C:\\Program Files (x86)\\Microsoft SQL Server\\100\\Tools\\Binn;C:\\Program Files\\Microsoft SQL Server\\100\\Tools\\Binn;C:\\Program Files\\Microsoft SQL Server\\100\\DTS\\Binn;C:\\Program Files\\Microsoft\\Web Platform Installer;C:\\Program Files (x86)\\Microsoft ASP.NET\\ASP.NET Web Pages\\v1.0;C:\\Program Files\\Microsoft SQL Server\\110\\Tools\\Binn;C:\\program files (x86)\\intel\\compiler\\11.1\\067\\tbb\\intel64\\vc9\\bin;C:\\program files (x86)\\intel\\compiler\\11.1\\067\\ipp\\em64t\\bin;C:\\Program Files (x86)\\Intel\\Compiler\\11.1\\067\\lib\\intel64;C:\\program files (x86)\\intel\\compiler\\11.1\\067\\mkl\\em64t\\bin;C:\\program files (x86)\\intel\\composerxe-2011\\redist\\intel64\\ipp;C:\\program files (x86)\\intel\\composerxe-2011\\redist\\intel64\\mkl;C:\\Program Files (x86)\\Intel\\ComposerXE-2011\\redist\\intel64\\compiler;C:\\Program Files (x86)\\Intel\\ComposerXE-2011\\compiler\\lib' \\
SystemDrive=C: \\
SystemRoot='C:\\Windows' \\
TEMP='C:\\cygwin\\tmp' \\
TMP='C:\\cygwin\\tmp' \\
windir='C:\\Windows' \\
CLASSPATH='C:\\Users\\aurora\\sandbox_keepme\\jtreg\\lib\\javatest.jar;C:\\Users\\aurora\\sandbox_keepme\\jtreg\\lib\\jtreg.jar;C:\\Users\\aurora\\sandbox_keepme\\results\\run_52\\testoutput\\tier2\\JTwork\\classes\\1\\tools\\pack200;C:\\Users\\aurora\\sandbox_keepme\\testbase\\jdk\\test\\tools\\pack200' \\
    'C:\\Users\\aurora\\sandbox_keepme\\jdk\\bin\\java' \\
        -Dtest.class.path.prefix='C:\\Users\\aurora\\sandbox_keepme\\results\\run_52\\testoutput\\tier2\\JTwork\\classes\\1\\tools\\pack200;C:\\Users\\aurora\\sandbox_keepme\\testbase\\jdk\\test\\tools\\pack200' \\
        -Dtest.src='C:\\Users\\aurora\\sandbox_keepme\\testbase\\jdk\\test\\tools\\pack200' \\
        -Dtest.src.path='C:\\Users\\aurora\\sandbox_keepme\\testbase\\jdk\\test\\tools\\pack200' \\
        -Dtest.classes='C:\\Users\\aurora\\sandbox_keepme\\results\\run_52\\testoutput\\tier2\\JTwork\\classes\\1\\tools\\pack200' \\
        -Dtest.class.path='C:\\Users\\aurora\\sandbox_keepme\\results\\run_52\\testoutput\\tier2\\JTwork\\classes\\1\\tools\\pack200' \\
        -Dtest.vm.opts='-ea -esa -Xmx512m -XX:-TransmitErrorReport' \\
        -Dtest.tool.vm.opts='-J-ea -J-esa -J-Xmx512m -J-XX:-TransmitErrorReport' \\
        -Dtest.compiler.opts= \\
        -Dtest.java.opts= \\
        -Dtest.jdk='C:\\Users\\aurora\\sandbox_keepme\\jdk' \\
        -Dcompile.jdk='C:\\Users\\aurora\\sandbox_keepme\\jdk' \\
        -Dtest.timeout.factor=8.0 \\
        -ea -esa -Xmx512m -XX:-TransmitErrorReport -Xmx1280m -Xshare:off \\
        com.sun.javatest.regtest.agent.MainWrapper 'C:\\Users\\aurora\\sandbox_keepme\\results\\run_52\\testoutput\\tier2\\JTwork\\classes\\1\\tools\\pack200\\Pack200Test.jta'
result: Failed. Unexpected exit from test [exit code: -1073740940]


test result: Failed. Unexpected exit from test [exit code: -1073740940]
Comments
Attached new reliable reproducer (pack200_8164263.tar.gz) that can easily set up on Windows and Linux, and can run multiple processes in parallel to speed up reproduction.
14-07-2016
Since the crash can no longer be reproduced with latest JDK9 build (ea 126), I am closing this bug as not reproducible. If this crash appears again, please reopen the bug, and try to use pack200_8146263.tar.gz to test reproducibility.
14-07-2016
Results of running pack200_8146263.tar.gz (2016/07/13, SVN version 525) JDK9 build 104 - windows-x64: crashed after about 20 attempts JDK9 build 126 - windows-x64: no crash after 500+ attempts JDK9 build 104 - linux-x64: no crash after 300+ attempts JDK9 build 126 - linux-x64: no crash after 1000+ attempts
14-07-2016
Summary of the crash condition: os::free(0x0000000029DC7EC0) is called. This block has been previously returned by os::malloc. The block is a Chunk object (allocation.hpp) with a length of 32728 bytes, which is the same as Chunk::size (see allocation.hpp) size = 32*K - slack, // Default size of an Arena chunk (following the first) So the Chunk was most likely created by Arena::grow. The entire content of the Chunk seems to be unused (filled with 0xab or 0xf1 -- the 0xab's probably were written by ZapResourceArea). However, the 2 bytes immediately following by the chunk is over-written by zeros.
13-07-2016
Kumar's crash stack: https://bugs.openjdk.java.net/secure/attachment/57003/hs_err_pid7344.log Stack: [0x00000055aefb0000,0x00000055af0b0000] Native frames: (J=compiled Java code, j=interpreted, Vv=VM code, C=native code) V [jvm.dll+0x8f6420] os::platform_print_native_stack+0x100 V [jvm.dll+0xa9cd0f] VMError::report+0xabf V [jvm.dll+0xa9dc17] VMError::report_and_die+0x477 V [jvm.dll+0xa9e20d] VMError::report_and_die+0x5d V [jvm.dll+0x4709aa] report_fatal+0x7a V [jvm.dll+0x8e9fb2] verify_memory+0xf2 V [jvm.dll+0x8e64aa] os::free+0x6a V [jvm.dll+0x1f81ac] ChunkPool::free_all_but+0x6c V [jvm.dll+0xa2855e] PeriodicTask::real_time_tick+0x14e V [jvm.dll+0xa51d9e] WatcherThread::run+0x14e V [jvm.dll+0x8f1de6] java_start+0xe6 C [msvcr120.dll+0x24f7f] C [msvcr120.dll+0x25126] C [KERNEL32.DLL+0x1842] C [ntdll.dll+0x3df11] My crash (https://bugs.openjdk.java.net/secure/attachment/61382/hs_err_pid4700.log) also has the exact same crash. The call stack is obscured due to C++ compiler inlining. The ChunkPool::free_all_but comes from this periodic task in hotspot/src/share/vm/memory/allocation.cpp: class ChunkPoolCleaner : public PeriodicTask { enum { CleaningInterval = 5000 }; // cleaning interval in ms public: ChunkPoolCleaner() : PeriodicTask(CleaningInterval) {} void task() { ChunkPool::clean(); } }; ====[detailed reports from the memory stomp (hs_err_pid4700.stdout in attachment)]==== bit length overflow code 12 bits 7->6 code 4 bits 5->6 [rt.jar, C:\cygwin\home\kumasrin\workspaces\hg-dev9\jdk9\jdk\test\tools\pack200\pack200-verifier\data\golden.jar] Packing [rt.jar] ## nof_mallocs = 495601, nof_frees = 105199 ## memory stomp: GuardedMemory(0x000000001ff8f710) base_addr=0x0000000029dc7ea0 tag=0x0000000000000000 user_size=32760 user_data=0x0000000029dc7ec0 Header guard @0x0000000029dc7ea0 is OK Trailer guard @0x0000000029dcfeb8 is BROKEN User data appears to be in use =======[memory content of my crash]===== head guard OK-------vvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvvv 0x0000000029DC7EA0 abababababababab abababababababab 0000000000007ff8 0000000000000000 0x0000000029DC7EC0 000000005b6d90d8 000000002c824b10 0000000000007fd8 f1f1f1f1f1f1f1f1 0x0000000029DC7EE0 abababababababab abababababababab abababababababab abababababababab 0x0000000029DC7F00 abababababababab abababababababab abababababababab abababababababab 0x0000000029DC7F20 abababababababab abababababababab abababababababab abababababababab (repeated .......) abababababababab abababababababab abababababababab abababababababab 0x0000000029DCFE98 abababababababab abababababababab abababababababab abababababababab tail graud bad------vvvvvvvvvvvv???? vvvvvvvvvvvvvvvv 0x0000000029DCFEB8 abababababab0000 abababababababab 107b78a3293f2a70 abababababababab 0x0000000029DCFED8 abababababababab 0000000000020020 0000000000000000 000000005b6d90d8 0x0000000029DCFEF8 00000000249e10f0 0000000000020000 f1f1f1f1f1f1f1f1 0000000000000000 [0x0000000029DC7EC0 + 0] 000000005b6d90d8 = (from jvm.map file) 0002:000aa0d8 const Chunk::`vftable' 0000000008b790d8 allocation.obj [0x0000000029DC7EC0 + 8] 000000002c824b10 = Chunk::_next [0x0000000029DC7EC0 + 16] 0000000000007fd8 = Chunk::_len = 32728 ===================== You can see the head guard is OK, but the first four bytes of the tail guard is overwritten with 16-bits of zero.
13-07-2016
With Kumar's doit script, I was able to reproduce the crash one out of 65 times, using JDK9 ea104 and version 13455 of tools/pack200/Pack200Test.java (the latest version of the test doesn't work with the latest version of JDK - see JDK-8158928 and JDK-8151901).
29-06-2016
In my previous try, issue reproducible in 50 runs (see also in previous comment 2016-01-18). And Kumar reproduced the issue: With fastdebug it fails immediately, and with release builds within 50-75 iterations.
15-02-2016
Kumar, since you posted a "doit" script, it would be good to know if it fails immediately, or fails only after 10000 cycles. Thank you for your answer.
09-02-2016
This bug has been tagged with mach5-frequent and samebinary-highfrequency, does it not answer your question ? With fastdebug it fails immediately, and with release builds within 50-75 iterations.
09-02-2016
Kumar, how often can you reproduce the failure?
09-02-2016
# Internal Error (C:\workspace\9-2-build-windows-amd64-cygwin-phase2\jdk9\4385\hotspot\src\share\vm\runtime\os.cpp:529), pid=7344, tid=8784 # fatal error: memory stomping error # # JRE version: Java(TM) SE Runtime Environment (9.0+104) (build 9-ea+104-2016-02-03-192034.javare.4385) # Java VM: Java HotSpot(TM) 64-Bit Server VM (9-ea+104-2016-02-03-192034.javare.4385, mixed mode, tiered, compressed oops, g1 gc, windows-amd64) Attached a "doit" reproducer and hs_err logfile, I have the mdmp (too big to attach), I can make it available.
09-02-2016
Issue reproducible with vm option -esa with JDK9 build 96 and later (tested at windows-x64). See details: Run with jtreg (4.1/b12) ======================== $JT_HOME/bin/jtreg \ -nr \ -agentvm \ -a \ -ea \ -esa \ -v:fail,error,time \ -retain:all \ -timeoutFactor:4 \ -J-Xmx512m \ -vmoption:-Xmx512m \ -w:$RST/JTwork \ -jdk:$TEST_JAVA \ ws/jdk/test/tools/pack200/Pack200Test.java ======================== 1) Run *with* -esa : Run with 9-ea+96: issue reproducible in 50 runs. Also tried 9-ea+97, 9-ea+101, all reproducible. Run with 9-ea+95: NOT see this issue. Test all pass in 500 runs 2) Run *without* -esa : Tested with 9-ea+101, NOT see issue, test all pass in 100 runs. Run with java directly ======================== $JAVA_HOME/bin/java \ -cp "$SANDBOX/classes;." \ -Dtest.java=$JAVA_HOME \ -Dtest.src=$SANDBOX/ws/jdk/test/tools/pack200 \ -Dtest.classes=$SANDBOX/classes \ -esa \ -Xmx1280m -Xshare:off Pack200Test ======================== 1) Run *with* -esa : Run with 9-ea+101: See test unexpected exit in the middle, reproducible in 10 runs. 2) Run *without* -esa : Run with 9-ea+101: NOT see issue, test all pass in 3000 runs.
22-01-2016
After running overnight I don't see a crash or failure.
13-01-2016
Is there a VM crash ? if so can you please attache the native stack trace or hotspot.log ? I am guessing it is a vm crash, if so this is would be a VM issue.
11-01-2016