Bug 1821924 - Network Manager cannot connect with EAP-TLS using PKCS11 Private Key
Summary: Network Manager cannot connect with EAP-TLS using PKCS11 Private Key
Keywords:
Status: CLOSED EOL
Alias: None
Product: Fedora
Classification: Fedora
Component: NetworkManager
Version: 32
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Lubomir Rintel
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2020-04-07 20:29 UTC by nicolasoliver03
Modified: 2021-05-25 15:54 UTC (History)
13 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2021-05-25 15:54:17 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
Output of journalctl for pkcs11 connection (276.34 KB, text/plain)
2020-04-07 20:29 UTC, nicolasoliver03
no flags Details

Description nicolasoliver03 2020-04-07 20:29:12 UTC
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

Comment 1 David Woodhouse 2020-04-07 21:38:15 UTC
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=

Comment 2 nicolasoliver03 2020-04-08 18:22:46 UTC
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?

Comment 3 nicolasoliver03 2020-04-10 17:20:43 UTC
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

Comment 4 Fedora Program Management 2021-04-29 16:17:27 UTC
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.

Comment 5 Ben Cotton 2021-05-25 15:54:17 UTC
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.


Note You need to log in before you can comment on or make changes to this bug.