[ASTERISK-171] chan_iax2: Crash due to memory corruption following packet decrypt failures

[2025-12-31 21:49:19.704] WARNING[1819857]: chan_iax2.c:10454 socket_process_helper: Packet Decrypt Failed!
[2025-12-31 21:49:19.784] ERROR[1819854]: iax2/parser.c:1224 iax_frame_wrap: Losing frame data because destination buffer size '4096' bytes not big enough for '-2' bytes in the frame
[2025-12-31 21:49:19.784] ERROR[1819854]: iax2/parser.c:1224 iax_frame_wrap: Losing frame data because destination buffer size '4096' bytes not big enough for '-2' bytes in the frame

#5  0x00007ff54c02686a in malloc_printerr (str=str@entry=0x7ff54c12f158 "double free or corruption (!prev)") at ./malloc/malloc.c:5660
#6  0x00007ff54c0288dc in _int_free (av=0x7ff53c000030, p=0x7ff53cada5a0, have_lock=<optimized out>, have_lock@entry=0) at ./malloc/malloc.c:4587
        size = 224
        fb = <optimized out>
        nextchunk = 0x7ff53cada680
        nextsize = <optimized out>
        nextinuse = <optimized out>
        prevsize = <optimized out>
        bck = <optimized out>
        fwd = <optimized out>
        __PRETTY_FUNCTION__ = "_int_free"
#7  0x00007ff54c02af4f in __GI___libc_free (mem=<optimized out>) at ./malloc/malloc.c:3385
        ar_ptr = <optimized out>
        p = <optimized out>
        err = 0
#8  0x0000563937216c55 in __ast_free (ptr=0x7ff53cada5b0, file=0x563937463889 "frame.c", lineno=169, func=0x563937463f28 <__PRETTY_FUNCTION__.3> "__frame_free") at astmm.c:1556
#9  0x00005639372c6950 in __frame_free (fr=0x7ff53cada5b0, cache=1) at frame.c:169
        __PRETTY_FUNCTION__ = "__frame_free"
#10 0x00005639372c6990 in ast_frame_free (frame=0x7ff53cada5b0, cache=1) at frame.c:182
        next = 0x0
#11 0x000056393725fab5 in __ast_read (chan=0x7ff524132410, dropaudio=0, dropnondefault=1) at channel.c:3739
        skipped_dtmf_frame = 0
        skip_dtmf = 0
        f = 0x7ff53cada5b0
        prestate = 4
        cause = 0
        stream = 0x0
        default_stream = 0x0
        __PRETTY_FUNCTION__ = "__ast_read"
        __FUNCTION__ = "__ast_read"
#12 0x0000563937261ae9 in ast_read (chan=0x7ff524132410) at channel.c:4265
#13 0x0000563937258d64 in safe_sleep_conditional (chan=0x7ff524132410, timeout_ms=1000, cond=0x0, data=0x0, generate_silence=1) at channel.c:1527
        dup_f = 0x0
        f = 0x5639374fbe20 <ast_null_frame>
        silgen = 0x0
        res = 0
        start = {tv_sec = 1767217759, tv_usec = 553782}
        ms = 770
        deferred_frames = {first = 0x0, last = 0x0}
        __PRETTY_FUNCTION__ = "safe_sleep_conditional"
#14 0x0000563937258f7d in ast_safe_sleep (chan=0x7ff524132410, ms=1000) at channel.c:1576
#15 0x00007ff5480c64ba in streamsilence_exec (chan=0x7ff524132410, data=0x7ff51f50f9d0 "1") at app_streamsilence.c:106

Happened again, not once, but twice, I believe:

