Yubikey init failed

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

Yubikey init failed

Robin Lambertz
Hello,

I'm trying to get my Yubikey NEO to work with GPG in an archlinux VM on Qubes OS. Unfortunately, it seems that PCSCD is unable to work with my yubikey, it doesn't appear when running pcsc_scan.

I started pcscd with `sudo LIBCCID_ifdLogLevel=0x000F pcscd --foreground --debug --apdu --color | tee log.txt` to get more info about where the problem could come from. The full logs are attached, but the interesting bits are here :

```
00000206 ccid_usb.c:621:OpenUSBByName() Found Vendor/Product: 1050/0111 (Yubico Yubikey NEO OTP+CCID)
00000012 ccid_usb.c:623:OpenUSBByName() Using USB bus/device: 2/4
00000010 ccid_usb.c:680:OpenUSBByName() bNumDataRatesSupported is 0
00001997 ccid_usb.c:1244:InterruptRead() before (0)
00103904 ccid_usb.c:1290:InterruptRead() after (0) (2)
00000072 -> 000000 65 00 00 00 00 00 00 00 00 00
00002614 <- 000000 81 00 00 00 00 00 00 00 00 00
00000050 -> 000000 65 00 00 00 00 00 01 00 00 00
00103063 ccid_usb.c:836:ReadUSB() read failed (2/4): -7 LIBUSB_ERROR_TIMEOUT
00000224 -> 000000 65 00 00 00 00 00 02 00 00 00
05002241 ccid_usb.c:797:WriteUSB() write failed (2/4): -7 LIBUSB_ERROR_TIMEOUT
00000242 ifdhandler.c:188:CreateChannelByNameOrChannel() failed
00000159 ccid_usb.c:879:CloseUSB() Closing USB device: 2/4
00000151 ccid_usb.c:889:CloseUSB() Last slot closed. Release resources
00000240 ccid_usb.c:189:close_libusb_if_needed() libusb_exit
00000476 readerfactory.c:1110:RFInitializeReader() Open Port 0x200000 Failed (usb:1050/0111:libudev:1:/dev/bus/usb/002/004)
00000161 readerfactory.c:375:RFAddReader() Yubico Yubikey NEO OTP+CCID init failed.
```

