Тема от beelze

  • beelze
  • Посетитель
  • Неактивен

Рутокен ЭЦП. Проблема с xhci?

Вчера получил новый Рутокен ЭЦП, на второй инициализации (pkcs15-init --erase-card) токен отвалился – я счел это случайностью, переткнул его и перезапустил покрошившийся pcscd. Но сегодня ситуация повторилась: при генерации ключей (pkcs15-init -G rsa) я увидел:

Using reader with a card: Aktiv Rutoken ECP 00 00
User PIN [...] required.
Please enter User PIN [...]: 
Failed to generate key: Card removed

для разрешения ситуации потребовалось снова переткнуть токен и перезапустить pcscd.
В сислоге я увидел следующее:

Oct  3 02:07:11 myhost kernel: [482662.588243] xhci_hcd 0000:02:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
Oct  3 02:07:14 myhost pcscd: /var/tmp/portage/app-crypt/ccid-1.4.18/work/ccid-1.4.18/src/ccid_usb.c:798:ReadUSB() read failed (5/29): -7 Resource temporarily unavailable
Oct  3 02:07:14 myhost pcscd: ifdwrapper.c:553:IFDTransmit() Card not transacted: 612
Oct  3 02:07:14 myhost pcscd: winscard.c:1638:SCardTransmit() Card not transacted: 0x80100016
Oct  3 02:07:17 myhost pcscd: /var/tmp/portage/app-crypt/ccid-1.4.18/work/ccid-1.4.18/src/ccid_usb.c:798:ReadUSB() read failed (5/29): -7 Resource temporarily unavailable
Oct  3 02:07:17 myhost pcscd: ifdwrapper.c:374:IFDStatusICC() Card not transacted: 612
Oct  3 02:07:17 myhost pcscd: eventhandler.c:339:EHStatusHandlerThread() Error communicating to: Aktiv Rutoken ECP 00 00
Oct  3 02:07:20 myhost pcscd: /var/tmp/portage/app-crypt/ccid-1.4.18/work/ccid-1.4.18/src/ccid_usb.c:798:ReadUSB() read failed (5/29): -7 Resource temporarily unavailable
Oct  3 02:07:20 myhost pcscd: ifdwrapper.c:553:IFDTransmit() Card not transacted: 612
Oct  3 02:07:20 myhost pcscd: winscard.c:1638:SCardTransmit() Card not transacted: 0x80100016
Oct  3 02:07:25 myhost pcscd: /var/tmp/portage/app-crypt/ccid-1.4.18/work/ccid-1.4.18/src/ccid_usb.c:759:WriteUSB() write failed (5/29): -7 Resource temporarily unavailable
Oct  3 02:07:25 myhost pcscd: ifdwrapper.c:374:IFDStatusICC() Card not transacted: 612
Oct  3 02:07:25 myhost pcscd: eventhandler.c:339:EHStatusHandlerThread() Error communicating to: Aktiv Rutoken ECP 00 00
Oct  3 02:07:31 myhost pcscd: /var/tmp/portage/app-crypt/ccid-1.4.18/work/ccid-1.4.18/src/ccid_usb.c:759:WriteUSB() write failed (5/29): -7 Resource temporarily unavailable
Oct  3 02:07:31 myhost pcscd: ifdwrapper.c:374:IFDStatusICC() Card not transacted: 612
Oct  3 02:07:31 myhost pcscd: eventhandler.c:339:EHStatusHandlerThread() Error communicating to: Aktiv Rutoken ECP 00 00
Oct  3 02:07:36 myhost pcscd: /var/tmp/portage/app-crypt/ccid-1.4.18/work/ccid-1.4.18/src/ccid_usb.c:759:WriteUSB() write failed (5/29): -7 Resource temporarily unavailable
Oct  3 02:07:36 myhost pcscd: ifdwrapper.c:374:IFDStatusICC() Card not transacted: 612
Oct  3 02:07:36 myhost pcscd: winscard.c:951:SCardDisconnect() Error resetting card.
Oct  3 02:07:41 myhost pcscd: /var/tmp/portage/app-crypt/ccid-1.4.18/work/ccid-1.4.18/src/ccid_usb.c:759:WriteUSB() write failed (5/29): -7 Resource temporarily unavailable
Oct  3 02:07:41 myhost pcscd: ifdwrapper.c:374:IFDStatusICC() Card not transacted: 612
Oct  3 02:07:41 myhost pcscd: winscard.c:951:SCardDisconnect() Error resetting card.
Oct  3 02:07:41 myhost pcscd: winscard.c:348:SCardConnect() Card Not Powered
Oct  3 02:07:42 myhost pcscd: winscard.c:348:SCardConnect() Card Not Powered
Oct  3 02:07:42 myhost pcscd: winscard.c:348:SCardConnect() Card Not Powered

