Troubleshooting Tip: Troubleshooting MAC filtering issues for Wi-Fi Users managed by FortiGate with FortiNAC acting as a RADIUS server

[pdhillon]

Description	This article describes the troubleshooting approach and debugging steps required to address MAC filtering issues for WIFI users on FortiGate.
Scope	FortiGate, FortiNAC.
Solution	In the following configuration, an access point is being managed by FortiGate. FortiNAC is acting as a RADIUS server and connected to FortiGate. FortiNAC is configured to control the MAC address database. Ideally, when a station tries connect to the SSID, FortiGate will send a RADIUS request and the RADIUS server will accept it. FortiGate should then allow the end user to connect to the network. The following debug commands are helpful to run in cases where issues are encountered with MAC filtering for Wi-Fi users: diagnose wireless-controller wlac sta_filter f8:89:d2:b9:48:f7 255 diagnose wpa wpad ha diagnose wireless-controller wlac -c was diagnose wireless-controller wlac -d sta online diagnose debug app wpad 7 Consider an example of an issue where attempting to do MAC filtering using FortiNAC breaks Wi-Fi connectivity for end clients. The STA (station) debug output indicates a RADIUS MAC authentication rejection, despite how the RADIUS server sent an acceptance packet. In this case, the FortiNAC device is configured with two locations for RADIUS server settings, but the customer mistakenly configured two different RADIUS secret keys in these locations. This inconsistency led to RADIUS authentication failures. The issue was resolved after correcting the RADIUS key in both configurations on the FortiNAC. 2024-03-20 14:09:38 61778.953 f8:89:d2:b9:48:f7 <eh> RADIUS message (type=0) ==> RADIUS Server code=1 (Access-Request) id=0 len=242 2024-03-20 14:09:39 61779.007 f8:89:d2:b9:48:f7 <eh> RADIUS message (type=0) <== RADIUS Server code=2 (Access-Accept) id=0 len=36 2024-03-20 14:09:42 66596.020 f8:89:d2:b9:48:f7 <ih> IEEE 802.11 mgmt::assoc_req <== f8:89:d2:b9:48:f7 ws (0-10.223.95.2:60418) vap test wifibridge rId 1 wId 0 84:39:8f:52:5d:e0 2024-03-20 14:09:42 66596.020 f8:89:d2:b9:48:f7 <ih> f8:89:d2:b9:48:f7 sta = 0x125c1f20, sta->flags = 0x00000001, auth_alg = 0, hapd->s plitMac: 1 2024-03-20 14:09:42 66596.020 f8:89:d2:b9:48:f7 cw_sta_load_chk ws (0-10.223.95.2:60418) rId 1 wId 0 sta f8:89:d2:b9:48:f7 2024-03-20 14:09:42 66596.020 f8:89:d2:b9:48:f7 cw_sta_load_chk ws (0-10.223.95.2:60418) vap (1, 0) RADIUS MAC AUTH REJECT sta f8:89:d2: >>>>> Radius mac auth reject b9:48:f7 2024-03-20 14:09:42 66596.020 f8:89:d2:b9:48:f7 <ih> IEEE 802.11 mgmt::assoc_resp ==> f8:89:d2:b9:48:f7 ws (0-10.223.95.2:60418) vap te stwifibridge rId 1 wId 0 84:39:8f:52:5d:e0 2024-03-20 14:09:42 66596.021 f8:89:d2:b9:48:f7 <ih> IEEE 802.11 mgmt::assoc_resp ==> f8:89:d2:b9:48:f7 ws (0-10.223.95.2:60418) vap tes twifibridge rId 1 wId 0 84:39:8f:52:5d:e0 2024-03-20 14:09:42 61782.020 f8:89:d2:b9:48:f7 <eh> RADIUS message (type=0) ==> RADIUS Server code=1 (Access-Request) id=1 len=242 2024-03-20 14:09:42 61782.120 f8:89:d2:b9:48:f7 <eh> RADIUS message (type=0) <== RADIUS Server code=2 (Access-Accept) id=1 len=36 2024-03-20 14:10:08 66622.944 f8:89:d2:b9:48:f7 <dc> STA chg f8:89:d2:b9:48:f7 vap testwifi ws (0-10.223.95.2:60417) rId 1 wId 0 b ssid 84:39:8f:52:60:00 Auth:deny 2024-03-20 14:10:12 66626.047 f8:89:d2:b9:48:f7 <dc> STA chg f8:89:d2:b9:48:f7 vap testwifi ws (0-10.223.95.2:60418) rId 1 wId 0 b ssid 84:39:8f:52:5d:e0 Auth:deny>>>>>>>>>>>>>>>>>>>>>>>>>>>>> Error Below is an illustration of functional debug outputs. Note that the MAC address and Access Point (AP) differ, and that these debug logs were collected from different devices and are provided here solely for demonstration purposes: > Working debugs -> Output from lab -> 72979.543 265 94:f6:d6:18:45:a2 <ih> IEEE 802.11 mgmt::assoc_req <== 94:f6:d6:18:45:a2 ws (0-10.10.200.4:5246) vap Taft-testing rId 0 wId 0 84:39:8f:0e:d6:91 72979.543 265 94:f6:d6:18:45:a2 <ih> 94:f6:d6:18:45:a2 sta = 0x91febb0, sta->flags = 0x00000001, auth_alg = 0, hapd->splitMac: 1 72979.543 265 94:f6:d6:18:45:a2 <ih> IEEE 802.11 mgmt::assoc_resp ==> 94:f6:d6:18:45:a2 ws (0-10.10.200.4:5246) vap Taft-testing rId 0 wId 0 84:39:8f:0e:d6:91 72979.543 265 94:f6:d6:18:45:a2 <ih> IEEE 802.11 mgmt::assoc_resp ==> 94:f6:d6:18:45:a2 ws (0-10.10.200.4:5246) vap Taft-testing rId 0 wId 0 84:39:8f:0e:d6:91 72979.543 265 94:f6:d6:18:45:a2 <dc> STA add 94:f6:d6:18:45:a2 vap Taft-testing ws (0-10.10.200.4:5246) rId 0 wId 0 bssid 84:39:8f:0e:d6:91 AUTH band 0x10 mimo 2*2 72979.543 265 94:f6:d6:18:45:a2 cwAcKernAddSta,6707 ws (0-10.10.200.4:5246) Taft-testing 94:f6:d6:18:45:a2 ret 0 72979.543 265 94:f6:d6:18:45:a2 <cc> STA_CFG_REQ(209) sta 94:f6:d6:18:45:a2 add ==> ws (0-10.10.200.4:5246) rId 0 wId 0 72979.543 265 94:f6:d6:18:45:a2 <cc> STA add 94:f6:d6:18:45:a2 vap Taft-testing ws (0-10.10.200.4:5246) rId 0 wId 0 84:39:8f:0e:d6:91 sec open auth 1 72979.543 265 94:f6:d6:18:45:a2 cwAcStaRbtAdd: I2C_STA_ADD insert sta 94:f6:d6:18:45:a2 10.10.200.4/0/0/1 20093.544 94:f6:d6:18:45:a2 <eh> RADIUS message (type=0) ==> RADIUS Server code=1 (Access-Request) id=0 len=235 72979.546 265 94:f6:d6:18:45:a2 <cc> STA_CFG_RESP(209) 94:f6:d6:18:45:a2 <== ws (0-10.10.200.4:5246) rc 0 (Success) 20093.549 94:f6:d6:18:45:a2 <eh> RADIUS message (type=0) <== RADIUS Server code=2 (Access-Accept) id=0 len=82 72979.549 265 94:f6:d6:18:45:a2 <dc> STA chg 94:f6:d6:18:45:a2 vap Taft-testing ws (0-10.10.200.4:5246) rId 0 wId 0 bssid 84:39:8f:0e:d6:91 AUTH 72979.550 265 94:f6:d6:18:45:a2 <cc> STA_CFG_REQ(210) sta 94:f6:d6:18:45:a2 update vlan id (10) ==> ws (0-10.10.200.4:5246) rId 0 wId 0 72979.550 265 94:f6:d6:18:45:a2 <dc> STA chg 94:f6:d6:18:45:a2 vap Taft-testing ws (0-10.10.200.4:5246) rId 0 wId 0 bssid 84:39:8f:0e:d6:91 Auth:allow 72980.698 265 94:f6:d6:18:45:a2 <cc> STA_CFG_RESP(210) 94:f6:d6:18:45:a2 <== ws (0-10.10.200.4:5246) rc 0 (Success) 72980.701 265 00:00:00:00:00:00 <cc> STA_CFG_RESP(211) <== ws (0-10.10.200.4:5246) rc 0 (Success) --- Matching STA_CFG_REQ parse error