Best mailing list for JVM embedding

Mon Jan 21 12:47:38 UTC 2019

On 1/19/19 6:55 PM, David Holmes wrote:
> Hi Robert,
> 
> Please take this to hotspot-dev as it covers a range of areas in hotspot.
> 
> Thanks,
> David

Thank you, subscribed to that list.

> 
> 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.
>>
>>