Outbound call - call is ended but audio message keeps playing

I use asterisk for outbound calling. The test i did is as follows,

  • Dialed a device using AMI originate
  • Device rang and i picked up
  • Pre-recorded message was played and i ended the call after 5 secs. Message is 22 secs.
  • On CLI it showed playing until the entire message played. CDR also collaborated this.
  • I am suspecting my dialplan cos it seems evident that there is no way to receive the end call to terminate call.

Please help me out, My dialplan is as follows;

exten => test,1,Playback(welcome)
same => n,hangup()

How do you dial out using originate command? Is it Analog line? If yes then seems to be an issue with disconnect supervision.

This is the AMI originate command;

curl -s -b ./wraps “http://127.0.0.1:8088/manager?action=originate&channel=SIP/test&context=phones&exten=test&priority=1&callerid=909090

This was successful. My SIP phone rang, i picked it up and the pre-recorded message played.

POST the Asterisk CLI and also make a SIP trace and BYE request is sent and received

~$P Trace.txt (162 Bytes)

Pls find the trace in the attachment.

I tried to open it with notepad and it doesnt work, post it here and only the relevant part to your issue


Transmitting (no NAT) to 168.253.114.14:56988:

ACK sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803 SIP/2.0

Via: SIP/2.0/UDP 10.239.239.50:5060;branch=z9hG4bK58a37979

Max-Forwards: 70

From: sip:09060008502@10.239.239.50;tag=as4bc7b329

To: sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803;tag=e0d10777

Contact: sip:09060008502@10.239.239.50:5060

Call-ID: 6d913b8f7d6107f47b7196c04b612571@10.239.239.50:5060

CSeq: 102 ACK

User-Agent: Asterisk PBX 16.8.0

Content-Length: 0


– SIP/9bits-000000c2 answered

– SIP/9bits-000000c2 answered

– Executing [9bits@phones:1] Playback(“SIP/9bits-000000c2”, “Eric”) in new stack

– Executing [9bits@phones:1] Playback(“SIP/9bits-000000c2”, “Eric”) in new stack

[Mar 1 23:46:32] WARNING[21237][C-0000006c]: mp3/interface.c:218 decodeMP3: Junk at the beginning of frame 49443303

[Mar 1 23:46:32] WARNING[21237][C-0000006c]: mp3/interface.c:218 decodeMP3: Junk at the beginning of frame 49443303

– <SIP/9bits-000000c2> Playing ‘Eric.slin’ (language ‘en’)

– <SIP/9bits-000000c2> Playing ‘Eric.slin’ (language ‘en’)

<— SIP read from UDP:168.253.114.14:56988 —>

SIP/2.0 200 OK

Via: SIP/2.0/UDP 10.239.239.50:5060;branch=z9hG4bK55e7f0cb;received=34.70.145.187

Contact: sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803;+sip.instance=“urn:uuid:01475fd3-cdab-4397-8c19-e92c40f93085

To: sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803;tag=e0d10777

From: sip:09060008502@10.239.239.50;tag=as4bc7b329

Call-ID: 6d913b8f7d6107f47b7196c04b612571@10.239.239.50:5060

CSeq: 102 INVITE

Allow: OPTIONS, INVITE, ACK, CANCEL, BYE, REFER, INFO, NOTIFY, UPDATE, PRACK, MESSAGE, SUBSCRIBE

Content-Type: application/sdp

Supported: replaces

User-Agent: Bria iOS release 6.1.1 stamp 46067.46068

Content-Length: 187

v=0

o=- 2921752980 3 IN IP4 168.253.114.14

s=Cpc session

c=IN IP4 168.253.114.14

t=0 0

m=audio 51674 RTP/AVP 0 8 101

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=sendrecv

<------------->

<— SIP read from UDP:168.253.114.14:56988 —>

SIP/2.0 200 OK

Via: SIP/2.0/UDP 10.239.239.50:5060;branch=z9hG4bK55e7f0cb;received=34.70.145.187

Contact: sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803;+sip.instance=“urn:uuid:01475fd3-cdab-4397-8c19-e92c40f93085

To: sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803;tag=e0d10777

From: sip:09060008502@10.239.239.50;tag=as4bc7b329

Call-ID: 6d913b8f7d6107f47b7196c04b612571@10.239.239.50:5060

CSeq: 102 INVITE

Allow: OPTIONS, INVITE, ACK, CANCEL, BYE, REFER, INFO, NOTIFY, UPDATE, PRACK, MESSAGE, SUBSCRIBE

Content-Type: application/sdp

Supported: replaces

User-Agent: Bria iOS release 6.1.1 stamp 46067.46068

Content-Length: 187

v=0

o=- 2921752980 3 IN IP4 168.253.114.14

s=Cpc session

