- Freeradius-Users - lists.freeradius.org

Testing WAP EAP from wired network?
by Jonathan D. Proulx 15 Oct '08

15 Oct '08

Hi All, This is probably a pipe dream, but... I'm desperately trying to get a WPA2 wireless system up at a remote site, I'm not using EAP-MD5 so radeapclient can't help me. At last test radclient authenticates and authorizes the way I want but EAP from an actual wireless supplicant fails. I have some input on what I might do to fix this but given the "remote" bit I can't test it as readily as I'd like. My question is if I set up 802.1x on a wired port (with a multi homed host so I can get to it through the back door as it were), would this be a valid test or do I just need to wait untill I can make a (relatively short) trip on site? I'm not clear on how the wired and wireless versions differ. Thanks, -Jon

3 3

Filter-Id SQL xlat function
by Ljupco Vangelski 15 Oct '08

15 Oct '08

Hi I want FreeRADIUS to return the Filter-Id attribute, on behalf of a service of the client which is in another table (not in radreply or radgroupreply). The idea is to have a different Filter-Id depending on the region the client is connecting to (which means depending on the CallingStation-Id parameter). So I have a separate table in which CallingStation-Ids and Filter-Ids are mapped. For example: mysql> select service from userinfo where username='ljupco' limit 1; +---------+ | service | +---------+ | net1 | +---------+ Now if I put that query in the Filter-Id, the XLAT function doesn't get executed: ==In radreply===================================== UserName......Attribute..........op.........Value ljupco............Filter-Id.............=.........%{sql:select service from userinfo where username='ljupco' limit 1;} ============================================== # radtest ljupco ljupco localhost 523 testing123 Sending Access-Request of id 201 to 127.0.0.1 port 1812 User-Name = "ljupco" User-Password = "ljupco" NAS-IP-Address = 255.255.255.255 NAS-Port = 523 rad_recv: Access-Accept packet from host 127.0.0.1:1812, id=201, length=89 Filter-Id = "%{sql:select service from userinfo where username='ljupco' limit 1;}" Instead of "%{sql:select service from userinfo where username='ljupco' limit 1;}" there should be net1. How can I do this? Output from radiusd -X (freeradius v1.1.6) rad_recv: Access-Request packet from host 127.0.0.1:59998, id=201, length=58 User-Name = "ljupco" User-Password = "ljupco" NAS-IP-Address = 255.255.255.255 NAS-Port = 523 rad_lowerpair: User-Name now 'ljupco' Processing the authorize section of radiusd.conf modcall: entering group authorize for request 7 modcall[authorize]: module "preprocess" returns ok for request 7 modcall[authorize]: module "chap" returns noop for request 7 modcall[authorize]: module "mschap" returns noop for request 7 rlm_realm: No '@' in User-Name = "ljupco", looking up realm NULL rlm_realm: No such realm "NULL" modcall[authorize]: module "suffix" returns noop for request 7 rlm_eap: No EAP-Message, not doing EAP modcall[authorize]: module "eap" returns noop for request 7 radius_xlat: 'ljupco' rlm_sql (sql): sql_set_user escaped user --> 'ljupco' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radcheck WHERE Username = 'ljupco' ORDER BY id' rlm_sql (sql): Reserving sql socket id: 3 radius_xlat: 'SELECT radgroupcheck.id,radgroupcheck.GroupName,radgroupcheck.Attribute,radgroupcheck.Value,radgroupcheck.op FROM radgroupcheck,usergroup WHERE usergroup.Username = 'ljupco' AND usergroup.GroupName = radgroupcheck.GroupName ORDER BY radgroupcheck.id' radius_xlat: 'SELECT id, UserName, Attribute, Value, op FROM radreply WHERE Username = 'ljupco' ORDER BY id' radius_xlat: 'SELECT radgroupreply.id,radgroupreply.GroupName,radgroupreply.Attribute,radgroupreply.Value,radgroupreply.op FROM radgroupreply,usergroup WHERE usergroup.Username = 'ljupco' AND usergroup.GroupName = radgroupreply.GroupName ORDER BY radgroupreply.id' rlm_sql (sql): Released sql socket id: 3 modcall[authorize]: module "sql" returns ok for request 7 modcall[authorize]: module "pap" returns updated for request 7 modcall: leaving group authorize (returns updated) for request 7 rad_check_password: Found Auth-Type pap auth: type "PAP" Processing the authenticate section of radiusd.conf modcall: entering group PAP for request 7 rlm_pap: login attempt with password ljupco rlm_pap: Using clear text password "ljupco". rlm_pap: User authenticated successfully modcall[authenticate]: module "pap" returns ok for request 7 modcall: leaving group PAP (returns ok) for request 7 Login OK: [ljupco/ljupco] (from client localhost port 523) Processing the post-auth section of radiusd.conf modcall: entering group post-auth for request 7 rlm_sql (sql): Processing sql_postauth radius_xlat: 'ljupco' rlm_sql (sql): sql_set_user escaped user --> 'ljupco' radius_xlat: 'INSERT into radpostauth (id, user, pass, reply, date) values ('', 'ljupco', 'ljupco', 'Access-Accept', NOW())' rlm_sql (sql) in sql_postauth: query is INSERT into radpostauth (id, user, pass, reply, date) values ('', 'ljupco', 'ljupco', 'Access-Accept', NOW()) rlm_sql (sql): Reserving sql socket id: 2 rlm_sql (sql): Released sql socket id: 2 modcall[post-auth]: module "sql" returns ok for request 7 modcall: leaving group post-auth (returns ok) for request 7 Sending Access-Accept of id 201 to 127.0.0.1 port 59998 Filter-Id = "%{sql:select service from userinfo where username='ljupco' limit 1}" Finished request 7 Going to the next request Tried as well with freeradius v2.0.5, the result is the same. Regards, -- Ljupco

2 2

redundant + load balancing not working?
by ST Wong (ITSC) 15 Oct '08

15 Oct '08

Hi all, I'm using freeradius 2.1.1 on CentOS 5.2. I've 2 ldap servers for authentication. It works when I specify: redundant { ldap1 ldap2 } As expected, requests go to ldap2 when ldap1 is down. However, when I specify the 2 ldap servers like following: redundant-load-balance { ldap1 ldap2 } The effect is just like redundant. All requests go still go to ldap1 instead of load balancing. Did I miss anything? Thanks a lot. /ST Wong

2 1

rlm_perl not working as expected on 2.0.5
by Eric Martell 15 Oct '08

15 Oct '08

