[OpenSIPS-Users] dialog time out not working

[Samuel Muller]

Hello Bogdan, Razvan,

A small update concerning the dialog time-out.
It's not working, again. I used the latest git version for my tests
(and yes Razvan, it fixed the var print).

Tried with :
modparam("tm","own_timer_proc",2), the 1, then disabling the stuff, no changes.


Here's all the relevant info :

=> modules config

modparam("tm","fr_timeout",10)      # default 30 sec
modparam("tm","fr_inv_timeout",60)  # default 120 sec
modparam("tm","wt_timer",5)         # default 5 sec
modparam("tm","delete_timer",2)     # default 2 sec
modparam("tm","T1_timer",500)       # default 500 msec
modparam("tm","T2_timer",4000)      # default 4000 msec
#modparam("tm","own_timer_proc",2)   # default 0 (disabled)
modparam("tm","ruri_matching",1)
modparam("tm","via1_matching",1)
modparam("tm","unix_tx_timeout",2)
modparam("tm","restart_fr_on_each_reply",1)
modparam("tm","pass_provisional_replies",0)
modparam("tm","syn_branch",1)
modparam("tm","onreply_avp_mode",1)
modparam("tm","disable_6xx_block",0)
modparam("tm","enable_stats",1)
modparam("tm","minor_branch_flag","MINOR_BFLAG")
modparam("dialog","enable_stats",1)
modparam("dialog","hash_size",4096)
modparam("dialog","log_profile_hash_size",4)
modparam("dialog","rr_param","did")
modparam("dialog","default_timeout",3600)
modparam("dialog","dlg_match_mode",1)
modparam("dialog","db_mode",0)
modparam("dialog","ping_interval",30)
modparam("sst","enable_stats",1)
modparam("sst","min_se",1800)
modparam("sst","sst_interval",0)
modparam("sst","reject_to_small",0)
modparam("sst","sst_flag","SST")

=> routing logic config

    if (is_method("INVITE")) {
        # SST module see dead people ...
        setflag(SST);
        # create the dialog
        create_dialog("B");
        # set the session timeout
        if (issflagset(CALLER_FOUND) && $(var(caller_stimeout){s.len}) != 0) {
            $DLG_timeout = $(var(caller_stimeout){s.int});
        } else {
            $DLG_timeout = 3600;
        }
        xlog("L_NOTICE","$var(log) invite: caller session timeout set
to $var(caller_stimeout) ($DLG_timeout) sec");
        # store a few values
        store_dlg_value("callid","$ci");
        store_dlg_value("dlgid","$DLG_did");
    }


=> debug logs (INVITE)

...
log[495]: DBG:dialog:w_create_dialog2: bye on timeout activated
log[495]: DBG:dialog:build_new_dlg: new dialog 0x7fb82da3e730
(c=da71a953f21b-7761pm3b03ux,f=sip:3933 at mysipdomain.com,t=sip:3101 at mysipdomain.com,ft=s3flexpnkz)
on hash 3263
log[495]: DBG:core:parse_params: Parsing params for:[reg-id=1]
log[495]: DBG:core:parse_headers: flags=ffffffffffffffff
log[495]: DBG:core:print_rr_body: current rr is
<sip:10.0.0.95;lr;ftag=s3flexpnkz;rr=vrf5411>
log[495]: DBG:core:print_rr_body: current rr is
<sip:192.168.0.33:6060;lr;ftag=s3flexpnkz;rr=sas>
log[495]: DBG:core:print_rr_body: skipping 0 route records
log[495]: DBG:core:print_rr_body: out rr
[<sip:10.0.0.95;lr;ftag=s3flexpnkz;rr=vrf5411>,<sip:192.168.0.33:6060;lr;ftag=s3flexpnkz;rr=sas>]
log[495]: DBG:core:print_rr_body: we have 2 records
log[495]: DBG:dialog:init_leg_info: route_set
<sip:10.0.0.95;lr;ftag=s3flexpnkz;rr=vrf5411>,<sip:192.168.0.33:6060;lr;ftag=s3flexpnkz;rr=sas>,
contact sip:3933 at 192.168.0.108:6060, cseq 2 and bind_addr
udp:10.0.0.92:5060
log[495]: DBG:dialog:dlg_add_leg_info: set leg 0 for 0x7fb82da3e730:
tag=<s3flexpnkz> rcseq=<0>
log[495]: DBG:dialog:link_dlg: ref dlg 0x7fb82da3e730 with 3 -> 3 in
h_entry 0x7fb82d8e6d80 - 3263
log[495]: DBG:rr:add_rr_param: adding (;did=fbc.4e0c3935) 0x7fb8565230c0
log[495]: DBG:core:comp_scriptvar: int 29 : 3 / 0
log[495]: da71a953f21b-7761pm3b03ux invite: caller session timeout set
to 120 (120) sec
log[495]: DBG:dialog:new_dlg_val: inserting <callid>=<da71a953f21b-7761pm3b03ux>
log[495]: DBG:dialog:new_dlg_val: inserting <dlgid>=<3263:1402192100>
...
log[495]: DBG:dialog:new_dlg_val: inserting <accX_created>=<?q?S>
log[495]: DBG:rr:is_direction: param ftag not found
log[495]: DBG:tm:run_reqin_callbacks: trans=0x7fb82da3fd00, callback
type 1, id 0 entered
log[495]: DBG:dialog:run_create_callbacks: dialog=0x7fb82da3e730
log[495]: DBG:core:parse_headers: flags=ffffffffffffffff
log[495]: DBG:core:parse_supported: parsing [Supported: timer, 100rel,
replaces, from-change] 0x7fb856520898
log[495]: DBG:sst:setup_dialog_callbacks: Adding callback
DLGCB_FAILED|DLGCB_TERMINATED|DLGCB_EXPIRED
log[495]: DBG:sst:setup_dialog_callbacks: Adding callback DLGCB_REQ_WITHIN
log[495]: DBG:sst:setup_dialog_callbacks: Adding callback
DLGCB_RESPONSE_FWDED|DLGCB_RESPONSE_WITHIN
log[495]: DBG:sst:setup_dialog_callbacks: Adding mi handler
log[495]: DBG:sst:set_dialog_lifetime: set dialog timeout value to 1800
log[495]: DBG:dialog:dlg_onreq: t hash_index = 27891, t label = 289580432
...

=> debug logs (PRACK)

...
log[497]: DBG:dialog:dlg_onroute: route param is 'fbc.4e0c3935' (len=12)
log[497]: DBG:dialog:lookup_dlg: ref dlg 0x7fb82da3e730 with 1 -> 3
log[497]: DBG:dialog:lookup_dlg: dialog id=1402192100 found on entry 3263
log[497]: DBG:core:parse_headers: flags=58
log[497]: DBG:dialog:next_state_dlg: dialog 0x7fb82da3e730 changed
from state 2 to state 2, due event 5
log[497]: DBG:dialog:run_dlg_callbacks: dialog=0x7fb82da3e730, type=16
log[497]: DBG:sst:sst_dialog_request_within_CB: ACK/PRACK workaround
applied!1800
log[497]: DBG:sst:set_dialog_lifetime: set dialog timeout value to 1800
log[497]: DBG:dialog:dlg_onroute: EARLY event 5 successfully processed
(dst_leg=1)
log[497]: DBG:dialog:switch_cseqs: prev_cseq = 2 for leg 1
log[497]: DBG:dialog:dlg_update_cseq: dlg 0x7fb82da3e730[1]: cseq is 3
...

and so on for all the others sip messages.


Thanks for your help, really needed it actually.


Samuel MULLER