[OpenSIPS-Users] BYE on 180 causing dialog loop
Vlad Paiu
vladpaiu at opensips.org
Thu Nov 17 12:53:56 CET 2011
Hello,
The problem lies in the fact that the device send BYE while the dialog
was not established yet, when in fact a Cancel should have been used.
When you are using topology hiding, OpenSIPS relies that it known the
Contacts of the end-points to over-write things in the messages in
proxies. But if there was no 200Ok, and the device miss-properly sends a
BYE, OpenSIPS does not have yet all the information to properly route a
sequential request, so what you'll get is the looping of that particular
BYE on the proxy side until Max-Forwards header reaches 0.
What you can do is reject the request in the match_dialog if, based on
the current dialog status, if it's not established yet. Try something like :
if (has_totag()&& (uri == myself)&&
is_method("INVITE|ACK|BYE|UPDATE")) {
if(match_dialog()) {
xlog(" in-dialog topology hiding request - $DLG_dir\n");
if (is_method("BYE")&& $DLG_status<= 2) {
#reject invalid BYE
send_reply("481","Dialog state does not allow BYE");
exit;
}
route(1);
exit;
}
}
Regards,
Vlad Paiu
OpenSIPS Developer
On 11/15/2011 07:12 PM, ddgiants wrote:
> 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.
>
> _______________________________________________
> Users mailing list
> Users at lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
More information about the Users
mailing list