- Freeradius-Users - lists.freeradius.org

Combining EAP, MSCHAP and LDAP
by David Hartburn 09 Dec '13

09 Dec '13

Hi, Can anyone help advise if FreeRADIUS is suitable without any other changes to the existing infrastructure at my institution? If so, any advice on the best way to implement would be appreciated. I am looking at options for replacing MS NPS with basically something better that works and is debuggable. FreeRadius looks the best option. Our setup is a little complicated. Wireless users authenticate with EAP type PEAP, the inner authentication being done via MSCHAPv2. At the backend, we have a *nix based LDAP server with a particular attribute set for if a user is permitted to access the wireless network. Passwords are stored in an encrypted format. When a user binds, they can not see the resource attribute saying if they are permitted to use wireless. The LDAP information is pushed into active directory, where a wireless user group is created and populated by those who have the wireless flag set. Currently NPS authenticates against AD and checks this group. My preference would be to leave any windows stuff out of the equation. I followed a couple of online guides and have had FreeRadius successfully authenticate users against AD, however I then found something saying if I wanted to check groups I would have to use LDAP. Following the information in the Dirk van der Walt book, it states that you can bind to LDAP as a user but are limited to PAP authentication or you can read the userPassword attribute which must be plain text if MSCHAP is needed. Neither sounds suitable for what I need. Is it possible for FreeRadius to use EAP, MSCHAP, check a LDAP attribute and an encrypted password? As the password is encrypted and of little use, our LDAP expert suggested that we bind using a system account to check the account exists and has rights for wireless (I have this bit working), then to authenticate a bind is made as the user. Does this sound reasonable? Would binding to the AD server as an LDAP server offer any better avenue? As this is currently a proof-of-concept lab exercise, we do not want to make any changes to our existing infrastructure if possible. If that is required, giving users permission to see their wireless attribute in LDAP seems like the least painful. Sorry for the rambling posts, I'm in the newbie situation of being faced with many paths open to me, and not really knowing the best one to take. Yours DaveH

4 4

diffrent services from same IP
by SkyDiablo 07 Dec '13

07 Dec '13

hi, i have running a freeradius, all works fine... but now, i need to handle two diffrent services from the same IP in diffrent virtual server. in detail: i have a VPN server and one or more coova chilli systeme. all this freeradius clients will running on the same system (localhost) but if i load the client configs, it throws the error "Failed to add duplicate client". of course, all client will have the same IP, all client running under localhost. it is possible to handle this ? diffrent services/clients on the same IP ? greez & thx, volker...

3 3

Help with Chap and ldap
by P K 06 Dec '13

06 Dec '13

