From miconda@gmail.com Fri Oct 29 10:59:38 2010
From: Daniel-Constantin Mierla <miconda@gmail.com>
To: sr-users@lists.kamailio.org
Subject: Re: [SR-Users] Problem with Kamailio not routing ACK to a 200 OK
Date: Fri, 29 Oct 2010 10:59:34 +0200
Message-ID: <4CCA8CF6.3030906@gmail.com>
In-Reply-To: <AANLkTi=SMZWUXKtgf2z8Dh5p=5vr8PP89R-a2Ja5O_H=@mail.gmail.com>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="===============1481894617=="

--===============1481894617==
Content-Type: text/plain; charset="utf-8"
Content-Transfer-Encoding: quoted-printable

Hello,

On 10/28/10 1:37 PM, Morten Isaksen wrote:
> Hi,
>
> I have a strange problem with Kamailio 3.0.2. When one of our end
> users makes a call Kamailio does not route the ACK (in response to the
> 200 OK). For all other end users it works fine.
>
> For me it looks the the has_totag() checks for some reason fails and
> then t_check_trans() thinks it is a ACK to a local transactions and
> then terminates the script. Otherwise there should be more lines in
> the log file.

if you add an xlog() after the if with has_totag(), do you get the=20
message in the logs?

Cheers,
Daniel

