search

inverse-inc / packetfence

PacketFence is a fully supported, trusted, Free and Open Source network access control (NAC) solution. Boasting an impressive feature set including a captive-portal for registration and remediation, centralized wired and wireless management, powerful BYOD management options, 802.1X support, layer-2 isolation of problematic devices; PacketFence can be used to effectively secure networks small to very large heterogeneous networks.
https://packetfence.org
GNU General Public License v2.0
1.39k stars 292 forks source link

Reevaluate access on wifi-client with FortiGate produces error #7450

Open heiko-ma opened 1 year ago

heiko-ma commented 1 year ago

Describe the bug When reevaluating access on a wifi-client connected to a FortiGate wifi, the disconnect request isn't being sent, and the log produces the following output: Jan 11 09:32:00 packetfence pfqueue[541526]: pfqueue(541526) INFO: [mac:ca:d8:b3:27:71:a1] [ca:d8:b3:27:71:a1] DesAssociating mac on switch (10.20.10.1) (pf::api::desAssociate) Jan 11 09:32:00 packetfence pfqueue[541526]: pfqueue(541526) INFO: [mac:ca:d8:b3:27:71:a1] deauthenticating (pf::Switch::radiusDisconnect) Jan 11 09:32:00 packetfence pfqueue[541526]: pfqueue(541526) INFO: [mac:ca:d8:b3:27:71:a1] controllerIp is set, we will use controller 10.20.10.1 to perform deauth (pf::Switch::radiusDisconnect) Jan 11 09:32:00 packetfence pfqueue[541526]: pfqueue(541526) INFO: [mac:ca:d8:b3:27:71:a1] Will be using connnector local_connector to perform the deauth (pf::Switch::radius_deauth_connection_info) Jan 11 09:32:00 packetfence pfqueue[541526]: pfqueue(541526) WARN: [mac:ca:d8:b3:27:71:a1] Unable to perform RADIUS Disconnect-Request: No answer from 10.20.10.1 on port 3799 at /usr/local/pf/lib/pf/util/radius.pm line 158. (pf::Switch::catch {...} )

As you can see in the timestamps, their isnt really a timeout being hit because the error does occur not even a second after the request. Also, packetfence does not seem to send a disconnect-request to the FortiGate.

To Reproduce Steps to reproduce the behavior:

  1. Select a node currently connected to a wifi network
  2. Click on 'reevaluate access'
  3. See error occuring in packetfence.log and no response from the FortiGate in the audit-log

Expected behavior The node gets deauthenticated and the admin receives a CoA-Accept in the audit-log

heiko-ma commented 1 year ago

I troubleshooted this issue a little more and found out, that his may be connected to a larger problem. The problem with CoA packages not being sent doesn't only occur on Wifi-Clients on FortiAPs but on our other switches too.

Meanwhile I encountered the following strange behavior: When using Firewall SSO (also with FortiGate), every 30-60 minutes, the packetfence would stop sending radius-accounting packages to authenticate the sessions. After a bit of troubleshooting, I found out, that the sockets of the server were filling up every hour (stopping at ca. 28k). After restarting pfconnector-client and pfconnector-server the socket-usage would reset and new accounting-requests would work fine.

I think this has something to do with the accounting sockets not being closed correctly. In pfsso.log I see the following log messages:

