Asterisk 16.3: DialEnd DialStatus always "NOANSWER"

Hi there,

On Asterisk 16.3 with PJSIP, when I use the Dial Application to dial a user registered with my Kamailio Registrar, and the user rejects the call (SIP 486 Busy Here), or has their device in DND (480 Temp Unavailable), the AMI DialEnd event’s DialStatus for those calls are always “NOANSWER” (I would expect “BUSY”).

With Asterisk 13 (chan_sip), it used to be “BUSY” in those cases.

If the user isn’t registered, then the DialStatus is also “NOANSWER”.

This makes it impossible for me to differentiate between SIP 404 Not Found, SIP 480 (DND) or SIP 486 (Busy/Rejected).

I’ve checked quite a lot of AMI Event history, and I can’t find a single case where the DialStatus is set to BUSY (which according to the documentation is an expected value for this field).

What is the value of the DIALSTATUS variable in the dialplan when it occurs? What is the console output? How is it being dialed?

After a little further investigation, and after my colleague actually did find some DialEnd events where DialStatus=“BUSY”, I’ve narrowed it down to what provokes this

If I set the c dial flag DIAL(PJSIP/user@registrar, 30, c), the DialEnd events will have “NOANSWER” instead of “BUSY”, if the user being dialed rejects the call (in Yealink’s case, that’s by responding to the invite with SIP 486 Busy Here). In this case, the DIALSTATUS variable is “CHANUNAVAIL”.

Without the c flag being set, it works as expected.

However… even without the c flag being set, if the device responds with 480 Temporary Unavailable, which happens if the phone is set to DND, then the DialEnd events DialString=“NOANSWER” as well. In this case, the DIALSTATUS variable is also “NOANSWER”.

I guess it’s some sort of bug that setting the c dial flag has an effect on the DialEnd events like that. That should only affect any SIP CANCEL asterisk would send out right?

The case where the device is in DND (responding with SIP 480, without first responding with Ringing), I guess this should also set DialStatus=“BUSY”?

There is nothing out of the ordinary in the console output:

    -- Executing [jonas2@dial:1] NoOp("PJSIP/registrar-000000d5", "AGI: ") in new stack
    -- Executing [jonas2@dial:2] GosubIf("PJSIP/registrar-000000d5", "1?init-agi,SetAgi,1") in new stack
    -- Executing [SetAgi@init-agi:1] NoOp("PJSIP/registrar-000000d5", "SET AGI") in new stack
    -- Executing [SetAgi@init-agi:2] Set("PJSIP/registrar-000000d5", "__agiUrl=vestergade.office.test.com:2000") in new stack
    -- Executing [SetAgi@init-agi:3] Return("PJSIP/registrar-000000d5", "") in new stack
    -- Executing [jonas2@dial:3] AGI("PJSIP/registrar-000000d5", "agi://vestergade.office.test.com:2000/dial") in new stack
    -- AGI Script Executing Application: (Ringing) Options: ()
     -- AGI Script Executing Application: (Monitor) Options: (wav,ast007-1558611941.407,bm)
    -- AGI Script Executing Application: (Dial) Options: (PJSIP/jonas2@registrar,300,b(headers^add^1))
    -- PJSIP/registrar-000000d6 Internal Gosub(headers,add,1) start
    -- Executing [add@headers:1] GotoIf("PJSIP/registrar-000000d6", "0?return") in new stack
    -- Executing [add@headers:2] Set("PJSIP/registrar-000000d6", "PJSIP_HEADER(add,X-Uid)=ast007-1558611950.408") in new stack
    -- Executing [add@headers:3] Set("PJSIP/registrar-000000d6", "headers=X-Call-ID") in new stack
    -- Executing [add@headers:4] While("PJSIP/registrar-000000d6", "1") in new stack
    -- Executing [add@headers:5] Set("PJSIP/registrar-000000d6", "PJSIP_HEADER(add,X-Call-ID)=7-5ce687e5-197") in new stack
    -- Executing [add@headers:6] EndWhile("PJSIP/registrar-000000d6", "") in new stack
    -- Executing [add@headers:4] While("PJSIP/registrar-000000d6", "0") in new stack
    -- Executing [add@headers:7] Return("PJSIP/registrar-000000d6", "") in new stack
  == Spawn extension (dial, jonas2, 1) exited non-zero on 'PJSIP/registrar-000000d6'
    -- PJSIP/registrar-000000d6 Internal Gosub(headers,add,1) complete GOSUB_RETVAL=
    -- Called PJSIP/jonas2@registrar
    -- No one is available to answer at this time (1:0/0/0)
    -- <PJSIP/registrar-000000d5>AGI Script agi://vestergade.office.test.com:2000/dial completed, returning 4
  == Spawn extension (dial, jonas2, 3) exited non-zero on 'PJSIP/registrar-000000d5'
    -- Executing [h@dial:1] NoOp("PJSIP/registrar-000000d5", "Hangup") in new stack

