[asterisk-dev] Maximum retries exceeded on transmission issue.

Johan Wilfer johan at wilfer.se
Tue Jun 24 08:35:48 CDT 2008


I had the same issue. See: http://bugs.digium.com/view.php?id=12746
After I sent my sip supplier the sip debug above and asked them over and 
over again they finally fixed their implementation.

So I don't have these issues any more. I would have requested the bug to 
be closed, but maybe you can use it.

An option to allow Asterisk to be more forgiving to bad RFC compliance, 
like this one, seems like a very good idea to me.

/Johan

Stuart Elvish skrev:
> Hi guys,
> 
> I have a system which is disconnecting between 3 and 6 calls per day 
> with a maximum retries exceeded on transmission error.
> 
> I have turned on SIP debug and found that it retries 6 times to send a 
> 200 OK to the remote host and then terminates the call with a BYE. (See 
> below for log excerpts.) The person ringing in just keeps on ringing 
> until a timeout at the host is reached and the maximum retries are 
> exceeded once the phone call has been answered.
> 
> Seeing as it is intermittent and fairly similar to this post 
> http://www.mail-archive.com/asterisk-users@lists.digium.com/msg178034.html 
> I was wondering if I have the same issue and wanted to chang the setting 
> in chan_sip.c. Would someone be able to confirm that the line I should 
> adjust (so the call is no longer terminated if the other side of the 
> conversation doesn't respect the 200 OK) is
> 
> res = transmit_response_with_sdp(p, "200 OK", &p->initreq, XMIT_CRITICAL);
> 
> and what values in the line I should change.
> 
> Whilst I believe all the NAT settings are correct, I am also going to 
> change the network layout so the server has a direct pulic IP address on 
> one interface and an internal IP address on the second interface so we 
> can avoid any issues related to NAT.
> 
> Thanks for your assistance.
> 
> 
> The log (trimmed but I think there might be a second call in here as well):
> 
> [Jun 23 15:45:22] VERBOSE[2687] logger.c:
> <--- SIP read from xxx.x.xx.xxx:5060 --->
> INVITE sip:0xxxxxxxxx at xxx.x.xx.xxx:5060 SIP/2.0
> Via: SIP/2.0/UDP 
> xxx.x.xx.xxx:5060;branch=z9hG4bK788e32928c747f8eac98e4e3d60214a4
> Max-Forwards: 69
> From: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx>;tag=1c1359910123
> To: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx;user=phone>
> Call-ID: 1359909400236200854521
> CSeq: 1 INVITE
> Supported: em,timer,replaces,path
> Allow: 
> REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE
> User-Agent: VIC-VOGW-01/v.4.80A.012.010
> Content-Type: application/sdp
> Content-Length: 304
> Date: Mon, 23 Jun 2008 05:45:22 GMT
> Contact: <sip:0xxxxxxxxx at xxx.x.xx.xxx:5060;transport=udp>
> 
> v=0
> o=AudiocodesGW 1359890123 1359889824 IN IP4 xxx.x.xx.xxx
> s=Phone-Call
> c=IN IP4 xxx.x.xx.xxx
> t=0 0
> m=audio 14988 RTP/AVP 18 8 101
> c=IN IP4 xxx.x.xx.xxx
> a=rtpmap:18 g729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:8 pcma/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-15
> a=ptime:20
> a=sendrecv
> 
> <------------->
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: --- (14 headers 14 lines) ---
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: Sending to xxx.x.xx.xxx : 5060 
> (NAT)
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: Using INVITE request as basis 
> request - 1359909400236200854521
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: Found peer 'XxxXxxxx-2'
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: Found RTP audio format 18
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: Found RTP audio format 8
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: Found RTP audio format 101
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: Peer audio RTP is at port 
> xxx.x.xx.xxx:14988
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: Found audio description format 
> g729 for ID 18
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: Found audio description format 
> pcma for ID 8
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: Found audio description format 
> telephone-event for ID 101
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: Capabilities: us - 0x10c 
> (ulaw|alaw|g729), peer - audio=0x108 (alaw|g729)/video=0x0 (nothing), 
> combined - 0x108 (alaw|g729)
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: Non-codec capabilities (dtmf): 
> us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 
> (telephone-event)
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: Peer audio RTP is at port 
> xxx.x.xx.xxx:14988
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: Looking for 0xxxxxxxxx in 
> custom-get-did-from-sip (domain xxx.x.xx.xxx)
> [Jun 23 15:45:22] VERBOSE[2687] logger.c: list_route: hop: 
> <sip:0xxxxxxxxx at xxx.x.xx.xxx:5060;transport=udp>
> [Jun 23 15:45:22] VERBOSE[2687] logger.c:
> <--- Transmitting (NAT) to xxx.x.xx.xxx:5060 --->
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP 
> xxx.x.xx.xxx:5060;branch=z9hG4bK788e32928c747f8eac98e4e3d60214a4;received=xxx.x.xx.xxx
> From: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx>;tag=1c1359910123
> To: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx;user=phone>
> Call-ID: 1359909400236200854521
> CSeq: 1 INVITE
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:0xxxxxxxxx at xxx.x.xx.xxx>
> Content-Length: 0
> 
> [Jun 23 15:45:22] DEBUG[4737] chan_sip.c: Call to peer '201' is 2 out of 50
> [Jun 23 15:45:22] VERBOSE[4737] logger.c: Audio is at 10.0.0.120 
> <http://10.0.0.120> port 14000
> [Jun 23 15:45:22] VERBOSE[4737] logger.c: Adding codec 0x8 (alaw) to SDP
> [Jun 23 15:45:22] VERBOSE[4737] logger.c: Adding codec 0x4 (ulaw) to SDP
> [Jun 23 15:45:22] VERBOSE[4737] logger.c: Adding non-codec 0x1 
> (telephone-event) to SDP
> [Jun 23 15:45:22] VERBOSE[4737] logger.c: Reliably Transmitting (no NAT) 
> to 10.0.0.220:5060 <http://10.0.0.220:5060>:
> INVITE sip:201 at 10.0.0.220:5060 <http://sip:201@10.0.0.220:5060> SIP/2.0
> Via: SIP/2.0/UDP 10.0.0.120:5060;branch=z9hG4bK7bf65928;rport
> From: "0xxxxxxxxx" <sip:0xxxxxxxxx at 10.0.0.120 
> <mailto:sip%3A0xxxxxxxxx at 10.0.0.120>>;tag=as6886acbe
> To: <sip:201 at 10.0.0.220:5060 <http://sip:201@10.0.0.220:5060>>
> Contact: <sip:0xxxxxxxxx at 10.0.0.120 <mailto:sip%3A0xxxxxxxxx at 10.0.0.120>>
> Call-ID: 37a77d2663c1934c3a04957a59b4878e at 10.0.0.120 
> <mailto:37a77d2663c1934c3a04957a59b4878e at 10.0.0.120>
> CSeq: 102 INVITE
> User-Agent: Asterisk PBX
> Max-Forwards: 70
> Date: Mon, 23 Jun 2008 05:45:22 GMT
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Content-Type: application/sdp
> Content-Length: 258
> 
> v=0
> o=root 2596 2596 IN IP4 10.0.0.120 <http://10.0.0.120>
> s=session
> c=IN IP4 10.0.0.120 <http://10.0.0.120>
> t=0 0
> m=audio 14000 RTP/AVP 8 0 101
> a=rtpmap:8 PCMA/8000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:20
> a=sendrecv
> 
> 
> [Jun 23 15:45:42] VERBOSE[2687] logger.c:
> <--- SIP read from 10.0.0.220:5060 <http://10.0.0.220:5060> --->
> SIP/2.0 200 OK
> To: <sip:201 at 10.0.0.220:5060 
> <http://sip:201@10.0.0.220:5060>>;tag=605a42dafdadd833i0
> From: "0xxxxxxxxx" <sip:0xxxxxxxxx at 10.0.0.120 
> <mailto:sip%3A0xxxxxxxxx at 10.0.0.120>>;tag=as6886acbe
> Call-ID: 37a77d2663c1934c3a04957a59b4878e at 10.0.0.120 
> <mailto:37a77d2663c1934c3a04957a59b4878e at 10.0.0.120>
> CSeq: 103 BYE
> Via: SIP/2.0/UDP 10.0.0.120:5060;branch=z9hG4bK57799f65
> Server: Linksys/SPA942-5.2.8
> Content-Length: 0
> 
> 
> <------------->
> [Jun 23 15:45:42] VERBOSE[2687] logger.c: --- (8 headers 0 lines) ---
> [Jun 23 15:45:42] VERBOSE[2687] logger.c: Really destroying SIP dialog 
> '37a77d2663c1934c3a04957a59b4878e at 10.0.0.120 
> <mailto:37a77d2663c1934c3a04957a59b4878e at 10.0.0.120>' Method: INVITE
> [Jun 23 15:45:42] VERBOSE[2687] logger.c: Retransmitting #1 (NAT) to 
> xxx.x.xx.xxx:5060:
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 
> xxx.x.xx.xxx:5060;branch=z9hG4bK788e32928c747f8eac98e4e3d60214a4;received=xxx.x.xx.xxx
> From: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx>;tag=1c1359910123
> To: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx;user=phone>;tag=as3c4944c2
> Call-ID: 1359909400236200854521
> CSeq: 1 INVITE
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:0xxxxxxxxx at xxx.x.xx.xxx>
> Content-Type: application/sdp
> Content-Length: 285
> 
> v=0
> o=root 2596 2596 IN IP4 xxx.x.xx.xxx
> s=session
> c=IN IP4 xxx.x.xx.xxx
> t=0 0
> m=audio 12734 RTP/AVP 8 18 101
> a=rtpmap:8 PCMA/8000
> a=rtpmap:18 G729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:20
> a=sendrecv
> 
> ---
> [Jun 23 15:45:42] VERBOSE[2687] logger.c: Retransmitting #2 (NAT) to 
> xxx.x.xx.xxx:5060:
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 
> xxx.x.xx.xxx:5060;branch=z9hG4bK788e32928c747f8eac98e4e3d60214a4;received=xxx.x.xx.xxx
> From: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx>;tag=1c1359910123
> To: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx;user=phone>;tag=as3c4944c2
> Call-ID: 1359909400236200854521
> CSeq: 1 INVITE
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:0xxxxxxxxx at xxx.x.xx.xxx>
> Content-Type: application/sdp
> Content-Length: 285
> 
> v=0
> o=root 2596 2596 IN IP4 xxx.x.xx.xxx
> s=session
> c=IN IP4 xxx.x.xx.xxx
> t=0 0
> m=audio 12734 RTP/AVP 8 18 101
> a=rtpmap:8 PCMA/8000
> a=rtpmap:18 G729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:20
> a=sendrecv
> 
> ---
> [Jun 23 15:45:42] VERBOSE[2687] logger.c: Retransmitting #3 (NAT) to 
> xxx.x.xx.xxx:5060:
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 
> xxx.x.xx.xxx:5060;branch=z9hG4bK788e32928c747f8eac98e4e3d60214a4;received=xxx.x.xx.xxx
> From: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx>;tag=1c1359910123
> To: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx;user=phone>;tag=as3c4944c2
> Call-ID: 1359909400236200854521
> CSeq: 1 INVITE
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:0xxxxxxxxx at xxx.x.xx.xxx>
> Content-Type: application/sdp
> Content-Length: 285
> 
> v=0
> o=root 2596 2596 IN IP4 xxx.x.xx.xxx
> s=session
> c=IN IP4 xxx.x.xx.xxx
> t=0 0
> m=audio 12734 RTP/AVP 8 18 101
> a=rtpmap:8 PCMA/8000
> a=rtpmap:18 G729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:20
> a=sendrecv
> 
> ---
> [Jun 23 15:45:43] VERBOSE[2687] logger.c: Retransmitting #4 (NAT) to 
> xxx.x.xx.xxx:5060:
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 
> xxx.x.xx.xxx:5060;branch=z9hG4bK788e32928c747f8eac98e4e3d60214a4;received=xxx.x.xx.xxx
> From: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx>;tag=1c1359910123
> To: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx;user=phone>;tag=as3c4944c2
> Call-ID: 1359909400236200854521
> CSeq: 1 INVITE
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:0xxxxxxxxx at xxx.x.xx.xxx>
> Content-Type: application/sdp
> Content-Length: 285
> 
> v=0
> o=root 2596 2596 IN IP4 xxx.x.xx.xxx
> s=session
> c=IN IP4 xxx.x.xx.xxx
> t=0 0
> m=audio 12734 RTP/AVP 8 18 101
> a=rtpmap:8 PCMA/8000
> a=rtpmap:18 G729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:20
> a=sendrecv
> 
> ---
> [Jun 23 15:45:45] VERBOSE[2687] logger.c: Retransmitting #5 (NAT) to 
> xxx.x.xx.xxx:5060:
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 
> xxx.x.xx.xxx:5060;branch=z9hG4bK788e32928c747f8eac98e4e3d60214a4;received=xxx.x.xx.xxx
> From: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx>;tag=1c1359910123
> To: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx;user=phone>;tag=as3c4944c2
> Call-ID: 1359909400236200854521
> CSeq: 1 INVITE
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:0xxxxxxxxx at xxx.x.xx.xxx>
> Content-Type: application/sdp
> Content-Length: 285
> 
> v=0
> o=root 2596 2596 IN IP4 xxx.x.xx.xxx
> s=session
> c=IN IP4 xxx.x.xx.xxx
> t=0 0
> m=audio 12734 RTP/AVP 8 18 101
> a=rtpmap:8 PCMA/8000
> a=rtpmap:18 G729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:20
> a=sendrecv
> 
> ---
> [Jun 23 15:45:45] VERBOSE[2687] logger.c:
> <--- SIP read from 10.0.0.220:5060 <http://10.0.0.220:5060> --->
> BYE sip:0xxxxxxxxx at 10.0.0.120 <mailto:sip%3A0xxxxxxxxx at 10.0.0.120> SIP/2.0
> Via: SIP/2.0/UDP 10.0.0.220:5060;branch=z9hG4bK-6da3d2e2
> From: <sip:201 at 10.0.0.220 
> <mailto:sip%3A201 at 10.0.0.220>>;tag=7ae697d099518d81i0
> To: "0xxxxxxxxx" <sip:0xxxxxxxxx at 10.0.0.120 
> <mailto:sip%3A0xxxxxxxxx at 10.0.0.120>>;tag=as2b6c1d69
> Call-ID: 2975319b72894a2c4151361567c5b360 at 10.0.0.120 
> <mailto:2975319b72894a2c4151361567c5b360 at 10.0.0.120>
> CSeq: 105 BYE
> Max-Forwards: 70
> User-Agent: Linksys/SPA942-5.2.8
> Content-Length: 0
> 
> 
> <------------->
> [Jun 23 15:45:45] VERBOSE[2687] logger.c: --- (9 headers 0 lines) ---
> [Jun 23 15:45:45] VERBOSE[2687] logger.c: Sending to 10.0.0.220 
> <http://10.0.0.220> : 5060 (no NAT)
> [Jun 23 15:45:45] VERBOSE[2687] logger.c: Scheduling destruction of SIP 
> dialog '2975319b72894a2c4151361567c5b360 at 10.0.0.120 
> <mailto:2975319b72894a2c4151361567c5b360 at 10.0.0.120>' in 6400 ms 
> (Method: BYE)
> [Jun 23 15:45:45] VERBOSE[2687] logger.c:
> <--- Transmitting (no NAT) to 10.0.0.220:5060 <http://10.0.0.220:5060> --->
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 
> 10.0.0.220:5060;branch=z9hG4bK-6da3d2e2;received=10.0.0.220 
> <http://10.0.0.220>
> From: <sip:201 at 10.0.0.220 
> <mailto:sip%3A201 at 10.0.0.220>>;tag=7ae697d099518d81i0
> To: "0xxxxxxxxx" <sip:0xxxxxxxxx at 10.0.0.120 
> <mailto:sip%3A0xxxxxxxxx at 10.0.0.120>>;tag=as2b6c1d69
> Call-ID: 2975319b72894a2c4151361567c5b360 at 10.0.0.120 
> <mailto:2975319b72894a2c4151361567c5b360 at 10.0.0.120>
> CSeq: 105 BYE
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:0xxxxxxxxx at 10.0.0.120 <mailto:sip%3A0xxxxxxxxx at 10.0.0.120>>
> Content-Length: 0
> 
> 
> <------------>
> [Jun 23 15:45:48] VERBOSE[2687] logger.c: Retransmitting #6 (NAT) to 
> xxx.x.xx.xxx:5060:
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 
> xxx.x.xx.xxx:5060;branch=z9hG4bK788e32928c747f8eac98e4e3d60214a4;received=xxx.x.xx.xxx
> From: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx>;tag=1c1359910123
> To: <sip:0xxxxxxxxx at xxx.xxxxxxxx.xxx.xx;user=phone>;tag=as3c4944c2
> Call-ID: 1359909400236200854521
> CSeq: 1 INVITE
> User-Agent: Asterisk PBX
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
> Supported: replaces
> Contact: <sip:0xxxxxxxxx at xxx.x.xx.xxx>
> Content-Type: application/sdp
> Content-Length: 285
> 
> v=0
> o=root 2596 2596 IN IP4 xxx.x.xx.xxx
> s=session
> c=IN IP4 xxx.x.xx.xxx
> t=0 0
> m=audio 12734 RTP/AVP 8 18 101
> a=rtpmap:8 PCMA/8000
> a=rtpmap:18 G729/8000
> a=fmtp:18 annexb=no
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:20
> a=sendrecv
> 
> 
> [Jun 23 15:45:51] VERBOSE[2687] logger.c: SIP Response message for 
> INCOMING dialog BYE arrived
> [Jun 23 15:45:51] VERBOSE[2687] logger.c: Really destroying SIP dialog 
> '2975319b72894a2c4151361567c5b360 at 10.0.0.120 
> <mailto:2975319b72894a2c4151361567c5b360 at 10.0.0.120>' Method: BYE
> [Jun 23 15:45:52] WARNING[2687] chan_sip.c: Maximum retries exceeded on 
> transmission 1359909400236200854521 for seqno 1 (Critical Response)
> [Jun 23 15:45:52] VERBOSE[2687] logger.c: Really destroying SIP dialog 
> '1359909400236200854521' Method: BYE
> 
> 
> ------------------------------------------------------------------------
> 
> _______________________________________________
> --Bandwidth and Colocation Provided by http://www.api-digital.com--
> 
> AstriCon 2008 - September 22 - 25 Phoenix, Arizona
> Register Now: http://www.astricon.net
> 
> asterisk-dev mailing list
> To UNSUBSCRIBE or update options visit:
>    http://lists.digium.com/mailman/listinfo/asterisk-dev





More information about the asterisk-dev mailing list