<HTML><HEAD></HEAD>
<BODY dir=ltr>
<DIV dir=ltr>
<DIV style="FONT-FAMILY: 'Calibri'; COLOR: #000000; FONT-SIZE: 12pt">
<DIV>Hello!</DIV>
<DIV> </DIV>
<DIV>We recently upgraded one of our customers from 1.4.44 to 1.8.15-cert1. We
have several other customers running both versions.</DIV>
<DIV>The customer in question does not use us as their provider as they’re
located in a different country.</DIV>
<DIV> </DIV>
<DIV>When they make outgoing calls, there is a 3 second delay between answering
the call and the call being established. When debugging this, I found that
Asterisk waits 3 seconds after receiving 200 OK before returning the ACK. See
attached image. There’s no verbose output in the CLI during this time. I turned
on full debugging. This seems to produce around a hundred lines of debug per
second until suddenly I see a full 3 seconds stop just before sending the
ACK.</DIV>
<DIV> </DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Header 0 [ 14]:
SIP/2.0 200 Ok</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Header 1 [ 57]: Via:
SIP/2.0/UDP xxx.xxx.xxx.xxx:xxxx;branch=z9hG4bK135effb0</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Header 2 [ 66]:
From: "a" <sip:a@xxx.xxx.xxx.xxx:xxxx>;tag=as6b9fcf86</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Header 3 [ 61]: To:
<sip:b@FQDNy:5060>;tag=1014243474</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Header 4 [ 59]:
Call-ID: 03dffd7b5ecd7eb47c2bae6b101ba1aa@62.109.37.34:5088</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Header 5 [ 16]:
CSeq: 102 INVITE</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Header 6 [ 51]:
Contact: <sip:b@FQDNz:5060></DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Header 7 [117]:
Record-Route:
<sip:yyy.yyy.yyy.yyy;lr=on;ftag=as6b9fcf86;d=b49.b0ae2a82;vsf=AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA6NTA4OA--></DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Header 8 [ 69]:
Allow: INVITE,ACK,PRACK,SUBSCRIBE,BYE,CANCEL,NOTIFY,INFO,REFER,UPDATE</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Header 9 [ 24]:
Supported: timer, 100rel</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Header 10 [ 29]:
Content-Type: application/sdp</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Header 11 [ 19]:
Content-Length: 352</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Header 12 [
0]:</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 0
[ 3]: v=0</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 1 [
35]: o=- 25469059 0 IN IP4 ccc.ccc.ccc.ccc</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 2 [
13]: s=Cisco SDP 0</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 3 [
22]: c=IN IP4 ccc.ccc.ccc.ccc</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 4
[ 5]: t=0 0</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 5 [
31]: m=audio 21252 RTP/AVP 8 101 100</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 6 [
33]: a=rtpmap:101 telephone-event/8000</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 7 [
15]: a=fmtp:101 0-15</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 8 [
23]: a=rtpmap:100 X-NSE/8000</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 9 [
18]: a=fmtp:100 200-202</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 10
[ 9]: a=X-sqn:0</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 11 [ 28]:
a=X-cap: 1 audio RTP/AVP 100</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 12 [ 33]:
a=X-cpar: a=rtpmap:100 X-NSE/8000</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 13 [ 28]:
a=X-cpar: a=fmtp:100 200-202</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Body 14 [ 26]:
a=X-cap: 2 image udptl t38</DIV>
<DIV>[Mar 15 13:16:05] VERBOSE[27947] chan_sip.c: [Mar 15 13:16:05] --- (12
headers 15 lines) ---</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: = Looking for Call ID: <A
href="mailto:03dffd7b5ecd7eb47c2bae6b101ba1aa@xxx.xxx.xxx.xxx:xxxx">03dffd7b5ecd7eb47c2bae6b101ba1aa@xxx.xxx.xxx.xxx:xxxx</A>
(Checking To) --From tag as6b9fcf86 --To-tag 1014243474</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Acked pending invite 102</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Stopping retransmission on <A
href="mailto:'03dffd7b5ecd7eb47c2bae6b101ba1aa@xxx.xxx.xxx.xxx:xxxx'">'03dffd7b5ecd7eb47c2bae6b101ba1aa@xxx.xxx.xxx.xxx:xxxx'</A>
of Request 102: Match Found</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: SIP response 200 to standard
invite</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: SIP response 200 to standard
invite</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Processing session-level SDP
v=0... UNSUPPORTED OR FAILED.</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Call <A
href="mailto:03dffd7b5ecd7eb47c2bae6b101ba1aa@xxx.xxx.xxx.xxx:xxxx">03dffd7b5ecd7eb47c2bae6b101ba1aa@xxx.xxx.xxx.xxx:xxxx</A>
responded to our reinvite without changing SDP version; ignoring SDP.</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: Updating call counter for
outgoing call</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] chan_sip.c: build_route: Record-Route hop:
<sip:yyy.yyy.yyy.yyy;lr=on;ftag=as6b9fcf86;d=b49.b0ae2a82;vsf=AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA6NTA4OA--></DIV>
<DIV>[Mar 15 13:16:05] VERBOSE[27947] chan_sip.c: [Mar 15 13:16:05] list_route:
hop:
<sip:yyy.yyy.yyy.yyy;lr=on;ftag=as6b9fcf86;d=b49.b0ae2a82;vsf=AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA6NTA4OA--></DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] netsock2.c: Splitting 'FQDNz:5060'
into...</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27947] netsock2.c: ...host 'FQDNz' and port
'5060'.</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27931] devicestate.c: No provider found, checking
channel drivers for SIP – FQDNy</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27931] chan_sip.c: Checking device state for peer
FQDNy</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27931] devicestate.c: Changing state for SIP/FQDNy
- state 2 (In use)</DIV>
<DIV>[Mar 15 13:16:05] DEBUG[27931] devicestate.c: device 'SIP/FQDNy' state
'2'</DIV>
<DIV><FONT color=#ff0000>[Mar 15 13:16:05] DEBUG[27967] app_queue.c: Device
'SIP/FQDNy' changed to state '2' (In use) but we don't care because they're not
a member of any queue.</FONT></DIV>
<DIV><FONT color=#ff0000>[Mar 15 13:16:08] DEBUG[27947] netsock2.c: Splitting
'yyy.yyy.yyy.yyy' into...</FONT></DIV>
<DIV>[Mar 15 13:16:08] DEBUG[27947] netsock2.c: ...host 'yyy.yyy.yyy.yyy' and
port ''.</DIV>
<DIV>[Mar 15 13:16:08] VERBOSE[27947] chan_sip.c: [Mar 15 13:16:08] Transmitting
(no NAT) to yyy.yyy.yyy.yyy:5060:</DIV>
<DIV>ACK sip:004741888800@FQDNz:5060 SIP/2.0</DIV>
<DIV> </DIV>
<DIV> </DIV>
<DIV>Could it be a parsing issue because the Record-Route header doesn’t include
a port?</DIV>
<DIV> </DIV>
<DIV>With kind regards,</DIV>
<DIV>Pan</DIV>
<DIV> </DIV></DIV></DIV></BODY></HTML>