January 2018 - Freeradius-Users - lists.freeradius.org

How to use sqlcounter to disconnect a user after reaching the daily quota?
by Houman 15 Jan '18

15 Jan '18

Hello & Merry Christmas. I have managed to enable accounting after all and it seems that the module sqlcounter is loaded too. Looking at the documentation here <https://freeradius.org/radiusd/man/rlm_counter.txt> The rlm_counter module provides a general framework to measure total data transferred in a given period. This is very useful in a 'Prepaid Service' situation, where a user has paid for a finite amount of usage and should not be allowed to use more than that service. This is perfect as I need exactly that. It seems I have to change count_attribute to data usage in order to measure the usage instead of session time, but I'm not quite sure where to find the accepted values. Nonetheless, I'm very confused how I'm supposed to use this module. I can see the module is loaded when I run it as freeradius -X. But how do I set it up to allow each user only 3 GB of data usage within a month? Or even for testing purposes 500KB on daily basis? When the month or the day has passed, then the user should be allowed access again. Which config files do I have to edit? Many Thanks for your advice, Houman

3 14

Conditional shell:priv-lvl as login reply on CISCO using client's source net and user's ldap attribute.
by Giuseppe Civitella 15 Jan '18

15 Jan '18

Hi all, I need to enable some users to login on different groups of CISCO devices getting different shell:priv-lvl. I'm trying to group the devices by their ip using a dynamic-clients template. I'd like to send them to a different virtual server based on source network of the auth request. Then I'd like to be able to choose which shell:priv-lvl give them using LDAP attributes like "o=groupA-shellPriv15" or "o=groupA-shellPriv7". I'm trying to achieve the first result using a configuration like this one: client my-dynclient { ipaddr = 10.200.20.0/24 dynamic_clients = my-dynclients lifetime = 3600 } server my-dynclients { authorize { if ("%{ldap:ldap:///BASEDN?objectClass?one?(radiusClientIdentifier=%{Packet-Src-IP-Address})}") { update control { &FreeRADIUS-Client-IP-Address = "%{Packet-Src-IP-Address}" &FreeRADIUS-Client-Shortname = "%{ldap:ldap:///BASEDN?radiusClientShortname,objectClass?one?(radiusClientIdentifier=%{Packet-Src-IP-Address})}" &FreeRADIUS-Client-Secret = "%{ldap:ldap:///BASEDN?radiusClientSecret,objectClass?one?(radiusClientIdentifier=%{Packet-Src-IP-Address})}" &FreeRADIUS-Client-Virtual-Server = "%{ldap:ldap:///BASEDN?radiusClientVirtualServer,objectClass?one?(radiusClientIdentifier=%{Packet-Src-IP-Address})}" } } ok } } when trying the login, the if condition succeeds: Fri Jan 12 16:12:57 2018 : Debug: rlm_ldap (ldap): Bind successful Fri Jan 12 16:12:57 2018 : Debug: (0) EXPAND %{ldap:ldap:///BASEDN?objectClass?one?(radiusClientIdentifier=%{Packet-Src-IP-Address})} Fri Jan 12 16:12:57 2018 : Debug: (0) --> radiusClient Fri Jan 12 16:12:57 2018 : Debug: (0) if ("%{ldap:ldap:///BASEDN?objectClass?one?(radiusClientIdentifier=%{Packet-Src-IP-Address})}") -> TRUE Fri Jan 12 16:12:57 2018 : Debug: (0) if ("%{ldap:ldap:///BASEDN?objectClass?one?(radiusClientIdentifier=%{Packet-Src-IP-Address})}") { Fri Jan 12 16:12:57 2018 : Debug: (0) update control { Fri Jan 12 16:12:57 2018 : Debug: (0) EXPAND %{Packet-Src-IP-Address} Fri Jan 12 16:12:57 2018 : Debug: (0) --> 10.200.20.79 Fri Jan 12 16:12:57 2018 : Debug: (0) &FreeRADIUS-Client-IP-Address = 10.200.20.79 Fri Jan 12 16:12:57 2018 : ERROR: (0) Bad attributes list in LDAP URL. URL must specify exactly one attribute to retrieve even if I get for the first time: "Bad attributes list in LDAP URL. URL must specify exactly one attribute to retrieve". While retrieving FreeRADIUS-Client-Shortname, FreeRADIUS-Client-Secret and FreeRADIUS-Client-Virtual-Server I got empty values and the same error about LDAP URL. I'm not sure about the debug message, I read that it is not possible to get just the value you need using an LDAP uri and no further filtering: am I wrong? Previously I did try to decide which privilege level send as a radiusReply by scanning the LDAP in a similar way: post-auth { ... if ("%{ldap:ldap://BASEDN?objectClass?one?(&(o=groupA-shellPriv15)(cn=%{User-Name})}") { update reply { #reply:ReplyAttribute += 'cisco-avpair = "shell:priv-lvl=15"' Reply-Message += "Bingo!!!" } } This worked in a setup without dynclients using the Reply-Message and raised an error while experimenting with the ReplyAttribute. Do someone have suggestions to realize such a setup? How much of this is possible to move to LDAP (and then eventually delegate to a web GUI)? Best regards, Giuseppe

2 2

rlm_perl
by Bassem Mettichi 14 Jan '18

14 Jan '18

Hello, please could someone tell us how to crypt Cleartext-Password with the CHAP-Challenge using rlm_perl on authorize method? need your help for a perl script to do this? Best Regards Mettichi Bassem

2 1

Freeradius 3.0.7 Multi-tenancy Radacct
by Emrah Yıldırım 13 Jan '18

13 Jan '18

Hi, I have added tenant_id columns to the NAS and Radacct tables in the Radius diagram. What I want to do is tenant_id of the tenant that I added to the NAS table, and users who authenticate with the captive portal will be equal to tenant_id in the Radacct table with the NAS connection. My goal is to allocate data in the RADACCT table for customers in the NAS table What arrangement should I make to ensure that. Please, help me. Regards

2 3

External Auth Script or local Auth
by JAHANZAIB SYED 13 Jan '18

13 Jan '18

Greetings, I am using Freeradius ver 2.1.10 I have noticed that some commercial radius servers (with freeradius backend) using External script (php/perl or C code) to authenticate users. I just wanted to know that what are the additional benefits of using external auth script over freeradius own authentication (via rad-groups) ? I made my own bash script that runs fine for authentication by checking user status in my_users table like expiry, disable/enable, quota, uptime etc , but for heavy load network like 20-30k users, what is recommended? script or local groups? Regards, JZ <http:///>

2 2

ERROR: eap: We expected EAP type PEAP, but received type MD5
by Truax, Peter 12 Jan '18

12 Jan '18

Hello everyone, I have a Packet Fence install running FreeRadius version freeradius-3.0.15-4.1.x86_64 on a CentOs VM. We are trying to authenticate using Mac-Auth-Bypass with a Dell 3500 switch. Below is the raddebug output when we attempt it. The significant portion of the debug output seems to be: 268) Mon Jan 8 14:04:01 2018: Debug: Found Auth-Type = eap (268) Mon Jan 8 14:04:01 2018: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (268) Mon Jan 8 14:04:01 2018: Debug: authenticate { (268) Mon Jan 8 14:04:01 2018: Debug: eap: Expiring EAP session with state 0x4dc5b0bd4dc4a935 (268) Mon Jan 8 14:04:01 2018: Debug: eap: Finished EAP session with state 0x4dc5b0bd4dc4a935 (268) Mon Jan 8 14:04:01 2018: Debug: eap: Previous EAP request found for state 0x4dc5b0bd4dc4a935, released from the list (268) Mon Jan 8 14:04:01 2018: ERROR: eap: Response appears to match a previous request, but the EAP type is wrong (268) Mon Jan 8 14:04:01 2018: ERROR: eap: We expected EAP type PEAP, but received type MD5 (268) Mon Jan 8 14:04:01 2018: ERROR: eap: Your Supplicant or NAS is probably broken (268) Mon Jan 8 14:04:01 2018: Debug: eap: Failed in handler (268) Mon Jan 8 14:04:01 2018: Debug: [eap] = invalid (268) Mon Jan 8 14:04:01 2018: Debug: } # authenticate = invalid (268) Mon Jan 8 14:04:01 2018: Debug: Failed to authenticate the user (268) Mon Jan 8 14:04:01 2018: Debug: Using Post-Auth-Type Reject The debug messages go to rejected from there. We have successfully authenticated with a different Dell switch (N1500), but cannot get the 3500s to work. The point where the 2 outputs deviates is the section: 265) Mon Jan 8 14:01:26 2018: Debug: Found Auth-Type = eap (265) Mon Jan 8 14:01:26 2018: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (265) Mon Jan 8 14:01:26 2018: Debug: authenticate { (265) Mon Jan 8 14:01:26 2018: Debug: eap: Expiring EAP session with state 0x26e9466f26e85fde (265) Mon Jan 8 14:01:26 2018: Debug: eap: Finished EAP session with state 0x26e9466f26e85fde (265) Mon Jan 8 14:01:26 2018: Debug: eap: Previous EAP request found for state 0x26e9466f26e85fde, released from the list (265) Mon Jan 8 14:01:26 2018: Debug: eap: Peer sent packet with method EAP NAK (3) (265) Mon Jan 8 14:01:26 2018: Debug: eap: Found mutually acceptable type MD5 (4) (265) Mon Jan 8 14:01:26 2018: Debug: eap: Calling submodule eap_md5 to process data Looking at the freeradius source code, I found that the " We expected EAP type PEAP, but received type MD5" error comes from FreeRadius. My question is what would cause this? And what configuration of either freeradius or the switch could I use to fix the issue? It seems that the switch isn't sending an EAP NAK packet that the server is expecting. Peter Truax Network Administrator (360) 688-2240 St. Martin's University 5000 Abbey Way E Lacey, WA 98503 P.S. Full Debug output for both switch types: **** Debug Output for Dell 3500 ***** (267) Mon Jan 8 14:04:01 2018: Debug: Received Access-Request Id 0 from 10.10.0.130:49154 to 10.0.1.44:1812 length 108 (267) Mon Jan 8 14:04:01 2018: Debug: NAS-IP-Address = 10.10.0.130 (267) Mon Jan 8 14:04:01 2018: Debug: NAS-Port-Type = Ethernet (267) Mon Jan 8 14:04:01 2018: Debug: NAS-Port = 7 (267) Mon Jan 8 14:04:01 2018: Debug: User-Name = "782bcbe1350b" (267) Mon Jan 8 14:04:01 2018: Debug: Calling-Station-Id = "78-2B-CB-E1-35-0B" (267) Mon Jan 8 14:04:01 2018: Debug: EAP-Message = 0x0200001101373832626362653133353062 (267) Mon Jan 8 14:04:01 2018: Debug: Message-Authenticator = 0x25c7983dccfc4d321955ff943818eb86 (267) Mon Jan 8 14:04:01 2018: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence (267) Mon Jan 8 14:04:01 2018: Debug: authorize { (267) Mon Jan 8 14:04:01 2018: Debug: update { (267) Mon Jan 8 14:04:01 2018: Debug: EXPAND %{Packet-Src-IP-Address} (267) Mon Jan 8 14:04:01 2018: Debug: --> 10.10.0.130 (267) Mon Jan 8 14:04:01 2018: Debug: EXPAND %l (267) Mon Jan 8 14:04:01 2018: Debug: --> 1515449041 (267) Mon Jan 8 14:04:01 2018: Debug: } # update = noop (267) Mon Jan 8 14:04:01 2018: Debug: policy rewrite_calling_station_id { (267) Mon Jan 8 14:04:01 2018: 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)) { (267) Mon Jan 8 14:04:01 2018: 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 (267) Mon Jan 8 14:04:01 2018: 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)) { (267) Mon Jan 8 14:04:01 2018: Debug: update request { (267) Mon Jan 8 14:04:01 2018: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (267) Mon Jan 8 14:04:01 2018: Debug: --> 78:2b:cb:e1:35:0b (267) Mon Jan 8 14:04:01 2018: Debug: } # update request = noop (267) Mon Jan 8 14:04:01 2018: Debug: [updated] = updated (267) Mon Jan 8 14:04:01 2018: 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 (267) Mon Jan 8 14:04:01 2018: Debug: ... skipping else: Preceding "if" was taken (267) Mon Jan 8 14:04:01 2018: Debug: } # policy rewrite_calling_station_id = updated (267) Mon Jan 8 14:04:01 2018: Debug: policy rewrite_called_station_id { (267) Mon Jan 8 14:04:01 2018: 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)) { (267) Mon Jan 8 14:04:01 2018: 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)) -> FALSE (267) Mon Jan 8 14:04:01 2018: Debug: else { (267) Mon Jan 8 14:04:01 2018: Debug: [noop] = noop (267) Mon Jan 8 14:04:01 2018: Debug: } # else = noop (267) Mon Jan 8 14:04:01 2018: Debug: } # policy rewrite_called_station_id = noop (267) Mon Jan 8 14:04:01 2018: Debug: policy filter_username { (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name) { (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name) -> TRUE (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name) { (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ / /) { (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ / /) -> FALSE (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /\.\./ ) { (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (267) Mon Jan 8 14:04:01 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (267) Mon Jan 8 14:04:01 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /\.$/) { (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /(a)\./) { (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (267) Mon Jan 8 14:04:01 2018: Debug: } # if (&User-Name) = updated (267) Mon Jan 8 14:04:01 2018: Debug: } # policy filter_username = updated (267) Mon Jan 8 14:04:01 2018: Debug: policy filter_password { (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) { (267) Mon Jan 8 14:04:01 2018: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE (267) Mon Jan 8 14:04:01 2018: Debug: } # policy filter_password = updated (267) Mon Jan 8 14:04:01 2018: Debug: [preprocess] = ok (267) Mon Jan 8 14:04:01 2018: Debug: suffix: Checking for suffix after "@" (267) Mon Jan 8 14:04:01 2018: Debug: suffix: No '@' in User-Name = "782bcbe1350b", skipping NULL due to config. (267) Mon Jan 8 14:04:01 2018: Debug: [suffix] = noop (267) Mon Jan 8 14:04:01 2018: Debug: ntdomain: Checking for prefix before "\" (267) Mon Jan 8 14:04:01 2018: Debug: ntdomain: No '\' in User-Name = "782bcbe1350b", looking up realm NULL (267) Mon Jan 8 14:04:01 2018: Debug: ntdomain: Found realm "null" (267) Mon Jan 8 14:04:01 2018: Debug: ntdomain: Adding Stripped-User-Name = "782bcbe1350b" (267) Mon Jan 8 14:04:01 2018: Debug: ntdomain: Adding Realm = "null" (267) Mon Jan 8 14:04:01 2018: Debug: ntdomain: Authentication realm is LOCAL (267) Mon Jan 8 14:04:01 2018: Debug: [ntdomain] = ok (267) Mon Jan 8 14:04:01 2018: Debug: eap: Peer sent EAP Response (code 2) ID 0 length 17 (267) Mon Jan 8 14:04:01 2018: Debug: eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (267) Mon Jan 8 14:04:01 2018: Debug: [eap] = ok (267) Mon Jan 8 14:04:01 2018: Debug: } # authorize = ok (267) Mon Jan 8 14:04:01 2018: Debug: Found Auth-Type = eap (267) Mon Jan 8 14:04:01 2018: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (267) Mon Jan 8 14:04:01 2018: Debug: authenticate { (267) Mon Jan 8 14:04:01 2018: Debug: eap: Peer sent packet with method EAP Identity (1) (267) Mon Jan 8 14:04:01 2018: Debug: eap: Calling submodule eap_peap to process data (267) Mon Jan 8 14:04:01 2018: Debug: eap_peap: Initiating new EAP-TLS session (267) Mon Jan 8 14:04:01 2018: Debug: eap_peap: [eaptls start] = request (267) Mon Jan 8 14:04:01 2018: Debug: eap: Sending EAP Request (code 1) ID 1 length 6 (267) Mon Jan 8 14:04:01 2018: Debug: eap: EAP session adding &reply:State = 0x4dc5b0bd4dc4a935 (267) Mon Jan 8 14:04:01 2018: Debug: [eap] = handled (267) Mon Jan 8 14:04:01 2018: Debug: } # authenticate = handled (267) Mon Jan 8 14:04:01 2018: Debug: Using Post-Auth-Type Challenge (267) Mon Jan 8 14:04:01 2018: Debug: Post-Auth-Type sub-section not found. Ignoring. (267) Mon Jan 8 14:04:01 2018: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (267) Mon Jan 8 14:04:01 2018: Debug: Sent Access-Challenge Id 0 from 10.0.1.44:1812 to 10.10.0.130:49154 length 0 (267) Mon Jan 8 14:04:01 2018: Debug: EAP-Message = 0x010100061920 (267) Mon Jan 8 14:04:01 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (267) Mon Jan 8 14:04:01 2018: Debug: State = 0x4dc5b0bd4dc4a935c0d86b7ff0b369b0 (267) Mon Jan 8 14:04:01 2018: Debug: Finished request (267) Mon Jan 8 14:04:01 2018: Debug: Cleaning up request packet ID 0 with timestamp +254115 (268) Mon Jan 8 14:04:01 2018: Debug: Received Access-Request Id 0 from 10.10.0.130:49154 to 10.0.1.44:1812 length 143 (268) Mon Jan 8 14:04:01 2018: Debug: NAS-IP-Address = 10.10.0.130 (268) Mon Jan 8 14:04:01 2018: Debug: NAS-Port-Type = Ethernet (268) Mon Jan 8 14:04:01 2018: Debug: NAS-Port = 7 (268) Mon Jan 8 14:04:01 2018: Debug: User-Name = "782bcbe1350b" (268) Mon Jan 8 14:04:01 2018: Debug: State = 0x4dc5b0bd4dc4a935c0d86b7ff0b369b0 (268) Mon Jan 8 14:04:01 2018: Debug: Calling-Station-Id = "78-2B-CB-E1-35-0B" (268) Mon Jan 8 14:04:01 2018: Debug: EAP-Message = 0x020100220410ee3ae909f6d578cba5049bf774ee2360373832626362653133353062 (268) Mon Jan 8 14:04:01 2018: Debug: Message-Authenticator = 0x8e93ade61a0f14ee8d6cb48b8c5aaf41 (268) Mon Jan 8 14:04:01 2018: Debug: session-state: No cached attributes (268) Mon Jan 8 14:04:01 2018: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence (268) Mon Jan 8 14:04:01 2018: Debug: authorize { (268) Mon Jan 8 14:04:01 2018: Debug: update { (268) Mon Jan 8 14:04:01 2018: Debug: EXPAND %{Packet-Src-IP-Address} (268) Mon Jan 8 14:04:01 2018: Debug: --> 10.10.0.130 (268) Mon Jan 8 14:04:01 2018: Debug: EXPAND %l (268) Mon Jan 8 14:04:01 2018: Debug: --> 1515449041 (268) Mon Jan 8 14:04:01 2018: Debug: } # update = noop (268) Mon Jan 8 14:04:01 2018: Debug: policy rewrite_calling_station_id { (268) Mon Jan 8 14:04:01 2018: 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)) { (268) Mon Jan 8 14:04:01 2018: 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 (268) Mon Jan 8 14:04:01 2018: 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)) { (268) Mon Jan 8 14:04:01 2018: Debug: update request { (268) Mon Jan 8 14:04:01 2018: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (268) Mon Jan 8 14:04:01 2018: Debug: --> 78:2b:cb:e1:35:0b (268) Mon Jan 8 14:04:01 2018: Debug: } # update request = noop (268) Mon Jan 8 14:04:01 2018: Debug: [updated] = updated (268) Mon Jan 8 14:04:01 2018: 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 (268) Mon Jan 8 14:04:01 2018: Debug: ... skipping else: Preceding "if" was taken (268) Mon Jan 8 14:04:01 2018: Debug: } # policy rewrite_calling_station_id = updated (268) Mon Jan 8 14:04:01 2018: Debug: policy rewrite_called_station_id { (268) Mon Jan 8 14:04:01 2018: 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)) { (268) Mon Jan 8 14:04:01 2018: 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)) -> FALSE (268) Mon Jan 8 14:04:01 2018: Debug: else { (268) Mon Jan 8 14:04:01 2018: Debug: [noop] = noop (268) Mon Jan 8 14:04:01 2018: Debug: } # else = noop (268) Mon Jan 8 14:04:01 2018: Debug: } # policy rewrite_called_station_id = noop (268) Mon Jan 8 14:04:01 2018: Debug: policy filter_username { (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name) { (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name) -> TRUE (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name) { (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ / /) { (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ / /) -> FALSE (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /\.\./ ) { (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (268) Mon Jan 8 14:04:01 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (268) Mon Jan 8 14:04:01 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /\.$/) { (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /(a)\./) { (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (268) Mon Jan 8 14:04:01 2018: Debug: } # if (&User-Name) = updated (268) Mon Jan 8 14:04:01 2018: Debug: } # policy filter_username = updated (268) Mon Jan 8 14:04:01 2018: Debug: policy filter_password { (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) { (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE (268) Mon Jan 8 14:04:01 2018: Debug: } # policy filter_password = updated (268) Mon Jan 8 14:04:01 2018: Debug: [preprocess] = ok (268) Mon Jan 8 14:04:01 2018: Debug: suffix: Checking for suffix after "@" (268) Mon Jan 8 14:04:01 2018: Debug: suffix: No '@' in User-Name = "782bcbe1350b", skipping NULL due to config. (268) Mon Jan 8 14:04:01 2018: Debug: [suffix] = noop (268) Mon Jan 8 14:04:01 2018: Debug: ntdomain: Checking for prefix before "\" (268) Mon Jan 8 14:04:01 2018: Debug: ntdomain: No '\' in User-Name = "782bcbe1350b", looking up realm NULL (268) Mon Jan 8 14:04:01 2018: Debug: ntdomain: Found realm "null" (268) Mon Jan 8 14:04:01 2018: Debug: ntdomain: Adding Stripped-User-Name = "782bcbe1350b" (268) Mon Jan 8 14:04:01 2018: Debug: ntdomain: Adding Realm = "null" (268) Mon Jan 8 14:04:01 2018: Debug: ntdomain: Authentication realm is LOCAL (268) Mon Jan 8 14:04:01 2018: Debug: [ntdomain] = ok (268) Mon Jan 8 14:04:01 2018: Debug: eap: Peer sent EAP Response (code 2) ID 1 length 34 (268) Mon Jan 8 14:04:01 2018: Debug: eap: No EAP Start, assuming it's an on-going EAP conversation (268) Mon Jan 8 14:04:01 2018: Debug: [eap] = updated (268) Mon Jan 8 14:04:01 2018: Debug: if ( !EAP-Message ) { (268) Mon Jan 8 14:04:01 2018: Debug: if ( !EAP-Message ) -> FALSE (268) Mon Jan 8 14:04:01 2018: Debug: policy packetfence-eap-mac-policy { (268) Mon Jan 8 14:04:01 2018: Debug: if ( &EAP-Type ) { (268) Mon Jan 8 14:04:01 2018: Debug: if ( &EAP-Type ) -> TRUE (268) Mon Jan 8 14:04:01 2018: Debug: if ( &EAP-Type ) { (268) Mon Jan 8 14:04:01 2018: 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)) { (268) Mon Jan 8 14:04:01 2018: 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 (268) Mon Jan 8 14:04:01 2018: 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)) { (268) Mon Jan 8 14:04:01 2018: Debug: update { (268) Mon Jan 8 14:04:01 2018: Debug: EXPAND %{tolower:%{1}%{2}%{3}%{4}%{5}%{6}} (268) Mon Jan 8 14:04:01 2018: Debug: --> 782bcbe1350b (268) Mon Jan 8 14:04:01 2018: Debug: } # update = noop (268) Mon Jan 8 14:04:01 2018: Debug: if ( &Tmp-String-1 == "%{tolower:%{User-Name}}" ) { (268) Mon Jan 8 14:04:01 2018: Debug: EXPAND %{tolower:%{User-Name}} (268) Mon Jan 8 14:04:01 2018: Debug: --> 782bcbe1350b (268) Mon Jan 8 14:04:01 2018: Debug: if ( &Tmp-String-1 == "%{tolower:%{User-Name}}" ) -> TRUE (268) Mon Jan 8 14:04:01 2018: Debug: if ( &Tmp-String-1 == "%{tolower:%{User-Name}}" ) { (268) Mon Jan 8 14:04:01 2018: Debug: update { (268) Mon Jan 8 14:04:01 2018: Debug: } # update = noop (268) Mon Jan 8 14:04:01 2018: Debug: [updated] = updated (268) Mon Jan 8 14:04:01 2018: Debug: } # if ( &Tmp-String-1 == "%{tolower:%{User-Name}}" ) = updated (268) Mon Jan 8 14:04:01 2018: 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 (268) Mon Jan 8 14:04:01 2018: Debug: } # if ( &EAP-Type ) = updated (268) Mon Jan 8 14:04:01 2018: Debug: [noop] = noop (268) Mon Jan 8 14:04:01 2018: Debug: } # policy packetfence-eap-mac-policy = updated (268) Mon Jan 8 14:04:01 2018: WARNING: pap: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! (268) Mon Jan 8 14:04:01 2018: WARNING: pap: !!! Ignoring control:User-Password. Update your !!! (268) Mon Jan 8 14:04:01 2018: WARNING: pap: !!! configuration so that the "known good" clear text !!! (268) Mon Jan 8 14:04:01 2018: WARNING: pap: !!! password is in Cleartext-Password and NOT in !!! (268) Mon Jan 8 14:04:01 2018: WARNING: pap: !!! User-Password. !!! (268) Mon Jan 8 14:04:01 2018: WARNING: pap: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! (268) Mon Jan 8 14:04:01 2018: WARNING: pap: Auth-Type already set. Not setting to PAP (268) Mon Jan 8 14:04:01 2018: Debug: [pap] = noop (268) Mon Jan 8 14:04:01 2018: Debug: } # authorize = updated (268) Mon Jan 8 14:04:01 2018: Debug: Found Auth-Type = eap (268) Mon Jan 8 14:04:01 2018: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (268) Mon Jan 8 14:04:01 2018: Debug: authenticate { (268) Mon Jan 8 14:04:01 2018: Debug: eap: Expiring EAP session with state 0x4dc5b0bd4dc4a935 (268) Mon Jan 8 14:04:01 2018: Debug: eap: Finished EAP session with state 0x4dc5b0bd4dc4a935 (268) Mon Jan 8 14:04:01 2018: Debug: eap: Previous EAP request found for state 0x4dc5b0bd4dc4a935, released from the list (268) Mon Jan 8 14:04:01 2018: ERROR: eap: Response appears to match a previous request, but the EAP type is wrong (268) Mon Jan 8 14:04:01 2018: ERROR: eap: We expected EAP type PEAP, but received type MD5 (268) Mon Jan 8 14:04:01 2018: ERROR: eap: Your Supplicant or NAS is probably broken (268) Mon Jan 8 14:04:01 2018: Debug: eap: Failed in handler (268) Mon Jan 8 14:04:01 2018: Debug: [eap] = invalid (268) Mon Jan 8 14:04:01 2018: Debug: } # authenticate = invalid (268) Mon Jan 8 14:04:01 2018: Debug: Failed to authenticate the user (268) Mon Jan 8 14:04:01 2018: Debug: Using Post-Auth-Type Reject (268) Mon Jan 8 14:04:01 2018: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (268) Mon Jan 8 14:04:01 2018: Debug: Post-Auth-Type REJECT { (268) Mon Jan 8 14:04:01 2018: Debug: update { (268) Mon Jan 8 14:04:01 2018: Debug: } # update = noop (268) Mon Jan 8 14:04:01 2018: Debug: if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) { (268) Mon Jan 8 14:04:01 2018: Debug: if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) -> TRUE (268) Mon Jan 8 14:04:01 2018: Debug: if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) { (268) Mon Jan 8 14:04:01 2018: Debug: policy packetfence-audit-log-reject { (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name != "dummy") { (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name != "dummy") -> TRUE (268) Mon Jan 8 14:04:01 2018: Debug: if (&User-Name != "dummy") { (268) Mon Jan 8 14:04:01 2018: Debug: policy request-timing { (268) Mon Jan 8 14:04:01 2018: Debug: if (control:PacketFence-Request-Time != 0) { (268) Mon Jan 8 14:04:01 2018: Debug: if (control:PacketFence-Request-Time != 0) -> FALSE (268) Mon Jan 8 14:04:01 2018: Debug: } # policy request-timing = noop (268) Mon Jan 8 14:04:01 2018: Debug: sql_reject: EXPAND type.reject.query (268) Mon Jan 8 14:04:01 2018: Debug: sql_reject: --> type.reject.query (268) Mon Jan 8 14:04:01 2018: Debug: sql_reject: Using query template 'query' (268) Mon Jan 8 14:04:01 2018: Debug: sql_reject: EXPAND %{User-Name} (268) Mon Jan 8 14:04:01 2018: Debug: sql_reject: --> 782bcbe1350b (268) Mon Jan 8 14:04:01 2018: Debug: sql_reject: SQL-User-Name set to '782bcbe1350b' (268) Mon Jan 8 14:04:01 2018: 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) 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}:-N/A}', '%{%{control:PacketFence-IsPhone}:-N/A}', '%{request:PacketFence-Domain}', '', '%{pairs:&request:[*]}','%{pairs:&reply:[*]}', '%{%{control:PacketFence-Request-Time}:-N/A}') (268) Mon Jan 8 14:04:01 2018: 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) VALUES ( '78:2b:cb:e1:35:0b', '', 'N/A', '782bcbe1350b', '782bcbe1350b', 'null', 'Radius-Access-Request', 'N/A', 'N/A', 'N/A', '10.10.0.130', '', '78:2b:cb:e1:35:0b', 'Ethernet', '', '', 'N/A', '7', 'N/A', '10.10.0.130', '', 'Reject', 'eap: Response appears to match a previous request=2C but the EAP type is wrong', 'eap', 'MD5', 'N/A', 'N/A', 'N/A', 'N/A', 'N/A', 'N/A', '', '', 'NAS-IP-Address =3D 10.10.0.130=2C NAS-Port-Type =3D Ethernet=2C NAS-Port =3D 7=2C User-Name =3D =22782bcbe1350b=22=2C State =3D 0x4dc5b0bd4dc4a935c0d86b7ff0b369b0=2C Calling-Station-Id =3D =2278:2b:cb:e1:35:0b=22=2C EAP-Message =3D 0x020100220410ee3ae909f6d578cba5049bf774ee2360373832626362653133353062=2C Message-Authenticator =3D 0x8e93ade61a0f14ee8d6cb48b8c5aaf41=2C FreeRADIUS-Client-IP-Address =3D 10.10.0.130=2C Event-Timestamp =3D =22Jan 8 2018 14:04:01 PST=22=2C Stripped-User-Name =3D =22782bcbe1350b=22=2C Realm =3D =22null=22=2C EAP-Type =3D MD5=2C Tmp-String-1 =3D =22782bcbe1350b=22=2C Module-Failure-Message =3D =22eap: Response appears to match a previous request=2C but the EAP type is wrong=22=2C Module-Failure-Message =3D =22eap: We expected EAP type PEAP=2C but received type MD5=22=2C Module-Failure-Message =3D =22eap: Your Supplicant or NAS is probably broken=22=2C User-Password =3D =22=2A=2A=2A=2A=2A=2A=22=2C SQL-User-Name =3D =22782bcbe1350b=22','', '0') (268) Mon Jan 8 14:04:01 2018: 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) VALUES ( '78:2b:cb:e1:35:0b', '', 'N/A', '782bcbe1350b', '782bcbe1350b', 'null', 'Radius-Access-Request', 'N/A', 'N/A', 'N/A', '10.10.0.130', '', '78:2b:cb:e1:35:0b', 'Ethernet', '', '', 'N/A', '7', 'N/A', '10.10.0.130', '', 'Reject', 'eap: Response appears to match a previous request=2C but the EAP type is wrong', 'eap', 'MD5', 'N/A', 'N/A', 'N/A', 'N/A', 'N/A', 'N/A', '', '', 'NAS-IP-Address =3D 10.10.0.130=2C NAS-Port-Type =3D Ethernet=2C NAS-Port =3D 7=2C User-Name =3D =22782bcbe1350b=22=2C State =3D 0x4dc5b0bd4dc4a935c0d86b7ff0b369b0=2C Calling-Station-Id =3D =2278:2b:cb:e1:35:0b=22=2C EAP-Message =3D 0x020100220410ee3ae909f6d578cba5049bf774ee2360373832626362653133353062=2C Message-Authenticator =3D 0x8e93ade61a0f14ee8d6cb48b8c5aaf41=2C FreeRADIUS-Client-IP-Address =3D 10.10.0.130=2C Event-Timestamp =3D =22Jan 8 2018 14:04:01 PST=22=2C Stripped-User-Name =3D =22782bcbe1350b=22=2C Realm =3D =22null=22=2C EAP-Type =3D MD5=2C Tmp-String-1 =3D =22782bcbe1350b=22=2C Module-Failure-Message =3D =22eap: Response appears to match a previous request=2C but the EAP type is wrong=22=2C Module-Failure-Message =3D =22eap: We expected EAP type PEAP=2C but received type MD5=22=2C Module-Failure-Message =3D =22eap: Your Supplicant or NAS is probably broken=22=2C User-Password =3D =22=2A=2A=2A=2A=2A=2A=22=2C SQL-User-Name =3D =22782bcbe1350b=22','', '0') (268) Mon Jan 8 14:04:01 2018: Debug: sql_reject: SQL query returned: success (268) Mon Jan 8 14:04:01 2018: Debug: sql_reject: 1 record(s) updated (268) Mon Jan 8 14:04:01 2018: Debug: [sql_reject] = ok (268) Mon Jan 8 14:04:01 2018: Debug: } # if (&User-Name != "dummy") = ok (268) Mon Jan 8 14:04:01 2018: Debug: } # policy packetfence-audit-log-reject = ok (268) Mon Jan 8 14:04:01 2018: Debug: } # if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) = ok (268) Mon Jan 8 14:04:01 2018: Debug: attr_filter.access_reject: EXPAND %{User-Name} (268) Mon Jan 8 14:04:01 2018: Debug: attr_filter.access_reject: --> 782bcbe1350b (268) Mon Jan 8 14:04:01 2018: Debug: attr_filter.access_reject: Matched entry DEFAULT at line 11 (268) Mon Jan 8 14:04:01 2018: Debug: [attr_filter.access_reject] = updated (268) Mon Jan 8 14:04:01 2018: Debug: attr_filter.packetfence_post_auth: EXPAND %{User-Name} (268) Mon Jan 8 14:04:01 2018: Debug: attr_filter.packetfence_post_auth: --> 782bcbe1350b (268) Mon Jan 8 14:04:01 2018: Debug: attr_filter.packetfence_post_auth: Matched entry DEFAULT at line 10 (268) Mon Jan 8 14:04:01 2018: Debug: [attr_filter.packetfence_post_auth] = updated (268) Mon Jan 8 14:04:01 2018: ERROR: eap: rlm_eap (EAP): No EAP session matching state 0x4dc5b0bd4dc4a935 (268) Mon Jan 8 14:04:01 2018: Debug: eap: Either EAP-request timed out OR EAP-response to an unknown EAP-request (268) Mon Jan 8 14:04:01 2018: Debug: eap: Failed to get handler, probably already removed, not inserting EAP-Failure (268) Mon Jan 8 14:04:01 2018: Debug: [eap] = noop (268) Mon Jan 8 14:04:01 2018: Debug: policy remove_reply_message_if_eap { (268) Mon Jan 8 14:04:01 2018: Debug: if (&reply:EAP-Message && &reply:Reply-Message) { (268) Mon Jan 8 14:04:01 2018: Debug: if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE (268) Mon Jan 8 14:04:01 2018: Debug: else { (268) Mon Jan 8 14:04:01 2018: Debug: [noop] = noop (268) Mon Jan 8 14:04:01 2018: Debug: } # else = noop (268) Mon Jan 8 14:04:01 2018: Debug: } # policy remove_reply_message_if_eap = noop (268) Mon Jan 8 14:04:01 2018: Debug: linelog: EXPAND messages.%{%{reply:Packet-Type}:-default} (268) Mon Jan 8 14:04:01 2018: Debug: linelog: --> messages.Access-Reject (268) Mon Jan 8 14:04:01 2018: Debug: linelog: EXPAND [mac:%{Calling-Station-Id}] Rejected user: %{User-Name} (268) Mon Jan 8 14:04:01 2018: Debug: linelog: --> [mac:78:2b:cb:e1:35:0b] Rejected user: 782bcbe1350b (268) Mon Jan 8 14:04:01 2018: Debug: [linelog] = ok (268) Mon Jan 8 14:04:01 2018: Debug: } # Post-Auth-Type REJECT = updated (268) Mon Jan 8 14:04:01 2018: Debug: Delaying response for 1.000000 seconds (268) Mon Jan 8 14:04:02 2018: Debug: Sending delayed response (268) Mon Jan 8 14:04:02 2018: Debug: Sent Access-Reject Id 0 from 10.0.1.44:1812 to 10.10.0.130:49154 length 20 (268) Mon Jan 8 14:04:06 2018: Debug: Cleaning up request packet ID 0 with timestamp +254115 ***** Debug Output For Dell N1500 ***** ]0;root@netreg:~ [?1034h[root@netreg ~]# raddebug -f /usr/local/pf/var/run/radiusd.sock -t 3600 (264) Mon Jan 8 14:01:26 2018: Debug: Received Access-Request Id 44 from 10.10.0.133:55190 to 10.0.1.44:1812 length 152 (264) Mon Jan 8 14:01:26 2018: Debug: User-Name = "782BCBE1350B" (264) Mon Jan 8 14:01:26 2018: Debug: Called-Station-Id = "f8-b1-56-31-90-5c" (264) Mon Jan 8 14:01:26 2018: Debug: Calling-Station-Id = "78:2b:cb:e1:35:0b" (264) Mon Jan 8 14:01:26 2018: Debug: NAS-Identifier = "f8-b1-56-31-90-5a" (264) Mon Jan 8 14:01:26 2018: Debug: NAS-IP-Address = 10.10.0.133 (264) Mon Jan 8 14:01:26 2018: Debug: NAS-Port = 1 (264) Mon Jan 8 14:01:26 2018: Debug: Framed-MTU = 1500 (264) Mon Jan 8 14:01:26 2018: Debug: NAS-Port-Type = Ethernet (264) Mon Jan 8 14:01:26 2018: Debug: EAP-Message = 0x0200001101373832424342453133353042 (264) Mon Jan 8 14:01:26 2018: Debug: Message-Authenticator = 0xf16efd118e4bc7f99777c0c9a0692c48 (264) Mon Jan 8 14:01:26 2018: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence (264) Mon Jan 8 14:01:26 2018: Debug: authorize { (264) Mon Jan 8 14:01:26 2018: Debug: update { (264) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{Packet-Src-IP-Address} (264) Mon Jan 8 14:01:26 2018: Debug: --> 10.10.0.133 (264) Mon Jan 8 14:01:26 2018: Debug: EXPAND %l (264) Mon Jan 8 14:01:26 2018: Debug: --> 1515448886 (264) Mon Jan 8 14:01:26 2018: Debug: } # update = noop (264) Mon Jan 8 14:01:26 2018: Debug: policy rewrite_calling_station_id { (264) Mon Jan 8 14:01:26 2018: 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)) { (264) Mon Jan 8 14:01:26 2018: 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 (264) Mon Jan 8 14:01:26 2018: 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)) { (264) Mon Jan 8 14:01:26 2018: Debug: update request { (264) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (264) Mon Jan 8 14:01:26 2018: Debug: --> 78:2b:cb:e1:35:0b (264) Mon Jan 8 14:01:26 2018: Debug: } # update request = noop (264) Mon Jan 8 14:01:26 2018: Debug: [updated] = updated (264) Mon Jan 8 14:01:26 2018: 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 (264) Mon Jan 8 14:01:26 2018: Debug: ... skipping else: Preceding "if" was taken (264) Mon Jan 8 14:01:26 2018: Debug: } # policy rewrite_calling_station_id = updated (264) Mon Jan 8 14:01:26 2018: Debug: policy rewrite_called_station_id { (264) Mon Jan 8 14:01:26 2018: 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)) { (264) Mon Jan 8 14:01:26 2018: 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 (264) Mon Jan 8 14:01:26 2018: 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)) { (264) Mon Jan 8 14:01:26 2018: Debug: update request { (264) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (264) Mon Jan 8 14:01:26 2018: Debug: --> f8:b1:56:31:90:5c (264) Mon Jan 8 14:01:26 2018: Debug: } # update request = noop (264) Mon Jan 8 14:01:26 2018: Debug: if ("%{8}") { (264) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{8} (264) Mon Jan 8 14:01:26 2018: Debug: --> (264) Mon Jan 8 14:01:26 2018: Debug: if ("%{8}") -> FALSE (264) Mon Jan 8 14:01:26 2018: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) { (264) Mon Jan 8 14:01:26 2018: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE (264) Mon Jan 8 14:01:26 2018: Debug: elsif (Aruba-Essid-Name) { (264) Mon Jan 8 14:01:26 2018: Debug: elsif (Aruba-Essid-Name) -> FALSE (264) Mon Jan 8 14:01:26 2018: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) { (264) Mon Jan 8 14:01:26 2018: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE (264) Mon Jan 8 14:01:26 2018: Debug: [updated] = updated (264) Mon Jan 8 14:01:26 2018: 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 (264) Mon Jan 8 14:01:26 2018: Debug: ... skipping else: Preceding "if" was taken (264) Mon Jan 8 14:01:26 2018: Debug: } # policy rewrite_called_station_id = updated (264) Mon Jan 8 14:01:26 2018: Debug: policy filter_username { (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name) { (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name) -> TRUE (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name) { (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ / /) { (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ / /) -> FALSE (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /\.\./ ) { (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (264) Mon Jan 8 14:01:26 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (264) Mon Jan 8 14:01:26 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /\.$/) { (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /(a)\./) { (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (264) Mon Jan 8 14:01:26 2018: Debug: } # if (&User-Name) = updated (264) Mon Jan 8 14:01:26 2018: Debug: } # policy filter_username = updated (264) Mon Jan 8 14:01:26 2018: Debug: policy filter_password { (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) { (264) Mon Jan 8 14:01:26 2018: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE (264) Mon Jan 8 14:01:26 2018: Debug: } # policy filter_password = updated (264) Mon Jan 8 14:01:26 2018: Debug: [preprocess] = ok (264) Mon Jan 8 14:01:26 2018: Debug: suffix: Checking for suffix after "@" (264) Mon Jan 8 14:01:26 2018: Debug: suffix: No '@' in User-Name = "782BCBE1350B", skipping NULL due to config. (264) Mon Jan 8 14:01:26 2018: Debug: [suffix] = noop (264) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Checking for prefix before "\" (264) Mon Jan 8 14:01:26 2018: Debug: ntdomain: No '\' in User-Name = "782BCBE1350B", looking up realm NULL (264) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Found realm "null" (264) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Adding Stripped-User-Name = "782BCBE1350B" (264) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Adding Realm = "null" (264) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Authentication realm is LOCAL (264) Mon Jan 8 14:01:26 2018: Debug: [ntdomain] = ok (264) Mon Jan 8 14:01:26 2018: Debug: eap: Peer sent EAP Response (code 2) ID 0 length 17 (264) Mon Jan 8 14:01:26 2018: Debug: eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (264) Mon Jan 8 14:01:26 2018: Debug: [eap] = ok (264) Mon Jan 8 14:01:26 2018: Debug: } # authorize = ok (264) Mon Jan 8 14:01:26 2018: Debug: Found Auth-Type = eap (264) Mon Jan 8 14:01:26 2018: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (264) Mon Jan 8 14:01:26 2018: Debug: authenticate { (264) Mon Jan 8 14:01:26 2018: Debug: eap: Peer sent packet with method EAP Identity (1) (264) Mon Jan 8 14:01:26 2018: Debug: eap: Calling submodule eap_peap to process data (264) Mon Jan 8 14:01:26 2018: Debug: eap_peap: Initiating new EAP-TLS session (264) Mon Jan 8 14:01:26 2018: Debug: eap_peap: [eaptls start] = request (264) Mon Jan 8 14:01:26 2018: Debug: eap: Sending EAP Request (code 1) ID 1 length 6 (264) Mon Jan 8 14:01:26 2018: Debug: eap: EAP session adding &reply:State = 0x26e9466f26e85fde (264) Mon Jan 8 14:01:26 2018: Debug: [eap] = handled (264) Mon Jan 8 14:01:26 2018: Debug: } # authenticate = handled (264) Mon Jan 8 14:01:26 2018: Debug: Using Post-Auth-Type Challenge (264) Mon Jan 8 14:01:26 2018: Debug: Post-Auth-Type sub-section not found. Ignoring. (264) Mon Jan 8 14:01:26 2018: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (264) Mon Jan 8 14:01:26 2018: Debug: Sent Access-Challenge Id 44 from 10.0.1.44:1812 to 10.10.0.133:55190 length 0 (264) Mon Jan 8 14:01:26 2018: Debug: EAP-Message = 0x010100061920 (264) Mon Jan 8 14:01:26 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (264) Mon Jan 8 14:01:26 2018: Debug: State = 0x26e9466f26e85fde8319bfa4a63b805d (264) Mon Jan 8 14:01:26 2018: Debug: Finished request (265) Mon Jan 8 14:01:26 2018: Debug: Received Access-Request Id 45 from 10.10.0.133:55190 to 10.0.1.44:1812 length 159 (265) Mon Jan 8 14:01:26 2018: Debug: User-Name = "782BCBE1350B" (265) Mon Jan 8 14:01:26 2018: Debug: Called-Station-Id = "f8-b1-56-31-90-5c" (265) Mon Jan 8 14:01:26 2018: Debug: Calling-Station-Id = "78:2b:cb:e1:35:0b" (265) Mon Jan 8 14:01:26 2018: Debug: NAS-Identifier = "f8-b1-56-31-90-5a" (265) Mon Jan 8 14:01:26 2018: Debug: NAS-IP-Address = 10.10.0.133 (265) Mon Jan 8 14:01:26 2018: Debug: NAS-Port = 1 (265) Mon Jan 8 14:01:26 2018: Debug: Framed-MTU = 1500 (265) Mon Jan 8 14:01:26 2018: Debug: NAS-Port-Type = Ethernet (265) Mon Jan 8 14:01:26 2018: Debug: State = 0x26e9466f26e85fde8319bfa4a63b805d (265) Mon Jan 8 14:01:26 2018: Debug: EAP-Message = 0x020100060304 (265) Mon Jan 8 14:01:26 2018: Debug: Message-Authenticator = 0x59b370e46568fb6f4813f958483d8036 (265) Mon Jan 8 14:01:26 2018: Debug: session-state: No cached attributes (265) Mon Jan 8 14:01:26 2018: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence (265) Mon Jan 8 14:01:26 2018: Debug: authorize { (265) Mon Jan 8 14:01:26 2018: Debug: update { (265) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{Packet-Src-IP-Address} (265) Mon Jan 8 14:01:26 2018: Debug: --> 10.10.0.133 (265) Mon Jan 8 14:01:26 2018: Debug: EXPAND %l (265) Mon Jan 8 14:01:26 2018: Debug: --> 1515448886 (265) Mon Jan 8 14:01:26 2018: Debug: } # update = noop (265) Mon Jan 8 14:01:26 2018: Debug: policy rewrite_calling_station_id { (265) Mon Jan 8 14:01:26 2018: 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)) { (265) Mon Jan 8 14:01:26 2018: 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 (265) Mon Jan 8 14:01:26 2018: 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)) { (265) Mon Jan 8 14:01:26 2018: Debug: update request { (265) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (265) Mon Jan 8 14:01:26 2018: Debug: --> 78:2b:cb:e1:35:0b (265) Mon Jan 8 14:01:26 2018: Debug: } # update request = noop (265) Mon Jan 8 14:01:26 2018: Debug: [updated] = updated (265) Mon Jan 8 14:01:26 2018: 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 (265) Mon Jan 8 14:01:26 2018: Debug: ... skipping else: Preceding "if" was taken (265) Mon Jan 8 14:01:26 2018: Debug: } # policy rewrite_calling_station_id = updated (265) Mon Jan 8 14:01:26 2018: Debug: policy rewrite_called_station_id { (265) Mon Jan 8 14:01:26 2018: 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)) { (265) Mon Jan 8 14:01:26 2018: 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 (265) Mon Jan 8 14:01:26 2018: 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)) { (265) Mon Jan 8 14:01:26 2018: Debug: update request { (265) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (265) Mon Jan 8 14:01:26 2018: Debug: --> f8:b1:56:31:90:5c (265) Mon Jan 8 14:01:26 2018: Debug: } # update request = noop (265) Mon Jan 8 14:01:26 2018: Debug: if ("%{8}") { (265) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{8} (265) Mon Jan 8 14:01:26 2018: Debug: --> (265) Mon Jan 8 14:01:26 2018: Debug: if ("%{8}") -> FALSE (265) Mon Jan 8 14:01:26 2018: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) { (265) Mon Jan 8 14:01:26 2018: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE (265) Mon Jan 8 14:01:26 2018: Debug: elsif (Aruba-Essid-Name) { (265) Mon Jan 8 14:01:26 2018: Debug: elsif (Aruba-Essid-Name) -> FALSE (265) Mon Jan 8 14:01:26 2018: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) { (265) Mon Jan 8 14:01:26 2018: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE (265) Mon Jan 8 14:01:26 2018: Debug: [updated] = updated (265) Mon Jan 8 14:01:26 2018: 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 (265) Mon Jan 8 14:01:26 2018: Debug: ... skipping else: Preceding "if" was taken (265) Mon Jan 8 14:01:26 2018: Debug: } # policy rewrite_called_station_id = updated (265) Mon Jan 8 14:01:26 2018: Debug: policy filter_username { (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name) { (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name) -> TRUE (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name) { (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ / /) { (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ / /) -> FALSE (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /\.\./ ) { (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (265) Mon Jan 8 14:01:26 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (265) Mon Jan 8 14:01:26 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /\.$/) { (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /(a)\./) { (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (265) Mon Jan 8 14:01:26 2018: Debug: } # if (&User-Name) = updated (265) Mon Jan 8 14:01:26 2018: Debug: } # policy filter_username = updated (265) Mon Jan 8 14:01:26 2018: Debug: policy filter_password { (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) { (265) Mon Jan 8 14:01:26 2018: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE (265) Mon Jan 8 14:01:26 2018: Debug: } # policy filter_password = updated (265) Mon Jan 8 14:01:26 2018: Debug: [preprocess] = ok (265) Mon Jan 8 14:01:26 2018: Debug: suffix: Checking for suffix after "@" (265) Mon Jan 8 14:01:26 2018: Debug: suffix: No '@' in User-Name = "782BCBE1350B", skipping NULL due to config. (265) Mon Jan 8 14:01:26 2018: Debug: [suffix] = noop (265) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Checking for prefix before "\" (265) Mon Jan 8 14:01:26 2018: Debug: ntdomain: No '\' in User-Name = "782BCBE1350B", looking up realm NULL (265) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Found realm "null" (265) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Adding Stripped-User-Name = "782BCBE1350B" (265) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Adding Realm = "null" (265) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Authentication realm is LOCAL (265) Mon Jan 8 14:01:26 2018: Debug: [ntdomain] = ok (265) Mon Jan 8 14:01:26 2018: Debug: eap: Peer sent EAP Response (code 2) ID 1 length 6 (265) Mon Jan 8 14:01:26 2018: Debug: eap: No EAP Start, assuming it's an on-going EAP conversation (265) Mon Jan 8 14:01:26 2018: Debug: [eap] = updated (265) Mon Jan 8 14:01:26 2018: Debug: if ( !EAP-Message ) { (265) Mon Jan 8 14:01:26 2018: Debug: if ( !EAP-Message ) -> FALSE (265) Mon Jan 8 14:01:26 2018: Debug: policy packetfence-eap-mac-policy { (265) Mon Jan 8 14:01:26 2018: Debug: if ( &EAP-Type ) { (265) Mon Jan 8 14:01:26 2018: Debug: if ( &EAP-Type ) -> TRUE (265) Mon Jan 8 14:01:26 2018: Debug: if ( &EAP-Type ) { (265) Mon Jan 8 14:01:26 2018: 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)) { (265) Mon Jan 8 14:01:26 2018: 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 (265) Mon Jan 8 14:01:26 2018: 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)) { (265) Mon Jan 8 14:01:26 2018: Debug: update { (265) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{tolower:%{1}%{2}%{3}%{4}%{5}%{6}} (265) Mon Jan 8 14:01:26 2018: Debug: --> 782bcbe1350b (265) Mon Jan 8 14:01:26 2018: Debug: } # update = noop (265) Mon Jan 8 14:01:26 2018: Debug: if ( &Tmp-String-1 == "%{tolower:%{User-Name}}" ) { (265) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{tolower:%{User-Name}} (265) Mon Jan 8 14:01:26 2018: Debug: --> 782bcbe1350b (265) Mon Jan 8 14:01:26 2018: Debug: if ( &Tmp-String-1 == "%{tolower:%{User-Name}}" ) -> TRUE (265) Mon Jan 8 14:01:26 2018: Debug: if ( &Tmp-String-1 == "%{tolower:%{User-Name}}" ) { (265) Mon Jan 8 14:01:26 2018: Debug: update { (265) Mon Jan 8 14:01:26 2018: Debug: } # update = noop (265) Mon Jan 8 14:01:26 2018: Debug: [updated] = updated (265) Mon Jan 8 14:01:26 2018: Debug: } # if ( &Tmp-String-1 == "%{tolower:%{User-Name}}" ) = updated (265) Mon Jan 8 14:01:26 2018: 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 (265) Mon Jan 8 14:01:26 2018: Debug: } # if ( &EAP-Type ) = updated (265) Mon Jan 8 14:01:26 2018: Debug: [noop] = noop (265) Mon Jan 8 14:01:26 2018: Debug: } # policy packetfence-eap-mac-policy = updated (265) Mon Jan 8 14:01:26 2018: WARNING: pap: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! (265) Mon Jan 8 14:01:26 2018: WARNING: pap: !!! Ignoring control:User-Password. Update your !!! (265) Mon Jan 8 14:01:26 2018: WARNING: pap: !!! configuration so that the "known good" clear text !!! (265) Mon Jan 8 14:01:26 2018: WARNING: pap: !!! password is in Cleartext-Password and NOT in !!! (265) Mon Jan 8 14:01:26 2018: WARNING: pap: !!! User-Password. !!! (265) Mon Jan 8 14:01:26 2018: WARNING: pap: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! (265) Mon Jan 8 14:01:26 2018: WARNING: pap: Auth-Type already set. Not setting to PAP (265) Mon Jan 8 14:01:26 2018: Debug: [pap] = noop (265) Mon Jan 8 14:01:26 2018: Debug: } # authorize = updated (265) Mon Jan 8 14:01:26 2018: Debug: Found Auth-Type = eap (265) Mon Jan 8 14:01:26 2018: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (265) Mon Jan 8 14:01:26 2018: Debug: authenticate { (265) Mon Jan 8 14:01:26 2018: Debug: eap: Expiring EAP session with state 0x26e9466f26e85fde (265) Mon Jan 8 14:01:26 2018: Debug: eap: Finished EAP session with state 0x26e9466f26e85fde (265) Mon Jan 8 14:01:26 2018: Debug: eap: Previous EAP request found for state 0x26e9466f26e85fde, released from the list (265) Mon Jan 8 14:01:26 2018: Debug: eap: Peer sent packet with method EAP NAK (3) (265) Mon Jan 8 14:01:26 2018: Debug: eap: Found mutually acceptable type MD5 (4) (265) Mon Jan 8 14:01:26 2018: Debug: eap: Calling submodule eap_md5 to process data (265) Mon Jan 8 14:01:26 2018: Debug: eap_md5: Issuing MD5 Challenge (265) Mon Jan 8 14:01:26 2018: Debug: eap: Sending EAP Request (code 1) ID 2 length 22 (265) Mon Jan 8 14:01:26 2018: Debug: eap: EAP session adding &reply:State = 0x26e9466f27eb42de (265) Mon Jan 8 14:01:26 2018: Debug: [eap] = handled (265) Mon Jan 8 14:01:26 2018: Debug: } # authenticate = handled (265) Mon Jan 8 14:01:26 2018: Debug: Using Post-Auth-Type Challenge (265) Mon Jan 8 14:01:26 2018: Debug: Post-Auth-Type sub-section not found. Ignoring. (265) Mon Jan 8 14:01:26 2018: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (265) Mon Jan 8 14:01:26 2018: Debug: Sent Access-Challenge Id 45 from 10.0.1.44:1812 to 10.10.0.133:55190 length 0 (265) Mon Jan 8 14:01:26 2018: Debug: EAP-Message = 0x0102001604108fcf9a3173c4a7d510712ad043ded2ea (265) Mon Jan 8 14:01:26 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (265) Mon Jan 8 14:01:26 2018: Debug: State = 0x26e9466f27eb42de8319bfa4a63b805d (265) Mon Jan 8 14:01:26 2018: Debug: Finished request (266) Mon Jan 8 14:01:26 2018: Debug: Received Access-Request Id 46 from 10.10.0.133:55190 to 10.0.1.44:1812 length 175 (266) Mon Jan 8 14:01:26 2018: Debug: User-Name = "782BCBE1350B" (266) Mon Jan 8 14:01:26 2018: Debug: Called-Station-Id = "f8-b1-56-31-90-5c" (266) Mon Jan 8 14:01:26 2018: Debug: Calling-Station-Id = "78:2b:cb:e1:35:0b" (266) Mon Jan 8 14:01:26 2018: Debug: NAS-Identifier = "f8-b1-56-31-90-5a" (266) Mon Jan 8 14:01:26 2018: Debug: NAS-IP-Address = 10.10.0.133 (266) Mon Jan 8 14:01:26 2018: Debug: NAS-Port = 1 (266) Mon Jan 8 14:01:26 2018: Debug: Framed-MTU = 1500 (266) Mon Jan 8 14:01:26 2018: Debug: NAS-Port-Type = Ethernet (266) Mon Jan 8 14:01:26 2018: Debug: State = 0x26e9466f27eb42de8319bfa4a63b805d (266) Mon Jan 8 14:01:26 2018: Debug: EAP-Message = 0x020200160410780dd2fb773db3731d527467949bc4ba (266) Mon Jan 8 14:01:26 2018: Debug: Message-Authenticator = 0x646cc2548777b3f79b3eea2988367a9a (266) Mon Jan 8 14:01:26 2018: Debug: session-state: No cached attributes (266) Mon Jan 8 14:01:26 2018: Debug: # Executing section authorize from file /usr/local/pf/raddb/sites-enabled/packetfence (266) Mon Jan 8 14:01:26 2018: Debug: authorize { (266) Mon Jan 8 14:01:26 2018: Debug: update { (266) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{Packet-Src-IP-Address} (266) Mon Jan 8 14:01:26 2018: Debug: --> 10.10.0.133 (266) Mon Jan 8 14:01:26 2018: Debug: EXPAND %l (266) Mon Jan 8 14:01:26 2018: Debug: --> 1515448886 (266) Mon Jan 8 14:01:26 2018: Debug: } # update = noop (266) Mon Jan 8 14:01:26 2018: Debug: policy rewrite_calling_station_id { (266) Mon Jan 8 14:01:26 2018: 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)) { (266) Mon Jan 8 14:01:26 2018: 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 (266) Mon Jan 8 14:01:26 2018: 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)) { (266) Mon Jan 8 14:01:26 2018: Debug: update request { (266) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (266) Mon Jan 8 14:01:26 2018: Debug: --> 78:2b:cb:e1:35:0b (266) Mon Jan 8 14:01:26 2018: Debug: } # update request = noop (266) Mon Jan 8 14:01:26 2018: Debug: [updated] = updated (266) Mon Jan 8 14:01:26 2018: 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 (266) Mon Jan 8 14:01:26 2018: Debug: ... skipping else: Preceding "if" was taken (266) Mon Jan 8 14:01:26 2018: Debug: } # policy rewrite_calling_station_id = updated (266) Mon Jan 8 14:01:26 2018: Debug: policy rewrite_called_station_id { (266) Mon Jan 8 14:01:26 2018: 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)) { (266) Mon Jan 8 14:01:26 2018: 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 (266) Mon Jan 8 14:01:26 2018: 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)) { (266) Mon Jan 8 14:01:26 2018: Debug: update request { (266) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{tolower:%{1}:%{2}:%{3}:%{4}:%{5}:%{6}} (266) Mon Jan 8 14:01:26 2018: Debug: --> f8:b1:56:31:90:5c (266) Mon Jan 8 14:01:26 2018: Debug: } # update request = noop (266) Mon Jan 8 14:01:26 2018: Debug: if ("%{8}") { (266) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{8} (266) Mon Jan 8 14:01:26 2018: Debug: --> (266) Mon Jan 8 14:01:26 2018: Debug: if ("%{8}") -> FALSE (266) Mon Jan 8 14:01:26 2018: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) { (266) Mon Jan 8 14:01:26 2018: Debug: elsif ( (Colubris-AVPair) && "%{Colubris-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE (266) Mon Jan 8 14:01:26 2018: Debug: elsif (Aruba-Essid-Name) { (266) Mon Jan 8 14:01:26 2018: Debug: elsif (Aruba-Essid-Name) -> FALSE (266) Mon Jan 8 14:01:26 2018: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) { (266) Mon Jan 8 14:01:26 2018: Debug: elsif ( (Cisco-AVPair) && "%{Cisco-AVPair}" =~ /^ssid=(.*)$/i) -> FALSE (266) Mon Jan 8 14:01:26 2018: Debug: [updated] = updated (266) Mon Jan 8 14:01:26 2018: 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 (266) Mon Jan 8 14:01:26 2018: Debug: ... skipping else: Preceding "if" was taken (266) Mon Jan 8 14:01:26 2018: Debug: } # policy rewrite_called_station_id = updated (266) Mon Jan 8 14:01:26 2018: Debug: policy filter_username { (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name) { (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name) -> TRUE (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name) { (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ / /) { (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ / /) -> FALSE (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) { (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /@[^@]*@/ ) -> FALSE (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /\.\./ ) { (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /\.\./ ) -> FALSE (266) Mon Jan 8 14:01:26 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (266) Mon Jan 8 14:01:26 2018: Debug: if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /\.$/) { (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /\.$/) -> FALSE (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /(a)\./) { (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name =~ /(a)\./) -> FALSE (266) Mon Jan 8 14:01:26 2018: Debug: } # if (&User-Name) = updated (266) Mon Jan 8 14:01:26 2018: Debug: } # policy filter_username = updated (266) Mon Jan 8 14:01:26 2018: Debug: policy filter_password { (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) { (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Password && (&User-Password != "%{string:User-Password}")) -> FALSE (266) Mon Jan 8 14:01:26 2018: Debug: } # policy filter_password = updated (266) Mon Jan 8 14:01:26 2018: Debug: [preprocess] = ok (266) Mon Jan 8 14:01:26 2018: Debug: suffix: Checking for suffix after "@" (266) Mon Jan 8 14:01:26 2018: Debug: suffix: No '@' in User-Name = "782BCBE1350B", skipping NULL due to config. (266) Mon Jan 8 14:01:26 2018: Debug: [suffix] = noop (266) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Checking for prefix before "\" (266) Mon Jan 8 14:01:26 2018: Debug: ntdomain: No '\' in User-Name = "782BCBE1350B", looking up realm NULL (266) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Found realm "null" (266) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Adding Stripped-User-Name = "782BCBE1350B" (266) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Adding Realm = "null" (266) Mon Jan 8 14:01:26 2018: Debug: ntdomain: Authentication realm is LOCAL (266) Mon Jan 8 14:01:26 2018: Debug: [ntdomain] = ok (266) Mon Jan 8 14:01:26 2018: Debug: eap: Peer sent EAP Response (code 2) ID 2 length 22 (266) Mon Jan 8 14:01:26 2018: Debug: eap: No EAP Start, assuming it's an on-going EAP conversation (266) Mon Jan 8 14:01:26 2018: Debug: [eap] = updated (266) Mon Jan 8 14:01:26 2018: Debug: if ( !EAP-Message ) { (266) Mon Jan 8 14:01:26 2018: Debug: if ( !EAP-Message ) -> FALSE (266) Mon Jan 8 14:01:26 2018: Debug: policy packetfence-eap-mac-policy { (266) Mon Jan 8 14:01:26 2018: Debug: if ( &EAP-Type ) { (266) Mon Jan 8 14:01:26 2018: Debug: if ( &EAP-Type ) -> TRUE (266) Mon Jan 8 14:01:26 2018: Debug: if ( &EAP-Type ) { (266) Mon Jan 8 14:01:26 2018: 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)) { (266) Mon Jan 8 14:01:26 2018: 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 (266) Mon Jan 8 14:01:26 2018: 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)) { (266) Mon Jan 8 14:01:26 2018: Debug: update { (266) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{tolower:%{1}%{2}%{3}%{4}%{5}%{6}} (266) Mon Jan 8 14:01:26 2018: Debug: --> 782bcbe1350b (266) Mon Jan 8 14:01:26 2018: Debug: } # update = noop (266) Mon Jan 8 14:01:26 2018: Debug: if ( &Tmp-String-1 == "%{tolower:%{User-Name}}" ) { (266) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{tolower:%{User-Name}} (266) Mon Jan 8 14:01:26 2018: Debug: --> 782bcbe1350b (266) Mon Jan 8 14:01:26 2018: Debug: if ( &Tmp-String-1 == "%{tolower:%{User-Name}}" ) -> TRUE (266) Mon Jan 8 14:01:26 2018: Debug: if ( &Tmp-String-1 == "%{tolower:%{User-Name}}" ) { (266) Mon Jan 8 14:01:26 2018: Debug: update { (266) Mon Jan 8 14:01:26 2018: Debug: } # update = noop (266) Mon Jan 8 14:01:26 2018: Debug: [updated] = updated (266) Mon Jan 8 14:01:26 2018: Debug: } # if ( &Tmp-String-1 == "%{tolower:%{User-Name}}" ) = updated (266) Mon Jan 8 14:01:26 2018: 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 (266) Mon Jan 8 14:01:26 2018: Debug: } # if ( &EAP-Type ) = updated (266) Mon Jan 8 14:01:26 2018: Debug: [noop] = noop (266) Mon Jan 8 14:01:26 2018: Debug: } # policy packetfence-eap-mac-policy = updated (266) Mon Jan 8 14:01:26 2018: WARNING: pap: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! (266) Mon Jan 8 14:01:26 2018: WARNING: pap: !!! Ignoring control:User-Password. Update your !!! (266) Mon Jan 8 14:01:26 2018: WARNING: pap: !!! configuration so that the "known good" clear text !!! (266) Mon Jan 8 14:01:26 2018: WARNING: pap: !!! password is in Cleartext-Password and NOT in !!! (266) Mon Jan 8 14:01:26 2018: WARNING: pap: !!! User-Password. !!! (266) Mon Jan 8 14:01:26 2018: WARNING: pap: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! (266) Mon Jan 8 14:01:26 2018: WARNING: pap: Auth-Type already set. Not setting to PAP (266) Mon Jan 8 14:01:26 2018: Debug: [pap] = noop (266) Mon Jan 8 14:01:26 2018: Debug: } # authorize = updated (266) Mon Jan 8 14:01:26 2018: Debug: Found Auth-Type = eap (266) Mon Jan 8 14:01:26 2018: Debug: # Executing group from file /usr/local/pf/raddb/sites-enabled/packetfence (266) Mon Jan 8 14:01:26 2018: Debug: authenticate { (266) Mon Jan 8 14:01:26 2018: Debug: eap: Expiring EAP session with state 0x26e9466f27eb42de (266) Mon Jan 8 14:01:26 2018: Debug: eap: Finished EAP session with state 0x26e9466f27eb42de (266) Mon Jan 8 14:01:26 2018: Debug: eap: Previous EAP request found for state 0x26e9466f27eb42de, released from the list (266) Mon Jan 8 14:01:26 2018: Debug: eap: Peer sent packet with method EAP MD5 (4) (266) Mon Jan 8 14:01:26 2018: Debug: eap: Calling submodule eap_md5 to process data (266) Mon Jan 8 14:01:26 2018: Debug: eap: Sending EAP Success (code 3) ID 2 length 4 (266) Mon Jan 8 14:01:26 2018: Debug: eap: Freeing handler (266) Mon Jan 8 14:01:26 2018: Debug: [eap] = ok (266) Mon Jan 8 14:01:26 2018: Debug: } # authenticate = ok (266) Mon Jan 8 14:01:26 2018: Debug: # Executing section post-auth from file /usr/local/pf/raddb/sites-enabled/packetfence (266) Mon Jan 8 14:01:26 2018: Debug: post-auth { (266) Mon Jan 8 14:01:26 2018: Debug: update { (266) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{Packet-Src-IP-Address} (266) Mon Jan 8 14:01:26 2018: Debug: --> 10.10.0.133 (266) Mon Jan 8 14:01:26 2018: Debug: } # update = noop (266) Mon Jan 8 14:01:26 2018: Debug: if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) { (266) Mon Jan 8 14:01:26 2018: Debug: if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) -> TRUE (266) Mon Jan 8 14:01:26 2018: Debug: if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) { (266) Mon Jan 8 14:01:26 2018: Debug: rest: Expanding URI components (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND http://127.0.0.1:7070 (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> http://127.0.0.1:7070 (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND //radius/rest/authorize (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> //radius/rest/authorize (266) Mon Jan 8 14:01:26 2018: Debug: rest: Sending HTTP POST to "http://127.0.0.1:7070//radius/rest/authorize" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "User-Name" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "NAS-IP-Address" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "NAS-Port" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "Framed-MTU" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "State" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "Called-Station-Id" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "Calling-Station-Id" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "NAS-Identifier" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "NAS-Port-Type" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "Event-Timestamp" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "EAP-Message" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "Message-Authenticator" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "EAP-Type" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "Stripped-User-Name" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "Realm" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "FreeRADIUS-Client-IP-Address" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "Tmp-String-1" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Returning 1000 bytes of JSON data (buffer full or chunk exceeded) (266) Mon Jan 8 14:01:26 2018: Debug: rest: Encoding attribute "Tmp-String-1" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Processing response header (266) Mon Jan 8 14:01:26 2018: Debug: rest: Status : 100 (Continue) (266) Mon Jan 8 14:01:26 2018: Debug: rest: Continuing... (266) Mon Jan 8 14:01:26 2018: Debug: rest: Processing response header (266) Mon Jan 8 14:01:26 2018: Debug: rest: Status : 200 (OK) (266) Mon Jan 8 14:01:26 2018: Debug: rest: Type : json (application/json) (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-Role" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND Employees (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> Employees (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-Role := "Employees" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-Eap-Type" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND 4 (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> 4 (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-Eap-Type := "4" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "Tunnel-Type" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND 13 (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> 13 (266) Mon Jan 8 14:01:26 2018: Debug: rest: Tunnel-Type := VLAN (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-AutoReg" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND 0 (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> 0 (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-AutoReg := "0" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-Authorization-Status" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND allow (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> allow (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-Authorization-Status := "allow" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "Tunnel-Private-Group-ID" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND 300 (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> 300 (266) Mon Jan 8 14:01:26 2018: Debug: rest: Tunnel-Private-Group-Id := "300" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-Switch-Ip-Address" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND 10.10.0.133 (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> 10.10.0.133 (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-Switch-Ip-Address := "10.10.0.133" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-Request-Time" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND 1515448886 (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> 1515448886 (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-Request-Time := 1515448886 (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-UserName" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND 782BCBE1350B (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> 782BCBE1350B (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-UserName := "782BCBE1350B" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-IsPhone" (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-IsPhone := "" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-Switch-Id" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND 10.10.0.133 (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> 10.10.0.133 (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-Switch-Id := "10.10.0.133" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-Switch-Mac" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND f8:b1:56:31:90:5c (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> f8:b1:56:31:90:5c (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-Switch-Mac := "f8:b1:56:31:90:5c" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "Tunnel-Medium-Type" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND 6 (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> 6 (266) Mon Jan 8 14:01:26 2018: Debug: rest: Tunnel-Medium-Type := IEEE-802 (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-Computer-Name" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND adele3 (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> adele3 (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-Computer-Name := "adele3" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-Mac" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND 78:2b:cb:e1:35:0b (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> 78:2b:cb:e1:35:0b (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-Mac := "78:2b:cb:e1:35:0b" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-IfIndex" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND 1 (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> 1 (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-IfIndex := "1" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-Connection-Type" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND WIRED_MAC_AUTH (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> WIRED_MAC_AUTH (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-Connection-Type := "WIRED_MAC_AUTH" (266) Mon Jan 8 14:01:26 2018: Debug: rest: Parsing attribute "control:PacketFence-Status" (266) Mon Jan 8 14:01:26 2018: Debug: rest: EXPAND reg (266) Mon Jan 8 14:01:26 2018: Debug: rest: --> reg (266) Mon Jan 8 14:01:26 2018: Debug: rest: PacketFence-Status := "reg" (266) Mon Jan 8 14:01:26 2018: Debug: [rest] = updated (266) Mon Jan 8 14:01:26 2018: Debug: update { (266) Mon Jan 8 14:01:26 2018: Debug: } # update = noop (266) Mon Jan 8 14:01:26 2018: Debug: if (&control:PacketFence-Authorization-Status == "deny") { (266) Mon Jan 8 14:01:26 2018: Debug: if (&control:PacketFence-Authorization-Status == "deny") -> FALSE (266) Mon Jan 8 14:01:26 2018: Debug: else { (266) Mon Jan 8 14:01:26 2018: Debug: policy packetfence-audit-log-accept { (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name != "dummy") { (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name != "dummy") -> TRUE (266) Mon Jan 8 14:01:26 2018: Debug: if (&User-Name != "dummy") { (266) Mon Jan 8 14:01:26 2018: Debug: policy request-timing { (266) Mon Jan 8 14:01:26 2018: Debug: if (control:PacketFence-Request-Time != 0) { (266) Mon Jan 8 14:01:26 2018: Debug: if (control:PacketFence-Request-Time != 0) -> TRUE (266) Mon Jan 8 14:01:26 2018: Debug: if (control:PacketFence-Request-Time != 0) { (266) Mon Jan 8 14:01:26 2018: Debug: update control { (266) Mon Jan 8 14:01:26 2018: Debug: EXPAND %{expr: %{control:PacketFence-Request-Time} - %{control:Tmp-Integer-0}} (266) Mon Jan 8 14:01:26 2018: Debug: --> 0 (266) Mon Jan 8 14:01:26 2018: Debug: } # update control = noop (266) Mon Jan 8 14:01:26 2018: Debug: } # if (control:PacketFence-Request-Time != 0) = noop (266) Mon Jan 8 14:01:26 2018: Debug: } # policy request-timing = noop (266) Mon Jan 8 14:01:26 2018: Debug: sql: EXPAND type.accept.query (266) Mon Jan 8 14:01:26 2018: Debug: sql: --> type.accept.query (266) Mon Jan 8 14:01:26 2018: Debug: sql: Using query template 'query' (266) Mon Jan 8 14:01:26 2018: Debug: sql: EXPAND %{User-Name} (266) Mon Jan 8 14:01:26 2018: Debug: sql: --> 782BCBE1350B (266) Mon Jan 8 14:01:26 2018: Debug: sql: SQL-User-Name set to '782BCBE1350B' (266) Mon Jan 8 14:01:26 2018: Debug: sql: 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) 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}', 'Accept', '%{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}:-N/A}', '%{%{control:PacketFence-IsPhone}:-N/A}', '%{request:PacketFence-Domain}', '', '%{pairs:&request:[*]}','%{pairs:&reply:[*]}', '%{control:PacketFence-Request-Time}') (266) Mon Jan 8 14:01:26 2018: Debug: sql: --> 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) VALUES ( '78:2b:cb:e1:35:0b', '', 'adele3', '782BCBE1350B', '782BCBE1350B', 'null', 'Radius-Access-Request', '10.10.0.133', 'f8:b1:56:31:90:5c', '10.10.0.133', '10.10.0.133', 'f8:b1:56:31:90:5c', '78:2b:cb:e1:35:0b', 'Ethernet', '', '', '1', '1', 'WIRED_MAC_AUTH', '10.10.0.133', 'f8-b1-56-31-90-5a', 'Accept', '', 'eap', 'MD5', 'Employees', 'reg', 'N/A', 'N/A', '0', 'N/A', '', '', 'User-Name =3D =22782BCBE1350B=22=2C NAS-IP-Address =3D 10.10.0.133=2C NAS-Port =3D 1=2C Framed-MTU =3D 1500=2C State =3D 0x26e9466f27eb42de8319bfa4a63b805d=2C Called-Station-Id =3D =22f8:b1:56:31:90:5c=22=2C Calling-Station-Id =3D =2278:2b:cb:e1:35:0b=22=2C NAS-Identifier =3D =22f8-b1-56-31-90-5a=22=2C NAS-Port-Type =3D Ethernet=2C Event-Timestamp =3D =22Jan 8 2018 14:01:26 PST=22=2C EAP-Message =3D 0x020200160410780dd2fb773db3731d527467949bc4ba=2C Message-Authenticator =3D 0x646cc2548777b3f79b3eea2988367a9a=2C EAP-Type =3D MD5=2C Stripped-User-Name =3D =22782BCBE1350B=22=2C Realm =3D =22null=22=2C FreeRADIUS-Client-IP-Address =3D 10.10.0.133=2C Tmp-String-1 =3D =22782bcbe1350b=22=2C User-Password =3D =22=2A=2A=2A=2A=2A=2A=22=2C SQL-User-Name =3D =22782BCBE1350B=22','EAP-Message =3D 0x03020004=2C Message-Authenticator =3D 0x00000000000000000000000000000000=2C Stripped-User-Name =3D =22782BCBE1350B=22=2C Tunnel-Type =3D VLAN=2C Tunnel-Private-Group-Id =3D =22300=22=2C Tunnel-Medium-Type =3D IEEE-802', '0') (266) Mon Jan 8 14:01:26 2018: Debug: sql: 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) VALUES ( '78:2b:cb:e1:35:0b', '', 'adele3', '782BCBE1350B', '782BCBE1350B', 'null', 'Radius-Access-Request', '10.10.0.133', 'f8:b1:56:31:90:5c', '10.10.0.133', '10.10.0.133', 'f8:b1:56:31:90:5c', '78:2b:cb:e1:35:0b', 'Ethernet', '', '', '1', '1', 'WIRED_MAC_AUTH', '10.10.0.133', 'f8-b1-56-31-90-5a', 'Accept', '', 'eap', 'MD5', 'Employees', 'reg', 'N/A', 'N/A', '0', 'N/A', '', '', 'User-Name =3D =22782BCBE1350B=22=2C NAS-IP-Address =3D 10.10.0.133=2C NAS-Port =3D 1=2C Framed-MTU =3D 1500=2C State =3D 0x26e9466f27eb42de8319bfa4a63b805d=2C Called-Station-Id =3D =22f8:b1:56:31:90:5c=22=2C Calling-Station-Id =3D =2278:2b:cb:e1:35:0b=22=2C NAS-Identifier =3D =22f8-b1-56-31-90-5a=22=2C NAS-Port-Type =3D Ethernet=2C Event-Timestamp =3D =22Jan 8 2018 14:01:26 PST=22=2C EAP-Message =3D 0x020200160410780dd2fb773db3731d527467949bc4ba=2C Message-Authenticator =3D 0x646cc2548777b3f79b3eea2988367a9a=2C EAP-Type =3D MD5=2C Stripped-User-Name =3D =22782BCBE1350B=22=2C Realm =3D =22null=22=2C FreeRADIUS-Client-IP-Address =3D 10.10.0.133=2C Tmp-String-1 =3D =22782bcbe1350b=22=2C User-Password =3D =22=2A=2A=2A=2A=2A=2A=22=2C SQL-User-Name =3D =22782BCBE1350B=22','EAP-Message =3D 0x03020004=2C Message-Authenticator =3D 0x00000000000000000000000000000000=2C Stripped-User-Name =3D =22782BCBE1350B=22=2C Tunnel-Type =3D VLAN=2C Tunnel-Private-Group-Id =3D =22300=22=2C Tunnel-Medium-Type =3D IEEE-802', '0') (266) Mon Jan 8 14:01:26 2018: Debug: sql: SQL query returned: success (266) Mon Jan 8 14:01:26 2018: Debug: sql: 1 record(s) updated (266) Mon Jan 8 14:01:26 2018: Debug: [sql] = ok (266) Mon Jan 8 14:01:26 2018: Debug: } # if (&User-Name != "dummy") = ok (266) Mon Jan 8 14:01:26 2018: Debug: } # policy packetfence-audit-log-accept = ok (266) Mon Jan 8 14:01:26 2018: Debug: } # else = ok (266) Mon Jan 8 14:01:26 2018: Debug: } # if (! EAP-Type || (EAP-Type != TTLS && EAP-Type != PEAP) ) = updated (266) Mon Jan 8 14:01:26 2018: Debug: attr_filter.packetfence_post_auth: EXPAND %{User-Name} (266) Mon Jan 8 14:01:26 2018: Debug: attr_filter.packetfence_post_auth: --> 782BCBE1350B (266) Mon Jan 8 14:01:26 2018: Debug: attr_filter.packetfence_post_auth: Matched entry DEFAULT at line 10 (266) Mon Jan 8 14:01:26 2018: Debug: [attr_filter.packetfence_post_auth] = updated (266) Mon Jan 8 14:01:26 2018: Debug: linelog: EXPAND messages.%{%{reply:Packet-Type}:-default} (266) Mon Jan 8 14:01:26 2018: Debug: linelog: --> messages.Access-Accept (266) Mon Jan 8 14:01:26 2018: Debug: linelog: EXPAND [mac:%{Calling-Station-Id}] Accepted user: %{reply:User-Name} and returned VLAN %{reply:Tunnel-Private-Group-ID} (266) Mon Jan 8 14:01:26 2018: Debug: linelog: --> [mac:78:2b:cb:e1:35:0b] Accepted user: and returned VLAN 300 (266) Mon Jan 8 14:01:26 2018: Debug: [linelog] = ok (266) Mon Jan 8 14:01:26 2018: Debug: } # post-auth = updated (266) Mon Jan 8 14:01:26 2018: Debug: Sent Access-Accept Id 46 from 10.0.1.44:1812 to 10.10.0.133:55190 length 0 (266) Mon Jan 8 14:01:26 2018: Debug: EAP-Message = 0x03020004 (266) Mon Jan 8 14:01:26 2018: Debug: Message-Authenticator = 0x00000000000000000000000000000000 (266) Mon Jan 8 14:01:26 2018: Debug: Tunnel-Type = VLAN (266) Mon Jan 8 14:01:26 2018: Debug: Tunnel-Private-Group-Id = "300" (266) Mon Jan 8 14:01:26 2018: Debug: Tunnel-Medium-Type = IEEE-802 (266) Mon Jan 8 14:01:26 2018: Debug: Finished request (264) Mon Jan 8 14:01:31 2018: Debug: Cleaning up request packet ID 44 with timestamp +253960 (265) Mon Jan 8 14:01:31 2018: Debug: Cleaning up request packet ID 45 with timestamp +253960 (266) Mon Jan 8 14:01:31 2018: Debug: Cleaning up request packet ID 46 with timestamp +253960

