[sr-dev] [SR-Users] 200 OK Retransmission Error

Daniel-Constantin Mierla miconda at gmail.com
Wed Jun 15 09:52:14 CEST 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 at 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 at 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 at 192.168.243.150 <mailto:1-8028 at 192.168.243.150> 
> -RR11 - Entry M=INVITE RURI=<null> From=sip:5616990103 at 192.168.243.150 
> <mailto:sip%3A5616990103 at 192.168.243.150> 
> To=sip:5616990102 at 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 at 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 at 192.168.243.150 <mailto:1-8028 at 192.168.243.150> 
> -RR11 - Entry M=INVITE RURI=<null> From=sip:5616990103 at 192.168.243.150 
> <mailto:sip%3A5616990103 at 192.168.243.150> 
> To=sip:5616990102 at 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 at 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 at 192.168.243.150 <mailto:1-8028 at 192.168.243.150> 
> -RR11 - Entry M=INVITE RURI=<null> From=sip:5616990103 at 192.168.243.150 
> <mailto:sip%3A5616990103 at 192.168.243.150> 
> To=sip:5616990102 at 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 at 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 at 192.168.243.150 <mailto:1-8028 at 192.168.243.150> 
> -RR11 - Entry M=INVITE RURI=<null> From=sip:5616990103 at 192.168.243.150 
> <mailto:sip%3A5616990103 at 192.168.243.150> 
> To=sip:5616990102 at 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 at 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 at 192.168.243.150 <mailto:1-8028 at 192.168.243.150> 
> -RR11 - Entry M=INVITE RURI=<null> From=sip:5616990103 at 192.168.243.150 
> <mailto:sip%3A5616990103 at 192.168.243.150> 
> To=sip:5616990102 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-dev/attachments/20110615/0d52291e/attachment-0001.htm>


More information about the sr-dev mailing list