- Freeradius-Users - lists.freeradius.org

winbind / ntlm_auth funny
by Alex Sharaz 18 Jan '18

18 Jan '18

Hi, I've been using winbindd for a long time to authenticate york users .. and it "just works" We now have a requirement to authenticate another relam via trust relationship between our AD domain and theirs so in mods-enabled copy mschap machap { ... } into mschap mschap_hyms { } replace winbind_username = "%{Stripped-User-Name}" winbind_domain = "ITS.YORK.AC.UK" with winbind_username = "%{Stripped-User-Name}" winbind_domain = "HYMS.AC.UK" plus a few other bits to get inner-tunnel to call mschap_hyms as appropriate Then run eapol_test to perform an auth attempt and the HYMS AD controller bounces the aut with a no such user request Try ntlm_auth --username=eduroamtest2 --domain=HYMS.AC.UK and get the same no such user message However, try ntlm_auth --username=\eduroamtest2 --domain=HYMS.AC.UK and get a success after entering a password. Thought I'd go back to using ntlm_auth in my FR config for HYMS So how do I prefix Stripped-user-name wtih a "\" in inner-tunnel ? A

3 3

Freeradius Restrict User Auth Request Based on VLAN
by JAHANZAIB SYED 18 Jan '18

18 Jan '18

Scenario: We have Mikrotik as NAS and Freeradius as billing. VLAN are configured for each dealer's area. We have few reseller/franchise managers, like Dealer-A, Dealer-B. They can create there own users in freeradius using fronted designed in php. All dealers can view/edit there own users only. Sometimes it happens that Dealer-A creates ID and give it to a user/friend who is sitting in Dealer-B network, therefore from Billing perspective its a Loss of Dealer-B. Can we impose some restriction so that User-ID's created by each dealer should be able to connect only from his network (or from there own VLAN) only. Regards, JZ <http:///>

3 10

Unable to compile Freeradius 3.0.16
by Peter Balsianok 15 Jan '18

15 Jan '18

Hi, I am unable to compile Freeradius 3.0.16. OS version: Red Hat Enterprise Linux Server release 5.11 (Tikanga) Compiler version: Using built-in specs. Target: i386-redhat-linux Configured with: ../configure --prefix=/usr --mandir=/usr/share/man --infodir=/usr/share/info --enable-shared --enable-threads=posix --enable-checking=release --with-system-zlib --enable-__cxa_atexit --disable-libunwind-exceptions --enable-libgcj-multifile --enable-languages=c,c++,objc,obj-c++,java,fortran,ada --enable-java-awt=gtk --disable-dssi --disable-plugin --with-java-home=/usr/lib/jvm/java-1.4.2-gcj-1.4.2.0/jre --with-cpu=generic --host=i386-redhat-linux Thread model: posix gcc version 4.1.2 20080704 (Red Hat 4.1.2-55) Debug logs: CC jlibtool.c HEADER src/include/attributes.h HEADER src/include/features.h HEADER src/include/missing.h HEADER src/include/tls.h HEADER src/include/rfc2865.h HEADER src/include/rfc2866.h HEADER src/include/rfc2867.h HEADER src/include/rfc2868.h HEADER src/include/rfc2869.h HEADER src/include/rfc3162.h HEADER src/include/rfc3576.h HEADER src/include/rfc3580.h HEADER src/include/rfc4072.h HEADER src/include/rfc4372.h HEADER src/include/rfc4603.h HEADER src/include/rfc4675.h HEADER src/include/rfc4679.h HEADER src/include/rfc4818.h HEADER src/include/rfc4849.h HEADER src/include/rfc5090.h HEADER src/include/rfc5176.h HEADER src/include/rfc5447.h HEADER src/include/rfc5580.h HEADER src/include/rfc5607.h HEADER src/include/rfc5904.h HEADER src/include/rfc6519.h HEADER src/include/rfc6572.h HEADER src/include/rfc6677.h HEADER src/include/rfc6911.h HEADER src/include/rfc6929.h HEADER src/include/rfc6930.h HEADER src/include/rfc7055.h HEADER src/include/rfc7155.h HEADER src/include/rfc7268.h HEADER src/include/rfc7499.h HEADER src/include/rfc7930.h HEADER src/include/vqp.h HEADER src/include/freeradius.h CC src/lib/cbuff.c cc1: error: unrecognized command line option "-Wno-date-time" make: *** [build/objs/src/lib/cbuff.lo] Error 1 I have fixed this issue by removing "-Wno-date-time" from configure & configure.ac files. But question is: is it correct approach? Thank you very much.

6 10

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