Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[defect]: ASSERT FAILED src/main/threads.c[794]: request->child_state == REQUEST_QUEUED #5512

Open
krtzsu opened this issue Feb 8, 2025 · 0 comments
Labels
defect category: a defect or misbehaviour

Comments

@krtzsu
Copy link

krtzsu commented Feb 8, 2025

What type of defect/bug is this?

Crash or memory corruption (segv, abort, etc...)

How can the issue be reproduced?

During a spike of authentication requests DB started to block threads and after a few seconds the v3.2.7 server crashed in assertion check. I have just started to use 3.2.x branch and cannot say is it a newly introduced issue.

Log output from the FreeRADIUS daemon

2025-02-08 00:00:11.569493 err 1 requests have been waiting in the processing queue for 7 seconds.  Check that all databases are running properly!
2025-02-08 00:00:11.577178 err (32911) Ignoring duplicate packet from client nas01c port 65360 - ID: 92 due to unfinished request in component <core> module <queue>
2025-02-08 00:00:11.577374 err (33113) Ignoring duplicate packet from client nas01c port 65360 - ID: 137 due to unfinished request in component <core> module <queue>
2025-02-08 00:00:11.577438 err (32854) Ignoring duplicate packet from client nas01c port 65348 - ID: 78 due to unfinished request in component <core> module <queue>
2025-02-08 00:00:11.577497 err (32879) Ignoring duplicate packet from client nas01c port 65356 - ID: 221 due to unfinished request in component <core> module <queue>
2025-02-08 00:00:11.577529 err (32937) Ignoring duplicate packet from client nas01c port 65356 - ID: 113 due to unfinished request in component <core> module <queue>
2025-02-08 00:00:11.577562 err (33031) Ignoring duplicate packet from client nas01c port 65356 - ID: 27 due to unfinished request in component <core> module <queue>
2025-02-08 00:00:11.578726 err ASSERT FAILED src/main/threads.c[794]: request->child_state == REQUEST_QUEUED

Relevant log output from client utilities

No response

Backtrace from LLDB or GDB

