- Freeradius-Devel - lists.freeradius.org

BUGREPORT: SQL module fails on every CISCO reboot
by Alexander Voropay 03 Jun '05

03 Jun '05

Hi! I'm using a CISCO NAS with 240 modem lines and SQL/MySQL as accounting module. FreeRADIUS CVS fails on every CISCO reboot ! As I found, CISCO send 240 packets with: "Acct-Status-Type = Stop" "Acct-Terminate-Cause = Lost-Carrier" in accounting requests (1 per line) in about 5 mS on reboot and FreeRADIUS dies on this massive bombing. May be, this is CISCO IOS error, but FreeRADIUS should (must) tolerate it... As far as I understand, SQL module segfaults when SQL connection pool is over. Seems, pooling mechanism is bogus. ======= preacct { preprocess } accounting { radutmp sql } ======= SQL module creates a pool : .... rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked rlm_sql (sql): Attempting to connect to radius@localhost:/radius rlm_sql (sql): starting 0 rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 rlm_sql_mysql: Starting connect to MySQL server for #0 rlm_sql (sql): Connected new DB handle, #0 rlm_sql (sql): starting 1 rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 rlm_sql_mysql: Starting connect to MySQL server for #1 rlm_sql (sql): Connected new DB handle, #1 rlm_sql (sql): starting 2 rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 rlm_sql_mysql: Starting connect to MySQL server for #2 rlm_sql (sql): Connected new DB handle, #2 rlm_sql (sql): starting 3 rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 rlm_sql_mysql: Starting connect to MySQL server for #3 rlm_sql (sql): Connected new DB handle, #3 rlm_sql (sql): starting 4 rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 rlm_sql_mysql: Starting connect to MySQL server for #4 rlm_sql (sql): Connected new DB handle, #4 Module: Instantiated sql (sql) .... .... CISCO produces heavy load on reboot : ... ... Thread 1 waiting to be assigned a request rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=163, length=109 Threads: total/active/spare threads = 18/12/6 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=164, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=165, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=166, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=167, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=168, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=169, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=170, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=171, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=172, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=173, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=174, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=175, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=176, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=177, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=178, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=179, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=180, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=181, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=182, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=183, length=109 Waking up in 30 seconds... rad_recv: Accounting-Request packet from host 192.168.1.36 port 1646, id=184, length=109 Waking up in 30 seconds... ... ... SQL segfaults after SQL_DOWN: ... ... Going to the next request Thread 15 waiting to be assigned a request Thread 15 got semaphore Thread 15 handling request 44, (2 handled so far) Acct-Session-Id = "000000AF" Acct-Session-Time = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Terminate-Cause = Lost-Carrier Acct-Status-Type = Stop NAS-Port = 175 NAS-Port-Type = Async radius_xlat: '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('0000009C', '3161648c243dee0b', '', '', '192.168.1.36', '156', 'Async', DATE_SUB('2005-06-03 11:31:39', INTERVAL (0 + 0) SECOND), '2005-06-03 11:31:39', '0', '', '', '', '0', '0', '', 'async', 'Lost-Carrier', 'Framed-User', '', '', '0', '0')' rlm_sql (sql): Reserving sql socket id: 3 radius_xlat: 'rlm_sql: Stop packet with zero session length. (user '', nas '192.168.1.36')' rlm_sql: Stop packet with zero session length. (user '', nas '192.168.1.36') rlm_sql (sql): Released sql socket id: 0 radius_xlat: '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('000000A1', 'ee06eeee60d67938', '', '', '192.168.1.36', '161', 'Async', DATE_SUB('2005-06-03 11:31:39', INTERVAL (0 + 0) SECOND), '2005-06-03 11:31:39', '0', '', '', '', '0', '0', '', 'async', 'Lost-Carrier', 'Framed-User', '', '', '0', '0')' Calling-Station-Id = "async" Service-Type = Framed-User NAS-IP-Address = 192.168.1.36 Acct-Delay-Time = 0 Processing the preacct section of radiusd.conf modcall: entering group preacct for request 44 modcall[preacct]: module "preprocess" returns ok for request 44 rlm_acct_unique: WARNING: Attribute Client-IP-Address was not found in request, unique ID MAY be inconsistent rlm_acct_unique: WARNING: Attribute User-Name was not found in request, unique ID MAY be inconsistent rlm_acct_unique: Hashing 'NAS-Port = 175,,NAS-IP-Address = 192.168.1.36,Acct-Session-Id = "000000AF",' rlm_acct_unique: Acct-Unique-Session-ID = "c49f73d50a4c8f2e". modcall[preacct]: module "acct_unique" returns ok for request 44 modcall: leaving group preacct (returns ok) for request 44 Processing the accounting section of radiusd.conf modcall: entering group accounting for request 44 radius_xlat: '/opt/var/log/radius/radutmp' radius_xlat: '' rlm_radutmp: Logout for NAS credit_test port 175, but no Login record modcall[accounting]: module "radutmp" returns ok for request 44 radius_xlat: '' radius_xlat: 'UPDATE radacct SET AcctStopTime = '2005-06-03 11:31:39', AcctSessionTime = '0', AcctInputOctets = '0', AcctOutputOctets = '0', AcctTerminateCause = 'Lost-Carrier', AcctStopDelay = '0', ConnectInfo_stop = '' WHERE AcctSessionId = '000000AF' AND UserName = '' AND NASIPAddress = '192.168.1.36'' rlm_sql (sql): Reserving sql socket id: 2 Acct-Session-Id = "00000095" Acct-Session-Time = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Terminate-Cause = Lost-Carrier rlm_sql_mysql: MYSQL check_error: 2013, returning SQL_DOWN rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 rlm_sql_mysql: Starting connect to MySQL server for #2 Acct-Status-Type = Stop NAS-Port = 122 NAS-Port-Type = Async Calling-Station-Id = "async" Service-Type = Framed-User NAS-IP-Address = 192.168.1.36 Acct-Delay-Time = 0 Processing the preacct section of radiusd.conf Segmentation fault SQL returninig SQL_DOWN rlm_sql_mysql: MYSQL check_error: 2013, returning SQL_DOWN Is there any way to avoid insertion of this empty records ? -- -=AV=-

