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

Proxy Problem
by Muhammad Nadeem 21 Feb '13

21 Feb '13

Hi everybody,, I have configured a proxy server with 'type=client-port-balance'. I have configure two backed FR servers(192.168.0.109 and 192.168.0.112). I am sending requests from a PC to 192.168.0.102 ( acting as proxy server). But requests are forwarded to only one FR server (i-e 192.168.0.112). Why proxy server is not sending requests to other one. As each request has same IP but different PORT, So hashing mechanism of Proxy server should also choose other FR server (192.168.0.109) for requests entertaining. could anyone please tell me what's the issue. Thanks

1 0

simulate Point Access
by tabibel sami 20 Feb '13

20 Feb '13

Hello, i try to make a virtual infrastructure for testing wireless eap authtication via freeradius, so i created three virtual machine for supplicant, authenticator (point access), radius server i installed wpa_supplicant on first machine, freeradius on server, but i have no idea on how can i simulate a point access whith a linux virtual machine. please help me ! thank you.

2 1

Listing attributes in a request
by Adam Moffett 20 Feb '13

20 Feb '13

Does the output from radius -X display all of the attributes in a request from a client? If not, is there a way to see all of the attributes in the request? I'm looking for the value of a VSA and I'm not seeing it. I'm not sure if it's not being displayed in the debug output or just not there at all.

2 1

Ntlm_auth vs. Cleartext-password
by Óscar Remírez de Ganuza Satrústegui 20 Feb '13

20 Feb '13

Good afternoon everybody, We have configured freeradius to authenticate against Active Directory/Samba using ntlm_auth, following the instructions on: http://deployingradius.com/documents/configuration/active_directory.html Everything works as expected. Right now on our production server we are using LDAP to store the user credentials. We would like to achieve a smooth transition to the new authentication method. So want to configure freeradius to authenticate with ntlm_auth just in the cases when there is not ClearText-Password available, but we do not know how to do it. Using instructions from modules/mschap: # If ntlm_auth is configured below, then the mschap # module will call ntlm_auth for every MS-CHAP # authentication request. If there is a cleartext # or NT hashed password available, you can set # "MS-CHAP-Use-NTLM-Auth := No" in the control items, # and the mschap module will do the authentication itself, # without calling ntlm_auth. We were able to *bypass* the ntlm_auth on some users/groups defining on the users file the control item "MS-CHAP-Use-NTLM-Auth := No". But is there a way to configure freeradius such that if Cleartext-Password password is available it uses it, and otherwise it uses ntlm_auth to authenticate? Thank you so much for your help. Regards, * Oscar Remírez de Ganuza Satrústegui* Servicios Informáticos (Área de Infraestructuras) Universidad de Navarra Tel. +34 948425600 x803130 http://www.unav.es/SI/

2 2

EAP-TLS and OS X clients
by Jaap Winius 20 Feb '13

20 Feb '13

Hi folks, My WPA2-Enterprise configuration with Freeradius 2.1.0, EAP-TLS and 4096-bit SHA-1 certificates works great with wpaspplicant on Linux, but can anyone help me understand how to get this to work for OS X (Lion) clients? My Linux client uses a copy of the ca.pem file to establish the link (after which PAP is used to authenticate), but although the same ca.pem file can be imported into the OS X client's keychain, this certificate never shows up as a selectable identity when configuring EAP-TLS wireless access, like in this case (bottom of the page): https://wiki.thayer.dartmouth.edu/display/computing/Configuring+an+OS+X+Mac… In this example, the users are given a personalized *.cer certificate to add to their keychain. Since I don't have any client.cer files, I tried this approach with a client.csr file instead, which seemed personalized enough, but still I run into the same roadblock. Can anyone say what I should be doing differently? E.g. are *.cer certificates mandatory (if so, how can I make them?), or can I not use my self-signed certificates? Thanks, Jaap

3 5

Radius server failed to respond
by ahmed.sajid＠stfc.ac.uk 20 Feb '13

20 Feb '13

Hi, I can authenticate using Kerberos, by running radius in debugging mode. I can see that I get Access-Accept packet but SSH doesn't gets logged in. I get following in /var/log/messages pam_radius_auth: DEBUG: getservbyname(radius, udp) returned -562132672. pam_radius_auth: RADIUS server 127.0.0.1 failled to respond pam_radius_auth: All RADIUS servers failed to respond. The file /etc/pam.d/sshd #%PAM-1.0 auth required pam_sepermit.so auth sufficient pam_radius_auth.so auth include password-auth account required pam_nologin.so account include password-auth password include password-auth # pam_selinux.so close should be the first session rule session required pam_selinux.so close session required pam_loginuid.so # pam_selinux.so open should only be followed by sessions to be executed in the user context session required pam_selinux.so open env_params session optional pam_keyinit.so force revoke session include password-auth It seems to work fine but every now and then it just breaks. Regards, Ahmed. -- Scanned by iCritical.

3 7

RADIUS-Proxy before MAC Auth
by Oliver Warda 20 Feb '13

20 Feb '13

Hello everybody, I'm using FR 2.1.12 on CentOS 6.3 802.1x and MAC Auth as described in WiKi is working fine. Authentication is done local Now, I have the demand to implement RADIUS Proxy also. As I understand MAC Auth is done before RADIUS Proxy. But I do not want to administrate about 5.000 RADIUS Proxy clients in my authorized_macs file (RADIUS Proxy is using 802.1x only). Is there a way to proxy requests based on realms before checking the MAC address? In my testing I couldn't realize RADIUS Proxy without keeping the MAC in authorized_macs file. Appreciate your help. Thank you in advance. Freundliche Grüße Oliver Warda Universitätsklinikum Tübingen Geschäftsbereich Informationstechnologie Geissweg 11 72076 Tübingen Telefon: +49 (0)7071 29 85604 E-Mail: oliver.warda(a)med.uni-tuebingen.de

2 1

eap testing
by Muhammad Nadeem 20 Feb '13

20 Feb '13

