Hello sorry for the delay Yes Daniel we see the incorrect value using $T_rpl($rb) on the failure_route. Alex we actually see the issue when using the same PID for processing all the responses of the different branches. Let me test the patch and i will let you know Daniel best regards david On 13/11/18 9:07, Daniel-Constantin Mierla wrote: > 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