[OpenSIPS-Users] Opensips 1.6.2 to 1.6.3 SST module question

Fri Aug 27 09:47:56 CEST 2010

Hi,

I see that the signalling requires a re-INVITE after 180 secs (3 
minutes) - the SST + DIALOG module will terminate the dialog if there is 
no such re-INVITE.

Unfortunatelly the trace has no timestamps to see if the dialog module 
fires the BYE after 3 minutes.

The re-INVITE must be fires by UAC (see in 200 OK : Session-Expires: 
180;refresher=uac )

Regards,
Bogdan

k1028 wrote:
> The call is established but terminated after some time.
>
> Here is the SIP trace from siptrace module and debug 5 from Opensips. There
> is no BYE in the SIPTrace. Debug 5 from Opensips did show BYE sent to caller
> and to callee from dialog module. 
>
> INVITE sip:1510495xxxx at 74.x.x.x. SIP/2.0
> Record-Route: <sip:1510495xxxx at 74.x.x.x.;lr=on;did=935.96fcf79>
> Via: SIP/2.0/UDP 74.x.x.x.;branch=z9hG4bKd659.0ab95ac3.0
> Via: SIP/2.0/UDP
> 192.168.8.222:5068;received=173.x.x.x;branch=z9hG4bK-d87543-21170d43ec319d0c-1--d87543-;rport=5068
> Max-Forwards: 69
> Contact: <sip:1111 at 173.x.x.x:5068>
> To: <sip:1510495xxxx at 74.x.x.x.>
> From: "1111"<sip:1111 at 74.x.x.x.>;tag=5145635c
> Call-ID: OThhNWNjOWNjZWFmZDkwMmFlNTExYmVmNTM1ZTE2NjM.
> CSeq: 2 INVITE
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS
> Content-Type: application/sdp
> User-Agent: Idefisk
> Content-Length: 220
> Session-Expires: 180
>
> v=0
> o=Idefisk_user 6056184806875838134 13270 IN IP4 192.168.8.222
> s=Idefisk_user
> c=IN IP4 74.x.x.x.
> t=0 0
> m=audio 1306 RTP/AVP 97 101
> a=fmtp:101  0-15
> a=rtpmap:97 iLBC/8000
> a=rtpmap:101 telephone-event/8000
>
> SIP/2.0 100 Trying
> Via: SIP/2.0/UDP 74.x.x.x.;branch=z9hG4bKd659.0ab95ac3.0;received=74.x.x.x.
> Via: SIP/2.0/UDP
> 192.168.8.222:5068;received=173.x.x.x;branch=z9hG4bK-d87543-21170d43ec319d0c-1--d87543-;rport=5068
> Record-Route: <sip:1510495xxxx at 74.x.x.x.;lr=on;did=935.96fcf79>
> From: "1111"<sip:1111 at 74.x.x.x.>;tag=5145635c
> To: <sip:1510495xxxx at 74.x.x.x.>
> Call-ID: OThhNWNjOWNjZWFmZDkwMmFlNTExYmVmNTM1ZTE2NjM.
> CSeq: 2 INVITE
> User-Agent: iWorld
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
> Supported: replaces
> Contact: <sip:1510495xxxx at 64.x.x.x>
> Content-Length: 0
>
> SIP/2.0 180 Ringing
> Via: SIP/2.0/UDP
> 192.168.8.222:5068;received=173.x.x.x;branch=z9hG4bK-d87543-21170d43ec319d0c-1--d87543-;rport=5068
> Record-Route: <sip:1510495xxxx at 74.x.x.x.;lr=on;did=935.96fcf79>
> From: "1111"<sip:1111 at 74.x.x.x.>;tag=5145635c
> To: <sip:1510495xxxx at 74.x.x.x.>;tag=as3154366e
> Call-ID: OThhNWNjOWNjZWFmZDkwMmFlNTExYmVmNTM1ZTE2NjM.
> CSeq: 2 INVITE
> User-Agent: iWorld
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
> Supported: replaces
> Contact: <sip:1510495xxxx at 64.x.x.x>
> Content-Length: 0
>
> SIP/2.0 180 Ringing
> Via: SIP/2.0/UDP 74.x.x.x.;branch=z9hG4bKd659.0ab95ac3.0;received=74.x.x.x.
> Via: SIP/2.0/UDP
> 192.168.8.222:5068;received=173.x.x.x;branch=z9hG4bK-d87543-21170d43ec319d0c-1--d87543-;rport=5068
> Record-Route: <sip:1510495xxxx at 74.x.x.x.;lr=on;did=935.96fcf79>
> From: "1111"<sip:1111 at 74.x.x.x.>;tag=5145635c
> To: <sip:1510495xxxx at 74.x.x.x.>;tag=as3154366e
> Call-ID: OThhNWNjOWNjZWFmZDkwMmFlNTExYmVmNTM1ZTE2NjM.
> CSeq: 2 INVITE
> User-Agent: iWorld
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
> Supported: replaces
> Contact: <sip:1510495xxxx at 64.x.x.x>
> Content-Length: 0
>
> SIP/2.0 183 Session Progress
> Via: SIP/2.0/UDP
> 192.168.8.222:5068;received=173.x.x.x;branch=z9hG4bK-d87543-21170d43ec319d0c-1--d87543-;rport=5068
> Record-Route: <sip:1510495xxxx at 74.x.x.x.;lr=on;did=935.96fcf79>
> From: "1111"<sip:1111 at 74.x.x.x.>;tag=5145635c
> To: <sip:1510495xxxx at 74.x.x.x.>;tag=as3154366e
> Call-ID: OThhNWNjOWNjZWFmZDkwMmFlNTExYmVmNTM1ZTE2NjM.
> CSeq: 2 INVITE
> User-Agent: iWorld
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
> Supported: replaces
> Contact: <sip:1510495xxxx at 64.x.x.x>
> Content-Type: application/sdp
> Content-Length: 259
>
> v=0
> o=root 7723 7723 IN IP4 64.x.x.x
> s=session
> c=IN IP4 74.x.x.x.
> t=0 0
> m=audio 1304 RTP/AVP 97 101
> a=rtpmap:97 iLBC/8000
> a=fmtp:97 mode=30
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:30
> a=sendrecv
>
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP 74.x.x.x.;branch=z9hG4bKd659.0ab95ac3.0;received=74.x.x.x.
> Via: SIP/2.0/UDP
> 192.168.8.222:5068;received=173.x.x.x;branch=z9hG4bK-d87543-21170d43ec319d0c-1--d87543-;rport=5068
> Record-Route: <sip:1510495xxxx at 74.x.x.x.;lr=on;did=935.96fcf79>
> From: "1111"<sip:1111 at 74.x.x.x.>;tag=5145635c
> To: <sip:1510495xxxx at 74.x.x.x.>;tag=as3154366e
> Call-ID: OThhNWNjOWNjZWFmZDkwMmFlNTExYmVmNTM1ZTE2NjM.
> CSeq: 2 INVITE
> User-Agent: iWorld
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
> Supported: replaces
> Contact: <sip:1510495xxxx at 64.x.x.x>
> Content-Type: application/sdp
> Content-Length: 259
>
> v=0
> o=root 7723 7724 IN IP4 64.x.x.x
> s=session
> c=IN IP4 64.x.x.x
> t=0 0
> m=audio 50450 RTP/AVP 97 101
> a=rtpmap:97 iLBC/8000
> a=fmtp:97 mode=30
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:30
> a=sendrecv
>
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP
> 192.168.8.222:5068;received=173.x.x.x;branch=z9hG4bK-d87543-21170d43ec319d0c-1--d87543-;rport=5068
> Record-Route: <sip:1510495xxxx at 74.x.x.x.;lr=on;did=935.96fcf79>
> From: "1111"<sip:1111 at 74.x.x.x.>;tag=5145635c
> To: <sip:1510495xxxx at 74.x.x.x.>;tag=as3154366e
> Call-ID: OThhNWNjOWNjZWFmZDkwMmFlNTExYmVmNTM1ZTE2NjM.
> CSeq: 2 INVITE
> User-Agent: iWorld
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
> Supported: replaces
> Contact: <sip:1510495xxxx at 64.x.x.x>
> Content-Type: application/sdp
> Content-Length: 259
> Session-Expires: 180;refresher=uac
>
> v=0
> o=root 7723 7724 IN IP4 64.x.x.x
> s=session
> c=IN IP4 74.x.x.x.
> t=0 0
> m=audio 1304 RTP/AVP 97 101
> a=rtpmap:97 iLBC/8000
> a=fmtp:97 mode=30
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:30
> a=sendrecv
>
> ACK sip:1510495xxxx at 64.x.x.x SIP/2.0
> Via: SIP/2.0/UDP
> 192.168.8.222:5068;branch=z9hG4bK-d87543-fc30fd0917758e54-1--d87543-;rport
> Max-Forwards: 70
> Route: <sip:1510495xxxx at 74.x.x.x.;lr;did=935.96fcf79>
> Contact: <sip:1111 at 192.168.8.222:5068>
> To: <sip:1510495xxxx at 74.x.x.x.>;tag=as3154366e
> From: "1111"<sip:1111 at 74.x.x.x.>;tag=5145635c
> Call-ID: OThhNWNjOWNjZWFmZDkwMmFlNTExYmVmNTM1ZTE2NjM.
> CSeq: 2 ACK
> Proxy-Authorization: Digest
> username="1111",realm="74.x.x.x.",nonce="4c754fc500000003cc350d97ea9ab177ce47146b80f9b7a5",uri="sip:1510495xxxx at 74.x.x.x.",response="8037cc4b5b1bc6c822f7742c02f3e7e0",algorithm=MD5
> User-Agent: Idefisk
> Content-Length: 0
>
> ACK sip:1510495xxxx at 64.x.x.x SIP/2.0
> Via: SIP/2.0/UDP 74.x.x.x.;branch=z9hG4bKd659.0ab95ac3.2
> Via: SIP/2.0/UDP
> 192.168.8.222:5068;received=173.x.x.x;branch=z9hG4bK-d87543-fc30fd0917758e54-1--d87543-;rport=5068
> Max-Forwards: 69
> Contact: <sip:1111 at 173.x.x.x:5068>
> To: <sip:1510495xxxx at 74.x.x.x.>;tag=as3154366e
> From: "1111"<sip:1111 at 74.x.x.x.>;tag=5145635c
> Call-ID: OThhNWNjOWNjZWFmZDkwMmFlNTExYmVmNTM1ZTE2NjM.
> CSeq: 2 ACK
> Proxy-Authorization: Digest
> username="1111",realm="74.x.x.x.",nonce="4c754fc500000003cc350d97ea9ab177ce47146b80f9b7a5",uri="sip:1510495xxxx at 74.x.x.x.",response="8037cc4b5b1bc6c822f7742c02f3e7e0",algorithm=MD5
> User-Agent: Idefisk
> Content-Length: 01111 at 64.x.x.x@64.x.x.x1111 at 173.x.x.x
>
>
>
>
> Aug 25 17:19:05 [14748] DBG:dialog:get_expired_dlgs: start with
> tl=0x7fb34b920ec0 tl->prev=0x7fb34b8ec938 tl->next=0x7fb34b8ec938 (375) at
> 375 and end with end=0x7fb34b8ec938 end->prev=0x7fb34b920ec0
> end->next=0x7fb34b920ec0
> Aug 25 17:19:05 [14748] DBG:dialog:get_expired_dlgs: getting
> tl=0x7fb34b920ec0 tl->prev=0x7fb34b8ec938 tl->next=0x7fb34b8ec938 with 375
> Aug 25 17:19:05 [14748] DBG:dialog:get_expired_dlgs: end with
> tl=0x7fb34b8ec938 tl->prev=0x7fb34b920ec0 tl->next=0x7fb34b920ec0 and
> d_timer->first.next->prev=(nil)
> Aug 25 17:19:05 [14748] DBG:dialog:dlg_timer_routine: tl=0x7fb34b920ec0
> next=(nil)
> Aug 25 17:19:05 [14748] DBG:dialog:send_leg_bye: sending BYE to caller (0)
> Aug 25 17:19:05 [14748] DBG:dialog:ref_dlg: ref dlg 0x7fb34b920e88 with 1 ->
> 3
> Aug 25 17:19:05 [14748] DBG:tm:t_uac: next_hop=<sip:1111 at 173.8.136.75:5068>
> Aug 25 17:19:05 [14748] DBG:core:mk_proxy: doing DNS lookup...
> Aug 25 17:19:05 [14748] DBG:tm:dlg2hash: 38254
> Aug 25 17:19:05 [14748] DBG:tm:print_request_uri: sip:1111 at 173.8.136.75:5068
> Aug 25 17:19:05 [14748] DBG:tm:set_timer: relative timeout is 500000
> Aug 25 17:19:05 [14748] DBG:tm:insert_timer_unsafe: [4]: 0x7fb34b91d288
> (375500000)
> Aug 25 17:19:05 [14748] DBG:tm:set_timer: relative timeout is 30
> Aug 25 17:19:05 [14748] DBG:tm:insert_timer_unsafe: [0]: 0x7fb34b91d2b8
> (405)
> Aug 25 17:19:05 [14748] DBG:dialog:send_leg_bye: BYE sent to caller
> Aug 25 17:19:05 [14748] DBG:dialog:send_leg_bye: sending BYE to callee (1)
> Aug 25 17:19:05 [14748] DBG:dialog:ref_dlg: ref dlg 0x7fb34b920e88 with 1 ->
> 4
> Aug 25 17:19:05 [14748] DBG:tm:t_uac: next_hop=<sip:1510495 at 64.74.140.57>
> Aug 25 17:19:05 [14748] DBG:core:mk_proxy: doing DNS lookup...
> Aug 25 17:19:05 [14748] DBG:tm:dlg2hash: 38254
> Aug 25 17:19:05 [14748] DBG:tm:print_request_uri: sip:1510495 at 64.74.140.57
> Aug 25 17:19:05 [14748] DBG:tm:set_timer: relative timeout is 500000
> Aug 25 17:19:05 [14748] DBG:tm:insert_timer_unsafe: [4]: 0x7fb34b921b58
> (375500000)
> Aug 25 17:19:05 [14748] DBG:tm:set_timer: relative timeout is 30
> Aug 25 17:19:05 [14748] DBG:tm:insert_timer_unsafe: [0]: 0x7fb34b921b88
> (405)
> Aug 25 17:19:05 [14748] DBG:dialog:send_leg_bye: BYE sent to callee
> Aug 25 17:19:05 [14748] DBG:dialog:unref_dlg: unref dlg 0x7fb34b920e88 with
> 1 -> 3
> Aug 25 17:19:05 [14746] DBG:core:parse_msg: SIP Reply  (status):
> Aug 25 17:19:05 [14746] DBG:core:parse_msg:  version: <SIP/2.0>
> Aug 25 17:19:05 [14746] DBG:core:parse_msg:  status:  <200>
> Aug 25 17:19:05 [14746] DBG:core:parse_msg:  reason:  <OK>
> Aug 25 17:19:05 [14746] DBG:core:parse_headers: flags=2
> Aug 25 17:19:05 [14746] DBG:core:parse_via_param: found param type 232,
> <branch> = <z9hG4bKe659.8c40efb6.0>; state=6
> Aug 25 17:19:05 [14746] DBG:core:parse_via_param: found param type 234,
> <received> = <74.x.x.x.x>; state=16
> Aug 25 17:19:05 [14746] DBG:core:parse_via: end of header reached, state=5
> Aug 25 17:19:05 [14746] DBG:core:parse_headers: via found, flags=2
> Aug 25 17:19:05 [14746] DBG:core:parse_headers: this is the first via
> Aug 25 17:19:05 [14746] DBG:core:receive_msg: After parse_msg...
> Aug 25 17:19:05 [14746] DBG:core:grep_sock_info: checking if host==us:
> 13==13 &&  [74.x.x.x.x] == [74.x.x.x.x]
> Aug 25 17:19:05 [14746] DBG:core:grep_sock_info: checking if port 5060
> matches port 5060
> Aug 25 17:19:05 [14746] DBG:core:forward_reply: found module tm, passing
> reply to it
> Aug 25 17:19:05 [14746] DBG:tm:t_check: start=0xffffffffffffffff
> Aug 25 17:19:05 [14746] DBG:core:parse_headers: flags=22
> Aug 25 17:19:05 [14746] DBG:core:parse_to_param: tag=as3154366e
> Aug 25 17:19:05 [14746] DBG:core:parse_to: end of header reached, state=29
> Aug 25 17:19:05 [14746] DBG:core:parse_to: display={},
> ruri={sip:1510495 at 74.x.x.x.x}
> Aug 25 17:19:05 [14746] DBG:core:get_hdr_field: <To> [48];
> uri=[sip:1510495 at 74.x.x.x.x]
> Aug 25 17:19:05 [14746] DBG:core:get_hdr_field: to body
> [<sip:1510495 at 74.x.x.x.x>]
> Aug 25 17:19:05 [14746] DBG:core:get_hdr_field: cseq <CSeq>: <3> <BYE>
> Aug 25 17:19:05 [14746] DBG:tm:t_reply_matching: hash 38254 label 1811809480
> branch 0
> Aug 25 17:19:05 [14746] DBG:tm:t_reply_matching: REF_UNSAFE: after is 1
> Aug 25 17:19:05 [14746] DBG:tm:t_reply_matching: reply matched
> (T=0x7fb34b921938)!
> Aug 25 17:19:05 [14746] DBG:tm:t_check: end=0x7fb34b921938
> Aug 25 17:19:05 [14746] DBG:tm:reply_received: org. status uas=0, uac[0]=0
> local=2 is_invite=0)
> Aug 25 17:19:05 [14746] DBG:tm:t_should_relay_response: T_code=0,
> new_code=200
> Aug 25 17:19:05 [14746] DBG:tm:local_reply: branch=0, save=0, winner=0
> Aug 25 17:19:05 [14746] DBG:tm:local_reply: local transaction completed
> Aug 25 17:19:05 [14746] DBG:tm:run_trans_callbacks: trans=0x7fb34b921938,
> callback type 512, id 0 entered
> Aug 25 17:19:05 [14746] DBG:dialog:bye_reply_cb: receiving a final reply 200
> Aug 25 17:19:05 [14746] DBG:dialog:next_state_dlg: dialog 0x7fb34b920e88
> changed from state 4 to state 5, due event 7
> Aug 25 17:19:05 [14746] DBG:dialog:dual_bye_event: removing dialog with
> h_entry 1337 and h_id 159371113
> Aug 25 17:19:05 [14746] DBG:dialog:dual_bye_event: dlg already expired (not
> in timer list) 0x7fb34b920e88 [1337:159371113] with clid
> 'OThhNWNjOWNjZWFmZDkwMmFlNTExYmVmNTM1ZTE2NjM.' and tags '5145635c'
> 'as3154366e'
> Aug 25 17:19:05 [14746] DBG:dialog:run_dlg_callbacks: dialog=0x7fb34b920e88,
> type=32
> Aug 25 17:19:05 [14746] DBG:dialog:run_dlg_callbacks: dialog=0x7fb34b920e88,
> type=32
> Aug 25 17:19:05 [14746] DBG:sst:sst_dialog_terminate_CB: Terminating DID
> 0x7fb34b920e88 session
> Aug 25 17:19:05 [14746] DBG:sst:sst_dialog_terminate_CB: freeing the
> sst_info_t from dialog 0x7fb34b920e88
> Aug 25 17:19:05 [14746] DBG:dialog:dual_bye_event: first final reply
> Aug 25 17:19:05 [14746] DBG:dialog:unref_dlg: unref dlg 0x7fb34b920e88 with
> 2 -> 1
> Aug 25 17:19:05 [14746] DBG:tm:cleanup_uac_timers: RETR/FR timers reset
> Aug 25 17:19:05 [14746] DBG:tm:insert_timer_unsafe: [2]: 0x7fb34b9219b8
> (380)
> Aug 25 17:19:05 [14746] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
> Aug 25 17:19:05 [14746] DBG:core:destroy_avp_list: destroying list (nil)
> Aug 25 17:19:05 [14746] DBG:core:receive_msg: cleaning up
> Aug 25 17:19:05 [14746] DBG:core:parse_msg: SIP Reply  (status):
> Aug 25 17:19:05 [14746] DBG:core:parse_msg:  version: <SIP/2.0>
> Aug 25 17:19:05 [14746] DBG:core:parse_msg:  status:  <200>
> Aug 25 17:19:05 [14746] DBG:core:parse_msg:  reason:  <OK>
> Aug 25 17:19:05 [14746] DBG:core:parse_headers: flags=2
> Aug 25 17:19:05 [14746] DBG:core:parse_via_param: found param type 232,
> <branch> = <z9hG4bKe659.7c40efb6.0>; state=16
> Aug 25 17:19:05 [14746] DBG:core:parse_via: end of header reached, state=5
> Aug 25 17:19:05 [14746] DBG:core:parse_headers: via found, flags=2
> Aug 25 17:19:05 [14746] DBG:core:parse_headers: this is the first via
> Aug 25 17:19:05 [14746] DBG:core:receive_msg: After parse_msg...
> Aug 25 17:19:05 [14746] DBG:core:grep_sock_info: checking if host==us:
> 13==13 &&  [74.x.x.x.x] == [74.x.x.x.x]
> Aug 25 17:19:05 [14746] DBG:core:grep_sock_info: checking if port 5060
> matches port 5060
> Aug 25 17:19:05 [14746] DBG:core:forward_reply: found module tm, passing
> reply to it
> Aug 25 17:19:05 [14746] DBG:tm:t_check: start=0xffffffffffffffff
> Aug 25 17:19:05 [14746] DBG:core:parse_headers: flags=22
> Aug 25 17:19:05 [14746] DBG:core:parse_to_param: tag=5145635c
> Aug 25 17:19:05 [14746] DBG:core:parse_to: end of header reached, state=29
> Aug 25 17:19:05 [14746] DBG:core:parse_to: display={},
> ruri={sip:1111 at 74.x.x.x.x}
> Aug 25 17:19:05 [14746] DBG:core:get_hdr_field: <To> [39];
> uri=[sip:1111 at 74.x.x.x.x]
> Aug 25 17:19:05 [14746] DBG:core:get_hdr_field: to body
> [<sip:1111 at 74.x.x.x.x>]
> Aug 25 17:19:05 [14746] DBG:core:get_hdr_field: cseq <CSeq>: <3> <BYE>
> Aug 25 17:19:05 [14746] DBG:tm:t_reply_matching: hash 38254 label 1811809479
> branch 0
> Aug 25 17:19:05 [14746] DBG:tm:t_reply_matching: REF_UNSAFE: after is 1
> Aug 25 17:19:05 [14746] DBG:tm:t_reply_matching: reply matched
> (T=0x7fb34b91d068)!
> Aug 25 17:19:05 [14746] DBG:tm:t_check: end=0x7fb34b91d068
> Aug 25 17:19:05 [14746] DBG:tm:reply_received: org. status uas=0, uac[0]=0
> local=2 is_invite=0)
> Aug 25 17:19:05 [14746] DBG:tm:t_should_relay_response: T_code=0,
> new_code=200
> Aug 25 17:19:05 [14746] DBG:tm:local_reply: branch=0, save=0, winner=0
> Aug 25 17:19:05 [14746] DBG:tm:local_reply: local transaction completed
> Aug 25 17:19:05 [14746] DBG:tm:run_trans_callbacks: trans=0x7fb34b91d068,
> callback type 512, id 0 entered
> Aug 25 17:19:05 [14746] DBG:dialog:bye_reply_cb: receiving a final reply 200
> Aug 25 17:19:05 [14746] DBG:dialog:next_state_dlg: dialog 0x7fb34b920e88
> changed from state 5 to state 5, due event 7
> Aug 25 17:19:05 [14746] DBG:dialog:dual_bye_event: second final reply
> Aug 25 17:19:05 [14746] DBG:dialog:remove_dialog_from_db: trying to remove a
> dialog, update_flag is 28
> Aug 25 17:19:05 [14746] DBG:db_mysql:has_stmt_ctx: ctx found for dialog
> Aug 25 17:19:05 [14746] DBG:db_mysql:db_mysql_do_prepared_query:
> conn=0x7cc640 (tail=8166584) MC=0x7c9d18
> Aug 25 17:19:05 [14746] DBG:db_mysql:db_mysql_do_prepared_query: set values
> for the statement run
> Aug 25 17:19:05 [14746] DBG:db_mysql:db_mysql_val2bind: added val (0):
> len=4; type=3; is_null=0
> Aug 25 17:19:05 [14746] DBG:db_mysql:db_mysql_val2bind: added val (1):
> len=4; type=3; is_null=0
> Aug 25 17:19:05 [14746] DBG:db_mysql:db_mysql_do_prepared_query: doing
> BIND_PARAM in...
> Aug 25 17:19:05 [14746] DBG:dialog:remove_dialog_from_db: callid was
> OThhNWNjOWNjZWFmZDkwMmFlNTExYmVmNTM1ZTE2NjM.
> Aug 25 17:19:05 [14746] DBG:dialog:unref_dlg: unref dlg 0x7fb34b920e88 with
> 1 -> 0
> Aug 25 17:19:05 [14746] DBG:dialog:unref_dlg: ref <=0 for dialog
> 0x7fb34b920e88
> Aug 25 17:19:05 [14746] DBG:dialog:destroy_dlg: destroing dialog
> 0x7fb34b920e88
> Aug 25 17:19:05 [14746] DBG:dialog:destroy_dlg: dlg expired or not in list -
> dlg 0x7fb34b920e88 [1337:159371113] with clid
> 'OThhNWNjOWNjZWFmZDkwMmFlNTExYmVmNTM1ZTE2NjM.' and tags '5145635c'
> 'as3154366e'
> Aug 25 17:19:05 [14746] DBG:dialog:run_dlg_callbacks: dialog=0x7fb34b920e88,
> type=2048
> Aug 25 17:19:05 [14746] DBG:tm:cleanup_uac_timers: RETR/FR timers reset
> Aug 25 17:19:05 [14746] DBG:tm:insert_timer_unsafe: [2]: 0x7fb34b91d0e8
> (380)
> Aug 25 17:19:05 [14746] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
> Aug 25 17:19:05 [14746] DBG:core:destroy_avp_list: destroying list (nil)
> Aug 25 17:19:05 [14746] DBG:core:receive_msg: cleaning up
> Aug 25 17:19:05 [14748] DBG:tm:utimer_routine: timer
> routine:4,tl=0x7fb34b91d288 next=0x7fb34b921b58, timeout=375500000
> Aug 25 17:19:05 [14748] DBG:tm:utimer_routine: timer
> routine:4,tl=0x7fb34b921b58 next=(nil), timeout=375500000
> Aug 25 17:19:10 [14748] DBG:tm:timer_routine: timer
> routine:2,tl=0x7fb34b9219b8 next=0x7fb34b91d0e8, timeout=380
> Aug 25 17:19:10 [14748] DBG:tm:wait_handler: removing 0x7fb34b921938 from
> table
> Aug 25 17:19:10 [14748] DBG:tm:delete_cell: delete transaction
> 0x7fb34b921938
> Aug 25 17:19:10 [14748] DBG:tm:wait_handler: done
> Aug 25 17:19:10 [14748] DBG:tm:timer_routine: timer
> routine:2,tl=0x7fb34b91d0e8 next=(nil), timeout=380
> Aug 25 17:19:10 [14748] DBG:tm:wait_handler: removing 0x7fb34b91d068 from
> table
> Aug 25 17:19:10 [14748] DBG:tm:delete_cell: delete transaction
> 0x7fb34b91d068
> Aug 25 17:19:10 [14748] DBG:tm:wait_handler: done
>
>
>   

-- 
Bogdan-Andrei Iancu
OpenSIPS Bootcamp
20 - 24 September 2010, Frankfurt, Germany
www.voice-system.ro