Bug 1947025

What was the last time the same process worked for you? RHEL 8.3? Before? The debug log would be more useful from the failing command:

$ OPENSC_DEBUG=9 pkcs15-init --store-private-key miker_idm.key  --auth-id 01 --id 01 --so-pin redhat --pin redhat

There was really just couple of small changes in the last update and really none of them related to MyEID driver nor pkcs15-init. Can you try with use_file_caching = false; in /etc/opensc.conf?

(In reply to Jakub Jelen from comment #1)
> What was the last time the same process worked for you? RHEL 8.3? Before?
> The debug log would be more useful from the failing command:
> 
> $ OPENSC_DEBUG=9 pkcs15-init --store-private-key miker_idm.key  --auth-id 01
> --id 01 --so-pin redhat --pin redhat
> 
> There was really just couple of small changes in the last update and really
> none of them related to MyEID driver nor pkcs15-init. Can you try with
> use_file_caching = false; in /etc/opensc.conf?

Correct, it worked in RHEL 8.3.

I am attaching the debug log for both with file caching and without.

Created attachment 1770266 [details]
with file caching

Created attachment 1770267 [details]
without file caching

Thank you for the logs. Without the caching, you already have different error:

  Failed to store private key: Non unique object ID

So I assume the key was already written, but the file cache was not updated (or something else was broken during the writing).

One fast idea how to solve this, can you try to add the following to the /etc/opensc.conf:

  app pkcs15-init {
  	framework pkcs15 {
  		use_file_caching = false;
  	}
  }

Then reset/format the card and retry the setup? Or just retry with the use_file_caching=false from the beginning to make sure this is the only cause for this issue?

I think we only tested reading cards with this option, where the file caching brings significant performance improvements, but I do not think we have some enrollment of myeid cards in the plans ...

(In reply to Jakub Jelen from comment #5)
> 
> One fast idea how to solve this, can you try to add the following to the
> /etc/opensc.conf:
> 
>   app pkcs15-init {
>   	framework pkcs15 {
>   		use_file_caching = false;
>   	}
>   }

This was already set to false, but apparently you need to restart after making the change for it to take effect. I had shut the machine down and when it came up, I verified that it was set to false and tried it again and it worked.

> Then reset/format the card and retry the setup? Or just retry with the
> use_file_caching=false from the beginning to make sure this is the only
> cause for this issue?
> 
> I think we only tested reading cards with this option, where the file
> caching brings significant performance improvements, but I do not think we
> have some enrollment of myeid cards in the plans ...

This does raise a question for me. This was a brand new install with a blank card, so what is cached to cause the issue?

The above snippet should disable the caching only for the pkcs15-init tool.

But you executed several commands, which touched the card. So probably the last one used some cached information from the previous invocation.

This is something we should fix. In short term with probably with a workaround as posted above (assuming it will work), in long term with proper cache invalidation during pkcs15-init enrollment. But as I do not have MyEID card myself at hand, it will take some time before I will get to that.

(In reply to Jakub Jelen from comment #7)
> The above snippet should disable the caching only for the pkcs15-init tool.
> 
> But you executed several commands, which touched the card. So probably the
> last one used some cached information from the previous invocation.
> 
> This is something we should fix. In short term with probably with a
> workaround as posted above (assuming it will work), in long term with proper
> cache invalidation during pkcs15-init enrollment. But as I do not have MyEID
> card myself at hand, it will take some time before I will get to that.

I just checked an opensc.conf on a RHEL 8.3, and it has use_file_caching commented out. Not certain if that means anything as some apps have default parameters commented out. The RHEL 8.4 Beta does not have it commented out.

So I have a couple of questions. First is since it might take some time to resolve this, what service reads opensc.conf? I will use this info to make a KCS until this is fixed.

Second one is, what is the difference between:
app default {
        framework pkcs15 {
                use_file_caching = true;
        }

and 

app pkcs15-init {
   	framework pkcs15 {
   		use_file_caching = false;
   	}
}

(In reply to Mike Ralph from comment #8)
> I just checked an opensc.conf on a RHEL 8.3, and it has use_file_caching
> commented out. Not certain if that means anything as some apps have default
> parameters commented out. The RHEL 8.4 Beta does not have it commented out.

Thats intended. See #1892810

> So I have a couple of questions. First is since it might take some time to
> resolve this, what service reads opensc.conf?

No service. The opensc-pkcs11.so a opensc tools read this file directly.

> I will use this info to make a KCS until this is fixed.
> 
> Second one is, what is the difference between:
> 
> app default {
>         framework pkcs15 {
>                 use_file_caching = true;
>         }
> 
> and 
> 
> app pkcs15-init {
>    	framework pkcs15 {
>    		use_file_caching = false;
>    	}
> }

The first is default and should apply to all opensc tools, the second should apply
only for the pkcs15-init for the card enrollment. Not sure what are priorities in
case of both of them are present (whether one needs to come before the other). It
needs some testing.

Looks good. Thanks!

FYI, this was recently discussed in the upstream PR https://github.com/OpenSC/OpenSC/pull/2501 when we tried to enable the file caching by default too.

The summary is that the caching code is not very suitable for updating cards objects as it is now so it would require some modification of the caching code to invalidate cache on write, which is not in place yet.

So for now, the workaround proposed in comment #5 should do the job. If we will update opensc in RHEL8, we should probably bring these changes in.

There is some work in progress of fixing this in upstream right now properly, but I do not think we will be backporting these changes to RHEL8 unless there would be huge demand for this so I am closing this bug.

https://github.com/OpenSC/OpenSC/pull/2501