curious network problem

Antony King antony.king at solutiontrax.com
Tue Aug 10 18:33:00 CEST 2010


Hi all,

I'm a bit of a radius noob, so if what I'm trying to do is daft for whatever 
reason, please be gentle!!

I'm trying to set up a radius server as part of a WPA2 enterprise project. It 
is using EAP/TTLS/MSCHAPv2 to authenticate.

On my test system ('goodserver'), an Ubuntu box, with freeradius 2.1.7 
compiled from source as per the advice here : 
http://www.linuxinsight.com/building-debian-freeradius-package-with-eap-tls-
ttls-peap-support.html, it all works fine, with local and remote clients. I've 
tested this using eapol_test, using a command line like this:

goodserver# eapol_test -c e2.conf  -alocalhost -p1812 -s testing123 -r0
and:
remoteserver# eapol_test -c e2.conf  -agoodserver -p1812 -s radiustest -r0

e2.conf contains this:

network={
        ssid="radius"
        key_mgmt=WPA-EAP
        eap=TTLS
        identity="john"
        anonymous_identity="anonymous"
        password="password1"
        phase2="autheap=MSCHAPv2"
}

It also works fine from several wrt54GL boxes running Tomato.

The 'live' server is a centos5.5 box. I've tried with the standard freeradius2 
package (version 2.1.7) and a version compiled from SRPMS in case there was a 
problem with ttls in that version. The configuration was copied over from the 
test server, with new keys generated but otherwise unchanged.

Locally, it authenticates correctly, using the first of the two commands 
above. If I try and authenticate from a remote system (eg, a NAS or my test 
server), it refuses to do the ttls negotiation. Here's a snippet from radiusd 
-X the live server for a request from localhost that worked:

[eap] EAP packet type response id 1 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
++[files] returns noop
rlm_checkval: Item Name: Calling-Station-Id, Value: 02-00-00-00-00-01
rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
++[checkval] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication 
may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] EAP-NAK asked for EAP-Type/ttls
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1



and here's the equivalent bit when a remote system tries to authenticate:

[eap] EAP packet type response id 0 length 14
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
++[files] returns noop
rlm_checkval: Item Name: Calling-Station-Id, Value: 02-00-00-00-00-01
rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
++[checkval] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication 
may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
Sending Access-Challenge of id 0 to 192.168.21.126 port 50659
        EAP-Message = 0x010100160410e0e066ae00aed2f10a808e81c37dd0c7
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x919a3359919b374cb07bfc1d3989d37e
Finished request 25


The rest of the conversation up to that point is broadly the same; I've 
attached the failing log below, followed by a working log.

Any suggestions would be greatly appreciated.

Thanks,

Antony.

-----------------------------------------------------------------------------------------------
Complete failing radiusd -X log in response to a remote system attempting 
authentication:

rad_recv: Access-Request packet from host 192.168.21.126 port 50659, id=0, 
length=126
        User-Name = "anonymous"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
        EAP-Message = 0x0200000e01616e6f6e796d6f7573
        Message-Authenticator = 0x6182aca4f8b2133d63750c2c5b131ada
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 0 length 14
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
++[files] returns noop
rlm_checkval: Item Name: Calling-Station-Id, Value: 02-00-00-00-00-01
rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
++[checkval] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication 
may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
Sending Access-Challenge of id 0 to 192.168.21.126 port 50659
        EAP-Message = 0x010100160410e0e066ae00aed2f10a808e81c37dd0c7
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x919a3359919b374cb07bfc1d3989d37e
Finished request 25.
Going to the next request
Waking up in 4.10 seconds.
rad_recv: Access-Request packet from host 192.168.21.126 port 50659, id=0, 
length=126
Sending duplicate reply to client DLCorpWifi port 50659 - ID: 0
Sending Access-Challenge of id 0 to 192.168.21.126 port 50659
Waking up in 1.9 seconds.
Cleaning up request 25 ID 0 with timestamp +4166
Ready to process requests.
rad_recv: Access-Request packet from host 192.168.21.126 port 50659, id=0, 
length=126
        User-Name = "anonymous"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
        EAP-Message = 0x0200000e01616e6f6e796d6f7573
        Message-Authenticator = 0x6182aca4f8b2133d63750c2c5b131ada
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 0 length 14
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
++[files] returns noop
rlm_checkval: Item Name: Calling-Station-Id, Value: 02-00-00-00-00-01
rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
++[checkval] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication 
may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
Sending Access-Challenge of id 0 to 192.168.21.126 port 50659
        EAP-Message = 0x010100160410d17a481031648eca7f569291c54870de
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x071c3844071d3c871a2285f50d0acb26
Finished request 26.
Going to the next request
Waking up in 4.10 seconds.
Cleaning up request 26 ID 0 with timestamp +4175
Ready to process requests.
rad_recv: Access-Request packet from host 192.168.21.126 port 50659, id=0, 
length=126
        User-Name = "anonymous"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
        EAP-Message = 0x0200000e01616e6f6e796d6f7573
        Message-Authenticator = 0x6182aca4f8b2133d63750c2c5b131ada
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 0 length 14
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
++[files] returns noop
rlm_checkval: Item Name: Calling-Station-Id, Value: 02-00-00-00-00-01
rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
++[checkval] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication 
may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
Sending Access-Challenge of id 0 to 192.168.21.126 port 50659
        EAP-Message = 0x010100160410aa54044e0e0cb1cd7777116d6144c4ee
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x2ca616d12ca7120eb7710be2baae4a1b
Finished request 27.
Going to the next request
Waking up in 4.10 seconds.
Cleaning up request 27 ID 0 with timestamp +4187
Ready to process requests.