Hi I am having similar problems like this thread http://lists.freeradius.org/mailman/htdig/freeradius-users/2008-August/msg0… Also I followed everything in http://wiki.freeradius.org/Rlm_perl Here is my radiusd -X log. Please let me know if I miss anything. Thanks and Regards. # ./radiusd -X -d /opt/freeradius-2.0.5/etc/raddb FreeRADIUS Version 2.0.5, for host i686-pc-linux-gnu, built on Oct 14 2008 at 12:32:23 Copyright (C) 1999-2008 The FreeRADIUS server project and contributors. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. You may redistribute copies of FreeRADIUS under the terms of the GNU General Public License v2. Starting - reading configuration files ... including configuration file /opt/freeradius-2.0.5/etc/raddb/radiusd.conf including configuration file /opt/freeradius-2.0.5/etc/raddb/proxy.conf including configuration file /opt/freeradius-2.0.5/etc/raddb/clients.conf including configuration file /opt/freeradius-2.0.5/etc/raddb/snmp.conf including files in directory /opt/freeradius-2.0.5/etc/raddb/modules/ including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/preprocess including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/exec including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/checkval including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/smbpasswd including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/radutmp including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/ldap including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/detail.log including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/krb5 including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/etc_group including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/attr_filter including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/expr including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/passwd including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/unix including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/detail including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/sradutmp including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/policy including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/logintime including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/pam including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/sql_log including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/attr_rewrite including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/files including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/pap including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/counter including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/mschap including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/realm including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/echo including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/digest including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/always including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/acct_unique including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/mac2vlan including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/chap including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/mac2ip including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/expiration including configuration file /opt/freeradius-2.0.5/etc/raddb/modules/ippool including configuration file /opt/freeradius-2.0.5/etc/raddb/eap.conf including configuration file /opt/freeradius-2.0.5/etc/raddb/sql.conf including configuration file /opt/freeradius-2.0.5/etc/raddb/sql/mysql/dialup.conf including configuration file /opt/freeradius-2.0.5/etc/raddb/sql/mysql/counter.conf including configuration file /opt/freeradius-2.0.5/etc/raddb/policy.conf including files in directory /opt/freeradius-2.0.5/etc/raddb/sites-enabled/ including configuration file /opt/freeradius-2.0.5/etc/raddb/sites-enabled/inner-tunnel including configuration file /opt/freeradius-2.0.5/etc/raddb/sites-enabled/default including dictionary file /opt/freeradius-2.0.5/etc/raddb/dictionary main { prefix = "/opt/freeradius-2.0.5" localstatedir = "/opt/freeradius-2.0.5/var" logdir = "/opt/freeradius-2.0.5/var/log/radius" libdir = "/opt/freeradius-2.0.5/lib" radacctdir = "/opt/freeradius-2.0.5/var/log/radius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 1024 allow_core_dumps = no pidfile = "/opt/freeradius-2.0.5/var/run/radiusd/radiusd.pid" checkrad = "/opt/freeradius-2.0.5/sbin/checkrad" debug_level = 0 proxy_requests = yes log { stripped_names = no auth = no auth_badpass = no auth_goodpass = no } } client localhost { ipaddr = 127.0.0.1 require_message_authenticator = no secret = "testing123" nastype = "other" } radiusd: #### Loading Realms and Home Servers #### proxy server { retry_delay = 5 retry_count = 3 default_fallback = no dead_time = 120 wake_all_if_all_dead = no } home_server localhost { ipaddr = 127.0.0.1 port = 1812 type = "auth" secret = "testing123" response_window = 20 max_outstanding = 65536 zombie_period = 40 status_check = "status-server" ping_check = "none" ping_interval = 30 check_interval = 30 num_answers_to_alive = 3 num_pings_to_alive = 3 revive_interval = 120 status_check_timeout = 4 } home_server_pool my_auth_failover { type = fail-over home_server = localhost } realm example.com { auth_pool = my_auth_failover } realm LOCAL { } realm raddb.net { authhost = LOCAL accthost = LOCAL } radiusd: #### Instantiating modules #### instantiate { Module: Linked to module rlm_exec Module: Instantiating exec exec { wait = no input_pairs = "request" shell_escape = yes } Module: Linked to module rlm_perl Module: Instantiating perl perl { module = "/home/user/test.pl" func_authorize = "authorize" func_authenticate = "authenticate" func_accounting = "accounting" func_preacct = "preacct" func_checksimul = "checksimul" func_detach = "detach" func_xlat = "xlat" func_pre_proxy = "pre_proxy" func_post_proxy = "post_proxy" func_post_auth = "post_auth" } perl { max_clones = 32 start_clones = 32 min_spare_clones = 0 max_spare_clones = 32 cleanup_delay = 5 max_request_per_clone = 0 } Module: Linked to module rlm_expr Module: Instantiating expr Module: Linked to module rlm_expiration Module: Instantiating expiration expiration { reply-message = "Password Has Expired " } Module: Linked to module rlm_logintime Module: Instantiating logintime logintime { reply-message = "You are calling outside your allowed timespan " minimum-timeout = 60 } } radiusd: #### Loading Virtual Servers #### server inner-tunnel { modules { Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_pap Module: Instantiating pap pap { encryption_scheme = "auto" auto_header = no } Module: Linked to module rlm_chap Module: Instantiating chap Module: Linked to module rlm_mschap Module: Instantiating mschap mschap { use_mppe = yes require_encryption = no require_strong = no with_ntdomain_hack = no } Module: Linked to module rlm_unix Module: Instantiating unix unix { radwtmp = "/opt/freeradius-2.0.5/var/log/radius/radwtmp" } Module: Linked to module rlm_eap Module: Instantiating eap eap { default_eap_type = "md5" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no } Module: Linked to sub-module rlm_eap_md5 Module: Instantiating eap-md5 Module: Linked to sub-module rlm_eap_leap Module: Instantiating eap-leap Module: Linked to sub-module rlm_eap_gtc Module: Instantiating eap-gtc gtc { challenge = "Password: " auth_type = "PAP" } Module: Linked to sub-module rlm_eap_tls Module: Instantiating eap-tls tls { rsa_key_exchange = no dh_key_exchange = yes rsa_key_length = 512 dh_key_length = 512 verify_depth = 0 pem_file_type = yes private_key_file = "/opt/freeradius-2.0.5/etc/raddb/certs/server.pem" certificate_file = "/opt/freeradius-2.0.5/etc/raddb/certs/server.pem" CA_file = "/opt/freeradius-2.0.5/etc/raddb/certs/ca.pem" private_key_password = "whatever" dh_file = "/opt/freeradius-2.0.5/etc/raddb/certs/dh" random_file = "/opt/freeradius-2.0.5/etc/raddb/certs/random" fragment_size = 1024 include_length = yes check_crl = no cipher_list = "DEFAULT" make_cert_command = "/opt/freeradius-2.0.5/etc/raddb/certs/bootstrap" } Module: Linked to sub-module rlm_eap_ttls Module: Instantiating eap-ttls ttls { default_eap_type = "md5" copy_request_to_tunnel = no use_tunneled_reply = no virtual_server = "inner-tunnel" } Module: Linked to sub-module rlm_eap_peap Module: Instantiating eap-peap peap { default_eap_type = "mschapv2" copy_request_to_tunnel = no use_tunneled_reply = no proxy_tunneled_request_as_eap = yes virtual_server = "inner-tunnel" } Module: Linked to sub-module rlm_eap_mschapv2 Module: Instantiating eap-mschapv2 mschapv2 { with_ntdomain_hack = no } Module: Checking authorize {...} for more modules to load Module: Linked to module rlm_realm Module: Instantiating suffix realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } Module: Linked to module rlm_files Module: Instantiating files files { usersfile = "/opt/freeradius-2.0.5/etc/raddb/users" acctusersfile = "/opt/freeradius-2.0.5/etc/raddb/acct_users" preproxy_usersfile = "/opt/freeradius-2.0.5/etc/raddb/preproxy_users" compat = "no" } /opt/freeradius-2.0.5/etc/raddb/users[169]: Parse error (check) for entry DEFAULT: Unknown value Perl for attribute Auth-Type Errors reading /opt/freeradius-2.0.5/etc/raddb/users /opt/freeradius-2.0.5/etc/raddb/modules/files[7]: Instantiation failed for module "files" /opt/freeradius-2.0.5/etc/raddb/sites-enabled/inner-tunnel[111]: Failed to find module "files". /opt/freeradius-2.0.5/etc/raddb/sites-enabled/inner-tunnel[34]: Errors parsing authorize section. } } Errors initializing modules # # #

