JDK-6913047 : Long term memory leak when using PKCS11 and JCE exceeds 32 bit process address space
  • Type: Bug
  • Component: security-libs
  • Sub-Component: javax.crypto:pkcs11
  • Affected Version: solaris_10u7,7,8,11,12
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • OS: generic
  • CPU: generic
  • Submitted: 2009-12-23
  • Updated: 2019-10-07
  • Resolved: 2019-01-11
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 11 JDK 13 Other
11.0.4Fixed 13 b04Fixed openjdk8u232Fixed
Related Reports
CSR :  
Relates :  
Relates :  
Relates :  
Relates :  
Relates :  
Relates :  
Sub Tasks
JDK-8215018 :  
Description
Both recent JDK1.6 and JDK1.7 (build 76 last tested) runs of a simple NIO Server using JCE cryptography results in the server running out of memory after a few days of running.  The customer's real application runs out of memory after a few hours.

The exact same code running with sunpkcs11 provider line commented out of the java.security file quickly reaches a steady process address space limit and remains there indefinitely, so the leak is definitely in our pkcs11 layer that apparently is needed to take advantage of CMT cryptographic acceleration.  This has been replicated on T5120 S10u7 and T2000 S10u6 machines, and I've attached a tarfile.

Comments
Fix Request (jdk8u) JDK-8 is affected by this bug. Most of the patch applies cleanly (after JDK-6946830 jdk8u backport is applied) but a few files do not. We will go through a review process.
19-07-2019

Fix Request JDK-11 is affected by this long standing bug. Even though many SunPKCS11 components are affected by the patch, it has been in baseline for about 6 months and followup bugs have been fixed. We propose to backport this patch along with 8216597 and 8220513
17-05-2019

Filed JDK-8216597 for the new crash.
13-01-2019

The failures all show something like ----------System.out:(21/1155)---------- nssLibDir: /usr/lib/mps/64/ # # A fatal error has been detected by the Java Runtime Environment: # # SIGBUS (0xa) at pc=0xffffffff5400b754, pid=26678, tid=20 # # JRE version: Java(TM) SE Runtime Environment (13.0) (build 13-internal+0-jdk13-jdk.126) # Java VM: Java HotSpot(TM) 64-Bit Server VM (13-internal+0-jdk13-jdk.126, mixed mode, sharing, tiered, compressed oops, g1 gc, solaris-sparc) # Problematic frame: # C [libj2pkcs11.so+0xb754] Java_sun_security_pkcs11_wrapper_PKCS11_getNativeKeyInfo+0x2e4 #
13-01-2019

This change seems to have caused a lot of breakage in the sun/security/pkcs11 tests on Solaris Sparc in tier4!
12-01-2019

For complete record keeping, here is more info regarding the patch above - The patch addresses the memory growth issue by extracting native key handles into java byte arrays and recreating the key handles as needed when using NSS PKCS11 library. This isn't a real solution as far as I am concerned, but there is no other better choices given the current situation. This approach is a bit fragile, i.e. the extraction is based on the list of all key attributes which are hard-coded in the code and may break if NSS adds more attributes due to new algorithms or other unforeseen reasons, thus we add a system property to disable this when necessary. Based on Redhat's testing, there is no performance hit with this approach and it addresses the memory growth problem. Thus, we are proceeding with this for JDK 12.
21-11-2018

Patch proposed on security-dev: http://mail.openjdk.java.net/pipermail/security-dev/2017-October/016405.html
12-12-2017