[2026-01-01 21:32:22.033] WARNING[3457527]: chan_iax2.c:10454 socket_process_helper: Packet Decrypt Failed!
[2026-01-01 21:32:22.053] WARNING[3457526]: chan_iax2.c:10454 socket_process_helper: Packet Decrypt Failed!
[2026-01-01 21:32:22.113] WARNING[3457524]: chan_iax2.c:10454 socket_process_helper: Packet Decrypt Failed!
[2026-01-01 21:32:22.143] WARNING[3457530]: chan_iax2.c:10454 socket_process_helper: Packet Decrypt Failed!
[2026-01-01 21:32:22.188] WARNING[3457531]: chan_iax2.c:10454 socket_process_helper: Packet Decrypt Failed!
[2026-01-01 21:32:22.449] ERROR[3457522]: iax2/parser.c:1224 iax_frame_wrap: Losing frame data because destination buffer size '4096' bytes not big enough for '-2' bytes in the frame
[2026-01-01 21:32:22.449] ERROR[3457522]: iax2/parser.c:1224 iax_frame_wrap: Losing frame data because destination buffer size '4096' bytes not big enough for '-2' bytes in the frame

Comments

1/1/2026 7:24 PM — csptechnologies

I’m having the same issue too! My asterisk crashes after that error message.

1/1/2026 7:29 PM — InterLinked

Very interesting... are you able to reproduce it reliably or does it seem kind of random?

1/2/2026 2:40 PM — InterLinked

Another crash today, with similar circumstances:

[2026-01-02 18:43:48.728] WARNING[3551228]: chan_iax2.c:10454 socket_process_helper: Packet Decrypt Failed!  
[2026-01-02 18:43:50.371] WARNING[3551230]: chan_iax2.c:10454 socket_process_helper: Packet Decrypt Failed!  
[2026-01-02 18:43:50.423] WARNING[3551227]: chan_iax2.c:10454 socket_process_helper: Packet Decrypt Failed!

However, the frame wrap thing didn't happen, as I added an assert in that function which was not triggered.

So far, I've only been seeing these on incoming calls from your node, @csptechnologies.

If you are able to set up a DISA on your node that would allow me to dial back so I can try to reproduce the crashes, that might help get to the bottom of this. Of course, if it also crashes yours, that might be a bit inconvenient... I have a cron job that runs every few minutes to start Asterisk if it's crashed.

1/2/2026 3:02 PM — csptechnologies

Mine happens at random times. I made an temporary DISA on 277-7473 and you should be able to natively dial PhreakNet Numbers.

1/2/2026 3:06 PM — csptechnologies

Sorry, I meant 277-7475

1/2/2026 3:45 PM — InterLinked

Looks like it happened just now, right after the start of an incoming call attempt:

[2026-01-02 20:43:28.211] WARNING[3555976]: chan_iax2.c:10454 socket_process_helper: Packet Decrypt Failed!  
[2026-01-02 20:43:28.260] ERROR[3555976]: iax2/parser.c:1224 iax_frame_wrap: Losing frame data because destination buffer size '4096' bytes not big enough for '-1' bytes in the frame  
[2026-01-02 20:43:28.261] ERROR[3555976]: iax2/parser.c:1224 iax_frame_wrap: Losing frame data because destination buffer size '4096' bytes not big enough for '-1' bytes in the frame

What's happening on your end when this happens? Do you crash as well?

1/2/2026 3:55 PM — csptechnologies

Yes, I crash as well. Here are my logs

-- Accepting AUTHENTICATED call from 68.180.38.252:4569:  
--        > requested auth methods = (RSA|MD5),  
--        > actual auth method = MD5,  
--        > encrypted = yes,  
--        > requested format = Unknown,  
--        > requested prefs = (h264|g722|ulaw|alaw|gsm|mpeg4),  
--        > actual format = g722,  
--        > host prefs = (g722|ulaw|alaw|gsm|h264|mpeg4),  
--        > priority = mine  
-- Executing [2772745@from-phreaknet:1] NoOp("IAX2/phreaknet-7968", "") in new stack  
-- Executing [2772745@from-phreaknet:2] Set("IAX2/phreaknet-7968", "CALLERID(num)=972774801") in new stack  
-- Executing [2772745@from-phreaknet:3] SIPAddHeader("IAX2/phreaknet-7968", "Alert-Info: <Bellcore-dr2>") in new stack  
-- Executing [2772745@from-phreaknet:4] Goto("IAX2/phreaknet-7968", "phreaknet-exchange,2772745,1") in new stack  
-- Goto (phreaknet-exchange,2772745,1)  
-- Executing [2772745@phreaknet-exchange:1] Goto("IAX2/phreaknet-7968", "from-internal,2745,1") in new stack  
-- Goto (from-internal,2745,1)  
-- Executing [2745@from-internal:1] Progress("IAX2/phreaknet-7968", "") in new stack

