2.2.0 crash at a strange location

Stefan Winter stefan.winter at restena.lu
Mon May 6 11:28:48 CEST 2013


Hi one more time,

and another update: it's one specific SSHA1-Hash which makes the server crash; I can reproduce this easily.

The magic hash value is:

SSHA1-Password := PVwqvpqoyQBACLE3Nxk2ItoDjx1RT3JyKm9SdkRTb1o5aSUm

and makes things fail specifically during a memcpy inside normify().
Below is what valgrind has to say. Note that the user input in 
User-Password is irrelevant; failure is before it's even checked.

HTH,

Stefan

Found Auth-Type = PAP
# Executing group from file /usr/local/freeradius/config/raddb/sites-enabled/SMTP
+- entering group PAP {...}
++- entering policy pap_hash_debugfallback {...}
+++- entering group  {...}
[pap] login attempt with password "foopass"
[pap] Using SSHA encryption.
[pap] Normalizing SSHA1-Password from base64 encoding
==13555== 
==13555== Process terminating with default action of signal 11 (SIGSEGV)
==13555==  Access not within mapped region at address 0x7FF001000
==13555==    at 0x4C2C476: memcpy@@GLIBC_2.14 (in /usr/lib64/valgrind/vgpreload_memcheck-amd64-linux.so)
==13555==    by 0x874B643: normify (rlm_pap.c:273)
==13555==    by 0x874BDDF: pap_authenticate (rlm_pap.c:707)
==13555==    by 0x41D764: modcall (modcall.c:304)
==13555==    by 0x41BF38: indexed_modcall (modules.c:740)
==13555==    by 0x40B176: rad_authenticate (auth.c:382)
==13555==    by 0x4296E4: radius_handle_request (event.c:3784)
==13555==    by 0x422227: thread_pool_addrequest (threads.c:887)
==13555==    by 0x4272E5: event_socket_handler (event.c:3429)
==13555==    by 0x4E4A2B4: fr_event_loop (event.c:415)
==13555==    by 0x409F53: main (radiusd.c:408)
==13555==  If you believe this happened as a result of a stack
==13555==  overflow in your program's main thread (unlikely but
==13555==  possible), you can try to increase the size of the
==13555==  main thread stack using the --main-stacksize= flag.
==13555==  The main thread stack size used in this run was 8388608.
==13555== 
==13555== ---- Attach to debugger ? --- [Return/N/n/Y/y/C/c] ---- --13555-- VALGRIND INTERNAL ERROR: Valgrind received a signal 11 (SIGSEGV) - exiting
--13555-- si_code=1;  Faulting address: 0xC2394B0;  sp: 0x402bda060

valgrind: the 'impossible' happened:
   Killed by fatal signal
==13555==    at 0x38057958: ??? (in /usr/lib64/valgrind/memcheck-amd64-linux)
==13555==    by 0x3802124C: ??? (in /usr/lib64/valgrind/memcheck-amd64-linux)
==13555==    by 0x380213DA: ??? (in /usr/lib64/valgrind/memcheck-amd64-linux)
==13555==    by 0x3808F8D4: ??? (in /usr/lib64/valgrind/memcheck-amd64-linux)
==13555==    by 0x380551FF: ??? (in /usr/lib64/valgrind/memcheck-amd64-linux)
==13555==    by 0x38055304: ??? (in /usr/lib64/valgrind/memcheck-amd64-linux)
==13555==    by 0x3809EA61: ??? (in /usr/lib64/valgrind/memcheck-amd64-linux)

sched status:
  running_tid=1

Thread 1: status = VgTs_Runnable
==13555==    at 0x4C2ABED: malloc (in /usr/lib64/valgrind/vgpreload_memcheck-amd64-linux.so)
==13555==    by 0x4013B76: _dl_close_worker (in /lib64/ld-2.15.so)
==13555==    by 0x40140AB: _dl_close (in /lib64/ld-2.15.so)
==13555==    by 0x400E5F5: _dl_catch_error (in /lib64/ld-2.15.so)
==13555==    by 0x64543CE: dlerror_run (in /lib64/libc-2.15.so)
==13555==    by 0x6485946: free_mem (in /lib64/libc-2.15.so)
==13555==    by 0x6485691: __libc_freeres (in /lib64/libc-2.15.so)
==13555==    by 0x4A246EC: _vgnU_freeres (in /usr/lib64/valgrind/vgpreload_core-amd64-linux.so)
==13555==    by 0x801604F: ???
==13555==    by 0x874B643: normify (rlm_pap.c:273)
==13555==    by 0x874BDDF: pap_authenticate (rlm_pap.c:707)
==13555==    by 0x41D764: modcall (modcall.c:304)
==13555==    by 0x41BF38: indexed_modcall (modules.c:740)
==13555==    by 0x40B176: rad_authenticate (auth.c:382)
==13555==    by 0x4296E4: radius_handle_request (event.c:3784)
==13555==    by 0x422227: thread_pool_addrequest (threads.c:887)
==13555==    by 0x4272E5: event_socket_handler (event.c:3429)
==13555==    by 0x4E4A2B4: fr_event_loop (event.c:415)
==13555==    by 0x409F53: main (radiusd.c:408)


