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

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

sqlippool querries
by Bill Schoolfield 02 Dec '13

02 Dec '13

Hello, I have a couple of things going on. (1) My mysql based ippool is out of sync with the ips actually in use. This is leading to ip conflicts and immediate drops after successful login. (2) take a look at the sql errors. It apparently doesn't like "expiry_time IS NULL" in the update. For (1) how can I get the ippool in sync? Is the only way to reset the radippool table and drop all the connections from the NAS? For (2) is this an error a by product of the immediate disconnect? Is the mysql version of sqlippool known to work. Also for number (2) one problem I see is the schema doesn't account for callingstationid that are this large. I assume I''ll need to change the schema for this. Happy to send config file setup and/or radiusd -X output if it will help. Though the setup is very basic. Bill > tail -f /var/log/radius/radius.log > Mon Dec 2 14:21:40 2013 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 > Mon Dec 2 14:21:40 2013 : Info: rlm_sql (sql): Connected new DB handle, #4 > Mon Dec 2 14:21:40 2013 : Info: Loaded virtual server <default> > Mon Dec 2 14:21:40 2013 : Info: Ready to process requests. > Mon Dec 2 14:28:24 2013 : Auth: Login OK: [abraham1078(a)epsiton.com] (from client ERX2 port 21068 cli GigabitEthernet 3/0/6.3220146:322-146#587449101#801 GE1 TOROON4415W-TOROON4425W##pppoe 68:15:90:3e:0b:81#) > Mon Dec 2 14:28:24 2013 : Error: sqlippool_command: database query error in: 'UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time IS NULL WHERE expiry_time <= NOW() - INTERVAL 1 SECOND AND nasipaddress = '204.101.13.1'' > Mon Dec 2 14:28:24 2013 : Error: rlm_radutmp: Logout for NAS ERX2 port 21068, but no Login record > Mon Dec 2 14:28:24 2013 : Error: sqlippool_command: database query error in: 'UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time IS NULL WHERE nasipaddress = '204.101.13.1' AND pool_key = '21068' AND username = 'abraham1078(a)epsiton.com' AND callingstationid = 'GigabitEthernet 3/0/6.3220146:322-146=23587449101=23801 GE1 TOROON4415W-TOROON4425W=23=23pppoe 68:15:90:3e:0b:81=23' AND framedipaddress = ''' > Mon Dec 2 14:28:24 2013 : Info: Released IP (did cli GigabitEthernet 3/0/6.3220146:322-146#587449101#801 GE1 TOROON4415W-TOROON4425W##pppoe 68:15:90:3e:0b:81# user abraham1078(a)epsiton.com) > Mon Dec 2 14:28:24 2013 : Info: [sql] stop packet with zero session length. [user 'abraham1078(a)epsiton.com', nas '204.101.13.1'] > Mon Dec 2 14:40:57 2013 : Auth: Login OK: [abraham1078(a)epsiton.com] (from client ERX2 port 21070 cli GigabitEthernet 3/0/6.3220146:322-146#587449101#801 GE1 TOROON4415W-TOROON4425W##pppoe 68:15:90:3e:0b:81#) query error here: > Mon Dec 2 14:40:57 2013 : Error: sqlippool_command: database query error in: 'UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time IS NULL WHERE expiry_time <= NOW() - INTERVAL 1 SECOND AND nasipaddress = '204.101.13.1'' > Mon Dec 2 14:40:57 2013 : Error: rlm_radutmp: Logout for NAS ERX2 port 21070, but no Login record > Mon Dec 2 14:40:57 2013 : Error: sqlippool_command: database query error in: 'UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time IS NULL WHERE nasipaddress = '204.101.13.1' AND pool_key = '21070' AND username = 'abraham1078(a)epsiton.com' AND callingstationid = 'GigabitEthernet 3/0/6.3220146:322-146=23587449101=23801 GE1 TOROON4415W-TOROON4425W=23=23pppoe 68:15:90:3e:0b:81=23' AND framedipaddress = ''' > Mon Dec 2 14:40:57 2013 : Info: Released IP (did cli GigabitEthernet 3/0/6.3220146:322-146#587449101#801 GE1 TOROON4415W-TOROON4425W##pppoe 68:15:90:3e:0b:81# user abraham1078(a)epsiton.com) > Mon Dec 2 14:40:57 2013 : Info: [sql] stop packet with zero session length. [user 'abraham1078(a)epsiton.com', nas '204.101.13.1']