EVALUATION Without new API from the VM, there isn't much that we can do at SunPKCS11 provider level. As for the SunPKCS11 workaround/temporary relief that Ramki suggested, it doesn't pan out. Thus, I am lowering the priority to P3 which is the same priority of the VM API enhancement. Here are the exchanges regarding the SunPKCS11 workaround: On 05/26/10 15:04, Y. Srinivas Ramakrishna wrote: > Valerie (Yu-Ching) Peng wrote: >> >> George may be able to tell you more on whether this customer can use CMS or not. >> Maybe they did at the end. >> >> Well, I spent quite some cycles on my end playing w/ CMS, but the test case just doesn't quite show the same problem as when parallel collector is used. > > Right. I remember that, and we never quite figured out why. > > OK, i'll see if we can build the requisite code into the parallel > collector in the next few weeks, so such an experiment could be done. > > Meanwhile, I'll also check with George re customer's use (or not) of CMS. > > thanks Valerie! > -- ramki > >> Valerie >> >> On 05/26/10 14:54, Y. Srinivas Ramakrishna wrote: >>> Valerie (Yu-Ching) Peng wrote: >>>> >>>> No numbers (yet). >>>> I recall the major bottleneck is about reproducing the memory leak when CMS collector is used. >>>> Tried tweaking the GC parameters, but the memory growth seems to occur only initially and very minimum afterwards. >>>> >>>> This counter-feedback strategy doesn't apply when parallel collector is used, right? >>>> I think maybe it'd be more useful if we have some strategy when parallel collector is used as default... Well, at least, that's what this particular customer is running into. >>> >>> Right, the counter-feedback strategy doesn't quite work with parallel gc unless we >>> put in a bunch of code into it in the JVM; and that is an investment in time. >>> With CMS that code is there already, so you can use it without our having >>> to invest more effort from the JVM side to get those numbers. >>> >>> Can this customer not use CMS, especially since they appear to be >>> pause-time sensitive for which CMS would anyway be a more natural >>> fit than parallel gc? >>> >>> -- ramki
17-11-2010

WORK AROUND The memory usage seems to remain flat when CMS collector is used.
10-06-2010