-------------------------------------------------------------------------------------------------------

Working, in response to local host connecting (v. long; nothing else follows 
this log):

rad_recv: Access-Request packet from host 127.0.0.1 port 40609, id=0, 
length=126
        User-Name = "anonymous"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
        EAP-Message = 0x0200000e01616e6f6e796d6f7573
        Message-Authenticator = 0x04b6832eda3285bbbb19315b80ef55fe
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 0 length 14
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
++[files] returns noop
rlm_checkval: Item Name: Calling-Station-Id, Value: 02-00-00-00-00-01
rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
++[checkval] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication 
may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
Sending Access-Challenge of id 0 to 127.0.0.1 port 40609
        EAP-Message = 0x0101001604104719a5bc40cadd5a795acdb21621fbd4
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x477b7bc0477a7f2c045f14d9c1a56447
Finished request 28.
Going to the next request
Waking up in 4.10 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 40609, id=1, 
length=136
        User-Name = "anonymous"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
        EAP-Message = 0x020100060315
        State = 0x477b7bc0477a7f2c045f14d9c1a56447
        Message-Authenticator = 0xf671acc6defc96d16952a12c015f3a22
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 1 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
++[files] returns noop
rlm_checkval: Item Name: Calling-Station-Id, Value: 02-00-00-00-00-01
rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
++[checkval] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.  Authentication 
may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP NAK
[eap] EAP-NAK asked for EAP-Type/ttls
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 1 to 127.0.0.1 port 40609
        EAP-Message = 0x010200061520
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x477b7bc046796e2c045f14d9c1a56447
Finished request 29.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 40609, id=2, 
length=233
        User-Name = "anonymous"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
        EAP-Message = 
