Craig Campbell <craig@ccraft.ca> wrote:

Thanks for the update - I was concluding I'd have to wait for the release of 2.1.8 to pursue this. I am currently in a situation where I can help debug 2.1.8, since the 'new' systems aren't yet in production.

Well I can see no reason to run FreeRADIUS no in a debugger all the time, even when in production. However my nickname is "Rambo Clouter" so maybe you do not want to follow my advice. :) When you compile FreeRADIUS you simply make sure you leave debugging symbols in and turn off compiler optimisations (so your CFLAGS should be '-O0 -g'. You probably can do this by running configure as follows: ---- CFLAGS='-O0 -g' ./configure --all-your-usual-options-that-you-want ----

Looking at your debug output (and I am in no way an expert at that) it seems as though the process received a signal?

Well FreeRADIUS is sending it to herself according to gdb: ---- src/main/radiusd.c line 419 ---- /* * Send a TERM signal to all * associated processes * (including us, which gets * ignored.) */ #ifndef __MINGW32__ if (spawn_flag) kill(-radius_pid, SIGTERM); #endif ---- For whatever reason, it is not getting ignored. At first I thought it was because I run my FreeRADIUS (even in production) in gdb, but as you do not I am wondering what is actually going on. To run it in the debugger just run 'gdb freeradius' and you will get the gdb prompt. There you want to type 'run -f' and wait for it to puke. When it does you could type 'where' for it to tell you what happened, but we know what is happening, we want to find which patch is doing it :) Oh familise yourself with screen[2] if you do not know it already, you should run the debugger in a screen'd session so you can return to it later without having to remain logged in.

I am running a 'custom' module (event.c as I recall) from Alan that resolves an issue with hung children (very exciting!), and I followed Alan's instructions to get to this point. I would really like to try to 'give back' if I can and assist in identifying the cause of the program exiting (assuming it is a new and as of yet unidentified bug).

Would copying the steps you have below on my two redhat systems be a good way to proceed?

Pretty much follow: http://www.reactivated.net/weblog/archives/2006/01/using-git-bisect-to-find-... I had been running with the cherry-pick'ed patches for weeks and had no problems up to 9261f3e0026323b2c397af13d02fbc5780908143, so I am certain that the issue is the result of the patches between 12ead56dffca9b3ecddc8a7860a1ef5b5361b374 and 9dbc8974fdd2300a70293eda9c62bce20a3c9165. The problem is you *have* to apply my listed cherry-picks, as if you add *any* of the TCP related code Alan has been working on, it all stops compiling[1] Cheers [1] I am pretty sure Alan has stashed a number of patches that he has not put into the publically available GIT trees as things like the jumbo socket clean up patch (e04b62f1bd257489bd92ccc584b0886c7e2011e8) refer to my_ipaddr/my_port which is not in any header files I have or found in 'master' [2] http://blogamundo.net/code/screen/ -- Alexander Clouter .sigmonster says: Simplicity does not precede complexity, but follows it.

Ok, I performed the following on two servers that relay receive accounting packets only and relay these to each other (if it matters). This is the same test code the Alan had me build, with his custom event.c. (I really do not know how to use git) I deleted the existing installation, and then performed the following steps. CFLAGS='-O0 -g' ./configure make clean make sudo make install I then ran the code from within gdb as Alexander described (within screen - thanks!) gdb radiusd (gdb) run -f <messages program runs until...> Detaching after fork from child process 14277. Detaching after fork from child process 14334. Detaching after fork from child process 14364. Detaching after fork from child process 14394. Detaching after fork from child process 14424. Program received signal SIGTERM, Terminated. 0x0000003acf4306a7 in kill () from /lib64/libc.so.6 (gdb) where #0 0x0000003acf4306a7 in kill () from /lib64/libc.so.6 #1 0x0000000000424186 in main (argc=2, argv=0x7fff67ce72d8) at radiusd.c:419 (gdb) The gdb output is identical for the other radius server. I'm afraid I haven't helped much. The source I have was acquired Oct 20 15:05 (EST) if that helps in any way. Perhaps I have fewer of the suspected patches in my build than you have in yours? Is there a way we could compare? Is there any way I can get more information out of these test runs? Thanks, -craig ----- Original Message ----- From: "Alexander Clouter" <alex@digriz.org.uk> To: <freeradius-users@lists.freeradius.org> Sent: Wednesday, November 04, 2009 3:47 PM Subject: Re: Unexpected "Exiting normally" 2.1.8?

Craig Campbell <craig@ccraft.ca> wrote:

...

Thanks for the update - I was concluding I'd have to wait for the release of 2.1.8 to pursue this. I am currently in a situation where I can help debug 2.1.8, since the 'new' systems aren't yet in production.

Well I can see no reason to run FreeRADIUS no in a debugger all the time, even when in production. However my nickname is "Rambo Clouter" so maybe you do not want to follow my advice. :)

When you compile FreeRADIUS you simply make sure you leave debugging symbols in and turn off compiler optimisations (so your CFLAGS should be '-O0 -g'. You probably can do this by running configure as follows: ---- CFLAGS='-O0 -g' ./configure --all-your-usual-options-that-you-want ----

...

Looking at your debug output (and I am in no way an expert at that) it seems as though the process received a signal?

Well FreeRADIUS is sending it to herself according to gdb: ---- src/main/radiusd.c line 419 ---- /* * Send a TERM signal to all * associated processes * (including us, which gets * ignored.) */ #ifndef __MINGW32__ if (spawn_flag) kill(-radius_pid, SIGTERM); #endif ----

For whatever reason, it is not getting ignored. At first I thought it was because I run my FreeRADIUS (even in production) in gdb, but as you do not I am wondering what is actually going on.

To run it in the debugger just run 'gdb freeradius' and you will get the gdb prompt. There you want to type 'run -f' and wait for it to puke. When it does you could type 'where' for it to tell you what happened, but we know what is happening, we want to find which patch is doing it :) Oh familise yourself with screen[2] if you do not know it already, you should run the debugger in a screen'd session so you can return to it later without having to remain logged in.

...

I am running a 'custom' module (event.c as I recall) from Alan that resolves an issue with hung children (very exciting!), and I followed Alan's instructions to get to this point. I would really like to try to 'give back' if I can and assist in identifying the cause of the program exiting (assuming it is a new and as of yet unidentified bug).

Would copying the steps you have below on my two redhat systems be a good way to proceed?

Pretty much follow:

http://www.reactivated.net/weblog/archives/2006/01/using-git-bisect-to-find-...

I had been running with the cherry-pick'ed patches for weeks and had no problems up to 9261f3e0026323b2c397af13d02fbc5780908143, so I am certain that the issue is the result of the patches between 12ead56dffca9b3ecddc8a7860a1ef5b5361b374 and 9dbc8974fdd2300a70293eda9c62bce20a3c9165. The problem is you *have* to apply my listed cherry-picks, as if you add *any* of the TCP related code Alan has been working on, it all stops compiling[1]

Cheers

[1] I am pretty sure Alan has stashed a number of patches that he has not put into the publically available GIT trees as things like the jumbo socket clean up patch (e04b62f1bd257489bd92ccc584b0886c7e2011e8) refer to my_ipaddr/my_port which is not in any header files I have or found in 'master' [2] http://blogamundo.net/code/screen/ -- Alexander Clouter .sigmonster says: Simplicity does not precede complexity, but follows it.

- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

__________ Information from ESET Smart Security, version of virus signature database 4574 (20091104) __________

The message was checked by ESET Smart Security.

http://www.eset.com

__________ Information from ESET Smart Security, version of virus signature database 4578 (20091106) __________ The message was checked by ESET Smart Security. http://www.eset.com

Regarding git bisect. I know the current version is "bad", but I have no idea if any 2.1.8 version is 'Good'. If there a way to use git bisect without identifying 'good'? How can we find the first version? Can we assume it was 'good'? Sorry to be so non knowledgeable about git. -craig ----- Original Message ----- From: "Alexander Clouter" <alex@digriz.org.uk> To: <freeradius-users@lists.freeradius.org> Sent: Friday, November 06, 2009 8:21 AM Subject: Re: Unexpected "Exiting normally" 2.1.8?

Craig Campbell <craig@ccraft.ca> wrote:

...

[snipped]

I then ran the code from within gdb as Alexander described (within screen - thanks!)

gdb radiusd (gdb) run -f <messages program runs until...> Detaching after fork from child process 14277. Detaching after fork from child process 14334. Detaching after fork from child process 14364. Detaching after fork from child process 14394. Detaching after fork from child process 14424.

Program received signal SIGTERM, Terminated. 0x0000003acf4306a7 in kill () from /lib64/libc.so.6 (gdb) where #0 0x0000003acf4306a7 in kill () from /lib64/libc.so.6 #1 0x0000000000424186 in main (argc=2, argv=0x7fff67ce72d8) at radiusd.c:419 (gdb)

The gdb output is identical for the other radius server.

I'm afraid I haven't helped much. The source I have was acquired Oct 20 15:05 (EST) if that helps in any way. Perhaps I have fewer of the suspected patches in my build than you have in yours? Is there a way we could compare?

Is there any way I can get more information out of these test runs?

Afraid that is all there is to see. If this was a more 'interesting' bug you would get a lot more, but the nature of this particular bug means you do not get much.

Now you have the compiling of FreeRADIUS working and got a successful round of GDB cooking, you need to play with 'git bisect' to pin it down to which patch broke things.

Cheers

-- Alexander Clouter .sigmonster says: You have many friends and very few living enemies.

- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

__________ Information from ESET Smart Security, version of virus signature database 4578 (20091106) __________

The message was checked by ESET Smart Security.

http://www.eset.com

