sr-users

sr-users@lists.kamailio.org

42 participants
37519 discussions

mod siptrace - option ping from nathelper do not get duplicated
by Roman Dissauer 14 Nov '18

14 Nov '18

Hi, we are using kamailio 5.1 with siptrace module in trace_mode on. Everything works perfect except that option pings from nathelper module do not get duplicated. Is there a reason for that? Thanks, Roman

2 1

Core dump on diameter CCR request
by Venkatesh Macha 14 Nov '18

14 Nov '18

Hi all, I am trying to implement Diameter charging with Kamailio. I am following below tutorial https://www.kamailio.org/events/2016-KamailioWorld/Day2/15-Carsten.Bock-Dia… But whenever I try to do the Ro_CCR from the INVITE block, Kamailio is crashing and generating the core dump. I am new to diameter. I might be doing something wrong here. please someone help me here. Please find the *diameter.xml* and *Diameter_core_dump_full_debug.txt* file. diameter.xml <http://sip-router.1086192.n5.nabble.com/file/t6374/diameter.xml> Diameter_core_dump_full_Debug.txt <http://sip-router.1086192.n5.nabble.com/file/t6374/Diameter_core_dump_full_…> Here is my kamailio.cfg : loadmodule "cdp" loadmodule "cdp_avp" loadmodule "ims_charging" loadmodule "ims_dialog" modparam("cdp","config_file","/etc/kamailio/diameter.xml") modparam("cdp", "debug_heavy", 1) # ----- ims_diameter_ro params ----- #modparam("ims_charging", "single_ro_session_per_dialog", 1) modparam("ims_charging", "origin_host", "10.195.0.38"); modparam("ims_charging", "origin_realm", "10.195.0.38"); modparam("ims_charging", "destination_realm", "mydomain.com"); modparam("ims_charging","interim_update_credits",30); modparam("ims_charging","timer_buffer",5); # -- ims_dialog params -- modparam("ims_dialog", "dlg_flag", 8) While starting the kamailio, i am getting following errors: Nov 11 11:40:03 ip-10-195-0-38 /usr/local/sbin/kamailio[25653]: ERROR: cdp [peerstatemachine.c:675]: add_peer_application(): Too many applications for this peer (max 0), not adding Application 4:0. Before crashing kamailio showing following error: Nov 11 11:39:49 ip-10-195-0-38 /usr/local/sbin/kamailio[25571]: INFO: {1 18325 INVITE Nf6-dl2WeXF.LJhXotiRsuMhijsNx45o} <script>: Entered into INVITE Block Nov 11 11:39:49 ip-10-195-0-38 /usr/local/sbin/kamailio[25571]: ERROR: {1 18325 INVITE Nf6-dl2WeXF.LJhXotiRsuMhijsNx45o} ims_dialog [dlg_handlers.c:264]: dlg_get_iuid_shm_clone(): ***** Requesting 8 Nov 11 11:39:49 ip-10-195-0-38 /usr/local/sbin/kamailio[25571]: CRITICAL: {1 18325 INVITE Nf6-dl2WeXF.LJhXotiRsuMhijsNx45o} <core> [core/mem/q_malloc.c:144]: qm_debug_check_frag(): BUG: qm: prev. fragm. tail overwritten(0, abcdefed)[0x7f467d438768:0x7f467d4387a0]! Memory allocator was called from cdp: diameter_avp.c:157. Fragment marked by cdp: peerstatemachine.c:602. Exec from core/mem/q_malloc.c:384. Nov 11 11:39:49 ip-10-195-0-38 /usr/local/sbin/kamailio[25599]: CRITICAL: <core> [core/pass_fd.c:277]: receive_fd(): EOF on 16 Nov 11 11:39:52 ip-10-195-0-38 /usr/local/sbin/kamailio[25567]: ALERT: <core> [main.c:740]: handle_sigs(): child process 25571 exited by a signal 6 Nov 11 11:39:52 ip-10-195-0-38 /usr/local/sbin/kamailio[25567]: ALERT: <core> [main.c:743]: handle_sigs(): core was generated Nov 11 11:39:52 ip-10-195-0-38 /usr/local/sbin/kamailio[25567]: INFO: <core> [main.c:766]: handle_sigs(): terminating due to SIGCHLD Thanks you in Advance, Venkey -- Sent from: http://sip-router.1086192.n5.nabble.com/Users-f3.html

