Re: [SR-Users] 200 OK Retransmission Error

15 Jun 2011

Hello,

On 6/15/11 6:16 AM, Jijo wrote:
...

 Hi All,

 In an INVITE transaction, no ACK from A party and B party continue 
 retransmission of 200 OK. I have observed that kamailio is not passing 
 the retransmitted 200 OK message from B party to the 
 Application(script) after 3 seconds. Instead kamailio directly sending 
 to A party without passing to the script. what do you mean "without passing to
the script"?

Note that a transaction is completed when a final reply is forwarded 
back to the sender of request. Then it is kept fore a short time in 
memory, if you want to increase that interval, see this parameter in tm:

http://kamailio.org/docs/modules/stable/modules/tm.html#wt_timer

Cheers,
Daniel

...

 I see in the logs that kamailio is cleaning up the transaction after 3 
 seconds..look for the string "DEBUG: t_lookup_request: no transaction 
 found"  before this log it is cleaning up the timer in the log "DEBUG: 
 cleanup_uac_timers: RETR/FR timers reset"

 What does it mean by that??
 How can we make the kamailio to pass the response to the application?

 Please let me know your comments.. Here is the flow. I cannot send the 
 complete logs which is quite big. so i grep'd using the stirng 
 "tcp_read_req: 
 content-length|get_hdr_field|t_reply_matching|cleanup_uac_timers|RR11" 
 from the complete log..

 A             kamailo                 B

 ----INVITE-->- --------------------INVITE

 180 Ringing--<---------------180 Ringing
 200 OK-----------<---------------200 OK 0
 200 OK-----------<---------------200 OK 500ms
 200 OK-----------<---------------200 OK 1s
 200 OK-----------<---------------200 OK 2s

 < From here it is not passing to the application- script>

 200 OK-----------<---------------200 OK 4s
 200 OK-----------<---------------200 OK 4s

   28 102:2011-06-13T19:47:37+01:00 [debug] sipserver: [26177] DEBUG: 
 <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [50]; 
 uri=[sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060>]
   36 95:2011-06-13T19:47:37+01:00 [debug] sipserver: [26177] DEBUG: 
 <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <1>
<INVITE>
   267 86:2011-06-13T19:47:37+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [tcp_read.c:933]: tcp_read_req: content-length= 0
   282 102:2011-06-13T19:47:37+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [65]; 
 uri=[sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060>]
   284 95:2011-06-13T19:47:37+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <1>
<INVITE>
   285 89:2011-06-13T19:47:37+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 5084 label 
 418362480 branch 0
   286 90:2011-06-13T19:47:38+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1018]: DEBUG: t_reply_matching: reply matched 
 (T=0xb0f62e50)!
   292 96:2011-06-13T19:47:38+01:00 [info] sipserver: [26269] INFO: 
 <script>: CI=1-8028(a)192.168.243.150 <mailto:1-8028@192.168.243.150> 
 -RR11 - Entry M=INVITE RURI=<null> From=sip:5616990103@192.168.243.150 
 <mailto:sip%3A5616990103@192.168.243.150> 
 To=sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060> RD= <null> 
 IP=192.168.243.161 Code:180 Reason=Ringing CT=5616990102 
 <tel:5616990102> <sip:5616990102 
 <tel:5616990102>@192.168.243.161:5060;transport=tcp>
   331 86:2011-06-13T19:47:39+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [tcp_read.c:933]: tcp_read_req: content-length= 191
   346 102:2011-06-13T19:47:39+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [65]; 
 uri=[sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060>]
   348 95:2011-06-13T19:47:39+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <1>
<INVITE>
   349 89:2011-06-13T19:47:39+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 5084 label 
 418362480 branch 0
   350 90:2011-06-13T19:47:39+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1018]: DEBUG: t_reply_matching: reply matched 
 (T=0xb0f62e50)!
   356 96:2011-06-13T19:47:39+01:00 [info] sipserver: [26269] INFO: 
 <script>: CI=1-8028(a)192.168.243.150 <mailto:1-8028@192.168.243.150> 
 -RR11 - Entry M=INVITE RURI=<null> From=sip:5616990103@192.168.243.150 
 <mailto:sip%3A5616990103@192.168.243.150> 
 To=sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060> RD= <null> 
 IP=192.168.243.161 Code:200 Reason=OK CT=5616990102 <tel:5616990102> 
 <sip:5616990102 <tel:5616990102>@192.168.243.161:5060;transport=tcp>
   398 89:2011-06-13T19:47:39+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_reply.c:1467]: DEBUG: cleanup_uac_timers: RETR/FR timers reset
   406 86:2011-06-13T19:47:40+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [tcp_read.c:933]: tcp_read_req: content-length= 191
   421 102:2011-06-13T19:47:40+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [65]; 
 uri=[sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060>]
   423 95:2011-06-13T19:47:40+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <1>
