Re: Freeradius crashing due to load?

5 Apr 2018

      Maybe there's something which blocks TCP connections.

- Checked all tcp connections, found them to be working well.

Ran it under GDB, not able to find much. maybe not able to find it(dont
know how to read it)
This is the panic command which ran
gdb -silent -x /usr/local/etc/raddb/panic.gdb /usr/local/sbin/radiusd 5678
2>&1 | tee /usr/local/var/log/radius/gdb-radiusd-5678.log

But I see a thread querying a php program from exec. but I think it returns
OK. Is this the problem causing part? Can you help me in finding the
problem? below are the part of GDB logs

Thread 4 (Thread 0x7f559b5fe700 (LWP 967)):
#0  0x00007f5624d71c4d in nanosleep () from /lib64/libc.so.6
No symbol table info available.
#1  0x00007f5624da6e94 in usleep () from /lib64/libc.so.6
No symbol table info available.
#2  0x000000000042bfce in rad_waitpid (pid=1006, status=0x7f559b5fbd2c) at
src/main/threads.c:1354
        i = <value optimized out>
        mytf = {pid = 1006, status = 0, exited = 0}
        tf = 0x7f55f010d6b0
#3  0x00007f56267ebad0 in radius_readfrom_program (fd=55, pid=1006,
timeout=10, answer=0x7f559b5fbda0 "10485760000\nU\177", left=4084) at
src/main/exec.c:446
        rcode = <value optimized out>
        fds = {fds_bits = {0 <repeats 16 times>}}
        when = {tv_sec = 10, tv_usec = 0}
        wake = {tv_sec = 0, tv_usec = 0}
        elapsed = <value optimized out>
        done = <value optimized out>
        status = 12
        start = {tv_sec = 1522052474, tv_usec = 715900}
        nonblock = true
#4  0x00007f56267ec1fb in radius_exec_program (ctx=0xc88330,
out=0x7f55f00414e0 "", outlen=2048, output_pairs=0x0, request=0xc88330,
cmd=0x7f55f010f750 " /var/www/html/internal_api/get_attributes.php
GUEST_DATA_LIMIT", input_pairs=0x7f55f01c9d30, exec_wait=true,
shell_escape=true, timeout=10) at src/main/exec.c:555
        pid = 1006
        from_child = 55
        p = <value optimized out>
        child_pid = <value optimized out>
        comma = 0
        status = <value optimized out>
        ret = 0
        len = <value optimized out>
        answer = "10485760000\nU\177\000\000\306\236t
V\177\000\000\327\217\320$V\177\000\000\306\236t
V\177\000\000\000\000\000\000\000\000\000\000\001", '\000' <repeats 11
times>, "\002", '\000' <repeats 35 times>,
"p\303_\233U\177\000\000\000\000\000\000\000\000\000\000\302\236t
V\177\000\000@'\005%V\177", '\000' <repeats 18 times>"\334,
\303_\233U\177\000\000\370\303_\233U\177\000\000\006\000\000\000\000\000\000\000\030\304_\233U\177\000\000\000\004\000\000\000\000\000\000(A\321$V\177\000\000\030\000\000\000\060\000\000\000@\277_\233U\177\000\000\000\000\000\000U\177",
'\000' <repeats 14 times>,
"F\303_\233`\277_\233U\177\000\000\377\377\377\377\377\377\377\377\320\303_\233U\177\000\000\000\000\000\000\000\000\000\000`\300_\233U\177\000\000\377\003\000\000\000\000\000\000"...
#5  0x00007f56246b7edd in exec_xlat (instance=0xc0cbb0, request=0xc88330,
fmt=<value optimized out>, out=0x7f55f00414e0 "", outlen=2048) at
src/modules/rlm_exec/rlm_exec.c:182
        result = <value optimized out>
        inst = 0xc0cbb0
        input_pairs = <value optimized out>
        p = <value optimized out>
#6  0x00007f56267fbfe4 in xlat_aprint (ctx=0xc88330, request=0xc88330,
node=0xf6cd80, escape=0, escape_ctx=0x0, lvl=0) at src/main/xlat.c:2320
        rcode = <value optimized out>
        str = 0x7f55f00414e0 ""
        child = 0x7f55f010f750 "
/var/www/html/internal_api/get_attributes.php GUEST_DATA_LIMIT"
        p = <value optimized out>
