an issue with macsec key agreement (machine falling out of sync?)

Wed Feb 21 08:34:21 PST 2024

Hello,

Before I will probably have to bury this macsec project at work I want
to report what appears to be a bug to me in wpa_supplicant's macsec key
agreement (MKA) implementation:

I have 3 machines: ed0, ed1 and ed2, they all share the same
wpa_supplicant.conf with the same values for MKA pre-shared keys and
systemd unit that starts wpa_supplicant.

Sometimes when I reboot all machines it works fine on start up, when I
ping the IPv6 link local multicast address ff02::1%macsec0 I get
response packets from all three machines:

ed0# ping ff02::1%macsec0
PING ff02::1%macsec0(ff02::1%macsec0) 56 data bytes
64 bytes from fe80::4801:e9ff:fe34:a268%macsec0: icmp_seq=1 ttl=64 time=0.117 ms
64 bytes from fe80::747f:28ff:fedc:abaa%macsec0: icmp_seq=1 ttl=64 time=2.85 ms (DUP!)
64 bytes from fe80::60a2:b8ff:fe98:ad8f%macsec0: icmp_seq=1 ttl=64 time=4.67 ms (DUP!)
^C

Other times one of the machines seems to have issues with key agreement
despite having the same shared key as the other machines (i.e. only one
DUP! response on pinging the multicast address):

$ ssh ed1
Warning: Permanently added 'fe80::4801:e9ff:fe34:a268%eno1' (ED25519) to the list of known hosts.
ed1# ping ff02::1%macsec0
PING ff02::1%macsec0(ff02::1%macsec0) 56 data bytes
64 bytes from fe80::4801:e9ff:fe34:a268%macsec0: icmp_seq=1 ttl=64 time=0.112 ms
64 bytes from fe80::60a2:b8ff:fe98:ad8f%macsec0: icmp_seq=1 ttl=64 time=4.89 ms (DUP!) <--- second DUP! from the 3rd machine is missing
64 bytes from fe80::4801:e9ff:fe34:a268%macsec0: icmp_seq=2 ttl=64 time=0.098 ms
64 bytes from fe80::60a2:b8ff:fe98:ad8f%macsec0: icmp_seq=2 ttl=64 time=2.69 ms (DUP!)
^C
--- ff02::1%macsec0 ping statistics ---
2 packets transmitted, 2 received, +2 duplicates, 0% packet loss, time 1001ms
rtt min/avg/max/mdev = 0.098/1.947/4.890/1.999 ms
ed1# systemctl status wpa_supplicant
● wpa_supplicant.service - WPA supplicant
     Loaded: loaded (/lib/systemd/system/wpa_supplicant.service; enabled; vendor preset: disabled)
     Active: active (running) since Sat 2024-02-10 16:07:19 UTC; 20s ago
   Main PID: 496 (wpa_supplicant)
      Tasks: 1 (limit: 404)
     Memory: 4.9M
     CGroup: /system.slice/wpa_supplicant.service
             └─496 /usr/sbin/wpa_supplicant -u -i br0 -Dmacsec_linux -c /etc/wpa_supplicant.conf

Feb 10 16:07:19 hostname systemd[1]: Starting WPA supplicant...
Feb 10 16:07:19 hostname wpa_supplicant[496]: Successfully initialized wpa_supplicant
Feb 10 16:07:19 hostname systemd[1]: Started WPA supplicant.
Feb 10 16:07:20 hostname wpa_supplicant[496]: br0: Associated with 01:80:c2:00:00:03
Feb 10 16:07:20 hostname wpa_supplicant[496]: br0: CTRL-EVENT-CONNECTED - Connection to 01:80:c2:00:00:03 completed [id=0 id_str=]
Feb 10 16:07:20 hostname wpa_supplicant[496]: br0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Feb 10 16:07:26 hostname wpa_supplicant[496]: KaY: duplicated SCI detected - maybe active attacker or peer selected new MI - ignore MKPDU
Feb 10 16:07:28 hostname wpa_supplicant[496]: KaY: duplicated SCI detected - maybe active attacker or peer selected new MI - ignore MKPDU
Feb 10 16:07:30 hostname wpa_supplicant[496]: KaY: duplicated SCI detected - maybe active attacker or peer selected new MI - ignore MKPDU
Feb 10 16:07:33 hostname wpa_supplicant[496]: KaY: Life time has not elapsed since prior SAK distributed
ed1# logout
Connection to fe80::4801:e9ff:fe34:a268%eno1 closed.

$ ssh ed2
Warning: Permanently added 'fe80::60a2:b8ff:fe98:ad8f%eno1' (ED25519) to the list of known hosts.
ed2# systemctl status wpa_supplicant
● wpa_supplicant.service - WPA supplicant
     Loaded: loaded (/lib/systemd/system/wpa_supplicant.service; enabled; vendor preset: disabled)
     Active: active (running) since Sat 2024-02-10 16:01:48 UTC; 47s ago
   Main PID: 496 (wpa_supplicant)
      Tasks: 1 (limit: 404)
     Memory: 4.8M
     CGroup: /system.slice/wpa_supplicant.service
             └─496 /usr/sbin/wpa_supplicant -u -i br0 -Dmacsec_linux -c /etc/wpa_supplicant.conf

