opensc-devel

[Opensc-devel] issues with smartcards and openvpn when renegotiating keys

[Chris J A. <chr...@gm...>]

I'm having (another) issue using OpenVPN with a smartcard in Ubuntu
12.04. If I do a clean install with the following packages:
 pcscd pcsc-tools libccid libpcsclite1 opensc libp11-2
libengine-pkcs11-openssl openvpn

Then I try to connect to an OpenVPN server, I can connect. However
whenever the data channel key is renegotiated the smartcard reader is
not found. This can be easily reproduced by connecting to an openvpn
server, making the client use a pkcs11 id, and setting reneg-sec to a
short interval to reproduce the problem sooner.

Here are the versions I am using currently:
  pcscd - Version: 1.7.4-2ubuntu2
  pcsc-tools - Version: 1.4.18-1
  libccid - Version: 1.4.5-1
  libpcsclite1 - Version: 1.7.4-2ubuntu2
  opensc - Version: 0.12.2-2ubuntu1
  libp11-2 - Version: 0.2.8-2
  libengine-pkcs11-openssl - Version: 0.1.8-2build1
  openvpn - Version: 2.2.1-8ubuntu1
  libpkcs11-helper1 - Version: 1.09-1

I have attached logs with the issue.
Let me know what else would be helpful to look at, or where I should
file a bug.

Thanks,
--chris j arges

Re: [Opensc-devel] issues with smartcards and openvpn when renegotiating keys

[Alon Bar-L. <alo...@gm...>]

I don't see an issue, you are being asked for PIN, this means that the card
was found.


On Fri, Feb 15, 2013 at 12:05 AM, Chris J Arges
<chr...@gm...>wrote:

> I'm having (another) issue using OpenVPN with a smartcard in Ubuntu
> 12.04. If I do a clean install with the following packages:
>  pcscd pcsc-tools libccid libpcsclite1 opensc libp11-2
> libengine-pkcs11-openssl openvpn
>
> Then I try to connect to an OpenVPN server, I can connect. However
> whenever the data channel key is renegotiated the smartcard reader is
> not found. This can be easily reproduced by connecting to an openvpn
> server, making the client use a pkcs11 id, and setting reneg-sec to a
> short interval to reproduce the problem sooner.
>
> Here are the versions I am using currently:
>   pcscd - Version: 1.7.4-2ubuntu2
>   pcsc-tools - Version: 1.4.18-1
>   libccid - Version: 1.4.5-1
>   libpcsclite1 - Version: 1.7.4-2ubuntu2
>   opensc - Version: 0.12.2-2ubuntu1
>   libp11-2 - Version: 0.2.8-2
>   libengine-pkcs11-openssl - Version: 0.1.8-2build1
>   openvpn - Version: 2.2.1-8ubuntu1
>   libpkcs11-helper1 - Version: 1.09-1
>
> I have attached logs with the issue.
> Let me know what else would be helpful to look at, or where I should
> file a bug.
>
> Thanks,
> --chris j arges
>

Re: [Opensc-devel] issues with smartcards and openvpn when renegotiating keys

[Chris J A. <chr...@gm...>]

On 02/14/2013 04:16 PM, Alon Bar-Lev wrote:
> I don't see an issue, you are being asked for PIN, this means that the
> card was found.
> 

In this part of the openvpn log you see it asks for the user PIN, and I
correctly enter the PIN. However it then gives a CKR_GENERAL_ERROR.

Thu Feb 14 12:05:55 2013 us=249692 PKCS#11: pkcs11h_token_freeTokenId return
Thu Feb 14 12:05:55 2013 us=249697 PKCS#11: _pkcs11h_session_reset
return rv=0-'CKR_OK', *p_slot=1
Thu Feb 14 12:05:55 2013 us=249717 PKCS#11: Calling pin_prompt hook for
'Client (User PIN)'
Thu Feb 14 12:05:59 2013 us=213357 PKCS#11: pin_prompt hook return rv=0
Thu Feb 14 12:05:59 2013 us=213669 PKCS#11: _pkcs11h_session_login
C_Login rv=5-'CKR_GENERAL_ERROR'

