[OpenSIPS-Users] topology hiding not accepting BYE before 200 OK
Trevor Steyn
trevor at webon.co.za
Thu Jul 23 17:12:29 CEST 2015
Hi Guys,
I seem to be having some trouble with the new topology_hiding module in
opensips 2.1
here is the call scenario
UAC --> Opensips --> UAS
UAC Sends Invite to UAS with topology hiding module
UAS sends 180 with to-tag
UAC sends BYE
When the Bye is sent opensips loops the call till max forwards is reached
from what i can see from the debugs the Bye from UAC is accepted and
matches the topology_hiding_match function but does not rewrite the
destination IP so when the message passes t_relay() its sending the Bye
to Itself from Itself.
I have tried this without topology hiding and the BYE is relayed as it
should
.
My route looks as follows
route{
script_trace( 3, "$rm from $si, ruri=$ru", "me");
if (!mf_process_maxfwd_header("10")) {
sl_send_reply("483","Too Many Hops");
exit;
}
if ( check_source_address("1","$avp(trunk_attrs)") ) {
# request comes from trunks
setflag(IS_TRUNK);
} else if ( is_from_gw() ) {
# request comes from GWs
} else {
# send_reply("403","Forbidden");
xlog("Message is not from Trunk or GW $si");
# exit;
}
if (has_totag()) {
# sequential request withing a dialog should
# take the path determined by record-routing
#if (loose_route()) {
if(topology_hiding_match()) {
# 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(ACC_DO); # do accounting ...
setflag(ACC_FAILED); # ... 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();
}
# lets handle re-invites and offer proxy
if (has_body("application/sdp")) {
# Begin rtp session update gyrations
if (method == "INVITE") {
# INVITE w/ SDP, so early neg
# This is offer, reply is answer
rtpproxy_offer("iewlz20");
t_on_reply("1");
} else if (method == "ACK") {
# ACK w/ SDP, so late neg (done now)
# This is answer
rtpproxy_answer("iewlz20");
}
}
# route it out to whatever destination was set by loose_route()
# in $du (destination URI).
route(RELAY);
} 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
if ( !isflagset(IS_TRUNK) ) {
## accept new calls only from trunks
send_reply("403","Not from trunk");
exit;
}
# CANCEL processing
if (is_method("CANCEL")) {
if (t_check_trans())
t_relay();
exit;
} else if (!is_method("INVITE")) {
send_reply("405","Method Not Allowed");
exit;
}
if ($rU==NULL) {
# request with no Username in RURI
sl_send_reply("484","Address Incomplete");
exit;
}
t_check_trans();
# preloaded route checking
if (loose_route()) {
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
record_route();
setflag(ACC_DO); # do accounting
# create dialog with timeout
if ( !create_dialog("B") ) {
send_reply("500","Internal Server Error");
exit;
}
if (is_avp_set("$avp(trunk_attrs)") && $avp(trunk_attrs)=~"^[0-9]+$") {
get_profile_size("trunkCalls","$si","$var(size)");
if ( $(var(size){s.int}) >= $(avp(trunk_attrs){s.int}) ) {
send_reply("486","Busy Here");
exit;
}
}
set_dlg_profile("trunkCalls","$si");
# apply transformations from dialplan table
dp_translate("0","$rU/$rU");
# route calls based on prefix
if ( !do_routing("1") ) {
send_reply("404","No Route found");
exit;
}
t_on_failure("GW_FAILOVER");
if (is_method("INVITE")) {
force_send_socket(udp:XXX.XXX.XXX.XXX:5060);
#rtpproxy_engage('ierz20');
topology_hiding();
}
if (has_body("application/sdp")) {
if (rtpproxy_offer('iewz20')) {
t_on_reply("1");
} else {
t_on_reply("2");
}
}
route(RELAY);
}
route[RELAY] {
if (!t_relay()) {
sl_reply_error();
};
exit;
}
failure_route[GW_FAILOVER] {
if (t_was_cancelled()) {
exit;
}
# detect failure and redirect to next available GW
if (t_check_status("(408)|([56][0-9][0-9])")) {
xlog("Failed GW $rd detected \n");
if ( use_next_gw() ) {
t_on_failure("GW_FAILOVER");
t_relay();
exit;
}
send_reply("500","All GW are down");
}
}
local_route {
if (is_method("BYE") && $DLG_dir=="UPSTREAM") {
acc_db_request("200 Dialog Timeout", "acc");
}
}
onreply_route[1]
{
if (has_body("application/sdp"))
if ($DLG_status) { # Update
rtpproxy_answer('eilz20');
} else {
rtpproxy_answer('eiz20');
}
}
onreply_route[2]
{
if (has_body("application/sdp"))
rtpproxy_offer('iewz20');
}
Debug below
[Script Trace][/etc/opensips/opensips.cfg:176][me][core if] -> (BYE from
10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:171][me][module
mf_process_maxfwd_header] -> (BYE from 10.10.16.1,
ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=100
Jul 23 16:01:16 [22780] DBG:core:parse_to_param: tag=6pou4pvn6xe2phuk.i
Jul 23 16:01:16 [22780] DBG:core:parse_to: end of header reached, state=29
Jul 23 16:01:16 [22780] DBG:core:parse_to: display={},
ruri={sip:27111000626 at 10.10.16.1:5060;user=phone}
Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: <To> [70];
uri=[sip:27111000626 at 10.10.16.1:5060;user=phone]
Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: to body
[<sip:27111000626 at 10.10.16.1:5060;user=phone>]
Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: cseq <CSeq>: <2> <BYE>
Jul 23 16:01:16 [22780] DBG:maxfwd:is_maxfwd_present: value = 67
[Script Trace][/etc/opensips/opensips.cfg:185][me][core if] -> (BYE from
10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:176][me][module
check_source_address] -> (BYE from 10.10.16.1,
ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:permissions:check_src_addr_3: Looking for :
<1, 10.10.16.1, 5060, 1> in tables
Jul 23 16:01:16 [22780] DBG:permissions:hash_match: no pattern to match
Jul 23 16:01:16 [22780] DBG:permissions:hash_match: match found in the
hash table
[Script Trace][/etc/opensips/opensips.cfg:178][me][core setflag] -> (BYE
from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:248][me][core if] -> (BYE from
10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:187][me][module has_totag] ->
(BYE from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:uri:has_totag: totag found
[Script Trace][/etc/opensips/opensips.cfg:242][me][core if] -> (BYE from
10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:191][me][module
topology_hiding_match] -> (BYE from 10.10.16.1,
ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=200
Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: content_length=0
Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: found end of header
Jul 23 16:01:16 [22780] DBG:core:grep_sock_info: checking if host==us:
13==13 && [10.10.16.2] == [10.10.16.2]
Jul 23 16:01:16 [22780] DBG:core:grep_sock_info: checking if port 5060
matches port 5060
Jul 23 16:01:16 [22780] DBG:dialog:w_match_dialog: We found DID param in
R-URI with value of dbf.d239f4f3
Jul 23 16:01:16 [22780] DBG:dialog:dlg_onroute: route param is
'dbf.d239f4f3' (len=12)
Jul 23 16:01:16 [22780] DBG:dialog:lookup_dlg: ref dlg 0x7f81e1b3c2f8
with 1 -> 4
Jul 23 16:01:16 [22780] DBG:dialog:lookup_dlg: dialog id=1062179629
found on entry 4029
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=58
Jul 23 16:01:16 [22780] DBG:core:parse_to_param:
tag=SDl3i7c02-55B0F3A1-1DDB4E1-0ADE2C1B
Jul 23 16:01:16 [22780] DBG:core:parse_to: end of header reached, state=29
Jul 23 16:01:16 [22780] DBG:core:parse_to: display={},
ruri={sip:27115138000 at 10.10.17.55;user=phone}
Jul 23 16:01:16 [22780] DBG:dialog:next_state_dlg: dialog 0x7f81e1b3c2f8
changed from state 2 to state 2, due event 7
[Script Trace][/etc/opensips/opensips.cfg:199][me][core if] -> (BYE from
10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:194][me][module
validate_dialog] -> (BYE from 10.10.16.1,
ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:dialog:dlg_validate_dialog: CSEQ validation
passed
[Script Trace][/etc/opensips/opensips.cfg:210][me][core if] -> (BYE from
10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:199][me][module is_method] ->
(BYE from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:200][me][core setflag] -> (BYE
from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:201][me][core setflag] -> (BYE
from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:227][me][core if] -> (BYE from
10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:210][me][module has_body] ->
(BYE from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:sipmsgops:has_body_f: content length is zero
[Script Trace][/etc/opensips/opensips.cfg:227][me][route RELAY] -> (BYE
from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:340][me][core if] -> (BYE from
10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:338][me][module t_relay] ->
(BYE from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:tm:t_newtran: transaction on
entrance=0xffffffffffffffff
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=ffffffffffffffff
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=78
Jul 23 16:01:16 [22780] DBG:tm:t_lookup_request: start searching:
hash=40946, isACK=0
Jul 23 16:01:16 [22780] DBG:tm:matching_3261: RFC3261 transaction
matching failed
Jul 23 16:01:16 [22780] DBG:tm:t_lookup_request: no transaction found
Jul 23 16:01:16 [22780] DBG:tm:run_reqin_callbacks:
trans=0x7f81e1b41548, callback type 1, id 1 entered
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=78
Jul 23 16:01:16 [22780] DBG:tm:run_reqin_callbacks:
trans=0x7f81e1b41548, callback type 1, id 0 entered
Jul 23 16:01:16 [22780] DBG:dialog:ref_dlg: ref dlg 0x7f81e1b3c2f8 with
1 -> 5
Jul 23 16:01:16 [22780] DBG:core:mk_proxy: doing DNS lookup...
Jul 23 16:01:16 [22780] DBG:core:check_ip_address: params 10.10.16.1,
10.10.16.1, 0
Jul 23 16:01:16 [22780] DBG:tm:set_timer: relative timeout is 500000
Jul 23 16:01:16 [22780] DBG:tm:insert_timer_unsafe: [4]: 0x7f81e1b41768
(15800000)
Jul 23 16:01:16 [22780] DBG:tm:insert_timer_unsafe: [0]: 0x7f81e1b41798 (20)
Jul 23 16:01:16 [22780] DBG:tm:t_relay_to: new transaction fwd'ed
[Script Trace][/etc/opensips/opensips.cfg:341][me][core exit] -> (BYE
from 10.10.16.1, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:tm:t_unref: UNREF_UNSAFE: [0x7f81e1b41548]
after is 0
Jul 23 16:01:16 [22780] DBG:dialog:unref_dlg: unref dlg 0x7f81e1b3c2f8
with 1 -> 4 in entry 0x7f81e1b35838
Jul 23 16:01:16 [22780] DBG:core:destroy_avp_list: destroying list (nil)
Jul 23 16:01:16 [22780] DBG:core:receive_msg: cleaning up
Jul 23 16:01:16 [22780] DBG:core:parse_msg: SIP Request:
Jul 23 16:01:16 [22780] DBG:core:parse_msg: method: <BYE>
Jul 23 16:01:16 [22780] DBG:core:parse_msg: uri:
<sip:10.10.16.2;did=dbf.d239f4f3>
Jul 23 16:01:16 [22780] DBG:core:parse_msg: version: <SIP/2.0>
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=2
Jul 23 16:01:16 [22780] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK2ff9.7dfac551.0>; state=16
Jul 23 16:01:16 [22780] DBG:core:parse_via: end of header reached, state=5
Jul 23 16:01:16 [22780] DBG:core:parse_headers: via found, flags=2
Jul 23 16:01:16 [22780] DBG:core:parse_headers: this is the first via
Jul 23 16:01:16 [22780] DBG:core:receive_msg: After parse_msg...
Jul 23 16:01:16 [22780] DBG:core:receive_msg: preparing to run routing
scripts...
[Script Trace][/etc/opensips/opensips.cfg:176][me][core if] -> (BYE from
10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:171][me][module
mf_process_maxfwd_header] -> (BYE from 10.10.16.2,
ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=100
Jul 23 16:01:16 [22780] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK53eneb00a89gqfc5m0o0.1>; state=16
Jul 23 16:01:16 [22780] DBG:core:parse_via: end of header reached, state=5
Jul 23 16:01:16 [22780] DBG:core:parse_headers: via found, flags=100
Jul 23 16:01:16 [22780] DBG:core:parse_headers: parse_headers: this is
the second via
Jul 23 16:01:16 [22780] DBG:core:parse_to_param: tag=6pou4pvn6xe2phuk.i
Jul 23 16:01:16 [22780] DBG:core:parse_to: end of header reached, state=29
Jul 23 16:01:16 [22780] DBG:core:parse_to: display={},
ruri={sip:27111000626 at 10.10.16.1:5060;user=phone}
Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: <To> [70];
uri=[sip:27111000626 at 10.10.16.1:5060;user=phone]
Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: to body
[<sip:27111000626 at 10.10.16.1:5060;user=phone>]
Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: cseq <CSeq>: <2> <BYE>
Jul 23 16:01:16 [22780] DBG:maxfwd:is_maxfwd_present: value = 66
[Script Trace][/etc/opensips/opensips.cfg:185][me][core if] -> (BYE from
10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:176][me][module
check_source_address] -> (BYE from 10.10.16.2,
ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:permissions:check_src_addr_3: Looking for :
<1, 10.10.16.2, 5060, 1> in tables
Jul 23 16:01:16 [22780] DBG:permissions:hash_match: no match in the hash
table
Jul 23 16:01:16 [22780] DBG:permissions:match_subnet_table: subnet table
is empty
[Script Trace][/etc/opensips/opensips.cfg:185][me][core if] -> (BYE from
10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:179][me][module is_from_gw] ->
(BYE from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:183][me][core xlog] -> (BYE
from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:core:buf_init: initializing...
Message is not from Trunk or GW 10.10.16.2[Script
Trace][/etc/opensips/opensips.cfg:248][me][core if] -> (BYE from
10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:187][me][module has_totag] ->
(BYE from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:uri:has_totag: totag found
[Script Trace][/etc/opensips/opensips.cfg:242][me][core if] -> (BYE from
10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:191][me][module
topology_hiding_match] -> (BYE from 10.10.16.2,
ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=200
Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: content_length=0
Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: found end of header
Jul 23 16:01:16 [22780] DBG:core:grep_sock_info: checking if host==us:
13==13 && [10.10.16.2] == [10.10.16.2]
Jul 23 16:01:16 [22780] DBG:core:grep_sock_info: checking if port 5060
matches port 5060
Jul 23 16:01:16 [22780] DBG:dialog:w_match_dialog: We found DID param in
R-URI with value of dbf.d239f4f3
Jul 23 16:01:16 [22780] DBG:dialog:dlg_onroute: route param is
'dbf.d239f4f3' (len=12)
Jul 23 16:01:16 [22780] DBG:dialog:lookup_dlg: ref dlg 0x7f81e1b3c2f8
with 1 -> 5
Jul 23 16:01:16 [22780] DBG:dialog:lookup_dlg: dialog id=1062179629
found on entry 4029
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=58
Jul 23 16:01:16 [22780] DBG:core:parse_to_param:
tag=SDl3i7c02-55B0F3A1-1DDB4E1-0ADE2C1B
Jul 23 16:01:16 [22780] DBG:core:parse_to: end of header reached, state=29
Jul 23 16:01:16 [22780] DBG:core:parse_to: display={},
ruri={sip:27115138000 at 10.10.17.55;user=phone}
Jul 23 16:01:16 [22780] DBG:dialog:next_state_dlg: dialog 0x7f81e1b3c2f8
changed from state 2 to state 2, due event 7
[Script Trace][/etc/opensips/opensips.cfg:199][me][core if] -> (BYE from
10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Trevor
[Script Trace][/etc/opensips/opensips.cfg:194][me][module
validate_dialog] -> (BYE from 10.10.16.2,
ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:dialog:dlg_validate_dialog: CSEQ validation
passed
[Script Trace][/etc/opensips/opensips.cfg:210][me][core if] -> (BYE from
10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:199][me][module is_method] ->
(BYE from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:200][me][core setflag] -> (BYE
from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:201][me][core setflag] -> (BYE
from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:227][me][core if] -> (BYE from
10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:210][me][module has_body] ->
(BYE from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:sipmsgops:has_body_f: content length is zero
[Script Trace][/etc/opensips/opensips.cfg:227][me][route RELAY] -> (BYE
from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:340][me][core if] -> (BYE from
10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:338][me][module t_relay] ->
(BYE from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:tm:t_newtran: transaction on
entrance=0xffffffffffffffff
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=ffffffffffffffff
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=78
Jul 23 16:01:16 [22780] DBG:tm:t_lookup_request: start searching:
hash=40946, isACK=0
Jul 23 16:01:16 [22780] DBG:tm:matching_3261: RFC3261 transaction
matching failed
Jul 23 16:01:16 [22780] DBG:tm:t_lookup_request: no transaction found
Jul 23 16:01:16 [22780] DBG:tm:run_reqin_callbacks:
trans=0x7f81e1b446a0, callback type 1, id 1 entered
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=78
Jul 23 16:01:16 [22780] DBG:tm:run_reqin_callbacks:
trans=0x7f81e1b446a0, callback type 1, id 0 entered
Jul 23 16:01:16 [22780] DBG:dialog:ref_dlg: ref dlg 0x7f81e1b3c2f8 with
1 -> 6
Jul 23 16:01:16 [22780] DBG:core:mk_proxy: doing DNS lookup...
Jul 23 16:01:16 [22780] DBG:core:check_ip_address: params 10.10.16.2,
10.10.16.2, 0
Jul 23 16:01:16 [22780] DBG:tm:set_timer: relative timeout is 500000
Jul 23 16:01:16 [22780] DBG:tm:insert_timer_unsafe: [4]: 0x7f81e1b448c0
(15800000)
Jul 23 16:01:16 [22780] DBG:tm:insert_timer_unsafe: [0]: 0x7f81e1b448f0 (20)
Jul 23 16:01:16 [22780] DBG:tm:t_relay_to: new transaction fwd'ed
[Script Trace][/etc/opensips/opensips.cfg:341][me][core exit] -> (BYE
from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:tm:t_unref: UNREF_UNSAFE: [0x7f81e1b446a0]
after is 0
Jul 23 16:01:16 [22780] DBG:dialog:unref_dlg: unref dlg 0x7f81e1b3c2f8
with 1 -> 5 in entry 0x7f81e1b35838
Jul 23 16:01:16 [22780] DBG:core:destroy_avp_list: destroying list (nil)
Jul 23 16:01:16 [22780] DBG:core:receive_msg: cleaning up
Jul 23 16:01:16 [22780] DBG:core:parse_msg: SIP Request:
Jul 23 16:01:16 [22780] DBG:core:parse_msg: method: <BYE>
Jul 23 16:01:16 [22780] DBG:core:parse_msg: uri:
<sip:10.10.16.2;did=dbf.d239f4f3>
Jul 23 16:01:16 [22780] DBG:core:parse_msg: version: <SIP/2.0>
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=2
Jul 23 16:01:16 [22780] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK2ff9.8dfac551.0>; state=16
Jul 23 16:01:16 [22780] DBG:core:parse_via: end of header reached, state=5
Jul 23 16:01:16 [22780] DBG:core:parse_headers: via found, flags=2
Jul 23 16:01:16 [22780] DBG:core:parse_headers: this is the first via
Jul 23 16:01:16 [22780] DBG:core:receive_msg: After parse_msg...
Jul 23 16:01:16 [22780] DBG:core:receive_msg: preparing to run routing
scripts...
[Script Trace][/etc/opensips/opensips.cfg:176][me][core if] -> (BYE from
10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:171][me][module
mf_process_maxfwd_header] -> (BYE from 10.10.16.2,
ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:core:parse_headers: flags=100
Jul 23 16:01:16 [22780] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK2ff9.7dfac551.0>; state=16
Jul 23 16:01:16 [22780] DBG:core:parse_via: end of header reached, state=5
Jul 23 16:01:16 [22780] DBG:core:parse_headers: via found, flags=100
Jul 23 16:01:16 [22780] DBG:core:parse_headers: parse_headers: this is
the second via
Jul 23 16:01:16 [22780] DBG:core:parse_via_param: found param type 232,
<branch> = <z9hG4bK53eneb00a89gqfc5m0o0.1>; state=16
Jul 23 16:01:16 [22780] DBG:core:parse_via: end of header reached, state=5
Jul 23 16:01:16 [22780] DBG:core:parse_headers: via found, flags=100
Jul 23 16:01:16 [22780] DBG:core:parse_to_param: tag=6pou4pvn6xe2phuk.i
Jul 23 16:01:16 [22780] DBG:core:parse_to: end of header reached, state=29
Jul 23 16:01:16 [22780] DBG:core:parse_to: display={},
ruri={sip:27111000626 at 10.10.16.1:5060;user=phone}
Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: <To> [70];
uri=[sip:27111000626 at 10.10.16.1:5060;user=phone]
Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: to body
[<sip:27111000626 at 10.10.16.1:5060;user=phone>]
Jul 23 16:01:16 [22780] DBG:core:get_hdr_field: cseq <CSeq>: <2> <BYE>
Jul 23 16:01:16 [22780] DBG:maxfwd:is_maxfwd_present: value = 65
[Script Trace][/etc/opensips/opensips.cfg:185][me][core if] -> (BYE from
10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:176][me][module
check_source_address] -> (BYE from 10.10.16.2,
ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Jul 23 16:01:16 [22780] DBG:permissions:check_src_addr_3: Looking for :
<1, 10.10.16.2, 5060, 1> in tables
Jul 23 16:01:16 [22780] DBG:permissions:hash_match: no match in the hash
table
Jul 23 16:01:16 [22780] DBG:permissions:match_subnet_table: subnet table
is empty
[Script Trace][/etc/opensips/opensips.cfg:185][me][core if] -> (BYE from
10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:179][me][module is_from_gw] ->
(BYE from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
[Script Trace][/etc/opensips/opensips.cfg:183][me][core xlog] -> (BYE
from 10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Message is not from Trunk or GW 10.10.16.2[Script
Trace][/etc/opensips/opensips.cfg:248][me][core if] -> (BYE from
10.10.16.2, ruri=sip:10.10.16.2;did=dbf.d239f4f3)
Regards
Trevor Steyn
More information about the Users
mailing list