Feb 10 16:01:47 hostname systemd[1]: Starting WPA supplicant...
Feb 10 16:01:48 hostname wpa_supplicant[496]: Successfully initialized wpa_supplicant
Feb 10 16:01:48 hostname systemd[1]: Started WPA supplicant.
Feb 10 16:01:48 hostname wpa_supplicant[496]: br0: Associated with 01:80:c2:00:00:03
Feb 10 16:01:48 hostname wpa_supplicant[496]: br0: CTRL-EVENT-CONNECTED - Connection to 01:80:c2:00:00:03 completed [id=0 id_str=]
Feb 10 16:01:48 hostname wpa_supplicant[496]: br0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Feb 10 16:01:54 hostname wpa_supplicant[496]: KaY: duplicated SCI detected - maybe active attacker or peer selected new MI - ignore MKPDU
Feb 10 16:01:56 hostname wpa_supplicant[496]: KaY: duplicated SCI detected - maybe active attacker or peer selected new MI - ignore MKPDU
ed2# logout
Connection to fe80::60a2:b8ff:fe98:ad8f%eno1 closed.

$ ssh ed0
Warning: Permanently added 'fe80::747f:28ff:fedc:abaa%eno1' (ED25519) to the list of known hosts.
ed0# systemctl status wpa_supplicant
● wpa_supplicant.service - WPA supplicant
     Loaded: loaded (/lib/systemd/system/wpa_supplicant.service; enabled; vendor preset: disabled)
     Active: active (running) since Sat 2024-02-10 16:07:00 UTC; 54s ago
   Main PID: 495 (wpa_supplicant)
      Tasks: 1 (limit: 404)
     Memory: 4.8M
     CGroup: /system.slice/wpa_supplicant.service
             └─495 /usr/sbin/wpa_supplicant -u -i br0 -Dmacsec_linux -c /etc/wpa_supplicant.conf

Feb 10 16:07:06 hostname wpa_supplicant[495]: KaY: The peer (73cec9c3a974289e25a335a4) is not my live peer - ignore MACsec SAK Use param>
Feb 10 16:07:06 hostname wpa_supplicant[495]: KaY: Discarding Rx MKPDU: decode of parameter set type (3) failed
Feb 10 16:07:06 hostname wpa_supplicant[495]: KaY: The peer (73cec9c3a974289e25a335a4) is not my live peer - ignore MACsec SAK Use param>
Feb 10 16:07:06 hostname wpa_supplicant[495]: KaY: Discarding Rx MKPDU: decode of parameter set type (3) failed
Feb 10 16:07:07 hostname wpa_supplicant[495]: KaY: The peer (73cec9c3a974289e25a335a4) is not my live peer - ignore MACsec SAK Use param>
Feb 10 16:07:07 hostname wpa_supplicant[495]: KaY: Discarding Rx MKPDU: decode of parameter set type (3) failed
Feb 10 16:07:09 hostname wpa_supplicant[495]: KaY: The peer (73cec9c3a974289e25a335a4) is not my live peer - ignore MACsec SAK Use param>
Feb 10 16:07:09 hostname wpa_supplicant[495]: KaY: Discarding Rx MKPDU: decode of parameter set type (3) failed
Feb 10 16:07:11 hostname wpa_supplicant[495]: KaY: The peer (73cec9c3a974289e25a335a4) is not my live peer - ignore MACsec SAK Use param>
Feb 10 16:07:11 hostname wpa_supplicant[495]: KaY: Discarding Rx MKPDU: decode of parameter set type (3) failed

^^^^ seems to me that the culprit in this case is ed0 that somehow fell
out of sync with the others if I'm reading this right, but I didn't
write this software so perhaps you tell me :)

Are you aware of/have you encountered this issue before? Is there any
known solution/software version where it's fixed?

Here's some more context and diagnostical info:

ed0# wpa_supplicant -v
wpa_supplicant v2.10
Copyright (c) 2003-2022, Jouni Malinen <j at w1.fi> and contributors

ed0# uname -a
Linux hostname 5.4.24 #1 SMP PREEMPT Thu Oct 7 08:39:19 UTC 2021 aarch64 aarch64 aarch64 GNU/Linux

ed0# cat /sys/class/net/br0/bridge/group_fwd_mask 
0x8

ed0# cat /etc/wpa_supplicant.conf 
ctrl_interface=/var/run/wpa_supplicant
eapol_version=3
ap_scan=0
fast_reauth=1

network={
        key_mgmt=NONE
        eapol_flags=0
        macsec_policy=1

        mka_cak=35659df249c7c90fcaeb675ef59eb783
        mka_ckn=83f447da8078c18a7bae35851a0349384e9da84ab45a705f304731f3dc7fee
}

The file is left as copied from the [RedHat introduction][1] with some
keys filled in where they belong and then copied identically to all
three machines.

Sorry I had to edit the logs to remove the hostname, I've signed an NDA.

Best regards,

Moritz

[1]: https://developers.redhat.com/blog/2017/06/28/whats-new-in-macsec-setting-up-macsec-using-wpa_supplicant-and-optionally-networkmanager#