dearsky/pico-openpgp
1
0
Fork 0
Code Issues 10 Pull Requests Actions Packages Projects Releases 15 Wiki Activity

version 1.6 causes hangs in pcsc, opensc, gpg #2

New Issue
Closed
opened 2022-11-23 14:06:30 +08:00 by al-heisner · 12 comments
al-heisner commented 2022-11-23 14:06:30 +08:00 (Migrated from github.com)
Copy Link

Working with both 1.4 and 1.6:
lsusb shows device: Bus 008 Device 037: ID 234b:0000 Free Software Initiative of Japan Gnuk Token
pcscd logs device: 00000104 [140218338324992] readerfactory.c:1387:RFCleanupReaders() Stopping reader: Free Software Initiative of Japan Gnuk [Pico HSM Interface] (E6609103C3395D24) 00 00
opensc-tool -l lists device:

Detected readers (pcsc)

Nr. Card Features Name
0 Yes Free Software Initiative of Japan Gnuk [Pico HSM Interface] (E6609103C3395D24) 00 00
opensc-tool -a lists atr bytes

Works in 1.4 but hangs in 1.6
opensc-tool --serial
opensc-tool -l -v
opensc-tool -n
gpg --card-edit

versions:
pcscd: pcsc-lite version 1.9.5
opensc-tool: 0.22.0-1ubuntu2
gpg: 0.22.0-1ubuntu2

Working with both 1.4 and 1.6: lsusb shows device: Bus 008 Device 037: ID 234b:0000 Free Software Initiative of Japan Gnuk Token pcscd logs device: 00000104 [140218338324992] readerfactory.c:1387:RFCleanupReaders() Stopping reader: Free Software Initiative of Japan Gnuk [Pico HSM Interface] (E6609103C3395D24) 00 00 opensc-tool -l lists device: # Detected readers (pcsc) Nr. Card Features Name 0 Yes Free Software Initiative of Japan Gnuk [Pico HSM Interface] (E6609103C3395D24) 00 00 opensc-tool -a lists atr bytes Works in 1.4 but hangs in 1.6 opensc-tool --serial opensc-tool -l -v opensc-tool -n gpg --card-edit versions: pcscd: pcsc-lite version 1.9.5 opensc-tool: 0.22.0-1ubuntu2 gpg: 0.22.0-1ubuntu2
polhenarejos commented 2022-11-23 18:17:22 +08:00 (Migrated from github.com)
Copy Link

It should be fixed in v1.8 https://github.com/polhenarejos/pico-openpgp/releases/tag/v1.8 check it and reopen if it happens again.

It should be fixed in v1.8 https://github.com/polhenarejos/pico-openpgp/releases/tag/v1.8 check it and reopen if it happens again.
al-heisner commented 2022-11-23 22:32:30 +08:00 (Migrated from github.com)
Copy Link

Same issue with 1.8

Same issue with 1.8
polhenarejos commented 2022-11-23 22:34:51 +08:00 (Migrated from github.com)
Copy Link

Did you compile or patch it?

Did you compile or patch it?
al-heisner commented 2022-11-23 23:20:18 +08:00 (Migrated from github.com)
Copy Link

I used the vid:pid patch script on release 1.8. I'm able to compile it also to test prior to new release.

I used the vid:pid patch script on release 1.8. I'm able to compile it also to test prior to new release.
al-heisner commented 2022-11-24 07:15:45 +08:00 (Migrated from github.com)
Copy Link

I did some debugging on this one.
Issue 1 was I saw bMessageType == 0x63 come in twice from pcsc (during opensc-tool -l, for example). It looks like this caused one to shut down the card thread, and the other remain in queue. The one in queue would immediately shut down the card thread when it was spun back up. I got past this problem in my setup by commenting out the original card_exit() in ccid.c and adding "if (ccid_status == 0) card_exit();" just before "ccid_status = 1;". This seems to prevent placing the extra shutdown on the card thread queue.