2 2

rediswho module
by Bassem Mettichi 12 Jan '18

12 Jan '18

Hello, please could any one tell us if we can execute two commands in the insert of rediswho module like this: Start { insert = "HSETNX MSISDN Calling-Station-Id %{Calling-Station-Id} \n\ HSETNX IP Framed-IP-Address %{Framed-IP-Address}" trim = "LTRIM %{Calling-Station-Id} 0 ${..trim_count}" expire = "EXPIRE %{User-Name} ${..expire_time}" } i need to insert into two hash for every accounting start . need your help the example above doesn't work for me i get an error rediswho: ERROR: Query failed, HSETNX MSISDN Calling-Station-Id %{Calling-Station-Id} \n HSETNX IP Framed-IP-Address %{Framed-IP-Address} rediswho_command: database query error in: 'HSETNX MSISDN Calling-Station-Id %{Calling-Station-Id} \n HSETNX IP Framed-IP-Address %{Framed-IP-Address}' Best Regards Mettichi Bassem

2 2

rlm_perl chap-password
by Bassem Mettichi 12 Jan '18

12 Jan '18

Hello, could someone tell me how to impliment CHAP-Password authentication using rlm_perl? i would like to know how to impliment the authorize methode in rlm_perl to encrypt the cleartext-password with the CHAP-Challenge and see if it matches the CHAP-Password. Thanks in advance Mettichi B assem