If you look at the opensc log from the same time you see:

0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
misc.c:136:session_start_operation: called
0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
misc.c:137:session_start_operation: Session 0x7fd537cf67c0, type 1
0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
pkcs11-object.c:594:C_SignInit: C_SignInit() = CKR_OK
0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
misc.c:158:session_get_operation: called
0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
misc.c:158:session_get_operation: called
0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
misc.c:158:session_get_operation: called
0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
framework-pkcs15.c:2630:pkcs15_prkey_sign: Initiating signing operation,
mechanism 0x1.
0x7fd535a83700 12:05:55.249 [opensc-pkcs11] card.c:292:sc_lock: called
0x7fd535a83700 12:05:55.249 [opensc-pkcs11] reader-pcsc.c:511:pcsc_lock:
called
0x7fd535a83700 12:05:55.249 [opensc-pkcs11] reader-pcsc.c:538:pcsc_lock:
Gemalto GemPC Express 00 00:SCardBeginTransaction failed: 0x8010001d
0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
misc.c:59:sc_to_cryptoki_error_common: libopensc return value: -1101 (No
readers found)
0x7fd535a83700 12:05:55.249 [opensc-pkcs11] pkcs11-object.c:635:C_Sign:
C_Sign() = CKR_GENERAL_ERROR

So it tries to call sc_lock, but somewhere SCARD_E_NO_SERVICE is being
returned. And at this point the card reader and smartcard are in my
computer.

So I'm not sure where the problem lies, yes it asks for a PIN, but it
does so over and over again and never accepts it. Thus after the first
data channel key renegotiation it no longer works.

--chris

> 
> On Fri, Feb 15, 2013 at 12:05 AM, Chris J Arges
> <chr...@gm... <mailto:chr...@gm...>> wrote:
> 
>     I'm having (another) issue using OpenVPN with a smartcard in Ubuntu
>     12.04. If I do a clean install with the following packages:
>      pcscd pcsc-tools libccid libpcsclite1 opensc libp11-2
>     libengine-pkcs11-openssl openvpn
> 
>     Then I try to connect to an OpenVPN server, I can connect. However
>     whenever the data channel key is renegotiated the smartcard reader is
>     not found. This can be easily reproduced by connecting to an openvpn
>     server, making the client use a pkcs11 id, and setting reneg-sec to a
>     short interval to reproduce the problem sooner.
> 
>     Here are the versions I am using currently:
>       pcscd - Version: 1.7.4-2ubuntu2
>       pcsc-tools - Version: 1.4.18-1
>       libccid - Version: 1.4.5-1
>       libpcsclite1 - Version: 1.7.4-2ubuntu2
>       opensc - Version: 0.12.2-2ubuntu1
>       libp11-2 - Version: 0.2.8-2
>       libengine-pkcs11-openssl - Version: 0.1.8-2build1
>       openvpn - Version: 2.2.1-8ubuntu1
>       libpkcs11-helper1 - Version: 1.09-1
> 
>     I have attached logs with the issue.
>     Let me know what else would be helpful to look at, or where I should
>     file a bug.
> 
>     Thanks,
>     --chris j arges
> 
> 

Re: [Opensc-devel] issues with smartcards and openvpn when renegotiating keys

[Ludovic R. <lud...@gm...>]