EVALUATION [The below was put into 6887619 when this bug was classifed a duplicate] Evaluation by bruce.chapman [2010-01-04 21:10] (Note : this is for the more general pkcs11 leak as in 6913047 as this leak occurs with or without CKM_TLS_PRF disabled) Here is how to easily run the attached pkcstest NIO server / client to show that a memory leak occurs only if pkcs11 provider is not commented out (README.PKCS from tarfile - run it on a CMT machine (T2000, T5120, similar) to see memory leak...) (1) put JDK1.6/1.7 bin directory first in your path (2) extract pkcstest.tar into /export/home/terracotta, cd to pkcstest dir (if not possible, modify pkcstest/resources/conf.properties accordingly) (3) ./server.sh (output goes to server.log) (4) nohup ./multiclient.sh & (5) tail -f serversize.out (or grep total\ nohup.out ) to see server process size reported every minute ... it will grow every several minutes unless you comment out the sunpkcs11 provider line in the ${JAVA_HOME}/jre/lib/security/java.security file (rerun each way to see) Note, you can lower the server.sh heap sizes if you have limited RAM, but I bumped them up from what ISV had set at 3GB so we don't have to wait for days to run out of process address space. (don't forget to pkill multiclient.sh before pkill java as there are issues with the client hanging so multiclient kills and restarts the client every minute) As requested, I ran the server with libumem preloaded and umem debugging set (this on a S10u6 T2000 w/ JDK 7 build 76, but the leak has also been verified on SNV123). I ran ::findleaks after starting the server (before any client load) and again after it had been running for a half our or so to show where leaks are coming from. First, here is the per-minute report of process address space (pmap <NIOserver pid> | tail -1) with pkcs11 commented out : total 3742936K total 3782712K total 3782712K total 3782712K .... repeats same size as long as the run continues (have run it for several days) And here it is without pkcs11 commented out (we expect memory footprint and growth pattern to be slightly different, but not to continue to grow ad infinitum) : total 3772504K total 3840928K total 3866016K total 3908448K total 3908832K total 3908832K total 3910304K total 3910432K total 3910432K total 3910432K total 3931808K total 3955104K total 3961568K total 3961568K total 3961568K total 3979936K total 3979936K .... repeats 50x total 3979936K total 4010720K total 4029536K total 4029728K total 4029728K total 4029728K total 4029792K total 4029792K total 4029792K total 4030560K total 4030560K (stopped here but other runs continue to grow until out of memory) Here is the umem debugging output for the normal (pkcs11) version of the server: > ::findleaks BYTES LEAKED VMEM_SEG CALLER 32768 1 16920000 MMAP ------------------------------------------------------------------------ Total 1 oversized leak, 32768 bytes CACHE LEAKED BUFCTL CALLER 0024c008 1 002a9608 libc.so.1`strdup+0xc 00258008 1 0029ac30 libc.so.1`strdup+0xc 00254008 1 002ea438 libc.so.1`strdup+0xc 0024c008 1 002a9518 libc.so.1`strdup+0xc 0024c008 1 002a49d8 libc.so.1`strdup+0xc 0026a008 1 002e3518 libjli.so`JLI_MemAlloc+0x1c 00258008 1 0029ab40 libjli.so`JLI_MemAlloc+0x1c 00250008 1 002b63c0 libjli.so`JLI_MemAlloc+0x1c 0024e008 1 002ae618 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0024e008 1 002ae258 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0025a008 1 002f9d10 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 00252008 1 002bc078 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0024c008 2 002a98d8 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 00252008 1 002bc1e0 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0024e008 1 002ac258 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0025e008 1 0030c8e8 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0024e008 2 002ae348 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 00250008 1 002b67f8 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0026a008 1 002e3608 libjvm.so`__1cCosNset_boot_path6Fcc_b_+0x3d8 ---------------------------------------------------------------------- Total 21 buffers, 1112 bytes And here's the later run : > ::findleaks CACHE LEAKED BUFCTL CALLER 00254008 1 002ea438 libc.so.1`strdup+0xc 0024c008 1 002a9518 libc.so.1`strdup+0xc 0024c008 1 002a9608 libc.so.1`strdup+0xc 0024c008 1 002a49d8 libc.so.1`strdup+0xc 00258008 1 0029ab40 libjli.so`JLI_MemAlloc+0x1c 00250008 1 002b63c0 libjli.so`JLI_MemAlloc+0x1c 00252008 1 002bc078 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0024c008 2 002a98d8 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0024e008 1 002ae618 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0024e008 2 002ae348 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 00250008 1 002b67f8 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0025a008 1 002f9d10 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0024e008 1 002ae258 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 00252008 1 002bc1e0 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0024e008 1 002ac258 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0025e008 1 0030c8e8 libjvm.so`__1cCosGmalloc6FI_pv_+0x24 0026a008 1 002e3608 libjvm.so`__1cCosNset_boot_path6Fcc_b_+0x3d8 00266008 1 009aa078 pkcs11_kernel.so.1`get_bigint_attr_from_template+0x28 00266008 2 009c3f68 pkcs11_kernel.so.1`get_bigint_attr_from_template+0x28 0024c008 3 00969608 pkcs11_kernel.so.1`get_bigint_attr_from_template+0x28 00250008 2 0095b6f8 pkcs11_kernel.so.1`get_bigint_attr_from_template+0x28 ---------------------------------------------------------------------- Total 27 buffers, 1424 bytes Note that all the above other than pkcs11_kernel leaks were flagged as "leaks" right after boot, so I'll only show stack trace dumps of these last few : > 009aa078$<bufctl_audit ADDR BUFADDR TIMESTAMP THREAD ^[[4m CACHE LASTLOG CONTENTS^[[m ^[[1m 9aa078^[[m 9c19a0 e655abd213754 74 266008 148e10 0 libumem.so.1`umem_cache_alloc+0x13c libumem.so.1`umem_alloc+0x60 libumem.so.1`malloc+0x28 pkcs11_kernel.so.1`get_bigint_attr_from_template+0x28 pkcs11_kernel.so.1`kernel_build_public_key_object+0x430 pkcs11_kernel.so.1`kernel_build_object+0xb8 pkcs11_kernel.so.1`kernel_add_object+0x1ec pkcs11_kernel.so.1`C_CreateObject+0x78 libpkcs11.so.1`meta_CreateObject+0x23c libpkcs11.so.1`C_CreateObject+0xcc libj2pkcs11.so`Java_sun_security_pkcs11_wrapper_PKCS11_C_1Creat eObject+0x8c 0xfc00d5c0 0xfc00d56c 0xfc005a18 0xfc005988 > 009c3f68$<bufctl_audit ADDR BUFADDR TIMESTAMP THREAD ^[[4m CACHE LASTLOG CONTENTS^[[m ^[[1m 9c3f68^[[m 9c1b00 e655abd20d195 74 266008 148ce4 0 libumem.so.1`umem_cache_alloc+0x13c libumem.so.1`umem_alloc+0x60 libumem.so.1`malloc+0x28 pkcs11_kernel.so.1`get_bigint_attr_from_template+0x28 pkcs11_kernel.so.1`kernel_build_public_key_object+0x450 pkcs11_kernel.so.1`kernel_build_object+0xb8 pkcs11_kernel.so.1`kernel_add_object+0x1ec pkcs11_kernel.so.1`C_CreateObject+0x78 libpkcs11.so.1`meta_CreateObject+0x23c libpkcs11.so.1`C_CreateObject+0xcc libj2pkcs11.so`Java_sun_security_pkcs11_wrapper_PKCS11_C_1Creat eObject+0x8c 0xfc00d5c0 0xfc00d56c 0xfc005a18 0xfc005988 > 00969608$<bufctl_audit ADDR BUFADDR TIMESTAMP THREAD ^[[4m CACHE LASTLOG CONTENTS^[[m ^[[1m 969608^[[m 964820 e655abbfd9938 74 24c008 147068 0 libumem.so.1`umem_cache_alloc+0x13c libumem.so.1`umem_alloc+0x60 libumem.so.1`malloc+0x28 pkcs11_kernel.so.1`get_bigint_attr_from_template+0x28 pkcs11_kernel.so.1`kernel_build_public_key_object+0x3d4 pkcs11_kernel.so.1`kernel_build_object+0xb8 pkcs11_kernel.so.1`kernel_add_object+0x1ec pkcs11_kernel.so.1`C_CreateObject+0x78 libpkcs11.so.1`meta_CreateObject+0x23c libpkcs11.so.1`C_CreateObject+0xcc libj2pkcs11.so`Java_sun_security_pkcs11_wrapper_PKCS11_C_1Creat eObject+0x8c 0xfc00d5c0 0xfc00d56c 0xfc005a18 0xfc005988 > 0095b6f8$<nbuf^H ^H^H ^H^H ^H^H ^Hbufctl_audit ADDR BUFADDR TIMESTAMP THREAD ^[[4m CACHE LASTLOG CONTENTS^[[m ^[[1m 95b6f8^[[m 955248 e655abd2116de 74 250008 148dac 0 libumem.so.1`umem_cache_alloc+0x13c libumem.so.1`umem_alloc+0x60 libumem.so.1`malloc+0x28 pkcs11_kernel.so.1`get_bigint_attr_from_template+0x28 pkcs11_kernel.so.1`kernel_build_public_key_object+0x410 pkcs11_kernel.so.1`kernel_build_object+0xb8 pkcs11_kernel.so.1`kernel_add_object+0x1ec pkcs11_kernel.so.1`C_CreateObject+0x78 libpkcs11.so.1`meta_CreateObject+0x23c libpkcs11.so.1`C_CreateObject+0xcc libj2pkcs11.so`Java_sun_security_pkcs11_wrapper_PKCS11_C_1Creat eObject+0x8c 0xfc00d5c0 0xfc00d56c 0xfc005a18 0xfc005988
06-01-2010