В сообщении от 27 Апрель 2005 09:00 Sergey Guriev написал:
Here is one big log of session. Please help me understand what realy wrong.
----------
rad_recv: Access-Request packet from host 80.243.64.30:14123, id=138,
length=142
User-Name = "[EMAIL PROTECTED]"
Framed-MTU = 1400
Called-Station-Id = "000d.edc3.08aa"
Calling-Station-Id = "000c.f154.0bf7"
Service-Type = Login-User
Message-Authenticator = 0x449fe5c8a1af72bfc019f7370857d3bd
EAP-Message = 0x020200110177777740776c616e2e6c616e
NAS-Port-Type = Wireless-802.11
NAS-Port = 397
NAS-IP-Address = 192.168.104.68
NAS-Identifier = "vntc-ka"
Thu Apr 28 11:33:52 2005 : Debug: Processing the authorize section of
radiusd.conf
Thu Apr 28 11:33:52 2005 : Debug: modcall: entering group authorize for
request 30
Thu Apr 28 11:33:52 2005 : Debug: modsingle[authorize]: calling preprocess
(rlm_preprocess) for request 30
Thu Apr 28 11:33:52 2005 : Debug: modsingle[authorize]: returned from
preprocess (rlm_preprocess) for request 30
Thu Apr 28 11:33:52 2005 : Debug: modcall[authorize]: module "preprocess"
returns ok for request 30
Thu Apr 28 11:33:52 2005 : Debug: modsingle[authorize]: calling auth_log
(rlm_detail) for request 30
Thu Apr 28 11:33:52 2005 : Debug: radius_xlat:
'/usr/local/var/log/radius/radacct/80.243.64.30/auth-detail-20050428'
Thu Apr 28 11:33:52 2005 : Debug: rlm_detail:
/usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to
/usr/local/var/log/radius/radacct/80.243.64.30/auth-detail-20050428
Thu Apr 28 11:33:52 2005 : Debug: modsingle[authorize]: returned from
auth_log (rlm_detail) for request 30
Thu Apr 28 11:33:52 2005 : Debug: modcall[authorize]: module "auth_log"
returns ok for request 30
Thu Apr 28 11:33:52 2005 : Debug: modsingle[authorize]: calling mschap
(rlm_mschap) for request 30
Thu Apr 28 11:33:52 2005 : Debug: modsingle[authorize]: returned from mschap
(rlm_mschap) for request 30
Thu Apr 28 11:33:52 2005 : Debug: modcall[authorize]: module "mschap"
returns noop for request 30
Thu Apr 28 11:33:52 2005 : Debug: modsingle[authorize]: calling suffix
(rlm_realm) for request 30
Thu Apr 28 11:33:52 2005 : Debug: rlm_realm: Looking up realm "wlan.lan"
for User-Name = "[EMAIL PROTECTED]"
Thu Apr 28 11:33:52 2005 : Debug: rlm_realm: Found realm "wlan.lan"
Thu Apr 28 11:33:52 2005 : Debug: rlm_realm: Adding Stripped-User-Name =
"www"
Thu Apr 28 11:33:52 2005 : Debug: rlm_realm: Proxying request from user
www to realm wlan.lan
Thu Apr 28 11:33:52 2005 : Debug: rlm_realm: Adding Realm = "wlan.lan"
Thu Apr 28 11:33:52 2005 : Debug: rlm_realm: Authentication realm is
LOCAL.
Thu Apr 28 11:33:52 2005 : Debug: modsingle[authorize]: returned from suffix
(rlm_realm) for request 30
Thu Apr 28 11:33:52 2005 : Debug: modcall[authorize]: module "suffix"
returns noop for request 30
Thu Apr 28 11:33:52 2005 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 30
Thu Apr 28 11:33:52 2005 : Debug: rlm_eap: EAP packet type response id 2
length 17
Thu Apr 28 11:33:52 2005 : Debug: rlm_eap: No EAP Start, assuming it's an
on-going EAP conversation
Thu Apr 28 11:33:52 2005 : Debug: modsingle[authorize]: returned from eap
(rlm_eap) for request 30
Thu Apr 28 11:33:52 2005 : Debug: modcall[authorize]: module "eap" returns
updated for request 30
Thu Apr 28 11:33:52 2005 : Debug: modsingle[authorize]: calling files
(rlm_files) for request 30
Thu Apr 28 11:33:52 2005 : Debug: users: Matched entry www at line 228
Thu Apr 28 11:33:52 2005 : Debug: modsingle[authorize]: returned from files
(rlm_files) for request 30
Thu Apr 28 11:33:52 2005 : Debug: modcall[authorize]: module "files" returns
ok for request 30
Thu Apr 28 11:33:52 2005 : Debug: modcall: group authorize returns updated for
request 30
Thu Apr 28 11:33:52 2005 : Debug: rad_check_password: Found Auth-Type EAP
Thu Apr 28 11:33:52 2005 : Debug: auth: type "EAP"
Thu Apr 28 11:33:52 2005 : Debug: Processing the authenticate section of
radiusd.conf
Thu Apr 28 11:33:52 2005 : Debug: modcall: entering group authenticate for
request 30
Thu Apr 28 11:33:52 2005 : Debug: modsingle[authenticate]: calling eap
(rlm_eap) for request 30
Thu Apr 28 11:33:52 2005 : Debug: rlm_eap: EAP Identity
Thu Apr 28 11:33:52 2005 : Debug: rlm_eap: processing type tls
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap_tls: Initiate
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap_tls: Start returned 1
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authenticate]: returned from eap
(rlm_eap) for request 30
Thu Apr 28 11:33:53 2005 : Debug: modcall[authenticate]: module "eap"
returns handled for request 30
Thu Apr 28 11:33:53 2005 : Debug: modcall: group authenticate returns handled
for request 30
Sending Access-Challenge of id 138 to 80.243.64.30:14123
EAP-Message = 0x010300061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x9f38c182ddd0f9b95c4486166258e60d
Thu Apr 28 11:33:53 2005 : Debug: Finished request 30
Thu Apr 28 11:33:53 2005 : Debug: Going to the next request
Thu Apr 28 11:33:53 2005 : Debug: --- Walking the entire request list ---
Thu Apr 28 11:33:53 2005 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 80.243.64.30:14123, id=139,
length=223
User-Name = "[EMAIL PROTECTED]"
Framed-MTU = 1400
Called-Station-Id = "000d.edc3.08aa"
Calling-Station-Id = "000c.f154.0bf7"
Service-Type = Login-User
Message-Authenticator = 0x8a9611566d7e6e15c11ed6377c3c7c70
EAP-Message =
0x0203005019800000004616030100410100003d030142702f75dc73a3d538cc08ae93377035918f32fee170daf864399320a82b8b0600001600040005000a000900640062000300060013001200630100
NAS-Port-Type = Wireless-802.11
NAS-Port = 397
State = 0x9f38c182ddd0f9b95c4486166258e60d
NAS-IP-Address = 192.168.104.68
NAS-Identifier = "vntc-ka"
Thu Apr 28 11:33:53 2005 : Debug: Processing the authorize section of
radiusd.conf
Thu Apr 28 11:33:53 2005 : Debug: modcall: entering group authorize for
request 31
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling preprocess
(rlm_preprocess) for request 31
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from
preprocess (rlm_preprocess) for request 31
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "preprocess"
returns ok for request 31
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling auth_log
(rlm_detail) for request 31
Thu Apr 28 11:33:53 2005 : Debug: radius_xlat:
'/usr/local/var/log/radius/radacct/80.243.64.30/auth-detail-20050428'
Thu Apr 28 11:33:53 2005 : Debug: rlm_detail:
/usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to
/usr/local/var/log/radius/radacct/80.243.64.30/auth-detail-20050428
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from
auth_log (rlm_detail) for request 31
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "auth_log"
returns ok for request 31
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling mschap
(rlm_mschap) for request 31
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from mschap
(rlm_mschap) for request 31
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "mschap"
returns noop for request 31
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling suffix
(rlm_realm) for request 31
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Looking up realm "wlan.lan"
for User-Name = "[EMAIL PROTECTED]"
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Found realm "wlan.lan"
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Adding Stripped-User-Name =
"www"
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Proxying request from user
www to realm wlan.lan
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Adding Realm = "wlan.lan"
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Authentication realm is
LOCAL.
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from suffix
(rlm_realm) for request 31
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "suffix"
returns noop for request 31
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 31
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: EAP packet type response id 3
length 80
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: No EAP Start, assuming it's an
on-going EAP conversation
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from eap
(rlm_eap) for request 31
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "eap" returns
updated for request 31
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling files
(rlm_files) for request 31
Thu Apr 28 11:33:53 2005 : Debug: users: Matched entry www at line 228
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from files
(rlm_files) for request 31
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "files" returns
ok for request 31
Thu Apr 28 11:33:53 2005 : Debug: modcall: group authorize returns updated for
request 31
Thu Apr 28 11:33:53 2005 : Debug: rad_check_password: Found Auth-Type EAP
Thu Apr 28 11:33:53 2005 : Debug: auth: type "EAP"
Thu Apr 28 11:33:53 2005 : Debug: Processing the authenticate section of
radiusd.conf
Thu Apr 28 11:33:53 2005 : Debug: modcall: entering group authenticate for
request 31
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authenticate]: calling eap
(rlm_eap) for request 31
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: Request found, released from the
list
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: EAP/peap
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: processing type peap
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap_peap: Authenticate
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap_tls: processing TLS
Thu Apr 28 11:33:53 2005 : Info: rlm_eap_tls: Length Included
Thu Apr 28 11:33:53 2005 : Debug: eaptls_verify returned 11
Thu Apr 28 11:33:53 2005 : Info: (other): before/accept initialization
Thu Apr 28 11:33:53 2005 : Info: TLS_accept: before/accept initialization
Thu Apr 28 11:33:53 2005 : Info: TLS_accept: SSLv3 read client hello A
Thu Apr 28 11:33:53 2005 : Info: TLS_accept: SSLv3 write server hello A
Thu Apr 28 11:33:53 2005 : Info: TLS_accept: SSLv3 write certificate A
Thu Apr 28 11:33:53 2005 : Info: TLS_accept: SSLv3 write server done A
Thu Apr 28 11:33:53 2005 : Info: TLS_accept: SSLv3 flush data
Thu Apr 28 11:33:53 2005 : Error: TLS_accept:error in SSLv3 read client
certificate A
Thu Apr 28 11:33:53 2005 : Debug: In SSL Handshake Phase
Thu Apr 28 11:33:53 2005 : Debug: In SSL Accept mode
Thu Apr 28 11:33:53 2005 : Debug: eaptls_process returned 13
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap_peap: EAPTLS_HANDLED
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authenticate]: returned from eap
(rlm_eap) for request 31
Thu Apr 28 11:33:53 2005 : Debug: modcall[authenticate]: module "eap"
returns handled for request 31
Thu Apr 28 11:33:53 2005 : Debug: modcall: group authenticate returns handled
for request 31
Sending Access-Challenge of id 139 to 80.243.64.30:14123
EAP-Message =
0x0104034e1900160301004a02000046030142702f718f110b5b516ec17c5907790d1042541ebe3fab3b5f21e77e0207661220ae9772b28d62cd2ea2a2ab83075a7269abd81d011ba6e0b1c1bd9b71a9c00f2c00040016030102eb0b0002e70002e40002e1308202dd30820246a003020102020101300d06092a864886f70d0101040500307e310b3009060355040613025255310d300b060355040813045072696d310d300b06035504071304566c6164310c300a060355040a13034e5443310b3009060355040b13024954311730150603550403130e6d61646469652e766e74632e7275311d301b06092a864886f70d010901160e6d61646469654076
EAP-Message =
0x6e74632e7275301e170d3035303431383232303433355a170d3036303431383232303433355a307e310b3009060355040613025255310d300b060355040813045072696d310d300b06035504071304566c6164310c300a060355040a13034e5443310b3009060355040b13024954311730150603550403130e6d61646469652e766e74632e7275311d301b06092a864886f70d010901160e6d616464696540766e74632e727530819f300d06092a864886f70d010101050003818d0030818902818100bc1555afb2a79eff4083cec43bdbdd345473e8c12fe8c695e57d1ddf9f15648365348ff32881ee5a140f6410a936b6864d2e7f79be8359243647
EAP-Message =
0x5819266952c7482799d28085022da01229f17dab49b868dde7c8a3a70484463f5c4a13082d1317567fdfae1b2257dba1367b807f02d798b0baaed3e5a703a76135af498be6170203010001a36b3069303206096086480186f842010404251623687474703a2f2f7777772e6372797074736f66742e636f6d2f63612d63726c2e70656d302006096086480186f842010d0413161154686973206973206120636f6d6d656e74301106096086480186f8420101040403020040300d06092a864886f70d0101040500038181002c8d378b485579b0faf0ee78baaa2c25c918023602d8c1c4c0e68d8b84c7c80551693998c3958614c19e060f614141fa31be
EAP-Message =
0x2f65526c5bd9a38d817c66563523768be58aa7206148e9c9c45464bddd399eb44f6a07db563584aea6f6388337aec089ef0bbc178cd139b7ccf4c773135776e49d6bab505ddd63dd36d62ba27b9616030100040e000000
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x2c5f8b577d7ece6904ae073fde0d4efd
Thu Apr 28 11:33:53 2005 : Debug: Finished request 31
Thu Apr 28 11:33:53 2005 : Debug: Going to the next request
Thu Apr 28 11:33:53 2005 : Debug: --- Walking the entire request list ---
Thu Apr 28 11:33:53 2005 : Debug: Waking up in 5 seconds...
rad_recv: Access-Request packet from host 80.243.64.30:14123, id=140,
length=335
User-Name = "[EMAIL PROTECTED]"
Framed-MTU = 1400
Called-Station-Id = "000d.edc3.08aa"
Calling-Station-Id = "000c.f154.0bf7"
Service-Type = Login-User
Message-Authenticator = 0x3b44308ad956393bcab264d155aaa0b9
EAP-Message =
0x020400c01980000000b6160301008610000082008008a3adeb51ab585f65cc063bfdec1834d73d4cc2da7aa9f887bcce503ad0cc293e8dad0bf2e2c3fbe3a6c7b17b9196a90b5673f671eb729092e2203e53011503150aa338fb29cbaffe8892c8caf441afa3eb3d4ee8d198a02abcb2043c0c3e361cf1a93911fbe51c553aa36653dfad2536dd977f6b033ddf413a2f38afb409151403010001011603010020160870b9afb6388c1ecbcea71787aff1fd311e417914672a714c588fec434d91
NAS-Port-Type = Wireless-802.11
NAS-Port = 397
State = 0x2c5f8b577d7ece6904ae073fde0d4efd
NAS-IP-Address = 192.168.104.68
NAS-Identifier = "vntc-ka"
Thu Apr 28 11:33:53 2005 : Debug: Processing the authorize section of
radiusd.conf
Thu Apr 28 11:33:53 2005 : Debug: modcall: entering group authorize for
request 32
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling preprocess
(rlm_preprocess) for request 32
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from
preprocess (rlm_preprocess) for request 32
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "preprocess"
returns ok for request 32
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling auth_log
(rlm_detail) for request 32
Thu Apr 28 11:33:53 2005 : Debug: radius_xlat:
'/usr/local/var/log/radius/radacct/80.243.64.30/auth-detail-20050428'
Thu Apr 28 11:33:53 2005 : Debug: rlm_detail:
/usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to
/usr/local/var/log/radius/radacct/80.243.64.30/auth-detail-20050428
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from
auth_log (rlm_detail) for request 32
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "auth_log"
returns ok for request 32
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling mschap
(rlm_mschap) for request 32
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from mschap
(rlm_mschap) for request 32
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "mschap"
returns noop for request 32
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling suffix
(rlm_realm) for request 32
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Looking up realm "wlan.lan"
for User-Name = "[EMAIL PROTECTED]"
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Found realm "wlan.lan"
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Adding Stripped-User-Name =
"www"
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Proxying request from user
www to realm wlan.lan
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Adding Realm = "wlan.lan"
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Authentication realm is
LOCAL.
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from suffix
(rlm_realm) for request 32
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "suffix"
returns noop for request 32
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 32
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: EAP packet type response id 4
length 192
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: No EAP Start, assuming it's an
on-going EAP conversation
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from eap
(rlm_eap) for request 32
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "eap" returns
updated for request 32
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling files
(rlm_files) for request 32
Thu Apr 28 11:33:53 2005 : Debug: users: Matched entry www at line 228
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from files
(rlm_files) for request 32
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "files" returns
ok for request 32
Thu Apr 28 11:33:53 2005 : Debug: modcall: group authorize returns updated for
request 32
Thu Apr 28 11:33:53 2005 : Debug: rad_check_password: Found Auth-Type EAP
Thu Apr 28 11:33:53 2005 : Debug: auth: type "EAP"
Thu Apr 28 11:33:53 2005 : Debug: Processing the authenticate section of
radiusd.conf
Thu Apr 28 11:33:53 2005 : Debug: modcall: entering group authenticate for
request 32
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authenticate]: calling eap
(rlm_eap) for request 32
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: Request found, released from the
list
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: EAP/peap
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: processing type peap
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap_peap: Authenticate
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap_tls: processing TLS
Thu Apr 28 11:33:53 2005 : Info: rlm_eap_tls: Length Included
Thu Apr 28 11:33:53 2005 : Debug: eaptls_verify returned 11
Thu Apr 28 11:33:53 2005 : Info: TLS_accept: SSLv3 read client key
exchange A
Thu Apr 28 11:33:53 2005 : Info: TLS_accept: SSLv3 read finished A
Thu Apr 28 11:33:53 2005 : Info: TLS_accept: SSLv3 write change cipher
spec A
Thu Apr 28 11:33:53 2005 : Info: TLS_accept: SSLv3 write finished A
Thu Apr 28 11:33:53 2005 : Info: TLS_accept: SSLv3 flush data
Thu Apr 28 11:33:53 2005 : Info: (other): SSL negotiation finished
successfully
Thu Apr 28 11:33:53 2005 : Debug: SSL Connection Established
Thu Apr 28 11:33:53 2005 : Debug: eaptls_process returned 13
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap_peap: EAPTLS_HANDLED
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authenticate]: returned from eap
(rlm_eap) for request 32
Thu Apr 28 11:33:53 2005 : Debug: modcall[authenticate]: module "eap"
returns handled for request 32
Thu Apr 28 11:33:53 2005 : Debug: modcall: group authenticate returns handled
for request 32
Sending Access-Challenge of id 140 to 80.243.64.30:14123
EAP-Message =
0x010500311900140301000101160301002013f41b0bdd2092d5f3829077bcb1b1ffef92c71b9085526bf71c394a4b82c9c7
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x76a86c433ffdb86cd4a585b3c2bff629
Thu Apr 28 11:33:53 2005 : Debug: Finished request 32
Thu Apr 28 11:33:53 2005 : Debug: Going to the next request
Thu Apr 28 11:33:53 2005 : Debug: Waking up in 5 seconds...
rad_recv: Access-Request packet from host 80.243.64.30:14123, id=141,
length=149
User-Name = "[EMAIL PROTECTED]"
Framed-MTU = 1400
Called-Station-Id = "000d.edc3.08aa"
Calling-Station-Id = "000c.f154.0bf7"
Service-Type = Login-User
Message-Authenticator = 0x20c67d9a4e9de994b551ccd080ce6b5e
EAP-Message = 0x020500061900
NAS-Port-Type = Wireless-802.11
NAS-Port = 397
State = 0x76a86c433ffdb86cd4a585b3c2bff629
NAS-IP-Address = 192.168.104.68
NAS-Identifier = "vntc-ka"
Thu Apr 28 11:33:53 2005 : Debug: Processing the authorize section of
radiusd.conf
Thu Apr 28 11:33:53 2005 : Debug: modcall: entering group authorize for
request 33
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling preprocess
(rlm_preprocess) for request 33
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from
preprocess (rlm_preprocess) for request 33
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "preprocess"
returns ok for request 33
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling auth_log
(rlm_detail) for request 33
Thu Apr 28 11:33:53 2005 : Debug: radius_xlat:
'/usr/local/var/log/radius/radacct/80.243.64.30/auth-detail-20050428'
Thu Apr 28 11:33:53 2005 : Debug: rlm_detail:
/usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to
/usr/local/var/log/radius/radacct/80.243.64.30/auth-detail-20050428
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from
auth_log (rlm_detail) for request 33
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "auth_log"
returns ok for request 33
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling mschap
(rlm_mschap) for request 33
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from mschap
(rlm_mschap) for request 33
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "mschap"
returns noop for request 33
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling suffix
(rlm_realm) for request 33
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Looking up realm "wlan.lan"
for User-Name = "[EMAIL PROTECTED]"
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Found realm "wlan.lan"
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Adding Stripped-User-Name =
"www"
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Proxying request from user
www to realm wlan.lan
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Adding Realm = "wlan.lan"
Thu Apr 28 11:33:53 2005 : Debug: rlm_realm: Authentication realm is
LOCAL.
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from suffix
(rlm_realm) for request 33
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "suffix"
returns noop for request 33
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 33
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: EAP packet type response id 5
length 6
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: No EAP Start, assuming it's an
on-going EAP conversation
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from eap
(rlm_eap) for request 33
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "eap" returns
updated for request 33
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: calling files
(rlm_files) for request 33
Thu Apr 28 11:33:53 2005 : Debug: users: Matched entry www at line 228
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authorize]: returned from files
(rlm_files) for request 33
Thu Apr 28 11:33:53 2005 : Debug: modcall[authorize]: module "files" returns
ok for request 33
Thu Apr 28 11:33:53 2005 : Debug: modcall: group authorize returns updated for
request 33
Thu Apr 28 11:33:53 2005 : Debug: rad_check_password: Found Auth-Type EAP
Thu Apr 28 11:33:53 2005 : Debug: auth: type "EAP"
Thu Apr 28 11:33:53 2005 : Debug: Processing the authenticate section of
radiusd.conf
Thu Apr 28 11:33:53 2005 : Debug: modcall: entering group authenticate for
request 33
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authenticate]: calling eap
(rlm_eap) for request 33
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: Request found, released from the
list
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: EAP/peap
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap: processing type peap
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap_peap: Authenticate
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap_tls: processing TLS
Thu Apr 28 11:33:53 2005 : Info: rlm_eap_tls: Received EAP-TLS ACK message
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap_tls: No SSL info available.
Waiting for more SSL data.
Thu Apr 28 11:33:53 2005 : Debug: eaptls_verify returned 1
Thu Apr 28 11:33:53 2005 : Debug: eaptls_process returned 13
Thu Apr 28 11:33:53 2005 : Debug: rlm_eap_peap: EAPTLS_HANDLED
Thu Apr 28 11:33:53 2005 : Debug: modsingle[authenticate]: returned from eap
(rlm_eap) for request 33
Thu Apr 28 11:33:53 2005 : Debug: modcall[authenticate]: module "eap"
returns handled for request 33
Thu Apr 28 11:33:53 2005 : Debug: modcall: group authenticate returns handled
for request 33
Sending Access-Challenge of id 141 to 80.243.64.30:14123
EAP-Message = 0x010600061900
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x8cf6cdff12a91fa4f863f5a19cf35945
Thu Apr 28 11:33:53 2005 : Debug: Finished request 33
Thu Apr 28 11:33:53 2005 : Debug: Going to the next request
Thu Apr 28 11:33:53 2005 : Debug: Waking up in 5 seconds...
Thu Apr 28 11:33:58 2005 : Debug: --- Walking the entire request list ---
Thu Apr 28 11:33:58 2005 : Debug: Cleaning up request 30 ID 138 with timestamp
42702f70
Thu Apr 28 11:33:58 2005 : Debug: Waking up in 1 seconds...
Thu Apr 28 11:33:59 2005 : Debug: --- Walking the entire request list ---
Thu Apr 28 11:33:59 2005 : Debug: Cleaning up request 31 ID 139 with timestamp
42702f71
Thu Apr 28 11:33:59 2005 : Debug: Cleaning up request 32 ID 140 with timestamp
42702f71
Thu Apr 28 11:33:59 2005 : Debug: Cleaning up request 33 ID 141 with timestamp
42702f71
Thu Apr 28 11:33:59 2005 : Debug: Nothing to do. Sleeping until we see a
request.
rad_recv: Access-Request packet from host 80.243.64.30:14123, id=142,
length=142
User-Name = "[EMAIL PROTECTED]"
Framed-MTU = 1400
Called-Station-Id = "000d.edc3.08aa"
Calling-Station-Id = "000c.f154.0bf7"
Service-Type = Login-User
Message-Authenticator = 0x07e66e2c8300f485e0500274879046ac
EAP-Message = 0x020200110177777740776c616e2e6c616e
NAS-Port-Type = Wireless-802.11
NAS-Port = 398
NAS-IP-Address = 192.168.104.68
NAS-Identifier = "vntc-ka"
Thu Apr 28 11:34:23 2005 : Debug: Processing the authorize section of
radiusd.conf
Thu Apr 28 11:34:23 2005 : Debug: modcall: entering group authorize for
request 34
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling preprocess
(rlm_preprocess) for request 34
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from
preprocess (rlm_preprocess) for request 34
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "preprocess"
returns ok for request 34
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling auth_log
(rlm_detail) for request 34
Thu Apr 28 11:34:23 2005 : Debug: radius_xlat:
'/usr/local/var/log/radius/radacct/80.243.64.30/auth-detail-20050428'
Thu Apr 28 11:34:23 2005 : Debug: rlm_detail:
/usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to
/usr/local/var/log/radius/radacct/80.243.64.30/auth-detail-20050428
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from
auth_log (rlm_detail) for request 34
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "auth_log"
returns ok for request 34
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling mschap
(rlm_mschap) for request 34
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from mschap
(rlm_mschap) for request 34
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "mschap"
returns noop for request 34
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling suffix
(rlm_realm) for request 34
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Looking up realm "wlan.lan"
for User-Name = "[EMAIL PROTECTED]"
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Found realm "wlan.lan"
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Adding Stripped-User-Name =
"www"
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Proxying request from user
www to realm wlan.lan
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Adding Realm = "wlan.lan"
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Authentication realm is
LOCAL.
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from suffix
(rlm_realm) for request 34
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "suffix"
returns noop for request 34
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 34
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: EAP packet type response id 2
length 17
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: No EAP Start, assuming it's an
on-going EAP conversation
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from eap
(rlm_eap) for request 34
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "eap" returns
updated for request 34
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling files
(rlm_files) for request 34
Thu Apr 28 11:34:23 2005 : Debug: users: Matched entry www at line 228
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from files
(rlm_files) for request 34
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "files" returns
ok for request 34
Thu Apr 28 11:34:23 2005 : Debug: modcall: group authorize returns updated for
request 34
Thu Apr 28 11:34:23 2005 : Debug: rad_check_password: Found Auth-Type EAP
Thu Apr 28 11:34:23 2005 : Debug: auth: type "EAP"
Thu Apr 28 11:34:23 2005 : Debug: Processing the authenticate section of
radiusd.conf
Thu Apr 28 11:34:23 2005 : Debug: modcall: entering group authenticate for
request 34
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authenticate]: calling eap
(rlm_eap) for request 34
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: EAP Identity
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: processing type tls
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap_tls: Initiate
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap_tls: Start returned 1
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authenticate]: returned from eap
(rlm_eap) for request 34
Thu Apr 28 11:34:23 2005 : Debug: modcall[authenticate]: module "eap"
returns handled for request 34
Thu Apr 28 11:34:23 2005 : Debug: modcall: group authenticate returns handled
for request 34
Sending Access-Challenge of id 142 to 80.243.64.30:14123
EAP-Message = 0x010300061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6df9addca8a82819895f70427f8105e3
Thu Apr 28 11:34:23 2005 : Debug: Finished request 34
Thu Apr 28 11:34:23 2005 : Debug: Going to the next request
Thu Apr 28 11:34:23 2005 : Debug: --- Walking the entire request list ---
Thu Apr 28 11:34:23 2005 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 80.243.64.30:14123, id=143,
length=255
User-Name = "[EMAIL PROTECTED]"
Framed-MTU = 1400
Called-Station-Id = "000d.edc3.08aa"
Calling-Station-Id = "000c.f154.0bf7"
Service-Type = Login-User
Message-Authenticator = 0x98a8fe5fbdd2927184fa0891c5cc0164
EAP-Message =
0x0203007019800000006616030100610100005d030142702f94a38e6bee104cece88b71e2e5fd9d4fb9c75dd054698d3313b8e42e7f20ae9772b28d62cd2ea2a2ab83075a7269abd81d011ba6e0b1c1bd9b71a9c00f2c001600040005000a000900640062000300060013001200630100
NAS-Port-Type = Wireless-802.11
NAS-Port = 398
State = 0x6df9addca8a82819895f70427f8105e3
NAS-IP-Address = 192.168.104.68
NAS-Identifier = "vntc-ka"
Thu Apr 28 11:34:23 2005 : Debug: Processing the authorize section of
radiusd.conf
Thu Apr 28 11:34:23 2005 : Debug: modcall: entering group authorize for
request 35
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling preprocess
(rlm_preprocess) for request 35
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from
preprocess (rlm_preprocess) for request 35
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "preprocess"
returns ok for request 35
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling auth_log
(rlm_detail) for request 35
Thu Apr 28 11:34:23 2005 : Debug: radius_xlat:
'/usr/local/var/log/radius/radacct/80.243.64.30/auth-detail-20050428'
Thu Apr 28 11:34:23 2005 : Debug: rlm_detail:
/usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to
/usr/local/var/log/radius/radacct/80.243.64.30/auth-detail-20050428
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from
auth_log (rlm_detail) for request 35
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "auth_log"
returns ok for request 35
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling mschap
(rlm_mschap) for request 35
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from mschap
(rlm_mschap) for request 35
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "mschap"
returns noop for request 35
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling suffix
(rlm_realm) for request 35
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Looking up realm "wlan.lan"
for User-Name = "[EMAIL PROTECTED]"
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Found realm "wlan.lan"
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Adding Stripped-User-Name =
"www"
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Proxying request from user
www to realm wlan.lan
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Adding Realm = "wlan.lan"
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Authentication realm is
LOCAL.
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from suffix
(rlm_realm) for request 35
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "suffix"
returns noop for request 35
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 35
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: EAP packet type response id 3
length 112
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: No EAP Start, assuming it's an
on-going EAP conversation
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from eap
(rlm_eap) for request 35
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "eap" returns
updated for request 35
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling files
(rlm_files) for request 35
Thu Apr 28 11:34:23 2005 : Debug: users: Matched entry www at line 228
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from files
(rlm_files) for request 35
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "files" returns
ok for request 35
Thu Apr 28 11:34:23 2005 : Debug: modcall: group authorize returns updated for
request 35
Thu Apr 28 11:34:23 2005 : Debug: rad_check_password: Found Auth-Type EAP
Thu Apr 28 11:34:23 2005 : Debug: auth: type "EAP"
Thu Apr 28 11:34:23 2005 : Debug: Processing the authenticate section of
radiusd.conf
Thu Apr 28 11:34:23 2005 : Debug: modcall: entering group authenticate for
request 35
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authenticate]: calling eap
(rlm_eap) for request 35
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: Request found, released from the
list
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: EAP/peap
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: processing type peap
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap_peap: Authenticate
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap_tls: processing TLS
Thu Apr 28 11:34:23 2005 : Info: rlm_eap_tls: Length Included
Thu Apr 28 11:34:23 2005 : Debug: eaptls_verify returned 11
Thu Apr 28 11:34:23 2005 : Info: (other): before/accept initialization
Thu Apr 28 11:34:23 2005 : Info: TLS_accept: before/accept initialization
Thu Apr 28 11:34:23 2005 : Info: TLS_accept: SSLv3 read client hello A
Thu Apr 28 11:34:23 2005 : Info: TLS_accept: SSLv3 write server hello A
Thu Apr 28 11:34:23 2005 : Info: TLS_accept: SSLv3 write change cipher
spec A
Thu Apr 28 11:34:23 2005 : Info: TLS_accept: SSLv3 write finished A
Thu Apr 28 11:34:23 2005 : Info: TLS_accept: SSLv3 flush data
Thu Apr 28 11:34:23 2005 : Error: TLS_accept:error in SSLv3 read finished
A
Thu Apr 28 11:34:23 2005 : Debug: In SSL Handshake Phase
Thu Apr 28 11:34:23 2005 : Debug: In SSL Accept mode
Thu Apr 28 11:34:23 2005 : Debug: eaptls_process returned 13
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap_peap: EAPTLS_HANDLED
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authenticate]: returned from eap
(rlm_eap) for request 35
Thu Apr 28 11:34:23 2005 : Debug: modcall[authenticate]: module "eap"
returns handled for request 35
Thu Apr 28 11:34:23 2005 : Debug: modcall: group authenticate returns handled
for request 35
Sending Access-Challenge of id 143 to 80.243.64.30:14123
EAP-Message =
0x010400801900160301004a02000046030142702f8f44048c4be6bd709fa9e9aadd0c79bcae83b1e65089d7f121bfc9022320ae9772b28d62cd2ea2a2ab83075a7269abd81d011ba6e0b1c1bd9b71a9c00f2c0004001403010001011603010020ba5d2f6f5d30239514668f8d47b7df522bb63bea78380d3c634d448baff4f976
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x6243c7b4efd1d30ced2c7d83ab4aa0ef
Thu Apr 28 11:34:23 2005 : Debug: Finished request 35
Thu Apr 28 11:34:23 2005 : Debug: Going to the next request
Thu Apr 28 11:34:23 2005 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 80.243.64.30:14123, id=144,
length=196
User-Name = "[EMAIL PROTECTED]"
Framed-MTU = 1400
Called-Station-Id = "000d.edc3.08aa"
Calling-Station-Id = "000c.f154.0bf7"
Service-Type = Login-User
Message-Authenticator = 0x3b49197a86b1104c4d495398817d3671
EAP-Message =
0x0204003519800000002b1403010001011603010020367a53a1c72ddd8b82add38ad2cda97669d15239004975409c393bfb21f3eb38
NAS-Port-Type = Wireless-802.11
NAS-Port = 398
State = 0x6243c7b4efd1d30ced2c7d83ab4aa0ef
NAS-IP-Address = 192.168.104.68
NAS-Identifier = "vntc-ka"
Thu Apr 28 11:34:23 2005 : Debug: Processing the authorize section of
radiusd.conf
Thu Apr 28 11:34:23 2005 : Debug: modcall: entering group authorize for
request 36
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling preprocess
(rlm_preprocess) for request 36
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from
preprocess (rlm_preprocess) for request 36
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "preprocess"
returns ok for request 36
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling auth_log
(rlm_detail) for request 36
Thu Apr 28 11:34:23 2005 : Debug: radius_xlat:
'/usr/local/var/log/radius/radacct/80.243.64.30/auth-detail-20050428'
Thu Apr 28 11:34:23 2005 : Debug: rlm_detail:
/usr/local/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d
expands to
/usr/local/var/log/radius/radacct/80.243.64.30/auth-detail-20050428
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from
auth_log (rlm_detail) for request 36
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "auth_log"
returns ok for request 36
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling mschap
(rlm_mschap) for request 36
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from mschap
(rlm_mschap) for request 36
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "mschap"
returns noop for request 36
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling suffix
(rlm_realm) for request 36
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Looking up realm "wlan.lan"
for User-Name = "[EMAIL PROTECTED]"
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Found realm "wlan.lan"
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Adding Stripped-User-Name =
"www"
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Proxying request from user
www to realm wlan.lan
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Adding Realm = "wlan.lan"
Thu Apr 28 11:34:23 2005 : Debug: rlm_realm: Authentication realm is
LOCAL.
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from suffix
(rlm_realm) for request 36
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "suffix"
returns noop for request 36
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 36
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: EAP packet type response id 4
length 53
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: No EAP Start, assuming it's an
on-going EAP conversation
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from eap
(rlm_eap) for request 36
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "eap" returns
updated for request 36
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: calling files
(rlm_files) for request 36
Thu Apr 28 11:34:23 2005 : Debug: users: Matched entry www at line 228
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authorize]: returned from files
(rlm_files) for request 36
Thu Apr 28 11:34:23 2005 : Debug: modcall[authorize]: module "files" returns
ok for request 36
Thu Apr 28 11:34:23 2005 : Debug: modcall: group authorize returns updated for
request 36
Thu Apr 28 11:34:23 2005 : Debug: rad_check_password: Found Auth-Type EAP
Thu Apr 28 11:34:23 2005 : Debug: auth: type "EAP"
Thu Apr 28 11:34:23 2005 : Debug: Processing the authenticate section of
radiusd.conf
Thu Apr 28 11:34:23 2005 : Debug: modcall: entering group authenticate for
request 36
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authenticate]: calling eap
(rlm_eap) for request 36
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: Request found, released from the
list
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: EAP/peap
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: processing type peap
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap_peap: Authenticate
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap_tls: processing TLS
Thu Apr 28 11:34:23 2005 : Info: rlm_eap_tls: Length Included
Thu Apr 28 11:34:23 2005 : Debug: eaptls_verify returned 11
Thu Apr 28 11:34:23 2005 : Info: TLS_accept: SSLv3 read finished A
Thu Apr 28 11:34:23 2005 : Info: (other): SSL negotiation finished
successfully
Thu Apr 28 11:34:23 2005 : Debug: SSL Connection Established
Thu Apr 28 11:34:23 2005 : Debug: eaptls_process returned 13
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap_peap: EAPTLS_HANDLED
Thu Apr 28 11:34:23 2005 : Debug: rlm_eap: Freeing handler
Thu Apr 28 11:34:23 2005 : Debug: modsingle[authenticate]: returned from eap
(rlm_eap) for request 36
Thu Apr 28 11:34:23 2005 : Debug: modcall[authenticate]: module "eap"
returns reject for request 36
Thu Apr 28 11:34:23 2005 : Debug: modcall: group authenticate returns reject
for request 36
Thu Apr 28 11:34:23 2005 : Debug: auth: Failed to validate the user.
Thu Apr 28 11:34:23 2005 : Debug: Delaying request 36 for 1 seconds
Thu Apr 28 11:34:23 2005 : Debug: Finished request 36
Thu Apr 28 11:34:23 2005 : Debug: Going to the next request
Thu Apr 28 11:34:23 2005 : Debug: Waking up in 6 seconds...
rad_recv: Access-Request packet from host 80.243.64.30:14123, id=144,
length=196
Sending Access-Reject of id 144 to 80.243.64.30:14123
EAP-Message = 0x04040004
Message-Authenticator = 0x00000000000000000000000000000000
Thu Apr 28 11:34:29 2005 : Debug: --- Walking the entire request list ---
Thu Apr 28 11:34:29 2005 : Debug: Cleaning up request 34 ID 142 with timestamp
42702f8f
Thu Apr 28 11:34:29 2005 : Debug: Cleaning up request 35 ID 143 with timestamp
42702f8f
Thu Apr 28 11:34:29 2005 : Debug: Cleaning up request 36 ID 144 with timestamp
42702f8f
Thu Apr 28 11:34:29 2005 : Debug: Nothing to do. Sleeping until we see a
request.
----------
Regards, Sergey.
------------------------------------------
Sergey A. Guriev
Organization: New Telephone Company
e-mail: [EMAIL PROTECTED]
------------------------------------------
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
