[SR-Users] kamailio as a proxy

Giuseppe Carella cargius at gmail.com
Wed May 15 22:22:21 CEST 2013


Hi all,

I'm trying to use kamailio as a proxy between webrtc clients and an
openIMSCore. For this reason I'm currently using the dispatcher module to
distribute all the requests coming from the clients to the IMS core, and
enabled the websocket module for getting the SIP messages in. SO far it
works fine for the registration, but it doesn't for the INVITEs. I noticed
that kamailio receives the message but it doesn't deliver it to the
clients. Please find attached the log and the configuration file that I
used. I'm not an expert with the configuration, so any help or feedback
would be very appreciated. Thank you in advance.

Best regards,
Giuseppe Carella
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20130515/cdd472c8/attachment-0001.html>
-------------- next part --------------
1(10362) DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: get_hdr_field: <To> [70]; uri=[sip:alice2 at open-ims.test]
 1(10362) DEBUG: <core> [parser/msg_parser.c:192]: DEBUG: to body [<sip:alice2 at open-ims.test>]
 1(10362) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field: cseq <CSeq>: <82> <REGISTER>
 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: <core> [parser/msg_parser.c:204]: DEBUG: get_hdr_body : content_length=0
 1(10362) DEBUG: <core> [parser/msg_parser.c:106]: found end of header
 1(10362) DEBUG: <core> [msg_translator.c:2008]:  old size: 1103, new size: 1029
 1(10362) DEBUG: <core> [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: <sip:alice2 at open-ims.test>;tag=a1b9ad4a2a4df0e5b663067884a87691-34b0
From: <sip:alice2 at open-ims.test>;tag=bmlh23ps9e
Call-ID: vn0p5v50ugskvfk612jbn9
CSeq: 82 REGISTER
P-Associated-URI: <sip:alice2 at open-ims.test>
Contact: <sip:alice2 at 192.168.144.48>;expires=3600;pub-gruu="sip:alice2 at open-ims.test;gr=urn:uuid:8f2b1620-007f-412b-ba54-811e999a3495"
Path: <sip:term at pcscf.open-ims.test:4060;lr>
Service-Route: <sip:orig at scscf.open-ims.test:6060;lr>
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: <core> [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: <sip:alice2 at open-ims.test>;tag=a1b9ad4a2a4df0e5b663067884a87691-34b0
From: <sip:alice2 at open-ims.test>;tag=bmlh23ps9e
Call-ID: vn0p5v50ugskvfk612jbn9
CSeq: 82 REGISTER
P-Associated-URI: <sip:alice2 at open-ims.test>
Contact: <sip:alice2 at 192.168.144.48>;expires=3600;pub-gruu="sip:alice2 at open-ims.test;gr=urn:uuid:8f2b1620-007f-412b-ba54-811e999a3495"
Path: <sip:term at pcscf.open-ims.test:4060;lr>
Service-Route: <sip:orig at scscf.open-ims.test:6060;lr>
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: <core> [tcp_main.c:2333]: tcp_send: tcp connection found (0x7f71ef930d20), acquiring fd
 1(10362) DEBUG: <core> [tcp_main.c:2344]: tcp_send, c= 0x7f71ef930d20, n=16
14(10375) DEBUG: <core> [tcp_main.c:3621]: handle_ser_child: read response= 7f71ef930d20, 2, fd -1 from 1 (10362)
 1(10362) DEBUG: <core> [tcp_main.c:2374]: tcp_send: after receive_fd: c= 0x7f71ef930d20 n=8 fd=8
 1(10362) DEBUG: <core> [tcp_main.c:2553]: tcp_send: sending...
 1(10362) DEBUG: <core> [tcp_main.c:2587]: tcp_send: after real write: c= 0x7f71ef930d20 n=1033 fd=8
 1(10362) DEBUG: <core> [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: <sip:alice2 at open-ims.test>;tag=a1b9ad4a2a4df0e5b663067884a87691-34b0
From: <sip:alice2 at open-ims.test>;tag=bmlh23ps9e
Call-ID: vn0p5v50ugskvfk612jbn9
CSeq: 82 REGISTER
P-Associated-URI: <sip:alice2 at open-ims.test>
Contact: <sip:alice2 at 192.168.144.48>;expires=3600;pub-gruu="sip:alice2 at open-ims.test;gr=urn:uuid:8f2b1620-007f-412b-ba54-811e999a3495"
Path: <sip:term at pcscf.open-ims.test:4060;lr>
Service-Route: <sip:orig at scscf.open-ims.test:6060;lr>
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: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 1(10362) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 1(10362) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 1(10362) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 1(10362) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 1(10362) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 1(10362) DEBUG: <core> [xavp.c:447]: destroying xavp list (nil)
 1(10362) DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
10(10371) DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x8cd0c0, 5, -1, 0x10) fd_no=2 called
10(10371) DEBUG: <core> [tcp_read.c:1434]: releasing con 0x7f71ef930d20, state 1, fd=5, id=5
10(10371) DEBUG: <core> [tcp_read.c:1435]:  extra_data (nil)
14(10375) DEBUG: <core> [tcp_main.c:3382]: handle_tcp_child: reader response= 7f71ef930d20, 1 from 0
14(10375) DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x888cc0, 30, 2, 0x7f71ef930d20), fd_no=23
14(10375) DEBUG: <core> [tcp_main.c:3512]: handle_tcp_child: CONN_RELEASE  0x7f71ef930d20 refcnt= 6
 4(10365) DEBUG: <core> [udp_server.c:498]: udp_rcv_loop: probing packet received from 192.168.144.44 56335
14(10375) DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x888cc0, 30, -1, 0x0) fd_no=24 called
14(10375) DEBUG: <core> [tcp_main.c:4299]: tcp: DBG: sending to child, events 1
14(10375) DEBUG: <core> [tcp_main.c:3970]: selected tcp worker 1 11(10372) for activity on [tcp:192.168.144.48:8080], 0x7f71ef930d20
11(10372) DEBUG: <core> [tcp_read.c:1507]: received n=8 con=0x7f71ef930d20, fd=5
11(10372) DEBUG: <core> [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>?<F_?
Z_?KG?D?Z>?._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 at open-ims.test SIP/2.0
Route: <sip:orig at scscf.open-ims.test:6060;lr>
Via: SIP/2.0/TCP 192.168.144.48;branch=z9hG4bK8702178
Max-Forwards: 69
To: <sip:alice1 at open-ims.test>
From: <sip:alice2 at open-ims.test>;tag=5b82i9gqt2
Call-ID: qip07c7lk96ogigujsv5
CSeq: 8665 INVITE
Contact: sip:alice2 at 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 at open-ims.test SIP/2.0
Route: <sip:orig at scscf.open-ims.test:6060;lr>
Via: SIP/2.0/TCP 192.168.144.48;branch=z9hG4bK8702178
Max-Forwards: 69
To: <sip:alice1 at open-ims.test>
From: <sip:alice2 at open-ims.test>;tag=5b82i9gqt2
Call-ID: qip07c7lk96ogigujsv5
CSeq: 8665 INVITE
Contact: sip:alice2 at 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: <core> [parser/msg_parser.c:623]: SIP Request:
11(10372) DEBUG: <core> [parser/msg_parser.c:625]:  method:  <INVITE>
11(10372) DEBUG: <core> [parser/msg_parser.c:627]:  uri:     <sip:alice1 at open-ims.test>
11(10372) DEBUG: <core> [parser/msg_parser.c:629]:  version: <SIP/2.0>
11(10372) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bK8702178>; state=16
11(10372) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
11(10372) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=2
11(10372) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers: this is the first via
11(10372) DEBUG: <core> [receive.c:149]: After parse_msg...
11(10372) DEBUG: <core> [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: <core> [parser/parse_to.c:799]: end of header reached, state=10
11(10372) DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: get_hdr_field: <To> [28]; uri=[sip:alice1 at open-ims.test]
11(10372) DEBUG: <core> [parser/msg_parser.c:192]: DEBUG: to body [<sip:alice1 at open-ims.test>
]
11(10372) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field: cseq <CSeq>: <8665> <INVITE>
11(10372) DEBUG: <core> [parser/msg_parser.c:204]: DEBUG: get_hdr_body : content_length=2203
11(10372) DEBUG: <core> [parser/msg_parser.c:106]: found end of header
11(10372) DEBUG: <core> [parser/parse_to.c:176]: DEBUG: add_param: tag=5b82i9gqt2
11(10372) DEBUG: <core> [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] <sip:192.168.144.44:4060>
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: <core> [msg_translator.c:206]: check_via_address(10.147.65.113, 192.168.144.48, 0)
11(10372) DEBUG: <core> [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: <sip:alice1 at open-ims.test>
From: <sip:alice2 at open-ims.test>;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: <core> [tcp_main.c:2317]: tcp_send: send from reader (10372 (11)), reusing fd
11(10372) DEBUG: <core> [tcp_main.c:2553]: tcp_send: sending...
11(10372) DEBUG: <core> [tcp_main.c:2587]: tcp_send: after real write: c= 0x7f71ef930d20 n=339 fd=5
11(10372) DEBUG: <core> [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: <sip:alice1 at open-ims.test>
From: <sip:alice2 at open-ims.test>;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: <core> [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: <core> [parser/msg_parser.c:633]: SIP Reply  (status):
 2(10363) DEBUG: <core> [parser/msg_parser.c:635]:  version: <SIP/2.0>
 2(10363) DEBUG: <core> [parser/msg_parser.c:637]:  status:  <100>
 2(10363) DEBUG: <core> [parser/msg_parser.c:639]:  reason:  <trying -- your call is important to us>
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.e0a654c.0>; state=6
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <5060>; state=16
 2(10363) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 2(10363) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=2
 2(10363) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers: this is the first via
 2(10363) DEBUG: <core> [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: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <33384>; state=6
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <10.147.65.113>; state=6
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bK8702178>; state=16
 2(10363) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 2(10363) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=62
 2(10363) DEBUG: <core> [parser/msg_parser.c:526]: parse_headers: this is the second via
 2(10363) DEBUG: <core> [parser/parse_to.c:799]: end of header reached, state=10
 2(10363) DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: get_hdr_field: <To> [28]; uri=[sip:alice1 at open-ims.test]
 2(10363) DEBUG: <core> [parser/msg_parser.c:192]: DEBUG: to body [<sip:alice1 at open-ims.test>
]
 2(10363) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field: cseq <CSeq>: <8665> <INVITE>
 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: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [xavp.c:447]: destroying xavp list (nil)
 2(10363) DEBUG: <core> [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: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
11(10372) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
11(10372) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
11(10372) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
11(10372) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
11(10372) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
11(10372) DEBUG: <core> [xavp.c:447]: destroying xavp list (nil)
11(10372) DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
11(10372) DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x8cd0c0, 5, 2, 0x7f71ef930d20), fd_no=1
 3(10364) DEBUG: <core> [parser/msg_parser.c:623]: SIP Request:
 3(10364) DEBUG: <core> [parser/msg_parser.c:625]:  method:  <INVITE>
 3(10364) DEBUG: <core> [parser/msg_parser.c:627]:  uri:     <sip:alice1 at 192.168.144.48>
 3(10364) DEBUG: <core> [parser/msg_parser.c:629]:  version: <SIP/2.0>
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.b05029c.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=2
 3(10364) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers: this is the first via
 3(10364) DEBUG: <core> [receive.c:149]: After parse_msg...
 3(10364) DEBUG: <core> [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: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <192.168.144.44>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <6060>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.83983be6.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 3(10364) DEBUG: <core> [parser/msg_parser.c:526]: parse_headers: this is the second via
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.73983be6.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.a05029c.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <5060>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.e0a654c.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <33384>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <10.147.65.113>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bK8702178>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [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: <core> [parser/parse_to.c:799]: end of header reached, state=10
 3(10364) DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: get_hdr_field: <To> [28]; uri=[sip:alice1 at open-ims.test]
 3(10364) DEBUG: <core> [parser/msg_parser.c:192]: DEBUG: to body [<sip:alice1 at open-ims.test>
]
 3(10364) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field: cseq <CSeq>: <8665> <INVITE>
 3(10364) DEBUG: <core> [parser/msg_parser.c:204]: DEBUG: get_hdr_body : content_length=2203
 3(10364) DEBUG: <core> [parser/msg_parser.c:106]: found end of header
 3(10364) DEBUG: <core> [parser/parse_to.c:176]: DEBUG: add_param: tag=5b82i9gqt2
 3(10364) DEBUG: <core> [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: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [xavp.c:447]: destroying xavp list (nil)
 3(10364) DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
 1(10362) DEBUG: <core> [udp_server.c:498]: udp_rcv_loop: probing packet received from 192.168.144.44 56335
 4(10365) DEBUG: <core> [parser/msg_parser.c:623]: SIP Request:
 4(10365) DEBUG: <core> [parser/msg_parser.c:625]:  method:  <INVITE>
 4(10365) DEBUG: <core> [parser/msg_parser.c:627]:  uri:     <sip:alice1 at 192.168.144.48>
 4(10365) DEBUG: <core> [parser/msg_parser.c:629]:  version: <SIP/2.0>
 4(10365) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.b05029c.0>; state=16
 4(10365) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 4(10365) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=2
 4(10365) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers: this is the first via
 4(10365) DEBUG: <core> [receive.c:149]: After parse_msg...
 4(10365) DEBUG: <core> [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: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <192.168.144.44>; state=6
 4(10365) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <6060>; state=6
 4(10365) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.83983be6.0>; state=16
 4(10365) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 4(10365) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 4(10365) DEBUG: <core> [parser/msg_parser.c:526]: parse_headers: this is the second via
 4(10365) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.73983be6.0>; state=16
 4(10365) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 4(10365) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 4(10365) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.a05029c.0>; state=16
 4(10365) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 4(10365) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 4(10365) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <5060>; state=6
 4(10365) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.e0a654c.0>; state=16
 4(10365) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 4(10365) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 4(10365) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <33384>; state=6
 4(10365) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <10.147.65.113>; state=6
 4(10365) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bK8702178>; state=16
 4(10365) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 4(10365) DEBUG: <core> [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: <core> [parser/parse_to.c:799]: end of header reached, state=10
 4(10365) DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: get_hdr_field: <To> [28]; uri=[sip:alice1 at open-ims.test]
 4(10365) DEBUG: <core> [parser/msg_parser.c:192]: DEBUG: to body [<sip:alice1 at open-ims.test>
]
 4(10365) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field: cseq <CSeq>: <8665> <INVITE>
 4(10365) DEBUG: <core> [parser/msg_parser.c:204]: DEBUG: get_hdr_body : content_length=2203
 4(10365) DEBUG: <core> [parser/msg_parser.c:106]: found end of header
 4(10365) DEBUG: <core> [parser/parse_to.c:176]: DEBUG: add_param: tag=5b82i9gqt2
 4(10365) DEBUG: <core> [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: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 4(10365) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 4(10365) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 4(10365) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 4(10365) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 4(10365) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 4(10365) DEBUG: <core> [xavp.c:447]: destroying xavp list (nil)
 4(10365) DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
 2(10363) DEBUG: <core> [parser/msg_parser.c:623]: SIP Request:
 2(10363) DEBUG: <core> [parser/msg_parser.c:625]:  method:  <INVITE>
 2(10363) DEBUG: <core> [parser/msg_parser.c:627]:  uri:     <sip:alice1 at 192.168.144.48>
 2(10363) DEBUG: <core> [parser/msg_parser.c:629]:  version: <SIP/2.0>
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.b05029c.0>; state=16
 2(10363) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 2(10363) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=2
 2(10363) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers: this is the first via
 2(10363) DEBUG: <core> [receive.c:149]: After parse_msg...
 2(10363) DEBUG: <core> [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: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <192.168.144.44>; state=6
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <6060>; state=6
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.83983be6.0>; state=16
 2(10363) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 2(10363) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 2(10363) DEBUG: <core> [parser/msg_parser.c:526]: parse_headers: this is the second via
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.73983be6.0>; state=16
 2(10363) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 2(10363) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.a05029c.0>; state=16
 2(10363) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 2(10363) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <5060>; state=6
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.e0a654c.0>; state=16
 2(10363) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 2(10363) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <33384>; state=6
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <10.147.65.113>; state=6
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bK8702178>; state=16
 2(10363) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 2(10363) DEBUG: <core> [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: <core> [parser/parse_to.c:799]: end of header reached, state=10
 2(10363) DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: get_hdr_field: <To> [28]; uri=[sip:alice1 at open-ims.test]
 2(10363) DEBUG: <core> [parser/msg_parser.c:192]: DEBUG: to body [<sip:alice1 at open-ims.test>
]
 2(10363) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field: cseq <CSeq>: <8665> <INVITE>
 2(10363) DEBUG: <core> [parser/msg_parser.c:204]: DEBUG: get_hdr_body : content_length=2203
 2(10363) DEBUG: <core> [parser/msg_parser.c:106]: found end of header
 2(10363) DEBUG: <core> [parser/parse_to.c:176]: DEBUG: add_param: tag=5b82i9gqt2
 2(10363) DEBUG: <core> [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: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [xavp.c:447]: destroying xavp list (nil)
 2(10363) DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
 3(10364) DEBUG: <core> [parser/msg_parser.c:623]: SIP Request:
 3(10364) DEBUG: <core> [parser/msg_parser.c:625]:  method:  <INVITE>
 3(10364) DEBUG: <core> [parser/msg_parser.c:627]:  uri:     <sip:alice1 at 192.168.144.48>
 3(10364) DEBUG: <core> [parser/msg_parser.c:629]:  version: <SIP/2.0>
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.b05029c.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=2
 3(10364) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers: this is the first via
 3(10364) DEBUG: <core> [receive.c:149]: After parse_msg...
 3(10364) DEBUG: <core> [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: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <192.168.144.44>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <6060>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.83983be6.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 3(10364) DEBUG: <core> [parser/msg_parser.c:526]: parse_headers: this is the second via
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.73983be6.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.a05029c.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <5060>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.e0a654c.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <33384>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <10.147.65.113>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bK8702178>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [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: <core> [parser/parse_to.c:799]: end of header reached, state=10
 3(10364) DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: get_hdr_field: <To> [28]; uri=[sip:alice1 at open-ims.test]
 3(10364) DEBUG: <core> [parser/msg_parser.c:192]: DEBUG: to body [<sip:alice1 at open-ims.test>
]
 3(10364) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field: cseq <CSeq>: <8665> <INVITE>
 3(10364) DEBUG: <core> [parser/msg_parser.c:204]: DEBUG: get_hdr_body : content_length=2203
 3(10364) DEBUG: <core> [parser/msg_parser.c:106]: found end of header
 3(10364) DEBUG: <core> [parser/parse_to.c:176]: DEBUG: add_param: tag=5b82i9gqt2
 3(10364) DEBUG: <core> [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: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [xavp.c:447]: destroying xavp list (nil)
 3(10364) DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
11(10372) DEBUG: <core> [io_wait.h:617]: DBG: io_watch_del (0x8cd0c0, 5, -1, 0x10) fd_no=2 called
11(10372) DEBUG: <core> [tcp_read.c:1434]: releasing con 0x7f71ef930d20, state 1, fd=5, id=5
11(10372) DEBUG: <core> [tcp_read.c:1435]:  extra_data (nil)
14(10375) DEBUG: <core> [tcp_main.c:3382]: handle_tcp_child: reader response= 7f71ef930d20, 1 from 1
14(10375) DEBUG: <core> [io_wait.h:390]: DBG: io_watch_add(0x888cc0, 30, 2, 0x7f71ef930d20), fd_no=23
14(10375) DEBUG: <core> [tcp_main.c:3512]: handle_tcp_child: CONN_RELEASE  0x7f71ef930d20 refcnt= 8
 1(10362) DEBUG: <core> [parser/msg_parser.c:623]: SIP Request:
 1(10362) DEBUG: <core> [parser/msg_parser.c:625]:  method:  <INVITE>
 1(10362) DEBUG: <core> [parser/msg_parser.c:627]:  uri:     <sip:alice1 at 192.168.144.48>
 1(10362) DEBUG: <core> [parser/msg_parser.c:629]:  version: <SIP/2.0>
 1(10362) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.b05029c.0>; state=16
 1(10362) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 1(10362) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=2
 1(10362) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers: this is the first via
 1(10362) DEBUG: <core> [receive.c:149]: After parse_msg...
 1(10362) DEBUG: <core> [receive.c:190]: preparing to run routing scripts...
 1(10362) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=530 a=5 n=route
 1(10362) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=613 a=16 n=if
 1(10362) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=608 a=25 n=mf_process_maxfwd_header
 1(10362) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <192.168.144.44>; state=6
 1(10362) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <6060>; state=6
 1(10362) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.83983be6.0>; state=16
 1(10362) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 1(10362) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 1(10362) DEBUG: <core> [parser/msg_parser.c:526]: parse_headers: this is the second via
 1(10362) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.73983be6.0>; state=16
 1(10362) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 1(10362) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 1(10362) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.a05029c.0>; state=16
 1(10362) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 1(10362) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 1(10362) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <5060>; state=6
 1(10362) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.e0a654c.0>; state=16
 1(10362) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 1(10362) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 1(10362) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <33384>; state=6
 1(10362) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <10.147.65.113>; state=6
 1(10362) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bK8702178>; state=16
 1(10362) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 1(10362) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 1(10362) DEBUG: maxfwd [mf_funcs.c:85]: value = 12
 1(10362) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=618 a=16 n=if
 1(10362) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=613 a=26 n=sanity_check
 1(10362) DEBUG: <core> [parser/parse_to.c:799]: end of header reached, state=10
 1(10362) DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: get_hdr_field: <To> [28]; uri=[sip:alice1 at open-ims.test]
 1(10362) DEBUG: <core> [parser/msg_parser.c:192]: DEBUG: to body [<sip:alice1 at open-ims.test>
]
 1(10362) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field: cseq <CSeq>: <8665> <INVITE>
 1(10362) DEBUG: <core> [parser/msg_parser.c:204]: DEBUG: get_hdr_body : content_length=2203
 1(10362) DEBUG: <core> [parser/msg_parser.c:106]: found end of header
 1(10362) DEBUG: <core> [parser/parse_to.c:176]: DEBUG: add_param: tag=5b82i9gqt2
 1(10362) DEBUG: <core> [parser/parse_to.c:799]: end of header reached, state=29
 1(10362) DEBUG: sanity [mod_sanity.c:255]: sanity checks result: 1
 1(10362) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=550 a=16 n=if
 1(10362) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=533 a=25 n=nat_uac_test
 1(10362) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=561 a=16 n=if
 1(10362) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=559 a=24 n=loose_route
 1(10362) DEBUG: rr [loose.c:112]: No Route headers found
 1(10362) DEBUG: rr [loose.c:927]: There is no Route HF
 1(10362) ERROR: *** cfgtrace: c=[/usr/local/kamailio-4.0/etc/kamailio/kamailio.cfg] l=560 a=24 n=record_route
 1(10362) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 1(10362) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 1(10362) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 1(10362) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 1(10362) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 1(10362) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 1(10362) DEBUG: <core> [xavp.c:447]: destroying xavp list (nil)
 1(10362) DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
 4(10365) DEBUG: <core> [udp_server.c:498]: udp_rcv_loop: probing packet received from 192.168.144.44 56335
 2(10363) DEBUG: <core> [parser/msg_parser.c:623]: SIP Request:
 2(10363) DEBUG: <core> [parser/msg_parser.c:625]:  method:  <INVITE>
 2(10363) DEBUG: <core> [parser/msg_parser.c:627]:  uri:     <sip:alice1 at 192.168.144.48>
 2(10363) DEBUG: <core> [parser/msg_parser.c:629]:  version: <SIP/2.0>
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.b05029c.0>; state=16
 2(10363) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 2(10363) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=2
 2(10363) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers: this is the first via
 2(10363) DEBUG: <core> [receive.c:149]: After parse_msg...
 2(10363) DEBUG: <core> [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: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <192.168.144.44>; state=6
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <6060>; state=6
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.83983be6.0>; state=16
 2(10363) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 2(10363) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 2(10363) DEBUG: <core> [parser/msg_parser.c:526]: parse_headers: this is the second via
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.73983be6.0>; state=16
 2(10363) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 2(10363) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.a05029c.0>; state=16
 2(10363) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 2(10363) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <5060>; state=6
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.e0a654c.0>; state=16
 2(10363) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 2(10363) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <33384>; state=6
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <10.147.65.113>; state=6
 2(10363) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bK8702178>; state=16
 2(10363) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 2(10363) DEBUG: <core> [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: <core> [parser/parse_to.c:799]: end of header reached, state=10
 2(10363) DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: get_hdr_field: <To> [28]; uri=[sip:alice1 at open-ims.test]
 2(10363) DEBUG: <core> [parser/msg_parser.c:192]: DEBUG: to body [<sip:alice1 at open-ims.test>
]
 2(10363) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field: cseq <CSeq>: <8665> <INVITE>
 2(10363) DEBUG: <core> [parser/msg_parser.c:204]: DEBUG: get_hdr_body : content_length=2203
 2(10363) DEBUG: <core> [parser/msg_parser.c:106]: found end of header
 2(10363) DEBUG: <core> [parser/parse_to.c:176]: DEBUG: add_param: tag=5b82i9gqt2
 2(10363) DEBUG: <core> [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: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 2(10363) DEBUG: <core> [xavp.c:447]: destroying xavp list (nil)
 2(10363) DEBUG: <core> [receive.c:293]: receive_msg: cleaning up
 3(10364) DEBUG: <core> [parser/msg_parser.c:623]: SIP Request:
 3(10364) DEBUG: <core> [parser/msg_parser.c:625]:  method:  <INVITE>
 3(10364) DEBUG: <core> [parser/msg_parser.c:627]:  uri:     <sip:alice1 at 192.168.144.48>
 3(10364) DEBUG: <core> [parser/msg_parser.c:629]:  version: <SIP/2.0>
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.b05029c.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=2
 3(10364) DEBUG: <core> [parser/msg_parser.c:515]: parse_headers: this is the first via
 3(10364) DEBUG: <core> [receive.c:149]: After parse_msg...
 3(10364) DEBUG: <core> [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: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <192.168.144.44>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <6060>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.83983be6.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 3(10364) DEBUG: <core> [parser/msg_parser.c:526]: parse_headers: this is the second via
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.73983be6.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.a05029c.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <5060>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bKec38.e0a654c.0>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [parser/msg_parser.c:513]: parse_headers: Via found, flags=100
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 235, <rport> = <33384>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 234, <received> = <10.147.65.113>; state=6
 3(10364) DEBUG: <core> [parser/parse_via.c:1284]: Found param type 232, <branch> = <z9hG4bK8702178>; state=16
 3(10364) DEBUG: <core> [parser/parse_via.c:2672]: end of header reached, state=5
 3(10364) DEBUG: <core> [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: <core> [parser/parse_to.c:799]: end of header reached, state=10
 3(10364) DEBUG: <core> [parser/msg_parser.c:190]: DEBUG: get_hdr_field: <To> [28]; uri=[sip:alice1 at open-ims.test]
 3(10364) DEBUG: <core> [parser/msg_parser.c:192]: DEBUG: to body [<sip:alice1 at open-ims.test>
]
 3(10364) DEBUG: <core> [parser/msg_parser.c:170]: get_hdr_field: cseq <CSeq>: <8665> <INVITE>
 3(10364) DEBUG: <core> [parser/msg_parser.c:204]: DEBUG: get_hdr_body : content_length=2203
 3(10364) DEBUG: <core> [parser/msg_parser.c:106]: found end of header
 3(10364) DEBUG: <core> [parser/parse_to.c:176]: DEBUG: add_param: tag=5b82i9gqt2
 3(10364) DEBUG: <core> [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: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroying list (nil)
 3(10364) DEBUG: <core> [usr_avp.c:644]: DEBUG:destroy_avp_list: destroy
-------------- next part --------------
A non-text attachment was scrubbed...
Name: kamailio-ws.cfg
Type: application/octet-stream
Size: 28167 bytes
Desc: not available
URL: <http://lists.sip-router.org/pipermail/sr-users/attachments/20130515/cdd472c8/attachment-0001.obj>


More information about the sr-users mailing list