__________ Information from ESET Smart Security, version of virus signature database 4579 (20091106) __________ The message was checked by ESET Smart Security. http://www.eset.com

I'm afraid I did something incorrect. I ended up with, gcc -o .libs/radmin .libs/radmin.o /usr/lib/libreadline.so /usr/lib/libtermcap.so .libs/util.o .libs/log.o .libs/conffile.o /home/craig/src/freeradius/freeradius-server/src/lib/.libs/libfreeradius-radius.so -lnsl -lresolv -lpthread -lreadline -ltermcap -Wl,--rpath -Wl,/usr/local/lib /usr/lib/libreadline.so: could not read symbols: File in wrong format collect2: ld returned 1 exit status Which I suspect is result of my git bisect attempts.... $git bisect start $git bisect bad $git bisect good 9261f3e0026323b2c397af13d02fbc5780908143 $git bisect loggit bisect start # bad: [1489f5ffa5835e001499ee4f7a5f50a0da375613] Conf for debugging git bisect bad 1489f5ffa5835e001499ee4f7a5f50a0da375613 # good: [9261f3e0026323b2c397af13d02fbc5780908143] Ensure that there is a cleanup event for proxied packets git bisect good 9261f3e0026323b2c397af13d02fbc5780908143 # good: [9261f3e0026323b2c397af13d02fbc5780908143] Ensure that there is a cleanup event for proxied packets git bisect good 9261f3e0026323b2c397af13d02fbc5780908143 $git bisect next $CFLAGS='-O0 -g' ./configure $make clean $make ..... gcc -o .libs/radmin .libs/radmin.o /usr/lib/libreadline.so /usr/lib/libtermcap.so .libs/util.o .libs/log.o .libs/conffile.o /home/craig/src/freeradius/freeradius-server/src/lib/.libs/libfreeradius-radius.so -lnsl -lresolv -lpthread -lreadline -ltermcap -Wl,--rpath -Wl,/usr/local/lib /usr/lib/libreadline.so: could not read symbols: File in wrong format collect2: ld returned 1 exit status ----- Original Message ----- From: "Alexander Clouter" <alex@digriz.org.uk> To: <freeradius-users@lists.freeradius.org> Sent: Friday, November 06, 2009 10:15 AM Subject: Re: Unexpected "Exiting normally" 2.1.8?

Craig Campbell <craig@ccraft.ca> wrote:

...

Regarding git bisect. I know the current version is "bad", but I have no idea if any 2.1.8 version is 'Good'.

If there a way to use git bisect without identifying 'good'? How can we find the first version? Can we assume it was 'good'?

Sorry to be so non knowledgeable about git.

Please read my original email listing all the git cherry picks that I used.

Cheers

-- Alexander Clouter .sigmonster says: Logic is a pretty flower that smells bad.

- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

__________ Information from ESET Smart Security, version of virus signature database 4579 (20091106) __________

The message was checked by ESET Smart Security.

http://www.eset.com

__________ Information from ESET Smart Security, version of virus signature database 4579 (20091106) __________ The message was checked by ESET Smart Security. http://www.eset.com

Craig Campbell wrote:

I was able to get some bisect runs (I think). However, I am encountering a different error in these.

If radiusd is run in multithreaded mode, it hangs shortly after beginning. This particular error has already been fixed (later).

Use a system that supports recursive mutexes.

Do you know if the Signal/Exit error depends upon multi threading? i.e will it happen if run with the -s option?

It depends on multithreading. Alan DeKok.

Craig Campbell wrote:

Still running tests with bisect.

successful runs take some time to identify (a day).

Please let me know if the bug is identified, otherwise I'll keep plugging away.

Thanks. Once we know the commit, the fix should hopefully be easy. Alan DeKok.

Craig Campbell wrote:

Ok, I hope this is helpful. Below please find the git bisect log. There were a number of iterations with make errors which I then skipped. I suspect the errors were OS specific and were clearly fixed in later iterations.

-bash-3.2$ git bisect log git bisect start # bad: [9dbc8974fdd2300a70293eda9c62bce20a3c9165] errormsg may be NULL

Huh... Since that commit doesn't help the reported bug, it's likely best to just revert it. Oh well. Alan DeKok.

Craig Campbell wrote:

Once you have another version (reverted), I can test again...

I am really unfamiliar with git, so I may need a hint as to getting the correct version for testing.

I've reverted the problem commit. It doesn't fix the PostgreSQL issue, and it causes other problems. The fix is now in the "stable" branch. Alan DeKok.

Craig Campbell wrote:

Thanks Alan, I re -acquired the source, but there seems to be a (minor I think) error.

$git clone git://git.freeradius.org/freeradius-server.git $cd freeradius-server $git fetch origin stable:stable $git pull

No. See http://git.freeradius.org for the exact commands. $ git checkout stable Alan DeKok.

Hi, Craig Campbell <craig@ccraft.ca> wrote:

I re -acquired the source, but there seems to be a (minor I think) error.

$git clone git://git.freeradius.org/freeradius-server.git $cd freeradius-server $git fetch origin stable:stable $git pull <----- should be 'git checkout stable' $make clean $CFLAGS='-O0 -g' ./configure $make

Otherwise if I am reading that right you are trying to compile off the unstable branch. Cheers -- Alexander Clouter .sigmonster says: BOFH excuse #169: broadcast packets on wrong frequency

Ok, can anyone identify a certain "GOOD" build to use for the git bisect? (Say where 2.1.7 was released?) I looked through the logs and have arbitrarily selected, 134f314c57d67b56bab93db4089c25e956ad6cf2] Lots of notes prior to 2.1.7 I do not know how to force git to build that revision so I could actually verify it is good. Thanks, -craig ----- Original Message ----- From: "Craig Campbell" <craig@ccraft.ca> To: "FreeRadius users mailing list" <freeradius-users@lists.freeradius.org> Sent: Tuesday, November 24, 2009 7:28 AM Subject: Re: Unexpected "Exiting normally" 2.1.8?

Thanks for the correction.

I have rebuilt and am re-running my test. I just hope I didn't somehow taint the bisect work and provide misleading information to Alan.

I should know some time today if I need to redo the bisection. For my previous work I had done,

$git bisect start $git bisect bad $git bisect good 321c0ae58641f709d115526bb564cbd8c4dab71d <- I do not have full confidence in this

Followed by loops of , $./conf $CFLAGS='-O0 -g' ./configure $make clean $find . -name "*.o" <- sometimes I found lingering .o files - not certain why. I would delete any I discovered at this point $make $git bisect skip|bad|good <- depending on if build failed, binary crashed or other error (skip), had error (bad), or succeeded(good) $git pull <- I THINK this may be unnecessary.. but not certain. Docs I found on git were not entirely clear

If I need to re-bisect, could you perhaps spoon feed me the commands to ensure I'm doing it correctly? Specifically, how can I acquire and verify I have my first "good" build? And then the incantation to perform iterative bisections until I run out.

I truly hope I haven't provided misleading info.

Thanks, -craig ----- Original Message ----- From: "Alexander Clouter" <alex@digriz.org.uk> To: <freeradius-users@lists.freeradius.org> Sent: Monday, November 23, 2009 8:13 AM Subject: Re: Unexpected "Exiting normally" 2.1.8?

...

Hi,

Craig Campbell <craig@ccraft.ca> wrote:

...

I re -acquired the source, but there seems to be a (minor I think) error.

$git clone git://git.freeradius.org/freeradius-server.git $cd freeradius-server $git fetch origin stable:stable $git pull <----- should be 'git checkout stable' $make clean $CFLAGS='-O0 -g' ./configure $make

Otherwise if I am reading that right you are trying to compile off the unstable branch.

Cheers

-- Alexander Clouter .sigmonster says: BOFH excuse #169: broadcast packets on wrong frequency

- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

__________ Information from ESET Smart Security, version of virus signature database 4630 (20091123) __________

The message was checked by ESET Smart Security.

http://www.eset.com

__________ Information from ESET Smart Security, version of virus signature database 4632 (20091124) __________

The message was checked by ESET Smart Security.

http://www.eset.com

- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

__________ Information from ESET Smart Security, version of virus signature database 4632 (20091124) __________

The message was checked by ESET Smart Security.

http://www.eset.com

__________ Information from ESET Smart Security, version of virus signature database 4635 (20091125) __________ The message was checked by ESET Smart Security. http://www.eset.com

Craig Campbell wrote:

Ok, can anyone identify a certain "GOOD" build to use for the git bisect? (Say where 2.1.7 was released?)

I looked through the logs and have arbitrarily selected, 134f314c57d67b56bab93db4089c25e956ad6cf2] Lots of notes prior to 2.1.7

I do not know how to force git to build that revision so I could actually verify it is good.

You could always try building it by hand. Also, when running it in gdb, try: (gdb) break radius_signal_self (gdb) cond 1 (flag == 2) (gdb) run That should catch the case where it's been told to exit. That should be the *only* case where it exits the event loop. Alan DeKok.

Bjørn Mork wrote:

I am now seeing this very same problem, and strongly suspect it to be related to dead proxy home servers. I was able to provoke the "Exiting normally" on a server with *no* traffic at all, by doing a couple of requests for a realm with dead home servers and then waiting:

Wed Nov 25 18:03:56 2009 : Error: PROXY: Marking home server 88.a.b.158 port 1812 as zombie (it looks like it is dead). Wed Nov 25 18:04:35 2009 : Error: PROXY: Marking home server 84.c.d.222 port 1812 as zombie (it looks like it is dead). Wed Nov 25 19:38:13 2009 : Info: Exiting normally.

No requests at all were sent to this server between the two last log lines.