#7  0x00007f56267fcb41 in xlat_process (out=0x7f559b5fcfa8,
request=0xc88330, head=<value optimized out>, escape=0, escape_ctx=0x0) at
src/main/xlat.c:2410
        i = <value optimized out>
        list = <value optimized out>
        total = <value optimized out>
        array = <value optimized out>
        answer = <value optimized out>
        node = <value optimized out>
#8  0x00007f56267fcba4 in xlat_expand_struct (out=0x7f559b5fd190, outlen=0,
request=<value optimized out>, node=<value optimized out>, escape=<value
optimized out>, escape_ctx=<value optimized out>) at src/main/xlat.c:2482
        buff = 0x0
        len = <value optimized out>
#9  0x00007f56267f3965 in tmpl_aexpand (ctx=0xc88330, out=0x7f559b5fd190,
request=0xc88330, vpt=0xbb6750, escape=0, escape_ctx=<value optimized out>)
at src/main/tmpl.c:1514
        vp = <value optimized out>
        slen = -1
#10 0x00007f56267eaf11 in cond_normalise_and_cmp (request=0xc88330,
c=0xbb6130, lhs_type=PW_TYPE_STRING, lhs_enumv=0x0, lhs=0x7f559b5fd210,
lhs_len=8) at src/main/evaluate.c:563
        p = <value optimized out>
        ret = <value optimized out>
        data = {strvalue = 0x7f5626a0b564 "", octets = 0x7f5626a0b564 "",
integer = 648066404, ipaddr = {s_addr = 648066404}, date = 648066404,
filter = {140007991981412, 140007989787096, 34, 11672224}, ifid =
"d\265\240&V\177\000", ipv6addr = {__in6_u = {__u6_addr8 =
"d\265\240&V\177\000\000\330\071\177&V\177\000", __u6_addr16 = {46436,
9888, 32598, 0, 14808, 9855, 32598, 0}, __u6_addr32 = {648066404, 32598,
645872088, 32598}}}, ipv6prefix =
"d\265\240&V\177\000\000\330\071\177&V\177\000\000\"", byte = 100 'd',
ushort = 46436, ether = "d\265\240&V\177", sinteger = 648066404, integer64
= 140007991981412, ipv4prefix = "d\265\240&V\177", ptr = 0x7f5626a0b564}
        map = 0xbb61d0
        cast = <value optimized out>
        cast_type = PW_TYPE_INVALID
        rcode = <value optimized out>
        rhs_type = PW_TYPE_INVALID
        rhs_enumv = 0x0
        rhs = 0x0
        rhs_len = <value optimized out>
        lhs_cast = {strvalue = 0x7f55f01cedd0 "95535243", octets =
0x7f55f01cedd0 "95535243", integer = 4028427728, ipaddr = {s_addr =
4028427728}, date = 4028427728, filter = {140007077375440, 140007989798589,
13139969, 13147840}, ifid = "\320\355\034\360U\177\000", ipv6addr =
{__in6_u = {__u6_addr8 =
"\320\355\034\360U\177\000\000\275f\177&V\177\000", __u6_addr16 = {60880,
61468, 32597, 0, 26301, 9855, 32598, 0}, __u6_addr32 = {4028427728, 32597,
645883581, 32598}}}, ipv6prefix =
"\320\355\034\360U\177\000\000\275f\177&V\177\000\000\001\200", byte = 208
'\320', ushort = 60880, ether = "\320\355\034\360U\177", sinteger =
-266539568, integer64 = 140007077375440, ipv4prefix =
"\320\355\034\360U\177", ptr = 0x7f55f01cedd0}
        rhs_cast = {strvalue = 0x7f559b5fd260 "0\203\310", octets =
0x7f559b5fd260 "0\203\310", integer = 2606748256, ipaddr = {s_addr =
2606748256}, date = 2606748256, filter = {140005655695968, 140005655695976,
8391101543934948398, 8751168581018742895}, ifid = "`\322_\233U\177\000",
ipv6addr = {__in6_u = {__u6_addr8 =
"`\322_\233U\177\000\000h\322_\233U\177\000", __u6_addr16 = {53856, 39775,
32597, 0, 53864, 39775, 32597, 0}, __u6_addr32 = {2606748256, 32597,
2606748264, 32597}}}, ipv6prefix =
"`\322_\233U\177\000\000h\322_\233U\177\000\000.t", byte = 96 '`', ushort =
53856, ether = "`\322_\233U\177", sinteger = -1688219040, integer64 =
140005655695968, ipv4prefix = "`\322_\233U\177", ptr = 0x7f559b5fd260}
        lhs_cast_buff = 0x0
        rhs_cast_buff = 0x0
        escape = <value optimized out>