c=IN IP4 168.253.114.14

t=0 0

m=audio 51674 RTP/AVP 0 8 101

a=rtpmap:101 telephone-event/8000

a=fmtp:101 0-15

a=sendrecv

<------------->

— (12 headers 9 lines) —

— (12 headers 9 lines) —

set_destination: Parsing sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803 for address/port to send to

set_destination: Parsing sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803 for address/port to send to

set_destination: set destination to 168.253.114.14:56988

set_destination: set destination to 168.253.114.14:56988

Transmitting (no NAT) to 168.253.114.14:56988:

ACK sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803 SIP/2.0

Via: SIP/2.0/UDP 10.239.239.50:5060;branch=z9hG4bK4f3d2200

Max-Forwards: 70

From: sip:09060008502@10.239.239.50;tag=as4bc7b329

To: sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803;tag=e0d10777

Contact: sip:09060008502@10.239.239.50:5060

Call-ID: 6d913b8f7d6107f47b7196c04b612571@10.239.239.50:5060

CSeq: 102 ACK

User-Agent: Asterisk PBX 16.8.0

Content-Length: 0


Transmitting (no NAT) to 168.253.114.14:56988:

ACK sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803 SIP/2.0

Via: SIP/2.0/UDP 10.239.239.50:5060;branch=z9hG4bK4f3d2200

Max-Forwards: 70

From: sip:09060008502@10.239.239.50;tag=as4bc7b329

To: sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803;tag=e0d10777

Contact: sip:09060008502@10.239.239.50:5060

Call-ID: 6d913b8f7d6107f47b7196c04b612571@10.239.239.50:5060

CSeq: 102 ACK

User-Agent: Asterisk PBX 16.8.0

Content-Length: 0


<— SIP read from UDP:168.253.114.14:56531 —>

<------------->

<— SIP read from UDP:168.253.114.14:56531 —>

<------------->

== HTTP Manager ‘admin’ timed out from 127.0.0.1

== HTTP Manager ‘admin’ timed out from 127.0.0.1

<— SIP read from UDP:168.253.114.14:59466 —>

<------------->

<— SIP read from UDP:168.253.114.14:59466 —>

<------------->

Really destroying SIP dialog ‘NGNkOTczMDgxNmJhM2Q0ZWUzMTI0MmM0OGYxYTMyZWY’ Method: OPTIONS

Really destroying SIP dialog ‘NGNkOTczMDgxNmJhM2Q0ZWUzMTI0MmM0OGYxYTMyZWY’ Method: OPTIONS

<— SIP read from UDP:168.253.114.14:56988 —>

<------------->

<— SIP read from UDP:168.253.114.14:56988 —>

<------------->

Really destroying SIP dialog ‘ZmQyMGEyZDU2MGI3YTRkMTBiZWQ3NjVlZWM0MGUyMDg’ Method: REGISTER

Really destroying SIP dialog ‘ZmQyMGEyZDU2MGI3YTRkMTBiZWQ3NjVlZWM0MGUyMDg’ Method: REGISTER

[Mar 1 23:46:56] WARNING[21237][C-0000006c]: mp3/interface.c:218 decodeMP3: Junk at the beginning of frame 54414700

[Mar 1 23:46:56] WARNING[21237][C-0000006c]: mp3/interface.c:218 decodeMP3: Junk at the beginning of frame 54414700

– Executing [9bits@phones:2] Hangup(“SIP/9bits-000000c2”, “”) in new stack

– Executing [9bits@phones:2] Hangup(“SIP/9bits-000000c2”, “”) in new stack

== Spawn extension (phones, 9bits, 2) exited non-zero on ‘SIP/9bits-000000c2’

== Spawn extension (phones, 9bits, 2) exited non-zero on ‘SIP/9bits-000000c2’

Scheduling destruction of SIP dialog ‘6d913b8f7d6107f47b7196c04b612571@10.239.239.50:5060’ in 32000 ms (Method: INVITE)

Scheduling destruction of SIP dialog ‘6d913b8f7d6107f47b7196c04b612571@10.239.239.50:5060’ in 32000 ms (Method: INVITE)

set_destination: Parsing sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803 for address/port to send to

set_destination: Parsing sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803 for address/port to send to

set_destination: set destination to 168.253.114.14:56988

set_destination: set destination to 168.253.114.14:56988

Reliably Transmitting (no NAT) to 168.253.114.14:56988:

BYE sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803 SIP/2.0

Via: SIP/2.0/UDP 10.239.239.50:5060;branch=z9hG4bK7258ecc1

Max-Forwards: 70

From: sip:09060008502@10.239.239.50;tag=as4bc7b329

To: sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803;tag=e0d10777

Call-ID: 6d913b8f7d6107f47b7196c04b612571@10.239.239.50:5060

CSeq: 103 BYE

User-Agent: Asterisk PBX 16.8.0

X-Asterisk-HangupCause: Normal Clearing

X-Asterisk-HangupCauseCode: 16

Content-Length: 0


Reliably Transmitting (no NAT) to 168.253.114.14:56988:

BYE sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803 SIP/2.0

Via: SIP/2.0/UDP 10.239.239.50:5060;branch=z9hG4bK7258ecc1

Max-Forwards: 70

From: sip:09060008502@10.239.239.50;tag=as4bc7b329

To: sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803;tag=e0d10777

Call-ID: 6d913b8f7d6107f47b7196c04b612571@10.239.239.50:5060

CSeq: 103 BYE

User-Agent: Asterisk PBX 16.8.0

X-Asterisk-HangupCause: Normal Clearing

X-Asterisk-HangupCauseCode: 16

Content-Length: 0


<— SIP read from UDP:168.253.114.14:56988 —>

SIP/2.0 200 OK

Via: SIP/2.0/UDP 10.239.239.50:5060;branch=z9hG4bK7258ecc1;received=34.70.145.187

Contact: sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803;+sip.instance=“urn:uuid:01475fd3-cdab-4397-8c19-e92c40f93085

To: sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803;tag=e0d10777

From: sip:09060008502@10.239.239.50;tag=as4bc7b329

Call-ID: 6d913b8f7d6107f47b7196c04b612571@10.239.239.50:5060

CSeq: 103 BYE

User-Agent: Bria iOS release 6.1.1 stamp 46067.46068

Content-Length: 0

------------->

<— SIP read from UDP:168.253.114.14:56988 —>

SIP/2.0 200 OK

Via: SIP/2.0/UDP 10.239.239.50:5060;branch=z9hG4bK7258ecc1;received=34.70.145.187

Contact: sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803;+sip.instance=“urn:uuid:01475fd3-cdab-4397-8c19-e92c40f93085

To: sip:9bits@168.253.114.14:56988;rinstance=cb8c0e77f2311803;tag=e0d10777

From: sip:09060008502@10.239.239.50;tag=as4bc7b329

Call-ID: 6d913b8f7d6107f47b7196c04b612571@10.239.239.50:5060

CSeq: 103 BYE

User-Agent: Bria iOS release 6.1.1 stamp 46067.46068

Content-Length: 0

<------------->

— (9 headers 0 lines) —

— (9 headers 0 lines) —

Really destroying SIP dialog ‘6d913b8f7d6107f47b7196c04b612571@10.239.239.50:5060’ Method: INVITE

Really destroying SIP dialog ‘6d913b8f7d6107f47b7196c04b612571@10.239.239.50:5060’ Method: INVITE

<— SIP read from UDP:168.253.114.14:56531 —>

Asterisk didn’t receive BYE request (i.e. Hangup) from your phone. Is NAT involved here?

I am using a soft SIP phone on my IOS and my internet access is natted. Asterisk app is in a server in the cloud.

You should look at the packet capture and see where it is getting lost. I would start with opening all the required ports on my cloud and forwarding them to Asterisk server first and then capturing SIP packets (tcpdump)to see they are reaching my system on which Asterisk is running. If that’s the case then the asterisk is not properly configured to handle the NAT’d endpoints

Another thing i noticed. The local asterisk IP is used and not the public one. Do you think that might be the issue.

Scheduling destruction of SIP dialog ‘6509efe37923ddb67d546f6a550ec105@10.239.239.50:5060’ in 32000 ms (Method: INVITE)
Scheduling destruction of SIP dialog ‘6509efe37923ddb67d546f6a550ec105@10.239.239.50:5060’ in 32000 ms (Method: INVITE)
Reliably Transmitting (NAT) to 168.253.114.14:46849:
BYE sip:9bits@168.253.114.14:46849 SIP/2.0
Via: SIP/2.0/UDP 10.239.239.50:5060;branch=z9hG4bK20972783;rport
Max-Forwards: 70
From: sip:09060008502@10.239.239.50;tag=as0b6f09b8
To: sip:9bits@168.253.114.14:46849;rinstance=f6331944abf1c2e8;transport=UDP;tag=f1496154
Call-ID: 6509efe37923ddb67d546f6a550ec105@10.239.239.50:5060
CSeq: 103 BYE
User-Agent: Asterisk PBX 16.8.0
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0

This is the trace. I’m seeing that the SIP phone send BYE a number of times without any ack from the server. Once the server sent BYE, the phone responded and thereafter exited. I think the issue is obvious now. The destination is the server’s local IP. How can i make it to be public.

Yes. Look at externip, localnet under general section and nat option under peer definition in sip.conf.

Thank you very much. I added both parameters and boom. I’m good. Cheers mate.

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