Я пока не исключил окончательно проблему с портом/xhci_hcd, однако перед рутокеном именно в этом порту несколько месяцев стоял етокен другого производителя и подобных проблем не замечалось.

Ответ от Кирилл Мещеряков

  • Кирилл Мещеряков
  • Посетитель
  • Неактивен

Re: Рутокен ЭЦП. Проблема с xhci?

Добрый день.
Это похоже на известную ошибку libusb, которая ничем не лечится, кроме как установкой обновления с багфиксом.
Можете посмотреть версии пакетов libusb на вашей системе?

Ответ от beelze (2014-10-03 19:38:24 отредактировано beelze)

  • beelze
  • Посетитель
  • Неактивен

Re: Рутокен ЭЦП. Проблема с xhci?

dev-libs/libusb-1.0.18, ядро 3.14.19 x86_64

а что за известная ошибка? я изначально подозреваю либо аппаратную проблему, либо баг в xhci_hcd. Однако ничего кроме уже исправленного «Intel xhci: Ignore spurious successful event» я не нашел. Уже ясно, что ошибка случается именно при записи (то есть многократные чтения ключей и сетов а также собственно процесс генерации – даже RSA 2048) ошибку не вызывают.

Ответ от _S

  • _S
  • Посетитель
  • Неактивен

Re: Рутокен ЭЦП. Проблема с xhci?

beelze пишет:

dev-libs/libusb-1.0.18, ядро 3.14.19 x86_64
а что за известная ошибка?

Ошибка была в libusb-1.0.8 (Исправление). Осложнялось всё тем, что версия libusb-1.0.9 очень долго не выходила в релиз и libusb-1.0.8 получила широкое распространение в дистрибутивах.

beelze пишет:

я изначально подозреваю либо аппаратную проблему, либо баг в xhci_hcd.

Судя по этому:

beelze пишет:

Oct  3 02:07:11 myhost kernel: [482662.588243] xhci_hcd 0000:02:00.0: ERROR Transfer event TRB DMA ptr not part of current TD

(а на неотладочном ядре, такого быть не должно) проблема действително на "низком уровне".

beelze пишет:

Уже ясно, что ошибка случается именно при записи (то есть многократные чтения ключей и сетов а также собственно процесс генерации – даже RSA 2048) ошибку не вызывают.

Укажите пожалуйста версию OpenSC, и если Вы собирали её сами, то приложите пожалуйста config.log
Также было бы очень полезно получить лог usbmon воспроизводящий ошибку how-to use usbmon

Ответ от beelze

  • beelze
  • Посетитель
  • Неактивен

Re: Рутокен ЭЦП. Проблема с xhci?

Ошибка была в libusb-1.0.8 (Исправление). Осложнялось всё тем, что версия libusb-1.0.9 очень долго не выходила в релиз и libusb-1.0.8 получила широкое распространение в дистрибутивах.

проверил linux_usbfs.c собранной версии, указанный патч там уже применен.

Судя по этому:
(а на неотладочном ядре, такого быть не должно) проблема действително на "низком уровне".
Укажите пожалуйста версию OpenSC, и если Вы собирали её сами, то приложите пожалуйста config.log

Под «отладочным ядром» применительно к данному случаю понимается ядро, собранное с CONFIG_USB_DEBUG? Нет, в моем случае это не так. Если про CONFIG_DEBUG_KERNEL, то эта опция выбирается автоматически при включении CONFIG_EXPERT, что, в свою очередь, мне необходимо.