[2026-01-02 14:41:20] WARNING[878856][C-000006d4]: pbx_functions.c:459 func_args: Can't find trailing parenthesis for function 'CALLERID(name'?
-- Executing [2745@from-internal:2] System("IAX2/phreaknet-7968", "/usr/bin/php /var/lib/asterisk/agi-bin/intercept.php "972774801" "2745" "Elliot McPike"") in new stack
-- Call accepted by 68.180.38.252:4569 (format g722)
-- Format for call is (g722)
-- IAX2/68.180.38.252:4569-14033 is making progress passing it to SIP/4801-000004d6
[2026-01-02 14:41:20] WARNING[710179]: res_pjsip_pubsub.c:3603 pubsub_on_rx_publish_request: No registered publish handler for event presence from 5336
[2026-01-02 14:41:21] WARNING[436071]: chan_iax2.c:12013 socket_process_helper: Received mini frame before first full video frame
[2026-01-02 14:41:21] WARNING[878864]: chan_iax2.c:12013 socket_process_helper: Received mini frame before first full video frame
[2026-01-02 14:41:21] WARNING[436068]: chan_iax2.c:10491 socket_process_helper: Packet Decrypt Failed!
[2026-01-02 14:41:21] WARNING[436065]: chan_iax2.c:12013 socket_process_helper: Received mini frame before first full video frame
[2026-01-02 14:41:21] WARNING[436066]: chan_iax2.c:12013 socket_process_helper: Received mini frame before first full video frame
[2026-01-02 14:41:21] WARNING[436074]: chan_iax2.c:12013 socket_process_helper: Received mini frame before first full video frame
[2026-01-02 14:41:21] WARNING[436073]: chan_iax2.c:12013 socket_process_helper: Received mini frame before first full video frame
[2026-01-02 14:41:21] WARNING[436072]: chan_iax2.c:12013 socket_process_helper: Received mini frame before first full video frame
[2026-01-02 14:41:21] WARNING[878865]: chan_iax2.c:12013 socket_process_helper: Received mini frame before first full video frame
[2026-01-02 14:41:21] WARNING[436065]: chan_iax2.c:12013 socket_process_helper: Received mini frame before first full video frame
[2026-01-02 14:41:21] ERROR[436072]: iax2/parser.c:1213 iax_frame_wrap: Losing frame data because destination buffer size '4096' bytes not big enough for '-2' bytes in the frame
[2026-01-02 14:41:21] ERROR[436072]: iax2/parser.c:1213 iax_frame_wrap: Losing frame data because destination buffer size '4096' bytes not big enough for '-2' bytes in the frame
-- Executing [2745@from-internal:3] Set("IAX2/phreaknet-7968", "CONNECTEDLINE(all,i)=SVA-INTERCEPT") in new stack
-- Executing [2745@from-internal:4] Wait("IAX2/phreaknet-7968", "1") in new stack
-- Executing [2745@from-internal:5] Playback("IAX2/phreaknet-7968", "custom/intercept_cisco") in new stack
-- IAX2/68.180.38.252:4569-14033 answered SIP/4801-000004d6
-- Channel IAX2/68.180.38.252:4569-14033 joined 'simple_bridge' basic-bridge <242bf7c6-29f0-4d8a-b6fe-2b8c7c98fcfc>
-- <IAX2/phreaknet-7968> Playing 'custom/intercept_cisco.g722' (language 'en')
-- Channel SIP/4801-000004d6 joined 'simple_bridge' basic-bridge <242bf7c6-29f0-4d8a-b6fe-2b8c7c98fcfc>
[2026-01-02 14:41:22] WARNING[440217]: res_pjsip_pubsub.c:1010 subscription_get_handler_from_rdata: No registered subscribe handler for event as-feature-event from 4448
cspserver*CLI>
Disconnected from Asterisk server
Asterisk cleanly ending (0).
Executing last minute cleanups

1/2/2026 3:58 PM — InterLinked

I wonder if this has to do with video support in some way... maybe try disabling that temporarily and see if that changes anything?
Could you also share the Asterisk version that you are using and anything that might be special about your build (how you installed it, etc.)

1/2/2026 4:02 PM — csptechnologies

Video Support over IAX2 is now disabled. I am currently running Asterisk 20.15.2 which was downloaded directly from Asterisk's Website, and compiled the official way (./configure, make, make install)

1/2/2026 4:08 PM — InterLinked

DISA was working before (sort of, I was getting a verification error), although now it's not going to it anymore it seems.

1/2/2026 4:28 PM — csptechnologies

DISA seems to be working on my end.

1/2/2026 4:44 PM — InterLinked

I'm getting a verification failure, likely due to the call not being out-verified when it leaves your node.
If you call the out verify routines, or as a simple hack, do Set(IAXVAR(nodevia)=2777475), I think that would fix the issue.

On another note, though it hasn't been long yet, things seem more stable... I haven't noticed any crashes since disabling video so maybe that's related.
Maybe we'll let it run for a little bit and if no crashes, then we can re-enable that for a more focused test.

1/2/2026 5:10 PM — csptechnologies

I made the changes now. Is the verfication working properly now?

1/2/2026 5:16 PM — InterLinked

Well, I spoke too soon - just saw this recently:

[2026-01-02 22:03:21.502] WARNING[3562480]: chan_iax2.c:10454 socket_process_helper: Packet Decrypt Failed!  
[2026-01-02 22:03:21.563] ERROR[3562479]: iax2/parser.c:1225 iax_frame_wrap: Losing frame data because destination buffer size '4096' bytes not big enough for '-1' bytes in the frame

I'm getting some leads though, it crashed somewhere I added an assertion.

On the DISA, I get "call cannot be completed as dialed" again now. I think this might be happening after a crash has happened.

1/2/2026 5:21 PM — csptechnologies

Interesting... I don't have video enabled at all. The DISA seems to be working though.

1/2/2026 6:22 PM — InterLinked

Yes, at the moment, all is well. I'm waiting for the next crash which should help me pinpoint closer to the root cause. If you're able to expedite that, that would certainly help ;)

