NoMoreFood
PKCS#11 fails intermittently on Windows 10 with "sign_and_send_pubkey: signing failed for RSA "..." from agent: incomplete message"
I'm not sure if this is an issue with Pageant/Putty or OpenSC. I'm on Windows 10 and using putty-cac 0.80 with OpenSC 0.24.0.
The idea is to use a hard token with agent-forwarding to SSH from the Windows machine to server A into server B. Most of the time, it works fine, but intermittently, it reaches a state where trying to connect to server B fails with this error message (usually after prompting for the PIN) -
sign_and_send_pubkey: signing failed for RSA "PKCS:...=C:\\Program Files\\OpenSC Project\\OpenSC\\pkcs11\\opensc-pkcs11.dll" from agent: incomplete message
Output from ssh-add -L on server A is the same regardless of whether it's working or not. Neither disconnecting from A and reconnecting, nor removing the PKCS cert from Pageant and solves the issue. Pageant has to be closed entirely on the Windows machine and then the cert re-added.
I don't believe this is a server-side issue, because once it reaches this failed state, I've tried multiple servers in the server A or server B role, and they all fail continuously until Pageant is restarted.
Are there any logs or any way of enabling debugging that I could use to provide more information? ssh -vvv doesn't give any more useful information aside from showing it working until it fails:
debug3: send packet: type 50
debug2: we sent a publickey packet, wait for reply
debug3: receive packet: type 60
debug1: Server accepts key: PKCS:...=C:\\Program Files\\OpenSC Project\\OpenSC\\pkcs11\\opensc-pkcs11.dll RSA SHA256:... agent
debug3: sign_and_send_pubkey: using publickey with RSA SHA256:...
debug3: sign_and_send_pubkey: signing using rsa-sha2-512 SHA256:...
sign_and_send_pubkey: signing failed for RSA "PKCS:...=C:\\Program Files\\OpenSC Project\\OpenSC\\pkcs11\\opensc-pkcs11.dll" from agent: incomplete message
It's likely not server side. Possible it's a bug with PuTTY, PuTTY CAC, or OpenSC. What sort of hardware token do you have?
Okay, I don't have that type of token but I can try reproducing the issue with the OpenSC library on another token (might be a few days). Is it possible for you to try using CAPI subsystem with the minidriver instead of the PKCS library? (https://fido.ftsafe.com/wp-content/uploads/2023/08/minidriver-2023-06-09.zip)
I need to do some reading but I believe so. It will be a few days on my side though too. Thanks for testing.
I can't find any reference on Feitan's site to those drivers, though they're clearly hosted by them. Can I ask what's the trail for finding the download? Thanks.
I got the download link from here: https://fido.ftsafe.com/piv-user-instruction/
@kayavila Did you have luck testing CAPI?
Would you say it's timing as anything to do with it? For example, is it more likely to occur if there are no transactions with the card for a certain period of time? We attempt to maintain a perpetual handle to the library in order to avoid unnecessary PIN prompts. It's possible that the connection is timing out.
Unforuately, I don't have a lot of logging setup in the PKCS/CAPI processing due to how the logging works in PuTTY. However, if we can narrow in on the likely culprit, I provide a popup message in a private build if an error occurs in a suspect area.
I haven't been able to get it to work with CAPI. I get prompted by the Windows UI to enter the smart card PIN, and then receive the same message from SSH (sign_and_send_pubkey: signing failed for RSA "CAPI:..." from agent: incomplete message).
Yes, my experience definitely correlates with the failed state happening if the connection has been idle for a while.
I've noticed that Pageant does crash on fairly regular basis as well, but this is mostly associated with the computer hibernating and then coming back awake.
If I provide a private build with some debug popups, would you be able to run that for me?
@kayavila Please try the attached binaries. They should make popup messages when an error occurs. I'd be most interested in the first messages when an error occurs. If you get them when things, are working "normally", let me know and I may have to remove some just so you can operate.
puttycac-0.80u1.zip
puttycac-64bit-0.80u1.zip
Thanks for working on this. It didn't take too long for me to get a failed condition today. The error was cert_pkcs_sign:225:Login Error.
Did you get prompted for a PIN right before, were you using PIN caching, or did you just get the error (without PIN caching)?
Also, please try the attached. This should add an additional error code to the message that will help me decide how I think we should best handle the error.
puttycac-0.80u1.zip puttycac-64bit-0.80u1.zip
I believe I just got the error, but I will have to pay attention more closely next time. Just as a heads up, unfortunately I'm tied up for the next few days and may not be able to test until next week.
Alright. I'll actually be on travel all next week without access to my development system so no rush from my end. Based on where it's erroring out, either the cached PIN is getting corrupted (if you've enabled caching), the PIN isn't prompting properly (if you have caching disabled), or there's something internal to how OpenSC handles that token such that we might need to reestablish the connection to the library. I'm still waiting for Feitan to call me back and send me a free token but they are taking their time; I couldn't reproduce the behavior using a DoD CAC with the OpenSC PKCS #11 library.
Very interesting. I'm not sure about the PIN caching. I checked through the settings in Putty and Pageant and am not coming up with anything, except for the "Force PIN caching" setting in Pageant that's being referenced in another open ticket here. Is there somewhere else I should be looking?
Yes, I was referring to whether you have the "Force PIN caching" enabled or not.
Thanks. So, when the error occurs, are you prompted for a PIN before it errors or does it just error without asking for a PIN. The error code would be helpful so please pass it along whenever you get it.
I had a failed state today. The error was cert_pkcs_sign:228:Login error (5). I did not get prompted for a PIN, and I don't have "Force PIN caching" enabled.
Alright, I think we are getting closer. Apparently the PKCS code was errantly caching PINs regardless of that "Force PIN Caching" setting. That doesn't quite explain your issue (since the PIN caching ought to have worked), but I made it so it properly honors that setting now.
puttycac-64bit-0.80u1.zip puttycac-0.80u1.zip
Got an error with cert_pkcs_sign:228:Login Error (160) and immediately afterward, cert_pkcs_sign:229:Pin Length(x) where x was the correct length of my PIN.
@kayavila Alright error 160 is basically the "Incorrect PIN" so either it's getting corrupted or the library is rejecting it for some reason. This version adds some informational popups when a) adding something to the cache, b) retrieving something from the cache, and c) immediately before asking you for the PIN when not found in the cache. It also adds a popup that will show you the PIN it's about to pass into the PKCS library; the PIN shown in cleartext within single quotes. I would be interested in seeing if that value is accurate. Obviously you don't need to send me that screen shot, but please let me know if it's accurate and obviously make sure nobody is shoulder surfing when you authenticate.
Thanks for help debugging this through these multiple iterations; I am not the best remote debugger.
puttycac-0.80u1.zip puttycac-64bit-0.80u1.zip
I'm happy to help and appreciate you working on it. The value in the popup for my PIN was correct. Here's the pop-up order -
Prompting User For PIN!
cert_pkcs_sign:226:PIN Data: '...' (correct value)
cert_pkcs_sign:231:Login Error (5)
cert_pkcs_sign:232:Pin Length (x) (correct length)
I get the same error and order if I enter an invalid PIN.
When it's working properly - and this may be by design in how you have the pop-ups set up - I don't get the message with the pin length, just the first two messages. Thought I'd mention it just in case it's relevant.
Yeah, the PIN length messages are only set to popup when the login process fails. I'm about 90% sure this is some sort of bug or nuanced behavior in the OpenSC PKCS library. Before we resort to using PKCS spy, give this version a try. I definitely found an odd behavior when using my USAccess token and added some code to workaround it. I also removed the PIN displays since it seems we've established it's not a problem acquiring or passing the PIN.
puttycac-64bit-0.80u1.zip puttycac-0.80u1.zip