0x020200671500160301005c0100005803014c617c16799c78a7843fb1ab5ef8f34074de17caa903f6bcd27cc3a3811b6d5400003000390038003500160013000a00330032002f006600050004006300620015001200090065006400140011000800060003020100
        State = 0x477b7bc046796e2c045f14d9c1a56447
        Message-Authenticator = 0x87c543835903394ea8132d7e486c9e2f
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 2 length 103
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7 
[ttls] Done initial handshake
[ttls]     (other): before/accept initialization 
[ttls]     TLS_accept: before/accept initialization 
[ttls] <<< TLS 1.0 Handshake [length 005c], ClientHello  
[ttls]     TLS_accept: SSLv3 read client hello A 
[ttls] >>> TLS 1.0 Handshake [length 002a], ServerHello  
[ttls]     TLS_accept: SSLv3 write server hello A 
[ttls] >>> TLS 1.0 Handshake [length 08a7], Certificate  
[ttls]     TLS_accept: SSLv3 write certificate A 
[ttls] >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange  
[ttls]     TLS_accept: SSLv3 write key exchange A 
[ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone  
[ttls]     TLS_accept: SSLv3 write server done A 
[ttls]     TLS_accept: SSLv3 flush data 
[ttls]     TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase 
In SSL Accept mode  
[ttls] eaptls_process returned 13 
++[eap] returns handled
Sending Access-Challenge of id 2 to 127.0.0.1 port 40609
        EAP-Message = 
0x0103040015c000000af6160301002a0200002603014c617c1627ac6923c328501dd4adc933dbd1dd2b3a9546732b1d7f2267da002f0000390116030108a70b0008a30008a00003cc308203c8308202b0a003020102020101300d06092a864886f70d010104050030819e310b3009060355040613024742310e300c060355040813054275636b73311630140603550407130d4d696c746f6e204b65796e6573311b3019060355040a13124469636b4c6f76657474204c696d697465643130302e06092a864886f70d0109011621637573746f6d65722e737570706f727440736f6c7574696f6e747261782e636f6d311830160603550403130f444c2043
        EAP-Message = 
0x6f72702057696669204341301e170d3130303830393135313132385a170d3131303830393135313132385a308196310b3009060355040613024742310e300c060355040813054275636b73311b3019060355040a13124469636b4c6f76657474204c696d69746564312830260603550403131f444c20436f72702057696669205365727665722043657274696669636174653130302e06092a864886f70d0109011621637573746f6d65722e737570706f727440736f6c7574696f6e747261782e636f6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100bedf6054159aea65a8a695396bacdc1d974e65733dcfd796
        EAP-Message = 
0x0248a9e9546f56b97dc4f07432ae8d266b92448955c265dd9412540e2dc3ee2b52a10afefe5ca57caf95a4b8b345014e55c160bb6acc2fa0cec266481136bad3c9129e305e4c18288ee2c1d53adeee44eaf5ccd2c6e2f9ba564924abb0221f092584649eef3fbdae99acc85dbfb92671eea4a75b77165d839839ce5273d848447bd3ce8d4754ac120ec21ae52684d6c99e00ff32fba95de651bf9ac3322295991a4efc34837c9c4b84c7276cabc5208242bac363c14190abaefea25dc21c6b6b245e142db83fc2fe0731e07908131d9eea8974fd80468182696bae8dc17b3f53f6273caf03b2c39f0203010001a317301530130603551d25040c300a06
        EAP-Message = 
0x082b06010505070301300d06092a864886f70d010104050003820101008037667a1c225b5a66f520ded7c0aad48dfa2a7909acc0fe7596c2bbc76980b303439a63c6f6d440bb0dba639fd6bad64cf44c95ec275b325fa94782dada64863829ce8e69558c7fdad914eb7ffcb01f673138264cb8b97765e4c72a42b63008c1dc5c3af27f6852d1cc79d48aa6570381a29251b7e3004b40f0c2adad46b49c49e2761ff779045a4fc09cd0ef62f752d7b79dd89d4391b73002ed23d48ad2626e7d9b2519627b651214d3beeb386a013afbcc80db1a4d556f90b0a3d878a0a131a71ba0749dd1ab33eb4a7dff4608ed76bea3f2470075f0c54bb24384c281c1
        EAP-Message = 0xe58944ac63d2975e3b97e153
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x477b7bc045786e2c045f14d9c1a56447
Finished request 30.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 40609, id=3, 
length=136
        User-Name = "anonymous"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
        EAP-Message = 0x020300061500
        State = 0x477b7bc045786e2c045f14d9c1a56447
        Message-Authenticator = 0x8a5a3ea0028bf651f2df7463b91662c6
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 3 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake fragment handler
[ttls] eaptls_verify returned 1 
[ttls] eaptls_process returned 13 
++[eap] returns handled
Sending Access-Challenge of id 3 to 127.0.0.1 port 40609
        EAP-Message = 
0x0104040015c000000af61c8f7f592f7ab2ccae17af97fbc0802e3ed139b50004ce308204ca308203b2a003020102020900c216fdd8064c8f67300d06092a864886f70d010105050030819e310b3009060355040613024742310e300c060355040813054275636b73311630140603550407130d4d696c746f6e204b65796e6573311b3019060355040a13124469636b4c6f76657474204c696d697465643130302e06092a864886f70d0109011621637573746f6d65722e737570706f727440736f6c7574696f6e747261782e636f6d311830160603550403130f444c20436f72702057696669204341301e170d3130303830393135313132385a170d31
        EAP-Message = 
0x31303830393135313132385a30819e310b3009060355040613024742310e300c060355040813054275636b73311630140603550407130d4d696c746f6e204b65796e6573311b3019060355040a13124469636b4c6f76657474204c696d697465643130302e06092a864886f70d0109011621637573746f6d65722e737570706f727440736f6c7574696f6e747261782e636f6d311830160603550403130f444c20436f7270205769666920434130820122300d06092a864886f70d01010105000382010f003082010a0282010100c9a7d7b0c22afe853ddde7d62c7e7d62e8e6fb58ca3f42bc9a172d092c31db0a81637df6df1b182e510a727de8dede
        EAP-Message = 
0x63d4f3b1fb031e74a5d3ca54804daaad8ec8a6e8b61a7f26d60837728585e1b81267856ead58a99383b29cac7cd0ed2dcd80fcdefc632a22fd23624911d61b1d4860d944c45b0d656780ac6738fec67393dad97c752f24a41cb07871ebe4871412efb5d772b60ad78abda5a86974105a85afc07fd0b07fac3ad25a0fd5c996829c92d04510704e5499220c6c0cffd16534a0a8a7dd16a26d610752f9a7b3c19371f7b516b3709d6ef5c9a2bf3ed266ad39363e8fa1bec9696731c5819ecb24be71c3c0e33afa44e0bb02b4682233a5efd10203010001a382010730820103301d0603551d0e041604141779973a1c8275d38bf2ae85104840cc4c66a5db
        EAP-Message = 
0x3081d30603551d230481cb3081c880141779973a1c8275d38bf2ae85104840cc4c66a5dba181a4a481a130819e310b3009060355040613024742310e300c060355040813054275636b73311630140603550407130d4d696c746f6e204b65796e6573311b3019060355040a13124469636b4c6f76657474204c696d697465643130302e06092a864886f70d0109011621637573746f6d65722e737570706f727440736f6c7574696f6e747261782e636f6d311830160603550403130f444c20436f72702057696669204341820900c216fdd8064c8f67300c0603551d13040530030101ff300d06092a864886f70d0101050500038201010098a389b111
        EAP-Message = 0x267f86354017bdf0d1364e56
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x477b7bc0447f6e2c045f14d9c1a56447
Finished request 31.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 40609, id=4, 
length=136
        User-Name = "anonymous"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
        EAP-Message = 0x020400061500
        State = 0x477b7bc0447f6e2c045f14d9c1a56447
        Message-Authenticator = 0xbeae0b09b1f478a6024e94690946d257
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 4 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake fragment handler
[ttls] eaptls_verify returned 1 
[ttls] eaptls_process returned 13 
++[eap] returns handled
Sending Access-Challenge of id 4 to 127.0.0.1 port 40609
        EAP-Message = 
0x01050314158000000af62f839804528c2c36733b0f4b1be32ddf1437b06ed574e4034c508b4f0715fe00aea2acf4da03a466d4ec9714bd5232bf6248580d805c2ad67c9f661b102e098a42ab9334de2a06dd18286533421452fe8d6d9ccaabc4fa4a187e78da6d960cac06ff2ed01e73f301d4aa6e587a91cdebe48466176d00709d7813adc612b85a28b10f96f2b110c5709e44b6623fbcaf8b98df3b25ed3c2b4f7957c19f57bd5a73dc7ef5ba98318a8020414072b92ae39c24affdd4cef31ff8453f609adb0ffe954201e2bcb7c8340c85e6d023e352ea7bf06ec3cd197bdc07c061d8a25fa9ee9c4e57ce40df181239beb692ea02fc4416030102
        EAP-Message = 
0x0d0c0002090080d8264a88509791af361c920288ca80bdefe6356030baff37a9211040829bf96bf568771e0810595535138454a565c371e3c9cef554bb0a7f7fcd607725217edfbde18c78b5815a92b981b06b4109aebd2d90f7588751f0e58f75f363cde714513035815e4ccbae0d649a336e4604a43726d48dcbf27698b9bb17df0f3810754b00010200800e730b494dc26929d4250ac808d9febd2df11c716a70a5fd5affbfa2e3721aeca6a2f639db80dad65edc4bfe66c53d03aa1f957acb320734771f8d374577599d664cffa9e11ac91ed0dbe91037f179772dc259c7e0d525ad74feb00590f32f6db70f3eb61483fa66ed0ffec8bcebb7f564
        EAP-Message = 
0xeaa5e9f4dfbe70d3134c905d37ae400100bcd7647152d75cae2cec848d8c675f0fb19afb0a0206cac9bc559ed466eab29fef4e1d4c3bdf243270caccb56b1b6049a7e2d871d73b9dc052dc24a75240aabae05e720653d8908909d679603f59a8ae961a9abc4b3c34017a6a60b2aa7a90976b343f02b009f7c521c9d599cc43fb60cbbd2be8a87b6244114d95ccb39ab2260e39a1e3a88171762ec8df7e2bc27ac2a4a3953cfd8e87cbeec46c33f8c365ba3c5bf50ccc7d33e72c95d518f9b05d1a87ee8766c9fcf9a4645ebab066be528eb04dc8583b79630ce06778248b2ecb186747b69e9ad61143ac176a11727ac1a7767475672dcb6d0e3287f0c4
        EAP-Message = 
0x212be90de4d2b3b88b052fda51aaa5265876d91b16030100040e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x477b7bc0437e6e2c045f14d9c1a56447
Finished request 32.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 40609, id=5, 
length=334
        User-Name = "anonymous"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
        EAP-Message = 
0x020500cc1500160301008610000082008017d3473998861d471e8a7125150176e85ad9190047165df6a9650e37511a87ca0ad5702afc58300fdc4372f2d4222075e66a99ba5728ef112242dfee2f1a939574f61aa0d423fde273926d4ec28497edec4c00fb49aef75dfb55500463977773f04cb9caf3aa1fdd91d22797af6fadd1b45380b9bfd5a57b52d1625bcdca3fb914030100010116030100309a74bcec40bb520eb89bc1c4f24211dad1deb921a1d2941a7765bc531c68a9dd846f20d74569542f199b5ad17cb78ab0
        State = 0x477b7bc0437e6e2c045f14d9c1a56447
        Message-Authenticator = 0x69d5a46a5c6a53682299121763f2e593
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 5 length 204
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7 
[ttls] Done initial handshake
[ttls] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange  
[ttls]     TLS_accept: SSLv3 read client key exchange A 
[ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001]  
[ttls] <<< TLS 1.0 Handshake [length 0010], Finished  
[ttls]     TLS_accept: SSLv3 read finished A 
[ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001]  
[ttls]     TLS_accept: SSLv3 write change cipher spec A 
[ttls] >>> TLS 1.0 Handshake [length 0010], Finished  
[ttls]     TLS_accept: SSLv3 write finished A 
[ttls]     TLS_accept: SSLv3 flush data 
[ttls]     (other): SSL negotiation finished successfully 
SSL Connection Established 
[ttls] eaptls_process returned 13 
++[eap] returns handled
Sending Access-Challenge of id 5 to 127.0.0.1 port 40609
        EAP-Message = 
0x0106004515800000003b14030100010116030100304dd32091564ace4e9f439585f7b2037506116f180b29547f4f26dcafdb055d2261240055af25fe853cc0b0ec57427320
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x477b7bc0427d6e2c045f14d9c1a56447
Finished request 33.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 40609, id=6, 
length=226
        User-Name = "anonymous"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
        EAP-Message = 
0x0206006015001703010020654ab2b04ef6aff22c11a82934844467db9e7db9eca4f3bce07d5ae466c60b451703010030af83c86cfe02487714a46b3f5076faa5038334cc26007de1b30eb5106034d44bd44f9bacb7486b87b6530c5aedc81242
        State = 0x477b7bc0427d6e2c045f14d9c1a56447
        Message-Authenticator = 0xde150bf24e63308295b94abafcfd200a
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 6 length 96
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7 
[ttls] Done initial handshake
[ttls] eaptls_process returned 7 
[ttls] Session established.  Proceeding to decode tunneled attributes.
[ttls] Got tunneled request
        EAP-Message = 0x02000009016a6f686e
        FreeRADIUS-Proxied-To = 127.0.0.1
[ttls] Got tunneled identity of john
[ttls] Setting default EAP type for tunneled EAP session.
[ttls] Sending tunneled request
        EAP-Message = 0x02000009016a6f686e
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "john"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
server inner-tunnel {
+- entering group authorize {...}
++[chap] returns noop
++[mschap] returns noop
++[unix] returns notfound
[suffix] No '@' in User-Name = "john", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
[eap] EAP packet type response id 0 length 9
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
[sql]   expand: %{User-Name} -> john
[sql] sql_set_user escaped user --> 'john'
rlm_sql (sql): Reserving sql socket id: 3
[sql]   expand: SELECT id, username, attribute, value, op           FROM 
radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -
> SELECT id, username, attribute, value, op           FROM radcheck           
WHERE username = 'john'           ORDER BY id
[sql] User found in radcheck table
[sql]   expand: SELECT id, username, attribute, value, op           FROM 
radreply           WHERE username = '%{SQL-User-Name}'           ORDER BY id -
> SELECT id, username, attribute, value, op           FROM radreply           
WHERE username = 'john'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup           WHERE 
username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           
FROM radusergroup           WHERE username = 'john'           ORDER BY 
priority
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
rlm_checkval: Item Name: Calling-Station-Id, Value: 02-00-00-00-00-01
rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
++[checkval] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] Found existing Auth-Type, not changing it.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] EAP Identity
[eap] processing type md5
rlm_eap_md5: Issuing Challenge
++[eap] returns handled
} # server inner-tunnel
[ttls] Got tunneled reply code 11
        EAP-Message = 0x010100160410e55cf3f132e3bba89b3bdc0633cedb0b
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x92db1d3d92da196b3735f5d4a01a13b3
[ttls] Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 6 to 127.0.0.1 port 40609
        EAP-Message = 