1/2/2026 7:03 PM — InterLinked

Also, what user agent (IP phone, ATA, analog phone) are you using to place calls?
I can't seem to trigger it when placing DISA calls, but it's happened several times on calls you've made it seems. One difference I see is your call used the G.722 codec, which I don't think a call from my system and then to yours would use (I'm also realizing your snippet above doesn't appear to be coming from my system, as I only allow ulaw and alaw).

1/2/2026 7:06 PM — csptechnologies

I am using a Cisco 8865-K9 which is on my Cisco UCM system which then trunks into my asterisk server, which then trunks into CSP CPBX Asterisk Server

1/2/2026 7:22 PM — InterLinked

I was able to get some useful insight on this from gdb... looks like this is indeed is video related in some way (at least from the one core dump I analyzed)

6  0x00007f39acc46542 in socket_process_helper (thread=0x55f368a05390) at chan_iax2.c:12132  
12132                   duped_fr = iaxfrdup2(fr);  
(gdb) print f.datalen  
$1 = -1  
(gdb) print f  
$2 = {frametype = AST_FRAME_VIDEO, subclass = {integer = 0, {format = 0x55f3680af6d8, topology = 0x55f3680af6d8}, frame_ending = 1}, datalen = -1, samples = 0, mallocd = 0, mallocd_hdr_len = 0,  
  offset = 0, src = 0x7f39acc6620c "IAX2", data = {ptr = 0x55f368a054a6, uint32 = 1755337894, pad = "\246T\240h\363U\000"}, delivery = {tv_sec = 0, tv_usec = 0}, frame_list = {next = 0x0},  
  flags = 0, ts = 0, len = 0, seqno = 0, stream_num = 0}

That might explain why it only happens when you make the calls... the 8865-K9 is a video-enabled phone, after all.