dev-libs/opensc
Installed versions:  0.14.0(18:24:34 10/01/14)(pcsc-lite readline ssl zlib -ctapi -doc -openct -secure-messaging)
то бишь (исходя из ебилда), конфигурировалось с pcsc openssl zlib и readline. можно, конечно, пересобрать и найти логи конфигурирования и сборки, но я полагаю этого достаточно. да и проблема пока на мой взгляд, указывает не на opensc.

Также было бы очень полезно получить лог usbmon воспроизводящий ошибку how-to use usbmon

для этого сначала потребуется найти более-менее уверенный способ воспроизведения ошибки. на днях этим займусь.

Ответ от _S

  • _S
  • Посетитель
  • Неактивен

Re: Рутокен ЭЦП. Проблема с xhci?

beelze пишет:

Под «отладочным ядром» применительно к данному случаю понимается ядро, собранное с CONFIG_USB_DEBUG? Нет, в моем случае это не так. Если про CONFIG_DEBUG_KERNEL, то эта опция выбирается автоматически при включении CONFIG_EXPERT, что, в свою очередь, мне необходимо.

Да, я конечно имел ввиду CONFIG_USB_DEBUG

beelze пишет:

dev-libs/opensc
Installed versions:  0.14.0(18:24:34 10/01/14)(pcsc-lite readline ssl zlib -ctapi -doc -openct -secure-messaging)
то бишь (исходя из ебилда), конфигурировалось с pcsc openssl zlib и readline. можно, конечно, пересобрать и найти логи конфигурирования и сборки, но я полагаю этого достаточно. да и проблема пока на мой взгляд, указывает не на opensc.

Да, этого вполне достаточно.

beelze пишет:

для этого сначала потребуется найти более-менее уверенный способ воспроизведения ошибки. на днях этим займусь.

Как редко проявляется ошибка?

Ответ от beelze

  • beelze
  • Посетитель
  • Неактивен

Re: Рутокен ЭЦП. Проблема с xhci?

Пока я не набрал презентативной статистики, но уже 3 раза такое произошло. На днях попробую погенерировать ключи – на разных портах. Для исключения проблемы на стороне хаба.

Ответ от _S

  • _S
  • Посетитель
  • Неактивен

Re: Рутокен ЭЦП. Проблема с xhci?

beelze пишет:

На днях попробую погенерировать ключи – на разных портах. Для исключения проблемы на стороне хаба.

Спасибо! Буду ждать результатов.

Ответ от beelze (2014-10-10 14:54:10 отредактировано beelze)

  • beelze
  • Посетитель
  • Неактивен

Re: Рутокен ЭЦП. Проблема с xhci?

upd:
сегодня при втыкании токена pcscd покрашился (но уже иначе):
использовался другой порт, не тот, что был в начале темы.

pcscd: /var/tmp/portage/app-crypt/ccid-1.4.18/work/ccid-1.4.18/src/ccid_usb.c:798:ReadUSB() read failed (1/7): -7 Resource temporarily unavailable
pcscd: /var/tmp/portage/app-crypt/ccid-1.4.18/work/ccid-1.4.18/src/ccid_usb.c:759:WriteUSB() write failed (1/7): -7 Resource temporarily unavailable
pcscd: /var/tmp/portage/app-crypt/ccid-1.4.18/work/ccid-1.4.18/src/ifdhandler.c:171:CreateChannelByNameOrChannel() failed
pcscd: readerfactory.c:1046:RFInitializeReader() Open Port 0x200000 Failed (usb:0a89/0030:libudev:0:/dev/bus/usb/001/007)
pcscd: readerfactory.c:338:RFAddReader() Aktiv Rutoken ECP init failed.
pcscd: hotplug_libudev.c:504:HPAddDevice() Failed adding USB device: Aktiv Rutoken ECP

версия ccid: 1.4.18.
Попробую включить отладку pcscd и откатиться на 1.4.15. И похоже, что проблема не в хабе.