Hmm... the "exiting normally" means that it received a signal to exit (internal or external). Otherwise, it just keeps running. Try using gdb, and: (gdb) break event_loop_exit (gdb) break radius_signal_self (gdb) cond 1 (flag == 2) (gdb) run And then when it stops: (gdb) thread apply all bt full That *should* catch the stack trace where it exits.

I was planning to use the 2.1.7 release, but hit the recursive mutex problem.

Ugh. Some systems don't support recursive mutexes, and even better, don't complain when you try to use them!

Now, adding the two facts, I'm starting to wonder whether the "Exiting normally" bug might be related to the fix for the recursive mutexes? They are both related to dead home servers. Makes me suspicious...

Quite possibly, yes. But the fact that it exits a minute and a half after the last packet is odd.

And I'm wondering what my other options are wrt the mutex problem. I am pretty much stuch with RHEL on these servers (not my choice). Is this a glibc 2.5 problem? Should I demand an upgrade to a more modern OS?

Let's wait for the back trace. Alan DeKok.

Alan DeKok <aland@deployingradius.com> writes:

Bjørn Mork wrote:

...

I am now seeing this very same problem, and strongly suspect it to be related to dead proxy home servers. I was able to provoke the "Exiting normally" on a server with *no* traffic at all, by doing a couple of requests for a realm with dead home servers and then waiting:

Wed Nov 25 18:03:56 2009 : Error: PROXY: Marking home server 88.a.b.158 port 1812 as zombie (it looks like it is dead). Wed Nov 25 18:04:35 2009 : Error: PROXY: Marking home server 84.c.d.222 port 1812 as zombie (it looks like it is dead). Wed Nov 25 19:38:13 2009 : Info: Exiting normally.

No requests at all were sent to this server between the two last log lines.

Hmm... the "exiting normally" means that it received a signal to exit (internal or external). Otherwise, it just keeps running.

Try using gdb, and:

(gdb) break event_loop_exit

I don't have that symbol. Did you mean fr_event_loop_exit? Anyway, I ran the server (this time a lab-/test-server with some traffic but nothing near any real load) using Breakpoint 1, radius_signal_self (flag=2) at event.c:3733 3733 event.c: No such file or directory. in event.c (gdb) cont Continuing. Breakpoint 2, fr_event_loop_exit (el=0x8e3c4d0, code=2) at event.c:309 309 event.c: No such file or directory. in event.c This is still based on the stable tree with commit 2df19cf0024fd23d2906c13c0b01067076540871 as the last one. And I got: Program received signal SIGTERM, Terminated. 0x000000390d8306f7 in kill () from /lib64/libc.so.6 (gdb) thread apply all bt full Thread 22 (Thread 0x4d189940 (LWP 23437)): #0 0x000000390e40c9b1 in sem_wait () from /lib64/libpthread.so.0 No symbol table info available. #1 0x000000000042632e in request_handler_thread (arg=0x1035f830) at threads.c:453 fun = (RAD_REQUEST_FUNP) 0x4080d8 <rad_accounting> self = (THREAD_HANDLE *) 0x1035f830 #2 0x000000390e4064a7 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #3 0x000000390d8d3c2d in clone () from /lib64/libc.so.6 No symbol table info available. Thread 20 (Thread 0x4bd87940 (LWP 23435)): #0 0x000000390e40c9b1 in sem_wait () from /lib64/libpthread.so.0 No symbol table info available. #1 0x000000000042632e in request_handler_thread (arg=0x1035f530) at threads.c:453 fun = (RAD_REQUEST_FUNP) 0x4094c7 <rad_authenticate> self = (THREAD_HANDLE *) 0x1035f530 #2 0x000000390e4064a7 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #3 0x000000390d8d3c2d in clone () from /lib64/libc.so.6 No symbol table info available. Thread 17 (Thread 0x49f84940 (LWP 23432)): #0 0x000000390e40c9b1 in sem_wait () from /lib64/libpthread.so.0 No symbol table info available. #1 0x000000000042632e in request_handler_thread (arg=0x1035f0b0) at threads.c:453 fun = (RAD_REQUEST_FUNP) 0x4094c7 <rad_authenticate> self = (THREAD_HANDLE *) 0x1035f0b0 #2 0x000000390e4064a7 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #3 0x000000390d8d3c2d in clone () from /lib64/libc.so.6 No symbol table info available. Thread 14 (Thread 0x48181940 (LWP 23429)): #0 0x000000390e40c9b1 in sem_wait () from /lib64/libpthread.so.0 No symbol table info available. #1 0x000000000042632e in request_handler_thread (arg=0x1035ec30) at threads.c:453 fun = (RAD_REQUEST_FUNP) 0x4080d8 <rad_accounting> self = (THREAD_HANDLE *) 0x1035ec30 #2 0x000000390e4064a7 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #3 0x000000390d8d3c2d in clone () from /lib64/libc.so.6 No symbol table info available. Thread 12 (Thread 0x46d7f940 (LWP 23427)): #0 0x000000390e40c9b1 in sem_wait () from /lib64/libpthread.so.0 No symbol table info available. #1 0x000000000042632e in request_handler_thread (arg=0x1035e930) at threads.c:453 fun = (RAD_REQUEST_FUNP) 0x4080d8 <rad_accounting> self = (THREAD_HANDLE *) 0x1035e930 #2 0x000000390e4064a7 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #3 0x000000390d8d3c2d in clone () from /lib64/libc.so.6 No symbol table info available. Thread 10 (Thread 0x4597d940 (LWP 23425)): #0 0x000000390e40c9b1 in sem_wait () from /lib64/libpthread.so.0 No symbol table info available. #1 0x000000000042632e in request_handler_thread (arg=0x1035e630) at threads.c:453 fun = (RAD_REQUEST_FUNP) 0x4094c7 <rad_authenticate> self = (THREAD_HANDLE *) 0x1035e630 #2 0x000000390e4064a7 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #3 0x000000390d8d3c2d in clone () from /lib64/libc.so.6 No symbol table info available. Thread 3 (Thread 0x41d77940 (LWP 23418)): #0 0x000000390e40c9b1 in sem_wait () from /lib64/libpthread.so.0 No symbol table info available. #1 0x000000000042632e in request_handler_thread (arg=0x1035dcf0) at threads.c:453 fun = (RAD_REQUEST_FUNP) 0x4094c7 <rad_authenticate> self = (THREAD_HANDLE *) 0x1035dcf0 #2 0x000000390e4064a7 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #3 0x000000390d8d3c2d in clone () from /lib64/libc.so.6 No symbol table info available. Thread 1 (Thread 0x2ad516d82e70 (LWP 23315)): #0 0x000000390d8306f7 in kill () from /lib64/libc.so.6 No symbol table info available. #1 0x0000000000423b6a in main (argc=4, argv=0x7fffecacbef8) at radiusd.c:419 rcode = 0 argval = -1 spawn_flag = 1 dont_fork = 1 flag = 0 act = {__sigaction_handler = {sa_handler = 0x423d41 <sig_fatal>, sa_sigaction = 0x423d41 <sig_fatal>}, sa_mask = {__val = { 0 <repeats 16 times>}}, sa_flags = 0, sa_restorer = 0} (gdb) (gdb) cont Continuing. [Thread 0x4bd87940 (LWP 23435) exited] [Thread 0x49f84940 (LWP 23432) exited] [Thread 0x48181940 (LWP 23429) exited] [Thread 0x46d7f940 (LWP 23427) exited] [Thread 0x4597d940 (LWP 23425) exited] [Thread 0x41d77940 (LWP 23418) exited] [Thread 0x4d189940 (LWP 23437) exited] Program exited with code 0377. Don't know if that helped anything at all? Bjørn

