java keytool with opensc pkcs#11 provider only works with debug option enabled

Question

I have the latest opensc 0.12.2 running on ubuntu 11.10 with OpenJDK ( java version "1.6.0_22")

I can read my smartcard (a Feitian ePass PKI) with

pkcs15-tool --dump

Now i try to use my smartcard with keytool:

keytool 
   -providerClass sun.security.pkcs11.SunPKCS11 \
   -providerArg /etc/opensc/opensc-java.cfg \
   -keystore NONE -storetype PKCS11 -list 

which results in an error:

keytool error: java.security.KeyStoreException: PKCS11 not found
java.security.KeyStoreException: PKCS11 not found
    at java.security.KeyStore.getInstance(KeyStore.java:603)
    at sun.security.tools.KeyTool.doCommands(KeyTool.java:621)
    at sun.security.tools.KeyTool.run(KeyTool.java:194)
    at sun.security.tools.KeyTool.main(KeyTool.java:188)
Caused by: java.security.NoSuchAlgorithmException: PKCS11 KeyStore not available
    at sun.security.jca.GetInstance.getInstance(GetInstance.java:159)
    at java.security.Security.getImpl(Security.java:696)
    at java.security.KeyStore.getInstance(KeyStore.java:600)
    ... 3 more

When i run the same command with debug options enabled like this:

keytool 
   -providerClass sun.security.pkcs11.SunPKCS11 \
   -providerArg /etc/opensc/opensc-java.cfg \
   -keystore NONE -storetype PKCS11 -list \
   -J-Djava.security.debug=sunpkcs11

it suddenly works:

... debug infos ...
Enter keystore password:  
sunpkcs11: login succeeded

Keystore type: PKCS11
Keystore provider: SunPKCS11-OpenSC

Your keystore contains 2 entries
...
Certificate fingerprint (MD5): ...
...
Certificate fingerprint (MD5): ...

The same behaviour when i configure it statically:

$ grep opensc /usr/lib/jvm/java-6-openjdk/jre/lib/security/java.security
security.provider.7=sun.security.pkcs11.SunPKCS11 /etc/opensc/opensc-java.cfg

and my config

$ cat /etc/opensc/opensc-java.cfg
name = OpenSC
description = SunPKCS11 w/ OpenSC Smart card Framework
library = /usr/lib/opensc-pkcs11.so

My guess it, it has something to do with openjdk or internal package sun.security which might usually not be used because it is an internal package. Activating Debug options might activate this internal package?

Answer 1

I got the same problem today and I digged onto the java sources until I found the source of the problem. I know this question is quite old and already have an accepted answer, but that one is not a real answer.

Basically, the SunPKCS11 provider does list all available slots, then, get the slot you specified in your config, and give the error (since you do not specified any slot and fot its default value).

When in debug, after listing all available slots, it does list all slots with a smartcard inserted. After having print all these information about the slot list, it does initialise its slotid variable overwriting what you wrote (or forget to write) in your config. The new value is a correct one since it is read from the opensc defaults.

This is the relevant code from SunPKCS11.java from openjdk project:

    long slotID = config.getSlotID();
    // ....
        if ((slotID < 0) || showInfo) {
            long[] slots = p11.C_GetSlotList(false);
            if (showInfo) {
                System.out.println("All slots: " + toString(slots));
                slots = p11.C_GetSlotList(true);
                System.out.println("Slots with tokens: " + toString(slots));
            }
            if (slotID < 0) {
                if ((slotListIndex < 0) || (slotListIndex >= slots.length)) {
                    throw new ProviderException("slotListIndex is " + slotListIndex
                        + " but token only has " + slots.length + " slots");
                }
                slotID = slots[slotListIndex];
            }
        }
        this.slotID = slotID;

So, a workaround is to always include in your config a negative value like slot = -1, so that the provider will always look for the right one.