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]: Freeradius service crashes when use dhcp module #5316

Open
elchin9610 opened this issue Apr 22, 2024 · 5 comments
Open

[defect]: Freeradius service crashes when use dhcp module #5316

elchin9610 opened this issue Apr 22, 2024 · 5 comments
Labels
defect category: a defect or misbehaviour

Comments

@elchin9610
Copy link

What type of defect/bug is this?

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

How can the issue be reproduced?

I used the freeradius module DHCP for my clients. My service crashes several times a day.

OS=Debian10
freeradius=3.0.26
database=oracle
clients=80k

At first, I received no error logs, so I thought it was either the database or the driver. Changing Oracle to Postgresql didn't the solve the problem.

Then decided to upgrade Debian10 to Debian12, also didn't the solve the problem.

When I use radiusd -X > /tmp/test.log there are no failures. As I understand it, this is because the service operates in a single-threaded mode

Finally, I rebuilt with the option: --with-experimental-modules --enable-developer, and received a log Error: ASSERT FAILED src/main/threads.c[679]: request->magic == REQUEST_MAGIC

My Config

cat radiusd.conf

thread pool {
start_servers = 50
max_servers = 200
min_spare_servers = 5
max_spare_servers = 15
}

cat mods-enabled/sql

sql {

    radius_db = "(DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=10.10.10.10)(PORT=1518))(CONNECT_DATA=(SERVICE_NAME=RADIUS)))"

    pool {
           start = ${thread[pool].start_servers}
            min = ${thread[pool].min_spare_servers}
            max = ${thread[pool].max_servers}
            spare = ${thread[pool].max_spare_servers}
            uses = 0
            retry_delay = 30
            lifetime = 0
            idle_timeout = 60
     }

}

cat sites-enabled/dhcp

dhcp DHCP-Discover {

    update reply {
           &DHCP-Message-Type = DHCP-Offer
            &DHCP-Domain-Name-Server = 8.8.8.8
            &DHCP-Domain-Name-Server += 8.8.4.4
            &DHCP-Subnet-Mask = 255.255.255.0
            &DHCP-IP-Address-Lease-Time = 1800
            &DHCP-DHCP-Server-Identifier = "192.168.29.10"

            DHCP-Server-Host-Name = "DHCP"
            &DHCP-Domain-Name = "DHCP"
            &NAS-IP-Address = "%{DHCP-Gateway-IP-Address}"

            &DHCP-Your-IP-Address= "%{sql:select dhcp.get_available_ip('%{string:DHCP-Relay-Circuit-Id}', '%{DHCP-Client-Hardware-Address}') from dual}"
           &DHCP-Router-Address = `${raddbdir}/bin/get_dhcp_client_gw %{reply:DHCP-Your-IP-Address}`

}
}

dhcp DHCP-Request {

    update reply {
           &DHCP-Message-Type = DHCP-Ack
           &DHCP-Domain-Name-Server = 8.8.8.8
           &DHCP-Domain-Name-Server += 8.8.4.4
           &DHCP-IP-Address-Lease-Time = 1800
           &DHCP-Subnet-Mask = 255.255.255.0
           &DHCP-DHCP-Server-Identifier = "192.168.29.10"
           DHCP-Server-Host-Name = "DHCP"
           &DHCP-Domain-Name = "DHCP"
           &Calling-Station-Id = "%{DHCP-Client-Hardware-Address}"

           &DHCP-Router-Address = "%{sql:select NCNRADIUS.DHCP_REQUEST('%{string:DHCP-Relay-Circuit-Id}') from dual}"
           &DHCP-Router-Address = `${raddbdir}/bin/get_dhcp_client_gw %{reply:DHCP-Your-IP-Address}`


    }

}

Log output from the FreeRADIUS daemon