With the info you need (I hope)... [root@radius-a ~]# gdb radiusd GNU gdb Fedora (6.8-27.el5) Copyright (C) 2008 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html> This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-redhat-linux-gnu"... (gdb) break event_loop_exit Function "event_loop_exit" not defined. Make breakpoint pending on future shared library load? (y or [n]) y Breakpoint 1 (event_loop_exit) pending. (gdb) break radius_signal_self Breakpoint 2 at 0x434d9f: file event.c, line 3733. (gdb) cond 1 (flag == 2) (gdb) run -f Starting program: /usr/local/sbin/radiusd -f Error in re-setting breakpoint 1: Function "event_loop_exit" not defined. [Thread debugging using libthread_db enabled] [New Thread 0x2b9e812b4e10 (LWP 5870)] [New Thread 0x4106d940 (LWP 5878)] [New Thread 0x41a6e940 (LWP 5879)] [New Thread 0x4246f940 (LWP 5880)] [New Thread 0x42e70940 (LWP 5881)] [New Thread 0x43871940 (LWP 5882)] Detaching after fork from child process 5884. <snip> Detaching after fork from child process 7376. [New Thread 0x44272940 (LWP 7379)] [New Thread 0x44c73940 (LWP 7380)] [New Thread 0x45674940 (LWP 7381)] Detaching after fork from child process 7382. <snip> Detaching after fork from child process 9604. [Switching to Thread 0x45674940 (LWP 7381)] Breakpoint 2, radius_signal_self (flag=8) at event.c:3733 3733 rcode = read(self_pipe[0], buffer, sizeof(buffer)); (gdb) bt #0 radius_signal_self (flag=8) at event.c:3733 #1 0x000000000043d12f in detail_send (listener=0x11534860, request=0x2aaaac00f650) at detail.c:119 #2 0x0000000000432902 in request_post_handler (request=0x2aaaac00f650) at event.c:2523 #3 0x0000000000435741 in radius_handle_request (request=0x2aaaac00f650, fun=0x408108 <rad_accounting>) at event.c:4092 #4 0x0000000000426bd6 in request_handler_thread (arg=0x2aaaac001420) at threads.c:492 #5 0x0000003ad0006367 in start_thread () from /lib64/libpthread.so.0 #6 0x0000003acf4d30ad in clone () from /lib64/libc.so.6 (gdb) thread apply all bt full Thread 9 (Thread 0x45674940 (LWP 7381)): #0 radius_signal_self (flag=8) at event.c:3733 rcode = 0 buffer = "@<gE\000\000\000\000²(\001Ï:\000\000" #1 0x000000000043d12f in detail_send (listener=0x11534860, request=0x2aaaac00f650) at detail.c:119 rtt = 0 now = {tv_sec = 290127440, tv_usec = 0} data = (listen_detail_t *) 0x115348f0 #2 0x0000000000432902 in request_post_handler (request=0x2aaaac00f650) at event.c:2523 child_state = 6 when = {tv_sec = 8589934594, tv_usec = 46912518551120} vp = (VALUE_PAIR *) 0x0 #3 0x0000000000435741 in radius_handle_request (request=0x2aaaac00f650, fun=0x408108 <rad_accounting>) at event.c:4092 No locals. #4 0x0000000000426bd6 in request_handler_thread (arg=0x2aaaac001420) at threads.c:492 fun = (RAD_REQUEST_FUNP) 0x408108 <rad_accounting> self = (THREAD_HANDLE *) 0x2aaaac001420 #5 0x0000003ad0006367 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #6 0x0000003acf4d30ad in clone () from /lib64/libc.so.6 No symbol table info available. Thread 8 (Thread 0x44c73940 (LWP 7380)): #0 0x0000003ad000c6b1 in sem_wait () from /lib64/libpthread.so.0 No symbol table info available. #1 0x0000000000426abb in request_handler_thread (arg=0x2aaaac002580) at threads.c:453 fun = (RAD_REQUEST_FUNP) 0x408108 <rad_accounting> self = (THREAD_HANDLE *) 0x2aaaac002580 #2 0x0000003ad0006367 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #3 0x0000003acf4d30ad in clone () from /lib64/libc.so.6 No symbol table info available. Thread 7 (Thread 0x44272940 (LWP 7379)): #0 0x0000003ad000c6b1 in sem_wait () from /lib64/libpthread.so.0 No symbol table info available. #1 0x0000000000426abb in request_handler_thread (arg=0x2aaaac001140) at threads.c:453 fun = (RAD_REQUEST_FUNP) 0x408108 <rad_accounting> self = (THREAD_HANDLE *) 0x2aaaac001140 #2 0x0000003ad0006367 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #3 0x0000003acf4d30ad in clone () from /lib64/libc.so.6 No symbol table info available. Thread 6 (Thread 0x43871940 (LWP 5882)): #0 0x0000003ad000c6b1 in sem_wait () from /lib64/libpthread.so.0 No symbol table info available. ---Type <return> to continue, or q <return> to quit--- #1 0x0000000000426abb in request_handler_thread (arg=0x11533bd0) at threads.c:453 fun = (RAD_REQUEST_FUNP) 0x408108 <rad_accounting> self = (THREAD_HANDLE *) 0x11533bd0 #2 0x0000003ad0006367 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #3 0x0000003acf4d30ad in clone () from /lib64/libc.so.6 No symbol table info available. Thread 5 (Thread 0x42e70940 (LWP 5881)): #0 0x0000003ad000c6b1 in sem_wait () from /lib64/libpthread.so.0 No symbol table info available. #1 0x0000000000426abb in request_handler_thread (arg=0x11533a50) at threads.c:453 fun = (RAD_REQUEST_FUNP) 0x408108 <rad_accounting> self = (THREAD_HANDLE *) 0x11533a50 #2 0x0000003ad0006367 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #3 0x0000003acf4d30ad in clone () from /lib64/libc.so.6 No symbol table info available. Thread 4 (Thread 0x4246f940 (LWP 5880)): #0 0x0000003ad000c6b1 in sem_wait () from /lib64/libpthread.so.0 No symbol table info available. #1 0x0000000000426abb in request_handler_thread (arg=0x115338d0) at threads.c:453 fun = (RAD_REQUEST_FUNP) 0x408108 <rad_accounting> self = (THREAD_HANDLE *) 0x115338d0 #2 0x0000003ad0006367 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #3 0x0000003acf4d30ad in clone () from /lib64/libc.so.6 No symbol table info available. Thread 3 (Thread 0x41a6e940 (LWP 5879)): #0 0x0000003ad000c6b1 in sem_wait () from /lib64/libpthread.so.0 No symbol table info available. #1 0x0000000000426abb in request_handler_thread (arg=0x11533750) at threads.c:453 fun = (RAD_REQUEST_FUNP) 0x408108 <rad_accounting> self = (THREAD_HANDLE *) 0x11533750 #2 0x0000003ad0006367 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #3 0x0000003acf4d30ad in clone () from /lib64/libc.so.6 No symbol table info available. Thread 2 (Thread 0x4106d940 (LWP 5878)): #0 0x0000003ad000c6b1 in sem_wait () from /lib64/libpthread.so.0 No symbol table info available. #1 0x0000000000426abb in request_handler_thread (arg=0x11532620) at threads.c:453 fun = (RAD_REQUEST_FUNP) 0x408108 <rad_accounting> self = (THREAD_HANDLE *) 0x11532620 #2 0x0000003ad0006367 in start_thread () from /lib64/libpthread.so.0 ---Type <return> to continue, or q <return> to quit--- No symbol table info available. #3 0x0000003acf4d30ad in clone () from /lib64/libc.so.6 No symbol table info available. Thread 1 (Thread 0x2b9e812b4e10 (LWP 5870)): #0 0x0000003acf4cc5f2 in select () from /lib64/libc.so.6 No symbol table info available. #1 0x00002b9e80e7fa4c in fr_event_loop (el=0x1151b7f0) at event.c:379 i = 5 rcode = 0 when = {tv_sec = 0, tv_usec = 617790} wake = (struct timeval *) 0x7fff29c4b000 read_fds = {fds_bits = {122944, 0 <repeats 15 times>}} #2 0x00000000004355b3 in radius_event_process () at event.c:4072 No locals. #3 0x0000000000424124 in main (argc=2, argv=0x7fff29c4b248) at radiusd.c:398 rcode = 58 argval = -1 spawn_flag = 1 dont_fork = 1 flag = 0 act = {__sigaction_handler = {sa_handler = 0x424349 <sig_fatal>, sa_sigaction = 0x424349 <sig_fatal>}, sa_mask = { __val = {0 <repeats 16 times>}}, sa_flags = 0, sa_restorer = 0} 3733 rcode = read(self_pipe[0], buffer, sizeof(buffer)); (gdb) I haven't quit gdb yet, so let me know if you need more... Thanks, -craig ----- Original Message ----- From: "Alan DeKok" <aland@deployingradius.com> To: "FreeRadius users mailing list" <freeradius-users@lists.freeradius.org> Sent: Thursday, November 26, 2009 7:36 AM Subject: Re: Unexpected "Exiting normally" 2.1.8?

Bjørn Mork wrote:

...

I don't have that symbol. Did you mean fr_event_loop_exit?

Sure.

...

Anyway, I ran the server (this time a lab-/test-server with some traffic but nothing near any real load) using

Breakpoint 1, radius_signal_self (flag=2) at event.c:3733 3733 event.c: No such file or directory. in event.c (gdb) cont

Arg... PLEASE give the stack trace for this! "bt", or "thread apply all bt full".

Simply continuing means that you've ignored the break point.

...

And I got:

The same stack trace as before, LONG after the useful information has been lost.

Alan DeKok.

- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

__________ Information from ESET Smart Security, version of virus signature database 4636 (20091125) __________ The message was checked by ESET Smart Security. http://www.eset.com

Alan DeKok <aland@deployingradius.com> writes:

Bjørn Mork wrote:

...

I don't have that symbol. Did you mean fr_event_loop_exit?

Sure.

...

Anyway, I ran the server (this time a lab-/test-server with some traffic but nothing near any real load) using

Breakpoint 1, radius_signal_self (flag=2) at event.c:3733 3733 event.c: No such file or directory. in event.c (gdb) cont

Arg... PLEASE give the stack trace for this! "bt", or "thread apply all bt full".

Simply continuing means that you've ignored the break point.

Sorry, that was a mere cut'n paste error from an initial test (no the actual bug, just tested that I'd actually break on SIGTERM). I apologise for the confusion this caused.

...

And I got:

The same stack trace as before, LONG after the useful information has been lost.

Yes. Just to be sure, I've repeated the process and the trace is the same: Useless: (gdb) bt full #0 0x000000390d8306f7 in kill () from /lib64/libc.so.6 No symbol table info available. #1 0x0000000000423b6a in main (argc=4, argv=0x7fff3ada9b18) at radiusd.c:419 rcode = 0 argval = -1 spawn_flag = 1 dont_fork = 1 flag = 0 act = {__sigaction_handler = {sa_handler = 0x423d41 <sig_fatal>, sa_sigaction = 0x423d41 <sig_fatal>}, sa_mask = {__val = { 0 <repeats 16 times>}}, sa_flags = 0, sa_restorer = 0} Which I guess tells us that there is some other path here than through fr_event_loop_exit and radius_signal_self with flag==2? What that could possibly be is beyond my imagination, I must admit... Bjørn

Alan DeKok <aland@deployingradius.com> writes:

Bjørn Mork wrote:

...

Yes. Just to be sure, I've repeated the process and the trace is the same: Useless: ... Which I guess tells us that there is some other path here than through fr_event_loop_exit and radius_signal_self with flag==2?

For the life of me, I can't see another path through the code.

Are you sending it period HUPs?

No

The only other possibility is some memory over-write. You should use gdb...

