Help Interpreting Supplicant Failure

Fri Feb 17 21:21:49 CET 2017

Hello FR List,

Running into an issue interpreting FR output from an authentication
attempt with a Windows7 domain-connected supplicant.  Moving from a
lab environment to a production one.  The lab version of this setup
works with both a Macintosh and Windows7 non-domain connected
supplicant.

Want to do EAP-TLS only AAA, but am seeing what looks to be use of
username instead of a certificate.  I'm not familiar with using
domain-connected Win7 supplicants and may be misunderstanding the FR
debug output.  I'm happy to troubleshoot further, but want to make
sure I'm understanding what's actually happening.

Can someone help me interpret this output?  Including only request in
which a reject happens.  If more is needed, I'm happy to include more
information.

Environment:
* CentOS 7.3
* FR 3.0.4

Reject information (domain name changed):
Received Access-Request Id 148 from 10.xx.4.205:1645 to
10.xx.130.253:1812 length 274
User-Name = 'ACME\\philip'
Service-Type = Framed-User
Framed-MTU = 1500
Called-Station-Id = '00-1B-D5-46-78-EF'
Calling-Station-Id = '5C-26-0A-77-B4-CA'
EAP-Message = 0x0208006b190017030100603bb7e79c335675f679b1688e85c39720460f055dc0ba7e96eb1c7e7b7b365a9f43bc1e142d183ac41cdf5b08ed8f1566a5f0faf5ac9c121ad26c8e4adbe2e881615e62072569e415039ea28c5a2bba997d67fd9f6d8618850b54b7ec9d01af6e
Message-Authenticator = 0x354e667dc313ae3f2c001a1cb013eecb
NAS-Port-Type = Ethernet
NAS-Port = 50248
NAS-Port-Id = 'GigabitEthernet2/48'
State = 0x2021716b262968d531eefb122cb3a198
NAS-IP-Address = 10.xx.4.205
(7) Received Access-Request packet from host 10.xx.4.205 port 1645,
id=148, length=274
(7) User-Name = 'ACME\\philip'
(7) Service-Type = Framed-User
(7) Framed-MTU = 1500
(7) Called-Station-Id = '00-1B-D5-46-78-EF'
(7) Calling-Station-Id = '5C-26-0A-77-B4-CA'
(7) EAP-Message =
0x0208006b190017030100603bb7e79c335675f679b1688e85c39720460f055dc0ba7e96eb1c7e7b7b365a9f43bc1e142d183ac41cdf5b08ed8f1566a5f0faf5ac9c121ad26c8e4adbe2e881615e62072569e415039ea28c5a2bba997d67fd9f6d8618850b54b7ec9d01af6e
(7) Message-Authenticator = 0x354e667dc313ae3f2c001a1cb013eecb
(7) NAS-Port-Type = Ethernet
(7) NAS-Port = 50248
(7) NAS-Port-Id = 'GigabitEthernet2/48'
(7) State = 0x2021716b262968d531eefb122cb3a198
(7) NAS-IP-Address = 10.xx.4.205
(7) # Executing section authorize from file /etc/raddb/sites-enabled/default
(7)   authorize {
(7)   filter_username filter_username {
(7)     if (!&User-Name)
(7)     if (!&User-Name)  -> FALSE
(7)     if (&User-Name =~ / /)
(7)     if (&User-Name =~ / /)  -> FALSE
(7)     if (&User-Name =~ /@.*@/ )
(7)     if (&User-Name =~ /@.*@/ )  -> FALSE
(7)     if (&User-Name =~ /\\.\\./ )
(7)     if (&User-Name =~ /\\.\\./ )  -> FALSE
(7)     if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\\.(.+)$/))
(7)     if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\\.(.+)$/))   -> FALSE
(7)     if (&User-Name =~ /\\.$/)
(7)     if (&User-Name =~ /\\.$/)   -> FALSE
(7)     if (&User-Name =~ /@\\./)
(7)     if (&User-Name =~ /@\\./)   -> FALSE
(7)   } # filter_username filter_username = notfound
(7)   [preprocess] = ok
(7)   [digest] = noop
(7)  suffix : Checking for suffix after "@"
(7)  suffix : No '@' in User-Name = "ACME\philip", looking up realm NULL
(7)  suffix : No such realm "NULL"
(7)   [suffix] = noop
(7)  eap : Peer sent code Response (2) ID 8 length 107
(7)  eap : Continuing tunnel setup
(7)   [eap] = ok
(7)  } #  authorize = ok
(7) Found Auth-Type = EAP
(7) # Executing group from file /etc/raddb/sites-enabled/default
(7)   authenticate {
(7)  eap : Expiring EAP session with state 0xf281125af2890830
(7)  eap : Finished EAP session with state 0x2021716b262968d5
(7)  eap : Previous EAP request found for state 0x2021716b262968d5,
released from the list
(7)  eap : Peer sent method PEAP (25)
(7)  eap : EAP PEAP (25)
(7)  eap : Calling eap_peap to process EAP data
(7)  eap_peap : processing EAP-TLS
(7)  eap_peap : eaptls_verify returned 7
(7)  eap_peap : Done initial handshake
(7)  eap_peap : eaptls_process returned 7
(7)  eap_peap : FR_TLS_OK
(7)  eap_peap : Session established.  Decoding tunneled attributes
(7)  eap_peap : Peap state phase2
(7)  eap_peap : EAP type MSCHAPv2 (26)
(7)  eap_peap : Got tunneled request
EAP-Message = 0x0208004b1a020800463191e6b09be07b605fda54036913080947000000000000000092ef9f3797c75a4e63bf6778433b6dbf51c612d8ef5824c0005941414e41544543485c7068696c6970
server default {
(7)  eap_peap : Setting User-Name to ACME\philip
Sending tunneled request
EAP-Message = 0x0208004b1a020800463191e6b09be07b605fda54036913080947000000000000000092ef9f3797c75a4e63bf6778433b6dbf51c612d8ef5824c0005941414e41544543485c7068696c6970
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = 'ACME\\philip'
State = 0xf281125af2890830f60662494a0c8653
server inner-tunnel {
(7)  server inner-tunnel {
(7)    Request:
EAP-Message = 0x0208004b1a020800463191e6b09be07b605fda54036913080947000000000000000092ef9f3797c75a4e63bf6778433b6dbf51c612d8ef5824c0005941414e41544543485c7068696c6970
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = 'ACME\\philip'
State = 0xf281125af2890830f60662494a0c8653
(7)  # Executing section authorize from file
/etc/raddb/sites-enabled/inner-tunnel
(7)    authorize {
(7)   suffix : Checking for suffix after "@"
(7)   suffix : No '@' in User-Name = "ACME\philip", looking up realm NULL
(7)   suffix : No such realm "NULL"
(7)    [suffix] = noop
(7)    update control {
(7)   Proxy-To-Realm := 'LOCAL'
(7)    } # update control = noop
(7)   eap : Peer sent code Response (2) ID 8 length 75
(7)   eap : No EAP Start, assuming it's an on-going EAP conversation
(7)    [eap] = updated
(7)    [files] = noop
(7)    [expiration] = noop
(7)    [logintime] = noop
(7)   } #  authorize = updated
(7)  Found Auth-Type = EAP
(7)  # Executing group from file /etc/raddb/sites-enabled/inner-tunnel
(7)    authenticate {
(7)   eap : Expiring EAP session with state 0xf281125af2890830
(7)   eap : Finished EAP session with state 0xf281125af2890830
(7)   eap : Previous EAP request found for state 0xf281125af2890830,
released from the list
(7)   eap : Peer sent method MSCHAPv2 (26)
(7)   eap : EAP MSCHAPv2 (26)
(7)   eap : Calling eap_mschapv2 to process EAP data
(7)   eap_mschapv2 : # Executing group from file
/etc/raddb/sites-enabled/inner-tunnel
(7)   eap : Freeing handler
(7)    [eap] = reject
(7)   } #  authenticate = reject
(7)  Failed to authenticate the user
(7)  Using Post-Auth-Type Reject
(7)  # Executing group from file /etc/raddb/sites-enabled/inner-tunnel
(7)   Post-Auth-Type REJECT {
(7)   attr_filter.access_reject : EXPAND %{User-Name}
(7)   attr_filter.access_reject :    --> ACME\\philip
(7)   attr_filter.access_reject : Matched entry DEFAULT at line 11
(7)    [attr_filter.access_reject] = updated
(7)   } # Post-Auth-Type REJECT = updated
(7)    Reply:
EAP-Message = 0x04080004
Message-Authenticator = 0x00000000000000000000000000000000
(7)  } # server inner-tunnel
} # server inner-tunnel
(7)  eap_peap : Got tunneled reply code 3
EAP-Message = 0x04080004
Message-Authenticator = 0x00000000000000000000000000000000
(7)  eap_peap : Got tunneled reply RADIUS code 3
EAP-Message = 0x04080004
Message-Authenticator = 0x00000000000000000000000000000000
(7)  eap_peap : Tunneled authentication was rejected
(7)  eap_peap : FAILURE
(7)  eap : New EAP session, adding 'State' attribute to reply 0x2021716b272868d5
(7)   [eap] = handled
(7)  } #  authenticate = handled
(7) Sending Access-Challenge packet to host 10.xx.4.205 port 1645,
id=148, length=0
(7) EAP-Message =
0x0109002b19001703010020a23fbc7b14012abe52ab4685295adca8dc32be35b9ffc8351c010143b44f8e2f
(7) Message-Authenticator = 0x00000000000000000000000000000000
(7) State = 0x2021716b272868d531eefb122cb3a198
Sending Access-Challenge Id 148 from 10.xx.130.253:1812 to 10.xx.4.205:1645
EAP-Message = 0x0109002b19001703010020a23fbc7b14012abe52ab4685295adca8dc32be35b9ffc8351c010143b44f8e2f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x2021716b272868d531eefb122cb3a198
(7) Finished request

Thank you,

Matthew