Mon Apr 22 13:21:21 2024 : Error: Received conflicting packet from client dhcp port 67 - ID: 0 due to unfinished request in module <queue>.  Giving up on old request.
Mon Apr 22 13:21:53 2024 : Error: Received conflicting packet from client dhcp port 54289 - ID: 0 due to unfinished request in module .  Giving up on old request.
Mon Apr 22 13:22:31 2024 : Error: Received conflicting packet from client dhcp port 67 - ID: 0 due to unfinished request in module <queue>.  Giving up on old request.
Mon Apr 22 13:22:32 2024 : Error: Received conflicting packet from client dhcp port 67 - ID: 0 due to unfinished request in module <queue>.  Giving up on old request.
Mon Apr 22 13:23:03 2024 : Error: Received conflicting packet from client dhcp port 67 - ID: 0 due to unfinished request in module <queue>.  Giving up on old request.
Mon Apr 22 13:23:05 2024 : Error: Received conflicting packet from client dhcp port 67 - ID: 0 due to unfinished request in module <queue>.  Giving up on old request.
Mon Apr 22 13:23:09 2024 : Error: Received conflicting packet from client dhcp port 67 - ID: 0 due to unfinished request in module <queue>.  Giving up on old request.
Mon Apr 22 13:23:09 2024 : Error: ASSERT FAILED src/main/threads.c[679]: request->magic == REQUEST_MAGIC
CAUGHT SIGNAL: Aborted
Backtrace of last 6 frames:
/opt/radius_3_0_26_multi_sql/lib/libfreeradius-radius.so(fr_fault+0x11d)[0x7fa74b7e1d53]
/opt/radius_3_0_26_multi_sql/lib/libfreeradius-server.so(rad_assert_fail+0x49)[0x7fa74b845429]
/opt/radius_3_0_26_multi_sql/sbin/radiusd(+0x43606)[0x5595ca54b606]
/opt/radius_3_0_26_multi_sql/sbin/radiusd(+0x438b6)[0x5595ca54b8b6]
/lib/x86_64-linux-gnu/libc.so.6(+0x89134)[0x7fa74b0a8134]
/lib/x86_64-linux-gnu/libc.so.6(+0x1097dc)[0x7fa74b1287dc]
No panic action set

Relevant log output from client utilities

No response

Backtrace from LLDB or GDB

No response

@elchin9610 elchin9610 added the defect category: a defect or misbehaviour label Apr 22, 2024
@alandekok
Copy link
Member

Mon Apr 22 13:21:21 2024 : Error: Received conflicting packet from client dhcp port 67 - ID: 0 due to unfinished request in module . Giving up on old request.
Mon Apr 22 13:21:53 2024 : Error: Received conflicting packet from client dhcp port 54289 - ID: 0 due to unfinished request in module . Giving up on old request.
Mon Apr 22 13:22:31 2024 : Error: Received conflicting packet from client dhcp port 67 - ID: 0 due to unfinished request in module . Giving up on old request.

This isn't a DHCP issue. The back-end is slow, and isn't responding to FreeRADIUS. But the client keeps sending DHCP packets, and eventually the server gets into a bad state, and crashes.

The simple fix is to ensure that the back-end is actually replying to the server.

A longer fix is to read the guidelines in the github issue template, and send over a full gdb back trace. We can then try to see what's going on.

But no amount of bug fixing in FreeRADIUS will make your SQL server faster. The first thing you should do is to find out why the SQL server is slow, and fix that.

@elchin9610
Copy link
Author

Thanks for your reply. To reduce the load on SQL , I use cache memcached. But the result is the same.
I'll try to use gdb back trace.

@alandekok
Copy link
Member

If memcache doesn't help, then the issue is elsewhere.

The default configuration has no issue replying to 10K packets/s. If your local configuration can't handle that, then something in your local configuration is breaking the server.

You will have to go through the configuration to see what has been changed from the defaults, and then find out which piece is taking a long time.

We can take a look at fixing the crash, but it won't have any meaningful change for your system. FreeRADIUS will still be blocked, and will be unable to respond to packets.

i.e. in practice, the difference between "down due to crash" and "down due to something blocking the server" is essentially zero.

Fix the underlying problem. Which is not the crash.

@elchin9610
Copy link
Author

Hello, this problem arose because I used &DHCP-Your-IP-Address= "%{sql:select dhcp.get_available_ip('%{string:DHCP-Relay-Circuit-Id}', '%{DHCP-Client-Hardware-Address}') from dual}"
Tonight I'll change to dhcp_sqlippool. Many thanks for the help!

@elchin9610
Copy link
Author

Hello, I was able to solve the problem by changing skip_duplicate_checks = yes. When duplicate packets arrive, the server crashes.
When I use radiusd -X > /tmp/test.log there are no failures. As I understand it, this is because the service operates in a single-threaded mode

Troubleshooting:

radiusd.conf

debug_level = 3

thread pool {
        start_servers = 1
        max_servers = 1
       min_spare_servers = 1
      max_spare_servers = 1
}

/mods-enabled/dhcp_sql

        pool {
                start = ${thread[pool].start_servers}
                min = ${thread[pool].min_spare_servers}
                max = ${thread[pool].max_servers}
                spare = ${thread[pool].max_spare_servers}
                uses = 0
                retry_delay = 30
                lifetime = 0
                idle_timeout = 60
        }