The “c” option works by way of the hangup cause, which is used for the dial status. It’s certainly possible there is some bug there where it is set when it shouldn’t be.

As for NOANSWER or BUSY when a 480 comes back, it’s documented[1] as NOANSWER at least. It doesn’t really map cleanly to either, but personally I think no answer makes more sense. BUSY is if you are on the phone - which you aren’t with a 480.

[1] https://wiki.asterisk.org/wiki/display/AST/Hangup+Cause+Mappings

Okay I agree it makes sense that NOANSWER is a good reponse for 480, it’s also clear from the Hangup events why the call was rejected.

But the way the C flag works makes it completely impossible to distingush between if a user just wasn’t registered, if they rejected a call or of they’re DND.

I’ll just list a few cases here, all where the C flag is set

User is not registered (SIP 404 response)
When the C flag is set, all HangupEvents associated with the call has Cause 26. Answered Elsewhere.

This is not true. This call was not ended because it was answered elsewhere, since no SIP CANCEL was ever sent out. On the initial invite asterisk gets a 404 back from the registrar, so the correct cause code should be 1. AST_CAUSE_UNALLOCATED

Here are the relevant events:

404 (with c)
{
  "Event": "DialEnd",
  "Channel": "PJSIP/registrar-000000dc",
  "ChannelState": 4,
  "ChannelStateDesc": "Ring",
  "CallerIDNum": "jonas1",
  "CallerIDName": "jonas1",
  "ConnectedLineNum": "jonas2",
  "ConnectedLineName": "<unknown>",
  "AccountCode": "",
  "Context": "dial",
  "Exten": "jonas2",
  "Priority": "2",
  "DestChannel": "PJSIP/registrar-000000dd",
  "DestChannelState": 0,
  "DestChannelStateDesc": "Down",
  "DestCallerIDNum": "jonas2",
  "DestCallerIDName": "<unknown>",
  "DestConnectedLineNum": "jonas1",
  "DestConnectedLineName": "jonas1",
  "DestAccountCode": "",
  "DestContext": "dial",
  "DestExten": "jonas2",
  "DestPriority": "1",
  "DestUniqueid": "ast007-1558613595.415",
  "DialStatus": "NOANSWER",
  "Forward": null,
  "Linkedid": "ast007-1558613595.414",
  "DestLinkedid": "ast007-1558613595.414",
  "Uniqueid": "ast007-1558613595.414",
  "UtcDate": "2019-05-23T12:13:15Z",
  "DateReceived": "23-05-2019 12:13:15",
  "Language": "en",
  "Privilege": "call,all",
  "SystemName": "ast007",
  "KafkaPartitionId": 0,
  "KafkaOffset": 0,
  "_sequence": 1838,
  "AdditionalAttributes": {
    "DestLanguage": "en",
    "ApproxTimeStamp": "2019-05-23T12:13:16.628+00:00"
  }
}
{
  "Event": "Hangup",
  "Channel": "PJSIP/registrar-000000dd",
  "ChannelState": 0,
  "ChannelStateDesc": "Down",
  "CallerIDNum": "jonas2",
  "CallerIDName": "<unknown>",
  "ConnectedLineNum": "jonas1",
  "ConnectedLineName": "jonas1",
  "AccountCode": "",
  "Context": "dial",
  "Exten": "jonas2",
  "Priority": "1",
  "Cause": 26,
  "Causetxt": "Answered elsewhere",
  "Linkedid": "ast007-1558613595.414",
  "Uniqueid": "ast007-1558613595.415",
  "UtcDate": "2019-05-23T12:13:15Z",
  "DateReceived": "23-05-2019 12:13:15",
  "Language": "en",
  "Privilege": "call,all",
  "SystemName": "ast007",
  "KafkaPartitionId": 0,
  "KafkaOffset": 0,
  "_sequence": 1839,
  "AdditionalAttributes": {
    "Cause-txt": "Answered elsewhere",
    "ApproxTimeStamp": "2019-05-23T12:13:16.628+00:00"
  }
}
{
  "Event": "Hangup",
  "Channel": "PJSIP/registrar-000000dc",
  "ChannelState": 4,
  "ChannelStateDesc": "Ring",
  "CallerIDNum": "jonas1",
  "CallerIDName": "jonas1",
  "ConnectedLineNum": "jonas2",
  "ConnectedLineName": "<unknown>",
  "AccountCode": "",
  "Context": "dial",
  "Exten": "h",
  "Priority": "2",
  "Cause": 26,
  "Causetxt": "Answered elsewhere",
  "Linkedid": "ast007-1558613595.414",
  "Uniqueid": "ast007-1558613595.414",
  "UtcDate": "2019-05-23T12:13:15Z",
  "DateReceived": "23-05-2019 12:13:15",
  "Language": "en",
  "Privilege": "call,all",
  "SystemName": "ast007",
  "KafkaPartitionId": 0,
  "KafkaOffset": 0,
  "_sequence": 1840,
  "AdditionalAttributes": {
    "Cause-txt": "Answered elsewhere",
    "ApproxTimeStamp": "2019-05-23T12:13:16.628+00:00"
  }
}