#11 0x00007f56267eb4a5 in radius_evaluate_map (request=0xc88330,
modreturn=<value optimized out>, depth=<value optimized out>, c=0xbb6130)
at src/main/evaluate.c:700
        ret = <value optimized out>
        data = {strvalue = 0x7f55f01cedd0 "95535243", octets =
0x7f55f01cedd0 "95535243", integer = 4028427728, ipaddr = {s_addr =
4028427728}, date = 4028427728, filter = {140007077375440,
18446744073709551615, 18446744073709551615, 18446744073709551615}, ifid =
"\320\355\034\360U\177\000", ipv6addr = {__in6_u = {__u6_addr8 =
"\320\355\034\360U\177\000\000\377\377\377\377\377\377\377\377",
__u6_addr16 = {60880, 61468, 32597, 0, 65535, 65535, 65535, 65535},
__u6_addr32 = {4028427728, 32597, 4294967295, 4294967295}}}, ipv6prefix =
"\320\355\034\360U\177\000\000\377\377\377\377\377\377\377\377\377\377",
byte = 208 '\320', ushort = 60880, ether = "\320\355\034\360U\177",
sinteger = -266539568, integer64 = 140007077375440, ipv4prefix =
"\320\355\034\360U\177", ptr = 0x7f55f01cedd0}
        rcode = 0
        map = 0xbb61d0
#12 0x00007f56267eb7a1 in radius_evaluate_cond (request=0xc88330,
modreturn=2, depth=0, c=<value optimized out>) at src/main/evaluate.c:750
        rcode = <value optimized out>
#13 0x000000000042514c in modcall_recurse (request=0xc88330,
component=MOD_ACCOUNTING, depth=2, entry=0x7f559b5fdaa0,
do_next_sibling=true) at src/main/modcall.c:479
        condition = <value optimized out>
        g = 0xf3a4c0
        if_taken = <value optimized out>
        was_if = <value optimized out>
        c = <value optimized out>
        priority = <value optimized out>
        result = RLM_MODULE_OK
#14 0x00000000004263ea in modcall_child (request=<value optimized out>,
component=<value optimized out>, depth=<value optimized out>,
entry=0x7f559b5fda88, c=<value optimized out>, result=0x7f559b5fd78c,
do_next_sibling=true) at src/main/modcall.c:408
        next = 0x7f559b5fdaa0
#15 0x00000000004251d5 in modcall_recurse (request=0xc88330,
component=MOD_ACCOUNTING, depth=1, entry=0x7f559b5fda88,
do_next_sibling=true) at src/main/modcall.c:785
        g = 0xf3a300
        if_taken = true
        was_if = true
        c = <value optimized out>
        priority = <value optimized out>
        result = RLM_MODULE_NOOP
#16 0x00000000004263ea in modcall_child (request=<value optimized out>,
component=<value optimized out>, depth=<value optimized out>,
entry=0x7f559b5fda70, c=<value optimized out>, result=0x7f559b5fda2c,
do_next_sibling=true) at src/main/modcall.c:408
        next = 0x7f559b5fda88
#17 0x00000000004251d5 in modcall_recurse (request=0xc88330,
component=MOD_ACCOUNTING, depth=0, entry=0x7f559b5fda70,
do_next_sibling=true) at src/main/modcall.c:785
        g = 0xf39a50
        if_taken = false
        was_if = false
        c = <value optimized out>
        priority = <value optimized out>
        result = RLM_MODULE_UNKNOWN