2 3

LDAP Module : basedn empty -> error
by Dominique Fournier 02 Dec '13

02 Dec '13

Hi I try to connect my Freeradius to a Zimbra LDAP server with multidomain. In Zimbra, the LDAP tree is something like : "ou=people,dc=domain,dc=tld". I have some domains in ".fr" and some other in ".org". If I configure with the basedn = "dc=fr", Freeradius works well for all the domains in ".fr". But if I try to allow all my domains (with a basedn=""), Freeradius don't accept to authenticate the users. In the logs, when there is a reject, I can see : [ldap-inner-tunnel] performing user authorization for XXXXX [ldap-inner-tunnel] expand: (mail=%{User-Name}) -> (mail=XXXXX.fr) [ldap-inner-tunnel] expand: -> [ldap-inner-tunnel] unable to create basedn. ++[ldap-inner-tunnel] returns invalid Invalid user: [XXXXX.fr] (from client localhost port 0 via TLS tunnel) I found a topic in the list http://freeradius.1045715.n5.nabble.com/Sending-null-BaseDN-td5716006.html in 2012, but there is no solution. I am on a Debian stable Freeradius 2.1.12 Thanks a lot. Dom

3 10

Re: Freeradius/LDAP/MySQL/Huntgroup - 2 Profiles for same equipment
by Alan DeKok 02 Dec '13

02 Dec '13

Francislaine Moreno wrote: > I'm trying to find some way to differentiate the same IP / switch in 2 > different huntgroups. Don't use huntgroups. They're not meant to do multiple group membership. You can put the group membership as a property in an SQL database. Then, write a query to get it. Alan DeKok.

1 0

FreeRadius, 802.1x authentication via PEAP-MsChapv2
by Esma 02 Dec '13

02 Dec '13

Hello, We are using Freeradius server via 802.1x authentication with PEAP-MsChapv2. We want to use our own server certificate and we have three certificate files server.key, server.pem and server.crt. We kindly ask you how to configurate the radius server in order to use following certificate files in 802.1x authentication. Server.crt Bag Attributes localKeyID: ... friendlyName: ... subject... issuer=... -----BEGIN CERTIFICATE----- ... -----END CERTIFICATE----- Server.key -----BEGIN RSA PRIVATE KEY----- ... -----END RSA PRIVATE KEY----- Server.pem Bag Attributes ... localKeyID: ... friendlyName: ... Microsoft CSP Name: Microsoft RSA SChannel Cryptographic Provider Key Attributes ... -----BEGIN RSA PRIVATE KEY----- Proc-Type: 4,ENCRYPTED DEK-Info: ... ... -----END RSA PRIVATE KEY----- Regards,

2 1

Freeradius/LDAP/MySQL/Huntgroup - 2 Profiles for same equipment
by Francislaine Moreno 02 Dec '13

02 Dec '13

I'm using google translator, I apologize. I'm using Freeradius with a database in MySQL and groups in OpenLDAP. Huntgroup'm using to create profiles of equipment. And the NAS table to record the switches. My problem is that when authenticating switches the Ciscos, the ENABLE profile, access works perfectly, but in the EXEC profile, no. The conflict is that signed up as the IP switch, ENABLE the first group, even if that user is logging in, belongs only to the EXEC group, FreeRadius to do the research, get the information that the switch belongs to ENABLE. I'm trying to find some way to differentiate the same IP / switch in 2 different huntgroups. Thank you for your help. Francislaine Aquino

1 0