[OpenSIPS-Users] BYE on 180 causing dialog loop
ddgiants
ddgiants at gmail.com
Tue Nov 15 18:12:34 CET 2011
Call flow using 1.7, dialog and topology hiding. Opensips does not core but
repeats a message over and over again shown below. SIP trace attached.
Config below. I suppose the UAC sending a BYE on 180 with no sdp is
debatable. Regardless how do I configure Opensips to NOT loop. It is
matching dialog and confirming dialog. So I am not sure how to recognize
and/or respond with something like 481? If this happens in production and we
get slammed it will most likely core or consume all resources.
Thanks
Darren
*Call flow*
uac1 -INVITE> opensips -INVITE> uac2
uac1 <100 TRYING- opensips <100 TRYING- uac2
uac1 <180 RINGING w/no sdp- opensips <180 RINGING w/no sdp- uac2
uac1 -BYE> opensips (loops message)
*LOG DEBUG 3*
Nov 15 11:52:15 [29299] CRITICAL:dialog:log_next_state_dlg: bogus event 7 in
state 2 for dlg 0xb532f894 [3456:1137368099] with clid
'YmExNGIyZmU0MWFjNzk0NDVkYTFjZmUxMjgzODQ1ZjU.' a
nd tags 'd625dfb9' '83cbbc3a'
*LOG DEBUG 6*
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_msg: SIP
Request:
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_msg: method:
<BYE>
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_msg: uri:
<sip:192.168.1.116:5060;did=188.8bf8ed32>
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_msg: version:
<SIP/2.0>
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_headers: flags=2
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_via_param: found
param type 232, <branch> = <z9hG4bK-d8754z-01554c81a80fa7c8-1---d8754z->;
state=6
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_via_param: found
param type 235, <rport> = <n/a>; state=17
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_via: end of
header reached, state=5
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_headers: via
found, flags=2
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_headers: this is
the first via
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:receive_msg: After
parse_msg...
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:receive_msg: preparing
to run routing scripts...
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_headers:
flags=100
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:maxfwd:is_maxfwd_present:
value = 70
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_headers: flags=8
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_to_param:
tag=16f91d44
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_to: end of
header reached, state=29
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_to: display={},
ruri={sip:14443332222 at 192.168.1.116}
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:get_hdr_field: <To>
[46]; uri=[sip:14443332222 at 192.168.1.116]
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:get_hdr_field: to body
[<sip:14443332222 at 192.168.1.116>]
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:uri:has_totag: totag found
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:uri:has_totag: totag found
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:grep_sock_info:
checking if host==us: 13==13 && [192.168.1.116] == [192.168.1.116]
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:grep_sock_info:
checking if port 5060 matches port 5060
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:dialog:dlg_onroute: Route
param 'did' not found
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_headers:
flags=58
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_to_param:
tag=ffd78602
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_to: end of
header reached, state=29
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_to:
display={"Opensips test"}, ruri={sip:12223334444 at 192.168.1.116}
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:dialog:get_dlg: input
ci=<OTZjYTUwY2I2MGFjNDE0NGIzZjNkZjEzMzc1ZDMwNDM.>(44), tt=<ffd78602>(8),
ft=<16f91d44>(8)
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:dialog:get_dlg: ref dlg
0xb5288894 with 1 -> 3
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:dialog:get_dlg: dialog
callid='OTZjYTUwY2I2MGFjNDE0NGIzZjNkZjEzMzc1ZDMwNDM.' found#012 on entry
2177, dir=1
Nov 15 12:04:41 hp-opensuse opensips[29620]:
CRITICAL:dialog:log_next_state_dlg: bogus event 7 in state 2 for dlg
0xb5288894 [2177:601788344] with clid 'OTZjYTUwY2I2MGFjNDE0NGIz
ZjNkZjEzMzc1ZDMwNDM.' and tags 'ffd78602' '16f91d44'
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:dialog:next_state_dlg:
dialog 0xb5288894 changed from state 2 to state 2, due event 7
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:dialog:dlg_save_del_vias:
Delete via [Via: SIP/2.0/UDP
192.168.1.214:5060;branch=z9hG4bK-d8754z-01554c81a80fa7c8-1---d8754z-;rpo
rt#015#012]
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:dialog:dlg_save_del_vias:
[leg= 0xb5288978] last_vias: Via: SIP/2.0/UDP
192.168.1.214:5060;branch=z9hG4bK-d8754z-01554c81a80fa7c
8-1---d8754z-;rport#015#012
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:dialog:dlg_replace_contact:
Replaced contact with [<sip:192.168.1.116:5060;did=188.8bf8ed32>]
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:dialog:ref_dlg: ref dlg
0xb5288894 with 1 -> 4
Nov 15 12:04:41 hp-opensuse opensips[29620]: INFO:core:buf_init:
initializing...
Nov 15 12:04:41 hp-opensuse opensips[29620]: in-dialog topology hiding
request - downstream
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:tm:t_newtran: transaction
on entrance=0xffffffff
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_headers:
flags=ffffffffffffffff
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:get_hdr_field: cseq
<CSeq>: <2> <BYE>
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:get_hdr_field:
content_length=0
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:get_hdr_field: found
end of header
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:parse_headers:
flags=78
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:tm:t_lookup_request: start
searching: hash=30901, isACK=0
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:tm:matching_3261: RFC3261
transaction matching failed
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:tm:t_lookup_request: no
transaction found
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:tm:run_reqin_callbacks:
trans=0xb528b520, callback type 1, id 1 entered
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:dialog:ref_dlg: ref dlg
0xb5288894 with 1 -> 5
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:tm:run_reqin_callbacks:
trans=0xb528b520, callback type 1, id 0 entered
Nov 15 12:04:41 hp-opensuse opensips[29620]: DBG:core:mk_proxy: doing DNS
lookup...
*OPENSIPS.CFG*
# $Id: opensips-b2b.cfg $
# Debugging mode:
debug=3
memlog= 6
fork=yes
auto_aliases=no
log_stderror=yes
disable_core_dump=yes
disable_dns_blacklist=yes
listen=192.168.1.116:5060
# alias=OSIPS_REALM
#port=OSIPS_PORT
sip_warning=0
#server_header="SRV_SIGNATURE"
#user_agent_header="PP_USER_AGENT"
#mhomed=yes
#memlog=2
check_via=no
dns=off
rev_dns=off
children=4
disable_tcp=yes
log_facility=LOG_LOCAL0
# for more info: opensips -h
# ------------------ module loading ----------------------------------
mpath="/usr/local/lib/opensips/modules/"
# Need acc and dialog to write cdrs
# Need uri to use has_totag
loadmodule "db_mysql.so"
loadmodule "avpops.so"
loadmodule "exec.so"
#loadmodule "xlog.so"
loadmodule "textops.so"
loadmodule "maxfwd.so"
loadmodule "rr.so"
loadmodule "sl.so"
loadmodule "tm.so"
loadmodule "signaling.so"
loadmodule "usrloc.so"
loadmodule "registrar.so"
loadmodule "mi_fifo.so"
loadmodule "uac_redirect.so"
loadmodule "localcache.so"
loadmodule "nathelper.so"
loadmodule "acc.so"
loadmodule "dialog.so"
loadmodule "uri.so"
# ----------------- setting module-specific parameters ---------------
modparam("mi_fifo", "fifo_name", "/tmp/opensips_fifo")
modparam("avpops","db_url","mysql://xxx:yyy@localhost/zzz")
modparam("acc", "db_url", "mysql://xxx:yyy@localhost/opensips")
modparam("acc", "failed_transaction_flag", 1)
modparam("acc", "log_level", 1)
modparam("acc", "db_missed_flag", 1)
modparam("acc", "log_missed_flag", 1)
modparam("acc", "log_flag", 1)
modparam("acc", "db_flag", 1)
modparam("acc", "cdr_flag", 1)
modparam("acc", "db_extra", "contacts=$avp(contacts); src_ip=$avp(src_ip);
uri_user_portion=$rU; dest_ip=$rd; orig_callid=$avp(orig_ci);
cust_rate=$avp(cust_rate); vendor_rate=$avp
(vendor_rate)")
modparam("acc", "db_table_acc", "cdrs")
modparam("acc", "db_table_missed_calls", "cdrs")
modparam("usrloc", "db_mode", 0)
modparam("tm", "pass_provisional_replies", 1)
route {
if (!mf_process_maxfwd_header("10")) {
sl_send_reply("483","Too Many Hops");
exit;
};
if (msg:len >= 2380 ) {
sl_send_reply("513", "Message too big");
exit;
};
if(!has_totag() && is_method("INVITE")) {
topology_hiding();
setflag(1);
$du = "sip:192.168.1.208";
$rd = "192.168.1.208";
route(1);
exit;
}
if (has_totag() && (uri == myself) &&
is_method("INVITE|ACK|BYE|UPDATE")) {
if(match_dialog()) {
xlog(" in-dialog topology hiding request - $DLG_dir\n");
route(1);
exit;
}
}
}#end route
route[1] {
if (!t_relay()) {
sl_reply_error();
};
t_on_reply("1");
exit;
}
onreply_route[1] {
if(t_check_status("200")) {
if(search("Content-type: application/sdp")) {
fix_nated_sdp("8", "192.168.1.116");
}
}
}
http://opensips-open-sip-server.1449251.n2.nabble.com/file/n6997019/opensips-180-bye.pcap
opensips-180-bye.pcap
--
View this message in context: http://opensips-open-sip-server.1449251.n2.nabble.com/BYE-on-180-causing-dialog-loop-tp6997019p6997019.html
Sent from the OpenSIPS - Users mailing list archive at Nabble.com.
More information about the Users
mailing list