Problem with Vista EAP-PEAP Authentication
debug afone
debug at afone.com
Tue Jan 22 17:24:29 CET 2008
Hi,
Yes, Freeradius has been compiled with freeradius.org sources.
You'll find below the end of Freeradius debug output :
Tue Jan 22 17:18:48 2008 : Debug: Thread 4 handling request 3, (1 handled so
far)
User-Name = "nsouleman"
NAS-IP-Address = 10.40.0.114
Connect-Info = "CONNECT 802.11"
Called-Station-Id = "000fb5905b7e"
Calling-Station-Id = "0019d2ae409a"
NAS-Identifier = "ap"
NAS-Port-Type = Wireless-802.11
NAS-Port = 32
NAS-Port-Id = "32"
Framed-MTU = 1400
State = 0x4d65e25317851beaa7122ab0f6d7758f
EAP-Message = 0x020400061900
Message-Authenticator = 0x5fe3280798b9c0bf7eb60427ac59acac
Tue Jan 22 17:18:48 2008 : Debug: Processing the authorize section of
radiusd.conf
Tue Jan 22 17:18:48 2008 : Debug: modcall: entering group authorize for
request 3
Tue Jan 22 17:18:48 2008 : Debug: modsingle[authorize]: calling preprocess
(rlm_preprocess) for request 3
Tue Jan 22 17:18:48 2008 : Debug: modsingle[authorize]: returned from
preprocess (rlm_preprocess) for request 3
Tue Jan 22 17:18:48 2008 : Debug: modcall[authorize]: module "preprocess"
returns ok for request 3
Tue Jan 22 17:18:48 2008 : Debug: modsingle[authorize]: calling auth_log
(rlm_detail) for request 3
Tue Jan 22 17:18:48 2008 : Debug: radius_xlat:
'/usr/local/freeradius-1.1.6/var/log/radius/radacct/10.40.0.114/auth-detail-
20080122'
Tue Jan 22 17:18:48 2008 : Debug: rlm_detail:
/usr/local/freeradius-1.1.6/var/log/radius/radacct/%{Client-IP-Address}/auth
-detail-%Y%m%d expands to
/usr/locaar/log/radius/radacct/10.40.0.114/auth-detail-20080122
Tue Jan 22 17:18:48 2008 : Debug: modsingle[authorize]: returned from
auth_log (rlm_detail) for request 3
Tue Jan 22 17:18:48 2008 : Debug: modcall[authorize]: module "auth_log"
returns ok for request 3
Tue Jan 22 17:18:48 2008 : Debug: modsingle[authorize]: calling chap
(rlm_chap) for request 3
Tue Jan 22 17:18:48 2008 : Debug: modsingle[authorize]: returned from chap
(rlm_chap) for request 3
Tue Jan 22 17:18:48 2008 : Debug: modcall[authorize]: module "chap"
returns noop for request 3
Tue Jan 22 17:18:48 2008 : Debug: modsingle[authorize]: calling mschap
(rlm_mschap) for request 3
Tue Jan 22 17:18:48 2008 : Debug: modsingle[authorize]: returned from
mschap (rlm_mschap) for request 3
Tue Jan 22 17:18:48 2008 : Debug: modcall[authorize]: module "mschap"
returns noop for request 3
Tue Jan 22 17:18:48 2008 : Debug: modsingle[authorize]: calling eap
(rlm_eap) for request 3
Tue Jan 22 17:18:48 2008 : Debug: rlm_eap: EAP packet type response id 4
length 6
Tue Jan 22 17:18:48 2008 : Debug: rlm_eap: No EAP Start, assuming it's an
on-going EAP conversation
Tue Jan 22 17:18:48 2008 : Debug: modsingle[authorize]: returned from eap
(rlm_eap) for request 3
Tue Jan 22 17:18:48 2008 : Debug: modcall[authorize]: module "eap" returns
updated for request 3
Tue Jan 22 17:18:48 2008 : Debug: modsingle[authorize]: calling ldap
(rlm_ldap) for request 3
Tue Jan 22 17:18:48 2008 : Debug: rlm_ldap: - authorize
Tue Jan 22 17:18:48 2008 : Debug: rlm_ldap: performing user authorization
for nsouleman
Tue Jan 22 17:18:48 2008 : Debug: radius_xlat:
'(&(objectclass=posixAccount)(uid=nsouleman))'
Tue Jan 22 17:18:48 2008 : Debug: radius_xlat:
'ou=Users,dc=angers,dc=afone,dc=fr'
Tue Jan 22 17:18:48 2008 : Debug: rlm_ldap: ldap_get_conn: Checking Id: 0
Tue Jan 22 17:18:48 2008 : Debug: rlm_ldap: ldap_get_conn: Got Id: 0
Tue Jan 22 17:18:48 2008 : Debug: rlm_ldap: performing search in
ou=Users,dc=angers,dc=afone,dc=fr, with filter
(&(objectclass=posixAccount)(uid=nsouleman))
Tue Jan 22 17:18:48 2008 : Debug: rlm_ldap: Added password xxxxxxx in check
items
Tue Jan 22 17:18:48 2008 : Debug: rlm_ldap: looking for check items in
directory...
Tue Jan 22 17:18:48 2008 : Debug: rlm_ldap: Adding sambaNTPassword as
NT-Password, value 06ED974D43A7B40ACF5F9798C7060A4B & op=21
Tue Jan 22 17:18:48 2008 : Debug: rlm_ldap: Adding sambaLMPassword as
LM-Password, value 2C720756F237E37AAAD3B435B51404EE & op=21
Tue Jan 22 17:18:48 2008 : Debug: rlm_ldap: looking for reply items in
directory...
Tue Jan 22 17:18:48 2008 : Debug: rlm_ldap: user nsouleman authorized to use
remote access
Tue Jan 22 17:18:48 2008 : Debug: rlm_ldap: ldap_release_conn: Release Id: 0
Tue Jan 22 17:18:48 2008 : Debug: modsingle[authorize]: returned from ldap
(rlm_ldap) for request 3
Tue Jan 22 17:18:48 2008 : Debug: modcall[authorize]: module "ldap"
returns ok for request 3
Tue Jan 22 17:18:48 2008 : Debug: modcall: leaving group authorize (returns
updated) for request 3
Tue Jan 22 17:18:48 2008 : Debug: rad_check_password: Found Auth-Type EAP
Tue Jan 22 17:18:48 2008 : Debug: auth: type "EAP"
Tue Jan 22 17:18:48 2008 : Debug: Processing the authenticate section of
radiu
Tue Jan 22 17:18:48 2008 : Debug: modcall: entering group authenticate for
reque
Tue Jan 22 17:18:48 2008 : Debug: modsingle[authenticate]: calling eap
(rlm_ea
Tue Jan 22 17:18:48 2008 : Debug: rlm_eap: Request found, released from
the li
Tue Jan 22 17:18:48 2008 : Debug: rlm_eap: EAP/peap
Tue Jan 22 17:18:48 2008 : Debug: rlm_eap: processing type peap
Tue Jan 22 17:18:48 2008 : Debug: rlm_eap_peap: Authenticate
Tue Jan 22 17:18:48 2008 : Debug: rlm_eap_tls: processing TLS
Tue Jan 22 17:18:48 2008 : Debug: rlm_eap_tls: Received EAP-TLS ACK message
Tue Jan 22 17:18:48 2008 : Debug: rlm_eap_tls: ack handshake fragment
handler
Tue Jan 22 17:18:48 2008 : Debug: eaptls_verify returned 1
Tue Jan 22 17:18:48 2008 : Debug: eaptls_process returned 13
Tue Jan 22 17:18:48 2008 : Debug: rlm_eap_peap: EAPTLS_HANDLED
Tue Jan 22 17:18:48 2008 : Debug: modsingle[authenticate]: returned from
eap (
Tue Jan 22 17:18:48 2008 : Debug: modcall[authenticate]: module "eap"
returns
Tue Jan 22 17:18:48 2008 : Debug: modcall: leaving group authenticate
(returns h
Sending Access-Challenge of id 155 to 10.40.0.114 port 1073
EAP-Message = 0x010500061900
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x4ad057184faa4b804f88ebf214d9cbe0
Tue Jan 22 17:18:48 2008 : Debug: Finished request 3
Tue Jan 22 17:18:48 2008 : Debug: Going to the next request
Tue Jan 22 17:18:48 2008 : Debug: Thread 4 waiting to be assigned a request
Tue Jan 22 17:19:19 2008 : Debug: --- Walking the entire request list ---
Tue Jan 22 17:19:19 2008 : Debug: Cleaning up request 0 ID 152 with
timestamp 47961768
Tue Jan 22 17:19:19 2008 : Debug: Cleaning up request 1 ID 153 with
timestamp 47961768
Tue Jan 22 17:19:19 2008 : Debug: Cleaning up request 2 ID 154 with
timestamp 47961768
Tue Jan 22 17:19:19 2008 : Debug: Cleaning up request 3 ID 155 with
timestamp 47961768
Tue Jan 22 17:19:19 2008 : Debug: Nothing to do. Sleeping until we see a
request.
More information about the Freeradius-Users
mailing list