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

David Escartín descartin at bts.io
Tue Nov 13 13:06:24 CET 2018


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/e2ca5516ae086cf33c61dbb9e653a5484cca2074
>
> 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 at 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 at 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 at 10.100.10.67:5069]
>> 11(8358) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 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 at 10.100.10.67:5069]
>> 11(8358) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 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 at 10.100.10.67:5069]
>> 13(8360) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 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 at 10.100.10.67:5069]
>> 13(8360) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 10.100.10.67:5060> q=10
>> 13(8360) DEBUG: uac_redirect [rd_funcs.c:295]: shmcontact2dset():
>> adding contact <sip:34666988297 at 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 at 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 at 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 at 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 at 10.100.10.67:5069]
>> 15(8362) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 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 at 10.100.10.67:5069]
>> 15(8362) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 10.100.10.67:5069]
>> 15(8362) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 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 at 10.100.10.67:5061>;tag=9680SIPpTag001
>> To: "Javi" <sip:34606147628 at 10.100.10.67:5069>;tag=5
>> Call-ID: 1-9680 at 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 at 10.100.10.67:5069]
>>   6(8353) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 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 at 10.100.10.67:5061>;tag=9680SIPpTag001
>> To: "Javi" <sip:34606147628 at 10.100.10.67:5069>;tag=5
>> Call-ID: 1-9680 at 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 at 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 at 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 at 10.100.10.67:5069]
>>   6(8353) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Test" <sip:34606147628 at 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 at 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 at 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 at 10.100.10.67:5061>;tag=9680SIPpTag001
>> To: "Test" <sip:34606147628 at 10.100.10.67:5069>;tag=5
>> Call-ID: 1-9680 at 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 at 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 at 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 at 10.100.10.67:5069]
>>   3(8350) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Test" <sip:34606147628 at 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 at 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 at 10.100.10.67:5069]
>>   7(8354) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Test" <sip:34606147628 at 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 at 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 at 10.100.10.67:5061>;tag=9680SIPpTag001
>> To: "Test" <sip:34606147628 at 10.100.10.67:5069>;tag=5
>> Call-ID: 1-9680 at 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 at 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 at 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 at 10.100.10.67:5069]
>>   1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 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 at 10.100.10.67:5069]
>>   1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 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 at 10.100.10.67:5069]
>>   1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 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 at 10.100.10.67:5069]
>>   1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 10.100.10.67:5060> q=10
>>   1(7698) DEBUG: uac_redirect [rd_funcs.c:295]: shmcontact2dset():
>> adding contact <sip:34666988297 at 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 at 10.100.10.67:5069]
>>   1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 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 at 10.100.10.67:5069]
>>   1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 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 at 10.100.10.67:5069]
>>   1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 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 at 10.100.10.67:5061>;tag=8173SIPpTag001
>> To: "Javi" <sip:34606147628 at 10.100.10.67:5069>;tag=3
>> Call-ID: 1-8173 at 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 at 10.100.10.67:5069]
>>   1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Javi" <sip:34606147628 at 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 at 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 at 10.100.10.67:5061>;tag=8173SIPpTag001
>> To: "Javi" <sip:34606147628 at 10.100.10.67:5069>;tag=3
>> Call-ID: 1-8173 at 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 at 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 at 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 at 10.100.10.67:5069]
>>   1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Test" <sip:34606147628 at 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 at 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 at 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 at 10.100.10.67:5061>;tag=8173SIPpTag001
>> To: "Test" <sip:34606147628 at 10.100.10.67:5069>;tag=3
>> Call-ID: 1-8173 at 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 at 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 at 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 at 10.100.10.67:5069]
>>   1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Test" <sip:34606147628 at 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 at 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 at 10.100.10.67:5069]
>>   1(7698) DEBUG: <core> [core/parser/msg_parser.c:172]:
>> get_hdr_field(): to body ["Test" <sip:34606147628 at 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 at 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 at 10.100.10.67:5061>;tag=8173SIPpTag001
>> To: "Test" <sip:34606147628 at 10.100.10.67:5069>;tag=3
>> Call-ID: 1-8173 at 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 at lists.kamailio.org
>> https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users



More information about the sr-users mailing list