$ gdb --args radiusd -f (gdb) break fr_event_loop (gdb) run (gdb) watch el->exit (gdb) del 1 (gdb) cont ... (gdb) bt

That should cause it to stop as soon as *anything* stomps on the event loop flag that says "stop the event loop"

Will do. However, I think I found one other possibility. This code in fr_event_loop() will exit if the select() fails: rcode = select(el->maxfd + 1, &read_fds, NULL, NULL, wake); if ((rcode < 0) && (errno != EINTR)) { el->dispatch = 0; return 0; } Might this happen due to a dead home server fd in the &read_fds? Bjørn

Ok, here is (I think) the debug you wanted. -craig [root@radius-a ~]# gdb radiusd GNU gdb Fedora (6.8-27.el5) Copyright (C) 2008 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html> This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-redhat-linux-gnu"... (gdb) break fr_event_loop Function "fr_event_loop" not defined. Make breakpoint pending on future shared library load? (y or [n]) y Breakpoint 1 (fr_event_loop) pending. (gdb) run -f Starting program: /usr/local/sbin/radiusd -f [Thread debugging using libthread_db enabled] [New Thread 0x2b5c60c5ee10 (LWP 23494)] [New Thread 0x4253c940 (LWP 23502)] [New Thread 0x42f3d940 (LWP 23503)] [New Thread 0x4393e940 (LWP 23504)] [New Thread 0x4433f940 (LWP 23505)] [New Thread 0x44d40940 (LWP 23506)] Breakpoint 1, fr_event_loop (el=0x1d94e7f0) at event.c:321 321 el->exit = 0; (gdb) watch el->exit Hardware watchpoint 2: el->exit (gdb) del 1 (gdb) cont Continuing. Watchpoint 2 deleted because the program has left the block in which its expression is valid. [Switching to Thread 0x4433f940 (LWP 23505)] 0x0000003acf499845 in fork () from /lib64/libc.so.6 (gdb) bt #0 0x0000003acf499845 in fork () from /lib64/libc.so.6 #1 0x000000000041104c in radius_exec_program (cmd=0x1d988a60 "/usr/local/sbin/acctstop.sh", request=0x1d9732f0, exec_wait=0, user_msg=0x0, msg_len=254, input_pairs=0x1d985fe0, output_pairs=0x0, shell_escape=1) at exec.c:274 #2 0x00002b5c60e6cf58 in exec_xlat (instance=0x1d8e90b0, request=0x1d9732f0, fmt=0x1d988a60 "/usr/local/sbin/acctstop.sh", out=0x4433df60 "", outlen=254, func=0x42bd95 <xlat_copy>) at rlm_exec.c:138 #3 0x000000000042bbd0 in decode_attribute (from=0x4433def0, to=0x4433dee8, freespace=254, open_p=0x4433de7c, request=0x1d9732f0, func=0x42bd95 <xlat_copy>) at xlat.c:911 #4 0x000000000042c0a1 in radius_xlat (out=0x4433df60 "", outlen=254, fmt=0x1d988818 "%{exec:/usr/local/sbin/acctstop.sh}", request=0x1d9732f0, func=0x42bd95 <xlat_copy>) at xlat.c:1086 #5 0x0000000000429613 in pairxlatmove (req=0x1d9732f0, to=0x1d9734a8, from=0x4433e238) at valuepair.c:587 #6 0x00002b5c632b993f in file_common (inst=0x1d90bb20, request=0x1d9732f0, filename=0x2b5c632b9e8e "acct_users", ht=0x1d90bdb0, request_pairs=0x1d985fe0, reply_pairs=0x1d9734a8) at rlm_files.c:472 #7 0x00002b5c632b9a66 in file_preacct (instance=0x1d90bb20, request=0x1d9732f0) at rlm_files.c:525 #8 0x0000000000420443 in call_modsingle (component=2, sp=0x1d94c8d0, request=0x1d9732f0) at modcall.c:297 #9 0x000000000042126b in modcall (component=2, c=0x1d94bcf0, request=0x1d9732f0) at modcall.c:669 #10 0x000000000041ea4f in indexed_modcall (comp=2, idx=0, request=0x1d9732f0) at modules.c:691 #11 0x000000000041fdb6 in module_preacct (request=0x1d9732f0) at modules.c:1470 #12 0x000000000040813c in rad_accounting (request=0x1d9732f0) at acct.c:57 #13 0x00000000004356b5 in radius_handle_request (request=0x1d9732f0, fun=0x408108 <rad_accounting>) at event.c:4086 #14 0x0000000000426bd6 in request_handler_thread (arg=0x1d966a50) at threads.c:492 #15 0x0000003ad0006367 in start_thread () from /lib64/libpthread.so.0 #16 0x0000003acf4d30ad in clone () from /lib64/libc.so.6 (gdb) thread apply all bt full Thread 6 (Thread 0x44d40940 (LWP 23506)): #0 0x0000003acf4dee6e in __lll_lock_wait_private () from /lib64/libc.so.6 No symbol table info available. #1 0x0000003acf476668 in _L_lock_12629 () from /lib64/libc.so.6 No symbol table info available. #2 0x0000003acf47477f in malloc_atfork () from /lib64/libc.so.6 No symbol table info available. #3 0x00002b5c60823dab in pairalloc (da=0x1d8d4df8) at valuepair.c:72 name_len = 0 vp = (VALUE_PAIR *) 0x44d3df90 #4 0x00002b5c60826302 in pairmake (attribute=0x2b5c640d42df "Acct-Unique-Session-Id", value=0x44d3e280 "2d5f2bbb0937b3b9", operator=0) at valuepair.c:1462 da = (DICT_ATTR *) 0x1d8d4df8 vp = (VALUE_PAIR *) 0x0 tc = 0x0 ts = 0x0 tag = 0 '\0' found_tag = 0 buffer = "\200âÓD\000\000\000\000pâÓD", '\0' <repeats 51 times> attrname = 0x2b5c640d42df "Acct-Unique-Session-Id" #5 0x00002b5c640d40ad in add_unique_id (instance=0x1d94aec0, request=0x1d972e90) at rlm_acct_unique.c:241 buffer = "2d5f2bbb0937b3b9\0009365,Client-IP-Address = 192.168.1.101,NAS-IP-Address = 192.168.1.101,Acct-Session-Id = \"0360078311\",User-Name = \"jpoduber@comfort\"", '\0' <repeats 1988 times>, "\030\a\aa\\+\000\000\000\000\000\000\000\000\000\000øE\230\035\000\000\000\000x\210\224\035\000\000\000\000\001\000\000\000ì\003\000\000\000\000"... md5_buf = "-_+»\t7³¹ÓôÏ\001bà>!" vp = (VALUE_PAIR *) 0x1d9845c0 p = 0x44d3e315 "" length = 30 left = 3947 inst = (rlm_acct_unique_t *) 0x1d94aec0 cur = (rlm_acct_unique_list_t *) 0x0 #6 0x0000000000420443 in call_modsingle (component=2, sp=0x1d94c7b0, request=0x1d972e90) at modcall.c:297 myresult = 0 #7 0x000000000042126b in modcall (component=2, c=0x1d94bcf0, request=0x1d972e90) at modcall.c:669 myresult = 2 stack = {pointer = 1, priority = {0, 2, 0, 1619038256, 11100, 1154742640, 0, 1619037392, 11100, 1619051949, 11100, 0, 0, -822046142, 58, 0, 0, 0, 0, 5, 5, -814409280, 0, 494780720, 0, 1154742704, 0, 0, 0, -814409184, 0, 1154742704}, result = {7, 2, 0, 1154742544, 0, 1619086899, 11100, 1154742712, 0, 494819072, 0, 1154742704, 0, 1619068620, -1966049091, 494819072, 0, 494773456, 0, 494819072, 0, 1154742704, 0, 1154742608, 0, 1619088694, 11100, 1154742640, 0, 494819072, 0, 1154742704}, children = {0x1d94bcf0, 0x1d94c7b0, 0x8ad078bd00000b51, 0x44d3f990, 0x2b5c608155e5, 0x44d3f9a0, 0x1d7dc130, 0x44d3f9b0, 0x1d7da4d0, 0x44d3fa00, 0x1d7e5700, 0x44d3f9d0, 0xfe, 0x1d7dc138, 0x1d985c78, 0x10000002d, 0x1d985c7f, 0x1d7dc13f, 0xf7, 0x44d3fa60, 0x2b5c6081e050, 0xa00000, 0x2b5c60823dd9, 0x100000000, 0x1d985c40, 0x1d972e80, 0x4, 0x2d00000000, 0x1d8e6180, 0x0, 0x1d972d00, 0x1d985c40}, start = {0x2d00000005, 0x1d94bc60, 0x1d7dc130, 0x1d7dbf58, 0x139e0ca400000000, 0x14, 0x1d972d90, 0x1d972da4, 0x1d972da4, 0x44d3fac0, 0x2b5c6082009a, 0x14, 0x1d972d90, 0x0, 0x139e0ca4, 0x1d972da6, 0x1d985c40, 0x44d3fc30, 0x2b5c6081f143, 0x44d3fb70, 0x2b5c6081cce1, 0x1d8e6180, 0x404f5f, 0x11d8e6180, 0x100000001, 0x1, 0x1d8e6180, 0x0, 0x1d972d00, 0x0, 0x0, 0x0}} parent = (modcallable *) 0x1d94bcf0 ---Type <return> to continue, or q <return> to quit--- child = (modcallable *) 0x1d94c7b0 sp = (modsingle *) 0x1d94c7b0 if_taken = 0 was_if = 0 #8 0x000000000041ea4f in indexed_modcall (comp=2, idx=0, request=0x1d972e90) at modules.c:691 rcode = 0 list = (modcallable *) 0x1d94bcf0 server = (virtual_server_t *) 0x1d94a550 #9 0x000000000041fdb6 in module_preacct (request=0x1d972e90) at modules.c:1470 No locals. #10 0x000000000040813c in rad_accounting (request=0x1d972e90) at acct.c:57 vp = (VALUE_PAIR *) 0x1d972e90 acct_type = 0 result = 2 #11 0x00000000004356b5 in radius_handle_request (request=0x1d972e90, fun=0x408108 <rad_accounting>) at event.c:4086 No locals. #12 0x0000000000426bd6 in request_handler_thread (arg=0x1d966bd0) at threads.c:492 fun = (RAD_REQUEST_FUNP) 0x408108 <rad_accounting> self = (THREAD_HANDLE *) 0x1d966bd0 #13 0x0000003ad0006367 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #14 0x0000003acf4d30ad in clone () from /lib64/libc.so.6 No symbol table info available. Thread 5 (Thread 0x4433f940 (LWP 23505)): #0 0x0000003acf499845 in fork () from /lib64/libc.so.6 No symbol table info available. #1 0x000000000041104c in radius_exec_program (cmd=0x1d988a60 "/usr/local/sbin/acctstop.sh", request=0x1d9732f0, exec_wait=0, user_msg=0x0, msg_len=254, input_pairs=0x1d985fe0, output_pairs=0x0, shell_escape=1) at exec.c:274 vp = (VALUE_PAIR *) 0x0 mycmd = "/usr/local/sbin/acctstop.sh", '\0' <repeats 45 times>, "À\031uÏ:\000\000\000\b\032uÏ:\000\000\000\b\032uÏ:", '\0' <repeats 11 times>, " \032uÏ:", '\0' <repeats 11 times>, "\214ÄJÏ:", '\0' <repeats 11 times>, "àØ3D\000\000\000\000\220\212\230\035\000\000\000\000°\207\230\035\000\000\000\000È\003\000\000\000\000\000\000 \032\000\000\003\000\000\000`§3D\000\000\000\000x§3D\000\000\000\000\220§3D\000\000\000\000À·3D\000\000\000\000À§3D\000\000\000\000P\224\230\035\000\000\000\000\230\212\230\035\000\000\000\000\004\000\000\000\000\000"... from = 0x1d988a7b "" p = 0x44338b26 "=\"b59b7e5cef8e3cf2\"" to = 0x4433af30 "" pd = {0, 0} pid = 0 child_pid = 0 argc = 1 comma = 0 status = 0 i = 1 n = 23 left = 4096 done = 0 ---Type <return> to continue, or q <return> to quit--- argv = {0x4433d750 "/usr/local/sbin/acctstop.sh", 0x0, 0x100000138 <Address 0x100000138 out of bounds>, 0x0, 0x1d94c3f0 "¸\202\200`\\+", 0x4433d080 "h³\200`\\+", 0x1d94c090 "", 0x2b5c640d34b8 "pairadd", 0x4433d030 "", 0x28608131b8 <Address 0x28608131b8 out of bounds>, 0x1d8d4df8 "\033\004", 0x2b5c640d42df "Acct-Unique-Session-Id", 0x6465636e61766461 <Address 0x6465636e61766461 out of bounds>, 0x0, 0x696e552d74636341 <Address 0x696e552d74636341 out of bounds>, 0x3acf7519c0 "\001", 0x138 <Address 0x138 out of bounds>, 0xa00000 <Address 0xa00000 out of bounds>, 0x4433f940 "@ù3D", 0x1d9885a8 "", 0x0, 0x4433d290 "", 0x7e <Address 0x7e out of bounds>, 0x10 <Address 0x10 out of bounds>, 0xa00000 <Address 0xa00000 out of bounds>, 0x32002b5c60823dd9 <Address 0x32002b5c60823dd9 out of bounds>, 0x2b5c6080b368 "n\b", 0x2b5c60808cd0 "", 0x30 <Address 0x30 out of bounds>, 0xffffffff <Address 0xffffffff out of bounds>, 0x0, 0x2016f0 <Address 0x2016f0 out of bounds>, 0xa00000 <Address 0xa00000 out of bounds>, 0x4433f940 "@ù3D", 0x44340000 "", 0x1000 <Address 0x1000 out of bounds>, 0x2b5c640d3000 "\177ELF\002\001\001", 0x3acf00cd35 "I\211Àd\213\004%\030", 0x5 <Address 0x5 out of bounds>, 0x0, 0x4433d280 "b59b7e5cef8e3cf2", 0x4433d270 "µ\233~\\ï\216<ò_/qÞ¹/ähb59b7e5cef8e3cf2", 0x2b5c6080b368 "n\b", 0x7e <Address 0x7e out of bounds>, 0x4433e2c0 "\020ã3D", 0x3acf0128b2 "I\211ÃL\213L$0L\213D$(H\213|$ H\213t$\030H\213T$\020H\213L$\bH\213\004$H\203ÄHAÿãf\220H\203ìPH\211\004$H\211T$\bL\211D$\020L\211L$\030H\211L$ H\211t$(H\211|$0H\211l$8H\215D$`H\211D$@H\215L$\bH\213T$`H\213t$XI\211óL\001ÞL\001ÞHÁæ\003H\213|$PL\215D$HèÀ\235ÿÿI\211ÃH\213T$\bL\213D$\020L\213L$\030H\213\004$L\213T$HM\205Òy\026H\213L$ H\213t$(H\213|$0H\203Ä`AÿãH\211\\$"..., 0x1d973110 "\016", 0xffffffffffffffee <Address 0xffffffffffffffee out of bounds>, 0x1d988560 "\bN\215\035", 0x1d988560 "\bN\215\035", 0x1d988560 "\bN\215\035", 0x1d973178 "à_\230\035", 0x600000 <Address 0x600000 out of bounds>, 0x1d988420 "\bÀ}\035", 0x4433e2c0 "\020ã3D", 0x2b5c640d40fa "Ç\205\\îÿÿ\002", 0xef <Address 0xef out of bounds>, 0x8e <Address 0x8e out of bounds>, 0x3c <Address 0x3c out of bounds>, 0xf2 <Address 0xf2 out of bounds>, 0x0, 0x200000000 <Address 0x200000000 out of bounds>, 0x1d9732f0 "ï¾­Þ", 0x1d94aec0 "@Å\224\035", 0x1d8d4e38 "Client-IP-Address", 0x41c <Address 0x41c out of bounds>, 0x2 <Address 0x2 out of bounds>, 0x4 <Address 0x4 out of bounds>, 0xb <Address 0xb out of bounds>, 0x0, 0x6501a8c0 <Address 0x6501a8c0 out of bounds>, 0x0 <repeats 33 times>, 0xf23c8eef5c7e9bb5 <Address 0xf23c8eef5c7e9bb5 out of bounds>, 0x68e42fb9de712f5f <Address 0x68e42fb9de712f5f out of bounds>, 0x6335653762393562 <Address 0x6335653762393562 out of bounds>, 0x3266633365386665 <Address 0x3266633365386665 out of bounds>, 0x6c432c3536333900 <Address 0x6c432c3536333900 out of bounds>, 0x2d50492d746e6569 <Address 0x2d50492d746e6569 out of bounds>, 0x2073736572646441 <Address 0x2073736572646441 out of bounds>, 0x36312e323931203d <Address 0x36312e323931203d out of bounds>, 0x2c3130312e312e38 <Address 0x2c3130312e312e38 out of bounds>, 0x412d50492d53414e <Address 0x412d50492d53414e out of bounds>, 0x3d20737365726464 <Address 0x3d20737365726464 out of bounds>, 0x3836312e32393120 <Address 0x3836312e32393120 out of bounds>, 0x412c3130312e312e <Address 0x412c3130312e312e out of bounds>, 0x737365532d746363 <Address 0x737365532d746363 out of bounds>, 0x3d2064492d6e6f69 <Address 0x3d2064492d6e6f69 out of bounds>, 0x3334393533302220 <Address 0x3334393533302220 out of bounds>, 0x73552c2235383331 <Address 0x73552c2235383331 out of bounds>, 0x20656d614e2d7265 <Address 0x20656d614e2d7265 out of bounds>, 0x6f626c617622203d <Address 0x6f626c617622203d out of bounds>, 0x4064726176656c75 <Address 0x4064726176656c75 out of bounds>, 0x6465636e61766461 <Address 0x6465636e61766461 out of bounds>, 0x22 <Address 0x22 out of bounds>, 0x0 <repeats 62 times>, 0x100000000 <Address 0x100000000 out of bounds>, 0x1d985fe0 " ¾}\035", 0x1d910ea0 " ¾}\035", 0x1d9732f0 "ï¾­Þ", 0x0 <repeats 64 times>} answer = '\0' <repeats 521 times>, "È3D\000\000\000\000¢üQÏ:\000\000\000¢üQÏ:", '\0' <repeats 11 times>, "ï4DÏ:\000\000\000ÀÇ3D", '\0' <repeats 12 times>, "àÂ3D", '\0' <repeats 28 times>, "0É3D\000\000\000\000\227üQÏ:\000\000\000\020È3D", '\0' <repeats 36 times>, "ÿÿÿÿÿÿÿÿ¡üQÏ:\000\000\000\227üQÏ:", '\0' <repeats 11 times>, "ÈÆ3D\000\000\000\000ÐÖ\202`\003\000\000\000\n", '\0' <repeats 11 times>, "\n", '\0' <repeats 43 times>, " ", '\0' <repeats 15 times>, " Ê3D\000\000\000\000ÎÖ\202u\\+"... argv_buf = '\0' <repeats 2200 times>, "\001", '\0' <repeats 35 times>, "@", '\0' <repeats 19 times>, "þÿÿÿÿÿÿÿþÿÿÿ¿", 'ÿ' <repeats 19 times>, '\0' <repeats 1807 times> envp = {0x1d989ba0 "ACCT_STATUS_TYPE=Stop", 0x1d988a90 "USER_NAME=\"valboulevard@advanced\"", 0x1d988ac0 "EVENT_TIMESTAMP=\"Nov 26 2009 15:25:20 AST\"", 0x1d9687f0 "ACCT_DELAY_TIME=30", 0x1d988c50 "NAS_IDENTIFIER=\"ERX-2\"", 0x1d988b00 "ACCT_SESSION_ID=\"0359431385\"", 0x1d988b30 "NAS_IP_ADDRESS=192.168.1.101", 0x1d988b60 "SERVICE_TYPE=Framed-User", 0x1d989b20 "FRAMED_PROTOCOL=PPP", 0x1d989b40 "FRAMED_COMPRESSION=None", 0x1d988b90 "ERX_PPPOE_DESCRIPTION=\"pppoe 00:90:d0:63:df:6d\"", 0x1d988bd0 "FRAMED_IP_ADDRESS=199.2.118.232", 0x1d968810 "FRAMED_IP_NETMASK=255.255.255.255", 0x1d988c00 "ERX_INGRESS_POLICY_NAME=\"ADVANCED_UP\"", ---Type <return> to continue, or q <return> to quit--- 0x1d968790 "ERX_EGRESS_POLICY_NAME=\"ADVANCED_DOWN\"", 0x1d9687c0 "CALLING_STATION_ID=\"ERX-09000000261\"", 0x1d989b60 "ACCT_INPUT_GIGAWORDS=0", 0x1d989ac0 "ACCT_INPUT_OCTETS=43839839", 0x1d989b80 "ACCT_OUTPUT_GIGAWORDS=0", 0x1d989af0 "ACCT_OUTPUT_OCTETS=15343206", 0x1d989aa0 "ERX_INPUT_GIGAPKTS=0", 0x1d988c70 "ACCT_INPUT_PACKETS=71072", 0x1d973530 "ERX_OUTPUT_GIGAPKTS=0", 0x1d988ca0 "ACCT_OUTPUT_PACKETS=56798", 0x1d968840 "NAS_PORT_TYPE=Ethernet", 0x1d988c30 "NAS_PORT=2415919365", 0x1d988cd0 "NAS_PORT_ID=\"GigabitEthernet 9/0.261:261\"", 0x1d988d10 "ACCT_AUTHENTIC=RADIUS", 0x1d988d30 "ACCT_SESSION_TIME=86400", 0x1d988d50 "ACCT_TERMINATE_CAUSE=Session-Timeout", 0x1d988d80 "ACCT_UNIQUE_SESSION_ID=\"b59b7e5cef8e3cf2\"", 0x0 <repeats 687 times>, 0x4433a5f0 "@¦3D", 0x0, 0x10 <Address 0x10 out of bounds>, 0x0, 0x31 <Address 0x31 out of bounds>, 0x0, 0x0, 0x3acf7519c0 "\001", 0x3acf751a08 "", 0x3acf751a08 "", 0x4433a640 "À\031uÏ:", 0x3acf751a20 "°\233\230\035", 0x10 <Address 0x10 out of bounds>, 0x3acf751a08 "", 0x4433a660 "À\031uÏ:", 0x3acf751a20 "°\233\230\035", 0x58 <Address 0x58 out of bounds>, 0x3acf7519c0 "\001", 0x4433d960 " 7@", 0x3acf751a20 "°\233\230\035", 0x3acf7519c0 "\001", 0x800 <Address 0x800 out of bounds>, 0x810 <Address 0x810 out of bounds>, 0x3acf4723fd "éÇûÿÿL\211øHÁè\fH\203ø\n\017\206\016\001", 0x3acf7519c0 "\001", 0x3acf7519c0 "\001", 0x4433a6c0 "ø\213\230\035\017", 0x4433d920 "\b5\216\037", 0x800 <Address 0x800 out of bounds>, 0x830 <Address 0x830 out of bounds>, 0x1d9887b0 "", 0x3acf47402a "H\205ÀI\211ÄtJ\203=¯\016.", 0x1d988c08 "ESS_POLICY_NAME=\"ADVANCED_UP\"", 0x1d988bf0 "\017", 0x4433d920 "\b5\216\037", 0x58cf4a5615 <Address 0x58cf4a5615 out of bounds>, 0xf1d988bf8 <Address 0xf1d988bf8 out of bounds>, 0x1d988bf0 "\017", 0x0, 0x4433d920 "\b5\216\037", 0x1d988bf8 "1", 0x3acf7519c0 "\001", 0x4433d960 " 7@", 0x3 <Address 0x3 out of bounds>, 0x1 <Address 0x1 out of bounds>, 0x18 <Address 0x18 out of bounds>, 0x0, 0x3acf47590c "\203=Õõ-", 0x10 <Address 0x10 out of bounds>, 0x4433d900 "\b5\216\037", 0x4433d960 " 7@", 0x3 <Address 0x3 out of bounds>, 0x1 <Address 0x1 out of bounds>, 0x4433a7f8 "", 0x4433d960 " 7@", 0x3acf4ad136 "D;¥\234þÿÿuç\200½\232þÿÿ", 0x1d988a90 "USER_NAME=\"valboulevard@advanced\"", 0x1d988bf0 "\017", 0x1d988b30 "NAS_IP_ADDRESS=192.168.1.101", 0x1d988a90 "USER_NAME=\"valboulevard@advanced\"", 0x1d988bf0 "\017", 0x1d988b30 "NAS_IP_ADDRESS=192.168.1.101", 0x1d988a90 "USER_NAME=\"valboulevard@advanced\"", 0x1d988bf0 "\017", 0x1d988b30 "NAS_IP_ADDRESS=192.168.1.101", 0x4433d960 " 7@", 0x4433a7e0 "\001", 0x3acf4ad5ca "\205À\017\205Q÷ÿÿH\211ßèF\001÷ÿH\205ÀH\211\205 þÿÿÆ\205\233þÿÿ\001\017\205T÷ÿÿéÝûÿÿH\215\004Í", 0x200000002 <Address 0x200000002 out of bounds>, 0x1d9899a0 "", 0x200000002 <Address 0x200000002 out of bounds>, 0x1d988910 "", 0x100000001 <Address 0x100000001 out of bounds>, 0x1d9687d0 "ID=\"ERX-09000000261\"", 0x0 <repeats 232 times>} #2 0x00002b5c60e6cf58 in exec_xlat (instance=0x1d8e90b0, request=0x1d9732f0, fmt=0x1d988a60 "/usr/local/sbin/acctstop.sh", out=0x4433df60 "", outlen=254, func=0x42bd95 <xlat_copy>) at rlm_exec.c:138 result = 0 inst = (rlm_exec_t *) 0x1d8e90b0 input_pairs = (VALUE_PAIR **) 0x1d973178 p = 0x1d988a60 "/usr/local/sbin/acctstop.sh" #3 0x000000000042bbd0 in decode_attribute (from=0x4433def0, to=0x4433dee8, freespace=254, open_p=0x4433de7c, request=0x1d9732f0, func=0x42bd95 <xlat_copy>) at xlat.c:911 stop = 1 delimitbrace = 0 do_length = 0 xlat_name = "exec\000\000\000\000ì\003\000\000ÿÿÿÿ\000\000\000\000\000\000\000\000@\210\224\035\000\000\000\000à_\230\035\000\000\000\000ð2\227\035\000\000\000\000à_\230\035\000\000\000\000\004\000\000\000\000\000\000\000ß2\227\035\006\000\000\000 h\230\035\000\000\000\000pÞ3D\000\000\000\000eìc\\+", '\0' <repeats 18 times>, "Ð5@\000\000\000\000\000\000\200\200`\\+\000" xlat_string = 0x1d988a60 "/usr/local/sbin/acctstop.sh" free_xlat_string = 1 p = 0x1d98883b "" q = 0x4433df60 "" pa = 0x1d988a7b "" found = 0 retlen = 0 ---Type <return> to continue, or q <return> to quit--- openbraces = 0 c = (const xlat_t *) 0x1d8e9960 spaces = 0 #4 0x000000000042c0a1 in radius_xlat (out=0x4433df60 "", outlen=254, fmt=0x1d988818 "%{exec:/usr/local/sbin/acctstop.sh}", request=0x1d9732f0, func=0x42bd95 <xlat_copy>) at xlat.c:1086 c = 37 len = 496021568 freespace = 254 p = 0x1d988819 "{exec:/usr/local/sbin/acctstop.sh}" q = 0x4433df60 "" nl = 0x0 tmp = (VALUE_PAIR *) 0x1d90c1c0 TM = (struct tm *) 0x4433e040 s_TM = {tm_sec = 0, tm_min = 0, tm_hour = 0, tm_mday = 0, tm_mon = 5, tm_year = 0, tm_wday = 0, tm_yday = 0, tm_isdst = 1, tm_gmtoff = 8589934592, tm_zone = 0x4433df20 "`¾\220\035"} tmpdt = "\020à3D\000\000\000\000Àß3D\000\000\000\000\001½\036ö\000\000\000\000Øß3D", '\0' <repeats 11 times> openbraces = 0 #5 0x0000000000429613 in pairxlatmove (req=0x1d9732f0, to=0x1d9734a8, from=0x4433e238) at valuepair.c:587 rcode = 0 buffer = "\0004\227\035\000\000\000\000 \016\221\035\000\000\000\000à_\230\035\000\000\000\000ð2\227\035\000\000\000\000\000\000\000\000\006\000\000\000\220\f\221\035(\000\000\000ؽ\220\035\000\000\000\000\006\000\000\000\036\000\000\000àß3D\000\000\000\000­Q\201`\\+\000\000ðß3D\036\000\000\000À\031uÏ:\000\000\000x3@\000\000\000\000\000\000\200\200`\\+\000\000@ù3D\000\000\000\000ÿÿÿÿ\000\000\000\000\000\020\000\000\000\000\000\000ð$ \000\000\000\000\000\000\000 \000\000\000\000\000@ù3D\000\000\000\000\000\0004D\000\000\000\000\000\020\000\000\000\000\000\000\000\200+c\\+\000\0005Í\000Ï:\000\000\000\005", '\0' <repeats 15 times>... tailto = (VALUE_PAIR **) 0x1d9734a8 i = (VALUE_PAIR *) 0x1d9887e0 j = (VALUE_PAIR *) 0x4433e238 next = (VALUE_PAIR *) 0x1d988920 tailfrom = (VALUE_PAIR *) 0x0 found = (VALUE_PAIR *) 0x2 #6 0x00002b5c632b993f in file_common (inst=0x1d90bb20, request=0x1d9732f0, filename=0x2b5c632b9e8e "acct_users", ht=0x1d90bdb0, request_pairs=0x1d985fe0, reply_pairs=0x1d9734a8) at rlm_files.c:472 pl = (const PAIR_LIST *) 0x1d90bd70 name = 0x1d986158 "valboulevard@advanced" match = 0x2b5c632b9e5e "DEFAULT" config_pairs = (VALUE_PAIR **) 0x1d973318 check_tmp = (VALUE_PAIR *) 0x1d9886a0 reply_tmp = (VALUE_PAIR *) 0x1d9887e0 user_pl = (const PAIR_LIST *) 0x0 default_pl = (const PAIR_LIST *) 0x0 found = 1 my_pl = {name = 0x2b5c632b9e5e "DEFAULT", check = 0x0, reply = 0xe0, lineno = 242428, order = 0, next = 0x0, lastdefault = 0x4433e120} buffer = '\0' <repeats 32 times>, "valboulevard\000advanced", '\0' <repeats 202 times> #7 0x00002b5c632b9a66 in file_preacct (instance=0x1d90bb20, request=0x1d9732f0) at rlm_files.c:525 inst = (struct file_instance *) 0x1d90bb20 #8 0x0000000000420443 in call_modsingle (component=2, sp=0x1d94c8d0, request=0x1d9732f0) at modcall.c:297 myresult = 0 ---Type <return> to continue, or q <return> to quit--- #9 0x000000000042126b in modcall (component=2, c=0x1d94bcf0, request=0x1d9732f0) at modcall.c:669 myresult = 7 stack = {pointer = 1, priority = {0, 2, 0 <repeats 14 times>, 4, -805247808, 58, 0, 0, 0, 0, 494780912, 0, 1144252848, 0, 0, 0, 0, 0, 1144252848}, result = {7, 2, 0, 1144252688, 0, 1619086899, 11100, 1144252856, 0, 494819584, 0, 1144252848, 0, 1619068620, -1672236017, 494849120, 0, 494773456, 0, 494819584, 0, 1144252848, 0, 1144252752, 0, 1619088694, 11100, 1144252784, 0, 494819584, 0, 1144252848}, children = {0x1d94bcf0, 0x1d94c8d0, 0x9c53b40f00000a39, 0x4433e990, 0x2b5c608155e5, 0x4433e9a0, 0x1d7dc1f0, 0x4433e9b0, 0x1d7da4d0, 0x4433ea00, 0x1d7e5900, 0x4433e9d0, 0xfe, 0x1d7dc1f8, 0x1d988458, 0x500000031, 0x1d988468, 0x1d7dc208, 0xee, 0x4433ea60, 0x2b5c6081e050, 0xa00000, 0x2b5c60823dd9, 0x100000000, 0x1d988420, 0x1d9732df, 0x4, 0x3100000000, 0x1d8e6180, 0x0, 0x1d973110, 0x1d988420}, start = {0x3100000005, 0x1d94bc60, 0x1d7dc1f0, 0x1d7dbff8, 0x300ac31e00000000, 0x14, 0x1d9731a0, 0x1d9731b4, 0x1d9731b4, 0x4433eac0, 0x2b5c6082009a, 0x14, 0x1d9731a0, 0x0, 0x300ac31e, 0x1d97314c, 0x1d988420, 0x4433ec30, 0x2b5c6081f143, 0x4433eb70, 0x2b5c6081cce1, 0x1d8e6180, 0x0, 0x11d8e6180, 0x100000001, 0x1, 0x1d8e6180, 0x0, 0x1d973110, 0x0, 0x0, 0x0}} parent = (modcallable *) 0x1d94bcf0 child = (modcallable *) 0x1d94c8d0 sp = (modsingle *) 0x1d94c8d0 if_taken = 0 was_if = 0 #10 0x000000000041ea4f in indexed_modcall (comp=2, idx=0, request=0x1d9732f0) at modules.c:691 rcode = 0 list = (modcallable *) 0x1d94bcf0 server = (virtual_server_t *) 0x1d94a550 #11 0x000000000041fdb6 in module_preacct (request=0x1d9732f0) at modules.c:1470 No locals. #12 0x000000000040813c in rad_accounting (request=0x1d9732f0) at acct.c:57 vp = (VALUE_PAIR *) 0x1d9732f0 acct_type = 0 result = 2 #13 0x00000000004356b5 in radius_handle_request (request=0x1d9732f0, fun=0x408108 <rad_accounting>) at event.c:4086 No locals. #14 0x0000000000426bd6 in request_handler_thread (arg=0x1d966a50) at threads.c:492 fun = (RAD_REQUEST_FUNP) 0x408108 <rad_accounting> self = (THREAD_HANDLE *) 0x1d966a50 #15 0x0000003ad0006367 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #16 0x0000003acf4d30ad in clone () from /lib64/libc.so.6 No symbol table info available. Thread 4 (Thread 0x4393e940 (LWP 23504)): #0 0x0000003acf4dee6e in __lll_lock_wait_private () from /lib64/libc.so.6 No symbol table info available. #1 0x0000003acf476668 in _L_lock_12629 () from /lib64/libc.so.6 No symbol table info available. #2 0x0000003acf47477f in malloc_atfork () from /lib64/libc.so.6 No symbol table info available. #3 0x0000003ad2cdab52 in CRYPTO_malloc () from /lib64/libcrypto.so.6 No symbol table info available. #4 0x0000003ad2c7fdbc in ?? () from /lib64/libcrypto.so.6 No symbol table info available. ---Type <return> to continue, or q <return> to quit--- #5 0x0000003ad2cd82bd in ERR_clear_error () from /lib64/libcrypto.so.6 No symbol table info available. #6 0x0000000000426b4f in request_handler_thread (arg=0x1d9668d0) at threads.c:474 fun = (RAD_REQUEST_FUNP) 0 self = (THREAD_HANDLE *) 0x1d9668d0 #7 0x0000003ad0006367 in start_thread () from /lib64/libpthread.so.0 No symbol table info available. #8 0x0000003acf4d30ad in clone () from /lib64/libc.so.6 No symbol table info available. Thread 3 (Thread 0x42f3d940 (LWP 23503)): #0 0x0000003acf4dee6e in __lll_lock_wait_private () from /lib64/libc.so.6 No symbol table info available. #1 0x0000003acf476668 in _L_lock_12629 () from /lib64/libc.so.6 No symbol table info available. #2 0x0000003acf47477f in malloc_atfork () from /lib64/libc.so.6 No symbol table info available. #3 0x0000003ad2cdab52 in CRYPTO_malloc () from /lib64/libcrypto.so.6 No symbol table info available. #4 0x0000003ad2c7fdbc in ?? () from /lib64/libcrypto.so.6 No symbol table info available. #5 0x0000003ad2cd82bd in ERR_clear_error () from /lib64/libcrypto.so.6 No symbol table info available. #6 0x0000000000426b4f in request_handler_thread (arg=0x1d966750) at threads.c:474 fun = (RAD_REQUEST_FUNP) 0 ----- Original Message ----- From: "Alan DeKok" <aland@deployingradius.com> To: "FreeRadius users mailing list" <freeradius-users@lists.freeradius.org> Sent: Thursday, November 26, 2009 2:19 PM Subject: Re: Unexpected "Exiting normally" 2.1.8?

