roelderickx / connective-plugin-linux

A replacement for the Connective Plugin which is used on several websites to log in or sign documents using a card reader and an electronic identity card.
GNU General Public License v3.0
36 stars 2 forks source link

Itsme / protocol tester {"error": {"code": 5, "id": 5, "message": "Error reading file (Comm 0x6a87) (0xa4080c)"}} #15

Closed LauryChaerle closed 10 months ago

LauryChaerle commented 11 months ago

Hello,

On both Firefox and Chrome, communication with the cardreader works (html protocol tester), PIN Tkinter window functionality VERIFY_PIN OK, but when reading the info with "READ_FILE", itsme account activation always fails with {"error": {"code": 5, "id": 5, "message": "Error reading file (Comm 0x6a87) (0xa4080c)"}}

As far as I could see in the firefox log (see below at end message) 5 files are read in sequence fileId":"3F00DF014031" to "fileId":"3F00DF014035 failure occurs sometimes at fileId":"3F00DF014032, once at 4034, but always at 3F00DF014035 (foto?) [so I never get the Tkinter window to enter PIN]

This is reproduced in the html protocol tester with {"cmd":"READ_FILE","reader":"ACS ACR 38U-CCID 00 00","activationToken":"","fileId":"3F00DF014035","isRequest":true} which clearly takes much longer than the 4031-4034 fileIds, and when executing the next request before the previous has -completely (there is still card reader activity after the response/output appears in the protocol tester) - finished generates the identical error as above

Request sent: {"cmd":"READ_FILE","reader":"ACS ACR 38U-CCID 00 00","activationToken":"","fileId":"3F00DF014035","isRequest":true} Response received: {"error":{"code":5,"id":5,"message":"Error reading file (Comm 0x6a87) (0xa4080c)"},"resp":"READ_FILE"}

[Simply clicking too fast generates Response received: {"error":{"code":99,"id":99,"message":"No request received after 10 seconds"},"resp":"READ_FILE"}] For FileId 3F00DF014032 the "5/5 Error reading file" error is much harder to generate this way.

