1(10362) DEBUG: [parser/msg_parser.c:190]: DEBUG: get_hdr_field: [70]; uri=[sip:alice2@open-ims.test] 1(10362) DEBUG: [parser/msg_parser.c:192]: DEBUG: to body [] 1(10362) DEBUG: [parser/msg_parser.c:170]: get_hdr_field: cseq : <82> 1(10362) DEBUG: tm [t_lookup.c:972]: DEBUG: t_reply_matching: hash 47799 label 2059816460 branch 0 1(10362) DEBUG: tm [t_lookup.c:1032]: DEBUG: t_reply_matching: reply matched (T=0x7f71ef920020)! 1(10362) DEBUG: tm [t_lookup.c:1164]: DEBUG: t_check_msg: msg id=3 global id=3 T end=0x7f71ef920020 1(10362) DEBUG: tm [t_reply.c:2085]: DEBUG: reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0) 1(10362) DEBUG: tm [t_reply.c:1207]: ->>>>>>>>> T_code=0, new_code=200 1(10362) DEBUG: tm [t_reply.c:1706]: DEBUG: relay_reply: branch=0, save=0, relay=0 1(10362) DEBUG: [parser/msg_parser.c:204]: DEBUG: get_hdr_body : content_length=0 1(10362) DEBUG: [parser/msg_parser.c:106]: found end of header 1(10362) DEBUG: [msg_translator.c:2008]: old size: 1103, new size: 1029 1(10362) DEBUG: [msg_translator.c:2026]: build_res_from_sip_res: copied size: orig:126, new: 52, rest: 977 msg= SIP/2.0 200 OK - SAR succesful and registrar saved Via: SIP/2.0/TCP 192.168.144.48;rport=33384;received=10.147.65.113;branch=z9hG4bK1792437 To: ;tag=a1b9ad4a2a4df0e5b663067884a87691-34b0 From: ;tag=bmlh23ps9e Call-ID: vn0p5v50ugskvfk612jbn9 CSeq: 82 REGISTER P-Associated-URI: Contact: ;expires=3600;pub-gruu="sip:alice2@open-ims.test;gr=urn:uuid:8f2b1620-007f-412b-ba54-811e999a3495" Path: Service-Route: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, PUBLISH, MESSAGE, INFO P-Charging-Function-Addresses: ccf=pri_ccf_address Server: Sip EXpress router (2.1.0-dev1 OpenIMSCore (x86_64/linux)) Content-Length: 0 Warning: 392 192.168.144.44:6060 "Noisy feedback tells: pid=3761 req_src_ip=192.168.144.44 req_src_port=5060 in_uri=sip:scscf.open-ims.test:6060 out_uri=sip:scscf.open-ims.test:6060 via_cnt==4" 1(10362) DEBUG: [mem/shm_mem.c:111]: WARNING:vqm_resize: resize(0) called 1(10362) DEBUG: websocket [ws_frame.c:641]: Tx message: SIP/2.0 200 OK - SAR succesful and registrar saved Via: SIP/2.0/TCP 192.168.144.48;rport=33384;received=10.147.65.113;branch=z9hG4bK1792437 To: ;tag=a1b9ad4a2a4df0e5b663067884a87691-34b0 From: ;tag=bmlh23ps9e Call-ID: vn0p5v50ugskvfk612jbn9 CSeq: 82 REGISTER P-Associated-URI: Contact: ;expires=3600;pub-gruu="sip:alice2@open-ims.test;gr=urn:uuid:8f2b1620-007f-412b-ba54-811e999a3495" Path: Service-Route: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, PUBLISH, MESSAGE, INFO P-Charging-Function-Addresses: ccf=pri_ccf_address Server: Sip EXpress router (2.1.0-dev1 OpenIMSCore (x86_64/linux)) Content-Length: 0 Warning: 392 192.168.144.44:6060 "Noisy feedback tells: pid=3761 req_src_ip=192.168.144.44 req_src_port=5060 in_uri=sip:scscf.open-ims.test:6060 out_uri=sip:scscf.open-ims.test:6060 via_cnt==4" 1(10362) DEBUG: websocket [ws_frame.c:130]: encoding WebSocket frame 1(10362) DEBUG: websocket [ws_frame.c:159]: supported non-control frame: 0x1 1(10362) DEBUG: [tcp_main.c:2333]: tcp_send: tcp connection found (0x7f71ef930d20), acquiring fd 1(10362) DEBUG: [tcp_main.c:2344]: tcp_send, c= 0x7f71ef930d20, n=16 14(10375) DEBUG: [tcp_main.c:3621]: handle_ser_child: read response= 7f71ef930d20, 2, fd -1 from 1 (10362) 1(10362) DEBUG: [tcp_main.c:2374]: tcp_send: after receive_fd: c= 0x7f71ef930d20 n=8 fd=8 1(10362) DEBUG: [tcp_main.c:2553]: tcp_send: sending... 1(10362) DEBUG: [tcp_main.c:2587]: tcp_send: after real write: c= 0x7f71ef930d20 n=1033 fd=8 1(10362) DEBUG: [tcp_main.c:2588]: tcp_send: buf= ?~SIP/2.0 200 OK - SAR succesful and registrar saved Via: SIP/2.0/TCP 192.168.144.48;rport=33384;received=10.147.65.113;branch=z9hG4bK1792437 To: ;tag=a1b9ad4a2a4df0e5b663067884a87691-34b0 From: ;tag=bmlh23ps9e Call-ID: vn0p5v50ugskvfk612jbn9 CSeq: 82 REGISTER P-Associated-URI: Contact: ;expires=3600;pub-gruu="sip:alice2@open-ims.test;gr=urn:uuid:8f2b1620-007f-412b-ba54-811e999a3495" Path: Service-Route: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, PUBLISH, MESSAGE, INFO P-Charging-Function-Addresses: ccf=pri_ccf_address Server: Sip EXpress router (2.1.0-dev1 OpenIMSCore (x86_64/linux)) Content-Length: 0 Warning: 392 192.168.144.44:6060 "Noisy feedback tells: pid=3761 req_src_ip=192.168.144.44 req_src_port=5060 in_uri=sip:scscf.open-ims.test:6060 out_uri=sip:scscf.open-ims.test:6060 via_cnt==4" 1(10362) DEBUG: tm [t_reply.c:1547]: DEBUG: cleanup_uac_timers: RETR/FR timers reset 1(10362) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 1(10362) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 1(10362) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 1(10362) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 1(10362) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 1(10362) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 1(10362) DEBUG: [xavp.c:447]: destroying xavp list (nil) 1(10362) DEBUG: [receive.c:293]: receive_msg: cleaning up 10(10371) DEBUG: [io_wait.h:617]: DBG: io_watch_del (0x8cd0c0, 5, -1, 0x10) fd_no=2 called 10(10371) DEBUG: [tcp_read.c:1434]: releasing con 0x7f71ef930d20, state 1, fd=5, id=5 10(10371) DEBUG: [tcp_read.c:1435]: extra_data (nil) 14(10375) DEBUG: [tcp_main.c:3382]: handle_tcp_child: reader response= 7f71ef930d20, 1 from 0 14(10375) DEBUG: [io_wait.h:390]: DBG: io_watch_add(0x888cc0, 30, 2, 0x7f71ef930d20), fd_no=23 14(10375) DEBUG: [tcp_main.c:3512]: handle_tcp_child: CONN_RELEASE 0x7f71ef930d20 refcnt= 6 4(10365) DEBUG: [udp_server.c:498]: udp_rcv_loop: probing packet received from 192.168.144.44 56335 14(10375) DEBUG: [io_wait.h:617]: DBG: io_watch_del (0x888cc0, 30, -1, 0x0) fd_no=24 called 14(10375) DEBUG: [tcp_main.c:4299]: tcp: DBG: sending to child, events 1 14(10375) DEBUG: [tcp_main.c:3970]: selected tcp worker 1 11(10372) for activity on [tcp:192.168.144.48:8080], 0x7f71ef930d20 11(10372) DEBUG: [tcp_read.c:1507]: received n=8 con=0x7f71ef930d20, fd=5 11(10372) DEBUG: [tcp_read.c:1132]: WebSocket Message: [[>>> ?? ?}*3?4de?)o?Z ?CP?Lj\?D?Y?YG?.cc?O?wx\? O ?AYZ?GEA?j@?IU?ZV?PC^?S^V? ??>?+CR?]yz?R?R~p?] SSS ?XR?B?DBt?a ?M?E'9?R?XD?N@?] O]?G@?CCO@?CG??EZ?[G?p p?F?9?Z?_?D\?MF?\?wi`? ?K?4de?)o>?>E]?IG?]YZ?GK_?O?L?L ?L?I>??._C?XG??^[?]EF?EF??_F?w@?r?DG?]`@?4z?S?p p?^V? ?MG?G ?M>?p E?M'9?@?J ?M?O q?3n?]KF?E>?^?N?GR??p R?CP?]}~?]pG?K}?%T?9hU?(mI?Eo{?KD]?7~J?6NK?$'9?@KF?E?I<<<]] 11(10372) DEBUG: websocket [ws_frame.c:346]: decoding WebSocket frame 11(10372) DEBUG: websocket [ws_frame.c:396]: supported non-control frame: 0x1 11(10372) DEBUG: websocket [ws_frame.c:500]: Rx (decoded): INVITE sip:alice1@open-ims.test SIP/2.0 Route: Via: SIP/2.0/TCP 192.168.144.48;branch=z9hG4bK8702178 Max-Forwards: 69 To: From: ;tag=5b82i9gqt2 Call-ID: qip07c7lk96ogigujsv5 CSeq: 8665 INVITE Contact: sip:alice2@192.168.144.48 Allow: ACK,CANCEL,BYE,OPTIONS,INVITE,MESSAGE,INVITE Content-Type: application/sdp Supported: path, outbound, gruu User-Agent: JsSIP 0.3.0 Content-Length: 2203 v=0 o=- 3769005042 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio a=msid-semantic: WMS ZtBbaN7X2gwDBfJUGzK8EHD6nnGJTyZKdxWY m=audio 44236 RTP/SAVPF 103 104 111 0 8 107 106 105 13 126 c=IN IP4 195.37.78.190 a=rtcp:44236 IN IP4 195.37.78.190 a=candidate:2318809477 1 udp 2113937151 10.0.0.1 44236 typ host generation 0 a=candidate:2318809477 2 udp 2113937151 10.0.0.1 44236 typ host generation 0 a=candidate:3590172715 1 udp 2113937151 10.147.65.113 53733 typ host generation 0 a=candidate:3590172715 2 udp 2113937151 10.147.65.113 53733 typ host generation 0 a=candidate:4062413514 1 udp 2113937151 192.168.122.1 55773 typ host generation 0 a=candidate:4062413514 2 udp 2113937151 192.168.122.1 55773 typ host generation 0 a=candidate:3041975724 1 udp 1845501695 195.37.78.190 44236 typ srflx raddr 10.0.0.1 rport 44236 generation 0 a=candidate:3041975724 2 udp 1845501695 195.37.78.190 44236 typ srflx raddr 10.0.0.1 rport 44236 generation 0 a=candidate:1421194911 1 udp 1845501695 195.37.78.190 53733 typ srflx raddr 10.147.65.113 rport 53733 generation 0 a=candidate:1421194911 2 udp 1845501695 195.37.78.190 53733 typ srflx raddr 10.147.65.113 rport 53733 generation 0 a=candidate:1936426110 1 udp 1845501695 195.37.78.190 55773 typ srflx raddr 192.168.122.1 rport 55773 generation 0 a=candidate:1936426110 2 udp 1845501695 195.37.78.190 55773 typ srflx raddr 192.168.122.1 rport 55773 generation 0 a=ice-ufrag:BLipXUFvYAH/FfNU a=ice-pwd:HMA+c9VxYbkcrrU83syE+1OG a=ice-options:google-ice a=sendrecv a=mid:audio a=rtcp-mux a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:A9C8bzChiA/SMYPtGI/XM7d9RPFBrWsmqvq1zKRN a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:JLbmnCwpU8FAAYo1OLgULIYG6iE8aMASb3QUHGTl a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:111 opus/48000/2 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:107 CN/48000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:126 telephone-event/8000 a=ssrc:1325907241 cname:J4xoahqN/hy4MbM5 a=ssrc:1325907241 msid:ZtBbaN7X2gwDBfJUGzK8EHD6nnGJTyZKdxWY a0 a=ssrc:1325907241 mslabel:ZtBbaN7X2gwDBfJUGzK8EHD6nnGJTyZKdxWY a=ssrc:1325907241 label:ZtBbaN7X2gwDBfJUGzK8EHD6nnGJTyZKdxWYa0 11(10372) DEBUG: websocket [ws_frame.c:580]: Rx SIP message: INVITE sip:alice1@open-ims.test SIP/2.0 Route: Via: SIP/2.0/TCP 192.168.144.48;branch=z9hG4bK8702178 Max-Forwards: 69 To: From: ;tag=5b82i9gqt2 Call-ID: qip07c7lk96ogigujsv5 CSeq: 8665 INVITE Contact: sip:alice2@192.168.144.48 Allow: ACK,CANCEL,BYE,OPTIONS,INVITE,MESSAGE,INVITE Content-Type: application/sdp Supported: path, outbound, gruu User-Agent: JsSIP 0.3.0 Content-Length: 2203 v=0 o=- 3769005042 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio a=msid-semantic: WMS ZtBbaN7X2gwDBfJUGzK8EHD6nnGJTyZKdxWY m=audio 44236 RTP/SAVPF 103 104 111 0 8 107 106 105 13 126 c=IN IP4 195.37.78.190 a=rtcp:44236 IN IP4 195.37.78.190 a=candidate:2318809477 1 udp 2113937151 10.0.0.1 44236 typ host generation 0 a=candidate:2318809477 2 udp 2113937151 10.0.0.1 44236 typ host generation 0 a=candidate:3590172715 1 udp 2113937151 10.147.65.113 53733 typ host generation 0 a=candidate:3590172715 2 udp 2113937151 10.147.65.113 53733 typ host generation 0 a=candidate:4062413514 1 udp 2113937151 192.168.122.1 55773 typ host generation 0 a=candidate:4062413514 2 udp 2113937151 192.168.122.1 55773 typ host generation 0 a=candidate:3041975724 1 udp 1845501695 195.37.78.190 44236 typ srflx raddr 10.0.0.1 rport 44236 generation 0 a=candidate:3041975724 2 udp 1845501695 195.37.78.190 44236 typ srflx raddr 10.0.0.1 rport 44236 generation 0 a=candidate:1421194911 1 udp 1845501695 195.37.78.190 53733 typ srflx raddr 10.147.65.113 rport 53733 generation 0 a=candidate:1421194911 2 udp 1845501695 195.37.78.190 53733 typ srflx raddr 10.147.65.113 rport 53733 generation 0 a=candidate:1936426110 1 udp 1845501695 195.37.78.190 55773 typ srflx raddr 192.168.122.1 rport 55773 generation 0 a=candidate:1936426110 2 udp 1845501695 195.37.78.190 55773 typ srflx raddr 192.168.122.1 rport 55773 generation 0 a=ice-ufrag:BLipXUFvYAH/FfNU a=ice-pwd:HMA+c9VxYbkcrrU83syE+1OG a=ice-options:google-ice a=sendrecv a=mid:audio a=rtcp-mux a=crypto:0 AES_CM_128_HMAC_SHA1_32 inline:A9C8bzChiA/SMYPtGI/XM7d9RPFBrWsmqvq1zKRN a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:JLbmnCwpU8FAAYo1OLgULIYG6iE8aMASb3QUHGTl a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:111 opus/48000/2 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:107 CN/48000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:126 telephone-event/8000 a=ssrc:1325907241 cname:J4xoahqN/hy4MbM5 a=ssrc:1325907241 msid:ZtBbaN7X2gwDBfJUGzK8EHD6nnGJTyZKdxWY a0 a=ssrc:1325907241 mslabel:ZtBbaN7X2gwDBfJUGzK8EHD6nnGJTyZKdxWY a=ssrc:1325907241 label:ZtBbaN7X2gwDBfJUGzK8EHD6nnGJTyZKdxWYa0 11(10372) DEBUG: [parser/msg_parser.c:623]: SIP Request: 11(10372) DEBUG: [parser/msg_parser.c:625]: method: 11(10372) DEBUG: [parser/msg_parser.c:627]: uri: 11(10372) DEBUG: [parser/msg_parser.c:629]: version: 11(10372) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 11(10372) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 11(10372) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=2 11(10372) DEBUG: [parser/msg_parser.c:515]: parse_headers: this is the first via 11(10372) DEBUG: [receive.c:149]: After parse_msg... 11(10372) DEBUG: [receive.c:190]: preparing to run routing scripts... 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=530 a=5 n=route 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=613 a=16 n=if 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=608 a=25 n=mf_process_maxfwd_header 11(10372) DEBUG: maxfwd [mf_funcs.c:85]: value = 69 11(10372) DEBUG: maxfwd [maxfwd.c:161]: value 69 decreased to 16 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=618 a=16 n=if 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=613 a=26 n=sanity_check 11(10372) DEBUG: [parser/parse_to.c:799]: end of header reached, state=10 11(10372) DEBUG: [parser/msg_parser.c:190]: DEBUG: get_hdr_field: [28]; uri=[sip:alice1@open-ims.test] 11(10372) DEBUG: [parser/msg_parser.c:192]: DEBUG: to body [ ] 11(10372) DEBUG: [parser/msg_parser.c:170]: get_hdr_field: cseq : <8665> 11(10372) DEBUG: [parser/msg_parser.c:204]: DEBUG: get_hdr_body : content_length=2203 11(10372) DEBUG: [parser/msg_parser.c:106]: found end of header 11(10372) DEBUG: [parser/parse_to.c:176]: DEBUG: add_param: tag=5b82i9gqt2 11(10372) DEBUG: [parser/parse_to.c:799]: end of header reached, state=29 11(10372) DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=550 a=16 n=if 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=533 a=25 n=nat_uac_test 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=538 a=55 n=force_rport 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=547 a=16 n=if 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=539 a=25 n=is_method 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=547 a=16 n=if 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=542 a=24 n=add_contact_alias 11(10372) DEBUG: nathelper [nathelper.c:962]: adding param <;alias=10.147.65.113~33384~5>> 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=561 a=16 n=if 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=552 a=26 n=ds_select_dst 11(10372) DEBUG: dispatcher [dispatch.c:1599]: set [1] 11(10372) DEBUG: dispatcher [dispatch.c:1701]: alg hash [3927422135] 11(10372) DEBUG: dispatcher [dispatch.c:1742]: selected [0-1/0] 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=553 a=24 n=t_relay 11(10372) DEBUG: tm [t_lookup.c:1395]: DEBUG: t_newtran: msg id=4 , global msg id=3 , T on entrance=0xffffffffffffffff 11(10372) DEBUG: tm [t_lookup.c:534]: t_lookup_request: start searching: hash=33742, isACK=0 11(10372) DEBUG: tm [t_lookup.c:492]: DEBUG: RFC3261 transaction matching failed 11(10372) DEBUG: tm [t_lookup.c:716]: DEBUG: t_lookup_request: no transaction found 11(10372) DEBUG: tm [t_hooks.c:374]: DBG: trans=0x7f71ef920020, callback type 1, id 0 entered 11(10372) DEBUG: tm [t_funcs.c:347]: SER: new INVITE 11(10372) DEBUG: [msg_translator.c:206]: check_via_address(10.147.65.113, 192.168.144.48, 0) 11(10372) DEBUG: [mem/shm_mem.c:111]: WARNING:vqm_resize: resize(0) called 11(10372) DEBUG: websocket [ws_frame.c:641]: Tx message: SIP/2.0 100 trying -- your call is important to us Via: SIP/2.0/TCP 192.168.144.48;branch=z9hG4bK8702178;rport=33384;received=10.147.65.113 To: From: ;tag=5b82i9gqt2 Call-ID: qip07c7lk96ogigujsv5 CSeq: 8665 INVITE Server: kamailio (4.0.0 (x86_64/linux)) Content-Length: 0 11(10372) DEBUG: websocket [ws_frame.c:130]: encoding WebSocket frame 11(10372) DEBUG: websocket [ws_frame.c:159]: supported non-control frame: 0x1 11(10372) DEBUG: [tcp_main.c:2317]: tcp_send: send from reader (10372 (11)), reusing fd 11(10372) DEBUG: [tcp_main.c:2553]: tcp_send: sending... 11(10372) DEBUG: [tcp_main.c:2587]: tcp_send: after real write: c= 0x7f71ef930d20 n=339 fd=5 11(10372) DEBUG: [tcp_main.c:2588]: tcp_send: buf= ?~OSIP/2.0 100 trying -- your call is important to us Via: SIP/2.0/TCP 192.168.144.48;branch=z9hG4bK8702178;rport=33384;received=10.147.65.113 To: From: ;tag=5b82i9gqt2 Call-ID: qip07c7lk96ogigujsv5 CSeq: 8665 INVITE Server: kamailio (4.0.0 (x86_64/linux)) Content-Length: 0 11(10372) DEBUG: tm [t_reply.c:706]: DEBUG: reply sent out. buf=0x7f71f6d8fc20: SIP/2.0 100 trying -..., shmem=0x7f71ef915c80: SIP/2.0 100 trying - 11(10372) DEBUG: tm [t_reply.c:716]: DEBUG: _reply_light: finished 11(10372) DEBUG: [msg_translator.c:206]: check_via_address(10.147.65.113, 192.168.144.48, 0) 11(10372) DEBUG: tm [t_funcs.c:384]: SER: new transaction fwd'ed 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=554 a=24 n=add_path_received 2(10363) DEBUG: [parser/msg_parser.c:633]: SIP Reply (status): 2(10363) DEBUG: [parser/msg_parser.c:635]: version: 2(10363) DEBUG: [parser/msg_parser.c:637]: status: <100> 2(10363) DEBUG: [parser/msg_parser.c:639]: reason: 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=6 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 235, = <5060>; state=16 2(10363) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 2(10363) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=2 2(10363) DEBUG: [parser/msg_parser.c:515]: parse_headers: this is the first via 2(10363) DEBUG: [receive.c:149]: After parse_msg... 2(10363) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=829 a=16 n=if 2(10363) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=836 a=16 n=if 2(10363) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=829 a=25 n=nat_uac_test 2(10363) DEBUG: tm [t_lookup.c:1095]: DEBUG: t_check_msg: msg id=3 global id=2 T start=0xffffffffffffffff 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 235, = <33384>; state=6 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 234, = <10.147.65.113>; state=6 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 2(10363) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 2(10363) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=62 2(10363) DEBUG: [parser/msg_parser.c:526]: parse_headers: this is the second via 2(10363) DEBUG: [parser/parse_to.c:799]: end of header reached, state=10 2(10363) DEBUG: [parser/msg_parser.c:190]: DEBUG: get_hdr_field: [28]; uri=[sip:alice1@open-ims.test] 2(10363) DEBUG: [parser/msg_parser.c:192]: DEBUG: to body [ ] 2(10363) DEBUG: [parser/msg_parser.c:170]: get_hdr_field: cseq : <8665> 2(10363) DEBUG: tm [t_lookup.c:972]: DEBUG: t_reply_matching: hash 33742 label 205875726 branch 0 2(10363) DEBUG: tm [t_lookup.c:1032]: DEBUG: t_reply_matching: reply matched (T=0x7f71ef920020)! 2(10363) DEBUG: tm [t_lookup.c:1164]: DEBUG: t_check_msg: msg id=3 global id=3 T end=0x7f71ef920020 2(10363) DEBUG: tm [t_reply.c:2085]: DEBUG: reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1) 2(10363) DEBUG: tm [t_reply.c:1207]: ->>>>>>>>> T_code=100, new_code=100 2(10363) DEBUG: tm [t_reply.c:1706]: DEBUG: relay_reply: branch=0, save=0, relay=-1 2(10363) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 2(10363) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 2(10363) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 2(10363) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 2(10363) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 2(10363) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 2(10363) DEBUG: [xavp.c:447]: destroying xavp list (nil) 2(10363) DEBUG: [receive.c:293]: receive_msg: cleaning up 11(10372) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=555 a=24 n=record_route 11(10372) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 11(10372) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 11(10372) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 11(10372) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 11(10372) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 11(10372) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 11(10372) DEBUG: [xavp.c:447]: destroying xavp list (nil) 11(10372) DEBUG: [receive.c:293]: receive_msg: cleaning up 11(10372) DEBUG: [io_wait.h:390]: DBG: io_watch_add(0x8cd0c0, 5, 2, 0x7f71ef930d20), fd_no=1 3(10364) DEBUG: [parser/msg_parser.c:623]: SIP Request: 3(10364) DEBUG: [parser/msg_parser.c:625]: method: 3(10364) DEBUG: [parser/msg_parser.c:627]: uri: 3(10364) DEBUG: [parser/msg_parser.c:629]: version: 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 3(10364) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 3(10364) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=2 3(10364) DEBUG: [parser/msg_parser.c:515]: parse_headers: this is the first via 3(10364) DEBUG: [receive.c:149]: After parse_msg... 3(10364) DEBUG: [receive.c:190]: preparing to run routing scripts... 3(10364) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=530 a=5 n=route 3(10364) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=613 a=16 n=if 3(10364) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=608 a=25 n=mf_process_maxfwd_header 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 234, = <192.168.144.44>; state=6 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 235, = <6060>; state=6 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 3(10364) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 3(10364) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 3(10364) DEBUG: [parser/msg_parser.c:526]: parse_headers: this is the second via 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 3(10364) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 3(10364) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 3(10364) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 3(10364) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 235, = <5060>; state=6 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 3(10364) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 3(10364) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 235, = <33384>; state=6 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 234, = <10.147.65.113>; state=6 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 3(10364) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 3(10364) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 3(10364) DEBUG: maxfwd [mf_funcs.c:85]: value = 12 3(10364) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=618 a=16 n=if 3(10364) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=613 a=26 n=sanity_check 3(10364) DEBUG: [parser/parse_to.c:799]: end of header reached, state=10 3(10364) DEBUG: [parser/msg_parser.c:190]: DEBUG: get_hdr_field: [28]; uri=[sip:alice1@open-ims.test] 3(10364) DEBUG: [parser/msg_parser.c:192]: DEBUG: to body [ ] 3(10364) DEBUG: [parser/msg_parser.c:170]: get_hdr_field: cseq : <8665> 3(10364) DEBUG: [parser/msg_parser.c:204]: DEBUG: get_hdr_body : content_length=2203 3(10364) DEBUG: [parser/msg_parser.c:106]: found end of header 3(10364) DEBUG: [parser/parse_to.c:176]: DEBUG: add_param: tag=5b82i9gqt2 3(10364) DEBUG: [parser/parse_to.c:799]: end of header reached, state=29 3(10364) DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1 3(10364) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=550 a=16 n=if 3(10364) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=533 a=25 n=nat_uac_test 3(10364) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=561 a=16 n=if 3(10364) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=559 a=24 n=loose_route 3(10364) DEBUG: rr [loose.c:112]: No Route headers found 3(10364) DEBUG: rr [loose.c:927]: There is no Route HF 3(10364) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=560 a=24 n=record_route 3(10364) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 3(10364) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 3(10364) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 3(10364) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 3(10364) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 3(10364) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 3(10364) DEBUG: [xavp.c:447]: destroying xavp list (nil) 3(10364) DEBUG: [receive.c:293]: receive_msg: cleaning up 1(10362) DEBUG: [udp_server.c:498]: udp_rcv_loop: probing packet received from 192.168.144.44 56335 4(10365) DEBUG: [parser/msg_parser.c:623]: SIP Request: 4(10365) DEBUG: [parser/msg_parser.c:625]: method: 4(10365) DEBUG: [parser/msg_parser.c:627]: uri: 4(10365) DEBUG: [parser/msg_parser.c:629]: version: 4(10365) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 4(10365) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 4(10365) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=2 4(10365) DEBUG: [parser/msg_parser.c:515]: parse_headers: this is the first via 4(10365) DEBUG: [receive.c:149]: After parse_msg... 4(10365) DEBUG: [receive.c:190]: preparing to run routing scripts... 4(10365) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=530 a=5 n=route 4(10365) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=613 a=16 n=if 4(10365) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=608 a=25 n=mf_process_maxfwd_header 4(10365) DEBUG: [parser/parse_via.c:1284]: Found param type 234, = <192.168.144.44>; state=6 4(10365) DEBUG: [parser/parse_via.c:1284]: Found param type 235, = <6060>; state=6 4(10365) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 4(10365) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 4(10365) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 4(10365) DEBUG: [parser/msg_parser.c:526]: parse_headers: this is the second via 4(10365) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 4(10365) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 4(10365) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 4(10365) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 4(10365) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 4(10365) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 4(10365) DEBUG: [parser/parse_via.c:1284]: Found param type 235, = <5060>; state=6 4(10365) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 4(10365) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 4(10365) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 4(10365) DEBUG: [parser/parse_via.c:1284]: Found param type 235, = <33384>; state=6 4(10365) DEBUG: [parser/parse_via.c:1284]: Found param type 234, = <10.147.65.113>; state=6 4(10365) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 4(10365) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 4(10365) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 4(10365) DEBUG: maxfwd [mf_funcs.c:85]: value = 12 4(10365) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=618 a=16 n=if 4(10365) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=613 a=26 n=sanity_check 4(10365) DEBUG: [parser/parse_to.c:799]: end of header reached, state=10 4(10365) DEBUG: [parser/msg_parser.c:190]: DEBUG: get_hdr_field: [28]; uri=[sip:alice1@open-ims.test] 4(10365) DEBUG: [parser/msg_parser.c:192]: DEBUG: to body [ ] 4(10365) DEBUG: [parser/msg_parser.c:170]: get_hdr_field: cseq : <8665> 4(10365) DEBUG: [parser/msg_parser.c:204]: DEBUG: get_hdr_body : content_length=2203 4(10365) DEBUG: [parser/msg_parser.c:106]: found end of header 4(10365) DEBUG: [parser/parse_to.c:176]: DEBUG: add_param: tag=5b82i9gqt2 4(10365) DEBUG: [parser/parse_to.c:799]: end of header reached, state=29 4(10365) DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1 4(10365) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=550 a=16 n=if 4(10365) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=533 a=25 n=nat_uac_test 4(10365) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=561 a=16 n=if 4(10365) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=559 a=24 n=loose_route 4(10365) DEBUG: rr [loose.c:112]: No Route headers found 4(10365) DEBUG: rr [loose.c:927]: There is no Route HF 4(10365) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=560 a=24 n=record_route 4(10365) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 4(10365) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 4(10365) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 4(10365) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 4(10365) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 4(10365) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 4(10365) DEBUG: [xavp.c:447]: destroying xavp list (nil) 4(10365) DEBUG: [receive.c:293]: receive_msg: cleaning up 2(10363) DEBUG: [parser/msg_parser.c:623]: SIP Request: 2(10363) DEBUG: [parser/msg_parser.c:625]: method: 2(10363) DEBUG: [parser/msg_parser.c:627]: uri: 2(10363) DEBUG: [parser/msg_parser.c:629]: version: 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 2(10363) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 2(10363) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=2 2(10363) DEBUG: [parser/msg_parser.c:515]: parse_headers: this is the first via 2(10363) DEBUG: [receive.c:149]: After parse_msg... 2(10363) DEBUG: [receive.c:190]: preparing to run routing scripts... 2(10363) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=530 a=5 n=route 2(10363) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=613 a=16 n=if 2(10363) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=608 a=25 n=mf_process_maxfwd_header 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 234, = <192.168.144.44>; state=6 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 235, = <6060>; state=6 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 2(10363) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 2(10363) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 2(10363) DEBUG: [parser/msg_parser.c:526]: parse_headers: this is the second via 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 2(10363) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 2(10363) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 2(10363) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 2(10363) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 235, = <5060>; state=6 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 2(10363) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 2(10363) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 235, = <33384>; state=6 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 234, = <10.147.65.113>; state=6 2(10363) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 2(10363) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 2(10363) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 2(10363) DEBUG: maxfwd [mf_funcs.c:85]: value = 12 2(10363) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=618 a=16 n=if 2(10363) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=613 a=26 n=sanity_check 2(10363) DEBUG: [parser/parse_to.c:799]: end of header reached, state=10 2(10363) DEBUG: [parser/msg_parser.c:190]: DEBUG: get_hdr_field: [28]; uri=[sip:alice1@open-ims.test] 2(10363) DEBUG: [parser/msg_parser.c:192]: DEBUG: to body [ ] 2(10363) DEBUG: [parser/msg_parser.c:170]: get_hdr_field: cseq : <8665> 2(10363) DEBUG: [parser/msg_parser.c:204]: DEBUG: get_hdr_body : content_length=2203 2(10363) DEBUG: [parser/msg_parser.c:106]: found end of header 2(10363) DEBUG: [parser/parse_to.c:176]: DEBUG: add_param: tag=5b82i9gqt2 2(10363) DEBUG: [parser/parse_to.c:799]: end of header reached, state=29 2(10363) DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1 2(10363) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=550 a=16 n=if 2(10363) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=533 a=25 n=nat_uac_test 2(10363) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=561 a=16 n=if 2(10363) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=559 a=24 n=loose_route 2(10363) DEBUG: rr [loose.c:112]: No Route headers found 2(10363) DEBUG: rr [loose.c:927]: There is no Route HF 2(10363) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=560 a=24 n=record_route 2(10363) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 2(10363) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 2(10363) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 2(10363) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 2(10363) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 2(10363) DEBUG: [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil) 2(10363) DEBUG: [xavp.c:447]: destroying xavp list (nil) 2(10363) DEBUG: [receive.c:293]: receive_msg: cleaning up 3(10364) DEBUG: [parser/msg_parser.c:623]: SIP Request: 3(10364) DEBUG: [parser/msg_parser.c:625]: method: 3(10364) DEBUG: [parser/msg_parser.c:627]: uri: 3(10364) DEBUG: [parser/msg_parser.c:629]: version: 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 3(10364) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 3(10364) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=2 3(10364) DEBUG: [parser/msg_parser.c:515]: parse_headers: this is the first via 3(10364) DEBUG: [receive.c:149]: After parse_msg... 3(10364) DEBUG: [receive.c:190]: preparing to run routing scripts... 3(10364) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=530 a=5 n=route 3(10364) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=613 a=16 n=if 3(10364) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=608 a=25 n=mf_process_maxfwd_header 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 234, = <192.168.144.44>; state=6 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 235, = <6060>; state=6 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 3(10364) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 3(10364) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 3(10364) DEBUG: [parser/msg_parser.c:526]: parse_headers: this is the second via 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 3(10364) DEBUG: [parser/parse_via.c:2672]: end of header reached, state=5 3(10364) DEBUG: [parser/msg_parser.c:513]: parse_headers: Via found, flags=100 3(10364) DEBUG: [parser/parse_via.c:1284]: Found param type 232, = ; state=16 3(10364) DEBUG: