ARI - Originate call but no ChannelCreated event back

Asterisk Asterisk APIs
1

I have an application that can successfully place calls using ARI.

The application creates a bridge, places the call and looks for a StasisStart message with the channel id as a signal that the call has been connected. At that point the app adds the channel to the bridge and we can proceed with the call. This works well most of the time.
We have been seeing that for some long distance calls (USA to Europe) we still receive StasisStart, the user is dialed and he picks up the call, but when we play a sound on the main channel the user can’t hear it. The application still receives PlaybackStarted and PlaybackFinished though.

One thing we have noticed is that we do not receive a “ChannelCreated” message back in those failure cases. The channel however enters Stasis and it is added to the bridge.
Does the app need to play the sound on the bridge as opposed to do it on the channel?
Is this a timing issue?
should we fail the call if ChannelCreated is not received?

Thanks

2

You’d need to provide the specific ARI requests you are making, and you should also look at the SIP signalling to see if there’s a difference.

3

Thanks for your help.
I am posting the sequence of events in that call. See how there’s no ChannelCreated event.
How can I look at the SIP signaling? Do I need to capture all networking events with wireshark?

API requests/incoming events in chronological order:

POST 10.32.8.31:8088
/ari/bridges/ea4e6e04-780b-41e6-989c-1e9bd7c520ba?type=mixing,dtmf_events  HTTP 1.1
--------------------
POST 10.32.8.31:8088
/ari/channels?endpoint=PJSIP0.000000B48797478585MyProvider&app=MyAppId&channelId=ea4e6e04-780b-41e6-989c-1e9bd7c520ba&callerId=fer%3CB140293577331.101614E-311&timeout=0&appArgs=internal  HTTP 1.1

+++ [5-7-2021 17:57:17:865Z] [DEBUG] 
Received raw event: {
  "type": "BridgeCreated",
  "timestamp": "2021-05-07T17:57:18.110+0000",
  "bridge": {
    "id": "ea4e6e04-780b-41e6-989c-1e9bd7c520ba",
    "technology": "simple_bridge",
    "bridge_type": "mixing",
    "bridge_class": "stasis",
    "creator": "Stasis",
    "name": "",
    "channels": [],
    "creationtime": "2021-05-07T17:57:18.110+0000",
    "video_mode": "talker"
  },
  "asterisk_id": "12:65:d8:12:ae:4f",
  "application": "Prove-spuate0"
}

+++ [5-7-2021 17:57:17:865Z] [DEBUG] 
Received raw event: {
  "type": "Dial",
  "timestamp": "2021-05-07T17:57:18.111+0000",
  "dialstatus": "",
  "forward": "",
  "dialstring": "+48797478585@MyProvider",
  "peer": {
    "id": "ea4e6e04-780b-41e6-989c-1e9bd7c520ba",
    "name": "PJSIP/00000445",
    "state": "Down",
    "caller": {
      "name": "fer",
      "number": "+14029357733"
    },
    "connected": {
      "name": "fer",
      "number": "+14029357733"
    },
    "accountcode": "",
    "dialplan": {
      "context": "voice-otp",
      "exten": "s",
      "priority": 1,
      "app_name": "AppDial2",
      "app_data": "(Outgoing Line)"
    },
    "creationtime": "2021-05-07T17:57:18.110+0000",
    "language": "en"
  },
  "asterisk_id": "12:65:d8:12:ae:4f",
  "application": "MyAppId"
}

+++ [5-7-2021 17:57:25:349Z] [DEBUG] [AsteriskPlugin]
Received raw event: {
  "type": "ChannelStateChange",
  "timestamp": "2021-05-07T17:57:25.590+0000",
  "channel": {
    "id": "ea4e6e04-780b-41e6-989c-1e9bd7c520ba",
    "name": "PJSIP/00000445",
    "state": "Up",
    "caller": {
      "name": "fer",
      "number": "+14029357733"
    },
    "connected": {
      "name": "fer",
      "number": "+14029357733"
    },
    "accountcode": "",
    "dialplan": {
      "context": "voice-otp",
      "exten": "s",
      "priority": 1,
      "app_name": "AppDial2",
      "app_data": "(Outgoing Line)"
    },
    "creationtime": "2021-05-07T17:57:18.110+0000",
    "language": "en"
  },
  "asterisk_id": "12:65:d8:12:ae:4f",
  "application": "MyAppId"
}

+++ [5-7-2021 17:57:25:349Z] [DEBUG] [AsteriskPlugin]
Received raw event: {
  "type": "Dial",
  "timestamp": "2021-05-07T17:57:25.590+0000",
  "dialstatus": "ANSWER",
  "forward": "",
  "dialstring": "+48797478585@Voxout",
  "peer": {
    "id": "ea4e6e04-780b-41e6-989c-1e9bd7c520ba",
    "name": "PJSIP/00000445",
    "state": "Up",
    "caller": {
      "name": "fer",
      "number": "+14029357733"
    },
    "connected": {
      "name": "fer",
      "number": "+14029357733"
    },
    "accountcode": "",
    "dialplan": {
      "context": "voice-otp",
      "exten": "s",
      "priority": 1,
      "app_name": "AppDial2",
      "app_data": "(Outgoing Line)"
    },
    "creationtime": "2021-05-07T17:57:18.110+0000",
    "language": "en"
  },
  "asterisk_id": "12:65:d8:12:ae:4f",
  "application": "MyAppId"
}