<INVITE>
   424 89:2011-06-13T19:47:40+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 5084 label 
 418362480 branch 0
   425 90:2011-06-13T19:47:40+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1018]: DEBUG: t_reply_matching: reply matched 
 (T=0xb0f62e50)!
   431 96:2011-06-13T19:47:40+01:00 [info] sipserver: [26269] INFO: 
 <script>: CI=1-8028(a)192.168.243.150 <mailto:1-8028@192.168.243.150> 
 -RR11 - Entry M=INVITE RURI=<null> From=sip:5616990103@192.168.243.150 
 <mailto:sip%3A5616990103@192.168.243.150> 
 To=sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060> RD= <null> 
 IP=192.168.243.161 Code:200 Reason=OK CT=5616990102 <tel:5616990102> 
 <sip:5616990102 <tel:5616990102>@192.168.243.161:5060;transport=tcp>
   481 86:2011-06-13T19:47:41+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [tcp_read.c:933]: tcp_read_req: content-length= 191
   496 102:2011-06-13T19:47:41+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [65]; 
 uri=[sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060>]
   498 95:2011-06-13T19:47:41+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <1>
<INVITE>
   499 89:2011-06-13T19:47:41+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 5084 label 
 418362480 branch 0
   500 90:2011-06-13T19:47:41+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1018]: DEBUG: t_reply_matching: reply matched 
 (T=0xb0f62e50)!
   506 96:2011-06-13T19:47:41+01:00 [info] sipserver: [26269] INFO: 
 <script>: CI=1-8028(a)192.168.243.150 <mailto:1-8028@192.168.243.150> 
 -RR11 - Entry M=INVITE RURI=<null> From=sip:5616990103@192.168.243.150 
 <mailto:sip%3A5616990103@192.168.243.150> 
 To=sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060> RD= <null> 
 IP=192.168.243.161 Code:200 Reason=OK CT=5616990102 <tel:5616990102> 
 <sip:5616990102 <tel:5616990102>@192.168.243.161:5060;transport=tcp>
   556 86:2011-06-13T19:47:43+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [tcp_read.c:933]: tcp_read_req: content-length= 191
   571 102:2011-06-13T19:47:43+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [65]; 
 uri=[sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060>]
   573 95:2011-06-13T19:47:43+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <1>
<INVITE>
   574 89:2011-06-13T19:47:43+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 5084 label 
 418362480 branch 0
   575 90:2011-06-13T19:47:43+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1018]: DEBUG: t_reply_matching: reply matched 
 (T=0xb0f62e50)!
   581 96:2011-06-13T19:47:43+01:00 [info] sipserver: [26269] INFO: 
 <script>: CI=1-8028(a)192.168.243.150 <mailto:1-8028@192.168.243.150> 
 -RR11 - Entry M=INVITE RURI=<null> From=sip:5616990103@192.168.243.150 
 <mailto:sip%3A5616990103@192.168.243.150> 
 To=sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060> RD= <null> 
 IP=192.168.243.161 Code:200 Reason=OK CT=5616990102 <tel:5616990102> 
 <sip:5616990102 <tel:5616990102>@192.168.243.161:5060;transport=tcp>
   631 86:2011-06-13T19:47:47+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [tcp_read.c:933]: tcp_read_req: content-length= 191
   646 102:2011-06-13T19:47:47+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [65]; 
 uri=[sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060>]
   648 95:2011-06-13T19:47:47+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <1>
<INVITE>
   649 89:2011-06-13T19:47:47+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 5084 label 
 418362480 branch 0
   650 90:2011-06-13T19:47:47+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1052]: DEBUG: t_reply_matching: no matching transaction 
 exists
   651 90:2011-06-13T19:47:47+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1055]: DEBUG: t_reply_matching: failure to match a 
 transaction
   693 86:2011-06-13T19:47:51+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [tcp_read.c:933]: tcp_read_req: content-length= 191
   708 102:2011-06-13T19:47:51+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [65]; 
 uri=[sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060>]
   710 95:2011-06-13T19:47:51+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <1>