2013/2/15 Chris J Arges <chr...@gm...>:
> On 02/14/2013 04:16 PM, Alon Bar-Lev wrote:
>> I don't see an issue, you are being asked for PIN, this means that the
>> card was found.
>>
>
> In this part of the openvpn log you see it asks for the user PIN, and I
> correctly enter the PIN. However it then gives a CKR_GENERAL_ERROR.
>
> Thu Feb 14 12:05:55 2013 us=249692 PKCS#11: pkcs11h_token_freeTokenId return
> Thu Feb 14 12:05:55 2013 us=249697 PKCS#11: _pkcs11h_session_reset
> return rv=0-'CKR_OK', *p_slot=1
> Thu Feb 14 12:05:55 2013 us=249717 PKCS#11: Calling pin_prompt hook for
> 'Client (User PIN)'
> Thu Feb 14 12:05:59 2013 us=213357 PKCS#11: pin_prompt hook return rv=0
> Thu Feb 14 12:05:59 2013 us=213669 PKCS#11: _pkcs11h_session_login
> C_Login rv=5-'CKR_GENERAL_ERROR'
>
> If you look at the opensc log from the same time you see:
>
> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
> misc.c:136:session_start_operation: called
> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
> misc.c:137:session_start_operation: Session 0x7fd537cf67c0, type 1
> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
> pkcs11-object.c:594:C_SignInit: C_SignInit() = CKR_OK
> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
> misc.c:158:session_get_operation: called
> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
> misc.c:158:session_get_operation: called
> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
> misc.c:158:session_get_operation: called
> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
> framework-pkcs15.c:2630:pkcs15_prkey_sign: Initiating signing operation,
> mechanism 0x1.
> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11] card.c:292:sc_lock: called
> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11] reader-pcsc.c:511:pcsc_lock:
> called
> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11] reader-pcsc.c:538:pcsc_lock:
> Gemalto GemPC Express 00 00:SCardBeginTransaction failed: 0x8010001d
> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
> misc.c:59:sc_to_cryptoki_error_common: libopensc return value: -1101 (No
> readers found)
> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11] pkcs11-object.c:635:C_Sign:
> C_Sign() = CKR_GENERAL_ERROR
>
> So it tries to call sc_lock, but somewhere SCARD_E_NO_SERVICE is being
> returned. And at this point the card reader and smartcard are in my
> computer.

SCARD_E_NO_SERVICE is returned when pcscd is not running (or has crashed).
>From you first log_pcscd.txt log file I can't find any crash of pcscd.

What happens in the pcscd log when OpenSC reports SCARD_E_NO_SERVICE?

Bye

-- 
 Dr. Ludovic Rousseau

Re: [Opensc-devel] issues with smartcards and openvpn when renegotiating keys

[Chris J A. <chr...@gm...>]

On 02/15/2013 01:50 AM, Ludovic Rousseau wrote:
> 2013/2/15 Chris J Arges <chr...@gm...>:
>> On 02/14/2013 04:16 PM, Alon Bar-Lev wrote:
>>> I don't see an issue, you are being asked for PIN, this means that the
>>> card was found.
>>>
>>
>> In this part of the openvpn log you see it asks for the user PIN, and I
>> correctly enter the PIN. However it then gives a CKR_GENERAL_ERROR.
>>
>> Thu Feb 14 12:05:55 2013 us=249692 PKCS#11: pkcs11h_token_freeTokenId return
>> Thu Feb 14 12:05:55 2013 us=249697 PKCS#11: _pkcs11h_session_reset
>> return rv=0-'CKR_OK', *p_slot=1
>> Thu Feb 14 12:05:55 2013 us=249717 PKCS#11: Calling pin_prompt hook for
>> 'Client (User PIN)'
>> Thu Feb 14 12:05:59 2013 us=213357 PKCS#11: pin_prompt hook return rv=0
>> Thu Feb 14 12:05:59 2013 us=213669 PKCS#11: _pkcs11h_session_login
>> C_Login rv=5-'CKR_GENERAL_ERROR'
>>
>> If you look at the opensc log from the same time you see:
>>
>> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
>> misc.c:136:session_start_operation: called
>> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
>> misc.c:137:session_start_operation: Session 0x7fd537cf67c0, type 1
>> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
>> pkcs11-object.c:594:C_SignInit: C_SignInit() = CKR_OK
>> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
>> misc.c:158:session_get_operation: called
>> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
>> misc.c:158:session_get_operation: called
>> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
>> misc.c:158:session_get_operation: called
>> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
>> framework-pkcs15.c:2630:pkcs15_prkey_sign: Initiating signing operation,
>> mechanism 0x1.
>> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11] card.c:292:sc_lock: called
>> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11] reader-pcsc.c:511:pcsc_lock:
>> called
>> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11] reader-pcsc.c:538:pcsc_lock:
>> Gemalto GemPC Express 00 00:SCardBeginTransaction failed: 0x8010001d
>> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11]
>> misc.c:59:sc_to_cryptoki_error_common: libopensc return value: -1101 (No
>> readers found)
>> 0x7fd535a83700 12:05:55.249 [opensc-pkcs11] pkcs11-object.c:635:C_Sign:
>> C_Sign() = CKR_GENERAL_ERROR
>>
>> So it tries to call sc_lock, but somewhere SCARD_E_NO_SERVICE is being
>> returned. And at this point the card reader and smartcard are in my
>> computer.
> 
> SCARD_E_NO_SERVICE is returned when pcscd is not running (or has crashed).
> From you first log_pcscd.txt log file I can't find any crash of pcscd.
> 
> What happens in the pcscd log when OpenSC reports SCARD_E_NO_SERVICE?
> 

