United StatesChange Country, Oracle Worldwide Web Sites Communities I am a... I want to...
Bug ID: 6924489 sun.security.pkcs11.wrapper.PKCS11Exception: CKR_OPERATION_NOT_INITIALIZED
6924489 : sun.security.pkcs11.wrapper.PKCS11Exception: CKR_OPERATION_NOT_INITIALIZED

Details
Type:
Bug
Submit Date:
2010-02-09
Status:
Closed
Updated Date:
2011-04-23
Project Name:
JDK
Resolved Date:
2010-04-28
Component:
security-libs
OS:
solaris_10
Sub-Component:
javax.crypto:pkcs11
CPU:
sparc
Priority:
P2
Resolution:
Fixed
Affected Versions:
5.0u19,6u23
Fixed Versions:
5.0u24-rev

Related Reports
Backport:
Backport:
Backport:
Backport:
Backport:
Backport:
Duplicate:
Relates:
Relates:
Relates:
Relates:
Relates:
Relates:
Relates:

Sub Tasks

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



Hardware and Software, Engineered to Work Together