Note: see also the FAQ in the source distribution.
It contains workarounds to several common problems.
In particular, if Valgrind aborted or crashed after
identifying problems in your program, there's a good chance
that fixing those problems will prevent Valgrind aborting or
crashing, especially if it happened in m_mallocfree.c.

If that doesn't help, please report this bug to: www.valgrind.org

In the bug report, send all the above text, the valgrind
version, and what OS and version you are using.  Thanks.

On 06.05.2013 10:48, Stefan Winter wrote:
> Hi again,
> 
> running with -X I get:
> 
> rlm_sql_mysql: query:  (SELECT id, username, attribute, value, op FROM check_smtp_ssha1 WHERE username='someusername')
> [sql-smtp-hash] User found in radcheck table
> rlm_sql (sql-smtp-hash): Released sql socket id: 1
> +++[sql-smtp-hash] returns ok
> ++- policy redundant returns ok
> [pap] Normalizing SSHA1-Password from base64 encoding
> ++[pap] returns updated
> Found Auth-Type = PAP
> # Executing group from file /usr/local/freeradius/config/raddb/sites-enabled/SMTP
> +- entering group PAP {...}
> ++- entering policy pap_hash_debugfallback {...}
> +++- entering group  {...}
> [pap] login attempt with password "eq346ici"
> [pap] Using SSHA encryption.
> [pap] Normalizing SSHA1-Password from base64 encoding
> Segmentation fault
> 
> Which is before the linelog is reached, so *maybe* the source of the problem is in the base64 normalisation code?
> 
> Stefan
> 
> On 06.05.2013 10:30, Stefan Winter wrote:
>> Hi,
>>
>> today I did some minor config changes which turned my stable-running
>> 2.2.0 into a crash-every-5-min server :-(
>>
>> The change involved 
>> a) switching from Cleartext-Password to SSHA1-Password (retaining the
>>    pap module for checking the PW validity)
>> b) a somewhat sophisticated unlang statement to express: if the SSHA1-PW
>>    was wrong, retrieve an alternative password from a VSA 
>>    ("RESTENA-Debug-Password") and set it to be the Cleartext-Password;
>>    then try pap again with that
>>
>> This is obviously the implementation of a "backdoor" for our helpdesk
>> if we need to login into a user's account for debugging without knowing
>> his actual password because it's SSHA'ed in the DB.
>>
>> All nice and cute, and it worked while doing "mild" usage with a test
>> account - but now in production things go down the drain with it.
>>
>> I've temporarily switched back to the previous SQL query which had
>> Cleartext-Password. And voilà: the server is stable again. Even with
>> the unlang construct still in place (below for reference).
>>
>> So I strongly suspect things to go wrong *only if* SSHA1-Passwords
>> are used to authenticate the user. 
>>
>> Strangely enough, the gdb backtrace shows that it fails somewhere inside
>> glibc while trying to expand a %S in xlat - which appears totally
>> unrelated to the changes I did. The backtrace is below.
>>
>> policy.conf: replacement for authenticate/pap:
>>
>> policy {
>>
>>         pap_hash_debugfallback {
>>                 group {
>>                         pap {
>>                                 reject = 2
>>                                 ok = return
>>                         }
>>
>>                         if ( "%{control:RESTENA-Debug-Password}" ) {
>>                                 update control {
>>                                         SSHA1-Password !* "nogood"
>>                                         NT-Password !* "nogood"
>>                                         Cleartext-Password := "%{control:RESTENA-Debug-Password}"
>>                                 }
>>                                 ok = 1 
>>                                 ok
>>                         }
>>                         
>>                         pap {
>>                                 reject = 2
>>                                 ok = return
>>                         }
>>                 }
>>         }
>> ...
>> }
>>
>>
>> Program received signal SIGSEGV, Segmentation fault.
>> [Switching to Thread 0x4b015950 (LWP 24837)]
>> 0x00002b380d7d5550 in ?? () from /lib64/libc.so.6
>> (gdb) bt
>> #0  0x00002b380d7d5550 in ?? () from /lib64/libc.so.6
>> #1  0x00002b380d7d6c0c in malloc () from /lib64/libc.so.6
>> #2  0x00002b380d7da8f2 in strdup () from /lib64/libc.so.6
>> #3  0x00002b380d7ed928 in ?? () from /lib64/libc.so.6
>> #4  0x00002b380d7ee3f0 in tzset () from /lib64/libc.so.6
>> #5  0x00002b380d7f2c94 in strftime_l () from /lib64/libc.so.6
>> #6  0x000000000042277d in radius_xlat (out=0x4b013a30 "[Access-Accept", outlen=1023, fmt=0x667c4e "[%S] [AUTH OK   ] '%{User-Name}' (%{RESTENA-Service-Type}:%{client:shortname})", request=0x2aaab0001f60, 
>>     func=0x2aaaab2e33d0 <linelog_escape_func>) at xlat.c:1348
>> #7  0x00002aaaab2e31d4 in do_linelog (instance=0x835a60, request=0x2aaab0001f60) at rlm_linelog.c:328
>> #8  0x000000000041c920 in modcall (component=7, c=<value optimized out>, request=0x2aaab0001f60) at modcall.c:304
>> #9  0x0000000000419be8 in indexed_modcall (comp=0, idx=0, request=0x2aaab0001f60) at modules.c:740
>> #10 0x00000000004094fd in rad_postauth (request=0x2aaab0001f60) at auth.c:433
>> #11 0x0000000000409b83 in rad_authenticate (request=0x2aaab0001f60) at auth.c:831
>> #12 0x0000000000427538 in radius_handle_request (request=0x2aaab0001f60, fun=0x409540 <rad_authenticate>) at event.c:3784
>> #13 0x0000000000420728 in request_handler_thread (arg=<value optimized out>) at threads.c:537
>> #14 0x00002b380c8d8020 in start_thread () from /lib64/libpthread.so.0
>> #15 0x00002b380d829f8d in clone () from /lib64/libc.so.6
>> #16 0x0000000000000000 in ?? ()
>> (gdb) bt full
>> #0  0x00002b380d7d5550 in ?? () from /lib64/libc.so.6
>> No symbol table info available.
>> #1  0x00002b380d7d6c0c in malloc () from /lib64/libc.so.6
>> No symbol table info available.
>> #2  0x00002b380d7da8f2 in strdup () from /lib64/libc.so.6
>> No symbol table info available.
>> #3  0x00002b380d7ed928 in ?? () from /lib64/libc.so.6
>> No symbol table info available.
>> #4  0x00002b380d7ee3f0 in tzset () from /lib64/libc.so.6
>> No symbol table info available.
>> #5  0x00002b380d7f2c94 in strftime_l () from /lib64/libc.so.6
>> No symbol table info available.
>> #6  0x000000000042277d in radius_xlat (out=0x4b013a30 "[Access-Accept", outlen=1023, fmt=0x667c4e "[%S] [AUTH OK   ] '%{User-Name}' (%{RESTENA-Service-Type}:%{client:shortname})", request=0x2aaab0001f60, 
>>     func=0x2aaaab2e33d0 <linelog_escape_func>) at xlat.c:1348
>>         c = <value optimized out>
>>         len = <value optimized out>
>>         freespace = <value optimized out>
>>         p = 0x667c50 "S] [AUTH OK   ] '%{User-Name}' (%{RESTENA-Service-Type}:%{client:shortname})"
>>         q = 0x4b013a31 "Access-Accept"
>>         tmp = (VALUE_PAIR *) 0x2aaab0001f60
>>         TM = (struct tm *) 0x3
>>         s_TM = {tm_sec = 45, tm_min = 15, tm_hour = 10, tm_mday = 6, tm_mon = 4, tm_year = 113, tm_wday = 1, tm_yday = 125, tm_isdst = 1, tm_gmtoff = 7200, tm_zone = 0x807da0 "CEST"}
>>         tmpdt = "\000\020\000\000\000\000\000\000\000\020\000\000\000\000\000\000\b\000\000\000\000\000\000\000\236A�G", '\0' <repeats 11 times>
>> #7  0x00002aaaab2e31d4 in do_linelog (instance=0x835a60, request=0x2aaab0001f60) at rlm_linelog.c:328
>>         ci = <value optimized out>
>>         cp = <value optimized out>
>>         fd = 56
>>         buffer = "/var/log/radius/activity.log\000+\000\000�*\001K\001\000\000\000�+\001K\000\000\000\000�X\001K\000\000\000\000\000�\213\000\000\000\000\000\005\000\000\000\000\000\000\000�>\000��*\000\000\000\000\000\000\000\000\000\000�>\000��*\000\000\n\000\000\000\000\000\000\000�>\000��*\000\000P>\001K\000\000\000\000�w�\0178+\000\000:=\000\000\000\000\000\000\030", '\0' <repeats 15 times>, "�\025B\000\000\000\000\000\000�\213\000\000\000\000\000�*\001K\000\000\000\000P>\001K\000\000\000\000`\037\000��*\000\000\000\000\002\000\000\000\000\000\220�\213\000\000"...
>>         p = <value optimized out>
>>         line = "[Access-Accept", '\0' <repeats 434 times>, "Mon May  6 10:15:45 2013\000\000\000\000\000\000\000\000Mon May  6 10:15:45 2013", '\0' <repeats 116 times>, "\024\000\000\000`\001\000\000\000\000\000\0008\001\000\000\000\000\000\000\000\000\000\000\024", '\0' <repeats 35 times>, "\202\230'\f8+\000\000`\003j\000\000\000\000\000 \000\000��*\000\0008\001", '\0' <repeats 14 times>, "\001\000\000\000\000\000\000\000`\037\000��*\000\0000}\203\000\000\000\000\000\fl}\r8+\000\000�\204|", '\0' <repeats 13 times>...
>>         value = 0x667c4e "[%S] [AUTH OK   ] '%{User-Name}' (%{RESTENA-Service-Type}:%{client:shortname})"
>>         gid = <value optimized out>
>>         grp = (struct group *) 0x0
>>         endptr = 0x6889fc ")"
>> #8  0x000000000041c920 in modcall (component=7, c=<value optimized out>, request=0x2aaab0001f60) at modcall.c:304
>>         server = <value optimized out>
>>         myresult = 1
>>         stack = {pointer = 0, priority = {0, 0, 3, 0, 0, 0, 0, 0, 0, 3, 0, 3, 0 <repeats 20 times>}, result = {7, 7, 2, 0, 0, 0, 0, 0, 0, 2, 2, 2, 2, 0 <repeats 19 times>}, children = {0x8f2910, 0x8f2730, 0x8f2800, 0x0, 
>>     0x837410, 0x0 <repeats 27 times>}, start = {0x0, 0x8f2730, 0x8f27a0, 0x0, 0x0, 0x837480, 0x8374f0, 0x8af080, 0x8e3ec0, 0x0 <repeats 23 times>}}
>>         parent = (modcallable *) 0x8f2730
>>         child = (modcallable *) 0x8f2800
>>         if_taken = 0
>>         was_if = 0
>> #9  0x0000000000419be8 in indexed_modcall (comp=0, idx=0, request=0x2aaab0001f60) at modules.c:740
>>         this = <value optimized out>
>>         rcode = <value optimized out>
>>         list = (modcallable *) 0x8f2910
>>         server = (virtual_server_t *) 0x837330
>> #10 0x00000000004094fd in rad_postauth (request=0x2aaab0001f60) at auth.c:433
>>         result = <value optimized out>
>>         postauth_type = 0
>>         vp = (VALUE_PAIR *) 0x0
>> #11 0x0000000000409b83 in rad_authenticate (request=0x2aaab0001f60) at auth.c:831
>>         namepair = (VALUE_PAIR *) 0x9a71f0
>>         check_item = (VALUE_PAIR *) 0x0
>>         auth_item = (VALUE_PAIR *) 0x9a8c10
>>         module_msg = <value optimized out>
>>         tmp = (VALUE_PAIR *) 0x0
>>         result = -1275060192
>>         autz_retry = <value optimized out>
>>         autz_type = <value optimized out>
>> #12 0x0000000000427538 in radius_handle_request (request=0x2aaab0001f60, fun=0x409540 <rad_authenticate>) at event.c:3784
>> ---Type <return> to continue, or q <return> to quit---
>> No locals.
>> #13 0x0000000000420728 in request_handler_thread (arg=<value optimized out>) at threads.c:537
>>         fun = (RAD_REQUEST_FUNP) 0x409540 <rad_authenticate>
>>         self = (THREAD_HANDLE *) 0x2aaab4001fe0
>> #14 0x00002b380c8d8020 in start_thread () from /lib64/libpthread.so.0
>> No symbol table info available.
>> #15 0x00002b380d829f8d in clone () from /lib64/libc.so.6
>> No symbol table info available.
>> #16 0x0000000000000000 in ?? ()
>> No symbol table info available.
>> (gdb)
>>
>>
>>
>> -
>> List info/subscribe/unsubscribe? See http://www.freeradius.org/list/devel.html
>>
> 
> 
> 
> 
> -
> 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

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 263 bytes
Desc: OpenPGP digital signature
URL: <http://lists.freeradius.org/pipermail/freeradius-devel/attachments/20130506/a3ff7811/attachment.pgp>


More information about the Freeradius-Devel mailing list