If the c-flag isn’t set, then I get the expected hangup code (1. Unallocated number). This makes it impossible for me to know that the user isn’t registered from any of the AMI events, or if the call was simply cancelled or timed out.

I don’t believe the C flag is supposed to alter the Hangup Cause like this, unless the call was actually cancelled.

User is DND (SIP 480 response)
Again, here the HangupEvents are being altered by the C flag, exactly like in the first case.

480 (with c)
{
  "Event": "DialEnd",
  "Channel": "PJSIP/registrar-000000e2",
  "ChannelState": 4,
  "ChannelStateDesc": "Ring",
  "CallerIDNum": "jonas1",
  "CallerIDName": "jonas1",
  "ConnectedLineNum": "jonas2",
  "ConnectedLineName": "<unknown>",
  "AccountCode": "",
  "Context": "dial",
  "Exten": "jonas2",
  "Priority": "2",
  "DestChannel": "PJSIP/registrar-000000e3",
  "DestChannelState": 0,
  "DestChannelStateDesc": "Down",
  "DestCallerIDNum": "jonas2",
  "DestCallerIDName": "<unknown>",
  "DestConnectedLineNum": "jonas1",
  "DestConnectedLineName": "jonas1",
  "DestAccountCode": "",
  "DestContext": "dial",
  "DestExten": "jonas2",
  "DestPriority": "1",
  "DestUniqueid": "ast007-1558613775.421",
  "DialStatus": "NOANSWER",
  "Forward": null,
  "Linkedid": "ast007-1558613775.420",
  "DestLinkedid": "ast007-1558613775.420",
  "Uniqueid": "ast007-1558613775.420",
  "UtcDate": "2019-05-23T12:16:15Z",
  "DateReceived": "23-05-2019 12:16:15",
  "Language": "en",
  "Privilege": "call,all",
  "SystemName": "ast007",
  "KafkaPartitionId": 0,
  "KafkaOffset": 0,
  "_sequence": 1862,
  "AdditionalAttributes": {
    "DestLanguage": "en",
    "ApproxTimeStamp": "2019-05-23T12:16:16.625+00:00"
  }
}
{
  "Event": "Hangup",
  "Channel": "PJSIP/registrar-000000e3",
  "ChannelState": 0,
  "ChannelStateDesc": "Down",
  "CallerIDNum": "jonas2",
  "CallerIDName": "<unknown>",
  "ConnectedLineNum": "jonas1",
  "ConnectedLineName": "jonas1",
  "AccountCode": "",
  "Context": "dial",
  "Exten": "jonas2",
  "Priority": "1",
  "Cause": 26,
  "Causetxt": "Answered elsewhere",
  "Linkedid": "ast007-1558613775.420",
  "Uniqueid": "ast007-1558613775.421",
  "UtcDate": "2019-05-23T12:16:15Z",
  "DateReceived": "23-05-2019 12:16:15",
  "Language": "en",
  "Privilege": "call,all",
  "SystemName": "ast007",
  "KafkaPartitionId": 0,
  "KafkaOffset": 0,
  "_sequence": 1863,
  "AdditionalAttributes": {
    "Cause-txt": "Answered elsewhere",
    "ApproxTimeStamp": "2019-05-23T12:16:16.625+00:00"
  }
}
{
  "Event": "Hangup",
  "Channel": "PJSIP/registrar-000000e2",
  "ChannelState": 4,
  "ChannelStateDesc": "Ring",
  "CallerIDNum": "jonas1",
  "CallerIDName": "jonas1",
  "ConnectedLineNum": "jonas2",
  "ConnectedLineName": "<unknown>",
  "AccountCode": "",
  "Context": "dial",
  "Exten": "h",
  "Priority": "2",
  "Cause": 26,
  "Causetxt": "Answered elsewhere",
  "Linkedid": "ast007-1558613775.420",
  "Uniqueid": "ast007-1558613775.420",
  "UtcDate": "2019-05-23T12:16:15Z",
  "DateReceived": "23-05-2019 12:16:15",
  "Language": "en",
  "Privilege": "call,all",
  "SystemName": "ast007",
  "KafkaPartitionId": 0,
  "KafkaOffset": 0,
  "_sequence": 1864,
  "AdditionalAttributes": {
    "Cause-txt": "Answered elsewhere",
    "ApproxTimeStamp": "2019-05-23T12:16:16.625+00:00"
  }
}

