JDK-8129634 : Reading the cacerts file one byte at a time
  • Type: Bug
  • Component: security-libs
  • Sub-Component: java.security
  • Affected Version: 8u40
  • Priority: P3
  • Status: Resolved
  • Resolution: Duplicate
  • Submitted: 2015-06-23
  • Updated: 2015-07-07
  • Resolved: 2015-07-07
Related Reports
Duplicate :  
Description
Noticed high system CPU time, around 70%, by running EEJS workload. Root caused the problem and found that
for each SSLContext.init(), the read from cacerts file happens one byte at a time. 

/79:    stat("/usr/jdk/instances/jdk1.8.0_60b19/jre/lib/security/jssecacerts", 0xFFFFFFFF35FFD8C8) Err#2 ENOENT
/79:    stat("/usr/jdk/instances/jdk1.8.0_60b19/jre/lib/security/cacerts", 0xFFFFFFFF35FFD8C8) = 0
/79:    open("/usr/jdk/instances/jdk1.8.0_60b19/jre/lib/security/cacerts", O_RDONLY) = 3467
/79:    fstat(3467, 0xFFFFFFFF35FFD750)                 = 0
/79:    read(3467, "FE", 1)                             = 1
/79:    read(3467, "ED", 1)                             = 1
/79:    read(3467, "FE", 1)                             = 1
/79:    read(3467, "ED", 1)                             = 1
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "02", 1)                             = 1
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, " ]", 1)                             = 1
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "02", 1)                             = 1
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "17", 1)                             = 1
/79:    read(3467, " d i g i c e r t a s s u".., 23)    = 23
/79:    read(3467, "\0\00119 W aE5D2", 8)               = 8
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "05", 1)                             = 1
/79:    read(3467, " X . 5 0 9", 5)                     = 5
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "03", 1)                             = 1
/79:    read(3467, "BB", 1)                             = 1
/79:    read(3467, " 08203B7 082029FA0030201".., 955)   = 955
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "02", 1)                             = 1
/79:    read(3467, "\0", 1)                             = 1
/79:    read(3467, "15", 1)                             = 1
/79:    read(3467, " t r u s t c e n t e r c".., 21)    = 21