Hi, I'm using openldap and phpldapadmin to create account. The interface allows me to store "clear" password. When I do an ldapsearch commandline, I get base64 password. I don't see an option in phpldapadmin to store "clear-text" type. I've configured freeradius to use ldap and I'm using radtest to test but chap always fails. Is it failing because of base64? It seems to have decoded fine looking at the logs. Why is CHAP failing? Please help. Here's my log. radtest -t chap boris password01 localhost 0 testing123 Sending Access-Request of id 74 to 127.0.0.1 port 1812 User-Name = "boris" CHAP-Password = 0x4ab32d3fc82d3d59528ca82338d3ed40aa NAS-IP-Address = 127.0.1.1 NAS-Port = 0 rad_recv: Access-Reject packet from host 127.0.0.1 port 1812, id=74, length=20 Listening on authentication address * port 1812 Listening on accounting address * port 1813 Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Listening on proxy address * port 1814 Ready to process requests. rad_recv: Access-Request packet from host 127.0.0.1 port 37517, id=74, length=58 User-Name = "boris" CHAP-Password = 0x4ab32d3fc82d3d59528ca82338d3ed40aa NAS-IP-Address = 127.0.1.1 NAS-Port = 0 # Executing section authorize from file /etc/freeradius/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok [auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/127.0.0.1/auth-detail-20131205 [auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/127.0.0.1/auth-detail-20131205 [auth_log] expand: %t -> Thu Dec 5 23:31:12 2013 ++[auth_log] returns ok [chap] Setting 'Auth-Type := CHAP' ++[chap] returns ok ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "boris", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] No EAP-Message, not doing EAP ++[eap] returns noop [files] expand: %{NAS-IP-Address} -> 127.0.1.1 [files] expand: %{NAS-IP-Address} -> 127.0.1.1 [files] users: Matched entry DEFAULT at line 23 ++[files] returns ok [ldap] performing user authorization for boris [ldap] expand: %{Stripped-User-Name} -> [ldap] ... expanding second conditional [ldap] expand: %{User-Name} -> boris [ldap] expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> (uid=boris) [ldap] expand: dc=example,dc=int -> dc=example,dc=int [ldap] ldap_get_conn: Checking Id: 0 [ldap] ldap_get_conn: Got Id: 0 [ldap] attempting LDAP reconnection [ldap] (re)connect to 127.0.0.1:389, authentication 0 [ldap] bind as cn=admin,dc=example,dc=int/P0intBlank to 127.0.0.1:389 [ldap] waiting for bind result ... [ldap] Bind was successful [ldap] performing search in dc=example,dc=int, with filter (uid=boris) [ldap] No default NMAS login sequence [ldap] looking for check items in directory... [ldap] userPassword -> Password-With-Header == "password01" [ldap] looking for reply items in directory... [ldap] user boris authorized to use remote access [ldap] ldap_release_conn: Release Id: 0 ++[ldap] returns ok ++[expiration] returns noop ++[logintime] returns noop [pap] Failed to decode Password-With-Header = "password01" [pap] WARNING: Auth-Type already set. Not setting to PAP ++[pap] returns noop Found Auth-Type = CHAP # Executing group from file /etc/freeradius/sites-enabled/default +- entering group CHAP {...} [chap] login attempt by "boris" with CHAP password [chap] Cleartext-Password is required for authentication ++[chap] returns invalid Failed to authenticate the user. Using Post-Auth-Type Reject # Executing group from file /etc/freeradius/sites-enabled/default +- entering group REJECT {...} [attr_filter.access_reject] expand: %{User-Name} -> boris attr_filter: Matched entry DEFAULT at line 11 ++[attr_filter.access_reject] returns updated Delaying reject of request 0 for 1 seconds Going to the next request Waking up in 0.9 seconds. Sending delayed reject for request 0 Sending Access-Reject of id 74 to 127.0.0.1 port 37517 Waking up in 4.9 seconds. Cleaning up request 0 ID 74 with timestamp +22 Ready to process requests. ^C

3 3

rlm_ldap (ldap): Could not start TLS: Connect error
by Hachmer, Tobias 05 Dec '13

05 Dec '13