+++ [5-7-2021 17:57:25:349Z] [DEBUG] [AsteriskPlugin]
Received raw event: {
  "variable": "STASISSTATUS",
  "value": "",
  "type": "ChannelVarset",
  "timestamp": "2021-05-07T17:57:25.590+0000",
  "channel": {
    "id": "ea4e6e04-780b-41e6-989c-1e9bd7c520ba",
    "name": "PJSIP/00000445",
    "state": "Up",
    "caller": {
      "name": "fer",
      "number": "+14029357733"
    },
    "connected": {
      "name": "fer",
      "number": "+14029357733"
    },
    "accountcode": "",
    "dialplan": {
      "context": "voice-otp",
      "exten": "s",
      "priority": 1,
      "app_name": "Stasis",
      "app_data": "MyAppId,internal"
    },
    "creationtime": "2021-05-07T17:57:18.110+0000",
    "language": "en"
  },
  "asterisk_id": "12:65:d8:12:ae:4f",
  "application": "MyAppId"
}

+++ [5-7-2021 17:57:25:349Z] [DEBUG] [AsteriskPlugin]
Received raw event: {
  "type": "StasisStart",
  "timestamp": "2021-05-07T17:57:25.590+0000",
  "args": [
    "internal"
  ],
  "channel": {
    "id": "ea4e6e04-780b-41e6-989c-1e9bd7c520ba",
    "name": "PJSIP/00000445",
    "state": "Up",
    "caller": {
      "name": "fer",
      "number": "+14029357733"
    },
    "connected": {
      "name": "fer",
      "number": "+14029357733"
    },
    "accountcode": "",
    "dialplan": {
      "context": "voice-otp",
      "exten": "s",
      "priority": 1,
      "app_name": "Stasis",
      "app_data": "MyAppId,internal"
    },
    "creationtime": "2021-05-07T17:57:18.110+0000",
    "language": "en"
  },
  "asterisk_id": "12:65:d8:12:ae:4f",
  "application": "MyAppId"
}

At this point the app has entered Stasis, so add the channel to the bridge and try to play a sound

+++ [5-7-2021 17:57:25:349Z] [DEBUG] 
--------------------
POST 10.32.8.31:8088
/ari/bridges/ea4e6e04-780b-41e6-989c-1e9bd7c520ba/addChannel?channel=ea4e6e04-780b-41e6-989c-1e9bd7c520ba&mute=false&role=participant  HTTP 1.1
Content-Length: 0

+++ [5-7-2021 17:57:25:349Z] [DEBUG] 
--------------------
POST 10.32.8.31:8088
/ari/channels/ea4e6e04-780b-41e6-989c-1e9bd7c520ba/play?media=sound0X0.000DC63CFECB0P-10220.000000var0.000000lib0.000000mfa0.000000confirminputmatch0.000000greetaffirm&playbackId=3eeedffb-6c0b-47f0-a155-c07a3f898063  HTTP 1.1
Content-Length: 0


+++ [5-7-2021 17:57:25:349Z] [DEBUG] 
Received raw event: {
  "type": "ChannelEnteredBridge",
  "timestamp": "2021-05-07T17:57:25.599+0000",
  "bridge": {
    "id": "ea4e6e04-780b-41e6-989c-1e9bd7c520ba",
    "technology": "simple_bridge",
    "bridge_type": "mixing",
    "bridge_class": "stasis",
    "creator": "Stasis",
    "name": "",
    "channels": [
      "ea4e6e04-780b-41e6-989c-1e9bd7c520ba"
    ],
    "creationtime": "2021-05-07T17:57:18.110+0000",
    "video_mode": "talker"
  },
  "channel": {
    "id": "ea4e6e04-780b-41e6-989c-1e9bd7c520ba",
    "name": "PJSIP/00000445",
    "state": "Up",
    "caller": {
      "name": "fer",
      "number": "+14029357733"
    },
    "connected": {
      "name": "fer",
      "number": "+14029357733"
    },
    "accountcode": "",
    "dialplan": {
      "context": "voice-otp",
      "exten": "s",
      "priority": 1,
      "app_name": "Stasis",
      "app_data": "MyAppId,internal"
    },
    "creationtime": "2021-05-07T17:57:18.110+0000",
    "language": "en"
  },
  "asterisk_id": "12:65:d8:12:ae:4f",
  "application": "MyAppId"
}

+++ [5-7-2021 17:57:25:349Z] [DEBUG] [AsteriskPlugin]
Received raw event: {
  "type": "PlaybackStarted",
  "timestamp": "2021-05-07T17:57:25.599+0000",
  "playback": {
    "id": "3eeedffb-6c0b-47f0-a155-c07a3f898063",
    "media_uri": "sound:/var/lib/mfa/en-us/confirminputmatch/greetaffirm",
    "target_uri": "channel:ea4e6e04-780b-41e6-989c-1e9bd7c520ba",
    "language": "en",
    "state": "playing"
  },
  "asterisk_id": "12:65:d8:12:ae:4f",
  "application": "MyAppId"
}
4

I’m surprised it lets you play a sound file on the channel while in the bridge. I don’t think this should actually work, but someone may correct me.

As for SIP traffic it can be done using Wireshark, or from the Asterisk CLI using “pjsip set logger on”. As it is though nothing stands out besides my comment on playing a sound file.

If you play the sound file before placing it into the bridge, does it change?

5

CreateChannelIssuewireshark.txt (1.3 MB)
I’ll try both options,
playing the sound from the bridge
playing the file before placing it into the bridge

6

Update:
My SIP provider took a look at the problem and it seems it has to do with a problem with the local mobile provider in Europe.
I won’t be changing my state machine as it does work exactly how I need it right now. I’ll update the thread if needed.
Thanks for your time.

7

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