3 3

build on PPC64 fails
by Alexander Voropay 03 Jun '05

03 Jun '05

Hi! I can't build free-radius CVS on a PPC64 RHAS 4.0 . $ ./configure stage is OK. $ make stage fails on rlm_mysql ... gcc -shared .libs/sql_mysql.o -L/usr/lib64/mysql -lmysqlclient -lcrypt -lnsl -lm -lz -m64 -mminimal-toc -Wl,-soname -Wl,rlm_sql_mysql-1.1.0-pre0.so -o .libs/rlm_sql_mysql-1.1.0-pre0.so /usr/bin/ld: cannot find -lmysqlclient collect2: ld returned 1 exit status ... ... As far as I understnad situation, the RHAS PPC64 is a bi-standart system (32- and 64-bit) so the "libmysqlclient.a" **library** on the RHAS PPC64 resides in the "/usr/lib/mysql/" folder. The "/usr/lib64/mysql/" contains a *.so objects only, without *.a. [root@tr radiusd]# ls -la /usr/lib/mysql/libmysqlclient.a -rw-r--r-- 1 root root 1262082 Nov 24 2004 /usr/lib/mysql/libmysqlclient.a [root@tr radiusd]# ls -la /usr/lib64/mysql/libmysqlclient.a ls: /usr/lib64/mysql/libmysqlclient.a: No such file or directory Is it possible to correct a ./configure script ? -- -=AV=-

3 4

cvs current with SIGSEGV; how to track down
by Jason Ornstein 02 Jun '05

02 Jun '05

I've worked around some of the compile time issues that I'm having and now I have something that is a bit more of a problem. I've configured the server with --enable-developer and I'm running the server with gdb (this happens without gdb too) and this is part of what I see: ... rlm_pap: User authenticated succesfully modcall[authenticate]: module "pap" returns ok for request 0 modcall: leaving group PAP (returns ok) for request 0 Sending Access-Accept of id 41 to 10.15.32.71 port 1645 Service-Type = NAS-Prompt-User Login-Service = Telnet Login-TCP-Port = Telnet Finished request 0 Going to the next request --- Walking the entire request list --- Program received signal SIGSEGV, Segmentation fault. 0x00000000 in ?? () (gdb) where #0 0x00000000 in ?? () (gdb) bt #0 0x00000000 in ?? () (gdb) Am I wrong in thinking, that in a normal case I should see some type of backtrace? The debug message, walking..., is from radiusd.c at line 737. Here is the code /* * Loop through the request lists once per * second, to clean up old requests. */ if (last_cleaned_lists != time_now) { last_cleaned_lists = time_now; DEBUG2("--- Walking the entire request list ---"); sleep_time = SLEEP_FOREVER; for (listener = mainconfig.listen; listener != NULL; listener = listener->next) { int next; next = listener->update(listener, time_now); if (next < sleep_time) { sleep_time = next; } } } Maybe listener is never NULL? -jason

3 14