[root@radius freeradius-3.2.7]# gdb sbin/radiusd core.radiusd.1019086
GNU gdb (GDB) Red Hat Enterprise Linux 8.2-20.el8
Copyright (C) 2018 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".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from sbin/radiusd...done.
[New LWP 1019157]
[New LWP 1019180]
[New LWP 1019174]
[New LWP 1019154]
[New LWP 1019119]
[New LWP 1019113]
[New LWP 1019098]
[New LWP 1019144]
[New LWP 1019162]
[New LWP 1019137]
[New LWP 1019145]
[New LWP 1019099]
[New LWP 1019093]
[New LWP 1019112]
[New LWP 1019086]
[New LWP 1019176]
[New LWP 1019096]
[New LWP 1019126]
[New LWP 1019108]
[New LWP 1019193]
[New LWP 1019102]
[New LWP 1019146]
[New LWP 1019103]
[New LWP 1019116]
[New LWP 1019109]
[New LWP 1019125]
[New LWP 1019152]
[New LWP 1019105]
[New LWP 1019215]
[New LWP 1019114]
[New LWP 1019120]
[New LWP 1019155]
[New LWP 1019094]
[New LWP 1019117]
[New LWP 1019118]
[New LWP 1019205]
[New LWP 1019190]
[New LWP 1019187]
[New LWP 1019122]
[New LWP 1019123]
[New LWP 1019192]
[New LWP 1019199]
[New LWP 1019209]
[New LWP 1019127]
[New LWP 1019131]
[New LWP 1019134]
[New LWP 1019141]
[New LWP 1019213]
[New LWP 1019129]
[New LWP 1019138]
[New LWP 1019148]
[New LWP 1019153]
[New LWP 1019165]
[New LWP 1019159]
[New LWP 1019189]
[New LWP 1019147]
[New LWP 1019196]
[New LWP 1019167]
[New LWP 1019104]
[New LWP 1019149]
[New LWP 1019101]
[New LWP 1019173]
[New LWP 1019203]
[New LWP 1019163]
[New LWP 1019142]
[New LWP 1019186]
[New LWP 1019188]
[New LWP 1019164]
[New LWP 1019169]
[New LWP 1019132]
[New LWP 1019182]
[New LWP 1019204]
[New LWP 1019194]
[New LWP 1019100]
[New LWP 1019179]
[New LWP 1019160]
[New LWP 1019177]
[New LWP 1019115]
[New LWP 1019158]
[New LWP 1019184]
[New LWP 1019212]
[New LWP 1019201]
[New LWP 1019178]
[New LWP 1019211]
[New LWP 1019724]
[New LWP 1019210]
[New LWP 1019725]
[New LWP 1019202]
[New LWP 1019197]
[New LWP 1019107]
[New LWP 1020077]
[New LWP 1019198]
[New LWP 1020078]
[New LWP 1019208]
[New LWP 1019095]
[New LWP 1019156]
[New LWP 1019195]
[New LWP 1019214]
[New LWP 1019151]
[New LWP 1019191]
[New LWP 1019183]
[New LWP 1019106]
[New LWP 1019150]
[New LWP 1019124]
[New LWP 1019136]
[New LWP 1019161]
[New LWP 1019097]
[New LWP 1019140]
[New LWP 1019143]
[New LWP 1019168]
[New LWP 1019139]
[New LWP 1019110]
[New LWP 1019206]
[New LWP 1019135]
[New LWP 1019207]
[New LWP 1019175]
[New LWP 1019130]
[New LWP 1019111]
[New LWP 1019172]
[New LWP 1019181]
[New LWP 1019133]
[New LWP 1019171]
[New LWP 1019128]
[New LWP 1019166]
[New LWP 1019218]
[New LWP 1019185]
[New LWP 1019200]
[New LWP 1019217]
[New LWP 1019216]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/opt/freeradius-3.2.7/sbin/radiusd -n radiusd3'.
Program terminated with signal SIGABRT, Aborted.
#0  0x00007f7860961b8f in raise () from /lib64/libpthread.so.0
[Current thread is 1 (Thread 0x7f77377fe700 (LWP 1019157))]
Missing separate debuginfos, use: yum debuginfo-install cyrus-sasl-gssapi-2.1.27-6.el8_5.x86_64 cyrus-sasl-lib-2.1.27-6.el8_5.x86_64 cyrus-sasl-md5-2.1.27-6.el8_5.x86_64 cyrus-sasl-plain-2.1.27-6.el8_5.x86_64 glibc-2.28-225.el8_8.6.x86_64 keyutils-libs-1.5.10-9.el8.x86_64 krb5-libs-1.18.2-25.el8_8.x86_64 libblkid-2.32.1-42.el8_8.x86_64 libcom_err-1.45.6-5.el8.x86_64 libdb-5.3.28-42.el8_4.x86_64 libgcc-8.5.0-18.el8.x86_64 libmount-2.32.1-42.el8_8.x86_64 libnsl-2.28-225.el8_8.6.x86_64 libselinux-2.9-8.el8.x86_64 libtalloc-2.3.4-1.el8.x86_64 libuuid-2.32.1-42.el8_8.x86_64 libxcrypt-4.1.1-6.el8.x86_64 openldap-2.4.46-18.el8.x86_64 openssl-libs-1.1.1k-9.el8_7.x86_64 pcre2-10.32-3.el8_6.x86_64 perl-Data-Dumper-2.167-399.el8.x86_64 perl-Digest-MD5-2.55-396.el8.x86_64 perl-Encode-2.97-3.el8.x86_64 perl-IO-1.38-422.el8.x86_64 perl-MIME-Base64-3.15-396.el8.x86_64 perl-NetAddr-IP-4.079-7.el8.x86_64 perl-PathTools-3.74-1.el8.x86_64 perl-Socket-2.027-3.el8.x86_64 perl-Socket6-0.28-6.el8.x86_64 perl-Storable-3.11-3.el8.x86_64 perl-interpreter-5.26.3-422.el8.x86_64 perl-libs-5.26.3-422.el8.x86_64 perl-threads-2.21-2.el8.x86_64 sssd-client-2.8.2-3.el8_8.x86_64 zlib-1.2.11-21.el8_7.x86_64
(gdb) bt full
#0  0x00007f7860961b8f in raise () from /lib64/libpthread.so.0
No symbol table info available.
#1  0x00007f7861b3ac13 in fr_fault (sig=6) at src/lib/debug.c:823
        cmd = '\000' <repeats 531 times>
        out = 0x7f77377fdbb0 ""
        left = 532
        ret = 140155018914688
        p = 0x7f7861d793e0 <panic_action> ""
        q = 0x7f77377fde30 "\220\336\177\067w\177"
        code = 668