0x0107004f1580000000451703010040d29825cbb4797eb9115c92c74145da6968e0e8704769fa4f8acfc6947c5cdf1f34360e7302a69801840005f1ecd037d79dd7d5cf80bea521fc45c72b34349b55
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x477b7bc0417c6e2c045f14d9c1a56447
Finished request 34.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 127.0.0.1 port 40609, id=7, 
length=242
        User-Name = "anonymous"
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
        EAP-Message = 
0x020700701500170301002050be57d2358f8e3cc50822d5fbaedf0fa237f294a3ea37416f3f3b43bbc608a51703010040dff4c3ac6a2688dfb044010d698bb6d16dda40f2973049b92b428bd680e971426cedaeb78b23afe71025991a883986dbef648b7e70f7ca3211b8befbf08f6f16
        State = 0x477b7bc0417c6e2c045f14d9c1a56447
        Message-Authenticator = 0xab5852a76ba14a733dc5a7e8263f09c7
+- entering group authorize {...}
++[preprocess] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] No '@' in User-Name = "anonymous", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
[eap] EAP packet type response id 7 length 112
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] eaptls_verify returned 7 
[ttls] Done initial handshake
[ttls] eaptls_process returned 7 
[ttls] Session established.  Proceeding to decode tunneled attributes.
[ttls] Got tunneled request
        EAP-Message = 0x020100160410bd122de2634f7b6bd701b2cc91adcdb7
        FreeRADIUS-Proxied-To = 127.0.0.1
