Hello. I'm having a problem with OpenVPN when using it with a smart card and with client software Viscosity. The problem is that the smart card PKCS#11 token label contains the umlaut characters and the OpenVPN management interface doesn't handle those characters well and doesn't understand that I'm entering the PIN number for that token and therefore the authentication never succeeds.
We first figured that the problem is with Viscosity software, but nice people at thesparklabs provided several fixes and now it seems that the OpenVPN management interface is the problem. OS: MacOSX 10.7.1 OpenVPN version: OpenVPN 2.2.1 x86_64-apple-darwin10.8.0 [SSL] [LZO2] [PKCS11] [eurephia] built on Aug 1 2011 Viscosity version: 1.3.5b7 (1037) OpenSC version: opensc 0.12.1-svn [gcc 4.2.1 (Apple Inc. build 5666) (dot 3)] Cardreader: OmniKey CardMan 1021 00 00 Effectively I'm using the following configuration file: #-- Config Auto Generated By Viscosity --# #viscosity startonopen false #viscosity dhcp true #viscosity dnssupport true #viscosity ipv6 false remote xxx.xxx.xxx.xxx 1193 udp pull tls-client pkcs11-id-management ca ca.crt dev tun persist-tun pkcs11-providers /Library/OpenSC/lib/opensc-pkcs11.so keepalive 5 10 verb 5 script-security 2 When I start the connection, the following log is created: Oct 12 17:07:58: Viscosity 1.3.5b7 (1037) Oct 12 17:07:58: Checking reachability status of connection... Oct 12 17:07:58: Connection is reachable. Starting connection attempt. >INFO:OpenVPN Management Interface Version 1 -- type 'help' for more info >HOLD:Waiting for hold release Oct 12 17:08:02: OpenVPN 2.2.1 x86_64-apple-darwin10.8.0 [SSL] [LZO2] [PKCS11] [eurephia] built on Aug 1 2011 SUCCESS: pid=61690 SUCCESS: real-time log notification set to ON >LOG:1318428481,D,MANAGEMENT: CMD 'state on' Oct 12 17:08:01: MANAGEMENT: CMD 'state on' SUCCESS: real-time state notification set to ON >LOG:1318428481,D,MANAGEMENT: CMD 'hold release' Oct 12 17:08:01: MANAGEMENT: CMD 'hold release' SUCCESS: hold release succeeded >LOG:1318428481,I,PKCS#11: Adding PKCS#11 provider >'/Library/OpenSC/lib/opensc-pkcs11.so' Oct 12 17:08:01: PKCS#11: Adding PKCS#11 provider '/Library/OpenSC/lib/opensc-pkcs11.so' >LOG:1318428490,W,WARNING: No server certificate verification method has been >enabled. See http://openvpn.net/howto.html#mitm for more info. Oct 12 17:08:10: WARNING: No server certificate verification method has been enabled. See http://openvpn.net/howto.html#mitm for more info. >LOG:1318428490,W,NOTE: the current --script-security setting may allow this >configuration to call user-defined scripts Oct 12 17:08:10: NOTE: the current --script-security setting may allow this configuration to call user-defined scripts >NEED-STR:Need 'pkcs11-id-request' string MSG:Please specify PKCS#11 id to use >LOG:1318428490,D,MANAGEMENT: CMD 'hold release' Oct 12 17:08:10: MANAGEMENT: CMD 'hold release' SUCCESS: hold release succeeded >LOG:1318428490,D,MANAGEMENT: CMD 'state on' Oct 12 17:08:10: MANAGEMENT: CMD 'state on' SUCCESS: real-time state notification set to ON >LOG:1318428490,D,MANAGEMENT: CMD 'hold release' Oct 12 17:08:10: MANAGEMENT: CMD 'hold release' SUCCESS: hold release succeeded >LOG:1318428490,D,MANAGEMENT: CMD 'pid' Oct 12 17:08:10: MANAGEMENT: CMD 'pid' SUCCESS: pid=61690 >LOG:1318428501,D,MANAGEMENT: CMD 'pid' Oct 12 17:08:21: MANAGEMENT: CMD 'pid' SUCCESS: pid=61690 >LOG:1318428502,D,MANAGEMENT: CMD 'hold release' Oct 12 17:08:22: MANAGEMENT: CMD 'hold release' SUCCESS: hold release succeeded >LOG:1318428502,D,MANAGEMENT: CMD 'pid' Oct 12 17:08:22: MANAGEMENT: CMD 'pid' SUCCESS: pid=61690 >LOG:1318428502,D,MANAGEMENT: CMD 'pid' Oct 12 17:08:22: MANAGEMENT: CMD 'pid' SUCCESS: pid=61690 >LOG:1318428506,D,MANAGEMENT: CMD 'needstr pkcs11-id-request >"AS\\x20Sertifitseerimiskeskus/PKCS\\x2315\\x20emulated/A1019298/J\\xC3\\x9CRGENSON\\x2CAIVO\\x2C37807156011\\x20\\x28PIN/01"' Oct 12 17:08:26: MANAGEMENT: CMD 'needstr pkcs11-id-request "AS\\x20Sertifitseerimiskeskus/PKCS\\x2315\\x20emulated/A1019298/J\\xC3\\x9CRGENSON\\x2CAIVO\\x2C37807156011\\x20\\x28PIN/01"' SUCCESS: 'pkcs11-id-request' needstr-string entered, but not yet verified >LOG:1318428506,,Control Channel MTU parms [ L:1541 D:138 EF:38 EB:0 ET:0 EL:0 ] Oct 12 17:08:26: Control Channel MTU parms [ L:1541 D:138 EF:38 EB:0 ET:0 EL:0 ] >LOG:1318428506,,Socket Buffers: R=[42080->65536] S=[9216->65536] Oct 12 17:08:26: Socket Buffers: R=[42080->65536] S=[9216->65536] >LOG:1318428506,,Data Channel MTU parms [ L:1541 D:1450 EF:41 EB:4 ET:0 EL:0 ] Oct 12 17:08:26: Data Channel MTU parms [ L:1541 D:1450 EF:41 EB:4 ET:0 EL:0 ] >LOG:1318428506,,Local Options String: 'V4,dev-type tun,link-mtu 1541,tun-mtu >1500,proto UDPv4,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client' Oct 12 17:08:26: Local Options String: 'V4,dev-type tun,link-mtu 1541,tun-mtu 1500,proto UDPv4,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-client' >LOG:1318428506,,Expected Remote Options String: 'V4,dev-type tun,link-mtu >1541,tun-mtu 1500,proto UDPv4,cipher BF-CBC,auth SHA1,keysize 128,key-method >2,tls-server' Oct 12 17:08:26: Expected Remote Options String: 'V4,dev-type tun,link-mtu 1541,tun-mtu 1500,proto UDPv4,cipher BF-CBC,auth SHA1,keysize 128,key-method 2,tls-server' >LOG:1318428506,,Local Options hash (VER=V4): '3514370b' Oct 12 17:08:26: Local Options hash (VER=V4): '3514370b' >LOG:1318428506,,Expected Remote Options hash (VER=V4): '239669a8' Oct 12 17:08:26: Expected Remote Options hash (VER=V4): '239669a8' >LOG:1318428506,I,UDPv4 link local (bound): [undef]:1194 Oct 12 17:08:26: UDPv4 link local (bound): [undef]:1194 >LOG:1318428506,I,UDPv4 link remote: xxx.xxx.xxx.xxx:1193 Oct 12 17:08:26: UDPv4 link remote: xxx.xxx.xxx.xxx:1193 >LOG:1318428506,,MANAGEMENT: >STATE:1318428506,WAIT,,, Oct 12 17:08:26: MANAGEMENT: >STATE:1318428506,WAIT,,, >STATE:1318428506,WAIT,,, >LOG:1318428506,,MANAGEMENT: >STATE:1318428506,AUTH,,, Oct 12 17:08:26: MANAGEMENT: >STATE:1318428506,AUTH,,, >STATE:1318428506,AUTH,,, >LOG:1318428506,,TLS: Initial packet from xxx.xxx.xxx.xxx:1193, sid=bd9352a0 >9beb379e Oct 12 17:08:26: TLS: Initial packet from xxx.xxx.xxx.xxx:1193, sid=bd9352a0 9beb379e >LOG:1318428506,,VERIFY OK: depth=2, /CN=XXX_CA Oct 12 17:08:26: VERIFY OK: depth=2, /CN=XXX_CA >LOG:1318428506,,VERIFY OK: depth=1, /CN=YYY_CA Oct 12 17:08:26: VERIFY OK: depth=1, /CN=YYY_CA >LOG:1318428506,,VERIFY OK: depth=0, >/C=EE/ST=Harjumaa/L=Tallinn/O=ZZZ/OU=ZZZ/CN=xxx.YYY.ee Oct 12 17:08:26: VERIFY OK: depth=0, /C=EE/ST=Harjumaa/L=Tallinn/O=ZZZ/OU=ZZZ/CN=xxx.YYY.ee >PASSWORD:Need 'JÜRGENSON,AIVO,37807156011 (PIN token' password >LOG:1318428511,D,MANAGEMENT: CMD 'password [...]' Oct 12 17:08:31: MANAGEMENT: CMD 'password [...]' ERROR: password of type 'JRGENSON,AIVO,37807156011 (PIN token' entered, but we need one of type 'JÜRGENSON,AIVO,37807156011 (PIN token' When I try to run OpenVPN on the command line with the same configuration file, I'm able to enter the PIN in the terminal and the authentication succeeds just fine. When I did tcpdump on the management interface traffic and captured the actual bytes sent between the Viscosity and OpenVPN, I got the following hex trace: > 00000000 70 61 73 73 77 6f 72 64 20 22 4a c3 9c 52 47 45 password "J..RGE > > 00000010 4e 53 4f 4e 2c 41 49 56 4f 2c 33 37 38 30 37 31 NSON,AIV O,378071 > > 00000020 35 36 30 31 31 20 28 50 49 4e 20 74 6f 6b 65 6e 56011 (P IN token > > 00000030 22 20 22 XX XX XX XX 22 0a " "XXXX" . > > 00000000 3e 4c 4f 47 3a 31 33 31 36 30 37 35 33 37 33 2c >LOG:131 6075373, > > 00000010 44 2c 4d 41 4e 41 47 45 4d 45 4e 54 3a 20 43 4d D,MANAGE MENT: CM > > 00000020 44 20 27 70 61 73 73 77 6f 72 64 20 5b 2e 2e 2e D 'passw ord [... > > 00000030 5d 27 0d 0a ]'.. > > 00000034 45 52 52 4f 52 3a 20 70 61 73 73 77 6f 72 64 20 ERROR: p assword > > 00000044 6f 66 20 74 79 70 65 20 27 4a 52 47 45 4e 53 4f of type 'JRGENSO > > 00000054 4e 2c 41 49 56 4f 2c 33 37 38 30 37 31 35 36 30 N,AIVO,3 78071560 > > 00000064 31 31 20 28 50 49 4e 20 74 6f 6b 65 6e 27 20 65 11 (PIN token' e > > 00000074 6e 74 65 72 65 64 2c 20 62 75 74 20 77 65 20 6e ntered, but we n > > 00000084 65 65 64 20 6f 6e 65 20 6f 66 20 74 79 70 65 20 eed one of type > > 00000094 27 4a c3 9c 52 47 45 4e 53 4f 4e 2c 41 49 56 4f 'J..RGEN SON,AIVO > > 000000A4 2c 33 37 38 30 37 31 35 36 30 31 31 20 28 50 49 ,3780715 6011 (PI > > 000000B4 4e 20 74 6f 6b 65 6e 27 0d 0a N token' .. Viscosity is sending the whole token name and with the correct bytes (20 22 4a c3 9c …) but OpenVPN is responding that this wasn't what he was expecting, even though "4a c3 9c" match what OpenVPN requested earlier. It seems that the umlaut characters are stripped somewhere in the OpenVPN, during processing the management command. The appropriate code snippet for giving the error message is in the manage.c file: static void man_query_user_pass (struct management *man, const char *type, const char *string, const bool needed, const char *prompt, char *dest, int len) { if (needed) { ASSERT (man->connection.up_query_type); if (streq (man->connection.up_query_type, type)) { strncpynt (dest, string, len); man_up_finalize (man); msg (M_CLIENT, "SUCCESS: '%s' %s entered, but not yet verified", type, prompt); } else msg (M_CLIENT, "ERROR: %s of type '%s' entered, but we need one of type '%s'", prompt, type, man->connection.up_query_type); } else { msg (M_CLIENT, "ERROR: no %s is currently needed at this time", prompt); } } But unfortunately I'm not able to track this problem further and find the actual point in code, where some characters are being dropped. Possible workaround would be to configure OpenSC or simply get another smart card with another token label, but the smart card is the government issued national identity card and I'm afraid that I cannot change the token label myself. Also, the similar problem can easily occur with other users as well, for example in Belgium, in Germany and in Finland, where government issued smart cards are in use and people's names easily contain umlaut characters. The same issue has been registered for the TunneBlick client software (http://code.google.com/p/tunnelblick/issues/detail?id=138) with person from Hungary, but it doesn't seem to be registered in the OpenVPN bug database itself (https://community.openvpn.net/openvpn/query?status=accepted&status=assigned&status=closed&status=new&status=reopened&component=Management&order=priority) There has been a similar issue in the OpenVPN mailing list in the year 2006 (http://article.gmane.org/gmane.network.openvpn.devel/1527), but that one had problems with the umlaut characters in the actual PIN code or password itself, not just the username or token label part. In my case, the PIN code entered contains just ASCII numbers and those are transferred fine between Viscosity and OpenVPN, but OpenVPN doesn't seem to understand that it is receiving the PIN code for that token. Would it be possible to patch OpenVPN in some way, so that the umlaut characters doesn't get stripped in the management interface … or perhaps there's some other, more robust way of handling such kind of smart-card authentication? -- Aivo Jürgenson, aivo.jurgen...@gmail.com
