Hi, here is my Opensips.cfg
#
# $Id: opensips_residential.m4 9042 2012-05-17 13:57:10Z vladut-paiu $
#
# OpenSIPS residential configuration script
# by OpenSIPS Solutions <team@opensips-solutions.com>
#
# This script was generated via "make menuconfig", from
# the "Residential" scenario.
# You can enable / disable more features / functionalities by
# re-generating the scenario with different options.#
#
# Please refer to the Core CookBook at:
#
http://www.opensips.org/Resources/DocsCookbooks# for a explanation of possible statements, functions and parameters.
#
####### Global Parameters #########
debug=8
log_stderror=no
log_facility=LOG_LOCAL1
fork=yes
children=4
/* uncomment the following lines to enable debugging */
#debug=6
#fork=no
#log_stderror=yes
/* uncomment the next line to enable the auto temporary blacklisting of
not available destinations (default disabled) */
#disable_dns_blacklist=no
/* uncomment the next line to enable IPv6 lookup after IPv4 dns
lookup failures (default disabled) */
#dns_try_ipv6=yes
/* comment the next line to enable the auto discovery of local aliases
based on revers DNS on IPs */
auto_aliases=no
listen=udp:10.9.23.41:5060 # CUSTOMIZE ME
listen=udp:151.8.12.201:5060
disable_tcp=no
listen=tcp:10.9.23.41:5060 # CUSTOMIZE ME
listen=tcp:151.8.12.201:5060
disable_tls=yes
server_header="Server: Lw-OpenSips Video Proxy"
server_signature=yes
user_agent_header="User-Agent: Lw-OpenSips Video Proxy"
sip_warning=0 ##by Antonio S. (0=No; 1=Si ) Aggiunge l'header "WARNING" in ogni risposta da parte di OPENSIPS. Utile per il DEBUG
#######################################################
# ----------------- Modules Section ----------------- #
#######################################################
#set module path
mpath="/usr/local/opensips_proxy/lib/opensips/modules/"
#### SIGNALING module
loadmodule "signaling.so"
#### StateLess module
loadmodule "sl.so"
#### Transaction Module
loadmodule "tm.so"
modparam("tm", "fr_timer", 5)
modparam("tm", "fr_inv_timer", 30)
modparam("tm", "restart_fr_on_each_reply", 0)
modparam("tm", "onreply_avp_mode", 1)
#### Record Route Module
loadmodule "rr.so"
/* do not append from tag to the RR (no need for this script) */
modparam("rr", "append_fromtag", 0)
#### MAX ForWarD module
loadmodule "maxfwd.so"
#### SIP MSG OPerationS module
loadmodule "sipmsgops.so"
#### FIFO Management Interface
loadmodule "mi_fifo.so"
modparam("mi_fifo", "fifo_name", "/tmp/opensips_fifo")
modparam("mi_fifo", "fifo_mode", 0666)
#### URI module
loadmodule "uri.so"
modparam("uri", "use_uri_table", 0)
modparam("uri", "db_url",
"mysql://opensips:opensipsrw@localhost/opensips")
#### MYSQL module
loadmodule "db_mysql.so"
#### USeR LOCation module
loadmodule "usrloc.so"
modparam("usrloc", "nat_bflag", 10)
modparam("usrloc", "db_mode", 2)
modparam("usrloc", "db_url",
"mysql://opensips:opensipsrw@localhost/opensips") # CUSTOMIZE ME
#### REGISTRAR module
loadmodule "registrar.so"
modparam("registrar", "tcp_persistent_flag", 7)
modparam("registrar", "received_avp", "$avp(received_nh)")
/* uncomment the next line not to allow more than 10 contacts per AOR */
#modparam("registrar", "max_contacts", 10)
#### TEXTOPS module
loadmodule "textops.so"
#### ACCounting module
loadmodule "acc.so"
/* what special events should be accounted ? */
modparam("acc", "early_media", 0)
modparam("acc", "report_cancels", 0)
/* by default we do not adjust the direct of the sequential requests.
if you enable this parameter, be sure the enable "append_fromtag"
in "rr" module */
modparam("acc", "detect_direction", 0)
modparam("acc", "failed_transaction_flag", 3)
/* account triggers (flags) */
modparam("acc", "db_flag", 1)
modparam("acc", "db_missed_flag", 2)
modparam("acc", "db_url",
"mysql://opensips:opensipsrw@localhost/opensips") # CUSTOMIZE ME
#### AUTHentication modules
loadmodule "auth.so"
loadmodule "auth_db.so"
modparam("auth_db", "calculate_ha1", yes)
modparam("auth_db", "password_column", "password")
modparam("auth_db", "db_url",
"mysql://opensips:opensipsrw@localhost/opensips") # CUSTOMIZE ME
modparam("auth_db", "load_credentials", "")
#### ALIAS module
loadmodule "alias_db.so"
modparam("alias_db", "db_url",
"mysql://opensips:opensipsrw@localhost/opensips") # CUSTOMIZE ME
#### DOMAIN module
loadmodule "domain.so"
modparam("domain", "db_url",
"mysql://opensips:opensipsrw@localhost/opensips") # CUSTOMIZE ME
modparam("domain", "db_mode", 1) # Use caching
modparam("auth_db|usrloc|uri", "use_domain", 1)
#### DIALOG module
loadmodule "dialog.so"
modparam("dialog", "dlg_match_mode", 1)
modparam("dialog", "default_timeout", 21600) # 6 hours timeout
modparam("dialog", "db_mode", 2)
modparam("dialog", "db_url",
"mysql://opensips:opensipsrw@localhost/opensips") # CUSTOMIZE ME
#### AVP module
loadmodule "avpops.so"
modparam("avpops", "avp_table", "usr_preferences")
modparam("avpops", "db_url",
"mysql://opensips:opensipsrw@localhost/opensips")
#### NAT module
loadmodule "nathelper.so"
modparam("nathelper", "natping_interval", 5)
modparam("nathelper", "ping_nated_only", 1)
modparam("nathelper", "received_avp", "$avp(received_nh)")
modparam("nathelper", "sipping_bflag", 7)
modparam("nathelper", "sipping_from", "sip:NAT_Pinger@10.9.23.41:5060")
#### RTPProxy module
loadmodule "rtpproxy.so"
modparam("rtpproxy", "rtpproxy_sock", "udp:127.0.0.1:7890") # CUSTOMIZE ME
modparam("rtpproxy", "rtpproxy_autobridge", 1)
#### DIALPLAN module
loadmodule "dialplan.so"
modparam("dialplan", "db_url",
"mysql://opensips:opensipsrw@localhost/opensips") # CUSTOMIZE ME
#### DYNAMMIC ROUTING module
loadmodule "drouting.so"
modparam("drouting", "db_url",
"mysql://opensips:opensipsrw@localhost/opensips") # CUSTOMIZE ME
#### SIP_TRACE_AGENT (Homer) ##by Antonio S.
loadmodule "siptrace.so"
modparam("siptrace", "db_url",
"mysql://opensips:opensipsrw@localhost/opensips")
modparam("siptrace", "duplicate_uri", "sip:10.9.101.168:9060")
modparam("siptrace", "duplicate_with_hep", 1)
modparam("siptrace", "trace_to_database", 0)
modparam("siptrace", "trace_flag", 22)
modparam("siptrace", "trace_on", 1)
modparam("siptrace", "hep_version", 2) #HEPv2 == timestamp will be included to HEP header
#####################################################
# ----------------- Routing Logic ----------------- #
#####################################################
# main request routing logic
route{
if (!mf_process_maxfwd_header("10")) {
send_reply("483","Too Many Hops");
exit;
}
#---- NAT Detection ----#
force_rport();
if (nat_uac_test("19")) {
if (is_method("REGISTER")) {
fix_nated_register();
} else {
fix_nated_contact();
#---- Insert nat=yes at the end of the Contact header ----#
#---- This helps with REINVITEs, ----#
#--- nat=yes will be included in the R-URI for sequential requests ---#
search_append('Contact:.*sip:[^>[:cntrl:]]*', ';nat=yes');
}
setflag(10);
}
#########################################
#----- Sequential requests section -----#
#########################################
if (has_totag()) {
# sequential request withing a dialog should
# take the path determined by record-routing
if (loose_route()) {
# validate the sequential request against dialog
if ( $DLG_status!=NULL && !validate_dialog() ) {
xlog("In-Dialog $rm from $si (callid=$ci) is not valid according to dialog\n");
## exit;
}
if (is_method("BYE")) {
setflag(1); # do accounting ...
setflag(3); # ... even if the transaction fails
} else if (is_method("INVITE")) {
# even if in most of the cases is useless, do RR for
# re-INVITEs alos, as some buggy clients do change route set
# during the dialog.
record_route();
}
if (check_route_param("nat=yes"))
setflag(10);
# route it out to whatever destination was set by loose_route()
# in $du (destination URI).
route(1);
} else {
if ( is_method("ACK") ) {
if ( t_check_trans() ) {
# non loose-route, but stateful ACK; must be an ACK after
# a 487 or e.g. 404 from upstream server
t_relay();
exit;
} else {
# ACK without matching transaction ->
# ignore and discard
exit;
}
}
sl_send_reply("404","Not here");
}
exit;
}
######################################
#----- Initial requests section -----#
######################################
# CANCEL processing
if (is_method("CANCEL"))
{
if (t_check_trans())
t_relay();
exit;
}
#---- catch retransmissions ----#
t_check_trans();
if ( !(is_method("REGISTER") || is_from_gw() ) ) {
if (is_from_local())
{
# authenticate if from local subscriber
# authenticate all initial non-REGISTER request that pretend to be
# generated by local subscriber (domain from FROM URI is local)
if (!proxy_authorize("", "subscriber")) {
proxy_challenge("", "0");
exit;
}
if (!db_check_from()) {
sl_send_reply("403","Forbidden auth ID");
exit;
}
consume_credentials();
# caller authenticated
} else {
# if caller is not local, then called number must be local
if (!is_uri_host_local()) {
send_reply("403","Rely forbidden");
exit;
}
}
}
######################################
#----- Preloaded Route Checking -----#
######################################
if (loose_route()) { ## Alcuni UAC aggiungono l'header "route" al primo INVITE, se ad es settano un outbound proxy!!
xlog("L_ERR",
"Attempt to route with preloaded Route's [$fu/$tu/$ru/$ci]");
if (!is_method("ACK"))
sl_send_reply("403","Preload Route denied");
exit;
}
# record routing
if (!is_method("REGISTER|MESSAGE"))
record_route();
# account only INVITEs
if (is_method("INVITE")) {
# create dialog with timeout
if ( !create_dialog("B") ) {
send_reply("500","Internal Server Error");
exit;
}
setflag(1); # do accounting
}
if (!is_uri_host_local()) {
append_hf("P-hint: outbound\r\n");
route(1);
}
# requests for my domain
if (is_method("PUBLISH"))
{
sl_send_reply("503", "Service Unavailable");
exit;
}
#--- registration handling ----#
if (is_method("REGISTER"))
{
# authenticate the REGISTER requests
if (!www_authorize("", "subscriber"))
{
www_challenge("", "0");
exit;
}
if (!db_check_to())
{
sl_send_reply("403","Forbidden auth ID");
exit;
}
if ( proto==TCP || 0 ) setflag(7);
if (!save("location"))
sl_reply_error();
exit;
}
#---- Request is behind NAT(flag5) save with bflag 6 ----#
#---- Use bflag 7 to start SIP pinging (Options) ----#
if (isflagset(5)) {
setbflag(6);
setbflag(7);
};
if ($rU==NULL) {
# request with no Username in RURI
sl_send_reply("484","Address Incomplete");
exit;
}
# apply DB based aliases
alias_db_lookup("dbaliases");
# apply transformations from dialplan table
dp_translate("0","$rU/$rU");
if ($rU=~"^\+[1-9][0-9]+$") {
if (!do_routing("0")) {
send_reply("500","No PSTN Route found");
exit;
}
route(1);
exit;
}
# do lookup with method filtering
if (!lookup("location","m")) {
if (!db_does_uri_exist()) {
send_reply("420","Bad Extension");
exit;
}
t_newtran();
t_reply("404", "Not Found");
exit;
}
if (isbflagset(10)) setflag(10);
# when routing via usrloc, log the missed calls also
setflag(2);
route(1);
}
######################
# ----- Routes ----- #
######################
route[1] {
# for INVITEs enable some additional helper routes
if (is_method("INVITE")) {
if (isflagset(10)) {
rtpproxy_offer("ro");
}
t_on_branch("2");
t_on_reply("2");
t_on_failure("1");
}
if (isflagset(10)) {
add_rr_param(";nat=yes");
}
if (!t_relay()) {
send_reply("500","Internal Error");
};
exit;
}
branch_route[2] {
xlog("new branch at $ru\n");
}
onreply_route[2] {
if (nat_uac_test("1"))
fix_nated_contact();
if ( isflagset(10) )
rtpproxy_answer("ro");
xlog("incoming reply\n");
}
failure_route[1] {
if (t_was_cancelled()) {
exit;
}
# uncomment the following lines if you want to block client
# redirect based on 3xx replies.
##if (t_check_status("3[0-9][0-9]")) {
##t_reply("404","Not found");
## exit;
##}
}
local_route {
if (is_method("BYE") && $DLG_dir=="UPSTREAM") {
acc_db_request("200 Dialog Timeout", "acc");
}
}
and here there is RTPPROXY.LOG, when call is made:
Sep 6 09:32:42 opensips rtpproxy[19964]: DBUG:handle_command: received command "19989_5 UR172.16.52.53c18,97 29d66022-c0a80101-0-1d@172.16.52.195 172.16.52.195 41000 c0a80101-7327839;1"
Sep 6 09:32:42 opensips rtpproxy[19964]: INFO:handle_command: new session 29d66022-c0a80101-0-1d@172.16.52.195, tag c0a80101-7327839;1 requested, type strong
OPENSIPS.LOG:
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_msg: SIP Request:
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_msg: method: <INVITE>
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_msg: uri: <sip:1000@video.longwave.eu:5060;user=phone>
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_msg: version: <SIP/2.0>
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=2
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK5747926469769213710-120748090>; state=
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_via: end of header reached, state=5
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: via found, flags=2
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: this is the first via
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:receive_msg: After parse_msg...
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:receive_msg: preparing to run routing scripts...
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=100
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_to: end of header reached, state=10
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_to: display={}, ruri={sip:1000@video.longwave.eu:5060;user=phone}
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:get_hdr_field: <t> [46]; uri=[sip:1000@video.longwave.eu:5060;user=phone]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:get_hdr_field: to body [<sip:1000@video.longwave.eu:5060;user=phone>#015#012]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:get_hdr_field: cseq <CSeq>: <1> <INVITE>
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:maxfwd:is_maxfwd_present: value = 70
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:check_ip_address: params 172.16.52.195, 172.16.52.195, 0
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:get_hdr_field: content_length=228
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:get_hdr_field: found end of header
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:uri:has_totag: no totag
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=78
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_lookup_request: start searching: hash=36067, isACK=0
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_lookup_request: no transaction found
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_to_param: tag=c0a80101-7327839
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_to: end of header reached, state=29
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_to: display={"OPENSIPS"}, ruri={sip:utente2@video.longwave.eu:5060;user=phone}
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=10000
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:auth:pre_auth: credentials with given realm not found
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:auth:reserve_nonce_index: second= 23, sec_monit= -1, index= 0
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:auth:build_auth_hf: nonce index= 0
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:auth:build_auth_hf: 'Proxy-Authenticate: Digest realm="video.longwave.eu", nonce="504851b8000000002fe
fac8972001622d3da8aabca2d7a"#015#012'
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:sl:run_sl_callbacks: callback id 0 entered
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:siptrace:trace_sl_onreply_out: trace slonreply out
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:siptrace:trace_sl_onreply_out: nothing to trace...
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:destroy_avp_list: destroying list (nil)
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:receive_msg: cleaning up
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_msg: SIP Request:
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_msg: method: <ACK>
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_msg: uri: <sip:1000@video.longwave.eu:5060;user=phone>
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_msg: version: <SIP/2.0>
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: flags=2
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK5747926469769213710-120748090>; state=
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_via: end of header reached, state=5
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: via found, flags=2
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: this is the first via
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:receive_msg: After parse_msg...
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:receive_msg: preparing to run routing scripts...
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: flags=8
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_to_param: tag=2fd9d4a31f868720ea20de4261af08b1.8e5b
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_to: end of header reached, state=29
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_to: display={}, ruri={sip:1000@video.longwave.eu:5060;user=phone}
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:get_hdr_field: <t> [88]; uri=[sip:1000@video.longwave.eu:5060;user=phone]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:get_hdr_field: to body [<sip:1000@video.longwave.eu:5060;user=phone>]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:sl:sl_filter_ACK: local ACK found -> dropping it!
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:destroy_avp_list: destroying list (nil)
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:receive_msg: cleaning up
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_msg: SIP Request:
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_msg: method: <INVITE>
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_msg: uri: <sip:1000@video.longwave.eu:5060;user=phone>
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_msg: version: <SIP/2.0>
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=2
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK2475363147136087087-120748101>; state=
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_via: end of header reached, state=5
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: via found, flags=2
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: this is the first via
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:receive_msg: After parse_msg...
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:receive_msg: preparing to run routing scripts...
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=100
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_to: end of header reached, state=10
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_to: display={}, ruri={sip:1000@video.longwave.eu:5060;user=phone}
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:get_hdr_field: <t> [46]; uri=[sip:1000@video.longwave.eu:5060;user=phone]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:get_hdr_field: to body [<sip:1000@video.longwave.eu:5060;user=phone>#015#012]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:get_hdr_field: cseq <CSeq>: <2> <INVITE>
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:maxfwd:is_maxfwd_present: value = 70
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:check_ip_address: params 172.16.52.195, 172.16.52.195, 0
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:get_hdr_field: content_length=228
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:get_hdr_field: found end of header
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:uri:has_totag: no totag
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=78
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:t_lookup_request: start searching: hash=36064, isACK=0
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:t_lookup_request: no transaction found
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_to_param: tag=c0a80101-7327839
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_to: end of header reached, state=29
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_to: display={"OPENSIPS"}, ruri={sip:utente2@video.longwave.eu:5060;user=phone}
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:auth:check_nonce: comparing [504851b8000000002fe41fac8972001622d3da8aabca2d7a] and [504851b8000000002
41fac8972001622d3da8aabca2d7a]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_do_prepared_query: conn=0xb7219940 (tail=-1222544604) MC=0xb7217358
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_do_prepared_query: new query=|select password from subscriber where username=? AND
main=?|
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:re_init_statement: query is <select password from subscriber where username=? AND domain=?
ptr=(nil)
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_do_prepared_query: new statement(0xb721aacc) on connection: (0xb7219940) 0xb7217324
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_val2bind: added val (0): len=7; type=254; is_null=0
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_val2bind: added val (1): len=17; type=254; is_null=0
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_do_prepared_query: prepared statement has 1 columns in result
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_do_prepared_query: doing to BIND_PARAM out ...
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_new_result: allocate 28 bytes for result set at 0xb721b050
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_get_columns: 1 columns returned from the query
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_allocate_columns: allocate 16 bytes for result columns at 0xb721b07c
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0xb721b080)[0]=[password]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_allocate_rows: allocate 28 bytes for result rows and values at 0xb721b098
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_str2val: converting STRING [opensips]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:auth_db:get_ha1: HA1 string calculated: 28c26c8854d209223fdb27b516870a70
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:auth:check_response: our result = '112b8dd2ff6ac56b6d21c62ff963fd3b'
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:auth:check_response: authorization is OK
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:auth:post_auth: nonce index= 0
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_free_columns: freeing result columns at 0xb721b07c
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_free_rows: freeing 1 rows
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_free_row: freeing row values at 0xb721b0a0
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_free_rows: freeing rows at 0xb721b098
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_free_result: freeing result set at 0xb721b050
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:uri:check_username: Digest username and URI username match
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=200
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:rr:find_first_route: No Route headers found
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:rr:loose_route: There is no Route HF
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:w_create_dialog2: bye on timeout activated
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:build_new_dlg: new dialog 0xaeeb5110 (c=29d66022-c0a80101-0-1d@172.16.52.195,f=sip:utente2@vid
.longwave.eu:5060;user=phone,t=sip:1000@video.longwave.eu:5060;user=phone,ft=c0a80101-7327839) on hash 3244
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:init_leg_info: route_set , contact sip:utente2@172.16.52.195:5060;transport=udp;user=phone, cs
2 and bind_addr udp:10.9.23.41:5060
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:dlg_add_leg_info: set leg 0 for 0xaeeb5110: tag=<c0a80101-7327839> rcseq=<0>
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:link_dlg: ref dlg 0xaeeb5110 with 3 -> 3
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:rr:add_rr_param: adding (;did=cac.deaa4071) 0xb721b1d8
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_new_result: allocate 28 bytes for result set at 0xb721b4e8
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_get_columns: 2 columns returned from the query
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_allocate_columns: allocate 32 bytes for result columns at 0xb721b514
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0xb721b51c)[0]=[username]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0xb721b524)[1]=[domain]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_allocate_rows: allocate 48 bytes for result rows and values at 0xb721b540
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_str2val: converting STRING [utente1]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:db_mysql:db_mysql_str2val: converting STRING [video.longwave.eu]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:alias_db:alias_db_query: new URI [0] is [sip:utente1@video.longwave.eu]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_free_columns: freeing result columns at 0xb721b514
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_free_rows: freeing 1 rows
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_free_row: freeing row values at 0xb721b548
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_free_rows: freeing rows at 0xb721b540
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:db_free_result: freeing result set at 0xb721b4e8
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialplan:dp_get_ivalue: integer value
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialplan:dp_translate_f: dpid is 0
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialplan:dp_get_svalue: searching 15
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialplan:dp_translate_f: input is utente1
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialplan:dp_translate_f: no information available for dpid 0
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:registrar:lookup: found a complete match
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:registrar:lookup: setting as ruri <sip:utente1@172.16.52.53:33606;rinstance=3f9c3a674b9ad47b>
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:registrar:lookup: looking for branches
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:decode_mime_type: Decoding MIME type for:[application/sdp]
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:rtpproxy:force_rtp_proxy: force rtp proxy with param1 <ro> and param2 <none>
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=40
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: INFO:rtpproxy:select_rtpp_node: rtpproxy node count = 1
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: INFO:rtpproxy:select_rtpp_node: node->rn_disabled = 0, node->rn_recheck_ticks = 0, get_ticks = 23
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: INFO:rtpproxy:select_rtpp_node: result rtpp_test = 0
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:rr:add_rr_param: adding (;nat=yes) 0xb721b46c
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:t_newtran: transaction on entrance=(nil)
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=78
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:t_lookup_request: start searching: hash=36064, isACK=0
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:t_lookup_request: no transaction found
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:run_reqin_callbacks: trans=0xaeeb56e4, callback type 1, id 2 entered
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:siptrace:trace_onreq_in: trace on req in
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:siptrace:trace_onreq_in: nothing to trace...
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:run_reqin_callbacks: trans=0xaeeb56e4, callback type 1, id 1 entered
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:dlg_onreq: t hash_index = 36064, t label = 1315880115
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:get_dlg_timeout: invalid AVP value, use default timeout
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:run_reqin_callbacks: trans=0xaeeb56e4, callback type 1, id 0 entered
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=78
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:_shm_resize: resize(0) called
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:_reply_light: reply sent out. buf=0xb721b75c: SIP/2.0 1..., shmem=0xaeeb7960: SIP/2.0 1
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:_reply_light: finished
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:buf_init: initializing...
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: new branch at sip:utente1@172.16.52.53:33606;rinstance=3f9c3a674b9ad47b
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:_shm_resize: resize(0) called
Sep 6 09:32:42 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:mk_proxy: doing DNS lookup...
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: ERROR:rtpproxy:send_rtpp_command: can't send command to a RTP proxy Connection refused
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: ERROR:rtpproxy:send_rtpp_command: proxy <udp:127.0.0.1:7890> does not respond, disable it
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:rtpproxy:raise_rtpproxy_event: no event sent
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: INFO:rtpproxy:force_rtp_proxy_body: command sent to rtpproxy, cp = (null), err = 0
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: INFO:rtpproxy:select_rtpp_node: rtpproxy node count = 1
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: INFO:rtpproxy:select_rtpp_node: node->rn_disabled = 1, node->rn_recheck_ticks = 84, get_ticks = 24
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: INFO:rtpproxy:select_rtpp_node: result rtpp_test = 1
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: ERROR:rtpproxy:force_rtp_proxy_body: no available proxies
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:set_timer: relative timeout is 500000
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:insert_timer_unsafe: [4]: 0xaeeb5830 (24900000)
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:set_timer: relative timeout is 5
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:insert_timer_unsafe: [0]: 0xaeeb584c (29)
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:t_relay_to: new transaction fwd'ed
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:t_unref: UNREF_UNSAFE: [0xaeeb56e4] after is 0
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:unref_dlg: unref dlg 0xaeeb5110 with 1 -> 2
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:destroy_avp_list: destroying list (nil)
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:receive_msg: cleaning up
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_msg: SIP Reply (status):
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_msg: version: <SIP/2.0>
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_msg: status: <100>
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_msg: reason: <Trying>
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=2
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK0ec8.3bcbe6e4.0>; state=16
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_via: end of header reached, state=5
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: via found, flags=2
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: this is the first via
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:receive_msg: After parse_msg...
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:forward_reply: found module nathelper, passing reply to it
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=4
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_via_param: found param type 235, <rport> = <5060>; state=6
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_via_param: found param type 234, <received> = <172.16.52.195>; state=6
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK2475363147136087087-120748101>; state=
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_via: end of header reached, state=5
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: via found, flags=4
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: parse_headers: this is the second via
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:forward_reply: found module tm, passing reply to it
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:t_check: start=0xffffffff
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=22
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_to: end of header reached, state=10
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_to: display={}, ruri={sip:1000@video.longwave.eu:5060;user=phone}
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:get_hdr_field: <To> [46]; uri=[sip:1000@video.longwave.eu:5060;user=phone]
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:get_hdr_field: to body [<sip:1000@video.longwave.eu:5060;user=phone>#015#012]
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:get_hdr_field: cseq <CSeq>: <2> <INVITE>
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=8
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:t_reply_matching: hash 36064 label 1315880115 branch 0
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xaeeb56e4] after is 1
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:t_reply_matching: reply matched (T=0xaeeb56e4)!
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:run_trans_callbacks: trans=0xaeeb56e4, callback type 2, id 1 entered
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:t_check: end=0xaeeb56e4
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1)
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:get_hdr_field: content_length=0
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:get_hdr_field: found end of header
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: ERROR:rtpproxy:force_rtp_proxy: Unable to parse body
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:buf_init: initializing...
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: incoming reply
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:t_should_relay_response: T_code=100, new_code=100
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:relay_reply: branch=0, save=0, relay=-1
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:set_timer: relative timeout is 30
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:insert_timer_unsafe: [1]: 0xaeeb584c (54)
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:t_unref: UNREF_UNSAFE: [0xaeeb56e4] after is 0
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:destroy_avp_list: destroying list (nil)
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:receive_msg: cleaning up
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_msg: SIP Reply (status):
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_msg: version: <SIP/2.0>
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_msg: status: <180>
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_msg: reason: <Ringing>
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=2
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK0ec8.3bcbe6e4.0>; state=16
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_via: end of header reached, state=5
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: via found, flags=2
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: this is the first via
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:receive_msg: After parse_msg...
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:forward_reply: found module nathelper, passing reply to it
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=4
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_via_param: found param type 235, <rport> = <5060>; state=6
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_via_param: found param type 234, <received> = <172.16.52.195>; state=6
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK2475363147136087087-120748101>; state=
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_via: end of header reached, state=5
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: via found, flags=4
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: parse_headers: this is the second via
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:forward_reply: found module tm, passing reply to it
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_check: start=0xffffffff
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=22
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_to_param: tag=0b433034
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_to: end of header reached, state=29
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_to: display={}, ruri={sip:1000@video.longwave.eu:5060;user=phone}
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:get_hdr_field: <To> [59]; uri=[sip:1000@video.longwave.eu:5060;user=phone]
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:get_hdr_field: to body [<sip:1000@video.longwave.eu:5060;user=phone>]
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:get_hdr_field: cseq <CSeq>: <2> <INVITE>
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=8
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_reply_matching: hash 36064 label 1315880115 branch 0
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xaeeb56e4] after is 1
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_reply_matching: reply matched (T=0xaeeb56e4)!
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:run_trans_callbacks: trans=0xaeeb56e4, callback type 2, id 1 entered
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_check: end=0xaeeb56e4
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:reply_received: org. status uas=100, uac[0]=100 local=0 is_invite=1)
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:get_hdr_field: content_length=0
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:get_hdr_field: found end of header
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: ERROR:rtpproxy:force_rtp_proxy: Unable to parse body
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:buf_init: initializing...
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: incoming reply
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_should_relay_response: T_code=100, new_code=180
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:relay_reply: branch=0, save=0, relay=0
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:run_trans_callbacks: trans=0xaeeb56e4, callback type 8, id 0 entered
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:dialog:push_reply_in_dialog: 0xaeeb5110 totag in rpl is <0b433034> (8)
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:dialog:push_reply_in_dialog: new branch with tag <0b433034>
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:dialog:init_leg_info: route_set , contact , cseq 2 and bind_addr udp:10.9.23.41:5060
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:dialog:dlg_add_leg_info: set leg 1 for 0xaeeb5110: tag=<0b433034> rcseq=<2>
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:build_res_buf_from_sip_res: old size: 603, new size: 544
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:build_res_buf_from_sip_res: copied size: orig:295, new: 236, rest: 308 msg=#012SIP/2.0 180 Ringi
#015#012Via: SIP/2.0/UDP 172.16.52.195:5060;rport=5060;received=172.16.52.195;branch=z9hG4bK2475363147136087087-120748101#015#012Record-Route: <sip:10.9.23.41;lr;did=cac.deaa4071
at=yes>#015#012Contact: <sip:utente1@172.16.52.53:33606>#015#012To: <sip:1000@video.longwave.eu:5060;user=phone>;tag=0b433034#015#012From: "OPENSIPS"<sip:utente2@video.longwave.e
5060;user=phone>;tag=c0a80101-7327839#015#012Call-ID: 29d66022-c0a80101-0-1d@172.16.52.195#015#012CSeq: 2 INVITE#015#012User-Agent: Bria 3 release 3.4.2 stamp 67674#015#012Allow-
ents: hold, talk#015#012Content-Length: 0#015#012#015#012
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:run_trans_callbacks: trans=0xaeeb56e4, callback type 64, id 0 entered
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:dialog:next_state_dlg: dialog 0xaeeb5110 changed from state 1 to state 2, due event 2
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:relay_reply: sent buf=0xb721ab78: SIP/2.0 1..., shmem=0xaeeb8084: SIP/2.0 1
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:run_trans_callbacks: trans=0xaeeb56e4, callback type 128, id 1 entered
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:set_timer: relative timeout is 30
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:insert_timer_unsafe: [1]: 0xaeeb584c (54)
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_unref: UNREF_UNSAFE: [0xaeeb56e4] after is 0
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:destroy_avp_list: destroying list (nil)
Sep 6 09:32:43 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:receive_msg: cleaning up
Sep 6 09:32:44 opensips /usr/local/opensips_proxy/sbin/opensips[19996]: DBG:tm:utimer_routine: timer routine:4,tl=0xaeeb5830 next=(nil), timeout=24900000
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_msg: SIP Reply (status):
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_msg: version: <SIP/2.0>
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_msg: status: <200>
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_msg: reason: <OK>
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: flags=2
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK0ec8.3bcbe6e4.0>; state=16
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_via: end of header reached, state=5
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: via found, flags=2
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: this is the first via
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:receive_msg: After parse_msg...
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:forward_reply: found module nathelper, passing reply to it
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: flags=4
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_via_param: found param type 235, <rport> = <5060>; state=6
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_via_param: found param type 234, <received> = <172.16.52.195>; state=6
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK2475363147136087087-120748101>; state=16
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_via: end of header reached, state=5
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: via found, flags=4
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: parse_headers: this is the second via
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:forward_reply: found module tm, passing reply to it
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:t_check: start=0xffffffff
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: flags=22
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_to_param: tag=0b433034
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_to: end of header reached, state=29
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_to: display={}, ruri={sip:1000@video.longwave.eu:5060;user=phone}
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:get_hdr_field: <To> [59]; uri=[sip:1000@video.longwave.eu:5060;user=phone]
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:get_hdr_field: to body [<sip:1000@video.longwave.eu:5060;user=phone>]
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:get_hdr_field: cseq <CSeq>: <2> <INVITE>
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: flags=8
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:t_reply_matching: hash 36064 label 1315880115 branch 0
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xaeeb56e4] after is 1
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:t_reply_matching: reply matched (T=0xaeeb56e4)!
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: flags=8
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:run_trans_callbacks: trans=0xaeeb56e4, callback type 2, id 1 entered
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: flags=8
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:t_check: end=0xaeeb56e4
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:reply_received: org. status uas=180, uac[0]=180 local=0 is_invite=1)
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:get_hdr_field: content_length=239
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:get_hdr_field: found end of header
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:decode_mime_type: Decoding MIME type for:[application/sdp]
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:rtpproxy:force_rtp_proxy: force rtp proxy with param1 <ro> and param2 <none>
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: flags=40
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: INFO:rtpproxy:select_rtpp_node: rtpproxy node count = 1
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: INFO:rtpproxy:select_rtpp_node: node->rn_disabled = 1, node->rn_recheck_ticks = 84, get_ticks = 27
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: INFO:rtpproxy:select_rtpp_node: result rtpp_test = 1
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: ERROR:rtpproxy:force_rtp_proxy: no available proxies
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:buf_init: initializing...
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: incoming reply
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:t_should_relay_response: T_code=180, new_code=200
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:relay_reply: branch=0, save=0, relay=0
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:run_trans_callbacks: trans=0xaeeb56e4, callback type 8, id 0 entered
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:dialog:push_reply_in_dialog: 0xaeeb5110 totag in rpl is <0b433034> (8)
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:dialog:push_reply_in_dialog: branch with tag <0b433034> already exists
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:print_rr_body: current rr is <sip:10.9.23.41;lr;did=cac.deaa4071;nat=yes>
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:print_rr_body: skipping 1 route records
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:print_rr_body: out rr []
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:print_rr_body: we have 1 records
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:dialog:dlg_update_routing: dialog 0xaeeb5110[1]: rr=<> contact=<sip:utente1@172.16.52.53:33606>
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:build_res_buf_from_sip_res: old size: 959, new size: 900
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:build_res_buf_from_sip_res: copied size: orig:290, new: 231, rest: 669 msg=#012SIP/2.0 200 OK#015#012Via: SIP/2.0/UDP 172.16.52.195:5060;rport=5060;received=172.16.52.195;branch=z9hG4bK2475363147136087087-120748101#015#012Record-Route: <sip:10.9.23.41;lr;did=cac.deaa4071;nat=yes>#015#012Contact: <sip:utente1@172.16.52.53:33606>#015#012To: <sip:1000@video.longwave.eu:5060;user=phone>;tag=0b433034#015#012From: "OPENSIPS"<sip:utente2@video.longwave.eu:5060;user=phone>;tag=c0a80101-7327839#015#012Call-ID: 29d66022-c0a80101-0-1d@172.16.52.195#015#012CSeq: 2 INVITE#015#012Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO#015#012Content-Type: application/sdp#015#012Supported: replaces, eventlist#015#012User-Agent: Bria 3 release 3.4.2 stamp 67674#015#012Content-Length: 239#015#012#015#012v=0#015#012o=- 1346916764885158 1 IN IP4 172.16.52.53#015#012s=CounterPath Bria 3.3#015#012c=IN IP4 172.16.52.53#015#012t=0 0#015#012m=audio 60404 RTP/AVP 18 97#015#012a=rtpmap:18 G729/8000#015#012a=fmtp:18 annexb=yes#015#012a=rtpmap:97 telephone-event/8000#015#012a=fmtp:97 0-15#015#012a=sendrecv#015#012
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:update_totag_set: new totag
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:insert_timer_unsafe: [2]: 0xaeeb572c (32)
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:run_trans_callbacks: trans=0xaeeb56e4, callback type 64, id 0 entered
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:dialog:next_state_dlg: dialog 0xaeeb5110 changed from state 2 to state 3, due event 3
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:dialog:dlg_onreply: dialog 0xaeeb5110 confirmed
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:dialog:insert_dlg_timer_unsafe: inserting 0xaeeb5144 for 21627
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:dialog:ref_dlg: ref dlg 0xaeeb5110 with 1 -> 3
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:relay_reply: sent buf=0xb721bbbc: SIP/2.0 2..., shmem=0xaeeb8350: SIP/2.0 2
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:run_trans_callbacks: trans=0xaeeb56e4, callback type 128, id 1 entered
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:db_mysql:db_mysql_do_prepared_query: conn=0xb721996c (tail=-1222544604) MC=0xb7217358
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:db_mysql:db_mysql_do_prepared_query: new query=|insert into acc (method,from_tag,to_tag,callid,sip_code,sip_reason,time ) values (?,?,?,?,?,?,?)|
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:db_mysql:re_init_statement: query is <insert into acc (method,from_tag,to_tag,callid,sip_code,sip_reason,time ) values (?,?,?,?,?,?,?)>, ptr=(nil)
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:db_mysql:db_mysql_do_prepared_query: new statement(0xb721bf50) on connection: (0xb721996c) 0xb7217324
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:db_mysql:db_mysql_val2bind: added val (0): len=6; type=254; is_null=0
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:db_mysql:db_mysql_val2bind: added val (1): len=16; type=254; is_null=0
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:db_mysql:db_mysql_val2bind: added val (2): len=8; type=254; is_null=0
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:db_mysql:db_mysql_val2bind: added val (3): len=36; type=254; is_null=0
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:db_mysql:db_mysql_val2bind: added val (4): len=3; type=254; is_null=0
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:db_mysql:db_mysql_val2bind: added val (5): len=2; type=254; is_null=0
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:db_mysql:db_mysql_val2bind: added val (6): len=36; type=12; is_null=0
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:tm:t_unref: UNREF_UNSAFE: [0xaeeb56e4] after is 0
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:destroy_avp_list: destroying list (nil)
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19987]: DBG:core:receive_msg: cleaning up
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_msg: SIP Request:
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_msg: method: <ACK>
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_msg: uri: <sip:utente1@172.16.52.53:33606;user=phone>
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_msg: version: <SIP/2.0>
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=2
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK7529708647547431532-120750068>; state=16
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_via: end of header reached, state=5
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: via found, flags=2
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: this is the first via
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:receive_msg: After parse_msg...
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:receive_msg: preparing to run routing scripts...
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:sl:sl_filter_ACK: to late to be a local ACK!
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=100
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_to_param: tag=0b433034
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_to: end of header reached, state=29
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_to: display={}, ruri={sip:1000@video.longwave.eu:5060;user=phone}
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:get_hdr_field: <t> [59]; uri=[sip:1000@video.longwave.eu:5060;user=phone]
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:get_hdr_field: to body [<sip:1000@video.longwave.eu:5060;user=phone>]
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:get_hdr_field: cseq <CSeq>: <2> <ACK>
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:maxfwd:is_maxfwd_present: value = 70
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:check_ip_address: params 172.16.52.195, 172.16.52.195, 0
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:get_hdr_field: content_length=0
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:get_hdr_field: found end of header
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:uri:has_totag: totag found
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=200
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:rr:is_preloaded: is_preloaded: No
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:grep_sock_info: checking if host==us: 12==10 && [172.16.52.53] == [10.9.23.41]
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:grep_sock_info: checking if port 5060 matches port 33606
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:grep_sock_info: checking if host==us: 12==12 && [172.16.52.53] == [151.8.12.201]
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:grep_sock_info: checking if port 5060 matches port 33606
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:grep_sock_info: checking if host==us: 12==10 && [172.16.52.53] == [10.9.23.41]
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:grep_sock_info: checking if port 5060 matches port 33606
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:grep_sock_info: checking if host==us: 12==12 && [172.16.52.53] == [151.8.12.201]
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:grep_sock_info: checking if port 5060 matches port 33606
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:check_self: host != me
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:grep_sock_info: checking if host==us: 10==10 && [10.9.23.41] == [10.9.23.41]
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:rr:after_loose: Topmost route URI: 'sip:10.9.23.41;lr;did=cac.deaa4071;nat=yes' is me
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=200
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:get_hdr_field: found end of header
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:rr:find_next_route: No next Route HF found
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:rr:after_loose: No next URI found!
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:rr:run_rr_callbacks: callback id 1 entered with <lr;did=cac.deaa4071;nat=yes>
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:dlg_onroute: route param is 'cac.deaa4071' (len=12)
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:lookup_dlg: ref dlg 0xaeeb5110 with 1 -> 4
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:lookup_dlg: dialog id=386181869 found on entry 3244
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=58
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_to_param: tag=c0a80101-7327839
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_to: end of header reached, state=29
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_to: display={"OPENSIPS"}, ruri={sip:utente2@video.longwave.eu:5060;user=phone}
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:next_state_dlg: dialog 0xaeeb5110 changed from state 3 to state 4, due event 6
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:dlg_onroute: sequential request successfully processed (dst_leg=1)
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:dlg_validate_dialog: CSEQ validation passed
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:compare_uris: Different uri types
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: ERROR:dialog:dlg_validate_dialog: failed to validate remote contact: dlg=[sip:utente1@172.16.52.53:33606] , req=[sip:utente1@172.16.52.53:33606;user=phone]
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: In-Dialog ACK from 172.16.52.195 (callid=29d66022-c0a80101-0-1d@172.16.52.195) is not valid according to dialog
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:rr:check_route_param: params are <;lr;did=cac.deaa4071;nat=yes>
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:rr:add_rr_param: adding (;nat=yes) (nil)
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:rr:add_rr_param: rr_param_buf=<;nat=yes>
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:t_newtran: transaction on entrance=0xffffffff
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=78
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:t_lookup_request: start searching: hash=36064, isACK=1
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:parse_headers: flags=38
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:t_lookup_request: REF_UNSAFE:[0xaeeb56e4] after is 1
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:t_lookup_request: e2e proxy ACK found
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:t_newtran: building branch for end2end ACK - flags=1
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:t_relay_to: forwarding ACK
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:mk_proxy: doing DNS lookup...
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:forward_request: sending:#012ACK sip:utente1@172.16.52.53:33606;user=phone SIP/2.0#015#012Via: SIP/2.0/UDP 10.9.23.41;branch=z9hG4bK0ec8.3bcbe6e4.2#015#012v: SIP/2.0/UDP 172.16.52.195:5060;rport=5060;received=172.16.52.195;branch=z9hG4bK7529708647547431532-120750068#015#012f: "OPENSIPS"<sip:utente2@video.longwave.eu:5060;user=phone>;tag=c0a80101-7327839#015#012t: <sip:1000@video.longwave.eu:5060;user=phone>;tag=0b433034#015#012i: 29d66022-c0a80101-0-1d@172.16.52.195#015#012CSeq: 2 ACK#015#012Max-Forwards: 69#015#012Allow-Events: refer,dialog,message-summary,check-sync,talk,hold#015#012Proxy-Authorization: Digest username="utente2", realm="video.longwave.eu", nonce="504851b8000000002fe41fac8972001622d3da8aabca2d7a", uri="sip:utente1@172.16.52.53:33606;user=phone", response="3cc07661ba3a9494afadcea2fb1a2261", algorithm=MD5#015#012User-Agent: THOMSON ST2030 hw5 fw2.72 00-1F-9F-16-C2-DC#015#012l: 0#015#012#015#012.
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:forward_request: orig. len=776, new_len=816, proto=1
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:run_fwd_callbacks: FWD callback entered
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:siptrace:trace_msg_out: trace off...
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:tm:t_unref_cell: UNREF_UNSAFE: [0xaeeb56e4] after is 0
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:dialog:unref_dlg: unref dlg 0xaeeb5110 with 1 -> 3
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:destroy_avp_list: destroying list (nil)
Sep 6 09:32:46 opensips /usr/local/opensips_proxy/sbin/opensips[19989]: DBG:core:receive_msg: cleaning up
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_msg: SIP Request:
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_msg: method: <BYE>
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_msg: uri: <sip:utente1@172.16.52.53:33606;user=phone>
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_msg: version: <SIP/2.0>
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=2
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK7960258682981536932-120752106>; state=16
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_via: end of header reached, state=5
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: via found, flags=2
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: this is the first via
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:receive_msg: After parse_msg...
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:receive_msg: preparing to run routing scripts...
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=100
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_to_param: tag=0b433034
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_to: end of header reached, state=29
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_to: display={}, ruri={sip:1000@video.longwave.eu:5060;user=phone}
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:get_hdr_field: <t> [59]; uri=[sip:1000@video.longwave.eu:5060;user=phone]
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:get_hdr_field: to body [<sip:1000@video.longwave.eu:5060;user=phone>]
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:get_hdr_field: cseq <CSeq>: <3> <BYE>
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:maxfwd:is_maxfwd_present: value = 70
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:check_ip_address: params 172.16.52.195, 172.16.52.195, 0
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:get_hdr_field: content_length=0
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:get_hdr_field: found end of header
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:uri:has_totag: totag found
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=200
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:rr:is_preloaded: is_preloaded: No
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:grep_sock_info: checking if host==us: 12==10 && [172.16.52.53] == [10.9.23.41]
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:grep_sock_info: checking if port 5060 matches port 33606
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:grep_sock_info: checking if host==us: 12==12 && [172.16.52.53] == [151.8.12.201]
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:grep_sock_info: checking if port 5060 matches port 33606
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:grep_sock_info: checking if host==us: 12==10 && [172.16.52.53] == [10.9.23.41]
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:grep_sock_info: checking if port 5060 matches port 33606
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:grep_sock_info: checking if host==us: 12==12 && [172.16.52.53] == [151.8.12.201]
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:grep_sock_info: checking if port 5060 matches port 33606
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:check_self: host != me
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:grep_sock_info: checking if host==us: 10==10 && [10.9.23.41] == [10.9.23.41]
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:grep_sock_info: checking if port 5060 matches port 5060
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:rr:after_loose: Topmost route URI: 'sip:10.9.23.41;lr;did=cac.deaa4071;nat=yes' is me
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=200
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:get_hdr_field: found end of header
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:rr:find_next_route: No next Route HF found
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:rr:after_loose: No next URI found!
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:rr:run_rr_callbacks: callback id 1 entered with <lr;did=cac.deaa4071;nat=yes>
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:dialog:dlg_onroute: route param is 'cac.deaa4071' (len=12)
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:dialog:lookup_dlg: ref dlg 0xaeeb5110 with 1 -> 4
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:dialog:lookup_dlg: dialog id=386181869 found on entry 3244
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=58
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_to_param: tag=c0a80101-7327839
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_to: end of header reached, state=29
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_to: display={"OPENSIPS"}, ruri={sip:utente2@video.longwave.eu:5060;user=phone}
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:dialog:next_state_dlg: dialog 0xaeeb5110 changed from state 4 to state 5, due event 7
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:dialog:dlg_onroute: BYE successfully processed - dst_leg = 1
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:dialog:remove_dialog_from_db: trying to remove a dialog, update_flag is 31
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:dialog:unref_dlg: unref dlg 0xaeeb5110 with 2 -> 2
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:dialog:dlg_validate_dialog: CSEQ validation passed
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:compare_uris: Different uri types
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: ERROR:dialog:dlg_validate_dialog: failed to validate remote contact: dlg=[sip:utente1@172.16.52.53:33606] , req=[sip:utente1@172.16.52.53:33606;user=phone]
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: In-Dialog BYE from 172.16.52.195 (callid=29d66022-c0a80101-0-1d@172.16.52.195) is not valid according to dialog
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:rr:check_route_param: params are <;lr;did=cac.deaa4071;nat=yes>
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:rr:add_rr_param: adding (;nat=yes) (nil)
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:rr:add_rr_param: rr_param_buf=<;nat=yes>
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:t_newtran: transaction on entrance=0xffffffff
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=ffffffffffffffff
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=78
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:t_lookup_request: start searching: hash=36065, isACK=0
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:matching_3261: RFC3261 transaction matching failed
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:t_lookup_request: no transaction found
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:run_reqin_callbacks: trans=0xaeeb86e4, callback type 1, id 2 entered
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:siptrace:trace_onreq_in: trace on req in
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:siptrace:trace_onreq_in: nothing to trace...
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:run_reqin_callbacks: trans=0xaeeb86e4, callback type 1, id 1 entered
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:dialog:ref_dlg: ref dlg 0xaeeb5110 with 1 -> 3
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:run_reqin_callbacks: trans=0xaeeb86e4, callback type 1, id 0 entered
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:parse_headers: flags=78
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:mk_proxy: doing DNS lookup...
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:set_timer: relative timeout is 500000
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:insert_timer_unsafe: [4]: 0xaeeb8830 (31900000)
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:set_timer: relative timeout is 5
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:insert_timer_unsafe: [0]: 0xaeeb884c (36)
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:t_relay_to: new transaction fwd'ed
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:tm:t_unref: UNREF_UNSAFE: [0xaeeb86e4] after is 0
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:dialog:unref_dlg: unref dlg 0xaeeb5110 with 1 -> 2
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:destroy_avp_list: destroying list (nil)
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19988]: DBG:core:receive_msg: cleaning up
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_msg: SIP Reply (status):
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_msg: version: <SIP/2.0>
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_msg: status: <200>
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_msg: reason: <OK>
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=2
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK1ec8.471796a4.0>; state=16
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_via: end of header reached, state=5
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: via found, flags=2
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: this is the first via
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:receive_msg: After parse_msg...
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:forward_reply: found module nathelper, passing reply to it
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=4
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_via_param: found param type 235, <rport> = <5060>; state=6
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_via_param: found param type 234, <received> = <172.16.52.195>; state=6
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK7960258682981536932-120752106>; state=16
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_via: end of header reached, state=5
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: via found, flags=4
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: parse_headers: this is the second via
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:forward_reply: found module tm, passing reply to it
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_check: start=0xffffffff
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=22
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_to_param: tag=0b433034
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_to: end of header reached, state=29
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_to: display={}, ruri={sip:1000@video.longwave.eu:5060;user=phone}
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:get_hdr_field: <To> [59]; uri=[sip:1000@video.longwave.eu:5060;user=phone]
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:get_hdr_field: to body [<sip:1000@video.longwave.eu:5060;user=phone>]
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:get_hdr_field: cseq <CSeq>: <3> <BYE>
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_reply_matching: hash 36065 label 1248424308 branch 0
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_reply_matching: REF_UNSAFE:[0xaeeb86e4] after is 1
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_reply_matching: reply matched (T=0xaeeb86e4)!
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:run_trans_callbacks: trans=0xaeeb86e4, callback type 2, id 1 entered
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:parse_headers: flags=8
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_check: end=0xaeeb86e4
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:reply_received: org. status uas=0, uac[0]=0 local=0 is_invite=0)
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_should_relay_response: T_code=0, new_code=200
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:relay_reply: branch=0, save=0, relay=0
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:build_res_buf_from_sip_res: old size: 509, new size: 450
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:build_res_buf_from_sip_res: copied size: orig:75, new: 16, rest: 434 msg=#012SIP/2.0 200 OK#015#012Via: SIP/2.0/UDP 172.16.52.195:5060;rport=5060;received=172.16.52.195;branch=z9hG4bK7960258682981536932-120752106#015#012Contact: <sip:utente1@172.16.52.53:33606>#015#012To: <sip:1000@video.longwave.eu:5060;user=phone>;tag=0b433034#015#012From: "OPENSIPS"<sip:utente2@video.longwave.eu:5060;user=phone>;tag=c0a80101-7327839#015#012Call-ID: 29d66022-c0a80101-0-1d@172.16.52.195#015#012CSeq: 3 BYE#015#012User-Agent: Bria 3 release 3.4.2 stamp 67674#015#012Content-Length: 0#015#012#015#012
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:_shm_resize: resize(0) called
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:insert_timer_unsafe: [2]: 0xaeeb872c (36)
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:relay_reply: sent buf=0xb721ab78: SIP/2.0 2..., shmem=0xaeeb8084: SIP/2.0 2
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:run_trans_callbacks: trans=0xaeeb86e4, callback type 128, id 1 entered
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:db_mysql:db_mysql_do_prepared_query: conn=0xb721983c (tail=-1222544604) MC=0xb7217358
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:db_mysql:db_mysql_do_prepared_query: new query=|insert into acc (method,from_tag,to_tag,callid,sip_code,sip_reason,time ) values (?,?,?,?,?,?,?)|
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:db_mysql:re_init_statement: query is <insert into acc (method,from_tag,to_tag,callid,sip_code,sip_reason,time ) values (?,?,?,?,?,?,?)>, ptr=(nil)
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:db_mysql:db_mysql_do_prepared_query: new statement(0xb721bdc8) on connection: (0xb721983c) 0xb7217324
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:db_mysql:db_mysql_val2bind: added val (0): len=3; type=254; is_null=0
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:db_mysql:db_mysql_val2bind: added val (1): len=16; type=254; is_null=0
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:db_mysql:db_mysql_val2bind: added val (2): len=8; type=254; is_null=0
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:db_mysql:db_mysql_val2bind: added val (3): len=36; type=254; is_null=0
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:db_mysql:db_mysql_val2bind: added val (4): len=3; type=254; is_null=0
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:db_mysql:db_mysql_val2bind: added val (5): len=2; type=254; is_null=0
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:db_mysql:db_mysql_val2bind: added val (6): len=36; type=12; is_null=0
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:tm:t_unref: UNREF_UNSAFE: [0xaeeb86e4] after is 0
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:destroy_avp_list: destroying list (nil)
Sep 6 09:32:50 opensips /usr/local/opensips_proxy/sbin/opensips[19990]: DBG:core:receive_msg: cleaning up
Sep 6 09:32:51 opensips /usr/local/opensips_proxy/sbin/opensips[19996]: DBG:tm:utimer_routine: timer routine:4,tl=0xaeeb8830 next=(nil), timeout=31900000
Sep 6 09:32:51 opensips /usr/local/opensips_proxy/sbin/opensips[19996]: DBG:tm:timer_routine: timer routine:2,tl=0xaeeb572c next=(nil), timeout=32
Sep 6 09:32:51 opensips /usr/local/opensips_proxy/sbin/opensips[19996]: DBG:tm:wait_handler: removing 0xaeeb56e4 from table
Sep 6 09:32:51 opensips /usr/local/opensips_proxy/sbin/opensips[19996]: DBG:tm:delete_cell: delete transaction 0xaeeb56e4
Sep 6 09:32:51 opensips /usr/local/opensips_proxy/sbin/opensips[19996]: DBG:dialog:next_state_dlg: dialog 0xaeeb5110 changed from state 5 to state 5, due event 1
Sep 6 09:32:51 opensips /usr/local/opensips_proxy/sbin/opensips[19996]: DBG:dialog:unref_dlg: unref dlg 0xaeeb5110 with 1 -> 1
Sep 6 09:32:51 opensips /usr/local/opensips_proxy/sbin/opensips[19996]: DBG:tm:wait_handler: done
Locked