Hello list, in my further tests with FreeRADIUS v3 (rpmbuild from v3.0.x branch) I have a problem with the ldap module and start_tls. This is definitely working: - Ldap connect with ldap utils (ldapsearch -ZZ and so on) via port 389 with starttls - Ldap connect with FreeRADIUS 2.1.12 via port 389 (start_tls = yes and require_cert = "demand") This is not working: - FR 3 ldap module isn't able to connect to ldap server via port 389 + start_tls=yes - FR debug error: # Loaded module rlm_ldap # Instantiating module "ldap" from file /etc/raddb/mods-enabled/ldap ldap { server = "fqdn" (matches CN in ldap server certificate) port = 389 password = "xxx" identity = "xxx" valuepair_attribute = "radiusVSA" read_clients = yes user { filter = "(&(uid=%{%{Stripped-User-Name}:-%{User-Name}})(objectClass=radiusProfile))" scope = "sub" base_dn = "xxx" access_attribute = "radiusAccountStatus" access_positive = yes } group { filter = "(objectClass=groupOfNames)" scope = "sub" base_dn = "xxx" name_attribute = "cn" membership_attribute = "memberOf" membership_filter = "(member=%{control:Ldap-UserDn})" cacheable_name = no cacheable_dn = yes } client { filter = "(objectClass=radiusClient)" scope = "sub" base_dn = "xxx" attribute { identifier = "radiusClientIdentifier" shortname = "radiusClientShortname" nas_type = "radiusClientType" secret = "radiusClientSecret" virtual_server = "radiusClientVirtualServer" require_message_authenticator = "radiusClientRequireMa" } } profile { filter = "(objectclass=radiusObjectProfile)" attribute = "radiusGroupName" default = "xxx" } options { ldap_debug = 597 chase_referrals = yes rebind = yes net_timeout = 1 res_timeout = 20 srv_timelimit = 20 idle = 60 probes = 3 interval = 3 } tls { ca_file = "/etc/raddb/certs/rootca_cert.pem" start_tls = yes require_cert = "demand" (also tested with never, same result) } } accounting { reference = "%{tolower:type.%{Acct-Status-Type}}" } post-auth { reference = "." } rlm_ldap (ldap): Initialising connection pool pool { start = 5 min = 4 max = 10 spare = 3 uses = 0 lifetime = 0 cleanup_delay = 5 idle_timeout = 60 spread = no } rlm_ldap (ldap): Opening additional connection (0) rlm_ldap (ldap): Connecting to fqdn:389 rlm_ldap (ldap): Could not start TLS: Connect error rlm_ldap (ldap): Opening connection failed (0) rlm_ldap (ldap): Removing connection pool /etc/raddb/mods-enabled/ldap[8]: Instantiation failed for module "ldap" - openldap debug log: Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on 1 descriptor Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on: Nov 28 11:21:00 radiusv3test slapd[7737]: Nov 28 11:21:00 radiusv3test slapd[7737]: slap_listener_activate(7): Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=7 busy Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=8 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=9 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=10 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=11 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: >>> slap_listener(ldap:///) Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: listen=7, new connection on 16 Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on 1 descriptor Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on: Nov 28 11:21:00 radiusv3test slapd[7737]: Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=7 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=8 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=9 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=10 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=11 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: added 16r (active) listener=(nil) Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on 2 descriptors Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on: Nov 28 11:21:00 radiusv3test slapd[7737]: 16r Nov 28 11:21:00 radiusv3test slapd[7737]: Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: read active on 16 Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=7 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=8 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=9 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: connection_get(16) Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=10 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: connection_get(16): got connid=1003 Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=11 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: connection_read(16): checking for input on id=1003 Nov 28 11:21:00 radiusv3test slapd[7737]: op tag 0x77, time 1385634060 Nov 28 11:21:00 radiusv3test slapd[7737]: conn=1003 op=0 do_extended Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on 1 descriptor Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on: Nov 28 11:21:00 radiusv3test slapd[7737]: do_extended: oid=1.3.6.1.4.1.1466.20037 Nov 28 11:21:00 radiusv3test slapd[7737]: Nov 28 11:21:00 radiusv3test slapd[7737]: send_ldap_extended: err=0 oid= len=0 Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=7 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: send_ldap_response: msgid=1 tag=120 err=0 Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=8 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=9 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=10 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=11 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on 1 descriptor Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on: Nov 28 11:21:00 radiusv3test slapd[7737]: 16r Nov 28 11:21:00 radiusv3test slapd[7737]: Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: read active on 16 Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=7 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=8 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=9 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=10 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=11 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: connection_get(16) Nov 28 11:21:00 radiusv3test slapd[7737]: connection_get(16): got connid=1003 Nov 28 11:21:00 radiusv3test slapd[7737]: connection_read(16): checking for input on id=1003 Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on 1 descriptor Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on: Nov 28 11:21:00 radiusv3test slapd[7737]: Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=7 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=8 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=9 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=10 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=11 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on 1 descriptor Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on: Nov 28 11:21:00 radiusv3test slapd[7737]: 16r Nov 28 11:21:00 radiusv3test slapd[7737]: Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: read active on 16 Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=7 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=8 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=9 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=10 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: connection_get(16) Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=11 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: connection_get(16): got connid=1003 Nov 28 11:21:00 radiusv3test slapd[7737]: connection_read(16): checking for input on id=1003 Nov 28 11:21:00 radiusv3test slapd[7737]: connection_read(16): TLS accept failure error=-1 id=1003, closing Nov 28 11:21:00 radiusv3test slapd[7737]: connection_closing: readying conn=1003 sd=16 for close Nov 28 11:21:00 radiusv3test slapd[7737]: connection_close: conn=1003 sd=16 Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: removing 16 Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on 1 descriptor Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: activity on: Nov 28 11:21:00 radiusv3test slapd[7737]: Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=7 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=8 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=9 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=10 active_threads=0 tvp=zero Nov 28 11:21:00 radiusv3test slapd[7737]: daemon: epoll: listen=11 active_threads=0 tvp=zero FreeRADIUS 3: # ldd /usr/sbin/radiusd linux-vdso.so.1 => (0x00007fff8c1ff000) libfreeradius-server.so => /usr/lib64/freeradius/libfreeradius-server.so (0x00007f224b44b000) libfreeradius-radius.so => /usr/lib64/freeradius/libfreeradius-radius.so (0x00007f224b21b000) libfreeradius-eap.so => /usr/lib64/freeradius/libfreeradius-eap.so (0x00007f224b011000) libpcre.so.0 => /lib64/libpcre.so.0 (0x00007f224ade0000) libpcreposix.so.0 => /usr/lib64/libpcreposix.so.0 (0x00007f224abdd000) libtalloc.so.2 => /usr/lib64/libtalloc.so.2 (0x00007f224a9d3000) libcrypto.so.10 => /usr/lib64/libcrypto.so.10 (0x00007f224a639000) libssl.so.10 => /usr/lib64/libssl.so.10 (0x00007f224a3db000) libnsl.so.1 => /lib64/libnsl.so.1 (0x00007f224a1c2000) libresolv.so.2 => /lib64/libresolv.so.2 (0x00007f2249fa8000) libdl.so.2 => /lib64/libdl.so.2 (0x00007f2249da3000) libpthread.so.0 => /lib64/libpthread.so.0 (0x00007f2249b86000) libreadline.so.6 => /lib64/libreadline.so.6 (0x00007f2249943000) libcrypt.so.1 => /lib64/libcrypt.so.1 (0x00007f224970b000) libc.so.6 => /lib64/libc.so.6 (0x00007f2249378000) /lib64/ld-linux-x86-64.so.2 (0x00007f224b66d000) librt.so.1 => /lib64/librt.so.1 (0x00007f2249170000) libz.so.1 => /lib64/libz.so.1 (0x00007f2248f59000) libgssapi_krb5.so.2 => /lib64/libgssapi_krb5.so.2 (0x00007f2248d15000) libkrb5.so.3 => /lib64/libkrb5.so.3 (0x00007f2248a2f000) libcom_err.so.2 => /lib64/libcom_err.so.2 (0x00007f224882a000) libk5crypto.so.3 => /lib64/libk5crypto.so.3 (0x00007f22485fe000) libtinfo.so.5 => /lib64/libtinfo.so.5 (0x00007f22483dd000) libfreebl3.so => /lib64/libfreebl3.so (0x00007f2248170000) libkrb5support.so.0 => /lib64/libkrb5support.so.0 (0x00007f2247f65000) libkeyutils.so.1 => /lib64/libkeyutils.so.1 (0x00007f2247d62000) libselinux.so.1 => /lib64/libselinux.so.1 (0x00007f2247b42000) FreeRADIUS v2.1.12 (default RPM from official CentOS Repo): # ldd /usr/sbin/radiusd linux-vdso.so.1 => (0x00007fffa9980000) libfreeradius-radius-2.1.12.so => /usr/lib64/freeradius/libfreeradius-radius-2.1.12.so (0x00007fb0297b0000) libnsl.so.1 => /lib64/libnsl.so.1 (0x00007fb029591000) libresolv.so.2 => /lib64/libresolv.so.2 (0x00007fb029377000) libpthread.so.0 => /lib64/libpthread.so.0 (0x00007fb02915a000) libcrypt.so.1 => /lib64/libcrypt.so.1 (0x00007fb028f22000) libltdl.so.7 => /usr/lib64/libltdl.so.7 (0x00007fb028d19000) libssl.so.10 => /usr/lib64/libssl.so.10 (0x00007fb028abc000) libcrypto.so.10 => /usr/lib64/libcrypto.so.10 (0x00007fb028721000) libc.so.6 => /lib64/libc.so.6 (0x00007fb02838e000) /lib64/ld-linux-x86-64.so.2 (0x00007fb029c1e000) libfreebl3.so => /lib64/libfreebl3.so (0x00007fb028122000) libdl.so.2 => /lib64/libdl.so.2 (0x00007fb027f1d000) libgssapi_krb5.so.2 => /lib64/libgssapi_krb5.so.2 (0x00007fb027cd9000) libkrb5.so.3 => /lib64/libkrb5.so.3 (0x00007fb0279f3000) libcom_err.so.2 => /lib64/libcom_err.so.2 (0x00007fb0277ee000) libk5crypto.so.3 => /lib64/libk5crypto.so.3 (0x00007fb0275c2000) libz.so.1 => /lib64/libz.so.1 (0x00007fb0273ac000) libkrb5support.so.0 => /lib64/libkrb5support.so.0 (0x00007fb0271a0000) libkeyutils.so.1 => /lib64/libkeyutils.so.1 (0x00007fb026f9d000) libselinux.so.1 => /lib64/libselinux.so.1 (0x00007fb026d7d000) Thanks in advance for any help and please let me know if further information is needed. Kind regards, Tobias Hachmer