I would say go ahead and re-enable video (it didn't seem to make much difference anyways). I have additional assertions in place now for spots where I think something fishy may be going.

1/7/2026 7:54 PM — InterLinked

Another crash, got some additional clues from that:

#4  0x00007f0d7d045064 in socket_process_helper (thread=0x7f0d940caf50) at chan_iax2.c:11981  
11981                   f.datalen = res - sizeof(*vh);  
(gdb) print f  
$4 = {frametype = AST_FRAME_VIDEO, subclass = {integer = 0, {format = 0x55ba23fb4c88, topology = 0x55ba23fb4c88}, frame_ending = 1}, datalen = -2, samples = 0, mallocd = 0, mallocd_hdr_len = 0,  
  offset = 0, src = 0x0, data = {ptr = 0x0, uint32 = 0, pad = "\000\000\000\000\000\000\000"}, delivery = {tv_sec = 0, tv_usec = 0}, frame_list = {next = 0x0}, flags = 0, ts = 0, len = 0,  
  seqno = 0, stream_num = 0}  
(gdb) print res  
$5 = 4  
(gdb) print sizeof(*vh)  
$6 = 6

1/7/2026 8:00 PM — csptechnologies

Interesting... It shouldn't send video packets at all when sending a fax. That might also explain why I didn't get a fax back

1/7/2026 8:17 PM — InterLinked

Well, it shouldn't be crashing, but it is, so I don't know how useful it is discuss what should be happening.
I just added some code that I think should prevent the crash, so feel free to try to break it!

1/7/2026 8:42 PM — csptechnologies

I do not see the code you added, could you clarify where you attached the code that should prevent it from crashing?

1/7/2026 8:52 PM — InterLinked

Sorry, I should have been cleared - I made some code changes on the server.
If there aren't any crashes after this, I'll clean it up and share/submit the patch.

1/7/2026 9:19 PM — csptechnologies

I'll try placing a video call, and then a non video call.

1/7/2026 9:34 PM — csptechnologies

My server did not crash. I think it's fixed

1/7/2026 9:37 PM — InterLinked

The issue hasn't been triggered yet, so it's not conclusive just yet - and I'm watching for a crash on my end.

1/7/2026 9:42 PM — InterLinked

It just happened... I could see a bunch of this:

[2026-01-08 02:40:15.091] WARNING[3743858]: chan_iax2.c:10456 socket_process_helper: Packet Decrypt Failed!  
[2026-01-08 02:40:15.195] WARNING[3743850]: chan_iax2.c:10456 socket_process_helper: Packet Decrypt Failed!  
[2026-01-08 02:40:15.294] WARNING[3743855]: chan_iax2.c:11985 socket_process_helper: Datalen < 0?  
[2026-01-08 02:40:15.324] WARNING[3743851]: chan_iax2.c:11985 socket_process_helper: Datalen < 0?  
[2026-01-08 02:40:15.352] WARNING[3743857]: chan_iax2.c:10456 socket_process_helper: Packet Decrypt Failed!  
[2026-01-08 02:40:15.462] WARNING[3743852]: chan_iax2.c:10456 socket_process_helper: Packet Decrypt Failed!  
[2026-01-08 02:40:15.499] WARNING[3743850]: chan_iax2.c:11985 socket_process_helper: Datalen < 0?  
[2026-01-08 02:40:15.629] WARNING[3743858]: chan_iax2.c:10456 socket_process_helper: Packet Decrypt Failed!  
[2026-01-08 02:40:15.727] WARNING[3743850]: chan_iax2.c:11985 socket_process_helper: Datalen < 0?  
[2026-01-08 02:40:15.789] WARNING[3743851]: chan_iax2.c:10456 socket_process_helper: Packet Decrypt Failed!  
[2026-01-08 02:40:15.856] WARNING[3743859]: chan_iax2.c:10456 socket_process_helper: Packet Decrypt Failed!  
[2026-01-08 02:40:15.926] WARNING[3743859]: chan_iax2.c:10456 socket_process_helper: Packet Decrypt Failed!

But the system seemed sane and didn't crash, so I'd say this is a success.
How'd your side fare?

1/7/2026 11:08 PM — csptechnologies

My system didn't seem to crash, My side appears sane as well.

You must be logged in to leave a comment.