Issue 2: I'm not sure what the problem is, as attempting to observe it changed the outcome. Compiling with debug and additional printf in usb_write_offest() and usb_write_flush() in usb.c made it not reproducible. Maybe a timing issue?

I did some debugging on this one. Issue 1 was I saw bMessageType == 0x63 come in twice from pcsc (during opensc-tool -l, for example). It looks like this caused one to shut down the card thread, and the other remain in queue. The one in queue would immediately shut down the card thread when it was spun back up. I got past this problem in my setup by commenting out the original card_exit() in ccid.c and adding "if (ccid_status == 0) card_exit();" just before "ccid_status = 1;". This seems to prevent placing the extra shutdown on the card thread queue. Issue 2: I'm not sure what the problem is, as attempting to observe it changed the outcome. Compiling with debug and additional printf in usb_write_offest() and usb_write_flush() in usb.c made it not reproducible. Maybe a timing issue?
polhenarejos commented 2022-11-24 19:22:17 +08:00 (Migrated from github.com)
Copy Link

I cannot reproduce it in a Debian machine.
I am using pcscd 1.8.24-1, libccid 1.4.30 and opensc 0.19.0.

  • Does it blink regularly?
  • Can you stop pcscd service, and execute it in foreground? pcscd --foreground --debug
  • Is lsusb -vvv detecting correctly?
  • Try with OPENSC_DEBUG=9 opensc-tool -an to see if it is a bug with the CCID or USB interface.
I cannot reproduce it in a Debian machine. I am using pcscd 1.8.24-1, libccid 1.4.30 and opensc 0.19.0. - Does it blink regularly? - Can you stop pcscd service, and execute it in foreground? `pcscd --foreground --debug` - Is `lsusb -vvv` detecting correctly? - Try with `OPENSC_DEBUG=9 opensc-tool -an` to see if it is a bug with the CCID or USB interface.
al-heisner commented 2022-11-25 02:22:39 +08:00 (Migrated from github.com)
Copy Link

I'm using Linux Mint 21, it's Debian/Ubuntu based but seems to have slightly newer package versions.
lsusb does show device.
I've been running pcscd in forground with debug, it is properly reporting the pico, eg:
Stopping reader: Free Software Initiative of Japan Gnuk [Pico HSM Interface] (E6609103C3395D24) 00 00

For issue 1 with card thread, I added some debug printf's to show it from the pico's serial connection.
From pico serial port during start of pcscd:
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65
usb_write_offset(): length=10
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65
usb_write_offset(): length=10
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65
usb_write_offset(): length=10
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65
usb_write_offset(): length=10
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65
usb_write_offset(): length=10
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=62
card_start(): called
card_thread(): start
usb_write_offset(): length=31
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65
usb_write_offset(): length=10
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65
usb_write_offset(): length=10
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=63
card_exit(): called
card_thread(): EXIT
usb_write_offset(): length=10
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=63
card_exit(): called
usb_write_offset(): length=10
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65
usb_write_offset(): length=10
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65
usb_write_offset(): length=10
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65
usb_write_offset(): length=10
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65
usb_write_offset(): length=10
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=63
card_exit(): called
usb_write_offset(): length=10

From the above output, I see that bMessageType=63 is sent several times just from starting pcscd. Then when I attempt opensc-tool -n, the card thread starts and exits immediate since "queue_try_add(&usb_to_card_q, &flag);" in card_exit() has placed extra exit messages on the usb_to_card_q queue.
From pico serial port when trying "opensc-tool -n":
driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=62
card_start(): called
card_thread(): start
usb_write_offset(): length=31
card_thread(): EXIT
driver_process_usb_packet(): dwLength=12 rx_read-10=12 bMessageType=6f
usb_write_offset(): length=10

The following in ccid.c seems to work to prevent the extra exit messages from being placed on usb_to_card_q by checking ccid_status before calling card_exit():

            else if (ccid_header->bMessageType == 0x63) {
                if (ccid_status == 0) card_exit();
                ccid_status = 1;
                ccid_response->bMessageType = CCID_SLOT_STATUS_RET;
                ccid_response->dwLength = 0;
                ccid_response->bSlot = 0;
                ccid_response->bSeq = ccid_header->bSeq;
                ccid_response->abRFU0 = ccid_status;
                ccid_response->abRFU1 = 0;
                //card_exit();
                ccid_write(0);
            }
