Created attachment 1677076 [details] Output of journalctl for pkcs11 connection Description of problem: Network Manager cannot connect with EAP-TLS using PKCS11 Private Key Version-Release number of selected component (if applicable): [root@localhost test]# rpm-ostree status State: idle AutomaticUpdates: disabled Deployments: * ostree://fedora-iot:fedora/devel/x86_64/iot Version: 32.20200406.0 (2020-04-06T17:10:41Z) BaseCommit: 659968ae6c6685bfa02731cb91e2c19ff54c23570c36b886f2e1be1379e9d1fd GPGSignature: Valid signature by 97A1AE57C3A2372CCA3A4ABA6C13026D12C944D0 LayeredPackages: bzip2 cockpit cockpit-ostree cockpit-selinux git gnutls-utils nano openvpn tpm2-pkcs11 tpm2-pkcs11-tools tpm2-tss-engine udisks2 [root@localhost test]# rpm -qa NetworkManger wpa_supplicant gnutls-utils tpm2-tss tpm2-tools tpm2-pkcs11 tpm2-pkcs11-tools tpm2-tss-engine tpm2-tss-engine-1.0.1-2.fc32.x86_64 tpm2-tools-4.1-2.fc32.x86_64 wpa_supplicant-2.9-3.fc32.x86_64 gnutls-utils-3.6.13-1.fc32.x86_64 tpm2-pkcs11-tools-1.2.0-1.fc32.x86_64 tpm2-pkcs11-1.2.0-1.fc32.x86_64 tpm2-tss-2.4.0-1.fc32.x86_64 How reproducible: The following configuration for wpa_supplicant works: [root@localhost ~]# cat wpa_supplicant.conf network={ ssid="PKCS11WIFITEST" key_mgmt=WPA-EAP eap=TLS identity="testing" ca_cert="./ca.pem" client_cert="./client-pkcs11.crt" private_key="pkcs11:model=Intel;manufacturer=Intel;serial=0000000000000000;token=label;id=%65%63%62%32%65%66%37%39%32%35%61%64%31%34%36%32;type=private;pin-value=myuserpin" } [root@localhost ~]# wpa_supplicant -c wpa_supplicant.conf -i wlp1s0 Successfully initialized wpa_supplicant nl80211: Could not set interface 'p2p-dev-wlp1s0' UP nl80211: deinit ifname=p2p-dev-wlp1s0 disabled_11b_rates=0 p2p-dev-wlp1s0: Failed to initialize driver interface P2P: Failed to enable P2P Device interface wlp1s0: SME: Trying to authenticate with 1c:87:2c:6a:c3:80 (SSID='PKCS11WIFITEST' freq=2417 MHz) wlp1s0: Trying to associate with 1c:87:2c:6a:c3:80 (SSID='PKCS11WIFITEST' freq=2417 MHz) wlp1s0: Associated with 1c:87:2c:6a:c3:80 wlp1s0: CTRL-EVENT-EAP-STARTED EAP authentication started wlp1s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 wlp1s0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=4 -> NAK wlp1s0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=13 wlp1s0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 13 (TLS) selected wlp1s0: CTRL-EVENT-EAP-PEER-CERT depth=1 subject='/C=FR/ST=Radius/L=Somewhere/O=Example Inc./emailAddress=admin/CN=Example Certificate Authority' hash=b871b58415355f1b171512787530b07f5370e34e0330b5fb95b5b76c4e42cdbc wlp1s0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/C=FR/ST=Radius/O=Example Inc./CN=Example Server Certificate/emailAddress=admin' hash=58dd55a34a0c518dba5984191b2e9c527f05fd5d4d8e56ba9b2d5b6a83a30e24 wlp1s0: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully wlp1s0: PMKSA-CACHE-ADDED 1c:87:2c:6a:c3:80 0 wlp1s0: WPA: Key negotiation completed with 1c:87:2c:6a:c3:80 [PTK=CCMP GTK=CCMP] wlp1s0: CTRL-EVENT-CONNECTED - Connection to 1c:87:2c:6a:c3:80 completed [id=0 id_str=] But the same configuration for NetworkManager in the same host does not work: nmcli c add type wifi ifname wlp1s0 con-name 'PKCS11WIFITEST' \ 802-11-wireless.ssid PKCS11WIFITEST \ 802-11-wireless-security.key-mgmt wpa-eap \ 802-1x.eap tls \ 802-1x.identity testing \ 802-1x.ca-cert /etc/pki/PKCS11WIFITEST/ca.pem \ 802-1x.client-cert /etc/pki/PKCS11WIFITEST/client-pkcs11.crt \ 802-1x.private-key 'pkcs11:model=Intel;manufacturer=Intel;serial=0000000000000000;token=label;id=%65%63%62%32%65%66%37%39%32%35%61%64%31%34%36%32;type=private;pin-value=myuserpin' [root@localhost ~]# nmcli connection up PKCS11WIFITEST Error: Connection activation failed: Secrets were required, but not provided Hint: use 'journalctl -xe NM_CONNECTION=bd8be689-9459-419b-a627-b63c2310de11 + NM_DEVICE=wlp1s0' to get more details. Attached is the journal output for NetworkManager and WPA_Supplicant. An interesting part of that log is pasted below: Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: wlp1s0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=13 Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: EAP: Status notification: accept proposed method (param=TLS) Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: EAP: Initialize selected EAP method: vendor 0 method 13 (TLS) Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: TLS: using phase1 config options Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: tls_connection_set_params: Clearing pending SSL error: error:26096080:engine routines:ENGINE_load_private_key:failed loading private key Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: SSL: Initializing TLS engine Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: ENGINE: engine initialized Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: ERROR: Cannot open database: unable to open database file Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: Failed to enumerate slots Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: ERROR: Cannot open database: unable to open database file Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: Failed to enumerate slots Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: PKCS11_get_private_key returned NULL Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: ENGINE: cannot load private key with id 'pkcs11:model=Intel;manufacturer=Intel;serial=0000000000000000;token=label;id=%65%63%62%32%65%66%37%39%32%35%61%64%31%34%36%32;type=private;pin-value=myuserpin?pin-value=' [error:80067065:pkcs11 engine:ctx_load_privkey:object not found] Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: TLS: Failed to initialize engine Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: TLS: Failed to set TLS connection parameters Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: ENGINE: engine deinit Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: EAP-TLS: Failed to initialize SSL. Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: EAP-TLS: Requesting private key passphrase Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: EAPOL: EAP parameter needed Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: wlp1s0: CTRL-REQ-PASSPHRASE-0:Private key passphrase needed for SSID PKCS11WIFITEST Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: wlp1s0: EAP: Failed to initialize EAP method: vendor 0 method 13 (TLS) Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: EAP: Pending PIN/passphrase request - skip Nak Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: EAP: EAP entering state SEND_RESPONSE Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: EAP: No eapRespData available Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: EAP: EAP entering state IDLE Apr 07 13:20:57 localhost.localdomain wpa_supplicant[993]: EAPOL: startWhen --> 0 Seems like it is failing to access the engine database. Additionally, the pin-value seems to ignored resulting in a ";pin-value=myuserpin?pin-value=" URI termination. Steps to Reproduce: 1. Setup a EAP-TLS connection with a PKCS11 private key with Network Manager CLI 2. Start the connection Actual results: Connection cannot be stablished Expected results: Connection stablished Additional info: Works with wpa_supplicant and eapol_test
Apr 07 13:20:55 localhost.localdomain wpa_supplicant[993]: ENGINE: cannot load private key with id 'pkcs11:model=Intel;manufacturer=Intel;serial=0000000000000000;token=label;id=%65%63%62%32%65%66%37%39%32%35%61%64%31%34%36%32;type=private;pin-value=myuserpin?pin-value= Seems NM added a second empty pin-value=
After some additional debugging, I got a connection successfully activated! and was able to identify some root causes... The tpm2-software team proposed that there may be permissions problems to access the db and tpm, given that NM runs as a service. To avoid any permission problems, I just stopped the NetworkManager and wpa_supplicant services and run them manually as root. systemctl stop NetworkManager systemctl stop wpa_supplicant /usr/sbin/NetworkManager --no-daemon --log-level=TRACE export TPM2TOOLS_TCTI="device:/dev/tpmrm0" export TPM2_PKCS11_TCTI="device:/dev/tpmrm0" export TPM2_PKCS11_LOG_LEVEL=2 source /etc/sysconfig/wpa_supplicant /usr/sbin/wpa_supplicant -c /etc/wpa_supplicant/wpa_supplicant.conf -u $INTERFACES $DRIVERS $OTHER_ARGS First, the errors I see about "cannot open database" are because the engine searches in the default directory (/root/.tpm2_pkcs11/tpm2_pkcs11.sqlite3), fails, and falls back to /root/tpm2_pkcs11.sqlite3. After using the TPM2_PKCS11_STORE=/root env var, the error log disappear. export TPM2_PKCS11_STORE=/root /usr/sbin/wpa_supplicant -c /etc/wpa_supplicant/wpa_supplicant.conf -u $INTERFACES $DRIVERS $OTHER_ARGS Then, I tried activating the connection again. I had the PKCS debug log enabled, and I could see that wpa_supplicant was hitting the engine. Then, wpa_supplicant prints the following errors on connection activation The key ID is not a valid PKCS#11 URI The PKCS#11 URI format is defined by RFC7512 The key ID is not a valid PKCS#11 URI The PKCS#11 URI format is defined by RFC7512 PKCS11_get_private_key returned NULL I inspected a little bit the code of NetworkManager (https://github.com/NetworkManager/NetworkManager/blob/bddba4ca8b17286f4851078d37cf4359b05af5b8/src/supplicant/nm-supplicant-config.c#L988), and it apparently does some mangling with the user provided URI before passing that to wpa_supplicant. The problem is that NetworkManager does not take into account the pin-value attribute in the URI. And it adds an empty pin value at the end as an URI attribute, and that’s why I see "pkcs11:..;...;...;pin-value=myuserpin?pin-value=". So apparently the NM generated URI is invalid. I removed the pin-value from the configured URI. Activated the connection again. I was expecting nmcli to ask me for the PIN (with --ask option), but it is the wpa_supplicant process who is stopped asking for the pin. I input the pin in the wpa_supplicant process prompt, and I got the connection activated. After this initial activation, then wpa_supplicant does not ask for the pin anymore until I kill the process and start again. Maybe there is some cache mechanism in NetworkManager or wpa_supplicant for pins NM seems to be incapable of asking for the pin. So, to configure the pin,I tried the following: 1. set 802-1x.pin -> Ignored, and I get the prompt again in the wpa_supplicant process 2. set 802-1x.private-key-password: Ignored again. There are some ifs in the NetworkManager code for pin-flags, I tried to brute force them to get a PIN passed to wpa_supplicant 1. set 802-1x.pin-flags agent-owned: pin ignored 2. set 802-1x.pin-flags none: pin ignored 3. set 802-1x.pin-flags not-required: pin ignored 4. set 802-1x.pin-flags not-saved: pin ignored 5. Tried doing the same brute force for 802-1x.private-key-password-flags but I started getting core dumps So, problems: 1. The PIN in the URI is ignored. NM adds that pin-value attribute, and ends up with a malformed URI. Workaround: remove pin from URI 2. After (1), the PIN is required as user input, but NM does not ask for the pin, and there is no way to passing the PIN to wpa_supplicant when it is running as a service 3. There is no apparent way of setting the PIN in the connection configuration. 802-1x.pin gets ignored, 802-1x.private-key-password get ignored, and no idea what is the behaviour of the flags. 4. Will need to verify permission problems once I am able to run this as services (depends on 2 and 3) I think that this configuration should work and pass the pin correctly, but NM does not think so: nmcli c add type wifi ifname wlp1s0 con-name 'PKCS11WIFITEST' \ 802-11-wireless.ssid PKCS11WIFITEST \ 802-11-wireless-security.key-mgmt wpa-eap \ 802-1x.eap tls \ 802-1x.identity testing \ 802-1x.ca-cert /etc/pki/PKCS11WIFITEST/ca.pem \ 802-1x.client-cert /etc/pki/PKCS11WIFITEST/client-pkcs11.crt \ 802-1x.private-key 'pkcs11:model=Intel;manufacturer=Intel;serial=0000000000000000;token=label;id=%65%63%62%32%65%66%37%39%32%35%61%64%31%34%36%32;type=private' \ 802-1x.pin 'myuserpin' any hints?
The following configuration works: nmcli c add type wifi ifname wlp1s0 con-name 'PKCS11WIFITEST' \ connection.autoconnect no \ ipv4.ignore-auto-routes yes \ ipv4.ignore-auto-dns yes \ 802-11-wireless.ssid PKCS11WIFITEST \ 802-11-wireless-security.key-mgmt wpa-eap \ 802-1x.eap tls \ 802-1x.identity testing \ 802-1x.ca-cert /root/ca.pem \ 802-1x.client-cert /root/client.crt \ 802-1x.private-key 'pkcs11:model=Intel;manufacturer=Intel;serial=0000000000000000;token=label;id=%65%31%30%35%65%30%39%30%36%39%61%63%32%30%31%36;type=private;pin-value=myuserpin' \ 802-1x.private-key-password-flags 4 The "802-1x.private-key-password-flags 4" prevents the mangling of the URI. This LOC explains it https://gitlab.freedesktop.org/NetworkManager/NetworkManager/-/blob/1.22.10/src/supplicant/nm-supplicant-config.c#L1010 /* Fill in the PIN if required. */ if (pin) { escaped = g_uri_escape_string (pin, NULL, TRUE); pin_qattr = g_strdup_printf ("pin-value=%s", escaped); g_free (escaped); } else if (!(pin_flags & NM_SETTING_SECRET_FLAG_NOT_REQUIRED)) { /* Include an empty PIN to indicate the login is still needed. * Probably a token that has a PIN path and the actual PIN will * be entered using a protected path. */ pin_qattr = g_strdup ("pin-value="); } If that flag is not passed, then NetworkManager will append the "?pin-value=" attr, resulting in a URI that wpa_supplicant consider malformed. The first problem I noticed is that, the code above always goes to the "else if" statement. The PIN is always empty! I tried 2 ways of setting the PIN: using 802-1x.pin, and 802-1x.private-key-password. The fact is that using 802-1x.pin is not correct, and this was very unintuitive! The docs in https://developer.gnome.org/NetworkManager/stable/nm-settings.html says that 802-1x.pin is the "PIN used for EAP authentication methods.", so one would guess that it will be used as the PIN attr, but no In https://gitlab.freedesktop.org/NetworkManager/NetworkManager/-/blob/1.22.10/src/supplicant/nm-supplicant-config.c#L1341, the "add_pkcs11_uri_with_pin" function gets called, with 802-1x.private-key-password as the PIN attribute. So the correct way of passing the PIN is using 802-1x.private-key-password. case NM_SETTING_802_1X_CK_SCHEME_PKCS11: if (!add_pkcs11_uri_with_pin (self, "private_key", nm_setting_802_1x_get_private_key_uri (setting), nm_setting_802_1x_get_private_key_password (setting), nm_setting_802_1x_get_private_key_password_flags (setting), error)) { return FALSE; } Now, using 802-1x.private-key-password did not solve the problem. Regardless of what I set in that property, the PIN arrives empty to the function above. So I think there is something here that is not working properly and just ignores the 802-1x.private-key-password parameter. If I remove the "802-1x.private-key-password-flags 4" property, NetworkManager should add that "?pin-value=" attr, and ask my for the PIN (a.k.a private-key-password)! but for some reason, the PIN prompt appears in the wpa_supplicant process, and I get no prompt in the nmcli connection (with or without --ask option) In summary: 1. BUG 1: 802-1x.private-key-password is ignored 2. BUG 2: nmcli does not ask for the PIN (a.k.a private-key-password) 3. BUG 3: documentation of 802-1x.pin is poor and misleading
This message is a reminder that Fedora 32 is nearing its end of life. Fedora will stop maintaining and issuing updates for Fedora 32 on 2021-05-25. It is Fedora's policy to close all bug reports from releases that are no longer maintained. At that time this bug will be closed as EOL if it remains open with a Fedora 'version' of '32'. Package Maintainer: If you wish for this bug to remain open because you plan to fix it in a currently maintained version, simply change the 'version' to a later Fedora version. Thank you for reporting this issue and we are sorry that we were not able to fix it before Fedora 32 is end of life. If you would still like to see this bug fixed and are able to reproduce it against a later version of Fedora, you are encouraged change the 'version' to a later Fedora version prior this bug is closed as described in the policy above. Although we aim to fix as many bugs as possible during every release's lifetime, sometimes those efforts are overtaken by events. Often a more recent Fedora release includes newer upstream software that fixes bugs or makes them obsolete.
Fedora 32 changed to end-of-life (EOL) status on 2021-05-25. Fedora 32 is no longer maintained, which means that it will not receive any further security or bug fix updates. As a result we are closing this bug. If you can reproduce this bug against a currently maintained version of Fedora please feel free to reopen this bug against that version. If you are unable to reopen this bug, please file a new report against the current release. If you experience problems, please add a comment to this bug. Thank you for reporting this bug and we are sorry it could not be fixed.