[ttls] Sending tunneled request
        EAP-Message = 0x020100160410bd122de2634f7b6bd701b2cc91adcdb7
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "john"
        State = 0x92db1d3d92da196b3735f5d4a01a13b3
        NAS-IP-Address = 127.0.0.1
        Calling-Station-Id = "02-00-00-00-00-01"
        Framed-MTU = 1400
        NAS-Port-Type = Wireless-802.11
        Connect-Info = "CONNECT 11Mbps 802.11b"
server inner-tunnel {
+- entering group authorize {...}
++[chap] returns noop
++[mschap] returns noop
++[unix] returns notfound
[suffix] No '@' in User-Name = "john", looking up realm NULL
[suffix] No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
[eap] EAP packet type response id 1 length 22
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
[sql]   expand: %{User-Name} -> john
[sql] sql_set_user escaped user --> 'john'
rlm_sql (sql): Reserving sql socket id: 2
[sql]   expand: SELECT id, username, attribute, value, op           FROM 
radcheck           WHERE username = '%{SQL-User-Name}'           ORDER BY id -
> SELECT id, username, attribute, value, op           FROM radcheck           
WHERE username = 'john'           ORDER BY id
[sql] User found in radcheck table
[sql]   expand: SELECT id, username, attribute, value, op           FROM 
radreply           WHERE username = '%{SQL-User-Name}'           ORDER BY id -
> SELECT id, username, attribute, value, op           FROM radreply           
WHERE username = 'john'           ORDER BY id
[sql]   expand: SELECT groupname           FROM radusergroup           WHERE 
username = '%{SQL-User-Name}'           ORDER BY priority -> SELECT groupname           
FROM radusergroup           WHERE username = 'john'           ORDER BY 
priority
rlm_sql (sql): Released sql socket id: 2
++[sql] returns ok
rlm_checkval: Item Name: Calling-Station-Id, Value: 02-00-00-00-00-01
rlm_checkval: Could not find attribute named Calling-Station-Id in check pairs
++[checkval] returns notfound
++[expiration] returns noop
++[logintime] returns noop
[pap] Found existing Auth-Type, not changing it.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/md5
[eap] processing type md5
[eap] Freeing handler
++[eap] returns ok
  WARNING: Empty post-auth section.  Using default return values.
} # server inner-tunnel
[ttls] Got tunneled reply code 2
        EAP-Message = 0x03010004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "john"