I'm using Linux Mint 21, it's Debian/Ubuntu based but seems to have slightly newer package versions. lsusb does show device. I've been running pcscd in forground with debug, it is properly reporting the pico, eg: Stopping reader: Free Software Initiative of Japan Gnuk [Pico HSM Interface] (E6609103C3395D24) 00 00 For issue 1 with card thread, I added some debug printf's to show it from the pico's serial connection. From pico serial port during start of pcscd: driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65 usb_write_offset(): length=10 driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65 usb_write_offset(): length=10 driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65 usb_write_offset(): length=10 driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65 usb_write_offset(): length=10 driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65 usb_write_offset(): length=10 driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=62 card_start(): called card_thread(): start usb_write_offset(): length=31 driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65 usb_write_offset(): length=10 driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65 usb_write_offset(): length=10 driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=63 card_exit(): called card_thread(): EXIT usb_write_offset(): length=10 driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=63 card_exit(): called usb_write_offset(): length=10 driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65 usb_write_offset(): length=10 driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65 usb_write_offset(): length=10 driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65 usb_write_offset(): length=10 driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=65 usb_write_offset(): length=10 driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=63 card_exit(): called usb_write_offset(): length=10 From the above output, I see that bMessageType=63 is sent several times just from starting pcscd. Then when I attempt opensc-tool -n, the card thread starts and exits immediate since "queue_try_add(&usb_to_card_q, &flag);" in card_exit() has placed extra exit messages on the usb_to_card_q queue. From pico serial port when trying "opensc-tool -n": driver_process_usb_packet(): dwLength=0 rx_read-10=0 bMessageType=62 card_start(): called card_thread(): start usb_write_offset(): length=31 card_thread(): EXIT driver_process_usb_packet(): dwLength=12 rx_read-10=12 bMessageType=6f usb_write_offset(): length=10 The following in ccid.c seems to work to prevent the extra exit messages from being placed on usb_to_card_q by checking ccid_status before calling card_exit(): ``` else if (ccid_header->bMessageType == 0x63) { if (ccid_status == 0) card_exit(); ccid_status = 1; ccid_response->bMessageType = CCID_SLOT_STATUS_RET; ccid_response->dwLength = 0; ccid_response->bSlot = 0; ccid_response->bSeq = ccid_header->bSeq; ccid_response->abRFU0 = ccid_status; ccid_response->abRFU1 = 0; //card_exit(); ccid_write(0); } ```
al-heisner commented 2022-11-25 02:41:55 +08:00 (Migrated from github.com)
Copy Link

After I've put the workaround in for card_exit, I then get hangs during communication with the pico. pcscd shows libusb timeout:

00000020 [140706369947200] APDU: 00 CA 00 6E 00 20 00 
00000020 [140706369947200] ifdhandler.c:1368:IFDHTransmitToICC() usb:234b/0000:libudev:0:/dev/bus/usb/008/060 (lun: 0)
14467008 [140706369947200] ccid_usb.c:993:ReadUSB() read failed (8/60): LIBUSB_ERROR_TIMEOUT
00000052 [140706369947200] SW: 
00000010 [140706369947200] ifdwrapper.c:543:IFDTransmit() Card not transacted: 612
00000021 [140706369947200] winscard.c:1618:SCardTransmit() Card not transacted: 0x80100016

This second issue seems to be timing related. With the workaround for the first issue in place, the pico appears to hang with any attempt to retrieve data from it. When I added a printf to the function usb_write_flush, it made this issue disappear. Swapping the printf out with busy_wait_us(10) also worked.

