[asterisk-dev] Asterisk Receives SIP 180 and then SIP 486 But Doesn't Play Busy Tones

Jamuel Starkey jamuel at hcvoip.com
Mon Jan 25 03:21:50 CST 2010 

Hi,

I'm hoping that this qualifies as Dev related if not my apologies in advance :)

We placed a call thru a carrier who sent a provisional SIP 180 RINGING with SDP (and even sent RTP media with ring tones). The carrier then turned around and sent a SIP 486 Busy Here.  Our dialplan allows for this Busy and falls thru to calling Playtones(busy) and then finally Busy().

The issue that I have is that our calling party (on Polycom SIP phone) heard the ringing media played by the remote/carrier but never heard the busy tones that should have been played by asterisk and ultimately was just disconnected.  A review of the asterisk log shows just after Playtone(busy) was called:  

Jan 22 17:20:50 PSL asterisk[29569]: WARNING[9449]: translate.c:168 in framein: no samples for ulawtolin

Which I'm guessing is why my calling party never heard the Busy tones media.

My set up is SIP Phone  > asterisk > sip carrier trunk (G.711 ulaw end-to-end)

Here's the full log piece:

     -- Executing [s at macro-dialout-trunk:20] Goto("SIP/0004F2237E42-08eed528", "s-BUSY,1") in new stack
     -- Goto (macro-dialout-trunk,s-BUSY,1)
     -- Executing [s-BUSY at macro-dialout-trunk:1] NoOp("SIP/0004F2237E42-08eed528", "Dial failed due to trunk reporting BUSY - giving up") in new stack
     -- Executing [s-BUSY at macro-dialout-trunk:2] PlayTones("SIP/0004F2237E42-08eed528", "busy") in new stack 
translate.c:168 in framein: no samples for ulawtolin
     -- Executing [s-BUSY at macro-dialout-trunk:3] Busy("SIP/0004F2237E42-08eed528", "20") in new stack
   == Spawn extension (macro-dialout-trunk, s-BUSY, 3) exited non-zero on 'SIP/0004F2237E42-08eed528' in macro 'dialout-trunk'

So my questions are:

