EAP-TLS with OVA ZEN 10.01

[whitezor]

Hi All,

We made a configuration with dot1x EAP-TLS. We first tested our config with a microsoft NPS and it's working fine.

Now with Packetfence, all certificate imported all config done but we receive an issue:

Here is the issue message :

&session-state:TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384" &session-state:TLS-Session-Version = "TLS 1.2" **&session-state:Module-Failure-Message := "eap: Tried to start unsupported EAP type MSCHAPv2 (26)"**

TLS negotiation seems to work fine and suddenly it's trying mschapv2..

Could you please help on this issue? Thank you a lot in advance

Here is ths debug log:

(116) Wed Jun 3 10:40:00 2020: Debug: Received Status-Server Id 204 from 127.0.0.1:58210 to 127.0.0.1:18121 length 50 (116) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0xe4fef7b4da35837ad3f9b1db7ac9778c (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Statistics-Type = 15 (116) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/status (116) Wed Jun 3 10:40:00 2020: Debug: Autz-Type Status-Server { (116) Wed Jun 3 10:40:00 2020: Debug: [ok] = ok (116) Wed Jun 3 10:40:00 2020: Debug: } # Autz-Type Status-Server = ok (116) Wed Jun 3 10:40:00 2020: Debug: Sent Access-Accept Id 204 from 127.0.0.1:18121 to 127.0.0.1:58210 length 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Access-Requests = 117 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Access-Accepts = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Access-Rejects = 3 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Access-Challenges = 21 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Auth-Responses = 24 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Auth-Duplicate-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Auth-Malformed-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Auth-Invalid-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Auth-Dropped-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Auth-Unknown-Types = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Accounting-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Accounting-Responses = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Acct-Duplicate-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Acct-Malformed-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Acct-Invalid-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Acct-Dropped-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Acct-Unknown-Types = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Access-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Access-Accepts = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Access-Rejects = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Access-Challenges = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Auth-Responses = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Auth-Duplicate-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Auth-Malformed-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Auth-Invalid-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Auth-Dropped-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Auth-Unknown-Types = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Accounting-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Accounting-Responses = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Acct-Duplicate-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Acct-Malformed-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Acct-Invalid-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Acct-Dropped-Requests = 0 (116) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Total-Proxy-Acct-Unknown-Types = 0 (116) Wed Jun 3 10:40:00 2020: Debug: Finished request (117) Wed Jun 3 10:40:00 2020: Debug: Received Access-Request Id 79 from 10.10.20.254:1812 to 10.10.20.40:1812 length 439 (117) Wed Jun 3 10:40:00 2020: Debug: Framed-MTU = 1492 (117) Wed Jun 3 10:40:00 2020: Debug: NAS-IP-Address = 10.10.20.254 (117) Wed Jun 3 10:40:00 2020: Debug: NAS-Identifier = "Aruba-2930F-8G-PoEP-2SFPP" (117) Wed Jun 3 10:40:00 2020: Debug: User-Name = "host/PC1189.nsi-labo.local" (117) Wed Jun 3 10:40:00 2020: Debug: Service-Type = Framed-User (117) Wed Jun 3 10:40:00 2020: Debug: Framed-Protocol = PPP (117) Wed Jun 3 10:40:00 2020: Debug: NAS-Port = 7 (117) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Type = Ethernet (117) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Id = "7" (117) Wed Jun 3 10:40:00 2020: Debug: Called-Station-Id = "98-f2-b3-bf-db-60" (117) Wed Jun 3 10:40:00 2020: Debug: Calling-Station-Id = "b4-b6-86-0d-8e-98" (117) Wed Jun 3 10:40:00 2020: Debug: Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex" (117) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Type:0 = VLAN (117) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Medium-Type:0 = IEEE-802 (117) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Private-Group-Id:0 = "1" (117) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x0216001f01686f73742f5043313138392e6e73692d6c61626f2e6c6f63616c (117) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0x5a9bf7e8e11b0531820f3be59a613902 (117) Wed Jun 3 10:40:00 2020: Debug: MS-RAS-Vendor = 11 (117) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b28 (117) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b2e (117) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b30 (117) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b3d (117) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b18 (117) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b19 (117) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1b (117) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1c (117) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0138 (117) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x013a (117) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0140 (117) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0141 (117) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0151 (117) Wed Jun 3 10:40:00 2020: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence (117) Wed Jun 3 10:40:00 2020: Debug: authorize { (117) Wed Jun 3 10:40:00 2020: Debug: update { (117) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Src-IP-Address} (117) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.254 (117) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Dst-IP-Address} (117) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.40 (117) Wed Jun 3 10:40:00 2020: Debug: EXPAND %l (117) Wed Jun 3 10:40:00 2020: Debug: --> 1591173600 (117) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (117) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-realm-if-machine { (117) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (117) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) -> TRUE (117) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (117) Wed Jun 3 10:40:00 2020: Debug: update { (117) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{2} (117) Wed Jun 3 10:40:00 2020: Debug: --> nsi-labo.local (117) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (117) Wed Jun 3 10:40:00 2020: Debug: } # if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) = noop (117) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-realm-if-machine = noop (117) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-balanced-key-policy { (117) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) { (117) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) -> FALSE (117) Wed Jun 3 10:40:00 2020: Debug: else { (117) Wed Jun 3 10:40:00 2020: Debug: update { (117) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (117) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (117) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (117) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (117) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (117) Wed Jun 3 10:40:00 2020: Debug: } # else = noop (117) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-balanced-key-policy = noop (117) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-tenant-id { (117) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){ (117) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE (117) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (117) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0} (117) Wed Jun 3 10:40:00 2020: Debug: --> 0 (117) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE (117) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (117) Wed Jun 3 10:40:00 2020: Debug: update control { (117) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{User-Name} (117) Wed Jun 3 10:40:00 2020: Debug: --> host/PC1189.nsi-labo.local (117) Wed Jun 3 10:40:00 2020: Debug: SQL-User-Name set to 'host/PC1189.nsi-labo.local' (117) Wed Jun 3 10:40:00 2020: Debug: Executing select query: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '10.10.20.254'), 0) (117) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{sql: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '%{NAS-IP-Address}'), 0)} (117) Wed Jun 3 10:40:00 2020: Debug: --> 1 (117) Wed Jun 3 10:40:00 2020: Debug: } # update control = noop (117) Wed Jun 3 10:40:00 2020: Debug: } # if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop (117) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) { (117) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE (117) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-tenant-id = noop (117) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_calling_station_id { (117) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (117) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) -> TRUE (117) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (117) Wed Jun 3 10:40:00 2020: Debug: update request { (117) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (117) Wed Jun 3 10:40:00 2020: Debug: --> b4:b6:86:0d:8e:98 (117) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (117) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (117) Wed Jun 3 10:40:00 2020: Debug: } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) = updated (117) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (117) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_calling_station_id = updated (117) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_called_station_id { (117) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (117) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) -> TRUE (117) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (117) Wed Jun 3 10:40:00 2020: Debug: update request { (117) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (117) Wed Jun 3 10:40:00 2020: Debug: --> 98:f2:b3:bf:db:60 (117) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (117) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") { (117) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{8} (117) Wed Jun 3 10:40:00 2020: Debug: --> (117) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") -> FALSE (117) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) { (117) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (117) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) { (117) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) -> FALSE (117) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) { (117) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (117) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (117) Wed Jun 3 10:40:00 2020: Debug: } # if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) = updated (117) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (117) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_called_station_id = updated (117) Wed Jun 3 10:40:00 2020: Debug: policy filter_username { (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) -> TRUE (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) { (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) -> FALSE (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) { (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) -> FALSE (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) { (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) -> FALSE (117) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) { (117) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) -> FALSE (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) { (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) -> FALSE (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) { (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) -> FALSE (117) Wed Jun 3 10:40:00 2020: Debug: } # if (&User-Name) = updated (117) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_username = updated (117) Wed Jun 3 10:40:00 2020: Debug: policy filter_password { (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) { (117) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE (117) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_password = updated (117) Wed Jun 3 10:40:00 2020: Debug: [preprocess] = ok (117) Wed Jun 3 10:40:00 2020: Debug: suffix: Request already has destination realm set. Ignoring (117) Wed Jun 3 10:40:00 2020: Debug: [suffix] = noop (117) Wed Jun 3 10:40:00 2020: Debug: ntdomain: Request already has destination realm set. Ignoring (117) Wed Jun 3 10:40:00 2020: Debug: [ntdomain] = noop (117) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent EAP Response (code 2) ID 22 length 31 (117) Wed Jun 3 10:40:00 2020: Debug: eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (117) Wed Jun 3 10:40:00 2020: Debug: [eap] = ok (117) Wed Jun 3 10:40:00 2020: Debug: } # authorize = ok (117) Wed Jun 3 10:40:00 2020: Debug: Found Auth-Type = eap (117) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (117) Wed Jun 3 10:40:00 2020: Debug: authenticate { (117) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent packet with method EAP Identity (1) (117) Wed Jun 3 10:40:00 2020: Debug: eap: Calling submodule eap_peap to process data (117) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Initiating new TLS session (117) Wed Jun 3 10:40:00 2020: Debug: eappeap: [eaptls start] = request (117) Wed Jun 3 10:40:00 2020: Debug: eap: Sending EAP Request (code 1) ID 23 length 6 (117) Wed Jun 3 10:40:00 2020: Debug: eap: EAP session adding &reply:State = 0xa066b5d3a071ac78 (117) Wed Jun 3 10:40:00 2020: Debug: [eap] = handled (117) Wed Jun 3 10:40:00 2020: Debug: } # authenticate = handled (117) Wed Jun 3 10:40:00 2020: Debug: Using Post-Auth-Type Challenge (117) Wed Jun 3 10:40:00 2020: Debug: Post-Auth-Type sub-section not found. Ignoring. (117) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (117) Wed Jun 3 10:40:00 2020: Debug: Sent Access-Challenge Id 79 from 10.10.20.40:1812 to 10.10.20.254:1812 length 0 (117) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x011700061920 (117) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (117) Wed Jun 3 10:40:00 2020: Debug: State = 0xa066b5d3a071ac78414a18978b5bd632 (117) Wed Jun 3 10:40:00 2020: Debug: Finished request (118) Wed Jun 3 10:40:00 2020: Debug: Received Access-Request Id 80 from 10.10.20.254:1812 to 10.10.20.40:1812 length 592 (118) Wed Jun 3 10:40:00 2020: Debug: Framed-MTU = 1492 (118) Wed Jun 3 10:40:00 2020: Debug: NAS-IP-Address = 10.10.20.254 (118) Wed Jun 3 10:40:00 2020: Debug: NAS-Identifier = "Aruba-2930F-8G-PoEP-2SFPP" (118) Wed Jun 3 10:40:00 2020: Debug: User-Name = "host/PC1189.nsi-labo.local" (118) Wed Jun 3 10:40:00 2020: Debug: Service-Type = Framed-User (118) Wed Jun 3 10:40:00 2020: Debug: Framed-Protocol = PPP (118) Wed Jun 3 10:40:00 2020: Debug: NAS-Port = 7 (118) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Type = Ethernet (118) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Id = "7" (118) Wed Jun 3 10:40:00 2020: Debug: Called-Station-Id = "98-f2-b3-bf-db-60" (118) Wed Jun 3 10:40:00 2020: Debug: Calling-Station-Id = "b4-b6-86-0d-8e-98" (118) Wed Jun 3 10:40:00 2020: Debug: Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex" (118) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Type:0 = VLAN (118) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Medium-Type:0 = IEEE-802 (118) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Private-Group-Id:0 = "1" (118) Wed Jun 3 10:40:00 2020: Debug: State = 0xa066b5d3a071ac78414a18978b5bd632 (118) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x021700a619800000009c16030300970100009303035ed761e21ceafc0eb523543f1e8ba133b2b9a4fec01d431cbdf5679078bbf5d200002ac02cc02bc030c02f009f009ec024c023c028c027c00ac009c014c013009d009c003d003c0035002f000a01000040000500050100000000000a00080006001d (118) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0x42658c10678e528e2092a10641c8911b (118) Wed Jun 3 10:40:00 2020: Debug: MS-RAS-Vendor = 11 (118) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b28 (118) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b2e (118) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b30 (118) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b3d (118) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b18 (118) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b19 (118) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1b (118) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1c (118) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0138 (118) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x013a (118) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0140 (118) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0141 (118) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0151 (118) Wed Jun 3 10:40:00 2020: Debug: session-state: No cached attributes (118) Wed Jun 3 10:40:00 2020: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence (118) Wed Jun 3 10:40:00 2020: Debug: authorize { (118) Wed Jun 3 10:40:00 2020: Debug: update { (118) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Src-IP-Address} (118) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.254 (118) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Dst-IP-Address} (118) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.40 (118) Wed Jun 3 10:40:00 2020: Debug: EXPAND %l (118) Wed Jun 3 10:40:00 2020: Debug: --> 1591173600 (118) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (118) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-realm-if-machine { (118) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (118) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) -> TRUE (118) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (118) Wed Jun 3 10:40:00 2020: Debug: update { (118) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{2} (118) Wed Jun 3 10:40:00 2020: Debug: --> nsi-labo.local (118) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (118) Wed Jun 3 10:40:00 2020: Debug: } # if (User-Name =~ /host\/([a-z0-9_-])[.](.)/i) = noop (118) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-realm-if-machine = noop (118) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-balanced-key-policy { (118) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) { (118) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) -> FALSE (118) Wed Jun 3 10:40:00 2020: Debug: else { (118) Wed Jun 3 10:40:00 2020: Debug: update { (118) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (118) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (118) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (118) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (118) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (118) Wed Jun 3 10:40:00 2020: Debug: } # else = noop (118) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-balanced-key-policy = noop (118) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-tenant-id { (118) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){ (118) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE (118) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (118) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0} (118) Wed Jun 3 10:40:00 2020: Debug: --> 0 (118) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE (118) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (118) Wed Jun 3 10:40:00 2020: Debug: update control { (118) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{User-Name} (118) Wed Jun 3 10:40:00 2020: Debug: --> host/PC1189.nsi-labo.local (118) Wed Jun 3 10:40:00 2020: Debug: SQL-User-Name set to 'host/PC1189.nsi-labo.local' (118) Wed Jun 3 10:40:00 2020: Debug: Executing select query: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '10.10.20.254'), 0) (118) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{sql: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '%{NAS-IP-Address}'), 0)} (118) Wed Jun 3 10:40:00 2020: Debug: --> 1 (118) Wed Jun 3 10:40:00 2020: Debug: } # update control = noop (118) Wed Jun 3 10:40:00 2020: Debug: } # if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop (118) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) { (118) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE (118) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-tenant-id = noop (118) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_calling_station_id { (118) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (118) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) -> TRUE (118) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (118) Wed Jun 3 10:40:00 2020: Debug: update request { (118) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (118) Wed Jun 3 10:40:00 2020: Debug: --> b4:b6:86:0d:8e:98 (118) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (118) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (118) Wed Jun 3 10:40:00 2020: Debug: } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) = updated (118) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (118) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_calling_station_id = updated (118) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_called_station_id { (118) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (118) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) -> TRUE (118) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (118) Wed Jun 3 10:40:00 2020: Debug: update request { (118) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (118) Wed Jun 3 10:40:00 2020: Debug: --> 98:f2:b3:bf:db:60 (118) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (118) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") { (118) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{8} (118) Wed Jun 3 10:40:00 2020: Debug: --> (118) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") -> FALSE (118) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) { (118) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (118) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) { (118) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) -> FALSE (118) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) { (118) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (118) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (118) Wed Jun 3 10:40:00 2020: Debug: } # if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) = updated (118) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (118) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_called_station_id = updated (118) Wed Jun 3 10:40:00 2020: Debug: policy filter_username { (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) -> TRUE (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) { (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) -> FALSE (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) { (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) -> FALSE (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) { (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) -> FALSE (118) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) { (118) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) -> FALSE (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) { (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) -> FALSE (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) { (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) -> FALSE (118) Wed Jun 3 10:40:00 2020: Debug: } # if (&User-Name) = updated (118) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_username = updated (118) Wed Jun 3 10:40:00 2020: Debug: policy filter_password { (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) { (118) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE (118) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_password = updated (118) Wed Jun 3 10:40:00 2020: Debug: [preprocess] = ok (118) Wed Jun 3 10:40:00 2020: Debug: suffix: Request already has destination realm set. Ignoring (118) Wed Jun 3 10:40:00 2020: Debug: [suffix] = noop (118) Wed Jun 3 10:40:00 2020: Debug: ntdomain: Request already has destination realm set. Ignoring (118) Wed Jun 3 10:40:00 2020: Debug: [ntdomain] = noop (118) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent EAP Response (code 2) ID 23 length 166 (118) Wed Jun 3 10:40:00 2020: Debug: eap: Continuing tunnel setup (118) Wed Jun 3 10:40:00 2020: Debug: [eap] = ok (118) Wed Jun 3 10:40:00 2020: Debug: } # authorize = ok (118) Wed Jun 3 10:40:00 2020: Debug: Found Auth-Type = eap (118) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (118) Wed Jun 3 10:40:00 2020: Debug: authenticate { (118) Wed Jun 3 10:40:00 2020: Debug: eap: Expiring EAP session with state 0xa066b5d3a071ac78 (118) Wed Jun 3 10:40:00 2020: Debug: eap: Finished EAP session with state 0xa066b5d3a071ac78 (118) Wed Jun 3 10:40:00 2020: Debug: eap: Previous EAP request found for state 0xa066b5d3a071ac78, released from the list (118) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent packet with method EAP PEAP (25) (118) Wed Jun 3 10:40:00 2020: Debug: eap: Calling submodule eap_peap to process data (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Continuing EAP-TLS (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Peer indicated complete TLS record size will be 156 bytes (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Got complete TLS record (156 bytes) (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: [eaptls verify] = length included (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: (other): before/accept initialization (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: before/accept initialization (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: SSLv3 read client hello A (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: SSLv3 write server hello A (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: SSLv3 write certificate A (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: SSLv3 write key exchange A (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: SSLv3 write server done A (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: SSLv3 flush data (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: SSLv3 read client certificate A (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: Need to read more data: SSLv3 read client key exchange A (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: Need to read more data: SSLv3 read client key exchange A (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS - In Handshake Phase (118) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS - got 2746 bytes of data (118) Wed Jun 3 10:40:00 2020: Debug: eappeap: [eaptls process] = handled (118) Wed Jun 3 10:40:00 2020: Debug: eap: Sending EAP Request (code 1) ID 24 length 1024 (118) Wed Jun 3 10:40:00 2020: Debug: eap: EAP session adding &reply:State = 0xa066b5d3a17eac78 (118) Wed Jun 3 10:40:00 2020: Debug: [eap] = handled (118) Wed Jun 3 10:40:00 2020: Debug: } # authenticate = handled (118) Wed Jun 3 10:40:00 2020: Debug: Using Post-Auth-Type Challenge (118) Wed Jun 3 10:40:00 2020: Debug: Post-Auth-Type sub-section not found. Ignoring. (118) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (118) Wed Jun 3 10:40:00 2020: Debug: Sent Access-Challenge Id 80 from 10.10.20.40:1812 to 10.10.20.254:1812 length 0 (118) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x0118040019c000000aba1603030039020000350303cfd5e74ee0547f9f39fee42d0c885e8314236708ff477fb631c2d7fcb9f8fbf900c03000000dff01000100000b000403000102160303091c0b00091800091500057c3082057830820460a0030201020213360000001a2b43a68a1ddf2be900000000 (118) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (118) Wed Jun 3 10:40:00 2020: Debug: State = 0xa066b5d3a17eac78414a18978b5bd632 (118) Wed Jun 3 10:40:00 2020: Debug: Finished request (119) Wed Jun 3 10:40:00 2020: Debug: Received Access-Request Id 81 from 10.10.20.254:1812 to 10.10.20.40:1812 length 432 (119) Wed Jun 3 10:40:00 2020: Debug: Framed-MTU = 1492 (119) Wed Jun 3 10:40:00 2020: Debug: NAS-IP-Address = 10.10.20.254 (119) Wed Jun 3 10:40:00 2020: Debug: NAS-Identifier = "Aruba-2930F-8G-PoEP-2SFPP" (119) Wed Jun 3 10:40:00 2020: Debug: User-Name = "host/PC1189.nsi-labo.local" (119) Wed Jun 3 10:40:00 2020: Debug: Service-Type = Framed-User (119) Wed Jun 3 10:40:00 2020: Debug: Framed-Protocol = PPP (119) Wed Jun 3 10:40:00 2020: Debug: NAS-Port = 7 (119) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Type = Ethernet (119) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Id = "7" (119) Wed Jun 3 10:40:00 2020: Debug: Called-Station-Id = "98-f2-b3-bf-db-60" (119) Wed Jun 3 10:40:00 2020: Debug: Calling-Station-Id = "b4-b6-86-0d-8e-98" (119) Wed Jun 3 10:40:00 2020: Debug: Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex" (119) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Type:0 = VLAN (119) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Medium-Type:0 = IEEE-802 (119) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Private-Group-Id:0 = "1" (119) Wed Jun 3 10:40:00 2020: Debug: State = 0xa066b5d3a17eac78414a18978b5bd632 (119) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x021800061900 (119) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0x5a83e07f1ff858bcd751d1ce02ea642d (119) Wed Jun 3 10:40:00 2020: Debug: MS-RAS-Vendor = 11 (119) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b28 (119) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b2e (119) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b30 (119) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b3d (119) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b18 (119) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b19 (119) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1b (119) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1c (119) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0138 (119) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x013a (119) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0140 (119) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0141 (119) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0151 (119) Wed Jun 3 10:40:00 2020: Debug: session-state: No cached attributes (119) Wed Jun 3 10:40:00 2020: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence (119) Wed Jun 3 10:40:00 2020: Debug: authorize { (119) Wed Jun 3 10:40:00 2020: Debug: update { (119) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Src-IP-Address} (119) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.254 (119) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Dst-IP-Address} (119) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.40 (119) Wed Jun 3 10:40:00 2020: Debug: EXPAND %l (119) Wed Jun 3 10:40:00 2020: Debug: --> 1591173600 (119) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (119) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-realm-if-machine { (119) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (119) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) -> TRUE (119) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (119) Wed Jun 3 10:40:00 2020: Debug: update { (119) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{2} (119) Wed Jun 3 10:40:00 2020: Debug: --> nsi-labo.local (119) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (119) Wed Jun 3 10:40:00 2020: Debug: } # if (User-Name =~ /host\/([a-z0-9_-])[.](.)/i) = noop (119) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-realm-if-machine = noop (119) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-balanced-key-policy { (119) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) { (119) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) -> FALSE (119) Wed Jun 3 10:40:00 2020: Debug: else { (119) Wed Jun 3 10:40:00 2020: Debug: update { (119) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (119) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (119) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (119) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (119) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (119) Wed Jun 3 10:40:00 2020: Debug: } # else = noop (119) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-balanced-key-policy = noop (119) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-tenant-id { (119) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){ (119) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE (119) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (119) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0} (119) Wed Jun 3 10:40:00 2020: Debug: --> 0 (119) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE (119) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (119) Wed Jun 3 10:40:00 2020: Debug: update control { (119) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{User-Name} (119) Wed Jun 3 10:40:00 2020: Debug: --> host/PC1189.nsi-labo.local (119) Wed Jun 3 10:40:00 2020: Debug: SQL-User-Name set to 'host/PC1189.nsi-labo.local' (119) Wed Jun 3 10:40:00 2020: Debug: Executing select query: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '10.10.20.254'), 0) (119) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{sql: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '%{NAS-IP-Address}'), 0)} (119) Wed Jun 3 10:40:00 2020: Debug: --> 1 (119) Wed Jun 3 10:40:00 2020: Debug: } # update control = noop (119) Wed Jun 3 10:40:00 2020: Debug: } # if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop (119) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) { (119) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE (119) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-tenant-id = noop (119) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_calling_station_id { (119) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (119) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) -> TRUE (119) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (119) Wed Jun 3 10:40:00 2020: Debug: update request { (119) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (119) Wed Jun 3 10:40:00 2020: Debug: --> b4:b6:86:0d:8e:98 (119) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (119) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (119) Wed Jun 3 10:40:00 2020: Debug: } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) = updated (119) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (119) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_calling_station_id = updated (119) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_called_station_id { (119) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (119) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) -> TRUE (119) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (119) Wed Jun 3 10:40:00 2020: Debug: update request { (119) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (119) Wed Jun 3 10:40:00 2020: Debug: --> 98:f2:b3:bf:db:60 (119) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (119) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") { (119) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{8} (119) Wed Jun 3 10:40:00 2020: Debug: --> (119) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") -> FALSE (119) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) { (119) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (119) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) { (119) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) -> FALSE (119) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) { (119) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (119) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (119) Wed Jun 3 10:40:00 2020: Debug: } # if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) = updated (119) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (119) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_called_station_id = updated (119) Wed Jun 3 10:40:00 2020: Debug: policy filter_username { (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) -> TRUE (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) { (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) -> FALSE (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) { (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) -> FALSE (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) { (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) -> FALSE (119) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) { (119) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) -> FALSE (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) { (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) -> FALSE (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) { (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) -> FALSE (119) Wed Jun 3 10:40:00 2020: Debug: } # if (&User-Name) = updated (119) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_username = updated (119) Wed Jun 3 10:40:00 2020: Debug: policy filter_password { (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) { (119) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE (119) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_password = updated (119) Wed Jun 3 10:40:00 2020: Debug: [preprocess] = ok (119) Wed Jun 3 10:40:00 2020: Debug: suffix: Request already has destination realm set. Ignoring (119) Wed Jun 3 10:40:00 2020: Debug: [suffix] = noop (119) Wed Jun 3 10:40:00 2020: Debug: ntdomain: Request already has destination realm set. Ignoring (119) Wed Jun 3 10:40:00 2020: Debug: [ntdomain] = noop (119) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent EAP Response (code 2) ID 24 length 6 (119) Wed Jun 3 10:40:00 2020: Debug: eap: Continuing tunnel setup (119) Wed Jun 3 10:40:00 2020: Debug: [eap] = ok (119) Wed Jun 3 10:40:00 2020: Debug: } # authorize = ok (119) Wed Jun 3 10:40:00 2020: Debug: Found Auth-Type = eap (119) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (119) Wed Jun 3 10:40:00 2020: Debug: authenticate { (119) Wed Jun 3 10:40:00 2020: Debug: eap: Expiring EAP session with state 0xa066b5d3a17eac78 (119) Wed Jun 3 10:40:00 2020: Debug: eap: Finished EAP session with state 0xa066b5d3a17eac78 (119) Wed Jun 3 10:40:00 2020: Debug: eap: Previous EAP request found for state 0xa066b5d3a17eac78, released from the list (119) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent packet with method EAP PEAP (25) (119) Wed Jun 3 10:40:00 2020: Debug: eap: Calling submodule eap_peap to process data (119) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Continuing EAP-TLS (119) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Peer ACKed our handshake fragment (119) Wed Jun 3 10:40:00 2020: Debug: eap_peap: [eaptls verify] = request (119) Wed Jun 3 10:40:00 2020: Debug: eappeap: [eaptls process] = handled (119) Wed Jun 3 10:40:00 2020: Debug: eap: Sending EAP Request (code 1) ID 25 length 1020 (119) Wed Jun 3 10:40:00 2020: Debug: eap: EAP session adding &reply:State = 0xa066b5d3a27fac78 (119) Wed Jun 3 10:40:00 2020: Debug: [eap] = handled (119) Wed Jun 3 10:40:00 2020: Debug: } # authenticate = handled (119) Wed Jun 3 10:40:00 2020: Debug: Using Post-Auth-Type Challenge (119) Wed Jun 3 10:40:00 2020: Debug: Post-Auth-Type sub-section not found. Ignoring. (119) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (119) Wed Jun 3 10:40:00 2020: Debug: Sent Access-Challenge Id 81 from 10.10.20.40:1812 to 10.10.20.254:1812 length 0 (119) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x011903fc194001010481ba3081b73081b406082b060105050730028681a76c6461703a2f2f2f434e3d6e73692d6c61626f2d4e45545345432d43412c434e3d4149412c434e3d5075626c69632532304b657925323053657276696365732c434e3d53657276696365732c434e3d436f6e66696775726174 (119) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (119) Wed Jun 3 10:40:00 2020: Debug: State = 0xa066b5d3a27fac78414a18978b5bd632 (119) Wed Jun 3 10:40:00 2020: Debug: Finished request (120) Wed Jun 3 10:40:00 2020: Debug: Received Access-Request Id 82 from 10.10.20.254:1812 to 10.10.20.40:1812 length 432 (120) Wed Jun 3 10:40:00 2020: Debug: Framed-MTU = 1492 (120) Wed Jun 3 10:40:00 2020: Debug: NAS-IP-Address = 10.10.20.254 (120) Wed Jun 3 10:40:00 2020: Debug: NAS-Identifier = "Aruba-2930F-8G-PoEP-2SFPP" (120) Wed Jun 3 10:40:00 2020: Debug: User-Name = "host/PC1189.nsi-labo.local" (120) Wed Jun 3 10:40:00 2020: Debug: Service-Type = Framed-User (120) Wed Jun 3 10:40:00 2020: Debug: Framed-Protocol = PPP (120) Wed Jun 3 10:40:00 2020: Debug: NAS-Port = 7 (120) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Type = Ethernet (120) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Id = "7" (120) Wed Jun 3 10:40:00 2020: Debug: Called-Station-Id = "98-f2-b3-bf-db-60" (120) Wed Jun 3 10:40:00 2020: Debug: Calling-Station-Id = "b4-b6-86-0d-8e-98" (120) Wed Jun 3 10:40:00 2020: Debug: Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex" (120) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Type:0 = VLAN (120) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Medium-Type:0 = IEEE-802 (120) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Private-Group-Id:0 = "1" (120) Wed Jun 3 10:40:00 2020: Debug: State = 0xa066b5d3a27fac78414a18978b5bd632 (120) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x021900061900 (120) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0x5aaa16e3f614b0281a29d4b38ae9f3d1 (120) Wed Jun 3 10:40:00 2020: Debug: MS-RAS-Vendor = 11 (120) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b28 (120) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b2e (120) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b30 (120) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b3d (120) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b18 (120) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b19 (120) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1b (120) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1c (120) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0138 (120) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x013a (120) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0140 (120) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0141 (120) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0151 (120) Wed Jun 3 10:40:00 2020: Debug: session-state: No cached attributes (120) Wed Jun 3 10:40:00 2020: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence (120) Wed Jun 3 10:40:00 2020: Debug: authorize { (120) Wed Jun 3 10:40:00 2020: Debug: update { (120) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Src-IP-Address} (120) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.254 (120) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Dst-IP-Address} (120) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.40 (120) Wed Jun 3 10:40:00 2020: Debug: EXPAND %l (120) Wed Jun 3 10:40:00 2020: Debug: --> 1591173600 (120) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (120) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-realm-if-machine { (120) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (120) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) -> TRUE (120) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (120) Wed Jun 3 10:40:00 2020: Debug: update { (120) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{2} (120) Wed Jun 3 10:40:00 2020: Debug: --> nsi-labo.local (120) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (120) Wed Jun 3 10:40:00 2020: Debug: } # if (User-Name =~ /host\/([a-z0-9_-])[.](.)/i) = noop (120) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-realm-if-machine = noop (120) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-balanced-key-policy { (120) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) { (120) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) -> FALSE (120) Wed Jun 3 10:40:00 2020: Debug: else { (120) Wed Jun 3 10:40:00 2020: Debug: update { (120) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (120) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (120) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (120) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (120) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (120) Wed Jun 3 10:40:00 2020: Debug: } # else = noop (120) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-balanced-key-policy = noop (120) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-tenant-id { (120) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){ (120) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE (120) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (120) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0} (120) Wed Jun 3 10:40:00 2020: Debug: --> 0 (120) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE (120) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (120) Wed Jun 3 10:40:00 2020: Debug: update control { (120) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{User-Name} (120) Wed Jun 3 10:40:00 2020: Debug: --> host/PC1189.nsi-labo.local (120) Wed Jun 3 10:40:00 2020: Debug: SQL-User-Name set to 'host/PC1189.nsi-labo.local' (120) Wed Jun 3 10:40:00 2020: Debug: Executing select query: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '10.10.20.254'), 0) (120) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{sql: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '%{NAS-IP-Address}'), 0)} (120) Wed Jun 3 10:40:00 2020: Debug: --> 1 (120) Wed Jun 3 10:40:00 2020: Debug: } # update control = noop (120) Wed Jun 3 10:40:00 2020: Debug: } # if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop (120) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) { (120) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE (120) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-tenant-id = noop (120) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_calling_station_id { (120) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (120) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) -> TRUE (120) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (120) Wed Jun 3 10:40:00 2020: Debug: update request { (120) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (120) Wed Jun 3 10:40:00 2020: Debug: --> b4:b6:86:0d:8e:98 (120) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (120) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (120) Wed Jun 3 10:40:00 2020: Debug: } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) = updated (120) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (120) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_calling_station_id = updated (120) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_called_station_id { (120) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (120) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) -> TRUE (120) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (120) Wed Jun 3 10:40:00 2020: Debug: update request { (120) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (120) Wed Jun 3 10:40:00 2020: Debug: --> 98:f2:b3:bf:db:60 (120) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (120) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") { (120) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{8} (120) Wed Jun 3 10:40:00 2020: Debug: --> (120) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") -> FALSE (120) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) { (120) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (120) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) { (120) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) -> FALSE (120) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) { (120) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (120) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (120) Wed Jun 3 10:40:00 2020: Debug: } # if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) = updated (120) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (120) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_called_station_id = updated (120) Wed Jun 3 10:40:00 2020: Debug: policy filter_username { (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) -> TRUE (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) { (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) -> FALSE (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) { (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) -> FALSE (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) { (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) -> FALSE (120) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) { (120) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) -> FALSE (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) { (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) -> FALSE (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) { (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) -> FALSE (120) Wed Jun 3 10:40:00 2020: Debug: } # if (&User-Name) = updated (120) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_username = updated (120) Wed Jun 3 10:40:00 2020: Debug: policy filter_password { (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) { (120) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE (120) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_password = updated (120) Wed Jun 3 10:40:00 2020: Debug: [preprocess] = ok (120) Wed Jun 3 10:40:00 2020: Debug: suffix: Request already has destination realm set. Ignoring (120) Wed Jun 3 10:40:00 2020: Debug: [suffix] = noop (120) Wed Jun 3 10:40:00 2020: Debug: ntdomain: Request already has destination realm set. Ignoring (120) Wed Jun 3 10:40:00 2020: Debug: [ntdomain] = noop (120) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent EAP Response (code 2) ID 25 length 6 (120) Wed Jun 3 10:40:00 2020: Debug: eap: Continuing tunnel setup (120) Wed Jun 3 10:40:00 2020: Debug: [eap] = ok (120) Wed Jun 3 10:40:00 2020: Debug: } # authorize = ok (120) Wed Jun 3 10:40:00 2020: Debug: Found Auth-Type = eap (120) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (120) Wed Jun 3 10:40:00 2020: Debug: authenticate { (120) Wed Jun 3 10:40:00 2020: Debug: eap: Expiring EAP session with state 0xa066b5d3a27fac78 (120) Wed Jun 3 10:40:00 2020: Debug: eap: Finished EAP session with state 0xa066b5d3a27fac78 (120) Wed Jun 3 10:40:00 2020: Debug: eap: Previous EAP request found for state 0xa066b5d3a27fac78, released from the list (120) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent packet with method EAP PEAP (25) (120) Wed Jun 3 10:40:00 2020: Debug: eap: Calling submodule eap_peap to process data (120) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Continuing EAP-TLS (120) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Peer ACKed our handshake fragment (120) Wed Jun 3 10:40:00 2020: Debug: eap_peap: [eaptls verify] = request (120) Wed Jun 3 10:40:00 2020: Debug: eappeap: [eaptls process] = handled (120) Wed Jun 3 10:40:00 2020: Debug: eap: Sending EAP Request (code 1) ID 26 length 724 (120) Wed Jun 3 10:40:00 2020: Debug: eap: EAP session adding &reply:State = 0xa066b5d3a37cac78 (120) Wed Jun 3 10:40:00 2020: Debug: [eap] = handled (120) Wed Jun 3 10:40:00 2020: Debug: } # authenticate = handled (120) Wed Jun 3 10:40:00 2020: Debug: Using Post-Auth-Type Challenge (120) Wed Jun 3 10:40:00 2020: Debug: Post-Auth-Type sub-section not found. Ignoring. (120) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (120) Wed Jun 3 10:40:00 2020: Debug: Sent Access-Challenge Id 82 from 10.10.20.40:1812 to 10.10.20.254:1812 length 0 (120) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x011a02d41900018237140204061e0400430041300e0603551d0f0101ff040403020186300f0603551d130101ff040530030101ff301d0603551d0e041604145baa7602a52e6820dad28008b044c4637a3d4492301006092b06010401823715010403020100300d06092a864886f70d01010b0500038201 (120) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (120) Wed Jun 3 10:40:00 2020: Debug: State = 0xa066b5d3a37cac78414a18978b5bd632 (120) Wed Jun 3 10:40:00 2020: Debug: Finished request (121) Wed Jun 3 10:40:00 2020: Debug: Received Access-Request Id 83 from 10.10.20.254:1812 to 10.10.20.40:1812 length 562 (121) Wed Jun 3 10:40:00 2020: Debug: Framed-MTU = 1492 (121) Wed Jun 3 10:40:00 2020: Debug: NAS-IP-Address = 10.10.20.254 (121) Wed Jun 3 10:40:00 2020: Debug: NAS-Identifier = "Aruba-2930F-8G-PoEP-2SFPP" (121) Wed Jun 3 10:40:00 2020: Debug: User-Name = "host/PC1189.nsi-labo.local" (121) Wed Jun 3 10:40:00 2020: Debug: Service-Type = Framed-User (121) Wed Jun 3 10:40:00 2020: Debug: Framed-Protocol = PPP (121) Wed Jun 3 10:40:00 2020: Debug: NAS-Port = 7 (121) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Type = Ethernet (121) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Id = "7" (121) Wed Jun 3 10:40:00 2020: Debug: Called-Station-Id = "98-f2-b3-bf-db-60" (121) Wed Jun 3 10:40:00 2020: Debug: Calling-Station-Id = "b4-b6-86-0d-8e-98" (121) Wed Jun 3 10:40:00 2020: Debug: Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex" (121) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Type:0 = VLAN (121) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Medium-Type:0 = IEEE-802 (121) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Private-Group-Id:0 = "1" (121) Wed Jun 3 10:40:00 2020: Debug: State = 0xa066b5d3a37cac78414a18978b5bd632 (121) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x021a008819800000007e160303004610000042410466ddc215e128f8ee7d11d32a24678c86e5499b21130afccbc19688945c6a85aa8fa49e07abfbf0b49ceece5b04b715d125fe09645412e9cd41ceeb3d807d7cfe140303000101160303002800000000000000001a311782c5bccc68fbc5a9cae80739 (121) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0x22846f0d59a7fcfb34c29e11f32fffa4 (121) Wed Jun 3 10:40:00 2020: Debug: MS-RAS-Vendor = 11 (121) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b28 (121) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b2e (121) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b30 (121) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b3d (121) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b18 (121) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b19 (121) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1b (121) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1c (121) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0138 (121) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x013a (121) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0140 (121) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0141 (121) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0151 (121) Wed Jun 3 10:40:00 2020: Debug: session-state: No cached attributes (121) Wed Jun 3 10:40:00 2020: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence (121) Wed Jun 3 10:40:00 2020: Debug: authorize { (121) Wed Jun 3 10:40:00 2020: Debug: update { (121) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Src-IP-Address} (121) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.254 (121) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Dst-IP-Address} (121) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.40 (121) Wed Jun 3 10:40:00 2020: Debug: EXPAND %l (121) Wed Jun 3 10:40:00 2020: Debug: --> 1591173600 (121) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (121) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-realm-if-machine { (121) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (121) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) -> TRUE (121) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (121) Wed Jun 3 10:40:00 2020: Debug: update { (121) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{2} (121) Wed Jun 3 10:40:00 2020: Debug: --> nsi-labo.local (121) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (121) Wed Jun 3 10:40:00 2020: Debug: } # if (User-Name =~ /host\/([a-z0-9_-])[.](.)/i) = noop (121) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-realm-if-machine = noop (121) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-balanced-key-policy { (121) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) { (121) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) -> FALSE (121) Wed Jun 3 10:40:00 2020: Debug: else { (121) Wed Jun 3 10:40:00 2020: Debug: update { (121) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (121) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (121) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (121) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (121) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (121) Wed Jun 3 10:40:00 2020: Debug: } # else = noop (121) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-balanced-key-policy = noop (121) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-tenant-id { (121) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){ (121) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE (121) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (121) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0} (121) Wed Jun 3 10:40:00 2020: Debug: --> 0 (121) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE (121) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (121) Wed Jun 3 10:40:00 2020: Debug: update control { (121) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{User-Name} (121) Wed Jun 3 10:40:00 2020: Debug: --> host/PC1189.nsi-labo.local (121) Wed Jun 3 10:40:00 2020: Debug: SQL-User-Name set to 'host/PC1189.nsi-labo.local' (121) Wed Jun 3 10:40:00 2020: Debug: Executing select query: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '10.10.20.254'), 0) (121) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{sql: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '%{NAS-IP-Address}'), 0)} (121) Wed Jun 3 10:40:00 2020: Debug: --> 1 (121) Wed Jun 3 10:40:00 2020: Debug: } # update control = noop (121) Wed Jun 3 10:40:00 2020: Debug: } # if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop (121) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) { (121) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE (121) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-tenant-id = noop (121) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_calling_station_id { (121) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (121) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) -> TRUE (121) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (121) Wed Jun 3 10:40:00 2020: Debug: update request { (121) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (121) Wed Jun 3 10:40:00 2020: Debug: --> b4:b6:86:0d:8e:98 (121) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (121) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (121) Wed Jun 3 10:40:00 2020: Debug: } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) = updated (121) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (121) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_calling_station_id = updated (121) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_called_station_id { (121) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (121) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) -> TRUE (121) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (121) Wed Jun 3 10:40:00 2020: Debug: update request { (121) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (121) Wed Jun 3 10:40:00 2020: Debug: --> 98:f2:b3:bf:db:60 (121) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (121) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") { (121) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{8} (121) Wed Jun 3 10:40:00 2020: Debug: --> (121) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") -> FALSE (121) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) { (121) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (121) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) { (121) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) -> FALSE (121) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) { (121) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (121) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (121) Wed Jun 3 10:40:00 2020: Debug: } # if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) = updated (121) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (121) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_called_station_id = updated (121) Wed Jun 3 10:40:00 2020: Debug: policy filter_username { (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) -> TRUE (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) { (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) -> FALSE (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) { (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) -> FALSE (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) { (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) -> FALSE (121) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) { (121) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) -> FALSE (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) { (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) -> FALSE (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) { (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) -> FALSE (121) Wed Jun 3 10:40:00 2020: Debug: } # if (&User-Name) = updated (121) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_username = updated (121) Wed Jun 3 10:40:00 2020: Debug: policy filter_password { (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) { (121) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE (121) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_password = updated (121) Wed Jun 3 10:40:00 2020: Debug: [preprocess] = ok (121) Wed Jun 3 10:40:00 2020: Debug: suffix: Request already has destination realm set. Ignoring (121) Wed Jun 3 10:40:00 2020: Debug: [suffix] = noop (121) Wed Jun 3 10:40:00 2020: Debug: ntdomain: Request already has destination realm set. Ignoring (121) Wed Jun 3 10:40:00 2020: Debug: [ntdomain] = noop (121) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent EAP Response (code 2) ID 26 length 136 (121) Wed Jun 3 10:40:00 2020: Debug: eap: Continuing tunnel setup (121) Wed Jun 3 10:40:00 2020: Debug: [eap] = ok (121) Wed Jun 3 10:40:00 2020: Debug: } # authorize = ok (121) Wed Jun 3 10:40:00 2020: Debug: Found Auth-Type = eap (121) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (121) Wed Jun 3 10:40:00 2020: Debug: authenticate { (121) Wed Jun 3 10:40:00 2020: Debug: eap: Expiring EAP session with state 0xa066b5d3a37cac78 (121) Wed Jun 3 10:40:00 2020: Debug: eap: Finished EAP session with state 0xa066b5d3a37cac78 (121) Wed Jun 3 10:40:00 2020: Debug: eap: Previous EAP request found for state 0xa066b5d3a37cac78, released from the list (121) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent packet with method EAP PEAP (25) (121) Wed Jun 3 10:40:00 2020: Debug: eap: Calling submodule eap_peap to process data (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Continuing EAP-TLS (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Peer indicated complete TLS record size will be 126 bytes (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Got complete TLS record (126 bytes) (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: [eaptls verify] = length included (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: SSLv3 read client key exchange A (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: SSLv3 read certificate verify A (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: SSLv3 read finished A (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: SSLv3 write change cipher spec A (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: SSLv3 write finished A (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS_accept: SSLv3 flush data (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: (other): SSL negotiation finished successfully (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS - Connection Established (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384" (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS-Session-Version = "TLS 1.2" (121) Wed Jun 3 10:40:00 2020: Debug: eap_peap: TLS - got 51 bytes of data (121) Wed Jun 3 10:40:00 2020: Debug: eappeap: [eaptls process] = handled (121) Wed Jun 3 10:40:00 2020: Debug: eap: Sending EAP Request (code 1) ID 27 length 57 (121) Wed Jun 3 10:40:00 2020: Debug: eap: EAP session adding &reply:State = 0xa066b5d3a47dac78 (121) Wed Jun 3 10:40:00 2020: Debug: [eap] = handled (121) Wed Jun 3 10:40:00 2020: Debug: } # authenticate = handled (121) Wed Jun 3 10:40:00 2020: Debug: Using Post-Auth-Type Challenge (121) Wed Jun 3 10:40:00 2020: Debug: Post-Auth-Type sub-section not found. Ignoring. (121) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (121) Wed Jun 3 10:40:00 2020: Debug: session-state: Saving cached attributes (121) Wed Jun 3 10:40:00 2020: Debug: TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384" (121) Wed Jun 3 10:40:00 2020: Debug: TLS-Session-Version = "TLS 1.2" (121) Wed Jun 3 10:40:00 2020: Debug: Sent Access-Challenge Id 83 from 10.10.20.40:1812 to 10.10.20.254:1812 length 0 (121) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x011b003919001403030001011603030028330a5248befa3e0522269a54130a1f53b98c403383fe3d6e8d0680e64bd85a0290133f039329c3c5 (121) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (121) Wed Jun 3 10:40:00 2020: Debug: State = 0xa066b5d3a47dac78414a18978b5bd632 (121) Wed Jun 3 10:40:00 2020: Debug: Finished request (122) Wed Jun 3 10:40:00 2020: Debug: Received Access-Request Id 84 from 10.10.20.254:1812 to 10.10.20.40:1812 length 432 (122) Wed Jun 3 10:40:00 2020: Debug: Framed-MTU = 1492 (122) Wed Jun 3 10:40:00 2020: Debug: NAS-IP-Address = 10.10.20.254 (122) Wed Jun 3 10:40:00 2020: Debug: NAS-Identifier = "Aruba-2930F-8G-PoEP-2SFPP" (122) Wed Jun 3 10:40:00 2020: Debug: User-Name = "host/PC1189.nsi-labo.local" (122) Wed Jun 3 10:40:00 2020: Debug: Service-Type = Framed-User (122) Wed Jun 3 10:40:00 2020: Debug: Framed-Protocol = PPP (122) Wed Jun 3 10:40:00 2020: Debug: NAS-Port = 7 (122) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Type = Ethernet (122) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Id = "7" (122) Wed Jun 3 10:40:00 2020: Debug: Called-Station-Id = "98-f2-b3-bf-db-60" (122) Wed Jun 3 10:40:00 2020: Debug: Calling-Station-Id = "b4-b6-86-0d-8e-98" (122) Wed Jun 3 10:40:00 2020: Debug: Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex" (122) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Type:0 = VLAN (122) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Medium-Type:0 = IEEE-802 (122) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Private-Group-Id:0 = "1" (122) Wed Jun 3 10:40:00 2020: Debug: State = 0xa066b5d3a47dac78414a18978b5bd632 (122) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x021b00061900 (122) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0xe3ca28e635652498cf32b2882d956810 (122) Wed Jun 3 10:40:00 2020: Debug: MS-RAS-Vendor = 11 (122) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b28 (122) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b2e (122) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b30 (122) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b3d (122) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b18 (122) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b19 (122) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1b (122) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1c (122) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0138 (122) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x013a (122) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0140 (122) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0141 (122) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0151 (122) Wed Jun 3 10:40:00 2020: Debug: Restoring &session-state (122) Wed Jun 3 10:40:00 2020: Debug: &session-state:TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384" (122) Wed Jun 3 10:40:00 2020: Debug: &session-state:TLS-Session-Version = "TLS 1.2" (122) Wed Jun 3 10:40:00 2020: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence (122) Wed Jun 3 10:40:00 2020: Debug: authorize { (122) Wed Jun 3 10:40:00 2020: Debug: update { (122) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Src-IP-Address} (122) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.254 (122) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Dst-IP-Address} (122) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.40 (122) Wed Jun 3 10:40:00 2020: Debug: EXPAND %l (122) Wed Jun 3 10:40:00 2020: Debug: --> 1591173600 (122) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (122) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-realm-if-machine { (122) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (122) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) -> TRUE (122) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (122) Wed Jun 3 10:40:00 2020: Debug: update { (122) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{2} (122) Wed Jun 3 10:40:00 2020: Debug: --> nsi-labo.local (122) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (122) Wed Jun 3 10:40:00 2020: Debug: } # if (User-Name =~ /host\/([a-z0-9_-])[.](.)/i) = noop (122) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-realm-if-machine = noop (122) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-balanced-key-policy { (122) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) { (122) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) -> FALSE (122) Wed Jun 3 10:40:00 2020: Debug: else { (122) Wed Jun 3 10:40:00 2020: Debug: update { (122) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (122) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (122) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (122) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (122) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (122) Wed Jun 3 10:40:00 2020: Debug: } # else = noop (122) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-balanced-key-policy = noop (122) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-tenant-id { (122) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){ (122) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE (122) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (122) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0} (122) Wed Jun 3 10:40:00 2020: Debug: --> 0 (122) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE (122) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (122) Wed Jun 3 10:40:00 2020: Debug: update control { (122) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{User-Name} (122) Wed Jun 3 10:40:00 2020: Debug: --> host/PC1189.nsi-labo.local (122) Wed Jun 3 10:40:00 2020: Debug: SQL-User-Name set to 'host/PC1189.nsi-labo.local' (122) Wed Jun 3 10:40:00 2020: Debug: Executing select query: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '10.10.20.254'), 0) (122) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{sql: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '%{NAS-IP-Address}'), 0)} (122) Wed Jun 3 10:40:00 2020: Debug: --> 1 (122) Wed Jun 3 10:40:00 2020: Debug: } # update control = noop (122) Wed Jun 3 10:40:00 2020: Debug: } # if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop (122) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) { (122) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE (122) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-tenant-id = noop (122) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_calling_station_id { (122) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (122) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) -> TRUE (122) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (122) Wed Jun 3 10:40:00 2020: Debug: update request { (122) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (122) Wed Jun 3 10:40:00 2020: Debug: --> b4:b6:86:0d:8e:98 (122) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (122) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (122) Wed Jun 3 10:40:00 2020: Debug: } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) = updated (122) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (122) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_calling_station_id = updated (122) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_called_station_id { (122) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (122) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) -> TRUE (122) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (122) Wed Jun 3 10:40:00 2020: Debug: update request { (122) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (122) Wed Jun 3 10:40:00 2020: Debug: --> 98:f2:b3:bf:db:60 (122) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (122) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") { (122) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{8} (122) Wed Jun 3 10:40:00 2020: Debug: --> (122) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") -> FALSE (122) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) { (122) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (122) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) { (122) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) -> FALSE (122) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) { (122) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (122) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (122) Wed Jun 3 10:40:00 2020: Debug: } # if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) = updated (122) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (122) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_called_station_id = updated (122) Wed Jun 3 10:40:00 2020: Debug: policy filter_username { (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) -> TRUE (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) { (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) -> FALSE (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) { (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) -> FALSE (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) { (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) -> FALSE (122) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) { (122) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) -> FALSE (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) { (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) -> FALSE (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) { (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) -> FALSE (122) Wed Jun 3 10:40:00 2020: Debug: } # if (&User-Name) = updated (122) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_username = updated (122) Wed Jun 3 10:40:00 2020: Debug: policy filter_password { (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) { (122) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE (122) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_password = updated (122) Wed Jun 3 10:40:00 2020: Debug: [preprocess] = ok (122) Wed Jun 3 10:40:00 2020: Debug: suffix: Request already has destination realm set. Ignoring (122) Wed Jun 3 10:40:00 2020: Debug: [suffix] = noop (122) Wed Jun 3 10:40:00 2020: Debug: ntdomain: Request already has destination realm set. Ignoring (122) Wed Jun 3 10:40:00 2020: Debug: [ntdomain] = noop (122) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent EAP Response (code 2) ID 27 length 6 (122) Wed Jun 3 10:40:00 2020: Debug: eap: Continuing tunnel setup (122) Wed Jun 3 10:40:00 2020: Debug: [eap] = ok (122) Wed Jun 3 10:40:00 2020: Debug: } # authorize = ok (122) Wed Jun 3 10:40:00 2020: Debug: Found Auth-Type = eap (122) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (122) Wed Jun 3 10:40:00 2020: Debug: authenticate { (122) Wed Jun 3 10:40:00 2020: Debug: eap: Expiring EAP session with state 0xa066b5d3a47dac78 (122) Wed Jun 3 10:40:00 2020: Debug: eap: Finished EAP session with state 0xa066b5d3a47dac78 (122) Wed Jun 3 10:40:00 2020: Debug: eap: Previous EAP request found for state 0xa066b5d3a47dac78, released from the list (122) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent packet with method EAP PEAP (25) (122) Wed Jun 3 10:40:00 2020: Debug: eap: Calling submodule eap_peap to process data (122) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Continuing EAP-TLS (122) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Peer ACKed our handshake fragment. handshake is finished (122) Wed Jun 3 10:40:00 2020: Debug: eap_peap: [eaptls verify] = success (122) Wed Jun 3 10:40:00 2020: Debug: eap_peap: [eaptls process] = success (122) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Session established. Decoding tunneled attributes (122) Wed Jun 3 10:40:00 2020: Debug: eappeap: PEAP state TUNNEL ESTABLISHED (122) Wed Jun 3 10:40:00 2020: Debug: eap: Sending EAP Request (code 1) ID 28 length 40 (122) Wed Jun 3 10:40:00 2020: Debug: eap: EAP session adding &reply:State = 0xa066b5d3a57aac78 (122) Wed Jun 3 10:40:00 2020: Debug: [eap] = handled (122) Wed Jun 3 10:40:00 2020: Debug: } # authenticate = handled (122) Wed Jun 3 10:40:00 2020: Debug: Using Post-Auth-Type Challenge (122) Wed Jun 3 10:40:00 2020: Debug: Post-Auth-Type sub-section not found. Ignoring. (122) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (122) Wed Jun 3 10:40:00 2020: Debug: session-state: Saving cached attributes (122) Wed Jun 3 10:40:00 2020: Debug: TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384" (122) Wed Jun 3 10:40:00 2020: Debug: TLS-Session-Version = "TLS 1.2" (122) Wed Jun 3 10:40:00 2020: Debug: Sent Access-Challenge Id 84 from 10.10.20.40:1812 to 10.10.20.254:1812 length 0 (122) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x011c00281900170303001d330a5248befa3e06c6ba19c375cf736cb814abbeb3595b833957239d76 (122) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (122) Wed Jun 3 10:40:00 2020: Debug: State = 0xa066b5d3a57aac78414a18978b5bd632 (122) Wed Jun 3 10:40:00 2020: Debug: Finished request (123) Wed Jun 3 10:40:00 2020: Debug: Received Access-Request Id 85 from 10.10.20.254:1812 to 10.10.20.40:1812 length 488 (123) Wed Jun 3 10:40:00 2020: Debug: Framed-MTU = 1492 (123) Wed Jun 3 10:40:00 2020: Debug: NAS-IP-Address = 10.10.20.254 (123) Wed Jun 3 10:40:00 2020: Debug: NAS-Identifier = "Aruba-2930F-8G-PoEP-2SFPP" (123) Wed Jun 3 10:40:00 2020: Debug: User-Name = "host/PC1189.nsi-labo.local" (123) Wed Jun 3 10:40:00 2020: Debug: Service-Type = Framed-User (123) Wed Jun 3 10:40:00 2020: Debug: Framed-Protocol = PPP (123) Wed Jun 3 10:40:00 2020: Debug: NAS-Port = 7 (123) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Type = Ethernet (123) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Id = "7" (123) Wed Jun 3 10:40:00 2020: Debug: Called-Station-Id = "98-f2-b3-bf-db-60" (123) Wed Jun 3 10:40:00 2020: Debug: Calling-Station-Id = "b4-b6-86-0d-8e-98" (123) Wed Jun 3 10:40:00 2020: Debug: Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex" (123) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Type:0 = VLAN (123) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Medium-Type:0 = IEEE-802 (123) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Private-Group-Id:0 = "1" (123) Wed Jun 3 10:40:00 2020: Debug: State = 0xa066b5d3a57aac78414a18978b5bd632 (123) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x021c003e1900170303003300000000000000018509a04df258cc808a8e99c7eeb38c1cbd979720af2db372a0bced430cfeba585fef667f972a72733d33f0 (123) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0x068c94e43cee1a0f642a030764f6c5d3 (123) Wed Jun 3 10:40:00 2020: Debug: MS-RAS-Vendor = 11 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b28 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b2e (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b30 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b3d (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b18 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b19 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1b (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1c (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0138 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x013a (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0140 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0141 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0151 (123) Wed Jun 3 10:40:00 2020: Debug: Restoring &session-state (123) Wed Jun 3 10:40:00 2020: Debug: &session-state:TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384" (123) Wed Jun 3 10:40:00 2020: Debug: &session-state:TLS-Session-Version = "TLS 1.2" (123) Wed Jun 3 10:40:00 2020: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence (123) Wed Jun 3 10:40:00 2020: Debug: authorize { (123) Wed Jun 3 10:40:00 2020: Debug: update { (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Src-IP-Address} (123) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.254 (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Dst-IP-Address} (123) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.40 (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %l (123) Wed Jun 3 10:40:00 2020: Debug: --> 1591173600 (123) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (123) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-realm-if-machine { (123) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (123) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) -> TRUE (123) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (123) Wed Jun 3 10:40:00 2020: Debug: update { (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{2} (123) Wed Jun 3 10:40:00 2020: Debug: --> nsi-labo.local (123) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (123) Wed Jun 3 10:40:00 2020: Debug: } # if (User-Name =~ /host\/([a-z0-9_-])[.](.)/i) = noop (123) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-realm-if-machine = noop (123) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-balanced-key-policy { (123) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: else { (123) Wed Jun 3 10:40:00 2020: Debug: update { (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (123) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (123) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (123) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (123) Wed Jun 3 10:40:00 2020: Debug: } # else = noop (123) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-balanced-key-policy = noop (123) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-tenant-id { (123) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){ (123) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0} (123) Wed Jun 3 10:40:00 2020: Debug: --> 0 (123) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE (123) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (123) Wed Jun 3 10:40:00 2020: Debug: update control { (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{User-Name} (123) Wed Jun 3 10:40:00 2020: Debug: --> host/PC1189.nsi-labo.local (123) Wed Jun 3 10:40:00 2020: Debug: SQL-User-Name set to 'host/PC1189.nsi-labo.local' (123) Wed Jun 3 10:40:00 2020: Debug: Executing select query: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '10.10.20.254'), 0) (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{sql: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '%{NAS-IP-Address}'), 0)} (123) Wed Jun 3 10:40:00 2020: Debug: --> 1 (123) Wed Jun 3 10:40:00 2020: Debug: } # update control = noop (123) Wed Jun 3 10:40:00 2020: Debug: } # if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop (123) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) { (123) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-tenant-id = noop (123) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_calling_station_id { (123) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) -> TRUE (123) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (123) Wed Jun 3 10:40:00 2020: Debug: update request { (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (123) Wed Jun 3 10:40:00 2020: Debug: --> b4:b6:86:0d:8e:98 (123) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (123) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (123) Wed Jun 3 10:40:00 2020: Debug: } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) = updated (123) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (123) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_calling_station_id = updated (123) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_called_station_id { (123) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (123) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) -> TRUE (123) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (123) Wed Jun 3 10:40:00 2020: Debug: update request { (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (123) Wed Jun 3 10:40:00 2020: Debug: --> 98:f2:b3:bf:db:60 (123) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (123) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") { (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{8} (123) Wed Jun 3 10:40:00 2020: Debug: --> (123) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) { (123) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) { (123) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) { (123) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (123) Wed Jun 3 10:40:00 2020: Debug: } # if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) = updated (123) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (123) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_called_station_id = updated (123) Wed Jun 3 10:40:00 2020: Debug: policy filter_username { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) -> TRUE (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) { (123) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: } # if (&User-Name) = updated (123) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_username = updated (123) Wed Jun 3 10:40:00 2020: Debug: policy filter_password { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_password = updated (123) Wed Jun 3 10:40:00 2020: Debug: [preprocess] = ok (123) Wed Jun 3 10:40:00 2020: Debug: suffix: Request already has destination realm set. Ignoring (123) Wed Jun 3 10:40:00 2020: Debug: [suffix] = noop (123) Wed Jun 3 10:40:00 2020: Debug: ntdomain: Request already has destination realm set. Ignoring (123) Wed Jun 3 10:40:00 2020: Debug: [ntdomain] = noop (123) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent EAP Response (code 2) ID 28 length 62 (123) Wed Jun 3 10:40:00 2020: Debug: eap: Continuing tunnel setup (123) Wed Jun 3 10:40:00 2020: Debug: [eap] = ok (123) Wed Jun 3 10:40:00 2020: Debug: } # authorize = ok (123) Wed Jun 3 10:40:00 2020: Debug: Found Auth-Type = eap (123) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (123) Wed Jun 3 10:40:00 2020: Debug: authenticate { (123) Wed Jun 3 10:40:00 2020: Debug: eap: Expiring EAP session with state 0xa066b5d3a57aac78 (123) Wed Jun 3 10:40:00 2020: Debug: eap: Finished EAP session with state 0xa066b5d3a57aac78 (123) Wed Jun 3 10:40:00 2020: Debug: eap: Previous EAP request found for state 0xa066b5d3a57aac78, released from the list (123) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent packet with method EAP PEAP (25) (123) Wed Jun 3 10:40:00 2020: Debug: eap: Calling submodule eap_peap to process data (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Continuing EAP-TLS (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: [eaptls verify] = ok (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Done initial handshake (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: [eaptls process] = ok (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Session established. Decoding tunneled attributes (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: PEAP state WAITING FOR INNER IDENTITY (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Identity - host/PC1189.nsi-labo.local (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Got inner identity 'host/PC1189.nsi-labo.local' (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Setting default EAP type for tunneled EAP session (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Got tunneled request (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: EAP-Message = 0x021c001f01686f73742f5043313138392e6e73692d6c61626f2e6c6f63616c (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Setting User-Name to host/PC1189.nsi-labo.local (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Sending tunneled request to packetfence-tunnel (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: EAP-Message = 0x021c001f01686f73742f5043313138392e6e73692d6c61626f2e6c6f63616c (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: User-Name = "host/PC1189.nsi-labo.local" (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Framed-MTU = 1492 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: NAS-IP-Address = 10.10.20.254 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: NAS-Identifier = "Aruba-2930F-8G-PoEP-2SFPP" (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Service-Type = Framed-User (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Framed-Protocol = PPP (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: NAS-Port = 7 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: NAS-Port-Type = Ethernet (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: NAS-Port-Id = "7" (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Calling-Station-Id := "b4:b6:86:0d:8e:98" (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex" (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Tunnel-Type:0 = VLAN (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Tunnel-Medium-Type:0 = IEEE-802 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Tunnel-Private-Group-Id:0 = "1" (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: MS-RAS-Vendor = 11 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: HP-Capability-Advert = 0x011a0000000b28 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: HP-Capability-Advert = 0x011a0000000b2e (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: HP-Capability-Advert = 0x011a0000000b30 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: HP-Capability-Advert = 0x011a0000000b3d (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: HP-Capability-Advert = 0x011a0000000b18 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: HP-Capability-Advert = 0x011a0000000b19 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: HP-Capability-Advert = 0x011a0000000b1b (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: HP-Capability-Advert = 0x011a0000000b1c (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: HP-Capability-Advert = 0x0138 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: HP-Capability-Advert = 0x013a (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: HP-Capability-Advert = 0x0140 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: HP-Capability-Advert = 0x0141 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: HP-Capability-Advert = 0x0151 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: PacketFence-Radius-Ip := "10.10.20.40" (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: PacketFence-KeyBalanced := "8063a5e8cea6c28a68e0ffa43791e430" (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Called-Station-Id := "98:f2:b3:bf:db:60" (123) Wed Jun 3 10:40:00 2020: Debug: eappeap: Event-Timestamp = "Jun 3 2020 10:40:00 CEST" (123) Wed Jun 3 10:40:00 2020: Debug: Virtual server packetfence-tunnel received request (123) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x021c001f01686f73742f5043313138392e6e73692d6c61626f2e6c6f63616c (123) Wed Jun 3 10:40:00 2020: Debug: FreeRADIUS-Proxied-To = 127.0.0.1 (123) Wed Jun 3 10:40:00 2020: Debug: User-Name = "host/PC1189.nsi-labo.local" (123) Wed Jun 3 10:40:00 2020: Debug: Framed-MTU = 1492 (123) Wed Jun 3 10:40:00 2020: Debug: NAS-IP-Address = 10.10.20.254 (123) Wed Jun 3 10:40:00 2020: Debug: NAS-Identifier = "Aruba-2930F-8G-PoEP-2SFPP" (123) Wed Jun 3 10:40:00 2020: Debug: Service-Type = Framed-User (123) Wed Jun 3 10:40:00 2020: Debug: Framed-Protocol = PPP (123) Wed Jun 3 10:40:00 2020: Debug: NAS-Port = 7 (123) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Type = Ethernet (123) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Id = "7" (123) Wed Jun 3 10:40:00 2020: Debug: Calling-Station-Id := "b4:b6:86:0d:8e:98" (123) Wed Jun 3 10:40:00 2020: Debug: Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex" (123) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Type:0 = VLAN (123) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Medium-Type:0 = IEEE-802 (123) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Private-Group-Id:0 = "1" (123) Wed Jun 3 10:40:00 2020: Debug: MS-RAS-Vendor = 11 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b28 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b2e (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b30 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b3d (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b18 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b19 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1b (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1c (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0138 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x013a (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0140 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0141 (123) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0151 (123) Wed Jun 3 10:40:00 2020: Debug: PacketFence-Radius-Ip := "10.10.20.40" (123) Wed Jun 3 10:40:00 2020: Debug: PacketFence-KeyBalanced := "8063a5e8cea6c28a68e0ffa43791e430" (123) Wed Jun 3 10:40:00 2020: Debug: Called-Station-Id := "98:f2:b3:bf:db:60" (123) Wed Jun 3 10:40:00 2020: Debug: Event-Timestamp = "Jun 3 2020 10:40:00 CEST" (123) Wed Jun 3 10:40:00 2020: WARNING: Outer and inner identities are the same. User privacy is compromised. (123) Wed Jun 3 10:40:00 2020: Debug: server packetfence-tunnel { (123) Wed Jun 3 10:40:00 2020: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence-tunnel (123) Wed Jun 3 10:40:00 2020: Debug: authorize { (123) Wed Jun 3 10:40:00 2020: Debug: if ( outer.EAP-Type == TTLS) { (123) Wed Jun 3 10:40:00 2020: Debug: if ( outer.EAP-Type == TTLS) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-realm-if-machine { (123) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (123) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) -> TRUE (123) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (123) Wed Jun 3 10:40:00 2020: Debug: update { (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{2} (123) Wed Jun 3 10:40:00 2020: Debug: --> nsi-labo.local (123) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (123) Wed Jun 3 10:40:00 2020: Debug: } # if (User-Name =~ /host\/([a-z0-9_-])[.](.)/i) = noop (123) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-realm-if-machine = noop (123) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-tenant-id { (123) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){ (123) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0} (123) Wed Jun 3 10:40:00 2020: Debug: --> 0 (123) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE (123) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (123) Wed Jun 3 10:40:00 2020: Debug: update control { (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{User-Name} (123) Wed Jun 3 10:40:00 2020: Debug: --> host/PC1189.nsi-labo.local (123) Wed Jun 3 10:40:00 2020: Debug: SQL-User-Name set to 'host/PC1189.nsi-labo.local' (123) Wed Jun 3 10:40:00 2020: Debug: Executing select query: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '10.10.20.254'), 0) (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{sql: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '%{NAS-IP-Address}'), 0)} (123) Wed Jun 3 10:40:00 2020: Debug: --> 1 (123) Wed Jun 3 10:40:00 2020: Debug: } # update control = noop (123) Wed Jun 3 10:40:00 2020: Debug: } # if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop (123) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) { (123) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-tenant-id = noop (123) Wed Jun 3 10:40:00 2020: Debug: policy filter_username { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) -> TRUE (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) { (123) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: } # if (&User-Name) = noop (123) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_username = noop (123) Wed Jun 3 10:40:00 2020: Debug: [mschap] = noop (123) Wed Jun 3 10:40:00 2020: Debug: suffix: Request already has destination realm set. Ignoring (123) Wed Jun 3 10:40:00 2020: Debug: [suffix] = noop (123) Wed Jun 3 10:40:00 2020: Debug: ntdomain: Request already has destination realm set. Ignoring (123) Wed Jun 3 10:40:00 2020: Debug: [ntdomain] = noop (123) Wed Jun 3 10:40:00 2020: Debug: update control { (123) Wed Jun 3 10:40:00 2020: Debug: } # update control = noop (123) Wed Jun 3 10:40:00 2020: Debug: userprincipalname: EXPAND %{User-Name} (123) Wed Jun 3 10:40:00 2020: Debug: userprincipalname: --> host/PC1189.nsi-labo.local (123) Wed Jun 3 10:40:00 2020: Debug: userprincipalname: Found entry for "host/PC1189.nsi-labo.local" (123) Wed Jun 3 10:40:00 2020: Debug: [userprincipalname] = ok (123) Wed Jun 3 10:40:00 2020: Debug: if (notfound) { (123) Wed Jun 3 10:40:00 2020: Debug: if (notfound) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: userprincipalname: EXPAND %{User-Name} (123) Wed Jun 3 10:40:00 2020: Debug: userprincipalname: --> host/PC1189.nsi-labo.local (123) Wed Jun 3 10:40:00 2020: Debug: userprincipalname: Found entry for "host/PC1189.nsi-labo.local" (123) Wed Jun 3 10:40:00 2020: Debug: userprincipalname: Merging cache entry into request (123) Wed Jun 3 10:40:00 2020: Debug: userprincipalname: &reply:Reply-Message += "Cache last updated at Wed Jun 3 10:17:21 2020" (123) Wed Jun 3 10:40:00 2020: Debug: userprincipalname: &reply:Class := 0x4b322f777978776d7451394a65782f5170414b2e737835367a444a7a54736845 (123) Wed Jun 3 10:40:00 2020: Debug: userprincipalname: &control:AD-Samaccountname += "PC1189$" (123) Wed Jun 3 10:40:00 2020: Debug: [userprincipalname] = ok (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'User-Name'} = &request:User-Name -> 'host/PC1189.nsi-labo.local' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'NAS-IP-Address'} = &request:NAS-IP-Address -> '10.10.20.254' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'NAS-Port'} = &request:NAS-Port -> '7' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Service-Type'} = &request:Service-Type -> 'Framed-User' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Framed-Protocol'} = &request:Framed-Protocol -> 'PPP' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Framed-MTU'} = &request:Framed-MTU -> '1492' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Called-Station-Id'} = &request:Called-Station-Id -> '98:f2:b3:bf:db:60' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Calling-Station-Id'} = &request:Calling-Station-Id -> 'b4:b6:86:0d:8e:98' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'NAS-Identifier'} = &request:NAS-Identifier -> 'Aruba-2930F-8G-PoEP-2SFPP' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'NAS-Port-Type'} = &request:NAS-Port-Type -> 'Ethernet' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Tunnel-Type'} = &request:Tunnel-Type -> 'VLAN' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Tunnel-Medium-Type'} = &request:Tunnel-Medium-Type -> 'IEEE-802' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Tunnel-Private-Group-Id'} = &request:Tunnel-Private-Group-Id -> '1' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Event-Timestamp'} = &request:Event-Timestamp -> 'Jun 3 2020 10:40:00 CEST' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Connect-Info'} = &request:Connect-Info -> 'CONNECT Ethernet 1000Mbps Full duplex' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'EAP-Message'} = &request:EAP-Message -> '0x021c001f01686f73742f5043313138392e6e73692d6c61626f2e6c6f63616c' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'NAS-Port-Id'} = &request:NAS-Port-Id -> '7' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'FreeRADIUS-Proxied-To'} = &request:FreeRADIUS-Proxied-To -> '127.0.0.1' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[0] = &request:HP-Capability-Advert -> '0x011a0000000b28' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[1] = &request:HP-Capability-Advert -> '0x011a0000000b2e' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[2] = &request:HP-Capability-Advert -> '0x011a0000000b30' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[3] = &request:HP-Capability-Advert -> '0x011a0000000b3d' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[4] = &request:HP-Capability-Advert -> '0x011a0000000b18' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[5] = &request:HP-Capability-Advert -> '0x011a0000000b19' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[6] = &request:HP-Capability-Advert -> '0x011a0000000b1b' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[7] = &request:HP-Capability-Advert -> '0x011a0000000b1c' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[8] = &request:HP-Capability-Advert -> '0x0138' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[9] = &request:HP-Capability-Advert -> '0x013a' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[10] = &request:HP-Capability-Advert -> '0x0140' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[11] = &request:HP-Capability-Advert -> '0x0141' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'HP-Capability-Advert'}[12] = &request:HP-Capability-Advert -> '0x0151' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'MS-RAS-Vendor'} = &request:MS-RAS-Vendor -> '11' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'Realm'} = &request:Realm -> 'nsi-labo.local' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'SQL-User-Name'} = &request:SQL-User-Name -> 'host/PC1189.nsi-labo.local' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'PacketFence-KeyBalanced'} = &request:PacketFence-KeyBalanced -> '8063a5e8cea6c28a68e0ffa43791e430' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REQUEST{'PacketFence-Radius-Ip'} = &request:PacketFence-Radius-Ip -> '10.10.20.40' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REPLY{'Reply-Message'} = &reply:Reply-Message -> 'Cache last updated at Wed Jun 3 10:17:21 2020' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_REPLY{'Class'} = &reply:Class -> '0x4b322f777978776d7451394a65782f5170414b2e737835367a444a7a54736845' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'EAP-Type'} = &control:EAP-Type -> 'MSCHAPv2' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'PacketFence-Tenant-Id'} = &control:PacketFence-Tenant-Id -> '1' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_CHECK{'AD-Samaccountname'} = &control:AD-Samaccountname -> 'PC1189$' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'EAP-Type'} = &control:EAP-Type -> 'MSCHAPv2' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'PacketFence-Tenant-Id'} = &control:PacketFence-Tenant-Id -> '1' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: $RAD_CONFIG{'AD-Samaccountname'} = &control:AD-Samaccountname -> 'PC1189$' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x011a0000000b28' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x011a0000000b2e' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x011a0000000b30' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x011a0000000b3d' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x011a0000000b18' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x011a0000000b19' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x011a0000000b1b' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x011a0000000b1c' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x0138' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x013a' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x0140' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x0141' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:HP-Capability-Advert += $RAD_REQUEST{'HP-Capability-Advert'} -> '0x0151' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:NAS-Port-Type = $RAD_REQUEST{'NAS-Port-Type'} -> 'Ethernet' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:PacketFence-Radius-Ip = $RAD_REQUEST{'PacketFence-Radius-Ip'} -> '10.10.20.40' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:MS-RAS-Vendor = $RAD_REQUEST{'MS-RAS-Vendor'} -> '11' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:Service-Type = $RAD_REQUEST{'Service-Type'} -> 'Framed-User' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:Called-Station-Id = $RAD_REQUEST{'Called-Station-Id'} -> '98:f2:b3:bf:db:60' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:FreeRADIUS-Proxied-To = $RAD_REQUEST{'FreeRADIUS-Proxied-To'} -> '127.0.0.1' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:Tunnel-Type:0 = $RAD_REQUEST{'Tunnel-Type:0'} -> 'VLAN' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:Connect-Info = $RAD_REQUEST{'Connect-Info'} -> 'CONNECT Ethernet 1000Mbps Full duplex' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:Realm = $RAD_REQUEST{'Realm'} -> 'nsi-labo.local' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:NAS-IP-Address = $RAD_REQUEST{'NAS-IP-Address'} -> '10.10.20.254' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:NAS-Port-Id = $RAD_REQUEST{'NAS-Port-Id'} -> '7' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:Tunnel-Medium-Type:0 = $RAD_REQUEST{'Tunnel-Medium-Type:0'} -> 'IEEE-802' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:SQL-User-Name = $RAD_REQUEST{'SQL-User-Name'} -> 'host/PC1189.nsi-labo.local' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:PacketFence-NTLMv2-Only = $RAD_REQUEST{'PacketFence-NTLMv2-Only'} -> '--allow-mschapv2' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:Calling-Station-Id = $RAD_REQUEST{'Calling-Station-Id'} -> 'b4:b6:86:0d:8e:98' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:PacketFence-KeyBalanced = $RAD_REQUEST{'PacketFence-KeyBalanced'} -> '8063a5e8cea6c28a68e0ffa43791e430' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:PacketFence-Domain = $RAD_REQUEST{'PacketFence-Domain'} -> 'NSILabo' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:Framed-Protocol = $RAD_REQUEST{'Framed-Protocol'} -> 'PPP' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:Tunnel-Private-Group-Id:0 = $RAD_REQUEST{'Tunnel-Private-Group-Id:0'} -> '1' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:User-Name = $RAD_REQUEST{'User-Name'} -> 'host/PC1189.nsi-labo.local' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:NAS-Identifier = $RAD_REQUEST{'NAS-Identifier'} -> 'Aruba-2930F-8G-PoEP-2SFPP' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:Event-Timestamp = $RAD_REQUEST{'Event-Timestamp'} -> 'Jun 3 2020 10:40:00 CEST' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:EAP-Message = $RAD_REQUEST{'EAP-Message'} -> '0x021c001f01686f73742f5043313138392e6e73692d6c61626f2e6c6f63616c' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:NAS-Port = $RAD_REQUEST{'NAS-Port'} -> '7' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &request:Framed-MTU = $RAD_REQUEST{'Framed-MTU'} -> '1492' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &reply:Reply-Message = $RAD_REPLY{'Reply-Message'} -> 'Cache last updated at Wed Jun 3 10:17:21 2020' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &reply:Class = $RAD_REPLY{'Class'} -> '0x4b322f777978776d7451394a65782f5170414b2e737835367a444a7a54736845' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &control:AD-Samaccountname = $RAD_CHECK{'AD-Samaccountname'} -> 'PC1189$' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &control:PacketFence-Tenant-Id = $RAD_CHECK{'PacketFence-Tenant-Id'} -> '1' (123) Wed Jun 3 10:40:00 2020: Debug: packetfence-multi-domain: &control:EAP-Type = $RAD_CHECK{'EAP-Type'} -> 'MSCHAPv2' (123) Wed Jun 3 10:40:00 2020: Debug: [packetfence-multi-domain] = updated (123) Wed Jun 3 10:40:00 2020: Debug: update control { (123) Wed Jun 3 10:40:00 2020: Debug: } # update control = noop (123) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent EAP Response (code 2) ID 28 length 31 (123) Wed Jun 3 10:40:00 2020: Debug: eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (123) Wed Jun 3 10:40:00 2020: Debug: [eap] = ok (123) Wed Jun 3 10:40:00 2020: Debug: } # authorize = ok (123) Wed Jun 3 10:40:00 2020: WARNING: You set Proxy-To-Realm = local, but it is a LOCAL realm! Cancelling proxy request. (123) Wed Jun 3 10:40:00 2020: Debug: Found Auth-Type = eap (123) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence-tunnel (123) Wed Jun 3 10:40:00 2020: Debug: authenticate { (123) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent packet with method EAP Identity (1) (123) Wed Jun 3 10:40:00 2020: ERROR: eap: Tried to start unsupported EAP type MSCHAPv2 (26) (123) Wed Jun 3 10:40:00 2020: Debug: eap: Sending EAP Failure (code 4) ID 28 length 4 (123) Wed Jun 3 10:40:00 2020: Debug: eap: Failed in EAP select (123) Wed Jun 3 10:40:00 2020: Debug: [eap] = invalid (123) Wed Jun 3 10:40:00 2020: Debug: } # authenticate = invalid (123) Wed Jun 3 10:40:00 2020: Debug: Failed to authenticate the user (123) Wed Jun 3 10:40:00 2020: Debug: Using Post-Auth-Type Reject (123) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence-tunnel (123) Wed Jun 3 10:40:00 2020: Debug: Post-Auth-Type REJECT { (123) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-tenant-id { (123) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){ (123) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0} (123) Wed Jun 3 10:40:00 2020: Debug: --> 1 (123) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) { (123) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-tenant-id = noop (123) Wed Jun 3 10:40:00 2020: Debug: update { (123) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (123) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-audit-log-reject { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name && (&User-Name == "dummy")) { (123) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name && (&User-Name == "dummy")) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: else { (123) Wed Jun 3 10:40:00 2020: Debug: policy request-timing { (123) Wed Jun 3 10:40:00 2020: Debug: if ("%{%{control:PacketFence-Request-Time}:-0}" != 0) { (123) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{%{control:PacketFence-Request-Time}:-0} (123) Wed Jun 3 10:40:00 2020: Debug: --> 0 (123) Wed Jun 3 10:40:00 2020: Debug: if ("%{%{control:PacketFence-Request-Time}:-0}" != 0) -> FALSE (123) Wed Jun 3 10:40:00 2020: Debug: } # policy request-timing = noop (123) Wed Jun 3 10:40:00 2020: Debug: sql_reject: EXPAND type.reject.query (123) Wed Jun 3 10:40:00 2020: Debug: sql_reject: --> type.reject.query (123) Wed Jun 3 10:40:00 2020: Debug: sql_reject: Using query template 'query' (123) Wed Jun 3 10:40:00 2020: Debug: sql_reject: EXPAND %{User-Name} (123) Wed Jun 3 10:40:00 2020: Debug: sql_reject: --> host/PC1189.nsi-labo.local (123) Wed Jun 3 10:40:00 2020: Debug: sql_reject: SQL-User-Name set to 'host/PC1189.nsi-labo.local' (123) Wed Jun 3 10:40:00 2020: Debug: sql_reject: EXPAND INSERT INTO radius_audit_log ( mac, ip, computer_name, user_name, stripped_user_name, realm, event_type, switch_id, switch_mac, switch_ip_address, radius_source_ip_address, called_station_id, calling_station_id, nas_port_type, ssid, nas_port_id, ifindex, nas_port, connection_type, nas_ip_address, nas_identifier, auth_status, reason, auth_type, eap_type, role, node_status, profile, source, auto_reg, is_phone, pf_domain, uuid, radius_request, radius_reply, request_time, tenant_id, radius_ip) VALUES ( '%{request:Calling-Station-Id}', '%{request:Framed-IP-Address}', '%{%{control:PacketFence-Computer-Name}:-N/A}', '%{request:User-Name}', '%{request:Stripped-User-Name}', '%{request:Realm}', 'Radius-Access-Request', '%{%{control:PacketFence-Switch-Id}:-N/A}', '%{%{control:PacketFence-Switch-Mac}:-N/A}', '%{%{control:PacketFence-Switch-Ip-Address}:-N/A}', '%{Packet-Src-IP-Address}', '%{request:Called-Station-Id}', '%{request:Calling-Station-Id}', '%{request:NAS-Port-Type}', '%{request:Called-Station-SSID}', '%{request:NAS-Port-Id}', '%{%{control:PacketFence-IfIndex}:-N/A}', '%{request:NAS-Port}', '%{%{control:PacketFence-Connection-Type}:-N/A}', '%{request:NAS-IP-Address}', '%{request:NAS-Identifier}', 'Reject', '%{request:Module-Failure-Message}', '%{control:Auth-Type}', '%{request:EAP-Type}', '%{%{control:PacketFence-Role}:-N/A}', '%{%{control:PacketFence-Status}:-N/A}', '%{%{control:PacketFence-Profile}:-N/A}', '%{%{control:PacketFence-Source}:-N/A}', '%{%{control:PacketFence-AutoReg}:-0}', '%{%{control:PacketFence-IsPhone}:-0}', '%{request:PacketFence-Domain}', '', '%{pairs:&request:[]}','%{pairs:&reply:[]}', '%{%{control:PacketFence-Request-Time}:-N/A}', '%{control:PacketFence-Tenant-Id}', '%{request:PacketFence-Radius-Ip}') (123) Wed Jun 3 10:40:00 2020: Debug: sql_reject: --> INSERT INTO radius_audit_log ( mac, ip, computer_name, user_name, stripped_user_name, realm, event_type, switch_id, switch_mac, switch_ip_address, radius_source_ip_address, called_station_id, calling_station_id, nas_port_type, ssid, nas_port_id, ifindex, nas_port, connection_type, nas_ip_address, nas_identifier, auth_status, reason, auth_type, eap_type, role, node_status, profile, source, auto_reg, is_phone, pf_domain, uuid, radius_request, radius_reply, request_time, tenant_id, radius_ip) VALUES ( 'b4:b6:86:0d:8e:98', '', 'N/A', 'host/PC1189.nsi-labo.local', '', 'nsi-labo.local', 'Radius-Access-Request', 'N/A', 'N/A', 'N/A', '10.10.20.254', '98:f2:b3:bf:db:60', 'b4:b6:86:0d:8e:98', 'Ethernet', '', '7', 'N/A', '7', 'N/A', '10.10.20.254', 'Aruba-2930F-8G-PoEP-2SFPP', 'Reject', 'eap: Tried to start unsupported EAP type MSCHAPv2 =2826=29', 'eap', 'Identity', 'N/A', 'N/A', 'N/A', 'N/A', '0', '0', 'NSILabo', '', 'HP-Capability-Advert =3D 0x011a0000000b28=2C HP-Capability-Advert =3D 0x011a0000000b2e=2C HP-Capability-Advert =3D 0x011a0000000b30=2C HP-Capability-Advert =3D 0x011a0000000b3d=2C HP-Capability-Advert =3D 0x011a0000000b18=2C HP-Capability-Advert =3D 0x011a0000000b19=2C HP-Capability-Advert =3D 0x011a0000000b1b=2C HP-Capability-Advert =3D 0x011a0000000b1c=2C HP-Capability-Advert =3D 0x0138=2C HP-Capability-Advert =3D 0x013a=2C HP-Capability-Advert =3D 0x0140=2C HP-Capability-Advert =3D 0x0141=2C HP-Capability-Advert =3D 0x0151=2C NAS-Port-Type =3D Ethernet=2C PacketFence-Radius-Ip =3D =2210.10.20.40=22=2C MS-RAS-Vendor =3D 11=2C Service-Type =3D Framed-User=2C Called-Station-Id =3D =2298:f2:b3:bf:db:60=22=2C FreeRADIUS-Proxied-To =3D 127.0.0.1=2C Tunnel-Type:0 =3D VLAN=2C Connect-Info =3D =22CONNECT Ethernet 1000Mbps Full duplex=22=2C Realm =3D =22nsi-labo.local=22=2C NAS-IP-Address =3D 10.10.20.254=2C NAS-Port-Id =3D =227=22=2C Tunnel-Medium-Type:0 =3D IEEE-802=2C PacketFence-NTLMv2-Only =3D =22--allow-mschapv2=22=2C Calling-Station-Id =3D =22b4:b6:86:0d:8e:98=22=2C PacketFence-KeyBalanced =3D =228063a5e8cea6c28a68e0ffa43791e430=22=2C PacketFence-Domain =3D =22NSILabo=22=2C Framed-Protocol =3D PPP=2C Tunnel-Private-Group-Id:0 =3D =221=22=2C User-Name =3D =22host/PC1189.nsi-labo.local=22=2C NAS-Identifier =3D =22Aruba-2930F-8G-PoEP-2SFPP=22=2C Event-Timestamp =3D =22Jun 3 2020 10:40:00 CEST=22=2C EAP-Message =3D 0x021c001f01686f73742f5043313138392e6e73692d6c61626f2e6c6f63616c=2C NAS-Port =3D 7=2C Framed-MTU =3D 1492=2C EAP-Type =3D Identity=2C Module-Failure-Message =3D =22eap: Tried to start unsupported EAP type MSCHAPv2 =2826=29=22=2C User-Password =3D =22=2A=2A=2A=2A=2A=2A=22=2C SQL-User-Name =3D =22host/PC1189.nsi-labo.local=22','Reply-Message =3D =22Cache last updated at Wed Jun 3 10:17:21 2020=22=2C Class =3D 0x4b322f777978776d7451394a65782f5170414b2e737835367a444a7a54736845=2C EAP-Message =3D 0x041c0004=2C Message-Authenticator =3D 0x00000000000000000000000000000000', 'N/A', '1', '10.10.20.40') (123) Wed Jun 3 10:40:00 2020: Debug: sql_reject: Executing query: INSERT INTO radius_audit_log ( mac, ip, computer_name, user_name, stripped_user_name, realm, event_type, switch_id, switch_mac, switch_ip_address, radius_source_ip_address, called_station_id, calling_station_id, nas_port_type, ssid, nas_port_id, ifindex, nas_port, connection_type, nas_ip_address, nas_identifier, auth_status, reason, auth_type, eap_type, role, node_status, profile, source, auto_reg, is_phone, pf_domain, uuid, radius_request, radius_reply, request_time, tenant_id, radius_ip) VALUES ( 'b4:b6:86:0d:8e:98', '', 'N/A', 'host/PC1189.nsi-labo.local', '', 'nsi-labo.local', 'Radius-Access-Request', 'N/A', 'N/A', 'N/A', '10.10.20.254', '98:f2:b3:bf:db:60', 'b4:b6:86:0d:8e:98', 'Ethernet', '', '7', 'N/A', '7', 'N/A', '10.10.20.254', 'Aruba-2930F-8G-PoEP-2SFPP', 'Reject', 'eap: Tried to start unsupported EAP type MSCHAPv2 =2826=29', 'eap', 'Identity', 'N/A', 'N/A', 'N/A', 'N/A', '0', '0', 'NSILabo', '', 'HP-Capability-Advert =3D 0x011a0000000b28=2C HP-Capability-Advert =3D 0x011a0000000b2e=2C HP-Capability-Advert =3D 0x011a0000000b30=2C HP-Capability-Advert =3D 0x011a0000000b3d=2C HP-Capability-Advert =3D 0x011a0000000b18=2C HP-Capability-Advert =3D 0x011a0000000b19=2C HP-Capability-Advert =3D 0x011a0000000b1b=2C HP-Capability-Advert =3D 0x011a0000000b1c=2C HP-Capability-Advert =3D 0x0138=2C HP-Capability-Advert =3D 0x013a=2C HP-Capability-Advert =3D 0x0140=2C HP-Capability-Advert =3D 0x0141=2C HP-Capability-Advert =3D 0x0151=2C NAS-Port-Type =3D Ethernet=2C PacketFence-Radius-Ip =3D =2210.10.20.40=22=2C MS-RAS-Vendor =3D 11=2C Service-Type =3D Framed-User=2C Called-Station-Id =3D =2298:f2:b3:bf:db:60=22=2C FreeRADIUS-Proxied-To =3D 127.0.0.1=2C Tunnel-Type:0 =3D VLAN=2C Connect-Info =3D =22CONNECT Ethernet 1000Mbps Full duplex=22=2C Realm =3D =22nsi-labo.local=22=2C NAS-IP-Address =3D 10.10.20.254=2C NAS-Port-Id =3D =227=22=2C Tunnel-Medium-Type:0 =3D IEEE-802=2C PacketFence-NTLMv2-Only =3D =22--allow-mschapv2=22=2C Calling-Station-Id =3D =22b4:b6:86:0d:8e:98=22=2C PacketFence-KeyBalanced =3D =228063a5e8cea6c28a68e0ffa43791e430=22=2C PacketFence-Domain =3D =22NSILabo=22=2C Framed-Protocol =3D PPP=2C Tunnel-Private-Group-Id:0 =3D =221=22=2C User-Name =3D =22host/PC1189.nsi-labo.local=22=2C NAS-Identifier =3D =22Aruba-2930F-8G-PoEP-2SFPP=22=2C Event-Timestamp =3D =22Jun 3 2020 10:40:00 CEST=22=2C EAP-Message =3D 0x021c001f01686f73742f5043313138392e6e73692d6c61626f2e6c6f63616c=2C NAS-Port =3D 7=2C Framed-MTU =3D 1492=2C EAP-Type =3D Identity=2C Module-Failure-Message =3D =22eap: Tried to start unsupported EAP type MSCHAPv2 =2826=29=22=2C User-Password =3D =22=2A=2A=2A=2A=2A=2A=22=2C SQL-User-Name =3D =22host/PC1189.nsi-labo.local=22','Reply-Message =3D =22Cache last updated at Wed Jun 3 10:17:21 2020=22=2C Class =3D 0x4b322f777978776d7451394a65782f5170414b2e737835367a444a7a54736845=2C EAP-Message =3D 0x041c0004=2C Message-Authenticator =3D 0x00000000000000000000000000000000', 'N/A', '1', '10.10.20.40') (123) Wed Jun 3 10:40:00 2020: Debug: sql_reject: SQL query returned: success (123) Wed Jun 3 10:40:00 2020: Debug: sql_reject: 1 record(s) updated (123) Wed Jun 3 10:40:00 2020: Debug: [sql_reject] = ok (123) Wed Jun 3 10:40:00 2020: Debug: } # else = ok (123) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-audit-log-reject = ok (123) Wed Jun 3 10:40:00 2020: Debug: attr_filter.access_reject: EXPAND %{User-Name} (123) Wed Jun 3 10:40:00 2020: Debug: attr_filter.access_reject: --> host/PC1189.nsi-labo.local (123) Wed Jun 3 10:40:00 2020: Debug: attr_filter.access_reject: Matched entry DEFAULT at line 11 (123) Wed Jun 3 10:40:00 2020: Debug: [attr_filter.access_reject] = updated (123) Wed Jun 3 10:40:00 2020: Debug: update outer.session-state { (123) Wed Jun 3 10:40:00 2020: Debug: } # update outer.session-state = noop (123) Wed Jun 3 10:40:00 2020: Debug: } # Post-Auth-Type REJECT = updated (123) Wed Jun 3 10:40:00 2020: Debug: } # server packetfence-tunnel (123) Wed Jun 3 10:40:00 2020: Debug: Virtual server sending reply (123) Wed Jun 3 10:40:00 2020: Debug: Reply-Message = "Cache last updated at Wed Jun 3 10:17:21 2020" (123) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x041c0004 (123) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Got tunneled reply code 3 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Reply-Message = "Cache last updated at Wed Jun 3 10:17:21 2020" (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: EAP-Message = 0x041c0004 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (123) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Tunneled authentication was rejected (123) Wed Jun 3 10:40:00 2020: Debug: eappeap: FAILURE (123) Wed Jun 3 10:40:00 2020: Debug: eap: Sending EAP Request (code 1) ID 29 length 46 (123) Wed Jun 3 10:40:00 2020: Debug: eap: EAP session adding &reply:State = 0xa066b5d3a67bac78 (123) Wed Jun 3 10:40:00 2020: Debug: [eap] = handled (123) Wed Jun 3 10:40:00 2020: Debug: } # authenticate = handled (123) Wed Jun 3 10:40:00 2020: Debug: Using Post-Auth-Type Challenge (123) Wed Jun 3 10:40:00 2020: Debug: Post-Auth-Type sub-section not found. Ignoring. (123) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (123) Wed Jun 3 10:40:00 2020: Debug: session-state: Saving cached attributes (123) Wed Jun 3 10:40:00 2020: Debug: TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384" (123) Wed Jun 3 10:40:00 2020: Debug: TLS-Session-Version = "TLS 1.2" (123) Wed Jun 3 10:40:00 2020: Debug: Module-Failure-Message := "eap: Tried to start unsupported EAP type MSCHAPv2 (26)" (123) Wed Jun 3 10:40:00 2020: Debug: Sent Access-Challenge Id 85 from 10.10.20.40:1812 to 10.10.20.254:1812 length 0 (123) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x011d002e19001703030023330a5248befa3e074556750eeaade0654f0b2f66d9bfb3f26a4430646cf5c7401c6b5e (123) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (123) Wed Jun 3 10:40:00 2020: Debug: State = 0xa066b5d3a67bac78414a18978b5bd632 (123) Wed Jun 3 10:40:00 2020: Debug: Finished request (124) Wed Jun 3 10:40:00 2020: Debug: Received Access-Request Id 86 from 10.10.20.254:1812 to 10.10.20.40:1812 length 472 (124) Wed Jun 3 10:40:00 2020: Debug: Framed-MTU = 1492 (124) Wed Jun 3 10:40:00 2020: Debug: NAS-IP-Address = 10.10.20.254 (124) Wed Jun 3 10:40:00 2020: Debug: NAS-Identifier = "Aruba-2930F-8G-PoEP-2SFPP" (124) Wed Jun 3 10:40:00 2020: Debug: User-Name = "host/PC1189.nsi-labo.local" (124) Wed Jun 3 10:40:00 2020: Debug: Service-Type = Framed-User (124) Wed Jun 3 10:40:00 2020: Debug: Framed-Protocol = PPP (124) Wed Jun 3 10:40:00 2020: Debug: NAS-Port = 7 (124) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Type = Ethernet (124) Wed Jun 3 10:40:00 2020: Debug: NAS-Port-Id = "7" (124) Wed Jun 3 10:40:00 2020: Debug: Called-Station-Id = "98-f2-b3-bf-db-60" (124) Wed Jun 3 10:40:00 2020: Debug: Calling-Station-Id = "b4-b6-86-0d-8e-98" (124) Wed Jun 3 10:40:00 2020: Debug: Connect-Info = "CONNECT Ethernet 1000Mbps Full duplex" (124) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Type:0 = VLAN (124) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Medium-Type:0 = IEEE-802 (124) Wed Jun 3 10:40:00 2020: Debug: Tunnel-Private-Group-Id:0 = "1" (124) Wed Jun 3 10:40:00 2020: Debug: State = 0xa066b5d3a67bac78414a18978b5bd632 (124) Wed Jun 3 10:40:00 2020: Debug: EAP-Message = 0x021d002e190017030300230000000000000002d2983d5f80ec5664785957b44a8d3aef412be986c17dc40d489191 (124) Wed Jun 3 10:40:00 2020: Debug: Message-Authenticator = 0xfdd7db0092899ccd2bfe8026ef65408b (124) Wed Jun 3 10:40:00 2020: Debug: MS-RAS-Vendor = 11 (124) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b28 (124) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b2e (124) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b30 (124) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b3d (124) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b18 (124) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b19 (124) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1b (124) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x011a0000000b1c (124) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0138 (124) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x013a (124) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0140 (124) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0141 (124) Wed Jun 3 10:40:00 2020: Debug: HP-Capability-Advert = 0x0151 (124) Wed Jun 3 10:40:00 2020: Debug: Restoring &session-state (124) Wed Jun 3 10:40:00 2020: Debug: &session-state:TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384" (124) Wed Jun 3 10:40:00 2020: Debug: &session-state:TLS-Session-Version = "TLS 1.2" (124) Wed Jun 3 10:40:00 2020: Debug: &session-state:Module-Failure-Message := "eap: Tried to start unsupported EAP type MSCHAPv2 (26)" (124) Wed Jun 3 10:40:00 2020: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence (124) Wed Jun 3 10:40:00 2020: Debug: authorize { (124) Wed Jun 3 10:40:00 2020: Debug: update { (124) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Src-IP-Address} (124) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.254 (124) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{Packet-Dst-IP-Address} (124) Wed Jun 3 10:40:00 2020: Debug: --> 10.10.20.40 (124) Wed Jun 3 10:40:00 2020: Debug: EXPAND %l (124) Wed Jun 3 10:40:00 2020: Debug: --> 1591173600 (124) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (124) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-realm-if-machine { (124) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (124) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) -> TRUE (124) Wed Jun 3 10:40:00 2020: Debug: if (User-Name =~ /host\/([a-z0-9-])[.](.)/i) { (124) Wed Jun 3 10:40:00 2020: Debug: update { (124) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{2} (124) Wed Jun 3 10:40:00 2020: Debug: --> nsi-labo.local (124) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (124) Wed Jun 3 10:40:00 2020: Debug: } # if (User-Name =~ /host\/([a-z0-9_-])[.](.)/i) = noop (124) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-realm-if-machine = noop (124) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-balanced-key-policy { (124) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) { (124) Wed Jun 3 10:40:00 2020: Debug: if (&PacketFence-KeyBalanced && (&PacketFence-KeyBalanced =~ /^(.)(.)$/i)) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: else { (124) Wed Jun 3 10:40:00 2020: Debug: update { (124) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (124) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (124) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{md5:%{Calling-Station-Id}%{User-Name}} (124) Wed Jun 3 10:40:00 2020: Debug: --> 8063a5e8cea6c28a68e0ffa43791e430 (124) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (124) Wed Jun 3 10:40:00 2020: Debug: } # else = noop (124) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-balanced-key-policy = noop (124) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-tenant-id { (124) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){ (124) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (124) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0} (124) Wed Jun 3 10:40:00 2020: Debug: --> 0 (124) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> TRUE (124) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (124) Wed Jun 3 10:40:00 2020: Debug: update control { (124) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{User-Name} (124) Wed Jun 3 10:40:00 2020: Debug: --> host/PC1189.nsi-labo.local (124) Wed Jun 3 10:40:00 2020: Debug: SQL-User-Name set to 'host/PC1189.nsi-labo.local' (124) Wed Jun 3 10:40:00 2020: Debug: Executing select query: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '10.10.20.254'), 0) (124) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{sql: SELECT IFNULL((SELECT tenant_id FROM radius_nas WHERE nasname = '%{NAS-IP-Address}'), 0)} (124) Wed Jun 3 10:40:00 2020: Debug: --> 1 (124) Wed Jun 3 10:40:00 2020: Debug: } # update control = noop (124) Wed Jun 3 10:40:00 2020: Debug: } # if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") = noop (124) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) { (124) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-tenant-id = noop (124) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_calling_station_id { (124) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (124) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) -> TRUE (124) Wed Jun 3 10:40:00 2020: Debug: if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) { (124) Wed Jun 3 10:40:00 2020: Debug: update request { (124) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (124) Wed Jun 3 10:40:00 2020: Debug: --> b4:b6:86:0d:8e:98 (124) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (124) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (124) Wed Jun 3 10:40:00 2020: Debug: } # if (&Calling-Station-Id && (&Calling-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})$/i)) = updated (124) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (124) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_calling_station_id = updated (124) Wed Jun 3 10:40:00 2020: Debug: policy rewrite_called_station_id { (124) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (124) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) -> TRUE (124) Wed Jun 3 10:40:00 2020: Debug: if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) { (124) Wed Jun 3 10:40:00 2020: Debug: update request { (124) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (124) Wed Jun 3 10:40:00 2020: Debug: --> 98:f2:b3:bf:db:60 (124) Wed Jun 3 10:40:00 2020: Debug: } # update request = noop (124) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") { (124) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{8} (124) Wed Jun 3 10:40:00 2020: Debug: --> (124) Wed Jun 3 10:40:00 2020: Debug: if ("%{8}") -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) { (124) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) { (124) Wed Jun 3 10:40:00 2020: Debug: elsif (Aruba-Essid-Name) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) { (124) Wed Jun 3 10:40:00 2020: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.)$/i) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: [updated] = updated (124) Wed Jun 3 10:40:00 2020: Debug: } # if ((&Called-Station-Id) && (&Called-Station-Id =~ /^([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})[^0-9a-f]?([0-9a-f]{2})(:(.+))?$/i)) = updated (124) Wed Jun 3 10:40:00 2020: Debug: ... skipping else: Preceding "if" was taken (124) Wed Jun 3 10:40:00 2020: Debug: } # policy rewrite_called_station_id = updated (124) Wed Jun 3 10:40:00 2020: Debug: policy filter_username { (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) -> TRUE (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name) { (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) { (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ / /) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) { (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@[^@]@/ ) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) { (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /../ ) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) { (124) Wed Jun 3 10:40:00 2020: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+).(.+)$/)) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) { (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /.$/) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) { (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Name =~ /@./) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: } # if (&User-Name) = updated (124) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_username = updated (124) Wed Jun 3 10:40:00 2020: Debug: policy filter_password { (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) { (124) Wed Jun 3 10:40:00 2020: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: } # policy filter_password = updated (124) Wed Jun 3 10:40:00 2020: Debug: [preprocess] = ok (124) Wed Jun 3 10:40:00 2020: Debug: suffix: Request already has destination realm set. Ignoring (124) Wed Jun 3 10:40:00 2020: Debug: [suffix] = noop (124) Wed Jun 3 10:40:00 2020: Debug: ntdomain: Request already has destination realm set. Ignoring (124) Wed Jun 3 10:40:00 2020: Debug: [ntdomain] = noop (124) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent EAP Response (code 2) ID 29 length 46 (124) Wed Jun 3 10:40:00 2020: Debug: eap: Continuing tunnel setup (124) Wed Jun 3 10:40:00 2020: Debug: [eap] = ok (124) Wed Jun 3 10:40:00 2020: Debug: } # authorize = ok (124) Wed Jun 3 10:40:00 2020: Debug: Found Auth-Type = eap (124) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (124) Wed Jun 3 10:40:00 2020: Debug: authenticate { (124) Wed Jun 3 10:40:00 2020: Debug: eap: Expiring EAP session with state 0xa066b5d3a67bac78 (124) Wed Jun 3 10:40:00 2020: Debug: eap: Finished EAP session with state 0xa066b5d3a67bac78 (124) Wed Jun 3 10:40:00 2020: Debug: eap: Previous EAP request found for state 0xa066b5d3a67bac78, released from the list (124) Wed Jun 3 10:40:00 2020: Debug: eap: Peer sent packet with method EAP PEAP (25) (124) Wed Jun 3 10:40:00 2020: Debug: eap: Calling submodule eap_peap to process data (124) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Continuing EAP-TLS (124) Wed Jun 3 10:40:00 2020: Debug: eap_peap: [eaptls verify] = ok (124) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Done initial handshake (124) Wed Jun 3 10:40:00 2020: Debug: eap_peap: [eaptls process] = ok (124) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Session established. Decoding tunneled attributes (124) Wed Jun 3 10:40:00 2020: Debug: eap_peap: PEAP state send tlv failure (124) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Received EAP-TLV response (124) Wed Jun 3 10:40:00 2020: ERROR: eap_peap: The users session was previously rejected: returning reject (again.) (124) Wed Jun 3 10:40:00 2020: Debug: eap_peap: This means you need to read the PREVIOUS messages in the debug output (124) Wed Jun 3 10:40:00 2020: Debug: eap_peap: to find out the reason why the user was rejected (124) Wed Jun 3 10:40:00 2020: Debug: eap_peap: Look for "reject" or "fail". Those earlier messages will tell you (124) Wed Jun 3 10:40:00 2020: Debug: eap_peap: what went wrong, and how to fix the problem (124) Wed Jun 3 10:40:00 2020: ERROR: eap: Failed continuing EAP PEAP (25) session. EAP sub-module failed (124) Wed Jun 3 10:40:00 2020: Debug: eap: Sending EAP Failure (code 4) ID 29 length 4 (124) Wed Jun 3 10:40:00 2020: Debug: eap: Failed in EAP select (124) Wed Jun 3 10:40:00 2020: Debug: [eap] = invalid (124) Wed Jun 3 10:40:00 2020: Debug: } # authenticate = invalid (124) Wed Jun 3 10:40:00 2020: Debug: Failed to authenticate the user (124) Wed Jun 3 10:40:00 2020: Debug: Using Post-Auth-Type Reject (124) Wed Jun 3 10:40:00 2020: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (124) Wed Jun 3 10:40:00 2020: Debug: Post-Auth-Type REJECT { (124) Wed Jun 3 10:40:00 2020: Debug: policy packetfence-set-tenant-id { (124) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0"){ (124) Wed Jun 3 10:40:00 2020: Debug: if (!NAS-IP-Address || NAS-IP-Address == "0.0.0.0") -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") { (124) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{%{control:PacketFence-Tenant-Id}:-0} (124) Wed Jun 3 10:40:00 2020: Debug: --> 1 (124) Wed Jun 3 10:40:00 2020: Debug: if ( "%{%{control:PacketFence-Tenant-Id}:-0}" == "0") -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) { (124) Wed Jun 3 10:40:00 2020: Debug: if ( &control:PacketFence-Tenant-Id == 0 ) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: } # policy packetfence-set-tenant-id = noop (124) Wed Jun 3 10:40:00 2020: Debug: update { (124) Wed Jun 3 10:40:00 2020: Debug: } # update = noop (124) Wed Jun 3 10:40:00 2020: Debug: if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) { (124) Wed Jun 3 10:40:00 2020: Debug: if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: if ("%{%{control:PacketFence-Proxied-From}:-False}" == "True") { (124) Wed Jun 3 10:40:00 2020: Debug: EXPAND %{%{control:PacketFence-Proxied-From}:-False} (124) Wed Jun 3 10:40:00 2020: Debug: --> False (124) Wed Jun 3 10:40:00 2020: Debug: if ("%{%{control:PacketFence-Proxied-From}:-False}" == "True") -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: attr_filter.access_reject: EXPAND %{User-Name} (124) Wed Jun 3 10:40:00 2020: Debug: attr_filter.access_reject: --> host/PC1189.nsi-labo.local (124) Wed Jun 3 10:40:00 2020: Debug: attr_filter.access_reject: Matched entry DEFAULT at line 11 (124) Wed Jun 3 10:40:00 2020: Debug: [attr_filter.access_reject] = updated (124) Wed Jun 3 10:40:00 2020: Debug: attr_filter.packetfence_post_auth: EXPAND %{User-Name} (124) Wed Jun 3 10:40:00 2020: Debug: attr_filter.packetfence_post_auth: --> host/PC1189.nsi-labo.local (124) Wed Jun 3 10:40:00 2020: Debug: attr_filter.packetfence_post_auth: Matched entry DEFAULT at line 10 (124) Wed Jun 3 10:40:00 2020: Debug: [attr_filter.packetfence_post_auth] = updated (124) Wed Jun 3 10:40:00 2020: Debug: [eap] = noop (124) Wed Jun 3 10:40:00 2020: Debug: policy remove_reply_message_if_eap { (124) Wed Jun 3 10:40:00 2020: Debug: if (&reply:EAP-Message && &reply:Reply-Message) { (124) Wed Jun 3 10:40:00 2020: Debug: if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE (124) Wed Jun 3 10:40:00 2020: Debug: else { (124) Wed Jun 3 10:40:00 2020: Debug: [noop] = noop (124) Wed Jun 3 10:40:00 2020: Debug: } # else = noop (124) Wed Jun 3 10:40:00 2020: Debug: } # policy remove_reply_message_if_eap = noop (124) Wed Jun 3 10:40:00 2020: Debug: linelog: EXPAND messages.%{%{reply:Packet-Type}:-default} (124) Wed Jun 3 10:40:00 2020: Debug: linelog: --> messages.Access-Reject (124) Wed Jun 3 10:40:00 2020: Debug: linelog: EXPAND [mac:%{Calling-Station-Id}] Rejected user: %{User-Name} (124) Wed Jun 3 10:40:00 2020: Debug: linelog: --> [mac:b4:b6:86:0d:8e:98] Rejected user: host/PC1189.nsi-labo.local (124) Wed Jun 3 10:40:00 2020: Debug: [linelog] = ok (124) Wed Jun 3 10:40:00 2020: Debug: } # Post-Auth-Type REJECT = updated (124) Wed Jun 3 10:40:00 2020: Debug: Delaying response for 1.000000 seconds (124) Wed Jun 3 10:40:01 2020: Debug: Sending delayed response (124) Wed Jun 3 10:40:01 2020: Debug: Sent Access-Reject Id 86 from 10.10.20.40:1812 to 10.10.20.254:1812 length 44 (124) Wed Jun 3 10:40:01 2020: Debug: EAP-Message = 0x041d0004 (124) Wed Jun 3 10:40:01 2020: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (116) Wed Jun 3 10:40:05 2020: Debug: Cleaning up request packet ID 204 with timestamp +1387

[extrafu]

Use the mailing list for that.

[whitezor]

Well that's why i came here.. There are no answers through the mailinglist... I was hoping somebody could help me there..

kr

Le ven. 5 juin 2020 à 12:30, Extra Fu notifications@github.com a écrit :

Closed #5535 https://github.com/inverse-inc/packetfence/issues/5535.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/inverse-inc/packetfence/issues/5535#event-3410701519, or unsubscribe https://github.com/notifications/unsubscribe-auth/AICXBPDWXY6KUYWCEBR63Q3RVDCMDANCNFSM4NTJ7NPQ .

-- Grégoire Vandendeurpel,

Network-Security Engineer

[extrafu]

Just be patient, the mailing list is free help.