Unfortunately I'm not sure how to relate the timestamps between logs. So
I re-ran and redirected everything into a single file. I've attached
this log.

When OpenSC reports SCARD_E_NO_SERVICE (0x8010001d), there is no
activity from pcscd. However, I am sure it hasn't crashed as the process
is still running after I kill openvpn.

Thanks,
--chris

Re: [Opensc-devel] issues with smartcards and openvpn when renegotiating keys

[Ludovic R. <lud...@gm...>]

2013/2/15 Chris J Arges <chr...@gm...>:
> On 02/15/2013 01:50 AM, Ludovic Rousseau wrote:

>> What happens in the pcscd log when OpenSC reports SCARD_E_NO_SERVICE?
>
> Unfortunately I'm not sure how to relate the timestamps between logs. So
> I re-ran and redirected everything into a single file. I've attached
> this log.
>
> When OpenSC reports SCARD_E_NO_SERVICE (0x8010001d), there is no
> activity from pcscd. However, I am sure it hasn't crashed as the process
> is still running after I kill openvpn.

Install the pcsc-tool package. And use the command pcsc_scan to list
the connected readers. You can exit pcsc_scan using Ctrl-C
After OpenSC reports SCARD_E_NO_SERVICE start pcsc_scan again to see
if this application can contact pcscd.


Also can you upgrade pcsc-lite from 1.7.4 to 1.8.6?
You may be able to use the Ubuntu packages from raring [1]. Or at
least try version 1.8.5 [2] from quantal.
You will need to upgrade pcscd and libpcsclite1 packages.

Bye,

[1] http://packages.ubuntu.com/raring/pcscd
[2] http://packages.ubuntu.com/quantal/pcscd

-- 
 Dr. Ludovic Rousseau

Re: [Opensc-devel] issues with smartcards and openvpn when renegotiating keys

[Chris J A. <chr...@gm...>]