Releasing 1.0.3?
by Alan DeKok 02 Jun '05

02 Jun '05

I think we're about ready to release 1.0.3. Comments? Objections? Alan DeKok.

3 5

Minor Bug in TTLS implementation
by fabien.marotte＠freesurf.fr 31 May '05

31 May '05

Hi, I notice a minor bug in ttls implementation. I configured my Freeradius server to do ttls exchange with a supplicant (through a NAS). This freeradius server proxies tunneled requests to an other radius server. When the external server replies EAP-Success/Radius-AccessAccept to the Freeradius proxy, the tunnel is correctly destroyed and the FreeRadius proxy sends EAP-Success/RADIUS-AccessAccept to the supplicant. This last message is correct but it contains the PROXY_STATE attribute that FreeRadius had added during the proxy exchanges. As it seems that the latest cvs version don't correct this bug, I had done a correction (in version 1.20) of the ttls.c file, in the process_reply function after the line 652. Value pairs of the proxy reply are moved into the reply vps. The problem is that the PROXY_STATE is still present in proxy reply vps and is moved with the others. So I have added these two instructions to remove the PROXY_STATE attribute in the reply vps: pairmove2(&vp, &request->reply->vps, PW_PROXY_STATE); pairfree(&vp); It works but I don't know if it's the best way to correct the bug. Fabien Marotte

2 1

Re: session_zap and MPP connections
by Alan DeKok 30 May '05

30 May '05

Stephan Jaeger <stephan.jaeger(a)ewetel.de> wrote: > so the Framed-IP-Address attribute is not appended to the virtual stop > ticket if the ip address is 0.0.0.0, but MPP ISDN Connections always > have a Framed-IP-Address of 0.0.0.0 for all but the first channel, so > these connections will never be closed by session_zap generated tickets. I'm not sure why. Won't the connection be closed based on Acct-Session-Id, and not Framed-IP-Address? > Is it safe to just remove this check, or does anyone have a better > solution? Look at the code that interprets the zap records, and see why it requires a Framed-IP-Address of 0. Alan DeKok.

2 1

Re: More radrelay && radsqlrelay
by Nicolas Baradakis 27 May '05

27 May '05

Alan DeKok wrote: > > If people would be interested, it can be added to the CVS tree (pending > > Alan's approval). > > A few comments: > > Don't use RADACCTDIR "/sql-relay" in the configuration section, use > "${radacctdir}/sql-relay", which is a little friendlier. Ok. > Also, call radius_xlat on inst->path, it makes the filename > configurable, too. Ok. > I don't think that the per-accounting type queries are necessary any > more, at least in the CVS head. You chould be able to save the > CONF_SECTION in the module instance struct, and call cf_pair_find(), > keying off of Acct-Status-Type. Ok. (the code example you posted in the other mail helped me a lot) > And since it's no longer relaying, it shouldn't be called sqlrelay. > Maybe "sql_query_log", or something like that... I agree. What about "rlm_sql_log" then? New version available there: http://nbk.perso.cegetel.net/sql_log.tar.gz -- Nicolas Baradakis

2 1

configure testing for sockaddr_storage on solaris
by Jason Ornstein 27 May '05

27 May '05

I noticed today that the current CVS head won't compile on Solaris and it looks like it is due to a configure change around the end of April. This change happened between version 1.211 and 1.212 and is the check for sockaddr_storage. The script seems to assume that this struct is defined in /usr/include/netinet/in.h, but on Solaris and maybe other OSs it isn't located there, but in /usr/include/sys/socket.h. Google shows a few ways of doing this, but this link shows what might be the closest to what you currently do http://article.gmane.org/gmane.comp.web.curl.cvs/4598 and it is doing dnl Check for struct sockaddr_storage. Most IPv6-enabled hosts have it, but dnl AIX 4.3 is one known exception. [in acinclude.m4] AC_DEFUN([TYPE_SOCKADDR_STORAGE], [ AC_CHECK_TYPE([struct sockaddr_storage], AC_DEFINE(HAVE_STRUCT_SOCKADDR_STORAGE, 1, [if struct sockaddr_storage is defined]), , [ #ifdef HAVE_SYS_TYPES_H #include <sys/types.h> #endif #ifdef HAVE_SYS_SOCKET_H #include <sys/socket.h> #endif #ifdef HAVE_NETINET_IN_H #include <netinet/in.h> #endif #ifdef HAVE_ARPA_INET_H #include <arpa/inet.h> #endif ]) ]) [in configure.ac] TYPE_SOCKADDR_STORAGE If that looks about right I can give it a test and submit a patch. Is it safe to modify acinclude.m4? -jason

2 1