1. Is it legal and/or appropriate for the carrier to sending 180 RINGING w/ ringing media only to then send 486 Busy Here? (I'm assuming yes but . . .)
2. What should I make of the translate.c warning? (This is my real question to the Asterisk brain trust)

In case you were wondering (and still reading this) as a sanity test I placed a similar call thru a different portion of my dialplan to verify if there was a general issue with Playtones--which does NOT appear to be the case--viz

exten => busy,1,Noop(Blackhole Dest: Busy)
exten => busy,n,Answer
exten => busy,n,Playtones(busy)
exten => busy,n,Busy(20)
exten => busy,n,Hangup

And the calling party hears busy media played back just fine:

    -- Executing [busy at app-blackhole:1] NoOp("SIP/GP-b77215b8", "Blackhole Dest: Busy") in new stack
    -- Executing [busy at app-blackhole:2] Answer("SIP/GP-b77215b8", "") in new stack
    -- Executing [busy at app-blackhole:3] PlayTones("SIP/GP-b77215b8", "busy") in new stack
    -- Executing [busy at app-blackhole:4] Busy("SIP/GP-b77215b8", "20") in new stack


Here's the complete SIP:

U 2010/01/22 17:21:02.809479 1.1.1.1:5060 -> 2.2.2.2:5060
INVITE sip:15305551212 at server.hcvoip.com:5060;user=phone SIP/2.0.
Via: SIP/2.0/UDP 1.1.1.1;branch=z9hG4bKd23b51d89F46664.
From: "1212" <sip:1212 at server.hcvoip.com>;tag=76CE3FD7-A56B182E.
To: <sip:15305551212 at server.hcvoip.com;user=phone>.
CSeq: 2 INVITE.
Call-ID: 57d2ee2-a48f8bf1-796c2258 at 1.1.1.1.
Contact: <sip:1212 at 1.1.1.1>.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER.
User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439.
Accept-Language: en.
Supported: 100rel,replaces.
Allow-Events: talk,hold,conference.
Authorization: Digest username="1212", realm="asterisk", nonce="41288c01", uri="sip:15305551212 at server.hcvoip.com:5060;user=phone", response="224cb7a7e0af83f2ed2124fae01fdd41", algorithm=MD5.
Max-Forwards: 70.
Content-Type: application/sdp.
Content-Length: 296.
.
v=0.
o=- 1264208504 1264208504 IN IP4 1.1.1.1.
s=Polycom IP Phone.
c=IN IP4 1.1.1.1.
t=0 0.
a=sendrecv.
m=audio 2222 RTP/AVP 9 0 8 18 101.
a=rtpmap:9 G722/8000.
a=rtpmap:0 PCMU/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:18 G729/8000.
a=fmtp:18 annexb=no.
a=rtpmap:101 telephone-event/8000.


U 2010/01/22 17:21:02.809980 2.2.2.2:5060 -> 1.1.1.1:5060
SIP/2.0 100 Trying.
Via: SIP/2.0/UDP 1.1.1.1;branch=z9hG4bKd23b51d89F46664;received=1.1.1.1.
From: "1212" <sip:1212 at server.hcvoip.com>;tag=76CE3FD7-A56B182E.
To: <sip:15305551212 at server.hcvoip.com;user=phone>.
Call-ID: 57d2ee2-a48f8bf1-796c2258 at 1.1.1.1.
CSeq: 2 INVITE.
Server: Asterisk PBX 1.6.1.8.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO.
Supported: replaces, timer.
Contact: <sip:15305551212 at 2.2.2.2>.
Content-Length: 0.
.


U 2010/01/22 17:21:02.979779 2.2.2.2:5060 -> 3.3.3.3:5060
INVITE sip:15305551212 at 3.3.3.3 SIP/2.0.
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK3b64cfee;rport.
Max-Forwards: 70.
From: "User" <sip:4155551212 at 2.2.2.2>;tag=as32f1b651.
To: <sip:15305551212 at 3.3.3.3>.
Contact: <sip:4155551212 at 2.2.2.2>.
Call-ID: 61eba3eb100f85321cd98ba13842e733 at 2.2.2.2.
CSeq: 102 INVITE.
User-Agent: Asterisk PBX 1.6.1.8.
Date: Sat, 23 Jan 2010 01:21:02 GMT.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO.
Supported: replaces, timer.
Content-Type: application/sdp.
Content-Length: 263.
.
v=0.
o=root 171124145 171124145 IN IP4 2.2.2.2.
s=Asterisk PBX 1.6.1.8.
c=IN IP4 2.2.2.2.
t=0 0.
m=audio 10460 RTP/AVP 0 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=silenceSupp:off - - - -.
a=ptime:20.
a=sendrecv.


U 2010/01/22 17:21:03.048024 3.3.3.3:5060 -> 2.2.2.2:5060
SIP/2.0 100 Trying.
From: "User" <sip:4155551212 at 2.2.2.2>;tag=as32f1b651.
To: <sip:15305551212 at 3.3.3.3>.
Call-ID: 61eba3eb100f85321cd98ba13842e733 at 2.2.2.2.
CSeq: 102 INVITE.
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK3b64cfee;rport=5060.
Contact: <sip:15305551212 at 3.3.3.3:5060;transport=udp>.
Content-Length: 0.
.


U 2010/01/22 17:21:10.633457 3.3.3.3:5060 -> 2.2.2.2:5060
SIP/2.0 180 Ringing.
From: "User" <sip:4155551212 at 2.2.2.2>;tag=as32f1b651.
To: <sip:15305551212 at 3.3.3.3>;tag=a9d5ed0-13c4-4b5a4f06-fcf2ed1-2e3f3d5.
Call-ID: 61eba3eb100f85321cd98ba13842e733 at 2.2.2.2.
CSeq: 102 INVITE.
Content-Disposition: session;handling=optional.
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK3b64cfee;rport=5060.
Contact: <sip:15305551212 at 3.3.3.3:5060;transport=udp>.
Content-Type: application/sdp.
Content-Length: 212.
.
v=0.
o=Acme_UAS 0 1 IN IP4 3.3.3.3.
s=SIP Media Capabilities.
c=IN IP4 3.3.3.3.
t=0 0.
m=audio 24392 RTP/AVP 0 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:101 telephone-event/8000.
a=maxptime:20.
a=sendrecv.


U 2010/01/22 17:21:10.633653 2.2.2.2:5060 -> 1.1.1.1:5060
SIP/2.0 180 Ringing.
Via: SIP/2.0/UDP 1.1.1.1;branch=z9hG4bKd23b51d89F46664;received=1.1.1.1.
From: "1212" <sip:1212 at server.hcvoip.com>;tag=76CE3FD7-A56B182E.
To: <sip:15305551212 at server.hcvoip.com;user=phone>;tag=as0e4f3e3d.
Call-ID: 57d2ee2-a48f8bf1-796c2258 at 1.1.1.1.
CSeq: 2 INVITE.
Server: Asterisk PBX 1.6.1.8.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO.
Supported: replaces, timer.
Contact: <sip:15305551212 at 2.2.2.2>.
Content-Length: 0.
.

U 2010/01/22 17:21:14.623749 3.3.3.3:5060 -> 2.2.2.2:5060
SIP/2.0 183 Session Progress.
From: "User" <sip:4155551212 at 2.2.2.2>;tag=as32f1b651.
To: <sip:15305551212 at 3.3.3.3>;tag=a9d5ed0-13c4-4b5a4f06-fcf2ed1-2e3f3d5.
Call-ID: 61eba3eb100f85321cd98ba13842e733 at 2.2.2.2.
CSeq: 102 INVITE.
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK3b64cfee;rport=5060.
Contact: <sip:15305551212 at 3.3.3.3:5060;transport=udp>.
Content-Length: 0.
.


U 2010/01/22 17:21:10.633744 2.2.2.2:5060 -> 1.1.1.1:5060
SIP/2.0 183 Session Progress.
Via: SIP/2.0/UDP 1.1.1.1;branch=z9hG4bKd23b51d89F46664;received=1.1.1.1.
From: "1212" <sip:1212 at server.hcvoip.com>;tag=76CE3FD7-A56B182E.
To: <sip:15305551212 at server.hcvoip.com;user=phone>;tag=as0e4f3e3d.
Call-ID: 57d2ee2-a48f8bf1-796c2258 at 1.1.1.1.
CSeq: 2 INVITE.
Server: Asterisk PBX 1.6.1.8.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO.
Supported: replaces, timer.
Contact: <sip:15305551212 at 2.2.2.2>.
Content-Type: application/sdp.
Content-Length: 289.
.
v=0.
o=root 1743362512 1743362512 IN IP4 2.2.2.2.
s=Asterisk PBX 1.6.1.8.
c=IN IP4 2.2.2.2.
t=0 0.
m=audio 19376 RTP/AVP 0 8 101.
a=rtpmap:0 PCMU/8000.
a=rtpmap:8 PCMA/8000.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=silenceSupp:off - - - -.
a=ptime:20.
a=sendrecv.


U 2010/01/22 17:21:16.747740 3.3.3.3:5060 -> 2.2.2.2:5060
SIP/2.0 486 Busy Here.
From: "User" <sip:4155551212 at 2.2.2.2>;tag=as32f1b651.
To: <sip:15305551212 at 3.3.3.3>;tag=a9d5ed0-13c4-4b5a4f06-fcf2ed1-2e3f3d5.
Call-ID: 61eba3eb100f85321cd98ba13842e733 at 2.2.2.2.
CSeq: 102 INVITE.
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK3b64cfee;rport=5060.
Content-Length: 0.
.


U 2010/01/22 17:21:16.747852 2.2.2.2:5060 -> 3.3.3.3:5060
ACK sip:15305551212 at 3.3.3.3 SIP/2.0.
Via: SIP/2.0/UDP 2.2.2.2:5060;branch=z9hG4bK3b64cfee;rport.
Max-Forwards: 70.
From: "User" <sip:4155551212 at 2.2.2.2>;tag=as32f1b651.
To: <sip:15305551212 at 3.3.3.3>;tag=a9d5ed0-13c4-4b5a4f06-fcf2ed1-2e3f3d5.
Contact: <sip:4155551212 at 2.2.2.2>.
Call-ID: 61eba3eb100f85321cd98ba13842e733 at 2.2.2.2.
CSeq: 102 ACK.
User-Agent: Asterisk PBX 1.6.1.8.
Content-Length: 0.


U 2010/01/22 17:21:16.748171 2.2.2.2:5060 -> 1.1.1.1:5060
SIP/2.0 486 Busy Here.
Via: SIP/2.0/UDP 1.1.1.1;branch=z9hG4bKd23b51d89F46664;received=1.1.1.1.
From: "1212" <sip:1212 at server.hcvoip.com>;tag=76CE3FD7-A56B182E.
To: <sip:15305551212 at server.hcvoip.com;user=phone>;tag=as0e4f3e3d.
Call-ID: 57d2ee2-a48f8bf1-796c2258 at 1.1.1.1.
CSeq: 2 INVITE.
Server: Asterisk PBX 1.6.1.8.
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO.
Supported: replaces, timer.
Content-Length: 0.
X-Asterisk-HangupCause: User busy.
X-Asterisk-HangupCauseCode: 17.
.


U 2010/01/22 17:21:16.775540 1.1.1.1:5060 -> 2.2.2.2:5060
ACK sip:15305551212 at 2.2.2.2 SIP/2.0.
Via: SIP/2.0/UDP 1.1.1.1;branch=z9hG4bKd23b51d89F46664.
From: "1212" <sip:1212 at server.hcvoip.com>;tag=76CE3FD7-A56B182E.
To: <sip:15305551212 at server.hcvoip.com;user=phone>;tag=as0e4f3e3d.
CSeq: 2 ACK.
Call-ID: 57d2ee2-a48f8bf1-796c2258 at 1.1.1.1.
Contact: <sip:1212 at 1.1.1.1>.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER.
User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439.
Accept-Language: en.
Max-Forwards: 70.
Content-Length: 0.
.


Any help or ideas would be greatly appreciated.  This is asterisk 1.6.1.8 on linux (CentOS 5.3).

TIA,

JPS

More information about the asterisk-dev mailing list