Asterisk 1.8.9 - Re-invites issue

Asterisk Asterisk Support
1

Hello,
I hope someone can help shed some light on this problem I’ve been experiencing. The issue is with one our international carriers we terminate traffic to. From their assessment, we are sending a re-invite request after acknowlegding their 200 ok request. We are sending a re-invite message for the same call with a different cseq number on which we are not changing any media or other invitation. When this happens, the call drops immediately when the remote end answers the phone (our carrier sends a 488 to drop the call).

I’ve reverted back to 1.4.43 because 1.6.x & 10.0 also exhibits the same behavior. In 1.4.43, we set canreinvite=no and the calls connect with no issues at all. From what I read in the changelog for 1.8.9, it states:

“…directmedia/canreinvite do not cause Asterisk to ignore reINVITEs. It is only used to stop Asterisk from generating a reINVITE, but does not stop it from accepting them if necessary…”

I’m baffled at what is causing our Asterisk box to send a re-invite to our carrier. I’ve tried different combinations of directmedia=/directrtpsetup/nat=/ but I’m unable to stop or find the reason that’s causing our Asterisk box to send re-invites. My debug log below is done with using G729a as passthrough because our carrier accepts G729a. See the bottom for the SIP history in the debug.

Here’s how our topology flows for those who want to know:
SIP signaling: ATA --> Proxy --> Asterisk --> Gateway --> Carrier

=====================================================================================
SIP.CONF

[general]
useragent = stggw01
udpbindaddr = MYASTERISK
allowguest = yes
ignoresdpversion = yes
match_auth_username = yes
realm = iworldaccounts.com
srvlookup = no
language = en
relaxdtmf = yes
trustrpid = yes
sendrpid = no
prematuremedia = no
progressinband = yes
sdpsession = iWorld
usereqphone = yes
dtmfmode = rfc2833
videosupport = yes
forwardloopdetected = no
session-timers = refuse
session-expires = 600
session-minse = 90
session-refresher = uas
allowsubscribe = no
directmedia = nonat
nat = no ; added
directrtpsetup = no ; added
allowexternaldomains = yes
jbenable = yes
autocreatepeer = yes
allowoverlap = no
allowtransfer = no
pedantic = no
usereqphone = yes
rtupdate = no
tos_sip=cs3 ; Sets TOS for SIP packets.
tos_audio=ef ; Sets TOS for RTP audio packets.
disallow = all
allow = g729
allow = g723.1
allow = ulaw
allow = ilbc
allow = gsm
allow = alaw
rtptimeout=60
rtpholdtimeout=300
autoframing=yes

[GW1G729]
host = MYGATEWAY
type = friend
disallow = all
allow = g729
directmedia=nonat

2

