Hello Ludovic, OK, here's from this morning:
[root@gatekeeper ~]# grep 58:cb:52:37:5d:ab /usr/local/pf/logs/packetfence.log Apr 16 09:13:51 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 16 09:13:52 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 16 09:13:52 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 16 09:13:52 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 16 09:13:52 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 16 09:13:52 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 16 09:13:52 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 16 09:13:52 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 16 09:13:52 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] Updating locationlog from accounting request (pf::api::handle_accounting_metadata) And here's from yesterday during that 15:40 timeframe if that helps: Apr 15 15:40:15 gatekeeper packetfence: pfperl-api(2161) INFO: Using 300 resolution threshold (pf::pfcron::task::cluster_check::run) Apr 15 15:40:15 gatekeeper packetfence: pfperl-api(2161) INFO: All cluster members are running the same configuration version (pf::pfcron::task::cluster_check::run) Apr 15 15:40:15 gatekeeper packetfence: pfperl-api(2162) INFO: getting security_events triggers for accounting cleanup (pf::accounting::acct_maintenance) Apr 15 15:40:42 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 15 15:40:43 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 15 15:40:43 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 15 15:40:43 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 15 15:40:43 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 15 15:40:43 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 15 15:40:43 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 15 15:40:43 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] RADIUS request contains more than one realm. Keeping the first one 'null' (pf::radius::_parseRequest) Apr 15 15:40:43 gatekeeper packetfence_httpd.aaa: httpd.aaa(2054) INFO: [mac:58:cb:52:37:5d:ab] Updating locationlog from accounting request (pf::api::handle_accounting_metadata) Apr 15 15:41:04 gatekeeper pfqueue: pfqueue(17589) WARN: [mac:00:25:90:87:e9:50] Unable to pull accounting history for device 00:25:90:87:e9:50. The history set doesn't exist yet. (pf::accounting_events_history::latest_mac_history) Joshua Nathan *IT Supervisor* Black Forest Academy p: +49 (0) 7626 9161 631 m: +49 (0) 152 3452 0056 a: w: Hammersteiner Straße 50, 79400 Kandern bfacademy.de On Thu, Apr 15, 2021 at 3:52 PM Ludovic Zammit <lzam...@inverse.ca> wrote: > Hello Nathan, > > Show me the output of: > > grep 58:cb:52:37:5d:ab /usr/local/pf/logs/packetfence.log > > Thanks, > > > Ludovic Zammit > lzam...@inverse.ca :: +1.514.447.4918 (x145) :: www.inverse.ca > Inverse inc. :: Leaders behind SOGo (http://www.sogo.nu) and PacketFence > (http://packetfence.org) > > > > > > > > > On Apr 15, 2021, at 9:48 AM, Nathan, Josh via PacketFence-users < > packetfence-users@lists.sourceforge.net> wrote: > > Hello, > > So, I'm trying to configure a 10.2 Zen version of PF. Our user > authentication happens via RADIUS. So I configured our RADIUS server under > the "Internal Sources" section, and everything is now "mostly" working. My > devices authenticate, but the Authentication Rules don't seem to be taking > effect. > > When I try using the debug command for RADIUS (raddebug -f > /usr/local/pf/var/run/radiusd.sock -t 3600), here's what I get. There must > be a setting I'm missing somewhere. The packetfence.log file is > effectively silent on the issue. > > (327) Thu Apr 15 15:40:43 2021: Debug: rest: Processing response header > (327) Thu Apr 15 15:40:43 2021: Debug: rest: Status : 200 (OK) > (327) Thu Apr 15 15:40:43 2021: Debug: rest: Type : json > (application/json) > (327) Thu Apr 15 15:40:43 2021: Debug: rest: Parsing attribute > "control:PacketFence-Authorization-Status" > (327) Thu Apr 15 15:40:43 2021: Debug: rest: EXPAND allow > (327) Thu Apr 15 15:40:43 2021: Debug: rest: --> allow > (327) Thu Apr 15 15:40:43 2021: Debug: rest: > PacketFence-Authorization-Status := "allow" > (327) Thu Apr 15 15:40:43 2021: Debug: [rest] = updated > (327) Thu Apr 15 15:40:43 2021: Debug: eap: Peer sent EAP Response (code > 2) ID 56 length 46 > (327) Thu Apr 15 15:40:43 2021: Debug: eap: Continuing tunnel setup > (327) Thu Apr 15 15:40:43 2021: Debug: [eap] = ok > (327) Thu Apr 15 15:40:43 2021: Debug: } # authorize = ok > (327) Thu Apr 15 15:40:43 2021: Debug: Found Auth-Type = eap > (327) Thu Apr 15 15:40:43 2021: Debug: # Executing group from file > /usr/local/pf/raddb/sites-enabled/packetfence > (327) Thu Apr 15 15:40:43 2021: Debug: authenticate { > (327) Thu Apr 15 15:40:43 2021: Debug: eap: Expiring EAP session with > state 0xce6b3ab6c75323c5 > (327) Thu Apr 15 15:40:43 2021: Debug: eap: Finished EAP session with > state 0xce6b3ab6c75323c5 > (327) Thu Apr 15 15:40:43 2021: Debug: eap: Previous EAP request found for > state 0xce6b3ab6c75323c5, released from the list > (327) Thu Apr 15 15:40:43 2021: Debug: eap: Peer sent packet with method > EAP PEAP (25) > (327) Thu Apr 15 15:40:43 2021: Debug: eap: Calling submodule eap_peap to > process data > (327) Thu Apr 15 15:40:43 2021: Debug: eap_peap: Continuing EAP-TLS > (327) Thu Apr 15 15:40:43 2021: Debug: eap_peap: [eaptls verify] = ok > (327) Thu Apr 15 15:40:43 2021: Debug: eap_peap: Done initial handshake > (327) Thu Apr 15 15:40:43 2021: Debug: eap_peap: [eaptls process] = ok > (327) Thu Apr 15 15:40:43 2021: Debug: eap_peap: Session established. > Decoding tunneled attributes > (327) Thu Apr 15 15:40:43 2021: Debug: eap_peap: PEAP state send tlv > success > (327) Thu Apr 15 15:40:43 2021: Debug: eap_peap: Received EAP-TLV response > (327) Thu Apr 15 15:40:43 2021: Debug: eap_peap: Success > (327) Thu Apr 15 15:40:43 2021: Debug: eap_peap: Using saved attributes > from the original Access-Accept > (327) Thu Apr 15 15:40:43 2021: Debug: eap_peap: User-Name = > "josh.nathan" > (327) Thu Apr 15 15:40:43 2021: Debug: eap: Sending EAP Success (code 3) > ID 56 length 4 > (327) Thu Apr 15 15:40:43 2021: Debug: eap: Freeing handler > (327) Thu Apr 15 15:40:43 2021: Debug: [eap] = ok > (327) Thu Apr 15 15:40:43 2021: Debug: } # authenticate = ok > (327) Thu Apr 15 15:40:43 2021: Debug: # Executing section post-auth from > file /usr/local/pf/raddb/sites-enabled/packetfence > (327) Thu Apr 15 15:40:43 2021: Debug: post-auth { > (327) Thu Apr 15 15:40:43 2021: Debug: update { > (327) Thu Apr 15 15:40:43 2021: Debug: EXPAND > %{Packet-Src-IP-Address} > (327) Thu Apr 15 15:40:43 2021: Debug: --> 172.20.50.76 > (327) Thu Apr 15 15:40:43 2021: Debug: EXPAND > %{Packet-Dst-IP-Address} > (327) Thu Apr 15 15:40:43 2021: Debug: --> 172.20.104.31 > (327) Thu Apr 15 15:40:43 2021: Debug: } # update = noop > (327) Thu Apr 15 15:40:43 2021: Debug: policy > packetfence-set-tenant-id { > (327) Thu Apr 15 15:40:43 2021: Debug: if (!NAS-IP-Address || > NAS-IP-Address == "0.0.0.0"){ > (327) Thu Apr 15 15:40:43 2021: Debug: if (!NAS-IP-Address || > NAS-IP-Address == "0.0.0.0") -> FALSE > (327) Thu Apr 15 15:40:43 2021: Debug: if ( > "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { > (327) Thu Apr 15 15:40:43 2021: Debug: EXPAND > %{%{control:PacketFence-Tenant-Id}:-0} > (327) Thu Apr 15 15:40:43 2021: Debug: --> 1 > (327) Thu Apr 15 15:40:43 2021: Debug: if ( > "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> FALSE > (327) Thu Apr 15 15:40:43 2021: Debug: if ( > &control:PacketFence-Tenant-Id == 0 ) { > (327) Thu Apr 15 15:40:43 2021: Debug: if ( > &control:PacketFence-Tenant-Id == 0 ) -> FALSE > (327) Thu Apr 15 15:40:43 2021: Debug: } # policy > packetfence-set-tenant-id = noop > (327) Thu Apr 15 15:40:43 2021: Debug: if > ("%{%{control:PacketFence-Proxied-From}:-False}" == "True") { > (327) Thu Apr 15 15:40:43 2021: Debug: EXPAND > %{%{control:PacketFence-Proxied-From}:-False} > (327) Thu Apr 15 15:40:43 2021: Debug: --> False > (327) Thu Apr 15 15:40:43 2021: Debug: if > ("%{%{control:PacketFence-Proxied-From}:-False}" == "True") -> FALSE > (327) Thu Apr 15 15:40:43 2021: Debug: if (! EAP-Type || (EAP-Type != > TTLS && EAP-Type != PEAP) ) { > (327) Thu Apr 15 15:40:43 2021: Debug: if (! EAP-Type || (EAP-Type != > TTLS && EAP-Type != PEAP) ) -> FALSE > (327) Thu Apr 15 15:40:43 2021: Debug: attr_filter.packetfence_post_auth: > EXPAND %{User-Name} > (327) Thu Apr 15 15:40:43 2021: Debug: attr_filter.packetfence_post_auth: > --> josh.nathan > (327) Thu Apr 15 15:40:43 2021: Debug: attr_filter.packetfence_post_auth: > Matched entry DEFAULT at line 10 > (327) Thu Apr 15 15:40:43 2021: Debug: > [attr_filter.packetfence_post_auth] = updated > (327) Thu Apr 15 15:40:43 2021: Debug: linelog: EXPAND > messages.%{%{reply:Packet-Type}:-default} > (327) Thu Apr 15 15:40:43 2021: Debug: linelog: --> > messages.Access-Accept > (327) Thu Apr 15 15:40:43 2021: Debug: linelog: EXPAND > [mac:%{Calling-Station-Id}] Accepted user: %{reply:User-Name} and returned > VLAN %{reply:Tunnel-Private-Group-ID} > (327) Thu Apr 15 15:40:43 2021: Debug: linelog: --> > [mac:58:cb:52:37:5d:ab] Accepted user: josh.nathan and returned VLAN > (327) Thu Apr 15 15:40:43 2021: Debug: [linelog] = ok > (327) Thu Apr 15 15:40:43 2021: Debug: } # post-auth = updated > (327) Thu Apr 15 15:40:43 2021: Debug: Sent Access-Accept Id 229 from > 172.20.104.31:1812 to 172.20.50.76:40485 length 0 > (327) Thu Apr 15 15:40:43 2021: Debug: User-Name = "josh.nathan" > (327) Thu Apr 15 15:40:43 2021: Debug: MS-MPPE-Recv-Key = > 0x600da060c2faa9fdf49eb732f5110f438b5d71f66e661345f268bf24252e85c3 > (327) Thu Apr 15 15:40:43 2021: Debug: MS-MPPE-Send-Key = > 0x8d6d99afd78af3ebade3b3869adc9ceef8f9782d323d553bce8cf5c1511d05d1 > (327) Thu Apr 15 15:40:43 2021: Debug: EAP-Message = 0x03380004 > (327) Thu Apr 15 15:40:43 2021: Debug: Message-Authenticator = > 0x00000000000000000000000000000000 > (327) Thu Apr 15 15:40:43 2021: Debug: Finished request > (317) Thu Apr 15 15:40:44 2021: Debug: Cleaning up request packet ID 219 > with timestamp +4564 > (318) Thu Apr 15 15:40:44 2021: Debug: Cleaning up request packet ID 220 > with timestamp +4564 > (319) Thu Apr 15 15:40:44 2021: Debug: Cleaning up request packet ID 221 > with timestamp +4564 > (328) Thu Apr 15 15:40:45 2021: Debug: Received Status-Server Id 161 from > 127.0.0.1:45116 to 127.0.0.1:18121 length 50 > (328) Thu Apr 15 15:40:45 2021: Debug: Message-Authenticator = > 0x0630aabb861db1ebd2a0892a5d55941e > (328) Thu Apr 15 15:40:45 2021: Debug: FreeRADIUS-Statistics-Type = 15 > (328) Thu Apr 15 15:40:45 2021: Debug: # Executing group from file > /usr/local/pf/raddb/sites-enabled/status > (328) Thu Apr 15 15:40:45 2021: Debug: Autz-Type Status-Server { > (328) Thu Apr 15 15:40:45 2021: Debug: [ok] = ok > (328) Thu Apr 15 15:40:45 2021: Debug: } # Autz-Type Status-Server = ok > (328) Thu Apr 15 15:40:45 2021: Debug: Sent Access-Accept Id 161 from > 127.0.0.1:18121 to 127.0.0.1:45116 length 0 > > > > Thank you for any guidance you can give! > > Joshua Nathan > *IT Supervisor* > Black Forest Academy > > p: +49 (0) 7626 9161 631 m: +49 (0) 152 3452 0056 > a: > w: Hammersteiner Straße 50, 79400 Kandern > bfacademy.de > > > _______________________________________________ > PacketFence-users mailing list > PacketFence-users@lists.sourceforge.net > https://lists.sourceforge.net/lists/listinfo/packetfence-users > > >
_______________________________________________ PacketFence-users mailing list PacketFence-users@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/packetfence-users
