Created
October 26, 2011 08:55
-
-
Save rednaxelafx/1315822 to your computer and use it in GitHub Desktop.
An example of JNI call and GC/Safepoint interaction. Shows that native call doesn't block GC/Safepoint. JNI postpones a GC if it's in a critical section.
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
$ java -version | |
java version "1.6.0_29" | |
Java(TM) SE Runtime Environment (build 1.6.0_29-b11) | |
Java HotSpot(TM) 64-Bit Server VM (build 20.4-b02, mixed mode) | |
$ vi TestSafepoint.java | |
$ javac TestSafepoint.java | |
$ javah TestSafepoint | |
$ vi test.c | |
$ gcc -fPIC -shared -I$JAVA_HOME/include -I$JAVA_HOME/include/linux -o libtestsp.so test.c | |
$ export LD_LIBRARY_PATH=. | |
$ export JAVA_OPTS='-XX:+PrintGCDetails -XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1' | |
$ java -cp . $JAVA_OPTS TestSafepoint > log.txt |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
[GC [PSYoungGen: 14016K->192K(16320K)] 14016K->192K(53696K), 0.0013830 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
0.133: ParallelGCFailedAllocation [ 8 1 0 ] [ 0 0 0 0 1 ] 0 | |
[GC [PSYoungGen: 14208K->160K(16320K)] 14208K->160K(53696K), 0.0012110 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
0.146: ParallelGCFailedAllocation [ 8 0 1 ] [ 0 0 0 0 1 ] 0 | |
[GC [PSYoungGen: 14176K->160K(16320K)] 14176K->160K(53696K), 0.0008710 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
0.159: ParallelGCFailedAllocation [ 8 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 14176K->160K(30336K)] 14176K->160K(67712K), 0.0010290 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
0.172: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 1 ] 0 | |
[GC [PSYoungGen: 28192K->160K(30336K)] 28192K->160K(67712K), 0.0010830 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
0.213: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 1 ] 0 | |
[GC [PSYoungGen: 28192K->160K(56256K)] 28192K->160K(93632K), 0.0010080 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
0.237: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 1 ] 0 | |
[GC [PSYoungGen: 56224K->0K(56256K)] 56224K->124K(93632K), 0.0011680 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
0.319: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 1 ] 0 | |
[GC [PSYoungGen: 56064K->0K(112384K)] 56188K->124K(149760K), 0.0005150 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
0.365: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 112128K->0K(112384K)] 112252K->124K(149760K), 0.0007000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
0.526: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 112128K->0K(179712K)] 112252K->124K(217088K), 0.0005000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
0.617: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 179456K->0K(179712K)] 179580K->124K(217088K), 0.0007790 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
0.844: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 179456K->0K(287360K)] 179580K->124K(324736K), 0.0005330 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
0.989: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 287168K->0K(273600K)] 287292K->124K(310976K), 0.0005120 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
1.350: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 273536K->0K(260608K)] 273660K->124K(297984K), 0.0005070 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
1.570: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 260544K->0K(248448K)] 260668K->124K(285824K), 0.0006080 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
1.780: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 248192K->0K(236544K)] 248316K->124K(273920K), 0.0006320 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
1.987: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 236480K->0K(225600K)] 236604K->124K(262976K), 0.0004820 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
2.183: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 225344K->0K(214848K)] 225468K->124K(252224K), 0.0005960 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
2.364: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 214784K->0K(204992K)] 214908K->124K(242368K), 0.0004840 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
2.537: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 204736K->0K(195264K)] 204860K->124K(232640K), 0.0005910 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
2.702: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 195200K->0K(186368K)] 195324K->124K(223744K), 0.0005000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
2.859: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 186112K->0K(177536K)] 186236K->124K(214912K), 0.0006090 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
3.010: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 177472K->0K(169472K)] 177596K->124K(206848K), 0.0005080 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
3.153: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 169280K->0K(161536K)] 169404K->124K(198912K), 0.0005660 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
3.289: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 161472K->0K(154240K)] 161596K->124K(191616K), 0.0005080 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
3.420: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
[GC [PSYoungGen: 154048K->0K(147072K)] 154172K->124K(184448K), 0.0005690 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
3.544: ParallelGCFailedAllocation [ 7 0 0 ] [ 0 0 0 0 0 ] 0 | |
Heap | |
PSYoungGen total 147072K, used 115438K [0x00000000edc00000, 0x00000000ff3b0000, 0x0000000100000000) | |
eden space 147008K, 78% used [0x00000000edc00000,0x00000000f4cbb878,0x00000000f6b90000) | |
from space 64K, 0% used [0x00000000ff3a0000,0x00000000ff3a0000,0x00000000ff3b0000) | |
to space 192K, 0% used [0x00000000ff350000,0x00000000ff350000,0x00000000ff380000) | |
PSOldGen total 37376K, used 124K [0x00000000c9400000, 0x00000000cb880000, 0x00000000edc00000) | |
object space 37376K, 0% used [0x00000000c9400000,0x00000000c941f060,0x00000000cb880000) | |
PSPermGen total 21248K, used 2571K [0x00000000c4200000, 0x00000000c56c0000, 0x00000000c9400000) | |
object space 21248K, 12% used [0x00000000c4200000,0x00000000c4482f58,0x00000000c56c0000) | |
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count | |
3.635: no vm operation [ 6 1 1 ] [ 0 0 0 0 0 ] 0 | |
Polling page always armed | |
ParallelGCFailedAllocation 26 | |
0 VM operations coalesced during safepoint | |
Maximum sync time 0 ms | |
Maximum vm operation time (except for Exit VM operation) 1 ms |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
#include "jni.h" | |
#include "TestSafepoint.h" | |
#include <unistd.h> | |
void JNICALL Java_TestSafepoint_nativeSleep(JNIEnv* env, jclass cls, jlong millis) { | |
usleep(millis); | |
} |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
/* DO NOT EDIT THIS FILE - it is machine generated */ | |
#include <jni.h> | |
/* Header for class TestSafepoint */ | |
#ifndef _Included_TestSafepoint | |
#define _Included_TestSafepoint | |
#ifdef __cplusplus | |
extern "C" { | |
#endif | |
/* | |
* Class: TestSafepoint | |
* Method: nativeSleep | |
* Signature: (J)V | |
*/ | |
JNIEXPORT void JNICALL Java_TestSafepoint_nativeSleep | |
(JNIEnv *, jclass, jlong); | |
#ifdef __cplusplus | |
} | |
#endif | |
#endif |
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
import java.util.*; | |
public class TestSafepoint { | |
static { | |
System.loadLibrary("testsp"); | |
} | |
public static native void nativeSleep(long millis); | |
public static void main(String[] args) { | |
new Thread(new Runnable() { | |
@Override | |
public void run() { | |
nativeSleep(10000); | |
} | |
}).start(); | |
for (int i = 0; i < 100000000; i++) { | |
new LinkedHashMap<Object, Object>(); // trigger minor GCs | |
} | |
} | |
} |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
normal JNI calls are "safepoint region"s, which doesn't block GCs.