- Freeradius-Users - lists.freeradius.org

acct copy
by Alexandre Chapellon 19 Feb '08

19 Feb '08

Hello all I come back with the same problem.... I don't want to annoy anybody but I'm still clueless. I use the fresh freeradius 2.0.2 as an accounting server (to a mysql database) but I have other server that must host accounting informations too (1 billing server and 2 for a content filtering product). I have tried to replicate my accouting data using copy-acct-to-home-server virtualhost: server copy-acct-to-home-server { listen { type = detail filename = ${radacctdir}/detail load_factor = 10 } preacct { suffix } while prior sql accouting is done by another virtual server that writes too the detail file (with the option locking = yes) used by copy-acct-to-home-server: server local_acct { accounting { detail_replic sql } } I have noticed that the detail file never gets read totaly (usually only one request) and so only few (most of the time one) requests get effectively proxied to the home server. I can't understand why... is it something contained in the request/response... I'm really clueless and would greatly appreciate any help. I have an addditionnal question.... will it be possible to copy accounting to 3 servers, and how? Thx

3 7

FR & Unix pws
by Lemaster, Rob 19 Feb '08

19 Feb '08

I read the passwd module in radiusd.conf, and I couldn't find how to enable clear-text passwords for authentication. Could you reply with a direct link or more specifics? 8 out of 11 dentists prefer FreeRADIUS over the leading brand for fresh breath and healthy gums. ------------------------- Lemaster, Rob wrote: > I am using FreeRADIUS v1.0.5 in a non-production lab environment. Well... I suggest upgrading. > What hashing algorithm is used to store passwords in passwd? $ man passwd i.e. whatever your system supports. > Does FreeRADIUS have an option to read passwords in clear text? Sure. See the "passwd" module && documentation in FreeRADIUS.> Is there an easy way to create hashed passwords from some Unix > command-line utility? The simplest is Apache's "htpasswd" program. > 4 out of 10 women surveyed think Alan DeKok is a sex magnet. Then they cry themselves to sleep at night. I'm not available. :( Alan DeKok.

2 1

EAP-PEAP-MS-CHAPv2: MS-CHAPv2 attributes discarded after proxying
by Dmitry Sergienko 18 Feb '08

18 Feb '08

Hi! I'm trying to setup the following scheme: [win_xp]-----[Wi-Fi AP with WPA]-------[FreeRADIUS]--------[home RADIUS server] FreeRADIUS: 1.1.7 Users being connected to access point must be authenticated against EAP-PEAP-MS-CHAPv2 protocol. Home RADIUS server can do only MS-CHAPv2 authorization and knows nothing about EAP. To pass extracted MS-CHAPv2 request from PEAP tunnel I've turned off proxy_tunneled_request_as_eap: ---------eap.conf------------- peap { default_eap_type = mschapv2 copy_request_to_tunnel = yes use_tunneled_reply = yes proxy_tunneled_request_as_eap = no } --------users----------------- aaa FreeRADIUS-Proxied-To == 127.0.0.1, Proxy-To-Realm := "xxx" Fall-Through := No --------proxy.conf------------ realm xxx { type = radius authhost = 192.168.2.80:1812 accthost = 192.168.2.80:1813 secret = pretty_secret } ------------------------------ Authorization requests are being proxied from FreeRADIUS to home RADIUS server as plain MS-CHAPv2. Home server authorizes client and passes back MS-MPPE-*-Keys. But FreeRADIUS discards all MS-CHAPv2 attributes from proxy reply just saying "rlm_eap_mschapv2: Authentication succeeded.". Here is the response from home server: rad_recv: Access-Accept packet from host 192.168.2.80:1812, id=0, length=262 Wed Jan 30 15:03:33 2008 : Debug: proxy: de-allocating 5002a8c0:1812 0 Reply-Message = "ACCESS: GRANTED" Reply-Message = "AGREEMENT-ID: 587986" Framed-IP-Address = 192.168.2.56 Framed-IP-Netmask = 255.255.255.255 Framed-Protocol = PPP MS-CHAP2-Success = 0x00533d37354142314531443945333538353133414541334245443244314630344333384533363742384232 MS-MPPE-Encryption-Policy = 0x00000001 MS-MPPE-Encryption-Types = 0x00000006 MS-MPPE-Recv-Key = 0xadfa59550658460011ffff6aee8df748 MS-MPPE-Send-Key = 0x2f62bd6b536d9e6141790bf5c477a5b8 Service-Type = Framed-User Reply-Message = "STATUS: 0.00000000" and the response to Wi-Fi AP before tunnel: PEAP: Final reply from tunneled session code 11 Reply-Message = "ACCESS: GRANTED" Reply-Message = "AGREEMENT-ID: 587986" Framed-IP-Address = 192.168.2.56 Framed-IP-Netmask = 255.255.255.255 Framed-Protocol = PPP Service-Type = Framed-User Reply-Message = "STATUS: 0.00000000" EAP-Message = 0x010700331a0306002e533d37354142314531443945333538353133414541334245443244314630344333384533363742384232 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xbb336a79c074253ad516aa753953f8aa There is no MS-CHAP2-Success attribute here. So no "rlm_eap_peap: Success" at the end of challenge and no Access-Accept packet being sent to Wi-Fi AP. When username is configured locally (i.e. with no proxying request to home server), everything works fine. Does anyone have such working scheme here? Please find complete log attached. -- Best wishes, Dmitry Sergienko (SDA104-RIPE) Trifle Co., Ltd. Wed Jan 30 16:21:17 2008 : Info: Starting - reading configuration files ... Wed Jan 30 16:21:17 2008 : Debug: reread_config: reading radiusd.conf Wed Jan 30 16:21:17 2008 : Debug: Config: including file: /etc/freeradius/proxy.conf Wed Jan 30 16:21:17 2008 : Debug: Config: including file: /etc/freeradius/clients.conf Wed Jan 30 16:21:17 2008 : Debug: Config: including file: /etc/freeradius/snmp.conf Wed Jan 30 16:21:17 2008 : Debug: Config: including file: /etc/freeradius/eap.conf Wed Jan 30 16:21:17 2008 : Debug: Config: including file: /etc/freeradius/sql.conf Wed Jan 30 16:21:17 2008 : Debug: main: prefix = "/usr" Wed Jan 30 16:21:17 2008 : Debug: main: localstatedir = "/var" Wed Jan 30 16:21:17 2008 : Debug: main: logdir = "/var/log/freeradius" Wed Jan 30 16:21:17 2008 : Debug: main: libdir = "/usr/lib/freeradius" Wed Jan 30 16:21:17 2008 : Debug: main: radacctdir = "/var/log/freeradius/radacct" Wed Jan 30 16:21:17 2008 : Debug: main: hostname_lookups = no Wed Jan 30 16:21:17 2008 : Debug: main: snmp = no Wed Jan 30 16:21:17 2008 : Debug: main: max_request_time = 30 Wed Jan 30 16:21:17 2008 : Debug: main: cleanup_delay = 5 Wed Jan 30 16:21:17 2008 : Debug: main: max_requests = 1024 Wed Jan 30 16:21:17 2008 : Debug: main: delete_blocked_requests = 0 Wed Jan 30 16:21:17 2008 : Debug: main: port = 0 Wed Jan 30 16:21:17 2008 : Debug: main: allow_core_dumps = no Wed Jan 30 16:21:17 2008 : Debug: main: log_stripped_names = no Wed Jan 30 16:21:17 2008 : Debug: main: log_file = "/var/log/freeradius/radius.log" Wed Jan 30 16:21:17 2008 : Debug: main: log_auth = no Wed Jan 30 16:21:17 2008 : Debug: main: log_auth_badpass = no Wed Jan 30 16:21:17 2008 : Debug: main: log_auth_goodpass = no Wed Jan 30 16:21:17 2008 : Debug: main: pidfile = "/var/run/freeradius/freeradius.pid" Wed Jan 30 16:21:17 2008 : Debug: main: user = "freerad" Wed Jan 30 16:21:17 2008 : Debug: main: group = "freerad" Wed Jan 30 16:21:17 2008 : Debug: main: usercollide = no Wed Jan 30 16:21:17 2008 : Debug: main: lower_user = "no" Wed Jan 30 16:21:17 2008 : Debug: main: lower_pass = "no" Wed Jan 30 16:21:17 2008 : Debug: main: nospace_user = "no" Wed Jan 30 16:21:17 2008 : Debug: main: nospace_pass = "no" Wed Jan 30 16:21:17 2008 : Debug: main: checkrad = "/usr/sbin/checkrad" Wed Jan 30 16:21:17 2008 : Debug: main: proxy_requests = yes Wed Jan 30 16:21:17 2008 : Debug: proxy: retry_delay = 5 Wed Jan 30 16:21:17 2008 : Debug: proxy: retry_count = 3 Wed Jan 30 16:21:17 2008 : Debug: proxy: synchronous = no Wed Jan 30 16:21:17 2008 : Debug: proxy: default_fallback = yes Wed Jan 30 16:21:17 2008 : Debug: proxy: dead_time = 120 Wed Jan 30 16:21:17 2008 : Debug: proxy: post_proxy_authorize = no Wed Jan 30 16:21:17 2008 : Debug: proxy: wake_all_if_all_dead = no Wed Jan 30 16:21:17 2008 : Debug: security: max_attributes = 200 Wed Jan 30 16:21:17 2008 : Debug: security: reject_delay = 1 Wed Jan 30 16:21:17 2008 : Debug: security: status_server = no Wed Jan 30 16:21:17 2008 : Debug: main: debug_level = 0 Wed Jan 30 16:21:17 2008 : Debug: read_config_files: reading dictionary Wed Jan 30 16:21:17 2008 : Debug: read_config_files: reading naslist Wed Jan 30 16:21:17 2008 : Debug: read_config_files: reading clients Wed Jan 30 16:21:17 2008 : Debug: read_config_files: reading realms Wed Jan 30 16:21:17 2008 : Debug: radiusd: entering modules setup Wed Jan 30 16:21:17 2008 : Debug: Module: Library search path is /usr/lib/freeradius Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded exec Wed Jan 30 16:21:17 2008 : Debug: exec: wait = yes Wed Jan 30 16:21:17 2008 : Debug: exec: program = "(null)" Wed Jan 30 16:21:17 2008 : Debug: exec: input_pairs = "request" Wed Jan 30 16:21:17 2008 : Debug: exec: output_pairs = "(null)" Wed Jan 30 16:21:17 2008 : Debug: exec: packet_type = "(null)" Wed Jan 30 16:21:17 2008 : Info: rlm_exec: Wait=yes but no output defined. Did you mean output=none? Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated exec (exec) Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded expr Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated expr (expr) Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded PAP Wed Jan 30 16:21:17 2008 : Debug: pap: encryption_scheme = "crypt" Wed Jan 30 16:21:17 2008 : Debug: pap: auto_header = yes Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated pap (pap) Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded CHAP Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated chap (chap) Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded MS-CHAP Wed Jan 30 16:21:17 2008 : Debug: mschap: use_mppe = yes Wed Jan 30 16:21:17 2008 : Debug: mschap: require_encryption = no Wed Jan 30 16:21:17 2008 : Debug: mschap: require_strong = no Wed Jan 30 16:21:17 2008 : Debug: mschap: with_ntdomain_hack = no Wed Jan 30 16:21:17 2008 : Debug: mschap: passwd = "(null)" Wed Jan 30 16:21:17 2008 : Debug: mschap: ntlm_auth = "(null)" Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated mschap (mschap) Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded System Wed Jan 30 16:21:17 2008 : Debug: unix: cache = no Wed Jan 30 16:21:17 2008 : Debug: unix: passwd = "(null)" Wed Jan 30 16:21:17 2008 : Debug: unix: shadow = "/etc/shadow" Wed Jan 30 16:21:17 2008 : Debug: unix: group = "(null)" Wed Jan 30 16:21:17 2008 : Debug: unix: radwtmp = "/var/log/freeradius/radwtmp" Wed Jan 30 16:21:17 2008 : Debug: unix: usegroup = no Wed Jan 30 16:21:17 2008 : Debug: unix: cache_reload = 600 Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated unix (unix) Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded eap Wed Jan 30 16:21:17 2008 : Debug: eap: default_eap_type = "peap" Wed Jan 30 16:21:17 2008 : Debug: eap: timer_expire = 60 Wed Jan 30 16:21:17 2008 : Debug: eap: ignore_unknown_eap_types = no Wed Jan 30 16:21:17 2008 : Debug: eap: cisco_accounting_username_bug = no Wed Jan 30 16:21:17 2008 : Debug: rlm_eap: Loaded and initialized type md5 Wed Jan 30 16:21:17 2008 : Debug: rlm_eap: Loaded and initialized type leap Wed Jan 30 16:21:17 2008 : Debug: gtc: challenge = "Password: " Wed Jan 30 16:21:17 2008 : Debug: gtc: auth_type = "PAP" Wed Jan 30 16:21:17 2008 : Debug: rlm_eap: Loaded and initialized type gtc Wed Jan 30 16:21:17 2008 : Debug: tls: rsa_key_exchange = no Wed Jan 30 16:21:17 2008 : Debug: tls: dh_key_exchange = yes Wed Jan 30 16:21:17 2008 : Debug: tls: rsa_key_length = 512 Wed Jan 30 16:21:17 2008 : Debug: tls: dh_key_length = 512 Wed Jan 30 16:21:17 2008 : Debug: tls: verify_depth = 0 Wed Jan 30 16:21:17 2008 : Debug: tls: CA_path = "(null)" Wed Jan 30 16:21:17 2008 : Debug: tls: pem_file_type = yes Wed Jan 30 16:21:17 2008 : Debug: tls: private_key_file = "/etc/freeradius/certs/cert-srv.pem" Wed Jan 30 16:21:17 2008 : Debug: tls: certificate_file = "/etc/freeradius/certs/cert-srv.pem" Wed Jan 30 16:21:17 2008 : Debug: tls: CA_file = "/etc/freeradius/certs/demoCA/cacert.pem" Wed Jan 30 16:21:17 2008 : Debug: tls: private_key_password = "whatever" Wed Jan 30 16:21:17 2008 : Debug: tls: dh_file = "/etc/freeradius/certs/dh" Wed Jan 30 16:21:17 2008 : Debug: tls: random_file = "/etc/freeradius/certs/random" Wed Jan 30 16:21:17 2008 : Debug: tls: fragment_size = 1024 Wed Jan 30 16:21:17 2008 : Debug: tls: include_length = yes Wed Jan 30 16:21:17 2008 : Debug: tls: check_crl = no Wed Jan 30 16:21:17 2008 : Debug: tls: check_cert_cn = "(null)" Wed Jan 30 16:21:17 2008 : Debug: tls: cipher_list = "(null)" Wed Jan 30 16:21:17 2008 : Debug: tls: check_cert_issuer = "(null)" Wed Jan 30 16:21:17 2008 : Info: rlm_eap_tls: Loading the certificate file as a chain Wed Jan 30 16:21:17 2008 : Info: WARNING: rlm_eap_tls: Unable to set DH parameters. DH cipher suites may not work! Wed Jan 30 16:21:17 2008 : Debug: WARNING: Fix this by running the OpenSSL command listed in eap.conf Wed Jan 30 16:21:17 2008 : Debug: rlm_eap: Loaded and initialized type tls Wed Jan 30 16:21:17 2008 : Debug: peap: default_eap_type = "mschapv2" Wed Jan 30 16:21:17 2008 : Debug: peap: copy_request_to_tunnel = no Wed Jan 30 16:21:17 2008 : Debug: peap: use_tunneled_reply = no Wed Jan 30 16:21:17 2008 : Debug: peap: proxy_tunneled_request_as_eap = no Wed Jan 30 16:21:17 2008 : Debug: rlm_eap: Loaded and initialized type peap Wed Jan 30 16:21:17 2008 : Debug: mschapv2: with_ntdomain_hack = no Wed Jan 30 16:21:17 2008 : Debug: rlm_eap: Loaded and initialized type mschapv2 Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated eap (eap) Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded preprocess Wed Jan 30 16:21:17 2008 : Debug: preprocess: huntgroups = "/etc/freeradius/huntgroups" Wed Jan 30 16:21:17 2008 : Debug: preprocess: hints = "/etc/freeradius/hints" Wed Jan 30 16:21:17 2008 : Debug: preprocess: with_ascend_hack = no Wed Jan 30 16:21:17 2008 : Debug: preprocess: ascend_channels_per_line = 23 Wed Jan 30 16:21:17 2008 : Debug: preprocess: with_ntdomain_hack = no Wed Jan 30 16:21:17 2008 : Debug: preprocess: with_specialix_jetstream_hack = no Wed Jan 30 16:21:17 2008 : Debug: preprocess: with_cisco_vsa_hack = no Wed Jan 30 16:21:17 2008 : Debug: preprocess: with_alvarion_vsa_hack = no Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated preprocess (preprocess) Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded detail Wed Jan 30 16:21:17 2008 : Debug: detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d" Wed Jan 30 16:21:17 2008 : Debug: detail: detailperm = 384 Wed Jan 30 16:21:17 2008 : Debug: detail: dirperm = 493 Wed Jan 30 16:21:17 2008 : Debug: detail: locking = no Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated detail (auth_log) Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded attr_filter Wed Jan 30 16:21:17 2008 : Debug: attr_filter: attrsfile = "/etc/freeradius/attrs" Wed Jan 30 16:21:17 2008 : Error: rlm_attr_filter: Authorize method will be deprecated. Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated attr_filter (attr_filter) Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded realm Wed Jan 30 16:21:17 2008 : Debug: realm: format = "suffix" Wed Jan 30 16:21:17 2008 : Debug: realm: delimiter = "@" Wed Jan 30 16:21:17 2008 : Debug: realm: ignore_default = no Wed Jan 30 16:21:17 2008 : Debug: realm: ignore_null = no Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated realm (suffix) Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded files Wed Jan 30 16:21:17 2008 : Debug: files: usersfile = "/etc/freeradius/users" Wed Jan 30 16:21:17 2008 : Debug: files: acctusersfile = "/etc/freeradius/acct_users" Wed Jan 30 16:21:17 2008 : Debug: files: preproxy_usersfile = "/etc/freeradius/preproxy_users" Wed Jan 30 16:21:17 2008 : Debug: files: compat = "no" Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated files (files) Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded Acct-Unique-Session-Id Wed Jan 30 16:21:17 2008 : Debug: acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated acct_unique (acct_unique) Wed Jan 30 16:21:17 2008 : Debug: detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/detail-%Y%m%d" Wed Jan 30 16:21:17 2008 : Debug: detail: detailperm = 384 Wed Jan 30 16:21:17 2008 : Debug: detail: dirperm = 493 Wed Jan 30 16:21:17 2008 : Debug: detail: locking = no Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated detail (detail) Wed Jan 30 16:21:17 2008 : Debug: Module: Loaded radutmp Wed Jan 30 16:21:17 2008 : Debug: radutmp: filename = "/var/log/freeradius/radutmp" Wed Jan 30 16:21:17 2008 : Debug: radutmp: username = "%{User-Name}" Wed Jan 30 16:21:17 2008 : Debug: radutmp: case_sensitive = yes Wed Jan 30 16:21:17 2008 : Debug: radutmp: check_with_nas = yes Wed Jan 30 16:21:17 2008 : Debug: radutmp: perm = 384 Wed Jan 30 16:21:17 2008 : Debug: radutmp: callerid = yes Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated radutmp (radutmp) Wed Jan 30 16:21:17 2008 : Debug: detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d" Wed Jan 30 16:21:17 2008 : Debug: detail: detailperm = 384 Wed Jan 30 16:21:17 2008 : Debug: detail: dirperm = 493 Wed Jan 30 16:21:17 2008 : Debug: detail: locking = no Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated detail (pre_proxy_log) Wed Jan 30 16:21:17 2008 : Debug: detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d" Wed Jan 30 16:21:17 2008 : Debug: detail: detailperm = 384 Wed Jan 30 16:21:17 2008 : Debug: detail: dirperm = 493 Wed Jan 30 16:21:17 2008 : Debug: detail: locking = no Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated detail (post_proxy_log) Wed Jan 30 16:21:17 2008 : Debug: detail: detailfile = "/var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d" Wed Jan 30 16:21:17 2008 : Debug: detail: detailperm = 384 Wed Jan 30 16:21:17 2008 : Debug: detail: dirperm = 493 Wed Jan 30 16:21:17 2008 : Debug: detail: locking = no Wed Jan 30 16:21:17 2008 : Debug: Module: Instantiated detail (reply_log) Wed Jan 30 16:21:17 2008 : Debug: Listening on authentication *:1812 Wed Jan 30 16:21:17 2008 : Debug: Listening on accounting *:1813 Wed Jan 30 16:21:17 2008 : Debug: Listening on proxy *:1814 Wed Jan 30 16:21:17 2008 : Info: Ready to process requests. rad_recv: Access-Request packet from host 192.168.2.28:1032, id=0, length=184 Message-Authenticator = 0x95738e03d1fb1c0ceba98dbdf1ab912f Service-Type = Framed-User User-Name = "aaa" Framed-MTU = 1488 Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN" Calling-Station-Id = "00-17-9A-82-C7-7B" NAS-Identifier = "WLAN Access Point" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x0200000801616161 NAS-IP-Address = 192.168.2.28 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Wed Jan 30 16:21:23 2008 : Debug: Processing the authorize section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 0 Wed Jan 30 16:21:23 2008 : Debug: radius_xlat: '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130' Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "auth_log" returns ok for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "attr_filter" returns noop for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 0 Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No such realm "NULL" Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 0 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP packet type response id 0 length 8 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 0 Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 0 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 0 Wed Jan 30 16:21:23 2008 : Debug: rad_check_password: Found Auth-Type EAP Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP" Wed Jan 30 16:21:23 2008 : Debug: Processing the authenticate section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 0 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 0 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP Identity Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: processing type tls Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: Initiate Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: Start returned 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 0 Wed Jan 30 16:21:23 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 0 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 0 Sending Access-Challenge of id 0 to 192.168.2.28 port 1032 EAP-Message = 0x010100061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x5db289aaf7d6fa0ebe901707a31e963c Wed Jan 30 16:21:23 2008 : Debug: Finished request 0 Wed Jan 30 16:21:23 2008 : Debug: Going to the next request Wed Jan 30 16:21:23 2008 : Debug: --- Walking the entire request list --- Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.2.28:1032, id=1, length=306 Message-Authenticator = 0x47b000110073bbb08377c494b4bd16ef Service-Type = Framed-User User-Name = "aaa" Framed-MTU = 1488 State = 0x5db289aaf7d6fa0ebe901707a31e963c Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN" Calling-Station-Id = "00-17-9A-82-C7-7B" NAS-Identifier = "WLAN Access Point" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x0201007019800000006616030100610100005d030147a087e3be36eef7e3c8558ad9836ef8545a57ad4ecd31cb1dee537f0217d0a0203285b3ca15b5bc19c4dc749138750ef06e349d1b28dc3864c757ae2d531b31bb001600040005000a000900640062000300060013001200630100 NAS-IP-Address = 192.168.2.28 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Wed Jan 30 16:21:23 2008 : Debug: Processing the authorize section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 1 Wed Jan 30 16:21:23 2008 : Debug: radius_xlat: '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130' Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "auth_log" returns ok for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "attr_filter" returns noop for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 1 Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No such realm "NULL" Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 1 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP packet type response id 1 length 112 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 1 Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 1 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 1 Wed Jan 30 16:21:23 2008 : Debug: rad_check_password: Found Auth-Type EAP Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP" Wed Jan 30 16:21:23 2008 : Debug: Processing the authenticate section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 1 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 1 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: Request found, released from the list Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP/peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: processing type peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: Authenticate Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: processing TLS Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: Length Included Wed Jan 30 16:21:23 2008 : Debug: eaptls_verify returned 11 Wed Jan 30 16:21:23 2008 : Debug: (other): before/accept initialization Wed Jan 30 16:21:23 2008 : Debug: TLS_accept: before/accept initialization Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0061], ClientHello Wed Jan 30 16:21:23 2008 : Debug: TLS_accept: SSLv3 read client hello A Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello Wed Jan 30 16:21:23 2008 : Debug: TLS_accept: SSLv3 write server hello A Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0694], Certificate Wed Jan 30 16:21:23 2008 : Debug: TLS_accept: SSLv3 write certificate A Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Wed Jan 30 16:21:23 2008 : Debug: TLS_accept: SSLv3 write server done A Wed Jan 30 16:21:23 2008 : Debug: TLS_accept: SSLv3 flush data Wed Jan 30 16:21:23 2008 : Debug: TLS_accept: Need to read more data: SSLv3 read client certificate A Wed Jan 30 16:21:23 2008 : Debug: In SSL Handshake Phase Wed Jan 30 16:21:23 2008 : Debug: In SSL Accept mode Wed Jan 30 16:21:23 2008 : Debug: eaptls_process returned 13 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: EAPTLS_HANDLED Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 1 Wed Jan 30 16:21:23 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 1 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 1 Sending Access-Challenge of id 1 to 192.168.2.28 port 1032 EAP-Message = 0x0102040a19c0000006f1160301004a02000046030147a087e30fe5927afc6e913fc013cdd64421ade59e5e48e0081dec52246dfb5620406d860bab150a348618c2468f0782195f2b7bad6e69a157ff5bbefb9bf70b6e00040016030106940b00069000068d0002cd308202c930820232a003020102020102300d06092a864886f70d010104050030819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e74206365 EAP-Message = 0x7274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d301e170d3034303132353133323631305a170d3035303132343133323631305a30819b310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f73743119301706035504031310526f6f74206365727469666963617465311f301d06092a864886f70d0109011610726f6f74406578616d706c652e636f6d30819f300d06092a864886f70d010101050003 EAP-Message = 0x818d0030818902818100dac525422bfedb082629a2cba44b3449c90d0ab462fb72c8434a782098863d7eb7d7e70028c2b7ad555a51cc756cf4fa1d7091615ab450d5289553ae6616aff014a55085d6b8fb4aee98638e426175cdd36c665c63cda177d34920eb30585edc8773999c2980f81ad4638bbbea1c82d054023db7ef24a3ec1c3f6241a903d7f30203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d0101040500038181007a2d921b1cf13bf2982a9178ec9ede6d88edc178a2e8bd40a0a06fb6f0769957884cd7084537083496fd184165293f583c8e8240eb68e042c94b15752e4c07e80d09 EAP-Message = 0x779afa3dd55c24fa54ac292d77205d1c2477ed30d59f57caf9bd21ff2a8d16cc0911c50e4f295763fcb60efa3c3d2d0e43850f6e6fbe284902f6e83503650003ba308203b63082031fa003020102020100300d06092a864886f70d010104050030819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c EAP-Message = 0x652e636f6d301e170d3034303132353133323630375a Message-Authenticator = 0x00000000000000000000000000000000 State = 0x5708202a97e43ae72b2b2c71ba80ada9 Wed Jan 30 16:21:23 2008 : Debug: Finished request 1 Wed Jan 30 16:21:23 2008 : Debug: Going to the next request Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.2.28:1032, id=2, length=200 Message-Authenticator = 0xc8c00d8115a81d1ef2d1975cd7b7815b Service-Type = Framed-User User-Name = "aaa" Framed-MTU = 1488 State = 0x5708202a97e43ae72b2b2c71ba80ada9 Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN" Calling-Station-Id = "00-17-9A-82-C7-7B" NAS-Identifier = "WLAN Access Point" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x020200061900 NAS-IP-Address = 192.168.2.28 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Wed Jan 30 16:21:23 2008 : Debug: Processing the authorize section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 2 Wed Jan 30 16:21:23 2008 : Debug: radius_xlat: '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130' Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "auth_log" returns ok for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "attr_filter" returns noop for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 2 Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No such realm "NULL" Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 2 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP packet type response id 2 length 6 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 2 Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 2 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 2 Wed Jan 30 16:21:23 2008 : Debug: rad_check_password: Found Auth-Type EAP Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP" Wed Jan 30 16:21:23 2008 : Debug: Processing the authenticate section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 2 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 2 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: Request found, released from the list Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP/peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: processing type peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: Authenticate Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: processing TLS Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: Received EAP-TLS ACK message Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: ack handshake fragment handler Wed Jan 30 16:21:23 2008 : Debug: eaptls_verify returned 1 Wed Jan 30 16:21:23 2008 : Debug: eaptls_process returned 13 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: EAPTLS_HANDLED Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 2 Wed Jan 30 16:21:23 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 2 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 2 Sending Access-Challenge of id 2 to 192.168.2.28 port 1032 EAP-Message = 0x010302f71900170d3036303132343133323630375a30819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d30819f300d06092a864886f70d010101050003818d0030818902818100d4c5b19724f164acf1ffb189db1c8fbff4f14396ea7cb1e90f78d69451725377895dfe52ccb99b41e8 EAP-Message = 0x0ddeb58b127a943f4f58cbc562878192fbdc6fece9f871e7c130d35cf5188817e9b133249edd2a1c75d31043ae87553cec7a77ef26aa7d74281db9b77e17c6446c5dd9b188b43250ca0229963722a123a726b00b4027fd0203010001a381ff3081fc301d0603551d0e0416041468d36d3e1ee7bc9d5a057021c363da1365d1ade33081cc0603551d230481c43081c1801468d36d3e1ee7bc9d5a057021c363da1365d1ade3a181a5a481a230819f310b30090603550406130243413111300f0603550408130850726f76696e63653112301006035504071309536f6d65204369747931153013060355040a130c4f7267616e697a6174696f6e31123010 EAP-Message = 0x060355040b13096c6f63616c686f7374311b301906035504031312436c69656e742063657274696669636174653121301f06092a864886f70d0109011612636c69656e74406578616d706c652e636f6d820100300c0603551d13040530030101ff300d06092a864886f70d01010405000381810033c00b66b1e579ef73a06798252dab8d5e5511fc00fd276d80d12f834777c6743fdc2743fca1507704e4bc0979e4f60ac3ad9ee83e6f347369229d1f77229ba2e982359da563024a00163dba6d6c986c0bad28af85132ff8f0d76501bf1b7c2dff658ce1e62c01997b6e64e3e8d4373354ce9912847651539063b85bbc5485c516030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xe6496d844bf69bdcdb1602289e985d94 Wed Jan 30 16:21:23 2008 : Debug: Finished request 2 Wed Jan 30 16:21:23 2008 : Debug: Going to the next request Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.2.28:1032, id=3, length=386 Message-Authenticator = 0x50eaac0ad7a2fe459a874501a98ac64b Service-Type = Framed-User User-Name = "aaa" Framed-MTU = 1488 State = 0xe6496d844bf69bdcdb1602289e985d94 Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN" Calling-Station-Id = "00-17-9A-82-C7-7B" NAS-Identifier = "WLAN Access Point" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x020300c01980000000b61603010086100000820080bac89a3ea71151d7ad09a69ff4ea8bc2951547167c8ea167fa9c3650285c4b106263fbff6b6b52bbbd6ec2c9eb4b9eb1a19d949ed96f2d81ee59cde3e388b26f6bc5285b71dcf6965e8ced6b59007420c47ac570b12d170c3bf9d3d3a133004a8e7fe37bf4fe4e27ed41982a8eec19682e20fa680c9bd41339e28477bce1d0581403010001011603010020fea0deb5a460a2665fc5b24deae99e753a3ba1a12c198817bb33422ec05227ee NAS-IP-Address = 192.168.2.28 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Wed Jan 30 16:21:23 2008 : Debug: Processing the authorize section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 3 Wed Jan 30 16:21:23 2008 : Debug: radius_xlat: '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130' Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "auth_log" returns ok for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "attr_filter" returns noop for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 3 Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No such realm "NULL" Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 3 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP packet type response id 3 length 192 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 3 Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 3 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 3 Wed Jan 30 16:21:23 2008 : Debug: rad_check_password: Found Auth-Type EAP Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP" Wed Jan 30 16:21:23 2008 : Debug: Processing the authenticate section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 3 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 3 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: Request found, released from the list Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP/peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: processing type peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: Authenticate Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: processing TLS Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: Length Included Wed Jan 30 16:21:23 2008 : Debug: eaptls_verify returned 11 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange Wed Jan 30 16:21:23 2008 : Debug: TLS_accept: SSLv3 read client key exchange A Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 ChangeCipherSpec [length 0001] Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 0010], Finished Wed Jan 30 16:21:23 2008 : Debug: TLS_accept: SSLv3 read finished A Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 ChangeCipherSpec [length 0001] Wed Jan 30 16:21:23 2008 : Debug: TLS_accept: SSLv3 write change cipher spec A Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0010], Finished Wed Jan 30 16:21:23 2008 : Debug: TLS_accept: SSLv3 write finished A Wed Jan 30 16:21:23 2008 : Debug: TLS_accept: SSLv3 flush data Wed Jan 30 16:21:23 2008 : Debug: (other): SSL negotiation finished successfully Wed Jan 30 16:21:23 2008 : Debug: SSL Connection Established Wed Jan 30 16:21:23 2008 : Debug: eaptls_process returned 13 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: EAPTLS_HANDLED Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 3 Wed Jan 30 16:21:23 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 3 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 3 Sending Access-Challenge of id 3 to 192.168.2.28 port 1032 EAP-Message = 0x0104003119001403010001011603010020a562e906ef0e8bcc20bdf677cf9488ea9f72210f343b6b2764f4751c5ec28418 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x3882c9b17babca451a6ccc9e89a82d1e Wed Jan 30 16:21:23 2008 : Debug: Finished request 3 Wed Jan 30 16:21:23 2008 : Debug: Going to the next request Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.2.28:1032, id=4, length=200 Message-Authenticator = 0x3d2571581a9de91e3544ff7994b3bc4c Service-Type = Framed-User User-Name = "aaa" Framed-MTU = 1488 State = 0x3882c9b17babca451a6ccc9e89a82d1e Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN" Calling-Station-Id = "00-17-9A-82-C7-7B" NAS-Identifier = "WLAN Access Point" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x020400061900 NAS-IP-Address = 192.168.2.28 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Wed Jan 30 16:21:23 2008 : Debug: Processing the authorize section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 4 Wed Jan 30 16:21:23 2008 : Debug: radius_xlat: '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130' Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "auth_log" returns ok for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "attr_filter" returns noop for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 4 Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No such realm "NULL" Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 4 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP packet type response id 4 length 6 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 4 Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 4 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 4 Wed Jan 30 16:21:23 2008 : Debug: rad_check_password: Found Auth-Type EAP Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP" Wed Jan 30 16:21:23 2008 : Debug: Processing the authenticate section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 4 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 4 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: Request found, released from the list Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP/peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: processing type peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: Authenticate Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: processing TLS Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: Received EAP-TLS ACK message Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: ack handshake is finished Wed Jan 30 16:21:23 2008 : Debug: eaptls_verify returned 3 Wed Jan 30 16:21:23 2008 : Debug: eaptls_process returned 3 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: EAPTLS_SUCCESS Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 4 Wed Jan 30 16:21:23 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 4 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 4 Sending Access-Challenge of id 4 to 192.168.2.28 port 1032 EAP-Message = 0x0105002019001703010015a003beb410bd42441cf8049fc078150a1f62dc13a5 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x6472259ba53a52a47938bbb75daab0fc Wed Jan 30 16:21:23 2008 : Debug: Finished request 4 Wed Jan 30 16:21:23 2008 : Debug: Going to the next request Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.2.28:1032, id=5, length=225 Message-Authenticator = 0xfa8d3e5d9994f240fd0ef4158a8c9246 Service-Type = Framed-User User-Name = "aaa" Framed-MTU = 1488 State = 0x6472259ba53a52a47938bbb75daab0fc Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN" Calling-Station-Id = "00-17-9A-82-C7-7B" NAS-Identifier = "WLAN Access Point" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x0205001f19001703010014f2094e78f3e975f48718cbb7d270c92bdeb7b1a5 NAS-IP-Address = 192.168.2.28 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Wed Jan 30 16:21:23 2008 : Debug: Processing the authorize section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 5 Wed Jan 30 16:21:23 2008 : Debug: radius_xlat: '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130' Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "auth_log" returns ok for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "attr_filter" returns noop for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 5 Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No such realm "NULL" Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP packet type response id 5 length 31 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 5 Wed Jan 30 16:21:23 2008 : Debug: rad_check_password: Found Auth-Type EAP Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP" Wed Jan 30 16:21:23 2008 : Debug: Processing the authenticate section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: Request found, released from the list Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP/peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: processing type peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: Authenticate Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: processing TLS Wed Jan 30 16:21:23 2008 : Debug: eaptls_verify returned 7 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: Done initial handshake Wed Jan 30 16:21:23 2008 : Debug: eaptls_process returned 7 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: EAPTLS_OK Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: Session established. Decoding tunneled attributes. PEAP tunnel data in 0000: 01 61 61 61 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: Identity - aaa Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: Tunneled data is valid. PEAP: Got tunneled EAP-Message EAP-Message = 0x0205000801616161 Wed Jan 30 16:21:23 2008 : Debug: PEAP: Got tunneled identity of aaa Wed Jan 30 16:21:23 2008 : Debug: PEAP: Setting default EAP type for tunneled EAP session. Wed Jan 30 16:21:23 2008 : Debug: PEAP: Setting User-Name to aaa PEAP: Sending tunneled request EAP-Message = 0x0205000801616161 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "aaa" Wed Jan 30 16:21:23 2008 : Debug: Processing the authorize section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 5 Wed Jan 30 16:21:23 2008 : Debug: radius_xlat: '/var/log/freeradius/radacct/127.0.0.1/auth-detail-20080130' Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/127.0.0.1/auth-detail-20080130 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "auth_log" returns ok for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "attr_filter" returns noop for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 5 Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No such realm "NULL" Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP packet type response id 5 length 8 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 5 Wed Jan 30 16:21:23 2008 : Debug: users: Matched entry aaa at line 85 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "files" returns ok for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 5 PEAP: Got tunneled reply RADIUS code 0 Wed Jan 30 16:21:23 2008 : Debug: PEAP: Calling authenticate in order to initiate tunneled EAP session. Wed Jan 30 16:21:23 2008 : Debug: Processing the authenticate section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 5 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP Identity Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: processing type mschapv2 Wed Jan 30 16:21:23 2008 : Info: rlm_eap_mschapv2: Issuing Challenge Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 5 Wed Jan 30 16:21:23 2008 : Debug: PEAP: Cancelling proxy to realm xxx until the tunneled EAP session has been established PEAP: Processing from tunneled session code 0x80147040 11 EAP-Message = 0x0106001d1a0106001810d705730f12a9595b41ac811cc23eab54616161 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x767993fd4ad4ebf861acdf27ec0a3a8e Wed Jan 30 16:21:23 2008 : Debug: PEAP: Got tunneled Access-Challenge PEAP tunnel data out 0000: 1a 01 06 00 18 10 d7 05 73 0f 12 a9 59 5b 41 ac PEAP tunnel data out 0010: 81 1c c2 3e ab 54 61 61 61 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 5 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 5 Sending Access-Challenge of id 5 to 192.168.2.28 port 1032 EAP-Message = 0x01060034190017030100291f8fadaf8be94d9469a30a78fcc2ae5503135fb3588b426d80237b5bb96cd390128aaaeab9af12f9f3 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x46e3664e4d1315184ed1a50e6dc819b3 Wed Jan 30 16:21:23 2008 : Debug: Finished request 5 Wed Jan 30 16:21:23 2008 : Debug: Going to the next request Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.2.28:1032, id=6, length=279 Message-Authenticator = 0xf24acb657d7e9f0ea425095ba74e861b Service-Type = Framed-User User-Name = "aaa" Framed-MTU = 1488 State = 0x46e3664e4d1315184ed1a50e6dc819b3 Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN" Calling-Station-Id = "00-17-9A-82-C7-7B" NAS-Identifier = "WLAN Access Point" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x020600551900170301004aba2524bee95d3df9b8b22f2250e4c4314a0e52353fd9037b6d96d8010f9811be0f665cae244749d9b0f10fa2d28d5660564fe27284e1f3d92a4222360cf90d70f12d193a481852d84bbe NAS-IP-Address = 192.168.2.28 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Wed Jan 30 16:21:23 2008 : Debug: Processing the authorize section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 6 Wed Jan 30 16:21:23 2008 : Debug: radius_xlat: '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130' Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "auth_log" returns ok for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "attr_filter" returns noop for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 6 Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No such realm "NULL" Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP packet type response id 6 length 85 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 6 Wed Jan 30 16:21:23 2008 : Debug: rad_check_password: Found Auth-Type EAP Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP" Wed Jan 30 16:21:23 2008 : Debug: Processing the authenticate section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: Request found, released from the list Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP/peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: processing type peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: Authenticate Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: processing TLS Wed Jan 30 16:21:23 2008 : Debug: eaptls_verify returned 7 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: Done initial handshake Wed Jan 30 16:21:23 2008 : Debug: eaptls_process returned 7 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: EAPTLS_OK Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: Session established. Decoding tunneled attributes. PEAP tunnel data in 0000: 1a 02 06 00 39 31 54 3b ff a8 dd c0 94 f4 dd 7d PEAP tunnel data in 0010: 68 d5 83 58 3c ef 00 00 00 00 00 00 00 00 37 cc PEAP tunnel data in 0020: 3c cd 31 b8 76 ad 62 b6 16 4c bb b4 7f 0f 87 d0 PEAP tunnel data in 0030: 4f 4c 21 56 a1 3d 00 61 61 61 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: EAP type mschapv2 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: Tunneled data is valid. PEAP: Got tunneled EAP-Message EAP-Message = 0x0206003e1a0206003931543bffa8ddc094f4dd7d68d583583cef000000000000000037cc3ccd31b876ad62b6164cbbb47f0f87d04f4c2156a13d00616161 Wed Jan 30 16:21:23 2008 : Debug: PEAP: Setting User-Name to aaa Wed Jan 30 16:21:23 2008 : Debug: PEAP: Adding old state with 76 79 PEAP: Sending tunneled request EAP-Message = 0x0206003e1a0206003931543bffa8ddc094f4dd7d68d583583cef000000000000000037cc3ccd31b876ad62b6164cbbb47f0f87d04f4c2156a13d00616161 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "aaa" State = 0x767993fd4ad4ebf861acdf27ec0a3a8e Wed Jan 30 16:21:23 2008 : Debug: Processing the authorize section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 6 Wed Jan 30 16:21:23 2008 : Debug: radius_xlat: '/var/log/freeradius/radacct/127.0.0.1/auth-detail-20080130' Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/127.0.0.1/auth-detail-20080130 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "auth_log" returns ok for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "attr_filter" returns noop for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 6 Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No such realm "NULL" Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP packet type response id 6 length 62 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 6 Wed Jan 30 16:21:23 2008 : Debug: users: Matched entry aaa at line 85 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "files" returns ok for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 6 PEAP: Got tunneled reply RADIUS code 0 Wed Jan 30 16:21:23 2008 : Debug: PEAP: Calling authenticate in order to initiate tunneled EAP session. Wed Jan 30 16:21:23 2008 : Debug: Processing the authenticate section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: Request found, released from the list Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP/mschapv2 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: processing type mschapv2 Wed Jan 30 16:21:23 2008 : Debug: Not-EAP proxy set. Not composing EAP Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 6 Wed Jan 30 16:21:23 2008 : Debug: PEAP: Tunneled authentication will be proxied to xxx Wed Jan 30 16:21:23 2008 : Debug: PEAP: Remembering to do EAP-MS-CHAP-V2 post-proxy. Wed Jan 30 16:21:23 2008 : Debug: Tunneled session will be proxied. Not doing EAP. Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[authenticate]: module "eap" returns handled for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns handled) for request 6 Wed Jan 30 16:21:23 2008 : Debug: Processing the pre-proxy section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group pre-proxy for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[pre-proxy]: calling files (rlm_files) for request 6 Wed Jan 30 16:21:23 2008 : Debug: preproxy_users: Matched entry DEFAULT at line 33 Wed Jan 30 16:21:23 2008 : Debug: modsingle[pre-proxy]: returned from files (rlm_files) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[pre-proxy]: module "files" returns ok for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[pre-proxy]: calling pre_proxy_log (rlm_detail) for request 6 Wed Jan 30 16:21:23 2008 : Debug: radius_xlat: '/var/log/freeradius/radacct/192.168.2.28/pre-proxy-detail-20080130' Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/pre-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/pre-proxy-detail-20080130 Wed Jan 30 16:21:23 2008 : Debug: modsingle[pre-proxy]: returned from pre_proxy_log (rlm_detail) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[pre-proxy]: module "pre_proxy_log" returns ok for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group pre-proxy (returns ok) for request 6 Wed Jan 30 16:21:23 2008 : Debug: proxy: creating 5002a8c0:1812 Wed Jan 30 16:21:23 2008 : Debug: proxy: allocating 5002a8c0:1812 0 Sending Access-Request of id 0 to 192.168.2.80 port 1812 User-Name = "aaa" NAS-IP-Address = 127.0.0.1 MS-CHAP-Challenge = 0xd705730f12a9595b41ac811cc23eab54 MS-CHAP2-Response = 0x0661543bffa8ddc094f4dd7d68d583583cef000000000000000037cc3ccd31b876ad62b6164cbbb47f0f87d04f4c2156a13d Proxy-State = 0x36 Service-Type := BOSS4-HomeNet-VPN Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Accept packet from host 192.168.2.80:1812, id=0, length=262 Wed Jan 30 16:21:23 2008 : Debug: proxy: de-allocating 5002a8c0:1812 0 Reply-Message = "ACCESS: GRANTED" Reply-Message = "AGREEMENT-ID: 587986" Framed-IP-Address = 192.168.2.56 Framed-IP-Netmask = 255.255.255.255 Framed-Protocol = PPP MS-CHAP2-Success = 0x00533d46344538343746453843323736414341453537393637343835343143384642303742334633303739 MS-MPPE-Encryption-Policy = 0x00000001 MS-MPPE-Encryption-Types = 0x00000006 MS-MPPE-Recv-Key = 0x6b79482763300b5dece7d6ac717d8a21 MS-MPPE-Send-Key = 0xe23347a646ed9a7a19693881f99ebb37 Service-Type = Framed-User Reply-Message = "STATUS: 0.00000000" Wed Jan 30 16:21:23 2008 : Debug: Processing the post-proxy section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group post-proxy for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[post-proxy]: calling post_proxy_log (rlm_detail) for request 6 Wed Jan 30 16:21:23 2008 : Debug: radius_xlat: '/var/log/freeradius/radacct/192.168.2.28/post-proxy-detail-20080130' Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/post-proxy-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/post-proxy-detail-20080130 Wed Jan 30 16:21:23 2008 : Debug: modsingle[post-proxy]: returned from post_proxy_log (rlm_detail) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[post-proxy]: module "post_proxy_log" returns ok for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[post-proxy]: calling eap (rlm_eap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: PEAP: Passing reply from proxy back into the tunnel. Wed Jan 30 16:21:23 2008 : Debug: PEAP: Passing reply back for EAP-MS-CHAP-V2 0x801453f8 2 Wed Jan 30 16:21:23 2008 : Debug: Processing the post-proxy section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group post-proxy for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[post-proxy]: calling post_proxy_log (rlm_detail) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[post-proxy]: returned from post_proxy_log (rlm_detail) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[post-proxy]: module "post_proxy_log" returns noop for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[post-proxy]: calling eap (rlm_eap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_mschapv2: Passing reply from proxy back into the tunnel 0x801453f8 2. Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_mschapv2: Authentication succeeded. Wed Jan 30 16:21:23 2008 : Debug: MSCHAP Success Wed Jan 30 16:21:23 2008 : Debug: modsingle[post-proxy]: returned from eap (rlm_eap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[post-proxy]: module "eap" returns ok for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group post-proxy (returns ok) for request 6 Wed Jan 30 16:21:23 2008 : Debug: POST-PROXY 2 Wed Jan 30 16:21:23 2008 : Debug: Processing the post-auth section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group post-auth for request 6 Wed Jan 30 16:21:23 2008 : Debug: modsingle[post-auth]: calling reply_log (rlm_detail) for request 6 Wed Jan 30 16:21:23 2008 : Debug: radius_xlat: '/var/log/freeradius/radacct/127.0.0.1/reply-detail-20080130' Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/log/freeradius/radacct/127.0.0.1/reply-detail-20080130 Wed Jan 30 16:21:23 2008 : Debug: modsingle[post-auth]: returned from reply_log (rlm_detail) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[post-auth]: module "reply_log" returns ok for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group post-auth (returns ok) for request 6 Wed Jan 30 16:21:23 2008 : Debug: POST-AUTH 2 PEAP: Final reply from tunneled session code 11 Reply-Message = "ACCESS: GRANTED" Reply-Message = "AGREEMENT-ID: 587986" Framed-IP-Address = 192.168.2.56 Framed-IP-Netmask = 255.255.255.255 Framed-Protocol = PPP Service-Type = Framed-User Reply-Message = "STATUS: 0.00000000" EAP-Message = 0x010700331a0306002e533d46344538343746453843323736414341453537393637343835343143384642303742334633303739 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2e6847c5eb9a59e5f7cdbc3d8f082a8f Wed Jan 30 16:21:23 2008 : Debug: PEAP: Got reply 11 PEAP: Processing from tunneled session code 0x80144e58 11 Reply-Message = "ACCESS: GRANTED" Reply-Message = "AGREEMENT-ID: 587986" Framed-IP-Address = 192.168.2.56 Framed-IP-Netmask = 255.255.255.255 Framed-Protocol = PPP Service-Type = Framed-User Reply-Message = "STATUS: 0.00000000" EAP-Message = 0x010700331a0306002e533d46344538343746453843323736414341453537393637343835343143384642303742334633303739 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2e6847c5eb9a59e5f7cdbc3d8f082a8f Wed Jan 30 16:21:23 2008 : Debug: PEAP: Got tunneled Access-Challenge PEAP tunnel data out 0000: 1a 03 06 00 2e 53 3d 46 34 45 38 34 37 46 45 38 PEAP tunnel data out 0010: 43 32 37 36 41 43 41 45 35 37 39 36 37 34 38 35 PEAP tunnel data out 0020: 34 31 43 38 46 42 30 37 42 33 46 33 30 37 39 Wed Jan 30 16:21:23 2008 : Debug: PEAP: Reply was handled Wed Jan 30 16:21:23 2008 : Debug: modsingle[post-proxy]: returned from eap (rlm_eap) for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall[post-proxy]: module "eap" returns ok for request 6 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group post-proxy (returns ok) for request 6 Sending Access-Challenge of id 6 to 192.168.2.28 port 1032 EAP-Message = 0x0107004a1900170301003f3cbae61fe7c97a3500bb9b7aa65a7ebf4dfde9f637ba2a0f53ed7e91716066ab1dac2c590f7476689bf80aacf390629dd56a9d5e9df17b60819fc23938d207 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x8f6fded6f73f89f6c871aa78026be3fe Wed Jan 30 16:21:23 2008 : Debug: Finished request 6 Wed Jan 30 16:21:23 2008 : Debug: Going to the next request Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds... rad_recv: Access-Request packet from host 192.168.2.28:1032, id=7, length=223 Message-Authenticator = 0xdf76dfa6cb666f43cae3f55e797a4b95 Service-Type = Framed-User User-Name = "aaa" Framed-MTU = 1488 State = 0x8f6fded6f73f89f6c871aa78026be3fe Called-Station-Id = "00-15-E9-AE-B2-BF:WLAN" Calling-Station-Id = "00-17-9A-82-C7-7B" NAS-Identifier = "WLAN Access Point" NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 54Mbps 802.11g" EAP-Message = 0x0207001d19001703010012156f46fa75527ef68f17bb704f8dba1532f7 NAS-IP-Address = 192.168.2.28 NAS-Port = 1 NAS-Port-Id = "STA port # 1" Wed Jan 30 16:21:23 2008 : Debug: Processing the authorize section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 7 Wed Jan 30 16:21:23 2008 : Debug: radius_xlat: '/var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130' Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/192.168.2.28/auth-detail-20080130 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "auth_log" returns ok for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "attr_filter" returns noop for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 7 Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No such realm "NULL" Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP packet type response id 7 length 29 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "files" returns notfound for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: rlm_pap: WARNING! No "known good" password found for the user. Authentication may fail because of this. Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 7 Wed Jan 30 16:21:23 2008 : Debug: rad_check_password: Found Auth-Type EAP Wed Jan 30 16:21:23 2008 : Debug: auth: type "EAP" Wed Jan 30 16:21:23 2008 : Debug: Processing the authenticate section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: Request found, released from the list Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP/peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: processing type peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: Authenticate Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: processing TLS Wed Jan 30 16:21:23 2008 : Debug: eaptls_verify returned 7 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_tls: Done initial handshake Wed Jan 30 16:21:23 2008 : Debug: eaptls_process returned 7 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: EAPTLS_OK Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: Session established. Decoding tunneled attributes. PEAP tunnel data in 0000: 1a 03 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: EAP type mschapv2 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap_peap: Tunneled data is valid. PEAP: Got tunneled EAP-Message EAP-Message = 0x020700061a03 Wed Jan 30 16:21:23 2008 : Debug: PEAP: Setting User-Name to aaa Wed Jan 30 16:21:23 2008 : Debug: PEAP: Adding old state with 2e 68 PEAP: Sending tunneled request EAP-Message = 0x020700061a03 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "aaa" State = 0x2e6847c5eb9a59e5f7cdbc3d8f082a8f Wed Jan 30 16:21:23 2008 : Debug: Processing the authorize section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authorize for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "preprocess" returns ok for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling auth_log (rlm_detail) for request 7 Wed Jan 30 16:21:23 2008 : Debug: radius_xlat: '/var/log/freeradius/radacct/127.0.0.1/auth-detail-20080130' Wed Jan 30 16:21:23 2008 : Debug: rlm_detail: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/127.0.0.1/auth-detail-20080130 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from auth_log (rlm_detail) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "auth_log" returns ok for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling attr_filter (rlm_attr_filter) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from attr_filter (rlm_attr_filter) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "attr_filter" returns noop for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "chap" returns noop for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "mschap" returns noop for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 7 Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No '@' in User-Name = "aaa", looking up realm NULL Wed Jan 30 16:21:23 2008 : Debug: rlm_realm: No such realm "NULL" Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "suffix" returns noop for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: EAP packet type response id 7 length 6 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "eap" returns updated for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 7 Wed Jan 30 16:21:23 2008 : Debug: users: Matched entry aaa at line 85 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "files" returns ok for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authorize]: module "pap" returns noop for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authorize (returns updated) for request 7 PEAP: Got tunneled reply RADIUS code 0 Wed Jan 30 16:21:23 2008 : Debug: PEAP: Calling authenticate in order to initiate tunneled EAP session. Wed Jan 30 16:21:23 2008 : Debug: Processing the authenticate section of radiusd.conf Wed Jan 30 16:21:23 2008 : Debug: modcall: entering group authenticate for request 7 Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: Request not found in the list Wed Jan 30 16:21:23 2008 : Error: rlm_eap: Either EAP-request timed out OR EAP-response to an unknown EAP-request Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: Failed in handler Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authenticate]: module "eap" returns invalid for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns invalid) for request 7 Wed Jan 30 16:21:23 2008 : Debug: PEAP: Can't handle the return code 4 Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: Handler failed in EAP/peap Wed Jan 30 16:21:23 2008 : Debug: rlm_eap: Failed in EAP select Wed Jan 30 16:21:23 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall[authenticate]: module "eap" returns invalid for request 7 Wed Jan 30 16:21:23 2008 : Debug: modcall: leaving group authenticate (returns invalid) for request 7 Wed Jan 30 16:21:23 2008 : Debug: auth: Failed to validate the user. Wed Jan 30 16:21:23 2008 : Debug: Delaying request 7 for 1 seconds Wed Jan 30 16:21:23 2008 : Debug: Finished request 7 Wed Jan 30 16:21:23 2008 : Debug: Going to the next request Wed Jan 30 16:21:23 2008 : Debug: Waking up in 6 seconds...

3 17

FreeRadius question
by Harley Race 18 Feb '08

18 Feb '08

Ladies and Gentlemen, I am trying to find out how I can check what options the freeradius binary available for download was compiled with. I have STFW and RTFM, but still am not sure as to how to check. radiusd -X gives some information, but nothing about what freeradius was compiled with. I am interested in finding out if the binary was compiled with e-Directory support. Thanks for any help. ____________________________________________________________________________________ Be a better friend, newshound, and know-it-all with Yahoo! Mobile. Try it now. http://mobile.yahoo.com/;_ylt=Ahu06i62sR8HDtDypao8Wcj9tAcJ

3 2

SMUX not registering with FreeRadius 1.1.7 and SNMP 5.1.2 after radiusd -X
by shrinivas alageri 18 Feb '08

18 Feb '08

Hello I wanted to integrate SMUX aith FreeRadius with above version. Tried the steps 1)Compiling FreeRadius with snmp option 2. modified the freeradius snmp.conf file to include smux_password = verysecret 2. modified the radiusd.conf file with snmp = yes $INCLUDE ${confdir}/snmp.conf 3. modified the net-snmp snmpd.conf file to include smuxpeer = 1.3.6.1.4.1.3317.1.3.1 verysecret 4. started the radiusd and snmpd daemons. When I do an 'snmpwalk -v1 -c public localhost system' I get the system info from the MIB (as expected). When I do radiusd -X no SMUX message is displayed Please help Thanks Shrinivas --------------------------------- Now you can chat without downloading messenger. Click here to know how.

1 0

Re: Re: 1.1.7 and rlm_sql_mysql duplicated query
by Georgi Alexandrov 18 Feb '08

18 Feb '08

>Santiago Balaguer García wrote: >> The answer is not totally correct. Because a microcuts in the >> connectibity of hotspot cause that hotspot re-sends the acct request. > >No, because then the Acct-Session-Id would remain the same. > >> In that case, you have to desactivate: >> - accounting_start_query_alt >> - accounting_stop_query_alt > >No. Re-read the original post. The Acct-Session-Id is different, hence 2 >sessions are being inserted into SQL, but no Accounting-Stop ever gets >send for the 1st. > >The NAS is misbehaving. > The problem was in the NAS itself indeed and not in freeradius. Thanks.

1 0

Query regarding Cluster configuration of Radius server
by Kartik CDS 18 Feb '08

18 Feb '08

Hello, I have a cluster setup of radius server. The cluster having ip adress as VIP and the cluster members are having IP1 and IP2. Radius client sends access-request to the ip address VIP The cluster is responding with IP1 or IP2 instead of VIP as the source address, should the radius client allow such a response ? I mean to say whether the radius client should validate the source address ?? [ I couldnt find anything related to this in the RFC, kindly help] Regards, Kartik

3 3

FreeRadius and LDAP/AD username/password check
by Mats Blomgren B 18 Feb '08

18 Feb '08

Hi, Today I check the "etc/passwd" for the usernames and passwords and fetches the users default group from "etc/passwd". In the "users" file I have the rights for each group. My current config: OS: Solaris 10 FreeRadius: 1.1.7 Mysql: 5.0.51 - For logging and NAS clients OS packages installed: db-4.2.52.NC-sol9-sparc-local OS packages installed: freeradius-1.1.7-sol10-sparc-local OS packages installed: gcc-3.4.6-sol10-sparc-local OS packages installed: gdbm-1.8.3-sol9-sparc-local OS packages installed: libiconv-1.11-sol10-sparc-local OS packages installed: libtool-1.5.24-sol10-sparc-local OS packages installed: make-3.81-sol10-sparc-local OS packages installed: mysql-5.0.51-sol10-sparc-local OS packages installed: ncurses-5.6-sol10-sparc-local OS packages installed: netsnmp-5.4.1-sol10-sparc-local OS packages installed: openldap-2.3.35-sol10-sparc-local OS packages installed: openssl-0.9.8f-sol10-sparc-local OS packages installed: perl-5.8.8-sol10-sparc-local OS packages installed: sasl-2.1.21-sol10-sparc-local OS packages installed: zlib-1.2.3-sol10-sparc-local OS packages installed: Freeradius: 1.1.7 #etc/passwd testuser:x:103:500:Test User:/home/testuser:/bin/bash #etc/group admin-network::500: user-network::600: #/usr/local/etc/raddb/users DEFAULT Group == "admin-network", Auth-Type = System Service-Type = Administrative-User, Fall-Through = No #/usr/local/etc/raddb/huntgroups defaultgroup NAS-IP-Address == 192.168.1.20 Group = admin-network, Group = user-network Today the user "testuser" would get Administrative rights on the nas with IP=192.168.1.20 since he is a member of the group "admin-network". I have been browsing the mailing list, wiki and google trying to find out if anyone has done the following: 1. I want to check the username/password against LDAP/AD instead of directly towards "etc/passwd". 2. After that I would like to continue by fetching the user's default group from the Solaris 10 system (/"etc/passwd") to give it rights depending on which group the user belongs to. 3. I know that this means I still have to have the username in the "/etc/passwd" but this will keep the users from having different logins in our infrastructure. Best regards Mats Blomgren B - IP Engineer

2 1

1.1.7 and rlm_sql_mysql duplicated query
by Georgi Alexandrov 18 Feb '08

18 Feb '08

Hello, I'm seeing duplicated queries made to the database when any (linux/pppoe) user logs in through freeradius 1.1.7. Log from mysql logger: 646 Query INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay, AcctStopDelay, XAscendSessionSvrKey) VALUES ('47B769162F4300', '66cf2392669a4dc6', 'time160', '', 'xx.xx.xxx.22', '0', 'Async', '2008-02-17 00:52:10', '0', '0', 'RADIUS', '', '', '0', '0', '', '00:13:20:xx.xx.xx', '', 'Framed-User', 'PPP', 'xx.xx.xxx.110', '0', '0', '') 645 Query INSERT INTO radacct (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctStopTime, AcctSessionTime, AcctAuthentic, ConnectInfo_start, ConnectInfo_stop, AcctInputOctets, AcctOutputOctets, CalledStationId, CallingStationId, AcctTerminateCause, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay, AcctStopDelay, XAscendSessionSvrKey) VALUES ('47B7691A2F4301', '82cd8d24e280bd07', 'time160', '', 'xx.xx.xx.22', '0', 'Async', '2008-02-17 00:52:10', '0', '0', 'RADIUS', '', '', '0', '0', '', '00:13:20:xx.xx.xx', '', 'Framed-User', 'PPP', 'xx.xx.xx.110', '0', '0', '') After user logs off the following query is passed to mysql: 080217 0:54:21 663 Query UPDATE radacct SET AcctStopTime = '2008-02-17 00:54:21', AcctSessionTime = '135', AcctInputOctets = '0' << 32 | '2556', AcctOutputOctets = '0' << 32 | '1486', AcctTerminateCause = 'User-Request', AcctStopDelay = '0', ConnectInfo_stop = '' WHERE AcctSessionId = '47B7691A2F4301' AND UserName = 'time160' AND NASIPAddress = 'xx.xx.xx.22' So when the user logs I have two queries inserting similar data with different sessions ids: 47B7691A2F4300 and 47B7691A2F4301 And when the user logs off I have only one query that notes the action in the database for session 47B7691A2F4301. So generally I get one "hanging" session in radacct table for a particular user where AcctStopTime is null. sql.conf is a default one with only db connect info changed. Tried to remove some of the insert statements but the only result I'm getting is no insert statement in radacct table at all or the double insert statement pointed above. I would really appreciate some guidance from this point on as I'm pretty much out of ideas. Thanks upfront

3 3

vocera(with Peap)+AP+freeRADIUS
by Hangjun He 18 Feb '08

18 Feb '08

Hi, I am using freeRADIUS 1.1.7. Notebook with odyssey client (peap mschap-v2) can talk to freeRADUS well. But when I use Vocera client, which can support peap + mschap-v2, It does not work. debug message (see more debug message in attachment): ... rad_recv: Access-Request packet from host 10.50.1.38:1034, id=55, length=233 User-Name = "lwang" NAS-IP-Address = 10.50.1.38 NAS-Identifier = "QA-AP1-21f0" NAS-Port = 0 Called-Station-Id = "00-19-77-00-21-F5:vocera_test" Calling-Station-Id = "00-16-41-F7-F7-75" Framed-MTU = 1500 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020a003919800000002f14030100010116030100248393f1d6391a86ab0605df998e0336f7c651a560328bf621b1ddebbfad332d8ea8796c49 State = 0xfd6f3b2761e20233acdc5d29ec63d11f Message-Authenticator = 0xc4ee170f5d47ee55bead80b4a36580cb Processing the authorize section of radiusd.conf modcall: entering group authorize for request 40 modcall[authorize]: module "preprocess" returns ok for request 40 radius_xlat: '/usr/local/var/log/radius/radacct/auth-detail-20080212' rlm_detail: /usr/local/var/log/radius/radacct/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/auth-detail-20080212 modcall[authorize]: module "auth_log" returns ok for request 40 modcall[authorize]: module "chap" returns noop for request 40 modcall[authorize]: module "mschap" returns noop for request 40 rlm_realm: No '@' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 40 rlm_realm: No '\' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "ntdomain" returns noop for request 40 rlm_eap: EAP packet type response id 10 length 57 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 40 users: Matched entry lwang at line 95 modcall[authorize]: module "files" returns ok for request 40 modcall: leaving group authorize (returns updated) for request 40 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 40 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: Length Included eaptls_verify returned 11 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 (other): SSL negotiation finished successfully SSL Connection Established eaptls_process returned 13 rlm_eap_peap: EAPTLS_HANDLED rlm_eap: Freeing handler modcall[authenticate]: module "eap" returns reject for request 40 modcall: leaving group authenticate (returns reject) for request 40 auth: Failed to validate the user. Delaying request 40 for 1 seconds Finished request 40 Going to the next request Waking up in 5 seconds... rad_recv: Access-Request packet from host 10.50.1.38:1034, id=56, length=156 User-Name = "lwang" NAS-IP-Address = 10.50.1.38 NAS-Identifier = "QA-AP1-21f0" NAS-Port = 0 Called-Station-Id = "00-19-77-00-21-F5:vocera_test" Calling-Station-Id = "00-16-41-F7-F7-75" Framed-MTU = 1500 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" Message-Authenticator = 0x834864649ecf9fba4cbd71673b5bb042 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 41 modcall[authorize]: module "preprocess" returns ok for request 41 radius_xlat: '/usr/local/var/log/radius/radacct/auth-detail-20080212' rlm_detail: /usr/local/var/log/radius/radacct/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/auth-detail-20080212 modcall[authorize]: module "auth_log" returns ok for request 41 modcall[authorize]: module "chap" returns noop for request 41 modcall[authorize]: module "mschap" returns noop for request 41 rlm_realm: No '@' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 41 rlm_realm: No '\' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "ntdomain" returns noop for request 41 rlm_eap: No EAP-Message, not doing EAP modcall[authorize]: module "eap" returns noop for request 41 users: Matched entry lwang at line 95 modcall[authorize]: module "files" returns ok for request 41 modcall: leaving group authorize (returns ok) for request 41 auth: type Local auth: No User-Password or CHAP-Password attribute in the request auth: Failed to validate the user. Delaying request 41 for 1 seconds Finished request 41 Going to the next request Waking up in 5 seconds... rad_recv: Access-Request packet from host 10.50.1.38:1034, id=57, length=156 User-Name = "lwang" NAS-IP-Address = 10.50.1.38 NAS-Identifier = "QA-AP1-21f0" NAS-Port = 0 Called-Station-Id = "00-19-77-00-21-F5:vocera_test" Calling-Station-Id = "00-16-41-F7-F7-75" Framed-MTU = 1500 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" Message-Authenticator = 0xfe7dea9b1f1eb6e620980f6f09a97012 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 42 modcall[authorize]: module "preprocess" returns ok for request 42 radius_xlat: '/usr/local/var/log/radius/radacct/auth-detail-20080212' rlm_detail: /usr/local/var/log/radius/radacct/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/auth-detail-20080212 modcall[authorize]: module "auth_log" returns ok for request 42 modcall[authorize]: module "chap" returns noop for request 42 modcall[authorize]: module "mschap" returns noop for request 42 rlm_realm: No '@' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 42 rlm_realm: No '\' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "ntdomain" returns noop for request 42 rlm_eap: No EAP-Message, not doing EAP modcall[authorize]: module "eap" returns noop for request 42 users: Matched entry lwang at line 95 modcall[authorize]: module "files" returns ok for request 42 modcall: leaving group authorize (returns ok) for request 42 auth: type Local auth: No User-Password or CHAP-Password attribute in the request auth: Failed to validate the user. Delaying request 42 for 1 seconds Finished request 42 Going to the next request --- Walking the entire request list --- Sending Access-Reject of id 51 to 10.50.1.38 port 1034 Sending Access-Reject of id 55 to 10.50.1.38 port 1034 EAP-Message = 0x040a0004 Message-Authenticator = 0x00000000000000000000000000000000 Sending Access-Reject of id 56 to 10.50.1.38 port 1034 --------------------------------- 雅虎邮箱传递新年祝福，个性贺卡送亲朋！ rad_recv: Access-Request packet from host 10.50.1.38:1034, id=51, length=184 User-Name = "lwang" NAS-IP-Address = 10.50.1.38 NAS-Identifier = "QA-AP1-21f0" NAS-Port = 0 Called-Station-Id = "00-19-77-00-21-F5:vocera_test" Calling-Station-Id = "00-16-41-F7-F7-75" Framed-MTU = 1500 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x0205000819801503 State = 0xe84cfd135516709bf6abae7113b60657 Message-Authenticator = 0xa133f6434f2160a46099f9e0b27ed064 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 36 modcall[authorize]: module "preprocess" returns ok for request 36 radius_xlat: '/usr/local/var/log/radius/radacct/auth-detail-20080212' rlm_detail: /usr/local/var/log/radius/radacct/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/auth-detail-20080212 modcall[authorize]: module "auth_log" returns ok for request 36 modcall[authorize]: module "chap" returns noop for request 36 modcall[authorize]: module "mschap" returns noop for request 36 rlm_realm: No '@' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 36 rlm_realm: No '\' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "ntdomain" returns noop for request 36 rlm_eap: EAP packet type response id 5 length 8 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 36 users: Matched entry lwang at line 95 modcall[authorize]: module "files" returns ok for request 36 modcall: leaving group authorize (returns updated) for request 36 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 36 rlm_eap: Request not found in the list rlm_eap: Either EAP-request timed out OR EAP-response to an unknown EAP-request rlm_eap: Failed in handler modcall[authenticate]: module "eap" returns invalid for request 36 modcall: leaving group authenticate (returns invalid) for request 36 auth: Failed to validate the user. Delaying request 36 for 1 seconds Finished request 36 Going to the next request Waking up in 5 seconds... rad_recv: Access-Request packet from host 10.50.1.38:1034, id=52, length=168 User-Name = "lwang" NAS-IP-Address = 10.50.1.38 NAS-Identifier = "QA-AP1-21f0" NAS-Port = 0 Called-Station-Id = "00-19-77-00-21-F5:vocera_test" Calling-Station-Id = "00-16-41-F7-F7-75" Framed-MTU = 1500 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x0207000a016c77616e67 Message-Authenticator = 0xd91d607c57472b2b534944a8d6630d0e Processing the authorize section of radiusd.conf modcall: entering group authorize for request 37 modcall[authorize]: module "preprocess" returns ok for request 37 radius_xlat: '/usr/local/var/log/radius/radacct/auth-detail-20080212' rlm_detail: /usr/local/var/log/radius/radacct/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/auth-detail-20080212 modcall[authorize]: module "auth_log" returns ok for request 37 modcall[authorize]: module "chap" returns noop for request 37 modcall[authorize]: module "mschap" returns noop for request 37 rlm_realm: No '@' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 37 rlm_realm: No '\' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "ntdomain" returns noop for request 37 rlm_eap: EAP packet type response id 7 length 10 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 37 users: Matched entry lwang at line 95 modcall[authorize]: module "files" returns ok for request 37 modcall: leaving group authorize (returns updated) for request 37 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 37 rlm_eap: EAP Identity rlm_eap: processing type md5 rlm_eap_md5: Issuing Challenge modcall[authenticate]: module "eap" returns handled for request 37 modcall: leaving group authenticate (returns handled) for request 37 Sending Access-Challenge of id 52 to 10.50.1.38 port 1034 EAP-Message = 0x0108001604104a82c158ba7bb7e572bf085b0ae2a3ce Message-Authenticator = 0x00000000000000000000000000000000 State = 0x5b52e8b66679defae03d024f61db78a4 Finished request 37 Going to the next request Waking up in 5 seconds... rad_recv: Access-Request packet from host 10.50.1.38:1034, id=53, length=184 User-Name = "lwang" NAS-IP-Address = 10.50.1.38 NAS-Identifier = "QA-AP1-21f0" NAS-Port = 0 Called-Station-Id = "00-19-77-00-21-F5:vocera_test" Calling-Station-Id = "00-16-41-F7-F7-75" Framed-MTU = 1500 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x0208000803199fbb State = 0x5b52e8b66679defae03d024f61db78a4 Message-Authenticator = 0xf6e209d24fc80cc9a970212ec3452143 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 38 modcall[authorize]: module "preprocess" returns ok for request 38 radius_xlat: '/usr/local/var/log/radius/radacct/auth-detail-20080212' rlm_detail: /usr/local/var/log/radius/radacct/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/auth-detail-20080212 modcall[authorize]: module "auth_log" returns ok for request 38 modcall[authorize]: module "chap" returns noop for request 38 modcall[authorize]: module "mschap" returns noop for request 38 rlm_realm: No '@' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 38 rlm_realm: No '\' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "ntdomain" returns noop for request 38 rlm_eap: EAP packet type response id 8 length 8 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 38 users: Matched entry lwang at line 95 modcall[authorize]: module "files" returns ok for request 38 modcall: leaving group authorize (returns updated) for request 38 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 38 rlm_eap: Request found, released from the list rlm_eap: EAP NAK rlm_eap: EAP-NAK asked for EAP-Type/peap rlm_eap: processing type tls rlm_eap_tls: Initiate rlm_eap_tls: Start returned 1 modcall[authenticate]: module "eap" returns handled for request 38 modcall: leaving group authenticate (returns handled) for request 38 Sending Access-Challenge of id 53 to 10.50.1.38 port 1034 EAP-Message = 0x010900061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x1f71ceb729cf8dd843503ad3d1143fbd Finished request 38 Going to the next request Waking up in 5 seconds... rad_recv: Access-Request packet from host 10.50.1.38:1034, id=54, length=270 User-Name = "lwang" NAS-IP-Address = 10.50.1.38 NAS-Identifier = "QA-AP1-21f0" NAS-Port = 0 Called-Station-Id = "00-19-77-00-21-F5:vocera_test" Calling-Station-Id = "00-16-41-F7-F7-75" Framed-MTU = 1500 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x0209005e198000000054160301004f0100004b030100000b2e660b4d53b6904c9388b8333940d93bc9ddd92253aab97b6a046d003d2039ea6005dca4832f4ca678e7364aa617fa1a73d878d6d18fadd5214fe89e87d30004000500040100 State = 0x1f71ceb729cf8dd843503ad3d1143fbd Message-Authenticator = 0x9a47dcdd414b0e3405f5ba80472d5996 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 39 modcall[authorize]: module "preprocess" returns ok for request 39 radius_xlat: '/usr/local/var/log/radius/radacct/auth-detail-20080212' rlm_detail: /usr/local/var/log/radius/radacct/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/auth-detail-20080212 modcall[authorize]: module "auth_log" returns ok for request 39 modcall[authorize]: module "chap" returns noop for request 39 modcall[authorize]: module "mschap" returns noop for request 39 rlm_realm: No '@' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 39 rlm_realm: No '\' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "ntdomain" returns noop for request 39 rlm_eap: EAP packet type response id 9 length 94 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 39 users: Matched entry lwang at line 95 modcall[authorize]: module "files" returns ok for request 39 modcall: leaving group authorize (returns updated) for request 39 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 39 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: Length Included eaptls_verify returned 11 (other): before/accept initialization TLS_accept: before/accept initialization rlm_eap_tls: <<< TLS 1.0 Handshake [length 004f], 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 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 TLS_accept: Need to read more data: SSLv3 read finished A In SSL Handshake Phase In SSL Accept mode eaptls_process returned 13 rlm_eap_peap: EAPTLS_HANDLED modcall[authenticate]: module "eap" returns handled for request 39 modcall: leaving group authenticate (returns handled) for request 39 Sending Access-Challenge of id 54 to 10.50.1.38 port 1034 EAP-Message = 0x010a00841900160301004a02000046030147b20435b84f8a3cf519ad0182abd419e199aedc74339134db68fdaded807fb22039ea6005dca4832f4ca678e7364aa617fa1a73d878d6d18fadd5214fe89e87d30005001403010001011603010024ca6d41fd9f4101a29f5cf01683b78485d2275ea68bc1b30b0c5b0e7021280ae33c84373b Message-Authenticator = 0x00000000000000000000000000000000 State = 0xfd6f3b2761e20233acdc5d29ec63d11f Finished request 39 Going to the next request Waking up in 5 seconds... rad_recv: Access-Request packet from host 10.50.1.38:1034, id=55, length=233 User-Name = "lwang" NAS-IP-Address = 10.50.1.38 NAS-Identifier = "QA-AP1-21f0" NAS-Port = 0 Called-Station-Id = "00-19-77-00-21-F5:vocera_test" Calling-Station-Id = "00-16-41-F7-F7-75" Framed-MTU = 1500 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" EAP-Message = 0x020a003919800000002f14030100010116030100248393f1d6391a86ab0605df998e0336f7c651a560328bf621b1ddebbfad332d8ea8796c49 State = 0xfd6f3b2761e20233acdc5d29ec63d11f Message-Authenticator = 0xc4ee170f5d47ee55bead80b4a36580cb Processing the authorize section of radiusd.conf modcall: entering group authorize for request 40 modcall[authorize]: module "preprocess" returns ok for request 40 radius_xlat: '/usr/local/var/log/radius/radacct/auth-detail-20080212' rlm_detail: /usr/local/var/log/radius/radacct/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/auth-detail-20080212 modcall[authorize]: module "auth_log" returns ok for request 40 modcall[authorize]: module "chap" returns noop for request 40 modcall[authorize]: module "mschap" returns noop for request 40 rlm_realm: No '@' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 40 rlm_realm: No '\' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "ntdomain" returns noop for request 40 rlm_eap: EAP packet type response id 10 length 57 rlm_eap: No EAP Start, assuming it's an on-going EAP conversation modcall[authorize]: module "eap" returns updated for request 40 users: Matched entry lwang at line 95 modcall[authorize]: module "files" returns ok for request 40 modcall: leaving group authorize (returns updated) for request 40 rad_check_password: Found Auth-Type EAP auth: type "EAP" Processing the authenticate section of radiusd.conf modcall: entering group authenticate for request 40 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: Length Included eaptls_verify returned 11 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 (other): SSL negotiation finished successfully SSL Connection Established eaptls_process returned 13 rlm_eap_peap: EAPTLS_HANDLED rlm_eap: Freeing handler modcall[authenticate]: module "eap" returns reject for request 40 modcall: leaving group authenticate (returns reject) for request 40 auth: Failed to validate the user. Delaying request 40 for 1 seconds Finished request 40 Going to the next request Waking up in 5 seconds... rad_recv: Access-Request packet from host 10.50.1.38:1034, id=56, length=156 User-Name = "lwang" NAS-IP-Address = 10.50.1.38 NAS-Identifier = "QA-AP1-21f0" NAS-Port = 0 Called-Station-Id = "00-19-77-00-21-F5:vocera_test" Calling-Station-Id = "00-16-41-F7-F7-75" Framed-MTU = 1500 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" Message-Authenticator = 0x834864649ecf9fba4cbd71673b5bb042 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 41 modcall[authorize]: module "preprocess" returns ok for request 41 radius_xlat: '/usr/local/var/log/radius/radacct/auth-detail-20080212' rlm_detail: /usr/local/var/log/radius/radacct/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/auth-detail-20080212 modcall[authorize]: module "auth_log" returns ok for request 41 modcall[authorize]: module "chap" returns noop for request 41 modcall[authorize]: module "mschap" returns noop for request 41 rlm_realm: No '@' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 41 rlm_realm: No '\' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "ntdomain" returns noop for request 41 rlm_eap: No EAP-Message, not doing EAP modcall[authorize]: module "eap" returns noop for request 41 users: Matched entry lwang at line 95 modcall[authorize]: module "files" returns ok for request 41 modcall: leaving group authorize (returns ok) for request 41 auth: type Local auth: No User-Password or CHAP-Password attribute in the request auth: Failed to validate the user. Delaying request 41 for 1 seconds Finished request 41 Going to the next request Waking up in 5 seconds... rad_recv: Access-Request packet from host 10.50.1.38:1034, id=57, length=156 User-Name = "lwang" NAS-IP-Address = 10.50.1.38 NAS-Identifier = "QA-AP1-21f0" NAS-Port = 0 Called-Station-Id = "00-19-77-00-21-F5:vocera_test" Calling-Station-Id = "00-16-41-F7-F7-75" Framed-MTU = 1500 NAS-Port-Type = Wireless-802.11 Connect-Info = "CONNECT 11Mbps 802.11b" Message-Authenticator = 0xfe7dea9b1f1eb6e620980f6f09a97012 Processing the authorize section of radiusd.conf modcall: entering group authorize for request 42 modcall[authorize]: module "preprocess" returns ok for request 42 radius_xlat: '/usr/local/var/log/radius/radacct/auth-detail-20080212' rlm_detail: /usr/local/var/log/radius/radacct/auth-detail-%Y%m%d expands to /usr/local/var/log/radius/radacct/auth-detail-20080212 modcall[authorize]: module "auth_log" returns ok for request 42 modcall[authorize]: module "chap" returns noop for request 42 modcall[authorize]: module "mschap" returns noop for request 42 rlm_realm: No '@' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 42 rlm_realm: No '\' in User-Name = "lwang", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "ntdomain" returns noop for request 42 rlm_eap: No EAP-Message, not doing EAP modcall[authorize]: module "eap" returns noop for request 42 users: Matched entry lwang at line 95 modcall[authorize]: module "files" returns ok for request 42 modcall: leaving group authorize (returns ok) for request 42 auth: type Local auth: No User-Password or CHAP-Password attribute in the request auth: Failed to validate the user. Delaying request 42 for 1 seconds Finished request 42 Going to the next request --- Walking the entire request list --- Sending Access-Reject of id 51 to 10.50.1.38 port 1034 Sending Access-Reject of id 55 to 10.50.1.38 port 1034 EAP-Message = 0x040a0004 Message-Authenticator = 0x00000000000000000000000000000000 Sending Access-Reject of id 56 to 10.50.1.38 port 1034

2 1