JDK-6924489 : sun.security.pkcs11.wrapper.PKCS11Exception: CKR_OPERATION_NOT_INITIALIZED
  • Type: Bug
  • Component: security-libs
  • Sub-Component: javax.crypto:pkcs11
  • Affected Version: 5.0u19,6u23
  • Priority: P2
  • Status: Closed
  • Resolution: Fixed
  • OS: solaris_10
  • CPU: sparc
  • Submitted: 2010-02-09
  • Updated: 2011-04-23
  • Resolved: 2010-04-28
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.
Other JDK 6 JDK 7
5.0u24-rev b07Fixed 6u24Fixed 7Fixed
Related Reports
Duplicate :  
Relates :  
Relates :  
Relates :  
Relates :  
Relates :  
Relates :  
Relates :  
Description
IBIS case 72329826.

JDK used : 5u19
Platform: T5220, Solaris 10u5 with 139555-08  118918-24 

 sun.security.pkcs11.wrapper.PKCS11Exception: CKR_OPERATION_NOT_INITIALIZED 
after many SSL operations:

Mon Feb 08 14:56:26 PST 2010 31374000 sdn CN=v4v-t5220f-sca11.sfbay.sun.com, OU=Services, O=Sun, L=Santa Clara, ST=California, C=US
[GC 44704K->33288K(60416K), 0.0255555 secs]
[GC 44872K->33545K(60288K), 0.0177596 secs]
[GC 45129K->33470K(60352K), 0.0165997 secs]
[GC 44926K->33518K(60352K), 0.0166519 secs]
[GC 44974K->33650K(60224K), 0.0180893 secs]
[GC 45106K->33515K(60288K), 0.0171511 secs]
[GC 44971K->33515K(60352K), 0.0168836 secs]
[GC 44968K->33716K(60352K), 0.0170418 secs]
[GC 45172K->33637K(60352K), 0.0169596 secs]
Got Exception : javax.net.ssl.SSLPeerUnverifiedException: peer not authenticatedThe (filename, line number, function, statement, value) is:
[('C:\\cygwin\\tmp\\wibapp.ear-SSL-LIB-ERR\\ckcert.py', 0, 'main', None)]
java_exp javax.net.ssl.SSLPeerUnverifiedException: peer not authenticated
java_expjavax.net.ssl.SSLPeerUnverifiedException: peer not authenticated
    at com.sun.net.ssl.internal.ssl.SSLSessionImpl.getPeerCertificateChain(SSLSessionImpl.java:394)
    at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:585)
    at org.python.core.PyBeanProperty._doget(Unknown Source)
    at org.python.core.PyObject._doget(Unknown Source)
    at org.python.core.PyObject.__get__(Unknown Source)
    at org.python.core.PyInstance.__findattr__(Unknown Source)
    at org.python.core.PyInstance.__findattr__(Unknown Source)
    at org.python.core.PyObject.__getattr__(Unknown Source)
    at ckcert$_PyInner.main$1(ckcert.java:106)
    at ckcert$_PyInner.call_function(ckcert.java:47)
    at org.python.core.PyTableCode.call(Unknown Source)
    at org.python.core.PyCode.call(Unknown Source)
    at org.python.core.imp.createFromCode(Unknown Source)
    at org.python.core.imp.createFromCode(Unknown Source)
    at org.python.core.Py.runMain(Unknown Source)
    at ckcert.main(ckcert.java:153)
 None
