IAX2 authentication failure causing Asterisk to crash

InterLinked · January 27, 2021, 1:23am

Multiple times in the past 36 hours, since deploying IAX2 encryption on multiple nodes, Asterisk switches have been crashing in a rather bizarre way.

Here’s what happens leading up to a crash. I can reproduce it by, it seems, dialing a number that requires MD5 encryption but not providing the secret. Only in certain cases, though. It wasn’t happening yesterday when I was messing around, but this happens not just on my Asterisk switch but multiple different switches. The below is a verbose 10, iax2 debug on CLI output from one switch:

[Jan 26 20:30:46] – Executing [start@dialredacted:9] Dial(“Local/211@dt-ld-00000000;2”, “IAX2/redacted@example.com/211,60,hg”) in new stack
[Jan 26 20:30:46] Tx-Frame Retry[000] – OSeqno: 000 ISeqno: 000 Type: IAX Subclass: NEW
[Jan 26 20:30:46] Timestamp: 00010ms SCall: 10373 DCall: 00000 1.1.1.1:4569
[Jan 26 20:30:46] VERSION : 2
[Jan 26 20:30:46] CALLED NUMBER : 211
[Jan 26 20:30:46] – Called IAX2/redacted@example.com/211
[Jan 26 20:30:46] CODEC_PREFS : (ulaw|gsm|ilbc|speex|lpc10|g729|g723|alaw|g726|g726aal2|adpcm|slin|slin16|speex16|g722|siren7|siren14|testlaw|g719|opus|jpeg|png|h261|h263|h263p|h264|mpeg4|vp8|red|t140)
[Jan 26 20:30:46] CALLING NUMBER : 2311126
[Jan 26 20:30:46] CALLING PRESNTN : 0
[Jan 26 20:30:46] CALLING TYPEOFN : 0
[Jan 26 20:30:46] CALLING TRANSIT : 0
[Jan 26 20:30:46] CALLING NAME : John Smith via redactedCFL01
[Jan 26 20:30:46] LANGUAGE : en
[Jan 26 20:30:46] USERNAME : redacted
[Jan 26 20:30:46] ENCRYPTION : 32769
[Jan 26 20:30:46] FORMAT : 4
[Jan 26 20:30:46] FORMAT2 : ulaw
[Jan 26 20:30:46] CAPABILITY : 218103807
[Jan 26 20:30:46] CAPABILITY2 : Unknown
[Jan 26 20:30:46] ADSICPE : 0
[Jan 26 20:30:46] DATE TIME : 2021-01-26 20:30:46
[Jan 26 20:30:46] VARIABLE : redactedmlpp=0
[Jan 26 20:30:46] VARIABLE : clidverif=10
[Jan 26 20:30:46] VARIABLE : DISAVIA=6461111
[Jan 26 20:30:46]
[Jan 26 20:30:46] Rx-Frame Retry[ No] – OSeqno: 000 ISeqno: 001 Type: IAX Subclass: CTOKEN
[Jan 26 20:30:46] Timestamp: 00010ms SCall: 00001 DCall: 10373 1.1.1.1:4569
[Jan 26 20:30:46] CALLTOKEN : 51 bytes
[Jan 26 20:30:46]
[Jan 26 20:30:46] Tx-Frame Retry[000] – OSeqno: 000 ISeqno: 000 Type: IAX Subclass: NEW
[Jan 26 20:30:46] Timestamp: 00049ms SCall: 10373 DCall: 00000 1.1.1.1:4569
[Jan 26 20:30:46] VERSION : 2
[Jan 26 20:30:46] CALLED NUMBER : 211
[Jan 26 20:30:46] CODEC_PREFS : (ulaw|gsm|ilbc|speex|lpc10|g729|g723|alaw|g726|g726aal2|adpcm|slin|slin16|speex16|g722|siren7|siren14|testlaw|g719|opus|jpeg|png|h261|h263|h263p|h264|mpeg4|vp8|red|t140)
[Jan 26 20:30:46] CALLING NUMBER : 2311126
[Jan 26 20:30:46] CALLING PRESNTN : 0
[Jan 26 20:30:46] CALLING TYPEOFN : 0
[Jan 26 20:30:46] CALLING TRANSIT : 0
[Jan 26 20:30:46] CALLING NAME : John Smith via redactedCFL01
[Jan 26 20:30:46] LANGUAGE : en
[Jan 26 20:30:46] USERNAME : redacted
[Jan 26 20:30:46] ENCRYPTION : 32769
[Jan 26 20:30:46] FORMAT : 4
[Jan 26 20:30:46] FORMAT2 : ulaw
[Jan 26 20:30:46] CAPABILITY : 218103807
[Jan 26 20:30:46] CAPABILITY2 : Unknown
[Jan 26 20:30:46] ADSICPE : 0
[Jan 26 20:30:46] DATE TIME : 2021-01-26 20:30:46
[Jan 26 20:30:46] VARIABLE : redactedmlpp=0
[Jan 26 20:30:46] VARIABLE : clidverif=10
[Jan 26 20:30:46] VARIABLE : DISAVIA=6461111
[Jan 26 20:30:46] CALLTOKEN : 51 bytes
[Jan 26 20:30:46]
[Jan 26 20:30:46] Rx-Frame Retry[ No] – OSeqno: 000 ISeqno: 001 Type: IAX Subclass: ACK
[Jan 26 20:30:46] Timestamp: 00049ms SCall: 02985 DCall: 10373 1.1.1.1:4569
[Jan 26 20:30:46] Rx-Frame Retry[ No] – OSeqno: 000 ISeqno: 001 Type: IAX Subclass: AUTHREQ
[Jan 26 20:30:46] Timestamp: 00013ms SCall: 02985 DCall: 10373 1.1.1.1:4569
[Jan 26 20:30:46] AUTHMETHODS : 2
[Jan 26 20:30:46] CHALLENGE : \x36\x39\x35\x35\x30\x39\x34\x36\x30
[Jan 26 20:30:46] ENCRYPTION : 1
[Jan 26 20:30:46] USERNAME : redacted
[Jan 26 20:30:46]
[Jan 26 20:30:46] WARNING[18195][C-00000000]: chan_iax2.c:11212 socket_process_helper: I don’t know how to authenticate redacted to 1.1.1.1:4569
[Jan 26 20:30:46] TE-Frame Retry[-01] – OSeqno: 001 ISeqno: 001 Type: IAX Subclass: ACK
[Jan 26 20:30:46] Timestamp: 00013ms SCall: 10373 DCall: 02985 1.1.1.1:4569
redactedcfl01*CLI>
Disconnected from Asterisk server
[Jan 26 20:30:46] Asterisk cleanly ending (0).
[Jan 26 20:30:46] Executing last minute cleanups
root@cfl01:~#

