Skip to content

Instantly share code, notes, and snippets.

@rednaxelafx
Created October 26, 2011 08:55
Show Gist options
  • Star 2 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save rednaxelafx/1315822 to your computer and use it in GitHub Desktop.
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.
$ 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
[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
#include "jni.h"
#include "TestSafepoint.h"
#include <unistd.h>
void JNICALL Java_TestSafepoint_nativeSleep(JNIEnv* env, jclass cls, jlong millis) {
usleep(millis);
}
/* 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
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
}
}
}
@rednaxelafx
Copy link
Author

normal JNI calls are "safepoint region"s, which doesn't block GCs.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment