January 2012 - Freeradius-Users - lists.freeradius.org

default attribute/group for res_mysql
by Oğuzhan Kayhan 29 Jan '12

29 Jan '12

Hi all, Is there any way to set a default group to all users that doesnt have any group , or any way of assigning an attribute to all users by default. As i read on previous mails DEFAULT parameter does not work for mysql users. Thanks

2 2

Re: Freeradius Mysql Performance
by Alan Buxey 29 Jan '12

29 Jan '12

What?? You dont need that kind of hardware for job, sure. Throwing that kind of horsepower might fix the speed but this is a DBA question. Look at your mysql configuration and see how it can be adjusted (my.cnf) look at the engine in use and see if you can use better..(eg innodb instead of myisam), look at an alternative SQL eg postgres. Look at your usage of sql with freeradius, eg the radius tables. What indexes are present what do you need , what do you not need? Can you divide the work? Use one server for one table or task and the other another...eg simple queries can be done against a passive slave server... alan

3 4

Unable to get freeradius server and client to communicate
by Haroon Abraham 29 Jan '12

29 Jan '12

Server is run in debug mode (radiusd -X) The following is entered in the clients.conf file: client erx.radius-src-ipaddr { secret = juniper nastype = other shorname = ERX1 } -------------------------------- Using netstat the server appears to be listenting on correct UDP port 1812 [root@freerad raddb]# netstat -a | grep radius udp 0 0 *:radius *:* udp 0 0 *:radius-acct *:* -------------------------------- Start Radius with : radiusd -X (debug mode) shows server listening on 1812 client erx.radius-src-ipaddr { require_message_authenticator = no secret = "juniper" nastype = "other" } ... adding new socket proxy address * port 38660 Listening on authentication address * port 1812 Listening on accounting address * port 1813 Listening on command file /usr/local/var/run/radiusd/radiusd.sock Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Listening on proxy address * port 1814 Ready to process requests. Testing local to server works correctly but when I test from NAS (ERX) there is no output observed in the debug window (radiusd -X). I used tcpdump to confirm that packets are reaching the server. Any help would be greatly appreciated...

2 3

Re: Freeradius Mysql Performance
by Alan Buxey 28 Jan '12

28 Jan '12

It's do-able. Though I would be worried about failover and resiliancy. alan

1 0

Freeradius Mysql Performance
by Morteza Milani 28 Jan '12

28 Jan '12

Hi, Our company is using freeradius as a VPN authentication & authorization system. In worse-case say we would have 1 Million users. Beside scaling our market, we are going to develop an application to analyze users with data mining algorithms. Currently we use a server with the following features: * RAM: 4 GB * Processor: 1x E8400 3.0 GHz For some queries it takes 15 seconds or more to get answer from mysql specially when queries work with radacct table. Any suggestion to improve performance? Regards, Morteza Milani

5 4

Autentication Problem with Freeradius on FREEBSD
by Rodrigo Yoshioka 28 Jan '12

28 Jan '12

Hi, I´m having some problems with a new radius server. I have an CentoOS with freeradius already working. But it was getting slow and let clients delay to connect. So I installed a new freeradius server on Freebsd, and I compare both configurations files. But when PPPoE server try to autenticate a client, radius.log says that its OK. but PPPoE server says RADIUS TIMEOUT. Do anyone knows where in the configuration should be that problem??? Thanks

3 2

Re: Unable to get freeradius server and client to communicate
by Alan Buxey 28 Jan '12

28 Jan '12

No packets seen coming in on the server when in debug mode? Check your server for a host based firewall, check with your network guys for eg inter VLAN ACLs, or other protection on the network alan

1 0

different NAS_ip_address
by sekchel lee 27 Jan '12

27 Jan '12

freeradius 2.1.9 mysql select nasipaddress from radacct; NAS_1 ==> 111.111.111.1 NAS 2 ==> 222.222.222.2 I want unification NAS_1 ==> 127.0.0.1 NAS_2 ==> 127.0.0.1 Thank you Everybody

2 1

Authorization with Active Directory
by suggestme 27 Jan '12

27 Jan '12

Hi, I have configured freeradius server to authenticate & authorize user with the supplied username and password against active directory. Till this stage; The user can be authenticated and authorized successfully with credentials provided. For this purpose; user is just authenticated and authorized depending upon the filter of LDAP module which I have set. My LDAP module filter configuration is as: filter = "(sAMAccountName=%{%{Stripped-User-Name}:-%{User-Name}})" But Now, I want to go deep on authenticating and authorizing user to allow or reject VPN or Wifi access, etc. For this purpose I have created extension attribute in Active directory and has assigned the value as "VPN" , "Wifi", etc..... Now my question is: How can I set the filter in Ldap module of FreeRadius to just allow the user belonging to VPN or wifi ? Should I need to add the extension attribute filter to the above mentioned filter? OR should I need to define 2 filters: the above one and another for extension attribute? I tried defining 2 filters separately; it didn't work. I know some people use the concept of "Group" for this purpose. In my case, I can't use Group. I just have to authenticate and authorize user just using Active Directory attribute. I don't know whether this is way to do or not. Any idea would be really helpful. This forum has really helped a lot to the beginner like me to reach till this stage. Thanks everyone............ -- View this message in context: http://freeradius.1045715.n5.nabble.com/Authorization-with-Active-Directory… Sent from the FreeRadius - User mailing list archive at Nabble.com.

4 9

huntgroup check problems
by Oscar Remírez de Ganuza Satrústegui 27 Jan '12

27 Jan '12

Hello everybody, We are using freeradius (Version 2.1.9) to serve access requests for 802.1x, using PEAP/EAP/MSCHAPv2 (windows7). We use LDAP for authentication (user accounts) and authorization (Ldap-Groups). We also tunneled the request to the same radius for our realm "unav.es". I am having some problems using huntgroups to identified the origin of a request. I have simplified the test trying to find out the problem, but I do not understand what it is happening: * It works ok when I use the following users file: ----- users file ----- DEFAULT Ldap-Group=="unav.radius.empleado" Reply-Message = "Empleado from test switch" DEFAULT Auth-Type := Reject Reply-Message = "Access not allowed." ----- * But it fails when I check the huntgroup: ----- users file ----- DEFAULT Huntgroup-Name == "huntpruebas", Ldap-Group=="unav.radius.empleado" Reply-Message = "Empleado from test switch" DEFAULT Auth-Type := Reject Reply-Message = "Access not allowed." ----- (The "notworking log" is appended at the end of the message. I had to trim it to make it shorter) (The "workingok log" is not attached as it made this message bigger than allowed on this list). I can see in the "not working log" that on the first requests the huntgroup is been recognised ok. I just do not understand why it tries again to check it, until it fails (request #9). I also do not understand why it needs so many requests (12!) to work ok. I will appreciate any help understanding what is happening, in order to find a solution for my problem. If it is needed more log or config files, I can attached them without problem. Thanks a lot. ====== Not working log ====== Thu Jan 19 12:34:20 2012 : Info: FreeRADIUS Version 2.1.9, for host i686-pc-linux-gnu, built on Oct 4 2010 at 13:35:26 [trimmed] Thu Jan 19 12:34:20 2012 : Debug: main { Thu Jan 19 12:34:20 2012 : Debug: prefix = "/usr/local/etc2/freeradius" Thu Jan 19 12:34:20 2012 : Debug: localstatedir = "/usr/local/etc2/freeradius/var" Thu Jan 19 12:34:20 2012 : Debug: logdir = "/usr/local/etc2/freeradius/var/log/radius" Thu Jan 19 12:34:20 2012 : Debug: libdir = "/usr/local/etc2/freeradius/lib" Thu Jan 19 12:34:20 2012 : Debug: radacctdir = "/usr/local/etc2/freeradius/var/log/radius/radacct" Thu Jan 19 12:34:20 2012 : Debug: hostname_lookups = no Thu Jan 19 12:34:20 2012 : Debug: max_request_time = 30 Thu Jan 19 12:34:20 2012 : Debug: cleanup_delay = 5 Thu Jan 19 12:34:20 2012 : Debug: max_requests = 1024 Thu Jan 19 12:34:20 2012 : Debug: pidfile = "/usr/local/etc2/freeradius/var/run/radiusd/radiusd.pid" Thu Jan 19 12:34:20 2012 : Debug: checkrad = "/usr/local/etc2/freeradius/sbin/checkrad" Thu Jan 19 12:34:20 2012 : Debug: debug_level = 0 Thu Jan 19 12:34:20 2012 : Debug: proxy_requests = yes Thu Jan 19 12:34:20 2012 : Debug: log { Thu Jan 19 12:34:20 2012 : Debug: stripped_names = no Thu Jan 19 12:34:20 2012 : Debug: auth = no Thu Jan 19 12:34:20 2012 : Debug: auth_badpass = no Thu Jan 19 12:34:20 2012 : Debug: auth_goodpass = no Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: security { Thu Jan 19 12:34:20 2012 : Debug: max_attributes = 200 Thu Jan 19 12:34:20 2012 : Debug: reject_delay = 1 Thu Jan 19 12:34:20 2012 : Debug: status_server = yes Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: radiusd: #### Loading Realms and Home Servers #### Thu Jan 19 12:34:20 2012 : Debug: proxy server { Thu Jan 19 12:34:20 2012 : Debug: retry_delay = 5 Thu Jan 19 12:34:20 2012 : Debug: retry_count = 3 Thu Jan 19 12:34:20 2012 : Debug: default_fallback = yes Thu Jan 19 12:34:20 2012 : Debug: dead_time = 120 Thu Jan 19 12:34:20 2012 : Debug: wake_all_if_all_dead = no Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: realm unav.es { Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: realm LOCAL { Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: home_server localhost { Thu Jan 19 12:34:20 2012 : Debug: ipaddr = 127.0.0.1 Thu Jan 19 12:34:20 2012 : Debug: port = 1812 Thu Jan 19 12:34:20 2012 : Debug: type = "auth+acct" Thu Jan 19 12:34:20 2012 : Debug: secret = "testing123" Thu Jan 19 12:34:20 2012 : Debug: response_window = 20 Thu Jan 19 12:34:20 2012 : Debug: max_outstanding = 65536 Thu Jan 19 12:34:20 2012 : Debug: require_message_authenticator = no Thu Jan 19 12:34:20 2012 : Debug: zombie_period = 40 Thu Jan 19 12:34:20 2012 : Debug: status_check = "status-server" Thu Jan 19 12:34:20 2012 : Debug: ping_interval = 30 Thu Jan 19 12:34:20 2012 : Debug: check_interval = 30 Thu Jan 19 12:34:20 2012 : Debug: num_answers_to_alive = 3 Thu Jan 19 12:34:20 2012 : Debug: num_pings_to_alive = 3 Thu Jan 19 12:34:20 2012 : Debug: revive_interval = 120 Thu Jan 19 12:34:20 2012 : Debug: status_check_timeout = 4 Thu Jan 19 12:34:20 2012 : Debug: irt = 2 Thu Jan 19 12:34:20 2012 : Debug: mrt = 16 Thu Jan 19 12:34:20 2012 : Debug: mrc = 5 Thu Jan 19 12:34:20 2012 : Debug: mrd = 30 Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: home_server_pool my_auth_failover { Thu Jan 19 12:34:20 2012 : Debug: type = fail-over Thu Jan 19 12:34:20 2012 : Debug: home_server = localhost Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: radiusd: #### Loading Clients #### Thu Jan 19 12:34:20 2012 : Debug: client localhost { Thu Jan 19 12:34:20 2012 : Debug: ipaddr = 127.0.0.1 Thu Jan 19 12:34:20 2012 : Debug: require_message_authenticator = no Thu Jan 19 12:34:20 2012 : Debug: secret = "testing123" Thu Jan 19 12:34:20 2012 : Debug: nastype = "other" Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: client naspruebas { Thu Jan 19 12:34:20 2012 : Debug: ipaddr = 159.237.8.200 Thu Jan 19 12:34:20 2012 : Debug: require_message_authenticator = no Thu Jan 19 12:34:20 2012 : Debug: secret = "pruebas" Thu Jan 19 12:34:20 2012 : Debug: shortname = "naspruebas" Thu Jan 19 12:34:20 2012 : Debug: nastype = "other" Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: radiusd: #### Instantiating modules #### Thu Jan 19 12:34:20 2012 : Debug: instantiate { Thu Jan 19 12:34:20 2012 : Debug: (Loaded rlm_exec, checking if it's valid) Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to module rlm_exec Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating exec Thu Jan 19 12:34:20 2012 : Debug: exec { Thu Jan 19 12:34:20 2012 : Debug: wait = no Thu Jan 19 12:34:20 2012 : Debug: input_pairs = "request" Thu Jan 19 12:34:20 2012 : Debug: shell_escape = yes Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: (Loaded rlm_expr, checking if it's valid) Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to module rlm_expr Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating expr Thu Jan 19 12:34:20 2012 : Debug: (Loaded rlm_expiration, checking if it's valid) Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to module rlm_expiration Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating expiration Thu Jan 19 12:34:20 2012 : Debug: expiration { Thu Jan 19 12:34:20 2012 : Debug: reply-message = "Password Has Expired " Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: (Loaded rlm_logintime, checking if it's valid) Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to module rlm_logintime Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating logintime Thu Jan 19 12:34:20 2012 : Debug: logintime { Thu Jan 19 12:34:20 2012 : Debug: reply-message = "You are calling outside your allowed timespan " Thu Jan 19 12:34:20 2012 : Debug: minimum-timeout = 60 Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: radiusd: #### Loading Virtual Servers #### Thu Jan 19 12:34:20 2012 : Debug: server inner-tunnel { Thu Jan 19 12:34:20 2012 : Debug: modules { Thu Jan 19 12:34:20 2012 : Debug: Module: Checking authenticate {...} for more modules to load Thu Jan 19 12:34:20 2012 : Debug: (Loaded rlm_pap, checking if it's valid) Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to module rlm_pap Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating pap Thu Jan 19 12:34:20 2012 : Debug: pap { Thu Jan 19 12:34:20 2012 : Debug: encryption_scheme = "auto" Thu Jan 19 12:34:20 2012 : Debug: auto_header = no Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: (Loaded rlm_chap, checking if it's valid) Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to module rlm_chap Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating chap Thu Jan 19 12:34:20 2012 : Debug: (Loaded rlm_mschap, checking if it's valid) Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to module rlm_mschap Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating mschap Thu Jan 19 12:34:20 2012 : Debug: mschap { Thu Jan 19 12:34:20 2012 : Debug: use_mppe = yes Thu Jan 19 12:34:20 2012 : Debug: require_encryption = yes Thu Jan 19 12:34:20 2012 : Debug: require_strong = yes Thu Jan 19 12:34:20 2012 : Debug: with_ntdomain_hack = no Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: (Loaded rlm_unix, checking if it's valid) Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to module rlm_unix Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating unix Thu Jan 19 12:34:20 2012 : Debug: unix { Thu Jan 19 12:34:20 2012 : Debug: radwtmp = "/usr/local/etc2/freeradius/var/log/radius/radwtmp" Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: (Loaded rlm_eap, checking if it's valid) Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to module rlm_eap Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating eap Thu Jan 19 12:34:20 2012 : Debug: eap { Thu Jan 19 12:34:20 2012 : Debug: default_eap_type = "md5" Thu Jan 19 12:34:20 2012 : Debug: timer_expire = 60 Thu Jan 19 12:34:20 2012 : Debug: ignore_unknown_eap_types = no Thu Jan 19 12:34:20 2012 : Debug: cisco_accounting_username_bug = no Thu Jan 19 12:34:20 2012 : Debug: max_sessions = 4096 Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to sub-module rlm_eap_md5 Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating eap-md5 Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to sub-module rlm_eap_leap Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating eap-leap Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to sub-module rlm_eap_gtc Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating eap-gtc Thu Jan 19 12:34:20 2012 : Debug: gtc { Thu Jan 19 12:34:20 2012 : Debug: challenge = "Password: " Thu Jan 19 12:34:20 2012 : Debug: auth_type = "PAP" Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to sub-module rlm_eap_tls Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating eap-tls Thu Jan 19 12:34:20 2012 : Debug: tls { Thu Jan 19 12:34:20 2012 : Debug: rsa_key_exchange = no Thu Jan 19 12:34:20 2012 : Debug: dh_key_exchange = yes Thu Jan 19 12:34:20 2012 : Debug: rsa_key_length = 512 Thu Jan 19 12:34:20 2012 : Debug: dh_key_length = 512 Thu Jan 19 12:34:20 2012 : Debug: verify_depth = 0 Thu Jan 19 12:34:20 2012 : Debug: pem_file_type = yes Thu Jan 19 12:34:20 2012 : Debug: private_key_file = "/usr/local/etc2/freeradius/etc/raddb/certs/radius.unav.es_privatekey.pem" Thu Jan 19 12:34:20 2012 : Debug: certificate_file = "/usr/local/etc2/freeradius/etc/raddb/certs/radius.unav.es_cert.pem" Thu Jan 19 12:34:20 2012 : Debug: CA_file = "/usr/local/etc2/freeradius/etc/raddb/certs/TERENASSL_PATH.pem" Thu Jan 19 12:34:20 2012 : Debug: dh_file = "/usr/local/etc2/freeradius/etc/raddb/certs/dh" Thu Jan 19 12:34:20 2012 : Debug: random_file = "/usr/local/etc2/freeradius/etc/raddb/certs/random" Thu Jan 19 12:34:20 2012 : Debug: fragment_size = 1024 Thu Jan 19 12:34:20 2012 : Debug: include_length = yes Thu Jan 19 12:34:20 2012 : Debug: check_crl = no Thu Jan 19 12:34:20 2012 : Debug: cipher_list = "DEFAULT" Thu Jan 19 12:34:20 2012 : Debug: make_cert_command = "/usr/local/etc2/freeradius/etc/raddb/certs/bootstrap" Thu Jan 19 12:34:20 2012 : Debug: cache { Thu Jan 19 12:34:20 2012 : Debug: enable = no Thu Jan 19 12:34:20 2012 : Debug: lifetime = 24 Thu Jan 19 12:34:20 2012 : Debug: max_entries = 255 Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to sub-module rlm_eap_ttls Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating eap-ttls Thu Jan 19 12:34:20 2012 : Debug: ttls { Thu Jan 19 12:34:20 2012 : Debug: default_eap_type = "md5" Thu Jan 19 12:34:20 2012 : Debug: copy_request_to_tunnel = yes Thu Jan 19 12:34:20 2012 : Debug: use_tunneled_reply = no Thu Jan 19 12:34:20 2012 : Debug: virtual_server = "inner-tunnel" Thu Jan 19 12:34:20 2012 : Debug: include_length = yes Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to sub-module rlm_eap_peap Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating eap-peap Thu Jan 19 12:34:20 2012 : Debug: peap { Thu Jan 19 12:34:20 2012 : Debug: default_eap_type = "mschapv2" Thu Jan 19 12:34:20 2012 : Debug: copy_request_to_tunnel = yes Thu Jan 19 12:34:20 2012 : Debug: use_tunneled_reply = no Thu Jan 19 12:34:20 2012 : Debug: proxy_tunneled_request_as_eap = no Thu Jan 19 12:34:20 2012 : Debug: virtual_server = "inner-tunnel" Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating eap-mschapv2 Thu Jan 19 12:34:20 2012 : Debug: mschapv2 { Thu Jan 19 12:34:20 2012 : Debug: with_ntdomain_hack = no Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:20 2012 : Debug: Module: Checking authorize {...} for more modules to load Thu Jan 19 12:34:20 2012 : Debug: (Loaded rlm_realm, checking if it's valid) Thu Jan 19 12:34:20 2012 : Debug: Module: Linked to module rlm_realm Thu Jan 19 12:34:20 2012 : Debug: Module: Instantiating suffix Thu Jan 19 12:34:20 2012 : Debug: realm suffix { Thu Jan 19 12:34:20 2012 : Debug: format = "suffix" Thu Jan 19 12:34:20 2012 : Debug: delimiter = "@" Thu Jan 19 12:34:20 2012 : Debug: ignore_default = no Thu Jan 19 12:34:20 2012 : Debug: ignore_null = no Thu Jan 19 12:34:20 2012 : Debug: } Thu Jan 19 12:34:21 2012 : Debug: (Loaded rlm_files, checking if it's valid) Thu Jan 19 12:34:21 2012 : Debug: Module: Linked to module rlm_files Thu Jan 19 12:34:21 2012 : Debug: Module: Instantiating files Thu Jan 19 12:34:21 2012 : Debug: files { Thu Jan 19 12:34:21 2012 : Debug: usersfile = "/usr/local/etc2/freeradius/etc/raddb/users" Thu Jan 19 12:34:21 2012 : Debug: acctusersfile = "/usr/local/etc2/freeradius/etc/raddb/acct_users" Thu Jan 19 12:34:21 2012 : Debug: preproxy_usersfile = "/usr/local/etc2/freeradius/etc/raddb/preproxy_users" Thu Jan 19 12:34:21 2012 : Debug: compat = "no" Thu Jan 19 12:34:21 2012 : Debug: } Thu Jan 19 12:34:21 2012 : Debug: (Loaded rlm_ldap, checking if it's valid) Thu Jan 19 12:34:21 2012 : Debug: Module: Linked to module rlm_ldap Thu Jan 19 12:34:21 2012 : Debug: Module: Instantiating ldap Thu Jan 19 12:34:21 2012 : Debug: ldap { Thu Jan 19 12:34:21 2012 : Debug: server = "ldappre.si.unav.es" Thu Jan 19 12:34:21 2012 : Debug: port = 389 Thu Jan 19 12:34:21 2012 : Debug: password = "xxx" Thu Jan 19 12:34:21 2012 : Debug: identity = "cn=radiusOp,dc=unav,dc=es" Thu Jan 19 12:34:21 2012 : Debug: net_timeout = 1 Thu Jan 19 12:34:21 2012 : Debug: timeout = 4 Thu Jan 19 12:34:21 2012 : Debug: timelimit = 3 Thu Jan 19 12:34:21 2012 : Debug: tls_mode = no Thu Jan 19 12:34:21 2012 : Debug: start_tls = no Thu Jan 19 12:34:21 2012 : Debug: tls_require_cert = "allow" Thu Jan 19 12:34:21 2012 : Debug: tls { Thu Jan 19 12:34:21 2012 : Debug: start_tls = yes Thu Jan 19 12:34:21 2012 : Debug: require_cert = "allow" Thu Jan 19 12:34:21 2012 : Debug: } Thu Jan 19 12:34:21 2012 : Debug: basedn = "ou=radius,o=accounts,dc=unav,dc=es" Thu Jan 19 12:34:21 2012 : Debug: filter = "(uid=%{%{Stripped-User-Name}:-%{User-Name}})" Thu Jan 19 12:34:21 2012 : Debug: base_filter = "(objectclass=radiusprofile)" Thu Jan 19 12:34:21 2012 : Debug: password_attribute = "unavRadiusPasswd" Thu Jan 19 12:34:21 2012 : Debug: auto_header = no Thu Jan 19 12:34:21 2012 : Debug: access_attr_used_for_allow = yes Thu Jan 19 12:34:21 2012 : Debug: groupname_attribute = "cn" Thu Jan 19 12:34:21 2012 : Debug: groupmembership_filter = "(|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn})))" Thu Jan 19 12:34:21 2012 : Debug: groupmembership_attribute = "member" Thu Jan 19 12:34:21 2012 : Debug: dictionary_mapping = "/usr/local/etc2/freeradius/etc/raddb/ldap.attrmap" Thu Jan 19 12:34:21 2012 : Debug: ldap_debug = 104 Thu Jan 19 12:34:21 2012 : Debug: ldap_connections_number = 10 Thu Jan 19 12:34:21 2012 : Debug: compare_check_items = no Thu Jan 19 12:34:21 2012 : Debug: do_xlat = no Thu Jan 19 12:34:21 2012 : Debug: set_auth_type = yes Thu Jan 19 12:34:21 2012 : Debug: } Thu Jan 19 12:34:21 2012 : Debug: rlm_ldap: Registering ldap_groupcmp for Ldap-Group Thu Jan 19 12:34:21 2012 : Debug: rlm_ldap: Registering ldap_xlat with xlat_name ldap Thu Jan 19 12:34:21 2012 : Debug: rlm_ldap: Over-riding set_auth_type, as there is no module ldap listed in the "authenticate" section. Thu Jan 19 12:34:21 2012 : Debug: rlm_ldap: reading ldap<->radius mappings from file /usr/local/etc2/freeradius/etc/raddb/ldap.attrmap [trimmed] Thu Jan 19 12:34:21 2012 : Debug: conns: 0x830e3c0 Thu Jan 19 12:34:21 2012 : Debug: Module: Checking session {...} for more modules to load Thu Jan 19 12:34:21 2012 : Debug: (Loaded rlm_radutmp, checking if it's valid) Thu Jan 19 12:34:21 2012 : Debug: Module: Linked to module rlm_radutmp Thu Jan 19 12:34:21 2012 : Debug: Module: Instantiating radutmp Thu Jan 19 12:34:21 2012 : Debug: radutmp { Thu Jan 19 12:34:21 2012 : Debug: filename = "/usr/local/etc2/freeradius/var/log/radius/radutmp" Thu Jan 19 12:34:21 2012 : Debug: username = "%{User-Name}" Thu Jan 19 12:34:21 2012 : Debug: case_sensitive = yes Thu Jan 19 12:34:21 2012 : Debug: check_with_nas = yes Thu Jan 19 12:34:21 2012 : Debug: perm = 384 Thu Jan 19 12:34:21 2012 : Debug: callerid = yes Thu Jan 19 12:34:21 2012 : Debug: } Thu Jan 19 12:34:21 2012 : Debug: Module: Checking post-proxy {...} for more modules to load Thu Jan 19 12:34:21 2012 : Debug: Module: Checking post-auth {...} for more modules to load Thu Jan 19 12:34:21 2012 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Thu Jan 19 12:34:21 2012 : Debug: Module: Linked to module rlm_attr_filter Thu Jan 19 12:34:21 2012 : Debug: Module: Instantiating attr_filter.access_reject Thu Jan 19 12:34:21 2012 : Debug: attr_filter attr_filter.access_reject { Thu Jan 19 12:34:21 2012 : Debug: attrsfile = "/usr/local/etc2/freeradius/etc/raddb/attrs.access_reject" Thu Jan 19 12:34:21 2012 : Debug: key = "%{User-Name}" Thu Jan 19 12:34:21 2012 : Debug: } Thu Jan 19 12:34:21 2012 : Debug: } # modules Thu Jan 19 12:34:21 2012 : Debug: } # server Thu Jan 19 12:34:21 2012 : Debug: server { Thu Jan 19 12:34:21 2012 : Debug: modules { Thu Jan 19 12:34:21 2012 : Debug: Module: Checking authenticate {...} for more modules to load Thu Jan 19 12:34:21 2012 : Debug: Module: Checking authorize {...} for more modules to load Thu Jan 19 12:34:21 2012 : Debug: (Loaded rlm_preprocess, checking if it's valid) Thu Jan 19 12:34:21 2012 : Debug: Module: Linked to module rlm_preprocess Thu Jan 19 12:34:21 2012 : Debug: Module: Instantiating preprocess Thu Jan 19 12:34:21 2012 : Debug: preprocess { Thu Jan 19 12:34:21 2012 : Debug: huntgroups = "/usr/local/etc2/freeradius/etc/raddb/huntgroups" Thu Jan 19 12:34:21 2012 : Debug: hints = "/usr/local/etc2/freeradius/etc/raddb/hints" Thu Jan 19 12:34:21 2012 : Debug: with_ascend_hack = no Thu Jan 19 12:34:21 2012 : Debug: ascend_channels_per_line = 23 Thu Jan 19 12:34:21 2012 : Debug: with_ntdomain_hack = no Thu Jan 19 12:34:21 2012 : Debug: with_specialix_jetstream_hack = no Thu Jan 19 12:34:21 2012 : Debug: with_cisco_vsa_hack = no Thu Jan 19 12:34:21 2012 : Debug: with_alvarion_vsa_hack = no Thu Jan 19 12:34:21 2012 : Debug: } Thu Jan 19 12:34:21 2012 : Debug: Module: Checking preacct {...} for more modules to load Thu Jan 19 12:34:21 2012 : Debug: (Loaded rlm_acct_unique, checking if it's valid) Thu Jan 19 12:34:21 2012 : Debug: Module: Linked to module rlm_acct_unique Thu Jan 19 12:34:21 2012 : Debug: Module: Instantiating acct_unique Thu Jan 19 12:34:21 2012 : Debug: acct_unique { Thu Jan 19 12:34:21 2012 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Thu Jan 19 12:34:21 2012 : Debug: } Thu Jan 19 12:34:21 2012 : Debug: Module: Checking accounting {...} for more modules to load Thu Jan 19 12:34:21 2012 : Debug: (Loaded rlm_detail, checking if it's valid) Thu Jan 19 12:34:21 2012 : Debug: Module: Linked to module rlm_detail Thu Jan 19 12:34:21 2012 : Debug: Module: Instantiating detail Thu Jan 19 12:34:21 2012 : Debug: detail { Thu Jan 19 12:34:21 2012 : Debug: detailfile = "/usr/local/etc2/freeradius/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d" Thu Jan 19 12:34:21 2012 : Debug: header = "%t" Thu Jan 19 12:34:21 2012 : Debug: detailperm = 384 Thu Jan 19 12:34:21 2012 : Debug: dirperm = 493 Thu Jan 19 12:34:21 2012 : Debug: locking = no Thu Jan 19 12:34:21 2012 : Debug: log_packet_header = no Thu Jan 19 12:34:21 2012 : Debug: } Thu Jan 19 12:34:21 2012 : Debug: Module: Instantiating attr_filter.accounting_response Thu Jan 19 12:34:21 2012 : Debug: attr_filter attr_filter.accounting_response { Thu Jan 19 12:34:21 2012 : Debug: attrsfile = "/usr/local/etc2/freeradius/etc/raddb/attrs.accounting_response" Thu Jan 19 12:34:21 2012 : Debug: key = "%{User-Name}" Thu Jan 19 12:34:21 2012 : Debug: } Thu Jan 19 12:34:21 2012 : Debug: Module: Checking session {...} for more modules to load Thu Jan 19 12:34:21 2012 : Debug: Module: Checking post-proxy {...} for more modules to load Thu Jan 19 12:34:21 2012 : Debug: Module: Checking post-auth {...} for more modules to load Thu Jan 19 12:34:21 2012 : Debug: } # modules Thu Jan 19 12:34:21 2012 : Debug: } # server Thu Jan 19 12:34:21 2012 : Debug: radiusd: #### Opening IP addresses and Ports #### Thu Jan 19 12:34:21 2012 : Debug: listen { Thu Jan 19 12:34:21 2012 : Debug: type = "auth" Thu Jan 19 12:34:21 2012 : Debug: ipaddr = * Thu Jan 19 12:34:21 2012 : Debug: port = 0 Thu Jan 19 12:34:21 2012 : Debug: } Thu Jan 19 12:34:21 2012 : Debug: listen { Thu Jan 19 12:34:21 2012 : Debug: type = "acct" Thu Jan 19 12:34:21 2012 : Debug: ipaddr = * Thu Jan 19 12:34:21 2012 : Debug: port = 0 Thu Jan 19 12:34:21 2012 : Debug: } Thu Jan 19 12:34:21 2012 : Debug: listen { Thu Jan 19 12:34:21 2012 : Debug: type = "control" Thu Jan 19 12:34:21 2012 : Debug: listen { Thu Jan 19 12:34:21 2012 : Debug: socket = "/usr/local/etc2/freeradius/var/run/radiusd/radiusd.sock" Thu Jan 19 12:34:21 2012 : Debug: } Thu Jan 19 12:34:21 2012 : Debug: } Thu Jan 19 12:34:21 2012 : Debug: Listening on authentication address * port 1812 Thu Jan 19 12:34:21 2012 : Debug: Listening on accounting address * port 1813 Thu Jan 19 12:34:21 2012 : Debug: Listening on command file /usr/local/etc2/freeradius/var/run/radiusd/radiusd.sock Thu Jan 19 12:34:21 2012 : Debug: Listening on proxy address * port 1814 Thu Jan 19 12:34:21 2012 : Info: Ready to process requests. rad_recv: Access-Request packet from host 159.237.8.200 port 3490, id=46, length=124 NAS-IP-Address = 159.237.8.200 NAS-Port-Type = Ethernet Service-Type = Framed-User Message-Authenticator = 0xb666f25ec9310bf99e0ac965a3325f71 NAS-Port = 5 Framed-MTU = 1490 User-Name = "caraiz(a)unav.es" Calling-Station-Id = "D0-67-E5-13-CC-17" EAP-Message = 0x02ff00130163617261697a40756e61762e6573 Thu Jan 19 12:35:17 2012 : Info: +- entering group authorize {...} Thu Jan 19 12:35:17 2012 : Info: ++[preprocess] returns ok Thu Jan 19 12:35:17 2012 : Info: ++[chap] returns noop Thu Jan 19 12:35:17 2012 : Info: ++[mschap] returns noop Thu Jan 19 12:35:17 2012 : Info: [suffix] Looking up realm "unav.es" for User-Name = "caraiz(a)unav.es" Thu Jan 19 12:35:17 2012 : Info: [suffix] Found realm "unav.es" Thu Jan 19 12:35:17 2012 : Info: [suffix] Adding Stripped-User-Name = "caraiz" Thu Jan 19 12:35:17 2012 : Info: [suffix] Adding Realm = "unav.es" Thu Jan 19 12:35:17 2012 : Info: [suffix] Authentication realm is LOCAL. Thu Jan 19 12:35:17 2012 : Info: ++[suffix] returns ok Thu Jan 19 12:35:17 2012 : Info: [eap] EAP packet type response id 255 length 19 Thu Jan 19 12:35:17 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Thu Jan 19 12:35:17 2012 : Info: ++[eap] returns updated Thu Jan 19 12:35:17 2012 : Debug: [ldap] Entering ldap_groupcmp() Thu Jan 19 12:35:17 2012 : Info: [files] expand: ou=radius,o=accounts,dc=unav,dc=es -> ou=radius,o=accounts,dc=unav,dc=es Thu Jan 19 12:35:17 2012 : Info: [files] expand: %{Stripped-User-Name} -> caraiz Thu Jan 19 12:35:17 2012 : Info: [files] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=caraiz) Thu Jan 19 12:35:17 2012 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Thu Jan 19 12:35:17 2012 : Debug: [ldap] ldap_get_conn: Got Id: 0 Thu Jan 19 12:35:17 2012 : Debug: [ldap] attempting LDAP reconnection Thu Jan 19 12:35:17 2012 : Debug: [ldap] (re)connect to ldappre.si.unav.es:389, authentication 0 Thu Jan 19 12:35:17 2012 : Debug: [ldap] starting TLS Thu Jan 19 12:35:17 2012 : Debug: [ldap] bind as cn=radiusOp,dc=unav,dc=es/RAD1bar to ldappre.si.unav.es:389 Thu Jan 19 12:35:17 2012 : Debug: [ldap] waiting for bind result ... Thu Jan 19 12:35:17 2012 : Debug: [ldap] Bind was successful Thu Jan 19 12:35:17 2012 : Debug: [ldap] performing search in ou=radius,o=accounts,dc=unav,dc=es, with filter (uid=caraiz) Thu Jan 19 12:35:17 2012 : Debug: [ldap] ldap_release_conn: Release Id: 0 Thu Jan 19 12:35:17 2012 : Info: [files] expand: (|(&(objectClass=GroupOfNames)(member=%{Ldap-UserDn}))(&(objectClass=GroupOfUniqueNames)(uniquemember=%{Ldap-UserDn}))) -> (|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=))) Thu Jan 19 12:35:17 2012 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Thu Jan 19 12:35:17 2012 : Debug: [ldap] ldap_get_conn: Got Id: 0 Thu Jan 19 12:35:17 2012 : Debug: [ldap] performing search in ou=radius,o=accounts,dc=unav,dc=es, with filter (&(cn=unav.radius.empleado)(|(&(objectClass=GroupOfNames)(member=))(&(objectClass=GroupOfUniqueNames)(uniquemember=)))) Thu Jan 19 12:35:17 2012 : Debug: [ldap] object not found Thu Jan 19 12:35:17 2012 : Debug: [ldap] ldap_release_conn: Release Id: 0 Thu Jan 19 12:35:17 2012 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Thu Jan 19 12:35:17 2012 : Debug: [ldap] ldap_get_conn: Got Id: 0 Thu Jan 19 12:35:17 2012 : Debug: [ldap] performing search in uid=caraiz,ou=radius,o=accounts,dc=unav,dc=es, with filter (objectclass=*) Thu Jan 19 12:35:17 2012 : Debug: [ldap] performing search in uid=unav.radius.arun,ou=groups,ou=radius,o=accounts,dc=unav,dc=es, with filter (cn=unav.radius.empleado) Thu Jan 19 12:35:17 2012 : Debug: [ldap] object not found Thu Jan 19 12:35:17 2012 : Debug: [ldap] performing search in uid=unav.radius.vpn,ou=groups,ou=radius,o=accounts,dc=unav,dc=es, with filter (cn=unav.radius.empleado) Thu Jan 19 12:35:17 2012 : Debug: [ldap] object not found Thu Jan 19 12:35:17 2012 : Debug: [ldap] performing search in uid=unav.radius.wireless,ou=groups,ou=radius,o=accounts,dc=unav,dc=es, with filter (cn=unav.radius.empleado) Thu Jan 19 12:35:17 2012 : Debug: [ldap] object not found Thu Jan 19 12:35:17 2012 : Debug: [ldap] performing search in uid=unav.radius.empleado,ou=groups,ou=radius,o=accounts,dc=unav,dc=es, with filter (cn=unav.radius.empleado) Thu Jan 19 12:35:17 2012 : Debug: rlm_ldap::ldap_groupcmp: User found in group unav.radius.empleado Thu Jan 19 12:35:17 2012 : Debug: [ldap] ldap_release_conn: Release Id: 0 Thu Jan 19 12:35:17 2012 : Info: [files] users: Matched entry DEFAULT at line 1 Thu Jan 19 12:35:17 2012 : Info: ++[files] returns ok Thu Jan 19 12:35:17 2012 : Info: [ldap] performing user authorization for caraiz Thu Jan 19 12:35:17 2012 : Info: [ldap] expand: %{Stripped-User-Name} -> caraiz Thu Jan 19 12:35:17 2012 : Info: [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=caraiz) Thu Jan 19 12:35:17 2012 : Info: [ldap] expand: ou=radius,o=accounts,dc=unav,dc=es -> ou=radius,o=accounts,dc=unav,dc=es Thu Jan 19 12:35:17 2012 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Thu Jan 19 12:35:17 2012 : Debug: [ldap] ldap_get_conn: Got Id: 0 Thu Jan 19 12:35:17 2012 : Debug: [ldap] performing search in ou=radius,o=accounts,dc=unav,dc=es, with filter (uid=caraiz) Thu Jan 19 12:35:17 2012 : Info: [ldap] Added User-Password = uSB8232 in check items Thu Jan 19 12:35:17 2012 : Info: [ldap] looking for check items in directory... Thu Jan 19 12:35:17 2012 : Debug: [ldap] unavRadiusPasswd -> Cleartext-Password == "uSB8232" Thu Jan 19 12:35:17 2012 : Info: [ldap] looking for reply items in directory... Thu Jan 19 12:35:17 2012 : Info: [ldap] user caraiz authorized to use remote access Thu Jan 19 12:35:17 2012 : Debug: [ldap] ldap_release_conn: Release Id: 0 Thu Jan 19 12:35:17 2012 : Info: ++[ldap] returns ok Thu Jan 19 12:35:17 2012 : Info: ++[expiration] returns noop Thu Jan 19 12:35:17 2012 : Info: ++[logintime] returns noop Thu Jan 19 12:35:17 2012 : Info: [pap] Found existing Auth-Type, not changing it. Thu Jan 19 12:35:17 2012 : Info: ++[pap] returns noop Thu Jan 19 12:35:17 2012 : Info: Found Auth-Type = EAP Thu Jan 19 12:35:17 2012 : Info: +- entering group authenticate {...} Thu Jan 19 12:35:17 2012 : Info: [eap] EAP Identity Thu Jan 19 12:35:17 2012 : Info: [eap] processing type md5 Thu Jan 19 12:35:17 2012 : Debug: rlm_eap_md5: Issuing Challenge Thu Jan 19 12:35:17 2012 : Info: ++[eap] returns handled Sending Access-Challenge of id 46 to 159.237.8.200 port 3490 Reply-Message = "Empleado from test switch" EAP-Message = 0x0100001604100355c7206b87c18d1b2f8d1f8d4e3c72 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x9739c5919739c13875490ff836b45426 Thu Jan 19 12:35:17 2012 : Info: Finished request 0. ... Requests 1 to 8 have been trimmed to make the log shorter, but the huntgroup is been recognized ok too. Next is request #9 where for the first time the huntgroup check is not working and the user get rejected: ... Thu Jan 19 12:35:18 2012 : Info: Finished request 8. Thu Jan 19 12:35:18 2012 : Debug: Going to the next request Thu Jan 19 12:35:18 2012 : Debug: Waking up in 4.4 seconds. rad_recv: Access-Request packet from host 159.237.8.200 port 3490, id=55, length=182 NAS-IP-Address = 159.237.8.200 NAS-Port-Type = Ethernet Service-Type = Framed-User Message-Authenticator = 0x4e2e7f7fc86e811f98694a66f5ca6805 NAS-Port = 5 Framed-MTU = 1490 User-Name = "caraiz(a)unav.es" Calling-Station-Id = "D0-67-E5-13-CC-17" State = 0x9739c5919f31dc3875490ff836b45426 EAP-Message = 0x0208003b190017030100302457ac1cb0d098d7cd44203a9d979a317ba06ed8370ef62a14955f4012fb98a6721e402a122fd366d3e8d673895d20fd Thu Jan 19 12:35:18 2012 : Info: +- entering group authorize {...} Thu Jan 19 12:35:18 2012 : Info: ++[preprocess] returns ok Thu Jan 19 12:35:18 2012 : Info: ++[chap] returns noop Thu Jan 19 12:35:18 2012 : Info: ++[mschap] returns noop Thu Jan 19 12:35:18 2012 : Info: [suffix] Looking up realm "unav.es" for User-Name = "caraiz(a)unav.es" Thu Jan 19 12:35:18 2012 : Info: [suffix] Found realm "unav.es" Thu Jan 19 12:35:18 2012 : Info: [suffix] Adding Stripped-User-Name = "caraiz" Thu Jan 19 12:35:18 2012 : Info: [suffix] Adding Realm = "unav.es" Thu Jan 19 12:35:18 2012 : Info: [suffix] Authentication realm is LOCAL. Thu Jan 19 12:35:18 2012 : Info: ++[suffix] returns ok Thu Jan 19 12:35:18 2012 : Info: [eap] EAP packet type response id 8 length 59 Thu Jan 19 12:35:18 2012 : Info: [eap] Continuing tunnel setup. Thu Jan 19 12:35:18 2012 : Info: ++[eap] returns ok Thu Jan 19 12:35:18 2012 : Info: Found Auth-Type = EAP Thu Jan 19 12:35:18 2012 : Info: +- entering group authenticate {...} Thu Jan 19 12:35:18 2012 : Info: [eap] Request found, released from the list Thu Jan 19 12:35:18 2012 : Info: [eap] EAP/peap Thu Jan 19 12:35:18 2012 : Info: [eap] processing type peap Thu Jan 19 12:35:18 2012 : Info: [peap] processing EAP-TLS Thu Jan 19 12:35:18 2012 : Info: [peap] eaptls_verify returned 7 Thu Jan 19 12:35:18 2012 : Info: [peap] Done initial handshake Thu Jan 19 12:35:18 2012 : Info: [peap] eaptls_process returned 7 Thu Jan 19 12:35:18 2012 : Info: [peap] EAPTLS_OK Thu Jan 19 12:35:18 2012 : Info: [peap] Session established. Decoding tunneled attributes. Thu Jan 19 12:35:18 2012 : Info: [peap] Identity - caraiz(a)unav.es Thu Jan 19 12:35:18 2012 : Info: [peap] Got tunneled request EAP-Message = 0x020800130163617261697a40756e61762e6573 server { Thu Jan 19 12:35:18 2012 : Debug: PEAP: Got tunneled identity of caraiz(a)unav.es Thu Jan 19 12:35:18 2012 : Debug: PEAP: Setting default EAP type for tunneled EAP session. Thu Jan 19 12:35:18 2012 : Debug: PEAP: Setting User-Name to caraiz(a)unav.es Sending tunneled request EAP-Message = 0x020800130163617261697a40756e61762e6573 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "caraiz(a)unav.es" NAS-IP-Address = 159.237.8.200 NAS-Port-Type = Ethernet Service-Type = Framed-User NAS-Port = 5 Framed-MTU = 1490 Calling-Station-Id = "D0-67-E5-13-CC-17" server inner-tunnel { Thu Jan 19 12:35:18 2012 : Info: +- entering group authorize {...} Thu Jan 19 12:35:18 2012 : Info: ++[chap] returns noop Thu Jan 19 12:35:18 2012 : Info: ++[mschap] returns noop Thu Jan 19 12:35:18 2012 : Info: ++[unix] returns notfound Thu Jan 19 12:35:18 2012 : Info: [suffix] Looking up realm "unav.es" for User-Name = "caraiz(a)unav.es" Thu Jan 19 12:35:18 2012 : Info: [suffix] Found realm "unav.es" Thu Jan 19 12:35:18 2012 : Info: [suffix] Adding Stripped-User-Name = "caraiz" Thu Jan 19 12:35:18 2012 : Info: [suffix] Adding Realm = "unav.es" Thu Jan 19 12:35:18 2012 : Info: [suffix] Authentication realm is LOCAL. Thu Jan 19 12:35:18 2012 : Info: ++[suffix] returns ok Thu Jan 19 12:35:18 2012 : Info: ++[control] returns ok Thu Jan 19 12:35:18 2012 : Info: [eap] EAP packet type response id 8 length 19 Thu Jan 19 12:35:18 2012 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Thu Jan 19 12:35:18 2012 : Info: ++[eap] returns updated Thu Jan 19 12:35:18 2012 : Info: [files] users: Matched entry DEFAULT at line 4 Thu Jan 19 12:35:18 2012 : Info: ++[files] returns ok Thu Jan 19 12:35:18 2012 : Info: [ldap] performing user authorization for caraiz Thu Jan 19 12:35:18 2012 : Info: [ldap] expand: %{Stripped-User-Name} -> caraiz Thu Jan 19 12:35:18 2012 : Info: [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=caraiz) Thu Jan 19 12:35:18 2012 : Info: [ldap] expand: ou=radius,o=accounts,dc=unav,dc=es -> ou=radius,o=accounts,dc=unav,dc=es Thu Jan 19 12:35:18 2012 : Debug: [ldap] ldap_get_conn: Checking Id: 0 Thu Jan 19 12:35:18 2012 : Debug: [ldap] ldap_get_conn: Got Id: 0 Thu Jan 19 12:35:18 2012 : Debug: [ldap] performing search in ou=radius,o=accounts,dc=unav,dc=es, with filter (uid=caraiz) Thu Jan 19 12:35:18 2012 : Info: [ldap] Added User-Password = uSB8232 in check items Thu Jan 19 12:35:18 2012 : Info: [ldap] looking for check items in directory... Thu Jan 19 12:35:18 2012 : Debug: [ldap] unavRadiusPasswd -> Cleartext-Password == "uSB8232" Thu Jan 19 12:35:18 2012 : Info: [ldap] looking for reply items in directory... Thu Jan 19 12:35:18 2012 : Info: [ldap] user caraiz authorized to use remote access Thu Jan 19 12:35:18 2012 : Debug: [ldap] ldap_release_conn: Release Id: 0 Thu Jan 19 12:35:18 2012 : Info: ++[ldap] returns ok Thu Jan 19 12:35:18 2012 : Info: ++[expiration] returns noop Thu Jan 19 12:35:18 2012 : Info: ++[logintime] returns noop Thu Jan 19 12:35:18 2012 : Info: [pap] Found existing Auth-Type, not changing it. Thu Jan 19 12:35:18 2012 : Info: ++[pap] returns noop Thu Jan 19 12:35:18 2012 : Info: Found Auth-Type = Reject Thu Jan 19 12:35:18 2012 : Info: Auth-Type = Reject, rejecting user Thu Jan 19 12:35:18 2012 : Info: Failed to authenticate the user. } # server inner-tunnel Thu Jan 19 12:35:18 2012 : Info: [peap] Got tunneled reply code 3 Reply-Message = "Access not allowed." Thu Jan 19 12:35:18 2012 : Info: [peap] Got tunneled reply RADIUS code 3 Reply-Message = "Access not allowed." Thu Jan 19 12:35:18 2012 : Info: [peap] Tunneled authentication was rejected. Thu Jan 19 12:35:18 2012 : Info: [peap] FAILURE Thu Jan 19 12:35:18 2012 : Info: ++[eap] returns handled Sending Access-Challenge of id 55 to 159.237.8.200 port 3490 EAP-Message = 0x0109002b19001703010020419852f0a6019cefb1881bb24d6bacc3bc6ca4cb0712da325d9708366a31c62d Message-Authenticator = 0x00000000000000000000000000000000 State = 0x9739c5919e30dc3875490ff836b45426 Thu Jan 19 12:35:18 2012 : Info: Finished request 9. ... Then it comes request #10 that is rejected too as the user session weas rejected before: * Oscar Remírez de Ganuza Satrústegui* Servicios Informáticos (Área de Infraestructuras) Universidad de Navarra Tel. +34 948425600 x3130 http://www.unav.es/SI/

2 3