<div dir="ltr"><span style="background-color:rgb(255,255,255)">I tried to enable push notifications, but the event E_UL_CONTACT REFRESH never triggered.<br><br>This is a register request.<br>===================================================================================<br>2021/06/24 06:18:07.886057 <a href="http://10.0.2.90:60730">10.0.2.90:60730</a> -> <a href="http://10.0.2.208:5060">10.0.2.208:5060</a><br>REGISTER sip:<a href="http://sip.mydomain.com">sip.mydomain.com</a> SIP/2.0<br>Via: SIP/2.0/UDP 192.168.31.223:59600;branch=z9hG4bK.3xtl2uq~l;rport<br>From: <<a href="mailto:sip%3Auser1@sip.mydomain.com">sip:user1@sip.mydomain.com</a>>;tag=zU9QsB04H<br>To: <a href="mailto:sip%3Auser1@sip.mydomain.com">sip:user1@sip.mydomain.com</a><br>CSeq: 20 REGISTER<br>Call-ID: HG8td6g-yW<br>Max-Forwards: 70<br>Supported: replaces, outbound, gruu<br>Accept: application/sdp<br>Accept: text/plain<br>Accept: application/vnd.gsma.rcs-ft-http+xml<br>Contact: <sip:user1@192.168.31.223:59600;pn-provider=fcm;pn-param=***;pn-prid=***;transport=udp>;+sip.instance="<urn:uuid:8e9c71c9-9279-00c5-99fe-c0f80d147511>"<br>Expires: 30<br>User-Agent: Unknown (belle-sip/4.3.0)</span><div><span style="background-color:rgb(255,255,255)">===================================================================================<br><br>register response<br>
===================================================================================
<br>2021/06/24 06:18:07.905925 <a href="http://10.0.2.208:5060">10.0.2.208:5060</a> -> <a href="http://10.0.2.90:60730">10.0.2.90:60730</a><br>SIP/2.0 200 OK<br>Via: SIP/2.0/UDP 192.168.31.223:59600;received=10.0.2.90;branch=z9hG4bK.3xtl2uq~l;rport=60730<br>From: <<a href="mailto:sip%3Auser1@sip.mydomain.com">sip:user1@sip.mydomain.com</a>>;tag=zU9QsB04H<br>To: <a href="mailto:sip%3Auser1@sip.mydomain.com">sip:user1@sip.mydomain.com</a>;tag=a98d.651a3aa6bda257b01dde8bf25e217bdd<br>CSeq: 20 REGISTER<br>Call-ID: HG8td6g-yW<br>Contact: <sip:user1@192.168.31.223:59600;pn-provider=fcm;pn-param=***;pn-prid=***;transport=udp>;expires=300<br>Server: OpenSIPS (3.1.2 (x86_64/linux))<br>Content-Length: 0<br>===================================================================================<br><br>opensips.cfg<br>
===================================================================================
<br>####### Global Parameters #########<br><br>/* uncomment the following lines to enable debugging */<br>debug_mode=yes<br><br>log_level=4<br>xlog_level=4<br>log_stderror=yes<br>log_facility=LOG_LOCAL0<br><br>udp_workers=4<br><br>/* uncomment the next line to enable the auto temporary blacklisting of<br> not available destinations (default disabled) */<br>#disable_dns_blacklist=no<br><br>/* uncomment the next line to enable IPv6 lookup after IPv4 dns<br> lookup failures (default disabled) */<br>#dns_try_ipv6=yes<br><br><br>socket=udp:<a href="http://10.0.2.208:5060">10.0.2.208:5060</a> # CUSTOMIZE ME<br><br>alias=udp:<a href="http://10.0.2.208:5060">10.0.2.208:5060</a><br>alias=udp:<a href="http://sip.mydomain.com:5060">sip.mydomain.com:5060</a><br><br>db_default_url="mysql://<a href="http://opensips_user:password@127.0.0.1/opensips">opensips_user:password@127.0.0.1/opensips</a>"<br><br>####### Modules Section ########<br><br>#set module path<br>mpath="/usr/lib/x86_64-linux-gnu/opensips/modules/"<br><br>#### SIGNALING module<br>loadmodule "signaling.so"<br><br>#### StateLess module<br>loadmodule "sl.so"<br><br>#### Transaction Module<br>loadmodule "tm.so"<br>modparam("tm", "fr_timeout", 5)<br>modparam("tm", "fr_inv_timeout", 30)<br>modparam("tm", "restart_fr_on_each_reply", 0)<br>modparam("tm", "onreply_avp_mode", 1)<br><br>#### Record Route Module<br>loadmodule "rr.so"<br>/* do not append from tag to the RR (no need for this script) */<br>modparam("rr", "append_fromtag", 0)<br><br>#### MAX ForWarD module<br>loadmodule "maxfwd.so"<br><br>#### SIP MSG OPerationS module<br>loadmodule "sipmsgops.so"<br><br>#### FIFO Management Interface<br>loadmodule "mi_fifo.so"<br>modparam("mi_fifo", "fifo_name", "/tmp/opensips_fifo")<br>modparam("mi_fifo", "fifo_mode", 0666)<br><br>#### MYSQL module<br>loadmodule "db_mysql.so"<br><br>#### USeR LOCation module<br>loadmodule "usrloc.so"<br>modparam("usrloc", "nat_bflag", "NAT")<br>modparam("usrloc", "working_mode_preset", "sql-only")<br>modparam("usrloc", "contact_refresh_timer", true)<br><br>#### REGISTRAR module<br>loadmodule "registrar.so"<br>modparam("registrar", "tcp_persistent_flag", "TCP_PERSISTENT")<br>modparam("registrar", "pn_enable", true)<br>modparam("registrar", "pn_providers", "fcm")<br>modparam("registrar", "pn_enable_purr", true)<br>modparam("registrar", "min_expires", 300)<br><br>#### ACCounting module<br>loadmodule "acc.so"<br>/* what special events should be accounted ? */<br>modparam("acc", "early_media", 0)<br>modparam("acc", "report_cancels", 0)<br>/* by default we do not adjust the direct of the sequential requests.<br> if you enable this parameter, be sure to enable "append_fromtag"<br> in "rr" module */<br>modparam("acc", "detect_direction", 0)<br><br>loadmodule "event_routing.so"<br>loadmodule "event_route.so"<br><br>loadmodule "proto_udp.so"<br><br>####### Routing Logic ########<br><br># main request routing logic<br><br>route{<br><br> if (!mf_process_maxfwd_header(10)) {<br> send_reply(483,"Too Many Hops");<br> exit;<br> }<br><br> if (has_totag()) {<br><br> # handle hop-by-hop ACK (no routing required)<br> if ( is_method("ACK") && t_check_trans() ) {<br> t_relay();<br> exit;<br> }<br><br> # sequential request within a dialog should<br> # take the path determined by record-routing<br> if ( !loose_route() ) {<br> # we do record-routing for all our traffic, so we should not<br> # receive any sequential requests without Route hdr.<br> send_reply(404,"Not here");<br> exit;<br> }<br><br> if (!is_method("ACK")) {<br> async (pn_process_purr("location"), resume_route);<br> }<br><br> # route it out to whatever destination was set by loose_route()<br> # in $du (destination URI).<br> route(resume_route);<br> exit;<br> }<br><br> # CANCEL processing<br> if (is_method("CANCEL")) {<br> if (t_check_trans())<br> t_relay();<br> exit;<br> }<br><br> # absorb retransmissions, but do not create transaction<br> t_check_trans();<br><br> if ( !(is_method("REGISTER") ) ) {<br><br> if (is_myself("$fd")) {<br><br> } else {<br> # if caller is not local, then called number must be local<br><br> if (!is_myself("$rd")) {<br> send_reply(403,"Relay Forbidden");<br> exit;<br> }<br> }<br><br> }<br><br> # preloaded route checking<br> if (loose_route()) {<br> xlog("L_ERR",<br> "Attempt to route with preloaded Route's [$fu/$tu/$ru/$ci]");<br> if (!is_method("ACK"))<br> send_reply(403,"Preload Route denied");<br> exit;<br> }<br><br> # record routing<br> if (!is_method("REGISTER|MESSAGE"))<br> record_route();<br><br> # account only INVITEs<br> if (is_method("INVITE")) {<br><br> do_accounting("log");<br> }<br><br><br> if (!is_myself("$rd")) {<br> append_hf("P-hint: outbound\r\n");<br><br> route(relay);<br> }<br><br> # requests for my domain<br><br> if (is_method("PUBLISH|SUBSCRIBE")) {<br> send_reply(503, "Service Unavailable");<br> exit;<br> }<br><br> if (is_method("REGISTER")) {<br> # store the registration and generate a SIP reply<br> if (!save("location"))<br> xlog("failed to register AoR $tu\n");<br><br> exit;<br> }<br><br> if ($rU==NULL) {<br> # request with no Username in RURI<br> send_reply(484,"Address Incomplete");<br> exit;<br> }<br><br> # do lookup with method filtering<br> #if (!lookup("location","m")) {<br> # t_reply(404, "Not Found");<br> # exit;<br> #}<br><br> $avp(skip_relay) = false;<br><br> lookup("location","m");<br> $var(rc) = $retcode;<br> switch ($var(rc)) {<br> case 1:<br> break;<br> case 2:<br> $avp(skip_relay) = true;<br> break;<br> default:<br> t_reply(404, "Not Found");<br> exit;<br> }<br><br> # when routing via usrloc, log the missed calls also<br> do_accounting("log","missed");<br> route(relay);<br>}<br><br><br>route[relay] {<br> # for INVITEs enable some additional helper routes<br> if (is_method("INVITE")) {<br> t_on_branch("per_branch_ops");<br> t_on_reply("handle_nat");<br> t_on_failure("missed_call");<br> }<br><br> if (!$avp(skip_relay) && !t_relay()) {<br> send_reply(500,"Internal Error");<br> }<br> exit;<br>}<br><br><br><br><br>branch_route[per_branch_ops] {<br> xlog("new branch at $ru\n");<br>}<br><br><br>onreply_route[handle_nat] {<br> xlog("incoming reply\n");<br>}<br><br><br>failure_route[missed_call] {<br> if (t_was_cancelled()) {<br> exit;<br> }<br><br> # uncomment the following lines if you want to block client<br> # redirect based on 3xx replies.<br> ##if (t_check_status("3[0-9][0-9]")) {<br> ##t_reply(404,"Not found");<br> ## exit;<br> ##}<br><br><br>}<br><br>event_route [E_UL_CONTACT_REFRESH]<br>{<br> xlog("L_INFO", "E_UL_CONTACT_REFRESH\n");<br>}<br><br>route [resume_route] {<br><br> if (is_method("BYE")) {<br> # do accounting even if the transaction fails<br> do_accounting("log","failed");<br> }<br><br> route(relay);<br> exit;<br>}<br>
===================================================================================</span></div><div><span style="background-color:rgb(255,255,255)">
<br>startup log<br></span> =================================================================================== <span style="background-color:rgb(255,255,255)"><br>Jun 24 06:16:03 [196] DBG:core:load_module: loading module /usr/lib/x86_64-linux-gnu/opensips/modules/signaling.so<br>Jun 24 06:16:03 [196] DBG:core:register_module: register_pv: signaling<br>Jun 24 06:16:03 [196] DBG:core:pv_add_extra: extra items list is not initialized<br>Jun 24 06:16:03 [196] DBG:core:add_module_dependency: adding type 0 dependency signaling - (module tm)<br>Jun 24 06:16:03 [196] DBG:core:add_module_dependency: adding type 0 dependency signaling - (module sl)<br>Jun 24 06:16:03 [196] DBG:core:load_module: loading module /usr/lib/x86_64-linux-gnu/opensips/modules/sl.so<br>Jun 24 06:16:03 [196] DBG:core:load_module: loading module /usr/lib/x86_64-linux-gnu/opensips/modules/tm.so<br>Jun 24 06:16:03 [196] DBG:core:register_module: register_pv: tm<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: tm matches module tm<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <fr_timeout> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: tm matches module tm<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <fr_inv_timeout> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: tm matches module tm<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <restart_fr_on_each_reply> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: tm matches module tm<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <onreply_avp_mode> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/] <br>Jun 24 06:16:03 [196] DBG:core:load_module: loading module /usr/lib/x86_64-linux-gnu/opensips/modules/rr.so<br>Jun 24 06:16:03 [196] DBG:core:register_module: register_pv: rr<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: rr matches module rr<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <append_fromtag> in module rr [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:load_module: loading module /usr/lib/x86_64-linux-gnu/opensips/modules/maxfwd.so<br>Jun 24 06:16:03 [196] DBG:core:load_module: loading module /usr/lib/x86_64-linux-gnu/opensips/modules/sipmsgops.so<br>Jun 24 06:16:03 [196] DBG:core:load_module: loading module /usr/lib/x86_64-linux-gnu/opensips/modules/mi_fifo.so<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: mi_fifo matches module mi_fifo<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <fifo_name> in module mi_fifo [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: mi_fifo matches module mi_fifo<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <fifo_mode> in module mi_fifo [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:load_module: loading module /usr/lib/x86_64-linux-gnu/opensips/modules/db_mysql.so<br>Jun 24 06:16:03 [196] DBG:core:load_module: loading module /usr/lib/x86_64-linux-gnu/opensips/modules/usrloc.so<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: usrloc matches module usrloc<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <nat_bflag> in module usrloc [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: usrloc matches module usrloc<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <working_mode_preset> in module usrloc [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:add_modparam_dependencies: adding modparam dependencies:<br>Jun 24 06:16:03 [196] DBG:core:add_modparam_dependencies: dependency found: usrloc ---> ( sqldb module (null) )<br>Jun 24 06:16:03 [196] DBG:core:add_module_dependency: adding type 2 dependency usrloc - (sqldb module (null))<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: usrloc matches module usrloc<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <contact_refresh_timer> in module usrloc [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:load_module: loading module /usr/lib/x86_64-linux-gnu/opensips/modules/registrar.so<br>Jun 24 06:16:03 [196] DBG:core:add_module_dependency: adding type 2 dependency registrar - (module usrloc)<br>Jun 24 06:16:03 [196] DBG:core:add_module_dependency: adding type 2 dependency registrar - (module signaling)<br>Jun 24 06:16:03 [196] DBG:core:add_module_dependency: adding type 0 dependency registrar - (module tm)<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: registrar matches module registrar<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <tcp_persistent_flag> in module registrar [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: registrar matches module registrar<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <pn_enable> in module registrar [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:add_modparam_dependencies: adding modparam dependencies:<br>Jun 24 06:16:03 [196] DBG:core:add_modparam_dependencies: dependency found: registrar ---> ( module tm )<br>Jun 24 06:16:03 [196] DBG:core:add_module_dependency: adding type 2 dependency registrar - (module tm)<br>Jun 24 06:16:03 [196] DBG:core:add_modparam_dependencies: dependency found: registrar ---> ( module event_routing )<br>Jun 24 06:16:03 [196] DBG:core:add_module_dependency: adding type 2 dependency registrar - (module event_routing)<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: registrar matches module registrar<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <pn_providers> in module registrar [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: registrar matches module registrar<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <pn_enable_purr> in module registrar [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: registrar matches module registrar<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <min_expires> in module registrar [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:load_module: loading module /usr/lib/x86_64-linux-gnu/opensips/modules/acc.so<br>Jun 24 06:16:03 [196] DBG:core:register_module: register_pv: acc<br>Jun 24 06:16:03 [196] DBG:core:add_module_dependency: adding type 2 dependency acc - (module tm)<br>Jun 24 06:16:03 [196] DBG:core:add_module_dependency: adding type 0 dependency acc - (module dialog)<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: acc matches module acc<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <early_media> in module acc [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: acc matches module acc<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <report_cancels> in module acc [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: acc matches module acc<br>Jun 24 06:16:03 [196] DBG:core:set_mod_param_regex: found <detect_direction> in module acc [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:load_module: loading module /usr/lib/x86_64-linux-gnu/opensips/modules/event_routing.so<br>Jun 24 06:16:03 [196] DBG:core:add_module_dependency: adding type 0 dependency event_routing - (module tm)<br>Jun 24 06:16:03 [196] DBG:core:load_module: loading module /usr/lib/x86_64-linux-gnu/opensips/modules/event_route.so<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <mf_process_maxfwd_header> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <mf_process_maxfwd_header> in module maxfwd [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <send_reply> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <send_reply> in module signaling [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <has_totag> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <has_totag> in module sipmsgops [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <is_method> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <is_method> in module sipmsgops [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <t_check_trans> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <t_check_trans> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <t_relay> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <t_relay> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <loose_route> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <loose_route> in module rr [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <send_reply> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <send_reply> in module signaling [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <is_method> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <is_method> in module sipmsgops [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_mod_acmd_export_t: found <pn_process_purr> in module registrar [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <is_method> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <is_method> in module sipmsgops [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <t_check_trans> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <t_check_trans> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <t_relay> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <t_relay> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <t_check_trans> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <t_check_trans> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <is_method> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <is_method> in module sipmsgops [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: found <is_myself> core function<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: found <is_myself> core function<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <send_reply> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <send_reply> in module signaling [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <loose_route> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <loose_route> in module rr [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <is_method> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <is_method> in module sipmsgops [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <send_reply> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <send_reply> in module signaling [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <is_method> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <is_method> in module sipmsgops [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <record_route> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <record_route> in module rr [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <is_method> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <is_method> in module sipmsgops [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <do_accounting> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <do_accounting> in module acc [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: found <is_myself> core function<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <append_hf> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <append_hf> in module sipmsgops [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <is_method> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <is_method> in module sipmsgops [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <send_reply> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <send_reply> in module signaling [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <is_method> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <is_method> in module sipmsgops [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <save> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <save> in module registrar [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <send_reply> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <send_reply> in module signaling [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:__search_avp_map: looking for [skip_relay] avp - found -1<br>Jun 24 06:16:03 [196] DBG:core:new_avp_alias: added alias skip_relay with id 1<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <lookup> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <lookup> in module registrar [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:__search_avp_map: looking for [skip_relay] avp - found 1<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <t_reply> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <t_reply> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <do_accounting> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <do_accounting> in module acc [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <is_method> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <is_method> in module sipmsgops [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <t_on_branch> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <t_on_branch> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <t_on_reply> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <t_on_reply> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <t_on_failure> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <t_on_failure> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:__search_avp_map: looking for [skip_relay] avp - found 1<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <t_relay> not found <br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <t_relay> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <send_reply> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <send_reply> in module signaling [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <t_was_cancelled> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <t_was_cancelled> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <is_method> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <is_method> in module sipmsgops [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_core_cmd_export_t: <do_accounting> not found<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <do_accounting> in module acc [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:solve_module_dependencies: solving dependency event_routing -> module tm<br>Jun 24 06:16:03 [196] DBG:core:solve_module_dependencies: solving dependency acc -> module dialog<br>Jun 24 06:16:03 [196] DBG:core:solve_module_dependencies: module acc soft-depends on module dialog, and it was not loaded -- proceeding<br>Jun 24 06:16:03 [196] DBG:core:solve_module_dependencies: solving dependency acc -> module tm<br>Jun 24 06:16:03 [196] DBG:core:solve_module_dependencies: solving dependency registrar -> module event_routing<br>Jun 24 06:16:03 [196] DBG:core:solve_module_dependencies: solving dependency registrar -> module tm<br>Jun 24 06:16:03 [196] DBG:core:solve_module_dependencies: solving dependency registrar -> module tm<br>Jun 24 06:16:03 [196] DBG:core:solve_module_dependencies: solving dependency registrar -> module signaling<br>Jun 24 06:16:03 [196] DBG:core:solve_module_dependencies: solving dependency registrar -> module usrloc<br>Jun 24 06:16:03 [196] DBG:core:solve_module_dependencies: solving dependency usrloc -> sqldb module<br>Jun 24 06:16:03 [196] DBG:core:solve_module_dependencies: solving dependency signaling -> module sl<br>Jun 24 06:16:03 [196] DBG:core:solve_module_dependencies: solving dependency signaling -> module tm<br>Jun 24 06:16:03 [196] INFO:core:fix_poll_method: using epoll as the IO watch method (auto detected)<br>Jun 24 06:16:03 [196] DBG:core:main: Loaded 1 transport protocols<br>Jun 24 06:16:03 [196] DBG:core:socket2str: <udp:<a href="http://10.0.2.208:5060">10.0.2.208:5060</a>><br>Listening on<br> udp: 10.0.2.208 [10.0.2.208]:5060<br>Aliases:<br> udp: <a href="http://sip.mydomain.com:5060">sip.mydomain.com:5060</a><br> udp: <a href="http://10.0.2.208:5060">10.0.2.208:5060</a><br><br>Jun 24 06:16:03 [196] DBG:core:create_status_pipe: created status pipe, fds=[3, 4]<br>Jun 24 06:16:03 [196] NOTICE:core:main: DEBUG MODE activated<br>Jun 24 06:16:03 [196] NOTICE:core:main: setting UDP children to 2 (found 4)<br>Jun 24 06:16:03 [196] DBG:core:install_sigs: override SIGSEGV handler: success<br>Jun 24 06:16:03 [196] DBG:core:set_core_dump: core dump limits set to 18446744073709551615<br>Jun 24 06:16:03 [196] NOTICE:core:main: version: opensips 3.1.2 (x86_64/linux)<br>Jun 24 06:16:03 [196] NOTICE:core:main: using 32 MB of shared memory, allocator: F_MALLOC<br>Jun 24 06:16:03 [196] NOTICE:core:main: using 16 MB of private process memory, allocator: F_MALLOC<br>Jun 24 06:16:03 [196] WARNING:core:init_reactor_size: shrinking reactor size from 1048576 (autodetected via rlimit) to 41943 (limited by memory of 10% from 16Mb)<br>Jun 24 06:16:03 [196] WARNING:core:init_reactor_size: use 'open_files_limit' to enforce other limit or increase pkg memory<br>Jun 24 06:16:03 [196] INFO:core:init_reactor_size: reactor size 41943 (using up to 1.60Mb of memory per process)<br>Jun 24 06:16:03 [196] DBG:core:ipc_register_handler: IPC type 0 [RPC] registered with handler (nil)<br>Jun 24 06:16:03 [196] DBG:core:__search_avp_map: looking for [serial_branch] avp - found -1<br>Jun 24 06:16:03 [196] DBG:core:new_avp_alias: added alias serial_branch with id 2<br>Jun 24 06:16:03 [196] DBG:core:find_mod_export: <trace_bind_api> in module proto_hep not found<br>Jun 24 06:16:03 [196] DBG:core:trace_prot_bind: <proto_hep> has no bind api function<br>Jun 24 06:16:03 [196] DBG:core:try_load_trace_api: No tracing module used!<br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_CORE_THRESHOLD(0)><br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_CORE_SHM_THRESHOLD(1)><br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_CORE_PKG_THRESHOLD(2)><br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_CORE_PROC_AUTO_SCALE(3)><br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: <load_dlg> not found<br>Jun 24 06:16:03 [196] DBG:acc:mod_preinit: failed to load dialog API - is the dialog module loaded?<br>Jun 24 06:16:03 [196] DBG:core:init_mod: initializing module tm<br>Jun 24 06:16:03 [196] INFO:tm:mod_init: TM - initializing...<br>Jun 24 06:16:03 [196] DBG:core:get_flag_id_by_name: Flag name is null!<br>Jun 24 06:16:03 [196] DBG:tm:init_callid: Call-ID initialization: '6f6ca3702815f552'<br>Jun 24 06:16:03 [196] DBG:tm:lock_initialize: lock initialization started<br>Jun 24 06:16:03 [196] DBG:tm:tm_init_timers: creating 0 parallel timer structures<br>Jun 24 06:16:03 [196] DBG:tm:mod_init: timer set shift is 3<br>Jun 24 06:16:03 [196] DBG:core:MD5StringArray: MD5 calculated: 020bb7acec0d52c399b40c59f5e1f126<br>Jun 24 06:16:03 [196] DBG:core:register_pv_context: Registered new context: request / 0x7fc8b3a2dc00<br>Jun 24 06:16:03 [196] DBG:core:register_pv_context: Context not found<br>Jun 24 06:16:03 [196] DBG:core:register_pv_context: Registered new context: reply / 0x7fc8b3a2c600<br>Jun 24 06:16:03 [196] DBG:core:register_pv_context: Context not found<br>Jun 24 06:16:03 [196] DBG:core:add_pv_context: Registered new context: reply<br>Jun 24 06:16:03 [196] DBG:core:__search_avp_map: looking for [uac_ctx] avp - found -1<br>Jun 24 06:16:03 [196] DBG:core:new_avp_alias: added alias uac_ctx with id 3<br>Jun 24 06:16:03 [196] DBG:tm:tm_init_cluster: tm_replication_cluster not set - not engaging!<br>Jun 24 06:16:03 [196] DBG:core:init_mod: registering stats for tm<br>Jun 24 06:16:03 [196] DBG:core:init_mod: register MI for tm<br>Jun 24 06:16:03 [196] DBG:core:init_mod: initializing module sl<br>Jun 24 06:16:03 [196] INFO:sl:mod_init: Initializing StateLess engine<br>Jun 24 06:16:03 [196] DBG:core:init_mod: registering stats for sl<br>Jun 24 06:16:03 [196] DBG:core:init_mod: initializing module signaling<br>Jun 24 06:16:03 [196] NOTICE:signaling:mod_init: initializing module ...<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <load_tm> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <load_sl> in module sl [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:init_mod: initializing module rr<br>Jun 24 06:16:03 [196] INFO:rr:mod_init: rr - initializing<br>Jun 24 06:16:03 [196] DBG:core:init_mod: initializing module maxfwd<br>Jun 24 06:16:03 [196] INFO:maxfwd:mod_init: initializing...<br>Jun 24 06:16:03 [196] DBG:core:init_mod: initializing module sipmsgops<br>Jun 24 06:16:03 [196] INFO:sipmsgops:mod_init: initializing...<br>Jun 24 06:16:03 [196] DBG:core:init_mod: initializing module mi_fifo<br>Jun 24 06:16:03 [196] DBG:mi_fifo:mi_mod_init: testing fifo existence ...<br>Jun 24 06:16:03 [196] DBG:core:init_mod: initializing module db_mysql<br>Jun 24 06:16:03 [196] DBG:db_mysql:mysql_mod_init: mysql: MySQL client version is 10.3.29<br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_MYSQL_CONNECTION(4)><br>Jun 24 06:16:03 [196] DBG:core:init_mod: initializing module usrloc<br>Jun 24 06:16:03 [196] DBG:usrloc:mod_init: initializing<br>Jun 24 06:16:03 [196] INFO:usrloc:ul_init_locks: locks array size 512<br>Jun 24 06:16:03 [196] DBG:core:get_flag_id_by_name: New flag: [ NAT : 0 ][1]<br>Jun 24 06:16:03 [196] DBG:usrloc:ul_check_config: ul config: db_mode=-1, cluster_mode=5, rrp=0, sql_wm=0<br>Jun 24 06:16:03 [196] DBG:core:find_mod_export: found <db_bind_api> in module db_mysql [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:db_bind_mod: using db bind api for db_mysql<br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_UL_AOR_INSERT(5)><br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_UL_AOR_DELETE(6)><br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_UL_CONTACT_INSERT(7)><br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_UL_CONTACT_UPDATE(8)><br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_UL_CONTACT_DELETE(9)><br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_UL_CONTACT_REFRESH(10)><br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_UL_LATENCY_UPDATE(11)><br>Jun 24 06:16:03 [196] DBG:core:init_mod: registering stats for usrloc<br>Jun 24 06:16:03 [196] DBG:core:init_mod: register MI for usrloc<br>Jun 24 06:16:03 [196] DBG:core:init_mod: initializing module event_routing<br>Jun 24 06:16:03 [196] DBG:core:ipc_register_handler: IPC type 1 [EBR] registered with handler 0x7fc8b2d3a9e0<br>Jun 24 06:16:03 [196] DBG:event_routing:mod_init: trying to load TM API, if available<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <load_tm> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:init_mod: initializing module registrar<br>Jun 24 06:16:03 [196] INFO:registrar:mod_init: initializing...<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <load_sig> in module signaling [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <load_tm> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <ul_bind_usrloc> in module usrloc [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:get_flag_id_by_name: New flag: [ TCP_PERSISTENT : 0 ][0]<br>Jun 24 06:16:03 [196] DBG:core:is_mod_func_used: function record_route found to be used in script<br>Jun 24 06:16:03 [196] DBG:core:is_mod_async_func_used: function pn_process_purr found to be used in script<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <ebr_bind> in module event_routing [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:event_routing:add_ebr_event: Adding new event <E_UL_CONTACT_UPDATE><br>Jun 24 06:16:03 [196] DBG:registrar:pn_init: parsed PN contact param: 'pn-provider'<br>Jun 24 06:16:03 [196] DBG:registrar:pn_init: parsed PN contact param: 'pn-prid'<br>Jun 24 06:16:03 [196] DBG:registrar:pn_init: parsed PN contact param: 'pn-param'<br>Jun 24 06:16:03 [196] DBG:registrar:pn_init: parsed PN provider: 'fcm', hdr: 'Feature-Caps: +sip.pns="fcm";+sip.pnsreg="130";+sip.pnspurr="'<br>Jun 24 06:16:03 [196] DBG:core:init_mod: registering stats for registrar<br>Jun 24 06:16:03 [196] DBG:core:init_mod: initializing module acc<br>Jun 24 06:16:03 [196] INFO:acc:mod_init: initializing...<br>Jun 24 06:16:03 [196] DBG:core:find_mod_cmd_export_t: found <load_tm> in module tm [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:find_mod_export: found <db_bind_api> in module db_mysql [/usr/lib/x86_64-linux-gnu/opensips/modules/]<br>Jun 24 06:16:03 [196] DBG:core:db_bind_mod: using db bind api for db_mysql<br>Jun 24 06:16:03 [196] DBG:core:db_do_init: connection 0x7fc8b5a9fbd0 not found in pool<br>Jun 24 06:16:03 [196] DBG:db_mysql:db_mysql_connect: opening connection: mysql://<a href="http://xxxx:xxxx@127.0.0.1/opensips">xxxx:xxxx@127.0.0.1/opensips</a><br>Jun 24 06:16:03 [196] DBG:db_mysql:db_mysql_connect: connection type is 127.0.0.1 via TCP/IP<br>Jun 24 06:16:03 [196] DBG:db_mysql:db_mysql_connect: protocol version is 10<br>Jun 24 06:16:03 [196] DBG:db_mysql:db_mysql_connect: server version is 5.7.33-google-log<br>Jun 24 06:16:03 [196] DBG:core:db_do_init: connection 0x7fc8b5a9fbd0 inserted in pool as 0x7fc8b5a9fc48<br>Jun 24 06:16:03 [196] DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected<br>Jun 24 06:16:03 [196] DBG:core:db_new_result: allocate 48 bytes for result set at 0x7fc8b5aa02d8<br>Jun 24 06:16:03 [196] DBG:db_mysql:db_mysql_get_columns: 1 columns returned from the query<br>Jun 24 06:16:03 [196] DBG:core:db_allocate_columns: allocate 28 bytes for result columns at 0x7fc8b5aa1670<br>Jun 24 06:16:03 [196] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7fc8b5aa1678)[0]=[table_version]<br>Jun 24 06:16:03 [196] DBG:db_mysql:db_mysql_get_columns: use DB_INT result type<br>Jun 24 06:16:03 [196] DBG:core:db_allocate_rows: allocate 48 bytes for result rows and values at 0x7fc8b5aa16c0<br>Jun 24 06:16:03 [196] DBG:db_mysql:db_mysql_str2val: converting INT [7]<br>Jun 24 06:16:03 [196] DBG:core:db_free_columns: freeing result columns at 0x7fc8b5aa1670<br>Jun 24 06:16:03 [196] DBG:core:db_free_rows: freeing 1 rows<br>Jun 24 06:16:03 [196] DBG:core:db_free_row: freeing row values at 0x7fc8b5aa16d0<br>Jun 24 06:16:03 [196] DBG:core:db_free_rows: freeing rows at 0x7fc8b5aa16c0<br>Jun 24 06:16:03 [196] DBG:core:db_free_result: freeing result set at 0x7fc8b5aa02d8<br>Jun 24 06:16:03 [196] DBG:core:pool_remove: removing connection from the pool<br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_ACC_EVENT(12)><br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_ACC_CDR(13)><br>Jun 24 06:16:03 [196] INFO:core:evi_publish_event: Registered event <E_ACC_MISSED_EVENT(14)><br>Jun 24 06:16:03 [196] DBG:core:init_mod: initializing module event_route<br>Jun 24 06:16:03 [196] NOTICE:event_route:mod_init: initializing module ...<br>Jun 24 06:16:03 [196] DBG:core:init_mod: initializing module proto_udp<br>Jun 24 06:16:03 [196] INFO:core:mod_init: initializing UDP-plain protocol<br>Jun 24 06:16:03 [196] DBG:core:buf_init: initializing...<br>Jun 24 06:16:03 [196] DBG:core:find_mod_export: <trace_bind_api> in module proto_hep not found<br>Jun 24 06:16:03 [196] DBG:core:trace_prot_bind: <proto_hep> has no bind api function<br>Jun 24 06:16:03 [196] DBG:core:init_xlog: failed to load trace protocol!<br>Jun 24 06:16:03 [196] DBG:core:count_module_procs: modules require 1 extra processes<br>Jun 24 06:16:03 [-1] DBG:core:init_pkg_stats: setting stats for 9 processes<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing mf_process_maxfwd_header, /etc/opensips/opensips.cfg:101<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing send_reply, /etc/opensips/opensips.cfg:102<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing has_totag, /etc/opensips/opensips.cfg:106<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing is_method, /etc/opensips/opensips.cfg:109<br>Jun 24 06:16:03 [196] DBG:core:parse_methods: methods 0x4<br>Jun 24 06:16:03 [196] DBG:sipmsgops:fixup_method: using id for method [ACK/4]<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing t_check_trans, /etc/opensips/opensips.cfg:109<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing t_relay, /etc/opensips/opensips.cfg:110<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing loose_route, /etc/opensips/opensips.cfg:116<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing send_reply, /etc/opensips/opensips.cfg:119<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing is_method, /etc/opensips/opensips.cfg:123<br>Jun 24 06:16:03 [196] DBG:core:parse_methods: methods 0x4<br>Jun 24 06:16:03 [196] DBG:sipmsgops:fixup_method: using id for method [ACK/4]<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing async pn_process_purr, /etc/opensips/opensips.cfg:124<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing is_method, /etc/opensips/opensips.cfg:134<br>Jun 24 06:16:03 [196] DBG:core:parse_methods: methods 0x2<br>Jun 24 06:16:03 [196] DBG:sipmsgops:fixup_method: using id for method [CANCEL/2]<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing t_check_trans, /etc/opensips/opensips.cfg:135<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing t_relay, /etc/opensips/opensips.cfg:136<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing t_check_trans, /etc/opensips/opensips.cfg:141<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing is_method, /etc/opensips/opensips.cfg:143<br>Jun 24 06:16:03 [196] DBG:core:parse_methods: methods 0x80<br>Jun 24 06:16:03 [196] DBG:sipmsgops:fixup_method: using id for method [REGISTER/128]<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing is_myself, /etc/opensips/opensips.cfg:145<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing is_myself, /etc/opensips/opensips.cfg:150<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing send_reply, /etc/opensips/opensips.cfg:151<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing loose_route, /etc/opensips/opensips.cfg:159<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing is_method, /etc/opensips/opensips.cfg:162<br>Jun 24 06:16:03 [196] DBG:core:parse_methods: methods 0x4<br>Jun 24 06:16:03 [196] DBG:sipmsgops:fixup_method: using id for method [ACK/4]<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing send_reply, /etc/opensips/opensips.cfg:163<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing is_method, /etc/opensips/opensips.cfg:168<br>Jun 24 06:16:03 [196] DBG:core:parse_methods: methods 0x180<br>Jun 24 06:16:03 [196] DBG:sipmsgops:fixup_method: using id for methods [REGISTER,MESSAGE/384]<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing record_route, /etc/opensips/opensips.cfg:169<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing is_method, /etc/opensips/opensips.cfg:172<br>Jun 24 06:16:03 [196] DBG:core:parse_methods: methods 0x1<br>Jun 24 06:16:03 [196] DBG:sipmsgops:fixup_method: using id for method [INVITE/1]<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing do_accounting, /etc/opensips/opensips.cfg:174<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing is_myself, /etc/opensips/opensips.cfg:178<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing append_hf, /etc/opensips/opensips.cfg:179<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing is_method, /etc/opensips/opensips.cfg:186<br>Jun 24 06:16:03 [196] DBG:core:parse_methods: methods 0x2200<br>Jun 24 06:16:03 [196] DBG:sipmsgops:fixup_method: using id for methods [PUBLISH,SUBSCRIBE/8704]<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing send_reply, /etc/opensips/opensips.cfg:187<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing is_method, /etc/opensips/opensips.cfg:191<br>Jun 24 06:16:03 [196] DBG:core:parse_methods: methods 0x80<br>Jun 24 06:16:03 [196] DBG:sipmsgops:fixup_method: using id for method [REGISTER/128]<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing save, /etc/opensips/opensips.cfg:193<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing send_reply, /etc/opensips/opensips.cfg:201<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing lookup, /etc/opensips/opensips.cfg:213<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing t_reply, /etc/opensips/opensips.cfg:222<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing do_accounting, /etc/opensips/opensips.cfg:227<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing is_method, /etc/opensips/opensips.cfg:281<br>Jun 24 06:16:03 [196] DBG:core:parse_methods: methods 0x8<br>Jun 24 06:16:03 [196] DBG:sipmsgops:fixup_method: using id for method [BYE/8]<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing do_accounting, /etc/opensips/opensips.cfg:283<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing is_method, /etc/opensips/opensips.cfg:234<br>Jun 24 06:16:03 [196] DBG:core:parse_methods: methods 0x1<br>Jun 24 06:16:03 [196] DBG:sipmsgops:fixup_method: using id for method [INVITE/1]<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing t_on_branch, /etc/opensips/opensips.cfg:235<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing t_on_reply, /etc/opensips/opensips.cfg:236<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing t_on_failure, /etc/opensips/opensips.cfg:237<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing t_relay, /etc/opensips/opensips.cfg:240<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing send_reply, /etc/opensips/opensips.cfg:241<br>Jun 24 06:16:03 [196] DBG:core:fix_actions: fixing t_was_cancelled, /etc/opensips/opensips.cfg:260<br>Jun 24 06:16:03 [196] DBG:core:probe_max_sock_buff: getsockopt: rcv is initially 212992<br>Jun 24 06:16:03 [196] DBG:core:probe_max_sock_buff: using rcv buffer of 416 kb<br>Jun 24 06:16:03 [196] DBG:core:start_module_procs: forking process "MI FIFO"/0 for module mi_fifo<br>Jun 24 06:16:03 [196] DBG:core:internal_fork: forking new process "MI FIFO" on slot 1<br>Jun 24 06:16:03 [196] DBG:core:internal_fork: forking new process "time_keeper" on slot 2<br>Jun 24 06:16:03 [196] DBG:core:internal_fork: forking new process "timer" on slot 3<br>Jun 24 06:16:03 [196] DBG:core:internal_fork: forking new process "UDP receiver" on slot 4<br>Jun 24 06:16:03 [197] DBG:core:init_mod_child: type=PROC_MODULE, rank=-2, module=tm<br>Jun 24 06:16:03 [197] DBG:tm:child_init_callid: callid: '<a href="mailto:6f6ca3702815f552-197@10.0.2.208">6f6ca3702815f552-197@10.0.2.208</a>'<br>Jun 24 06:16:03 [197] DBG:core:init_mod_child: type=PROC_MODULE, rank=-2, module=usrloc<br>Jun 24 06:16:03 [197] DBG:core:init_mod_child: type=PROC_MODULE, rank=-2, module=registrar<br>Jun 24 06:16:03 [197] DBG:core:init_mod_child: type=PROC_MODULE, rank=-2, module=acc<br>Jun 24 06:16:03 [197] DBG:core:db_do_init: connection 0x7fc8b5a9c9d8 not found in pool<br>Jun 24 06:16:03 [196] DBG:core:internal_fork: forking new process "UDP receiver" on slot 5<br>Jun 24 06:16:03 [197] DBG:db_mysql:db_mysql_connect: opening connection: mysql://<a href="http://xxxx:xxxx@127.0.0.1/opensips">xxxx:xxxx@127.0.0.1/opensips</a><br>Jun 24 06:16:03 [196] DBG:core:internal_fork: forking new process "UDP receiver" on slot 6<br>Jun 24 06:16:03 [196] DBG:core:internal_fork: forking new process "UDP receiver" on slot 7<br>Jun 24 06:16:03 [196] DBG:core:internal_fork: forking new process "Timer handler" on slot 8<br>Jun 24 06:16:03 [198] DBG:core:run_timer_process_jif: tv = 0, 10000 , m=10, mu=10<br>Jun 24 06:16:03 [202] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (5 on 47) (0x55bd331b7500, 5, 1, (nil),1), fd_no=0/41943<br>Jun 24 06:16:03 [202] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (34 on 47) (0x55bd331b7500, 34, 4, (nil),1), fd_no=1/41943<br>Jun 24 06:16:03 [202] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (7 on 47) (0x55bd331b7500, 7, 4, (nil),1), fd_no=2/41943<br>Jun 24 06:16:03 [202] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (46 on 47) (0x55bd331b7500, 46, 17, 0x7fc8b5a8dcf8,1), fd_no=3/41943<br>Jun 24 06:16:03 [202] DBG:core:init_mod_child: type=CHILD, rank=3, module=tm<br>Jun 24 06:16:03 [202] DBG:tm:child_init_callid: callid: '<a href="mailto:6f6ca3702815f552-202@10.0.2.208">6f6ca3702815f552-202@10.0.2.208</a>'<br>Jun 24 06:16:03 [202] DBG:core:init_mod_child: type=CHILD, rank=3, module=usrloc<br>Jun 24 06:16:03 [202] DBG:core:db_do_init: connection 0x7fc8b5cdb220 not found in pool<br>Jun 24 06:16:03 [202] DBG:db_mysql:db_mysql_connect: opening connection: mysql://<a href="http://xxxx:xxxx@127.0.0.1/opensips">xxxx:xxxx@127.0.0.1/opensips</a><br>Jun 24 06:16:03 [204] DBG:core:io_watch_add: [Timer_extra] io_watch_add op (42 on 47) (0x55bd331b7500, 42, 4, (nil),1), fd_no=0/41943<br>Jun 24 06:16:03 [204] DBG:core:io_watch_add: [Timer_extra] io_watch_add op (5 on 47) (0x55bd331b7500, 5, 1, (nil),1), fd_no=1/41943<br>Jun 24 06:16:03 [204] DBG:core:init_mod_child: type=CHILD, rank=5, module=tm<br>Jun 24 06:16:03 [204] DBG:tm:child_init_callid: callid: '<a href="mailto:6f6ca3702815f552-204@10.0.2.208">6f6ca3702815f552-204@10.0.2.208</a>'<br>Jun 24 06:16:03 [204] DBG:core:init_mod_child: type=CHILD, rank=5, module=usrloc<br>Jun 24 06:16:03 [204] DBG:core:db_do_init: connection 0x7fc8b5cdb220 not found in pool<br>Jun 24 06:16:03 [204] DBG:db_mysql:db_mysql_connect: opening connection: mysql://<a href="http://xxxx:xxxx@127.0.0.1/opensips">xxxx:xxxx@127.0.0.1/opensips</a><br>Jun 24 06:16:03 [199] DBG:core:run_timer_process: tv = 0, 100000 , m=10<br>Jun 24 06:16:03 [201] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (5 on 47) (0x55bd331b7500, 5, 1, (nil),1), fd_no=0/41943<br>Jun 24 06:16:03 [201] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (30 on 47) (0x55bd331b7500, 30, 4, (nil),1), fd_no=1/41943<br>Jun 24 06:16:03 [203] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (5 on 47) (0x55bd331b7500, 5, 1, (nil),1), fd_no=0/41943<br>Jun 24 06:16:03 [200] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (5 on 47) (0x55bd331b7500, 5, 1, (nil),1), fd_no=0/41943<br>Jun 24 06:16:03 [201] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (7 on 47) (0x55bd331b7500, 7, 4, (nil),1), fd_no=2/41943<br>Jun 24 06:16:03 [201] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (46 on 47) (0x55bd331b7500, 46, 17, 0x7fc8b5a8dcf8,1), fd_no=3/41943<br>Jun 24 06:16:03 [201] DBG:core:init_mod_child: type=CHILD, rank=2, module=tm<br>Jun 24 06:16:03 [203] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (38 on 47) (0x55bd331b7500, 38, 4, (nil),1), fd_no=1/41943<br>Jun 24 06:16:03 [201] DBG:tm:child_init_callid: callid: '<a href="mailto:6f6ca3702815f552-201@10.0.2.208">6f6ca3702815f552-201@10.0.2.208</a>'<br>Jun 24 06:16:03 [201] DBG:core:init_mod_child: type=CHILD, rank=2, module=usrloc<br>Jun 24 06:16:03 [201] DBG:core:db_do_init: connection 0x7fc8b5cdb220 not found in pool<br>Jun 24 06:16:03 [203] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (7 on 47) (0x55bd331b7500, 7, 4, (nil),1), fd_no=2/41943<br>Jun 24 06:16:03 [200] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (26 on 47) (0x55bd331b7500, 26, 4, (nil),1), fd_no=1/41943<br>Jun 24 06:16:03 [201] DBG:db_mysql:db_mysql_connect: opening connection: mysql://<a href="http://xxxx:xxxx@127.0.0.1/opensips">xxxx:xxxx@127.0.0.1/opensips</a><br>Jun 24 06:16:03 [203] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (46 on 47) (0x55bd331b7500, 46, 17, 0x7fc8b5a8dcf8,1), fd_no=3/41943<br>Jun 24 06:16:03 [197] DBG:db_mysql:db_mysql_connect: connection type is 127.0.0.1 via TCP/IP<br>Jun 24 06:16:03 [200] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (7 on 47) (0x55bd331b7500, 7, 4, (nil),1), fd_no=2/41943<br>Jun 24 06:16:03 [197] DBG:db_mysql:db_mysql_connect: protocol version is 10<br>Jun 24 06:16:03 [197] DBG:db_mysql:db_mysql_connect: server version is 5.7.33-google-log<br>Jun 24 06:16:03 [197] DBG:core:db_do_init: connection 0x7fc8b5a9c9d8 inserted in pool as 0x7fc8b5a9ad40<br>Jun 24 06:16:03 [197] DBG:core:init_mod_child: type=PROC_MODULE, rank=-2, module=event_route<br>Jun 24 06:16:03 [197] DBG:mi_fifo:fifo_process: new process with pid = 197 created<br>Jun 24 06:16:03 [197] DBG:mi_fifo:mi_create_fifo: FIFO created @ /tmp/opensips_fifo<br>Jun 24 06:16:03 [197] DBG:mi_fifo:mi_create_fifo: fifo /tmp/opensips_fifo opened, mode=666<br>Jun 24 06:16:03 [197] DBG:core:db_do_init: connection 0x7fc8b5a9a9a8 found in pool as 0x7fc8b5a9ad40<br>Jun 24 06:16:03 [203] DBG:core:init_mod_child: type=CHILD, rank=4, module=tm<br>Jun 24 06:16:03 [203] DBG:tm:child_init_callid: callid: '<a href="mailto:6f6ca3702815f552-203@10.0.2.208">6f6ca3702815f552-203@10.0.2.208</a>'<br>Jun 24 06:16:03 [203] DBG:core:init_mod_child: type=CHILD, rank=4, module=usrloc<br>Jun 24 06:16:03 [203] DBG:core:db_do_init: connection 0x7fc8b5cdb220 not found in pool<br>Jun 24 06:16:03 [203] DBG:db_mysql:db_mysql_connect: opening connection: mysql://<a href="http://xxxx:xxxx@127.0.0.1/opensips">xxxx:xxxx@127.0.0.1/opensips</a><br>Jun 24 06:16:03 [200] DBG:core:io_watch_add: [UDP_worker] io_watch_add op (46 on 47) (0x55bd331b7500, 46, 17, 0x7fc8b5a8dcf8,1), fd_no=3/41943<br>Jun 24 06:16:03 [200] DBG:core:init_mod_child: type=CHILD, rank=1, module=tm<br>Jun 24 06:16:03 [200] DBG:tm:child_init_callid: callid: '<a href="mailto:6f6ca3702815f552-200@10.0.2.208">6f6ca3702815f552-200@10.0.2.208</a>'<br>Jun 24 06:16:03 [200] DBG:core:init_mod_child: type=CHILD, rank=1, module=usrloc<br>Jun 24 06:16:03 [200] DBG:core:db_do_init: connection 0x7fc8b5cdb220 not found in pool<br>Jun 24 06:16:03 [200] DBG:db_mysql:db_mysql_connect: opening connection: mysql://<a href="http://xxxx:xxxx@127.0.0.1/opensips">xxxx:xxxx@127.0.0.1/opensips</a><br>Jun 24 06:16:03 [202] DBG:db_mysql:db_mysql_connect: connection type is 127.0.0.1 via TCP/IP<br>Jun 24 06:16:03 [202] DBG:db_mysql:db_mysql_connect: protocol version is 10<br>Jun 24 06:16:03 [202] DBG:db_mysql:db_mysql_connect: server version is 5.7.33-google-log<br>Jun 24 06:16:03 [202] DBG:core:db_do_init: connection 0x7fc8b5cdb220 inserted in pool as 0x7fc8b5cdb3d8<br>Jun 24 06:16:03 [202] DBG:core:init_mod_child: type=CHILD, rank=3, module=registrar<br>Jun 24 06:16:03 [202] DBG:core:init_mod_child: type=CHILD, rank=3, module=acc<br>Jun 24 06:16:03 [202] DBG:core:db_do_init: connection 0x7fc8b5cdbb18 found in pool as 0x7fc8b5cdb3d8<br>Jun 24 06:16:03 [204] DBG:db_mysql:db_mysql_connect: connection type is 127.0.0.1 via TCP/IP<br>Jun 24 06:16:03 [204] DBG:db_mysql:db_mysql_connect: protocol version is 10<br>Jun 24 06:16:03 [204] DBG:db_mysql:db_mysql_connect: server version is 5.7.33-google-log<br>Jun 24 06:16:03 [204] DBG:core:db_do_init: connection 0x7fc8b5cdb220 inserted in pool as 0x7fc8b5cdb3d8<br>Jun 24 06:16:03 [204] DBG:core:init_mod_child: type=CHILD, rank=5, module=registrar<br>Jun 24 06:16:03 [204] DBG:core:init_mod_child: type=CHILD, rank=5, module=acc<br>Jun 24 06:16:03 [204] DBG:core:db_do_init: connection 0x7fc8b5cdbb18 found in pool as 0x7fc8b5cdb3d8<br>Jun 24 06:16:03 [204] DBG:core:init_mod_child: type=CHILD, rank=5, module=event_route<br>Jun 24 06:16:03 [202] DBG:core:init_mod_child: type=CHILD, rank=3, module=event_route<br>Jun 24 06:16:03 [201] DBG:db_mysql:db_mysql_connect: connection type is 127.0.0.1 via TCP/IP<br>Jun 24 06:16:03 [201] DBG:db_mysql:db_mysql_connect: protocol version is 10<br>Jun 24 06:16:03 [201] DBG:db_mysql:db_mysql_connect: server version is 5.7.33-google-log<br>Jun 24 06:16:03 [201] DBG:core:db_do_init: connection 0x7fc8b5cdb220 inserted in pool as 0x7fc8b5cdb3d8<br>Jun 24 06:16:03 [201] DBG:core:init_mod_child: type=CHILD, rank=2, module=registrar<br>Jun 24 06:16:03 [201] DBG:core:init_mod_child: type=CHILD, rank=2, module=acc<br>Jun 24 06:16:03 [201] DBG:core:db_do_init: connection 0x7fc8b5cdbb18 found in pool as 0x7fc8b5cdb3d8<br>Jun 24 06:16:03 [201] DBG:core:init_mod_child: type=CHILD, rank=2, module=event_route<br>Jun 24 06:16:03 [203] DBG:db_mysql:db_mysql_connect: connection type is 127.0.0.1 via TCP/IP<br>Jun 24 06:16:03 [203] DBG:db_mysql:db_mysql_connect: protocol version is 10<br>Jun 24 06:16:03 [203] DBG:db_mysql:db_mysql_connect: server version is 5.7.33-google-log<br>Jun 24 06:16:03 [203] DBG:core:db_do_init: connection 0x7fc8b5cdb220 inserted in pool as 0x7fc8b5cdb3d8<br>Jun 24 06:16:03 [203] DBG:core:init_mod_child: type=CHILD, rank=4, module=registrar<br>Jun 24 06:16:03 [203] DBG:core:init_mod_child: type=CHILD, rank=4, module=acc<br>Jun 24 06:16:03 [203] DBG:core:db_do_init: connection 0x7fc8b5cdbb18 found in pool as 0x7fc8b5cdb3d8<br>Jun 24 06:16:03 [203] DBG:core:init_mod_child: type=CHILD, rank=4, module=event_route<br>Jun 24 06:16:03 [200] DBG:db_mysql:db_mysql_connect: connection type is 127.0.0.1 via TCP/IP<br>Jun 24 06:16:03 [200] DBG:db_mysql:db_mysql_connect: protocol version is 10<br>Jun 24 06:16:03 [200] DBG:db_mysql:db_mysql_connect: server version is 5.7.33-google-log<br>Jun 24 06:16:03 [200] DBG:core:db_do_init: connection 0x7fc8b5cdb220 inserted in pool as 0x7fc8b5cdb3d8<br>Jun 24 06:16:03 [200] DBG:core:init_mod_child: type=CHILD, rank=1, module=registrar<br>Jun 24 06:16:03 [200] DBG:core:init_mod_child: type=CHILD, rank=1, module=acc<br>Jun 24 06:16:03 [200] DBG:core:db_do_init: connection 0x7fc8b5cdbb18 found in pool as 0x7fc8b5cdb3d8<br>Jun 24 06:16:03 [200] DBG:core:init_mod_child: type=CHILD, rank=1, module=event_route<br>Jun 24 06:16:03 [200] DBG:event_route:child_init: Registering event E_UL_CONTACT_REFRESH<br>Jun 24 06:16:03 [200] DBG:event_route:scriptroute_parse: route is <E_UL_CONTACT_REFRESH> idx 1<br>Jun 24 06:16:03 [200] DBG:core:evi_event_subscribe: added new subscriber for event 10<br></span>=================================================================================== <span style="background-color:rgb(255,255,255)"><br><br>register request log<br></span>=================================================================================== <span style="background-color:rgb(255,255,255)"><br>Jun 24 06:18:07 [212] DBG:core:parse_msg: SIP Request:<br>Jun 24 06:18:07 [212] DBG:core:parse_msg: method: <REGISTER><br>Jun 24 06:18:07 [212] DBG:core:parse_msg: uri: <sip:<a href="http://sip.mydomain.com">sip.mydomain.com</a>><br>Jun 24 06:18:07 [212] DBG:core:parse_msg: version: <SIP/2.0><br>Jun 24 06:18:07 [212] DBG:core:parse_headers: flags=ffffffffffffffff<br>Jun 24 06:18:07 [212] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK.3xtl2uq~l>; state=6<br>Jun 24 06:18:07 [212] DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17<br>Jun 24 06:18:07 [212] DBG:core:parse_via: end of header reached, state=5<br>Jun 24 06:18:07 [212] DBG:core:parse_headers: via found, flags=ffffffffffffffff<br>Jun 24 06:18:07 [212] DBG:core:parse_headers: this is the first via<br>Jun 24 06:18:07 [212] DBG:core:_parse_to: end of header reached, state=9<br>Jun 24 06:18:07 [212] DBG:core:_parse_to: display={}, ruri={<a href="mailto:sip%3Auser1@sip.mydomain.com">sip:user1@sip.mydomain.com</a>}<br>Jun 24 06:18:07 [212] DBG:core:get_hdr_field: <To> [39]; uri=[<a href="mailto:sip%3Auser1@sip.mydomain.com">sip:user1@sip.mydomain.com</a>]<br>Jun 24 06:18:07 [212] DBG:core:get_hdr_field: to body [<a href="mailto:sip%3Auser1@sip.mydomain.com">sip:user1@sip.mydomain.com</a><br>]<br>Jun 24 06:18:07 [212] DBG:core:get_hdr_field: cseq <CSeq>: <20> <REGISTER><br>Jun 24 06:18:07 [212] DBG:core:get_hdr_field: found end of header<br>Jun 24 06:18:07 [212] DBG:core:receive_msg: After parse_msg...<br>Jun 24 06:18:07 [212] DBG:core:receive_msg: preparing to run routing scripts...<br>Jun 24 06:18:07 [212] DBG:maxfwd:is_maxfwd_present: value = 70<br>Jun 24 06:18:07 [212] DBG:sipmsgops:has_totag: no totag<br>Jun 24 06:18:07 [212] DBG:core:parse_headers: flags=78<br>Jun 24 06:18:07 [212] DBG:tm:t_lookup_request: start searching: hash=51128, isACK=0<br>Jun 24 06:18:07 [212] DBG:tm:matching_3261: RFC3261 transaction matching failed<br>Jun 24 06:18:07 [212] DBG:tm:t_lookup_request: no transaction found<br>Jun 24 06:18:07 [212] DBG:core:parse_headers: flags=200<br>Jun 24 06:18:07 [212] DBG:rr:find_first_route: No Route headers found<br>Jun 24 06:18:07 [212] DBG:rr:loose_route: There is no Route HF<br>Jun 24 06:18:07 [212] DBG:core:grep_sock_info_ext: checking if host==us: 27==10 && [<a href="http://sip.mydomain.com">sip.mydomain.com</a>] == [10.0.2.208]<br>Jun 24 06:18:07 [212] DBG:core:parse_headers: flags=ffffffffffffffff<br>Jun 24 06:18:07 [212] DBG:core:parse_params: Parsing params for:[+sip.instance="<urn:uuid:8e9c71c9-9279-00c5-99fe-c0f80d147511>"]<br>Jun 24 06:18:07 [212] DBG:registrar:pn_inspect_request: skip PN processing, matching mode already enforced<br>Jun 24 06:18:07 [212] DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected<br>Jun 24 06:18:07 [212] DBG:core:db_new_result: allocate 48 bytes for result set at 0x7f3279067500<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: 17 columns returned from the query<br>Jun 24 06:18:07 [212] DBG:core:db_allocate_columns: allocate 476 bytes for result columns at 0x7f3279067560<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f32790675e8)[0]=[contact_id]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_BIGINT result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f32790675f8)[1]=[contact]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067608)[2]=[expires]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_INT result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067618)[3]=[q]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_DOUBLE result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067628)[4]=[callid]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067638)[5]=[cseq]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_INT result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067648)[6]=[flags]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_INT result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067658)[7]=[cflags]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067668)[8]=[user_agent]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067678)[9]=[received]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067688)[10]=[path]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067698)[11]=[socket]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f32790676a8)[12]=[methods]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_INT result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f32790676b8)[13]=[last_modified]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_DATETIME result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f32790676c8)[14]=[sip_instance]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f32790676d8)[15]=[kv_store]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_BLOB result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f32790676e8)[16]=[attr]<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_convert_rows: no rows returned from the query<br>Jun 24 06:18:07 [212] DBG:usrloc:db_load_urecord: aor user1 not found in table location<br>Jun 24 06:18:07 [212] DBG:core:db_free_columns: freeing result columns at 0x7f3279067560<br>Jun 24 06:18:07 [212] DBG:core:db_free_rows: freeing 0 rows<br>Jun 24 06:18:07 [212] DBG:core:db_free_result: freeing result set at 0x7f3279067500<br>Jun 24 06:18:07 [212] DBG:core:parse_headers: flags=8000000<br>Jun 24 06:18:07 [212] DBG:core:parse_headers: flags=ffffffffffffffff<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set str domain='location'<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set str aor='user1'<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set str uri='sip:user1@192.168.31.223:59600;pn-provider=fcm;pn-param=***;pn-prid=***;transport=udp'<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set str received=''<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set str path=''<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set int qval=-1<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set str user_agent='Unknown (belle-sip/4.3.0)'<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set str socket='udp:<a href="http://10.0.2.208:5060">10.0.2.208:5060</a>'<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set int bflags=0<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set int expires=1624515787<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set str callid='HG8td6g-yW'<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set int cseq=20<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set str attr=''<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set int latency=0<br>Jun 24 06:18:07 [212] DBG:core:evi_param_set: set str shtag=''<br>Jun 24 06:18:07 [212] DBG:core:get_dummy_sip_msg: allocating new sip msg<br>Jun 24 06:18:07 [212] DBG:core:parse_msg: SIP Request:<br>Jun 24 06:18:07 [212] DBG:core:parse_msg: method: <DUMMY><br>Jun 24 06:18:07 [212] DBG:core:parse_msg: uri: <<a href="mailto:sip%3Auser@dummy.com">sip:user@dummy.com</a>><br>Jun 24 06:18:07 [212] DBG:core:parse_msg: version: <SIP/2.0><br>Jun 24 06:18:07 [212] DBG:core:parse_headers: flags=ffffffffffffffff<br>Jun 24 06:18:07 [212] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bKdummy>; state=16<br>Jun 24 06:18:07 [212] DBG:core:parse_via: end of header reached, state=5<br>Jun 24 06:18:07 [212] DBG:core:parse_headers: via found, flags=ffffffffffffffff<br>Jun 24 06:18:07 [212] DBG:core:parse_headers: this is the first via<br>Jun 24 06:18:07 [212] DBG:core:_parse_to: end of header reached, state=10<br>Jun 24 06:18:07 [212] DBG:core:_parse_to: display={}, ruri={<a href="mailto:sip%3Ato@dummy.com">sip:to@dummy.com</a>}<br>Jun 24 06:18:07 [212] DBG:core:get_hdr_field: <To> [20]; uri=[<a href="mailto:sip%3Ato@dummy.com">sip:to@dummy.com</a>]<br>Jun 24 06:18:07 [212] DBG:core:get_hdr_field: to body [<<a href="mailto:sip%3Ato@dummy.com">sip:to@dummy.com</a>><br>]<br>Jun 24 06:18:07 [212] DBG:core:get_hdr_field: cseq <CSeq>: <1> <DUMMY><br>Jun 24 06:18:07 [212] DBG:core:get_hdr_field: found end of header<br>Jun 24 06:18:07 [212] DBG:core:parse_headers: flags=ffffffffffffffff<br>Jun 24 06:18:07 [212] DBG:core:get_dummy_sip_msg: setting as static to 0x7f3279067770<br>Jun 24 06:18:07 [212] DBG:core:release_dummy_sip_msg: cleaning the static sip msg 0x7f3279067770<br>Jun 24 06:18:07 [212] DBG:core:destroy_avp_list: destroying list (nil)<br>Jun 24 06:18:07 [212] DBG:registrar:pn_add_reply_purr: no need to add +sip.pnspurr for 'fcm'<br>Jun 24 06:18:07 [212] DBG:registrar:build_contact: created Contact HF: Contact: <sip:user1@192.168.31.223:59600;pn-provider=fcm;pn-param=***;pn-prid=***;transport=udp>;expires=300<br><br>Jun 24 06:18:07 [212] DBG:usrloc:db_insert_ucontact: zero map size<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_do_prepared_query: conn=0x7f3279065170 (tail=139854755550168) MC=0x7f3279065470<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_do_prepared_query: new query=|insert into location (username,contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified,sip_instance,kv_store,attr ) values (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)|<br>Jun 24 06:18:07 [212] DBG:db_mysql:re_init_statement: query is <insert into location (username,contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified,sip_instance,kv_store,attr ) values (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)>, ptr=(nil)<br>Jun 24 06:18:07 [212] DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_do_prepared_query: new statement(0x7f32790688b0) on connection: (0x7f3279065170) 0x7f32790653d8<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_val2bind: added val (0): len=5; type=254; is_null=0<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_val2bind: added val (1): len=254; type=254; is_null=0<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_val2bind: added val (2): len=4; type=3; is_null=0<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_val2bind: added val (3): len=8; type=5; is_null=0<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_val2bind: added val (4): len=10; type=254; is_null=0<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_val2bind: added val (5): len=4; type=3; is_null=0<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_val2bind: added val (6): len=4; type=3; is_null=0<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_val2bind: added val (7): len=0; type=254; is_null=0<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_val2bind: added val (8): len=25; type=254; is_null=0<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_val2bind: added val (11): len=19; type=254; is_null=0<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_val2bind: added val (13): len=40; type=12; is_null=0<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_val2bind: added val (14): len=47; type=254; is_null=0<br>Jun 24 06:18:07 [212] DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...<br>Jun 24 06:18:07 [212] DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected<br>Jun 24 06:18:07 [212] DBG:core:MD5StringArray: MD5 calculated: 651a3aa6bda257b01dde8bf25e217bdd<br>Jun 24 06:18:07 [212] DBG:core:parse_headers: flags=ffffffffffffffff<br>Jun 24 06:18:07 [212] DBG:core:destroy_avp_list: destroying list (nil)<br>Jun 24 06:18:07 [212] DBG:core:receive_msg: cleaning up<br>Jun 24 06:18:07 [209] DBG:core:parse_msg: SIP Request:<br>Jun 24 06:18:07 [209] DBG:core:parse_msg: method: <REGISTER><br>Jun 24 06:18:07 [209] DBG:core:parse_msg: uri: <sip:<a href="http://sip.mydomain.com">sip.mydomain.com</a>><br>Jun 24 06:18:07 [209] DBG:core:parse_msg: version: <SIP/2.0><br>Jun 24 06:18:07 [209] DBG:core:parse_headers: flags=ffffffffffffffff<br>Jun 24 06:18:07 [209] DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK.fTP4rkt1q>; state=6<br>Jun 24 06:18:07 [209] DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17<br>Jun 24 06:18:07 [209] DBG:core:parse_via: end of header reached, state=5<br>Jun 24 06:18:07 [209] DBG:core:parse_headers: via found, flags=ffffffffffffffff<br>Jun 24 06:18:07 [209] DBG:core:parse_headers: this is the first via<br>Jun 24 06:18:07 [209] DBG:core:_parse_to: end of header reached, state=9<br>Jun 24 06:18:07 [209] DBG:core:_parse_to: display={}, ruri={<a href="mailto:sip%3Auser1@sip.mydomain.com">sip:user1@sip.mydomain.com</a>}<br>Jun 24 06:18:07 [209] DBG:core:get_hdr_field: <To> [39]; uri=[<a href="mailto:sip%3Auser1@sip.mydomain.com">sip:user1@sip.mydomain.com</a>]<br>Jun 24 06:18:07 [209] DBG:core:get_hdr_field: to body [<a href="mailto:sip%3Auser1@sip.mydomain.com">sip:user1@sip.mydomain.com</a><br>]<br>Jun 24 06:18:07 [209] DBG:core:get_hdr_field: cseq <CSeq>: <21> <REGISTER><br>Jun 24 06:18:07 [209] DBG:core:get_hdr_field: found end of header<br>Jun 24 06:18:07 [209] DBG:core:receive_msg: After parse_msg...<br>Jun 24 06:18:07 [209] DBG:core:receive_msg: preparing to run routing scripts...<br>Jun 24 06:18:07 [209] DBG:maxfwd:is_maxfwd_present: value = 70<br>Jun 24 06:18:07 [209] DBG:sipmsgops:has_totag: no totag<br>Jun 24 06:18:07 [209] DBG:core:parse_headers: flags=78<br>Jun 24 06:18:07 [209] DBG:tm:t_lookup_request: start searching: hash=51129, isACK=0<br>Jun 24 06:18:07 [209] DBG:tm:matching_3261: RFC3261 transaction matching failed<br>Jun 24 06:18:07 [209] DBG:tm:t_lookup_request: no transaction found<br>Jun 24 06:18:07 [209] DBG:core:parse_headers: flags=200<br>Jun 24 06:18:07 [209] DBG:rr:find_first_route: No Route headers found<br>Jun 24 06:18:07 [209] DBG:rr:loose_route: There is no Route HF<br>Jun 24 06:18:07 [209] DBG:core:grep_sock_info_ext: checking if host==us: 27==10 && [<a href="http://sip.mydomain.com">sip.mydomain.com</a>] == [10.0.2.208]<br>Jun 24 06:18:07 [209] DBG:core:parse_headers: flags=ffffffffffffffff<br>Jun 24 06:18:07 [209] DBG:core:parse_params: Parsing params for:[+sip.instance="<urn:uuid:8e9c71c9-9279-00c5-99fe-c0f80d147511>"]<br>Jun 24 06:18:07 [209] DBG:registrar:pn_inspect_request: skip PN processing, matching mode already enforced<br>Jun 24 06:18:07 [209] DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected<br>Jun 24 06:18:07 [209] DBG:core:db_new_result: allocate 48 bytes for result set at 0x7f3279067470<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: 17 columns returned from the query<br>Jun 24 06:18:07 [209] DBG:core:db_allocate_columns: allocate 476 bytes for result columns at 0x7f3279067680<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067708)[0]=[contact_id]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_BIGINT result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067718)[1]=[contact]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067728)[2]=[expires]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_INT result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067738)[3]=[q]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_DOUBLE result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067748)[4]=[callid]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067758)[5]=[cseq]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_INT result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067768)[6]=[flags]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_INT result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067778)[7]=[cflags]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067788)[8]=[user_agent]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067798)[9]=[received]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f32790677a8)[10]=[path]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f32790677b8)[11]=[socket]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f32790677c8)[12]=[methods]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_INT result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f32790677d8)[13]=[last_modified]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_DATETIME result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f32790677e8)[14]=[sip_instance]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f32790677f8)[15]=[kv_store]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_BLOB result type<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7f3279067808)[16]=[attr]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type<br>Jun 24 06:18:07 [209] DBG:core:db_allocate_rows: allocate 560 bytes for result rows and values at 0x7f3279068b28<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_str2val: converting INT BIG[4189995556047270793]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_str2val: converting STRING [sip:user1@192.168.31.223:59600;pn-provider=fcm;pn-param=***;pn-prid=***;transport=udp]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_str2val: converting INT [1624515787]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_str2val: converting DOUBLE [-1.00]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_str2val: converting STRING [HG8td6g-yW]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_str2val: converting INT [20]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_str2val: converting INT [0]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_str2val: converting STRING []<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_str2val: converting STRING [Unknown (belle-sip/4.3.0)]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_str2val: converting STRING [udp:<a href="http://10.0.2.208:5060">10.0.2.208:5060</a>]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_str2val: converting DATETIME [2021-06-24 06:18:07]<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_str2val: converting STRING [<urn:uuid:8e9c71c9-9279-00c5-99fe-c0f80d147511>]<br>Jun 24 06:18:07 [209] DBG:usrloc:dbrow2info: flag str: ''<br>Jun 24 06:18:07 [209] DBG:usrloc:dbrow2info: set flags: 0<br>Jun 24 06:18:07 [209] DBG:core:grep_sock_info_ext: checking if host==us: 10==10 && [10.0.2.208] == [10.0.2.208]<br>Jun 24 06:18:07 [209] DBG:core:grep_sock_info_ext: checking if port 5060 matches port 5060<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str domain='location'<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str aor='user1'<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str uri='sip:user1@192.168.31.223:59600;pn-provider=fcm;pn-param=***;pn-prid=***;transport=udp'<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str received=''<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str path=''<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set int qval=-1<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str user_agent='Unknown (belle-sip/4.3.0)'<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str socket='udp:<a href="http://10.0.2.208:5060">10.0.2.208:5060</a>'<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set int bflags=0<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set int expires=1624515787<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str callid='HG8td6g-yW'<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set int cseq=20<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str attr=''<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set int latency=0<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str shtag=''<br>Jun 24 06:18:07 [209] DBG:core:get_dummy_sip_msg: reusing the static sip msg 0x7f32790678e0<br>Jun 24 06:18:07 [209] DBG:core:release_dummy_sip_msg: cleaning the static sip msg 0x7f32790678e0<br>Jun 24 06:18:07 [209] DBG:core:destroy_avp_list: destroying list (nil)<br>Jun 24 06:18:07 [209] DBG:core:db_free_columns: freeing result columns at 0x7f3279067680<br>Jun 24 06:18:07 [209] DBG:core:db_free_rows: freeing 1 rows<br>Jun 24 06:18:07 [209] DBG:core:db_free_row: freeing row values at 0x7f3279068b38<br>Jun 24 06:18:07 [209] DBG:core:db_free_rows: freeing rows at 0x7f3279068b28<br>Jun 24 06:18:07 [209] DBG:core:db_free_result: freeing result set at 0x7f3279067470<br>Jun 24 06:18:07 [209] DBG:core:parse_headers: flags=8000000<br>Jun 24 06:18:07 [209] DBG:usrloc:get_ucontact: using ct matching mode 0<br>Jun 24 06:18:07 [209] DBG:usrloc:get_ucontact: failed to match any existing contacts<br>Jun 24 06:18:07 [209] DBG:core:parse_headers: flags=ffffffffffffffff<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str domain='location'<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str aor='user1'<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str uri='sip:user1@10.0.2.90:60730;pn-provider=fcm;pn-param=***;pn-prid=***;transport=udp'<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str received=''<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str path=''<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set int qval=-1<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str user_agent='Unknown (belle-sip/4.3.0)'<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str socket='udp:<a href="http://10.0.2.208:5060">10.0.2.208:5060</a>'<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set int bflags=0<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set int expires=1624515787<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str callid='HG8td6g-yW'<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set int cseq=21<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str attr=''<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set int latency=0<br>Jun 24 06:18:07 [209] DBG:core:evi_param_set: set str shtag=''<br>Jun 24 06:18:07 [209] DBG:core:get_dummy_sip_msg: reusing the static sip msg 0x7f32790678e0<br>Jun 24 06:18:07 [209] DBG:core:release_dummy_sip_msg: cleaning the static sip msg 0x7f32790678e0<br>Jun 24 06:18:07 [209] DBG:core:destroy_avp_list: destroying list (nil)<br>Jun 24 06:18:07 [209] DBG:registrar:pn_add_reply_purr: no need to add +sip.pnspurr for 'fcm'<br>Jun 24 06:18:07 [209] DBG:registrar:build_contact: created Contact HF: Contact: <sip:user1@192.168.31.223:59600;pn-provider=fcm;pn-param=***;pn-prid=***;transport=udp>;expires=300, <sip:user1@10.0.2.90:60730;pn-provider=fcm;pn-param=***;pn-prid=***;transport=udp>;expires=300<br><br>Jun 24 06:18:07 [209] DBG:usrloc:db_insert_ucontact: zero map size<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_do_prepared_query: conn=0x7f3279065170 (tail=139854755550168) MC=0x7f3279065470<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_do_prepared_query: new query=|insert into location (username,contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified,sip_instance,kv_store,attr ) values (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)|<br>Jun 24 06:18:07 [209] DBG:db_mysql:re_init_statement: query is <insert into location (username,contact,expires,q,callid,cseq,flags,cflags,user_agent,received,path,socket,methods,last_modified,sip_instance,kv_store,attr ) values (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)>, ptr=(nil)<br>Jun 24 06:18:07 [209] DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_do_prepared_query: new statement(0x7f3279069000) on connection: (0x7f3279065170) 0x7f32790653d8<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_val2bind: added val (0): len=5; type=254; is_null=0<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_val2bind: added val (1): len=249; type=254; is_null=0<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_val2bind: added val (2): len=4; type=3; is_null=0<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_val2bind: added val (3): len=8; type=5; is_null=0<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_val2bind: added val (4): len=10; type=254; is_null=0<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_val2bind: added val (5): len=4; type=3; is_null=0<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_val2bind: added val (6): len=4; type=3; is_null=0<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_val2bind: added val (7): len=0; type=254; is_null=0<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_val2bind: added val (8): len=25; type=254; is_null=0<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_val2bind: added val (11): len=19; type=254; is_null=0<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_val2bind: added val (13): len=40; type=12; is_null=0<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_val2bind: added val (14): len=47; type=254; is_null=0<br>Jun 24 06:18:07 [209] DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...<br>Jun 24 06:18:07 [209] DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected<br>Jun 24 06:18:07 [209] DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected<br>Jun 24 06:18:07 [209] DBG:core:MD5StringArray: MD5 calculated: dfa41a9b0abf079682247285be03936f<br>Jun 24 06:18:07 [209] DBG:core:parse_headers: flags=ffffffffffffffff<br>Jun 24 06:18:07 [209] DBG:core:destroy_avp_list: destroying list (nil)<br>Jun 24 06:18:07 [209] DBG:core:receive_msg: cleaning up<br></span>=================================================================================== <span style="background-color:rgb(255,255,255)"><br><br>database location table<br></span><img src="cid:ii_kqapdidz0" alt="location.PNG" style="margin-right: 25px;"><br><span style="background-color:rgb(255,255,255)"><br><br></span>I already have pn-provide, pn-param and pn-prid but why the flags are still 0?<span style="background-color:rgb(255,255,255)"><br><br></span>Does the problem occur here?<br><font color="#ff0000">DBG:registrar:pn_inspect_request: skip PN processing, matching mode already enforced</font></div><div><font color="#ff0000"><br></font>I don’t know why PN processing was skipped, where can I solve the problem?<span style="background-color:rgb(255,255,255)"><br><br>Thanks!<br><br></span>This is the original question <a href="https://github.com/OpenSIPS/opensips/issues/2556">link</a>.<span style="background-color:rgb(255,255,255)"><br></span>===================================================================================</div><div><span style="background-color:rgb(255,255,255)">google kubernates engine: 1.17.17-gke.4900<br>opensips: 3.1<br>android: 6.0.1</span><br></div></div>