Jan 16 20:16:42 packetfence pfsso-docker-wrapper[96960]: t=2023-01-16T20:16:42+0100 lvl=info msg="Calling Unified API on uri: http://100.64.0.1:22226/api/v1/pfconnector/dynreverse" pid=9 request-uuid=4f68d574-95d2-11ed-90ba-02426440000a username= ip=10.83.20.40 mac=d8:9e:f3:f3:68:88 role=client firewall-id=10.91.0.1 Jan 16 20:16:42 packetfence pfsso-docker-wrapper[96960]: t=2023-01-16T20:16:42+0100 lvl=info msg="Calling Unified API on uri: http://100.64.0.1:22226/api/v1/pfconnector/dynreverse" pid=9 request-uuid=4f68d574-95d2-11ed-90ba-02426440000a username= ip=10.83.20.40 mac=d8:9e:f3:f3:68:88 role=client firewall-id=10.20.248.5 Jan 16 20:16:42 packetfence pfsso-docker-wrapper[96960]: t=2023-01-16T20:16:42+0100 lvl=info msg="Reusing existing port 42867" pid=9 request-uuid=4f68d574-95d2-11ed-90ba-02426440000a username= ip=10.83.20.40 mac=d8:9e:f3:f3:68:88 role=client firewall-id=10.91.0.1 Jan 16 20:16:42 packetfence pfsso-docker-wrapper[96960]: t=2023-01-16T20:16:42+0100 lvl=info msg="Reusing existing port 38535" pid=9 request-uuid=4f68d574-95d2-11ed-90ba-02426440000a username= ip=10.83.20.40 mac=d8:9e:f3:f3:68:88 role=client firewall-id=10.20.248.5 Jan 16 20:16:42 packetfence pfsso-docker-wrapper[96960]: t=2023-01-16T20:16:42+0100 lvl=eror msg="Couldn't SSO to the fortigate, got the following error: context deadline exceeded" pid=9 request-uuid=4c762d18-95d2-11ed-90ba-02426440000a username= ip=10.23.66.20 mac=4c:44:5b:4c:93:39 role=client firewall-id=10.91.0.1 Jan 16 20:16:42 packetfence pfsso-docker-wrapper[96960]: t=2023-01-16T20:16:42+0100 lvl=eror msg="Error while sending SSO to context deadline exceeded: %!s(MISSING)10.91.0.1" pid=9 request-uuid=4c762d18-95d2-11ed-90ba-02426440000a username= ip=10.23.66.20 mac=4c:44:5b:4c:93:39 role=client Jan 16 20:16:42 packetfence pfsso-docker-wrapper[96960]: t=2023-01-16T20:16:42+0100 lvl=eror msg="Couldn't SSO to the fortigate, got the following error: context deadline exceeded" pid=9 request-uuid=4c762d18-95d2-11ed-90ba-02426440000a username= ip=10.23.66.20 mac=4c:44:5b:4c:93:39 role=client firewall-id=10.20.248.5 Jan 16 20:16:42 packetfence pfsso-docker-wrapper[96960]: t=2023-01-16T20:16:42+0100 lvl=eror msg="Error while sending SSO to context deadline exceeded: %!s(MISSING)10.20.248.5" pid=9 request-uuid=4c762d18-95d2-11ed-90ba-02426440000a username= ip=10.23.66.20 mac=4c:44:5b:4c:93:39 role=client Jan 16 20:16:42 packetfence pfsso-docker-wrapper[96960]: t=2023-01-16T20:16:42+0100 lvl=eror msg="Couldn't SSO to the fortigate, got the following error: context deadline exceeded" pid=9 request-uuid=4c87fb64-95d2-11ed-90ba-02426440000a username= ip=10.23.20.45 mac=00:1a:e8:b3:ee:21 role=voice firewall-id=10.91.0.1 Jan 16 20:16:42 packetfence pfsso-docker-wrapper[96960]: t=2023-01-16T20:16:42+0100 lvl=eror msg="Error while sending SSO to context deadline exceeded: %!s(MISSING)10.91.0.1" pid=9 request-uuid=4c87fb64-95d2-11ed-90ba-02426440000a username= ip=10.23.20.45 mac=00:1a:e8:b3:ee:21 role=voice Jan 16 20:16:42 packetfence pfsso-docker-wrapper[96960]: t=2023-01-16T20:16:42+0100 lvl=eror msg="Couldn't SSO to the fortigate, got the following error: context deadline exceeded" pid=9 request-uuid=4c87fb64-95d2-11ed-90ba-02426440000a username= ip=10.23.20.45 mac=00:1a:e8:b3:ee:21 role=voice firewall-id=10.20.248.5 Jan 16 20:16:42 packetfence pfsso-docker-wrapper[96960]: t=2023-01-16T20:16:42+0100 lvl=eror msg="Error while sending SSO to context deadline exceeded: %!s(MISSING)10.20.248.5" pid=9 request-uuid=4c87fb64-95d2-11ed-90ba-02426440000a username= ip=10.23.20.45 mac=00:1a:e8:b3:ee:21 role=voice

The registration at fortigate works fine and the firewall also sends an accounting response but somehow packetfence doesn't recognize it as a correct answer and keeps the socket open.

To bring me back to the original issue, restarting those two services mentioned also resolves the original error, after that the issues are correctly deauthenticated and correctly logged.

If you need any more information (logfiles, config-snippets) please reach out to me. Thank you!