ReadUSB returns immediately with the TIMEOUT error (isn't that weird ?), while the WriteUSB times out after 5 seconds. I'm not sure what to do to further debug this. Any hint as to what I could do to figure out where the issue is coming from ?

Additional info :

# Versions

- CCID driver version : 1.4.25

- pcsc-lite version : 1.8.20

- smart card reader : Yubico Yubikey NEO OTP+CCID

- output of /usr/sbin/pcscd --version :
```
pcsc-lite version 1.8.20.
Copyright (C) 1999-2002 by David Corcoran [hidden email].
Copyright (C) 2001-2015 by Ludovic Rousseau [hidden email].
Copyright (C) 2003-2004 by Damien Sauveron [hidden email].
Report bugs to [hidden email].
Enabled features: Linux x86_64-pc-linux-gnu serial usb libudev usbdropdir=/usr/lib/pcsc/drivers ipcdir=/run/pcscd configdir=/etc/reader.conf.d
```

- OS: ArchLinux in a VM, kernel version 4.4.38-11.pvops.qubes.x86_64

_______________________________________________
Pcsclite-muscle mailing list
[hidden email]
http://lists.alioth.debian.org/cgi-bin/mailman/listinfo/pcsclite-muscle

log.txt (10K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Yubikey init failed

Stein, Maximilian
On 14.02.2017 01:53, Robin Lambertz wrote:
> Hello,

Hi

> I'm trying to get my Yubikey NEO to work with GPG in an archlinux VM on
> Qubes OS. Unfortunately, it seems that PCSCD is unable to work with my
> yubikey, it doesn't appear when running pcsc_scan.

This is probably a problem with your virtualisation software. I've found
that certain constellations of VirtualBox do not play nicely together
with non-mass-storage USB usage.

> ReadUSB returns immediately with the TIMEOUT error (isn't that weird ?),

Not at all, the first InterruptRead is just to clear the interrupt
endpoint and therefore has a timeout of only 100ms, which expires in
your logs.

> while the WriteUSB times out after 5 seconds. I'm not sure what to do to
> further debug this. Any hint as to what I could do to figure out where
> the issue is coming from ?

You could try to use a different virtualisation software or version,
updating guest additions (in case of VirtualBox). You could try a newer
kernel in the VM guest or a newer version of libusbx/libusb-1.0.


To further debug the problem you could monitor the USB traffic inside
the guest and on the host via usbmon [1]. Most probably you will see USB
traffic coming back from the device on the host, but not inside the guest.


Best regards and good luck,
Maximilian Stein

[1] https://www.kernel.org/doc/Documentation/usb/usbmon.txt

_______________________________________________
Pcsclite-muscle mailing list
[hidden email]
http://lists.alioth.debian.org/cgi-bin/mailman/listinfo/pcsclite-muscle
Reply | Threaded
Open this post in threaded view
|

Re: Yubikey init failed

Ludovic Rousseau
In reply to this post by Robin Lambertz
2017-02-14 1:53 GMT+01:00 Robin Lambertz <[hidden email]>:
Hello,

Hello,
 

I'm trying to get my Yubikey NEO to work with GPG in an archlinux VM on Qubes OS. Unfortunately, it seems that PCSCD is unable to work with my yubikey, it doesn't appear when running pcsc_scan.

I started pcscd with `sudo LIBCCID_ifdLogLevel=0x000F pcscd --foreground --debug --apdu --color | tee log.txt` to get more info about where the problem could come from. The full logs are attached, but the interesting bits are here :

```
00000206 ccid_usb.c:621:OpenUSBByName() Found Vendor/Product: 1050/0111 (Yubico Yubikey NEO OTP+CCID)
00000012 ccid_usb.c:623:OpenUSBByName() Using USB bus/device: 2/4
00000010 ccid_usb.c:680:OpenUSBByName() bNumDataRatesSupported is 0
00001997 ccid_usb.c:1244:InterruptRead() before (0)
00103904 ccid_usb.c:1290:InterruptRead() after (0) (2)
00000072 -> 000000 65 00 00 00 00 00 00 00 00 00
00002614 <- 000000 81 00 00 00 00 00 00 00 00 00
00000050 -> 000000 65 00 00 00 00 00 01 00 00 00
00103063 ccid_usb.c:836:ReadUSB() read failed (2/4): -7 LIBUSB_ERROR_TIMEOUT
00000224 -> 000000 65 00 00 00 00 00 02 00 00 00
05002241 ccid_usb.c:797:WriteUSB() write failed (2/4): -7 LIBUSB_ERROR_TIMEOUT
00000242 ifdhandler.c:188:CreateChannelByNameOrChannel() failed
00000159 ccid_usb.c:879:CloseUSB() Closing USB device: 2/4
00000151 ccid_usb.c:889:CloseUSB() Last slot closed. Release resources
00000240 ccid_usb.c:189:close_libusb_if_needed() libusb_exit
00000476 readerfactory.c:1110:RFInitializeReader() Open Port 0x200000 Failed (usb:1050/0111:libudev:1:/dev/bus/usb/002/004)
00000161 readerfactory.c:375:RFAddReader() Yubico Yubikey NEO OTP+CCID init failed.
```

ReadUSB returns immediately with the TIMEOUT error (isn't that weird ?), while the WriteUSB times out after 5 seconds. I'm not sure what to do to further debug this. Any hint as to what I could do to figure out where the issue is coming from ?

The first ReadUSB() works.
But then the next two ReadUSB() fails after 103 ms. Your device is not responding.

Does the device works fine with a normal computer + OS (not in a virtual machine)?

Bye

--
 Dr. Ludovic Rousseau

_______________________________________________
Pcsclite-muscle mailing list
[hidden email]
http://lists.alioth.debian.org/cgi-bin/mailman/listinfo/pcsclite-muscle
Reply | Threaded
Open this post in threaded view
|

Re: Yubikey init failed

Robin Lambertz
In reply to this post by Stein, Maximilian
Hi,

First, thanks for the help and the swift reply :).

So I should note that the yubikey works fine when accessed directly on the host, it only fails in the guest.

The virtualization software used by QubesOS is Xen. However, I found out that it uses a "USB proxy"[0] to protect the system from DMA attacks. They call it a "USB device passthrough using USBIP as a protocol, but qrexec as link layer" (qrexec is qube's cross-vm communication layer). What this means is that they tunnel a single USB device from the host to the guest using the USBIP protocol (instead of assigning the whole bus to the guest).

I tried using usbmon with wireshark as you suggested to find out more. The logs of the guest and host are attached (they are the same session). I'm not too sure what to make of it though. Clearly, the usb doesn't seem to answer in time to the Get Slot Status request. It looks like it times out after 100ms in both the guest and the host. Is it possible that the USB proxy would add latency, causing the timeout ? And if so, how can I increase this timeout ? I figured DEFAULT_COM_READ_TIMEOUT is where the timeout is defined, but it is specified as 3000ms in the source, whereas I timeout after 100ms, so I guess the timeout I'm seeing comes from somewhere else ?

I also have made another wireshark log of what happens in the host when accessing the yubikey directly from there (the scenario where the yubikey works) in case that's useful.

I'm contacting the Qubes mailing list, maybe they have more insight into what their usb proxy entails.

Again, thanks a lot for the help :)

Robin Lambertz

[0]: https://github.com/QubesOS/qubes-app-linux-usb-proxy

On 02/14/2017 09:48 AM, Maximilian Stein wrote:
On 14.02.2017 01:53, Robin Lambertz wrote:
Hello,
Hi

I'm trying to get my Yubikey NEO to work with GPG in an archlinux VM on
Qubes OS. Unfortunately, it seems that PCSCD is unable to work with my
yubikey, it doesn't appear when running pcsc_scan.
This is probably a problem with your virtualisation software. I've found
that certain constellations of VirtualBox do not play nicely together
with non-mass-storage USB usage.

ReadUSB returns immediately with the TIMEOUT error (isn't that weird ?),
Not at all, the first InterruptRead is just to clear the interrupt
endpoint and therefore has a timeout of only 100ms, which expires in
your logs.

while the WriteUSB times out after 5 seconds. I'm not sure what to do to
further debug this. Any hint as to what I could do to figure out where
the issue is coming from ?
You could try to use a different virtualisation software or version,
updating guest additions (in case of VirtualBox). You could try a newer
kernel in the VM guest or a newer version of libusbx/libusb-1.0.


To further debug the problem you could monitor the USB traffic inside
the guest and on the host via usbmon [1]. Most probably you will see USB
traffic coming back from the device on the host, but not inside the guest.


Best regards and good luck,
Maximilian Stein

[1] https://www.kernel.org/doc/Documentation/usb/usbmon.txt

_______________________________________________
Pcsclite-muscle mailing list
[hidden email]
http://lists.alioth.debian.org/cgi-bin/mailman/listinfo/pcsclite-muscle


_______________________________________________
Pcsclite-muscle mailing list
[hidden email]
http://lists.alioth.debian.org/cgi-bin/mailman/listinfo/pcsclite-muscle

guest.pcap (11K) Download Attachment
host.pcap (7K) Download Attachment
host_direct_access.pcap (29K) Download Attachment
Reply | Threaded
Open this post in threaded view
|

Re: Yubikey init failed

Ludovic Rousseau
2017-02-16 14:01 GMT+01:00 Robin Lambertz <[hidden email]>:
> Hi,


Hello,

> First, thanks for the help and the swift reply :).
>
> So I should note that the yubikey works fine when accessed directly on the host, it only fails in the guest.
>
> The virtualization software used by QubesOS is Xen. However, I found out that it uses a "USB proxy"[0] to protect the system from DMA attacks. They call it a "USB device passthrough using USBIP as a protocol, but qrexec as link layer" (qrexec is qube's cross-vm communication layer). What this means is that they tunnel a single USB device from the host to the guest using the USBIP protocol (instead of assigning the whole bus to the guest).
>
> I tried using usbmon with wireshark as you suggested to find out more. The logs of the guest and host are attached (they are the same session). I'm not too sure what to make of it though. Clearly, the usb doesn't seem to answer in time to the Get Slot Status request. It looks like it times out after 100ms in both the guest and the host. Is it possible that the USB proxy would add latency, causing the timeout ? And if so, how can I increase this timeout ? I figured DEFAULT_COM_READ_TIMEOUT is where the timeout is defined, but it is specified as 3000ms in the source, whereas I timeout after 100ms, so I guess the timeout I'm seeing comes from somewhere else ?

The 100 ms timeout comes from https://github.com/LudovicRousseau/CCID/blob/master/src/ifdhandler.c#L190

Note that (from your initial logs) the device + VM + USBIP + etc. responded in  2.614 ms to the first PC_to_RDR_GetSlotStatus command (command 0x65)

00000072 -> 000000 65 00 00 00 00 00 00 00 00 00
00002614 <- 000000 81 00 00 00 00 00 00 00 00 00

So latency or timeout may not really be the problem here.

From your usbmon traces guest.pcap & host.pcap I see that, even on the host, the device does not answer to the second and third PC_to_RDR_GetSlotStatus commands.

> I also have made another wireshark log of what happens in the host when accessing the yubikey directly from there (the scenario where the yubikey works) in case that's useful.

From your log host_direct_access.pcap it looks like the token worked in this case.
Yes, that is useful. The problem does not come from the token firmware or CCID driver.

> I'm contacting the Qubes mailing list, maybe they have more insight into what their usb proxy entails.

I, also, suspect a problem in QubesOS.

> Again, thanks a lot for the help :)

Bye

--
 Dr. Ludovic Rousseau

_______________________________________________
Pcsclite-muscle mailing list
[hidden email]
http://lists.alioth.debian.org/cgi-bin/mailman/listinfo/pcsclite-muscle