3.0.1: good old "die on exit" again
Hello, sending a SIGTERM to my 3.0.1 installation again doesn't terminate cleanly any more (not sure when it broke, sorry). The possibly good news: it's a talloc SIGABRT, so may be easier to find than some spurious pointer thing? Here's the gdb (I don't know how much it can help with talloc issues...) Ready to process requests. Program received signal SIGTERM, Terminated. 0x00007ffff5d4f913 in select () from /lib64/libc.so.6 (gdb) c Continuing. Signalled to terminate Exiting normally. rlm_sql (cuisql): Removing connection pool rlm_sql (cuisql): Closing connection (4) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (cuisql): Closing connection (3) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (cuisql): Closing connection (2) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (cuisql): Closing connection (1) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (cuisql): Closing connection (0) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (sql-aai-hash): Removing connection pool rlm_sql (sql-aai-hash): Closing connection (4) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-aai-hash): Closing connection (3) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-aai-hash): Closing connection (2) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-aai-hash): Closing connection (1) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-aai-hash): Closing connection (0) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-cloudstoresso-users): Removing connection pool rlm_sql (sql-cloudstoresso-users): Closing connection (4) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-cloudstoresso-users): Closing connection (3) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-cloudstoresso-users): Closing connection (2) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-cloudstoresso-users): Closing connection (1) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-cloudstoresso-users): Closing connection (0) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-cloudstore-hash): Removing connection pool rlm_sql (sql-cloudstore-hash): Closing connection (4) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-cloudstore-hash): Closing connection (3) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-cloudstore-hash): Closing connection (2) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-cloudstore-hash): Closing connection (1) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-cloudstore-hash): Closing connection (0) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-imap-hash): Removing connection pool rlm_sql (sql-imap-hash): Closing connection (4) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-imap-hash): Closing connection (3) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-imap-hash): Closing connection (2) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-imap-hash): Closing connection (1) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-imap-hash): Closing connection (0) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-null-acct-eduroam): Removing connection pool rlm_sql (sql-null-acct-eduroam): Closing connection (2) rlm_sql (sql-null-acct-eduroam): Closing connection (1) rlm_sql (sql-null-acct-eduroam): Closing connection (0) rlm_sql (sql-null-acct-erx): Removing connection pool rlm_sql (sql-null-acct-erx): Closing connection (2) rlm_sql (sql-null-acct-erx): Closing connection (1) rlm_sql (sql-null-acct-erx): Closing connection (0) rlm_sql (sql-null-acct-cops): Removing connection pool rlm_sql (sql-null-acct-cops): Closing connection (2) rlm_sql (sql-null-acct-cops): Closing connection (1) rlm_sql (sql-null-acct-cops): Closing connection (0) rlm_sql (sql-null-lastusage): Removing connection pool rlm_sql (sql-null-lastusage): Closing connection (2) rlm_sql (sql-null-lastusage): Closing connection (1) rlm_sql (sql-null-lastusage): Closing connection (0) rlm_sql (sql-null-postauth): Removing connection pool rlm_sql (sql-null-postauth): Closing connection (2) rlm_sql (sql-null-postauth): Closing connection (1) rlm_sql (sql-null-postauth): Closing connection (0) rlm_sql (sql-userjabber-hash): Removing connection pool rlm_sql (sql-userjabber-hash): Closing connection (4) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-userjabber-hash): Closing connection (3) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-userjabber-hash): Closing connection (2) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-userjabber-hash): Closing connection (1) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-userjabber-hash): Closing connection (0) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-smtp-hash): Removing connection pool rlm_sql (sql-smtp-hash): Closing connection (4) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-smtp-hash): Closing connection (3) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-smtp-hash): Closing connection (2) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-smtp-hash): Closing connection (1) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-smtp-hash): Closing connection (0) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-null-staff-tacacsaccounting): Removing connection pool rlm_sql (sql-null-staff-tacacsaccounting): Closing connection (2) rlm_sql (sql-null-staff-tacacsaccounting): Closing connection (1) rlm_sql (sql-null-staff-tacacsaccounting): Closing connection (0) rlm_sql (sql-null-acct-vpn): Removing connection pool rlm_sql (sql-null-acct-vpn): Closing connection (2) rlm_sql (sql-null-acct-vpn): Closing connection (1) rlm_sql (sql-null-acct-vpn): Closing connection (0) rlm_sql (sql-webmailsso-staff): Removing connection pool rlm_sql (sql-webmailsso-staff): Closing connection (4) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-webmailsso-staff): Closing connection (3) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-webmailsso-staff): Closing connection (2) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-webmailsso-staff): Closing connection (1) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-webmailsso-staff): Closing connection (0) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-webmailsso-users): Removing connection pool rlm_sql (sql-webmailsso-users): Closing connection (4) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-webmailsso-users): Closing connection (3) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-webmailsso-users): Closing connection (2) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-webmailsso-users): Closing connection (1) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-webmailsso-users): Closing connection (0) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-vpn-hash): Removing connection pool rlm_sql (sql-vpn-hash): Closing connection (4) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-vpn-hash): Closing connection (3) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-vpn-hash): Closing connection (2) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-vpn-hash): Closing connection (1) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-vpn-hash): Closing connection (0) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-eduroam-hash): Removing connection pool rlm_sql (sql-eduroam-hash): Closing connection (4) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-eduroam-hash): Closing connection (3) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-eduroam-hash): Closing connection (2) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-eduroam-hash): Closing connection (1) rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql-eduroam-hash): Closing connection (0) rlm_sql_mysql: Socket destructor called, closing socket Bad talloc magic value - unknown value Program received signal SIGABRT, Aborted. 0x00007ffff5ca4849 in raise () from /lib64/libc.so.6 (gdb) c Continuing. Program terminated with signal SIGABRT, Aborted. The program no longer exists. (gdb) q -- Stefan WINTER Ingenieur de Recherche Fondation RESTENA - Réseau Téléinformatique de l'Education Nationale et de la Recherche 6, rue Richard Coudenhove-Kalergi L-1359 Luxembourg Tel: +352 424409 1 Fax: +352 422473 PGP key updated to 4096 Bit RSA - I will encrypt all mails if the recipient's key is known to me http://pgp.mit.edu:11371/pks/lookup?op=get&search=0xC0DE6A358A39DC66
On 3 Feb 2014, at 08:12, Stefan Winter <stefan.winter@restena.lu> wrote:
Hello,
sending a SIGTERM to my 3.0.1 installation again doesn't terminate cleanly any more (not sure when it broke, sorry).
The possibly good news: it's a talloc SIGABRT, so may be easier to find than some spurious pointer thing?
Here's the gdb (I don't know how much it can help with talloc issues...)
Well not very much seeing as you've not provided the backtrace. Could you try with 3.0.x and see if the issue is still present. You can use panic_action to produce the backtrace. -Arran Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
Hi,
Well not very much seeing as you've not provided the backtrace.
Could you try with 3.0.x and see if the issue is still present. You can use panic_action to produce the backtrace.
Program received signal SIGABRT, Aborted. 0x00007ffff5ca4849 in raise () from /lib64/libc.so.6 (gdb) bt #0 0x00007ffff5ca4849 in raise () from /lib64/libc.so.6 #1 0x00007ffff5ca5cd8 in abort () from /lib64/libc.so.6 #2 0x00007ffff70fdfac in ?? () from /usr/lib64/libtalloc.so.2 #3 0x00007ffff70fdd5e in _talloc_free () from /usr/lib64/libtalloc.so.2 #4 0x000000000043a6f6 in home_server_free (data=0x89eb70) at <command-line>:108 #5 0x00007ffff799a522 in FreeWalker (tree=0x89dba0, X=0x89ed60) at <command-line>:75 #6 0x00007ffff799a4d5 in FreeWalker (tree=0x89dba0, X=0x89e740) at <command-line>:72 #7 0x00007ffff799a58e in rbtree_free (tree=0x89dba0) at <command-line>:88 #8 0x000000000043ac1a in realms_free () at <command-line>:251 #9 0x000000000041fdb4 in free_mainconfig () at <command-line>:979 #10 0x0000000000428e73 in main (argc=2, argv=0x7fffffffe418) at <command-line>:585 (gdb) quit I compiled with --enable-developer and still see those "command-line" traces. I believe this has to do with the recently discussed issue about a bug in ... some version of some software; either gdb or C libs? Greetings, Stefan Winter -- Stefan WINTER Ingenieur de Recherche Fondation RESTENA - Réseau Téléinformatique de l'Education Nationale et de la Recherche 6, rue Richard Coudenhove-Kalergi L-1359 Luxembourg Tel: +352 424409 1 Fax: +352 422473 PGP key updated to 4096 Bit RSA - I will encrypt all mails if the recipient's key is known to me http://pgp.mit.edu:11371/pks/lookup?op=get&search=0xC0DE6A358A39DC66
On 3 Feb 2014, at 10:46, Stefan Winter <stefan.winter@restena.lu> wrote:
Hi,
Well not very much seeing as you've not provided the backtrace.
Could you try with 3.0.x and see if the issue is still present. You can use panic_action to produce the backtrace.
Program received signal SIGABRT, Aborted. 0x00007ffff5ca4849 in raise () from /lib64/libc.so.6 (gdb) bt #0 0x00007ffff5ca4849 in raise () from /lib64/libc.so.6 #1 0x00007ffff5ca5cd8 in abort () from /lib64/libc.so.6 #2 0x00007ffff70fdfac in ?? () from /usr/lib64/libtalloc.so.2 #3 0x00007ffff70fdd5e in _talloc_free () from /usr/lib64/libtalloc.so.2 #4 0x000000000043a6f6 in home_server_free (data=0x89eb70) at <command-line>:108 #5 0x00007ffff799a522 in FreeWalker (tree=0x89dba0, X=0x89ed60) at <command-line>:75 #6 0x00007ffff799a4d5 in FreeWalker (tree=0x89dba0, X=0x89e740) at <command-line>:72 #7 0x00007ffff799a58e in rbtree_free (tree=0x89dba0) at <command-line>:88 #8 0x000000000043ac1a in realms_free () at <command-line>:251 #9 0x000000000041fdb4 in free_mainconfig () at <command-line>:979 #10 0x0000000000428e73 in main (argc=2, argv=0x7fffffffe418) at <command-line>:585 (gdb) quit
Thanks.
I compiled with --enable-developer and still see those "command-line" traces. I believe this has to do with the recently discussed issue about a bug in ... some version of some software; either gdb or C libs?
Hm. Could you edit Make.inc and change the -imacros to -include and see if you get the same result. If so I can change it, I don't think there'll be any side effects, they basically do the same thing, except -imacros only pulls in the preprocessor macros whereas -include would pull in function signatures too. -Arran Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
Hi,
If so I can change it, I don't think there'll be any side effects, they basically do the same thing, except -imacros only pulls in the preprocessor macros whereas -include would pull in function signatures too.
shouldnt it be the default then when 'developer' mode is present? alan
On 3 Feb 2014, at 11:58, A.L.M.Buxey@lboro.ac.uk wrote:
Hi,
If so I can change it, I don't think there'll be any side effects, they basically do the same thing, except -imacros only pulls in the preprocessor macros whereas -include would pull in function signatures too.
shouldnt it be the default then when 'developer' mode is present?
Well, it's a bug in GDB, were using the GCC flags correctly, but GDB like most of the GNU tool chain, is pretty inconsistent and crappy. If Stefan says it fixes the command line issue I guess we can change it though, just to make extracting backtraces from users easier... Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
On 3 Feb 2014, at 11:16, Arran Cudbard-Bell <a.cudbardb@freeradius.org> wrote:
On 3 Feb 2014, at 10:46, Stefan Winter <stefan.winter@restena.lu> wrote:
Hi,
Well not very much seeing as you've not provided the backtrace.
Could you try with 3.0.x and see if the issue is still present. You can use panic_action to produce the backtrace.
Program received signal SIGABRT, Aborted. 0x00007ffff5ca4849 in raise () from /lib64/libc.so.6 (gdb) bt #0 0x00007ffff5ca4849 in raise () from /lib64/libc.so.6 #1 0x00007ffff5ca5cd8 in abort () from /lib64/libc.so.6 #2 0x00007ffff70fdfac in ?? () from /usr/lib64/libtalloc.so.2 #3 0x00007ffff70fdd5e in _talloc_free () from /usr/lib64/libtalloc.so.2 #4 0x000000000043a6f6 in home_server_free (data=0x89eb70) at <command-line>:108 #5 0x00007ffff799a522 in FreeWalker (tree=0x89dba0, X=0x89ed60) at <command-line>:75 #6 0x00007ffff799a4d5 in FreeWalker (tree=0x89dba0, X=0x89e740) at <command-line>:72 #7 0x00007ffff799a58e in rbtree_free (tree=0x89dba0) at <command-line>:88 #8 0x000000000043ac1a in realms_free () at <command-line>:251 #9 0x000000000041fdb4 in free_mainconfig () at <command-line>:979 #10 0x0000000000428e73 in main (argc=2, argv=0x7fffffffe418) at <command-line>:585 (gdb) quit
Thanks.
Ok. Probably fixed... Home server was being alloced with normal malloc at realms.c:1181, it wasn't in master. It was a bug anyway, even if it wasn't the thing you're seeing, the alloced home server was being inserted into the home_servers_byaddr tree, which uses talloc_free as it's free callback. Thanks for the bug report. -Arran Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
Hi, this moved the crash to a different nuance :-/ Stefan rlm_sql_mysql: Socket destructor called, closing socket talloc: access after free error - first free may be at <command-line>:2024 Bad talloc magic value - access after free Program received signal SIGABRT, Aborted. 0x00007ffff5ca1849 in raise () from /lib64/libc.so.6 (gdb) bt #0 0x00007ffff5ca1849 in raise () from /lib64/libc.so.6 #1 0x00007ffff5ca2cd8 in abort () from /lib64/libc.so.6 #2 0x00007ffff70fafac in ?? () from /usr/lib64/libtalloc.so.2 #3 0x00007ffff70fa6ff in ?? () from /usr/lib64/libtalloc.so.2 #4 0x00007ffff70fe198 in ?? () from /usr/lib64/libtalloc.so.2 #5 0x00007ffff70fde73 in ?? () from /usr/lib64/libtalloc.so.2 #6 0x00007ffff70fde73 in ?? () from /usr/lib64/libtalloc.so.2 #7 0x00007ffff70faabb in _talloc_free () from /usr/lib64/libtalloc.so.2 #8 0x00007ffff7bc13a6 in cf_file_free (cs=0x68cd30) at <command-line>:2024 #9 0x000000000041fbfd in free_mainconfig () at <command-line>:1023 #10 0x0000000000428c0f in main (argc=2, argv=0x7fffffffe3f8) at <command-line>:596 (gdb) c Continuing. FATAL SIGNAL: Aborted Backtrace of last 15 frames: /usr/local/freeradius/3.0.2-pre-201402023/lib64/libfreeradius-radius.so(+0x987f) [0x7ffff798287f] /lib64/libpthread.so.0(+0xf9f0) [0x7ffff64cb9f0] /lib64/libc.so.6(gsignal+0x39) [0x7ffff5ca1849] /lib64/libc.so.6(abort+0x148) [0x7ffff5ca2cd8] /usr/lib64/libtalloc.so.2(+0x2fac) [0x7ffff70fafac] /usr/lib64/libtalloc.so.2(+0x26ff) [0x7ffff70fa6ff] /usr/lib64/libtalloc.so.2(+0x6198) [0x7ffff70fe198] /usr/lib64/libtalloc.so.2(+0x5e73) [0x7ffff70fde73] /usr/lib64/libtalloc.so.2(+0x5e73) [0x7ffff70fde73] /usr/lib64/libtalloc.so.2(_talloc_free+0x10b) [0x7ffff70faabb] /usr/local/freeradius/3.0.2-pre-201402023/lib64/libfreeradius-server.so(cf_file_free+0x1f) [0x7ffff7bc13a6] /usr/local/freeradius/3.0.2-pre-201402023/sbin/radiusd(free_mainconfig+0x59) [0x41fbfd] /usr/local/freeradius/3.0.2-pre-201402023/sbin/radiusd(main+0xc90) [0x428c0f] /lib64/libc.so.6(__libc_start_main+0xf5) [0x7ffff5c8dbe5] /usr/local/freeradius/3.0.2-pre-201402023/sbin/radiusd() [0x40d7a9] No panic action set _EXIT CALLED <command-line>[261]: 1: On 03.02.2014 12:59, Arran Cudbard-Bell wrote:
On 3 Feb 2014, at 11:16, Arran Cudbard-Bell <a.cudbardb@freeradius.org> wrote:
On 3 Feb 2014, at 10:46, Stefan Winter <stefan.winter@restena.lu> wrote:
Hi,
Well not very much seeing as you've not provided the backtrace.
Could you try with 3.0.x and see if the issue is still present. You can use panic_action to produce the backtrace.
Program received signal SIGABRT, Aborted. 0x00007ffff5ca4849 in raise () from /lib64/libc.so.6 (gdb) bt #0 0x00007ffff5ca4849 in raise () from /lib64/libc.so.6 #1 0x00007ffff5ca5cd8 in abort () from /lib64/libc.so.6 #2 0x00007ffff70fdfac in ?? () from /usr/lib64/libtalloc.so.2 #3 0x00007ffff70fdd5e in _talloc_free () from /usr/lib64/libtalloc.so.2 #4 0x000000000043a6f6 in home_server_free (data=0x89eb70) at <command-line>:108 #5 0x00007ffff799a522 in FreeWalker (tree=0x89dba0, X=0x89ed60) at <command-line>:75 #6 0x00007ffff799a4d5 in FreeWalker (tree=0x89dba0, X=0x89e740) at <command-line>:72 #7 0x00007ffff799a58e in rbtree_free (tree=0x89dba0) at <command-line>:88 #8 0x000000000043ac1a in realms_free () at <command-line>:251 #9 0x000000000041fdb4 in free_mainconfig () at <command-line>:979 #10 0x0000000000428e73 in main (argc=2, argv=0x7fffffffe418) at <command-line>:585 (gdb) quit
Thanks.
Ok. Probably fixed... Home server was being alloced with normal malloc at realms.c:1181, it wasn't in master.
It was a bug anyway, even if it wasn't the thing you're seeing, the alloced home server was being inserted into the home_servers_byaddr tree, which uses talloc_free as it's free callback.
Thanks for the bug report.
-Arran
Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team
FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
-- Stefan WINTER Ingenieur de Recherche Fondation RESTENA - Réseau Téléinformatique de l'Education Nationale et de la Recherche 6, rue Richard Coudenhove-Kalergi L-1359 Luxembourg Tel: +352 424409 1 Fax: +352 422473 PGP key updated to 4096 Bit RSA - I will encrypt all mails if the recipient's key is known to me http://pgp.mit.edu:11371/pks/lookup?op=get&search=0xC0DE6A358A39DC66
Stefan Winter wrote:
this moved the crash to a different nuance :-/
Hmm.. that's a bit weirder. You've HUPed the server a few times. It keeps the old config around (crappy home-brew garbage collector, really...). Then on exit, it free's the older configs. But it should only do that once. Alan DeKok.
Hi,
this moved the crash to a different nuance :-/
Hmm.. that's a bit weirder.
You've HUPed the server a few times. It keeps the old config around (crappy home-brew garbage collector, really...). Then on exit, it free's the older configs. But it should only do that once.
No... this was after a fresh start, 0 packets processed. Just start and shut down. Stefan -- Stefan WINTER Ingenieur de Recherche Fondation RESTENA - Réseau Téléinformatique de l'Education Nationale et de la Recherche 6, rue Richard Coudenhove-Kalergi L-1359 Luxembourg Tel: +352 424409 1 Fax: +352 422473 PGP key updated to 4096 Bit RSA - I will encrypt all mails if the recipient's key is known to me http://pgp.mit.edu:11371/pks/lookup?op=get&search=0xC0DE6A358A39DC66
On 3 Feb 2014, at 15:25, Stefan Winter <stefan.winter@restena.lu> wrote:
Hi,
this moved the crash to a different nuance :-/
Hmm.. that's a bit weirder.
You've HUPed the server a few times. It keeps the old config around (crappy home-brew garbage collector, really...). Then on exit, it free's the older configs. But it should only do that once.
No... this was after a fresh start, 0 packets processed. Just start and shut down.
Just tried and I can't reproduce it... Could you maybe install lldb, just so we can get proper backtraces? The syntax is similar to GDB: lldb -- <radiusd> -f -l stdout -xx run kill <radiusd.pid> bt Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
Hi,
Could you maybe install lldb, just so we can get proper backtraces?
zyper install lldb -> no such package. Do I need to compile this myself, or is that piece usually in a different package? Stefan
The syntax is similar to GDB:
lldb -- <radiusd> -f -l stdout -xx run kill <radiusd.pid> bt
Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team
FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
-- Stefan WINTER Ingenieur de Recherche Fondation RESTENA - Réseau Téléinformatique de l'Education Nationale et de la Recherche 6, rue Richard Coudenhove-Kalergi L-1359 Luxembourg Tel: +352 424409 1 Fax: +352 422473 PGP key updated to 4096 Bit RSA - I will encrypt all mails if the recipient's key is known to me http://pgp.mit.edu:11371/pks/lookup?op=get&search=0xC0DE6A358A39DC66
Hi,
Is there a minimal config which reproduces this problem?
I'm building one right now. I noticed immediately that, depending what I delete from the config, I see two distinct issues. Despite running 3.0.x from yesterday with the first fix, I still "sometimes" see "unknown value". At other config constellations, I see "access after free". Particularly, I get the "unknown value" after commenting my last occurence of an rlm_sql_null in the vserver; as soon as I *un*comment that line again, I get "access after free". Maybe the null driver is at fault? As you see below I still instantiate more sql instances than I actually use in the vserver. Maybe that exacerbates the problem. I'm attaching a gdb bt of both instances. It's both in a config with just one vserver, and stripped-down authorize. I'm minimising more gradually, but attach that one vserver config to this mail... "unknown value" (sql_null commented) ==================================== Ready to process requests. Program received signal SIGTERM, Terminated. 0x00007ffff5b048f3 in __select_nocancel () from /lib64/libc.so.6 (gdb) c Continuing. Signalled to terminate Exiting normally. rlm_sql (cuisql): Removing connection pool rlm_sql (cuisql): Closing connection (4) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (cuisql): Closing connection (3) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (cuisql): Closing connection (2) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (cuisql): Closing connection (1) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (cuisql): Closing connection (0) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (sql-imap-hash): Removing connection pool rlm_sql (sql-imap-hash): Closing connection (4) rlm_sql (sql-imap-hash): Closing connection (3) rlm_sql (sql-imap-hash): Closing connection (2) rlm_sql (sql-imap-hash): Closing connection (1) rlm_sql (sql-imap-hash): Closing connection (0) rlm_sql (sql-null-postauth): Removing connection pool rlm_sql (sql-null-postauth): Closing connection (2) rlm_sql (sql-null-postauth): Closing connection (1) rlm_sql (sql-null-postauth): Closing connection (0) rlm_sql (sql-null-lastusage): Removing connection pool rlm_sql (sql-null-lastusage): Closing connection (2) rlm_sql (sql-null-lastusage): Closing connection (1) rlm_sql (sql-null-lastusage): Closing connection (0) rlm_sql (sql-webmailsso-users): Removing connection pool rlm_sql (sql-webmailsso-users): Closing connection (4) rlm_sql (sql-webmailsso-users): Closing connection (3) rlm_sql (sql-webmailsso-users): Closing connection (2) rlm_sql (sql-webmailsso-users): Closing connection (1) rlm_sql (sql-webmailsso-users): Closing connection (0) rlm_sql (sql-null-staff-tacacsaccounting): Removing connection pool rlm_sql (sql-null-staff-tacacsaccounting): Closing connection (2) rlm_sql (sql-null-staff-tacacsaccounting): Closing connection (1) rlm_sql (sql-null-staff-tacacsaccounting): Closing connection (0) Bad talloc magic value - unknown value Program received signal SIGABRT, Aborted. 0x00007ffff5a59849 in raise () from /lib64/libc.so.6 (gdb) bt #0 0x00007ffff5a59849 in raise () from /lib64/libc.so.6 #1 0x00007ffff5a5acd8 in abort () from /lib64/libc.so.6 #2 0x00007ffff70fafac in ?? () from /usr/lib64/libtalloc.so.2 #3 0x00007ffff70fe1da in ?? () from /usr/lib64/libtalloc.so.2 #4 0x00007ffff70fde73 in ?? () from /usr/lib64/libtalloc.so.2 #5 0x00007ffff70fde73 in ?? () from /usr/lib64/libtalloc.so.2 #6 0x00007ffff70faabb in _talloc_free () from /usr/lib64/libtalloc.so.2 #7 0x00007ffff7bc13a6 in cf_file_free (cs=0x68cd30) at <command-line>:2024 #8 0x000000000041fc0d in free_mainconfig () at <command-line>:1023 #9 0x0000000000428c1f in main (argc=2, argv=0x7fffffffdc78) at <command-line>:596 (gdb) c Continuing. FATAL SIGNAL: Aborted Missing separate debuginfo for /lib64/libgcc_s.so.1 Try: zypper install -C "debuginfo(build-id)=26253bec1076626f73b8b13bed9510ae626e1ead" Backtrace of last 14 frames: /usr/local/freeradius/3.0.2-pre-201402023/lib64/libfreeradius-radius.so(+0x988f) [0x7ffff798288f] /lib64/libpthread.so.0(+0xf9f0) [0x7ffff64cb9f0] /lib64/libc.so.6(gsignal+0x39) [0x7ffff5a59849] /lib64/libc.so.6(abort+0x148) [0x7ffff5a5acd8] /usr/lib64/libtalloc.so.2(+0x2fac) [0x7ffff70fafac] /usr/lib64/libtalloc.so.2(+0x61da) [0x7ffff70fe1da] /usr/lib64/libtalloc.so.2(+0x5e73) [0x7ffff70fde73] /usr/lib64/libtalloc.so.2(+0x5e73) [0x7ffff70fde73] /usr/lib64/libtalloc.so.2(_talloc_free+0x10b) [0x7ffff70faabb] /usr/local/freeradius/3.0.2-pre-201402023/lib64/libfreeradius-server.so(cf_file_free+0x1f) [0x7ffff7bc13a6] /usr/local/freeradius/3.0.2-pre-201402023/sbin/radiusd(free_mainconfig+0x59) [0x41fc0d] /usr/local/freeradius/3.0.2-pre-201402023/sbin/radiusd(main+0xc90) [0x428c1f] /lib64/libc.so.6(__libc_start_main+0xf5) [0x7ffff5a45be5] /usr/local/freeradius/3.0.2-pre-201402023/sbin/radiusd() [0x40d7b9] No panic action set _EXIT CALLED <command-line>[261]: 1: Access after free (sql_null uncommented) ======================================== Ready to process requests. Program received signal SIGTERM, Terminated. 0x00007ffff5b048f3 in __select_nocancel () from /lib64/libc.so.6 (gdb) c Continuing. Signalled to terminate Exiting normally. rlm_sql (cuisql): Removing connection pool rlm_sql (cuisql): Closing connection (4) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (cuisql): Closing connection (3) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (cuisql): Closing connection (2) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (cuisql): Closing connection (1) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (cuisql): Closing connection (0) rlm_sql_sqlite: Socket destructor called, closing socket rlm_sql (sql-imap-hash): Removing connection pool rlm_sql (sql-imap-hash): Closing connection (4) rlm_sql (sql-imap-hash): Closing connection (3) rlm_sql (sql-imap-hash): Closing connection (2) rlm_sql (sql-imap-hash): Closing connection (1) rlm_sql (sql-imap-hash): Closing connection (0) rlm_sql (sql-null-postauth): Removing connection pool rlm_sql (sql-null-postauth): Closing connection (2) rlm_sql (sql-null-postauth): Closing connection (1) rlm_sql (sql-null-postauth): Closing connection (0) rlm_sql (sql-null-lastusage): Removing connection pool rlm_sql (sql-null-lastusage): Closing connection (2) rlm_sql (sql-null-lastusage): Closing connection (1) rlm_sql (sql-null-lastusage): Closing connection (0) rlm_sql (sql-webmailsso-users): Removing connection pool rlm_sql (sql-webmailsso-users): Closing connection (4) rlm_sql (sql-webmailsso-users): Closing connection (3) rlm_sql (sql-webmailsso-users): Closing connection (2) rlm_sql (sql-webmailsso-users): Closing connection (1) rlm_sql (sql-webmailsso-users): Closing connection (0) rlm_sql (sql-null-staff-tacacsaccounting): Removing connection pool rlm_sql (sql-null-staff-tacacsaccounting): Closing connection (2) rlm_sql (sql-null-staff-tacacsaccounting): Closing connection (1) rlm_sql (sql-null-staff-tacacsaccounting): Closing connection (0) talloc: access after free error - first free may be at <command-line>:2024 Bad talloc magic value - access after free Program received signal SIGABRT, Aborted. 0x00007ffff5a59849 in raise () from /lib64/libc.so.6 (gdb) c Continuing. FATAL SIGNAL: Aborted Missing separate debuginfo for /lib64/libgcc_s.so.1 Try: zypper install -C "debuginfo(build-id)=26253bec1076626f73b8b13bed9510ae626e1ead" Backtrace of last 15 frames: /usr/local/freeradius/3.0.2-pre-201402023/lib64/libfreeradius-radius.so(+0x988f) [0x7ffff798288f] /lib64/libpthread.so.0(+0xf9f0) [0x7ffff64cb9f0] /lib64/libc.so.6(gsignal+0x39) [0x7ffff5a59849] /lib64/libc.so.6(abort+0x148) [0x7ffff5a5acd8] /usr/lib64/libtalloc.so.2(+0x2fac) [0x7ffff70fafac] /usr/lib64/libtalloc.so.2(+0x26ff) [0x7ffff70fa6ff] /usr/lib64/libtalloc.so.2(+0x6198) [0x7ffff70fe198] /usr/lib64/libtalloc.so.2(+0x5e73) [0x7ffff70fde73] /usr/lib64/libtalloc.so.2(+0x5e73) [0x7ffff70fde73] /usr/lib64/libtalloc.so.2(_talloc_free+0x10b) [0x7ffff70faabb] /usr/local/freeradius/3.0.2-pre-201402023/lib64/libfreeradius-server.so(cf_file_free+0x1f) [0x7ffff7bc13a6] /usr/local/freeradius/3.0.2-pre-201402023/sbin/radiusd(free_mainconfig+0x59) [0x41fc0d] /usr/local/freeradius/3.0.2-pre-201402023/sbin/radiusd(main+0xc90) [0x428c1f] /lib64/libc.so.6(__libc_start_main+0xf5) [0x7ffff5a45be5] /usr/local/freeradius/3.0.2-pre-201402023/sbin/radiusd() [0x40d7b9] No panic action set _EXIT CALLED <command-line>[261]: 1: -- Stefan WINTER Ingenieur de Recherche Fondation RESTENA - Réseau Téléinformatique de l'Education Nationale et de la Recherche 6, rue Richard Coudenhove-Kalergi L-1359 Luxembourg Tel: +352 424409 1 Fax: +352 422473 PGP key updated to 4096 Bit RSA - I will encrypt all mails if the recipient's key is known to me http://pgp.mit.edu:11371/pks/lookup?op=get&search=0xC0DE6A358A39DC66
Hi,
I'm attaching a gdb bt of both instances. It's both in a config with just one vserver, and stripped-down authorize. I'm minimising more gradually, but attach that one vserver config to this mail...
Great - now the vserver is *empty* - attached. It still happens?! Must be the modules which get instantiated even though not used. I'm now deleting gradually from mods-enabled until I hopefully find the source. Stefan -- Stefan WINTER Ingenieur de Recherche Fondation RESTENA - Réseau Téléinformatique de l'Education Nationale et de la Recherche 6, rue Richard Coudenhove-Kalergi L-1359 Luxembourg Tel: +352 424409 1 Fax: +352 422473 PGP key updated to 4096 Bit RSA - I will encrypt all mails if the recipient's key is known to me http://pgp.mit.edu:11371/pks/lookup?op=get&search=0xC0DE6A358A39DC66
Hi,
Must be the modules which get instantiated even though not used. I'm now deleting gradually from mods-enabled until I hopefully find the source.
Weird. So long as I only have one instance of sql-null-* named instances, I'm good. As soon as I instantiate a second one, death by TERM. Here are the two instances I used - deleting any one of the two makes the server behave again: aragorn:/usr/local/freeradius/config/raddb/mods-enabled # cat sql-null-lastusage sql sql-null-lastusage { $INCLUDE ../sql-null-include.conf postauth_table = "lastusage" # in radius_internal post-auth { logfile = "${radacctdir}/sql-relay-common" sql_user_name = "%{%{User-Name}:-NO User-Name}" query = "INSERT INTO ${..postauth_table} \ (username, \ service, \ type) \ VALUES ( '%{User-Name}', \ '%{RESTENA-Service-Type}', \ '%{reply:Packet-Type}') \ ON DUPLICATE KEY UPDATE last_seen='%S'" } } aragorn:/usr/local/freeradius/config/raddb/mods-enabled # cat sql-null-postauth sql sql-null-postauth { $INCLUDE ../sql-null-include.conf postauth_table = "radpostauth" # in radius_internal post-auth { logfile = "${radacctdir}/sql-relay-common" sql_user_name = "%{%{User-Name}:-NO User-Name}" query = "INSERT INTO ${..postauth_table} \ (user, \ pass, \ reply, date) \ VALUES ('%{User-Name}', \ '%{RESTENA-Service-Type}', \ '%{reply:Packet-Type}', \ '%S')" } } aragorn:/usr/local/freeradius/config/raddb/mods-enabled # Both include the same template file (that's not forbidden, I hope... I used to have this for *years* now...). It's attached due to the default comments making it too big to paste. I realise that I have only defined the post-auth queries with that method (the last line in the template about queries.conf is commented); the modules only get used in post-auth. For the rest of the query set, I don't care. Greetings, Stefan Winter -- Stefan WINTER Ingenieur de Recherche Fondation RESTENA - Réseau Téléinformatique de l'Education Nationale et de la Recherche 6, rue Richard Coudenhove-Kalergi L-1359 Luxembourg Tel: +352 424409 1 Fax: +352 422473 PGP key updated to 4096 Bit RSA - I will encrypt all mails if the recipient's key is known to me http://pgp.mit.edu:11371/pks/lookup?op=get&search=0xC0DE6A358A39DC66
Stefan Winter wrote:
Weird. So long as I only have one instance of sql-null-* named instances, I'm good. As soon as I instantiate a second one, death by TERM.
OK. So there's a problem with the sql-null module. Either it double-frees something, or there's an over-run.
Here are the two instances I used - deleting any one of the two makes the server behave again:
I'll see if I can reproduce it.
Both include the same template file (that's not forbidden, I hope...
Nope. Alan DEKok.
Stefan Winter wrote:
Weird. So long as I only have one instance of sql-null-* named instances, I'm good. As soon as I instantiate a second one, death by TERM.
Hmm... I don't see that here.
Here are the two instances I used - deleting any one of the two makes the server behave again:
I can start && stop the server with both of the modules you posted. Ugh. Maybe try with the latest v3.0.x branch? Alan DeKok.
Hi,
Hm. Could you edit Make.inc and change the -imacros to -include and see if you get the same result.
I still get <command-line> . That's three occurences in one line of Make.inc - if there's more, I've overlooked the extra occurences. Stefan
If so I can change it, I don't think there'll be any side effects, they basically do the same thing, except -imacros only pulls in the preprocessor macros whereas -include would pull in function signatures too.
-Arran
Arran Cudbard-Bell <a.cudbardb@freeradius.org> FreeRADIUS Development Team
FD31 3077 42EC 7FCD 32FE 5EE2 56CF 27F9 30A8 CAA2
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
-- Stefan WINTER Ingenieur de Recherche Fondation RESTENA - Réseau Téléinformatique de l'Education Nationale et de la Recherche 6, rue Richard Coudenhove-Kalergi L-1359 Luxembourg Tel: +352 424409 1 Fax: +352 422473 PGP key updated to 4096 Bit RSA - I will encrypt all mails if the recipient's key is known to me http://pgp.mit.edu:11371/pks/lookup?op=get&search=0xC0DE6A358A39DC66
participants (4)
-
A.L.M.Buxey＠lboro.ac.uk -
Alan DeKok -
Arran Cudbard-Bell -
Stefan Winter