4 9

WebRTC video call terminated after ~30 seconds
by Mathias Brodala - Pagemachine AG 14 Nov '18

14 Nov '18

Hi, I am currently testing a setup to do video calls via WebRTC and have set up Kamailio as SIP server. So far the calls are working fine, but after around 30 seconds the calls are terminated. I can reproduce this easily both with the JsSIP demo [0] as well as the SIPjs demo [1]. The browser console using JsSIP log [2] shows me this: > JsSIP:WebSocketInterface WebSocket wss://sip.example.org closed +60s > jssip-3.2.10.js:23490 JsSIP:WebSocketInterface WebSocket abrupt disconnection +1ms Please also have a look at my kamailio.cfg [3]. I tried to follow the docs of the websocket module [4] as close as possible to get everything up and running. Kamailio is currently running on a private DigitalOcean droplet and I already tried to disable all firewall rules without change. I also asked the DO staff if something could lead to UDP packets getting dropped after some time but I was told that there is no such logic in the DO network. Please let me know if you can find anything unusual which could cause this behavior or if you need more information. Thank you, Mathias Brodala [0] https://tryit.jssip.net/ [1] https://sipjs.com/demo-phone/ [2] https://gist.github.com/mbrodala/0f81aaa174be87096cf20502633f3ac3 [3] https://gist.github.com/mbrodala/066faa455da46362dab3dd5326ba8ad1 [4] https://www.kamailio.org/docs/modules/5.1.x/modules/websocket.html -- Dipl.-Inf. (FH) Mathias Brodala Tel.: 069.260.99.70.45 Fax: .31 mbrodala(a)pagemachine.de <https://www.pagemachine.de/> Pagemachine AG Solmsstraße 6a, 60486 Frankfurt am Main <https://maps.google.com/?q=Solmsstra%C3%9Fe+6a,+60486+Frankfurt+am+Main&ent…> Vorstand: Volker Neuenhaus, Stefan Schütt, Miklos Weiszhaupt Vorsitzender des Aufsichtsrats: Holger Kleinschmidt Registergericht: Amtsgericht Frankfurt Registernummer: HRB 56436 Umsatzsteuer-ID: DE226286966 <https://www.kununu.com/de/pagemachine> <https://www.kununu.com/de/pagemachine> <http://www.frankfurt-main.ihk.de/> <https://typo3.com/>

2 1

topos without db?
by Giuseppe Pandolfi 13 Nov '18

13 Nov '18

Hi, Is it possible using topos module without db support? I'm trying to use topos module with sqlite db backend, but I have any concurrency problems during write procedure (I use WALL pragma). When execute speed calls traffic sqlite emits an error trace telling it's locked. Is it possible to use a sort of hash tabel to save topos informations and don't use the db? Best regards, Giuseppe

5 4

variable $rb not updated on failure route after a 302 on the same PID
by David Escartín 13 Nov '18

13 Nov '18

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

3 5

dlflags interface deprecated
by AL S 13 Nov '18

13 Nov '18

Hi, We are running the old release of Kamailio 3.3.7 and getting the following notice log: kamailio: NOTICE: <core> [sr_module.c:627]: /usr/local/lib64/kamailio/modules_k/perl.so: exports dlflags interface is deprecated and it will not be supported in newer versions; consider using mod_register() instead Is there a way to fix this issue on the same Kamailio3.3.7 code? Thanks, AL

3 2

Execution Sequence of the Request_Route
by Abdulaziz Alghosh 13 Nov '18