<INVITE>
   711 89:2011-06-13T19:47:51+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 5084 label 
 418362480 branch 0
   712 90:2011-06-13T19:47:51+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1052]: DEBUG: t_reply_matching: no matching transaction 
 exists
   713 90:2011-06-13T19:47:51+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1055]: DEBUG: t_reply_matching: failure to match a 
 transaction
   755 86:2011-06-13T19:47:55+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [tcp_read.c:933]: tcp_read_req: content-length= 191
   770 102:2011-06-13T19:47:55+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [65]; 
 uri=[sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060>]
   772 95:2011-06-13T19:47:55+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <1>
<INVITE>
   773 89:2011-06-13T19:47:55+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 5084 label 
 418362480 branch 0
   774 90:2011-06-13T19:47:55+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1052]: DEBUG: t_reply_matching: no matching transaction 
 exists
   775 90:2011-06-13T19:47:55+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1055]: DEBUG: t_reply_matching: failure to match a 
 transaction
   817 86:2011-06-13T19:47:59+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [tcp_read.c:933]: tcp_read_req: content-length= 191
   832 102:2011-06-13T19:47:59+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [65]; 
 uri=[sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060>]
   834 95:2011-06-13T19:47:59+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <1>
<INVITE>
   835 89:2011-06-13T19:47:59+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 5084 label 
 418362480 branch 0
   836 90:2011-06-13T19:47:59+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1052]: DEBUG: t_reply_matching: no matching transaction 
 exists
   837 90:2011-06-13T19:47:59+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1055]: DEBUG: t_reply_matching: failure to match a 
 transaction
   879 86:2011-06-13T19:48:03+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [tcp_read.c:933]: tcp_read_req: content-length= 191
   894 102:2011-06-13T19:48:03+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [65]; 
 uri=[sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060>]
   896 95:2011-06-13T19:48:03+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <1>
<INVITE>
   897 89:2011-06-13T19:48:03+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 5084 label 
 418362480 branch 0
   898 90:2011-06-13T19:48:03+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1052]: DEBUG: t_reply_matching: no matching transaction 
 exists
   899 90:2011-06-13T19:48:03+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1055]: DEBUG: t_reply_matching: failure to match a 
 transaction
   941 86:2011-06-13T19:48:07+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [tcp_read.c:933]: tcp_read_req: content-length= 191
   956 102:2011-06-13T19:48:07+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [65]; 
 uri=[sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060>]
   958 95:2011-06-13T19:48:07+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <1>
<INVITE>
   959 89:2011-06-13T19:48:07+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 5084 label 
 418362480 branch 0
   960 90:2011-06-13T19:48:07+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1052]: DEBUG: t_reply_matching: no matching transaction 
 exists
   961 90:2011-06-13T19:48:07+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1055]: DEBUG: t_reply_matching: failure to match a 
 transaction
   1003 86:2011-06-13T19:48:11+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [tcp_read.c:933]: tcp_read_req: content-length= 191
   1018 102:2011-06-13T19:48:11+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:185]: DEBUG: get_hdr_field: <To> [65]; 
 uri=[sip:5616990102@192.168.243.151:5060 
 <http://sip:5616990102@192.168.243.151:5060>]
   1020 95:2011-06-13T19:48:11+01:00 [debug] sipserver: [26269] DEBUG: 
 <core> [parser/msg_parser.c:165]: get_hdr_field: cseq <CSeq>: <1>
<INVITE>
   1021 89:2011-06-13T19:48:11+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:967]: DEBUG: t_reply_matching: hash 5084 label 
 418362480 branch 0
   1022 90:2011-06-13T19:48:11+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1052]: DEBUG: t_reply_matching: no matching transaction 
 exists
   1023 90:2011-06-13T19:48:11+01:00 [debug] sipserver: [26269] DEBUG: 
 tm [t_lookup.c:1055]: DEBUG: t_reply_matching: failure to match a 
 transaction

 _______________________________________________
 SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
 sr-users(a)lists.sip-router.org
 http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users 
-- 
Daniel-Constantin Mierla -- http://www.asipto.com
http://linkedin.com/in/miconda -- http://twitter.com/miconda

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

2005

2004

2003

2002

Re: [SR-Users] 200 OK Retransmission Error