TTLS + GTC Configuration -> No Error in log but cleint stuck on "connecting"

Mark mclarke4 at gmail.com
Thu Sep 14 11:32:05 CEST 2017


Hi all,

I have a openldap server with hashed password and am attempting to set up
WPA-Enterprise authentication. I have enabled the ldpap module and straight
authentication usng ldap and pap works. i.e the proxy server authenticates
without any problems.

I have the client configured to use ttls and gtc. I have done the same with
the eap configuration file. I don't get any error messages in the log file
when trying to connect. (I regengerated the ssl certs as hinted at by a
previous message but this took away the ssl cert warning but did not solve
the problem.)

Below is the debug log output. Trying to understand radius and the whole
EAP protocol requires a large amount of effort. I have already understood a
lot more than I did 3 days ago but am not at the end of my concpetual
models ability to trouble shoot this problem. I have tried setting the
Auth-Type: to LDAP in the gtc configuration in the eap conf file as well
but the results are the same.

Any help or hints appreciated. From the log file below it looks like the
client is not responding to the final Access-Challenge. The only other idea
I have is that the User-Password: field is not being passed to the eap
process? Not sure how to fix that or if it is the problem.

Thanks

Ready to process requests
(0) Received Access-Request Id 224 from 192.168.45.05:37339 to
192.168.45.74:1812 length 166
(0)   User-Name = "bob"
(0)   Called-Station-Id = "54-27-1E-4C-F9-E4:Jumping Bean"
(0)   NAS-Port-Type = Wireless-802.11
(0)   NAS-Port = 0
(0)   Calling-Station-Id = "60-FE-1E-A0-4F-C4"
(0)   Connect-Info = "CONNECT 0Mbps 802.11b"
(0)   Acct-Session-Id = "59B902E8-000000EA"
(0)   Framed-MTU = 1400
(0)   EAP-Message = 0x02270009016d61726b
(0)   Message-Authenticator = 0x4e878ddb529b319d77ea2abfb3131112
(0) # Executing section authorize from file
/etc/freeradius/3.0/sites-enabled/default
(0)   authorize {
(0)     policy filter_username {
(0)       if (&User-Name) {
(0)       if (&User-Name)  -> TRUE
(0)       if (&User-Name)  {
(0)         if (&User-Name =~ / /) {
(0)         if (&User-Name =~ / /)  -> FALSE
(0)         if (&User-Name =~ /@[^@]*@/ ) {
(0)         if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(0)         if (&User-Name =~ /\.\./ ) {
(0)         if (&User-Name =~ /\.\./ )  -> FALSE
(0)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(0)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   ->
FALSE
(0)         if (&User-Name =~ /\.$/)  {
(0)         if (&User-Name =~ /\.$/)   -> FALSE
(0)         if (&User-Name =~ /@\./)  {
(0)         if (&User-Name =~ /@\./)   -> FALSE
(0)       } # if (&User-Name)  = notfound
(0)     } # policy filter_username = notfound
(0)     [preprocess] = ok
(0) auth_log: EXPAND
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
(0) auth_log:    --> /var/log/freeradius/radacct/
192.168.45.05/auth-detail-20170914
(0) auth_log:
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/192.168.45.05/auth-detail-20170914
(0) auth_log: EXPAND %t
(0) auth_log:    --> Thu Sep 14 11:19:11 2017
(0)     [auth_log] = ok
(0)     [chap] = noop
(0)     [mschap] = noop
(0)     [digest] = noop
(0) suffix: Checking for suffix after "@"
(0) suffix: No '@' in User-Name = "bob", looking up realm NULL
(0) suffix: No such realm "NULL"
(0)     [suffix] = noop
(0) eap: Peer sent EAP Response (code 2) ID 39 length 9
(0) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the
rest of authorize
(0)     [eap] = ok
(0)   } # authorize = ok
(0) Found Auth-Type = eap
(0) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(0)   authenticate {
(0) eap: Peer sent packet with method EAP Identity (1)
(0) eap: Calling submodule eap_ttls to process data
(0) eap_ttls: Initiating new EAP-TLS session
(0) eap_ttls: [eaptls start] = request
(0) eap: Sending EAP Request (code 1) ID 40 length 6
(0) eap: EAP session adding &reply:State = 0xbdc37936bdeb6cdd
(0)     [eap] = handled
(0)   } # authenticate = handled
(0) Using Post-Auth-Type Challenge
(0) Post-Auth-Type sub-section not found.  Ignoring.
(0) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(0) Sent Access-Challenge Id 224 from 192.168.45.74:1812 to
192.168.45.05:37339 length 0
(0)   EAP-Message = 0x012800061520
(0)   Message-Authenticator = 0x00000000000000000000000000000000
(0)   State = 0xbdc37936bdeb6cdd84932144ea25780b
(0) Finished request
Waking up in 4.9 seconds.
(1) Received Access-Request Id 225 from 192.168.45.05:37339 to
192.168.45.74:1812 length 339
(1)   User-Name = "bob"
(1)   Called-Station-Id = "54-27-1E-4C-F9-E4:Jumping Bean"
(1)   NAS-Port-Type = Wireless-802.11
(1)   NAS-Port = 0
(1)   Calling-Station-Id = "60-FE-1E-A0-4F-C4"
(1)   Connect-Info = "CONNECT 0Mbps 802.11b"
(1)   Acct-Session-Id = "59B902E8-000000EA"
(1)   Framed-MTU = 1400
(1)   EAP-Message =
0x022800a4150016030100990100009503030a1c1c168f1fe7ca21b8e5ee873c19ba1e777641a3b13e1cca092bfa7fe66fc100003cc02cc030009fc02bc02f009ec00ac024c014c0280039006bc009c023c013c02700330067c007c011009d009c0035003d002f003c00050004000a00ff01000030001700
(1)   State = 0xbdc37936bdeb6cdd84932144ea25780b
(1)   Message-Authenticator = 0xc6c693312fb56f022f47198c94f4c3c7
(1) session-state: No cached attributes
(1) # Executing section authorize from file
/etc/freeradius/3.0/sites-enabled/default
(1)   authorize {
(1)     policy filter_username {
(1)       if (&User-Name) {
(1)       if (&User-Name)  -> TRUE
(1)       if (&User-Name)  {
(1)         if (&User-Name =~ / /) {
(1)         if (&User-Name =~ / /)  -> FALSE
(1)         if (&User-Name =~ /@[^@]*@/ ) {
(1)         if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(1)         if (&User-Name =~ /\.\./ ) {
(1)         if (&User-Name =~ /\.\./ )  -> FALSE
(1)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(1)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   ->
FALSE
(1)         if (&User-Name =~ /\.$/)  {
(1)         if (&User-Name =~ /\.$/)   -> FALSE
(1)         if (&User-Name =~ /@\./)  {
(1)         if (&User-Name =~ /@\./)   -> FALSE
(1)       } # if (&User-Name)  = notfound
(1)     } # policy filter_username = notfound
(1)     [preprocess] = ok
(1) auth_log: EXPAND
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
(1) auth_log:    --> /var/log/freeradius/radacct/
192.168.45.05/auth-detail-20170914
(1) auth_log:
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/192.168.45.05/auth-detail-20170914
(1) auth_log: EXPAND %t
(1) auth_log:    --> Thu Sep 14 11:19:11 2017
(1)     [auth_log] = ok
(1)     [chap] = noop
(1)     [mschap] = noop
(1)     [digest] = noop
(1) suffix: Checking for suffix after "@"
(1) suffix: No '@' in User-Name = "bob", looking up realm NULL
(1) suffix: No such realm "NULL"
(1)     [suffix] = noop
(1) eap: Peer sent EAP Response (code 2) ID 40 length 164
(1) eap: Continuing tunnel setup
(1)     [eap] = ok
(1)   } # authorize = ok
(1) Found Auth-Type = eap
(1) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(1)   authenticate {
(1) eap: Expiring EAP session with state 0xbdc37936bdeb6cdd
(1) eap: Finished EAP session with state 0xbdc37936bdeb6cdd
(1) eap: Previous EAP request found for state 0xbdc37936bdeb6cdd, released
from the list
(1) eap: Peer sent packet with method EAP TTLS (21)
(1) eap: Calling submodule eap_ttls to process data
(1) eap_ttls: Authenticate
(1) eap_ttls: Continuing EAP-TLS
(1) eap_ttls: Got final TLS record fragment (158 bytes)
(1) eap_ttls: WARNING: Total received TLS record fragments (158 bytes),
does not equal indicated TLS record length (0 bytes)
(1) eap_ttls: [eaptls verify] = ok
(1) eap_ttls: Done initial handshake
(1) eap_ttls: (other): before SSL initialization
(1) eap_ttls: TLS_accept: before SSL initialization
(1) eap_ttls: TLS_accept: before SSL initialization
(1) eap_ttls: <<< recv TLS 1.2  [length 0099]
(1) eap_ttls: TLS_accept: SSLv3/TLS read client hello
(1) eap_ttls: >>> send TLS 1.2  [length 003d]
(1) eap_ttls: TLS_accept: SSLv3/TLS write server hello
(1) eap_ttls: >>> send TLS 1.2  [length 08d3]
(1) eap_ttls: TLS_accept: SSLv3/TLS write certificate
(1) eap_ttls: >>> send TLS 1.2  [length 014d]
(1) eap_ttls: TLS_accept: SSLv3/TLS write key exchange
(1) eap_ttls: >>> send TLS 1.2  [length 0004]
(1) eap_ttls: TLS_accept: SSLv3/TLS write server done
(1) eap_ttls: TLS_accept: Need to read more data: SSLv3/TLS write server
done
(1) eap_ttls: In SSL Handshake Phase
(1) eap_ttls: In SSL Accept mode
(1) eap_ttls: [eaptls process] = handled
(1) eap: Sending EAP Request (code 1) ID 41 length 1004
(1) eap: EAP session adding &reply:State = 0xbdc37936bcea6cdd
(1)     [eap] = handled
(1)   } # authenticate = handled
(1) Using Post-Auth-Type Challenge
(1) Post-Auth-Type sub-section not found.  Ignoring.
(1) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(1) Sent Access-Challenge Id 225 from 192.168.45.74:1812 to
192.168.45.05:37339 length 0
(1)   EAP-Message =
0x012903ec15c000000a75160303003d020000390303bfef2af615bb30a1795e1502febfbbcfaf0829baff49038576161b0bbe9082d500c030000011ff01000100000b0004030001020017000016030308d30b0008cf0008cc0003de308203da308202c2a003020102020101300d06092a864886f70d0101
(1)   Message-Authenticator = 0x00000000000000000000000000000000
(1)   State = 0xbdc37936bcea6cdd84932144ea25780b
(1) Finished request
Waking up in 4.9 seconds.
(2) Received Access-Request Id 226 from 192.168.45.05:37339 to
192.168.45.74:1812 length 181
(2)   User-Name = "bob"
(2)   Called-Station-Id = "54-27-1E-4C-F9-E4:Jumping Bean"
(2)   NAS-Port-Type = Wireless-802.11
(2)   NAS-Port = 0
(2)   Calling-Station-Id = "60-FE-1E-A0-4F-C4"
(2)   Connect-Info = "CONNECT 0Mbps 802.11b"
(2)   Acct-Session-Id = "59B902E8-000000EA"
(2)   Framed-MTU = 1400
(2)   EAP-Message = 0x022900061500
(2)   State = 0xbdc37936bcea6cdd84932144ea25780b
(2)   Message-Authenticator = 0x5e81d512883c3437d5d7c4b1576509da
(2) session-state: No cached attributes
(2) # Executing section authorize from file
/etc/freeradius/3.0/sites-enabled/default
(2)   authorize {
(2)     policy filter_username {
(2)       if (&User-Name) {
(2)       if (&User-Name)  -> TRUE
(2)       if (&User-Name)  {
(2)         if (&User-Name =~ / /) {
(2)         if (&User-Name =~ / /)  -> FALSE
(2)         if (&User-Name =~ /@[^@]*@/ ) {
(2)         if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(2)         if (&User-Name =~ /\.\./ ) {
(2)         if (&User-Name =~ /\.\./ )  -> FALSE
(2)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(2)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   ->
FALSE
(2)         if (&User-Name =~ /\.$/)  {
(2)         if (&User-Name =~ /\.$/)   -> FALSE
(2)         if (&User-Name =~ /@\./)  {
(2)         if (&User-Name =~ /@\./)   -> FALSE
(2)       } # if (&User-Name)  = notfound
(2)     } # policy filter_username = notfound
(2)     [preprocess] = ok
(2) auth_log: EXPAND
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
(2) auth_log:    --> /var/log/freeradius/radacct/
192.168.45.05/auth-detail-20170914
(2) auth_log:
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/192.168.45.05/auth-detail-20170914
(2) auth_log: EXPAND %t
(2) auth_log:    --> Thu Sep 14 11:19:11 2017
(2)     [auth_log] = ok
(2)     [chap] = noop
(2)     [mschap] = noop
(2)     [digest] = noop
(2) suffix: Checking for suffix after "@"
(2) suffix: No '@' in User-Name = "bob", looking up realm NULL
(2) suffix: No such realm "NULL"
(2)     [suffix] = noop
(2) eap: Peer sent EAP Response (code 2) ID 41 length 6
(2) eap: Continuing tunnel setup
(2)     [eap] = ok
(2)   } # authorize = ok
(2) Found Auth-Type = eap
(2) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(2)   authenticate {
(2) eap: Expiring EAP session with state 0xbdc37936bcea6cdd
(2) eap: Finished EAP session with state 0xbdc37936bcea6cdd
(2) eap: Previous EAP request found for state 0xbdc37936bcea6cdd, released
from the list
(2) eap: Peer sent packet with method EAP TTLS (21)
(2) eap: Calling submodule eap_ttls to process data
(2) eap_ttls: Authenticate
(2) eap_ttls: Continuing EAP-TLS
(2) eap_ttls: Peer ACKed our handshake fragment
(2) eap_ttls: [eaptls verify] = request
(2) eap_ttls: [eaptls process] = handled
(2) eap: Sending EAP Request (code 1) ID 42 length 1004
(2) eap: EAP session adding &reply:State = 0xbdc37936bfe96cdd
(2)     [eap] = handled
(2)   } # authenticate = handled
(2) Using Post-Auth-Type Challenge
(2) Post-Auth-Type sub-section not found.  Ignoring.
(2) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(2) Sent Access-Challenge Id 226 from 192.168.45.74:1812 to
192.168.45.05:37339 length 0
(2)   EAP-Message =
0x012a03ec15c000000a75318c53693caf5cec07a26c179201b35044f8b0a36585e88ac8887724d038dace205f76b50f376be76dd9ebe975518e8d82a931d370995cd79469cd39278883b89faf674e3bc275747a253d0cab0004e8308204e4308203cca003020102020900acfa1c7c27c4f226300d06092a
(2)   Message-Authenticator = 0x00000000000000000000000000000000
(2)   State = 0xbdc37936bfe96cdd84932144ea25780b
(2) Finished request
Waking up in 4.9 seconds.
(3) Received Access-Request Id 227 from 192.168.45.05:37339 to
192.168.45.74:1812 length 181
(3)   User-Name = "bob"
(3)   Called-Station-Id = "54-27-1E-4C-F9-E4:Jumping Bean"
(3)   NAS-Port-Type = Wireless-802.11
(3)   NAS-Port = 0
(3)   Calling-Station-Id = "60-FE-1E-A0-4F-C4"
(3)   Connect-Info = "CONNECT 0Mbps 802.11b"
(3)   Acct-Session-Id = "59B902E8-000000EA"
(3)   Framed-MTU = 1400
(3)   EAP-Message = 0x022a00061500
(3)   State = 0xbdc37936bfe96cdd84932144ea25780b
(3)   Message-Authenticator = 0x9fd121549085c6c53071b12b8b96285a
(3) session-state: No cached attributes
(3) # Executing section authorize from file
/etc/freeradius/3.0/sites-enabled/default
(3)   authorize {
(3)     policy filter_username {
(3)       if (&User-Name) {
(3)       if (&User-Name)  -> TRUE
(3)       if (&User-Name)  {
(3)         if (&User-Name =~ / /) {
(3)         if (&User-Name =~ / /)  -> FALSE
(3)         if (&User-Name =~ /@[^@]*@/ ) {
(3)         if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(3)         if (&User-Name =~ /\.\./ ) {
(3)         if (&User-Name =~ /\.\./ )  -> FALSE
(3)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(3)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   ->
FALSE
(3)         if (&User-Name =~ /\.$/)  {
(3)         if (&User-Name =~ /\.$/)   -> FALSE
(3)         if (&User-Name =~ /@\./)  {
(3)         if (&User-Name =~ /@\./)   -> FALSE
(3)       } # if (&User-Name)  = notfound
(3)     } # policy filter_username = notfound
(3)     [preprocess] = ok
(3) auth_log: EXPAND
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
(3) auth_log:    --> /var/log/freeradius/radacct/
192.168.45.05/auth-detail-20170914
(3) auth_log:
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/192.168.45.05/auth-detail-20170914
(3) auth_log: EXPAND %t
(3) auth_log:    --> Thu Sep 14 11:19:11 2017
(3)     [auth_log] = ok
(3)     [chap] = noop
(3)     [mschap] = noop
(3)     [digest] = noop
(3) suffix: Checking for suffix after "@"
(3) suffix: No '@' in User-Name = "bob", looking up realm NULL
(3) suffix: No such realm "NULL"
(3)     [suffix] = noop
(3) eap: Peer sent EAP Response (code 2) ID 42 length 6
(3) eap: Continuing tunnel setup
(3)     [eap] = ok
(3)   } # authorize = ok
(3) Found Auth-Type = eap
(3) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(3)   authenticate {
(3) eap: Expiring EAP session with state 0xbdc37936bfe96cdd
(3) eap: Finished EAP session with state 0xbdc37936bfe96cdd
(3) eap: Previous EAP request found for state 0xbdc37936bfe96cdd, released
from the list
(3) eap: Peer sent packet with method EAP TTLS (21)
(3) eap: Calling submodule eap_ttls to process data
(3) eap_ttls: Authenticate
(3) eap_ttls: Continuing EAP-TLS
(3) eap_ttls: Peer ACKed our handshake fragment
(3) eap_ttls: [eaptls verify] = request
(3) eap_ttls: [eaptls process] = handled
(3) eap: Sending EAP Request (code 1) ID 43 length 699
(3) eap: EAP session adding &reply:State = 0xbdc37936bee86cdd
(3)     [eap] = handled
(3)   } # authenticate = handled
(3) Using Post-Auth-Type Challenge
(3) Post-Auth-Type sub-section not found.  Ignoring.
(3) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(3) Sent Access-Challenge Id 227 from 192.168.45.74:1812 to
192.168.45.05:37339 length 0
(3)   EAP-Message =
0x012b02bb158000000a750101ff040530030101ff30360603551d1f042f302d302ba029a0278625687474703a2f2f7777772e6578616d706c652e6f72672f6578616d706c655f63612e63726c300d06092a864886f70d01010b05000382010100e3995c54d00cee2fbbc14478b89b75b38a11643e5c1a51
(3)   Message-Authenticator = 0x00000000000000000000000000000000
(3)   State = 0xbdc37936bee86cdd84932144ea25780b
(3) Finished request
Waking up in 4.9 seconds.
(4) Received Access-Request Id 228 from 192.168.45.05:37339 to
192.168.45.74:1812 length 307
(4)   User-Name = "bob"
(4)   Called-Station-Id = "54-27-1E-4C-F9-E4:Jumping Bean"
(4)   NAS-Port-Type = Wireless-802.11
(4)   NAS-Port = 0
(4)   Calling-Station-Id = "60-FE-1E-A0-4F-C4"
(4)   Connect-Info = "CONNECT 0Mbps 802.11b"
(4)   Acct-Session-Id = "59B902E8-000000EA"
(4)   Framed-MTU = 1400
(4)   EAP-Message =
0x022b0084150016030300461000004241047d7abad05d5661d82c204f0d953f0ce6f5b508de608abf44b528fc3897c2f548baacdb60f5cd867ea90d976f1ad767249c4fc28ba8a810d62bb1102d57fd00e514030300010116030300280000000000000000c227b6f946893e02d0eac613069cdc09d93578
(4)   State = 0xbdc37936bee86cdd84932144ea25780b
(4)   Message-Authenticator = 0xb50eb2de770b6149c3752e62afebe833
(4) session-state: No cached attributes
(4) # Executing section authorize from file
/etc/freeradius/3.0/sites-enabled/default
(4)   authorize {
(4)     policy filter_username {
(4)       if (&User-Name) {
(4)       if (&User-Name)  -> TRUE
(4)       if (&User-Name)  {
(4)         if (&User-Name =~ / /) {
(4)         if (&User-Name =~ / /)  -> FALSE
(4)         if (&User-Name =~ /@[^@]*@/ ) {
(4)         if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(4)         if (&User-Name =~ /\.\./ ) {
(4)         if (&User-Name =~ /\.\./ )  -> FALSE
(4)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(4)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   ->
FALSE
(4)         if (&User-Name =~ /\.$/)  {
(4)         if (&User-Name =~ /\.$/)   -> FALSE
(4)         if (&User-Name =~ /@\./)  {
(4)         if (&User-Name =~ /@\./)   -> FALSE
(4)       } # if (&User-Name)  = notfound
(4)     } # policy filter_username = notfound
(4)     [preprocess] = ok
(4) auth_log: EXPAND
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
(4) auth_log:    --> /var/log/freeradius/radacct/
192.168.45.05/auth-detail-20170914
(4) auth_log:
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/192.168.45.05/auth-detail-20170914
(4) auth_log: EXPAND %t
(4) auth_log:    --> Thu Sep 14 11:19:11 2017
(4)     [auth_log] = ok
(4)     [chap] = noop
(4)     [mschap] = noop
(4)     [digest] = noop
(4) suffix: Checking for suffix after "@"
(4) suffix: No '@' in User-Name = "bob", looking up realm NULL
(4) suffix: No such realm "NULL"
(4)     [suffix] = noop
(4) eap: Peer sent EAP Response (code 2) ID 43 length 132
(4) eap: Continuing tunnel setup
(4)     [eap] = ok
(4)   } # authorize = ok
(4) Found Auth-Type = eap
(4) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(4)   authenticate {
(4) eap: Expiring EAP session with state 0xbdc37936bee86cdd
(4) eap: Finished EAP session with state 0xbdc37936bee86cdd
(4) eap: Previous EAP request found for state 0xbdc37936bee86cdd, released
from the list
(4) eap: Peer sent packet with method EAP TTLS (21)
(4) eap: Calling submodule eap_ttls to process data
(4) eap_ttls: Authenticate
(4) eap_ttls: Continuing EAP-TLS
(4) eap_ttls: [eaptls verify] = ok
(4) eap_ttls: Done initial handshake
(4) eap_ttls: TLS_accept: SSLv3/TLS write server done
(4) eap_ttls: <<< recv TLS 1.2  [length 0046]
(4) eap_ttls: TLS_accept: SSLv3/TLS read client key exchange
(4) eap_ttls: TLS_accept: SSLv3/TLS read change cipher spec
(4) eap_ttls: <<< recv TLS 1.2  [length 0010]
(4) eap_ttls: TLS_accept: SSLv3/TLS read finished
(4) eap_ttls: >>> send TLS 1.2  [length 0001]
(4) eap_ttls: TLS_accept: SSLv3/TLS write change cipher spec
(4) eap_ttls: >>> send TLS 1.2  [length 0010]
(4) eap_ttls: TLS_accept: SSLv3/TLS write finished
(4) eap_ttls: (other): SSL negotiation finished successfully
(4) eap_ttls: SSL Connection Established
(4) eap_ttls: [eaptls process] = handled
(4) eap: Sending EAP Request (code 1) ID 44 length 61
(4) eap: EAP session adding &reply:State = 0xbdc37936b9ef6cdd
(4)     [eap] = handled
(4)   } # authenticate = handled
(4) Using Post-Auth-Type Challenge
(4) Post-Auth-Type sub-section not found.  Ignoring.
(4) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(4) Sent Access-Challenge Id 228 from 192.168.45.74:1812 to
192.168.45.05:37339 length 0
(4)   EAP-Message =
0x012c003d1580000000331403030001011603030028471e30dc08a6d794f227f69ef0ae81d75a7082e5643ef6c65d9ee2604fcd4f7c55114fc65525a838
(4)   Message-Authenticator = 0x00000000000000000000000000000000
(4)   State = 0xbdc37936b9ef6cdd84932144ea25780b
(4) Finished request
Waking up in 4.8 seconds.
(5) Received Access-Request Id 229 from 192.168.45.05:37339 to
192.168.45.74:1812 length 230
(5)   User-Name = "bob"
(5)   Called-Station-Id = "54-27-1E-4C-F9-E4:Jumping Bean"
(5)   NAS-Port-Type = Wireless-802.11
(5)   NAS-Port = 0
(5)   Calling-Station-Id = "60-FE-1E-A0-4F-C4"
(5)   Connect-Info = "CONNECT 0Mbps 802.11b"
(5)   Acct-Session-Id = "59B902E8-000000EA"
(5)   Framed-MTU = 1400
(5)   EAP-Message =
0x022c00371500170303002c0000000000000001595cecb3de730e899e84a9f3e32a5b344f7831ba3a3b08486ae4ed71c158e57359dded07
(5)   State = 0xbdc37936b9ef6cdd84932144ea25780b
(5)   Message-Authenticator = 0x04079a652bd0207cdffa3715b865b41a
(5) session-state: No cached attributes
(5) # Executing section authorize from file
/etc/freeradius/3.0/sites-enabled/default
(5)   authorize {
(5)     policy filter_username {
(5)       if (&User-Name) {
(5)       if (&User-Name)  -> TRUE
(5)       if (&User-Name)  {
(5)         if (&User-Name =~ / /) {
(5)         if (&User-Name =~ / /)  -> FALSE
(5)         if (&User-Name =~ /@[^@]*@/ ) {
(5)         if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(5)         if (&User-Name =~ /\.\./ ) {
(5)         if (&User-Name =~ /\.\./ )  -> FALSE
(5)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(5)         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   ->
FALSE
(5)         if (&User-Name =~ /\.$/)  {
(5)         if (&User-Name =~ /\.$/)   -> FALSE
(5)         if (&User-Name =~ /@\./)  {
(5)         if (&User-Name =~ /@\./)   -> FALSE
(5)       } # if (&User-Name)  = notfound
(5)     } # policy filter_username = notfound
(5)     [preprocess] = ok
(5) auth_log: EXPAND
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
(5) auth_log:    --> /var/log/freeradius/radacct/
192.168.45.05/auth-detail-20170914
(5) auth_log:
/var/log/freeradius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/192.168.45.05/auth-detail-20170914
(5) auth_log: EXPAND %t
(5) auth_log:    --> Thu Sep 14 11:19:11 2017
(5)     [auth_log] = ok
(5)     [chap] = noop
(5)     [mschap] = noop
(5)     [digest] = noop
(5) suffix: Checking for suffix after "@"
(5) suffix: No '@' in User-Name = "bob", looking up realm NULL
(5) suffix: No such realm "NULL"
(5)     [suffix] = noop
(5) eap: Peer sent EAP Response (code 2) ID 44 length 55
(5) eap: Continuing tunnel setup
(5)     [eap] = ok
(5)   } # authorize = ok
(5) Found Auth-Type = eap
(5) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(5)   authenticate {
(5) eap: Expiring EAP session with state 0xbdc37936b9ef6cdd
(5) eap: Finished EAP session with state 0xbdc37936b9ef6cdd
(5) eap: Previous EAP request found for state 0xbdc37936b9ef6cdd, released
from the list
(5) eap: Peer sent packet with method EAP TTLS (21)
(5) eap: Calling submodule eap_ttls to process data
(5) eap_ttls: Authenticate
(5) eap_ttls: Continuing EAP-TLS
(5) eap_ttls: [eaptls verify] = ok
(5) eap_ttls: Done initial handshake
(5) eap_ttls: [eaptls process] = ok
(5) eap_ttls: Session established.  Proceeding to decode tunneled attributes
(5) eap_ttls: Got tunneled request
(5) eap_ttls:   EAP-Message = 0x02000009016d61726b
(5) eap_ttls:   FreeRADIUS-Proxied-To = 127.0.0.1
(5) eap_ttls: Got tunneled identity of bob
(5) eap_ttls: Setting default EAP type for tunneled EAP session
(5) eap_ttls: Sending tunneled request
(5) Virtual server inner-tunnel received request
(5)   EAP-Message = 0x02000009016d61726b
(5)   FreeRADIUS-Proxied-To = 127.0.0.1
(5)   User-Name = "bob"
(5)   Called-Station-Id = "54-27-1E-4C-F9-E4:Jumping Bean"
(5)   NAS-Port-Type = Wireless-802.11
(5)   NAS-Port = 0
(5)   Calling-Station-Id = "60-FE-1E-A0-4F-C4"
(5)   Connect-Info = "CONNECT 0Mbps 802.11b"
(5)   Acct-Session-Id = "59B902E8-000000EA"
(5)   Framed-MTU = 1400
(5)   Event-Timestamp = "Sep 14 2017 11:19:11 SAST"
(5)   NAS-IP-Address = 192.168.45.05
(5) WARNING: Outer and inner identities are the same.  User privacy is
compromised.
(5) server inner-tunnel {
(5)   # Executing section authorize from file
/etc/freeradius/3.0/sites-enabled/inner-tunnel
(5)     authorize {
(5)       policy filter_username {
(5)         if (&User-Name) {
(5)         if (&User-Name)  -> TRUE
(5)         if (&User-Name)  {
(5)           if (&User-Name =~ / /) {
(5)           if (&User-Name =~ / /)  -> FALSE
(5)           if (&User-Name =~ /@[^@]*@/ ) {
(5)           if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(5)           if (&User-Name =~ /\.\./ ) {
(5)           if (&User-Name =~ /\.\./ )  -> FALSE
(5)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(5)           if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))
-> FALSE
(5)           if (&User-Name =~ /\.$/)  {
(5)           if (&User-Name =~ /\.$/)   -> FALSE
(5)           if (&User-Name =~ /@\./)  {
(5)           if (&User-Name =~ /@\./)   -> FALSE
(5)         } # if (&User-Name)  = notfound
(5)       } # policy filter_username = notfound
(5)       [chap] = noop
(5)       [mschap] = noop
(5) suffix: Checking for suffix after "@"
(5) suffix: No '@' in User-Name = "bob", looking up realm NULL
(5) suffix: No such realm "NULL"
(5)       [suffix] = noop
(5)       update control {
(5)         &Proxy-To-Realm := LOCAL
(5)       } # update control = noop
(5) eap: Peer sent EAP Response (code 2) ID 0 length 9
(5) eap: EAP-Identity reply, returning 'ok' so we can short-circuit the
rest of authorize
(5)       [eap] = ok
(5)     } # authorize = ok
(5)   Found Auth-Type = eap
(5)   # Executing group from file
/etc/freeradius/3.0/sites-enabled/inner-tunnel
(5)     authenticate {
(5) eap: Peer sent packet with method EAP Identity (1)
(5) eap: Calling submodule eap_gtc to process data
(5) eap_gtc: EXPAND Password:
(5) eap_gtc:    --> Password:
(5) eap: Sending EAP Request (code 1) ID 1 length 15
(5) eap: EAP session adding &reply:State = 0x939300d7939206e6
(5)       [eap] = handled
(5)     } # authenticate = handled
(5) } # server inner-tunnel
(5) Virtual server sending reply
(5)   EAP-Message = 0x0101000f0650617373776f72643a20
(5)   Message-Authenticator = 0x00000000000000000000000000000000
(5)   State = 0x939300d7939206e632565a4a2d1be287
(5) eap_ttls: Got tunneled Access-Challenge
(5) eap: Sending EAP Request (code 1) ID 45 length 63
(5) eap: EAP session adding &reply:State = 0xbdc37936b8ee6cdd
(5)     [eap] = handled
(5)   } # authenticate = handled
(5) Using Post-Auth-Type Challenge
(5) Post-Auth-Type sub-section not found.  Ignoring.
(5) # Executing group from file /etc/freeradius/3.0/sites-enabled/default
(5) Sent Access-Challenge Id 229 from 192.168.45.74:1812 to
192.168.45.05:37339 length 0
(5)   EAP-Message =
0x012d003f1580000000351703030030471e30dc08a6d79553ed6a4977806816b7ccd9f91d3c7e620176ceb206f3a0d52f0918d696626cf670769ccb64d27449
(5)   Message-Authenticator = 0x00000000000000000000000000000000
(5)   State = 0xbdc37936b8ee6cdd84932144ea25780b
(5) Finished request
Waking up in 4.8 seconds.
(0) Cleaning up request packet ID 224 with timestamp +10
(1) Cleaning up request packet ID 225 with timestamp +10
(2) Cleaning up request packet ID 226 with timestamp +10
(3) Cleaning up request packet ID 227 with timestamp +10
(4) Cleaning up request packet ID 228 with timestamp +10
(5) Cleaning up request packet ID 229 with timestamp +10


More information about the Freeradius-Users mailing list