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