---------- SIP HISTORY for ‘6091d6c860dcc10f14c86f165af0ab2d@MYASTERISK:5060’
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: * SIP Call
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 001. NewChan Channel SIP/GW1G729-00000027 - from 6091d6c860dcc10f14c86f165af
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 002. TxReqRel INVITE / 102 INVITE - INVITE
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 003. ReTx 1000 INVITE sip:CARRIER011919838878657@MYGATEWAY SIP/2.0
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 004. Rx SIP/2.0 / 102 INVITE / 183 Session Progress
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 005. Rx SIP/2.0 / 102 INVITE / 180 Ringing
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 006. Rx SIP/2.0 / 102 INVITE / 200 OK
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 007. TxReq ACK / 102 ACK - ACK
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 008. ReInv Re-invite sent
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 009. TxReqRel INVITE / 103 INVITE - INVITE
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 010. ReTx 1000 INVITE sip:011919838878657@CARRIER:5060 SIP/2.0
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 011. Rx SIP/2.0 / 103 INVITE / 200 OK
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 012. TxReq ACK / 103 ACK - ACK
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 013. ReInv Re-invite sent
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 014. TxReqRel INVITE / 104 INVITE - INVITE
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 015. ReTx 1000 INVITE sip:011919838878657@CARRIER:5060 SIP/2.0
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 016. Rx SIP/2.0 / 104 INVITE / 200 OK
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 017. TxReq ACK / 104 ACK - ACK
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 018. ReInv Re-invite sent
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 019. TxReqRel INVITE / 105 INVITE - INVITE
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 020. Hangup Cause Normal Clearing
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 021. SchedDestroy 32000 ms
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 022. CancelDestroy
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 023. ReTx 1000 INVITE sip:011919838878657@CARRIER:5060 SIP/2.0
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 024. Rx SIP/2.0 / 105 INVITE / 200 OK
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 025. TxReq ACK / 105 ACK - ACK
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 026. TxReqRel BYE / 106 BYE - BYE
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 027. SchedDestroy 32000 ms
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 028. Rx SIP/2.0 / 106 BYE / 200 OK
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c: 029. NeedDestroy Setting needdestroy because received 200 response
[2012-02-03 13:53:38] DEBUG[2917] chan_sip.c:
---------- END SIP HISTORY for ‘6091d6c860dcc10f14c86f165af0ab2d@MYASTERISK:5060’
[2012-02-03 13:53:38] DEBUG[2917] rtp_engine.c: Destroyed RTP instance ‘0x7f718c005f28’
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: Auto destroying SIP dialog 'b8152216-4de43ed1@192.168.8.x’
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: Destroying SIP dialog b8152216-4de43ed1@192.168.8.x
[2012-02-03 13:54:09] VERBOSE[2917] chan_sip.c: Really destroying SIP dialog 'b8152216-4de43ed1@192.168.8.x’ Method: BYE
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: Destroying SIP peer SIPACCOUNT
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: -REALTIME- peer Destroyed. Name: SIPACCOUNT. Realtime Peer objects: 0
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c:
---------- SIP HISTORY for 'b8152216-4de43ed1@192.168.8.x’
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: * SIP Call
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 001. Rx INVITE / 102 INVITE / sip:919838878657@MYPROXY
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 002. NewChan Channel SIP/SIPACCOUNT-00000026 - from b8152216-4de43ed1@192.
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 003. TxResp SIP/2.0 / 102 INVITE - 100 Trying
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 004. Rx INVITE / 102 INVITE / sip:919838878657@MYPROXY
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 005. TxResp SIP/2.0 / 102 INVITE - 100 Trying
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 006. TxResp SIP/2.0 / 102 INVITE - 183 Session Progress
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 007. TxRespRel SIP/2.0 / 102 INVITE - 200 OK
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 008. Rx ACK / 102 ACK / sip:919838878657@MYASTERISK:5060
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 009. ReInv Re-invite sent
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 010. TxReqRel INVITE / 102 INVITE - INVITE
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 011. Rx SIP/2.0 / 102 INVITE / 100 Giving a try
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 012. Rx SIP/2.0 / 102 INVITE / 200 OK
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 013. TxReq ACK / 102 ACK - ACK
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 014. Rx BYE / 103 BYE / sip:919838878657@MYASTERISK:5060
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 015. RTCPaudio Quality:ssrc=688776254;themssrc=4029104110;lp=0;rxjitter=0.0056
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 016. RTCPaudioJitter Quality:minrxjitter=0.000000;maxrxjitter=0.000000;avgrxjitter=0
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 017. RTCPaudioLoss Quality:minrxlost=0.000000;maxrxlost=0.000000;avgrxlost=0.00000
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 018. RTCPaudioRTT Quality:minrtt=0.000000;maxrtt=0.000000;avgrtt=0.000000;stdevrt
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 019. SchedDestroy 32000 ms
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 020. TxResp SIP/2.0 / 103 BYE - 200 OK
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 021. Hangup Cause Normal Clearing
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c: 022. AutoDestroy b8152216-4de43ed1@192.168.8.x
[2012-02-03 13:54:09] DEBUG[2917] chan_sip.c:
---------- END SIP HISTORY for 'b8152216-4de43ed1@192.168.8.x’
[2012-02-03 13:54:09] DEBUG[2917] rtp_engine.c: Destroyed RTP instance ‘0x7f71d80060e8’

3

.

4

If you had said this only affected 1.8 and 1.10, I would have said it was updating the connected line information. I believe this can be frustrated by disabling the use of RPID, although the service provide is broken if they drop the call on a reinvite. If they don’t like it they should reject it and continue the call.

5

Hello David,
I’m still having the same issue, the call will drop on a re-invite. Do you have any further suggestions? I’ve tried your suggestion with different combinations of the following settings:

trustrpid = yes/no
sendrpid = yes/rpid/pai/no
rpid_update = no/yes

How do I configure the inbound and outbound leg to be bridged within my asterisk and not an attempt to divert/update the original call mid-transaction/process on our carriers’ servers?

I’ve included the debug messages for the Re-invite and the SIP history at the end of the call.