User Rejects (SIP 180 Ringing -> SIP 486 Busy Here)
Again, here the HangupEvents are being altered by the C flag, exactly like in the first case.

486 (with c)
{
  "Event": "DialEnd",
  "Channel": "PJSIP/registrar-000000e8",
  "ChannelState": 4,
  "ChannelStateDesc": "Ring",
  "CallerIDNum": "jonas1",
  "CallerIDName": "jonas1",
  "ConnectedLineNum": "jonas2",
  "ConnectedLineName": "<unknown>",
  "AccountCode": "",
  "Context": "dial",
  "Exten": "jonas2",
  "Priority": "2",
  "DestChannel": "PJSIP/registrar-000000e9",
  "DestChannelState": 5,
  "DestChannelStateDesc": "Ringing",
  "DestCallerIDNum": "jonas2",
  "DestCallerIDName": "<unknown>",
  "DestConnectedLineNum": "jonas1",
  "DestConnectedLineName": "jonas1",
  "DestAccountCode": "",
  "DestContext": "dial",
  "DestExten": "jonas2",
  "DestPriority": "1",
  "DestUniqueid": "ast007-1558613944.427",
  "DialStatus": "NOANSWER",
  "Forward": null,
  "Linkedid": "ast007-1558613944.426",
  "DestLinkedid": "ast007-1558613944.426",
  "Uniqueid": "ast007-1558613944.426",
  "UtcDate": "2019-05-23T12:19:06Z",
  "DateReceived": "23-05-2019 12:19:06",
  "Language": "en",
  "Privilege": "call,all",
  "SystemName": "ast007",
  "KafkaPartitionId": 0,
  "KafkaOffset": 0,
  "_sequence": 1889,
  "AdditionalAttributes": {
    "DestLanguage": "en",
    "ApproxTimeStamp": "2019-05-23T12:19:07.609+00:00"
  }
}
{
  "Event": "Hangup",
  "Channel": "PJSIP/registrar-000000e9",
  "ChannelState": 5,
  "ChannelStateDesc": "Ringing",
  "CallerIDNum": "jonas2",
  "CallerIDName": "<unknown>",
  "ConnectedLineNum": "jonas1",
  "ConnectedLineName": "jonas1",
  "AccountCode": "",
  "Context": "dial",
  "Exten": "jonas2",
  "Priority": "1",
  "Cause": 26,
  "Causetxt": "Answered elsewhere",
  "Linkedid": "ast007-1558613944.426",
  "Uniqueid": "ast007-1558613944.427",
  "UtcDate": "2019-05-23T12:19:06Z",
  "DateReceived": "23-05-2019 12:19:06",
  "Language": "en",
  "Privilege": "call,all",
  "SystemName": "ast007",
  "KafkaPartitionId": 0,
  "KafkaOffset": 0,
  "_sequence": 1890,
  "AdditionalAttributes": {
    "Cause-txt": "Answered elsewhere",
    "ApproxTimeStamp": "2019-05-23T12:19:07.609+00:00"
  }
}
{
  "Event": "Hangup",
  "Channel": "PJSIP/registrar-000000e8",
  "ChannelState": 4,
  "ChannelStateDesc": "Ring",
  "CallerIDNum": "jonas1",
  "CallerIDName": "jonas1",
  "ConnectedLineNum": "jonas2",
  "ConnectedLineName": "<unknown>",
  "AccountCode": "",
  "Context": "dial",
  "Exten": "h",
  "Priority": "2",
  "Cause": 26,
  "Causetxt": "Answered elsewhere",
  "Linkedid": "ast007-1558613944.426",
  "Uniqueid": "ast007-1558613944.426",
  "UtcDate": "2019-05-23T12:19:06Z",
  "DateReceived": "23-05-2019 12:19:06",
  "Language": "en",
  "Privilege": "call,all",
  "SystemName": "ast007",
  "KafkaPartitionId": 0,
  "KafkaOffset": 0,
  "_sequence": 1891,
  "AdditionalAttributes": {
    "Cause-txt": "Answered elsewhere",
    "ApproxTimeStamp": "2019-05-23T12:19:07.609+00:00"
  }
}