2 1

Best method to filter on calling-station-ID/IP Address?
by D J 14 Oct '08

14 Oct '08

All, I have VPN users who connect to a Cisco ASA firewall, which authenticates using radius off of Freeradius. I would like to enforce which IP addresses users may connect from. Am I correct to assume the Radius server is the best place to perform this? If so, what is the best way to go about doing this? Since our users.conf is programitcally generated, hopefully the changing part of the configuration can be isolated to this file? Below is an example login from the free-radius server. I want to filter on "Calling-Station-Id", to enforce a specified source IP which may vary by user. Thanks! rad_recv: Access-Request packet from host 3.3.3.3:1025, id=177, length=157 User-Name = "john" User-Password = "xxxx" NAS-Port = xxxx Service-Type = Framed-User Framed-Protocol = PPP Called-Station-Id = "1.1.1.1" Calling-Station-Id = "2.2.2.2" NAS-Port-Type = Virtual Tunnel-Client-Endpoint:0 = "4.4.4.4" NAS-IP-Address = 3.3.3.3 Cisco-AVPair = "ip:source-ip=2.2.2.2N\233" Processing the authorize section of radiusd.conf

2 1

Error in the negotiations certificates
by Martin Silvero 14 Oct '08

14 Oct '08

Hello people! I was watching this problems https://lists.freeradius.org/pipermail/freeradius-users/2008-October/msg002… to solve my problem with the certificates but do not understand very well the suggestion. My problem is with insurance certificates, what I need is a certificate to anyone who serves me, this created a user and their respective licenses but when I want to connect me generates the following error: rad_recv: Access-Request packet from host 10.0.31.40 port 1645, id=254, length=136 User-Name = "cert" Framed-MTU = 1400 Called-Station-Id = "0019.2fdb.9e00" Calling-Station-Id = "001f.3c22.44c5" Service-Type = Login-User Message-Authenticator = 0x7eba201ec8bca0ce6d69fb1d2b8fa434 EAP-Message = 0x020100090163657274 NAS-Port-Type = Wireless-802.11 NAS-Port = 923 NAS-IP-Address = 10.0.31.40 NAS-Identifier = "ap-Reconquista-31" Tue Oct 14 17:50:56 2008 : Debug: +- entering group authorize Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 0 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 0 Tue Oct 14 17:50:56 2008 : Debug: ++[preprocess] returns ok Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 0 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 0 Tue Oct 14 17:50:56 2008 : Debug: ++[chap] returns noop Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 0 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 0 Tue Oct 14 17:50:56 2008 : Debug: ++[mschap] returns noop Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 0 Tue Oct 14 17:50:56 2008 : Debug: rlm_realm: No '@' in User-Name = "cert", looking up realm NULL Tue Oct 14 17:50:56 2008 : Debug: rlm_realm: No such realm "NULL" Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 0 Tue Oct 14 17:50:56 2008 : Debug: ++[suffix] returns noop Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 0 Tue Oct 14 17:50:56 2008 : Debug: rlm_eap: EAP packet type response id 1 length 9 Tue Oct 14 17:50:56 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 0 Tue Oct 14 17:50:56 2008 : Debug: ++[eap] returns updated Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling unix (rlm_unix) for request 0 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from unix (rlm_unix) for request 0 Tue Oct 14 17:50:56 2008 : Debug: ++[unix] returns notfound Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 0 Tue Oct 14 17:50:56 2008 : Debug: users: Matched entry cert at line 76 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 0 Tue Oct 14 17:50:56 2008 : Debug: ++[files] returns ok Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling expiration (rlm_expiration) for request 0 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from expiration (rlm_expiration) for request 0 Tue Oct 14 17:50:56 2008 : Debug: ++[expiration] returns noop Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling logintime (rlm_logintime) for request 0 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from logintime (rlm_logintime) for request 0 Tue Oct 14 17:50:56 2008 : Debug: ++[logintime] returns noop Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 0 Tue Oct 14 17:50:56 2008 : Debug: rlm_pap: Found existing Auth-Type, not changing it. Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 0 Tue Oct 14 17:50:56 2008 : Debug: ++[pap] returns noop Tue Oct 14 17:50:56 2008 : Debug: rad_check_password: Found Auth-Type EAP Tue Oct 14 17:50:56 2008 : Debug: auth: type "EAP" Tue Oct 14 17:50:56 2008 : Debug: +- entering group authenticate Tue Oct 14 17:50:56 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 0 Tue Oct 14 17:50:56 2008 : Debug: rlm_eap: EAP Identity Tue Oct 14 17:50:56 2008 : Debug: rlm_eap: processing type md5 Tue Oct 14 17:50:56 2008 : Debug: rlm_eap_md5: Issuing Challenge Tue Oct 14 17:50:56 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 0 Tue Oct 14 17:50:56 2008 : Debug: ++[eap] returns handled Sending Access-Challenge of id 254 to 10.0.31.40 port 1645 EAP-Message = 0x0102001604105891faeac7cf95672897e7a8a6593391 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2bd9a2512bdba60c046668376d4bbecf Tue Oct 14 17:50:56 2008 : Debug: Finished request 0. Tue Oct 14 17:50:56 2008 : Debug: Going to the next request Tue Oct 14 17:50:56 2008 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.31.40 port 1645, id=255, length=151 User-Name = "cert" Framed-MTU = 1400 Called-Station-Id = "0019.2fdb.9e00" Calling-Station-Id = "001f.3c22.44c5" Service-Type = Login-User Message-Authenticator = 0x029f86b7a5f68f1f5a708b680660ee0b EAP-Message = 0x02020006030d NAS-Port-Type = Wireless-802.11 NAS-Port = 923 State = 0x2bd9a2512bdba60c046668376d4bbecf NAS-IP-Address = 10.0.31.40 NAS-Identifier = "ap-Reconquista-31" Tue Oct 14 17:50:56 2008 : Debug: +- entering group authorize Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 1 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 1 Tue Oct 14 17:50:56 2008 : Debug: ++[preprocess] returns ok Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 1 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 1 Tue Oct 14 17:50:56 2008 : Debug: ++[chap] returns noop Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 1 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 1 Tue Oct 14 17:50:56 2008 : Debug: ++[mschap] returns noop Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 1 Tue Oct 14 17:50:56 2008 : Debug: rlm_realm: No '@' in User-Name = "cert", looking up realm NULL Tue Oct 14 17:50:56 2008 : Debug: rlm_realm: No such realm "NULL" Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 1 Tue Oct 14 17:50:56 2008 : Debug: ++[suffix] returns noop Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 1 Tue Oct 14 17:50:56 2008 : Debug: rlm_eap: EAP packet type response id 2 length 6 Tue Oct 14 17:50:56 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 1 Tue Oct 14 17:50:56 2008 : Debug: ++[eap] returns updated Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling unix (rlm_unix) for request 1 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from unix (rlm_unix) for request 1 Tue Oct 14 17:50:56 2008 : Debug: ++[unix] returns notfound Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 1 Tue Oct 14 17:50:56 2008 : Debug: users: Matched entry cert at line 76 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 1 Tue Oct 14 17:50:56 2008 : Debug: ++[files] returns ok Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling expiration (rlm_expiration) for request 1 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from expiration (rlm_expiration) for request 1 Tue Oct 14 17:50:56 2008 : Debug: ++[expiration] returns noop Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling logintime (rlm_logintime) for request 1 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from logintime (rlm_logintime) for request 1 Tue Oct 14 17:50:56 2008 : Debug: ++[logintime] returns noop Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 1 Tue Oct 14 17:50:56 2008 : Debug: rlm_pap: Found existing Auth-Type, not changing it. Tue Oct 14 17:50:56 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 1 Tue Oct 14 17:50:56 2008 : Debug: ++[pap] returns noop Tue Oct 14 17:50:56 2008 : Debug: rad_check_password: Found Auth-Type EAP Tue Oct 14 17:50:56 2008 : Debug: auth: type "EAP" Tue Oct 14 17:50:56 2008 : Debug: +- entering group authenticate Tue Oct 14 17:50:56 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 1 Tue Oct 14 17:50:56 2008 : Debug: rlm_eap: Request found, released from the list Tue Oct 14 17:50:56 2008 : Debug: rlm_eap: EAP NAK Tue Oct 14 17:50:56 2008 : Debug: rlm_eap: EAP-NAK asked for EAP-Type/tls Tue Oct 14 17:50:56 2008 : Debug: rlm_eap: processing type tls Tue Oct 14 17:50:56 2008 : Debug: rlm_eap_tls: Requiring client certificate Tue Oct 14 17:50:56 2008 : Debug: rlm_eap_tls: Initiate Tue Oct 14 17:50:56 2008 : Debug: rlm_eap_tls: Start returned 1 Tue Oct 14 17:50:56 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 1 Tue Oct 14 17:50:56 2008 : Debug: ++[eap] returns handled Sending Access-Challenge of id 255 to 10.0.31.40 port 1645 EAP-Message = 0x010300060d20 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2bd9a2512adaaf0c046668376d4bbecf Tue Oct 14 17:50:56 2008 : Debug: Finished request 1. Tue Oct 14 17:50:56 2008 : Debug: Going to the next request Tue Oct 14 17:50:56 2008 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 10.0.31.40 port 1645, id=0, length=255 User-Name = "cert" Framed-MTU = 1400 Called-Station-Id = "0019.2fdb.9e00" Calling-Station-Id = "001f.3c22.44c5" Service-Type = Login-User Message-Authenticator = 0xdacedfa862fbfb7ae7b852679c61f8cc EAP-Message = 0x0203006e0d8000000064160301005f0100005b030148f5062db86506be032517f2561a0b321baf4c5e3e07de558c9c2dc63d238a8900003400390038003500160013000a00330032002f006600050004006500640063006200610060001500120009001400110008000600030100 NAS-Port-Type = Wireless-802.11 NAS-Port = 923 State = 0x2bd9a2512adaaf0c046668376d4bbecf NAS-IP-Address = 10.0.31.40 NAS-Identifier = "ap-Reconquista-31" Tue Oct 14 17:50:57 2008 : Debug: +- entering group authorize Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 2 Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 2 Tue Oct 14 17:50:57 2008 : Debug: ++[preprocess] returns ok Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 2 Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 2 Tue Oct 14 17:50:57 2008 : Debug: ++[chap] returns noop Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 2 Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 2 Tue Oct 14 17:50:57 2008 : Debug: ++[mschap] returns noop Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 2 Tue Oct 14 17:50:57 2008 : Debug: rlm_realm: No '@' in User-Name = "cert", looking up realm NULL Tue Oct 14 17:50:57 2008 : Debug: rlm_realm: No such realm "NULL" Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 2 Tue Oct 14 17:50:57 2008 : Debug: ++[suffix] returns noop Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 2 Tue Oct 14 17:50:57 2008 : Debug: rlm_eap: EAP packet type response id 3 length 110 Tue Oct 14 17:50:57 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 2 Tue Oct 14 17:50:57 2008 : Debug: ++[eap] returns updated Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: calling unix (rlm_unix) for request 2 Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: returned from unix (rlm_unix) for request 2 Tue Oct 14 17:50:57 2008 : Debug: ++[unix] returns notfound Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 2 Tue Oct 14 17:50:57 2008 : Debug: users: Matched entry cert at line 76 Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 2 Tue Oct 14 17:50:57 2008 : Debug: ++[files] returns ok Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: calling expiration (rlm_expiration) for request 2 Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: returned from expiration (rlm_expiration) for request 2 Tue Oct 14 17:50:57 2008 : Debug: ++[expiration] returns noop Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: calling logintime (rlm_logintime) for request 2 Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: returned from logintime (rlm_logintime) for request 2 Tue Oct 14 17:50:57 2008 : Debug: ++[logintime] returns noop Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 2 Tue Oct 14 17:50:57 2008 : Debug: rlm_pap: Found existing Auth-Type, not changing it. Tue Oct 14 17:50:57 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 2 Tue Oct 14 17:50:57 2008 : Debug: ++[pap] returns noop Tue Oct 14 17:50:57 2008 : Debug: rad_check_password: Found Auth-Type EAP Tue Oct 14 17:50:57 2008 : Debug: auth: type "EAP" Tue Oct 14 17:50:57 2008 : Debug: +- entering group authenticate Tue Oct 14 17:50:57 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 2 Tue Oct 14 17:50:57 2008 : Debug: rlm_eap: Request found, released from the list Tue Oct 14 17:50:57 2008 : Debug: rlm_eap: EAP/tls Tue Oct 14 17:50:57 2008 : Debug: rlm_eap: processing type tls Tue Oct 14 17:50:57 2008 : Debug: rlm_eap_tls: Authenticate Tue Oct 14 17:50:57 2008 : Debug: rlm_eap_tls: processing TLS Tue Oct 14 17:50:57 2008 : Debug: TLS Length 100 Tue Oct 14 17:50:57 2008 : Debug: rlm_eap_tls: Length Included Tue Oct 14 17:50:57 2008 : Debug: eaptls_verify returned 11 Tue Oct 14 17:50:57 2008 : Debug: (other): before/accept initialization Tue Oct 14 17:50:57 2008 : Debug: TLS_accept: before/accept initialization Tue Oct 14 17:50:57 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 005f], ClientHello Tue Oct 14 17:50:57 2008 : Debug: TLS_accept: SSLv3 read client hello A Tue Oct 14 17:50:57 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello Tue Oct 14 17:50:57 2008 : Debug: TLS_accept: SSLv3 write server hello A Tue Oct 14 17:50:57 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0839], Certificate Tue Oct 14 17:50:57 2008 : Debug: TLS_accept: SSLv3 write certificate A Tue Oct 14 17:50:57 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange Tue Oct 14 17:50:57 2008 : Debug: TLS_accept: SSLv3 write key exchange A Tue Oct 14 17:50:57 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 00a0], CertificateRequest Tue Oct 14 17:50:57 2008 : Debug: TLS_accept: SSLv3 write certificate request A Tue Oct 14 17:50:57 2008 : Debug: TLS_accept: SSLv3 flush data Tue Oct 14 17:50:57 2008 : Debug: TLS_accept: Need to read more data: SSLv3 read client certificate A Tue Oct 14 17:50:57 2008 : Debug: In SSL Handshake Phase Tue Oct 14 17:50:57 2008 : Debug: In SSL Accept mode Tue Oct 14 17:50:57 2008 : Debug: eaptls_process returned 13 Tue Oct 14 17:50:57 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 2 Tue Oct 14 17:50:57 2008 : Debug: ++[eap] returns handled Sending Access-Challenge of id 0 to 10.0.31.40 port 1645 EAP-Message = 0x010404000dc000000b44160301004a02000046030148f50631e271b1ec27b9a3e25b318621dc8fe85c68f645d0fb4ee0d758b6fae22055002a49812a62e07b82c078e9068198316be3da418ce9125c1d7b48cb79cd6100390016030108390b000835000832000396308203923082027aa003020102020101300d06092a864886f70d010104050030818c310b3009060355040613024152311530130603550408130c4275656e6f73204169726573311430120603550407130b5265636f6e717569737461310e300c060355040a130549504c414e3120301e06092a864886f70d0109011611636572744069706c616e2e636f6d2e6172311e301c060355 EAP-Message = 0x04031315436572746966696361746520417574686f72697479301e170d3038313031303134353031385a170d3039313031303134353031385a3073310b3009060355040613024152311530130603550408130c4275656e6f73204169726573310e300c060355040a130549504c414e311b3019060355040313125365727665722043657274696669636174653120301e06092a864886f70d0109011611636572744069706c616e2e636f6d2e617230820122300d06092a864886f70d01010105000382010f003082010a0282010100bacfd3d0fa48b30002182ca8ac9a31672b4ad7dcd6b45d7df598774e7af3c4d6cd46447144260ae3daac561a93e7 EAP-Message = 0xd97d8a9889591b5cd3cf6924d4dc5aaa78a8013bde946b633e51abb4b6150fbe66a8743dd34a887f5c731a685c811c5660ba3d68abd028679464d28af4171dea0a3e99a80ba7b75c10d3c5480a319ea9b9ca6a9d14536b6524eb6f559b10f8f326d612836e88d2b28e03a574ede8b7a7bfdde0a7846543a713bb279c81bb681e50609c10ca2b2f5b6b4b2c1683c9a60ae8c7121ce2a81fc124189d4f356dee804a45b49f71547f788006bc247c65a98e81c2359cc537ef1c65d8137aa6cf6b2aff605d4da97c7a5abad17885608d027ddc370203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104 EAP-Message = 0x050003820101008c4607f2629625d8c81fce1a7e3afddd78428b75078cd3d8e56f27c48c18af5aa4bd56bc0cb18b750abdaf2d2c275f280a10f96b7768982115fde0abe0f0efa32fc684ce1d15512346aae7e8bef802a06b2f4b5013614208f5d32916532e9ba00b2a24da3cf20fdd7137b6792b80a508b0ccd5781446eed07f2afe8b132818d4e82c94200f8561b80f55550f9eb8db6cdb5ad6efa0588cfd3bcfbdfd329ce85ccf598ffdc95d5b06a4b7e2ef5b77fb895acf66969780419bdc0c8c0ecfe9d3978ffafcde51868b257f8c14cf2669cce1d7a6c4b0a3868e9bfff3408d694f2250ff3b9e730ceed97d84e6f21e80062326d63c771a946d EAP-Message = 0x4d7692a192d9ca4b95110004 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2bd9a25129ddaf0c046668376d4bbecf Tue Oct 14 17:50:57 2008 : Debug: Finished request 2. Tue Oct 14 17:50:57 2008 : Debug: Going to the next request Tue Oct 14 17:50:57 2008 : Debug: Waking up in 4.3 seconds. * * * * * * * *. * * * Sending Access-Reject of id 3 to 10.0.31.40 port 1645 EAP-Message = 0x04060004 Message-Authenticator = 0x00000000000000000000000000000000 Tue Oct 14 17:50:58 2008 : Debug: Finished request 5. Tue Oct 14 17:50:58 2008 : Debug: Going to the next request Tue Oct 14 17:50:58 2008 : Debug: Waking up in 3.6 seconds. rad_recv: Access-Request packet from host 10.0.31.40 port 1645, id=4, length=136 User-Name = "cert" Framed-MTU = 1400 Called-Station-Id = "0019.2fdb.9e00" Calling-Station-Id = "001f.3c22.44c5" Service-Type = Login-User Message-Authenticator = 0x8168cb6bc60da8a5a4ea24db5318fce8 EAP-Message = 0x020100090163657274 NAS-Port-Type = Wireless-802.11 NAS-Port = 924 NAS-IP-Address = 10.0.31.40 NAS-Identifier = "ap-Reconquista-31" Tue Oct 14 17:50:58 2008 : Debug: +- entering group authorize Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 6 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 6 Tue Oct 14 17:50:58 2008 : Debug: ++[preprocess] returns ok Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 6 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 6 Tue Oct 14 17:50:58 2008 : Debug: ++[chap] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 6 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 6 Tue Oct 14 17:50:58 2008 : Debug: ++[mschap] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 6 Tue Oct 14 17:50:58 2008 : Debug: rlm_realm: No '@' in User-Name = "cert", looking up realm NULL Tue Oct 14 17:50:58 2008 : Debug: rlm_realm: No such realm "NULL" Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 6 Tue Oct 14 17:50:58 2008 : Debug: ++[suffix] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 6 Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: EAP packet type response id 1 length 9 Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 6 Tue Oct 14 17:50:58 2008 : Debug: ++[eap] returns updated Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling unix (rlm_unix) for request 6 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from unix (rlm_unix) for request 6 Tue Oct 14 17:50:58 2008 : Debug: ++[unix] returns notfound Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 6 Tue Oct 14 17:50:58 2008 : Debug: users: Matched entry cert at line 76 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 6 Tue Oct 14 17:50:58 2008 : Debug: ++[files] returns ok Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling expiration (rlm_expiration) for request 6 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from expiration (rlm_expiration) for request 6 Tue Oct 14 17:50:58 2008 : Debug: ++[expiration] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling logintime (rlm_logintime) for request 6 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from logintime (rlm_logintime) for request 6 Tue Oct 14 17:50:58 2008 : Debug: ++[logintime] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 6 Tue Oct 14 17:50:58 2008 : Debug: rlm_pap: Found existing Auth-Type, not changing it. Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 6 Tue Oct 14 17:50:58 2008 : Debug: ++[pap] returns noop Tue Oct 14 17:50:58 2008 : Debug: rad_check_password: Found Auth-Type EAP Tue Oct 14 17:50:58 2008 : Debug: auth: type "EAP" Tue Oct 14 17:50:58 2008 : Debug: +- entering group authenticate Tue Oct 14 17:50:58 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 6 Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: EAP Identity Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: processing type md5 Tue Oct 14 17:50:58 2008 : Debug: rlm_eap_md5: Issuing Challenge Tue Oct 14 17:50:58 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 6 Tue Oct 14 17:50:58 2008 : Debug: ++[eap] returns handled Sending Access-Challenge of id 4 to 10.0.31.40 port 1645 EAP-Message = 0x010200160410c1523ac0e4a4f484ca8e724838e7d951 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x53214e1953234a772105e442b8f04324 Tue Oct 14 17:50:58 2008 : Debug: Finished request 6. Tue Oct 14 17:50:58 2008 : Debug: Going to the next request Tue Oct 14 17:50:58 2008 : Debug: Waking up in 3.1 seconds. rad_recv: Access-Request packet from host 10.0.31.40 port 1645, id=5, length=151 User-Name = "cert" Framed-MTU = 1400 Called-Station-Id = "0019.2fdb.9e00" Calling-Station-Id = "001f.3c22.44c5" Service-Type = Login-User Message-Authenticator = 0x4350c31430c15d510495391f0e939803 EAP-Message = 0x02020006030d NAS-Port-Type = Wireless-802.11 NAS-Port = 924 State = 0x53214e1953234a772105e442b8f04324 NAS-IP-Address = 10.0.31.40 NAS-Identifier = "ap-Reconquista-31" Tue Oct 14 17:50:58 2008 : Debug: +- entering group authorize Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 7 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 7 Tue Oct 14 17:50:58 2008 : Debug: ++[preprocess] returns ok Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 7 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 7 Tue Oct 14 17:50:58 2008 : Debug: ++[chap] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 7 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 7 Tue Oct 14 17:50:58 2008 : Debug: ++[mschap] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 7 Tue Oct 14 17:50:58 2008 : Debug: rlm_realm: No '@' in User-Name = "cert", looking up realm NULL Tue Oct 14 17:50:58 2008 : Debug: rlm_realm: No such realm "NULL" Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 7 Tue Oct 14 17:50:58 2008 : Debug: ++[suffix] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 7 Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: EAP packet type response id 2 length 6 Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 7 Tue Oct 14 17:50:58 2008 : Debug: ++[eap] returns updated Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling unix (rlm_unix) for request 7 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from unix (rlm_unix) for request 7 Tue Oct 14 17:50:58 2008 : Debug: ++[unix] returns notfound Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 7 Tue Oct 14 17:50:58 2008 : Debug: users: Matched entry cert at line 76 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 7 Tue Oct 14 17:50:58 2008 : Debug: ++[files] returns ok Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling expiration (rlm_expiration) for request 7 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from expiration (rlm_expiration) for request 7 Tue Oct 14 17:50:58 2008 : Debug: ++[expiration] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling logintime (rlm_logintime) for request 7 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from logintime (rlm_logintime) for request 7 Tue Oct 14 17:50:58 2008 : Debug: ++[logintime] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 7 Tue Oct 14 17:50:58 2008 : Debug: rlm_pap: Found existing Auth-Type, not changing it. Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 7 Tue Oct 14 17:50:58 2008 : Debug: ++[pap] returns noop Tue Oct 14 17:50:58 2008 : Debug: rad_check_password: Found Auth-Type EAP Tue Oct 14 17:50:58 2008 : Debug: auth: type "EAP" Tue Oct 14 17:50:58 2008 : Debug: +- entering group authenticate Tue Oct 14 17:50:58 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 7 Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: Request found, released from the list Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: EAP NAK Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: EAP-NAK asked for EAP-Type/tls Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: processing type tls Tue Oct 14 17:50:58 2008 : Debug: rlm_eap_tls: Requiring client certificate Tue Oct 14 17:50:58 2008 : Debug: rlm_eap_tls: Initiate Tue Oct 14 17:50:58 2008 : Debug: rlm_eap_tls: Start returned 1 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 7 Tue Oct 14 17:50:58 2008 : Debug: ++[eap] returns handled Sending Access-Challenge of id 5 to 10.0.31.40 port 1645 EAP-Message = 0x010300060d20 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x53214e19522243772105e442b8f04324 Tue Oct 14 17:50:58 2008 : Debug: Finished request 7. Tue Oct 14 17:50:58 2008 : Debug: Going to the next request Tue Oct 14 17:50:58 2008 : Debug: Waking up in 3.1 seconds. rad_recv: Access-Request packet from host 10.0.31.40 port 1645, id=6, length=255 User-Name = "cert" Framed-MTU = 1400 Called-Station-Id = "0019.2fdb.9e00" Calling-Station-Id = "001f.3c22.44c5" Service-Type = Login-User Message-Authenticator = 0x531eac3e1d25194e19d1391e9e25d099 EAP-Message = 0x0203006e0d8000000064160301005f0100005b030148f5062f307e645c06a6432cf1d9169376cdb5131590394dc7afa95b00abceb900003400390038003500160013000a00330032002f006600050004006500640063006200610060001500120009001400110008000600030100 NAS-Port-Type = Wireless-802.11 NAS-Port = 924 State = 0x53214e19522243772105e442b8f04324 NAS-IP-Address = 10.0.31.40 NAS-Identifier = "ap-Reconquista-31" Tue Oct 14 17:50:58 2008 : Debug: +- entering group authorize Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling preprocess (rlm_preprocess) for request 8 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from preprocess (rlm_preprocess) for request 8 Tue Oct 14 17:50:58 2008 : Debug: ++[preprocess] returns ok Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling chap (rlm_chap) for request 8 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from chap (rlm_chap) for request 8 Tue Oct 14 17:50:58 2008 : Debug: ++[chap] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling mschap (rlm_mschap) for request 8 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from mschap (rlm_mschap) for request 8 Tue Oct 14 17:50:58 2008 : Debug: ++[mschap] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling suffix (rlm_realm) for request 8 Tue Oct 14 17:50:58 2008 : Debug: rlm_realm: No '@' in User-Name = "cert", looking up realm NULL Tue Oct 14 17:50:58 2008 : Debug: rlm_realm: No such realm "NULL" Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from suffix (rlm_realm) for request 8 Tue Oct 14 17:50:58 2008 : Debug: ++[suffix] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling eap (rlm_eap) for request 8 Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: EAP packet type response id 3 length 110 Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: No EAP Start, assuming it's an on-going EAP conversation Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from eap (rlm_eap) for request 8 Tue Oct 14 17:50:58 2008 : Debug: ++[eap] returns updated Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling unix (rlm_unix) for request 8 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from unix (rlm_unix) for request 8 Tue Oct 14 17:50:58 2008 : Debug: ++[unix] returns notfound Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling files (rlm_files) for request 8 Tue Oct 14 17:50:58 2008 : Debug: users: Matched entry cert at line 76 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from files (rlm_files) for request 8 Tue Oct 14 17:50:58 2008 : Debug: ++[files] returns ok Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling expiration (rlm_expiration) for request 8 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from expiration (rlm_expiration) for request 8 Tue Oct 14 17:50:58 2008 : Debug: ++[expiration] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling logintime (rlm_logintime) for request 8 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from logintime (rlm_logintime) for request 8 Tue Oct 14 17:50:58 2008 : Debug: ++[logintime] returns noop Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: calling pap (rlm_pap) for request 8 Tue Oct 14 17:50:58 2008 : Debug: rlm_pap: Found existing Auth-Type, not changing it. Tue Oct 14 17:50:58 2008 : Debug: modsingle[authorize]: returned from pap (rlm_pap) for request 8 Tue Oct 14 17:50:58 2008 : Debug: ++[pap] returns noop Tue Oct 14 17:50:58 2008 : Debug: rad_check_password: Found Auth-Type EAP Tue Oct 14 17:50:58 2008 : Debug: auth: type "EAP" Tue Oct 14 17:50:58 2008 : Debug: +- entering group authenticate Tue Oct 14 17:50:58 2008 : Debug: modsingle[authenticate]: calling eap (rlm_eap) for request 8 Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: Request found, released from the list Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: EAP/tls Tue Oct 14 17:50:58 2008 : Debug: rlm_eap: processing type tls Tue Oct 14 17:50:58 2008 : Debug: rlm_eap_tls: Authenticate Tue Oct 14 17:50:58 2008 : Debug: rlm_eap_tls: processing TLS Tue Oct 14 17:50:58 2008 : Debug: TLS Length 100 Tue Oct 14 17:50:58 2008 : Debug: rlm_eap_tls: Length Included Tue Oct 14 17:50:58 2008 : Debug: eaptls_verify returned 11 Tue Oct 14 17:50:58 2008 : Debug: (other): before/accept initialization Tue Oct 14 17:50:58 2008 : Debug: TLS_accept: before/accept initialization Tue Oct 14 17:50:58 2008 : Debug: rlm_eap_tls: <<< TLS 1.0 Handshake [length 005f], ClientHello Tue Oct 14 17:50:58 2008 : Debug: TLS_accept: SSLv3 read client hello A Tue Oct 14 17:50:58 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello Tue Oct 14 17:50:58 2008 : Debug: TLS_accept: SSLv3 write server hello A Tue Oct 14 17:50:58 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 0839], Certificate Tue Oct 14 17:50:58 2008 : Debug: TLS_accept: SSLv3 write certificate A Tue Oct 14 17:50:58 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange Tue Oct 14 17:50:58 2008 : Debug: TLS_accept: SSLv3 write key exchange A Tue Oct 14 17:50:58 2008 : Debug: rlm_eap_tls: >>> TLS 1.0 Handshake [length 00a0], CertificateRequest Tue Oct 14 17:50:58 2008 : Debug: TLS_accept: SSLv3 write certificate request A Tue Oct 14 17:50:58 2008 : Debug: TLS_accept: SSLv3 flush data Tue Oct 14 17:50:58 2008 : Debug: TLS_accept: Need to read more data: SSLv3 read client certificate A Tue Oct 14 17:50:58 2008 : Debug: In SSL Handshake Phase Tue Oct 14 17:50:58 2008 : Debug: In SSL Accept mode Tue Oct 14 17:50:58 2008 : Debug: eaptls_process returned 13 Tue Oct 14 17:50:58 2008 : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 8 Tue Oct 14 17:50:58 2008 : Debug: ++[eap] returns handled Sending Access-Challenge of id 6 to 10.0.31.40 port 1645 EAP-Message = 0x010404000dc000000b44160301004a02000046030148f50632255a7a086246b9f75b2cbf73b60452aeef20144b1e530c1939d8f9c720f435c9357e0e717dbc526c87fb94e670dcdc242dbca8b4846a66b8f18ba2bc5a00390016030108390b000835000832000396308203923082027aa003020102020101300d06092a864886f70d010104050030818c310b3009060355040613024152311530130603550408130c4275656e6f73204169726573311430120603550407130b5265636f6e717569737461310e300c060355040a130549504c414e3120301e06092a864886f70d0109011611636572744069706c616e2e636f6d2e6172311e301c060355 EAP-Message = 0x04031315436572746966696361746520417574686f72697479301e170d3038313031303134353031385a170d3039313031303134353031385a3073310b3009060355040613024152311530130603550408130c4275656e6f73204169726573310e300c060355040a130549504c414e311b3019060355040313125365727665722043657274696669636174653120301e06092a864886f70d0109011611636572744069706c616e2e636f6d2e617230820122300d06092a864886f70d01010105000382010f003082010a0282010100bacfd3d0fa48b30002182ca8ac9a31672b4ad7dcd6b45d7df598774e7af3c4d6cd46447144260ae3daac561a93e7 EAP-Message = 0xd97d8a9889591b5cd3cf6924d4dc5aaa78a8013bde946b633e51abb4b6150fbe66a8743dd34a887f5c731a685c811c5660ba3d68abd028679464d28af4171dea0a3e99a80ba7b75c10d3c5480a319ea9b9ca6a9d14536b6524eb6f559b10f8f326d612836e88d2b28e03a574ede8b7a7bfdde0a7846543a713bb279c81bb681e50609c10ca2b2f5b6b4b2c1683c9a60ae8c7121ce2a81fc124189d4f356dee804a45b49f71547f788006bc247c65a98e81c2359cc537ef1c65d8137aa6cf6b2aff605d4da97c7a5abad17885608d027ddc370203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d010104 EAP-Message = 0x050003820101008c4607f2629625d8c81fce1a7e3afddd78428b75078cd3d8e56f27c48c18af5aa4bd56bc0cb18b750abdaf2d2c275f280a10f96b7768982115fde0abe0f0efa32fc684ce1d15512346aae7e8bef802a06b2f4b5013614208f5d32916532e9ba00b2a24da3cf20fdd7137b6792b80a508b0ccd5781446eed07f2afe8b132818d4e82c94200f8561b80f55550f9eb8db6cdb5ad6efa0588cfd3bcfbdfd329ce85ccf598ffdc95d5b06a4b7e2ef5b77fb895acf66969780419bdc0c8c0ecfe9d3978ffafcde51868b257f8c14cf2669cce1d7a6c4b0a3868e9bfff3408d694f2250ff3b9e730ceed97d84e6f21e80062326d63c771a946d EAP-Message = 0x4d7692a192d9ca4b95110004 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x53214e19512543772105e442b8f04324 Tue Oct 14 17:50:58 2008 : Debug: Finished request 8. Tue Oct 14 17:50:58 2008 : Debug: Going to the next request Tue Oct 14 17:50:58 2008 : Debug: Waking up in 3.1 seconds. Tue Oct 14 17:51:01 2008 : Debug: Cleaning up request 0 ID 254 with timestamp +488 Tue Oct 14 17:51:01 2008 : Debug: Cleaning up request 1 ID 255 with timestamp +488 Tue Oct 14 17:51:01 2008 : Debug: Waking up in 0.6 seconds. Tue Oct 14 17:51:02 2008 : Debug: Cleaning up request 2 ID 0 with timestamp +489 Tue Oct 14 17:51:02 2008 : Debug: Cleaning up request 3 ID 1 with timestamp +489 Tue Oct 14 17:51:02 2008 : Debug: Cleaning up request 4 ID 2 with timestamp +489 Tue Oct 14 17:51:02 2008 : Debug: Waking up in 0.6 seconds. Tue Oct 14 17:51:03 2008 : Debug: Cleaning up request 5 ID 3 with timestamp +490 Tue Oct 14 17:51:03 2008 : Debug: Waking up in 0.5 seconds. Tue Oct 14 17:51:03 2008 : Debug: Cleaning up request 6 ID 4 with timestamp +490 Tue Oct 14 17:51:03 2008 : Debug: Cleaning up request 7 ID 5 with timestamp +490 Tue Oct 14 17:51:03 2008 : Debug: Cleaning up request 8 ID 6 with timestamp +490 Tue Oct 14 17:51:03 2008 : Debug: Ready to process requests. in the notebook client install "ca.der" and "client.p12", at first not recognized as an entity of strength and confidence but install it by force, and the client.p12 installs fine but the state tells me that "no You can find the issuer of the certificate " reinstall the certificates and tried to locate the error somewhere but I do not find much. thanks again. -- -- Silvero Martin