13 Nov '18

Hello, I migrated from Kamailio 3.0.3 to Kamailio 5.1.4. and have two questions about the execution sequence of the Request_Route. The following condition trys to authenticate the first INVITE or REGISTER request which normally does not have the Authorization Header: route (auth) .. .. .. route[auth]{ if ( !proxy_authorize("myrealm", "subscriber") ) { proxy_challenge("myrealm", "0"); sl_reply_error(); exit; }; return; } For sure the Return Code of "proxy_authorize" will not be one (1) at the beginneing, so the proxy_challenge() will generate the "407 Proxy Authentication Required" request and the agent will send the INVITE or the REGISTER again with the Authorization-Header and the call or the registration attempt succeeds. During my observation to the new returned codes (values) of both proxy_authorize() and proxy_challenge() in Kamailio 5.1.4, I noticed the following differnet execution sequence of this "Request_Route". at Kamailio 3.0.3, and exactly after the proxy_challenge("myrealm", "0") command was executed, no more commands were excuted as if it jumped out of the if statement, and the proxy was wating for the new INVITE or REGISTER. Hence the sl_reply_error() did not send any error reply. I wrote several logging commad before and after the proxy_challenge("myrealm", "0"), so I am pretty sure that the proxy_challenge("myrealm", "0") is last excuted command to be excuted here. at Kamailio 5.1.4, the behaviour was more logical and the proxy executes commands which come under the proxy_challenge("myrealm", "0") like logging commands or sl_reply_error() which generates usually the error reply " 500 I'm terribly sorry, server error occurred". My first question is: May somebody explain this different behavior? My second Question: assume that the agent will send a wrong credentials and response, does the proxy_challenge("myrealm", "0") function terminate this dialouge with 401 Unauthorized Error or I must add the following "if condition" afterwards: if ( !proxy_authorize("myrealm", "subscriber") ) { proxy_challenge("myrealm", "0"); if (!$rc){ sl_reply_error(); '#### or I will be more specific sl_send_reply (code, reason) } exit; }; Thanks and best regards Abdulaziz Alghosh

2 1

Redirects - are q values required to implement serial forking?
by Mike Montgomery 12 Nov '18

12 Nov '18

We have a situation where we get a redirect from a carrier with a list of carriers to send the transaction to in the contact header. None of the carriers in the contact header have q values assigned. We have implemented our redirect handling logic using the UAC_REDIRECT module (get_redirects()) with help from TM module (t-load_contacts(), t_next_contact()). (failure_route code is at bottom of this note) We find that when we receive a contact header with q values, we can launch requests serially using t_next_contact() and individually work through the contact list until we get a positive response. When we get a redirect with no q values in the contact header we find that all contacts get loaded and launched in parallel. Although not stated in the documentation, it appears that in order to implement serial contact redirect handling, q values must be present in the contact header. Based on this assumption, and knowing that the redirecting carrier cannot include q values, we have attempted to modify the contact header and find that we are unable to add q values to the contact header. We have attempted without success to use remove_hf("Contact”) followed by append_hf("Contact: $(avp(contact)) \r\n”); where $(avp(contact)) is the avp where we have rewritten the contact header to include q values. Any guidance on how to handle this issue is appreciated. _________________________________________________________- Our failure route code: if (t_check_status("3[0-9][0-9]")) { xlog("L_INFO", "----> REDIRECT Contact Header --> $T_rpl($ct) --- Method $rm --- From $T_req($fu) --- To $T_req($tu) --- Destination $T_req($du) \n"); get_redirects("*:*"); if (!t_load_contacts()) { xlog("L_INFO", "-t_load_contacts() FAILED /n"); }; xlog("L_INFO", "####->LOAD CONTACT LIST $xavp(tm_contacts[0]=>uri) \n"); if (t_next_contacts()) { xlog("L_INFO", "-t_next_contact() loaded successfully /n"); xlog("L_INFO", "####-> NEXT CONTACT LIST $xavp(tm_contacts[0]=>uri) \n"); }; t_on_failure("serial"); if(t_relay()){ xlog("L_INFO","----->Relayed in MANAGE_FAILURE --- Method $rm --- Contact Header $ct \n"); }; exit; } else { xlog("L_INFO","-----> NO REDIRECT --- Method $rm --- Contact Header $ct \n"); exit; } failure_route["serial"] { xlog ("L_INFO", "Entered failure_route(serial) /n"); if (t_check_status("3[0-9][0-9]")) { xlog("L_INFO", "----> DOUBLE REDIRECT Contact Header --> $T_rpl($ct) --- Method $rm --- From $T_req($fu) --- To $T_req($tu) --- Destination $T_req($du) \n"); $xavp(tm_contacts[*]) = $null; xlog("L_INFO", "XXX-> tm_contacts reset to Null $xavp(tm_contacts[0]=>uri)\n"); get_redirects("*:*"); if (!t_load_contacts()) { xlog("L_INFO", "-t_load_contacts() FAILED /n"); }; xlog("L_INFO", "####-> LOAD 2 CONTACT LIST $xavp(tm_contacts[0]=>uri) \n"); } if (!t_next_contacts()) { exit; } xlog("L_INFO", "-t_next_contact() loaded successfully /n"); xlog("L_INFO", "####-> NEXT CONTACT LIST $xavp(tm_contacts[0]=>uri) \n"); t_on_failure("serial"); if(t_relay()){ xlog("L_INFO","----->Relayed in failure_route(serial) --- Method $rm --- Contact Header $ct \n"); }; } Best Regards, Mike Montgomery Principal, Trusted Technical Services, Inc. o - 919 924 4703 x3000 m - 919 539 6133

2 1

Adding Perl Module to kamailio-5.1.6
by AL S 12 Nov '18

12 Nov '18

I am trying to install Perl module on Ubuntu 18.04 / Kamailio kamailio-5.1.6 and getting the following response: $ sudo apt-get install kamailio-perl-modules Reading package lists... Done Building dependency tree Reading state information... Done kamailio-perl-modules is already the newest version (5.1.2-1ubuntu2). You might want to run 'apt --fix-broken install' to correct these. The following packages have unmet dependencies: kamailio-perl-modules : Depends: kamailio (= 5.1.2-1ubuntu2) but it is not installable E: Unmet dependencies. Try 'apt --fix-broken install' with no packages (or specify a solution). Is there a better way to add perl module? PS: libperl-dev already installed. Thanks, AL

2 1

siptrace module doesn't close db connections
by Roman Dissauer 12 Nov '18

12 Nov '18

Hi, it seems that siptrace module doesn’t close db connections. I’m on Kamailio 5.1.4 from official debian stretch repository with postgresql db module enabled. siptrace config: modparam("siptrace", "db_url", DBURL) modparam("siptrace", "duplicate_uri", "sip:193.32.51.189:9060") modparam("siptrace", "hep_mode_on", 1) modparam("siptrace", "hep_version", 3) modparam("siptrace", "hep_capture_id", 1001) modparam("siptrace", "trace_mode", 1) Here you can see the open connections from the kamailio host: # select client_addr, state, query from pg_stat_activity where client_addr = '10.23.101.61'; client_addr | state | query --------------+-------+---------------------------------------------------------------- 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' 10.23.101.61 | idle | select table_version from version where table_name='sip_trace' (31 Zeilen) another example, other installation with same kamailio version 5.1.4: # select client_addr, state, query from pg_stat_activity where client_addr = '10.23.102.1'; client_addr | state | query -------------+-------+---------------------------------------------------------------- 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' 10.23.102.1 | idle | select table_version from version where table_name='sip_trace' (39 Zeilen) Thanks Roman

2 2

Jump to page:

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

2005

2004

2003

2002

sr-users