[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c: Done building SDP. Settling with this capability: 0x100 (g729)
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c: Initializing already initialized SIP dialog 4a6673cf1c6f4af117a4f8e6586456cf@MYASTERISK:5060 (presumably reinvite)
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header  0 [ 55]: INVITE sip:94771542226@CARRIER:5060 SIP/2.0
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header  1 [ 57]: Via: SIP/2.0/UDP MYASTERISK:5060;branch=z9hG4bK436eb151
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header  2 [ 83]: Route: <sip:94771542226@MYGATEWAY;lr=on;ftag=as25fa33e2;did=56d.4bb499c1>
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header  3 [ 16]: Max-Forwards: 70
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header  4 [ 65]: From: "SIPACCOUNT" <sip:SIPACCOUNT@MYASTERISK>;tag=as25fa33e2
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header  5 [ 74]: To: <sip:94771542226@MYGATEWAY;user=phone>;tag=3537720169-765117
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header  6 [ 44]: Contact: <sip:SIPACCOUNT@MYASTERISK:5060>
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header  7 [ 59]: Call-ID: 4a6673cf1c6f4af117a4f8e6586456cf@MYASTERISK:5060
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header  8 [ 16]: CSeq: 103 INVITE
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header  9 [ 19]: User-Agent: MYASTERISK
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header 10 [ 37]: Access-URL: <94771542226>;mode=active
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header 11 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header 12 [ 19]: Supported: replaces
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header 13 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge)
[2012-02-08 12:02:51] DEBUG[4855] chan_sip.c:  Header 14 [ 29]: Content-Type: application/sdp



---------- SIP HISTORY for '4a6673cf1c6f4af117a4f8e6586456cf@MYASTERISK:5060'
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   * SIP Call
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   001. NewChan         Channel SIP/DIAL-00000049 - from 4a6673cf1c6f4af117a4f8e6586
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   002. TxReqRel        INVITE / 102 INVITE - INVITE
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   003. ReTx            1000 INVITE sip:94771542226@MYGATEWAY;user=phone SIP/
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   004. ReTx            2000 INVITE sip:94771542226@MYGATEWAY;user=phone SIP/
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   005. ReTx            4000 INVITE sip:94771542226@MYGATEWAY;user=phone SIP/
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   006. ReTx            8000 INVITE sip:94771542226@MYGATEWAY;user=phone SIP/
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   007. Rx              SIP/2.0 / 102 INVITE / 183 Session Progress
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   008. Rx              SIP/2.0 / 102 INVITE / 200 OK
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   009. TxReq           ACK / 102 ACK - ACK
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   010. ReInv           Re-invite sent
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   011. TxReqRel        INVITE / 103 INVITE - INVITE
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   012. Rx              SIP/2.0 / 103 INVITE / 488 Not Acceptable Here
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   013. TxReq           ACK / 103 ACK - ACK
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   014. NeedDestroy     Setting needdestroy because received 488 response
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   015. Hangup          Cause Bearer capability not available
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   016. SchedDestroy    32000 ms
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   017. RTCPaudio       Quality:ssrc=1033111065;themssrc=818934718;lp=0;rxjitter=0.0037
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   018. TxReqRel        BYE / 104 BYE - BYE
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   019. Rx              SIP/2.0 / 104 BYE / 200 OK
[2012-02-08 12:02:52] DEBUG[4584] chan_sip.c:   020. NeedDestroy     Setting needdestroy because received 200 response
6 
[2012-02-08 12:43:56] VERBOSE[4584] chan_sip.c: --- (16 headers 13 lines) ---
[2012-02-08 12:43:56] DEBUG[4584] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE
[2012-02-08 12:43:56] DEBUG[4584] chan_sip.c: Ignoring SIP message because of retransmit (INVITE Seqno 102, ours 102)
[2012-02-08 12:43:56] VERBOSE[4584] chan_sip.c: Ignoring this INVITE request
[2012-02-08 12:43:56] DEBUG[4584] chan_sip.c: Got a SIP re-transmit of INVITE for call 3cebae56-610b9cbb@192.168.4.123
[2012-02-08 12:43:56] VERBOSE[4584] chan_sip.c:
7

directmedia should be no, not nonat. nonat only applies when Asterisk is on a public network and the peer is not. You almost certainly have the reverse case.

8

Hello David,
I tried with directmedia=no/nonat/yes and the results are the same. Again, when we downgrade back to 1.4.43 using canreinvite=no, the problem doesn’t exist. But since directmedia= was introduced, we started seeing this problem. Any other suggestions.?

9

directmedia is just a renaming of canreinvite, as there are other reasons for reinvites, so the original name was misleading.

I note that it says “X-asterisk-Info: SIP re-invite (External RTP bridge)” which means it is due to the use of directmedia.

The channel name doesn’t look right. I would expect SIP/GW1G729-…, although maybe this is a 1.8 thing. Previous versions would have used the target address when not using sip.conf, and the sip.conf section name, when using it. Are you doing that? (putting the target address in sip.conf, rather than referencing the sip.conf section name? That would cause you to get the default directmedia setting.

Generally including the dialplan CLI output from, at least, verbose level 3, makes it much easier to see what is going on.