5 Mar
2007
5 Mar
'07
7:55 a.m.
Hi,
I'm trying to understand how the SST handles the case of a UA that is
off the network when the session timer expires.
I have the following configuration:
x-lite has session timer support, so using that to test the module.
min session timer is set to 91 seconds.
x-lite (149) - > openser --> x-lite ( 101)
INVITE --->
-> INVITE
<--100 trying
100 trying <-----
<-180 ringing
180 ringing <--
<-200 ok
200 ok <---
ack --->
-->ack
Call is setup at this point.
I then remove the power supply from 101.
some seconds later we see this:
INVITE -------> --> INVITE
100 trying <------
...... ( no response from 101)
<--- 408 timeout
BYE ---------->
....
Ok at this point openser never sends a 200 ok to the BYE.
From what I can see in the SST module, that it deletes
the dialog.in
memory, but not sure how that will help here.
--- debug logs -- where the FIRST bye comes in from 149:
0(5526) SIP Request:
0(5526) method: <BYE>
0(5526) uri: <sip:101@192.168.0.104:5061>
0(5526) version: <SIP/2.0>
0(5526) parse_headers: flags=2
0(5526) Found param type 232, <branch> =
<z9hG4bK-d87543-8f727a53ca51673e-1--d87543->; state=6
0(5526) Found param type 235, <rport> = <n/a>; state=17
0(5526) end of header reached, state=5
0(5526) parse_headers: Via found, flags=2
0(5526) parse_headers: this is the first via
0(5526) After parse_msg...
0(5526) preparing to run routing scripts...
0(5526) parse_headers: flags=100
0(5526) DEBUG:maxfwd:is_maxfwd_present: value = 70
0(5526) parse_headers: flags=10
0(5526) DEBUG: add_param: tag=faea2a83cd5fd6c1
0(5526) DEBUG:parse_to:end of header reached, state=29
0(5526) DBUG:parse_to: display={"101"}, ruri={sip:101@192.168.0.101}
0(5526) DEBUG: get_hdr_field: <To> [51]; uri=[sip:101@192.168.0.101]
0(5526) DEBUG: to body ["101"<sip:101@192.168.0.101>]
0(5526) DEBUG: add_param: tag=5077431e
0(5526) DEBUG:parse_to:end of header reached, state=29
0(5526) DBUG:parse_to: display={"149"}, ruri={sip:149@192.168.0.101}
0(5526) parse_headers: flags=200
0(5526) is_preloaded: No
0(5526) grep_sock_info - checking if host==us: 13==13 &&
[192.168.0.104] == [192.168.0.101]
0(5526) grep_sock_info - checking if port 5060 matches port 5061
0(5526) grep_sock_info - checking if host==us: 13==13 &&
[192.168.0.104] == [192.168.0.101]
0(5526) grep_sock_info - checking if port 5060 matches port 5061
0(5526) DEBUG:check_self: host != me
0(5526) grep_sock_info - checking if host==us: 13==13 &&
[192.168.0.101] == [192.168.0.101]
0(5526) grep_sock_info - checking if port 5060 matches port 5060
0(5526) after_loose: Topmost route URI:
'sip:192.168.0.101;lr;ftag=5077431e;did=5ff.8e4f3775' is me
0(5526) parse_headers: flags=200
0(5526) get_hdr_field: cseq <CSeq>: <3> <BYE>
0(5526) DEBUG: get_hdr_body : content_length=0
0(5526) found end of header
0(5526) find_next_route: No next Route HF found
0(5526) after_loose: No next URI found
0(5526) DBG:rr:run_rr_callbacks: callback id 0 entered with
<lr;ftag=5077431e;did=5ff.8e4f3775>
0(5526) DEBUG:dialog:dlg_onroute: route param is '5ff.8e4f3775' (len=12)
0(5526) DEBUG:dialog:lookup_dlg: dialog id=1467217128 found on entry 4085
0(5526) DEBUG:dialog:run_create_callbacks: dialog=0xb5c65280, type=16
0(5526) DEBUG:sst_handlers.c:sst_dialog_terminate_CB:403: Terminating
DID 0xb5c65280 session
0(5526) DEBUG:sst_handlers.c:sst_dialog_terminate_CB:410: Freeing the
sst_info_t from dialog 0xb5c65280
0(5526) DBUG:dialog:unref_dlg: unref dlg 0xb5c65280 with 2 (delete=1)-> 0
0(5526) DBUG:dialog:destroy_dlg: destroing dialog 0xb5c65280
0(5526) loose_route() succeeded - M=BYE
RURI=sip:101@192.168.0.104:5061 F=sip:149@192.168.0.101
T=sip:101@192.168.0.101 IP=192.168.0.102
ID=NTUzNzA5NWNjYmM5YWQ2MjQxYzgzZDdkZTRlMmQwODk.
0(5526) ERROR:dialog:dlg_status: res->ri = 5
0(5526) comp_scriptvar: int 20 : 5 / 0
0(5526) DEBUG: t_newtran: msg id=8 , global msg id=7 , T on entrance=0xffffffff
0(5526) parse_headers: flags=ffffffffffffffff
0(5526) parse_headers: flags=78
0(5526) t_lookup_request: start searching: hash=10869, isACK=0
0(5526) DEBUG: RFC3261 transaction matching failed
0(5526) DEBUG: t_lookup_request: no transaction found
0(5526) DBG: trans=0xb5c67b00, callback type 1, id 1 entered
0(5526) DBG: trans=0xb5c67b00, callback type 1, id 0 entered
0(5526) parse_headers: flags=78
0(5526) DEBUG: mk_proxy: doing DNS lookup...
0(5526) check_via_address(192.168.0.102, 192.168.0.102, 0)
0(5526) DBG:check_against_rule_list: using list dns
0(5526) DEBUG:tm:set_timer: relative timeout is 500000
0(5526) DEBUG: add_to_tail_of_timer[4]: 0xb5c67c4c (61500000)
0(5526) DEBUG:tm:set_timer: relative timeout is 30
0(5526) DEBUG: add_to_tail_of_timer[0]: 0xb5c67c68 (91)
0(5526) DEBUG:tm:t_relay_to: new transaction fwd'ed
0(5526) DEBUG:tm:UNREF_UNSAFE: after is 0
0(5526) DEBUG:destroy_avp_list: destroying list (nil)
0(5526) receive_msg: cleaning up
---
thanks,
Andy