2 1

sqlippool/rlm_sql_query relocation error (mysql)
by Andre Dalle 14 Oct '08

14 Oct '08

Recently upgraded from 1.0.4 to 2.1.1 to use sqlippool. Chiefly because rlm_ippool began failing on us. Server with sql accounting is working well, but I'm experiencing a relocation error with sqlippool. I had to use --with-system-libtool to build freeradius with libtool 2.2.4. Relocation errors on linking otherwise. rlm_sql (sql): Reserving sql socket id: 3 [sqlippool] expand: %{User-Name} -> snippy(a)snip.ca [sqlippool] sql_set_user escaped user --> 'snippy(a)snip.ca' [sqlippool] expand: START TRANSACTION -> START TRANSACTION ld.so.1: radiusd: fatal: relocation error: file +/usr/local/lib/rlm_sqlippool-2.1.1.so: symbol rlm_sql_query: referenced symbol +not found -- André Dalle Systems Administrator NCF Internet

1 0

Problem Accounting with PostGreSQL
by mehtap＠comu.edu.tr 14 Oct '08

14 Oct '08

Hi, We are using PostGreSQL for accounting. But when we made a query, we saw all tables are empty except "radpostauth" and we need informations about "radacct" table. So, when we were using FreeRADIUS 1.1.7, we changed "postgresql.conf"'s last comment like that: We changed this comment: postauth_query = "INSERT INTO ${postauth_table} (username, pass, reply, authdate) VALUES ('%{User-Name}', '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', NOW())" like that: postauth_query = "INSERT into ${acct_table1} \ (AcctSessionId, AcctUniqueId, UserName, Realm, NASIPAddress, NASPortId, NASPortType, AcctStartTime, AcctAuthentic, \ ConnectInfo_start, CalledStationId, CallingStationId, ServiceType, FramedProtocol, FramedIPAddress, AcctStartDelay, XAscendSessionSvrKey) \ values('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', \ '%{NAS-Port}', '%{NAS-Port-Type}', ('%S'::timestamp - '%{Acct-Delay-Time:-0}'::interval), '%{Acct-Authentic}', '%{Connect-Info}', \ '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', \ NULLIF('%{Framed-IP-Address}', '')::inet, 0, '%{X-Ascend-Session-Svr-Key}')" And it worked:) But now, we are using FreeRADIUS 2.0.4 and when we have changed "postgresql.conf" like over, it doesn't work. When someone tries to connect with FreeRADIUS, it gives "Login Incorrect" message. Is there any link including a solution about my problem?