1 0

Reply attributes from users file are being wiped
by Kennedy, Sean M 12 Jan '18

12 Jan '18

I am in the process of upgrading an OLD freeradius instance to version 3.0.16 and I am running into an issue where I am not seeing my extra reply attributes returned when the user is being proxied to another auth server. Here are some snippets from the debug... you can see the users file matches 2 sections and that is exactly the correct lines it should match on to append in my custom reply attributes. (1) suffix: Checking for suffix after "@" (1) suffix: Looking up realm "xxx.net" for User-Name = "xxx(a)xxx.net" (1) suffix: Found realm "xxx.net" (1) suffix: Adding Realm = "xxx.net" (1) suffix: Proxying request from user xxx(a)xxx.net to realm xxx.net (1) suffix: Preparing to proxy authentication request to realm "xxx.net" (1) [suffix] = updated (1) eap: No EAP-Message, not doing EAP (1) [eap] = noop (1) files: EXPAND 216.126.204.* (1) files: --> 216.126.204.* (1) files: EXPAND 165.154.11.* (1) files: --> 165.154.11.* (1) files: EXPAND 209.244.* (1) files: --> 209.244.* (1) files: EXPAND 209.247.* (1) files: --> 209.247.* (1) files: EXPAND 209.253.* (1) files: --> 209.253.* (1) files: users: Matched entry DEFAULT at line 928 (1) files: users: Matched entry DEFAULT at line 940 The debug proceeds to send the request to the proxy: (1) Starting proxy to home server x.x.x.x port 1812 (1) Proxying request to home server x.x.x.x port 1812 timeout 30.000000 (1) Sent Access-Request Id 102 from 0.0.0.0:34505 to x.x.x.x:1812 length 116 (1) User-Name = "xxx(a)xxx.net" (1) User-Password = "xxx" (1) NAS-IP-Address = x.x.x.x (1) NAS-Port = 1 (1) Framed-Protocol = PPP (1) Service-Type = Framed-User (1) Event-Timestamp = "Jan 11 2018 20:08:34 MST" (1) Message-Authenticator := 0x00 (1) Proxy-State = 0x3838 It then wipes the reply attributes out: Waking up in 0.3 seconds. (1) Marking home server x.x.x.x port 1812 alive (1) Clearing existing &reply: attributes Why is this "Clearing existing &reply: attributes" happening? It seems that is my issue as the actual reply is missing my extra attributes that I defined in the "users" file. Thank you in advance, Sean