3 14

sqltrace.sql
by Sanity Computers 04 Dec '13

04 Dec '13

Ok thanks, the sqltrace feature is handy, it was a display error as the trace looks to be perfect. Now its enabled the display shows the full query. Thanks for the help.

1 0

Crash problem with FR 2.x.x when background databases delay
by Jim Madden 04 Dec '13

04 Dec '13

This note is both a request for assistance in debugging a problem where I’m way out of my depth and a warning that there may be a crash problem lurking in the current 2.x.x code that won’t be visible until a server running it encounters an unusual delay from a back end system. I am not including much detailed diagnostic output because the problem I’m describing doesn’t happen under single threaded debugging and the debugging traces and core dumps that accumulate in multi-threaded mode are gigantic. We have been struggling with an attempted conversion of a Redhat compile-from-source Freeradius 2.2.1 deployment to a compile-from-source version of the latest 2.x.x code. Our very heavily loaded Radius servers provide MAC address and EAP/PEAP/TTLS authentication through a set of very creaky multi-use back-end Mysql servers which can occasionally go non-responsive for many seconds at a time. Ultimately I’d guess that we’ll switch to the FR 3 code but that change requires significant modification to a configuration that has grown up piecemeal over several years, so, in the meantime, we try to keep up with the FR 2 improvements. We’ll also fix our underlying load issues with hardware changes over the next few months, but for now, we have to live with them, so we see the problem described here if we try to advance beyond 2.2.1 code. Our 2.2.1 systems sometimes encounter database response delays that cause them to generate error messages like this Tue Nov 26 15:21:47 2013 : Error: Received conflicting packet from client Campus_WISM port 32770 - ID: 247 due to unfinished request 8533348. Giving up on old request. Tue Nov 26 15:21:50 2013 : Info: WARNING: Module rlm_eap became unblocked for request 8533348 but the servers continue to run. Under 2.2.3, the situation that produces these messages seems likely to generate a follow-on crash after a short period of time. The resulting crash dump shows that the failure is an illegal memory reference in a thread that has a normal seeming stack of modcall routines and code that is referencing a linked structure through a ‘request’ structure that has been damaged; the particular code that fails is not consistent but seems always to be a reference through a ‘request’; inspection of the broken request in the dump shows varying kinds of garbage; to get to the failed code, lots of earlier routines in the call stack would have used the same ‘request’ pointer value to extract data and apparently succeeded in doing so. It is as if some clean-up mechanism in another thread has destroyed the request while it is in use. Other threads in the server seem perfectly happy, waiting for their turn to get a request or to receive data from a database or ntlm_auth process. There seem always to be an error message like the one listed above in the log or log buffers. The crash does not happen under light load on the server and backend systems so that there are no conflicting packets, nor does it happen in unthreaded debug mode apparently because request processing happens sequentially. It does happen with radmin debugging turned on although those are so voluminous that it’s hard to extract useful information about what has happened. It is interesting that, even with backend delays, the crashes do not happen if I change the code in main/event.c that looks like int received_request(rad_listen_t *listener, ... /* * The new request is different from the old one, * but maybe the old is finished. If so, delete * the old one. */ switch (request->child_state) { struct timeval when; default: /* * Special hacks for race conditions. * The reply is encoded, and therefore * likely sent. We received a *new* * packet from the client, likely before * the next line or two of code which * updated the child state. In this * case, just accept the new request. */ if ((request->reply->code != 0) && request->reply->data) { radlog(L_INFO, "WARNING: Allowing fast client %s port %d - ID: %d for recent request %u.", client->shortname, packet->src_port, packet->id, request->number); remove_from_request_hash(request); request = NULL; break; } gettimeofday(&when, NULL); when.tv_sec -= 1; /* * If the cached request was received * within the last second, then we * discard the NEW request instead of the * old one. This will happen ONLY when * the client is severely broken, and is * sending conflicting packets very * quickly. */ if (timercmp(&when, &request->received, <)) { radlog(L_ERR, "Discarding conflicting packet from " "client %s port %d - ID: %d due to recent request %u.", client->shortname, packet->src_port, packet->id, request->number); return 0; } received_conflicting_request(request, client); request = NULL; break; to allow a 300 second leeway instead of the 1 second one so that in effect, received_conflicting_request is never called. I don’t think this particular code or most of its supporting routines have changed much between 2.2.1 and the current 2.x.x. My limited understanding of what’s happening here is that the server has matched a new incoming request with one that’s already in process and calls received_conflicting_request to try to terminate the on-going processing; this can leave an old request that’s waiting for some external event like a database request in process in an active thread but marked to stop when it comes to a sync point. After doing this marking, the code above then goes on to queue the newly arrived request to be worked on. I’m way out of my depth about how these two variants of the same request will be handled beyond this point in the server, but it appears that something has changed about it between the 2.2.1 code that works and the current 2.x.x code that crashes. I wonder if some table look-up or queuing mechanism has changed so that two threads processing these requests get confused about each others data? I will gladly provide more information under direction from the experts. I don’t want to flood the list with endless streams of useless debugging. Jim Madden UCSD Networking jmadden(a)ucsd.edu

3 3

query is been cut short
by Sanity Computers 04 Dec '13

04 Dec '13

Hi all, I'm getting some odd behaviour where a counter is not replying with session-timeout. You can see in the debug below that this accounting update query seems to stop at "AN" rather than "AND nasipaddress = 'NAS-IP-Address'". Sometimes it ends like this also: AND username = 'tes It seems to be cutting off the end of the query. Is this just a debug display/ouput error or an actual problem? ---------------------------- [sql] expand: 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}' -> UPDATE radacct SET framedipaddress = '101.144.24.2', acctsessiontime = '301', acctinputoctets = '0' << 32 | '65806', acctoutputoctets = '0' << 32 | '110397' WHERE acctsessionid = '529e87e100000001' AND username = 'test' AN rlm_sql (sql): Reserving sql socket id: 0 rlm_sql (sql): Released sql socket id: 0 Regards Carl

2 1

Secure auth methods pam_radius
by Bob Probert 03 Dec '13

03 Dec '13

Hello all, I would like to use the PAM Radius module to authenticate Linux servers against my Radius server. I compiled and configured the PAM module, things appear to be working, however I would like to use a more secure authentication method than PAP. Is it possible to force the PAM module to use a more secure method? What does the community endorse as the most secure authentication method for Radius. Thanks! Bob

3 6

decoupled accounting
by Rui Ribeiro 03 Dec '13

03 Dec '13

Hi, I just made the setup of a second RADIUS server, and trying to relay the accounting, preferably with decouple-accounting, because I think it is a more robust configuration. I have already read the freeradius.org pages, a lot of posts, and the virtual server itself; put the decouple-accounting in sites-enabled; managed to intercept the accounting setting up the write_detail.xxxx server, and indeed all the correct accounting goes to /var/log/freeradius/radacct/detail.xxx I also setup on the master side, this secondary server as client in the clients.conf file. However, I am a bit at a loss how to reach the read_detail.xxx server to process the files left by write_detail. Any clues? Regards, Rui Ribeiro

3 2

Acct and Auth on single port
by Jonathan Moore 03 Dec '13

03 Dec '13

Is it possible to have both accounting a authorization requests on a single port? I have a bit of legacy equipment that has a single configuration option for radius port, and appears to send both the account and authorization packets to whatever port is defined there. I have tried created two listen directives both using the same port and listing auth in one and acct in the other, with no success. Is there some method to making this work, or am I stuck with just not getting accounting from this device? Thanks -- Jon M

2 1