Hi every body,, I have fallen into a serious trouble :( I have configured a proxy server, that is proxying all incoming requests to two backend servers. in 'proxy.conf' i have configured 'type=client-balance' so that it can work with EAP. Now i wanna do load testing of this configuration with EAP-TLS. So with configuration i need to have a lot of NAS, with different IP's. But I only have 2. Could any one please help me in this situation. Could please suggest me a tool or a guideline to achieve my goal. Thanks in advance

2 11

unsubscribe
by Andrew Long 20 Feb '13

20 Feb '13

unsubscribe

2 1

New Server EAP issue
by David Peterson 19 Feb '13

19 Feb '13

I cant figure out where I went wrong. The auth never gets to the inner-tunnel. David root@hafreeradius1://usr/local/etc/raddb# radiusd -Xxx Tue Feb 19 12:21:30 2013 : Info: radiusd: FreeRADIUS Version 2.2.1 (git #97cba57), for host x86_64-unknown-linux-gnu, built on Feb 18 2013 at 14:52:13 Tue Feb 19 12:21:30 2013 : Debug: Server was built with: Tue Feb 19 12:21:30 2013 : Debug: accounting Tue Feb 19 12:21:30 2013 : Debug: authentication Tue Feb 19 12:21:30 2013 : Debug: WITH_DHCP Tue Feb 19 12:21:30 2013 : Debug: WITH_VMPS Tue Feb 19 12:21:30 2013 : Debug: Server core libs: Tue Feb 19 12:21:30 2013 : Debug: ssl: OpenSSL 1.0.1c 10 May 2012 Tue Feb 19 12:21:30 2013 : Info: Copyright (C) 1999-2013 The FreeRADIUS server project and contributors. Tue Feb 19 12:21:30 2013 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Tue Feb 19 12:21:30 2013 : Info: PARTICULAR PURPOSE. Tue Feb 19 12:21:30 2013 : Info: You may redistribute copies of FreeRADIUS under the terms of the Tue Feb 19 12:21:30 2013 : Info: GNU General Public License. Tue Feb 19 12:21:30 2013 : Info: For more information about these matters, see the file named COPYRIGHT. Tue Feb 19 12:21:30 2013 : Info: Starting - reading configuration files ... Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/radiusd.conf Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/proxy.conf Tue Feb 19 12:21:30 2013 : Debug: including files in directory /usr/local/etc/raddb/modules/ Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/acct_unique Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/always Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/attr_filter Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/attr_rewrite Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/cache Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/chap Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/checkval Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/counter Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/cui Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/detail Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/detail.example.com Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/detail.log Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/dhcp_sqlippool Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/sql/mysql/ippool-dhcp.conf Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/digest Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/dynamic_clients Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/echo Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/etc_group Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/exec Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/expiration Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/expr Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/files Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/inner-eap Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/ippool Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/krb5 Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/ldap Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/linelog Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/logintime Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/mac2ip Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/mac2vlan Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/mschap Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/ntlm_auth Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/opendirectory Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/otp Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/pam Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/pap Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/passwd Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/perl Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/policy Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/preprocess Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/radrelay Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/radutmp Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/realm Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/redis Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/rediswho Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/replicate Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/smbpasswd Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/smsotp Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/soh Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/sql Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/sql/mysql/dialup.conf Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/sql_log Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/sqlcounter_expire_on_login Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/sradutmp Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/unix Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/modules/wimax Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/eap.conf Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/policy.conf Tue Feb 19 12:21:30 2013 : Debug: including files in directory /usr/local/etc/raddb/sites-enabled/ Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/WiMAX.com Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/sites-available/default Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/control-socket Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/default Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/dynamic-clients Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/virtual.example.com Tue Feb 19 12:21:30 2013 : Debug: including configuration file /usr/local/etc/raddb/sites-available/default Tue Feb 19 12:21:30 2013 : Debug: main { Tue Feb 19 12:21:30 2013 : Debug: allow_core_dumps = no Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: including dictionary file /usr/local/etc/raddb/dictionary Tue Feb 19 12:21:30 2013 : Debug: main { Tue Feb 19 12:21:30 2013 : Debug: name = "radiusd" Tue Feb 19 12:21:30 2013 : Debug: prefix = "/usr/local" Tue Feb 19 12:21:30 2013 : Debug: localstatedir = "/usr/local/var" Tue Feb 19 12:21:30 2013 : Debug: sbindir = "/usr/local/sbin" Tue Feb 19 12:21:30 2013 : Debug: logdir = "/usr/local/var/log/radius" Tue Feb 19 12:21:30 2013 : Debug: run_dir = "/usr/local/var/run/radiusd" Tue Feb 19 12:21:30 2013 : Debug: libdir = "/usr/local/lib" Tue Feb 19 12:21:30 2013 : Debug: radacctdir = "/usr/local/var/log/radius/radacct" Tue Feb 19 12:21:30 2013 : Debug: hostname_lookups = no Tue Feb 19 12:21:30 2013 : Debug: max_request_time = 30 Tue Feb 19 12:21:30 2013 : Debug: cleanup_delay = 5 Tue Feb 19 12:21:30 2013 : Debug: max_requests = 1024 Tue Feb 19 12:21:30 2013 : Debug: pidfile = "/usr/local/var/run/radiusd/radiusd.pid" Tue Feb 19 12:21:30 2013 : Debug: checkrad = "/usr/local/sbin/checkrad" Tue Feb 19 12:21:30 2013 : Debug: debug_level = 0 Tue Feb 19 12:21:30 2013 : Debug: proxy_requests = yes Tue Feb 19 12:21:30 2013 : Debug: log { Tue Feb 19 12:21:30 2013 : Debug: stripped_names = no Tue Feb 19 12:21:30 2013 : Debug: auth = no Tue Feb 19 12:21:30 2013 : Debug: auth_badpass = no Tue Feb 19 12:21:30 2013 : Debug: auth_goodpass = no Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: security { Tue Feb 19 12:21:30 2013 : Debug: max_attributes = 200 Tue Feb 19 12:21:30 2013 : Debug: reject_delay = 1 Tue Feb 19 12:21:30 2013 : Debug: status_server = yes Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: radiusd: #### Loading Realms and Home Servers #### Tue Feb 19 12:21:30 2013 : Debug: proxy server { Tue Feb 19 12:21:30 2013 : Debug: retry_delay = 5 Tue Feb 19 12:21:30 2013 : Debug: retry_count = 3 Tue Feb 19 12:21:30 2013 : Debug: default_fallback = no Tue Feb 19 12:21:30 2013 : Debug: dead_time = 120 Tue Feb 19 12:21:30 2013 : Debug: wake_all_if_all_dead = no Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: home_server localhost { Tue Feb 19 12:21:30 2013 : Debug: ipaddr = 127.0.0.1 Tue Feb 19 12:21:30 2013 : Debug: port = 1812 Tue Feb 19 12:21:30 2013 : Debug: type = "auth" Tue Feb 19 12:21:30 2013 : Debug: secret = "testing123" Tue Feb 19 12:21:30 2013 : Debug: response_window = 20 Tue Feb 19 12:21:30 2013 : Debug: max_outstanding = 65536 Tue Feb 19 12:21:30 2013 : Debug: require_message_authenticator = yes Tue Feb 19 12:21:30 2013 : Debug: zombie_period = 40 Tue Feb 19 12:21:30 2013 : Debug: status_check = "status-server" Tue Feb 19 12:21:30 2013 : Debug: ping_interval = 30 Tue Feb 19 12:21:30 2013 : Debug: check_interval = 30 Tue Feb 19 12:21:30 2013 : Debug: num_answers_to_alive = 3 Tue Feb 19 12:21:30 2013 : Debug: num_pings_to_alive = 3 Tue Feb 19 12:21:30 2013 : Debug: revive_interval = 120 Tue Feb 19 12:21:30 2013 : Debug: status_check_timeout = 4 Tue Feb 19 12:21:30 2013 : Debug: coa { Tue Feb 19 12:21:30 2013 : Debug: irt = 2 Tue Feb 19 12:21:30 2013 : Debug: mrt = 16 Tue Feb 19 12:21:30 2013 : Debug: mrc = 5 Tue Feb 19 12:21:30 2013 : Debug: mrd = 30 Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: realm WiMAX.com { Tue Feb 19 12:21:30 2013 : Debug: nostrip Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: realm LOCAL { Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: realm virtual.example.com { Tue Feb 19 12:21:30 2013 : Debug: virtual_server = virtual.example.com Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: home_server_pool my_auth_failover { Tue Feb 19 12:21:30 2013 : Debug: type = fail-over Tue Feb 19 12:21:30 2013 : Debug: home_server = localhost Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: radiusd: #### Loading Clients #### Tue Feb 19 12:21:30 2013 : Debug: client dynamic { Tue Feb 19 12:21:30 2013 : Debug: ipaddr = 172.16.4.0 Tue Feb 19 12:21:30 2013 : Debug: netmask = 24 Tue Feb 19 12:21:30 2013 : Debug: require_message_authenticator = no Tue Feb 19 12:21:30 2013 : Debug: dynamic_clients = "dynamic_client_server" Tue Feb 19 12:21:30 2013 : Debug: lifetime = 3600 Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: radiusd: #### Instantiating modules #### Tue Feb 19 12:21:30 2013 : Debug: instantiate { Tue Feb 19 12:21:30 2013 : Debug: (Loaded rlm_exec, checking if it's valid) Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to module rlm_exec Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating module "exec" from file /usr/local/etc/raddb/modules/exec Tue Feb 19 12:21:30 2013 : Debug: exec { Tue Feb 19 12:21:30 2013 : Debug: wait = no Tue Feb 19 12:21:30 2013 : Debug: input_pairs = "request" Tue Feb 19 12:21:30 2013 : Debug: shell_escape = yes Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: (Loaded rlm_expr, checking if it's valid) Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to module rlm_expr Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating module "expr" from file /usr/local/etc/raddb/modules/expr Tue Feb 19 12:21:30 2013 : Debug: (Loaded rlm_expiration, checking if it's valid) Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to module rlm_expiration Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating module "expiration" from file /usr/local/etc/raddb/modules/expiration Tue Feb 19 12:21:30 2013 : Debug: expiration { Tue Feb 19 12:21:30 2013 : Debug: reply-message = "Password Has Expired " Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: (Loaded rlm_logintime, checking if it's valid) Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to module rlm_logintime Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating module "logintime" from file /usr/local/etc/raddb/modules/logintime Tue Feb 19 12:21:30 2013 : Debug: logintime { Tue Feb 19 12:21:30 2013 : Debug: reply-message = "You are calling outside your allowed timespan " Tue Feb 19 12:21:30 2013 : Debug: minimum-timeout = 60 Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: radiusd: #### Loading Virtual Servers #### Tue Feb 19 12:21:30 2013 : Debug: server { # from file /usr/local/etc/raddb/radiusd.conf Tue Feb 19 12:21:30 2013 : Debug: modules { Tue Feb 19 12:21:30 2013 : Debug: Module: Creating Post-Auth-Type = REJECT Tue Feb 19 12:21:30 2013 : Debug: Module: Checking authenticate {...} for more modules to load Tue Feb 19 12:21:30 2013 : Debug: (Loaded rlm_pap, checking if it's valid) Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to module rlm_pap Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating module "pap" from file /usr/local/etc/raddb/modules/pap Tue Feb 19 12:21:30 2013 : Debug: pap { Tue Feb 19 12:21:30 2013 : Debug: encryption_scheme = "auto" Tue Feb 19 12:21:30 2013 : Debug: auto_header = no Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: (Loaded rlm_chap, checking if it's valid) Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to module rlm_chap Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating module "chap" from file /usr/local/etc/raddb/modules/chap Tue Feb 19 12:21:30 2013 : Debug: (Loaded rlm_mschap, checking if it's valid) Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to module rlm_mschap Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating module "mschap" from file /usr/local/etc/raddb/modules/mschap Tue Feb 19 12:21:30 2013 : Debug: mschap { Tue Feb 19 12:21:30 2013 : Debug: use_mppe = yes Tue Feb 19 12:21:30 2013 : Debug: require_encryption = no Tue Feb 19 12:21:30 2013 : Debug: require_strong = no Tue Feb 19 12:21:30 2013 : Debug: with_ntdomain_hack = no Tue Feb 19 12:21:30 2013 : Debug: allow_retry = yes Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: (Loaded rlm_eap, checking if it's valid) Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to module rlm_eap Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating module "eap" from file /usr/local/etc/raddb/eap.conf Tue Feb 19 12:21:30 2013 : Debug: eap { Tue Feb 19 12:21:30 2013 : Debug: default_eap_type = "md5" Tue Feb 19 12:21:30 2013 : Debug: timer_expire = 60 Tue Feb 19 12:21:30 2013 : Debug: ignore_unknown_eap_types = no Tue Feb 19 12:21:30 2013 : Debug: cisco_accounting_username_bug = no Tue Feb 19 12:21:30 2013 : Debug: max_sessions = 4096 Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to sub-module rlm_eap_md5 Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating eap-md5 Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to sub-module rlm_eap_leap Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating eap-leap Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to sub-module rlm_eap_gtc Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating eap-gtc Tue Feb 19 12:21:30 2013 : Debug: gtc { Tue Feb 19 12:21:30 2013 : Debug: challenge = "Password: " Tue Feb 19 12:21:30 2013 : Debug: auth_type = "PAP" Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to sub-module rlm_eap_tls Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating eap-tls Tue Feb 19 12:21:30 2013 : Debug: tls { Tue Feb 19 12:21:30 2013 : Debug: rsa_key_exchange = no Tue Feb 19 12:21:30 2013 : Debug: dh_key_exchange = yes Tue Feb 19 12:21:30 2013 : Debug: rsa_key_length = 512 Tue Feb 19 12:21:30 2013 : Debug: dh_key_length = 512 Tue Feb 19 12:21:30 2013 : Debug: verify_depth = 0 Tue Feb 19 12:21:30 2013 : Debug: CA_path = "/usr/local/etc/raddb/certs" Tue Feb 19 12:21:30 2013 : Debug: pem_file_type = yes Tue Feb 19 12:21:30 2013 : Debug: private_key_file = "/usr/local/etc/raddb/certs/server.pem" Tue Feb 19 12:21:30 2013 : Debug: certificate_file = "/usr/local/etc/raddb/certs/server.pem" Tue Feb 19 12:21:30 2013 : Debug: CA_file = "/usr/local/etc/raddb/certs/ca.pem" Tue Feb 19 12:21:30 2013 : Debug: private_key_password = "whatever" Tue Feb 19 12:21:30 2013 : Debug: dh_file = "/usr/local/etc/raddb/certs/dh" Tue Feb 19 12:21:30 2013 : Debug: random_file = "/usr/local/etc/raddb/certs/random" Tue Feb 19 12:21:30 2013 : Debug: fragment_size = 1024 Tue Feb 19 12:21:30 2013 : Debug: include_length = yes Tue Feb 19 12:21:30 2013 : Debug: check_crl = no Tue Feb 19 12:21:30 2013 : Debug: cipher_list = "DEFAULT" Tue Feb 19 12:21:30 2013 : Debug: make_cert_command = "/usr/local/etc/raddb/certs/bootstrap" Tue Feb 19 12:21:30 2013 : Debug: ecdh_curve = "prime256v1" Tue Feb 19 12:21:30 2013 : Debug: cache { Tue Feb 19 12:21:30 2013 : Debug: enable = no Tue Feb 19 12:21:30 2013 : Debug: lifetime = 24 Tue Feb 19 12:21:30 2013 : Debug: max_entries = 255 Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: verify { Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: ocsp { Tue Feb 19 12:21:30 2013 : Debug: enable = no Tue Feb 19 12:21:30 2013 : Debug: override_cert_url = yes Tue Feb 19 12:21:30 2013 : Debug: url = "http://127.0.0.1/ocsp/" Tue Feb 19 12:21:30 2013 : Debug: use_nonce = yes Tue Feb 19 12:21:30 2013 : Debug: timeout = 0 Tue Feb 19 12:21:30 2013 : Debug: softfail = no Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to sub-module rlm_eap_ttls Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating eap-ttls Tue Feb 19 12:21:30 2013 : Debug: ttls { Tue Feb 19 12:21:30 2013 : Debug: default_eap_type = "mschapv2" Tue Feb 19 12:21:30 2013 : Debug: copy_request_to_tunnel = yes Tue Feb 19 12:21:30 2013 : Debug: use_tunneled_reply = yes Tue Feb 19 12:21:30 2013 : Debug: virtual_server = "inner-tunnel" Tue Feb 19 12:21:30 2013 : Debug: include_length = yes Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to sub-module rlm_eap_peap Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating eap-peap Tue Feb 19 12:21:30 2013 : Debug: peap { Tue Feb 19 12:21:30 2013 : Debug: default_eap_type = "mschapv2" Tue Feb 19 12:21:30 2013 : Debug: copy_request_to_tunnel = no Tue Feb 19 12:21:30 2013 : Debug: use_tunneled_reply = no Tue Feb 19 12:21:30 2013 : Debug: proxy_tunneled_request_as_eap = yes Tue Feb 19 12:21:30 2013 : Debug: virtual_server = "inner-tunnel" Tue Feb 19 12:21:30 2013 : Debug: soh = no Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating eap-mschapv2 Tue Feb 19 12:21:30 2013 : Debug: mschapv2 { Tue Feb 19 12:21:30 2013 : Debug: with_ntdomain_hack = no Tue Feb 19 12:21:30 2013 : Debug: send_error = no Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: Module: Checking authorize {...} for more modules to load Tue Feb 19 12:21:30 2013 : Debug: (Loaded rlm_preprocess, checking if it's valid) Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to module rlm_preprocess Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating module "preprocess" from file /usr/local/etc/raddb/modules/preprocess Tue Feb 19 12:21:30 2013 : Debug: preprocess { Tue Feb 19 12:21:30 2013 : Debug: huntgroups = "/usr/local/etc/raddb/huntgroups" Tue Feb 19 12:21:30 2013 : Debug: hints = "/usr/local/etc/raddb/hints" Tue Feb 19 12:21:30 2013 : Debug: with_ascend_hack = no Tue Feb 19 12:21:30 2013 : Debug: ascend_channels_per_line = 23 Tue Feb 19 12:21:30 2013 : Debug: with_ntdomain_hack = no Tue Feb 19 12:21:30 2013 : Debug: with_specialix_jetstream_hack = no Tue Feb 19 12:21:30 2013 : Debug: with_cisco_vsa_hack = no Tue Feb 19 12:21:30 2013 : Debug: with_alvarion_vsa_hack = no Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: reading pairlist file /usr/local/etc/raddb/huntgroups Tue Feb 19 12:21:30 2013 : Debug: reading pairlist file /usr/local/etc/raddb/hints Tue Feb 19 12:21:30 2013 : Debug: (Loaded rlm_wimax, checking if it's valid) Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to module rlm_wimax Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating module "wimax" from file /usr/local/etc/raddb/modules/wimax Tue Feb 19 12:21:30 2013 : Debug: wimax { Tue Feb 19 12:21:30 2013 : Debug: delete_mppe_keys = yes Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: (Loaded rlm_realm, checking if it's valid) Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to module rlm_realm Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating module "suffix" from file /usr/local/etc/raddb/modules/realm Tue Feb 19 12:21:30 2013 : Debug: realm suffix { Tue Feb 19 12:21:30 2013 : Debug: format = "suffix" Tue Feb 19 12:21:30 2013 : Debug: delimiter = "@" Tue Feb 19 12:21:30 2013 : Debug: ignore_default = no Tue Feb 19 12:21:30 2013 : Debug: ignore_null = no Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:30 2013 : Debug: (Loaded rlm_sql, checking if it's valid) Tue Feb 19 12:21:30 2013 : Debug: Module: Linked to module rlm_sql Tue Feb 19 12:21:30 2013 : Debug: Module: Instantiating module "sql" from file /usr/local/etc/raddb/modules/sql Tue Feb 19 12:21:30 2013 : Debug: sql { Tue Feb 19 12:21:30 2013 : Debug: driver = "rlm_sql_mysql" Tue Feb 19 12:21:30 2013 : Debug: server = "localhost" Tue Feb 19 12:21:30 2013 : Debug: port = "" Tue Feb 19 12:21:30 2013 : Debug: login = "radius" Tue Feb 19 12:21:30 2013 : Debug: password = "unl0ck" Tue Feb 19 12:21:30 2013 : Debug: radius_db = "radius" Tue Feb 19 12:21:30 2013 : Debug: read_groups = yes Tue Feb 19 12:21:30 2013 : Debug: sqltrace = no Tue Feb 19 12:21:30 2013 : Debug: sqltracefile = "/usr/local/var/log/radius/sqltrace.sql" Tue Feb 19 12:21:30 2013 : Debug: readclients = yes Tue Feb 19 12:21:30 2013 : Debug: deletestalesessions = yes Tue Feb 19 12:21:30 2013 : Debug: num_sql_socks = 5 Tue Feb 19 12:21:30 2013 : Debug: lifetime = 0 Tue Feb 19 12:21:30 2013 : Debug: max_queries = 0 Tue Feb 19 12:21:30 2013 : Debug: sql_user_name = "%{User-Name}" Tue Feb 19 12:21:30 2013 : Debug: default_user_profile = "" Tue Feb 19 12:21:30 2013 : Debug: nas_query = "SELECT id, nasname, shortname, type, secret, server FROM nas" Tue Feb 19 12:21:30 2013 : Debug: authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id" Tue Feb 19 12:21:30 2013 : Debug: authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id" Tue Feb 19 12:21:30 2013 : Debug: authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id" Tue Feb 19 12:21:30 2013 : Debug: authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id" Tue Feb 19 12:21:30 2013 : Debug: accounting_onoff_query = " UPDATE radacct SET acctstoptime = '%S', acctsessiontime = unix_timestamp('%S') - unix_timestamp(acctstarttime), acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = %{%{Acct-Delay-Time}:-0} WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= '%S'" Tue Feb 19 12:21:30 2013 : Debug: accounting_update_query = " UPDATE radacct SET framedipaddress = '%{Framed-IP-Address}', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" Tue Feb 19 12:21:30 2013 : Debug: accounting_update_query_alt = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctsessiontime, acctauthentic, connectinfo_start, acctinputoctets, acctoutputoctets, 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}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{X-Ascend-Session-Svr-Key}')" Tue Feb 19 12:21:30 2013 : Debug: accounting_start_query = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}')" Tue Feb 19 12:21:30 2013 : Debug: accounting_start_query_alt = " UPDATE radacct SET acctstarttime = '%S', acctstartdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_start = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" Tue Feb 19 12:21:30 2013 : Debug: accounting_stop_query = " UPDATE radacct SET acctstoptime = '%S', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" Tue Feb 19 12:21:30 2013 : Debug: accounting_stop_query_alt = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Connect-Info}', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{%{Acct-Delay-Time}:-0}')" Tue Feb 19 12:21:30 2013 : Debug: group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority" Tue Feb 19 12:21:30 2013 : Debug: connect_failure_retry_delay = 60 Tue Feb 19 12:21:30 2013 : Debug: simul_count_query = "" Tue Feb 19 12:21:30 2013 : Debug: simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" Tue Feb 19 12:21:30 2013 : Debug: postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')" Tue Feb 19 12:21:30 2013 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Tue Feb 19 12:21:30 2013 : Debug: } Tue Feb 19 12:21:31 2013 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Tue Feb 19 12:21:31 2013 : Info: rlm_sql (sql): Attempting to connect to radius@localhost:/radius Tue Feb 19 12:21:31 2013 : Debug: rlm_sql (sql): starting 0 Tue Feb 19 12:21:31 2013 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 Tue Feb 19 12:21:31 2013 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Tue Feb 19 12:21:31 2013 : Info: rlm_sql (sql): Connected new DB handle, #0 Tue Feb 19 12:21:31 2013 : Debug: rlm_sql (sql): starting 1 Tue Feb 19 12:21:31 2013 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 Tue Feb 19 12:21:31 2013 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1 Tue Feb 19 12:21:31 2013 : Info: rlm_sql (sql): Connected new DB handle, #1 Tue Feb 19 12:21:31 2013 : Debug: rlm_sql (sql): starting 2 Tue Feb 19 12:21:31 2013 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 Tue Feb 19 12:21:31 2013 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Tue Feb 19 12:21:31 2013 : Info: rlm_sql (sql): Connected new DB handle, #2 Tue Feb 19 12:21:31 2013 : Debug: rlm_sql (sql): starting 3 Tue Feb 19 12:21:31 2013 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 Tue Feb 19 12:21:31 2013 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3 Tue Feb 19 12:21:31 2013 : Info: rlm_sql (sql): Connected new DB handle, #3 Tue Feb 19 12:21:31 2013 : Debug: rlm_sql (sql): starting 4 Tue Feb 19 12:21:31 2013 : Info: rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 Tue Feb 19 12:21:31 2013 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Tue Feb 19 12:21:31 2013 : Info: rlm_sql (sql): Connected new DB handle, #4 Tue Feb 19 12:21:31 2013 : Debug: rlm_sql (sql): Processing generate_sql_clients Tue Feb 19 12:21:31 2013 : Debug: rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret, server FROM nas Tue Feb 19 12:21:31 2013 : Debug: rlm_sql (sql): Reserving sql socket id: 4 Tue Feb 19 12:21:31 2013 : Debug: rlm_sql (sql): Read entry nasname=172.16.4.10,shortname=Test NAS,secret=unl0ck Tue Feb 19 12:21:31 2013 : Debug: rlm_sql (sql): Adding client 172.16.4.10 (Test NAS, server=<none>) to clients list Tue Feb 19 12:21:31 2013 : Debug: rlm_sql (sql): Released sql socket id: 4 Tue Feb 19 12:21:31 2013 : Debug: Module: Checking preacct {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: (Loaded rlm_acct_unique, checking if it's valid) Tue Feb 19 12:21:31 2013 : Debug: Module: Linked to module rlm_acct_unique Tue Feb 19 12:21:31 2013 : Debug: Module: Instantiating module "acct_unique" from file /usr/local/etc/raddb/modules/acct_unique Tue Feb 19 12:21:31 2013 : Debug: acct_unique { Tue Feb 19 12:21:31 2013 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, NAS-Identifier, NAS-Port" Tue Feb 19 12:21:31 2013 : Debug: } Tue Feb 19 12:21:31 2013 : Debug: Module: Checking accounting {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: (Loaded rlm_detail, checking if it's valid) Tue Feb 19 12:21:31 2013 : Debug: Module: Linked to module rlm_detail Tue Feb 19 12:21:31 2013 : Debug: Module: Instantiating module "detail" from file /usr/local/etc/raddb/modules/detail Tue Feb 19 12:21:31 2013 : Debug: detail { Tue Feb 19 12:21:31 2013 : Debug: detailfile = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src- IPv6-Address}}/detail-%Y%m%d" Tue Feb 19 12:21:31 2013 : Debug: header = "%t" Tue Feb 19 12:21:31 2013 : Debug: detailperm = 384 Tue Feb 19 12:21:31 2013 : Debug: dirperm = 493 Tue Feb 19 12:21:31 2013 : Debug: locking = no Tue Feb 19 12:21:31 2013 : Debug: log_packet_header = no Tue Feb 19 12:21:31 2013 : Debug: } Tue Feb 19 12:21:31 2013 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Tue Feb 19 12:21:31 2013 : Debug: Module: Linked to module rlm_attr_filter Tue Feb 19 12:21:31 2013 : Debug: Module: Instantiating module "attr_filter.accounting_response" from file /usr/local/etc/raddb/modules/attr_filter Tue Feb 19 12:21:31 2013 : Debug: attr_filter attr_filter.accounting_response { Tue Feb 19 12:21:31 2013 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.accounting_response" Tue Feb 19 12:21:31 2013 : Debug: key = "%{User-Name}" Tue Feb 19 12:21:31 2013 : Debug: relaxed = no Tue Feb 19 12:21:31 2013 : Debug: } Tue Feb 19 12:21:31 2013 : Debug: reading pairlist file /usr/local/etc/raddb/attrs.accounting_response Tue Feb 19 12:21:31 2013 : Debug: Module: Checking session {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: (Loaded rlm_radutmp, checking if it's valid) Tue Feb 19 12:21:31 2013 : Debug: Module: Linked to module rlm_radutmp Tue Feb 19 12:21:31 2013 : Debug: Module: Instantiating module "radutmp" from file /usr/local/etc/raddb/modules/radutmp Tue Feb 19 12:21:31 2013 : Debug: radutmp { Tue Feb 19 12:21:31 2013 : Debug: filename = "/usr/local/var/log/radius/radutmp" Tue Feb 19 12:21:31 2013 : Debug: username = "%{User-Name}" Tue Feb 19 12:21:31 2013 : Debug: case_sensitive = yes Tue Feb 19 12:21:31 2013 : Debug: check_with_nas = yes Tue Feb 19 12:21:31 2013 : Debug: perm = 384 Tue Feb 19 12:21:31 2013 : Debug: callerid = yes Tue Feb 19 12:21:31 2013 : Debug: } Tue Feb 19 12:21:31 2013 : Debug: Module: Checking post-proxy {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking post-auth {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Instantiating module "attr_filter.access_reject" from file /usr/local/etc/raddb/modules/attr_filter Tue Feb 19 12:21:31 2013 : Debug: attr_filter attr_filter.access_reject { Tue Feb 19 12:21:31 2013 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.access_reject" Tue Feb 19 12:21:31 2013 : Debug: key = "%{User-Name}" Tue Feb 19 12:21:31 2013 : Debug: relaxed = no Tue Feb 19 12:21:31 2013 : Debug: } Tue Feb 19 12:21:31 2013 : Debug: reading pairlist file /usr/local/etc/raddb/attrs.access_reject Tue Feb 19 12:21:31 2013 : Debug: } # modules Tue Feb 19 12:21:31 2013 : Debug: } # server Tue Feb 19 12:21:31 2013 : Debug: server WiMax.com { # from file /usr/local/etc/raddb/sites-enabled/WiMAX.com Tue Feb 19 12:21:31 2013 : Debug: modules { Tue Feb 19 12:21:31 2013 : Debug: Module: Checking authenticate {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking authorize {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking preacct {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking accounting {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking session {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking post-proxy {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking post-auth {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: } # modules Tue Feb 19 12:21:31 2013 : Debug: } # server Tue Feb 19 12:21:31 2013 : Debug: server dynamic_client_server { # from file /usr/local/etc/raddb/sites-enabled/dynamic-clients Tue Feb 19 12:21:31 2013 : Debug: modules { Tue Feb 19 12:21:31 2013 : Debug: Module: Checking authorize {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: (Loaded rlm_dynamic_clients, checking if it's valid) Tue Feb 19 12:21:31 2013 : Debug: Module: Linked to module rlm_dynamic_clients Tue Feb 19 12:21:31 2013 : Debug: Module: Instantiating module "dynamic_clients" from file /usr/local/etc/raddb/modules/dynamic_clients Tue Feb 19 12:21:31 2013 : Debug: (Loaded rlm_always, checking if it's valid) Tue Feb 19 12:21:31 2013 : Debug: Module: Linked to module rlm_always Tue Feb 19 12:21:31 2013 : Debug: Module: Instantiating module "ok" from file /usr/local/etc/raddb/modules/always Tue Feb 19 12:21:31 2013 : Debug: always ok { Tue Feb 19 12:21:31 2013 : Debug: rcode = "ok" Tue Feb 19 12:21:31 2013 : Debug: simulcount = 0 Tue Feb 19 12:21:31 2013 : Debug: mpp = no Tue Feb 19 12:21:31 2013 : Debug: } Tue Feb 19 12:21:31 2013 : Debug: } # modules Tue Feb 19 12:21:31 2013 : Debug: } # server Tue Feb 19 12:21:31 2013 : Debug: server inner-tunnel { # from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Tue Feb 19 12:21:31 2013 : Debug: modules { Tue Feb 19 12:21:31 2013 : Debug: Module: Checking authenticate {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking authorize {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking session {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking post-proxy {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking post-auth {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: (Loaded rlm_sql_log, checking if it's valid) Tue Feb 19 12:21:31 2013 : Debug: Module: Linked to module rlm_sql_log Tue Feb 19 12:21:31 2013 : Debug: Module: Instantiating module "sql_log" from file /usr/local/etc/raddb/modules/sql_log Tue Feb 19 12:21:31 2013 : Debug: sql_log { Tue Feb 19 12:21:31 2013 : Debug: path = "/usr/local/var/log/radius/radacct/sql-relay" Tue Feb 19 12:21:31 2013 : Debug: Post-Auth = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ('%{User-Name}', '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', '%S');" Tue Feb 19 12:21:31 2013 : Debug: sql_user_name = "%{%{User-Name}:-DEFAULT}" Tue Feb 19 12:21:31 2013 : Debug: utf8 = no Tue Feb 19 12:21:31 2013 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Tue Feb 19 12:21:31 2013 : Debug: } Tue Feb 19 12:21:31 2013 : Debug: } # modules Tue Feb 19 12:21:31 2013 : Debug: } # server Tue Feb 19 12:21:31 2013 : Debug: server virtual.example.com { # from file /usr/local/etc/raddb/sites-enabled/virtual.example.com Tue Feb 19 12:21:31 2013 : Debug: modules { Tue Feb 19 12:21:31 2013 : Debug: Module: Checking authenticate {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking authorize {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking preacct {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking accounting {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking session {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking post-proxy {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: Module: Checking post-auth {...} for more modules to load Tue Feb 19 12:21:31 2013 : Debug: } # modules Tue Feb 19 12:21:31 2013 : Debug: } # server Tue Feb 19 12:21:31 2013 : Debug: radiusd: #### Opening IP addresses and Ports #### Tue Feb 19 12:21:31 2013 : Debug: listen { Tue Feb 19 12:21:31 2013 : Debug: type = "auth" Tue Feb 19 12:21:31 2013 : Debug: ipaddr = * Tue Feb 19 12:21:31 2013 : Debug: port = 0 Tue Feb 19 12:21:31 2013 : Debug: } Tue Feb 19 12:21:31 2013 : Debug: listen { Tue Feb 19 12:21:31 2013 : Debug: type = "acct" Tue Feb 19 12:21:31 2013 : Debug: ipaddr = * Tue Feb 19 12:21:31 2013 : Debug: port = 0 Tue Feb 19 12:21:31 2013 : Debug: } Tue Feb 19 12:21:31 2013 : Debug: listen { Tue Feb 19 12:21:31 2013 : Debug: type = "control" Tue Feb 19 12:21:31 2013 : Debug: listen { Tue Feb 19 12:21:31 2013 : Debug: socket = "/usr/local/var/run/radiusd/radiusd.sock" Tue Feb 19 12:21:31 2013 : Debug: } Tue Feb 19 12:21:31 2013 : Debug: } Tue Feb 19 12:21:31 2013 : Debug: listen { Tue Feb 19 12:21:31 2013 : Debug: type = "auth" Tue Feb 19 12:21:31 2013 : Debug: ipaddr = 127.0.0.1 Tue Feb 19 12:21:31 2013 : Debug: port = 18120 Tue Feb 19 12:21:31 2013 : Debug: } Tue Feb 19 12:21:31 2013 : Debug: ... adding new socket proxy address * port 39057 Tue Feb 19 12:21:31 2013 : Debug: Listening on authentication address * port 1812 Tue Feb 19 12:21:31 2013 : Debug: Listening on accounting address * port 1813 Tue Feb 19 12:21:31 2013 : Debug: Listening on command file /usr/local/var/run/radiusd/radiusd.sock Tue Feb 19 12:21:31 2013 : Debug: Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Tue Feb 19 12:21:31 2013 : Debug: Listening on proxy address * port 1814 Tue Feb 19 12:21:31 2013 : Info: Ready to process requests. rad_recv: Access-Request packet from host 172.16.4.10 port 1812, id=108, length=240 User-Name = "{sm=1}A7A87F7B3E7468918C72CC7CF8E80E4C(a)WiMAX.com" EAP-Message = 0x02010035017b736d3d317d4137413837463742334537343638393138433732434337434638 4538304534434057694d41582e636f6d Message-Authenticator = 0x6c06035e0f8f87be2df9cc3c79b59f87 NAS-IP-Address = 172.16.4.10 Calling-Station-Id = "00-26-82-C4-B2-86" WiMAX-BS-Id = 0xfff3290a162c NAS-Port-Type = Wireless-802.16 Framed-MTU = 2000 Service-Type = Framed-User WiMAX-GMT-Timezone-offset = 0 WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-Hotlining-Capabilities = Hotline-Profile-Id WiMAX-Attr-1793 = 0x0000028a Tue Feb 19 12:21:32 2013 : Info: # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Tue Feb 19 12:21:32 2013 : Info: +- entering group authorize {...} Tue Feb 19 12:21:32 2013 : Info: ++[preprocess] returns ok Tue Feb 19 12:21:32 2013 : Info: ++[mschap] returns noop Tue Feb 19 12:21:32 2013 : Info: ++[wimax] returns ok Tue Feb 19 12:21:32 2013 : Info: [suffix] Looking up realm "WiMAX.com" for User-Name = "{sm=1}A7A87F7B3E7468918C72CC7CF8E80E4C(a)WiMAX.com" Tue Feb 19 12:21:32 2013 : Info: [suffix] Found realm "WiMAX.com" Tue Feb 19 12:21:32 2013 : Info: [suffix] Adding Realm = "WiMAX.com" Tue Feb 19 12:21:32 2013 : Info: [suffix] Authentication realm is LOCAL. Tue Feb 19 12:21:32 2013 : Info: ++[suffix] returns ok Tue Feb 19 12:21:32 2013 : Info: [eap] EAP packet type response id 1 length 53 Tue Feb 19 12:21:32 2013 : Info: [eap] No EAP Start, assuming it's an on-going EAP conversation Tue Feb 19 12:21:32 2013 : Info: ++[eap] returns updated Tue Feb 19 12:21:32 2013 : Info: [sql] expand: %{User-Name} -> {sm=1}A7A87F7B3E7468918C72CC7CF8E80E4C(a)WiMAX.com Tue Feb 19 12:21:32 2013 : Info: [sql] sql_set_user escaped user --> '{sm=1}A7A87F7B3E7468918C72CC7CF8E80E4C(a)WiMAX.com' Tue Feb 19 12:21:32 2013 : Debug: rlm_sql (sql): Reserving sql socket id: 3 Tue Feb 19 12:21:32 2013 : Info: [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = '=7Bsm=3D1=7DA7A87F7B3E7468918C72CC7CF8E80E4C(a)WiMAX.com' ORDER BY id Tue Feb 19 12:21:32 2013 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '=7Bsm=3D1=7DA7A87F7B3E7468918C72CC7CF8E80E4C(a)WiMAX.com' ORDER BY priority Tue Feb 19 12:21:32 2013 : Debug: rlm_sql (sql): Released sql socket id: 3 Tue Feb 19 12:21:32 2013 : Info: [sql] User {sm=1}A7A87F7B3E7468918C72CC7CF8E80E4C(a)WiMAX.com not found Tue Feb 19 12:21:32 2013 : Info: ++[sql] returns notfound Tue Feb 19 12:21:32 2013 : Info: ++[expiration] returns noop Tue Feb 19 12:21:32 2013 : Info: ++[logintime] returns noop Tue Feb 19 12:21:32 2013 : Info: Found Auth-Type = EAP Tue Feb 19 12:21:32 2013 : Info: # Executing group from file /usr/local/etc/raddb/sites-enabled/default Tue Feb 19 12:21:32 2013 : Info: +- entering group authenticate {...} Tue Feb 19 12:21:32 2013 : Info: [eap] EAP Identity Tue Feb 19 12:21:32 2013 : Info: [eap] processing type md5 Tue Feb 19 12:21:32 2013 : Debug: rlm_eap_md5: Issuing Challenge Tue Feb 19 12:21:32 2013 : Info: ++[eap] returns handled Sending Access-Challenge of id 108 to 172.16.4.10 port 1812 EAP-Message = 0x0102001604100fc4f706667b63fe100609f538afe0f5 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xdc923277dc90367d008f589074a14c27 Tue Feb 19 12:21:32 2013 : Info: Finished request 0. Tue Feb 19 12:21:32 2013 : Debug: Going to the next request Tue Feb 19 12:21:32 2013 : Debug: Waking up in 4.9 seconds. rad_recv: Access-Request packet from host 172.16.4.10 port 1812, id=108, length=240 Tue Feb 19 12:21:37 2013 : Info: Sending duplicate reply to client Test NAS port 1812 - ID: 108 Sending Access-Challenge of id 108 to 172.16.4.10 port 1812 Tue Feb 19 12:21:37 2013 : Info: Cleaning up request 0 ID 108 with timestamp +1 Tue Feb 19 12:21:37 2013 : Info: Ready to process requests.

2 3