On chrome the 409 conflict / signid version info appears, in the 3th line "unspecified error" here below the same {code: 5, id: 5, message: 'Error reading file (Comm 0x6a87) error.) as in firefox is listed ...

GET https://bmid-id.connective.eu/configuration/plugin/latestversion/8637d59cdc9447dda9ee8d260137b439 409 (Conflict)

could not fetch latest signid version info. Defaulting to no version restrictions... The SignIdPlugin setting is not enabled. Check configuration for tenant 4.

t {code: 99, message: 'An unspecified error occured', stack: 'Error\n at new t (https://bmid-id.connective.eu/…d.connective.eu/resources/bundle-legacy.js:2:4911', e: {…}}code: 99e: {code: 5, id: 5, message: 'Error reading file (Comm 0x6a87) (0xa4080c)'}message: "An unspecified error occured"stack: "Error\n at new t (https://bmid-id.connective.eu/resources/bundle-legacy.js:9:143)\n at _.getErrorForResponse (https://bmid-id.connective.eu/resources/bundle-legacy.js:20:1963)\n at https://bmid-id.connective.eu/resources/bundle-legacy.js:22:1225\n at https://bmid-id.connective.eu/resources/bundle-legacy.js:2:4911"[[Prototype]]: Error

### Firefox console LOG: stderr output from native app com.connective.signer: IN {"cmd":"GET_INFO","isRequest":true} stderr output from native app com.connective.signer: OUT {"version": "2.0.2", "binVersion": "2.0.9"} stderr output from native app com.connective.signer: IN {"cmd":"GET_INFO","isRequest":true} stderr output from native app com.connective.signer: OUT {"version": "2.0.2", "binVersion": "2.0.9"} stderr output from native app com.connective.signer: IN {"cmd":"GET_READERS","activationToken":"KffI8Yw+tmG7zrwgAQvVIIWCH2QP421ZhEoLCoYZZ6oBKGRi2+OhaUZM3+ON0GeXU34fHMTdu69ErhXOtAbBcT4hQskBrLrfqhB4hp7PUzDMSufGlBpMIuxwSY8A1h6qeFm2z3sNNIOtO7Riwpx6LMx0sX7/wvYbKFJoyLG1sefannULQmlmJfXR3Gn72FJPhjzG1py+yjt5J8WyS9poihK+F4TlzhgVkwOZ8lOZHIpQWcXOn3qO8Hr8r1vBb/HP7Xd3nQUJ/Sw43tWsb1dRpfhxhgavdBH7GmPugqILbucM1H7e+0VWqAAmC+Nu6BLAaSqcVuKZdCs7kISYqjtQuA==","isRequest":true} stderr output from native app com.connective.signer: Card applet version: 17 stderr output from native app com.connective.signer: Card 0x6C delay required: 0 ms stderr output from native app com.connective.signer: OUT {"readerList": [{"index": 0, "library": "cardcomm", "name": "ACS ACR 38U-CCID 00 00", "atr": "3B9813400AA503010101AD1311", "cardPresent": true, "cardType": 1}]} stderr output from native app com.connective.signer: IN {"cmd":"READ_FILE","reader":"ACS ACR 38U-CCID 00 00","fileId":"3F00DF014031","activationToken":"KffI8Yw+tmG7zrwgAQvVIIWCH2QP421ZhEoLCoYZZ6oBKGRi2+OhaUZM3+ON0GeXU34fHMTdu69ErhXOtAbBcT4hQskBrLrfqhB4hp7PUzDMSufGlBpMIuxwSY8A1h6qeFm2z3sNNIOtO7Riwpx6LMx0sX7/wvYbKFJoyLG1sefannULQmlmJfXR3Gn72FJPhjzG1py+yjt5J8WyS9poihK+F4TlzhgVkwOZ8lOZHIpQWcXOn3qO8Hr8r1vBb/HP7Xd3nQUJ/Sw43tWsb1dRpfhxhgavdBH7GmPugqILbucM1H7e+0VWqAAmC+Nu6BLAaSqcVuKZdCs7kISYqjtQuA==","isRequest":true} stderr output from native app com.connective.signer: Card applet version: 17 stderr output from native app com.connective.signer: Card 0x6C delay required: 0 ms stderr output from native app com.connective.signer: OUT {"data": "redacted"} stderr output from native app com.connective.signer: IN {"cmd":"READ_FILE","reader":"ACS ACR 38U-CCID 00 00","fileId":"3F00DF014032","activationToken":"KffI8Yw+tmG7zrwgAQvVIIWCH2QP421ZhEoLCoYZZ6oBKGRi2+OhaUZM3+ON0GeXU34fHMTdu69ErhXOtAbBcT4hQskBrLrfqhB4hp7PUzDMSufGlBpMIuxwSY8A1h6qeFm2z3sNNIOtO7Riwpx6LMx0sX7/wvYbKFJoyLG1sefannULQmlmJfXR3Gn72FJPhjzG1py+yjt5J8WyS9poihK+F4TlzhgVkwOZ8lOZHIpQWcXOn3qO8Hr8r1vBb/HP7Xd3nQUJ/Sw43tWsb1dRpfhxhgavdBH7GmPugqILbucM1H7e+0VWqAAmC+Nu6BLAaSqcVuKZdCs7kISYqjtQuA==","isRequest":true} stderr output from native app com.connective.signer: Card applet version: 17 stderr output from native app com.connective.signer: Card 0x6C delay required: 0 ms stderr output from native app com.connective.signer: OUT {"data": "redacted"} stderr output from native app com.connective.signer: IN {"cmd":"READ_FILE","reader":"ACS ACR 38U-CCID 00 00","fileId":"3F00DF014033","activationToken":"KffI8Yw+tmG7zrwgAQvVIIWCH2QP421ZhEoLCoYZZ6oBKGRi2+OhaUZM3+ON0GeXU34fHMTdu69ErhXOtAbBcT4hQskBrLrfqhB4hp7PUzDMSufGlBpMIuxwSY8A1h6qeFm2z3sNNIOtO7Riwpx6LMx0sX7/wvYbKFJoyLG1sefannULQmlmJfXR3Gn72FJPhjzG1py+yjt5J8WyS9poihK+F4TlzhgVkwOZ8lOZHIpQWcXOn3qO8Hr8r1vBb/HP7Xd3nQUJ/Sw43tWsb1dRpfhxhgavdBH7GmPugqILbucM1H7e+0VWqAAmC+Nu6BLAaSqcVuKZdCs7kISYqjtQuA==","isRequest":true} stderr output from native app com.connective.signer: Card applet version: 17 stderr output from native app com.connective.signer: Card 0x6C delay required: 0 ms stderr output from native app com.connective.signer: OUT {"data": "redacted"} stderr output from native app com.connective.signer: IN {"cmd":"READ_FILE","reader":"ACS ACR 38U-CCID 00 00","fileId":"3F00DF014034","activationToken":"KffI8Yw+tmG7zrwgAQvVIIWCH2QP421ZhEoLCoYZZ6oBKGRi2+OhaUZM3+ON0GeXU34fHMTdu69ErhXOtAbBcT4hQskBrLrfqhB4hp7PUzDMSufGlBpMIuxwSY8A1h6qeFm2z3sNNIOtO7Riwpx6LMx0sX7/wvYbKFJoyLG1sefannULQmlmJfXR3Gn72FJPhjzG1py+yjt5J8WyS9poihK+F4TlzhgVkwOZ8lOZHIpQWcXOn3qO8Hr8r1vBb/HP7Xd3nQUJ/Sw43tWsb1dRpfhxhgavdBH7GmPugqILbucM1H7e+0VWqAAmC+Nu6BLAaSqcVuKZdCs7kISYqjtQuA==","isRequest":true} stderr output from native app com.connective.signer: Card applet version: 17 stderr output from native app com.connective.signer: Card 0x6C delay required: 0 ms stderr output from native app com.connective.signer: OUT {"data": "redacted"} stderr output from native app com.connective.signer: IN {"cmd":"READ_FILE","reader":"ACS ACR 38U-CCID 00 00","fileId":"3F00DF014035","activationToken":"KffI8Yw+tmG7zrwgAQvVIIWCH2QP421ZhEoLCoYZZ6oBKGRi2+OhaUZM3+ON0GeXU34fHMTdu69ErhXOtAbBcT4hQskBrLrfqhB4hp7PUzDMSufGlBpMIuxwSY8A1h6qeFm2z3sNNIOtO7Riwpx6LMx0sX7/wvYbKFJoyLG1sefannULQmlmJfXR3Gn72FJPhjzG1py+yjt5J8WyS9poihK+F4TlzhgVkwOZ8lOZHIpQWcXOn3qO8Hr8r1vBb/HP7Xd3nQUJ/Sw43tWsb1dRpfhxhgavdBH7GmPugqILbucM1H7e+0VWqAAmC+Nu6BLAaSqcVuKZdCs7kISYqjtQuA==","isRequest":true} stderr output from native app com.connective.signer: Card applet version: 17 stderr output from native app com.connective.signer: Card 0x6C delay required: 0 ms stderr output from native app com.connective.signer: OUT {"error": {"code": 5, "id": 5, "message": "Error reading file (Comm 0x6a87) (0xa4080c)"}}

roelderickx commented 11 months ago

Thanks for the completeness of your bug report :+1: (I even had to redact your report to protect your privacy) It is exactly what someone else reported in #1 at some point and it is probably due to the fact that the card reader works slightly different. I'll try adding some extra logging to find out, but it's a while ago I worked on this project and I have to dig deeper to know what and where to add.

LauryChaerle commented 11 months ago

Hi, Thanks for the swift response, and I indeed realised -after submitting- that including the complete log output was not very smart...

I went through the (closed) issues, but in #1 had the impression that the read always failed (indeed with the same error). I would assume -without having much insight/knowledge on how this works- there is some timing issue when reading the different files from the eid card in succession

It would be very much appreciated if you could further check this, and I would of course test promptly with a new version when available

Last time I tried to get Itsme going via linux was in may22 - somehow I didn't find your project back then.... Authentication on Belgian govmt sites has always worked OK with this combination of cardreader and Fedora Anyway, installation went well according to the instructions, including adding missing dependencies. What I didn't get immediately: the html protocol test page was unresponsive at first - in chrome I needed to allow access to local files in extension settings, and in firefox it needed to be allowed to start in private windows...

De: "Roel Derickx" @.> À: "roelderickx/connective-plugin-linux" @.> Cc: "laury" @.>, "Author" @.> Envoyé: Jeudi 7 Septembre 2023 22:07:19 Objet: Re: [roelderickx/connective-plugin-linux] Itsme / protocol tester {"error": {"code": 5, "id": 5, "message": "Error reading file (Comm 0x6a87) (0xa4080c)"}} (Issue #15)

Thanks for the completeness of your bug report 👍 (I even had to redact your report to protect your privacy) It is exactly what someone else reported in [ https://github.com/roelderickx/connective-plugin-linux/issues/1 | #1 ] at some point and it is probably due to the fact that the card reader works slightly different. I'll try adding some extra logging to find out, but it's a while ago I worked on this project and I have to dig deeper to know what and where to add.

— Reply to this email directly, [ https://github.com/roelderickx/connective-plugin-linux/issues/15#issuecomment-1710707552 | view it on GitHub ] , or [ https://github.com/notifications/unsubscribe-auth/BCNLVZ4NUPMGE4YOOQ4MLW3XZISPPANCNFSM6AAAAAA4PC6N3M | unsubscribe ] . You are receiving this because you authored the thread. Message ID: @.***>

roelderickx commented 11 months ago

To read a file we send a request to fetch 252 bytes (the max message size is 256, there is a 4 byte header) and try to interpret the returned data to detect if we reached end of file. I assume in your case it doesn't work correctly (that is only if the length is smaller than 252 bytes), the file is probably completely read and we still try to continue. Some card readers (like mine for example) are somewhat more intelligent and hide certain return codes, others are more low-level and require more defensive programming. To see what happens at your end I added excessive logging in a new branch called extralogging, please try reading a file in debug mode with this version and report back what the logging tells us. Only the part between read file and the actual data is interesting, it looks like this - but I expect different values for sw1:

stderr output from native app com.connective.signer: read file
stderr output from native app com.connective.signer: sw1 0x90  sw2 0x 0  data length 252
stderr output from native app com.connective.signer: sw1 0x90  sw2 0x 0  data length 136 
LauryChaerle commented 11 months ago

I first tested reading the file "3F00DF014035" with file:///.../connective-plugin-linux-main/test/protocoltest.html

stderr output from native app com.connective.signer: IN {"cmd":"READ_FILE","reader":"ACS ACR 38U-CCID 00 00","activationToken":"","fileId":"3F00DF014035","isRequest":true}

the "sw1 0x90 sw2 0x 0 data length 252"(?) is repeated 12 times (I attempted to 'disable' the console option "group similar messages" but somehow to no avail... I would expect the last one is not identical < 252??)

12:06:03.645 stderr output from native app com.connective.signer: read file 12:06:03.733 stderr output from native app com.connective.signer: sw1 0x90 sw2 0x 0 data length 252 12 12:06:04.705 stderr output from native app com.connective.signer: sw1 0x6c sw2 0x 2 data length 0 12:06:04.919 stderr output from native app com.connective.signer: OUT {"data":

Then I used the Itsme website https://bmid-id.connective.eu where it always blocks at read file 14035 12:10:31.672 stderr output from native app com.connective.signer: read file
12:10:31.759 stderr output from native app com.connective.signer: sw1 0x90 sw2 0x 0 data length 252
12:10:31.786 stderr output from native app com.connective.signer: sw1 0x69 sw2 0x86 data length 0
12:10:32.086 stderr output from native app com.connective.signer: OUT {"error": {"code": 5, "id": 5, "message": "Error reading file (Comm 0x6a87) (0xa4080c)"}}

As in my previous report I can reproduce the error when using protocoltest.html when clicking again on "read_file" just after the output appears but before the last cardreader activity ceases

12:13:08.138 stderr output from native app com.connective.signer: read file 12:13:08.226 stderr output from native app com.connective.signer: sw1 0x90 sw2 0x 0 data length 252 12:13:08.253 stderr output from native app com.connective.signer: sw1 0x69 sw2 0x86 data length 0 12:13:08.551 stderr output from native app com.connective.signer: OUT {"error": {"code": 5, "id": 5, "message": "Error reading file (Comm 0x6a87) (0xa4080c)"}}

The 4 reads that are successfull from the Itsme website (identical output from protocoltest.html) :

file14031 12:05:11.877 stderr output from native app com.connective.signer: read file
12:05:11.886 stderr output from native app com.connective.signer: sw1 0x6c sw2 0xa9 data length 0
12:05:12.147 stderr output from native app com.connective.signer: OUT {"data": file14032 12:04:21.294 stderr output from native app com.connective.signer: read file
12:04:21.385 stderr output from native app com.connective.signer: sw1 0x90 sw2 0x 0 data length 252
12:04:21.392 stderr output from native app com.connective.signer: sw1 0x6c sw2 0x 4 data length 0
12:04:21.606 stderr output from native app com.connective.signer: OUT {"data":
file14033 12:03:17.880 stderr output from native app com.connective.signer: read file
12:03:17.890 stderr output from native app com.connective.signer: sw1 0x6c sw2 0x79 data length 0
12:03:18.136 stderr output from native app com.connective.signer: OUT {"data": file14034 12:02:15.733 stderr output from native app com.connective.signer: read file
12:02:15.821 stderr output from native app com.connective.signer: sw1 0x90 sw2 0x 0 data length 252
12:02:15.831 stderr output from native app com.connective.signer: sw1 0x6c sw2 0x 4 data length 0
12:02:16.044 stderr output from native app com.connective.signer: OUT {"data":

The example command "read_file" on the protocoltest.html generates 7 'similar' messages .... stderr output from native app com.connective.signer: read file

stderr output from native app com.connective.signer: sw1 0x90 sw2 0x 0 data length 252 7 stderr output from native app com.connective.signer: sw1 0x6c sw2 0x88 data length 0 stderr output from native app com.connective.signer: OUT {"data":

roelderickx commented 11 months ago

As you have guessed in your first message file 4035 is the photo. It is common to have multiple blocks of 252 bytes (sw1=0x90, sw2=0x00) and then another block with the remaining bytes (sw1=0x6C, sw2=amount of bytes remaining). The data is subsequently fetched but I didn't log that, in your example the photo is 12*252 + 2 = 3026 bytes.

When you try fetching the photo on the itsme site the card is returning 1 block of 252 bytes and then code 0x69/0x86, which means "Command not allowed (no current EF)" according to the documentation. Really strange, since right before reading the file we selected the file using the given EF. That call must have returned a 0x90/0x00 (ok) status and as such an active EF, otherwise read file wouldn't have started.

That being said, I can replicate the 0x69/0x86 error when clicking twice in a row in the protocol tester, as you suggested. It implies the card reader is still processing the previous file while starting to read the photo, although from the log in your first message it does not seem to run simultaneously.

If itsme is waiting for a response before starting a new request, and if the new request is idd starting too fast, I propose to try sleeping 100ms before sending the response. That gives the card reader the time to finalize the connection before itsme spawns a new request. I modified it in the extralogging branch, can you test again? You can increase the sleeping time on line 990 if you think it may help, but beyond 0.5 it will be really slow :slightly_smiling_face:

I'm sorry this will be a trial-and-error approach and may take a while to get resolved, but in the protocoltester everything seems to work fine so I am confident we can make it work on the itsme site too.

LauryChaerle commented 10 months ago

I succeeded in activating my Itsme account with the latest version and the delay increased to 1 second (sorry for the late report). However several tries are still needed to achieve success.

I started out with the new version with 100ms delay. To my surprise the procedure on the Itsme website blocked consistently at file 4032, and not later at the larger 4035 as before. Increasing the delay to 500ms or decreasing seemingly had no effect. Hence I rebooted and reverted to the original version: same result (block at 4032) New version 100ms delay, idem block at 4032 always the same OUT {"error": {"code": 5, "id": 5, "message": "Error reading file (Comm 0x6a87) (0xa4080c)"}} Increase to 500ms: now sometimes progressing to 4034 (still not 4035) 800ms: 4035 now sometimes OK but now blocking at "fileId":"3F00DF00503C" (RN certificate) 1sec: RN read sometimes successfull (4 x 252): info + foto on screen in Itsme website 17:31:28.257 stderr output from native app com.connective.signer: read file 17:31:28.345 stderr output from native app com.connective.signer: sw1 0x90 sw2 0x 0 data length 252 4 17:31:28.616 stderr output from native app com.connective.signer: sw1 0x6c sw2 0xc7 data length 0 17:31:29.888 stderr output from native app com.connective.signer: OUT {"data":

I didn't immediately get further because the Tk window for PIN entry failed to appear Opening the protocoltest.html and GET_PIN showed the entry window, thereafter the procedure on the Itsme website also -always- launched the PIN entry window (coincidence?)

In the subsequent step on the Itsme window (signing) the file access again sometimes blocked, but after a few trials I got finally through.

As this is a once-to-follow step, and maybe/likely cardreader-linked, I'm happy I got through without having to install windows in a VM Thanks for your help with this issue!

roelderickx commented 10 months ago

Thanks for the heads up, I am happy to hear it succeeded.

I gave it some thought and it may be because I am initializing the card on each call, something the official connective plugin doesn't do. Almost all card readers can handle this but apparently yours doesn't (I assume it is the reader to blame, not the card itself).

You probably don't need this application anymore since you succeeded in creating an itsme account, so I will close the issue for now. Feel free to reopen if you want me to try suppressing the card initialization on each call.

LauryChaerle commented 9 months ago

Thanks for the follow-up A late reply: if there would still be related issues coming up, I'm willing to test in the future if it could be helpfull

De: "Roel Derickx" @.> À: "roelderickx" @.> Cc: "laury" @.>, "Author" @.> Envoyé: Vendredi 13 Octobre 2023 16:59:33 Objet: Re: [roelderickx/connective-plugin-linux] Itsme / protocol tester {"error": {"code": 5, "id": 5, "message": "Error reading file (Comm 0x6a87) (0xa4080c)"}} (Issue #15)

Thanks for the heads up, I am happy to hear it succeeded.

I gave it some thought and it may be because I am initializing the card on each call, something the official connective plugin doesn't do. Almost all card readers can handle this but apparently yours doesn't (I assume it is the reader to blame, not the card itself).

You probably don't need this application anymore since you succeeded in creating an itsme account, so I will close the issue for now. Feel free to reopen if you want me to try suppressing the card initialization on each call.

— Reply to this email directly, [ https://github.com/roelderickx/connective-plugin-linux/issues/15#issuecomment-1761663805 | view it on GitHub ] , or [ https://github.com/notifications/unsubscribe-auth/BCNLVZ6LLEFJEJST7BQWXTDX7FJNLAVCNFSM6AAAAAA4PC6N3OVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTONRRGY3DGOBQGU | unsubscribe ] . You are receiving this because you authored the thread. Message ID: @.***>