Seg-fault with proxy and fail-overs
Hi, today I have just had the initial 'live' test of a new FreeRADIUS server. The setup had passed all testing performed in the Lab before re-location. The server is a dual-core Xeon with 4G RAM running Debian Stable (Lenny): Linux tas1 2.6.26-1-amd64 #1 SMP Sat Jan 10 17:57:00 UTC 2009 x86_64 GNU/Linux FreeRADIUS was built with the command: dpkg-buildpackage -rfakeroot -us -uc The resulting .deb files were installed. The source is from GIT 'stable' from the build date. This 'stable' branch included patches after the tarball release. I will be able to supply the GIT information later when my build system is up again. freeradius -v : freeradius: FreeRADIUS Version 2.1.4, for host x86_64-pc-linux-gnu, built on Feb 20 2009 at 10:39:25 -- The system seems to run fine for some time. Then I get a Seg-Fault. I was quickly able to isolate one clear cause for a seg-fault, which was my 'copy-acct-to-home-server' setup. Disabling the virtual server made the system run, apparently, fine. Setting up this virtual server independently by duplicating and suitably modifying the configuration and running with the '-d' option I was able to watch this system run. It was happily reading from the log file and sending the data to the home-server. After a number of records, (I noted 50-300 on various runs), the freeradius process would segfault. This happend, as far as I could see, always after the home-server failed to respond within the timeout (response_window) and so failed. Being more sys-admin than developer I though I would pass this on. Any ideas welcome, I will look more at this tomorrow. I believe that I also had a seg-fault from the system when the 'copy-acct-to-home-server' virtual server was disabled, at least at one point I had no freeradius process running when I am sure the 'main' one was. The system is currently offline. --> detail below <-- I have been trying to get a core file from the system without success (very embarrassing): ulimit -c -> unlimited allow_core_dumps = yes cat /proc/sys/kernel/core_pattern -> core The freeradius user has write access to the location where I execute the program. Debug output: ----- Going to the next request rad_recv: Accounting-Response packet from host <home-server-IP> port 4367, id=234, length=20 Segmentation fault ----- Doing an strace of the process was not very insightful: ----- select(26, [19 21 22 23 24 25], NULL, NULL, {0, 28186}) = 0 (Timeout) select(26, [19 21 22 23 24 25], NULL, NULL, {0, 47114}) = 0 (Timeout) select(26, [19 21 22 23 24 25], NULL, NULL, {0, 45698}) = 0 (Timeout) select(26, [19 21 22 23 24 25], NULL, NULL, {0, 43934}) = 0 (Timeout) select(26, [19 21 22 23 24 25], NULL, NULL, {0, 935}) = 0 (Timeout) select(26, [19 21 22 23 24 25], NULL, NULL, {0, 41526}) = 0 (Timeout) select(26, [19 21 22 23 24 25], NULL, NULL, {0, 7897}) = 0 (Timeout) select(26, [19 21 22 23 24 25], NULL, NULL, {0, 33998}) = 0 (Timeout) select(26, [19 21 22 23 24 25], NULL, NULL, {0, 18882}) = 0 (Timeout) select(26, [19 21 22 23 24 25], NULL, NULL, {0, 5182}) = 0 (Timeout) stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2960, ...}) = 0 sendto(3, "<27>Mar 2 14:29:07 freeradius[12"..., 130, MSG_NOSIGNAL, NULL, 0) = 130 read(19, 0x7fff88cb1070, 16) = -1 EAGAIN (Resource temporarily unavailable) write(20, "\10"..., 1) = 1 stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2960, ...}) = 0 sendto(3, "<27>Mar 2 14:29:07 freeradius[12"..., 128, MSG_NOSIGNAL, NULL, 0) = 128 sendmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(4367), sin_addr=inet_addr("<home-server-IP>")}, msg_iov(1)=[{"\4\312\0H\346e\330\232\230\340X\204\240\v\203\251\211\314\356*(\6\0\0\0\2,\n00000"..., 72}], msg_controllen=32, {cmsg_len=28, cmsg_level=SOL_IP, cmsg_type=, ...}, msg_flags=0}, 0) = 72 select(26, [19 21 22 23 24 25], NULL, NULL, {0, 20719}) = 1 (in [19], left {0, 20719}) read(19, "\10"..., 32) = 1 select(26, [19 21 22 23 24 25], NULL, NULL, {0, 20673}) = 0 (Timeout) select(26, [19 21 22 23 24 25], NULL, NULL, {0, 17346}) = 1 (in [25], left {0, 12000}) getsockname(25, {sa_family=AF_INET, sin_port=htons(1814), sin_addr=inet_addr("0.0.0.0")}, [549755813904]) = 0 recvfrom(25, "\5\312\0\24"..., 4, MSG_PEEK, {sa_family=AF_INET, sin_port=htons(4367), sin_addr=inet_addr("<home-server-IP>")}, [16]) = 4 getsockname(25, {sa_family=AF_INET, sin_port=htons(1814), sin_addr=inet_addr("0.0.0.0")}, [107374182416]) = 0 recvmsg(25, {msg_name(16)={sa_family=AF_INET, sin_port=htons(4367), sin_addr=inet_addr("<home-server-IP>")}, msg_iov(1)=[{"\5\312\0\24bTk\201\263\265\r\237\362\r\233\37-\344\356\367"..., 20}], msg_controllen=32, {cmsg_len=28, cmsg_level=SOL_IP, cmsg_type=, ...}, msg_flags=0}, 0) = 20 --- SIGSEGV (Segmentation fault) @ 0 (0) --- ----- Doing a 'kill -TERM' to the process when _not_ processing data produced this: Waking up in 1.2 seconds. Waking up in 0.1 seconds. Exiting normally. *** glibc detected *** freeradius: corrupted double-linked list: 0x000000000083b1f0 *** ======= Backtrace: ========= /lib/libc.so.6[0x7fbe1b341948] /lib/libc.so.6[0x7fbe1b341c10] /lib/libc.so.6[0x7fbe1b343708] /lib/libc.so.6(cfree+0x76)[0x7fbe1b343a56] /usr/lib/freeradius/libfreeradius-radius-2.1.4.so(fr_hash_table_free+0x93)[0x7fbe1c69db63] /usr/lib/freeradius/libfreeradius-radius-2.1.4.so(dict_free+0x7a)[0x7fbe1c69c1da] freeradius(free_mainconfig+0x27)[0x4151b7] freeradius(main+0x5bf)[0x41a54f] /lib/libc.so.6(__libc_start_main+0xe6)[0x7fbe1b2ec1a6] freeradius[0x4085e9] ======= Memory map: ======== 00400000-0043b000 r-xp 00000000 fe:01 144730 /usr/sbin/freeradius 0063b000-0063f000 rw-p 0003b000 fe:01 144730 /usr/sbin/freeradius 0081b000-0094b000 rw-p 0081b000 00:00 0 [heap] 7fbe14000000-7fbe14021000 rw-p 7fbe14000000 00:00 0 7fbe14021000-7fbe18000000 ---p 7fbe14021000 00:00 0 7fbe19c71000-7fbe19c87000 r-xp 00000000 fe:00 62788 /lib/libgcc_s.so.1 7fbe19c87000-7fbe19e87000 ---p 00016000 fe:00 62788 /lib/libgcc_s.so.1 7fbe19e87000-7fbe19e88000 rw-p 00016000 fe:00 62788 /lib/libgcc_s.so.1 7fbe19e88000-7fbe19e89000 r-xp 00000000 fe:01 186032 /usr/lib/freeradius/rlm_always-2.1.4.so 7fbe19e89000-7fbe1a089000 ---p 00001000 fe:01 186032 /usr/lib/freeradius/rlm_always-2.1.4.so 7fbe1a089000-7fbe1a08a000 rw-p 00001000 fe:01 186032 /usr/lib/freeradius/rlm_always-2.1.4.so 7fbe1a08a000-7fbe1a08d000 r-xp 00000000 fe:01 186059 /usr/lib/freeradius/rlm_logintime-2.1.4.so 7fbe1a08d000-7fbe1a28c000 ---p 00003000 fe:01 186059 /usr/lib/freeradius/rlm_logintime-2.1.4.so 7fbe1a28c000-7fbe1a28d000 rw-p 00002000 fe:01 186059 /usr/lib/freeradius/rlm_logintime-2.1.4.so 7fbe1a28d000-7fbe1a28f000 r-xp 00000000 fe:01 186053 /usr/lib/freeradius/rlm_expiration-2.1.4.so 7fbe1a28f000-7fbe1a48e000 ---p 00002000 fe:01 186053 /usr/lib/freeradius/rlm_expiration-2.1.4.so 7fbe1a48e000-7fbe1a48f000 rw-p 00001000 fe:01 186053 /usr/lib/freeradius/rlm_expiration-2.1.4.so 7fbe1a48f000-7fbe1a491000 r-xp 00000000 fe:01 186054 /usr/lib/freeradius/rlm_expr-2.1.4.so 7fbe1a491000-7fbe1a691000 ---p 00002000 fe:01 186054 /usr/lib/freeradius/rlm_expr-2.1.4.so 7fbe1a691000-7fbe1a692000 rw-p 00002000 fe:01 186054 /usr/lib/freeradius/rlm_expr-2.1.4.so 7fbe1a692000-7fbe1a694000 r-xp 00000000 fe:01 186052 /usr/lib/freeradius/rlm_exec-2.1.4.so 7fbe1a694000-7fbe1a893000 ---p 00002000 fe:01 186052 /usr/lib/freeradius/rlm_exec-2.1.4.so 7fbe1a893000-7fbe1a894000 rw-p 00001000 fe:01 186052 /usr/lib/freeradius/rlm_exec-2.1.4.so 7fbe1a894000-7fbe1a89e000 r-xp 00000000 fe:00 62759 /lib/libnss_files-2.7.so 7fbe1a89e000-7fbe1aa9e000 ---p 0000a000 fe:00 62759 /lib/libnss_files-2.7.so 7fbe1aa9e000-7fbe1aaa0000 rw-p 0000a000 fe:00 62759 /lib/libnss_files-2.7.so 7fbe1aaa0000-7fbe1aaaa000 r-xp 00000000 fe:00 62748 /lib/libnss_nis-2.7.so 7fbe1aaaa000-7fbe1aca9000 ---p 0000a000 fe:00 62748 /lib/libnss_nis-2.7.so 7fbe1aca9000-7fbe1acab000 rw-p 00009000 fe:00 62748 /lib/libnss_nis-2.7.so 7fbe1acab000-7fbe1acb2000 r-xp 00000000 fe:00 62754 /lib/libnss_compat-2.7.so 7fbe1acb2000-7fbe1aeb1000 ---p 00007000 fe:00 62754 /lib/libnss_compat-2.7.so 7fbe1aeb1000-7fbe1aeb3000 rw-p 00006000 fe:00 62754 /lib/libnss_compat-2.7.so 7fbe1aeb3000-7fbe1aec9000 r-xp 00000000 fe:01 176723 /usr/lib/libz.so.1.2.3.3 7fbe1aec9000-7fbe1b0c9000 ---p 00016000 fe:01 176723 /usr/lib/libz.so.1.2.3.3 7fbe1b0c9000-7fbe1b0ca000 rw-p 00016000 fe:01 176723 /usr/lib/libz.so.1.2.3.3 7fbe1b0ca000-7fbe1b0cc000 r-xp 00000000 fe:00 62766 /lib/libdl-2.7.so 7fbe1b0cc000-7fbe1b2cc000 ---p 00002000 fe:00 62766 /lib/libdl-2.7.so 7fbe1b2cc000-7fbe1b2ce000 rw-p 00002000 fe:00 62766 /lib/libdl-2.7.so 7fbe1b2ce000-7fbe1b418000 r-xp 00000000 fe:00 62762 /lib/libc-2.7.so 7fbe1b418000-7fbe1b617000 ---p 0014a000 fe:00 62762 /lib/libc-2.7.so 7fbe1b617000-7fbe1b61a000 r--p 00149000 fe:00 62762 /lib/libc-2.7.so 7fbe1b61a000-7fbe1b61c000 rw-p 0014c000 fe:00 62762 /lib/libc-2.7.so 7fbe1b61c000-7fbe1b621000 rw-p 7fbe1b61c000 00:00 0 7fbe1b621000-7fbe1b792000 r-xp 00000000 fe:01 177147 /usr/lib/libcrypto.so.0.9.8 7fbe1b792000-7fbe1b992000 ---p 00171000 fe:01 177147 /usr/lib/libcrypto.so.0.9.8 7fbe1b992000-7fbe1b9b8000 rw-p 00171000 fe:01 177147 /usr/lib/libcrypto.so.0.9.8 7fbe1b9b8000-7fbe1b9bc000 rw-p 7fbe1b9b8000 00:00 0 7fbe1b9bc000-7fbe1ba06000 r-xp 00000000 fe:01 177148 /usr/lib/libssl.so.0.9.8 7fbe1ba06000-7fbe1bc06000 ---p 0004a000 fe:01 177148 /usr/lib/libssl.so.0.9.8 7fbe1bc06000-7fbe1bc0d000 rw-p 0004a000 fe:01 177148 /usr/lib/libssl.so.0.9.8 7fbe1bc0d000-7fbe1bc14000 r-xp 00000000 fe:01 178225 /usr/lib/libltdl.so.3.1.6 7fbe1bc14000-7fbe1be13000 ---p 00007000 fe:01 178225 /usr/lib/libltdl.so.3.1.6 7fbe1be13000-7fbe1be14000 rw-p 00006000 fe:01 178225 /usr/lib/libltdl.so.3.1.6 7fbe1be14000-7fbe1be1c000 r-xp 00000000 fe:00 62760 /lib/libcrypt-2.7.so 7fbe1be1c000-7fbe1c01c000 ---p 00008000 fe:00 62760 /lib/libcrypt-2.7.so 7fbe1c01c000-7fbe1c01e000 rw-p 00008000 fe:00 62760 /lib/libcrypt-2.7.so 7fbe1c01e000-7fbe1c04c000 rw-p 7fbe1c01e000 00:00 0 7fbe1c04c000-7fbe1c062000 r-xp 00000000 fe:00 62758 /lib/libpthread-2.7.so 7fbe1c062000-7fbe1c262000 ---p 00016000 fe:00 62758 /lib/libpthread-2.7.so 7fbe1c262000-7fbe1c264000 rw-p 00016000 fe:00 62758 /lib/libpthread-2.7.so 7fbe1c264000-7fbe1c268000 rw-p 7fbe1c264000 00:00 0 7fbe1c268000-7fbe1c278000 r-xp 00000000 fe:00 62756 /lib/libresolv-2.7.so 7fbe1c278000-7fbe1c478000 ---p 00010000 fe:00 62756 /lib/libresolv-2.7.so 7fbe1c478000-7fbe1c47a000 rw-p 00010000 fe:00 62756 /lib/libresolv-2.7.so 7fbe1c47a000-7fbe1c47c000 rw-p 7fbe1c47a000 00:00 0 7fbe1c47c000-7fbe1c491000 r-xp 00000000 fe:00 62752 /lib/libnsl-2.7.so 7fbe1c491000-7fbe1c690000 ---p 00015000 fe:00 62752 /lib/libnsl-2.7.so 7fbe1c690000-7fbe1c692000 rw-p 00014000 fe:00 62752 /lib/libnsl-2.7.so 7fbe1c692000-7fbe1c694000 rw-p 7fbe1c692000 00:00 0 7fbe1c694000-7fbe1c6b3000 r-xp 00000000 fe:01 186029 /usr/lib/freeradius/libfreeradius-radius-2.1.4.so 7fbe1c6b3000-7fbe1c8b3000 ---p 0001f000 fe:01 186029 /usr/lib/freeradius/libfreeradius-radius-2.1.4.so 7fbe1c8b3000-7fbe1c8b5000 rw-p 0001f000 fe:01 186029 /usr/lib/freeradius/libfreeradius-radius-2.1.4.so 7fbe1c8b5000-7fbe1c8b6000 rw-p 7fbe1c8b5000 00:00 0 7fbe1c8b6000-7fbe1c8d2000 r-xp 00000000 fe:00 62765 /lib/ld-2.7.so 7fbe1cac4000-7fbe1caca000 rw-p 7fbe1cac4000 00:00 0 7fbe1cace000-7fbe1cad1000 rw-p 7fbe1cace000 00:00 0 7fbe1cad1000-7fbe1cad3000 rw-p 0001b000 fe:00 62765 /lib/ld-2.7.so 7fff24abb000-7fff24ad2000 rw-p 7ffffffe8000 00:00 0 [stack] 7fff24bfe000-7fff24bff000 r-xp 7fff24bfe000 00:00 0 [vdso] ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0 [vsyscall] Aborted
Chris Moules wrote:
The system seems to run fine for some time. Then I get a Seg-Fault. I was quickly able to isolate one clear cause for a seg-fault, which was my 'copy-acct-to-home-server' setup. Disabling the virtual server made the system run, apparently, fine. Setting up this virtual server independently by duplicating and suitably modifying the configuration and running with the '-d' option I was able to watch this system run. It was happily reading from the log file and sending the data to the home-server. After a number of records, (I noted 50-300 on various runs), the freeradius process would segfault. This happend, as far as I could see, always after the home-server failed to respond within the timeout (response_window) and so failed.
Ugh. There are ways to track this down, but it involves re-building the server with debugging symbols.
I have been trying to get a core file from the system without success (very embarrassing): ulimit -c -> unlimited allow_core_dumps = yes cat /proc/sys/kernel/core_pattern -> core The freeradius user has write access to the location where I execute the program.
Run it in a "screen" output, under "gdb". See doc/bugs for instructions.
Doing an strace of the process was not very insightful:
That won't tell you much,
Doing a 'kill -TERM' to the process when _not_ processing data produced this: ... *** glibc detected *** freeradius: corrupted double-linked list: 0x000000000083b1f0 *** ... /usr/lib/freeradius/libfreeradius-radius-2.1.4.so(fr_hash_table_free+0x93)[0x7fbe1c69db63] /usr/lib/freeradius/libfreeradius-radius-2.1.4.so(dict_free+0x7a)[0x7fbe1c69c1da]
Hmm... that's not good. It's not serious, but it's not good. The problem is I don't see that on my test systems. Some more output from "gdb" after a crash would be *enormously* helpful. Alan DeKok.
Alan DeKok wrote:
Chris Moules wrote:
The system seems to run fine for some time. Then I get a Seg-Fault. I was quickly able to isolate one clear cause for a seg-fault, which was my 'copy-acct-to-home-server' setup. Disabling the virtual server made the system run, apparently, fine. Setting up this virtual server independently by duplicating and suitably modifying the configuration and running with the '-d' option I was able to watch this system run. It was happily reading from the log file and sending the data to the home-server. After a number of records, (I noted 50-300 on various runs), the freeradius process would segfault. This happend, as far as I could see, always after the home-server failed to respond within the timeout (response_window) and so failed.
Ugh.
There are ways to track this down, but it involves re-building the server with debugging symbols.
The debian build system creates the -dbg package too, I will install this.
I have been trying to get a core file from the system without success (very embarrassing): ulimit -c -> unlimited allow_core_dumps = yes cat /proc/sys/kernel/core_pattern -> core The freeradius user has write access to the location where I execute the program.
Run it in a "screen" output, under "gdb". See doc/bugs for instructions.
OK, I have screen on the server. I will need to install gdb and read the doc/bugs document.
Doing an strace of the process was not very insightful:
That won't tell you much,
Doing a 'kill -TERM' to the process when _not_ processing data produced this: ... *** glibc detected *** freeradius: corrupted double-linked list: 0x000000000083b1f0 *** ... /usr/lib/freeradius/libfreeradius-radius-2.1.4.so(fr_hash_table_free+0x93)[0x7fbe1c69db63] /usr/lib/freeradius/libfreeradius-radius-2.1.4.so(dict_free+0x7a)[0x7fbe1c69c1da]
Hmm... that's not good. It's not serious, but it's not good.
The problem is I don't see that on my test systems.
Some more output from "gdb" after a crash would be *enormously* helpful.
Alan DeKok. -
OK, I will try to get more info. My dev/test setup is i686 and this server is amd64 (if that is at all related). I built the software in a chroot on a separate disk attached to the system. I have another amd64 system that I will use for more testing. Thanks again Alan! Regards Chris
Please find attached the gdb output. When running inside gdb, if I did not supply the '-X' arg then I just got something along the lines of 'the program terminated normally' right away. I guess it forked off and gdb did not follow. All this server is doing is reading a log file and sending it to the home server. This server is known to have issues and be unresponsive at times. All accounting data is also stored locally. Thanks for any help on this. Chris Alan DeKok wrote:
Chris Moules wrote:
The system seems to run fine for some time. Then I get a Seg-Fault. I was quickly able to isolate one clear cause for a seg-fault, which was my 'copy-acct-to-home-server' setup. Disabling the virtual server made the system run, apparently, fine. Setting up this virtual server independently by duplicating and suitably modifying the configuration and running with the '-d' option I was able to watch this system run. It was happily reading from the log file and sending the data to the home-server. After a number of records, (I noted 50-300 on various runs), the freeradius process would segfault. This happend, as far as I could see, always after the home-server failed to respond within the timeout (response_window) and so failed.
Ugh.
There are ways to track this down, but it involves re-building the server with debugging symbols.
I have been trying to get a core file from the system without success (very embarrassing): ulimit -c -> unlimited allow_core_dumps = yes cat /proc/sys/kernel/core_pattern -> core The freeradius user has write access to the location where I execute the program.
Run it in a "screen" output, under "gdb". See doc/bugs for instructions.
Doing an strace of the process was not very insightful:
That won't tell you much,
Doing a 'kill -TERM' to the process when _not_ processing data produced this: ... *** glibc detected *** freeradius: corrupted double-linked list: 0x000000000083b1f0 *** ... /usr/lib/freeradius/libfreeradius-radius-2.1.4.so(fr_hash_table_free+0x93)[0x7fbe1c69db63] /usr/lib/freeradius/libfreeradius-radius-2.1.4.so(dict_free+0x7a)[0x7fbe1c69c1da]
Hmm... that's not good. It's not serious, but it's not good.
The problem is I don't see that on my test systems.
Some more output from "gdb" after a crash would be *enormously* helpful.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
Chris Moules wrote:
When running inside gdb, if I did not supply the '-X' arg then I just got something along the lines of 'the program terminated normally' right away. I guess it forked off and gdb did not follow.
Yes.
All this server is doing is reading a log file and sending it to the home server. This server is known to have issues and be unresponsive at times. All accounting data is also stored locally.
Ok. That *should* work fine... Can you post the contents of the "request" structure when it dies? i.e.: ... (gdb) p/x *request That will let me know *which* piece of the structure has the wrong value. Alan DeKok.
Alan DeKok wrote:
Chris Moules wrote:
When running inside gdb, if I did not supply the '-X' arg then I just got something along the lines of 'the program terminated normally' right away. I guess it forked off and gdb did not follow.
Yes.
All this server is doing is reading a log file and sending it to the home server. This server is known to have issues and be unresponsive at times. All accounting data is also stored locally.
Ok. That *should* work fine...
Can you post the contents of the "request" structure when it dies? i.e.:
... (gdb) p/x *request
That will let me know *which* piece of the structure has the wrong value.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
OK, I have re-done the debugging. This time I have left gdb running in case you want more output. Regards Chris
Chris Moules wrote:
OK, I have re-done the debugging. This time I have left gdb running in case you want more output.
Thanks... if you could also show: (gdb) p/x request->proxy That would confirm my suspicions. i.e. When it determines that the home server is down, it starts pinging it with internally generated packets. Those packets don't have some fields that are required for "normal" packets. I've committed fixes to git that will fix this. To grab them, do: $ git pull $ cd src/main $ make radiusd $ make install You don't need to re-install any of the modules. Thanks for the report. Alan DeKok.
Alan DeKok wrote:
Chris Moules wrote:
OK, I have re-done the debugging. This time I have left gdb running in case you want more output.
Thanks... if you could also show:
(gdb) p/x request->proxy
That would confirm my suspicions.
OK, here you go: (gdb) p/x *request $1 = {magic = 0xdeadbeef, packet = 0x0, proxy = 0xeebff0, reply = 0x0, proxy_reply = 0x0, config_items = 0x0, username = 0x0, password = 0x0, root = 0x0, data = 0x0, client = 0x0, child_pid = 0x0, timestamp = 0x49ae6bd4, number = 0x4, listener = 0x0, proxy_listener = 0xee5700, simul_max = 0x0, simul_count = 0x0, simul_mpp = 0x0, options = 0x0, module = 0x42f4ed, component = 0x42f4ed, received = {tv_sec = 0x0, tv_usec = 0x0}, when = { tv_sec = 0x49ae6bd8, tv_usec = 0x1060e}, delay = 0x0, master_state = 0x0, child_state = 0x3, priority = 0x0, ev = 0xeec6b0, next_when = {tv_sec = 0x0, tv_usec = 0x0}, next_callback = 0x0, in_request_hash = 0x0, in_proxy_hash = 0x1, home_server = 0xddcc50, home_pool = 0x0, proxy_when = {tv_sec = 0x0, tv_usec = 0x0}, num_proxied_requests = 0x0, num_proxied_responses = 0x1, server = 0x0, parent = 0x0, radlog = 0x414cb0, coa = 0x0, num_coa_requests = 0x0} (gdb) p/x request->proxy $2 = 0xeebff0
i.e. When it determines that the home server is down, it starts pinging it with internally generated packets. Those packets don't have some fields that are required for "normal" packets.
OK, so that is why it only dies when the server replies to a 'are you there' packet after it has died / zombied.
I've committed fixes to git that will fix this. To grab them, do:
$ git pull $ cd src/main $ make radiusd $ make install
You don't need to re-install any of the modules.
Thanks for the report.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
I will end up rebuilding new packages. This is not a problem. You have already commited the couple of patches that I needed to get the build working. There have been a few more patches since. I may wait with this until tomorrow however. My client does not like things going wrong at just-before-home-time ;) Thanks for the support on this! Regards Chris
Chris Moules wrote:
Alan DeKok wrote:
Chris Moules wrote:
OK, I have re-done the debugging. This time I have left gdb running in case you want more output.
Thanks... if you could also show:
(gdb) p/x request->proxy
Sorry... (gdb) p/x *request->proxy Little characters make all the difference. Alan DeKok.
Alan DeKok wrote:
Chris Moules wrote:
Alan DeKok wrote:
Chris Moules wrote:
OK, I have re-done the debugging. This time I have left gdb running in case you want more output. Thanks... if you could also show:
(gdb) p/x request->proxy
Sorry...
(gdb) p/x *request->proxy
Little characters make all the difference.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
Hi Alan, no problem, I did wonder. hope this is more helpful. (gdb) p/x request->proxy $2 = 0xeebff0 (gdb) p/x *request->proxy $3 = {sockfd = 0x8, src_ipaddr = {af = 0x2, ipaddr = {ip4addr = {s_addr = 0x0}, ip6addr = {in6_u = {u6_addr8 = {0x0, 0x0, 0x0, 0x0, 0x12, 0xe0, 0x15, 0x7a, 0x38, 0x7f, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, u6_addr16 = {0x0, 0x0, 0xe012, 0x7a15, 0x7f38, 0x0, 0x0, 0x0}, u6_addr32 = {0x0, 0x7a15e012, 0x7f38, 0x0}}}}}, dst_ipaddr = {af = 0x2, ipaddr = {ip4addr = {s_addr = 0x9bef482}, ip6addr = {in6_u = {u6_addr8 = {0x82, 0xf4, 0xbe, 0x9, 0x0 <repeats 12 times>}, u6_addr16 = {0xf482, 0x9be, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, u6_addr32 = {0x9bef482, 0x0, 0x0, 0x0}}}}}, src_port = 0x542, dst_port = 0x110f, id = 0xc3, code = 0x4, hash = 0x268b44dc, vector = {0xed, 0xd6, 0xfe, 0xd5, 0x5e, 0xec, 0xe6, 0x3e, 0x9a, 0x4e, 0x5e, 0xb6, 0x4e, 0x5d, 0x9b, 0xdb}, timestamp = 0x0, data = 0xeea910, data_len = 0x48, vps = 0xeec070, offset = 0x0} Chris
Morning, it looks like this is not 100% resolved. I installed a patched version on FreeRADIUS stable: ----------------- git branch master * stable commit 2b79682e175312703743acd6ed98b988a3e74884 Author: Alan T. DeKok <aland@freeradius.org> Date: Wed Mar 4 13:52:35 2009 +0100 Simplified use of syslog options Patch from Hermann Lauer commit cb291079f09cdea0ecf75948b10377b6ef6b3687 Author: Alan T. DeKok <aland@freeradius.org> Date: Wed Mar 4 13:38:03 2009 +0100 Cleaned up code based on report of crash. Added additional notes on coa moved "check for reply" in received_proxy_response to earlier, as it shouldn't be done later. Simplified check for CoA divorce. This is the code that crashed (still no idea why), but the new code should do the intended checks, without the un-intended side effects commit c191369bc562b9f9b83b511270c417e8988d2454 Author: Alan T. DeKok <aland@freeradius.org> Date: Mon Mar 2 10:31:16 2009 +0100 Keep track of total responses for clients, too ----------------- After installation, I ran my home_server proxy, reading the local log file. This ran for about a minute and then crashed. I then installed the dbg package and ran it again with gdb. Attached is the gdb log file. Apart from the content of the log file, there was a dump to stderr: Going to the next request Delaying next detail event for 1.0 seconds. rad_recv: Accounting-Response packet from host <home_server_ip> port 4367, id=93, length=20 *** glibc detected *** /usr/sbin/freeradius: double free or corruption (top): 0x0000000002773790 *** ======= Backtrace: ========= /lib/libc.so.6[0x7fc0148ee948] /lib/libc.so.6(cfree+0x76)[0x7fc0148f0a56] /usr/lib/freeradius/libfreeradius-radius-2.1.4.so(rad_free+0x38)[0x7fc015c4e0a8] /usr/sbin/freeradius[0x4128cd] /usr/sbin/freeradius[0x42173e] /usr/lib/freeradius/libfreeradius-radius-2.1.4.so(fr_event_loop+0x36b)[0x7fc015c5929b] /usr/sbin/freeradius(main+0x56d)[0x41aebd] /lib/libc.so.6(__libc_start_main+0xe6)[0x7fc0148991a6] /usr/sbin/freeradius[0x408689] ======= Memory map: ======== 00400000-0043c000 r-xp 00000000 fe:01 144774 /usr/sbin/freeradius 0063b000-0063f000 rw-p 0003b000 fe:01 144774 /usr/sbin/freeradius 0063f000-00640000 rw-p 0063f000 00:00 0 02622000-02793000 rw-p 02622000 00:00 0 [heap] 7fc00c000000-7fc00c021000 rw-p 7fc00c000000 00:00 0 7fc00c021000-7fc010000000 ---p 7fc00c021000 00:00 0 7fc01321e000-7fc013234000 r-xp 00000000 fe:00 62788 /lib/libgcc_s.so.1 7fc013234000-7fc013434000 ---p 00016000 fe:00 62788 /lib/libgcc_s.so.1 7fc013434000-7fc013435000 rw-p 00016000 fe:00 62788 /lib/libgcc_s.so.1 7fc013435000-7fc013436000 r-xp 00000000 fe:01 186390 /usr/lib/freeradius/rlm_always-2.1.4.so 7fc013436000-7fc013636000 ---p 00001000 fe:01 186390 /usr/lib/freeradius/rlm_always-2.1.4.so 7fc013636000-7fc013637000 rw-p 00001000 fe:01 186390 /usr/lib/freeradius/rlm_always-2.1.4.so 7fc013637000-7fc01363a000 r-xp 00000000 fe:01 186417 /usr/lib/freeradius/rlm_logintime-2.1.4.so 7fc01363a000-7fc013839000 ---p 00003000 fe:01 186417 /usr/lib/freeradius/rlm_logintime-2.1.4.so 7fc013839000-7fc01383a000 rw-p 00002000 fe:01 186417 /usr/lib/freeradius/rlm_logintime-2.1.4.so 7fc01383a000-7fc01383c000 r-xp 00000000 fe:01 186411 /usr/lib/freeradius/rlm_expiration-2.1.4.so 7fc01383c000-7fc013a3b000 ---p 00002000 fe:01 186411 /usr/lib/freeradius/rlm_expiration-2.1.4.so 7fc013a3b000-7fc013a3c000 rw-p 00001000 fe:01 186411 /usr/lib/freeradius/rlm_expiration-2.1.4.so 7fc013a3c000-7fc013a3e000 r-xp 00000000 fe:01 186412 /usr/lib/freeradius/rlm_expr-2.1.4.so 7fc013a3e000-7fc013c3e000 ---p 00002000 fe:01 186412 /usr/lib/freeradius/rlm_expr-2.1.4.so 7fc013c3e000-7fc013c3f000 rw-p 00002000 fe:01 186412 /usr/lib/freeradius/rlm_expr-2.1.4.so 7fc013c3f000-7fc013c41000 r-xp 00000000 fe:01 186410 /usr/lib/freeradius/rlm_exec-2.1.4.so 7fc013c41000-7fc013e40000 ---p 00002000 fe:01 186410 /usr/lib/freeradius/rlm_exec-2.1.4.so 7fc013e40000-7fc013e41000 rw-p 00001000 fe:01 186410 /usr/lib/freeradius/rlm_exec-2.1.4.so 7fc013e41000-7fc013e4b000 r-xp 00000000 fe:00 62759 /lib/libnss_files-2.7.so 7fc013e4b000-7fc01404b000 ---p 0000a000 fe:00 62759 /lib/libnss_files-2.7.so 7fc01404b000-7fc01404d000 rw-p 0000a000 fe:00 62759 /lib/libnss_files-2.7.so 7fc01404d000-7fc014057000 r-xp 00000000 fe:00 62748 /lib/libnss_nis-2.7.so 7fc014057000-7fc014256000 ---p 0000a000 fe:00 62748 /lib/libnss_nis-2.7.so 7fc014256000-7fc014258000 rw-p 00009000 fe:00 62748 /lib/libnss_nis-2.7.so 7fc014258000-7fc01425f000 r-xp 00000000 fe:00 62754 /lib/libnss_compat-2.7.so 7fc01425f000-7fc01445e000 ---p 00007000 fe:00 62754 /lib/libnss_compat-2.7.so 7fc01445e000-7fc014460000 rw-p 00006000 fe:00 62754 /lib/libnss_compat-2.7.so 7fc014460000-7fc014476000 r-xp 00000000 fe:01 176723 /usr/lib/libz.so.1.2.3.3 7fc014476000-7fc014676000 ---p 00016000 fe:01 176723 /usr/lib/libz.so.1.2.3.3 7fc014676000-7fc014677000 rw-p 00016000 fe:01 176723 /usr/lib/libz.so.1.2.3.3 7fc014677000-7fc014679000 r-xp 00000000 fe:00 62766 /lib/libdl-2.7.so 7fc014679000-7fc014879000 ---p 00002000 fe:00 62766 /lib/libdl-2.7.so 7fc014879000-7fc01487b000 rw-p 00002000 fe:00 62766 /lib/libdl-2.7.so 7fc01487b000-7fc0149c5000 r-xp 00000000 fe:00 62762 /lib/libc-2.7.so 7fc0149c5000-7fc014bc4000 ---p 0014a000 fe:00 62762 /lib/libc-2.7.so 7fc014bc4000-7fc014bc7000 r--p 00149000 fe:00 62762 /lib/libc-2.7.so 7fc014bc7000-7fc014bc9000 rw-p 0014c000 fe:00 62762 /lib/libc-2.7.so 7fc014bc9000-7fc014bce000 rw-p 7fc014bc9000 00:00 0 7fc014bce000-7fc014d3f000 r-xp 00000000 fe:01 177147 /usr/lib/libcrypto.so.0.9.8 7fc014d3f000-7fc014f3f000 ---p 00171000 fe:01 177147 /usr/lib/libcrypto.so.0.9.8 7fc014f3f000-7fc014f65000 rw-p 00171000 fe:01 177147 /usr/lib/libcrypto.so.0.9.8 7fc014f65000-7fc014f69000 rw-p 7fc014f65000 00:00 0 7fc014f69000-7fc014fb3000 r-xp 00000000 fe:01 177148 /usr/lib/libssl.so.0.9.8 7fc014fb3000-7fc0151b3000 ---p 0004a000 fe:01 177148 /usr/lib/libssl.so.0.9.8 7fc0151b3000-7fc0151ba000 rw-p 0004a000 fe:01 177148 /usr/lib/libssl.so.0.9.8 7fc0151ba000-7fc0151c1000 r-xp 00000000 fe:01 178225 /usr/lib/libltdl.so.3.1.6 7fc0151c1000-7fc0153c0000 ---p 00007000 fe:01 178225 /usr/lib/libltdl.so.3.1.6 7fc0153c0000-7fc0153c1000 rw-p 00006000 fe:01 178225 /usr/lib/libltdl.so.3.1.6 7fc0153c1000-7fc0153c9000 r-xp 00000000 fe:00 62760 /lib/libcrypt-2.7.so 7fc0153c9000-7fc0155c9000 ---p 00008000 fe:00 62760 /lib/libcrypt-2.7.so 7fc0155c9000-7fc0155cb000 rw-p 00008000 fe:00 62760 /lib/libcrypt-2.7.so 7fc0155cb000-7fc0155f9000 rw-p 7fc0155cb000 00:00 0 7fc0155f9000-7fc01560f000 r-xp 00000000 fe:00 62758 /lib/libpthread-2.7.so 7fc01560f000-7fc01580f000 ---p 00016000 fe:00 62758 /lib/libpthread-2.7.so 7fc01580f000-7fc015811000 rw-p 00016000 fe:00 62758 /lib/libpthread-2.7.so 7fc015811000-7fc015815000 rw-p 7fc015811000 00:00 0 7fc015815000-7fc015825000 r-xp 00000000 fe:00 62756 /lib/libresolv-2.7.so 7fc015825000-7fc015a25000 ---p 00010000 fe:00 62756 /lib/libresolv-2.7.so 7fc015a25000-7fc015a27000 rw-p 00010000 fe:00 62756 /lib/libresolv-2.7.so 7fc015a27000-7fc015a29000 rw-p 7fc015a27000 00:00 0 7fc015a29000-7fc015a3e000 r-xp 00000000 fe:00 62752 /lib/libnsl-2.7.so 7fc015a3e000-7fc015c3d000 ---p 00015000 fe:00 62752 /lib/libnsl-2.7.so 7fc015c3d000-7fc015c3f000 rw-p 00014000 fe:00 62752 /lib/libnsl-2.7.so 7fc015c3f000-7fc015c41000 rw-p 7fc015c3f000 00:00 0 7fc015c41000-7fc015c60000 r-xp 00000000 fe:01 186387 /usr/lib/freeradius/libfreeradius-radius-2.1.4.so 7fc015c60000-7fc015e60000 ---p 0001f000 fe:01 186387 /usr/lib/freeradius/libfreeradius-radius-2.1.4.so 7fc015e60000-7fc015e62000 rw-p 0001f000 fe:01 186387 /usr/lib/freeradius/libfreeradius-radius-2.1.4.so 7fc015e62000-7fc015e63000 rw-p 7fc015e62000 00:00 0 7fc015e63000-7fc015e7f000 r-xp 00000000 fe:00 62765 /lib/ld-2.7.so 7fc016071000-7fc016077000 rw-p 7fc016071000 00:00 0 7fc016079000-7fc01607e000 rw-p 7fc016079000 00:00 0 7fc01607e000-7fc016080000 rw-p 0001b000 fe:00 62765 /lib/ld-2.7.so 7fff1e067000-7fff1e07f000 rw-p 7ffffffe7000 00:00 0 [stack] 7fff1e1fe000-7fff1e1ff000 r-xp 7fff1e1fe000 00:00 0 [vdso] ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0 [vsyscall] Program received signal SIGABRT, Aborted. [Switching to Thread 0x7fc016071ae0 (LWP 25399)] Chris Chris Moules wrote:
Alan DeKok wrote:
Chris Moules wrote:
Alan DeKok wrote:
Chris Moules wrote:
OK, I have re-done the debugging. This time I have left gdb running in case you want more output. Thanks... if you could also show:
(gdb) p/x request->proxy
Sorry...
(gdb) p/x *request->proxy
Little characters make all the difference.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
Hi Alan,
no problem, I did wonder.
hope this is more helpful.
(gdb) p/x request->proxy $2 = 0xeebff0 (gdb) p/x *request->proxy $3 = {sockfd = 0x8, src_ipaddr = {af = 0x2, ipaddr = {ip4addr = {s_addr = 0x0}, ip6addr = {in6_u = {u6_addr8 = {0x0, 0x0, 0x0, 0x0, 0x12, 0xe0, 0x15, 0x7a, 0x38, 0x7f, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, u6_addr16 = {0x0, 0x0, 0xe012, 0x7a15, 0x7f38, 0x0, 0x0, 0x0}, u6_addr32 = {0x0, 0x7a15e012, 0x7f38, 0x0}}}}}, dst_ipaddr = {af = 0x2, ipaddr = {ip4addr = {s_addr = 0x9bef482}, ip6addr = {in6_u = {u6_addr8 = {0x82, 0xf4, 0xbe, 0x9, 0x0 <repeats 12 times>}, u6_addr16 = {0xf482, 0x9be, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}, u6_addr32 = {0x9bef482, 0x0, 0x0, 0x0}}}}}, src_port = 0x542, dst_port = 0x110f, id = 0xc3, code = 0x4, hash = 0x268b44dc, vector = {0xed, 0xd6, 0xfe, 0xd5, 0x5e, 0xec, 0xe6, 0x3e, 0x9a, 0x4e, 0x5e, 0xb6, 0x4e, 0x5d, 0x9b, 0xdb}, timestamp = 0x0, data = 0xeea910, data_len = 0x48, vps = 0xeec070, offset = 0x0}
Chris - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
Alan DeKok wrote:
Chris Moules wrote:
it looks like this is not 100% resolved. I installed a patched version on FreeRADIUS stable:
That's a *different* problem.
OK, This will be the one that I got the libc warning about when I did a kill -TERM to radiusd when I pointed it at a non-existing file when attempting to get a core dump.
It's nice that one bug hides behind another one.
Yes, this deployment was a little unnerving... It is always nice when you find that the tests run fine but after X thousand requests the thing bombs.
I've pushed a new fix to git.freeradius.org.
Applied. Again I patched the 'stable' branch with this and the previous patch. I have this now running in testing. I am trying to proxy the content of the smaller proxy log (6.2MB - 7137 requests) to the remote server. So far so good. The other system has had a number of pauses and I think I have seen a couple of time-outs and recoveries. I don't think that I will try to proxy the rest of the data (~ 900MB of packets in the meantime), it is not that important to them. All the accounting data is also in the local DB.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
Thanks again Alan! Chris
Chris Moules wrote:
I have this now running in testing. I am trying to proxy the content of the smaller proxy log (6.2MB - 7137 requests) to the remote server. So far so good. The other system has had a number of pauses and I think I have seen a couple of time-outs and recoveries.
OK, thanks. Alan DeKok.
Alan DeKok wrote:
Chris Moules wrote:
I have this now running in testing. I am trying to proxy the content of the smaller proxy log (6.2MB - 7137 requests) to the remote server. So far so good. The other system has had a number of pauses and I think I have seen a couple of time-outs and recoveries.
OK, thanks.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
The system has just finished proxying all 7137 requests (just shy of one hour). The other server is _really_ slow. I will work with my client tomorrow to do another live test on this code. That way we will see how auth and acct work with the proxy code and fail-over. If all that works fine I will let you know, if there are problems I will send another debug but I really hope it does not come to that. Regards Chris
Just a quick update. The system has been running with the two patches all day today (well from about 9:30am) and there has been no problems. The server has processed ~33,000 authentication attempts and ~4,100 Accounting sessions. Most of this data is proxied. Looks good. Have a nice Weekend! Chris Chris Moules wrote:
Alan DeKok wrote:
Chris Moules wrote:
I have this now running in testing. I am trying to proxy the content of the smaller proxy log (6.2MB - 7137 requests) to the remote server. So far so good. The other system has had a number of pauses and I think I have seen a couple of time-outs and recoveries.
OK, thanks.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
The system has just finished proxying all 7137 requests (just shy of one hour). The other server is _really_ slow.
I will work with my client tomorrow to do another live test on this code. That way we will see how auth and acct work with the proxy code and fail-over. If all that works fine I will let you know, if there are problems I will send another debug but I really hope it does not come to that.
Regards
Chris
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
Chris Moules wrote:
Just a quick update.
The system has been running with the two patches all day today (well from about 9:30am) and there has been no problems.
The server has processed ~33,000 authentication attempts and ~4,100 Accounting sessions. Most of this data is proxied.
Looks good.
Thanks. This makes me feel better about releasing 2.1.4. Alan DeKok.
participants (2)
-
Alan DeKok -
Chris Moules