Bjørn Mork wrote:

...

However, I think I found one other possibility. This code in fr_event_loop() will exit if the select() fails:

rcode = select(el->maxfd + 1, &read_fds, NULL, NULL, wake); if ((rcode < 0) && (errno != EINTR)) { el->dispatch = 0; return 0; }

Might this happen due to a dead home server fd in the &read_fds?

It shouldn't. The only fail in select() is that one of the file descriptors has been closed, without updating the read_fds array. And that shouldn't happen, either.

What error is select() returning?

Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

__________ Information from ESET Smart Security, version of virus signature database 4640 (20091126) __________ The message was checked by ESET Smart Security. http://www.eset.com

Alexander Clouter wrote:

It's when I add (I am pretty sure it's the in the first 8 or so patches) the following I get the same problem with FreeRADIUS: ... I guess at this point I am going to be told to be a good boy and run off and use git bisect? :)

Pretty much, sorry.

Looking through the patches normally I cannot see what could have caused the graceful exit...which is exactly what I am getting: ... #1 0x00000000004228d9 in main (argc=2, argv=0x7fffaaef61c8) at radiusd.c:419

That just means that the main event loop exited, and the server is telling all child threads to stop. It looks like the server received a TERM, QUIT, or INT signal. Why, I don't know. But yes, "git bisect" would be tremendously useful. I'm traveling for the next week, so I'll have limited time to look at it myself. Alan DeKok.