The stack trace for the read is like:
------------  lwp# 67 / thread# 67  ---------------
 ffffffff7ed4b048 __read (0, ffffffff377fe1cf, 1, 18b410, ffffffff4230ca40, 18b400) + c
 ffffffff3cd1cd38 handleRead (14e6, ffffffff377fe1cf, 1, 1, c, 114a) + 10
 ffffffff3cd1c8fc readSingle (103de39f8, ffffffff377fe338, 42, ffffffff3e354e40, 10f77c, ffffffff31afe2b8) + 7c
 ffffffff3cd15724 Java_java_io_FileInputStream_read0 (103de39f8, ffffffff3ce2e838, 2838, 116904, ffffffff3ce2c000, 2800) + 34
 ffffffff679be9ac * *java/io/FileInputStream.read0()I [compiled]
 ffffffff679c8bc8 * *java/io/FileInputStream.read()I [compiled] +2
 ffffffff69a8b658 * *java/io/DataInputStream.readInt()I [compiled] +5
 ffffffff69a8b658 * *sun/security/provider/JavaKeyStore.engineLoad(Ljava/io/InputStream;[C)V+168
 ffffffff69273174 * *sun/security/provider/JavaKeyStore$JKS.engineLoad(Ljava/io/InputStream;[C)V [compiled] +4
 ffffffff69273174 * *sun/security/provider/KeyStoreDelegator.engineLoad(Ljava/io/InputStream;[C)V+87
 ffffffff6853280c * *sun/security/provider/JavaKeyStore$DualFormatJKS.engineLoad(Ljava/io/InputStream;[C)V [compiled] +4
 ffffffff6853280c * *java/security/KeyStore.load(Ljava/io/InputStream;[C)V+7
 ffffffff6853280c * *sun/security/ssl/TrustManagerFactoryImpl.getCacertsKeyStore(Ljava/lang/String;)Ljava/security/KeyStore;+430
 ffffffff6933c114 * *sun/security/ssl/TrustManagerFactoryImpl.engineInit(Ljava/security/KeyStore;)V [compiled] +7
 ffffffff67f41fb8 * *javax/net/ssl/TrustManagerFactory.init(Ljava/security/KeyStore;)V [compiled] +6
 ffffffff67f41fb8 * *sun/security/ssl/SSLContextImpl.engineInit([Ljavax/net/ssl/KeyManager;[Ljavax/net/ssl/TrustManager;Ljava/security/SecureRandom;)V+33
 ffffffff69e37168 * *javax/net/ssl/SSLContext.init([Ljavax/net/ssl/KeyManager;[Ljavax/net/ssl/TrustManager;Ljava/security/SecureRandom;)V [compiled] +8
 ffffffff69e37168 * *org/apache/http/ssl/SSLContexts.createDefault()Ljavax/net/ssl/SSLContext;+11
 ffffffff69e37168 * *org/apache/http/impl/client/HttpClientBuilder.build()Lorg/apache/http/impl/client/CloseableHttpClient;+178
 ffffffff69e1d4a8 * *org/apache/http/impl/client/HttpClients.createDefault()Lorg/apache/http/impl/client/CloseableHttpClient; [compiled] +4
 ffffffff69e1d4a8 * *org/spec/web/bank/HttpClientObject.<init>(I)V+11
....

------------  lwp# 69 / thread# 69  ---------------
 ffffffff7ed4b048 __read (0, ffffffff373fe22f, 1, 18b410, ffffffff4230da40, 18b400) + c
 ffffffff3cd1cd38 handleRead (14cd, ffffffff373fe22f, 1, 1, c, 114a) + 10
 ffffffff3cd1c8fc readSingle (103de71f8, ffffffff373fe398, 42, ffffffff3e354e40, 10f77c, 0) + 7c
 ffffffff3cd15724 Java_java_io_FileInputStream_read0 (103de71f8, ffffffff3ce2e838, 2838, 116904, ffffffff3ce2c000, 2800) + 34
 ffffffff679be9ac * *java/io/FileInputStream.read0()I [compiled]
 ffffffff679c8bc8 * *java/io/FileInputStream.read()I [compiled] +2
 ffffffff682f85f0 * *java/io/DataInputStream.readUnsignedShort()I [compiled] +13
 ffffffff682f85f0 * *java/io/DataInputStream.readUTF(Ljava/io/DataInput;)Ljava/lang/String;+2
 ffffffff69a8b90c * *java/io/DataInputStream.readUTF()Ljava/lang/String; [compiled] +2
 ffffffff69a8b90c * *sun/security/provider/JavaKeyStore.engineLoad(Ljava/io/InputStream;[C)V+462
 ffffffff69273174 * *sun/security/provider/JavaKeyStore$JKS.engineLoad(Ljava/io/InputStream;[C)V [compiled] +4
 ffffffff69273174 * *sun/security/provider/KeyStoreDelegator.engineLoad(Ljava/io/InputStream;[C)V+87
 ffffffff6853280c * *sun/security/provider/JavaKeyStore$DualFormatJKS.engineLoad(Ljava/io/InputStream;[C)V [compiled] +4
 ffffffff6853280c * *java/security/KeyStore.load(Ljava/io/InputStream;[C)V+7
 ffffffff6853280c * *sun/security/ssl/TrustManagerFactoryImpl.getCacertsKeyStore(Ljava/lang/String;)Ljava/security/KeyStore;+430
 ffffffff6933c114 * *sun/security/ssl/TrustManagerFactoryImpl.engineInit(Ljava/security/KeyStore;)V [compiled] +7
 ffffffff67f41fb8 * *javax/net/ssl/TrustManagerFactory.init(Ljava/security/KeyStore;)V [compiled] +6
 ffffffff67f41fb8 * *sun/security/ssl/SSLContextImpl.engineInit([Ljavax/net/ssl/KeyManager;[Ljavax/net/ssl/TrustManager;Ljava/security/SecureRandom;)V+33
....


Comments
This issue is corrected as part of the fix for JDK-8062552.
07-07-2015

I think the performance improvement is a side-effect of JDK-8062552, which wraps the keystore stream in a BufferedInputStream.
26-06-2015

It is a performance issue. Even the meta-data should not be read one byte at time. We noticed quite high system CPU time, around 70%. But this problem has been fixed in JDK8u60b20, with the implementaion of BufferedInputStream. It is reading 8K bytes each time instead of one byte.
26-06-2015

It's not clear what problem is being reported. Closing as Not an Issue. Only the JKS keystore meta-data is read one byte at a time. Each keystore cert is read several bytes at a time. For example, the following trace line shows the first cert is loaded in a single call to read() of 955 bytes: /79: read(3467, " 08203B7 082029FA0030201".., 955) = 955
24-06-2015