On 02/15/2013 09:17 AM, Ludovic Rousseau wrote:
> 2013/2/15 Chris J Arges <chr...@gm...>:
>> On 02/15/2013 01:50 AM, Ludovic Rousseau wrote:
> 
>>> What happens in the pcscd log when OpenSC reports SCARD_E_NO_SERVICE?
>>
>> Unfortunately I'm not sure how to relate the timestamps between logs. So
>> I re-ran and redirected everything into a single file. I've attached
>> this log.
>>
>> When OpenSC reports SCARD_E_NO_SERVICE (0x8010001d), there is no
>> activity from pcscd. However, I am sure it hasn't crashed as the process
>> is still running after I kill openvpn.
> 
> Install the pcsc-tool package. And use the command pcsc_scan to list
> the connected readers. You can exit pcsc_scan using Ctrl-C
> After OpenSC reports SCARD_E_NO_SERVICE start pcsc_scan again to see
> if this application can contact pcscd.
> 
> 
> Also can you upgrade pcsc-lite from 1.7.4 to 1.8.6?
> You may be able to use the Ubuntu packages from raring [1]. Or at
> least try version 1.8.5 [2] from quantal.
> You will need to upgrade pcscd and libpcsclite1 packages.
> 
Hi,
Yes this is what I originally did was to actually try and run everything
from Raring to test the latest versions; however I was unable to connect
to the OpenVPN server at all. With pcsc-lite 1.8.6, installed onto 12.04
I have the same issues. I'll attach a new log with this information.

Here are the versions for the new log:
pcscd - Version: 1.8.6-3ubuntu1
pcsc-tools - Version: 1.4.18-1
libccid - Version: 1.4.5-1
libpcsclite1 - Version: 1.8.6-3ubuntu1
opensc - Version: 0.12.2-2ubuntu1
libp11-2 - Version: 0.2.8-2
libengine-pkcs11-openssl - Version: 0.1.8-2build1
openvpn - Version: 2.2.1-8ubuntu1
libpkcs11-helper1 - Version: 1.09-1

I have also attached pcsc_scan(before|after) which show the output of
pcsc_scan before initiating the openvpn connection, and after. It is
identical.

Thanks,
--chris

Re: [Opensc-devel] issues with smartcards and openvpn when renegotiating keys

[Ludovic R. <lud...@gm...>]

2013/2/15 Chris J Arges <chr...@gm...>:
> On 02/15/2013 09:17 AM, Ludovic Rousseau wrote:
>> 2013/2/15 Chris J Arges <chr...@gm...>:
>>> On 02/15/2013 01:50 AM, Ludovic Rousseau wrote:
>>
>>>> What happens in the pcscd log when OpenSC reports SCARD_E_NO_SERVICE?
>>>
>>> Unfortunately I'm not sure how to relate the timestamps between logs. So
>>> I re-ran and redirected everything into a single file. I've attached
>>> this log.
>>>
>>> When OpenSC reports SCARD_E_NO_SERVICE (0x8010001d), there is no
>>> activity from pcscd. However, I am sure it hasn't crashed as the process
>>> is still running after I kill openvpn.
>>
>> Install the pcsc-tool package. And use the command pcsc_scan to list
>> the connected readers. You can exit pcsc_scan using Ctrl-C
>> After OpenSC reports SCARD_E_NO_SERVICE start pcsc_scan again to see
>> if this application can contact pcscd.
>>
>>
>> Also can you upgrade pcsc-lite from 1.7.4 to 1.8.6?
>> You may be able to use the Ubuntu packages from raring [1]. Or at
>> least try version 1.8.5 [2] from quantal.
>> You will need to upgrade pcscd and libpcsclite1 packages.
>>
> Hi,
> Yes this is what I originally did was to actually try and run everything
> from Raring to test the latest versions; however I was unable to connect
> to the OpenVPN server at all. With pcsc-lite 1.8.6, installed onto 12.04
> I have the same issues. I'll attach a new log with this information.
>
> Here are the versions for the new log:
> pcscd - Version: 1.8.6-3ubuntu1
> pcsc-tools - Version: 1.4.18-1
> libccid - Version: 1.4.5-1
> libpcsclite1 - Version: 1.8.6-3ubuntu1
> opensc - Version: 0.12.2-2ubuntu1
> libp11-2 - Version: 0.2.8-2
> libengine-pkcs11-openssl - Version: 0.1.8-2build1
> openvpn - Version: 2.2.1-8ubuntu1
> libpkcs11-helper1 - Version: 1.09-1
>
> I have also attached pcsc_scan(before|after) which show the output of
> pcsc_scan before initiating the openvpn connection, and after. It is
> identical.