[ttls] Got tunneled Access-Accept
[eap] Freeing handler
rlm_eap_ttls: Freeing handler for user john
++[eap] returns ok
+- entering group post-auth {...}
[reply_log]     expand: /var/log/freeradius/radacct/%{Client-IP-
Address}/reply-detail-%Y%m%d -> /var/log/freeradius/radacct/127.0.0.1/reply-
detail-20100810
[reply_log] /var/log/freeradius/radacct/%{Client-IP-Address}/reply-
detail-%Y%m%d expands to /var/log/freeradius/radacct/127.0.0.1/reply-
detail-20100810
[reply_log]     expand: %t -> Tue Aug 10 17:19:34 2010
++[reply_log] returns ok
[sql]   expand: %{User-Name} -> anonymous
[sql] sql_set_user escaped user --> 'anonymous'
[sql]   expand: %{User-Password} -> 
[sql]   ... expanding second conditional
[sql]   expand: %{Chap-Password} -> 
[sql]   expand: INSERT INTO radpostauth                           (username, 
pass, reply, authdate)                           VALUES (                           
'%{User-Name}',                           '%{%{User-Password}:-%{Chap-
Password}}',                           '%{reply:Packet-Type}', '%S') -> INSERT 
INTO radpostauth                           (username, pass, reply, authdate)                           
VALUES (                           'anonymous',                           '',                           
'Access-Accept', '2010-08-10 17:19:34')
rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth                           
(username, pass, reply, authdate)                           VALUES (                           
'anonymous',                           '',                           'Access-
Accept', '2010-08-10 17:19:34')
rlm_sql (sql): Reserving sql socket id: 1
rlm_sql (sql): Released sql socket id: 1
++[sql] returns ok
++[exec] returns noop
Sending Access-Accept of id 7 to 127.0.0.1 port 40609
        MS-MPPE-Recv-Key = 
0x1e4491c233d0270c4f3bc4829f088dfbc8dcd8ba6541683752b76e424ffea8de
        MS-MPPE-Send-Key = 
0x64317ca56d6213c2e04813b157c9e923ed8d33b7dd0f6a8fd51aacb8c5bd790c
        EAP-Message = 0x03070004
        Message-Authenticator = 0x00000000000000000000000000000000
        User-Name = "anonymous"
Finished request 35.
Going to the next request
Waking up in 4.9 seconds.
Cleaning up request 28 ID 0 with timestamp +4232
Cleaning up request 29 ID 1 with timestamp +4232
Cleaning up request 30 ID 2 with timestamp +4232
Cleaning up request 31 ID 3 with timestamp +4232
Cleaning up request 32 ID 4 with timestamp +4232
Cleaning up request 33 ID 5 with timestamp +4232
Cleaning up request 34 ID 6 with timestamp +4232
Cleaning up request 35 ID 7 with timestamp +4232
Ready to process requests.





More information about the Freeradius-Users mailing list