RFC3261 transaction matching failed and get_record(): lookup failed - sr-users

22 May 2020


      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#001aÖ*~‘ÖŒÁ*~Ì#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
http://xn--q-yfa29a.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