I connect one test host and block the database using iptables iptables -A OUTPUT -d 10.132.25.20 -j REJECT .
I wait 5 minutes and then allow the database connection again iptables -D OUTPUT -d 10.132.25.20 -j REJECT
Having received several duplicate packets, the server crashes.

radius.log

Tue Jun 4 12:04:19 2024 : Debug: (21) Received code 1027 Id 788269544 from 10.10.70.6:67 to 192.168.29.9:67 length 367
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Opcode = Client-Message
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Hardware-Type = Ethernet
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Hardware-Address-Length = 6
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Hop-Count = 1
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Transaction-Id = 788269544
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Number-of-Seconds = 1792
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Flags = Broadcast
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Client-IP-Address = 0.0.0.0
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Your-IP-Address = 0.0.0.0
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Server-IP-Address = 0.0.0.0
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Gateway-IP-Address = 10.10.70.6
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Client-Hardware-Address = 84:2a:fd:6e:20:a0
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Message-Type = DHCP-Request
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Client-Identifier = 0x01842afd6e20a0
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Requested-IP-Address = 1.1.1.1
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Hostname = "DESKTOP-C3J2DH0"
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Client-FQDN = 0x0000004445534b544f502d43334a32444830
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Vendor-Class-Identifier = 0x4d53465420352e30
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Parameter-Request-List = DHCP-Subnet-Mask
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Parameter-Request-List = DHCP-Router-Address
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Parameter-Request-List = DHCP-Domain-Name-Server
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Parameter-Request-List = DHCP-Domain-Name
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Parameter-Request-List = DHCP-Perform-Router-Discovery
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Parameter-Request-List = DHCP-Static-Routes
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Parameter-Request-List = DHCP-Vendor
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Parameter-Request-List = DHCP-NETBIOS-Name-Servers
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Parameter-Request-List = DHCP-NETBIOS-Node-Type
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Parameter-Request-List = DHCP-NETBIOS
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Parameter-Request-List = DHCP-Domain-Search
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Parameter-Request-List = DHCP-Classless-Static-Route
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Parameter-Request-List = 249
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Parameter-Request-List = 252
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Relay-Circuit-Id = 0x323038302d313532
Tue Jun 4 12:04:19 2024 : Debug: (21) Attr-26.54.3154 = 0x0002000000000583010000000000000063343a30393a62373a33373a66633a
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Network-Subnet = 10.10.70.6/32
Tue Jun 4 12:04:19 2024 : Debug: Trying sub-section dhcp DHCP-Request {...}
Tue Jun 4 12:04:19 2024 : Debug: (21) dhcp DHCP-Request {
Tue Jun 4 12:04:19 2024 : Debug: (21) update control {
Tue Jun 4 12:04:19 2024 : Debug: (21) &Pool-Name := "public"
Tue Jun 4 12:04:19 2024 : Debug: (21) } # update control = noop
Tue Jun 4 12:04:19 2024 : Debug: (21) policy dhcp_common {
Tue Jun 4 12:04:19 2024 : Debug: (21) update reply {
Tue Jun 4 12:04:19 2024 : Debug: (21) &DHCP-Domain-Name-Server = 2.2.2.2
Tue Jun 4 12:04:19 2024 : Debug: (21) &DHCP-Domain-Name-Server += 2.2.2.3
Tue Jun 4 12:04:19 2024 : Debug: (21) &DHCP-Subnet-Mask = 255.255.255.0
Tue Jun 4 12:04:19 2024 : Debug: (21) &DHCP-IP-Address-Lease-Time = 1000
Tue Jun 4 12:04:19 2024 : Debug: (21) &DHCP-DHCP-Server-Identifier = 192.168.29.9
Tue Jun 4 12:04:19 2024 : Debug: (21) DHCP-Server-Host-Name = "DHCP"
Tue Jun 4 12:04:19 2024 : Debug: (21) &DHCP-Domain-Name = "DHCP"
Tue Jun 4 12:04:19 2024 : Debug: (21) EXPAND %{DHCP-Gateway-IP-Address}
Tue Jun 4 12:04:19 2024 : Debug: (21) --> 10.10.70.6
Tue Jun 4 12:04:19 2024 : Debug: (21) &NAS-IP-Address = 10.10.70.6
Tue Jun 4 12:04:19 2024 : Debug: (21) } # update reply = noop
Tue Jun 4 12:04:19 2024 : Debug: (21) } # policy dhcp_common = noop
Tue Jun 4 12:04:19 2024 : Debug: (21) policy dhcp_sqlippool_request {
Tue Jun 4 12:04:19 2024 : Debug: (21) if (&DHCP-Requested-IP-Address) {
Tue Jun 4 12:04:19 2024 : Debug: (21) if (&DHCP-Requested-IP-Address) -> TRUE
Tue Jun 4 12:04:19 2024 : Debug: (21) if (&DHCP-Requested-IP-Address) {
Tue Jun 4 12:04:19 2024 : Debug: (21) update request {
Tue Jun 4 12:04:19 2024 : Debug: (21) &Acct-Status-Type := Start
Tue Jun 4 12:04:19 2024 : Debug: (21) } # update request = noop
Tue Jun 4 12:04:19 2024 : Debug: (21) modsingle[accounting]: calling dhcp_sqlippool (rlm_sqlippool)
Tue Jun 4 12:04:19 2024 : Debug: rlm_sql (dhcp_sql): Reserved connection (0)
Tue Jun 4 12:04:19 2024 : Debug: %{control:DHCP-SQL-Option-Identifier}
Tue Jun 4 12:04:19 2024 : Debug: Parsed xlat tree:
Tue Jun 4 12:04:19 2024 : Debug: attribute --> DHCP-SQL-Option-Identifier
Tue Jun 4 12:04:19 2024 : Debug: (21) dhcp_sqlippool: EXPAND %{control:DHCP-SQL-Option-Identifier}
Tue Jun 4 12:04:19 2024 : Debug: (21) dhcp_sqlippool: -->
Tue Jun 4 12:04:19 2024 : Debug: (21) dhcp_sqlippool: SQL-User-Name set to ''
Tue Jun 4 12:04:19 2024 : Debug: commit
Tue Jun 4 12:04:19 2024 : Debug: Parsed xlat tree:
Tue Jun 4 12:04:19 2024 : Debug: literal --> commit
Tue Jun 4 12:04:19 2024 : Debug: (21) dhcp_sqlippool: EXPAND commit
Tue Jun 4 12:04:19 2024 : Debug: (21) dhcp_sqlippool: --> commit
Tue Jun 4 12:04:19 2024 : Debug: (21) dhcp_sqlippool: Executing query: commit
Tue Jun 4 12:04:19 2024 : Debug: Waking up in 0.4 seconds.
Tue Jun 4 12:04:20 2024 : Debug: Waking up in 0.7 seconds.
Tue Jun 4 12:04:20 2024 : Debug: Waking up in 1.1 seconds.
Tue Jun 4 12:04:22 2024 : Debug: Waking up in 1.6 seconds.
Tue Jun 4 12:04:23 2024 : Debug: Waking up in 2.5 seconds.
Tue Jun 4 12:04:25 2024 : Debug: Threads: total/active/spare threads = 1/1/0
Tue Jun 4 12:04:25 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:04:25 2024 : Debug: Waking up in 0.4 seconds.
Tue Jun 4 12:04:26 2024 : Debug: Waking up in 0.1 seconds.
Tue Jun 4 12:04:26 2024 : Debug: Waking up in 0.5 seconds.
Tue Jun 4 12:04:26 2024 : Debug: Waking up in 1.1 seconds.
Tue Jun 4 12:04:27 2024 : Error: (22) Ignoring duplicate packet from client dhcp port 67 - ID: 3107335243 due to unfinished request in component module
Tue Jun 4 12:04:28 2024 : Debug: Waking up in 1.6 seconds.
Tue Jun 4 12:04:29 2024 : Debug: Waking up in 0.4 seconds.
Tue Jun 4 12:04:30 2024 : Debug: Waking up in 2.1 seconds.
Tue Jun 4 12:04:30 2024 : Error: (22) Ignoring duplicate packet from client dhcp port 67 - ID: 3107335243 due to unfinished request in component module
Tue Jun 4 12:04:30 2024 : Debug: Waking up in 2.0 seconds.
Tue Jun 4 12:04:32 2024 : Debug: Waking up in 3.5 seconds.
Tue Jun 4 12:04:35 2024 : Debug: Waking up in 0.2 seconds.
Tue Jun 4 12:04:36 2024 : Debug: Waking up in 5.6 seconds.
Tue Jun 4 12:04:41 2024 : Debug: Waking up in 2.6 seconds.
Tue Jun 4 12:04:44 2024 : Debug: Waking up in 5.9 seconds.
Tue Jun 4 12:04:50 2024 : Debug: Waking up in 6.8 seconds.
Tue Jun 4 12:04:57 2024 : Error: Unresponsive child for request 21, in component post-auth module dhcp_sqlippool
Tue Jun 4 12:04:57 2024 : Debug: Waking up in 5.9 seconds.
Tue Jun 4 12:05:03 2024 : Debug: Waking up in 13.2 seconds.
Tue Jun 4 12:05:03 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:03 2024 : Debug: Waking up in 0.4 seconds.
Tue Jun 4 12:05:04 2024 : Debug: Waking up in 0.7 seconds.
Tue Jun 4 12:05:04 2024 : Debug: Waking up in 1.1 seconds.
Tue Jun 4 12:05:05 2024 : Error: (23) Ignoring duplicate packet from client dhcp port 67 - ID: 1840839282 due to unfinished request in component module
Tue Jun 4 12:05:05 2024 : Debug: Waking up in 0.7 seconds.
Tue Jun 4 12:05:05 2024 : Debug: Waking up in 1.6 seconds.
Tue Jun 4 12:05:07 2024 : Error: (23) Ignoring duplicate packet from client dhcp port 67 - ID: 1840839282 due to unfinished request in component module
Tue Jun 4 12:05:07 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:07 2024 : Debug: Waking up in 2.5 seconds.
Tue Jun 4 12:05:10 2024 : Debug: Waking up in 3.7 seconds.
Tue Jun 4 12:05:10 2024 : Error: (23) Ignoring duplicate packet from client dhcp port 67 - ID: 1840839282 due to unfinished request in component module
Tue Jun 4 12:05:10 2024 : Debug: Waking up in 3.7 seconds.
Tue Jun 4 12:05:13 2024 : Debug: Waking up in 2.4 seconds.
Tue Jun 4 12:05:16 2024 : Debug: Waking up in 3.2 seconds.
Tue Jun 4 12:05:19 2024 : Debug: Waking up in 2.6 seconds.
Tue Jun 4 12:05:21 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:21 2024 : Debug: Waking up in 0.4 seconds.
Tue Jun 4 12:05:22 2024 : Debug: Waking up in 0.2 seconds.
Tue Jun 4 12:05:22 2024 : Debug: Waking up in 0.5 seconds.
Tue Jun 4 12:05:22 2024 : Debug: Waking up in 1.1 seconds.
Tue Jun 4 12:05:23 2024 : Debug: Waking up in 1.6 seconds.
Tue Jun 4 12:05:24 2024 : Error: (24) Ignoring duplicate packet from client dhcp port 67 - ID: 1692463661 due to unfinished request in component module
Tue Jun 4 12:05:24 2024 : Debug: Waking up in 1.3 seconds.
Tue Jun 4 12:05:25 2024 : Error: (24) Ignoring duplicate packet from client dhcp port 67 - ID: 1692463661 due to unfinished request in component module
Tue Jun 4 12:05:25 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:25 2024 : Debug: Waking up in 0.7 seconds.
Tue Jun 4 12:05:26 2024 : Debug: Waking up in 1.7 seconds.
Tue Jun 4 12:05:26 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:26 2024 : Error: Received conflicting packet from client dhcp port 67 - ID: 0 due to unfinished request in module . Giving up on old request.
Tue Jun 4 12:05:26 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:27 2024 : Debug: Waking up in 0.1 seconds.
Tue Jun 4 12:05:27 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:27 2024 : Debug: Waking up in 0.4 seconds.
Tue Jun 4 12:05:28 2024 : Debug: Waking up in 0.1 seconds.
Tue Jun 4 12:05:28 2024 : Debug: Waking up in 0.1 seconds.
Tue Jun 4 12:05:28 2024 : Debug: Waking up in 0.7 seconds.
Tue Jun 4 12:05:29 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:29 2024 : Debug: Waking up in 1.3 seconds.
Tue Jun 4 12:05:30 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:31 2024 : Debug: Waking up in 0.7 seconds.
Tue Jun 4 12:05:31 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:32 2024 : Debug: Waking up in 1.0 seconds.
Tue Jun 4 12:05:32 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:32 2024 : Debug: Waking up in 0.4 seconds.
Tue Jun 4 12:05:33 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:33 2024 : Debug: Waking up in 0.4 seconds.
Tue Jun 4 12:05:34 2024 : Debug: Waking up in 1.1 seconds.
Tue Jun 4 12:05:35 2024 : Debug: Waking up in 1.0 seconds.
Tue Jun 4 12:05:36 2024 : Debug: Waking up in 0.5 seconds.
Tue Jun 4 12:05:37 2024 : Debug: Waking up in 0.2 seconds.
Tue Jun 4 12:05:37 2024 : Error: (27) Ignoring duplicate packet from client dhcp port 67 - ID: 100377858 due to unfinished request in component module
Tue Jun 4 12:05:37 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:37 2024 : Debug: Waking up in 0.1 seconds.
Tue Jun 4 12:05:37 2024 : Debug: Waking up in 1.8 seconds.
Tue Jun 4 12:05:39 2024 : Debug: Waking up in 1.4 seconds.
Tue Jun 4 12:05:41 2024 : Debug: Waking up in 1.3 seconds.
Tue Jun 4 12:05:41 2024 : Error: (27) Ignoring duplicate packet from client dhcp port 67 - ID: 100377858 due to unfinished request in component module
Tue Jun 4 12:05:41 2024 : Debug: Waking up in 1.1 seconds.
Tue Jun 4 12:05:42 2024 : Debug: Waking up in 0.5 seconds.
Tue Jun 4 12:05:42 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:43 2024 : Debug: Waking up in 2.8 seconds.
Tue Jun 4 12:05:46 2024 : Debug: Waking up in 0.1 seconds.
Tue Jun 4 12:05:46 2024 : Debug: Waking up in 2.6 seconds.
Tue Jun 4 12:05:49 2024 : Debug: Waking up in 2.4 seconds.
Tue Jun 4 12:05:49 2024 : Error: (27) Ignoring duplicate packet from client dhcp port 67 - ID: 100377858 due to unfinished request in component module
Tue Jun 4 12:05:49 2024 : Debug: Waking up in 1.7 seconds.
Tue Jun 4 12:05:51 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:05:51 2024 : Debug: Waking up in 0.5 seconds.
Tue Jun 4 12:05:52 2024 : Debug: Waking up in 4.0 seconds.
Tue Jun 4 12:05:56 2024 : Debug: Waking up in 1.1 seconds.
Tue Jun 4 12:05:57 2024 : Debug: Waking up in 1.4 seconds.
Tue Jun 4 12:05:59 2024 : Debug: Waking up in 1.2 seconds.
Tue Jun 4 12:06:00 2024 : Debug: Waking up in 1.2 seconds.
Tue Jun 4 12:06:01 2024 : Debug: Waking up in 0.8 seconds.
Tue Jun 4 12:06:02 2024 : Debug: Waking up in 2.2 seconds.
Tue Jun 4 12:06:04 2024 : Debug: Waking up in 1.8 seconds.
Tue Jun 4 12:06:05 2024 : Error: (27) Ignoring duplicate packet from client dhcp port 67 - ID: 100377858 due to unfinished request in component module
Tue Jun 4 12:06:05 2024 : Debug: Waking up in 0.4 seconds.
Tue Jun 4 12:06:06 2024 : Debug: Waking up in 3.8 seconds.
Tue Jun 4 12:06:10 2024 : Debug: Waking up in 0.1 seconds.
Tue Jun 4 12:06:10 2024 : Debug: Waking up in 1.0 seconds.
Tue Jun 4 12:06:11 2024 : Debug: Waking up in 0.8 seconds.
Tue Jun 4 12:06:12 2024 : Debug: Waking up in 4.0 seconds.
Tue Jun 4 12:06:16 2024 : Debug: Waking up in 1.8 seconds.
Tue Jun 4 12:06:18 2024 : Debug: Waking up in 1.9 seconds.
Tue Jun 4 12:06:20 2024 : Debug: Waking up in 1.2 seconds.
Tue Jun 4 12:06:21 2024 : Debug: Waking up in 0.8 seconds.
Tue Jun 4 12:06:22 2024 : Debug: Waking up in 1.4 seconds.
Tue Jun 4 12:06:23 2024 : Debug: Waking up in 2.5 seconds.
Tue Jun 4 12:06:26 2024 : Debug: Waking up in 1.8 seconds.
Tue Jun 4 12:06:28 2024 : Debug: Waking up in 1.3 seconds.
Tue Jun 4 12:06:29 2024 : Debug: Waking up in 0.6 seconds.
Tue Jun 4 12:06:30 2024 : Debug: Waking up in 1.2 seconds.
Tue Jun 4 12:06:31 2024 : Debug: Waking up in 0.8 seconds.
Tue Jun 4 12:06:32 2024 : Debug: Waking up in 1.4 seconds.
Tue Jun 4 12:06:33 2024 : Debug: Waking up in 2.5 seconds.
Tue Jun 4 12:06:36 2024 : Debug: Waking up in 1.8 seconds.
Tue Jun 4 12:06:37 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:06:37 2024 : Debug: Waking up in 0.4 seconds.
Tue Jun 4 12:06:38 2024 : Debug: Waking up in 0.7 seconds.
Tue Jun 4 12:06:39 2024 : Debug: Waking up in 0.6 seconds.
Tue Jun 4 12:06:39 2024 : Debug: Waking up in 0.5 seconds.
Tue Jun 4 12:06:40 2024 : Debug: Waking up in 0.1 seconds.
Tue Jun 4 12:06:40 2024 : Debug: Waking up in 1.2 seconds.
Tue Jun 4 12:06:41 2024 : Debug: Waking up in 0.3 seconds.
Tue Jun 4 12:06:41 2024 : Debug: Waking up in 0.5 seconds.
Tue Jun 4 12:06:42 2024 : Error: (28) Ignoring duplicate packet from client dhcp port 67 - ID: 2961325333 due to unfinished request in component module
Tue Jun 4 12:06:42 2024 : Debug: Waking up in 0.2 seconds.
Tue Jun 4 12:06:42 2024 : Debug: Waking up in 1.4 seconds.
Tue Jun 4 12:06:43 2024 : Debug: Waking up in 0.5 seconds.
Tue Jun 4 12:06:44 2024 : Debug: Waking up in 2.0 seconds.
Tue Jun 4 12:06:46 2024 : Debug: Waking up in 1.7 seconds.
Tue Jun 4 12:06:48 2024 : Debug: Waking up in 0.1 seconds.
Tue Jun 4 12:06:48 2024 : Debug: Waking up in 1.3 seconds.
Tue Jun 4 12:06:49 2024 : Debug: Waking up in 0.6 seconds.
Tue Jun 4 12:06:49 2024 : Error: (28) Ignoring duplicate packet from client dhcp port 67 - ID: 2961325333 due to unfinished request in component module
Tue Jun 4 12:06:49 2024 : Debug: Waking up in 0.4 seconds.
Tue Jun 4 12:06:50 2024 : Debug: Waking up in 1.2 seconds.
Tue Jun 4 12:06:51 2024 : Debug: Waking up in 0.8 seconds.
Tue Jun 4 12:06:52 2024 : Debug: Waking up in 1.4 seconds.
Tue Jun 4 12:06:53 2024 : Debug: Waking up in 2.5 seconds.
Tue Jun 4 12:06:56 2024 : Debug: Waking up in 1.8 seconds.
Tue Jun 4 12:06:58 2024 : Debug: Waking up in 1.3 seconds.
Tue Jun 4 12:06:59 2024 : Debug: Waking up in 0.6 seconds.
Tue Jun 4 12:07:00 2024 : Debug: Waking up in 1.2 seconds.
Tue Jun 4 12:07:01 2024 : Debug: Waking up in 0.8 seconds.
Tue Jun 4 12:07:02 2024 : Debug: Waking up in 1.4 seconds.
Tue Jun 4 12:07:03 2024 : Debug: Waking up in 2.5 seconds.
Tue Jun 4 12:07:05 2024 : Error: (28) Ignoring duplicate packet from client dhcp port 67 - ID: 2961325333 due to unfinished request in component module
Tue Jun 4 12:07:05 2024 : Debug: Waking up in 1.0 seconds.
Tue Jun 4 12:07:06 2024 : Debug: Waking up in 1.8 seconds.
Tue Jun 4 12:07:08 2024 : Debug: Waking up in 1.3 seconds.
Tue Jun 4 12:07:09 2024 : Debug: Waking up in 0.6 seconds.
Tue Jun 4 12:07:10 2024 : Debug: Waking up in 1.2 seconds.
Tue Jun 4 12:07:11 2024 : Debug: Waking up in 0.8 seconds.
Tue Jun 4 12:07:12 2024 : Debug: Waking up in 1.4 seconds.
Tue Jun 4 12:07:13 2024 : Debug: Waking up in 1.3 seconds.
Tue Jun 4 12:07:15 2024 : Debug: Waking up in 1.2 seconds.
Tue Jun 4 12:07:16 2024 : Debug: Waking up in 1.8 seconds.
Tue Jun 4 12:07:18 2024 : Debug: Waking up in 1.3 seconds.
Tue Jun 4 12:07:19 2024 : Debug: Waking up in 0.6 seconds.
Tue Jun 4 12:07:20 2024 : Debug: Waking up in 1.2 seconds.
Tue Jun 4 12:07:21 2024 : Debug: Waking up in 0.8 seconds.
Tue Jun 4 12:07:22 2024 : Debug: Waking up in 1.4 seconds.
Tue Jun 4 12:07:23 2024 : Debug: Waking up in 2.5 seconds.
Tue Jun 4 12:07:26 2024 : Debug: Waking up in 1.8 seconds.
Tue Jun 4 12:07:28 2024 : Debug: Waking up in 1.3 seconds.
Tue Jun 4 12:07:29 2024 : Debug: Waking up in 0.6 seconds.
Tue Jun 4 12:07:30 2024 : Debug: Waking up in 1.2 seconds.
Tue Jun 4 12:07:31 2024 : Debug: Waking up in 0.8 seconds.
Tue Jun 4 12:07:32 2024 : Debug: Waking up in 1.4 seconds.
Tue Jun 4 12:07:33 2024 : Debug: Waking up in 0.5 seconds.
Tue Jun 4 12:07:34 2024 : Debug: Waking up in 2.0 seconds.
Tue Jun 4 12:07:36 2024 : Debug: Waking up in 1.8 seconds.
Tue Jun 4 12:07:38 2024 : Debug: Waking up in 1.3 seconds.
Tue Jun 4 12:07:39 2024 : Debug: Waking up in 0.6 seconds.
Tue Jun 4 12:07:40 2024 : Debug: Waking up in 1.2 seconds.
Tue Jun 4 12:07:41 2024 : Debug: Waking up in 0.8 seconds.
Tue Jun 4 12:07:42 2024 : Debug: Waking up in 1.4 seconds.
Tue Jun 4 12:07:43 2024 : Debug: Waking up in 0.5 seconds.
Tue Jun 4 12:07:44 2024 : Debug: Waking up in 2.0 seconds.
Tue Jun 4 12:07:46 2024 : Debug: Waking up in 1.8 seconds.
Tue Jun 4 12:07:48 2024 : Debug: Waking up in 1.3 seconds.
Tue Jun 4 12:07:49 2024 : Debug: Waking up in 0.6 seconds.
Tue Jun 4 12:07:50 2024 : Debug: Waking up in 1.2 seconds.
Tue Jun 4 12:07:51 2024 : Debug: Waking up in 0.8 seconds.
Tue Jun 4 12:07:52 2024 : Debug: Waking up in 1.4 seconds.
Tue Jun 4 12:07:52 2024 : Debug: rlm_sql (dhcp_sql): Released connection (0)
Tue Jun 4 12:07:52 2024 : WARNING: (21) Module rlm_sqlippool became unblocked
Tue Jun 4 12:07:52 2024 : Debug: (21) modsingle[accounting]: returned from dhcp_sqlippool (rlm_sqlippool)
Tue Jun 4 12:07:52 2024 : Debug: (21) [dhcp_sqlippool.accounting] = ok
Tue Jun 4 12:07:52 2024 : Debug: (21) } # if (&DHCP-Requested-IP-Address) = ok
Tue Jun 4 12:07:52 2024 : Debug: (21) } # policy dhcp_sqlippool_request = fail
Tue Jun 4 12:07:52 2024 : Debug: (21) } # dhcp DHCP-Request = fail
Tue Jun 4 12:07:52 2024 : Debug: (21) DHCP: Reply will be unicast to giaddr from original packet
Tue Jun 4 12:07:52 2024 : Debug: Thread 1 waiting to be assigned a request
Tue Jun 4 12:07:52 2024 : Debug: Thread 1 got semaphore
Tue Jun 4 12:07:53 2024 : Debug: (26) : Cleaning up request packet ID 0 with timestamp +4182 due to timer
Tue Jun 4 12:07:53 2024 : Debug: Waking up in 0.5 seconds.
Tue Jun 4 12:07:54 2024 : Debug: (28) : Cleaning up request packet ID 2961325333 with timestamp +4253 due to timer
Tue Jun 4 12:07:54 2024 : Debug: Waking up in 2.0 seconds.
Tue Jun 4 12:07:54 2024 : Error: ASSERT FAILED src/main/threads.c[679]: request->magic == REQUEST_MAGIC
CAUGHT SIGNAL: Aborted
Backtrace of last 6 frames:
/opt/radius_3_0_26_multi_sql2/lib/libfreeradius-radius.so(fr_fault+0x114)[0x7f1315453cad]
/opt/radius_3_0_26_multi_sql2/lib/libfreeradius-server.so(rad_assert_fail+0x46)[0x7f13154b7ae0]
/opt/radius_3_0_26_multi_sql2/sbin/radiusd(+0x42280)[0x5578367a7280]
/opt/radius_3_0_26_multi_sql2/sbin/radiusd(+0x4251a)[0x5578367a751a]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x7ea7)[0x7f1315086ea7]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x3f)[0x7f1314f6ba6f]
No panic action set

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

2 participants