I can't find the SCARD_E_NO_SERVICE (0x8010001d) error in this log.
Maybe you still have a problem but it should not be the same as before.

Bye

-- 
 Dr. Ludovic Rousseau

Re: [Opensc-devel] issues with smartcards and openvpn when renegotiating keys

[Chris J A. <chr...@gm...>]

On 02/16/2013 01:57 PM, Ludovic Rousseau wrote:
> 2013/2/15 Chris J Arges <chr...@gm...>:
>> On 02/15/2013 09:17 AM, Ludovic Rousseau wrote:
>>> 2013/2/15 Chris J Arges <chr...@gm...>:
>>>> On 02/15/2013 01:50 AM, Ludovic Rousseau wrote:
>>>
>>>>> What happens in the pcscd log when OpenSC reports SCARD_E_NO_SERVICE?
>>>>
>>>> Unfortunately I'm not sure how to relate the timestamps between logs. So
>>>> I re-ran and redirected everything into a single file. I've attached
>>>> this log.
>>>>
>>>> When OpenSC reports SCARD_E_NO_SERVICE (0x8010001d), there is no
>>>> activity from pcscd. However, I am sure it hasn't crashed as the process
>>>> is still running after I kill openvpn.
>>>
>>> Install the pcsc-tool package. And use the command pcsc_scan to list
>>> the connected readers. You can exit pcsc_scan using Ctrl-C
>>> After OpenSC reports SCARD_E_NO_SERVICE start pcsc_scan again to see
>>> if this application can contact pcscd.
>>>
>>>
>>> Also can you upgrade pcsc-lite from 1.7.4 to 1.8.6?
>>> You may be able to use the Ubuntu packages from raring [1]. Or at
>>> least try version 1.8.5 [2] from quantal.
>>> You will need to upgrade pcscd and libpcsclite1 packages.
>>>
>> Hi,
>> Yes this is what I originally did was to actually try and run everything
>> from Raring to test the latest versions; however I was unable to connect
>> to the OpenVPN server at all. With pcsc-lite 1.8.6, installed onto 12.04
>> I have the same issues. I'll attach a new log with this information.
>>
>> Here are the versions for the new log:
>> pcscd - Version: 1.8.6-3ubuntu1
>> pcsc-tools - Version: 1.4.18-1
>> libccid - Version: 1.4.5-1
>> libpcsclite1 - Version: 1.8.6-3ubuntu1
>> opensc - Version: 0.12.2-2ubuntu1
>> libp11-2 - Version: 0.2.8-2
>> libengine-pkcs11-openssl - Version: 0.1.8-2build1
>> openvpn - Version: 2.2.1-8ubuntu1
>> libpkcs11-helper1 - Version: 1.09-1
>>
>> I have also attached pcsc_scan(before|after) which show the output of
>> pcsc_scan before initiating the openvpn connection, and after. It is
>> identical.
> 
> I can't find the SCARD_E_NO_SERVICE (0x8010001d) error in this log.
> Maybe you still have a problem but it should not be the same as before.
> 
> Bye
> 

Yes, when I use the original versions (1.7.4), I can connect to an
OpenVPN server, but after the first key renegotiation, I can no longer
connect. If I upgrade to 1.8.6, then I cannot connect to the OpenVPN
server at all.

So the newer version could be introducing another issue. I originally
posted about this with the subject "Issues connecting to OpenVPN with
Smartcard", and have logs attached there.

Have you or anyone else been able to reproduce this issue? I'm not sure
if this is specific to my reader/smartcard or not. I followed directions
from here:
http://www.gooze.eu/howto/openvpn-with-smart-cards-crypto-tokens-howto

Thanks,
--chris