No I don't.
thanks Mike.
-=Bill
Michael Griego wrote:
Umm... dumb question, but you don't have "eap" listed in the authenticate section of your radiusd.conf file twice do you?
--Mike
On Wed, 2003-11-19 at 12:31, Bill Reid wrote:
Hey everyone,
I continue to have a problem using peap with freeradius-snapshot-20031110. From what I have read about EAP, and from my discussions with others on this list, I believe I am seeing a problem from freeradius.
Please correct me if I am wrong.
According to the documentation in ./doc/rlm_eap. The client is not responding to step 6 "Access Challenge" from the radius server. I can see the Radius packet making it to the client. The only thing I can find that is odd about the challenge is that there are two eap portions of the frame. My hope is that the client is ignoring the frame because of this.
Since there is no response from the client(supplicant) I do not get an EAP-Success/EAP-failure and begin to negotiate any ssl/wep stuff. So I don't even think I am verifying the server using the installed CERT at this point. In other words, I don't suspect I have a key/cert problem yet :).
I have included the frames in this email. They were captured on the radius server side. Note there are two separate attempts from the client to authenticate itself. I am questioning either of the Access Challenge frames. I would love it if someone could look at these frames and tell me if they are correct (that freeradius is creating them properly).
Below the message Authenticator is similar to 0x000000000000000000. In the frame sent to the supplicant, the second portion EAP type 79 does not have the authenticator, the first portion EAP type 79 does have the Message Authenticator and is filled with a value other then 0x000000000..... I am guessing that is where the hash for the password goes.
Any help would be greatly appreciated.
Here is the output of radiusd -Xxx
Tue Nov 18 14:52:33 2003 : Info: Starting - reading configuration files ...
Tue Nov 18 14:52:33 2003 : Debug: reread_config: reading radiusd.conf
Tue Nov 18 14:52:33 2003 : Debug: Config: including file: /usr/local/etc/raddb/clients.conf
Tue Nov 18 14:52:33 2003 : Debug: Config: including file: /usr/local/etc/raddb/snmp.conf
Tue Nov 18 14:52:33 2003 : Debug: main: prefix = "/usr/local"
Tue Nov 18 14:52:33 2003 : Debug: main: localstatedir = "/usr/local/var"
Tue Nov 18 14:52:33 2003 : Debug: main: logdir = "/var/log/radius"
Tue Nov 18 14:52:33 2003 : Debug: main: libdir = "/usr/local/lib"
Tue Nov 18 14:52:33 2003 : Debug: main: radacctdir = "/var/log/radius/radacct"
Tue Nov 18 14:52:33 2003 : Debug: main: hostname_lookups = no
Tue Nov 18 14:52:33 2003 : Debug: main: max_request_time = 30
Tue Nov 18 14:52:33 2003 : Debug: main: cleanup_delay = 5
Tue Nov 18 14:52:33 2003 : Debug: main: max_requests = 1024
Tue Nov 18 14:52:33 2003 : Debug: main: delete_blocked_requests = 0
Tue Nov 18 14:52:33 2003 : Debug: main: port = 0
Tue Nov 18 14:52:33 2003 : Debug: main: allow_core_dumps = no
Tue Nov 18 14:52:33 2003 : Debug: main: log_stripped_names = no
Tue Nov 18 14:52:33 2003 : Debug: main: log_file = "/var/log/radius/radius.log"
Tue Nov 18 14:52:33 2003 : Debug: main: log_auth = yes
Tue Nov 18 14:52:33 2003 : Debug: main: log_auth_badpass = yes
Tue Nov 18 14:52:33 2003 : Debug: main: log_auth_goodpass = no
Tue Nov 18 14:52:33 2003 : Debug: main: pidfile = "/usr/local/var/run/radiusd/radiusd.pid"
Tue Nov 18 14:52:33 2003 : Debug: main: user = "(null)"
Tue Nov 18 14:52:33 2003 : Debug: main: group = "(null)"
Tue Nov 18 14:52:33 2003 : Debug: main: usercollide = yes
Tue Nov 18 14:52:33 2003 : Debug: main: lower_user = "before"
Tue Nov 18 14:52:33 2003 : Debug: main: lower_pass = "no"
Tue Nov 18 14:52:33 2003 : Debug: main: nospace_user = "no"
Tue Nov 18 14:52:33 2003 : Debug: main: nospace_pass = "no"
Tue Nov 18 14:52:33 2003 : Debug: main: checkrad = "/usr/local/sbin/checkrad"
Tue Nov 18 14:52:33 2003 : Debug: main: proxy_requests = no
Tue Nov 18 14:52:33 2003 : Debug: security: max_attributes = 200
Tue Nov 18 14:52:33 2003 : Debug: security: reject_delay = 1
Tue Nov 18 14:52:33 2003 : Debug: security: status_server = no
Tue Nov 18 14:52:33 2003 : Debug: main: debug_level = 0
Tue Nov 18 14:52:33 2003 : Debug: read_config_files: reading dictionary
Tue Nov 18 14:52:34 2003 : Debug: read_config_files: reading naslist
Tue Nov 18 14:52:34 2003 : Info: Using deprecated naslist file. Support for this will go away soon.
Tue Nov 18 14:52:34 2003 : Debug: read_config_files: reading clients
Tue Nov 18 14:52:34 2003 : Debug: read_config_files: reading realms
Tue Nov 18 14:52:34 2003 : Info: Using deprecated realms file. Support for this will go away soon.
Tue Nov 18 14:52:34 2003 : Debug: radiusd: entering modules setup
Tue Nov 18 14:52:34 2003 : Debug: Module: Library search path is /usr/local/lib
Tue Nov 18 14:52:34 2003 : Debug: Module: Loaded expr
Tue Nov 18 14:52:34 2003 : Debug: Module: Instantiated expr (expr)
Tue Nov 18 14:52:34 2003 : Debug: Module: Loaded eap
Tue Nov 18 14:52:34 2003 : Debug: eap: default_eap_type = "peap"
Tue Nov 18 14:52:34 2003 : Debug: eap: timer_expire = 60
Tue Nov 18 14:52:34 2003 : Debug: eap: ignore_unknown_eap_types = no
Tue Nov 18 14:52:34 2003 : Debug: tls: rsa_key_exchange = no
Tue Nov 18 14:52:34 2003 : Debug: tls: dh_key_exchange = yes
Tue Nov 18 14:52:34 2003 : Debug: tls: rsa_key_length = 512
Tue Nov 18 14:52:34 2003 : Debug: tls: dh_key_length = 512
Tue Nov 18 14:52:34 2003 : Debug: tls: verify_depth = 0
Tue Nov 18 14:52:34 2003 : Debug: tls: CA_path = "/usr/local/etc/raddb/cert/demoCA"
Tue Nov 18 14:52:34 2003 : Debug: tls: pem_file_type = yes
Tue Nov 18 14:52:34 2003 : Debug: tls: private_key_file = "/usr/local/etc/raddb/hotspot.ntelos.net.key"
Tue Nov 18 14:52:34 2003 : Debug: tls: certificate_file = "/usr/local/etc/raddb/hotspot.ntelos.net.crt"
Tue Nov 18 14:52:34 2003 : Debug: tls: CA_file = "/usr/local/etc/raddb/ntelos.cacrt"
Tue Nov 18 14:52:34 2003 : Debug: tls: private_key_password = "testtest"
Tue Nov 18 14:52:34 2003 : Debug: tls: dh_file = "/usr/local/etc/raddb/my_imap.dh"
Tue Nov 18 14:52:34 2003 : Debug: tls: random_file = "/usr/local/etc/raddb/random"
Tue Nov 18 14:52:34 2003 : Debug: tls: fragment_size = 1024
Tue Nov 18 14:52:34 2003 : Debug: tls: include_length = no
Tue Nov 18 14:52:34 2003 : Debug: tls: check_crl = no
Tue Nov 18 14:52:34 2003 : Debug: rlm_eap: Loaded and initialized type tls
Tue Nov 18 14:52:34 2003 : Debug: peap: default_eap_type = "mschapv2"
Tue Nov 18 14:52:34 2003 : Debug: peap: copy_request_to_tunnel = no
Tue Nov 18 14:52:34 2003 : Debug: peap: use_tunneled_reply = no
Tue Nov 18 14:52:34 2003 : Debug: rlm_eap: Loaded and initialized type peap
Tue Nov 18 14:52:34 2003 : Debug: rlm_eap: Loaded and initialized type mschapv2
Tue Nov 18 14:52:34 2003 : Debug: Module: Instantiated eap (eap)
Tue Nov 18 14:52:34 2003 : Debug: Module: Loaded PAP
Tue Nov 18 14:52:34 2003 : Debug: pap: encryption_scheme = "crypt"
Tue Nov 18 14:52:34 2003 : Debug: Module: Instantiated pap (pap)
Tue Nov 18 14:52:34 2003 : Debug: Module: Loaded CHAP
Tue Nov 18 14:52:34 2003 : Debug: Module: Instantiated chap (chap)
Tue Nov 18 14:52:34 2003 : Debug: Module: Loaded MS-CHAP
Tue Nov 18 14:52:34 2003 : Debug: mschap: use_mppe = yes
Tue Nov 18 14:52:34 2003 : Debug: mschap: require_encryption = no
Tue Nov 18 14:52:34 2003 : Debug: mschap: require_strong = yes
Tue Nov 18 14:52:34 2003 : Debug: mschap: passwd = "(null)"
Tue Nov 18 14:52:34 2003 : Debug: mschap: authtype = "MS-CHAP"
Tue Nov 18 14:52:34 2003 : Debug: Module: Instantiated mschap (mschap)
Tue Nov 18 14:52:34 2003 : Debug: Module: Loaded preprocess
Tue Nov 18 14:52:34 2003 : Debug: preprocess: huntgroups = "/usr/local/etc/raddb/huntgroups"
Tue Nov 18 14:52:34 2003 : Debug: preprocess: hints = "/usr/local/etc/raddb/hints"
Tue Nov 18 14:52:34 2003 : Debug: preprocess: with_ascend_hack = no
Tue Nov 18 14:52:34 2003 : Debug: preprocess: ascend_channels_per_line = 23
Tue Nov 18 14:52:34 2003 : Debug: preprocess: with_ntdomain_hack = yes
Tue Nov 18 14:52:34 2003 : Debug: preprocess: with_specialix_jetstream_hack = no
Tue Nov 18 14:52:34 2003 : Debug: preprocess: with_cisco_vsa_hack = yes
Tue Nov 18 14:52:34 2003 : Debug: Module: Instantiated preprocess (preprocess)
Tue Nov 18 14:52:34 2003 : Debug: Module: Loaded detail
Tue Nov 18 14:52:34 2003 : Debug: detail: detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/auth-detail
-%Y%m%d"
Tue Nov 18 14:52:34 2003 : Debug: detail: detailperm = 384
Tue Nov 18 14:52:34 2003 : Debug: detail: dirperm = 493
Tue Nov 18 14:52:34 2003 : Debug: detail: locking = no
Tue Nov 18 14:52:34 2003 : Debug: Module: Instantiated detail (auth_log)
Tue Nov 18 14:52:34 2003 : Debug: Module: Loaded realm
Tue Nov 18 14:52:34 2003 : Debug: realm: format = "suffix"
Tue Nov 18 14:52:34 2003 : Debug: realm: delimiter = "@"
Tue Nov 18 14:52:34 2003 : Debug: Module: Instantiated realm (suffix)
Tue Nov 18 14:52:34 2003 : Debug: Module: Loaded files
Tue Nov 18 14:52:34 2003 : Debug: files: usersfile = "/usr/local/etc/raddb/users"
Tue Nov 18 14:52:34 2003 : Debug: files: acctusersfile = "/usr/local/etc/raddb/acct_users"
Tue Nov 18 14:52:34 2003 : Debug: files: preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users"
Tue Nov 18 14:52:34 2003 : Debug: files: compat = "no"
Tue Nov 18 14:52:34 2003 : Debug: Module: Instantiated files (files)
Tue Nov 18 14:52:34 2003 : Debug: Module: Loaded Acct-Unique-Session-Id
Tue Nov 18 14:52:34 2003 : Debug: acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Addr
ess, NAS-Port-Id"
Tue Nov 18 14:52:34 2003 : Debug: Module: Instantiated acct_unique (acct_unique)
Tue Nov 18 14:52:34 2003 : Debug: detail: detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m
%d"
Tue Nov 18 14:52:34 2003 : Debug: detail: detailperm = 384
Tue Nov 18 14:52:34 2003 : Debug: detail: dirperm = 493
Tue Nov 18 14:52:34 2003 : Debug: detail: locking = no
Tue Nov 18 14:52:34 2003 : Debug: Module: Instantiated detail (detail)
Tue Nov 18 14:52:34 2003 : Info: Listening on IP address *, ports 1812/udp and 1813/udp.
Tue Nov 18 14:52:34 2003 : Info: Ready to process requests.
rad_recv: Access-Request packet from host xxx.xx.xx.xx:3478, id=0, length=151
User-Name = "wer"
Cisco-AVPair = "ssid=Ntelos_AP_01"
NAS-IP-Address = xxx.xx.xx.30
Called-Station-Id = "000dbda1f1e9"
Calling-Station-Id = "000dbd05196d"
NAS-Identifier = "AP1200-a1f1e9"
NAS-Port = 37
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Service-Type = Login-User
EAP-Message = 0x0204000801776572
Message-Authenticator = 0xd2b26a05cb73ad0a4fc147eb2d3185cb
Tue Nov 18 16:27:46 2003 : Debug: rad_lowerpair: User-Name now 'wer'
Tue Nov 18 16:27:46 2003 : Debug: modcall: entering group authorize for request 0
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0
Tue Nov 18 16:27:46 2003 : Debug: modcall[authorize]: module "preprocess" returns ok for request 0
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 0
Tue Nov 18 16:27:46 2003 : Debug: radius_xlat: '/var/log/radius/radacct/209.145.66.30/auth-detail-20031118'
Tue Nov 18 16:27:46 2003 : Debug: rlm_detail: /var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d exp
ands to /var/log/radius/radacct/209.145.66.30/auth-detail-20031118
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 0
Tue Nov 18 16:27:46 2003 : Debug: modcall[authorize]: module "auth_log" returns ok for request 0
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 0
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 0
Tue Nov 18 16:27:46 2003 : Debug: modcall[authorize]: module "chap" returns noop for request 0
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 0
Tue Nov 18 16:27:46 2003 : Debug: rlm_eap: EAP packet type response id 4 length 8
Tue Nov 18 16:27:46 2003 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 0
Tue Nov 18 16:27:46 2003 : Debug: modcall[authorize]: module "eap" returns updated for request 0
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 0
Tue Nov 18 16:27:46 2003 : Debug: rlm_realm: No '@' in User-Name = "wer", looking up realm NULL
Tue Nov 18 16:27:46 2003 : Debug: rlm_realm: No such realm "NULL"
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 0
Tue Nov 18 16:27:46 2003 : Debug: modcall[authorize]: module "suffix" returns noop for request 0
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authorize]: calling files (rlm_files) for request 0
Tue Nov 18 16:27:46 2003 : Debug: users: Checking wer at 107
Tue Nov 18 16:27:46 2003 : Debug: rad_check_password: Found Auth-Type EAP
Tue Nov 18 16:27:46 2003 : Debug: auth: type "EAP"
Tue Nov 18 16:27:46 2003 : Debug: modcall: entering group authenticate for request 0
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 0
Tue Nov 18 16:27:46 2003 : Debug: rlm_eap: EAP Identity
Tue Nov 18 16:27:46 2003 : Debug: rlm_eap: processing type tls
Tue Nov 18 16:27:46 2003 : Debug: rlm_eap_tls: Initiate
Tue Nov 18 16:27:46 2003 : Debug: rlm_eap_tls: Start returned 1
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 0
Tue Nov 18 16:27:46 2003 : Debug: modcall[authenticate]: module "eap" returns handled for request 0
Tue Nov 18 16:27:46 2003 : Debug: modcall: group authenticate returns handled for request 0
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 0
Tue Nov 18 16:27:46 2003 : Debug: modcall[authorize]: module "files" returns notfound for request 0
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 0
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 0
Tue Nov 18 16:27:46 2003 : Debug: modcall[authorize]: module "mschap" returns noop for request 0
Tue Nov 18 16:27:46 2003 : Debug: modcall: group authorize returns updated for request 0
Tue Nov 18 16:27:46 2003 : Debug: rad_check_password: Found Auth-Type EAP
Tue Nov 18 16:27:46 2003 : Debug: auth: type "EAP"
Tue Nov 18 16:27:46 2003 : Debug: modcall: entering group authenticate for request 0
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 0
Tue Nov 18 16:27:46 2003 : Debug: rlm_eap: EAP Identity
Tue Nov 18 16:27:46 2003 : Debug: rlm_eap: processing type tls
Tue Nov 18 16:27:46 2003 : Debug: rlm_eap_tls: Initiate
Tue Nov 18 16:27:46 2003 : Debug: rlm_eap_tls: Start returned 1
Tue Nov 18 16:27:46 2003 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 0
Tue Nov 18 16:27:46 2003 : Debug: modcall[authenticate]: module "eap" returns ok for request 0
Tue Nov 18 16:27:46 2003 : Debug: modcall: group authenticate returns ok for request 0
Tue Nov 18 16:27:46 2003 : Auth: Login OK: [wer] (from client vxworks port 37 cli 000dbd05196d)
Sending Access-Challenge of id 0 to xxx.xx.xx.30:3478
EAP-Message = 0x010500061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xdb2f1835ce2a00e92bb9c03a9c402f16
EAP-Message = 0x010500061920
State = 0xc0efdbdc7e50636cfbd37c5abdafdbbb
Tue Nov 18 16:27:46 2003 : Debug: Finished request 0
Tue Nov 18 16:27:46 2003 : Debug: Going to the next request
Tue Nov 18 16:27:46 2003 : Debug: --- Walking the entire request list ---
Tue Nov 18 16:27:46 2003 : Debug: Waking up in 6 seconds...
Tue Nov 18 16:27:52 2003 : Debug: --- Walking the entire request list ---
Tue Nov 18 16:27:52 2003 : Debug: Cleaning up request 0 ID 0 with timestamp 3fba8ed2
Tue Nov 18 16:27:52 2003 : Debug: Nothing to do. Sleeping until we see a request.
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
