[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