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.27k stars 274 forks source link

v13: deauthentication with local connector works randomly #7772

Open nqb opened 11 months ago

nqb commented 11 months ago

Describe the bug The deauthentication process is not consistent when used with local-connector (default). On 10 attempts, I have seen 1 attempt to succeed.

To Reproduce Steps to reproduce the behavior:

  1. Configure a switch to use a local connector for deauthentication
  2. Create a location for a device attached to this switch
  3. Try to deauthenticate your device

=> There is no RADIUS request sent to your network device.

Expected behavior Deauthentication message is sent and visible in RADIUS Audit log.

Additional context I don't see any specific error in packetfence.log:

Jul 19 12:51:36 pfel8dev pfqueue[18661]: pfqueue(18661) DEBUG: [mac:00:03:00:11:11:01] deauthenticate 00:03:00:11:11:01 using RADIUS Disconnect-Request deauth method (pf::Switch::Template::deauthenticateMacRadius)
Jul 19 12:51:36 pfel8dev pfqueue[18661]: pfqueue(18661) INFO: [mac:00:03:00:11:11:01] deauthenticating (pf::Switch::Template::radiusDisconnect)
Jul 19 12:51:36 pfel8dev pfqueue[18661]: pfqueue(18661) INFO: [mac:00:03:00:11:11:01] controllerIp is set, we will use controller 172.18.200.201 to perform deauth (pf::Switch::Template::disconnectAddress)
Jul 19 12:51:37 pfel8dev pfqueue[18661]: pfqueue(18661) INFO: [mac:00:03:00:11:11:01] Will be using connnector local_connector to perform the deauth (pf::Switch::radius_deauth_connection_info)
Jul 19 12:51:37 pfel8dev pfqueue[18661]: pfqueue(18661) DEBUG: [mac:00:03:00:11:11:01] cache get for namespace='Default', key='HASH(0x55e8dcf8e388)', cache='RawMemory', time='0ms': MISS (not in cache) (CHI::Driver::_log_get_result)
Jul 19 12:51:37 pfel8dev pfqueue[18661]: pfqueue(18661) DEBUG: [mac:00:03:00:11:11:01] cache set for namespace='Default', key='{"encoding":null,"reconnect":"60","server":"containers-gateway.internal:6379"}', size=1, expires='never', cach
e='RawMemory', time='0ms' (CHI::Driver::_log_set_result)
Jul 19 12:51:37 pfel8dev pfqueue[18661]: pfqueue(18661) DEBUG: [mac:00:03:00:11:11:01] cache get for namespace='route_int', key='172.18.200.201', cache='Redis', time='1ms': HIT (CHI::Driver::_log_get_result)
Jul 19 12:51:37 pfel8dev pfqueue[18661]: pfqueue(18661) DEBUG: [mac:00:03:00:11:11:01] cache get for namespace='Default', key='HASH(0x55e8dcf8e388)', cache='RawMemory', time='0ms': MISS (not in cache) (CHI::Driver::_log_get_result)
Jul 19 12:51:37 pfel8dev pfqueue[18661]: pfqueue(18661) DEBUG: [mac:00:03:00:11:11:01] cache set for namespace='Default', key='{"server":"containers-gateway.internal:6379"}', size=1, expires='never', cache='RawM

In pfconnector-server logs, I see those messages at the moment of the reevaluation:

Jul 19 12:51:37 pfel8dev pfconnector-server-docker-wrapper[2634]: t=2023-07-19T12:51:37+0000 lvl=info msg="Handling POST /api/v1/pfconnector/dynreverse" pid=1
Jul 19 12:51:37 pfel8dev pfconnector-server-docker-wrapper[2634]: t=2023-07-19T12:51:37+0000 lvl=dbug msg="Memory configuration is more than 5 seconds old. Considering config::Connector() as invalid do reload it." pid=1
Jul 19 12:51:37 pfel8dev pfconnector-server-docker-wrapper[2634]: t=2023-07-19T12:51:37+0000 lvl=dbug msg="Resource is not valid anymore. Was loaded at 2023-07-19 12:51:26.669550435 +0000 UTC m=+5122.755583423" pid=1
Jul 19 12:51:37 pfel8dev pfconnector-server-docker-wrapper[2634]: t=2023-07-19T12:51:37+0000 lvl=dbug msg="Memory configuration is more than 5 seconds old. Considering config::Connector() as invalid do reload it." pid=1
Jul 19 12:51:37 pfel8dev pfconnector-server-docker-wrapper[2634]: t=2023-07-19T12:51:37+0000 lvl=dbug msg="Resource is not valid anymore. Was loaded at 2023-07-19 12:51:26.669550435 +0000 UTC m=+5122.755583423" pid=1
Jul 19 12:51:37 pfel8dev pfconnector-server-docker-wrapper[2634]: 2023/07/19 12:51:37 server: session#1: tun: proxy#R:0=>172.18.200.201:3799/udp: Listening
Jul 19 12:51:37 pfel8dev pfconnector-server-docker-wrapper[2634]: t=2023-07-19T12:51:37+0000 lvl=dbug msg="Memory configuration was never loaded. Considering config::Connector() as invalid do the initial load." pid=1
Jul 19 12:51:37 pfel8dev pfconnector-server-docker-wrapper[2634]: t=2023-07-19T12:51:37+0000 lvl=dbug msg="Item local_connector has been detected as expired in pfconfig. Reloading." pid=1
Jul 19 12:51:37 pfel8dev pfconnector-server-docker-wrapper[2634]: t=2023-07-19T12:51:37+0000 lvl=dbug msg="Adding object local_connector" pid=1
Jul 19 12:51:37 pfel8dev pfconnector-server-docker-wrapper[2634]: t=2023-07-19T12:51:37+0000 lvl=dbug msg="Memory configuration was never loaded. Considering config::Connector() as invalid do the initial load." pid=1

=> We see that the tunnel is opened to port 3799 but not used.

Important: if I make a new reevaluation just after a failed one, it works automatically.

nqb commented 11 months ago

The problem seems to be that when the tunnel is closed, the opening is down too late to be used by pfqueue

extrafu commented 11 months ago

Moved to v13.1. @jrouzierinverse link to your revert and rationale and what's next to fix the original code.

satkunas commented 10 months ago

@jrouzierinverse please verify and close if fixed