2 1

FilterID or Aruba-User-Role being returned for captive portal but not 802.1X authentication
by David Hendricks 11 Jan '18

11 Jan '18

I have a wireless lab with an Aruba 7005 Controller (ArubaOS 6.5.4.3), and now FreeRADIUS 3.0.15. Client authentication succeeds for both 802.1X and captive portal users. A rule at the controller that is supposed to assign user role based on returned Filter-Id works for the captive portal / guest users but not 802.1X users. Filter-Id = "labguest" but the assigned role is the 802.1X default, "authenticated". I posted the issue at https://stackoverflow.com/questions/47681051/server- derived-role-based-on-filterid-using-freeradius-not-working I simultaneously posted it on the Aruba Airheads blog at http://community. arubanetworks.com/t5/Security/Server-derived-rule-using- Filter-Id-from-FreeRADIUS-not-working/m-p/322046 With no resolution at either stackoverflow or Airheads, I opened an Aruba TAC case. After some troubleshooting, the Aruba engineer asks: "I would like to inform you that I went through the packet captures and I have attached the screenshots from the same based on what we observed; As seen in the CP-Accept screenshot, we see the Radius Accept, for when the user was authenticating with Captive Portal. We see in the accept packet, that the server is sending the attribute 'labguest' to the controller for the user role to be assigned. In the case of Dot1x-Accept screenshot, we do not see any attribute being sent by the server in the accept packet for when the user was authenticating with dot1x authentication. Please check on the server end if we need to enable sending attribute for MSCHAPv2 along with the PAP protocol, or if there are any specific configurations on the server that are handling the attributes to be sent based on the authentication type." users file entry: guest123 Cleartext-Password := guest123 Service-Type = Framed-User, Framed-Filter-Id = labguest # Aruba-User-Role = labguest freeradius -X >debug.txt (during 802.1X authentication) FreeRADIUS Version 3.0.15 Copyright (C) 1999-2017 The FreeRADIUS server project and contributors There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE You may redistribute copies of FreeRADIUS under the terms of the GNU General Public License For more information about these matters, see the file named COPYRIGHT Starting - reading configuration files ... including dictionary file /usr/share/freeradius/dictionary including dictionary file /usr/share/freeradius/dictionary.dhcp including dictionary file /usr/share/freeradius/dictionary.vqp including dictionary file /etc/freeradius/dictionary including configuration file /etc/freeradius/radiusd.conf including configuration file /etc/freeradius/proxy.conf including configuration file /etc/freeradius/clients.conf including files in directory /etc/freeradius/mods-enabled/ including configuration file /etc/freeradius/mods-enabled/dynamic_clients including configuration file /etc/freeradius/mods-enabled/unix including configuration file /etc/freeradius/mods-enabled/passwd including configuration file /etc/freeradius/mods-enabled/pap including configuration file /etc/freeradius/mods-enabled/always including configuration file /etc/freeradius/mods-enabled/chap including configuration file /etc/freeradius/mods-enabled/exec including configuration file /etc/freeradius/mods-enabled/linelog including configuration file /etc/freeradius/mods-enabled/eap including configuration file /etc/freeradius/mods-enabled/sradutmp including configuration file /etc/freeradius/mods-enabled/unpack including configuration file /etc/freeradius/mods-enabled/date including configuration file /etc/freeradius/mods-enabled/replicate including configuration file /etc/freeradius/mods-enabled/echo including configuration file /etc/freeradius/mods-enabled/expiration including configuration file /etc/freeradius/mods-enabled/mschap including configuration file /etc/freeradius/mods-enabled/detail.log including configuration file /etc/freeradius/mods-enabled/expr including configuration file /etc/freeradius/mods-enabled/radutmp including configuration file /etc/freeradius/mods-enabled/cache_eap including configuration file /etc/freeradius/mods-enabled/digest including configuration file /etc/freeradius/mods-enabled/logintime including configuration file /etc/freeradius/mods-enabled/attr_filter including configuration file /etc/freeradius/mods-enabled/realm including configuration file /etc/freeradius/mods-enabled/utf8 including configuration file /etc/freeradius/mods-enabled/ntlm_auth including configuration file /etc/freeradius/mods-enabled/detail including configuration file /etc/freeradius/mods-enabled/soh including configuration file /etc/freeradius/mods-enabled/files including configuration file /etc/freeradius/mods-enabled/preprocess including files in directory /etc/freeradius/policy.d/ including configuration file /etc/freeradius/policy.d/filter including configuration file /etc/freeradius/policy.d/accounting including configuration file /etc/freeradius/policy.d/control including configuration file /etc/freeradius/policy.d/canonicalization including configuration file /etc/freeradius/policy.d/cui including configuration file /etc/freeradius/policy.d/eap including configuration file /etc/freeradius/policy.d/dhcp including configuration file /etc/freeradius/policy.d/operator-name including configuration file /etc/freeradius/policy.d/abfab-tr including configuration file /etc/freeradius/policy.d/debug including configuration file /etc/freeradius/policy.d/moonshot-targeted-ids including files in directory /etc/freeradius/sites-enabled/ including configuration file /etc/freeradius/sites-enabled/inner-tunnel including configuration file /etc/freeradius/sites-enabled/default main { security { user = "freerad" group = "freerad" allow_core_dumps = no } name = "freeradius" prefix = "/usr" localstatedir = "/var" logdir = "/var/log/freeradius" run_dir = "/var/run/freeradius" } main { name = "freeradius" prefix = "/usr" localstatedir = "/var" sbindir = "/usr/sbin" logdir = "/var/log/freeradius" run_dir = "/var/run/freeradius" libdir = "/usr/lib/freeradius" radacctdir = "/var/log/freeradius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 16384 pidfile = "/var/run/freeradius/freeradius.pid" checkrad = "/usr/sbin/checkrad" debug_level = 0 proxy_requests = yes log { stripped_names = no auth = no auth_badpass = no auth_goodpass = no colourise = yes msg_denied = "You are already logged in - access denied" } resources { } security { max_attributes = 200 reject_delay = 1.000000 status_server = yes } } radiusd: #### Loading Realms and Home Servers #### proxy server { retry_delay = 5 retry_count = 3 default_fallback = no dead_time = 120 wake_all_if_all_dead = no } home_server localhost { ipaddr = 127.0.0.1 port = 1812 type = "auth" secret = <<< secret >>> response_window = 20.000000 response_timeouts = 1 max_outstanding = 65536 zombie_period = 40 status_check = "status-server" ping_interval = 30 check_interval = 30 check_timeout = 4 num_answers_to_alive = 3 revive_interval = 120 limit { max_connections = 16 max_requests = 0 lifetime = 0 idle_timeout = 0 } coa { irt = 2 mrt = 16 mrc = 5 mrd = 30 } } home_server_pool my_auth_failover { type = fail-over home_server = localhost } realm example.com { auth_pool = my_auth_failover } realm LOCAL { } radiusd: #### Loading Clients #### client localhost { ipaddr = 127.0.0.1 require_message_authenticator = no secret = <<< secret >>> nas_type = "other" proto = "*" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client localhost_ipv6 { ipv6addr = ::1 require_message_authenticator = no secret = <<< secret >>> limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } client 192.168.18.252/30 { require_message_authenticator = no secret = <<< secret >>> shortname = "controllers" limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } No 'ipaddr' or 'ipv4addr' or 'ipv6addr' field found in client 192.168.18.252/30. Please fix your configuration Support for old-style clients will be removed in a future release Debugger not attached # Creating Auth-Type = mschap # Creating Auth-Type = eap # Creating Auth-Type = PAP # Creating Auth-Type = CHAP # Creating Auth-Type = MS-CHAP # Creating Auth-Type = digest radiusd: #### Instantiating modules #### modules { # Loaded module rlm_dynamic_clients # Loading module "dynamic_clients" from file /etc/freeradius/mods-enabled/dynamic_clients # Loaded module rlm_unix # Loading module "unix" from file /etc/freeradius/mods-enabled/unix unix { radwtmp = "/var/log/freeradius/radwtmp" } Creating attribute Unix-Group # Loaded module rlm_passwd # Loading module "etc_passwd" from file /etc/freeradius/mods-enabled/passwd passwd etc_passwd { filename = "/etc/passwd" format = "*User-Name:Crypt-Password:" delimiter = ":" ignore_nislike = no ignore_empty = yes allow_multiple_keys = no hash_size = 100 } # Loaded module rlm_pap # Loading module "pap" from file /etc/freeradius/mods-enabled/pap pap { normalise = yes } # Loaded module rlm_always # Loading module "reject" from file /etc/freeradius/mods-enabled/always always reject { rcode = "reject" simulcount = 0 mpp = no } # Loading module "fail" from file /etc/freeradius/mods-enabled/always always fail { rcode = "fail" simulcount = 0 mpp = no } # Loading module "ok" from file /etc/freeradius/mods-enabled/always always ok { rcode = "ok" simulcount = 0 mpp = no } # Loading module "handled" from file /etc/freeradius/mods-enabled/always always handled { rcode = "handled" simulcount = 0 mpp = no } # Loading module "invalid" from file /etc/freeradius/mods-enabled/always always invalid { rcode = "invalid" simulcount = 0 mpp = no } # Loading module "userlock" from file /etc/freeradius/mods-enabled/always always userlock { rcode = "userlock" simulcount = 0 mpp = no } # Loading module "notfound" from file /etc/freeradius/mods-enabled/always always notfound { rcode = "notfound" simulcount = 0 mpp = no } # Loading module "noop" from file /etc/freeradius/mods-enabled/always always noop { rcode = "noop" simulcount = 0 mpp = no } # Loading module "updated" from file /etc/freeradius/mods-enabled/always always updated { rcode = "updated" simulcount = 0 mpp = no } # Loaded module rlm_chap # Loading module "chap" from file /etc/freeradius/mods-enabled/chap # Loaded module rlm_exec # Loading module "exec" from file /etc/freeradius/mods-enabled/exec exec { wait = no input_pairs = "request" shell_escape = yes timeout = 10 } # Loaded module rlm_linelog # Loading module "linelog" from file /etc/freeradius/mods-enabled/linelog linelog { filename = "/var/log/freeradius/linelog" escape_filenames = no syslog_severity = "info" permissions = 384 format = "This is a log message for %{User-Name}" reference = "messages.%{%{reply:Packet-Type}:-default}" } # Loading module "log_accounting" from file /etc/freeradius/mods-enabled/linelog linelog log_accounting { filename = "/var/log/freeradius/linelog-accounting" escape_filenames = no syslog_severity = "info" permissions = 384 format = "" reference = "Accounting-Request.%{%{Acct-Status-Type}:-unknown}" } # Loaded module rlm_eap # Loading module "eap" from file /etc/freeradius/mods-enabled/eap eap { default_eap_type = "md5" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = 16384 } # Loaded module rlm_radutmp # Loading module "sradutmp" from file /etc/freeradius/mods-enabled/sradutmp radutmp sradutmp { filename = "/var/log/freeradius/sradutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes permissions = 420 caller_id = no } # Loaded module rlm_unpack # Loading module "unpack" from file /etc/freeradius/mods-enabled/unpack # Loaded module rlm_date # Loading module "date" from file /etc/freeradius/mods-enabled/date date { format = "%b %e %Y %H:%M:%S %Z" utc = no } # Loaded module rlm_replicate # Loading module "replicate" from file /etc/freeradius/mods-enabled/replicate # Loading module "echo" from file /etc/freeradius/mods-enabled/echo exec echo { wait = yes program = "/bin/echo %{User-Name}" input_pairs = "request" output_pairs = "reply" shell_escape = yes } # Loaded module rlm_expiration # Loading module "expiration" from file /etc/freeradius/mods-enabled/expiration # Loaded module rlm_mschap # Loading module "mschap" from file /etc/freeradius/mods-enabled/mschap mschap { use_mppe = yes require_encryption = no require_strong = no with_ntdomain_hack = yes passchange { } allow_retry = yes winbind_retry_with_normalised_username = no } # Loaded module rlm_detail # Loading module "auth_log" from file /etc/freeradius/mods-enabled/detail.log detail auth_log { filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loading module "reply_log" from file /etc/freeradius/mods-enabled/detail.log detail reply_log { filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loading module "pre_proxy_log" from file /etc/freeradius/mods-enabled/detail.log detail pre_proxy_log { filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/pre-proxy-detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loading module "post_proxy_log" from file /etc/freeradius/mods-enabled/detail.log detail post_proxy_log { filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/post-proxy-detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loaded module rlm_expr # Loading module "expr" from file /etc/freeradius/mods-enabled/expr expr { safe_characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /Ã¤Ã©Ã¶Ã¼Ã Ã¢Ã¦Ã§Ã¨Ã©ÃªÃ«Ã®Ã¯Ã´Å“Ã¹Ã»Ã¼aÃ¿Ã„Ã‰Ã–ÃœÃŸÃ€Ã‚Ã†Ã‡ÃˆÃ‰ÃŠÃ‹ÃŽÃ Ã”Å’Ã™Ã›ÃœÅ¸" } # Loading module "radutmp" from file /etc/freeradius/mods-enabled/radutmp radutmp { filename = "/var/log/freeradius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes permissions = 384 caller_id = yes } # Loaded module rlm_cache # Loading module "cache_eap" from file /etc/freeradius/mods-enabled/cache_eap cache cache_eap { driver = "rlm_cache_rbtree" key = "%{%{control:State}:-%{%{reply:State}:-%{State}}}" ttl = 15 max_entries = 0 epoch = 0 add_stats = no } # Loaded module rlm_digest # Loading module "digest" from file /etc/freeradius/mods-enabled/digest # Loaded module rlm_logintime # Loading module "logintime" from file /etc/freeradius/mods-enabled/logintime logintime { minimum_timeout = 60 } # Loaded module rlm_attr_filter # Loading module "attr_filter.post-proxy" from file /etc/freeradius/mods-enabled/attr_filter attr_filter attr_filter.post-proxy { filename = "/etc/freeradius/mods-config/attr_filter/post-proxy" key = "%{Realm}" relaxed = no } # Loading module "attr_filter.pre-proxy" from file /etc/freeradius/mods-enabled/attr_filter attr_filter attr_filter.pre-proxy { filename = "/etc/freeradius/mods-config/attr_filter/pre-proxy" key = "%{Realm}" relaxed = no } # Loading module "attr_filter.access_reject" from file /etc/freeradius/mods-enabled/attr_filter attr_filter attr_filter.access_reject { filename = "/etc/freeradius/mods-config/attr_filter/access_reject" key = "%{User-Name}" relaxed = no } # Loading module "attr_filter.access_challenge" from file /etc/freeradius/mods-enabled/attr_filter attr_filter attr_filter.access_challenge { filename = "/etc/freeradius/mods-config/attr_filter/access_challenge" key = "%{User-Name}" relaxed = no } # Loading module "attr_filter.accounting_response" from file /etc/freeradius/mods-enabled/attr_filter attr_filter attr_filter.accounting_response { filename = "/etc/freeradius/mods-config/attr_filter/accounting_response" key = "%{User-Name}" relaxed = no } # Loaded module rlm_realm # Loading module "IPASS" from file /etc/freeradius/mods-enabled/realm realm IPASS { format = "prefix" delimiter = "/" ignore_default = no ignore_null = no } # Loading module "suffix" from file /etc/freeradius/mods-enabled/realm realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } # Loading module "realmpercent" from file /etc/freeradius/mods-enabled/realm realm realmpercent { format = "suffix" delimiter = "%" ignore_default = no ignore_null = no } # Loading module "ntdomain" from file /etc/freeradius/mods-enabled/realm realm ntdomain { format = "prefix" delimiter = "\\" ignore_default = no ignore_null = no } # Loaded module rlm_utf8 # Loading module "utf8" from file /etc/freeradius/mods-enabled/utf8 # Loading module "ntlm_auth" from file /etc/freeradius/mods-enabled/ntlm_auth exec ntlm_auth { wait = yes program = "/path/to/ntlm_auth --request-nt-key --domain=MYDOMAIN --username=%{mschap:User-Name} --password=%{User-Password}" shell_escape = yes } # Loading module "detail" from file /etc/freeradius/mods-enabled/detail detail { filename = "/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" header = "%t" permissions = 384 locking = no escape_filenames = no log_packet_header = no } # Loaded module rlm_soh # Loading module "soh" from file /etc/freeradius/mods-enabled/soh soh { dhcp = yes } # Loaded module rlm_files # Loading module "files" from file /etc/freeradius/mods-enabled/files files { filename = "/etc/freeradius/mods-config/files/authorize" acctusersfile = "/etc/freeradius/mods-config/files/accounting" preproxy_usersfile = "/etc/freeradius/mods-config/files/pre-proxy" } # Loaded module rlm_preprocess # Loading module "preprocess" from file /etc/freeradius/mods-enabled/preprocess preprocess { huntgroups = "/etc/freeradius/mods-config/preprocess/huntgroups" hints = "/etc/freeradius/mods-config/preprocess/hints" with_ascend_hack = no ascend_channels_per_line = 23 with_ntdomain_hack = no with_specialix_jetstream_hack = no with_cisco_vsa_hack = no with_alvarion_vsa_hack = no } instantiate { } # Instantiating module "etc_passwd" from file /etc/freeradius/mods-enabled/passwd rlm_passwd: nfields: 3 keyfield 0(User-Name) listable: no # Instantiating module "pap" from file /etc/freeradius/mods-enabled/pap # Instantiating module "reject" from file /etc/freeradius/mods-enabled/always # Instantiating module "fail" from file /etc/freeradius/mods-enabled/always # Instantiating module "ok" from file /etc/freeradius/mods-enabled/always # Instantiating module "handled" from file /etc/freeradius/mods-enabled/always # Instantiating module "invalid" from file /etc/freeradius/mods-enabled/always # Instantiating module "userlock" from file /etc/freeradius/mods-enabled/always # Instantiating module "notfound" from file /etc/freeradius/mods-enabled/always # Instantiating module "noop" from file /etc/freeradius/mods-enabled/always # Instantiating module "updated" from file /etc/freeradius/mods-enabled/always # Instantiating module "linelog" from file /etc/freeradius/mods-enabled/linelog # Instantiating module "log_accounting" from file /etc/freeradius/mods-enabled/linelog # Instantiating module "eap" from file /etc/freeradius/mods-enabled/eap # Linked to sub-module rlm_eap_md5 # Linked to sub-module rlm_eap_leap # Linked to sub-module rlm_eap_gtc gtc { challenge = "Password: " auth_type = "PAP" } # Linked to sub-module rlm_eap_tls tls { tls = "tls-common" } tls-config tls-common { verify_depth = 0 ca_path = "/etc/freeradius/certs" pem_file_type = yes private_key_file = "/etc/freeradius/certs/server.pem" certificate_file = "/etc/freeradius/certs/server.pem" ca_file = "/etc/freeradius/certs/ca.pem" private_key_password = <<< secret >>> dh_file = "/etc/freeradius/certs/dh" fragment_size = 1024 include_length = yes auto_chain = yes check_crl = no check_all_crl = no cipher_list = "DEFAULT" cipher_server_preference = no ecdh_curve = "prime256v1" cache { enable = no lifetime = 24 max_entries = 255 } verify { skip_if_ocsp_ok = no } ocsp { enable = no override_cert_url = yes url = "http://127.0.0.1/ocsp/" use_nonce = yes timeout = 0 softfail = no } } # Linked to sub-module rlm_eap_ttls ttls { tls = "tls-common" default_eap_type = "md5" copy_request_to_tunnel = no use_tunneled_reply = no virtual_server = "inner-tunnel" include_length = yes require_client_cert = no } tls: Using cached TLS configuration from previous invocation # Linked to sub-module rlm_eap_peap peap { tls = "tls-common" default_eap_type = "mschapv2" copy_request_to_tunnel = no use_tunneled_reply = no proxy_tunneled_request_as_eap = yes virtual_server = "inner-tunnel" soh = no require_client_cert = no } tls: Using cached TLS configuration from previous invocation # Linked to sub-module rlm_eap_mschapv2 mschapv2 { with_ntdomain_hack = no send_error = no } # Instantiating module "expiration" from file /etc/freeradius/mods-enabled/expiration # Instantiating module "mschap" from file /etc/freeradius/mods-enabled/mschap rlm_mschap (mschap): using internal authentication # Instantiating module "auth_log" from file /etc/freeradius/mods-enabled/detail.log rlm_detail (auth_log): 'User-Password' suppressed, will not appear in detail output # Instantiating module "reply_log" from file /etc/freeradius/mods-enabled/detail.log # Instantiating module "pre_proxy_log" from file /etc/freeradius/mods-enabled/detail.log # Instantiating module "post_proxy_log" from file /etc/freeradius/mods-enabled/detail.log # Instantiating module "cache_eap" from file /etc/freeradius/mods-enabled/cache_eap rlm_cache (cache_eap): Driver rlm_cache_rbtree (module rlm_cache_rbtree) loaded and linked # Instantiating module "logintime" from file /etc/freeradius/mods-enabled/logintime # Instantiating module "attr_filter.post-proxy" from file /etc/freeradius/mods-enabled/attr_filter reading pairlist file /etc/freeradius/mods-config/attr_filter/post-proxy # Instantiating module "attr_filter.pre-proxy" from file /etc/freeradius/mods-enabled/attr_filter reading pairlist file /etc/freeradius/mods-config/attr_filter/pre-proxy # Instantiating module "attr_filter.access_reject" from file /etc/freeradius/mods-enabled/attr_filter reading pairlist file /etc/freeradius/mods-config/attr_filter/access_reject [/etc/freeradius/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay" found in filter list for realm "DEFAULT". [/etc/freeradius/mods-config/attr_filter/access_reject]:11 Check item "FreeRADIUS-Response-Delay-USec" found in filter list for realm "DEFAULT". # Instantiating module "attr_filter.access_challenge" from file /etc/freeradius/mods-enabled/attr_filter reading pairlist file /etc/freeradius/mods-config/attr_filter/access_challenge # Instantiating module "attr_filter.accounting_response" from file /etc/freeradius/mods-enabled/attr_filter reading pairlist file /etc/freeradius/mods-config/attr_filter/accounting_response # Instantiating module "IPASS" from file /etc/freeradius/mods-enabled/realm # Instantiating module "suffix" from file /etc/freeradius/mods-enabled/realm # Instantiating module "realmpercent" from file /etc/freeradius/mods-enabled/realm # Instantiating module "ntdomain" from file /etc/freeradius/mods-enabled/realm # Instantiating module "detail" from file /etc/freeradius/mods-enabled/detail # Instantiating module "files" from file /etc/freeradius/mods-enabled/files reading pairlist file /etc/freeradius/mods-config/files/authorize reading pairlist file /etc/freeradius/mods-config/files/accounting reading pairlist file /etc/freeradius/mods-config/files/pre-proxy # Instantiating module "preprocess" from file /etc/freeradius/mods-enabled/preprocess reading pairlist file /etc/freeradius/mods-config/preprocess/huntgroups reading pairlist file /etc/freeradius/mods-config/preprocess/hints } # modules radiusd: #### Loading Virtual Servers #### server { # from file /etc/freeradius/radiusd.conf } # server server inner-tunnel { # from file /etc/freeradius/sites-enabled/inner-tunnel # Loading authenticate {...} # Loading authorize {...} Ignoring "sql" (see raddb/mods-available/README.rst) Ignoring "ldap" (see raddb/mods-available/README.rst) # Loading session {...} # Loading post-proxy {...} # Loading post-auth {...} # Skipping contents of 'if' as it is always 'false' -- /etc/freeradius/sites-enabled/inner-tunnel:331 } # server inner-tunnel server default { # from file /etc/freeradius/sites-enabled/default # Loading authenticate {...} # Loading authorize {...} # Loading preacct {...} # Loading accounting {...} # Loading post-proxy {...} # Loading post-auth {...} } # server default radiusd: #### Opening IP addresses and Ports #### listen { type = "auth" ipaddr = 127.0.0.1 port = 18120 } listen { type = "auth" ipaddr = * port = 0 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "acct" ipaddr = * port = 0 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "auth" ipv6addr = :: port = 0 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } listen { type = "acct" ipv6addr = :: port = 0 limit { max_connections = 16 lifetime = 0 idle_timeout = 30 } } Listening on auth address 127.0.0.1 port 18120 bound to server inner-tunnel Listening on auth address * port 1812 bound to server default Listening on acct address * port 1813 bound to server default Listening on auth address :: port 1812 bound to server default Listening on acct address :: port 1813 bound to server default Listening on proxy address * port 52175 Listening on proxy address :: port 58823 Ready to process requests (0) Received Access-Request Id 25 from 192.168.18.254:34699 to 192.168.18.249:1812 length 175 (0) User-Name = "guest123" (0) NAS-IP-Address = 192.168.18.254 (0) NAS-Port = 0 (0) NAS-Identifier = "192.168.18.254" (0) NAS-Port-Type = Wireless-802.11 (0) Calling-Station-Id = "FCC2DE13D615" (0) Called-Station-Id = "000B86BE91F0" (0) Service-Type = Framed-User (0) Framed-MTU = 1100 (0) EAP-Message = 0x0201000d016775657374313233 (0) Aruba-Essid-Name = "Lab-Emp" (0) Aruba-Location-Id = "AP2" (0) Aruba-AP-Group = "Lab1" (0) Message-Authenticator = 0x925f4bb690888ecfb2ed0712e9dc2763 (0) # Executing section authorize from file /etc/freeradius/sites-enabled/default (0) authorize { (0) policy filter_username { (0) if (&User-Name) { (0) if (&User-Name) -> TRUE (0) if (&User-Name) { (0) if (&User-Name =~ / /) { (0) if (&User-Name =~ / /) -> FALSE (0) if (&User-Name =~ /@[^@]*@/ ) { (0) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (0) if (&User-Name =~ /\.\./ ) { (0) if (&User-Name =~ /\.\./ ) -> FALSE (0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (0) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (0) if (&User-Name =~ /\.$/) { (0) if (&User-Name =~ /\.$/) -> FALSE (0) if (&User-Name =~ /(a)\./) { (0) if (&User-Name =~ /(a)\./) -> FALSE (0) } # if (&User-Name) = notfound (0) } # policy filter_username = notfound (0) [preprocess] = ok (0) [chap] = noop (0) [mschap] = noop (0) [digest] = noop (0) suffix: Checking for suffix after "@" (0) suffix: No '@' in User-Name = "guest123", looking up realm NULL (0) suffix: No such realm "NULL" (0) [suffix] = noop (0) eap: Peer sent EAP Response (code 2) ID 1 length 13 (0) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (0) [eap] = ok (0) } # authorize = ok (0) Found Auth-Type = eap (0) # Executing group from file /etc/freeradius/sites-enabled/default (0) authenticate { (0) eap: Peer sent packet with method EAP Identity (1) (0) eap: Calling submodule eap_md5 to process data (0) eap_md5: Issuing MD5 Challenge (0) eap: Sending EAP Request (code 1) ID 2 length 22 (0) eap: EAP session adding &reply:State = 0x2724385327263c5e (0) [eap] = handled (0) } # authenticate = handled (0) Using Post-Auth-Type Challenge (0) # Executing group from file /etc/freeradius/sites-enabled/default (0) Challenge { ... } # empty sub-section is ignored (0) Sent Access-Challenge Id 25 from 192.168.18.249:1812 to 192.168.18.254:34699 length 0 (0) EAP-Message = 0x010200160410be92f80cde14421822c7aef9cddd92ad (0) Message-Authenticator = 0x00000000000000000000000000000000 (0) State = 0x2724385327263c5e98ac8b27aec7a2e9 (0) Finished request Waking up in 4.9 seconds. (1) Received Access-Request Id 26 from 192.168.18.254:34699 to 192.168.18.249:1812 length 186 (1) User-Name = "guest123" (1) NAS-IP-Address = 192.168.18.254 (1) NAS-Port = 0 (1) NAS-Identifier = "192.168.18.254" (1) NAS-Port-Type = Wireless-802.11 (1) Calling-Station-Id = "FCC2DE13D615" (1) Called-Station-Id = "000B86BE91F0" (1) Service-Type = Framed-User (1) Framed-MTU = 1100 (1) EAP-Message = 0x020200060319 (1) State = 0x2724385327263c5e98ac8b27aec7a2e9 (1) Aruba-Essid-Name = "Lab-Emp" (1) Aruba-Location-Id = "AP2" (1) Aruba-AP-Group = "Lab1" (1) Message-Authenticator = 0x4811f18d2df2e85e6331dc9706d6339a (1) session-state: No cached attributes (1) # Executing section authorize from file /etc/freeradius/sites-enabled/default (1) authorize { (1) policy filter_username { (1) if (&User-Name) { (1) if (&User-Name) -> TRUE (1) if (&User-Name) { (1) if (&User-Name =~ / /) { (1) if (&User-Name =~ / /) -> FALSE (1) if (&User-Name =~ /@[^@]*@/ ) { (1) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (1) if (&User-Name =~ /\.\./ ) { (1) if (&User-Name =~ /\.\./ ) -> FALSE (1) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (1) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (1) if (&User-Name =~ /\.$/) { (1) if (&User-Name =~ /\.$/) -> FALSE (1) if (&User-Name =~ /(a)\./) { (1) if (&User-Name =~ /(a)\./) -> FALSE (1) } # if (&User-Name) = notfound (1) } # policy filter_username = notfound (1) [preprocess] = ok (1) [chap] = noop (1) [mschap] = noop (1) [digest] = noop (1) suffix: Checking for suffix after "@" (1) suffix: No '@' in User-Name = "guest123", looking up realm NULL (1) suffix: No such realm "NULL" (1) [suffix] = noop (1) eap: Peer sent EAP Response (code 2) ID 2 length 6 (1) eap: No EAP Start, assuming it's an on-going EAP conversation (1) [eap] = updated (1) files: users: Matched entry guest123 at line 83 (1) [files] = ok (1) [expiration] = noop (1) [logintime] = noop (1) pap: WARNING: Auth-Type already set. Not setting to PAP (1) [pap] = noop (1) } # authorize = updated (1) Found Auth-Type = eap (1) # Executing group from file /etc/freeradius/sites-enabled/default (1) authenticate { (1) eap: Expiring EAP session with state 0x2724385327263c5e (1) eap: Finished EAP session with state 0x2724385327263c5e (1) eap: Previous EAP request found for state 0x2724385327263c5e, released from the list (1) eap: Peer sent packet with method EAP NAK (3) (1) eap: Found mutually acceptable type PEAP (25) (1) eap: Calling submodule eap_peap to process data (1) eap_peap: Initiating new EAP-TLS session (1) eap_peap: [eaptls start] = request (1) eap: Sending EAP Request (code 1) ID 3 length 6 (1) eap: EAP session adding &reply:State = 0x272438532627215e (1) [eap] = handled (1) } # authenticate = handled (1) Using Post-Auth-Type Challenge (1) # Executing group from file /etc/freeradius/sites-enabled/default (1) Challenge { ... } # empty sub-section is ignored (1) Sent Access-Challenge Id 26 from 192.168.18.249:1812 to 192.168.18.254:34699 length 0 (1) Service-Type = Framed-User (1) Framed-Filter-Id = "labguest" (1) EAP-Message = 0x010300061920 (1) Message-Authenticator = 0x00000000000000000000000000000000 (1) State = 0x272438532627215e98ac8b27aec7a2e9 (1) Finished request Waking up in 4.9 seconds. (2) Received Access-Request Id 27 from 192.168.18.254:34699 to 192.168.18.249:1812 length 348 (2) User-Name = "guest123" (2) NAS-IP-Address = 192.168.18.254 (2) NAS-Port = 0 (2) NAS-Identifier = "192.168.18.254" (2) NAS-Port-Type = Wireless-802.11 (2) Calling-Station-Id = "FCC2DE13D615" (2) Called-Station-Id = "000B86BE91F0" (2) Service-Type = Framed-User (2) Framed-MTU = 1100 (2) EAP-Message = 0x020300a819800000009e160301009901000095030351420a701c69b71e022bfefca1f2db978fea3b282c885e1fe769c98633b61bf200003cc02cc030009fc02bc02f009ec00ac024c014c0280039006bc009c023c013c02700330067c007c011009d009c0035003d002f003c00050004000a00ff010000 (2) State = 0x272438532627215e98ac8b27aec7a2e9 (2) Aruba-Essid-Name = "Lab-Emp" (2) Aruba-Location-Id = "AP2" (2) Aruba-AP-Group = "Lab1" (2) Message-Authenticator = 0x4de1e143ed6f87e69dd173b1b6b9badf (2) session-state: No cached attributes (2) # Executing section authorize from file /etc/freeradius/sites-enabled/default (2) authorize { (2) policy filter_username { (2) if (&User-Name) { (2) if (&User-Name) -> TRUE (2) if (&User-Name) { (2) if (&User-Name =~ / /) { (2) if (&User-Name =~ / /) -> FALSE (2) if (&User-Name =~ /@[^@]*@/ ) { (2) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (2) if (&User-Name =~ /\.\./ ) { (2) if (&User-Name =~ /\.\./ ) -> FALSE (2) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (2) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (2) if (&User-Name =~ /\.$/) { (2) if (&User-Name =~ /\.$/) -> FALSE (2) if (&User-Name =~ /(a)\./) { (2) if (&User-Name =~ /(a)\./) -> FALSE (2) } # if (&User-Name) = notfound (2) } # policy filter_username = notfound (2) [preprocess] = ok (2) [chap] = noop (2) [mschap] = noop (2) [digest] = noop (2) suffix: Checking for suffix after "@" (2) suffix: No '@' in User-Name = "guest123", looking up realm NULL (2) suffix: No such realm "NULL" (2) [suffix] = noop (2) eap: Peer sent EAP Response (code 2) ID 3 length 168 (2) eap: Continuing tunnel setup (2) [eap] = ok (2) } # authorize = ok (2) Found Auth-Type = eap (2) # Executing group from file /etc/freeradius/sites-enabled/default (2) authenticate { (2) eap: Expiring EAP session with state 0x272438532627215e (2) eap: Finished EAP session with state 0x272438532627215e (2) eap: Previous EAP request found for state 0x272438532627215e, released from the list (2) eap: Peer sent packet with method EAP PEAP (25) (2) eap: Calling submodule eap_peap to process data (2) eap_peap: Continuing EAP-TLS (2) eap_peap: Peer indicated complete TLS record size will be 158 bytes (2) eap_peap: Got complete TLS record (158 bytes) (2) eap_peap: [eaptls verify] = length included (2) eap_peap: (other): before/accept initialization (2) eap_peap: TLS_accept: before/accept initialization (2) eap_peap: <<< recv TLS 1.2 [length 0099] (2) eap_peap: TLS_accept: unknown state (2) eap_peap: >>> send TLS 1.2 [length 0039] (2) eap_peap: TLS_accept: unknown state (2) eap_peap: >>> send TLS 1.2 [length 08d3] (2) eap_peap: TLS_accept: unknown state (2) eap_peap: >>> send TLS 1.2 [length 014d] (2) eap_peap: TLS_accept: unknown state (2) eap_peap: >>> send TLS 1.2 [length 0004] (2) eap_peap: TLS_accept: unknown state (2) eap_peap: TLS_accept: unknown state (2) eap_peap: TLS_accept: unknown state (2) eap_peap: TLS_accept: Need to read more data: unknown state (2) eap_peap: TLS_accept: Need to read more data: unknown state (2) eap_peap: In SSL Handshake Phase (2) eap_peap: In SSL Accept mode (2) eap_peap: [eaptls process] = handled (2) eap: Sending EAP Request (code 1) ID 4 length 1004 (2) eap: EAP session adding &reply:State = 0x272438532520215e (2) [eap] = handled (2) } # authenticate = handled (2) Using Post-Auth-Type Challenge (2) # Executing group from file /etc/freeradius/sites-enabled/default (2) Challenge { ... } # empty sub-section is ignored (2) Sent Access-Challenge Id 27 from 192.168.18.249:1812 to 192.168.18.254:34699 length 0 (2) EAP-Message = 0x010403ec19c000000a7116030300390200003503038b8c255d818236f426c1840ad18a511f5766971605f11426679da99674863f3900c03000000dff01000100000b00040300010216030308d30b0008cf0008cc0003de308203da308202c2a003020102020101300d06092a864886f70d01010b050030 (2) Message-Authenticator = 0x00000000000000000000000000000000 (2) State = 0x272438532520215e98ac8b27aec7a2e9 (2) Finished request Waking up in 4.9 seconds. (3) Received Access-Request Id 28 from 192.168.18.254:34699 to 192.168.18.249:1812 length 186 (3) User-Name = "guest123" (3) NAS-IP-Address = 192.168.18.254 (3) NAS-Port = 0 (3) NAS-Identifier = "192.168.18.254" (3) NAS-Port-Type = Wireless-802.11 (3) Calling-Station-Id = "FCC2DE13D615" (3) Called-Station-Id = "000B86BE91F0" (3) Service-Type = Framed-User (3) Framed-MTU = 1100 (3) EAP-Message = 0x020400061900 (3) State = 0x272438532520215e98ac8b27aec7a2e9 (3) Aruba-Essid-Name = "Lab-Emp" (3) Aruba-Location-Id = "AP2" (3) Aruba-AP-Group = "Lab1" (3) Message-Authenticator = 0x2599264e8586db5dae34da0eaef3289e (3) session-state: No cached attributes (3) # Executing section authorize from file /etc/freeradius/sites-enabled/default (3) authorize { (3) policy filter_username { (3) if (&User-Name) { (3) if (&User-Name) -> TRUE (3) if (&User-Name) { (3) if (&User-Name =~ / /) { (3) if (&User-Name =~ / /) -> FALSE (3) if (&User-Name =~ /@[^@]*@/ ) { (3) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (3) if (&User-Name =~ /\.\./ ) { (3) if (&User-Name =~ /\.\./ ) -> FALSE (3) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (3) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (3) if (&User-Name =~ /\.$/) { (3) if (&User-Name =~ /\.$/) -> FALSE (3) if (&User-Name =~ /(a)\./) { (3) if (&User-Name =~ /(a)\./) -> FALSE (3) } # if (&User-Name) = notfound (3) } # policy filter_username = notfound (3) [preprocess] = ok (3) [chap] = noop (3) [mschap] = noop (3) [digest] = noop (3) suffix: Checking for suffix after "@" (3) suffix: No '@' in User-Name = "guest123", looking up realm NULL (3) suffix: No such realm "NULL" (3) [suffix] = noop (3) eap: Peer sent EAP Response (code 2) ID 4 length 6 (3) eap: Continuing tunnel setup (3) [eap] = ok (3) } # authorize = ok (3) Found Auth-Type = eap (3) # Executing group from file /etc/freeradius/sites-enabled/default (3) authenticate { (3) eap: Expiring EAP session with state 0x272438532520215e (3) eap: Finished EAP session with state 0x272438532520215e (3) eap: Previous EAP request found for state 0x272438532520215e, released from the list (3) eap: Peer sent packet with method EAP PEAP (25) (3) eap: Calling submodule eap_peap to process data (3) eap_peap: Continuing EAP-TLS (3) eap_peap: Peer ACKed our handshake fragment (3) eap_peap: [eaptls verify] = request (3) eap_peap: [eaptls process] = handled (3) eap: Sending EAP Request (code 1) ID 5 length 1000 (3) eap: EAP session adding &reply:State = 0x272438532421215e (3) [eap] = handled (3) } # authenticate = handled (3) Using Post-Auth-Type Challenge (3) # Executing group from file /etc/freeradius/sites-enabled/default (3) Challenge { ... } # empty sub-section is ignored (3) Sent Access-Challenge Id 28 from 192.168.18.249:1812 to 192.168.18.254:34699 length 0 (3) EAP-Message = 0x010503e81940b3464a51b48237f903c224328639e85e5b770170059dee2e5f6262ea8eaa176d0b7375178b2fc5e2982d52109a1d28afa041936bbde97f01eb488c556c3ad793a3c05c4ce03ec60a250004e8308204e4308203cca003020102020900ba4d5f67b91400f4300d06092a864886f70d01010b (3) Message-Authenticator = 0x00000000000000000000000000000000 (3) State = 0x272438532421215e98ac8b27aec7a2e9 (3) Finished request Waking up in 4.9 seconds. (4) Received Access-Request Id 29 from 192.168.18.254:34699 to 192.168.18.249:1812 length 186 (4) User-Name = "guest123" (4) NAS-IP-Address = 192.168.18.254 (4) NAS-Port = 0 (4) NAS-Identifier = "192.168.18.254" (4) NAS-Port-Type = Wireless-802.11 (4) Calling-Station-Id = "FCC2DE13D615" (4) Called-Station-Id = "000B86BE91F0" (4) Service-Type = Framed-User (4) Framed-MTU = 1100 (4) EAP-Message = 0x020500061900 (4) State = 0x272438532421215e98ac8b27aec7a2e9 (4) Aruba-Essid-Name = "Lab-Emp" (4) Aruba-Location-Id = "AP2" (4) Aruba-AP-Group = "Lab1" (4) Message-Authenticator = 0x2a5dee3c82daff22fa3784aaa42efdeb (4) session-state: No cached attributes (4) # Executing section authorize from file /etc/freeradius/sites-enabled/default (4) authorize { (4) policy filter_username { (4) if (&User-Name) { (4) if (&User-Name) -> TRUE (4) if (&User-Name) { (4) if (&User-Name =~ / /) { (4) if (&User-Name =~ / /) -> FALSE (4) if (&User-Name =~ /@[^@]*@/ ) { (4) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (4) if (&User-Name =~ /\.\./ ) { (4) if (&User-Name =~ /\.\./ ) -> FALSE (4) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (4) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (4) if (&User-Name =~ /\.$/) { (4) if (&User-Name =~ /\.$/) -> FALSE (4) if (&User-Name =~ /(a)\./) { (4) if (&User-Name =~ /(a)\./) -> FALSE (4) } # if (&User-Name) = notfound (4) } # policy filter_username = notfound (4) [preprocess] = ok (4) [chap] = noop (4) [mschap] = noop (4) [digest] = noop (4) suffix: Checking for suffix after "@" (4) suffix: No '@' in User-Name = "guest123", looking up realm NULL (4) suffix: No such realm "NULL" (4) [suffix] = noop (4) eap: Peer sent EAP Response (code 2) ID 5 length 6 (4) eap: Continuing tunnel setup (4) [eap] = ok (4) } # authorize = ok (4) Found Auth-Type = eap (4) # Executing group from file /etc/freeradius/sites-enabled/default (4) authenticate { (4) eap: Expiring EAP session with state 0x272438532421215e (4) eap: Finished EAP session with state 0x272438532421215e (4) eap: Previous EAP request found for state 0x272438532421215e, released from the list (4) eap: Peer sent packet with method EAP PEAP (25) (4) eap: Calling submodule eap_peap to process data (4) eap_peap: Continuing EAP-TLS (4) eap_peap: Peer ACKed our handshake fragment (4) eap_peap: [eaptls verify] = request (4) eap_peap: [eaptls process] = handled (4) eap: Sending EAP Request (code 1) ID 6 length 691 (4) eap: EAP session adding &reply:State = 0x272438532322215e (4) [eap] = handled (4) } # authenticate = handled (4) Using Post-Auth-Type Challenge (4) # Executing group from file /etc/freeradius/sites-enabled/default (4) Challenge { ... } # empty sub-section is ignored (4) Sent Access-Challenge Id 29 from 192.168.18.249:1812 to 192.168.18.254:34699 length 0 (4) EAP-Message = 0x010602b319000530030101ff30360603551d1f042f302d302ba029a0278625687474703a2f2f7777772e6578616d706c652e6f72672f6578616d706c655f63612e63726c300d06092a864886f70d01010b0500038201010014ce6047b11dc0496a6a34b1f3816e18cd01ac2674bcff0a863e13c4e9cbfc (4) Message-Authenticator = 0x00000000000000000000000000000000 (4) State = 0x272438532322215e98ac8b27aec7a2e9 (4) Finished request Waking up in 4.9 seconds. (5) Received Access-Request Id 30 from 192.168.18.254:34699 to 192.168.18.249:1812 length 316 (5) User-Name = "guest123" (5) NAS-IP-Address = 192.168.18.254 (5) NAS-Port = 0 (5) NAS-Identifier = "192.168.18.254" (5) NAS-Port-Type = Wireless-802.11 (5) Calling-Station-Id = "FCC2DE13D615" (5) Called-Station-Id = "000B86BE91F0" (5) Service-Type = Framed-User (5) Framed-MTU = 1100 (5) EAP-Message = 0x0206008819800000007e1603030046100000424104d0f9e8adeef83edd7b632876ad923ec186ae8b1e859ea4fa359dbd35de9642ba0f559498b3eddc2447904549bb594a13b88840d09e87251b5f80643854a7e2b614030300010116030300280000000000000000557431360d5361ce5e15b5371e31dd (5) State = 0x272438532322215e98ac8b27aec7a2e9 (5) Aruba-Essid-Name = "Lab-Emp" (5) Aruba-Location-Id = "AP2" (5) Aruba-AP-Group = "Lab1" (5) Message-Authenticator = 0x3564ee1b45184fc438f8f3bdf1b1fe1b (5) session-state: No cached attributes (5) # Executing section authorize from file /etc/freeradius/sites-enabled/default (5) authorize { (5) policy filter_username { (5) if (&User-Name) { (5) if (&User-Name) -> TRUE (5) if (&User-Name) { (5) if (&User-Name =~ / /) { (5) if (&User-Name =~ / /) -> FALSE (5) if (&User-Name =~ /@[^@]*@/ ) { (5) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (5) if (&User-Name =~ /\.\./ ) { (5) if (&User-Name =~ /\.\./ ) -> FALSE (5) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (5) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (5) if (&User-Name =~ /\.$/) { (5) if (&User-Name =~ /\.$/) -> FALSE (5) if (&User-Name =~ /(a)\./) { (5) if (&User-Name =~ /(a)\./) -> FALSE (5) } # if (&User-Name) = notfound (5) } # policy filter_username = notfound (5) [preprocess] = ok (5) [chap] = noop (5) [mschap] = noop (5) [digest] = noop (5) suffix: Checking for suffix after "@" (5) suffix: No '@' in User-Name = "guest123", looking up realm NULL (5) suffix: No such realm "NULL" (5) [suffix] = noop (5) eap: Peer sent EAP Response (code 2) ID 6 length 136 (5) eap: Continuing tunnel setup (5) [eap] = ok (5) } # authorize = ok (5) Found Auth-Type = eap (5) # Executing group from file /etc/freeradius/sites-enabled/default (5) authenticate { (5) eap: Expiring EAP session with state 0x272438532322215e (5) eap: Finished EAP session with state 0x272438532322215e (5) eap: Previous EAP request found for state 0x272438532322215e, released from the list (5) eap: Peer sent packet with method EAP PEAP (25) (5) eap: Calling submodule eap_peap to process data (5) eap_peap: Continuing EAP-TLS (5) eap_peap: Peer indicated complete TLS record size will be 126 bytes (5) eap_peap: Got complete TLS record (126 bytes) (5) eap_peap: [eaptls verify] = length included (5) eap_peap: <<< recv TLS 1.2 [length 0046] (5) eap_peap: TLS_accept: unknown state (5) eap_peap: TLS_accept: unknown state (5) eap_peap: <<< recv TLS 1.2 [length 0001] (5) eap_peap: <<< recv TLS 1.2 [length 0010] (5) eap_peap: TLS_accept: unknown state (5) eap_peap: >>> send TLS 1.2 [length 0001] (5) eap_peap: TLS_accept: unknown state (5) eap_peap: >>> send TLS 1.2 [length 0010] (5) eap_peap: TLS_accept: unknown state (5) eap_peap: TLS_accept: unknown state (5) eap_peap: (other): SSL negotiation finished successfully (5) eap_peap: SSL Connection Established (5) eap_peap: [eaptls process] = handled (5) eap: Sending EAP Request (code 1) ID 7 length 57 (5) eap: EAP session adding &reply:State = 0x272438532223215e (5) [eap] = handled (5) } # authenticate = handled (5) Using Post-Auth-Type Challenge (5) # Executing group from file /etc/freeradius/sites-enabled/default (5) Challenge { ... } # empty sub-section is ignored (5) Sent Access-Challenge Id 30 from 192.168.18.249:1812 to 192.168.18.254:34699 length 0 (5) EAP-Message = 0x01070039190014030300010116030300289018523e94e9668064012fd528ca23ff74f19d11f0b81931e73f8f8196da044df416429f9ba7df00 (5) Message-Authenticator = 0x00000000000000000000000000000000 (5) State = 0x272438532223215e98ac8b27aec7a2e9 (5) Finished request Waking up in 4.9 seconds. (6) Received Access-Request Id 31 from 192.168.18.254:34699 to 192.168.18.249:1812 length 186 (6) User-Name = "guest123" (6) NAS-IP-Address = 192.168.18.254 (6) NAS-Port = 0 (6) NAS-Identifier = "192.168.18.254" (6) NAS-Port-Type = Wireless-802.11 (6) Calling-Station-Id = "FCC2DE13D615" (6) Called-Station-Id = "000B86BE91F0" (6) Service-Type = Framed-User (6) Framed-MTU = 1100 (6) EAP-Message = 0x020700061900 (6) State = 0x272438532223215e98ac8b27aec7a2e9 (6) Aruba-Essid-Name = "Lab-Emp" (6) Aruba-Location-Id = "AP2" (6) Aruba-AP-Group = "Lab1" (6) Message-Authenticator = 0x2d3960cecca5ad8f5711842e056644a8 (6) session-state: No cached attributes (6) # Executing section authorize from file /etc/freeradius/sites-enabled/default (6) authorize { (6) policy filter_username { (6) if (&User-Name) { (6) if (&User-Name) -> TRUE (6) if (&User-Name) { (6) if (&User-Name =~ / /) { (6) if (&User-Name =~ / /) -> FALSE (6) if (&User-Name =~ /@[^@]*@/ ) { (6) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (6) if (&User-Name =~ /\.\./ ) { (6) if (&User-Name =~ /\.\./ ) -> FALSE (6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (6) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (6) if (&User-Name =~ /\.$/) { (6) if (&User-Name =~ /\.$/) -> FALSE (6) if (&User-Name =~ /(a)\./) { (6) if (&User-Name =~ /(a)\./) -> FALSE (6) } # if (&User-Name) = notfound (6) } # policy filter_username = notfound (6) [preprocess] = ok (6) [chap] = noop (6) [mschap] = noop (6) [digest] = noop (6) suffix: Checking for suffix after "@" (6) suffix: No '@' in User-Name = "guest123", looking up realm NULL (6) suffix: No such realm "NULL" (6) [suffix] = noop (6) eap: Peer sent EAP Response (code 2) ID 7 length 6 (6) eap: Continuing tunnel setup (6) [eap] = ok (6) } # authorize = ok (6) Found Auth-Type = eap (6) # Executing group from file /etc/freeradius/sites-enabled/default (6) authenticate { (6) eap: Expiring EAP session with state 0x272438532223215e (6) eap: Finished EAP session with state 0x272438532223215e (6) eap: Previous EAP request found for state 0x272438532223215e, released from the list (6) eap: Peer sent packet with method EAP PEAP (25) (6) eap: Calling submodule eap_peap to process data (6) eap_peap: Continuing EAP-TLS (6) eap_peap: Peer ACKed our handshake fragment. handshake is finished (6) eap_peap: [eaptls verify] = success (6) eap_peap: [eaptls process] = success (6) eap_peap: Session established. Decoding tunneled attributes (6) eap_peap: PEAP state TUNNEL ESTABLISHED (6) eap: Sending EAP Request (code 1) ID 8 length 40 (6) eap: EAP session adding &reply:State = 0x27243853212c215e (6) [eap] = handled (6) } # authenticate = handled (6) Using Post-Auth-Type Challenge (6) # Executing group from file /etc/freeradius/sites-enabled/default (6) Challenge { ... } # empty sub-section is ignored (6) Sent Access-Challenge Id 31 from 192.168.18.249:1812 to 192.168.18.254:34699 length 0 (6) EAP-Message = 0x010800281900170303001d9018523e94e96681f327f9aab624fdd3fb220a996352a11c1c8bd3f09a (6) Message-Authenticator = 0x00000000000000000000000000000000 (6) State = 0x27243853212c215e98ac8b27aec7a2e9 (6) Finished request Waking up in 4.9 seconds. (7) Received Access-Request Id 32 from 192.168.18.254:34699 to 192.168.18.249:1812 length 224 (7) User-Name = "guest123" (7) NAS-IP-Address = 192.168.18.254 (7) NAS-Port = 0 (7) NAS-Identifier = "192.168.18.254" (7) NAS-Port-Type = Wireless-802.11 (7) Calling-Station-Id = "FCC2DE13D615" (7) Called-Station-Id = "000B86BE91F0" (7) Service-Type = Framed-User (7) Framed-MTU = 1100 (7) EAP-Message = 0x0208002c190017030300210000000000000001baa0f292af6e46b9011ba57555d82552a599aa231fe0567668 (7) State = 0x27243853212c215e98ac8b27aec7a2e9 (7) Aruba-Essid-Name = "Lab-Emp" (7) Aruba-Location-Id = "AP2" (7) Aruba-AP-Group = "Lab1" (7) Message-Authenticator = 0x140fe08d897ef464a081fd62b9e1558a (7) session-state: No cached attributes (7) # Executing section authorize from file /etc/freeradius/sites-enabled/default (7) authorize { (7) policy filter_username { (7) if (&User-Name) { (7) if (&User-Name) -> TRUE (7) if (&User-Name) { (7) if (&User-Name =~ / /) { (7) if (&User-Name =~ / /) -> FALSE (7) if (&User-Name =~ /@[^@]*@/ ) { (7) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (7) if (&User-Name =~ /\.\./ ) { (7) if (&User-Name =~ /\.\./ ) -> FALSE (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (7) if (&User-Name =~ /\.$/) { (7) if (&User-Name =~ /\.$/) -> FALSE (7) if (&User-Name =~ /(a)\./) { (7) if (&User-Name =~ /(a)\./) -> FALSE (7) } # if (&User-Name) = notfound (7) } # policy filter_username = notfound (7) [preprocess] = ok (7) [chap] = noop (7) [mschap] = noop (7) [digest] = noop (7) suffix: Checking for suffix after "@" (7) suffix: No '@' in User-Name = "guest123", looking up realm NULL (7) suffix: No such realm "NULL" (7) [suffix] = noop (7) eap: Peer sent EAP Response (code 2) ID 8 length 44 (7) eap: Continuing tunnel setup (7) [eap] = ok (7) } # authorize = ok (7) Found Auth-Type = eap (7) # Executing group from file /etc/freeradius/sites-enabled/default (7) authenticate { (7) eap: Expiring EAP session with state 0x27243853212c215e (7) eap: Finished EAP session with state 0x27243853212c215e (7) eap: Previous EAP request found for state 0x27243853212c215e, released from the list (7) eap: Peer sent packet with method EAP PEAP (25) (7) eap: Calling submodule eap_peap to process data (7) eap_peap: Continuing EAP-TLS (7) eap_peap: [eaptls verify] = ok (7) eap_peap: Done initial handshake (7) eap_peap: [eaptls process] = ok (7) eap_peap: Session established. Decoding tunneled attributes (7) eap_peap: PEAP state WAITING FOR INNER IDENTITY (7) eap_peap: Identity - guest123 (7) eap_peap: Got inner identity 'guest123' (7) eap_peap: Setting default EAP type for tunneled EAP session (7) eap_peap: Got tunneled request (7) eap_peap: EAP-Message = 0x0208000d016775657374313233 (7) eap_peap: Setting User-Name to guest123 (7) eap_peap: Sending tunneled request to inner-tunnel (7) eap_peap: EAP-Message = 0x0208000d016775657374313233 (7) eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1 (7) eap_peap: User-Name = "guest123" (7) Virtual server inner-tunnel received request (7) EAP-Message = 0x0208000d016775657374313233 (7) FreeRADIUS-Proxied-To = 127.0.0.1 (7) User-Name = "guest123" (7) WARNING: Outer and inner identities are the same. User privacy is compromised. (7) server inner-tunnel { (7) # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel (7) authorize { (7) policy filter_username { (7) if (&User-Name) { (7) if (&User-Name) -> TRUE (7) if (&User-Name) { (7) if (&User-Name =~ / /) { (7) if (&User-Name =~ / /) -> FALSE (7) if (&User-Name =~ /@[^@]*@/ ) { (7) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (7) if (&User-Name =~ /\.\./ ) { (7) if (&User-Name =~ /\.\./ ) -> FALSE (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (7) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (7) if (&User-Name =~ /\.$/) { (7) if (&User-Name =~ /\.$/) -> FALSE (7) if (&User-Name =~ /(a)\./) { (7) if (&User-Name =~ /(a)\./) -> FALSE (7) } # if (&User-Name) = notfound (7) } # policy filter_username = notfound (7) [chap] = noop (7) [mschap] = noop (7) suffix: Checking for suffix after "@" (7) suffix: No '@' in User-Name = "guest123", looking up realm NULL (7) suffix: No such realm "NULL" (7) [suffix] = noop (7) update control { (7) &Proxy-To-Realm := LOCAL (7) } # update control = noop (7) eap: Peer sent EAP Response (code 2) ID 8 length 13 (7) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (7) [eap] = ok (7) } # authorize = ok (7) Found Auth-Type = eap (7) # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel (7) authenticate { (7) eap: Peer sent packet with method EAP Identity (1) (7) eap: Calling submodule eap_mschapv2 to process data (7) eap_mschapv2: Issuing Challenge (7) eap: Sending EAP Request (code 1) ID 9 length 43 (7) eap: EAP session adding &reply:State = 0x7e55fae97e5ce062 (7) [eap] = handled (7) } # authenticate = handled (7) } # server inner-tunnel (7) Virtual server sending reply (7) EAP-Message = 0x0109002b1a010900261097922be676e49f82a77191d1f81936fd667265657261646975732d332e302e3135 (7) Message-Authenticator = 0x00000000000000000000000000000000 (7) State = 0x7e55fae97e5ce062953a46e59f6aca5d (7) eap_peap: Got tunneled reply code 11 (7) eap_peap: EAP-Message = 0x0109002b1a010900261097922be676e49f82a77191d1f81936fd667265657261646975732d332e302e3135 (7) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (7) eap_peap: State = 0x7e55fae97e5ce062953a46e59f6aca5d (7) eap_peap: Got tunneled reply RADIUS code 11 (7) eap_peap: EAP-Message = 0x0109002b1a010900261097922be676e49f82a77191d1f81936fd667265657261646975732d332e302e3135 (7) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (7) eap_peap: State = 0x7e55fae97e5ce062953a46e59f6aca5d (7) eap_peap: Got tunneled Access-Challenge (7) eap: Sending EAP Request (code 1) ID 9 length 74 (7) eap: EAP session adding &reply:State = 0x27243853202d215e (7) [eap] = handled (7) } # authenticate = handled (7) Using Post-Auth-Type Challenge (7) # Executing group from file /etc/freeradius/sites-enabled/default (7) Challenge { ... } # empty sub-section is ignored (7) Sent Access-Challenge Id 32 from 192.168.18.249:1812 to 192.168.18.254:34699 length 0 (7) EAP-Message = 0x0109004a1900170303003f9018523e94e96682367ce8727a8a9e14ec67e81247024d824abd55a3221de0086eb247f7b416ddbd8ed22a6f89317e7c4d61b0683d1b443f5fbd77b63489e1 (7) Message-Authenticator = 0x00000000000000000000000000000000 (7) State = 0x27243853202d215e98ac8b27aec7a2e9 (7) Finished request Waking up in 4.9 seconds. (8) Received Access-Request Id 33 from 192.168.18.254:34699 to 192.168.18.249:1812 length 278 (8) User-Name = "guest123" (8) NAS-IP-Address = 192.168.18.254 (8) NAS-Port = 0 (8) NAS-Identifier = "192.168.18.254" (8) NAS-Port-Type = Wireless-802.11 (8) Calling-Station-Id = "FCC2DE13D615" (8) Called-Station-Id = "000B86BE91F0" (8) Service-Type = Framed-User (8) Framed-MTU = 1100 (8) EAP-Message = 0x020900621900170303005700000000000000025b07e90041ca58d369208d24becfafc781f48ac97a8d3bcf6af4da664b59c3089af6f9bf7e3a4fe2958ddeddcd36ecf109b4e876af1bc4ed0413a81043dea336a6dfdbc1f082c226aa82674d7f2760 (8) State = 0x27243853202d215e98ac8b27aec7a2e9 (8) Aruba-Essid-Name = "Lab-Emp" (8) Aruba-Location-Id = "AP2" (8) Aruba-AP-Group = "Lab1" (8) Message-Authenticator = 0x1494d4f4e6f96b9d38954a5858f21942 (8) session-state: No cached attributes (8) # Executing section authorize from file /etc/freeradius/sites-enabled/default (8) authorize { (8) policy filter_username { (8) if (&User-Name) { (8) if (&User-Name) -> TRUE (8) if (&User-Name) { (8) if (&User-Name =~ / /) { (8) if (&User-Name =~ / /) -> FALSE (8) if (&User-Name =~ /@[^@]*@/ ) { (8) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (8) if (&User-Name =~ /\.\./ ) { (8) if (&User-Name =~ /\.\./ ) -> FALSE (8) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (8) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (8) if (&User-Name =~ /\.$/) { (8) if (&User-Name =~ /\.$/) -> FALSE (8) if (&User-Name =~ /(a)\./) { (8) if (&User-Name =~ /(a)\./) -> FALSE (8) } # if (&User-Name) = notfound (8) } # policy filter_username = notfound (8) [preprocess] = ok (8) [chap] = noop (8) [mschap] = noop (8) [digest] = noop (8) suffix: Checking for suffix after "@" (8) suffix: No '@' in User-Name = "guest123", looking up realm NULL (8) suffix: No such realm "NULL" (8) [suffix] = noop (8) eap: Peer sent EAP Response (code 2) ID 9 length 98 (8) eap: Continuing tunnel setup (8) [eap] = ok (8) } # authorize = ok (8) Found Auth-Type = eap (8) # Executing group from file /etc/freeradius/sites-enabled/default (8) authenticate { (8) eap: Expiring EAP session with state 0x7e55fae97e5ce062 (8) eap: Finished EAP session with state 0x27243853202d215e (8) eap: Previous EAP request found for state 0x27243853202d215e, released from the list (8) eap: Peer sent packet with method EAP PEAP (25) (8) eap: Calling submodule eap_peap to process data (8) eap_peap: Continuing EAP-TLS (8) eap_peap: [eaptls verify] = ok (8) eap_peap: Done initial handshake (8) eap_peap: [eaptls process] = ok (8) eap_peap: Session established. Decoding tunneled attributes (8) eap_peap: PEAP state phase2 (8) eap_peap: EAP method MSCHAPv2 (26) (8) eap_peap: Got tunneled request (8) eap_peap: EAP-Message = 0x020900431a0209003e31a6e58c71825a239eba1d236b87edfbaf0000000000000000a490586c52df19fb3daed0ff3c660c65f4a0e42deda644e4006775657374313233 (8) eap_peap: Setting User-Name to guest123 (8) eap_peap: Sending tunneled request to inner-tunnel (8) eap_peap: EAP-Message = 0x020900431a0209003e31a6e58c71825a239eba1d236b87edfbaf0000000000000000a490586c52df19fb3daed0ff3c660c65f4a0e42deda644e4006775657374313233 (8) eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1 (8) eap_peap: User-Name = "guest123" (8) eap_peap: State = 0x7e55fae97e5ce062953a46e59f6aca5d (8) Virtual server inner-tunnel received request (8) EAP-Message = 0x020900431a0209003e31a6e58c71825a239eba1d236b87edfbaf0000000000000000a490586c52df19fb3daed0ff3c660c65f4a0e42deda644e4006775657374313233 (8) FreeRADIUS-Proxied-To = 127.0.0.1 (8) User-Name = "guest123" (8) State = 0x7e55fae97e5ce062953a46e59f6aca5d (8) WARNING: Outer and inner identities are the same. User privacy is compromised. (8) server inner-tunnel { (8) session-state: No cached attributes (8) # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel (8) authorize { (8) policy filter_username { (8) if (&User-Name) { (8) if (&User-Name) -> TRUE (8) if (&User-Name) { (8) if (&User-Name =~ / /) { (8) if (&User-Name =~ / /) -> FALSE (8) if (&User-Name =~ /@[^@]*@/ ) { (8) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (8) if (&User-Name =~ /\.\./ ) { (8) if (&User-Name =~ /\.\./ ) -> FALSE (8) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (8) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (8) if (&User-Name =~ /\.$/) { (8) if (&User-Name =~ /\.$/) -> FALSE (8) if (&User-Name =~ /(a)\./) { (8) if (&User-Name =~ /(a)\./) -> FALSE (8) } # if (&User-Name) = notfound (8) } # policy filter_username = notfound (8) [chap] = noop (8) [mschap] = noop (8) suffix: Checking for suffix after "@" (8) suffix: No '@' in User-Name = "guest123", looking up realm NULL (8) suffix: No such realm "NULL" (8) [suffix] = noop (8) update control { (8) &Proxy-To-Realm := LOCAL (8) } # update control = noop (8) eap: Peer sent EAP Response (code 2) ID 9 length 67 (8) eap: No EAP Start, assuming it's an on-going EAP conversation (8) [eap] = updated (8) files: users: Matched entry guest123 at line 83 (8) [files] = ok (8) [expiration] = noop (8) [logintime] = noop (8) pap: WARNING: Auth-Type already set. Not setting to PAP (8) [pap] = noop (8) } # authorize = updated (8) Found Auth-Type = eap (8) # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel (8) authenticate { (8) eap: Expiring EAP session with state 0x7e55fae97e5ce062 (8) eap: Finished EAP session with state 0x7e55fae97e5ce062 (8) eap: Previous EAP request found for state 0x7e55fae97e5ce062, released from the list (8) eap: Peer sent packet with method EAP MSCHAPv2 (26) (8) eap: Calling submodule eap_mschapv2 to process data (8) eap_mschapv2: # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel (8) eap_mschapv2: authenticate { (8) mschap: Found Cleartext-Password, hashing to create NT-Password (8) mschap: Found Cleartext-Password, hashing to create LM-Password (8) mschap: Creating challenge hash with username: guest123 (8) mschap: Client is using MS-CHAPv2 (8) mschap: Adding MS-CHAPv2 MPPE keys (8) [mschap] = ok (8) } # authenticate = ok (8) MSCHAP Success (8) eap: Sending EAP Request (code 1) ID 10 length 51 (8) eap: EAP session adding &reply:State = 0x7e55fae97f5fe062 (8) [eap] = handled (8) } # authenticate = handled (8) } # server inner-tunnel (8) Virtual server sending reply (8) Service-Type = Framed-User (8) Framed-Filter-Id = "labguest" (8) EAP-Message = 0x010a00331a0309002e533d35333438383739343943363842353730453536434335453930373133303941383631384133353138 (8) Message-Authenticator = 0x00000000000000000000000000000000 (8) State = 0x7e55fae97f5fe062953a46e59f6aca5d (8) eap_peap: Got tunneled reply code 11 (8) eap_peap: Service-Type = Framed-User (8) eap_peap: Framed-Filter-Id = "labguest" (8) eap_peap: EAP-Message = 0x010a00331a0309002e533d35333438383739343943363842353730453536434335453930373133303941383631384133353138 (8) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (8) eap_peap: State = 0x7e55fae97f5fe062953a46e59f6aca5d (8) eap_peap: Got tunneled reply RADIUS code 11 (8) eap_peap: Service-Type = Framed-User (8) eap_peap: Framed-Filter-Id = "labguest" (8) eap_peap: EAP-Message = 0x010a00331a0309002e533d35333438383739343943363842353730453536434335453930373133303941383631384133353138 (8) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (8) eap_peap: State = 0x7e55fae97f5fe062953a46e59f6aca5d (8) eap_peap: Got tunneled Access-Challenge (8) eap: Sending EAP Request (code 1) ID 10 length 82 (8) eap: EAP session adding &reply:State = 0x272438532f2e215e (8) [eap] = handled (8) } # authenticate = handled (8) Using Post-Auth-Type Challenge (8) # Executing group from file /etc/freeradius/sites-enabled/default (8) Challenge { ... } # empty sub-section is ignored (8) Sent Access-Challenge Id 33 from 192.168.18.249:1812 to 192.168.18.254:34699 length 0 (8) EAP-Message = 0x010a0052190017030300479018523e94e96683003a64f8c2fc607231faab888b7914d28511b61349fdf799e48fb5275a8279c3dad0dbfa972e89b71d70dd3b5f7f88fdabb45c2f7ed0eb35ff5458b62be6f3 (8) Message-Authenticator = 0x00000000000000000000000000000000 (8) State = 0x272438532f2e215e98ac8b27aec7a2e9 (8) Finished request Waking up in 4.9 seconds. (9) Received Access-Request Id 34 from 192.168.18.254:34699 to 192.168.18.249:1812 length 217 (9) User-Name = "guest123" (9) NAS-IP-Address = 192.168.18.254 (9) NAS-Port = 0 (9) NAS-Identifier = "192.168.18.254" (9) NAS-Port-Type = Wireless-802.11 (9) Calling-Station-Id = "FCC2DE13D615" (9) Called-Station-Id = "000B86BE91F0" (9) Service-Type = Framed-User (9) Framed-MTU = 1100 (9) EAP-Message = 0x020a00251900170303001a00000000000000031a0db7fef0d6affebf275ef50f7c34ccbe4e (9) State = 0x272438532f2e215e98ac8b27aec7a2e9 (9) Aruba-Essid-Name = "Lab-Emp" (9) Aruba-Location-Id = "AP2" (9) Aruba-AP-Group = "Lab1" (9) Message-Authenticator = 0x2b3cc1b5e21a1cb3d3ccf39d0da2f8c1 (9) session-state: No cached attributes (9) # Executing section authorize from file /etc/freeradius/sites-enabled/default (9) authorize { (9) policy filter_username { (9) if (&User-Name) { (9) if (&User-Name) -> TRUE (9) if (&User-Name) { (9) if (&User-Name =~ / /) { (9) if (&User-Name =~ / /) -> FALSE (9) if (&User-Name =~ /@[^@]*@/ ) { (9) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (9) if (&User-Name =~ /\.\./ ) { (9) if (&User-Name =~ /\.\./ ) -> FALSE (9) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (9) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (9) if (&User-Name =~ /\.$/) { (9) if (&User-Name =~ /\.$/) -> FALSE (9) if (&User-Name =~ /(a)\./) { (9) if (&User-Name =~ /(a)\./) -> FALSE (9) } # if (&User-Name) = notfound (9) } # policy filter_username = notfound (9) [preprocess] = ok (9) [chap] = noop (9) [mschap] = noop (9) [digest] = noop (9) suffix: Checking for suffix after "@" (9) suffix: No '@' in User-Name = "guest123", looking up realm NULL (9) suffix: No such realm "NULL" (9) [suffix] = noop (9) eap: Peer sent EAP Response (code 2) ID 10 length 37 (9) eap: Continuing tunnel setup (9) [eap] = ok (9) } # authorize = ok (9) Found Auth-Type = eap (9) # Executing group from file /etc/freeradius/sites-enabled/default (9) authenticate { (9) eap: Expiring EAP session with state 0x7e55fae97f5fe062 (9) eap: Finished EAP session with state 0x272438532f2e215e (9) eap: Previous EAP request found for state 0x272438532f2e215e, released from the list (9) eap: Peer sent packet with method EAP PEAP (25) (9) eap: Calling submodule eap_peap to process data (9) eap_peap: Continuing EAP-TLS (9) eap_peap: [eaptls verify] = ok (9) eap_peap: Done initial handshake (9) eap_peap: [eaptls process] = ok (9) eap_peap: Session established. Decoding tunneled attributes (9) eap_peap: PEAP state phase2 (9) eap_peap: EAP method MSCHAPv2 (26) (9) eap_peap: Got tunneled request (9) eap_peap: EAP-Message = 0x020a00061a03 (9) eap_peap: Setting User-Name to guest123 (9) eap_peap: Sending tunneled request to inner-tunnel (9) eap_peap: EAP-Message = 0x020a00061a03 (9) eap_peap: FreeRADIUS-Proxied-To = 127.0.0.1 (9) eap_peap: User-Name = "guest123" (9) eap_peap: State = 0x7e55fae97f5fe062953a46e59f6aca5d (9) Virtual server inner-tunnel received request (9) EAP-Message = 0x020a00061a03 (9) FreeRADIUS-Proxied-To = 127.0.0.1 (9) User-Name = "guest123" (9) State = 0x7e55fae97f5fe062953a46e59f6aca5d (9) WARNING: Outer and inner identities are the same. User privacy is compromised. (9) server inner-tunnel { (9) session-state: No cached attributes (9) # Executing section authorize from file /etc/freeradius/sites-enabled/inner-tunnel (9) authorize { (9) policy filter_username { (9) if (&User-Name) { (9) if (&User-Name) -> TRUE (9) if (&User-Name) { (9) if (&User-Name =~ / /) { (9) if (&User-Name =~ / /) -> FALSE (9) if (&User-Name =~ /@[^@]*@/ ) { (9) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (9) if (&User-Name =~ /\.\./ ) { (9) if (&User-Name =~ /\.\./ ) -> FALSE (9) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (9) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (9) if (&User-Name =~ /\.$/) { (9) if (&User-Name =~ /\.$/) -> FALSE (9) if (&User-Name =~ /(a)\./) { (9) if (&User-Name =~ /(a)\./) -> FALSE (9) } # if (&User-Name) = notfound (9) } # policy filter_username = notfound (9) [chap] = noop (9) [mschap] = noop (9) suffix: Checking for suffix after "@" (9) suffix: No '@' in User-Name = "guest123", looking up realm NULL (9) suffix: No such realm "NULL" (9) [suffix] = noop (9) update control { (9) &Proxy-To-Realm := LOCAL (9) } # update control = noop (9) eap: Peer sent EAP Response (code 2) ID 10 length 6 (9) eap: No EAP Start, assuming it's an on-going EAP conversation (9) [eap] = updated (9) files: users: Matched entry guest123 at line 83 (9) [files] = ok (9) [expiration] = noop (9) [logintime] = noop (9) pap: WARNING: Auth-Type already set. Not setting to PAP (9) [pap] = noop (9) } # authorize = updated (9) Found Auth-Type = eap (9) # Executing group from file /etc/freeradius/sites-enabled/inner-tunnel (9) authenticate { (9) eap: Expiring EAP session with state 0x7e55fae97f5fe062 (9) eap: Finished EAP session with state 0x7e55fae97f5fe062 (9) eap: Previous EAP request found for state 0x7e55fae97f5fe062, released from the list (9) eap: Peer sent packet with method EAP MSCHAPv2 (26) (9) eap: Calling submodule eap_mschapv2 to process data (9) eap: Sending EAP Success (code 3) ID 10 length 4 (9) eap: Freeing handler (9) [eap] = ok (9) } # authenticate = ok (9) # Executing section post-auth from file /etc/freeradius/sites-enabled/inner-tunnel (9) post-auth { (9) if (0) { (9) if (0) -> FALSE (9) } # post-auth = noop (9) } # server inner-tunnel (9) Virtual server sending reply (9) Service-Type = Framed-User (9) Framed-Filter-Id = "labguest" (9) MS-MPPE-Encryption-Policy = Encryption-Allowed (9) MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed (9) MS-MPPE-Send-Key = 0x6b660abc849dd06d02c8666fb1df94e9 (9) MS-MPPE-Recv-Key = 0x7fc0b21fdd0d434e44d71e1ecffa48d0 (9) EAP-Message = 0x030a0004 (9) Message-Authenticator = 0x00000000000000000000000000000000 (9) User-Name = "guest123" (9) eap_peap: Got tunneled reply code 2 (9) eap_peap: Service-Type = Framed-User (9) eap_peap: Framed-Filter-Id = "labguest" (9) eap_peap: MS-MPPE-Encryption-Policy = Encryption-Allowed (9) eap_peap: MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed (9) eap_peap: MS-MPPE-Send-Key = 0x6b660abc849dd06d02c8666fb1df94e9 (9) eap_peap: MS-MPPE-Recv-Key = 0x7fc0b21fdd0d434e44d71e1ecffa48d0 (9) eap_peap: EAP-Message = 0x030a0004 (9) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (9) eap_peap: User-Name = "guest123" (9) eap_peap: Got tunneled reply RADIUS code 2 (9) eap_peap: Service-Type = Framed-User (9) eap_peap: Framed-Filter-Id = "labguest" (9) eap_peap: MS-MPPE-Encryption-Policy = Encryption-Allowed (9) eap_peap: MS-MPPE-Encryption-Types = RC4-40or128-bit-Allowed (9) eap_peap: MS-MPPE-Send-Key = 0x6b660abc849dd06d02c8666fb1df94e9 (9) eap_peap: MS-MPPE-Recv-Key = 0x7fc0b21fdd0d434e44d71e1ecffa48d0 (9) eap_peap: EAP-Message = 0x030a0004 (9) eap_peap: Message-Authenticator = 0x00000000000000000000000000000000 (9) eap_peap: User-Name = "guest123" (9) eap_peap: Tunneled authentication was successful (9) eap_peap: SUCCESS (9) eap: Sending EAP Request (code 1) ID 11 length 46 (9) eap: EAP session adding &reply:State = 0x272438532e2f215e (9) [eap] = handled (9) } # authenticate = handled (9) Using Post-Auth-Type Challenge (9) # Executing group from file /etc/freeradius/sites-enabled/default (9) Challenge { ... } # empty sub-section is ignored (9) Sent Access-Challenge Id 34 from 192.168.18.249:1812 to 192.168.18.254:34699 length 0 (9) EAP-Message = 0x010b002e190017030300239018523e94e96684fda2acd46fa344dfb4bd6e9dc2819017927fe688abfe208a8d651f (9) Message-Authenticator = 0x00000000000000000000000000000000 (9) State = 0x272438532e2f215e98ac8b27aec7a2e9 (9) Finished request Waking up in 4.9 seconds. (10) Received Access-Request Id 35 from 192.168.18.254:34699 to 192.168.18.249:1812 length 226 (10) User-Name = "guest123" (10) NAS-IP-Address = 192.168.18.254 (10) NAS-Port = 0 (10) NAS-Identifier = "192.168.18.254" (10) NAS-Port-Type = Wireless-802.11 (10) Calling-Station-Id = "FCC2DE13D615" (10) Called-Station-Id = "000B86BE91F0" (10) Service-Type = Framed-User (10) Framed-MTU = 1100 (10) EAP-Message = 0x020b002e190017030300230000000000000004f146d1ea0f8955fd7d856784ab41de9850863bcbb43418d874af5a (10) State = 0x272438532e2f215e98ac8b27aec7a2e9 (10) Aruba-Essid-Name = "Lab-Emp" (10) Aruba-Location-Id = "AP2" (10) Aruba-AP-Group = "Lab1" (10) Message-Authenticator = 0xc84dc673770cea5197b5288dd7635f1a (10) session-state: No cached attributes (10) # Executing section authorize from file /etc/freeradius/sites-enabled/default (10) authorize { (10) policy filter_username { (10) if (&User-Name) { (10) if (&User-Name) -> TRUE (10) if (&User-Name) { (10) if (&User-Name =~ / /) { (10) if (&User-Name =~ / /) -> FALSE (10) if (&User-Name =~ /@[^@]*@/ ) { (10) if (&User-Name =~ /@[^@]*@/ ) -> FALSE (10) if (&User-Name =~ /\.\./ ) { (10) if (&User-Name =~ /\.\./ ) -> FALSE (10) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) { (10) if ((&User-Name =~ /@/) && (&User-Name !~ /(a)(.+)\.(.+)$/)) -> FALSE (10) if (&User-Name =~ /\.$/) { (10) if (&User-Name =~ /\.$/) -> FALSE (10) if (&User-Name =~ /(a)\./) { (10) if (&User-Name =~ /(a)\./) -> FALSE (10) } # if (&User-Name) = notfound (10) } # policy filter_username = notfound (10) [preprocess] = ok (10) [chap] = noop (10) [mschap] = noop (10) [digest] = noop (10) suffix: Checking for suffix after "@" (10) suffix: No '@' in User-Name = "guest123", looking up realm NULL (10) suffix: No such realm "NULL" (10) [suffix] = noop (10) eap: Peer sent EAP Response (code 2) ID 11 length 46 (10) eap: Continuing tunnel setup (10) [eap] = ok (10) } # authorize = ok (10) Found Auth-Type = eap (10) # Executing group from file /etc/freeradius/sites-enabled/default (10) authenticate { (10) eap: Expiring EAP session with state 0x272438532e2f215e (10) eap: Finished EAP session with state 0x272438532e2f215e (10) eap: Previous EAP request found for state 0x272438532e2f215e, released from the list (10) eap: Peer sent packet with method EAP PEAP (25) (10) eap: Calling submodule eap_peap to process data (10) eap_peap: Continuing EAP-TLS (10) eap_peap: [eaptls verify] = ok (10) eap_peap: Done initial handshake (10) eap_peap: [eaptls process] = ok (10) eap_peap: Session established. Decoding tunneled attributes (10) eap_peap: PEAP state send tlv success (10) eap_peap: Received EAP-TLV response (10) eap_peap: Success (10) eap: Sending EAP Success (code 3) ID 11 length 4 (10) eap: Freeing handler (10) [eap] = ok (10) } # authenticate = ok (10) # Executing section post-auth from file /etc/freeradius/sites-enabled/default (10) post-auth { (10) update { (10) No attributes updated (10) } # update = noop (10) [exec] = noop (10) policy remove_reply_message_if_eap { (10) if (&reply:EAP-Message && &reply:Reply-Message) { (10) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE (10) else { (10) [noop] = noop (10) } # else = noop (10) } # policy remove_reply_message_if_eap = noop (10) } # post-auth = noop (10) Sent Access-Accept Id 35 from 192.168.18.249:1812 to 192.168.18.254:34699 length 0 (10) MS-MPPE-Recv-Key = 0x1898fd2108c78f60fdd3ebc6e998001935e960f785b5fcb3c1765ba0329c8b90 (10) MS-MPPE-Send-Key = 0xb027c9455d30fd20e58e1db39bea514d5b5deee855e215b8485be483be3060da (10) EAP-Message = 0x030b0004 (10) Message-Authenticator = 0x00000000000000000000000000000000 (10) User-Name = "guest123" (10) Finished request Waking up in 4.8 seconds. (0) Cleaning up request packet ID 25 with timestamp +22 (1) Cleaning up request packet ID 26 with timestamp +22 (2) Cleaning up request packet ID 27 with timestamp +22 (3) Cleaning up request packet ID 28 with timestamp +22 (4) Cleaning up request packet ID 29 with timestamp +22 (5) Cleaning up request packet ID 30 with timestamp +22 (6) Cleaning up request packet ID 31 with timestamp +22 (7) Cleaning up request packet ID 32 with timestamp +22 (8) Cleaning up request packet ID 33 with timestamp +22 (9) Cleaning up request packet ID 34 with timestamp +22 (10) Cleaning up request packet ID 35 with timestamp +22 Ready to process requests

2 3