failed when try to #add or #invite a user to a private chat room with imc module. #join  to a public room works!
attached kamailio log:

May 20 20:43:19 dev /usr/sbin/kamailio[23771]: DEBUG: <core> [core/tcp_read.c:198]: tcp_emit_closed_event(): TCP closed event creation triggered (reason: 0)
May 20 20:43:19 dev /usr/sbin/kamailio[23771]: DEBUG: <core> [core/tcp_read.c:206]: tcp_emit_closed_event(): no callback registering for handling TCP closed event
May 20 20:43:19 dev /usr/sbin/kamailio[23771]: DEBUG: <core> [core/tcp_read.c:315]: tcp_read_data(): EOF on 0x7fbdf2a25f28, FD 11 ([37.77.127.147]:36732 ->
May 20 20:43:19 dev /usr/sbin/kamailio[23771]: DEBUG: <core> [core/tcp_read.c:316]: tcp_read_data(): -> [195.201.132.99]:5061)
May 20 20:43:19 dev /usr/sbin/kamailio[23771]: DEBUG: <core> [core/tcp_read.c:1507]: tcp_read_req(): EOF
May 20 20:43:19 dev /usr/sbin/kamailio[23771]: DEBUG: <core> [core/tcp_read.c:1664]: release_tcpconn(): releasing con 0x7fbdf2a25f28, state -1, fd=11, id=5 ([37.77.127.147]:36732 -> [37.77.127.147]:5061)
May 20 20:43:19 dev /usr/sbin/kamailio[23771]: DEBUG: <core> [core/tcp_read.c:1665]: release_tcpconn(): extra_data 0x7fbdf2a409a0
May 20 20:43:19 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:3308]: handle_tcp_child(): reader response= 7fbdf2a25f28, -1 from 6
May 20 20:43:19 dev /usr/sbin/kamailio[23773]: DEBUG: tls [tls_server.c:667]: tls_h_close(): Closing SSL connection 0x7fbdf2a409a0
May 20 20:43:22 dev /usr/sbin/kamailio[23736]: DEBUG: msilo [msilo.c:1214]: m_clean_silo(): cleaning stored messages - 51560299
May 20 20:43:27 dev /usr/sbin/kamailio[23736]: DEBUG: msilo [msilo.c:1214]: m_clean_silo(): cleaning stored messages - 51560304
May 20 20:43:27 dev /usr/sbin/kamailio[23736]: DEBUG: msilo [msilo.c:1274]: m_clean_silo(): cleaning expired messages
May 20 20:43:32 dev /usr/sbin/kamailio[23736]: DEBUG: msilo [msilo.c:1214]: m_clean_silo(): cleaning stored messages - 51560309
May 20 20:43:33 dev /usr/sbin/kamailio[23736]: DEBUG: tm [t_reply.c:1263]: t_should_relay_response(): ->>>>>>>>> T_code=0, new_code=408
May 20 20:43:33 dev /usr/sbin/kamailio[23736]: DEBUG: tm [t_reply.c:2074]: local_reply(): branch=0, save=0, winner=0
May 20 20:43:33 dev /usr/sbin/kamailio[23736]: DEBUG: tm [t_reply.c:2113]: local_reply(): local transaction completed 408/0 (totag retr: 0/0)
May 20 20:43:37 dev /usr/sbin/kamailio[23736]: DEBUG: msilo [msilo.c:1214]: m_clean_silo(): cleaning stored messages - 51560314
May 20 20:43:42 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection: 37.77.127.147
May 20 20:43:42 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:999]: tcpconn_new(): on port 35906, type 3
May 20 20:43:42 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:1309]: tcpconn_add(): hashes: 1993:1592:1498, 6
May 20 20:43:42 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa5bf80, 49, 2, 0x7fbdf2a25f28), fd_no=38
May 20 20:43:42 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xa5bf80, 49, -1, 0x0) fd_no=39 called
May 20 20:43:42 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:4196]: handle_tcpconn_ev(): sending to child, events 1
May 20 20:43:42 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:3878]: send2child(): selected tcp worker 7 28(23772) for activity on [tls:0.0.0.0:5061], 0x7fbdf2a25f28
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/tcp_read.c:1740]: handle_io(): received n=8 con=0x7fbdf2a25f28, fd=11
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: tls [tls_server.c:199]: tls_complete_init(): completing tls connection initialization
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: tls [tls_server.c:228]: tls_complete_init(): Using initial TLS domain TLSs<default> (dom 0x7fbdf283eb58 ctx 0x7fbdf28a1e20 sn [])
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: tls [tls_domain.c:724]: sr_ssl_ctx_info_callback(): SSL handshake started
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/tcp_main.c:2460]: tcpconn_do_send(): sending...
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= 0x7fbdf2a25f28 n=2974 fd=11
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/tcp_main.c:2495]: tcpconn_do_send(): buf=#012#026#003#003
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xaa5680, 11, 2, 0x7fbdf2a25f28), fd_no=1
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: tls [tls_domain.c:736]: sr_ssl_ctx_info_callback(): SSL handshake done
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: tls [tls_domain.c:740]: sr_ssl_ctx_info_callback(): SSL disable renegotiation
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: tls [tls_server.c:415]: tls_accept(): TLS accept successful
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: tls [tls_server.c:422]: tls_accept(): tls_accept: new connection from 37.77.127.147:35906 using TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384 256
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: tls [tls_server.c:425]: tls_accept(): tls_accept: local socket: 195.201.132.99:5061
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: tls [tls_server.c:436]: tls_accept(): tls_accept: client did not present a certificate
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/tcp_main.c:2460]: tcpconn_do_send(): sending...
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= 0x7fbdf2a25f28 n=258 fd=11
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/tcp_main.c:2495]: tcpconn_do_send(): buf=#012#026#003#003
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/tcp_read.c:1540]: tcp_read_req(): content-length=264
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg():  method:  <MESSAGE>
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg():  uri:     <sips:room002@dev.pynlab.com;transport=TLS>
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg():  version: <SIP/2.0>
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPj.Z.jKY.-rqjbw05tczxvsl1hqgmPWSDj>; state=6
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 237, <alias> = <n/a>; state=16
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [31]; uri=[sips:room002@dev.pynlab.com]
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sips:room002@dev.pynlab.com>#015#012]
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <49520> <MESSAGE>
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - request - call-id: [3KayGmm0.QsAWphKP57ypGB8BIOG9xsx] - cseq: [49520 MESSAGE]
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing to run routing scripts...
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=4 a=5 n=route
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[SIP_TRACE_LOG] c=[/etc/kamailio/kamailio_routes.cfg] l=138 a=16 n=if
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[SIP_TRACE_LOG] c=[/etc/kamailio/kamailio_routes.cfg] l=135 a=25 n=is_method
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[SIP_TRACE_LOG] c=[/etc/kamailio/kamailio_routes.cfg] l=136 a=2 n=return
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=7 a=5 n=route
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=183 a=16 n=if
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==9 && [37.77.127.147] == [127.0.0.1]
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==9 && [37.77.127.147] == [127.0.0.1]
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==7 && [37.77.127.147] == [0.0.0.0]
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/socket_info.c:583]: grep_sock_info(): checking advertise if host==us: 13==14 && [37.77.127.147] == [195.201.132.99]
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/forward.c:412]: check_self(): host != me
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=171 a=25 n=is_method
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=190 a=16 n=if
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=195 a=16 n=if
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=190 a=25 n=mf_process_maxfwd_header
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=203 a=16 n=if
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=195 a=25 n=is_method
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=208 a=16 n=if
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=203 a=26 n=sanity_check
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=264
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=Y6PtMn4f5iWSYw672lqeTu8AsprDvBS8
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=213 a=16 n=if
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=208 a=25 n=is_method
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=212 a=16 n=if
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=210 a=2 n=exit
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/receive.c:289]: receive_msg(): request-route executed in: 613 usec
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
May 20 20:43:42 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
May 20 20:43:42 dev /usr/sbin/kamailio[23736]: DEBUG: msilo [msilo.c:1214]: m_clean_silo(): cleaning stored messages - 51560319
May 20 20:43:47 dev /usr/sbin/kamailio[23736]: DEBUG: msilo [msilo.c:1214]: m_clean_silo(): cleaning stored messages - 51560324
May 20 20:43:48 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xaa5680, 11, -1, 0x10) fd_no=2 called
May 20 20:43:48 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/tcp_read.c:1664]: release_tcpconn(): releasing con 0x7fbdf2a25f28, state 1, fd=11, id=6 ([37.77.127.147]:35906 -> [37.77.127.147]:5061)
May 20 20:43:48 dev /usr/sbin/kamailio[23772]: DEBUG: <core> [core/tcp_read.c:1665]: release_tcpconn(): extra_data 0x7fbdf2a409a0
May 20 20:43:48 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:3308]: handle_tcp_child(): reader response= 7fbdf2a25f28, 1 from 7
May 20 20:43:48 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa5bf80, 49, 2, 0x7fbdf2a25f28), fd_no=38
May 20 20:43:48 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:3435]: handle_tcp_child(): CONN_RELEASE  0x7fbdf2a25f28 refcnt= 1
May 20 20:43:52 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xa5bf80, 49, -1, 0x0) fd_no=39 called
May 20 20:43:52 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:4196]: handle_tcpconn_ev(): sending to child, events 1
May 20 20:43:52 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:3878]: send2child(): selected tcp worker 0 21(23765) for activity on [tls:0.0.0.0:5061], 0x7fbdf2a25f28
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/tcp_read.c:1740]: handle_io(): received n=8 con=0x7fbdf2a25f28, fd=11
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/tcp_read.c:1540]: tcp_read_req(): content-length=25
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg():  method:  <MESSAGE>
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg():  uri:     <sips:room002@dev.pynlab.com;transport=TLS>
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg():  version: <SIP/2.0>
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjH-sqvDaQtX52oig1Z9xMlYueNGFkJ4xm>; state=6
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 237, <alias> = <n/a>; state=16
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [31]; uri=[sips:room002@dev.pynlab.com]
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sips:room002@dev.pynlab.com>#015#012]
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <8712> <MESSAGE>
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - request - call-id: [s32551vkfpHNKwAdUPlt8w9smFgAAb3t] - cseq: [8712 MESSAGE]
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing to run routing scripts...
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=4 a=5 n=route
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[SIP_TRACE_LOG] c=[/etc/kamailio/kamailio_routes.cfg] l=138 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[SIP_TRACE_LOG] c=[/etc/kamailio/kamailio_routes.cfg] l=135 a=25 n=is_method
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[SIP_TRACE_LOG] c=[/etc/kamailio/kamailio_routes.cfg] l=136 a=2 n=return
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=7 a=5 n=route
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=183 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==9 && [37.77.127.147] == [127.0.0.1]
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==9 && [37.77.127.147] == [127.0.0.1]
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==7 && [37.77.127.147] == [0.0.0.0]
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/socket_info.c:583]: grep_sock_info(): checking advertise if host==us: 13==14 && [37.77.127.147] == [195.201.132.99]
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/forward.c:412]: check_self(): host != me
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=171 a=25 n=is_method
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=190 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=195 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=190 a=25 n=mf_process_maxfwd_header
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=203 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=195 a=25 n=is_method
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=208 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=203 a=26 n=sanity_check
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=25
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=NXDpIWMgNBoIc34osnQ-PPAFaaRGD8Se
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=213 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=208 a=25 n=is_method
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=212 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=10 a=5 n=route
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=539 a=55 n=force_rport
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=555 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=551 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=545 a=25 n=is_method
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=551 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=548 a=24 n=is_first_hop
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: siputils [sipops.c:159]: is_first_hop(): no 2nd via found - first hop
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=549 a=24 n=set_contact_alias
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=552 a=39 n=setflag
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=555 a=2 n=return
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=23 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=13 a=25 n=is_method
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=23 a=5 n=route
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[WITHINDLG] c=[/etc/kamailio/kamailio_routes.cfg] l=229 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[WITHINDLG] c=[/etc/kamailio/kamailio_routes.cfg] l=219 a=24 n=has_totag
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: siputils [checks.c:120]: has_totag(): no totag
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[WITHINDLG] c=[/etc/kamailio/kamailio_routes.cfg] l=219 a=2 n=return
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=33 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=29 a=24 n=t_precheck_trans
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=33 a=24 n=t_check_trans
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7fbdfdd20280) id=2 global id=0 T start=0xffffffffffffffff
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: tm [t_lookup.c:477]: t_lookup_request(): start searching: hash=56282, isACK=0
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: tm [t_lookup.c:435]: matching_3261(): RFC3261 transaction matching failed
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: tm [t_lookup.c:659]: t_lookup_request(): no transaction found
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg (0x7fbdfdd20280) id=2 global id=2 T end=(nil)
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=48 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=41 a=25 n=is_method
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=71 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=51 a=25 n=xdbg
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <script>: script: message from [sip:651097007@dev.pynlab.com] r-uri [sips:room002@dev.pynlab.com;transport=TLS] msg [#invite 704021003 room002]
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=61 a=16 n=if
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=52 a=25 n=is_method
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=54 a=3 n=log
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=55 a=26 n=sl_send_reply
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: sl [sl_funcs.c:490]: sl_run_callbacks(): execute callback for event type 1
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: siptrace [siptrace.c:1350]: trace_sl_onreply_out(): trace off...
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/tcp_main.c:2226]: tcpconn_send_put(): send from reader (23765 (21)), reusing fd
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/tcp_main.c:2460]: tcpconn_do_send(): sending...
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= 0x7fbdf2a25f28 n=433 fd=11
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/tcp_main.c:2495]: tcpconn_do_send(): buf=#012#027#003#003#001¬·ÝˆV#037£G—܈ˆ â¿S½²#033ðPñÎ_e.¹¯„Ív Œ92‚Âës#003˜…ž§ ü#012æTÓô³YêLzOeeb%èÏewÂ#037Ì2ˆ
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=56 a=24 n=imc_manager
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: ERROR: imc [imc.c:499]: ki_imc_manager(): BODY #invite 704021003 room002
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: imc [imc.c:502]: ki_imc_manager(): found command
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: imc [imc_cmd.c:144]: imc_parse_cmd(): command: [invite]
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: imc [imc_cmd.c:149]: imc_parse_cmd(): parameter 0=[704021003]
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: imc [imc_cmd.c:149]: imc_parse_cmd(): parameter 1=[room002]
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: imc [imc_mng.c:371]: imc_get_member(): found member
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: imc [imc_mng.c:320]: imc_add_member(): [uri]= sip:704021003@dev.pynlab.com
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: imc [imc_mng.c:324]: imc_add_member(): [user]= 704021003
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: imc [imc_cmd.c:484]: imc_handle_invite(): to=[sip:704021003@dev.pynlab.com]#012from=[sip:room002@dev.pynlab.com]#012body=[INVITE from: 704021003@dev.pynlab.com(Type: '#accept' or '#deny')]
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: tm [uac.c:427]: t_uac_prepare(): next_hop=<sip:704021003@dev.pynlab.com>
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/dns_cache.c:542]: _dns_hash_find(): (_sip._udp.dev.pynlab.com(24), 33), h=5
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/resolve.c:744]: get_record(): lookup(_sip._udp.dev.pynlab.com, 33) failed
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/dns_cache.c:871]: dns_cache_mk_bad_entry(): (_sip._udp.dev.pynlab.com, 33, 60, 1)
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/dns_cache.c:805]: dns_cache_add(): adding _sip._udp.dev.pynlab.com(24) 33 (flags=1) at 5
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/dns_cache.c:542]: _dns_hash_find(): (dev.pynlab.com(14), 1), h=696
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: tm [uac.c:152]: dlg2hash(): hashid 5690
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: tm [uac.c:646]: send_prepared_request_impl(): uac: 0x7fbdf2a6c238  branch: 0  to 195.201.132.99:5060
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: tm [../../core/onsend.h:69]: run_onsend(): required parameters are not available - ignoring
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=57 a=2 n=exit
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/receive.c:289]: receive_msg(): request-route executed in: 11030 usec
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
May 20 20:43:52 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xaa5680, 11, 2, 0x7fbdf2a25f28), fd_no=1
May 20 20:43:52 dev /usr/sbin/kamailio[23736]: DEBUG: msilo [msilo.c:1214]: m_clean_silo(): cleaning stored messages - 51560329
May 20 20:43:57 dev /usr/sbin/kamailio[23736]: DEBUG: msilo [msilo.c:1214]: m_clean_silo(): cleaning stored messages - 51560334
May 20 20:43:58 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xaa5680, 11, -1, 0x10) fd_no=2 called
May 20 20:43:58 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/tcp_read.c:1664]: release_tcpconn(): releasing con 0x7fbdf2a25f28, state 1, fd=11, id=6 ([37.77.127.147]:35906 -> [37.77.127.147]:5061)
May 20 20:43:58 dev /usr/sbin/kamailio[23765]: DEBUG: <core> [core/tcp_read.c:1665]: release_tcpconn(): extra_data 0x7fbdf2a409a0
May 20 20:43:58 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:3308]: handle_tcp_child(): reader response= 7fbdf2a25f28, 1 from 0
May 20 20:43:58 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa5bf80, 49, 2, 0x7fbdf2a25f28), fd_no=38
May 20 20:43:58 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:3435]: handle_tcp_child(): CONN_RELEASE  0x7fbdf2a25f28 refcnt= 1
May 20 20:44:02 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/ip_addr.c:229]: print_ip(): tcpconn_new: new tcp connection: 37.77.127.147
May 20 20:44:02 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:999]: tcpconn_new(): on port 36289, type 3
May 20 20:44:02 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:1309]: tcpconn_add(): hashes: 1609:1976:1114, 7
May 20 20:44:02 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa5bf80, 50, 2, 0x7fbdf2a7c0b0), fd_no=39
May 20 20:44:02 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xa5bf80, 50, -1, 0x0) fd_no=40 called
May 20 20:44:02 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:4196]: handle_tcpconn_ev(): sending to child, events 1
May 20 20:44:02 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:3878]: send2child(): selected tcp worker 1 22(23766) for activity on [tls:0.0.0.0:5061], 0x7fbdf2a7c0b0
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/tcp_read.c:1740]: handle_io(): received n=8 con=0x7fbdf2a7c0b0, fd=11
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: tls [tls_server.c:199]: tls_complete_init(): completing tls connection initialization
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: tls [tls_server.c:228]: tls_complete_init(): Using initial TLS domain TLSs<default> (dom 0x7fbdf283eb58 ctx 0x7fbdf28974a0 sn [])
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: tls [tls_domain.c:724]: sr_ssl_ctx_info_callback(): SSL handshake started
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/tcp_main.c:2460]: tcpconn_do_send(): sending...
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= 0x7fbdf2a7c0b0 n=2974 fd=11
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/tcp_main.c:2495]: tcpconn_do_send(): buf=#012#026#003#003
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xaa5680, 11, 2, 0x7fbdf2a7c0b0), fd_no=1
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: tls [tls_domain.c:736]: sr_ssl_ctx_info_callback(): SSL handshake done
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: tls [tls_domain.c:740]: sr_ssl_ctx_info_callback(): SSL disable renegotiation
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: tls [tls_server.c:415]: tls_accept(): TLS accept successful
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: tls [tls_server.c:422]: tls_accept(): tls_accept: new connection from 37.77.127.147:36289 using TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384 256
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: tls [tls_server.c:425]: tls_accept(): tls_accept: local socket: 195.201.132.99:5061
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: tls [tls_server.c:436]: tls_accept(): tls_accept: client did not present a certificate
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/tcp_main.c:2460]: tcpconn_do_send(): sending...
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= 0x7fbdf2a7c0b0 n=258 fd=11
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/tcp_main.c:2495]: tcpconn_do_send(): buf=#012#026#003#003
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/tcp_read.c:1540]: tcp_read_req(): content-length=264
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg():  method:  <MESSAGE>
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg():  uri:     <sips:room002@dev.pynlab.com;transport=TLS>
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg():  version: <SIP/2.0>
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjb53tgvUypUfxAVP3JE33IG0Mti7LxdJf>; state=6
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 237, <alias> = <n/a>; state=16
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [31]; uri=[sips:room002@dev.pynlab.com]
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sips:room002@dev.pynlab.com>#015#012]
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <21738> <MESSAGE>
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - request - call-id: [UtD.tzGUrqp658sgiCsswG5XkExXahlZ] - cseq: [21738 MESSAGE]
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing to run routing scripts...
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=4 a=5 n=route
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[SIP_TRACE_LOG] c=[/etc/kamailio/kamailio_routes.cfg] l=138 a=16 n=if
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[SIP_TRACE_LOG] c=[/etc/kamailio/kamailio_routes.cfg] l=135 a=25 n=is_method
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[SIP_TRACE_LOG] c=[/etc/kamailio/kamailio_routes.cfg] l=136 a=2 n=return
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=7 a=5 n=route
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=183 a=16 n=if
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==9 && [37.77.127.147] == [127.0.0.1]
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==9 && [37.77.127.147] == [127.0.0.1]
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==7 && [37.77.127.147] == [0.0.0.0]
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/socket_info.c:583]: grep_sock_info(): checking advertise if host==us: 13==14 && [37.77.127.147] == [195.201.132.99]
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/forward.c:412]: check_self(): host != me
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=171 a=25 n=is_method
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=190 a=16 n=if
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=195 a=16 n=if
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=190 a=25 n=mf_process_maxfwd_header
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=203 a=16 n=if
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=195 a=25 n=is_method
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=208 a=16 n=if
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=203 a=26 n=sanity_check
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=264
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=YxAZ238hjrNKzwbGOxUxPQW2SIO8LMIn
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=213 a=16 n=if
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=208 a=25 n=is_method
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=212 a=16 n=if
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=210 a=2 n=exit
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/receive.c:289]: receive_msg(): request-route executed in: 704 usec
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
May 20 20:44:02 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
May 20 20:44:02 dev /usr/sbin/kamailio[23736]: DEBUG: msilo [msilo.c:1214]: m_clean_silo(): cleaning stored messages - 51560339
May 20 20:44:07 dev /usr/sbin/kamailio[23736]: DEBUG: msilo [msilo.c:1214]: m_clean_silo(): cleaning stored messages - 51560344
May 20 20:44:08 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xaa5680, 11, -1, 0x10) fd_no=2 called
May 20 20:44:08 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/tcp_read.c:1664]: release_tcpconn(): releasing con 0x7fbdf2a7c0b0, state 1, fd=11, id=7 ([37.77.127.147]:36289 -> [37.77.127.147]:5061)
May 20 20:44:08 dev /usr/sbin/kamailio[23766]: DEBUG: <core> [core/tcp_read.c:1665]: release_tcpconn(): extra_data 0x7fbdf2a2db18
May 20 20:44:08 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:3308]: handle_tcp_child(): reader response= 7fbdf2a7c0b0, 1 from 1
May 20 20:44:08 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xa5bf80, 50, 2, 0x7fbdf2a7c0b0), fd_no=39
May 20 20:44:08 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:3435]: handle_tcp_child(): CONN_RELEASE  0x7fbdf2a7c0b0 refcnt= 1
May 20 20:44:09 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/io_wait.h:602]: io_watch_del(): DBG: io_watch_del (0xa5bf80, 50, -1, 0x0) fd_no=40 called
May 20 20:44:09 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:4196]: handle_tcpconn_ev(): sending to child, events 1
May 20 20:44:09 dev /usr/sbin/kamailio[23773]: DEBUG: <core> [core/tcp_main.c:3878]: send2child(): selected tcp worker 2 23(23767) for activity on [tls:0.0.0.0:5061], 0x7fbdf2a7c0b0
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/tcp_read.c:1740]: handle_io(): received n=8 con=0x7fbdf2a7c0b0, fd=11
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/tcp_read.c:1540]: tcp_read_req(): content-length=15
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg():  method:  <MESSAGE>
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg():  uri:     <sips:room002@dev.pynlab.com;transport=TLS>
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg():  version: <SIP/2.0>
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKPjqh8tjTMEwA1J8Q0Po93DllWCft4Hz-WA>; state=6
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 237, <alias> = <n/a>; state=16
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [31]; uri=[sips:room002@dev.pynlab.com]
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body [<sips:room002@dev.pynlab.com>#015#012]
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <29567> <MESSAGE>
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/receive.c:205]: receive_msg(): --- received sip message - request - call-id: [8UDGmawPuNWXuk8iDNJuE9ekNCiH1mVN] - cseq: [29567 MESSAGE]
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing to run routing scripts...
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=4 a=5 n=route
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[SIP_TRACE_LOG] c=[/etc/kamailio/kamailio_routes.cfg] l=138 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[SIP_TRACE_LOG] c=[/etc/kamailio/kamailio_routes.cfg] l=135 a=25 n=is_method
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[SIP_TRACE_LOG] c=[/etc/kamailio/kamailio_routes.cfg] l=136 a=2 n=return
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=7 a=5 n=route
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=183 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==9 && [37.77.127.147] == [127.0.0.1]
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==9 && [37.77.127.147] == [127.0.0.1]
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/socket_info.c:564]: grep_sock_info(): checking if host==us: 13==7 && [37.77.127.147] == [0.0.0.0]
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/socket_info.c:583]: grep_sock_info(): checking advertise if host==us: 13==14 && [37.77.127.147] == [195.201.132.99]
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/forward.c:412]: check_self(): host != me
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=171 a=25 n=is_method
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=190 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=195 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=190 a=25 n=mf_process_maxfwd_header
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 70
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=203 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=195 a=25 n=is_method
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=208 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=203 a=26 n=sanity_check
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=15
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=I5suPLl6lYTIqikf8qYpr6QWNEqeaR30
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=213 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=208 a=25 n=is_method
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[REQINIT] c=[/etc/kamailio/kamailio_routes.cfg] l=212 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=10 a=5 n=route
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=539 a=55 n=force_rport
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=555 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=551 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=545 a=25 n=is_method
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=551 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=548 a=24 n=is_first_hop
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: siputils [sipops.c:159]: is_first_hop(): no 2nd via found - first hop
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=549 a=24 n=set_contact_alias
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=552 a=39 n=setflag
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[NATDETECT] c=[/etc/kamailio/kamailio_routes.cfg] l=555 a=2 n=return
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=23 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=13 a=25 n=is_method
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=23 a=5 n=route
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[WITHINDLG] c=[/etc/kamailio/kamailio_routes.cfg] l=229 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[WITHINDLG] c=[/etc/kamailio/kamailio_routes.cfg] l=219 a=24 n=has_totag
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: siputils [checks.c:120]: has_totag(): no totag
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[WITHINDLG] c=[/etc/kamailio/kamailio_routes.cfg] l=219 a=2 n=return
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=33 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=29 a=24 n=t_precheck_trans
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=33 a=24 n=t_check_trans
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: tm [t_lookup.c:1019]: t_check_msg(): msg (0x7fbdfdd20280) id=2 global id=1 T start=(nil)
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: tm [t_lookup.c:477]: t_lookup_request(): start searching: hash=1234, isACK=0
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: tm [t_lookup.c:435]: matching_3261(): RFC3261 transaction matching failed
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: tm [t_lookup.c:659]: t_lookup_request(): no transaction found
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: tm [t_lookup.c:1088]: t_check_msg(): msg (0x7fbdfdd20280) id=2 global id=2 T end=(nil)
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=48 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=41 a=25 n=is_method
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=71 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=51 a=25 n=xdbg
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <script>: script: message from [sip:704021003@dev.pynlab.com] r-uri [sips:room002@dev.pynlab.com;transport=TLS] msg [#accept room002]
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=61 a=16 n=if
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=52 a=25 n=is_method
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=54 a=3 n=log
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=55 a=26 n=sl_send_reply
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: sl [sl_funcs.c:490]: sl_run_callbacks(): execute callback for event type 1
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: siptrace [siptrace.c:1350]: trace_sl_onreply_out(): trace off...
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/tcp_main.c:2226]: tcpconn_send_put(): send from reader (23767 (23)), reusing fd
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/tcp_main.c:2460]: tcpconn_do_send(): sending...
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/tcp_main.c:2494]: tcpconn_do_send(): after real write: c= 0x7fbdf2a7c0b0 n=434 fd=11
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/tcp_main.c:2495]: tcpconn_do_send(): buf=#012#027#003#003#001­aÖ*­~‘ÖŒÁ*~Ì#035R9à‹#034¦ÆFîí¯#015sÖvy¯]ß÷zdï}sT ÑSê{#016­^±þKX`#001Öo˜:#013™æØD#005pÓ!3U¨ÛÞ]®#027…*ž)Ûøï>žÆ_=Y3#022$+Hyj6Îc#035#027#016#033ÿŒ#024#012#030¢#036¨±LÚE#002Ó öe#030VÉ›#015 ­—‹VòV2žJÙ)°›^“#013ç#005— ‡¸þ›Â#013$2ª#001Ù«-rAe ;ö-DY(#026 -Ÿú@@5‚#025è.9®‹Àb¯³qãš.bn»v¿²ý,q¶*P—µæèÒšÔb(ÚhòŠv#026FòŠ;fý]#024ƒI#022…ÞütàZrÈ$êln¹ç z”Ç©TÜ‘#015Bƒî£Ñ+vÝÚíûñ#012#005#032[FÐëè¥#024»%_™‹$×½˜3Ú%ÀŒJ#034<©9í{ø#031h•#037"°qß³…–¨óùºñ#012ì1§úPàB‡10veÓö=”Ñ[‹¡Ì‘1#037à#033>±%ƒÖ\Ivœø«úP
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=56 a=24 n=imc_manager
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: ERROR: imc [imc.c:499]: ki_imc_manager(): BODY #accept room002
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: imc [imc.c:502]: ki_imc_manager(): found command
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: imc [imc_cmd.c:144]: imc_parse_cmd(): command: [accept]
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: imc [imc_cmd.c:149]: imc_parse_cmd(): parameter 0=[room002]
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: imc [imc_mng.c:371]: imc_get_member(): found member
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: imc [imc_cmd.c:1097]: imc_room_broadcast(): nr = 2
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: imc [imc_cmd.c:1101]: imc_room_broadcast(): to uri = sip:651097007@dev.pynlab.com
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: tm [uac.c:427]: t_uac_prepare(): next_hop=<sip:651097007@dev.pynlab.com>
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/dns_cache.c:542]: _dns_hash_find(): (_sip._udp.dev.pynlab.com(24), 33), h=5
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/dns_cache.c:542]: _dns_hash_find(): (dev.pynlab.com(14), 1), h=696
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: tm [uac.c:152]: dlg2hash(): hashid 54753
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: tm [uac.c:646]: send_prepared_request_impl(): uac: 0x7fbdf2a9ad58  branch: 0  to 195.201.132.99:5060
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: tm [../../core/onsend.h:69]: run_onsend(): required parameters are not available - ignoring
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: imc [imc_cmd.c:1101]: imc_room_broadcast(): to uri = sip:704021003@dev.pynlab.com
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: tm [uac.c:427]: t_uac_prepare(): next_hop=<sip:704021003@dev.pynlab.com>
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/dns_cache.c:542]: _dns_hash_find(): (_sip._udp.dev.pynlab.com(24), 33), h=5
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/dns_cache.c:542]: _dns_hash_find(): (dev.pynlab.com(14), 1), h=696
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: tm [uac.c:152]: dlg2hash(): hashid 54767
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: tm [uac.c:646]: send_prepared_request_impl(): uac: 0x7fbdf2a9c408  branch: 0  to 195.201.132.99:5060
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: tm [../../core/onsend.h:69]: run_onsend(): required parameters are not available - ignoring
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: exec: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/etc/kamailio/kamailio_routes.cfg] l=57 a=2 n=exit
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/receive.c:289]: receive_msg(): request-route executed in: 3448 usec
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/xavp.c:446]: xavp_destroy_list(): destroying xavp list (nil)
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/receive.c:378]: receive_msg(): cleaning up
May 20 20:44:09 dev /usr/sbin/kamailio[23767]: DEBUG: <core> [core/io_wait.h:380]: io_watch_add(): DBG: io_watch_add(0xaa5680, 11, 2, 0x7fbdf2a7c0b0), fd_no=1
May 20 20:44:12 dev /usr/sbin/kamailio[23736]: DEBUG: msilo [msilo.c:1214]: m_clean_silo(): cleaning stored messages - 51560349