[LBBS-121] mod_asterisk_queues: Memory corruption or use after free in agent list
This crash has been observed on two different occasions, though not in close proximity, so this is not a frequent crash, but does seem consistent.
The logs make it clear that something like this happens:
- ami_callback(): An incoming operator call gives us an QueueCallerJoin event
- We call new_call(), which iterates the calls list and calls call_is_dead() for each of them to check if it's dead
- call_is_dead() finds a dead call with the same call ID (typically 0) and calls mark_dead(), setting call->dead to 1
- ami_callback(): We then get an AgentCalled event which calls agent_printf()
- agent_printf() iterates the agents list, and some agent in the loop is invalid memory (confirmed by gdb)
What's strange is that there seems to be some kind old stale call in the calls list, but what causes the crash is an invalid agent in the agents list.
More complete logs filed at X:\Development\LBBS-121.txt - from these additional logs it seems a call comes into the agent, who handles the call, but does NOT return to the main menu before the second call comes in, i.e. the call becomes dead while the agent is in a submenu.
(m:ss)
2:33 IAX2/phreaknet-13486 calls 0
2:38 Answers
2:46 press l
2:48 choose call 0
2:58 Choose [S] option and key number, hit ENTER
LBBS/asterisk merged timeline:
3:05 Far end answers
3:08 far end hangs up
3:09 caller gets disconnected
3:16 press ENTER
3:16 IAX2/phreaknet-78 calls 0 using 231 DISA
3:19 press l
3:23 answers
3:27 choose call 0
3:31 choose option 3 ([S])
3:46 enter number and hit ENTER. do not touch terminal from now on
3:58 xfer complete
4:06 caller gets disconnected
4:11 IAX2/phreaknet-16132 calls 0 (crash)
Reproducing 3:16-4:11 sequence does give similar log results:
[2025-09-27 09:02:27.480] DEBUG[32945]: mod_asterisk_queues.c:571 ami_callback: Processing queue event 'QueueCallerJoin'
[2025-09-27 09:02:27.554] DEBUG[32945]: mod_asterisk_queues.c:397 call_is_dead: Marking queue call 0 as dead: IAX2/phreaknet-14122
[2025-09-27 09:02:27.554] DEBUG[32945]: mod_asterisk_queues.c:502 new_call: Added call from 'REDACTED' (IAX2/phreaknet-10052) to queue 'phreaknet-operator' as call 0[2025-09-26 20:03:17.485] DEBUG[83287]: mod_asterisk_queues.c:495 new_call: Added call from '8848537' (IAX2/phreaknet-78) to queue 'phreaknet-operator' as call 0
...
[2025-09-26 20:04:11.945] DEBUG[83287]: mod_asterisk_queues.c:564 ami_callback: Processing queue event 'QueueCallerJoin'
[2025-09-26 20:04:11.947] DEBUG[83287]: mod_asterisk_queues.c:361 __mark_dead: Marking queue call 0 as dead: IAX2/phreaknet-78
[2025-09-26 20:04:11.947] DEBUG[83287]: mod_asterisk_queues.c:495 new_call: Added call from '8848537' (IAX2/phreaknet-16132) to queue 'phreaknet-operator' as call 0
[2025-09-26 20:04:11.948] DEBUG[83287]: mod_asterisk_queues.c:564 ami_callback: Processing queue event 'AgentCalled'
Segmentation fault (core dumped)
Thread 1 (Thread 0x7f489ee486c0 (LWP 83287)):
#0 0x00007f48a058b0ca in agent_printf (queue=0x5623b503d550, member_name=0x7f4894085760 "791", fmt=0x7f48a058f40f "%s\r%s%-15s %-22s %15s\n") at mod_asterisk_queues.c:519
buf = 0x7f4890006120 "\033[0m\r\aACD RING OPERATOR", ' ' <repeats 23 times>, "8848537\n"
len = 61
ap = {{gp_offset = 48, fp_offset = 48, overflow_arg_area = 0x7f489ed47cb0, reg_save_area = 0x7f489ed47be0}}
agent = 0x51858d6eaed7cf55
agent_id = 791
__func__ = "agent_printf"
#1 0x00007f48a058b6ba in ami_callback (e=0x7f4894087040, eventname=0x7f48940049a0 "AgentCalled") at mod_asterisk_queues.c:594
callerid = 0x7f489400bef0 "8848537"
member_name = 0x7f4894085760 "791"
queue_name = 0x7f4894011490 "phreaknet-operator"
queue = 0x5623b503d550
__func__ = "ami_callback"
#2 0x00007f48a0c866b3 in ami_callback (ami=0x5623b5039a60, event=0x7f4894087040) at mod_asterisk_ami.c:115
res = -1
cb = 0x5623b503deb0
do_reload = 0
eventname = 0x7f48940049a0 "AgentCalled"
__func__ = "ami_callback"
#3 0x00007f48a0877c86 in ami_event_dispatch (varg=0x5623b5039a60) at cami.c:806
bytes_used = <optimized out>
start = 0x7f489ed47ea0 "Event: AgentCalled\r\nPrivilege: agent,all\r\nTimestamp: 1758917051.950755\r\nSystemName: ARTNVAAXCG0\r\nChannel: IAX2/phreaknet-16132\r\nChannelState: 4\r\nChannelStateDesc: Ring\r\nCallerIDNum: 8848537\r\nCallerIDN"...
end = 0x7f489ed4826a ""
fds = {fd = 16, events = 1, revents = 1}
event = <optimized out>
res = 971
buf = Python Exception <class 'gdb.error'>: value requires 1048576 bytes, which is more than max-value-size
#4 0x00007f48a0f1f1f5 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
ret = <optimized out>
pd = <optimized out>
unwind_buf = {cancel_jmp_buf = {{jmp_buf = {139949880149696, 5120490681186163102, -136, 25, 140732927007232, 139949871759360, -5071441385835685474, -5071366787108529762}, mask_was_saved = 0}}, priv = {pad = {0x0, 0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0, canceltype = 0}}}
not_first_call = <optimized out>
#5 0x00007f48a0f9f8dc in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
Normal call (for comparison):
[2025-09-26 20:30:15.509] DEBUG[15891]: mod_asterisk_queues.c:564 ami_callback: Processing queue event 'QueueCallerJoin'
[2025-09-26 20:30:15.596] DEBUG[15891]: mod_asterisk_queues.c:495 new_call: Added call from '2703330' (IAX2/phreaknet-1029) to queue 'phreaknet-operator' as call 0
[2025-09-26 20:30:15.596] DEBUG[15891]: mod_asterisk_queues.c:564 ami_callback: Processing queue event 'AgentCalled'
...
[2025-09-26 20:30:15.596] DEBUG[15891]: mod_asterisk_queues.c:564 ami_callback: Processing queue event 'AgentCalled'
[2025-09-26 20:30:20.329] DEBUG[15891]: mod_asterisk_queues.c:564 ami_callback: Processing queue event 'QueueCallerAbandon'
[2025-09-26 20:30:20.330] DEBUG[15891]: mod_asterisk_queues.c:361 __mark_dead: Marking queue call 0 as dead: IAX2/phreaknet-1029
[2025-09-26 20:30:20.330] DEBUG[15891]: mod_asterisk_queues.c:564 ami_callback: Processing queue event 'QueueCallerLeave'Comments
You must be logged in to leave a comment.