#18 0x0000000000426383 in modcall (component=<value optimized out>,
c=<value optimized out>, request=<value optimized out>) at
src/main/modcall.c:1130
        stack = {{result = RLM_MODULE_NOOP, priority = 0, unwind = 0, c =
0xf39a50}, {result = RLM_MODULE_NOOP, priority = 1, unwind = 0, c =
0xf3a300}, {result = RLM_MODULE_OK, priority = 2, unwind = 0, c =
0xf3a4c0}, {result = RLM_MODULE_NOOP, priority = 1, unwind = 0, c = 0x0},
{result = 13140653, priority = 0, unwind = 0, c = 0xc88e48}, {result = 47,
priority = 0, unwind = -1688216528, c = 0x0}, {result = 100663296, priority
= 0, unwind = 473, c = 0x932a70}, {result = 2606750552, priority = 32597,
unwind = -268168912, c = 0xdc86e0}, {result = 14452496, priority = 0,
unwind = 638003378, c = 0x7f559b5fdb90}, {result = 638009003, priority =
32598, unwind = 0, c = 0x0}, {result = RLM_MODULE_REJECT, priority = 0,
unwind = -1688216080, c = 0x7f559b5fdb90}, {result = 638009424, priority =
32598, unwind = 0, c = 0x0}, {result = RLM_MODULE_REJECT, priority = 0,
unwind = -1688213760, c = 0x0}, {result = RLM_MODULE_REJECT, priority = 0,
unwind = 0, c = 0x0}, {result = RLM_MODULE_REJECT, priority = 0, unwind =
0, c = 0x0}, {result = RLM_MODULE_REJECT, priority = 0, unwind =
-1688216320, c = 0x10}, {result = 2606750752, priority = 32597, unwind = 1,
c = 0x7f559b5fdae0}, {result = 32, priority = 0, unwind = 0, c = 0x0},
{result = 15079056, priority = 0, unwind = 20, c = 0xc88e40}, {result =
4381689, priority = 0, unwind = 27, c = 0x7f559b5fdd00}, {result =
4294967295, priority = 0, unwind = 13140080, c = 0xc882ab}, {result =
RLM_MODULE_REJECT, priority = 0, unwind = 13140080, c = 0x7f559b5fddb0},
{result = 2606751152, priority = 32597, unwind = 643553695, c = 0x1b},
{result = 27, priority = 0, unwind = -1688216144, c = 0x7f559b5fdd10},
{result = 29, priority = 0, unwind = 12588288, c = 0xc88170}, {result =
643536663, priority = 32598, unwind = 28, c = 0xc89b78}, {result =
RLM_MODULE_REJECT, priority = 0, unwind = 13140651, c = 0xc88070}, {result
= 643554284, priority = 32598, unwind = -1688216144, c = 0x48}, {result =
3978007402, priority = 1973628208, unwind = 0, c = 0xc01500}, {result =
2606751160, priority = 32597, unwind = 0, c = 0x0}, {result =
RLM_MODULE_REJECT, priority = 0, unwind = 0, c = 0xc885f0}, {result =
4322832, priority = 0, unwind = -1688216160, c = 0xc88330}}
#19 0x000000000041f9c5 in indexed_modcall (comp=MOD_ACCOUNTING, idx=0,
request=0xc88330) at src/main/modules.c:1028
        rcode = <value optimized out>
        list = 0xf39a50
        server = 0xf2d5c0
#20 0x000000000040ea37 in rad_accounting (request=0xc88330) at
src/main/acct.c:93
        vp = <value optimized out>
        acct_type = 0
        result = <value optimized out>
#21 0x0000000000433dda in request_running (request=0xc88330, action=<value
optimized out>) at src/main/process.c:1527
        __FUNCTION__ = "request_running"
#22 0x000000000042cb4a in request_handler_thread (arg=0xdc86e0) at
src/main/threads.c:690
        self = 0xdc86e0
#23 0x00007f5625297aa1 in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#24 0x00007f5624dadbcd in clone () from /lib64/libc.so.6
No symbol table info available.

On Mar 1, 2018, at 2:29 AM, 8zero2 operations <8zero2ops@gmail.com> wrote:
...
...
I am attaching error logs of freeradius getting crashed randomly during
day.
...
...
Thu Mar  1 11:45:24 2018 : Error: (1304488) Ignoring duplicate packet
from
client XXXXXXXX port 44953 - ID: 35 due to unfinished request in
component
authorize module
Something is blocking the server.  Fix that.
It's usually the SQL module...
...
Thu Mar  1 11:45:34 2018 : ERROR: (1304618)       ERROR: Timeout waiting
for child
Yes.  The child thread is being blocked.
...
I have database server modules enabled of sql and ldap. I have monitored
them and there is no considerable load on them when this crash happens.
That doesn't matter.  What matters is that the client library isn't
returning to FreeRADIUS.
Maybe there's something which blocks TCP connections.
...
How can I debug it and find which module is unresponsive while crash?
Just
point a finger to a direction i will find the way.
Run it under gdb.  See doc/bugs for details.
Alan DeKok.
-
List info/subscribe/unsubscribe? See http://www.freeradius.org/
list/users.html