Not long afterwards, on the switch I called into that switch from and the switch I was trying to call, I see:

[2021-01-26 20:30:56] WARNING[20129]: chan_iax2.c:6725 iax2_send: Supposed to send packet encrypted, but no key?
[Jan 26 20:30:57]     -- Executing [s@carriercrosstalk:9] Goto("Local/s@carriercrosstalk-000000f1;2", "loop") in new stack
[Jan 26 20:30:57]     -- Goto (carriercrosstalk,s,6)
[Jan 26 20:30:57]     -- Executing [s@carriercrosstalk:6] ExecIf("Local/s@carriercrosstalk-000000f1;2", "1?Hangup") in new stack
[Jan 26 20:30:57]   == Spawn extension (carriercrosstalk, s, 6) exited non-zero on 'Local/s@carriercrosstalk-000000f1;2'
[2021-01-26 20:31:06] WARNING[20125]: chan_iax2.c:6725 iax2_send: Supposed to send packet encrypted, but no key?
[2021-01-26 20:31:07] WARNING[20126]: chan_iax2.c:6725 iax2_send: Supposed to send packet encrypted, but no key?
[2021-01-26 20:31:16] WARNING[20131]: chan_iax2.c:6725 iax2_send: Supposed to send packet encrypted, but no key?

No surprise here. The remote Asterisk has crashed, so that’s probably where this is coming from.