As you can see, the DialEnd and Hangup events are completely identical for all three cases, making it completely impossible to tell these three very different outcomes of a call apart.

Reading the documentation for the c argument on the Dial application (https://wiki.asterisk.org/wiki/display/AST/Asterisk+16+Application_Dial):

  • c - If the Dial() application cancels this call, always set HANGUPCAUSE to ‘answered elsewhere’

It should only apply this change to hangup cause IF it cancels the call. In all of the above cases, none of the calls were cancelled.

I’d suggest filing an issue on the issue tracker[1] but I have no timeframe on when it will get looked into.

[1] https://issues.asterisk.org/jira

Issue filed: https://issues.asterisk.org/jira/browse/ASTERISK-28428

Note that is is adviasable to cross-reference this thread in the issue report. Also, this doesn’t seem to meet the criteria for Major, in that it does not affect most users.

I’ve added a link to this post under external references in the issue.

Fair enough if it’s not major - I just went by the definition on the issue guidelines which lists “Major loss of function” as an example. It’s a major loss of functionality to people who rely on this functionality I guess :wink:

Minor is exemplified as something where there is an easy workaround available, which there isn’t in this case. At least not one I’ve managed to discover. But I’m of course at the end of the day I’m not the judge of determining the severity of the issue.

1 Like

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