Got Exception : java.security.ProviderException: update() failed
The (filename, line number, function, statement, value) is:
[('C:\\cygwin\\tmp\\wibapp.ear-SSL-LIB-ERR\\ckcert.py', 0, 'main', None)]
java_exp java.security.ProviderException: update() failed
java_expjava.security.ProviderException: update() failed
    at sun.security.pkcs11.P11Cipher.implUpdate(P11Cipher.java:460)
    at sun.security.pkcs11.P11Cipher.engineUpdate(P11Cipher.java:391)
    at javax.crypto.Cipher.update(DashoA12275)
    at com.sun.net.ssl.internal.ssl.CipherBox.encrypt(CipherBox.java:184)
    at com.sun.net.ssl.internal.ssl.OutputRecord.encrypt(OutputRecord.java:197)
    at com.sun.net.ssl.internal.ssl.SSLSocketImpl.writeRecordInternal(SSLSocketImpl.java:726)
    at com.sun.net.ssl.internal.ssl.SSLSocketImpl.writeRecord(SSLSocketImpl.java:715)
    at com.sun.net.ssl.internal.ssl.SSLSocketImpl.sendAlert(SSLSocketImpl.java:1688)
    at com.sun.net.ssl.internal.ssl.SSLSocketImpl.fatal(SSLSocketImpl.java:1579)    at com.sun.net.ssl.internal.ssl.SSLSocketImpl.fatal(SSLSocketImpl.java:1547)    at com.sun.net.ssl.internal.ssl.SSLSocketImpl.handleException(SSLSocketImpl.java:1530)
    at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1123)
    at com.sun.net.ssl.internal.ssl.SSLSocketImpl.getSession(SSLSocketImpl.java:1823)
    at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:585)
    at org.python.core.PyBeanProperty._doget(Unknown Source)
    at org.python.core.PyObject._doget(Unknown Source)
    at org.python.core.PyObject.__get__(Unknown Source)
    at org.python.core.PyInstance.__findattr__(Unknown Source)
    at org.python.core.PyInstance.__findattr__(Unknown Source)
    at org.python.core.PyObject.__getattr__(Unknown Source)
    at ckcert$_PyInner.main$1(ckcert.java:105)
    at ckcert$_PyInner.call_function(ckcert.java:47)
    at org.python.core.PyTableCode.call(Unknown Source)
    at org.python.core.PyCode.call(Unknown Source)
    at org.python.core.imp.createFromCode(Unknown Source)
    at org.python.core.imp.createFromCode(Unknown Source)
    at org.python.core.Py.runMain(Unknown Source)
    at ckcert.main(ckcert.java:153)
Caused by: sun.security.pkcs11.wrapper.PKCS11Exception: CKR_OPERATION_NOT_INITIALIZED
    at sun.security.pkcs11.wrapper.PKCS11.C_EncryptUpdate(Native Method)
    at sun.security.pkcs11.P11Cipher.implUpdate(P11Cipher.java:450)
    ... 29 more
 None


testcase:
#!/bin/ksh

mv ckcert.out ckcert.out.old

h=v4v-t5220f-sca11.sfbay

p=443

set -x

/chow/jdk1.5.0_19/bin/java -Xms64m -Xmx64m -verbose:gc -Djavax.net.ssl.trustStoreType=JKS -Djavax.net.ssl.trustStore=$(pwd)/testkeystore -Djavax.net.ssl.trustStorePassword=testpass -jar  $(pwd)/ckcert.jar $h $p > ckcert.out  2>&1 &

tail -f  ckcert.out


i = 0

e = 0

while 1 :

  try :

   i += 1 ;

   sslsf = SSLSocketFactory.getDefault() ;

   ssls  = sslsf.createSocket(str(sys.argv[1]),int(sys.argv[2])) ;

   ssls =  ssls.session ;

   pcca = ssls.peerCertificateChain ;

   pcc = pcca[0] ;

   sdn = pcc.subjectDN ;

   if ( i % 1000 ) == 0 :

      print Date(),i,'sdn',sdn ;

  except Exception,java_exp :

    e += 1 ;

    exc_type, exc_value, exc_tb = sys.exc_info()

    print "Got Exception : "+str(exc_value)

    print "The (filename, line number, function, statement, value) is:"

    print str(traceback.extract_tb(exc_tb))

    print 'java_exp',java_exp

    print 'java_exp',java_exp.printStackTrace()

    time.sleep(60)

    if e > 10000 :

      sys.exit()

Comments
EVALUATION http://hg.openjdk.java.net/jdk7/build/jdk/rev/adff75ebdc00
2011-01-17

EVALUATION According to the truss output, here is what actually happened: C_EncryptUpdate() <- CKR_HOST_MEMORY error (due to too many PKCS11 sessions being opened) (Note: however, this error sometimes does not show up at the top level for some unknown reason) C_EncryptUpdate() <- CKR_OPERATION_NOT_INITIALIZED (since the previous failing C_EncryptUpdate() call terminates the operation and would require re-initialization again) First, the P11Cipher impl needs to reset its internal state when the first C_EncryptUpdate() call fails, so it'd re-initialize before calling the C_EncryptUpdate() again. However, the more severe problem here is the high number of PKCS11 sessions which is mostly contributed by JSSE not calling doFinal() on the Cipher objects that it use. This is only a problem for 5U though since JSSE addressed this under 6750401 "SSL stress test with GF leads to 32 bit max process size in less than 5 minutes,with PCKS11 provider" for both jdk 6U and 7.
2010-03-26