#2  0x00007f7861d9ec2b in rad_assert_fail (file=0x47aade "src/main/threads.c",
    line=794, expr=0x47abc8 "request->child_state == REQUEST_QUEUED")
    at src/main/util.c:557
No locals.
#3  0x000000000043f55b in request_dequeue (prequest=0x2202cdb0)
    at src/main/threads.c:794
        blocked = 140150008962800
        last_complained = 1738965611
        total_blocked = 0
        num_blocked = 0
        i = RAD_LISTEN_MAX
        request = 0x249a9970
#4  0x000000000043f7f8 in request_handler_thread (arg=0x2202cd80)
    at src/main/threads.c:906
        self = 0x2202cd80
#5  0x00007f78609571ca in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#6  0x00007f786039ae73 in clone () from /lib64/libc.so.6
No symbol table info available.
(gdb) frame 3
#3  0x000000000043f55b in request_dequeue (prequest=0x2202cdb0)
    at src/main/threads.c:794
794     src/main/threads.c: No such file or directory.
(gdb) p *request
$1 = {magic = 3735928559, number = 29787, timestamp = 1738965604, data = 0x0,
  listener = 0x21607960, client = 0x226363f0, packet = 0x249a9790,
  username = 0x0, password = 0x0, reply = 0x249a9b20, config = 0x0,
  state_ctx = 0x7f7842e221c0, state = 0x0, proxy_listener = 0x0, proxy = 0x0,
  proxy_reply = 0x0, home_server = 0x0, home_pool = 0x0,
  process = 0x441fbc <request_done>, response_delay = {tv_sec = 0,
    tv_usec = 0}, timer_action = FR_ACTION_TIMER, ev = 0x2467b0d0,
  handle = 0x40ff86 <rad_accounting>, rcode = RLM_MODULE_REJECT,
  module = 0x47be6e "", component = 0x47c042 "<REQUEST_DONE>",
  delay = 5695294, master_state = REQUEST_STOP_PROCESSING,
  child_state = REQUEST_DONE, child_pid = 140155018914688,
  root = 0x696ba0 <main_config>, simul_max = 0, simul_count = 0,
  simul_mpp = 0, priority = RAD_LISTEN_ACCT, max_time = false,
  in_request_hash = false, eap_inner_tunnel = false, in_proxy_hash = false,
  num_proxied_requests = 0, num_proxied_responses = 0,
  server = 0x219571a0 "DNRA", parent = 0x0, log = {
    func = 0x7f7861d91182 <vradlog_request>, lvl = L_DBG_LVL_OFF,
    indent = 0 '\000'}, options = 2, coa = 0x0, num_coa_requests = 0}
(gdb)
@krtzsu krtzsu added the defect category: a defect or misbehaviour label Feb 8, 2025
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
defect category: a defect or misbehaviour
Projects
None yet
Development

No branches or pull requests

1 participant