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

Alex Balashov abalashov at evaristesys.com
Thu Nov 8 17:40:45 CET 2018


Hi,

Unlike onreply_routes, failure_routes do not directly correspond to a
discrete SIP reply, because a SIP reply is only one of the things that
can cause a failure_route to trigger. Other possibilities include a
branch timeout, and possibly some other errors of an internal nature. 

In other words, a failure_route is a bit more abstract than an
onreply_route. So, in order to get the message attributes of a reply,
you need to specify exactly which reply you want to access; this is
usually the winning reply of the last branch attempted.

Or, to be more concrete and less pedagogic, try: $T_rpl($rb)

https://www.kamailio.org/wiki/cookbooks/5.1.x/pseudovariables#t_rpl_pv

-- Alex

On Thu, Nov 08, 2018 at 01:22:14PM +0100, 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

-- 
Alex Balashov | Principal | Evariste Systems LLC

Tel: +1-706-510-6800 / +1-800-250-5920 (toll-free) 
Web: http://www.evaristesys.com/, http://www.csrpswitch.com/



More information about the sr-users mailing list