ERROR: eap: We expected EAP type PEAP, but received type MD5
Truax, Peter
PTruax at stmartin.edu
Fri Jan 12 19:44:59 CET 2018
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 !~ /@(.+)\.(.+)$/)) {
(267) Mon Jan 8 14:04:01 2018: Debug: if ((&User-Name =~ /@/) && (&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) = 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 !~ /@(.+)\.(.+)$/)) {
(268) Mon Jan 8 14:04:01 2018: Debug: if ((&User-Name =~ /@/) && (&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) = 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 at netreg:~
[?1034h[root at 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 !~ /@(.+)\.(.+)$/)) {
(264) Mon Jan 8 14:01:26 2018: Debug: if ((&User-Name =~ /@/) && (&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) = 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 !~ /@(.+)\.(.+)$/)) {
(265) Mon Jan 8 14:01:26 2018: Debug: if ((&User-Name =~ /@/) && (&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) = 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 !~ /@(.+)\.(.+)$/)) {
(266) Mon Jan 8 14:01:26 2018: Debug: if ((&User-Name =~ /@/) && (&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) = 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
More information about the Freeradius-Users
mailing list