2 1

Setting Auth-Type to Accept using unlang
by Abel Alejandro 14 Oct '08

14 Oct '08

Hello, I want freeradius to assign to a specific ippool any invalid user (user not found or wrong password) as well as accept it. I am trying to do the following in post-auth but so far I can get freeradius to send the Reply-Message, DNS, etc... but it will still send Reject-Access. I am guessing that doing Auth-Type := "Accept" is too late in post-auth. Post-Auth-Type REJECT { if (!NAS-IP-Address == X.X.X.X) { update reply { Reply-Message = "Restricted Access" MS-Primary-DNS-Server = X.X.X.X MS-Secondary-DNS-Server = X.X.X.X RP-Max-Sessions-Per-User = 100 } update control { Auth-Type := "Accept" Pool-Name := "invaliduser_pool" } # Get an address from the IP Pool. invaliduser_pool sql } } I am using the latest version of freeradius 2.1.1. Regards, Abel.

3 5

Re: R: TLV format in WiMAX dictionary
by Alan DeKok 14 Oct '08

14 Oct '08

Stefano Colagreco wrote: > ASN-GW receive attribute but not recognize attribute of WiMAX QoS. Then it's not WiMAX compatible. Simple, isn't it? > Looking at the trace of ASN-GW i've noticed the following mistakes: > > - vendor-unkonwn-type29:00 06 06 00 07 D0 00 Mistake? If you don't want to do QoS, don't send it a QoS attribute. If the ASN-GW doesn't support QoS, buy a standards-compatible gateway. > ASN-GW I used is guaranteed as fully compliant with WiMAX standard. Well, ask for your money back, or for an updated version that's compliant with the WiMAX standard. The QoS attribute has been around for a LONG time in WiMAX. Over a year, IIRC. So there's no excuse for the vendor to ignore it. Alan DeKok.

1 0