The only thing in the error log (messages) is:
[Jan 26 20:30:46] WARNING[18195][C-00000000] chan_iax2.c: I don't know how to authenticate readacted to redacted:4569

debug log is… completely empty! (Yes, I have it enabled in logger.conf)

No duh… but why does this crash the entire Asterisk process? I’ve tried this before where if the secret is not provided, the call fails - so why is Asterisk crashing consistently in this case? This happens on multiple versions of Asterisk: 13.23.1, 13.36, and 16, every single time if the secret is not provided.

As expected, as soon as I provide in Dial() the secret required by the peer, the call completes normally and does not crash. Why is it crashing when the secret is not provided?

Here are a few additional observations:

If the wrong secret is provided (but one IS provided), it will attempt the call for about 30 seconds or so before timing out CHANUNAVAIL - Max retries exceeded. Makes perfect sense to me and this seems like expected behavior.
It does not seem to matter if the called IAX user is “recognized” as requiring IAX authentication or not. I tried with a brand new one, omitting the password, and Asterisk also crashes as before.
If the requested IAX2 user does NOT exist on the remote end, this does not happen. I suppose that also makes sense. So, it seems to me that somehow the failed negotiation/authentication of a user where an MD5 secret is required but no secret is required causes Asterisk to crash.
This only happens with MD5 authentication. If I change auth=md5 to auth=plaintext on the called node, the calling node no longer crashes, it just has the same behavior as if the wrong secret was provided (CHANUNAVAIL / I don’t know how to authenticate). So, plain text “works”. Something is wrong with MD5.

Just to be clear, I also see the “I don’t know how to authenticate” message in the console on MD5 calls, but Asterisk crashes immediately afterwards.

I enabled the option to dump core when Asterisk crashes, and I tried to inspect this, but it appears to be a binary file so I am not really sure how to read that.

jcolp · January 27, 2021, 10:36am

The process for getting a backtrace out of the core dump is on the wiki[1]. You’re likely in uncharted territory though, as per my other comment chan_iax2 sees little use or attention, and the encryption hasn’t been touched I believe since it was implemented a considerable number of years ago - so there’s likely noone familiar with it any longer.

[1] https://wiki.asterisk.org/wiki/display/AST/Getting+a+Backtrace

InterLinked · January 27, 2021, 2:17pm

Thanks, I will do that right now. Do I need to create a JIRA account myself to put this in the system or can I just send the ast dump files the core dumper generates to someone?

I don’t think it’s an issue with the authentication/encryption per se so much as some issue with the way the calling switch reacts when there was supposed to be a secret provided but none was. My instinct here at least, even though this is a very serious bug, is that it’s probably a relatively simple fix, but that statement isn’t based on looking at any actual code.

I’d posit IAX2 is used much more widely than you or the other Asterisk devs seem to think, though, so if this can be fixed I think it would be worthwhile. I may have found a workaround, but it’s just that, a workaround, and fundamentally doesn’t address whatever instability issue/bug is causing the crash.

I haven’t tested RSA but I think it’s reasonable to infer the issue might exist there as well.

Thanks!

jcolp · January 27, 2021, 2:18pm

Your community account works on JIRA. I have no time frame on when or if such a thing would be resolved.

InterLinked · January 27, 2021, 3:37pm

On examining the dumps, it seems the issue may be related more to res_crypto than it is to chan_iax2, which I suppose may make the issue more amenable to receiving attention. In any case, I’ve submitted the necessary information through JIRA now, and can provide more information for debug there if needed.

jcolp · January 27, 2021, 3:40pm

For anyone who finds this Discourse post, the issue is located at https://issues.asterisk.org/jira/browse/ASTERISK-29264

system · February 26, 2021, 3:40pm

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.