uint32_t usb_write_flush() {
    if (w_len > 0) {
        busy_wait_us(10);
        driver_write(tx_buffer+tx_r_offset, MIN(w_len, 64));
        //printf("usb_write_flush(): length=%i\r\n",MIN(w_len, 64));
        tx_r_offset += MIN(w_len, 64);
        w_len -= MIN(w_len, 64);
    }
    return w_len;
}
After I've put the workaround in for card_exit, I then get hangs during communication with the pico. pcscd shows libusb timeout: ``` 00000020 [140706369947200] APDU: 00 CA 00 6E 00 20 00 00000020 [140706369947200] ifdhandler.c:1368:IFDHTransmitToICC() usb:234b/0000:libudev:0:/dev/bus/usb/008/060 (lun: 0) 14467008 [140706369947200] ccid_usb.c:993:ReadUSB() read failed (8/60): LIBUSB_ERROR_TIMEOUT 00000052 [140706369947200] SW: 00000010 [140706369947200] ifdwrapper.c:543:IFDTransmit() Card not transacted: 612 00000021 [140706369947200] winscard.c:1618:SCardTransmit() Card not transacted: 0x80100016 ``` This second issue seems to be timing related. With the workaround for the first issue in place, the pico appears to hang with any attempt to retrieve data from it. When I added a printf to the function usb_write_flush, it made this issue disappear. Swapping the printf out with busy_wait_us(10) also worked. ``` uint32_t usb_write_flush() { if (w_len > 0) { busy_wait_us(10); driver_write(tx_buffer+tx_r_offset, MIN(w_len, 64)); //printf("usb_write_flush(): length=%i\r\n",MIN(w_len, 64)); tx_r_offset += MIN(w_len, 64); w_len -= MIN(w_len, 64); } return w_len; } ```
polhenarejos commented 2022-11-25 03:21:52 +08:00 (Migrated from github.com)
Copy Link

Sounds interesting.

I made some changes in usb_write_flush weeks ago on streamline of pico-hsm-sdk. Could you cd pico-hsm-sdk && git checkout - and recompile with the latest version of the HSM SDK?
I also added a bugfix for multiple cardPowerOff (0x63).

Sounds interesting. I made some changes in `usb_write_flush` weeks ago on streamline of pico-hsm-sdk. Could you `cd pico-hsm-sdk && git checkout -` and recompile with the latest version of the HSM SDK? I also added a bugfix for multiple cardPowerOff (0x63).
al-heisner commented 2022-11-25 04:46:11 +08:00 (Migrated from github.com)
Copy Link

With the bugfix for cardPowerOff and latest HSM SDK it appears to work. I'm able to use opensc-tool without hang, and I was able to use gpg --card-edit to generate keys on the virtual gpg card

With the bugfix for cardPowerOff and latest HSM SDK it appears to work. I'm able to use opensc-tool without hang, and I was able to use gpg --card-edit to generate keys on the virtual gpg card
al-heisner commented 2022-11-26 00:57:17 +08:00 (Migrated from github.com)
Copy Link

perhaps the cardPowerOff bug is this one too? https://github.com/polhenarejos/pico-hsm/issues/9

perhaps the cardPowerOff bug is this one too? https://github.com/polhenarejos/pico-hsm/issues/9
polhenarejos commented 2022-11-30 03:24:38 +08:00 (Migrated from github.com)
Copy Link

Could be. I could not reproduce it, hope it will help fixing it. BTW, it is fixed in openpgp.

Could be. I could not reproduce it, hope it will help fixing it. BTW, it is fixed in openpgp.
Sign in to join this conversation.
No Branch/Tag Specified
Branches Tags
Labels
Clear labels
bug
Something isn't working
 documentation
Improvements or additions to documentation
 duplicate
This issue or pull request already exists
 enhancement
New feature or request
 good first issue
Good for newcomers
 help wanted
Extra attention is needed
 invalid
This doesn't seem right
 question
Further information is requested
 wontfix
This will not be worked on
No Label
Milestone
No items
No Milestone
Projects
Clear projects
No project
Assignees
Clear assignees
dearsky
No Assignees
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: dearsky/pico-openpgp#2
Delete Branch "%!s()"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?