> The conf is pretty standard.
>
> route{
>
>          xlog("L_WARN", "New request - M=3D$rm RURI=3D$ru F=3D$fu T=3D$tu
> IP=3D$si ID=3D$ci\n");
>          xlog("L_WARN", "ua=3D$ua");
>          if (!mf_process_maxfwd_header("10")) {
>                  sl_send_reply("483","Too Many Hops");
>                  exit;
>          }
>
>          if(!sanity_check("1511", "7"))
>          {
>                  xlog("Malformed SIP message from $si:$sp\n");
>                  exit;
>          }
>
>
>          if (has_totag()) {
>                  xlog("L_WARN", "has_totag start - M=3D$rm RURI=3D$ru F=3D$=
fu
> T=3D$tu IP=3D$si ID=3D$ci\n");
>                  # sequential request withing a dialog should
>                  # take the path determined by record-routing
>                  if (loose_route()) {
>                          xlog("L_WARN", "loose_route - M=3D$rm RURI=3D$ru
> F=3D$fu T=3D$tu IP=3D$si ID=3D$ci\n");
>                          route(RELAY);
>                  } else {
>                          if (is_method("SUBSCRIBE")&&  uri =3D=3D myself) {
>                                  # in-dialog subscribe requests
>                                  #route(PRESENCE);
>                                  exit;
>                          }
>                          if ( is_method("ACK") ) {
>                                  if ( t_check_trans() ) {
>                                          xlog("L_WARN", "ACK
> t_check_trans - M=3D$rm RURI=3D$ru F=3D$fu T=3D$tu IP=3D$si ID=3D$ci\n");
>                                          # non loose-route, but
> stateful ACK; must be an ACK after a 487 or e.g. 404 from upstream
> server
>                                          t_relay();
>                                          exit;
>                                  } else {
>                                          xlog("Ignoring ACK - M=3D$rm
> RURI=3D$ru F=3D$fu T=3D$tu IP=3D$si ID=3D$ci\n");
>                                          # ACK without matching
> transaction ... ignore and discard.\n");
>                                          exit;
>                                  }
>                          }
>                          sl_send_reply("404","Not here");
>                  }
>                  xlog("L_WARN", "has_totag end - M=3D$rm RURI=3D$ru F=3D$fu
> T=3D$tu IP=3D$si ID=3D$ci\n");
>                  exit;
>          }
>
>          #initial requests
>
>          # CANCEL processing
>          if (is_method("CANCEL"))
>          {
>                  if (t_check_trans())
>                          t_relay();
>                  exit;
>          }
>
>          setflag(4);
>          t_check_trans();
>
> ...
>
> The log files show:
>
> Oct 28 10:51:13 sip-core-1 /usr/local/sbin/kamailio[10503]: WARNING:
> <script>: New request - M=3DACK RURI=3Dsip:1105(a)178.21.248.56:5060
> F=3Dsip:87776688(a)sip.uni-tel.dk T=3Dsip:869
> 87106(a)sip.uni-tel.dk IP=3D178.21.248.20 ID=3DAI231CA9BD0A4A1C53(a)10.0.0.=
150
> Oct 28 10:51:13 sip-core-1 /usr/local/sbin/kamailio[10503]: WARNING:
> <script>: ua=3DAastra Intelligate
>
>
>
>
> The trace
>
> U 2010/10/28 10:51:02.616337 178.21.248.7:5060 ->  178.21.248.56:5060
> INVITE sip:86987106(a)178.21.248.56 SIP/2.0.
> Record-Route:<sip:178.21.248.7;lr;ftag=3DAI8DA85D59B9B6634F;did=3Df48.5fd1d=
b02>.
> Record-Route:<sip:178.21.248.20;lr;ftag=3DAI8DA85D59B9B6634F>.
> Via: SIP/2.0/UDP 178.21.248.7;branch=3Dz9hG4bK690c.9cfea506.0.
> Via: SIP/2.0/UDP 178.21.248.20;branch=3Dz9hG4bK690c.97354e4.0.
> Via: SIP/2.0/UDP
> 87.104.233.108:5060;rport=3D5060;branch=3Dz9hG4bK3c70fae55c8b362ff34e6c782c=
c21592.
> To:<sip:86987106(a)sip.uni-tel.dk>.
> From:<sip:87776688(a)sip.uni-tel.dk>;tag=3DAI8DA85D59B9B6634F.
> Call-ID: AI231CA9BD0A4A1C53(a)10.0.0.150.
> CSeq: 2 INVITE.
> Max-Forwards: 68.
> Contact:<sip:87776688(a)87.104.233.108:5060;line=3DAI7EFC34995E724DD7>.
> Accept: application/sdp.
> Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER.
> P-Preferred-Identity:<sip:87776688(a)sip.uni-tel.dk>.
> Privacy: none.
> User-Agent: Aastra Intelligate.
> Content-Type: application/sdp.
> Content-Length: 280.
> X-trunktype: IC.
> .
> v=3D0.
> o=3Dintelligate 1194032777 1194032777 IN IP4 87.104.233.106.
> s=3Dcall.
> c=3DIN IP4 178.21.248.22.
> t=3D0 0.
> m=3Daudio 60984 RTP/AVP 8 0 18 101.
> a=3Drtpmap:8 PCMA/8000.
> a=3Drtpmap:0 PCMU/8000.
> a=3Drtpmap:18 G729/8000.
> a=3Drtpmap:101 telephone-event/8000.
> a=3Dfmtp:101 0-15.
> a=3Dsendrecv.
> a=3Dptime:20.
>
> #
> U 2010/10/28 10:51:02.636854 178.21.248.56:5060 ->  178.21.248.7:5060
> SIP/2.0 100 Trying.
> Via: SIP/2.0/UDP 178.21.248.7;branch=3Dz9hG4bK690c.9cfea506.0.
> Via: SIP/2.0/UDP 178.21.248.20;branch=3Dz9hG4bK690c.97354e4.0.
> Via: SIP/2.0/UDP
> 87.104.233.108:5060;rport=3D5060;branch=3Dz9hG4bK3c70fae55c8b362ff34e6c782c=
c21592.
> From:<sip:87776688(a)sip.uni-tel.dk>;tag=3DAI8DA85D59B9B6634F.
> To:<sip:86987106(a)sip.uni-tel.dk>;tag=3D1c2073920452.
> Call-ID: AI231CA9BD0A4A1C53(a)10.0.0.150.
> CSeq: 2 INVITE.
> Supported: em,timer,replaces,path,early-session,resource-priority.
> Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSC=
RIBE,UPDATE.
> Server: Audiocodes-Sip-Gateway-Mediant 2000/v.5.60A.035.002.
> Content-Length: 0.
> .
>
> #####
> U 2010/10/28 10:51:04.134445 178.21.248.56:5060 ->  178.21.248.7:5060
> SIP/2.0 183 Session Progress.
> Via: SIP/2.0/UDP 178.21.248.7;branch=3Dz9hG4bK690c.9cfea506.0.
> Via: SIP/2.0/UDP 178.21.248.20;branch=3Dz9hG4bK690c.97354e4.0.
> Via: SIP/2.0/UDP
> 87.104.233.108:5060;rport=3D5060;branch=3Dz9hG4bK3c70fae55c8b362ff34e6c782c=
c21592.
> From:<sip:87776688(a)sip.uni-tel.dk>;tag=3DAI8DA85D59B9B6634F.
> To:<sip:86987106(a)sip.uni-tel.dk>;tag=3D1c2073920452.
> Call-ID: AI231CA9BD0A4A1C53(a)10.0.0.150.
> CSeq: 2 INVITE.
> Contact:<sip:1105(a)178.21.248.56:5060>.
> Record-Route:<sip:178.21.248.7;lr;ftag=3DAI8DA85D59B9B6634F;did=3Df48.5fd1d=
b02>,<sip:178.21.248.20;lr;ftag=3DAI8DA85D59B9B6634F>.
> Supported: em,timer,replaces,path,early-session,resource-priority.
> Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSC=
RIBE,UPDATE.
> Server: Audiocodes-Sip-Gateway-Mediant 2000/v.5.60A.035.002.
> Content-Type: application/sdp.
> Content-Length: 259.
> .
> v=3D0.
> o=3DAudiocodesGW 2073965634 2073965290 IN IP4 178.21.248.56.
> s=3DPhone-Call.
> c=3DIN IP4 178.21.248.56.
> t=3D0 0.
> m=3Daudio 6050 RTP/AVP 8 101.
> c=3DIN IP4 178.21.248.56.
> a=3Drtpmap:8 PCMA/8000.
> a=3Drtpmap:101 telephone-event/8000.
> a=3Dfmtp:101 0-15.
> a=3Dptime:20.
> a=3Dsendrecv.
>
> #
> U 2010/10/28 10:51:04.134748 178.21.248.7:5060 ->  178.21.248.20:5060
> SIP/2.0 183 Session Progress.
> Via: SIP/2.0/UDP 178.21.248.20;branch=3Dz9hG4bK690c.97354e4.0.
> Via: SIP/2.0/UDP
> 87.104.233.108:5060;rport=3D5060;branch=3Dz9hG4bK3c70fae55c8b362ff34e6c782c=
c21592.
> From:<sip:87776688(a)sip.uni-tel.dk>;tag=3DAI8DA85D59B9B6634F.
> To:<sip:86987106(a)sip.uni-tel.dk>;tag=3D1c2073920452.
> Call-ID: AI231CA9BD0A4A1C53(a)10.0.0.150.
> CSeq: 2 INVITE.
> Contact:<sip:1105(a)178.21.248.56:5060>.
> Record-Route:<sip:178.21.248.7;lr;ftag=3DAI8DA85D59B9B6634F;did=3Df48.5fd1d=
b02>,<sip:178.21.248.20;lr;ftag=3DAI8DA85D59B9B6634F>.
> Supported: em,timer,replaces,path,early-session,resource-priority.
> Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSC=
RIBE,UPDATE.
> Server: Audiocodes-Sip-Gateway-Mediant 2000/v.5.60A.035.002.
> Content-Type: application/sdp.
> Content-Length: 259.
> .
> v=3D0.
> o=3DAudiocodesGW 2073965634 2073965290 IN IP4 178.21.248.56.
> s=3DPhone-Call.
> c=3DIN IP4 178.21.248.56.
> t=3D0 0.
> m=3Daudio 6050 RTP/AVP 8 101.
> c=3DIN IP4 178.21.248.56.
> a=3Drtpmap:8 PCMA/8000.
> a=3Drtpmap:101 telephone-event/8000.
> a=3Dfmtp:101 0-15.
> a=3Dptime:20.
> a=3Dsendrecv.
>
> #
> U 2010/10/28 10:51:04.136586 178.21.248.56:5060 ->  178.21.248.7:5060
> SIP/2.0 180 Ringing.
> Via: SIP/2.0/UDP 178.21.248.7;branch=3Dz9hG4bK690c.9cfea506.0.
> Via: SIP/2.0/UDP 178.21.248.20;branch=3Dz9hG4bK690c.97354e4.0.
> Via: SIP/2.0/UDP
> 87.104.233.108:5060;rport=3D5060;branch=3Dz9hG4bK3c70fae55c8b362ff34e6c782c=
c21592.
> From:<sip:87776688(a)sip.uni-tel.dk>;tag=3DAI8DA85D59B9B6634F.
> To:<sip:86987106(a)sip.uni-tel.dk>;tag=3D1c2073920452.
> Call-ID: AI231CA9BD0A4A1C53(a)10.0.0.150.
> CSeq: 2 INVITE.
> Contact:<sip:1105(a)178.21.248.56:5060>.
> Record-Route:<sip:178.21.248.7;lr;ftag=3DAI8DA85D59B9B6634F;did=3Df48.5fd1d=
b02>,<sip:178.21.248.20;lr;ftag=3DAI8DA85D59B9B6634F>.
> Supported: em,timer,replaces,path,early-session,resource-priority.
> Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSC=
RIBE,UPDATE.
> Server: Audiocodes-Sip-Gateway-Mediant 2000/v.5.60A.035.002.
> Content-Type: application/sdp.
> Content-Length: 259.
> .
> v=3D0.
> o=3DAudiocodesGW 2073965634 2073965290 IN IP4 178.21.248.56.
> s=3DPhone-Call.
> c=3DIN IP4 178.21.248.56.
> t=3D0 0.
> m=3Daudio 6050 RTP/AVP 8 101.
> c=3DIN IP4 178.21.248.56.
> a=3Drtpmap:8 PCMA/8000.
> a=3Drtpmap:101 telephone-event/8000.
> a=3Dfmtp:101 0-15.
> a=3Dptime:20.
> a=3Dsendrecv.
>
> #
> U 2010/10/28 10:51:04.136837 178.21.248.7:5060 ->  178.21.248.20:5060
> SIP/2.0 180 Ringing.
> Via: SIP/2.0/UDP 178.21.248.20;branch=3Dz9hG4bK690c.97354e4.0.
> Via: SIP/2.0/UDP
> 87.104.233.108:5060;rport=3D5060;branch=3Dz9hG4bK3c70fae55c8b362ff34e6c782c=
c21592.
> From:<sip:87776688(a)sip.uni-tel.dk>;tag=3DAI8DA85D59B9B6634F.
> To:<sip:86987106(a)sip.uni-tel.dk>;tag=3D1c2073920452.
> Call-ID: AI231CA9BD0A4A1C53(a)10.0.0.150.
> CSeq: 2 INVITE.
> Contact:<sip:1105(a)178.21.248.56:5060>.
> Record-Route:<sip:178.21.248.7;lr;ftag=3DAI8DA85D59B9B6634F;did=3Df48.5fd1d=
b02>,<sip:178.21.248.20;lr;ftag=3DAI8DA85D59B9B6634F>.
> Supported: em,timer,replaces,path,early-session,resource-priority.
> Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSC=
RIBE,UPDATE.
> Server: Audiocodes-Sip-Gateway-Mediant 2000/v.5.60A.035.002.
> Content-Type: application/sdp.
> Content-Length: 259.
> .
> v=3D0.
> o=3DAudiocodesGW 2073965634 2073965290 IN IP4 178.21.248.56.
> s=3DPhone-Call.
> c=3DIN IP4 178.21.248.56.
> t=3D0 0.
> m=3Daudio 6050 RTP/AVP 8 101.
> c=3DIN IP4 178.21.248.56.
> a=3Drtpmap:8 PCMA/8000.
> a=3Drtpmap:101 telephone-event/8000.
> a=3Dfmtp:101 0-15.
> a=3Dptime:20.
> a=3Dsendrecv.
>
> ##############################
> U 2010/10/28 10:51:12.881179 178.21.248.56:5060 ->  178.21.248.7:5060
> SIP/2.0 200 OK.
> Via: SIP/2.0/UDP 178.21.248.7;branch=3Dz9hG4bK690c.9cfea506.0.
> Via: SIP/2.0/UDP 178.21.248.20;branch=3Dz9hG4bK690c.97354e4.0.
> Via: SIP/2.0/UDP
> 87.104.233.108:5060;rport=3D5060;branch=3Dz9hG4bK3c70fae55c8b362ff34e6c782c=
c21592.
> From:<sip:87776688(a)sip.uni-tel.dk>;tag=3DAI8DA85D59B9B6634F.
> To:<sip:86987106(a)sip.uni-tel.dk>;tag=3D1c2073920452.
> Call-ID: AI231CA9BD0A4A1C53(a)10.0.0.150.
> CSeq: 2 INVITE.
> Contact:<sip:1105(a)178.21.248.56:5060>.
> Record-Route:<sip:178.21.248.7;lr;ftag=3DAI8DA85D59B9B6634F;did=3Df48.5fd1d=
b02>,<sip:178.21.248.20;lr;ftag=3DAI8DA85D59B9B6634F>.
> Supported: em,timer,replaces,path,early-session,resource-priority.
> Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSC=
RIBE,UPDATE.
> Server: Audiocodes-Sip-Gateway-Mediant 2000/v.5.60A.035.002.
> Content-Type: application/sdp.
> Content-Length: 259.
> .
> v=3D0.
> o=3DAudiocodesGW 2073965634 2073965290 IN IP4 178.21.248.56.
> s=3DPhone-Call.
> c=3DIN IP4 178.21.248.56.
> t=3D0 0.
> m=3Daudio 6050 RTP/AVP 8 101.
> c=3DIN IP4 178.21.248.56.
> a=3Drtpmap:8 PCMA/8000.
> a=3Drtpmap:101 telephone-event/8000.
> a=3Dfmtp:101 0-15.
> a=3Dptime:20.
> a=3Dsendrecv.
>
> #
> U 2010/10/28 10:51:12.882388 178.21.248.7:5060 ->  178.21.248.20:5060
> SIP/2.0 200 OK.
> Via: SIP/2.0/UDP 178.21.248.20;branch=3Dz9hG4bK690c.97354e4.0.
> Via: SIP/2.0/UDP
> 87.104.233.108:5060;rport=3D5060;branch=3Dz9hG4bK3c70fae55c8b362ff34e6c782c=
c21592.
> From:<sip:87776688(a)sip.uni-tel.dk>;tag=3DAI8DA85D59B9B6634F.
> To:<sip:86987106(a)sip.uni-tel.dk>;tag=3D1c2073920452.
> Call-ID: AI231CA9BD0A4A1C53(a)10.0.0.150.
> CSeq: 2 INVITE.
> Contact:<sip:1105(a)178.21.248.56:5060>.
> Record-Route:<sip:178.21.248.7;lr;ftag=3DAI8DA85D59B9B6634F;did=3Df48.5fd1d=
b02>,<sip:178.21.248.20;lr;ftag=3DAI8DA85D59B9B6634F>.
> Supported: em,timer,replaces,path,early-session,resource-priority.
> Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSC=
RIBE,UPDATE.
> Server: Audiocodes-Sip-Gateway-Mediant 2000/v.5.60A.035.002.
> Content-Type: application/sdp.
> Content-Length: 259.
> .
> v=3D0.
> o=3DAudiocodesGW 2073965634 2073965290 IN IP4 178.21.248.56.
> s=3DPhone-Call.
> c=3DIN IP4 178.21.248.56.
> t=3D0 0.
> m=3Daudio 6050 RTP/AVP 8 101.
> c=3DIN IP4 178.21.248.56.
> a=3Drtpmap:8 PCMA/8000.
> a=3Drtpmap:101 telephone-event/8000.
> a=3Dfmtp:101 0-15.
> a=3Dptime:20.
> a=3Dsendrecv.
>
> #####<<<<<<<<<<<<<<<<<<<<<<   This is the problem packet>>>>>>>>>>>>>>>>>>>=
>>
> U 2010/10/28 10:51:13.267863 178.21.248.20:5060 ->  178.21.248.7:5060
> ACK sip:1105(a)178.21.248.56:5060 SIP/2.0.
> Record-Route:<sip:178.21.248.20;lr;ftag=3DAI8DA85D59B9B6634F>.
> Via: SIP/2.0/UDP 178.21.248.20;branch=3Dz9hG4bK690c.97354e4.2.
> Via: SIP/2.0/UDP
> 87.104.233.108:5060;rport=3D5060;branch=3Dz9hG4bK07103fe69c8af048b9b8216eb2=
f7233f.
> To:<sip:86987106(a)sip.uni-tel.dk>;tag=3D1c2073920452.
> From:<sip:87776688(a)sip.uni-tel.dk>;tag=3DAI8DA85D59B9B6634F.
> Call-ID: AI231CA9BD0A4A1C53(a)10.0.0.150.
> CSeq: 2 ACK.
> Max-Forwards: 69.
> Route:<sip:178.21.248.7;lr=3Don;ftag=3DAI8DA85D59B9B6634F;did=3Df48.5fd1db0=
2>.
> User-Agent: Aastra Intelligate.
> Content-Length: 0.
>
>
>
>
>
>
>
>

--=20
Daniel-Constantin Mierla
http://www.asipto.com



--===============1481894617==--