Re: [SR-Users] variable $rb not updated on failure route after a 302 on the same PID

Hello, for clarification, it is actually the $T_rpl($rb) not giving the expected value, right? Not the pure $rb... If yes, then can you try with the patch from the next commit:   * https://github.com/kamailio/kamailio/commit/e2ca5516ae086cf33c61dbb9e653a54… When all ok, I will backport. Cheers, Daniel On 08.11.18 13:22, David Escartín wrote: > Hello all > we are seeing what we think is quite strange behaviour > > We have expecienced this on 5.0 and 5.1 version. > > this is the call flow > INV--> > <-- 302 (SDP) > INV--> > > <-- 503 (SDP) (or another 302) > > > When we receive a 302 and we load contacts and create a new branch, > when we receive the second error response, and we receive it on the > same udp receiver process, if we read the content of $rb on the the > onreply_route, we get the proper value of the response SDP, but when > we read $T_rpl($rb) on the failure_route, we get the value of the > first error transaction. > > If the response (second) is received in another PID, it's ok. > > > I'm not sure if i'm explaining myself, but we would think that the > value should be updated, no matter which PID is used to process the > response > > > for example, running the kamailio with only 1 child. For the first 302 > we have > > > onreply route checking $rb > 1(7698) INFO: <script>: LAL > {"sdp_data":"3466666666","sdp_data_2":null,"nrn":null} > failure_route checking $T_rpl($rb) >  1(7698) INFO: <script>: LOOOOOOOOL > {"sdp_data":"3466666666","sdp_data_2":null,"nrn":null} > and for the next error >  1(7698) INFO: <script>: LAL > {"sdp_data":"34619796636","sdp_data_2":null,"nrn":null} >  1(7698) INFO: <script>: LOOOOOOOOL > {"sdp_data":"3466666666","sdp_data_2":null,"nrn":null} > > If we run it with 16 children and the PID don't match. For the first > 302 we have > > onreply route checking $rb > 13(8360) INFO: <script>: LAL > {"sdp_data":"3466666666","sdp_data_2":null,"nrn":null} > failure_route checking $T_rpl($rb) > 13(8360) INFO: <script>: LOOOOOOOOL > {"sdp_data":"3466666666","sdp_data_2":null,"nrn":null} > and for the next error after loading the contacts > 15(8362) INFO: <script>: LAL > {"sdp_data":"34619796636","sdp_data_2":null,"nrn":null} > > 15(8362) INFO: <script>: LOOOOOOOOL > {"sdp_data":"34619796636","sdp_data_2":null,"nrn":null} > > > i attach you the logs in both cases > > could you please check if you see anything wrong? > > best regards > > david > > > 16_children.log > > 11(8358) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/634) [[INVITE > sip:34606147628@10.100.10.67:5069 SIP/2.0 0D  0A Via: SIP/2.0/UDP > 10.100.10.67:5061;branch=z9hG4bK-]] > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): > SIP Request: > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg(): > method:  <INVITE> > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg(): > uri:     <sip:34606147628@10.100.10.67:5069> > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): > version: <SIP/2.0> > 11(8358) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-9680-1-0>; state=16 > 11(8358) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via > 11(8358) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=10 > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [44]; uri=[sip:34606147628@10.100.10.67:5069] > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069> > ] > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> > 11(8358) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - request - call-id: [1-9680(a)10.100.10.67] - > cseq: [1 INVITE] > 11(8358) DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing > to run routing scripts... > 11(8358) INFO: <script>: hereeeeeeeeeee > 11(8358) DEBUG: tm [t_lookup.c:1320]: t_newtran(): msg id=1 , global > msg id=0 , T on entrance=0xffffffffffffffff > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=217 > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header > 11(8358) DEBUG: tm [t_lookup.c:477]: t_lookup_request(): start > searching: hash=13774, isACK=0 > 11(8358) DEBUG: tm [t_lookup.c:435]: matching_3261(): RFC3261 > transaction matching failed > 11(8358) DEBUG: tm [t_lookup.c:659]: t_lookup_request(): no > transaction found > 11(8358) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=9680SIPpTag001 > 11(8358) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 > 11(8358) DEBUG: <core> [core/md5utils.c:67]: MD5StringArray(): MD5 > calculated: 56115a2d09f62d466f1d45a5f5ff7cc2 > 11(8358) DEBUG: tm [t_funcs.c:324]: t_relay_to(): new INVITE > 11(8358) DEBUG: <core> [core/msg_translator.c:159]: > check_via_address(): (10.100.10.67, 10.100.10.67, 0) > 11(8358) DEBUG: tm [t_reply.c:596]: _reply_light(): reply sent out. > buf=0x7f334b5f4ea0: SIP/2.0 100 trying -..., shmem=0x7f3346638240: > SIP/2.0 100 trying - > 11(8358) DEBUG: tm [t_reply.c:606]: _reply_light(): finished > 11(8358) INFO: <script>: LEL > 11(8358) DEBUG: <core> [core/msg_translator.c:159]: > check_via_address(): (10.100.10.67, 10.100.10.67, 0) > 11(8358) INFO: <script>: hereeeeeeeeeee > 11(8358) DEBUG: tm [t_funcs.c:372]: t_relay_to(): new transaction > forwarded > 11(8358) DEBUG: <core> [core/receive.c:289]: receive_msg(): > request-route executed in: 550 usec > 11(8358) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 11(8358) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 11(8358) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 11(8358) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 11(8358) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 11(8358) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 11(8358) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) > 11(8358) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up > 11(8358) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/397) [[SIP/2.0 100 Trying 0D  0A Via: > SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKec53.56115a2d09f62d466f1d45a5f]] > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <100> > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <Trying> > 11(8358) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKec53.56115a2d09f62d466f1d45a5f5ff7cc2.0>; state=9 > 11(8358) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via > 11(8358) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-9680-1-0>; state=16 > 11(8358) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via > 11(8358) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=10 > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [44]; uri=[sip:34606147628@10.100.10.67:5069] > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069> > ] > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> > 11(8358) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - reply - call-id: [1-9680(a)10.100.10.67] - cseq: > [1 INVITE] > 11(8358) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7f334b5f3768) id=2 global id=1 T start=0xffffffffffffffff > 13(8360) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/479) [[SIP/2.0 302 Moved Temporarily > 0D  0A Via: SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKec53.56115a2d09f62d]] > 11(8358) DEBUG: tm [t_lookup.c:897]: t_reply_matching(): > t_reply_matching: hash 13774 label 0 branch 0 > 11(8358) DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply > (0x7f334b5f3768) matched an active transaction (T=0x7f334663b040)! > 11(8358) DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg > (0x7f334b5f3768) id=2 global id=2 T end=0x7f334663b040 > 11(8358) DEBUG: tm [t_reply.c:2209]: reply_received(): org. status > uas=100, uac[0]=0 local=0 is_invite=1) > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=0 > 11(8358) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header > 11(8358) INFO: <script>: LAL > 11(8358) DEBUG: tm [t_reply.c:1265]: t_should_relay_response(): > ->>>>>>>>> T_code=100, new_code=100 > 11(8358) DEBUG: tm [t_reply.c:1788]: relay_reply(): branch=0, save=0, > relay=-1 icode=0 > 11(8358) DEBUG: <core> [core/receive.c:362]: receive_msg(): > reply-route executed in: 149 usec > 11(8358) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 11(8358) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 11(8358) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 11(8358) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 11(8358) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 11(8358) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 11(8358) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) > 11(8358) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <302> > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <Moved Temporarily> > 13(8360) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKec53.56115a2d09f62d466f1d45a5f5ff7cc2.0>; state=9 > 13(8360) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via > 13(8360) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-9680-1-0>; state=16 > 13(8360) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via > 13(8360) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=5 > 13(8360) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069>] > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> > 13(8360) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - reply - call-id: [1-9680(a)10.100.10.67] - cseq: > [1 INVITE] > 13(8360) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7f334b5f3768) id=1 global id=0 T start=0xffffffffffffffff > 13(8360) DEBUG: tm [t_lookup.c:897]: t_reply_matching(): > t_reply_matching: hash 13774 label 0 branch 0 > 13(8360) DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply > (0x7f334b5f3768) matched an active transaction (T=0x7f334663b040)! > 13(8360) DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg > (0x7f334b5f3768) id=1 global id=1 T end=0x7f334663b040 > 13(8360) DEBUG: tm [t_reply.c:2209]: reply_received(): org. status > uas=100, uac[0]=100 local=0 is_invite=1) > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=63 > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header > 13(8360) INFO: <script>: LAL > {"sdp_data":"3466666666","sdp_data_2":null,"nrn":null} > > 13(8360) DEBUG: tm [t_reply.c:1265]: t_should_relay_response(): > ->>>>>>>>> T_code=100, new_code=302 > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <302> > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <Moved Temporarily> > 13(8360) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKec53.56115a2d09f62d466f1d45a5f5ff7cc2.0>; state=9 > 13(8360) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via > 13(8360) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-9680-1-0>; state=16 > 13(8360) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via > 13(8360) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=5 > 13(8360) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069>] > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=63 > 13(8360) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header > 13(8360) INFO: <script>: LOOOOOOOOL > {"sdp_data":"3466666666","sdp_data_2":null,"nrn":null} > > 13(8360) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7f3346637088) id=0 global id=0 T start=0x7f334663b040 > 13(8360) DEBUG: tm [t_lookup.c:1091]: t_check_msg(): T > (0x7f334663b040) already found for msg (0x7f3346637088)! > 13(8360) DEBUG: tmx [t_var.c:534]: pv_get_tm_reply_code(): reply code > is <302> > 13(8360) INFO: <script>: Call: 302 received, trying to load contacts > 13(8360) DEBUG: uac_redirect [rd_funcs.c:72]: get_redirect(): resume > branch=0 > 13(8360) DEBUG: uac_redirect [rd_funcs.c:79]: get_redirect(): checking > branch=0 (added=0) > 13(8360) DEBUG: uac_redirect [rd_funcs.c:83]: get_redirect(): branch=0 > is a redirect (added=0) > 13(8360) DEBUG: uac_redirect [rd_funcs.c:159]: sort_contacts(): > sort_contacts: <sip:34666988297@10.100.10.67:5060> q=10 > 13(8360) DEBUG: uac_redirect [rd_funcs.c:295]: shmcontact2dset(): > adding contact <sip:34666988297@10.100.10.67:5060> > 13(8360) DEBUG: <core> [sruid.c:183]: sruid_next(): new sruid is > [rdir-5be4236b-20a8-1] (1 / 20) > 13(8360) DEBUG: tm [t_serial.c:191]: ki_t_load_contacts(): nr_branches > is 1 > 13(8360) DEBUG: tm [t_serial.c:194]: ki_t_load_contacts(): nothing to > do - only one contact! > 13(8360) INFO: <script>: LEL > 13(8360) DEBUG: <core> [core/msg_translator.c:159]: > check_via_address(): (10.100.10.67, 10.100.10.67, 0) > 13(8360) INFO: <script>: hereeeeeeeeeee > 13(8360) DEBUG: tm [t_reply.c:1788]: relay_reply(): branch=0, save=0, > relay=-1 icode=0 > 13(8360) DEBUG: <core> [core/receive.c:362]: receive_msg(): > reply-route executed in: 783 usec > 13(8360) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 13(8360) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 13(8360) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 13(8360) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 13(8360) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 13(8360) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 13(8360) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) > 13(8360) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up > 14(8361) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/397) [[SIP/2.0 100 Trying 0D  0A Via: > SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKec53.56115a2d09f62d466f1d45a5f]] > 15(8362) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/482) [[SIP/2.0 503 Service > Unavailable 0D  0A Via: SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKec53.56115a2d09f6]] > 14(8361) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): > 14(8361) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> > 14(8361) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <100> > 14(8361) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <Trying> > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <503> > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <Service Unavailable> > 14(8361) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKec53.56115a2d09f62d466f1d45a5f5ff7cc2.1>; state=9 > 14(8361) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via > 14(8361) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-9680-1-0>; state=16 > 14(8361) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 > 14(8361) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 > 14(8361) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via > 15(8362) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKec53.56115a2d09f62d466f1d45a5f5ff7cc2.1>; state=9 > 15(8362) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via > 15(8362) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-9680-1-0>; state=16 > 15(8362) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 > 14(8361) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=10 > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 > 14(8361) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [44]; uri=[sip:34606147628@10.100.10.67:5069] > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via > 14(8361) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069> > ] > 14(8361) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> > 14(8361) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - reply - call-id: [1-9680(a)10.100.10.67] - cseq: > [1 INVITE] > 15(8362) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=5 > 15(8362) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069>] > 14(8361) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7f334b5f3768) id=1 global id=0 T start=0xffffffffffffffff > 14(8361) DEBUG: tm [t_lookup.c:897]: t_reply_matching(): > t_reply_matching: hash 13774 label 0 branch 1 > 14(8361) DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply > (0x7f334b5f3768) matched an active transaction (T=0x7f334663b040)! > 14(8361) DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg > (0x7f334b5f3768) id=1 global id=1 T end=0x7f334663b040 > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> > 14(8361) DEBUG: tm [t_reply.c:2209]: reply_received(): org. status > uas=100, uac[1]=0 local=0 is_invite=1) > 15(8362) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - reply - call-id: [1-9680(a)10.100.10.67] - cseq: > [1 INVITE] > 15(8362) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7f334b5f3768) id=1 global id=0 T start=0xffffffffffffffff > 15(8362) DEBUG: tm [t_lookup.c:897]: t_reply_matching(): > t_reply_matching: hash 13774 label 0 branch 1 > 15(8362) DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply > (0x7f334b5f3768) matched an active transaction (T=0x7f334663b040)! > 14(8361) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=0 > 15(8362) DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg > (0x7f334b5f3768) id=1 global id=1 T end=0x7f334663b040 > 15(8362) DEBUG: tm [t_reply.c:2209]: reply_received(): org. status > uas=100, uac[1]=100 local=0 is_invite=1) > 14(8361) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header > 14(8361) INFO: <script>: LAL > 14(8361) DEBUG: tm [t_reply.c:1265]: t_should_relay_response(): > ->>>>>>>>> T_code=100, new_code=100 > 14(8361) DEBUG: tm [t_reply.c:1788]: relay_reply(): branch=1, save=0, > relay=-1 icode=0 > 14(8361) DEBUG: <core> [core/receive.c:362]: receive_msg(): > reply-route executed in: 199 usec > 14(8361) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 14(8361) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 14(8361) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 14(8361) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 14(8361) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 14(8361) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 14(8361) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) > 14(8361) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=64 > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header > 15(8362) INFO: <script>: LAL > {"sdp_data":"34619796636","sdp_data_2":null,"nrn":null} > > 15(8362) DEBUG: tm [t_reply.c:1265]: t_should_relay_response(): > ->>>>>>>>> T_code=100, new_code=503 > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <503> > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <Service Unavailable> > 15(8362) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKec53.56115a2d09f62d466f1d45a5f5ff7cc2.1>; state=9 > 15(8362) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via > 15(8362) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-9680-1-0>; state=16 > 15(8362) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via > 15(8362) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=5 > 15(8362) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069>] > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=64 > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header > 15(8362) INFO: <script>: LOOOOOOOOL > {"sdp_data":"34619796636","sdp_data_2":null,"nrn":null} > > 15(8362) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7f3346637088) id=0 global id=0 T start=0x7f334663b040 > 15(8362) DEBUG: tm [t_lookup.c:1091]: t_check_msg(): T > (0x7f334663b040) already found for msg (0x7f3346637088)! > 15(8362) DEBUG: tmx [t_var.c:534]: pv_get_tm_reply_code(): reply code > is <503> > 15(8362) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7f3346637088) id=0 global id=0 T start=0x7f334663b040 > 15(8362) DEBUG: tm [t_lookup.c:1091]: t_check_msg(): T > (0x7f334663b040) already found for msg (0x7f3346637088)! > 15(8362) DEBUG: tmx [t_var.c:534]: pv_get_tm_reply_code(): reply code > is <503> > 15(8362) INFO: <script>: LEL > 15(8362) DEBUG: <core> [core/msg_translator.c:159]: > check_via_address(): (10.100.10.67, 10.100.10.67, 0) > 15(8362) INFO: <script>: hereeeeeeeeeee > 15(8362) DEBUG: tm [t_reply.c:1788]: relay_reply(): branch=1, save=0, > relay=-1 icode=0 > 15(8362) DEBUG: <core> [core/receive.c:362]: receive_msg(): > reply-route executed in: 676 usec > 15(8362) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 15(8362) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 15(8362) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 15(8362) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 15(8362) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 15(8362) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 15(8362) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) > 15(8362) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up > 15(8362) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/404) [[SIP/2.0 180 Ringing 0D  0A > Via: SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKec53.56115a2d09f62d466f1d45a5]] > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <180> > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <Ringing> > 15(8362) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKec53.56115a2d09f62d466f1d45a5f5ff7cc2.2>; state=9 > 15(8362) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via > 15(8362) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-9680-1-0>; state=16 > 15(8362) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via > 15(8362) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=5 > 15(8362) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069>] > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> > 15(8362) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - reply - call-id: [1-9680(a)10.100.10.67] - cseq: > [1 INVITE] > 15(8362) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7f334b5f3768) id=2 global id=1 T start=0xffffffffffffffff >  6(8353) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/595) [[SIP/2.0 200 OK 0D  0A Via: > SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKec53.56115a2d09f62d466f1d45a5f5ff7]] > 15(8362) DEBUG: tm [t_lookup.c:897]: t_reply_matching(): > t_reply_matching: hash 13774 label 0 branch 2 > 15(8362) DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply > (0x7f334b5f3768) matched an active transaction (T=0x7f334663b040)! > 15(8362) DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg > (0x7f334b5f3768) id=2 global id=2 T end=0x7f334663b040 > 15(8362) DEBUG: tm [t_reply.c:2209]: reply_received(): org. status > uas=100, uac[2]=0 local=0 is_invite=1) > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=0 > 15(8362) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header > 15(8362) INFO: <script>: LAL > 15(8362) DEBUG: tm [t_reply.c:1265]: t_should_relay_response(): > ->>>>>>>>> T_code=100, new_code=180 > 15(8362) DEBUG: tm [t_reply.c:1788]: relay_reply(): branch=2, save=0, > relay=2 icode=0 > 15(8362) DEBUG: <core> [core/msg_translator.c:2270]: > generate_res_buf_from_sip_res(): old size: 404, new size: 318 > 15(8362) DEBUG: <core> [core/msg_translator.c:2288]: > generate_res_buf_from_sip_res(): copied size: orig:112, new: 26, rest: > 292 msg= > SIP/2.0 180 Ringing > Via: SIP/2.0/UDP 10.100.10.67:5061;branch=z9hG4bK-9680-1-0 > From: "BTS" <sip:34917019888@10.100.10.67:5061>;tag=9680SIPpTag001 > To: "Javi" <sip:34606147628@10.100.10.67:5069>;tag=5 > Call-ID: 1-9680(a)10.100.10.67 > CSeq: 1 INVITE > Contact: <sip:10.100.10.67:5060;transport=UDP> > Content-Length: 0 > > > 15(8362) DEBUG: <core> [core/receive.c:362]: receive_msg(): > reply-route executed in: 71 usec > 15(8362) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 15(8362) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 15(8362) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 15(8362) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 15(8362) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 15(8362) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) > 15(8362) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) > 15(8362) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <200> >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <OK> >  6(8353) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKec53.56115a2d09f62d466f1d45a5f5ff7cc2.2>; state=9 >  6(8353) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via >  6(8353) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-9680-1-0>; state=16 >  6(8353) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  6(8353) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=5 >  6(8353) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069>] >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> >  6(8353) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - reply - call-id: [1-9680(a)10.100.10.67] - cseq: > [1 INVITE] >  6(8353) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7f334b5f3768) id=1 global id=0 T start=0xffffffffffffffff >  6(8353) DEBUG: tm [t_lookup.c:897]: t_reply_matching(): > t_reply_matching: hash 13774 label 0 branch 2 >  6(8353) DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply > (0x7f334b5f3768) matched an active transaction (T=0x7f334663b040)! >  6(8353) DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg > (0x7f334b5f3768) id=1 global id=1 T end=0x7f334663b040 >  6(8353) DEBUG: tm [t_reply.c:2209]: reply_received(): org. status > uas=180, uac[2]=180 local=0 is_invite=1) >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=161 >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header >  6(8353) INFO: <script>: LAL v=0 > o=user1 53655765 2353687637 IN IP4 10.100.10.67 > s=- > c=IN IP4 10.100.10.67 > t=0 0 > m=audio 6000 RTP/AVP 0 18 > a=rtpmap:0 PCMU/8000 > a=rtpmap:18 G729/8000 > >  6(8353) DEBUG: tm [t_reply.c:1265]: t_should_relay_response(): > ->>>>>>>>> T_code=180, new_code=200 >  6(8353) DEBUG: tm [t_reply.c:1788]: relay_reply(): branch=2, save=0, > relay=2 icode=0 >  6(8353) DEBUG: <core> [core/msg_translator.c:2270]: > generate_res_buf_from_sip_res(): old size: 595, new size: 509 >  6(8353) DEBUG: <core> [core/msg_translator.c:2288]: > generate_res_buf_from_sip_res(): copied size: orig:107, new: 21, rest: > 488 msg= > SIP/2.0 200 OK > Via: SIP/2.0/UDP 10.100.10.67:5061;branch=z9hG4bK-9680-1-0 > From: "BTS" <sip:34917019888@10.100.10.67:5061>;tag=9680SIPpTag001 > To: "Javi" <sip:34606147628@10.100.10.67:5069>;tag=5 > Call-ID: 1-9680(a)10.100.10.67 > CSeq: 1 INVITE > Contact: <sip:10.100.10.67:5060;transport=UDP> > Content-Type: application/sdp > Content-Length:   161 > > v=0 > o=user1 53655765 2353687637 IN IP4 10.100.10.67 > s=- > c=IN IP4 10.100.10.67 > t=0 0 > m=audio 6000 RTP/AVP 0 18 > a=rtpmap:0 PCMU/8000 > a=rtpmap:18 G729/8000 > >  6(8353) DEBUG: tm [t_reply.c:1631]: cleanup_uac_timers(): RETR/FR > timers reset >  6(8353) DEBUG: <core> [core/receive.c:362]: receive_msg(): > reply-route executed in: 283 usec >  6(8353) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  6(8353) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  6(8353) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  6(8353) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  6(8353) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  6(8353) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  6(8353) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) >  6(8353) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up >  6(8353) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/323) [[ACK > sip:34606147628@10.100.10.67:5060 SIP/2.0 0D  0A Via: SIP/2.0/UDP > 10.100.10.67:5061;branch=z9hG4bK-968]] >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): > SIP Request: >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg(): > method:  <ACK> >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg(): > uri:     <sip:34606147628@10.100.10.67:5060> >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): > version: <SIP/2.0> >  6(8353) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-9680-1-0>; state=16 >  6(8353) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  6(8353) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=5 >  6(8353) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Test" <sip:34606147628@10.100.10.67:5069>] >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <ACK> >  6(8353) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - request - call-id: [1-9680(a)10.100.10.67] - > cseq: [1 ACK] >  6(8353) DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing > to run routing scripts... >  6(8353) DEBUG: sl [sl_funcs.c:387]: sl_filter_ACK(): too late to be a > local ACK! >  6(8353) INFO: <script>: hereeeeeeeeeee >  6(8353) DEBUG: tm [t_lookup.c:1320]: t_newtran(): msg id=2 , global > msg id=1 , T on entrance=0xffffffffffffffff >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=0 >  6(8353) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header >  6(8353) DEBUG: tm [t_lookup.c:477]: t_lookup_request(): start > searching: hash=13774, isACK=1 >  6(8353) DEBUG: tm [t_lookup.c:435]: matching_3261(): RFC3261 > transaction matching failed >  6(8353) DEBUG: tm [t_lookup.c:659]: t_lookup_request(): no > transaction found >  6(8353) DEBUG: tm [t_funcs.c:284]: t_relay_to(): forwarding ACK > statelessly >  6(8353) DEBUG: <core> [core/md5utils.c:67]: MD5StringArray(): MD5 > calculated: 56115a2d09f62d466f1d45a5f5ff7cc2 >  6(8353) DEBUG: <core> [core/msg_translator.c:159]: > check_via_address(): (10.100.10.67, 10.100.10.67, 0) >  6(8353) DEBUG: <core> [core/forward.c:557]: forward_request(): Sending: > ACK sip:34606147628@10.100.10.67:5060 SIP/2.0 > Via: SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKec53.56115a2d09f62d466f1d45a5f5ff7cc2.0 > Via: SIP/2.0/UDP 10.100.10.67:5061;branch=z9hG4bK-9680-1-0 > From: "BTS" <sip:34917019888@10.100.10.67:5061>;tag=9680SIPpTag001 > To: "Test" <sip:34606147628@10.100.10.67:5069>;tag=5 > Call-ID: 1-9680(a)10.100.10.67 > CSeq: 1 ACK > Max-Forwards: 70 > Subject: 1 > Content-Length: 0 > > . >  6(8353) DEBUG: <core> [core/forward.c:559]: forward_request(): orig. > len=323, new_len=414, proto=1 >  6(8353) INFO: <script>: hereeeeeeeeeee >  6(8353) DEBUG: <core> [core/receive.c:289]: receive_msg(): > request-route executed in: 232 usec >  6(8353) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  6(8353) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  6(8353) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  6(8353) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  6(8353) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  6(8353) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  6(8353) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) >  6(8353) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up >  3(8350) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/338) [[BYE > sip:34606147628@10.100.10.67:5060 SIP/2.0 0D  0A Via: SIP/2.0/UDP > 10.100.10.67:5061;branch=z9hG4bK-968]] >  3(8350) DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): > SIP Request: >  3(8350) DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg(): > method:  <BYE> >  3(8350) DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg(): > uri:     <sip:34606147628@10.100.10.67:5060> >  3(8350) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): > version: <SIP/2.0> >  3(8350) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-9680-1-8>; state=16 >  3(8350) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  3(8350) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  3(8350) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  3(8350) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=5 >  3(8350) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 >  3(8350) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] >  3(8350) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Test" <sip:34606147628@10.100.10.67:5069>] >  3(8350) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <2> <BYE> >  3(8350) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - request - call-id: [1-9680(a)10.100.10.67] - > cseq: [2 BYE] >  3(8350) DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing > to run routing scripts... >  3(8350) INFO: <script>: hereeeeeeeeeee >  3(8350) DEBUG: tm [t_lookup.c:1320]: t_newtran(): msg id=2 , global > msg id=1 , T on entrance=0xffffffffffffffff >  3(8350) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=0 >  3(8350) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header >  3(8350) DEBUG: tm [t_lookup.c:477]: t_lookup_request(): start > searching: hash=13771, isACK=0 >  3(8350) DEBUG: tm [t_lookup.c:435]: matching_3261(): RFC3261 > transaction matching failed >  3(8350) DEBUG: tm [t_lookup.c:659]: t_lookup_request(): no > transaction found >  3(8350) DEBUG: <core> [core/md5utils.c:67]: MD5StringArray(): MD5 > calculated: 5b69d64cadac24fd6fc477c074a9b4c9 >  3(8350) INFO: <script>: LEL >  3(8350) DEBUG: <core> [core/msg_translator.c:159]: > check_via_address(): (10.100.10.67, 10.100.10.67, 0) >  3(8350) INFO: <script>: hereeeeeeeeeee >  3(8350) DEBUG: tm [t_funcs.c:372]: t_relay_to(): new transaction > forwarded >  3(8350) DEBUG: <core> [core/receive.c:289]: receive_msg(): > request-route executed in: 265 usec >  3(8350) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  3(8350) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  3(8350) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  3(8350) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  3(8350) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  3(8350) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  3(8350) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) >  3(8350) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up >  7(8354) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/396) [[SIP/2.0 200 OK 0D  0A Via: > SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKbc53.5b69d64cadac24fd6fc477c074a9b]] >  7(8354) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): >  7(8354) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> >  7(8354) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <200> >  7(8354) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <OK> >  7(8354) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKbc53.5b69d64cadac24fd6fc477c074a9b4c9.0>; state=9 >  7(8354) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via >  7(8354) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-9680-1-8>; state=16 >  7(8354) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  7(8354) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  7(8354) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  7(8354) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=5 >  7(8354) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 >  7(8354) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] >  7(8354) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Test" <sip:34606147628@10.100.10.67:5069>] >  7(8354) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <2> <BYE> >  7(8354) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - reply - call-id: [1-9680(a)10.100.10.67] - cseq: > [2 BYE] >  7(8354) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7f334b5f3768) id=2 global id=1 T start=0xffffffffffffffff >  7(8354) DEBUG: tm [t_lookup.c:897]: t_reply_matching(): > t_reply_matching: hash 13771 label 0 branch 0 >  7(8354) DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply > (0x7f334b5f3768) matched an active transaction (T=0x7f33466359d8)! >  7(8354) DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg > (0x7f334b5f3768) id=2 global id=2 T end=0x7f33466359d8 >  7(8354) DEBUG: tm [t_reply.c:2209]: reply_received(): org. status > uas=0, uac[0]=0 local=0 is_invite=0) >  7(8354) DEBUG: tm [t_reply.c:1265]: t_should_relay_response(): > ->>>>>>>>> T_code=0, new_code=200 >  7(8354) DEBUG: tm [t_reply.c:1788]: relay_reply(): branch=0, save=0, > relay=0 icode=0 >  7(8354) DEBUG: <core> [core/msg_translator.c:2270]: > generate_res_buf_from_sip_res(): old size: 396, new size: 310 >  7(8354) DEBUG: <core> [core/msg_translator.c:2288]: > generate_res_buf_from_sip_res(): copied size: orig:107, new: 21, rest: > 289 msg= > SIP/2.0 200 OK > Via: SIP/2.0/UDP 10.100.10.67:5061;branch=z9hG4bK-9680-1-8 > From: "BTS" <sip:34917019888@10.100.10.67:5061>;tag=9680SIPpTag001 > To: "Test" <sip:34606147628@10.100.10.67:5069>;tag=5 > Call-ID: 1-9680(a)10.100.10.67 > CSeq: 2 BYE > Contact: <sip:10.100.10.67:5060;transport=UDP> > Content-Length: 0 > > >  7(8354) DEBUG: tm [t_reply.c:1631]: cleanup_uac_timers(): RETR/FR > timers reset >  7(8354) DEBUG: <core> [core/receive.c:362]: receive_msg(): > reply-route executed in: 137 usec >  7(8354) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  7(8354) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  7(8354) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  7(8354) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  7(8354) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  7(8354) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  7(8354) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) >  7(8354) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up > 18(8365) DEBUG: tm [h_table.c:129]: free_cell_helper(): freeing > transaction 0x7f334663b040 from timer.c:654 > 18(8365) DEBUG: tm [h_table.c:129]: free_cell_helper(): freeing > transaction 0x7f33466359d8 from timer.c:654 > > > > 1_children.log > > 1(7698) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/634) [[INVITE > sip:34606147628@10.100.10.67:5069 SIP/2.0 0D  0A Via: SIP/2.0/UDP > 10.100.10.67:5061;branch=z9hG4bK-]] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): > SIP Request: >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg(): > method:  <INVITE> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg(): > uri:     <sip:34606147628@10.100.10.67:5069> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): > version: <SIP/2.0> >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-8173-1-0>; state=16 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=10 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [44]; uri=[sip:34606147628@10.100.10.67:5069] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069> > ] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> >  1(7698) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - request - call-id: [1-8173(a)10.100.10.67] - > cseq: [1 INVITE] >  1(7698) DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing > to run routing scripts... >  1(7698) INFO: <script>: hereeeeeeeeeee >  1(7698) DEBUG: tm [t_lookup.c:1320]: t_newtran(): msg id=1 , global > msg id=0 , T on entrance=0xffffffffffffffff >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=217 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header >  1(7698) DEBUG: tm [t_lookup.c:477]: t_lookup_request(): start > searching: hash=65453, isACK=0 >  1(7698) DEBUG: tm [t_lookup.c:435]: matching_3261(): RFC3261 > transaction matching failed >  1(7698) DEBUG: tm [t_lookup.c:659]: t_lookup_request(): no > transaction found >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=8173SIPpTag001 >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 >  1(7698) DEBUG: <core> [core/md5utils.c:67]: MD5StringArray(): MD5 > calculated: 8f25665e8c867e73b07da3cb1f702171 >  1(7698) DEBUG: tm [t_funcs.c:324]: t_relay_to(): new INVITE >  1(7698) DEBUG: <core> [core/msg_translator.c:159]: > check_via_address(): (10.100.10.67, 10.100.10.67, 0) >  1(7698) DEBUG: tm [t_reply.c:596]: _reply_light(): reply sent out. > buf=0x7fe2c208bea0: SIP/2.0 100 trying -..., shmem=0x7fe2bd0c9f40: > SIP/2.0 100 trying - >  1(7698) DEBUG: tm [t_reply.c:606]: _reply_light(): finished >  1(7698) INFO: <script>: LEL >  1(7698) DEBUG: <core> [core/msg_translator.c:159]: > check_via_address(): (10.100.10.67, 10.100.10.67, 0) >  1(7698) INFO: <script>: hereeeeeeeeeee >  1(7698) DEBUG: tm [t_funcs.c:372]: t_relay_to(): new transaction > forwarded >  1(7698) DEBUG: <core> [core/receive.c:289]: receive_msg(): > request-route executed in: 607 usec >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) >  1(7698) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up >  1(7698) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/397) [[SIP/2.0 100 Trying 0D  0A Via: > SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKdaff.8f25665e8c867e73b07da3cb1]] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <100> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <Trying> >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKdaff.8f25665e8c867e73b07da3cb1f702171.0>; state=9 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-8173-1-0>; state=16 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=10 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [44]; uri=[sip:34606147628@10.100.10.67:5069] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069> > ] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> >  1(7698) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - reply - call-id: [1-8173(a)10.100.10.67] - cseq: > [1 INVITE] >  1(7698) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7fe2c208a768) id=2 global id=1 T start=0xffffffffffffffff >  1(7698) DEBUG: tm [t_lookup.c:897]: t_reply_matching(): > t_reply_matching: hash 65453 label 0 branch 0 >  1(7698) DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply > (0x7fe2c208a768) matched an active transaction (T=0x7fe2bd0c76d8)! >  1(7698) DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg > (0x7fe2c208a768) id=2 global id=2 T end=0x7fe2bd0c76d8 >  1(7698) DEBUG: tm [t_reply.c:2209]: reply_received(): org. status > uas=100, uac[0]=0 local=0 is_invite=1) >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=0 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header >  1(7698) INFO: <script>: LAL >  1(7698) DEBUG: tm [t_reply.c:1265]: t_should_relay_response(): > ->>>>>>>>> T_code=100, new_code=100 >  1(7698) DEBUG: tm [t_reply.c:1788]: relay_reply(): branch=0, save=0, > relay=-1 icode=0 >  1(7698) DEBUG: <core> [core/receive.c:362]: receive_msg(): > reply-route executed in: 118 usec >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) >  1(7698) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up >  1(7698) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/479) [[SIP/2.0 302 Moved Temporarily > 0D  0A Via: SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKdaff.8f25665e8c867e]] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <302> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <Moved Temporarily> >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKdaff.8f25665e8c867e73b07da3cb1f702171.0>; state=9 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-8173-1-0>; state=16 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=3 >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069>] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> >  1(7698) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - reply - call-id: [1-8173(a)10.100.10.67] - cseq: > [1 INVITE] >  1(7698) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7fe2c208a768) id=3 global id=2 T start=0xffffffffffffffff >  1(7698) DEBUG: tm [t_lookup.c:897]: t_reply_matching(): > t_reply_matching: hash 65453 label 0 branch 0 >  1(7698) DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply > (0x7fe2c208a768) matched an active transaction (T=0x7fe2bd0c76d8)! >  1(7698) DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg > (0x7fe2c208a768) id=3 global id=3 T end=0x7fe2bd0c76d8 >  1(7698) DEBUG: tm [t_reply.c:2209]: reply_received(): org. status > uas=100, uac[0]=100 local=0 is_invite=1) >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=63 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header >  1(7698) INFO: <script>: LAL > {"sdp_data":"3466666666","sdp_data_2":null,"nrn":null} > >  1(7698) DEBUG: tm [t_reply.c:1265]: t_should_relay_response(): > ->>>>>>>>> T_code=100, new_code=302 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <302> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <Moved Temporarily> >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKdaff.8f25665e8c867e73b07da3cb1f702171.0>; state=9 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-8173-1-0>; state=16 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=3 >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069>] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=63 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header >  1(7698) INFO: <script>: LOOOOOOOOL > {"sdp_data":"3466666666","sdp_data_2":null,"nrn":null} > >  1(7698) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7fe2bd0ca850) id=0 global id=0 T start=0x7fe2bd0c76d8 >  1(7698) DEBUG: tm [t_lookup.c:1091]: t_check_msg(): T > (0x7fe2bd0c76d8) already found for msg (0x7fe2bd0ca850)! >  1(7698) DEBUG: tmx [t_var.c:534]: pv_get_tm_reply_code(): reply code > is <302> >  1(7698) INFO: <script>: Call: 302 received, trying to load contacts >  1(7698) DEBUG: uac_redirect [rd_funcs.c:72]: get_redirect(): resume > branch=0 >  1(7698) DEBUG: uac_redirect [rd_funcs.c:79]: get_redirect(): checking > branch=0 (added=0) >  1(7698) DEBUG: uac_redirect [rd_funcs.c:83]: get_redirect(): branch=0 > is a redirect (added=0) >  1(7698) DEBUG: uac_redirect [rd_funcs.c:159]: sort_contacts(): > sort_contacts: <sip:34666988297@10.100.10.67:5060> q=10 >  1(7698) DEBUG: uac_redirect [rd_funcs.c:295]: shmcontact2dset(): > adding contact <sip:34666988297@10.100.10.67:5060> >  1(7698) DEBUG: <core> [sruid.c:183]: sruid_next(): new sruid is > [rdir-5be42212-1e12-1] (1 / 20) >  1(7698) DEBUG: tm [t_serial.c:191]: ki_t_load_contacts(): nr_branches > is 1 >  1(7698) DEBUG: tm [t_serial.c:194]: ki_t_load_contacts(): nothing to > do - only one contact! >  1(7698) INFO: <script>: LEL >  1(7698) DEBUG: <core> [core/msg_translator.c:159]: > check_via_address(): (10.100.10.67, 10.100.10.67, 0) >  1(7698) INFO: <script>: hereeeeeeeeeee >  1(7698) DEBUG: tm [t_reply.c:1788]: relay_reply(): branch=0, save=0, > relay=-1 icode=0 >  1(7698) DEBUG: <core> [core/receive.c:362]: receive_msg(): > reply-route executed in: 581 usec >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) >  1(7698) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up >  1(7698) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/397) [[SIP/2.0 100 Trying 0D  0A Via: > SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKdaff.8f25665e8c867e73b07da3cb1]] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <100> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <Trying> >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKdaff.8f25665e8c867e73b07da3cb1f702171.1>; state=9 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-8173-1-0>; state=16 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=10 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [44]; uri=[sip:34606147628@10.100.10.67:5069] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069> > ] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> >  1(7698) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - reply - call-id: [1-8173(a)10.100.10.67] - cseq: > [1 INVITE] >  1(7698) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7fe2c208a768) id=4 global id=3 T start=0xffffffffffffffff >  1(7698) DEBUG: tm [t_lookup.c:897]: t_reply_matching(): > t_reply_matching: hash 65453 label 0 branch 1 >  1(7698) DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply > (0x7fe2c208a768) matched an active transaction (T=0x7fe2bd0c76d8)! >  1(7698) DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg > (0x7fe2c208a768) id=4 global id=4 T end=0x7fe2bd0c76d8 >  1(7698) DEBUG: tm [t_reply.c:2209]: reply_received(): org. status > uas=100, uac[1]=0 local=0 is_invite=1) >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=0 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header >  1(7698) INFO: <script>: LAL >  1(7698) DEBUG: tm [t_reply.c:1265]: t_should_relay_response(): > ->>>>>>>>> T_code=100, new_code=100 >  1(7698) DEBUG: tm [t_reply.c:1788]: relay_reply(): branch=1, save=0, > relay=-1 icode=0 >  1(7698) DEBUG: <core> [core/receive.c:362]: receive_msg(): > reply-route executed in: 38 usec >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) >  1(7698) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up >  1(7698) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/482) [[SIP/2.0 503 Service > Unavailable 0D  0A Via: SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKdaff.8f25665e8c86]] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <503> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <Service Unavailable> >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKdaff.8f25665e8c867e73b07da3cb1f702171.1>; state=9 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-8173-1-0>; state=16 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=3 >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069>] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> >  1(7698) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - reply - call-id: [1-8173(a)10.100.10.67] - cseq: > [1 INVITE] >  1(7698) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7fe2c208a768) id=5 global id=4 T start=0xffffffffffffffff >  1(7698) DEBUG: tm [t_lookup.c:897]: t_reply_matching(): > t_reply_matching: hash 65453 label 0 branch 1 >  1(7698) DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply > (0x7fe2c208a768) matched an active transaction (T=0x7fe2bd0c76d8)! >  1(7698) DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg > (0x7fe2c208a768) id=5 global id=5 T end=0x7fe2bd0c76d8 >  1(7698) DEBUG: tm [t_reply.c:2209]: reply_received(): org. status > uas=100, uac[1]=100 local=0 is_invite=1) >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=64 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header >  1(7698) INFO: <script>: LAL > {"sdp_data":"34619796636","sdp_data_2":null,"nrn":null} > >  1(7698) DEBUG: tm [t_reply.c:1265]: t_should_relay_response(): > ->>>>>>>>> T_code=100, new_code=503 >  1(7698) INFO: <script>: LOOOOOOOOL > {"sdp_data":"3466666666","sdp_data_2":null,"nrn":null} > >  1(7698) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7fe2bd0cbb88) id=0 global id=0 T start=0x7fe2bd0c76d8 >  1(7698) DEBUG: tm [t_lookup.c:1091]: t_check_msg(): T > (0x7fe2bd0c76d8) already found for msg (0x7fe2bd0cbb88)! >  1(7698) DEBUG: tmx [t_var.c:534]: pv_get_tm_reply_code(): reply code > is <503> >  1(7698) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7fe2bd0cbb88) id=0 global id=0 T start=0x7fe2bd0c76d8 >  1(7698) DEBUG: tm [t_lookup.c:1091]: t_check_msg(): T > (0x7fe2bd0c76d8) already found for msg (0x7fe2bd0cbb88)! >  1(7698) DEBUG: tmx [t_var.c:534]: pv_get_tm_reply_code(): reply code > is <503> >  1(7698) INFO: <script>: LEL >  1(7698) DEBUG: <core> [core/msg_translator.c:159]: > check_via_address(): (10.100.10.67, 10.100.10.67, 0) >  1(7698) INFO: <script>: hereeeeeeeeeee >  1(7698) DEBUG: tm [t_reply.c:1788]: relay_reply(): branch=1, save=0, > relay=-1 icode=0 >  1(7698) DEBUG: <core> [core/receive.c:362]: receive_msg(): > reply-route executed in: 188 usec >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) >  1(7698) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up >  1(7698) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/404) [[SIP/2.0 180 Ringing 0D  0A > Via: SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKdaff.8f25665e8c867e73b07da3cb]] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <180> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <Ringing> >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKdaff.8f25665e8c867e73b07da3cb1f702171.2>; state=9 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-8173-1-0>; state=16 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=3 >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069>] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> >  1(7698) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - reply - call-id: [1-8173(a)10.100.10.67] - cseq: > [1 INVITE] >  1(7698) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7fe2c208a768) id=6 global id=5 T start=0xffffffffffffffff >  1(7698) DEBUG: tm [t_lookup.c:897]: t_reply_matching(): > t_reply_matching: hash 65453 label 0 branch 2 >  1(7698) DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply > (0x7fe2c208a768) matched an active transaction (T=0x7fe2bd0c76d8)! >  1(7698) DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg > (0x7fe2c208a768) id=6 global id=6 T end=0x7fe2bd0c76d8 >  1(7698) DEBUG: tm [t_reply.c:2209]: reply_received(): org. status > uas=100, uac[2]=0 local=0 is_invite=1) >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=0 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header >  1(7698) INFO: <script>: LAL >  1(7698) DEBUG: tm [t_reply.c:1265]: t_should_relay_response(): > ->>>>>>>>> T_code=100, new_code=180 >  1(7698) DEBUG: tm [t_reply.c:1788]: relay_reply(): branch=2, save=0, > relay=2 icode=0 >  1(7698) DEBUG: <core> [core/msg_translator.c:2270]: > generate_res_buf_from_sip_res(): old size: 404, new size: 318 >  1(7698) DEBUG: <core> [core/msg_translator.c:2288]: > generate_res_buf_from_sip_res(): copied size: orig:112, new: 26, rest: > 292 msg= > SIP/2.0 180 Ringing > Via: SIP/2.0/UDP 10.100.10.67:5061;branch=z9hG4bK-8173-1-0 > From: "BTS" <sip:34917019888@10.100.10.67:5061>;tag=8173SIPpTag001 > To: "Javi" <sip:34606147628@10.100.10.67:5069>;tag=3 > Call-ID: 1-8173(a)10.100.10.67 > CSeq: 1 INVITE > Contact: <sip:10.100.10.67:5060;transport=UDP> > Content-Length: 0 > > >  1(7698) DEBUG: <core> [core/receive.c:362]: receive_msg(): > reply-route executed in: 93 usec >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) >  1(7698) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up >  1(7698) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/595) [[SIP/2.0 200 OK 0D  0A Via: > SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKdaff.8f25665e8c867e73b07da3cb1f702]] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <200> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <OK> >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKdaff.8f25665e8c867e73b07da3cb1f702171.2>; state=9 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-8173-1-0>; state=16 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=3 >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Javi" <sip:34606147628@10.100.10.67:5069>] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <INVITE> >  1(7698) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - reply - call-id: [1-8173(a)10.100.10.67] - cseq: > [1 INVITE] >  1(7698) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7fe2c208a768) id=7 global id=6 T start=0xffffffffffffffff >  1(7698) DEBUG: tm [t_lookup.c:897]: t_reply_matching(): > t_reply_matching: hash 65453 label 0 branch 2 >  1(7698) DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply > (0x7fe2c208a768) matched an active transaction (T=0x7fe2bd0c76d8)! >  1(7698) DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg > (0x7fe2c208a768) id=7 global id=7 T end=0x7fe2bd0c76d8 >  1(7698) DEBUG: tm [t_reply.c:2209]: reply_received(): org. status > uas=180, uac[2]=180 local=0 is_invite=1) >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=161 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header >  1(7698) INFO: <script>: LAL v=0 > o=user1 53655765 2353687637 IN IP4 10.100.10.67 > s=- > c=IN IP4 10.100.10.67 > t=0 0 > m=audio 6000 RTP/AVP 0 18 > a=rtpmap:0 PCMU/8000 > a=rtpmap:18 G729/8000 > >  1(7698) DEBUG: tm [t_reply.c:1265]: t_should_relay_response(): > ->>>>>>>>> T_code=180, new_code=200 >  1(7698) DEBUG: tm [t_reply.c:1788]: relay_reply(): branch=2, save=0, > relay=2 icode=0 >  1(7698) DEBUG: <core> [core/msg_translator.c:2270]: > generate_res_buf_from_sip_res(): old size: 595, new size: 509 >  1(7698) DEBUG: <core> [core/msg_translator.c:2288]: > generate_res_buf_from_sip_res(): copied size: orig:107, new: 21, rest: > 488 msg= > SIP/2.0 200 OK > Via: SIP/2.0/UDP 10.100.10.67:5061;branch=z9hG4bK-8173-1-0 > From: "BTS" <sip:34917019888@10.100.10.67:5061>;tag=8173SIPpTag001 > To: "Javi" <sip:34606147628@10.100.10.67:5069>;tag=3 > Call-ID: 1-8173(a)10.100.10.67 > CSeq: 1 INVITE > Contact: <sip:10.100.10.67:5060;transport=UDP> > Content-Type: application/sdp > Content-Length:   161 > > v=0 > o=user1 53655765 2353687637 IN IP4 10.100.10.67 > s=- > c=IN IP4 10.100.10.67 > t=0 0 > m=audio 6000 RTP/AVP 0 18 > a=rtpmap:0 PCMU/8000 > a=rtpmap:18 G729/8000 > >  1(7698) DEBUG: tm [t_reply.c:1631]: cleanup_uac_timers(): RETR/FR > timers reset >  1(7698) DEBUG: <core> [core/receive.c:362]: receive_msg(): > reply-route executed in: 185 usec >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) >  1(7698) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up >  1(7698) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/323) [[ACK > sip:34606147628@10.100.10.67:5060 SIP/2.0 0D  0A Via: SIP/2.0/UDP > 10.100.10.67:5061;branch=z9hG4bK-817]] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): > SIP Request: >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg(): > method:  <ACK> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg(): > uri:     <sip:34606147628@10.100.10.67:5060> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): > version: <SIP/2.0> >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-8173-1-0>; state=16 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=3 >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Test" <sip:34606147628@10.100.10.67:5069>] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <1> <ACK> >  1(7698) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - request - call-id: [1-8173(a)10.100.10.67] - > cseq: [1 ACK] >  1(7698) DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing > to run routing scripts... >  1(7698) DEBUG: sl [sl_funcs.c:387]: sl_filter_ACK(): too late to be a > local ACK! >  1(7698) INFO: <script>: hereeeeeeeeeee >  1(7698) DEBUG: tm [t_lookup.c:1320]: t_newtran(): msg id=8 , global > msg id=7 , T on entrance=0xffffffffffffffff >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=0 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header >  1(7698) DEBUG: tm [t_lookup.c:477]: t_lookup_request(): start > searching: hash=65453, isACK=1 >  1(7698) DEBUG: tm [t_lookup.c:435]: matching_3261(): RFC3261 > transaction matching failed >  1(7698) DEBUG: tm [t_lookup.c:659]: t_lookup_request(): no > transaction found >  1(7698) DEBUG: tm [t_funcs.c:284]: t_relay_to(): forwarding ACK > statelessly >  1(7698) DEBUG: <core> [core/md5utils.c:67]: MD5StringArray(): MD5 > calculated: 8f25665e8c867e73b07da3cb1f702171 >  1(7698) DEBUG: <core> [core/msg_translator.c:159]: > check_via_address(): (10.100.10.67, 10.100.10.67, 0) >  1(7698) DEBUG: <core> [core/forward.c:557]: forward_request(): Sending: > ACK sip:34606147628@10.100.10.67:5060 SIP/2.0 > Via: SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKdaff.8f25665e8c867e73b07da3cb1f702171.0 > Via: SIP/2.0/UDP 10.100.10.67:5061;branch=z9hG4bK-8173-1-0 > From: "BTS" <sip:34917019888@10.100.10.67:5061>;tag=8173SIPpTag001 > To: "Test" <sip:34606147628@10.100.10.67:5069>;tag=3 > Call-ID: 1-8173(a)10.100.10.67 > CSeq: 1 ACK > Max-Forwards: 70 > Subject: 1 > Content-Length: 0 > > . >  1(7698) DEBUG: <core> [core/forward.c:559]: forward_request(): orig. > len=323, new_len=414, proto=1 >  1(7698) INFO: <script>: hereeeeeeeeeee >  1(7698) DEBUG: <core> [core/receive.c:289]: receive_msg(): > request-route executed in: 109 usec >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) >  1(7698) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up >  1(7698) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/338) [[BYE > sip:34606147628@10.100.10.67:5060 SIP/2.0 0D  0A Via: SIP/2.0/UDP > 10.100.10.67:5061;branch=z9hG4bK-817]] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): > SIP Request: >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg(): > method:  <BYE> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg(): > uri:     <sip:34606147628@10.100.10.67:5060> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): > version: <SIP/2.0> >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-8173-1-8>; state=16 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=3 >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Test" <sip:34606147628@10.100.10.67:5069>] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <2> <BYE> >  1(7698) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - request - call-id: [1-8173(a)10.100.10.67] - > cseq: [2 BYE] >  1(7698) DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing > to run routing scripts... >  1(7698) INFO: <script>: hereeeeeeeeeee >  1(7698) DEBUG: tm [t_lookup.c:1320]: t_newtran(): msg id=9 , global > msg id=8 , T on entrance=(nil) >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:183]: > get_hdr_field(): content_length=0 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): > found end of header >  1(7698) DEBUG: tm [t_lookup.c:477]: t_lookup_request(): start > searching: hash=65450, isACK=0 >  1(7698) DEBUG: tm [t_lookup.c:435]: matching_3261(): RFC3261 > transaction matching failed >  1(7698) DEBUG: tm [t_lookup.c:659]: t_lookup_request(): no > transaction found >  1(7698) DEBUG: <core> [core/md5utils.c:67]: MD5StringArray(): MD5 > calculated: 72541dabc2c0991bc1a987a58afe468a >  1(7698) INFO: <script>: LEL >  1(7698) DEBUG: <core> [core/msg_translator.c:159]: > check_via_address(): (10.100.10.67, 10.100.10.67, 0) >  1(7698) INFO: <script>: hereeeeeeeeeee >  1(7698) DEBUG: tm [t_funcs.c:372]: t_relay_to(): new transaction > forwarded >  1(7698) DEBUG: <core> [core/receive.c:289]: receive_msg(): > request-route executed in: 223 usec >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) >  1(7698) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up >  1(7698) DEBUG: <core> [core/udp_server.c:492]: udp_rcv_loop(): > received on udp socket: (106/100/396) [[SIP/2.0 200 OK 0D  0A Via: > SIP/2.0/UDP > 52.88.180.226:5069;branch=z9hG4bKaaff.72541dabc2c0991bc1a987a58afe4]] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): > SIP Reply  (status): >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg(): > version: <SIP/2.0> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg(): > status:  <200> >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg(): > reason:  <OK> >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bKaaff.72541dabc2c0991bc1a987a58afe468a.0>; state=9 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2681]: parse_via(): > parsing via: next via >  1(7698) DEBUG: <core> [core/parser/parse_via.c:1303]: > parse_via_param(): Found param type 232, <branch> = > <z9hG4bK-8173-1-8>; state=16 >  1(7698) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): > end of header reached, state=5 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:492]: > parse_headers(): Via found, flags=2 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:494]: > parse_headers(): this is the first via >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: > parse_to_param(): add param: tag=3 >  1(7698) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: > parse_addr_spec(): end of header reached, state=29 >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:171]: > get_hdr_field(): <To> [50]; uri=[sip:34606147628@10.100.10.67:5069] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]: > get_hdr_field(): to body ["Test" <sip:34606147628@10.100.10.67:5069>] >  1(7698) DEBUG: <core> [core/parser/msg_parser.c:152]: > get_hdr_field(): cseq <CSeq>: <2> <BYE> >  1(7698) DEBUG: <core> [core/receive.c:205]: receive_msg(): --- > received sip message - reply - call-id: [1-8173(a)10.100.10.67] - cseq: > [2 BYE] >  1(7698) DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg > (0x7fe2c208a768) id=10 global id=9 T start=0xffffffffffffffff >  1(7698) DEBUG: tm [t_lookup.c:897]: t_reply_matching(): > t_reply_matching: hash 65450 label 0 branch 0 >  1(7698) DEBUG: tm [t_lookup.c:951]: t_reply_matching(): reply > (0x7fe2c208a768) matched an active transaction (T=0x7fe2bd0ccd40)! >  1(7698) DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg > (0x7fe2c208a768) id=10 global id=10 T end=0x7fe2bd0ccd40 >  1(7698) DEBUG: tm [t_reply.c:2209]: reply_received(): org. status > uas=0, uac[0]=0 local=0 is_invite=0) >  1(7698) DEBUG: tm [t_reply.c:1265]: t_should_relay_response(): > ->>>>>>>>> T_code=0, new_code=200 >  1(7698) DEBUG: tm [t_reply.c:1788]: relay_reply(): branch=0, save=0, > relay=0 icode=0 >  1(7698) DEBUG: <core> [core/msg_translator.c:2270]: > generate_res_buf_from_sip_res(): old size: 396, new size: 310 >  1(7698) DEBUG: <core> [core/msg_translator.c:2288]: > generate_res_buf_from_sip_res(): copied size: orig:107, new: 21, rest: > 289 msg= > SIP/2.0 200 OK > Via: SIP/2.0/UDP 10.100.10.67:5061;branch=z9hG4bK-8173-1-8 > From: "BTS" <sip:34917019888@10.100.10.67:5061>;tag=8173SIPpTag001 > To: "Test" <sip:34606147628@10.100.10.67:5069>;tag=3 > Call-ID: 1-8173(a)10.100.10.67 > CSeq: 2 BYE > Contact: <sip:10.100.10.67:5060;transport=UDP> > Content-Length: 0 > > >  1(7698) DEBUG: tm [t_reply.c:1631]: cleanup_uac_timers(): RETR/FR > timers reset >  1(7698) DEBUG: <core> [core/receive.c:362]: receive_msg(): > reply-route executed in: 74 usec >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): > destroying list (nil) >  1(7698) DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): > destroying xavp list (nil) >  1(7698) DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up >  3(7700) DEBUG: tm [h_table.c:129]: free_cell_helper(): freeing > transaction 0x7fe2bd0c76d8 from timer.c:654 >  3(7700) DEBUG: tm [h_table.c:129]: free_cell_helper(): freeing > transaction 0x7fe2bd0ccd40 from timer.c:654 > > > > _______________________________________________ > Kamailio (SER) - Users Mailing List > sr-users(a)lists.kamailio.org > https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users