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.
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] 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] 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@192.168.243.150 -RR11 - Entry M=INVITE RURI=<null> From= sip:5616990103@192.168.243.150 To=sip:5616990102@192.168.243.151:5060 RD= <null> IP=192.168.243.161 Code:180 Reason=Ringing CT=5616990102 sip: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] 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@192.168.243.150 -RR11 - Entry M=INVITE RURI=<null> From= sip:5616990103@192.168.243.150 To=sip:5616990102@192.168.243.151:5060 RD= <null> IP=192.168.243.161 Code:200 Reason=OK CT=5616990102 sip: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] 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@192.168.243.150 -RR11 - Entry M=INVITE RURI=<null> From= sip:5616990103@192.168.243.150 To=sip:5616990102@192.168.243.151:5060 RD= <null> IP=192.168.243.161 Code:200 Reason=OK CT=5616990102 sip: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] 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@192.168.243.150 -RR11 - Entry M=INVITE RURI=<null> From= sip:5616990103@192.168.243.150 To=sip:5616990102@192.168.243.151:5060 RD= <null> IP=192.168.243.161 Code:200 Reason=OK CT=5616990102 sip: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] 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@192.168.243.150 -RR11 - Entry M=INVITE RURI=<null> From= sip:5616990103@192.168.243.150 To=sip:5616990102@192.168.243.151:5060 RD= <null> IP=192.168.243.161 Code:200 Reason=OK CT=5616990102 sip: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] 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] 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] 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] 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] 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] 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] 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
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.
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] 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] 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@192.168.243.150 -RR11 - Entry M=INVITE RURI=<null> From= sip:5616990103@192.168.243.150 To=sip:5616990102@192.168.243.151:5060 RD= <null> IP=192.168.243.161 Code:180 Reason=Ringing CT=5616990102 sip: 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] 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@192.168.243.150 -RR11 - Entry M=INVITE RURI=<null> From= sip:5616990103@192.168.243.150 To=sip:5616990102@192.168.243.151:5060 RD= <null> IP=192.168.243.161 Code:200 Reason=OK CT=5616990102 sip: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] 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@192.168.243.150 -RR11 - Entry M=INVITE RURI=<null> From= sip:5616990103@192.168.243.150 To=sip:5616990102@192.168.243.151:5060 RD= <null> IP=192.168.243.161 Code:200 Reason=OK CT=5616990102 sip: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] 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@192.168.243.150 -RR11 - Entry M=INVITE RURI=<null> From= sip:5616990103@192.168.243.150 To=sip:5616990102@192.168.243.151:5060 RD= <null> IP=192.168.243.161 Code:200 Reason=OK CT=5616990102 sip: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] 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@192.168.243.150 -RR11 - Entry M=INVITE RURI=<null> From= sip:5616990103@192.168.243.150 To=sip:5616990102@192.168.243.151:5060 RD= <null> IP=192.168.243.161 Code:200 Reason=OK CT=5616990102 sip: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] 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] 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] 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] 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] 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] 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] 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