Freeradius and winbind problem
Jean-Hubert Monlord
jean-hubert.monlord at acms.asso.fr
Mon Aug 3 14:35:20 CEST 2009
I have a problem with my freeradius installed on a Debian Lenny :
I want to use PEAP with Active Directory. It works fine during a few
minutes.
After that, freeradius don't send the Access-Accept, it seems it waits
for a response which never comes.
I must restart winbind daemon and freeradius to succeed an authentification.
The client is Aruba, but I have tested with Netgear with the same result.
Here is the debug when it doesn't work and after when it works :
rad_recv: Access-Request packet from host 10.254.0.32 port 32822,
id=189, length=173
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 1
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0013CE8BE8A6"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message = 0x020100130141434d535c6a686d6f6e6c6f7264
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.3"
Message-Authenticator = 0x21e1615eabadbb261c919283b3f5c77c
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 11:32:20 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 1 length 19
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
rlm_pap: WARNING! No "known good" password found for the user.
Authentication may fail because of this.
++[pap] returns noop
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: EAP Identity
rlm_eap: processing type tls
rlm_eap_tls: Initiate
rlm_eap_tls: Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 189 to 10.254.0.32 port 32822
EAP-Message = 0x010200061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x67acae1867aeb710f826cb3d04781dae
Finished request 3.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.254.0.32 port 32822,
id=190, length=252
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 1
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0013CE8BE8A6"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message =
0x0202005019800000004616030100410100003d03014a76aea459001bbf5e7c46d2faf33b74835c5f446843ed2fe97a84f4d5380fa300001600040005000a000900640062000300060013001200630100
State = 0x67acae1867aeb710f826cb3d04781dae
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.3"
Message-Authenticator = 0xebe44d56018b2078dc05fd10b49363ea
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 11:32:20 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 2 length 80
rlm_eap: Continuing tunnel setup.
++[eap] returns ok
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/peap
rlm_eap: processing type peap
rlm_eap_peap: Authenticate
rlm_eap_tls: processing TLS
TLS Length 70
rlm_eap_tls: Length Included
eaptls_verify returned 11
(other): before/accept initialization
TLS_accept: before/accept initialization
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0041], ClientHello
TLS_accept: SSLv3 read client hello A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello
TLS_accept: SSLv3 write server hello A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 06fa], Certificate
TLS_accept: SSLv3 write certificate A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
TLS_accept: SSLv3 write server done A
TLS_accept: SSLv3 flush data
TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
eaptls_process returned 13
rlm_eap_peap: EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 190 to 10.254.0.32 port 32822
EAP-Message =
0x0103040019c000000757160301004a0200004603014a76aea439fe1adad0be15346fa9ddb8a2d4a2f98c906b8c279870926a73bd9e20684cafb03aa6b70221b0faa4f14e7a5ef2d5a7927a97cfdc560d0ac5b580b7b200040016030106fa0b0006f60006f30003243082032030820289a003020102020104300d06092a864886f70d010104050030819e310b3009060355040613024652310f300d060355040813064672616e63653111300f0603550407130853757265736e6573310d300b060355040a130441434d53310b3009060355040b13024449312730250603550403131e41434d53202d2043657274696669636174696f6e20417574686f72
EAP-Message =
0x6974793126302406092a864886f70d0109011617706f73746d61737465724061636d732e6173736f2e6672301e170d3039303531323037303233315a170d3139303531303037303233315a3070310b3009060355040613024652310f300d060355040813064672616e6365310d300b060355040a130441434d5331193017060355040313106c2d726164697573312e48512e444f4d3126302406092a864886f70d0109011617706f73746d61737465724061636d732e6173736f2e667230820122300d06092a864886f70d01010105000382010f003082010a0282010100b591a1d3adb4e4ea8041108e8b7858638f181e1b0c9439ae22b6dd85f754c9
EAP-Message =
0x5a0cb03b3a5f5e44294598d31b1e69590452621253f761f2986999ef6e7814965bf0cbe10b16e0295fb88efc68979772f5053ba685d9af99b39994cbf17accde0831c26685960431dc4ac3696bf061ff0496a142ce2a576ad16c66c766cfe47038139a0584effb5bd1f63e502ae117e5286c79ad82192194bace81564e2c0ee5217b277a6969fd865a19152913cf50718ab09ccf01375bc1d5e7d501be14882cc1932693221a3274898e2d7387ced11b273c72d69a7719df1e43df7b6f54e7b70e9f3d91f216dcf1499e7ed37299fc3a982410737cde9ae04d76ab4053be800b0f0203010001a317301530130603551d25040c300a06082b0601050507
EAP-Message =
0x0301300d06092a864886f70d010104050003818100628fd16c16c9ca25d9fd4bf42b45dd9d1bba1b64146625d572b86a97e6c3780315511194fcf2510c4ce99393e61a63af985e6eb48438e8ef10d1f56f0380f626d9290e6b30f3459aa1ee66ae0556c5f5971a603343af9472105cabfb70eb144cb043f5cfadcc3a536f44bf3cd98c2bbb63af699594956609f75af9c9cadfe4e40003c9308203c53082032ea003020102020900ad028a9e72fb0f0a300d06092a864886f70d010104050030819e310b3009060355040613024652310f300d060355040813064672616e63653111300f0603550407130853757265736e6573310d300b060355040a13
EAP-Message = 0x0441434d53310b3009060355
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x67acae1866afb710f826cb3d04781dae
Finished request 4.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.254.0.32 port 32822,
id=191, length=178
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 1
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0013CE8BE8A6"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message = 0x020300061900
State = 0x67acae1866afb710f826cb3d04781dae
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.3"
Message-Authenticator = 0x69b0156bc0eb57e635cba7dbdc059fcf
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 11:32:20 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 3 length 6
rlm_eap: Continuing tunnel setup.
++[eap] returns ok
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/peap
rlm_eap: processing type peap
rlm_eap_peap: Authenticate
rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
rlm_eap_tls: ack handshake fragment handler
eaptls_verify returned 1
eaptls_process returned 13
rlm_eap_peap: EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 191 to 10.254.0.32 port 32822
EAP-Message =
0x010403671900040b13024449312730250603550403131e41434d53202d2043657274696669636174696f6e20417574686f726974793126302406092a864886f70d0109011617706f73746d61737465724061636d732e6173736f2e6672301e170d3036303232383134323835375a170d3236303232333134323835375a30819e310b3009060355040613024652310f300d060355040813064672616e63653111300f0603550407130853757265736e6573310d300b060355040a130441434d53310b3009060355040b13024449312730250603550403131e41434d53202d2043657274696669636174696f6e20417574686f726974793126302406092a
EAP-Message =
0x864886f70d0109011617706f73746d61737465724061636d732e6173736f2e667230819f300d06092a864886f70d010101050003818d0030818902818100bc7d9f74ab64f276ac4c0059fbb63dd341d6e3f6938bbcc1d18614b5218a137322253da30d2c08e67d48425c192b3693766807b794f928a931adbe115181bc8f00941de778eb402079cce8298e0dd0fe6e80921db123209728442395c238c2902ac3dc5b9f23d239fadea85e62cabd30a3c6cdb162c46fd51e6d386ba868a3390203010001a382010730820103301d0603551d0e041604149cbb859d57389413b3def35ced857b46105dc5de3081d30603551d230481cb3081c880149cbb85
EAP-Message =
0x9d57389413b3def35ced857b46105dc5dea181a4a481a130819e310b3009060355040613024652310f300d060355040813064672616e63653111300f0603550407130853757265736e6573310d300b060355040a130441434d53310b3009060355040b13024449312730250603550403131e41434d53202d2043657274696669636174696f6e20417574686f726974793126302406092a864886f70d0109011617706f73746d61737465724061636d732e6173736f2e6672820900ad028a9e72fb0f0a300c0603551d13040530030101ff300d06092a864886f70d0101040500038181001b0a6fb0e890320aadf9c0baa7f3ca810ad2c8e6f246bdeadc
EAP-Message =
0xcda483532b27e5fb39164b2e3db6fb717f8534442e9efd065309d0e6c9d1a6e90c2fba2b7beb1e72f794bcccd2fc95190c65d9e97d1d37089610db9f6238adff67a1a2c818bd2e7ad5707603d6eb25e47681a57aceda1d2e2ea0e9ced9ba61c463f671a1b1d2f716030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x67acae1865a8b710f826cb3d04781dae
Finished request 5.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.254.0.32 port 32822,
id=192, length=494
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 1
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0013CE8BE8A6"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message =
0x0204014019800000013616030101061000010201006246ea1f8687d388d33a330d27ac41af039202ed25cc671b6c3b8feb6c70e61b80b965c252763ae7ad471ddf2019e8350ee0ee2562198dfdcf9280f8d44be13abbd17c2cf3c54daa125da6def0eab93a83a47ffcd4f183d3b44784edbbfab51f8db3c18cfaae60c6e2d25e398a1b57aaad2b97279c9501bef114811f2a617268718db187b5989b1f584752479c2a645877ff7ce68781e79dec1ca2c436d35d6497e0618fd1608c5b9b884569a3178c0baeeabb32a14b5c1c134adb18058ed373874a666e31a6a0a46220b63c275732db13abba3450b09ec624a2bf920f7a82439104b46d7ec901d1
EAP-Message =
0x40d0e6c361ac05a3d36a80be2c6097880ce35f69b19a5dbe1403010001011603010020c9efd83f8f0f46b740068191ae62591016a0d2039264d4e4dc79cc4377557e15
State = 0x67acae1865a8b710f826cb3d04781dae
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.3"
Message-Authenticator = 0xf3f7bf3ef7829cbf5076a085ad37306e
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 11:32:20 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 4 length 253
rlm_eap: Continuing tunnel setup.
++[eap] returns ok
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/peap
rlm_eap: processing type peap
rlm_eap_peap: Authenticate
rlm_eap_tls: processing TLS
TLS Length 310
rlm_eap_tls: Length Included
eaptls_verify returned 11
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange
TLS_accept: SSLv3 read client key exchange A
rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 read finished A
rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
TLS_accept: SSLv3 write change cipher spec A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 write finished A
TLS_accept: SSLv3 flush data
(other): SSL negotiation finished successfully
SSL Connection Established
eaptls_process returned 13
rlm_eap_peap: EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 192 to 10.254.0.32 port 32822
EAP-Message =
0x01050031190014030100010116030100207740a100507477c1f718fb32124193de13aaead0837f5851882e8b7972a94c0c
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x67acae1864a9b710f826cb3d04781dae
Finished request 6.
Going to the next request
Waking up in 4.8 seconds.
rad_recv: Access-Request packet from host 10.254.0.32 port 32822,
id=193, length=178
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 1
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0013CE8BE8A6"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message = 0x020500061900
State = 0x67acae1864a9b710f826cb3d04781dae
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.3"
Message-Authenticator = 0x318ea52e0b08a88236c56460b2cd2297
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 11:32:21 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 5 length 6
rlm_eap: Continuing tunnel setup.
++[eap] returns ok
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/peap
rlm_eap: processing type peap
rlm_eap_peap: Authenticate
rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
rlm_eap_tls: ack handshake is finished
eaptls_verify returned 3
eaptls_process returned 3
rlm_eap_peap: EAPTLS_SUCCESS
++[eap] returns handled
Sending Access-Challenge of id 193 to 10.254.0.32 port 32822
EAP-Message =
0x0106002019001703010015e31d9132a53caf4685e485312527c05fc62af5b815
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x67acae1863aab710f826cb3d04781dae
Finished request 7.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.254.0.32 port 32822,
id=194, length=214
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 1
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0013CE8BE8A6"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message =
0x0206002a1900170301001f9bdb3d417ff127d40066de4a25ba5d90e9743ec8ddd21e88b35661d661bd21
State = 0x67acae1863aab710f826cb3d04781dae
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.3"
Message-Authenticator = 0x2e4b14281e38b2f5c3a3d51bd8ae5247
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 11:32:21 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 6 length 42
rlm_eap: Continuing tunnel setup.
++[eap] returns ok
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/peap
rlm_eap: processing type peap
rlm_eap_peap: Authenticate
rlm_eap_tls: processing TLS
eaptls_verify returned 7
rlm_eap_tls: Done initial handshake
eaptls_process returned 7
rlm_eap_peap: EAPTLS_OK
rlm_eap_peap: Session established. Decoding tunneled attributes.
rlm_eap_peap: Identity - ACMS\usertest
PEAP: Got tunneled EAP-Message
EAP-Message = 0x020600130141434d535c6a686d6f6e6c6f7264
PEAP: Got tunneled identity of ACMS\usertest
PEAP: Setting default EAP type for tunneled EAP session.
PEAP: Setting User-Name to ACMS\usertest
PEAP: Sending tunneled request
EAP-Message = 0x020600130141434d535c6a686d6f6e6c6f7264
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "ACMS\\usertest"
server inner-tunnel {
+- entering group authorize
++[chap] returns noop
++[mschap] returns noop
++[unix] returns notfound
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
rlm_eap: EAP packet type response id 6 length 19
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: EAP Identity
rlm_eap: processing type mschapv2
rlm_eap_mschapv2: Issuing Challenge
++[eap] returns handled
} # server inner-tunnel
PEAP: Got tunneled reply RADIUS code 11
EAP-Message =
0x010700281a0107002310ba2fc1f10c107456492d749e4c51620041434d535c6a686d6f6e6c6f7264
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x410be7cb410cfdb5854c84f429fbe15f
PEAP: Processing from tunneled session code 0x1448b50 11
EAP-Message =
0x010700281a0107002310ba2fc1f10c107456492d749e4c51620041434d535c6a686d6f6e6c6f7264
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x410be7cb410cfdb5854c84f429fbe15f
PEAP: Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 194 to 10.254.0.32 port 32822
EAP-Message =
0x0107003f19001703010034382dac222a8cbe39aa7423d7009bbb6cc7b99e27c8055439a29cc831faa8ceaeba250bd480aac0fd08a0f6be91a630027b16f8ec
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x67acae1862abb710f826cb3d04781dae
Finished request 8.
Going to the next request
Waking up in 4.6 seconds.
rad_recv: Access-Request packet from host 10.254.0.32 port 32822,
id=195, length=268
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 1
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0013CE8BE8A6"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message =
0x020700601900170301005519e0c573c160d61825e0c1b4263659d02f871ee7d2b94b55e02b723733d2ac9b5f608539c59e517a7ba949007f888c19ee622fe8ae2a1886cf9977c98d49b80b2f6723b75097445c5f41cac1a738e381c73e56720b
State = 0x67acae1862abb710f826cb3d04781dae
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.3"
Message-Authenticator = 0xc298a38a0773ca5e6f26806e0750b6f7
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 11:32:21 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 7 length 96
rlm_eap: Continuing tunnel setup.
++[eap] returns ok
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/peap
rlm_eap: processing type peap
rlm_eap_peap: Authenticate
rlm_eap_tls: processing TLS
eaptls_verify returned 7
rlm_eap_tls: Done initial handshake
eaptls_process returned 7
rlm_eap_peap: EAPTLS_OK
rlm_eap_peap: Session established. Decoding tunneled attributes.
rlm_eap_peap: EAP type mschapv2
PEAP: Got tunneled EAP-Message
EAP-Message =
0x020700491a02070044318960abe2a4d2e1fe66969c8a71bbcfaa0000000000000000767c9816c36b03b2b3d7ae686db05eb5319239da6548f01e0041434d535c6a686d6f6e6c6f7264
PEAP: Setting User-Name to ACMS\usertest
PEAP: Sending tunneled request
EAP-Message =
0x020700491a02070044318960abe2a4d2e1fe66969c8a71bbcfaa0000000000000000767c9816c36b03b2b3d7ae686db05eb5319239da6548f01e0041434d535c6a686d6f6e6c6f7264
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "ACMS\\usertest"
State = 0x410be7cb410cfdb5854c84f429fbe15f
server inner-tunnel {
+- entering group authorize
++[chap] returns noop
++[mschap] returns noop
++[unix] returns notfound
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
rlm_eap: EAP packet type response id 7 length 73
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/mschapv2
rlm_eap: processing type mschapv2
+- entering group MS-CHAP
rlm_mschap: No Cleartext-Password configured. Cannot create LM-Password.
rlm_mschap: No Cleartext-Password configured. Cannot create NT-Password.
rlm_mschap: Told to do MS-CHAPv2 for usertest with NT-Password
expand: --domain=%{mschap:NT-Domain} -> --domain=ACMS
expand: --username=%{mschap:User-Name} -> --username=usertest
mschap2: ba
expand: --challenge=%{mschap:Challenge:-00} ->
--challenge=b3dfd0f2062ff185
expand: --nt-response=%{mschap:NT-Response:-00} ->
--nt-response=767c9816c36b03b2b3d7ae686db05eb5319239da6548f01e
Exec-Program output: NT_KEY: 35E241131A9A3028B30C29496120AA85
Exec-Program-Wait: plaintext: NT_KEY: 35E241131A9A3028B30C29496120AA85
Exec-Program: returned: 0
rlm_mschap: adding MS-CHAPv2 MPPE keys
++[mschap] returns ok
MSCHAP Success
++[eap] returns handled
} # server inner-tunnel
PEAP: Got tunneled reply RADIUS code 11
EAP-Message =
0x010800331a0307002e533d34413435444431363133373234353141303230454339443134413644423132313746334130364546
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x410be7cb4003fdb5854c84f429fbe15f
PEAP: Processing from tunneled session code 0x1448d00 11
EAP-Message =
0x010800331a0307002e533d34413435444431363133373234353141303230454339443134413644423132313746334130364546
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x410be7cb4003fdb5854c84f429fbe15f
PEAP: Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 195 to 10.254.0.32 port 32822
EAP-Message =
0x0108004a1900170301003f363cfc69b8eb543b309b5e3b0eeba4662d61f3f1ec8a55a0b4b401f987bcd6f1d8cf5f9e3cdc0c7d0afb0a22b49f6b0e67a301a591480f764cd0f5156c126f
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x67acae1861a4b710f826cb3d04781dae
Finished request 9.
Going to the next request
Waking up in 4.6 seconds.
Cleaning up request 3 ID 189 with timestamp +539
Cleaning up request 4 ID 190 with timestamp +539
Cleaning up request 5 ID 191 with timestamp +539
Waking up in 0.1 seconds.
Cleaning up request 6 ID 192 with timestamp +539
Waking up in 0.1 seconds.
Cleaning up request 7 ID 193 with timestamp +540
Cleaning up request 8 ID 194 with timestamp +540
Cleaning up request 9 ID 195 with timestamp +540
Ready to process requests.
Here, it works :
rad_recv: Access-Request packet from host 10.254.0.32 port 32822, id=80,
length=167
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 2
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0018DECCECAA"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message = 0x0201001001444f4d5c6361726c696f7a
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.2"
Message-Authenticator = 0x74ac90d2e39e6e057f970e06f8d308f6
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 14:06:35 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 1 length 16
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
rlm_pap: WARNING! No "known good" password found for the user.
Authentication may fail because of this.
++[pap] returns noop
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: EAP Identity
rlm_eap: processing type tls
rlm_eap_tls: Initiate
rlm_eap_tls: Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 80 to 10.254.0.32 port 32822
EAP-Message = 0x010200061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb1d1cd33b1d3d4b9577b19a501eee06e
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.254.0.32 port 32822, id=81,
length=281
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 2
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0018DECCECAA"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message =
0x0202007019800000006616030100610100005d03014a76d2cb4fcdc3ecfcf18e4f349f62ca5dff023b687e8448aa20c99d8aaa1dc02052f6239bf116d56a2f94fc6106c098bb169d635312641c10d18e36178ea6e45c001600040005000a000900640062000300060013001200630100
State = 0xb1d1cd33b1d3d4b9577b19a501eee06e
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.2"
Message-Authenticator = 0x8a4f52d9a7d1030ca81375cb707dbbf9
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 14:06:36 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 2 length 112
rlm_eap: Continuing tunnel setup.
++[eap] returns ok
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/peap
rlm_eap: processing type peap
rlm_eap_peap: Authenticate
rlm_eap_tls: processing TLS
TLS Length 102
rlm_eap_tls: Length Included
eaptls_verify returned 11
(other): before/accept initialization
TLS_accept: before/accept initialization
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0061], ClientHello
TLS_accept: SSLv3 read client hello A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello
TLS_accept: SSLv3 write server hello A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 06fa], Certificate
TLS_accept: SSLv3 write certificate A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
TLS_accept: SSLv3 write server done A
TLS_accept: SSLv3 flush data
TLS_accept: Need to read more data: SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
eaptls_process returned 13
rlm_eap_peap: EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 81 to 10.254.0.32 port 32822
EAP-Message =
0x0103040019c000000757160301004a0200004603014a76d2ccf7d4afc8a7cdbafc342ef1b377a655e92f5329cd0367ba8ef969447f20e37338d7a07f9ad5f0fb0999ed7e6af69a00fefe44d7c085de718cd53f61f04d00040016030106fa0b0006f60006f30003243082032030820289a003020102020104300d06092a864886f70d010104050030819e310b3009060355040613024652310f300d060355040813064672616e63653111300f0603550407130853757265736e6573310d300b060355040a130441434d53310b3009060355040b13024449312730250603550403131e41434d53202d2043657274696669636174696f6e20417574686f72
EAP-Message =
0x6974793126302406092a864886f70d0109011617706f73746d61737465724061636d732e6173736f2e6672301e170d3039303531323037303233315a170d3139303531303037303233315a3070310b3009060355040613024652310f300d060355040813064672616e6365310d300b060355040a130441434d5331193017060355040313106c2d726164697573312e48512e444f4d3126302406092a864886f70d0109011617706f73746d61737465724061636d732e6173736f2e667230820122300d06092a864886f70d01010105000382010f003082010a0282010100b591a1d3adb4e4ea8041108e8b7858638f181e1b0c9439ae22b6dd85f754c9
EAP-Message =
0x5a0cb03b3a5f5e44294598d31b1e69590452621253f761f2986999ef6e7814965bf0cbe10b16e0295fb88efc68979772f5053ba685d9af99b39994cbf17accde0831c26685960431dc4ac3696bf061ff0496a142ce2a576ad16c66c766cfe47038139a0584effb5bd1f63e502ae117e5286c79ad82192194bace81564e2c0ee5217b277a6969fd865a19152913cf50718ab09ccf01375bc1d5e7d501be14882cc1932693221a3274898e2d7387ced11b273c72d69a7719df1e43df7b6f54e7b70e9f3d91f216dcf1499e7ed37299fc3a982410737cde9ae04d76ab4053be800b0f0203010001a317301530130603551d25040c300a06082b0601050507
EAP-Message =
0x0301300d06092a864886f70d010104050003818100628fd16c16c9ca25d9fd4bf42b45dd9d1bba1b64146625d572b86a97e6c3780315511194fcf2510c4ce99393e61a63af985e6eb48438e8ef10d1f56f0380f626d9290e6b30f3459aa1ee66ae0556c5f5971a603343af9472105cabfb70eb144cb043f5cfadcc3a536f44bf3cd98c2bbb63af699594956609f75af9c9cadfe4e40003c9308203c53082032ea003020102020900ad028a9e72fb0f0a300d06092a864886f70d010104050030819e310b3009060355040613024652310f300d060355040813064672616e63653111300f0603550407130853757265736e6573310d300b060355040a13
EAP-Message = 0x0441434d53310b3009060355
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb1d1cd33b0d2d4b9577b19a501eee06e
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.254.0.32 port 32822, id=82,
length=175
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 2
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0018DECCECAA"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message = 0x020300061900
State = 0xb1d1cd33b0d2d4b9577b19a501eee06e
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.2"
Message-Authenticator = 0x6db7cf5ed3d73d831bb04492bc36e0a8
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 14:06:36 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 3 length 6
rlm_eap: Continuing tunnel setup.
++[eap] returns ok
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/peap
rlm_eap: processing type peap
rlm_eap_peap: Authenticate
rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
rlm_eap_tls: ack handshake fragment handler
eaptls_verify returned 1
eaptls_process returned 13
rlm_eap_peap: EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 82 to 10.254.0.32 port 32822
EAP-Message =
0x010403671900040b13024449312730250603550403131e41434d53202d2043657274696669636174696f6e20417574686f726974793126302406092a864886f70d0109011617706f73746d61737465724061636d732e6173736f2e6672301e170d3036303232383134323835375a170d3236303232333134323835375a30819e310b3009060355040613024652310f300d060355040813064672616e63653111300f0603550407130853757265736e6573310d300b060355040a130441434d53310b3009060355040b13024449312730250603550403131e41434d53202d2043657274696669636174696f6e20417574686f726974793126302406092a
EAP-Message =
0x864886f70d0109011617706f73746d61737465724061636d732e6173736f2e667230819f300d06092a864886f70d010101050003818d0030818902818100bc7d9f74ab64f276ac4c0059fbb63dd341d6e3f6938bbcc1d18614b5218a137322253da30d2c08e67d48425c192b3693766807b794f928a931adbe115181bc8f00941de778eb402079cce8298e0dd0fe6e80921db123209728442395c238c2902ac3dc5b9f23d239fadea85e62cabd30a3c6cdb162c46fd51e6d386ba868a3390203010001a382010730820103301d0603551d0e041604149cbb859d57389413b3def35ced857b46105dc5de3081d30603551d230481cb3081c880149cbb85
EAP-Message =
0x9d57389413b3def35ced857b46105dc5dea181a4a481a130819e310b3009060355040613024652310f300d060355040813064672616e63653111300f0603550407130853757265736e6573310d300b060355040a130441434d53310b3009060355040b13024449312730250603550403131e41434d53202d2043657274696669636174696f6e20417574686f726974793126302406092a864886f70d0109011617706f73746d61737465724061636d732e6173736f2e6672820900ad028a9e72fb0f0a300c0603551d13040530030101ff300d06092a864886f70d0101040500038181001b0a6fb0e890320aadf9c0baa7f3ca810ad2c8e6f246bdeadc
EAP-Message =
0xcda483532b27e5fb39164b2e3db6fb717f8534442e9efd065309d0e6c9d1a6e90c2fba2b7beb1e72f794bcccd2fc95190c65d9e97d1d37089610db9f6238adff67a1a2c818bd2e7ad5707603d6eb25e47681a57aceda1d2e2ea0e9ced9ba61c463f671a1b1d2f716030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb1d1cd33b3d5d4b9577b19a501eee06e
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.254.0.32 port 32822, id=83,
length=491
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 2
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0018DECCECAA"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message =
0x020401401980000001361603010106100001020100621a6d6489a3b775a64ad3ee2f28e053794c50f912e68f4e67f03d70f8a0d1dd9dda173b2f6669f1b4c3bfdf17ae425ea3a2475b1191083540da42b1418efe2641b3a218326f60cf1b6eecd32d21409ea10079a2be923248253fd9a1c36db54260dc3562fb6c49245980d521d894763779662b0f70a32e0f48ae6b5767ea2c9e6c11409830b84f4bd3e553ee460afa486508d0e3e823fc251c6cd850cfbb1a43eecf83d5d03aed2e78f80f2e965ce7ceebf9259655c4c32d5efd88ed7a60ced5fcdaa5531be9bf7379597e25e7c37eca79eeca6ade118f9c7f904256e9f8b7d2563308f0480c8559
EAP-Message =
0x8942ff0c70a8c3ce206f908d3d2b3ee44fadc13d9a9f1e68140301000101160301002060d7e7fc4d412ea50f03efecf0d0cd8d01267753af8a16ff3095758ca82c3b9e
State = 0xb1d1cd33b3d5d4b9577b19a501eee06e
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.2"
Message-Authenticator = 0x2c34b230bef2071b982d584fca5ec843
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 14:06:36 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 4 length 253
rlm_eap: Continuing tunnel setup.
++[eap] returns ok
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/peap
rlm_eap: processing type peap
rlm_eap_peap: Authenticate
rlm_eap_tls: processing TLS
TLS Length 310
rlm_eap_tls: Length Included
eaptls_verify returned 11
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange
TLS_accept: SSLv3 read client key exchange A
rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001]
rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 read finished A
rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001]
TLS_accept: SSLv3 write change cipher spec A
rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished
TLS_accept: SSLv3 write finished A
TLS_accept: SSLv3 flush data
(other): SSL negotiation finished successfully
SSL Connection Established
eaptls_process returned 13
rlm_eap_peap: EAPTLS_HANDLED
++[eap] returns handled
Sending Access-Challenge of id 83 to 10.254.0.32 port 32822
EAP-Message =
0x0105003119001403010001011603010020c9602cd84aa7982ac74fdd03d1b658d1fb963f2d3b8ead12ea31c58209248c2b
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb1d1cd33b2d4d4b9577b19a501eee06e
Finished request 3.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 10.254.0.32 port 32822, id=85,
length=175
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 2
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0018DECCECAA"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message = 0x020500061900
State = 0xb1d1cd33b2d4d4b9577b19a501eee06e
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.2"
Message-Authenticator = 0x51af73ed1ede861fc06ee69ee7362ddd
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 14:06:36 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 5 length 6
rlm_eap: Continuing tunnel setup.
++[eap] returns ok
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/peap
rlm_eap: processing type peap
rlm_eap_peap: Authenticate
rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
rlm_eap_tls: ack handshake is finished
eaptls_verify returned 3
eaptls_process returned 3
rlm_eap_peap: EAPTLS_SUCCESS
++[eap] returns handled
Sending Access-Challenge of id 85 to 10.254.0.32 port 32822
EAP-Message =
0x010600201900170301001514a38092da042a09a0d53f71c5db3c20253be3932a
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb1d1cd33b5d7d4b9577b19a501eee06e
Finished request 4.
Going to the next request
Waking up in 4.6 seconds.
rad_recv: Access-Request packet from host 10.254.0.32 port 32822, id=84,
length=208
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 2
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0018DECCECAA"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message =
0x020600271900170301001c377f4b5460aaaa3ed396b66c24a6e7da327d38ffc15fdbbfa5071b7e
State = 0xb1d1cd33b5d7d4b9577b19a501eee06e
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.2"
Message-Authenticator = 0x9458c933041125b9f6ca8610574f998f
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 14:06:36 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 6 length 39
rlm_eap: Continuing tunnel setup.
++[eap] returns ok
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/peap
rlm_eap: processing type peap
rlm_eap_peap: Authenticate
rlm_eap_tls: processing TLS
eaptls_verify returned 7
rlm_eap_tls: Done initial handshake
eaptls_process returned 7
rlm_eap_peap: EAPTLS_OK
rlm_eap_peap: Session established. Decoding tunneled attributes.
rlm_eap_peap: Identity - ACMS\usertest
PEAP: Got tunneled EAP-Message
EAP-Message = 0x0206001001444f4d5c6361726c696f7a
PEAP: Got tunneled identity of ACMS\usertest
PEAP: Setting default EAP type for tunneled EAP session.
PEAP: Setting User-Name to ACMS\usertest
PEAP: Sending tunneled request
EAP-Message = 0x0206001001444f4d5c6361726c696f7a
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "ACMS\\usertest"
server inner-tunnel {
+- entering group authorize
++[chap] returns noop
++[mschap] returns noop
++[unix] returns notfound
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
rlm_eap: EAP packet type response id 6 length 16
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: EAP Identity
rlm_eap: processing type mschapv2
rlm_eap_mschapv2: Issuing Challenge
++[eap] returns handled
} # server inner-tunnel
PEAP: Got tunneled reply RADIUS code 11
EAP-Message =
0x010700251a0107002010556e70ce846691aea2c042838cb465b6444f4d5c6361726c696f7a
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x5bbb7f125bbc65603c947384488c39d8
PEAP: Processing from tunneled session code 0x1d6fa00 11
EAP-Message =
0x010700251a0107002010556e70ce846691aea2c042838cb465b6444f4d5c6361726c696f7a
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x5bbb7f125bbc65603c947384488c39d8
PEAP: Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 84 to 10.254.0.32 port 32822
EAP-Message =
0x0107003c190017030100315d3c38589f24e052410d29c4316debb268b576d1491c91397a2c2c47ed82de8d07e25f85ddbca888ce5f2f52498b00a17a
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb1d1cd33b4d6d4b9577b19a501eee06e
Finished request 5.
Going to the next request
Waking up in 4.6 seconds.
rad_recv: Access-Request packet from host 10.254.0.32 port 32822, id=86,
length=262
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 2
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0018DECCECAA"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message =
0x0207005d19001703010052c5802a50a76626e911c84500e1b139ec0e448554c2539bfd8f2c422a750c6b46c2f45c07d81b631135434e59b0127081fbbb408133efa7d87546245dc74d5ea394ba4725db00c777e1db5649858339a6ff89
State = 0xb1d1cd33b4d6d4b9577b19a501eee06e
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.2"
Message-Authenticator = 0xaaba5a2f699aa217dc67dbd1ad2c1b8b
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 14:06:36 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 7 length 93
rlm_eap: Continuing tunnel setup.
++[eap] returns ok
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/peap
rlm_eap: processing type peap
rlm_eap_peap: Authenticate
rlm_eap_tls: processing TLS
eaptls_verify returned 7
rlm_eap_tls: Done initial handshake
eaptls_process returned 7
rlm_eap_peap: EAPTLS_OK
rlm_eap_peap: Session established. Decoding tunneled attributes.
rlm_eap_peap: EAP type mschapv2
PEAP: Got tunneled EAP-Message
EAP-Message =
0x020700461a0207004131b8a86f74525f79287c685926df8506b30000000000000000937766f3b6118923d4a2833ba1d198e1b0c984525ac7d57000444f4d5c6361726c696f7a
PEAP: Setting User-Name to ACMS\usertest
PEAP: Sending tunneled request
EAP-Message =
0x020700461a0207004131b8a86f74525f79287c685926df8506b30000000000000000937766f3b6118923d4a2833ba1d198e1b0c984525ac7d57000444f4d5c6361726c696f7a
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "ACMS\\usertest"
State = 0x5bbb7f125bbc65603c947384488c39d8
server inner-tunnel {
+- entering group authorize
++[chap] returns noop
++[mschap] returns noop
++[unix] returns notfound
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
rlm_eap: EAP packet type response id 7 length 70
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/mschapv2
rlm_eap: processing type mschapv2
+- entering group MS-CHAP
rlm_mschap: No Cleartext-Password configured. Cannot create LM-Password.
rlm_mschap: No Cleartext-Password configured. Cannot create NT-Password.
rlm_mschap: Told to do MS-CHAPv2 for usertest with NT-Password
expand: --ACMSain=%{mschap:NT-ACMSain} -> --ACMSain=ACMS
expand: --username=%{mschap:User-Name} -> --username=usertest
mschap2: 55
expand: --challenge=%{mschap:Challenge:-00} ->
--challenge=b4dbd917acb3d690
expand: --nt-response=%{mschap:NT-Response:-00} ->
--nt-response=937766f3b6118923d4a2833ba1d198e1b0c984525ac7d570
Exec-Program output: NT_KEY: D139B35EDBE5A4E870E34920F2D63FEF
Exec-Program-Wait: plaintext: NT_KEY: D139B35EDBE5A4E870E34920F2D63FEF
Exec-Program: returned: 0
rlm_mschap: adding MS-CHAPv2 MPPE keys
++[mschap] returns ok
MSCHAP Success
++[eap] returns handled
} # server inner-tunnel
PEAP: Got tunneled reply RADIUS code 11
EAP-Message =
0x010800331a0307002e533d36303743343137423644323646333643423935313230443135454133304346393743383145354232
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x5bbb7f125ab365603c947384488c39d8
PEAP: Processing from tunneled session code 0x1d48ad0 11
EAP-Message =
0x010800331a0307002e533d36303743343137423644323646333643423935313230443135454133304346393743383145354232
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x5bbb7f125ab365603c947384488c39d8
PEAP: Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 86 to 10.254.0.32 port 32822
EAP-Message =
0x0108004a1900170301003f790d3c1318deb33bc9b0bffbdc62f89cb9ef00e48a4369d5176e082332ac0f3e1adeececf9133a24e2db88a48f131b24f96b470ad735d56aab1e398d8b1962
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb1d1cd33b7d9d4b9577b19a501eee06e
Finished request 6.
Going to the next request
Waking up in 4.6 seconds.
rad_recv: Access-Request packet from host 10.254.0.32 port 32822, id=87,
length=198
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 2
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0018DECCECAA"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message =
0x0208001d19001703010012c0833497cbb416bd4af4736ed09a77f33fcc
State = 0xb1d1cd33b7d9d4b9577b19a501eee06e
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.2"
Message-Authenticator = 0x11904e5ce88bdc7e4015519888a50038
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 14:06:36 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 8 length 29
rlm_eap: Continuing tunnel setup.
++[eap] returns ok
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/peap
rlm_eap: processing type peap
rlm_eap_peap: Authenticate
rlm_eap_tls: processing TLS
eaptls_verify returned 7
rlm_eap_tls: Done initial handshake
eaptls_process returned 7
rlm_eap_peap: EAPTLS_OK
rlm_eap_peap: Session established. Decoding tunneled attributes.
rlm_eap_peap: EAP type mschapv2
PEAP: Got tunneled EAP-Message
EAP-Message = 0x020800061a03
PEAP: Setting User-Name to ACMS\usertest
PEAP: Sending tunneled request
EAP-Message = 0x020800061a03
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "ACMS\\usertest"
State = 0x5bbb7f125ab365603c947384488c39d8
server inner-tunnel {
+- entering group authorize
++[chap] returns noop
++[mschap] returns noop
++[unix] returns notfound
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
++[control] returns noop
rlm_eap: EAP packet type response id 8 length 6
rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/mschapv2
rlm_eap: processing type mschapv2
rlm_eap: Freeing handler
++[eap] returns ok
Login OK: [ACMS\\usertest/<via Auth-Type = EAP>] (from client aruba1
port 0 via TLS tunnel)
} # server inner-tunnel
PEAP: Got tunneled reply RADIUS code 2
EAP-Message = 0x03080004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "ACMS\\usertest"
PEAP: Processing from tunneled session code 0x1d6d7f0 2
EAP-Message = 0x03080004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "ACMS\\usertest"
PEAP: Tunneled authentication was successful.
rlm_eap_peap: SUCCESS
++[eap] returns handled
Sending Access-Challenge of id 87 to 10.254.0.32 port 32822
EAP-Message =
0x010900261900170301001b740c352358b879b666b2617fe8fa1cb29288f5b899546d41a5655a
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xb1d1cd33b6d8d4b9577b19a501eee06e
Finished request 7.
Going to the next request
Waking up in 4.6 seconds.
rad_recv: Access-Request packet from host 10.254.0.32 port 32822, id=88,
length=207
User-Name = "ACMS\\usertest"
NAS-IP-Address = 10.254.0.30
NAS-Port = 2
NAS-Identifier = "10.254.0.32"
NAS-Port-Type = Wireless-802.11
Calling-Station-Id = "0018DECCECAA"
Called-Station-Id = "000B86613054"
Service-Type = Login-User
Framed-MTU = 1100
EAP-Message =
0x020900261900170301001bd911f82a6b41a035a62496200168b13d84f72b9c8b9d86ed23c3c0
State = 0xb1d1cd33b6d8d4b9577b19a501eee06e
Aruba-Essid-Name = "ACMS"
Aruba-Location-Id = "254.1.2"
Message-Authenticator = 0xc65b393765c82022a70ba974c1df2966
+- entering group authorize
++[preprocess] returns ok
expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
rlm_detail:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to /var/log/freeradius/radacct/10.254.0.32/auth-detail-20090803
expand: %t -> Mon Aug 3 14:06:36 2009
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
rlm_realm: No '@' in User-Name = "ACMS\usertest", looking up realm NULL
rlm_realm: No such realm "NULL"
++[suffix] returns noop
rlm_eap: EAP packet type response id 9 length 38
rlm_eap: Continuing tunnel setup.
++[eap] returns ok
rad_check_password: Found Auth-Type EAP
auth: type "EAP"
+- entering group authenticate
rlm_eap: Request found, released from the list
rlm_eap: EAP/peap
rlm_eap: processing type peap
rlm_eap_peap: Authenticate
rlm_eap_tls: processing TLS
eaptls_verify returned 7
rlm_eap_tls: Done initial handshake
eaptls_process returned 7
rlm_eap_peap: EAPTLS_OK
rlm_eap_peap: Session established. Decoding tunneled attributes.
rlm_eap_peap: Received EAP-TLV response.
rlm_eap_peap: Success
rlm_eap: Freeing handler
++[eap] returns ok
Login OK: [ACMS\\usertest/<via Auth-Type = EAP>] (from client aruba1
port 2 cli 0018DECCECAA)
+- entering group post-auth
++[exec] returns noop
Sending Access-Accept of id 88 to 10.254.0.32 port 32822
MS-MPPE-Recv-Key =
0x695e9dd8253cf8ad3be2d108b81c7071284dce6533e98dfc3c776afd46f80a2a
MS-MPPE-Send-Key =
0x48dea6a783506a6d57acd8d4ae74e9911463c666e58cd632b44cb3146c832d30
EAP-Message = 0x03090004
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "ACMS\\usertest"
Finished request 8.
Going to the next request
Waking up in 4.6 seconds.
Cleaning up request 0 ID 80 with timestamp +164
Cleaning up request 1 ID 81 with timestamp +165
Cleaning up request 2 ID 82 with timestamp +165
Waking up in 0.2 seconds.
Cleaning up request 3 ID 83 with timestamp +165
Cleaning up request 4 ID 85 with timestamp +165
Cleaning up request 5 ID 84 with timestamp +165
Cleaning up request 6 ID 86 with timestamp +165
Cleaning up request 7 ID 87 with timestamp +165
Cleaning up request 8 ID 88 with timestamp +165
Thanks
Jean-Hubert Monlord
More information about the Freeradius-Users
mailing list