February 2008 - Freeradius-Users - lists.freeradius.org

one username and 2 NAS
by Enrico Fanti 19 Feb '08

19 Feb '08

Hi , I have freeradius configured with Mysql. I would like to have a user "pippo" can ssh login to 2 server linux wich uses pam_radius in /etc/pam.d/sshd (i.e. 2 NAS , same username). Freeradius must make the control if NAS-IP Address is ok for this user in the radcheck table.. I use the "==" operator end my radcheck table is: mysql> SELECT id, UserName, Attribute, Value, op from radcheck WHERE Username = 'pippo' order by id; +----+----------+----------------+---------------+----+ | id | UserName | Attribute | Value | op | +----+----------+----------------+---------------+----+ | 39 | pippo | NAS-IP-Address | 10.0.0.52 <http://10.0.0.52> | == | | 40 | pippo | NAS-IP-Address | 10.0.0.49 <http://10.0.0.49> | == | | 41 | pippo | Expiration | 1203325200 | == | | 42 | pippo | Crypt-Password | v7fawImvQUoXM | == | +----+----------+----------------+---------------+----+ It doesn't work...... Some ideas ??? Thank you Enrico

2 5

proxed EAP and eduroam project
by inverse 19 Feb '08

19 Feb '08

hi all, rather than a problem, this is a question. I assume you know what eduroam is, but just in case: What is eduroam eduroam which stands for Education Roaming, is a RADIUS-based infrastructure that uses 802.1X security technology to allow for inter-institutional roaming. Substitute institutional with 'university' and you get the picture. So basically this is a hierarchy of radius servers at european level. Implementing it from my side (that of a university) has been rather trivial. What happens is that the EAP conversation traverls in cleartext across the public internet (really the inter-university networks). I would assume that EAP-TLS is highly safe from this point of view, am I right? Bye Inverse -- "In a sea of glass shards, I hear you screaming" --icchan

4 5

EAP/PEAP inner identity and rlm_exec
by Kolbjørn Barmen 19 Feb '08

19 Feb '08

I'm trying to use a selfmade script to decide VLAN-attributes for EAP/PEAP users: DEFAULT Realm == realm.org Tunnel-Type = VLAN, Tunnel-Medium-Type = IEEE-802, Tunnel-Private-Group-Id = `%{exec:/usr/sbin/ldap2vlan %{User-Name}` However, it only works for the so called "outter" identity. Any tip on how to make it work for the "inner" identity instead? -- Kolbjørn Barmen UNINETT Driftsenter

2 1

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