Best mailing list for JVM embedding

David Holmes david.holmes at oracle.com
Sat Jan 19 22:55:14 UTC 2019


Hi Robert,

Please take this to hotspot-dev as it covers a range of areas in hotspot.

Thanks,
David

On 20/01/2019 3:22 am, Robert Marcano wrote:
> Greetings, which is the best mailing list for discussions about 
> embedding the JVM (via JNI_CreateJavaVM)?
> 
> The JVM is being embedded for desktop integration issues, for example to 
> show the appropriate application name on the process list instead of 
> java/java.exe, among many other things.
> 
> I am experiencing what looks like higher memory usage and/or failure to 
> garbage collect correctly when OpenJDK 11 is the embedded JVM. Starting 
> a test application using the java launcher, I get a GC log like this:
> 
>> [0.007s][info][gc] Using G1
>> [0.389s][info][gc] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 
>> 10M->8M(124M) 8.661ms
>> [0.705s][info][gc] GC(1) Pause Young (Normal) (G1 Evacuation Pause) 
>> 13M->10M(124M) 6.148ms
>> Jan 19, 2019 1:04:26 PM test.Test init
>> FINE: Starting application
>> [1.376s][info][gc] GC(3) Pause Young (Normal) (G1 Evacuation Pause) 
>> 18M->10M(40M) 4.763ms
>> [2.288s][info][gc] GC(4) Pause Young (Normal) (G1 Evacuation Pause) 
>> 23M->12M(40M) 6.382ms
>> [2.444s][info][gc] GC(5) Pause Young (Concurrent Start) (Metadata GC 
>> Threshold) 18M->12M(48M) 7.579ms
>> [2.444s][info][gc] GC(6) Concurrent Cycle
>> [2.481s][info][gc] GC(6) Pause Remark 13M->13M(48M) 5.255ms
>> [2.498s][info][gc] GC(6) Pause Cleanup 13M->13M(48M) 0.090ms
>> [2.499s][info][gc] GC(6) Concurrent Cycle 54.811ms
>> [2.905s][info][gc] GC(7) Pause Young (Normal) (G1 Evacuation Pause) 
>> 26M->13M(48M) 12.726ms
>> [3.204s][info][gc] GC(8) Pause Young (Normal) (GCLocker Initiated GC) 
>> 29M->15M(48M) 11.216ms
>> [3.462s][info][gc] GC(9) Pause Young (Normal) (G1 Evacuation Pause) 
>> 30M->17M(48M) 18.043ms
>> [3.679s][info][gc] GC(10) Pause Young (Normal) (G1 Evacuation Pause) 
>> 31M->18M(64M) 15.195ms
>> [3.933s][info][gc] GC(11) Pause Young (Normal) (G1 Evacuation Pause) 
>> 38M->20M(64M) 9.412ms
>> [4.230s][info][gc] GC(12) Pause Young (Normal) (G1 Evacuation Pause) 
>> 40M->21M(64M) 16.319ms
>> [4.536s][info][gc] GC(13) Pause Young (Normal) (G1 Evacuation Pause) 
>> 41M->23M(64M) 23.897ms
>> [4.750s][info][gc] GC(14) Pause Young (Normal) (G1 Evacuation Pause) 
>> 43M->24M(94M) 8.776ms
>> [5.180s][info][gc] GC(15) Pause Young (Normal) (G1 Evacuation Pause) 
>> 58M->26M(94M) 15.610ms
>> [5.546s][info][gc] GC(16) Pause Young (Normal) (G1 Evacuation Pause) 
>> 67M->27M(94M) 18.075ms
>> [6.058s][info][gc] GC(17) Pause Young (Normal) (G1 Evacuation Pause) 
>> 69M->30M(94M) 32.625ms
>> [7.268s][info][gc] GC(18) Pause Young (Normal) (G1 Evacuation Pause) 
>> 71M->31M(156M) 18.999ms
>> [7.458s][info][gc] GC(19) Pause Young (Concurrent Start) (Metadata GC 
>> Threshold) 40M->31M(156M) 20.217ms
>> [7.459s][info][gc] GC(20) Concurrent Cycle
>> [7.676s][info][gc] GC(20) Pause Remark 35M->35M(156M) 19.304ms
>> [7.748s][info][gc] GC(20) Pause Cleanup 36M->36M(156M) 0.183ms
>> [7.782s][info][gc] GC(20) Concurrent Cycle 323.765ms
>> [8.899s][info][gc] GC(21) Pause Young (Concurrent Start) (G1 
>> Evacuation Pause) 84M->40M(156M) 69.976ms
>> [8.899s][info][gc] GC(22) Concurrent Cycle
>> [9.152s][info][gc] GC(22) Pause Remark 47M->47M(156M) 21.133ms
>> [9.244s][info][gc] GC(22) Pause Cleanup 49M->49M(156M) 0.127ms
>> [9.247s][info][gc] GC(22) Concurrent Cycle 348.256ms
>> [10.203s][info][gc] GC(23) Pause Young (Normal) (G1 Evacuation Pause) 
>> 97M->55M(156M) 74.572ms
>> [11.102s][info][gc] GC(24) Pause Full (System.gc()) 100M->21M(77M) 
>> 115.166ms
>> [15.382s][info][gc] GC(25) Pause Young (Normal) (G1 Evacuation Pause) 
>> 48M->22M(154M) 6.371ms
> 
> When the same Java 11 JVM is loaded via JNI, with the same VM arguments 
> than using the java launcher, the log look like this (to reach the same 
> point at startup)
> 
>> [0.015s][info][gc] Using G1
>> [0.501s][info][gc] GC(0) Pause Young (Normal) (G1 Evacuation Pause) 
>> 6M->1M(124M) 8.550ms
>> [0.785s][info][gc] GC(1) Pause Young (Normal) (G1 Evacuation Pause) 
>> 8M->3M(124M) 6.533ms
>> [0.940s][info][gc] GC(2) Pause Young (Normal) (G1 Evacuation Pause) 
>> 14M->7M(124M) 17.822ms
>> [1.212s][info][gc] GC(3) Pause Young (Normal) (G1 Evacuation Pause) 
>> 22M->10M(124M) 11.145ms
>> [1.462s][info][gc] GC(4) Pause Young (Normal) (G1 Evacuation Pause) 
>> 29M->15M(180M) 16.451ms
>> [1.695s][info][gc] GC(5) Pause Young (Normal) (G1 Evacuation Pause) 
>> 47M->25M(180M) 38.828ms
>> [2.041s][info][gc] GC(6) Pause Young (Normal) (G1 Evacuation Pause) 
>> 55M->30M(180M) 22.151ms
>> [2.346s][info][gc] GC(7) Pause Young (Normal) (G1 Evacuation Pause) 
>> 80M->49M(180M) 53.093ms
>> Jan 19, 2019 1:01:05 PM test.Test init
>> FINE: Starting application
>> [4.094s][info][gc] GC(9) Pause Young (Concurrent Start) (Metadata GC 
>> Threshold) 64M->40M(258M) 50.663ms
>> [4.094s][info][gc] GC(10) Concurrent Cycle
>> [4.480s][info][gc] GC(10) Pause Remark 48M->48M(258M) 7.442ms
>> [4.652s][info][gc] GC(10) Pause Cleanup 55M->55M(258M) 0.186ms
>> [4.656s][info][gc] GC(10) Concurrent Cycle 562.009ms
>> [5.174s][info][gc] GC(11) Pause Young (Concurrent Start) (G1 
>> Evacuation Pause) 82M->46M(258M) 24.726ms
>> [5.174s][info][gc] GC(12) Concurrent Cycle
>> [5.513s][info][gc] GC(12) Pause Remark 56M->56M(258M) 11.695ms
>> [5.657s][info][gc] GC(12) Pause Cleanup 62M->62M(258M) 0.176ms
>> [5.660s][info][gc] GC(12) Concurrent Cycle 486.466ms
>> [6.430s][info][gc] GC(13) Pause Young (Normal) (G1 Evacuation Pause) 
>> 107M->58M(258M) 55.665ms
>> [7.538s][info][gc] GC(14) Pause Young (Normal) (G1 Evacuation Pause) 
>> 107M->63M(258M) 58.642ms
>> [8.724s][info][gc] GC(15) Pause Young (Concurrent Start) (Metadata GC 
>> Threshold) 91M->68M(496M) 47.374ms
>> [8.724s][info][gc] GC(16) Concurrent Cycle
>> [9.417s][info][gc] GC(16) Pause Remark 79M->79M(496M) 19.350ms
>> [9.557s][info][gc] GC(16) Pause Cleanup 81M->81M(496M) 0.340ms
>> [9.575s][info][gc] GC(16) Concurrent Cycle 850.788ms
>> [10.954s][info][gc] GC(17) Pause Young (Concurrent Start) (G1 
>> Evacuation Pause) 134M->85M(496M) 162.779ms
>> [10.954s][info][gc] GC(18) Concurrent Cycle
>> [11.389s][info][gc] GC(19) Pause Young (Normal) (G1 Evacuation Pause) 
>> 99M->90M(496M) 79.954ms
>> [11.519s][info][gc] GC(18) Pause Remark 93M->92M(496M) 24.636ms
>> [11.896s][info][gc] GC(18) Pause Cleanup 102M->102M(496M) 0.326ms
>> [11.903s][info][gc] GC(18) Concurrent Cycle 949.231ms
>> [17.356s][info][gc] GC(22) Pause Young (Concurrent Start) (G1 
>> Humongous Allocation) 131M->81M(365M) 56.745ms
>> [17.357s][info][gc] GC(23) Concurrent Cycle
>> [17.706s][info][gc] GC(23) Pause Remark 116M->113M(365M) 31.351ms
>> [18.008s][info][gc] GC(23) Pause Cleanup 117M->117M(365M) 0.250ms
>> [18.018s][info][gc] GC(23) Concurrent Cycle 661.284ms
>> [18.888s][info][gc] GC(24) Pause Young (Normal) (G1 Evacuation Pause) 
>> 205M->91M(365M) 93.737ms
>> [20.355s][info][gc] GC(25) Pause Young (Normal) (G1 Evacuation Pause) 
>> 324M->136M(378M) 125.037ms
>> [21.091s][info][gc] GC(26) Pause Young (Normal) (G1 Evacuation Pause) 
>> 295M->150M(378M) 93.607ms
>> [21.631s][info][gc] GC(27) Pause Young (Concurrent Start) (G1 
>> Humongous Allocation) 261M->164M(516M) 77.013ms
>> [21.631s][info][gc] GC(28) Concurrent Cycle
>> [21.981s][info][gc] GC(28) Pause Remark 212M->169M(516M) 43.679ms
>> [22.243s][info][gc] GC(28) Pause Cleanup 214M->214M(516M) 0.257ms
>> [22.250s][info][gc] GC(28) Concurrent Cycle 619.296ms
>> [22.827s][info][gc] GC(29) Pause Young (Normal) (G1 Evacuation Pause) 
>> 321M->155M(516M) 106.789ms
>> [23.758s][info][gc] GC(30) Pause Young (Normal) (G1 Evacuation Pause) 
>> 363M->187M(516M) 121.025ms
>> [24.957s][info][gc] GC(31) Pause Young (Normal) (GCLocker Initiated 
>> GC) 386M->207M(516M) 111.118ms
>> [25.697s][info][gc] GC(32) Pause Young (Concurrent Start) (G1 
>> Humongous Allocation) 346M->222M(656M) 104.765ms
>> [25.697s][info][gc] GC(33) Concurrent Cycle
>> [26.128s][info][gc] GC(33) Pause Remark 270M->192M(656M) 55.681ms
>> [26.342s][info][gc] GC(33) Pause Cleanup 203M->203M(656M) 0.371ms
>> [26.349s][info][gc] GC(33) Concurrent Cycle 651.801ms
>> [27.421s][info][gc] GC(34) Pause Young (Prepare Mixed) (G1 Evacuation 
>> Pause) 380M->180M(656M) 195.335ms
>> [27.543s][info][gc] GC(35) Pause Young (Mixed) (G1 Evacuation Pause) 
>> 195M->172M(656M) 38.254ms
>> [28.694s][info][gc] GC(36) Pause Young (Normal) (G1 Evacuation Pause) 
>> 427M->214M(656M) 107.817ms
>> [31.109s][info][gc] GC(37) Pause Young (Normal) (G1 Evacuation Pause) 
>> 486M->239M(656M) 117.275ms
> 
> Notice, the higher memory usage. If a more complex applications is 
> started, the heap continue to grow indefinitely, with long GC pauses and 
> a growing heap. It is my understanding that the JVM should setup default 
> GC and or memory related configuration by itself, be it from the java 
> launcher or JNI_CreateJavaVM.
> 
> The same custom launcher does not experience this when the embedded JVM 
> is version 8.
> 
> Note: the launcher is a simple Rust program, not a complex thing, just 
> locate libjvm.so/jvm.dll, build the VM options, Use JNI_CreateJavaVM, 
> locate the main class and invoke the main method. These logs are for the 
> Linux version.
> 
> Any help is appreciated, or a pointer to the correct mailing list.
> 
> 


More information about the discuss mailing list