Sorry, something wrong with the log file.
Resend...

-----Original Message-----
From: Bogdan-Andrei Iancu [mailto:[EMAIL PROTECTED] 
Sent: 2008年3月25日 19:59
To: Bai Shi
Cc: Andreas Granig; Thomas Gelf; [EMAIL PROTECTED]
Subject: Re: [OpenSER-Users] uac_replace_from and CANCEL

Hi Bai Shi,

Andreas also confirmed to work properly (when not used from branch 
route), so it is not a bug, but maybe some cfg/scenario error.

Try placing the call (only the test one) and grab the full debug log 
from openser - post it somewhere and I will take a look.

Regards,
Bogdan

Bai Shi wrote:
> Hi Andreas,
> I called without any branches.
>
> Bogdan, I'd appreciate if you can spare sometime to look at this again.
> Rgds,
> Bai Shi
>
> -----Original Message-----
> From: Andreas Granig [mailto:[EMAIL PROTECTED] 
> Sent: 2008年3月20日 1:34
> To: Bogdan-Andrei Iancu
> Cc: Bai Shi; Thomas Gelf; [EMAIL PROTECTED]
> Subject: Re: [OpenSER-Users] uac_replace_from and CANCEL
>
> Or, to be more specific, I call it from a route which is called by a 
> branch_route. Not sure if that matters.
>
> Andreas
>
> Andreas Granig wrote:
>   
>> Bogdan,
>>
>> I just tested with 1.3.1, and there the From of the CANCEL is also NOT 
>> updated. A probably not so unimportant side-note is that I call 
>> uac_replace_from() from a branch_route.
>>
>> Andreas
>>
>> Bogdan-Andrei Iancu wrote:
>>     
>>> Hi Bai Shi,
>>>
>>> I just tested (to be sure no bugs are present) and in 1.3, the CANCELs 
>>> are automatically updated (the FROM header), as expected.
>>>
>>> Regards,
>>> Bogdan
>>>
>>> Bai Shi wrote:
>>>       
>>>> Hi, Thomas,
>>>> This will do in openser 1.2, however, in openser 1.3 it won't do any 
>>>> help. The CANCEL will be sent out regardless what you have done to 
>>>> the request, but follow the information in the original INVITE. I 
>>>> tested it and suffered a lot ;(
>>>> Rgds,
>>>> BS
>>>>
>>>> -----Original Message-----
>>>> From: [EMAIL PROTECTED] 
>>>> [mailto:[EMAIL PROTECTED] On Behalf Of Andreas Granig
>>>> Sent: 2008年3月13日 2:54
>>>> To: Thomas Gelf
>>>> Cc: [EMAIL PROTECTED]
>>>> Subject: Re: [OpenSER-Users] uac_replace_from and CANCEL
>>>>
>>>> Hi Thomas,
>>>>
>>>> Yes, I'm doing it that way now (without that "append_branch()" 
>>>> though), but if you have an uuid-based setup where you fetch the uuid 
>>>> from the subscriber table during authentication of the INVITE and 
>>>> then with that uuid fetch dynamic data from the usr_preferences table 
>>>> to be used for "uac_rewrite_host()", then you have to do some 
>>>> work-arounds and hacks to get that data for the CANCEL as well, which 
>>>> could be quite a pain.
>>>>
>>>> So yes, it would be really great if this could be done automatically 
>>>> *hint hint* :)
>>>>
>>>> Andreas
>>>>
>>>> Thomas Gelf wrote:
>>>>  
>>>>         
>>>>> Applying uac_replace_from() to the CANCEL request should do the job,
>>>>> it sadly doesn't happen automagically :'-(
>>>>>
>>>>> Try something like:
>>>>>
>>>>>      if(is_method("CANCEL") && uri =~ "^sip:...")
>>>>>      {
>>>>>          if(t_check_trans())
>>>>>          {
>>>>>              rewritehostport("...");
>>>>>              uac_replace_from("...");
>>>>>              append_branch();
>>>>>          }
>>>>>          if(!t_relay())
>>>>>          {
>>>>>              sl_reply_error();
>>>>>          }
>>>>>      }
>>>>>
>>>>> Cheers,
>>>>> Thomas Gelf
>>>>>
>>>>> Andreas Granig schrieb:
>>>>>   
>>>>>           
>>>>>> Hi,
>>>>>>
>>>>>> I hit another problem with a Cisco PGW in combination with CANCEL, 
>>>>>> and I'm not sure which fault it is. If I do uac_replace_from in the 
>>>>>> INVITE, the From-Header is altered somehow and sent to the PGW. So 
>>>>>> if A calls B where B is a PGW, the From from A to OpenSER is for 
>>>>>> example sip:[EMAIL PROTECTED] and from OpenSER to B it's 
>>>>>> sip:[EMAIL PROTECTED]
>>>>>>
>>>>>> If the call is cancelled, the From-header isn't altered, so the 
>>>>>> From from A to OpenSER is sip:[EMAIL PROTECTED] and from OpenSER to B 
>>>>>> it's sip:[EMAIL PROTECTED] as well.
>>>>>>
>>>>>> Now the PGW seems to ignore this CANCEL, and I guess it's because 
>>>>>> of the different From-usernames, since it works if I don't do any 
>>>>>> uac_replace_from.
>>>>>>
>>>>>> RFC3261 says in §9.1:
>>>>>> The Request-URI, Call-ID, To, the numeric part of CSeq, and From 
>>>>>> header
>>>>>> fields in the CANCEL request MUST be identical to those in the
>>>>>> request being cancelled, including tags.
>>>>>>
>>>>>> So is it correct behavior of the PGW because the From header in the 
>>>>>> CANCEL is different from the From header in the INVITE? Should 
>>>>>> OpenSER alter the From in the CANCEL as well? Or should the PGW 
>>>>>> just check the  From tags, but not the From URI?
>>>>>>
>>>>>> Andreas
>>>>>>
>>>>>>       
>>>>>>             
>>>>> _______________________________________________
>>>>> Users mailing list
>>>>> Users@lists.openser.org
>>>>> http://lists.openser.org/cgi-bin/mailman/listinfo/users
>>>>>     
>>>>>           
>>>> _______________________________________________
>>>> Users mailing list
>>>> Users@lists.openser.org
>>>> http://lists.openser.org/cgi-bin/mailman/listinfo/users
>>>>
>>>> _______________________________________________
>>>> Users mailing list
>>>> Users@lists.openser.org
>>>> http://lists.openser.org/cgi-bin/mailman/listinfo/users
>>>>   
>>>>         

Mar 25 21:42:20 [4001] DBG:core:parse_msg: SIP Request:
Mar 25 21:42:20 [4001] DBG:core:parse_msg:  method:  <INVITE>
Mar 25 21:42:20 [4001] DBG:core:parse_msg:  uri:     <sip:[EMAIL 
PROTECTED]:5070>
Mar 25 21:42:20 [4001] DBG:core:parse_msg:  version: <SIP/2.0>
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=2
Mar 25 21:42:20 [4001] DBG:core:parse_via_param: found param type 232, <branch> 
= <z9hG4bK-d87543-912ace5f9f7da033-1--d87543->; state=6
Mar 25 21:42:20 [4001] DBG:core:parse_via_param: found param type 235, <rport> 
= <n/a>; state=17
Mar 25 21:42:20 [4001] DBG:core:parse_via: end of header reached, state=5
Mar 25 21:42:20 [4001] DBG:core:parse_headers: via found, flags=2
Mar 25 21:42:20 [4001] DBG:core:parse_headers: this is the first via
Mar 25 21:42:20 [4001] DBG:core:receive_msg: After parse_msg...
Mar 25 21:42:20 [4001] DBG:core:receive_msg: preparing to run routing scripts...
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=100
Mar 25 21:42:20 [4001] DBG:maxfwd:is_maxfwd_present: value = 70
Method: INVITE
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=10
Mar 25 21:42:20 [4001] DBG:core:parse_to: end of header reached, state=10
Mar 25 21:42:20 [4001] DBG:core:parse_to: display={"85285523133"}, 
ruri={sip:[EMAIL PROTECTED]:5070}
Mar 25 21:42:20 [4001] DBG:core:get_hdr_field: <To> [50]; uri=[sip:[EMAIL 
PROTECTED]:5070]
Mar 25 21:42:20 [4001] DBG:core:get_hdr_field: to body 
["85285523133"<sip:[EMAIL PROTECTED]:5070>
]
Mar 25 21:42:20 [4001] DBG:core:parse_to_param: tag=ea0e5c79
Mar 25 21:42:20 [4001] DBG:core:parse_to: end of header reached, state=29
Mar 25 21:42:20 [4001] DBG:core:parse_to: display={"laobai"}, ruri={sip:[EMAIL 
PROTECTED]:5070}
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=200
Mar 25 21:42:20 [4001] DBG:core:get_hdr_field: cseq <CSeq>: <1> <INVITE>
Mar 25 21:42:20 [4001] DBG:core:get_hdr_field: content_length=375
Mar 25 21:42:20 [4001] DBG:core:get_hdr_field: found end of header
Mar 25 21:42:20 [4001] DBG:rr:find_first_route: No Route headers found
Mar 25 21:42:20 [4001] DBG:rr:loose_route: There is no Route HF
Mar 25 21:42:20 [4001] DBG:core:grep_sock_info: checking if host==us: 14==9 &&  
[172.19.172.101] == [127.0.0.1]
Mar 25 21:42:20 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:20 [4001] DBG:core:grep_sock_info: checking if host==us: 14==14 && 
 [172.19.172.101] == [172.19.172.101]
Mar 25 21:42:20 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:20 [4001] DBG:registrar:lookup: '85285523133' Not found in usrloc
Mar 25 21:42:20 [4001] DBG:core:grep_sock_info: checking if host==us: 14==9 &&  
[172.19.172.101] == [127.0.0.1]
Mar 25 21:42:20 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:20 [4001] DBG:core:grep_sock_info: checking if host==us: 14==14 && 
 [172.19.172.101] == [172.19.172.101]
Mar 25 21:42:20 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:20 [4001] DBG:core:grep_sock_info: checking if host==us: 14==9 &&  
[172.19.172.101] == [127.0.0.1]
Mar 25 21:42:20 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:20 [4001] DBG:core:grep_sock_info: checking if host==us: 14==14 && 
 [172.19.172.101] == [172.19.172.101]
Mar 25 21:42:20 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 25 21:42:20 [4001] DBG:core:run_transformations: return val is 0
Mar 25 21:42:20 [4001] DBG:avpops:ops_op_avp:  use <31> and <2>
Mar 25 21:42:20 [4001] DBG:avpops:ops_op_avp: done
tr_eval_string: i=1 j=29
Mar 25 21:42:20 [4001] DBG:core:run_transformations: return val is 0
Mar 25 21:42:20 [4001] DBG:core:run_transformations: return val is 0
requested for cli: INVITE
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=78
Mar 25 21:42:20 [4001] DBG:core:MDStringArray: MD5 calculated: 
12af839a9443c647d481ebab12698a05
Mar 25 21:42:20 [4001] DBG:exec:print_hf_var: SIP_HF_CONTENT_LENGTH=375
Mar 25 21:42:20 [4001] DBG:exec:print_hf_var: SIP_HF_USER_AGENT=eyeBeam release 
1003s stamp 31159
Mar 25 21:42:20 [4001] DBG:exec:print_hf_var: 
SIP_HF_CONTENT_TYPE=application/sdp
Mar 25 21:42:20 [4001] DBG:exec:print_hf_var: SIP_HF_ALLOW=INVITE, ACK, CANCEL, 
OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
Mar 25 21:42:20 [4001] DBG:exec:print_hf_var: SIP_HF_CSEQ=1 INVITE
Mar 25 21:42:20 [4001] DBG:exec:print_hf_var: 
SIP_HF_CALLID=e408742adf675949YmQxNjQ4NDA1OTU1ZDgwYjg0ZTNmYjEzNjY2NWU5MGY.
Mar 25 21:42:20 [4001] DBG:exec:print_hf_var: SIP_HF_FROM="laobai"<sip:[EMAIL 
PROTECTED]:5070>;tag=ea0e5c79
Mar 25 21:42:20 [4001] DBG:exec:print_hf_var: 
SIP_HF_TO="85285523133"<sip:[EMAIL PROTECTED]:5070>
Mar 25 21:42:20 [4001] DBG:exec:print_hf_var: SIP_HF_CONTACT=<sip:[EMAIL 
PROTECTED]:42566>
Mar 25 21:42:20 [4001] DBG:exec:print_hf_var: SIP_HF_MAX_FORWARDS=69
Mar 25 21:42:20 [4001] DBG:exec:print_hf_var: SIP_HF_VIA=SIP/2.0/UDP 
172.19.172.176:42566;branch=z9hG4bK-d87543-912ace5f9f7da033-1--d87543-;rport
Mar 25 21:42:20 [4001] DBG:exec:w_exec_avp: executing 
[/home/baishi/proj/teliwave/cli/twcli '172.19.172.176' 
'e408742adf675949YmQxNjQ4NDA1OTU1ZDgwYjg0ZTNmYjEzNjY2NWU5MGY.']
Mar 25 21:42:20 [4001] DBG:core:sig_usr: SIGCHLD received: we do not worry 
about grand-children
172.19.172.176 e408742adf675949YmQxNjQ4NDA1OTU1ZDgwYjg0ZTNmYjEzNjY2NWU5MGY. 
172.19.172.101
newcli: 852133143235
Mar 25 21:42:20 [4001] DBG:core:run_transformations: return val is 0
Mar 25 21:42:20 [4001] DBG:uac:replace_from: removing display ["laobai"]
Mar 25 21:42:20 [4001] DBG:uac:replace_from: uri to replace [sip:[EMAIL 
PROTECTED]:5070]
Mar 25 21:42:20 [4001] DBG:uac:replace_from: replacement uri is [sip:[EMAIL 
PROTECTED]:5070]
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 25 21:42:20 [4001] DBG:core:run_transformations: return val is 0
Mar 25 21:42:20 [4001] DBG:core:run_transformations: return val is 0
INVITE
route 1 reached
Mar 25 21:42:20 [4001] DBG:tm:t_newtran: transaction on entrance=0xffffffff
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=78
Mar 25 21:42:20 [4001] DBG:tm:t_lookup_request: start searching: hash=55692, 
isACK=0
Mar 25 21:42:20 [4001] DBG:tm:matching_3261: RFC3261 transaction matching failed
Mar 25 21:42:20 [4001] DBG:tm:t_lookup_request: no transaction found
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 25 21:42:20 [4001] DBG:core:check_via_address: params 172.19.172.176, 
172.19.172.176, 0
Mar 25 21:42:20 [4001] DBG:core:_shm_resize: resize(0) called
Mar 25 21:42:20 [4001] DBG:tm:_reply_light: reply sent out. buf=0x818a2f0: 
SIP/2.0 1..., shmem=0xb5e85a68: SIP/2.0 1
Mar 25 21:42:20 [4001] DBG:tm:_reply_light: finished
Mar 25 21:42:20 [4001] DBG:core:mk_proxy: doing DNS lookup...
Mar 25 21:42:20 [4001] DBG:core:check_via_address: params 172.19.172.176, 
172.19.172.176, 0
Mar 25 21:42:20 [4001] DBG:tm:set_timer: relative timeout is 500000
Mar 25 21:42:20 [4001] DBG:tm:insert_timer_unsafe: [4]: 0xb5e8355c (1126800000)
Mar 25 21:42:20 [4001] DBG:tm:set_timer: relative timeout is 30
Mar 25 21:42:20 [4001] DBG:tm:insert_timer_unsafe: [0]: 0xb5e83578 (1156)
Mar 25 21:42:20 [4001] DBG:tm:t_relay_to: new transaction fwd'ed
Mar 25 21:42:20 [4001] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Mar 25 21:42:20 [4001] DBG:core:destroy_avp_list: destroying list (nil)
Mar 25 21:42:20 [4001] DBG:core:receive_msg: cleaning up
Mar 25 21:42:20 [4001] DBG:core:parse_msg: SIP Reply  (status):
Mar 25 21:42:20 [4001] DBG:core:parse_msg:  version: <SIP/2.0>
Mar 25 21:42:20 [4001] DBG:core:parse_msg:  status:  <100>
Mar 25 21:42:20 [4001] DBG:core:parse_msg:  reason:  <Trying>
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=2
Mar 25 21:42:20 [4001] DBG:core:parse_via_param: found param type 232, <branch> 
= <z9hG4bKc89d.f721b532.0>; state=6
Mar 25 21:42:20 [4001] DBG:core:parse_via_param: found param type 234, 
<received> = <172.19.172.101>; state=16
Mar 25 21:42:20 [4001] DBG:core:parse_via: end of header reached, state=5
Mar 25 21:42:20 [4001] DBG:core:parse_headers: via found, flags=2
Mar 25 21:42:20 [4001] DBG:core:parse_headers: this is the first via
Mar 25 21:42:20 [4001] DBG:core:receive_msg: After parse_msg...
Mar 25 21:42:20 [4001] DBG:core:forward_reply: found module tm, passing reply 
to it
Mar 25 21:42:20 [4001] DBG:tm:t_check: start=0xffffffff
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=22
Mar 25 21:42:20 [4001] DBG:core:parse_via_param: found param type 232, <branch> 
= <z9hG4bK-d87543-912ace5f9f7da033-1--d87543->; state=6
Mar 25 21:42:20 [4001] DBG:core:parse_via_param: found param type 235, <rport> 
= <42566>; state=16
Mar 25 21:42:20 [4001] DBG:core:parse_via: end of header reached, state=5
Mar 25 21:42:20 [4001] DBG:core:parse_headers: via found, flags=22
Mar 25 21:42:20 [4001] DBG:core:parse_headers: parse_headers: this is the 
second via
Mar 25 21:42:20 [4001] DBG:core:parse_to: end of header reached, state=10
Mar 25 21:42:20 [4001] DBG:core:parse_to: display={"85285523133"}, 
ruri={sip:[EMAIL PROTECTED]:5070}
Mar 25 21:42:20 [4001] DBG:core:get_hdr_field: <To> [50]; uri=[sip:[EMAIL 
PROTECTED]:5070]
Mar 25 21:42:20 [4001] DBG:core:get_hdr_field: to body 
["85285523133"<sip:[EMAIL PROTECTED]:5070>
]
Mar 25 21:42:20 [4001] DBG:core:get_hdr_field: cseq <CSeq>: <1> <INVITE>
Mar 25 21:42:20 [4001] DBG:core:parse_headers: flags=8
Mar 25 21:42:20 [4001] DBG:tm:t_reply_matching: hash 55692 label 593171071 
branch 0
Mar 25 21:42:20 [4001] DBG:tm:t_reply_matching: REF_UNSAFE: after is 1
Mar 25 21:42:20 [4001] DBG:tm:t_reply_matching: reply matched (T=0xb5e83410)!
Mar 25 21:42:20 [4001] DBG:tm:t_check: end=0xb5e83410
Mar 25 21:42:20 [4001] DBG:tm:reply_received: org. status uas=100, uac[0]=0 
local=0 is_invite=1)
Mar 25 21:42:20 [4001] DBG:tm:t_check_status: checked status is <100>
Mar 25 21:42:20 [4001] DBG:tm:t_should_relay_response: T_code=100, new_code=100
Mar 25 21:42:20 [4001] DBG:tm:relay_reply: branch=0, save=0, relay=-1
Mar 25 21:42:20 [4001] DBG:tm:set_timer: relative timeout is 120
Mar 25 21:42:20 [4001] DBG:tm:insert_timer_unsafe: [1]: 0xb5e83578 (1246)
Mar 25 21:42:20 [4001] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Mar 25 21:42:20 [4001] DBG:core:destroy_avp_list: destroying list (nil)
Mar 25 21:42:20 [4001] DBG:core:receive_msg: cleaning up
Mar 25 21:42:21 [4001] DBG:core:parse_msg: SIP Reply  (status):
Mar 25 21:42:21 [4001] DBG:core:parse_msg:  version: <SIP/2.0>
Mar 25 21:42:21 [4001] DBG:core:parse_msg:  status:  <183>
Mar 25 21:42:21 [4001] DBG:core:parse_msg:  reason:  <Session Progress>
Mar 25 21:42:21 [4001] DBG:core:parse_headers: flags=2
Mar 25 21:42:21 [4001] DBG:core:parse_via_param: found param type 232, <branch> 
= <z9hG4bKc89d.f721b532.0>; state=6
Mar 25 21:42:21 [4001] DBG:core:parse_via_param: found param type 234, 
<received> = <172.19.172.101>; state=16
Mar 25 21:42:21 [4001] DBG:core:parse_via: end of header reached, state=5
Mar 25 21:42:21 [4001] DBG:core:parse_headers: via found, flags=2
Mar 25 21:42:21 [4001] DBG:core:parse_headers: this is the first via
Mar 25 21:42:21 [4001] DBG:core:receive_msg: After parse_msg...
Mar 25 21:42:21 [4001] DBG:core:forward_reply: found module tm, passing reply 
to it
Mar 25 21:42:21 [4001] DBG:tm:t_check: start=0xffffffff
Mar 25 21:42:21 [4001] DBG:core:parse_headers: flags=22
Mar 25 21:42:21 [4001] DBG:core:parse_via_param: found param type 232, <branch> 
= <z9hG4bK-d87543-912ace5f9f7da033-1--d87543->; state=6
Mar 25 21:42:21 [4001] DBG:core:parse_via_param: found param type 235, <rport> 
= <42566>; state=16
Mar 25 21:42:21 [4001] DBG:core:parse_via: end of header reached, state=5
Mar 25 21:42:21 [4001] DBG:core:parse_headers: via found, flags=22
Mar 25 21:42:21 [4001] DBG:core:parse_headers: parse_headers: this is the 
second via
Mar 25 21:42:21 [4001] DBG:core:parse_to_param: tag=as7903fabe
Mar 25 21:42:21 [4001] DBG:core:parse_to: end of header reached, state=29
Mar 25 21:42:21 [4001] DBG:core:parse_to: display={"85285523133"}, 
ruri={sip:[EMAIL PROTECTED]:5070}
Mar 25 21:42:21 [4001] DBG:core:get_hdr_field: <To> [65]; uri=[sip:[EMAIL 
PROTECTED]:5070]
Mar 25 21:42:21 [4001] DBG:core:get_hdr_field: to body 
["85285523133"<sip:[EMAIL PROTECTED]:5070>]
Mar 25 21:42:21 [4001] DBG:core:get_hdr_field: cseq <CSeq>: <1> <INVITE>
Mar 25 21:42:21 [4001] DBG:core:parse_headers: flags=8
Mar 25 21:42:21 [4001] DBG:tm:t_reply_matching: hash 55692 label 593171071 
branch 0
Mar 25 21:42:21 [4001] DBG:tm:t_reply_matching: REF_UNSAFE: after is 1
Mar 25 21:42:21 [4001] DBG:tm:t_reply_matching: reply matched (T=0xb5e83410)!
Mar 25 21:42:21 [4001] DBG:tm:t_check: end=0xb5e83410
Mar 25 21:42:21 [4001] DBG:tm:reply_received: org. status uas=100, uac[0]=100 
local=0 is_invite=1)
Mar 25 21:42:21 [4001] DBG:tm:t_check_status: checked status is <183>
Mar 25 21:42:21 [4001] DBG:tm:t_should_relay_response: T_code=100, new_code=183
Mar 25 21:42:21 [4001] DBG:tm:relay_reply: branch=0, save=0, relay=0
Mar 25 21:42:21 [4001] DBG:core:build_res_buf_from_sip_res:  old size: 1012, 
new size: 920
Mar 25 21:42:21 [4001] DBG:core:build_res_buf_from_sip_res: copied size: 
orig:122, new: 30, rest: 890 msg=
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 
172.19.172.176:42566;branch=z9hG4bK-d87543-912ace5f9f7da033-1--d87543-;rport=42566
Record-Route: <sip:172.19.172.101:5070;lr=on;ftag=ea0e5c79>
From: "852133143235"<sip:[EMAIL PROTECTED]:5070>;tag=ea0e5c79
To: "85285523133"<sip:[EMAIL PROTECTED]:5070>;tag=as7903fabe
Call-ID: e408742adf675949YmQxNjQ4NDA1OTU1ZDgwYjg0ZTNmYjEzNjY2NWU5MGY.
CSeq: 1 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:[EMAIL PROTECTED]>
Content-Type: application/sdp
Content-Length: 289

v=0
o=root 10059 10059 IN IP4 gatewayip
s=session
c=IN IP4 gatewayip
t=0 0
m=audio 14260 RTP/AVP 18 0 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

Mar 25 21:42:21 [4001] DBG:tm:relay_reply: sent buf=0x818a760: SIP/2.0 1..., 
shmem=0xb5e86af0: SIP/2.0 1
Mar 25 21:42:21 [4001] DBG:tm:set_timer: relative timeout is 120
Mar 25 21:42:21 [4001] DBG:tm:insert_timer_unsafe: [1]: 0xb5e83578 (1246)
Mar 25 21:42:21 [4001] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Mar 25 21:42:21 [4001] DBG:core:destroy_avp_list: destroying list (nil)
Mar 25 21:42:21 [4001] DBG:core:receive_msg: cleaning up
Mar 25 21:42:21 [4002] DBG:tm:utimer_routine: timer routine:4,tl=0xb5e8355c 
next=(nil), timeout=1126800000
Mar 25 21:42:23 [4001] DBG:core:parse_msg: SIP Request:
Mar 25 21:42:23 [4001] DBG:core:parse_msg:  method:  <CANCEL>
Mar 25 21:42:23 [4001] DBG:core:parse_msg:  uri:     <sip:[EMAIL 
PROTECTED]:5070>
Mar 25 21:42:23 [4001] DBG:core:parse_msg:  version: <SIP/2.0>
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=2
Mar 25 21:42:23 [4001] DBG:core:parse_via_param: found param type 232, <branch> 
= <z9hG4bK-d87543-912ace5f9f7da033-1--d87543->; state=6
Mar 25 21:42:23 [4001] DBG:core:parse_via_param: found param type 235, <rport> 
= <n/a>; state=17
Mar 25 21:42:23 [4001] DBG:core:parse_via: end of header reached, state=5
Mar 25 21:42:23 [4001] DBG:core:parse_headers: via found, flags=2
Mar 25 21:42:23 [4001] DBG:core:parse_headers: this is the first via
Mar 25 21:42:23 [4001] DBG:core:receive_msg: After parse_msg...
Mar 25 21:42:23 [4001] DBG:core:receive_msg: preparing to run routing scripts...
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=100
Mar 25 21:42:23 [4001] DBG:core:parse_to: end of header reached, state=10
Mar 25 21:42:23 [4001] DBG:core:parse_to: display={"85285523133"}, 
ruri={sip:[EMAIL PROTECTED]:5070}
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: <To> [50]; uri=[sip:[EMAIL 
PROTECTED]:5070]
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: to body 
["85285523133"<sip:[EMAIL PROTECTED]:5070>
]
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: cseq <CSeq>: <1> <CANCEL>
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: content_length=0
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: found end of header
Mar 25 21:42:23 [4001] DBG:maxfwd:is_maxfwd_present: max_forwards header not 
found!
Method: CANCEL
Mar 25 21:42:23 [4001] DBG:core:parse_to_param: tag=ea0e5c79
Mar 25 21:42:23 [4001] DBG:core:parse_to: end of header reached, state=29
Mar 25 21:42:23 [4001] DBG:core:parse_to: display={"laobai"}, ruri={sip:[EMAIL 
PROTECTED]:5070}
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=200
Mar 25 21:42:23 [4001] DBG:rr:find_first_route: No Route headers found
Mar 25 21:42:23 [4001] DBG:rr:loose_route: There is no Route HF
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if host==us: 14==9 &&  
[172.19.172.101] == [127.0.0.1]
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if host==us: 14==14 && 
 [172.19.172.101] == [172.19.172.101]
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:23 [4001] DBG:registrar:lookup: '85285523133' Not found in usrloc
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if host==us: 14==9 &&  
[172.19.172.101] == [127.0.0.1]
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if host==us: 14==14 && 
 [172.19.172.101] == [172.19.172.101]
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if host==us: 14==9 &&  
[172.19.172.101] == [127.0.0.1]
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if host==us: 14==14 && 
 [172.19.172.101] == [172.19.172.101]
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
NON-LOOSEROUTE CANCLE OR BYE
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=78
Mar 25 21:42:23 [4001] DBG:core:MDStringArray: MD5 calculated: 
12af839a9443c647d481ebab12698a05
Mar 25 21:42:23 [4001] DBG:exec:print_hf_var: SIP_HF_CONTENT_LENGTH=0
Mar 25 21:42:23 [4001] DBG:exec:print_hf_var: SIP_HF_USER_AGENT=eyeBeam release 
1003s stamp 31159
Mar 25 21:42:23 [4001] DBG:exec:print_hf_var: SIP_HF_CSEQ=1 CANCEL
Mar 25 21:42:23 [4001] DBG:exec:print_hf_var: 
SIP_HF_CALLID=e408742adf675949YmQxNjQ4NDA1OTU1ZDgwYjg0ZTNmYjEzNjY2NWU5MGY.
Mar 25 21:42:23 [4001] DBG:exec:print_hf_var: SIP_HF_FROM="laobai"<sip:[EMAIL 
PROTECTED]:5070>;tag=ea0e5c79
Mar 25 21:42:23 [4001] DBG:exec:print_hf_var: 
SIP_HF_TO="85285523133"<sip:[EMAIL PROTECTED]:5070>
Mar 25 21:42:23 [4001] DBG:exec:print_hf_var: SIP_HF_VIA=SIP/2.0/UDP 
172.19.172.176:42566;branch=z9hG4bK-d87543-912ace5f9f7da033-1--d87543-;rport
Mar 25 21:42:23 [4001] DBG:core:sig_usr: SIGCHLD received: we do not worry 
about grand-children
Mar 25 21:42:23 [4001] DBG:uac:replace_from: removing display ["laobai"]
Mar 25 21:42:23 [4001] DBG:uac:replace_from: uri to replace [sip:[EMAIL 
PROTECTED]:5070]
Mar 25 21:42:23 [4001] DBG:uac:replace_from: replacement uri is [sip:[EMAIL 
PROTECTED]
CLI: 852133143235
CANCEL
route 1 reached
Mar 25 21:42:23 [4001] DBG:tm:t_newtran: transaction on entrance=0xffffffff
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=78
Mar 25 21:42:23 [4001] DBG:tm:t_lookup_request: start searching: hash=55692, 
isACK=0
Mar 25 21:42:23 [4001] DBG:tm:matching_3261: RFC3261 transaction matching failed
Mar 25 21:42:23 [4001] DBG:tm:t_lookup_request: no transaction found
Mar 25 21:42:23 [4001] DBG:tm:t_lookupOriginalT: searching on hash entry 55692
Mar 25 21:42:23 [4001] DBG:tm:matching_3261: RFC3261 transaction matched, 
tid=-d87543-912ace5f9f7da033-1--d87543-
Mar 25 21:42:23 [4001] DBG:tm:t_lookupOriginalT: canceled transaction found 
(0xb5e83410)!
Mar 25 21:42:23 [4001] DBG:tm:t_lookupOriginalT: REF_UNSAFE: after is 1
Mar 25 21:42:23 [4001] DBG:tm:t_lookupOriginalT: t_lookupOriginalT completed
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=ffffffffffffffff
Mar 25 21:42:23 [4001] DBG:core:check_via_address: params 172.19.172.176, 
172.19.172.176, 0
Mar 25 21:42:23 [4001] DBG:core:_shm_resize: resize(0) called
Mar 25 21:42:23 [4001] DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Mar 25 21:42:23 [4001] DBG:tm:insert_timer_unsafe: [2]: 0xb5e85cf0 (1133)
Mar 25 21:42:23 [4001] DBG:tm:_reply_light: reply sent out. buf=0x818a2f0: 
SIP/2.0 2..., shmem=0xb5e876e8: SIP/2.0 2
Mar 25 21:42:23 [4001] DBG:tm:_reply_light: finished
Mar 25 21:42:23 [4001] DBG:tm:build_local: using FROM=<From: 
"laobai"<sip:[EMAIL PROTECTED]:5070>;tag=ea0e5c79
>, TO=<To: "85285523133"<sip:[EMAIL PROTECTED]:5070>
>, CSEQ_N=<CSeq: 1>
Mar 25 21:42:23 [4001] DBG:tm:cancel_branch: sending cancel...
Mar 25 21:42:23 [4001] DBG:tm:set_timer: relative timeout is 500000
Mar 25 21:42:23 [4001] DBG:tm:insert_timer_unsafe: [4]: 0xb5e835d8 (1129200000)
Mar 25 21:42:23 [4001] DBG:tm:set_timer: relative timeout is 30
Mar 25 21:42:23 [4001] DBG:tm:insert_timer_unsafe: [0]: 0xb5e835f4 (1158)
Mar 25 21:42:23 [4001] DBG:tm:t_relay_to: new transaction fwd'ed
Mar 25 21:42:23 [4001] DBG:tm:t_unref_cell: UNREF_UNSAFE: after is 0
Mar 25 21:42:23 [4001] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Mar 25 21:42:23 [4001] DBG:core:destroy_avp_list: destroying list (nil)
Mar 25 21:42:23 [4001] DBG:core:receive_msg: cleaning up
Mar 25 21:42:23 [4001] DBG:core:parse_msg: SIP Reply  (status):
Mar 25 21:42:23 [4001] DBG:core:parse_msg:  version: <SIP/2.0>
Mar 25 21:42:23 [4001] DBG:core:parse_msg:  status:  <487>
Mar 25 21:42:23 [4001] DBG:core:parse_msg:  reason:  <Request Terminated>
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=2
Mar 25 21:42:23 [4001] DBG:core:parse_via_param: found param type 232, <branch> 
= <z9hG4bKc89d.f721b532.0>; state=6
Mar 25 21:42:23 [4001] DBG:core:parse_via_param: found param type 234, 
<received> = <172.19.172.101>; state=16
Mar 25 21:42:23 [4001] DBG:core:parse_via: end of header reached, state=5
Mar 25 21:42:23 [4001] DBG:core:parse_headers: via found, flags=2
Mar 25 21:42:23 [4001] DBG:core:parse_headers: this is the first via
Mar 25 21:42:23 [4001] DBG:core:receive_msg: After parse_msg...
Mar 25 21:42:23 [4001] DBG:core:forward_reply: found module tm, passing reply 
to it
Mar 25 21:42:23 [4001] DBG:tm:t_check: start=0xffffffff
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=22
Mar 25 21:42:23 [4001] DBG:core:parse_via_param: found param type 232, <branch> 
= <z9hG4bK-d87543-912ace5f9f7da033-1--d87543->; state=6
Mar 25 21:42:23 [4001] DBG:core:parse_via_param: found param type 235, <rport> 
= <42566>; state=16
Mar 25 21:42:23 [4001] DBG:core:parse_via: end of header reached, state=5
Mar 25 21:42:23 [4001] DBG:core:parse_headers: via found, flags=22
Mar 25 21:42:23 [4001] DBG:core:parse_headers: parse_headers: this is the 
second via
Mar 25 21:42:23 [4001] DBG:core:parse_to_param: tag=as7903fabe
Mar 25 21:42:23 [4001] DBG:core:parse_to: end of header reached, state=29
Mar 25 21:42:23 [4001] DBG:core:parse_to: display={"85285523133"}, 
ruri={sip:[EMAIL PROTECTED]:5070}
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: <To> [65]; uri=[sip:[EMAIL 
PROTECTED]:5070]
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: to body 
["85285523133"<sip:[EMAIL PROTECTED]:5070>]
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: cseq <CSeq>: <1> <INVITE>
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=8
Mar 25 21:42:23 [4001] DBG:tm:t_reply_matching: hash 55692 label 593171071 
branch 0
Mar 25 21:42:23 [4001] DBG:tm:t_reply_matching: REF_UNSAFE: after is 1
Mar 25 21:42:23 [4001] DBG:tm:t_reply_matching: reply matched (T=0xb5e83410)!
Mar 25 21:42:23 [4001] DBG:tm:t_check: end=0xb5e83410
Mar 25 21:42:23 [4001] DBG:tm:reply_received: org. status uas=183, uac[0]=183 
local=0 is_invite=1)
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=8
Mar 25 21:42:23 [4001] DBG:tm:build_local: using FROM=<From: 
"laobai"<sip:[EMAIL PROTECTED]:5070>;tag=ea0e5c79
>, TO=<To: "85285523133"<sip:[EMAIL PROTECTED]:5070>;tag=as7903fabe
>, CSEQ_N=<CSeq: 1>
Mar 25 21:42:23 [4001] DBG:tm:t_check_status: checked status is <487>
487 received
Mar 25 21:42:23 [4001] DBG:tm:t_should_relay_response: T_code=183, new_code=487
Mar 25 21:42:23 [4001] DBG:tm:t_pick_branch: picked branch 0, code 487
Mar 25 21:42:23 [4001] DBG:tm:is_3263_failure: dns-failover test: branch=0, 
last_recv=487, flags=2
Mar 25 21:42:23 [4001] DBG:tm:t_check_status: checked status is <487>
Mar 25 21:42:23 [4001] DBG:tm:relay_reply: branch=0, save=0, relay=0
Mar 25 21:42:23 [4001] DBG:core:build_res_buf_from_sip_res:  old size: 590, new 
size: 498
Mar 25 21:42:23 [4001] DBG:core:build_res_buf_from_sip_res: copied size: 
orig:124, new: 32, rest: 466 msg=
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 
172.19.172.176:42566;branch=z9hG4bK-d87543-912ace5f9f7da033-1--d87543-;rport=42566
From: "852133143235"<sip:[EMAIL PROTECTED]:5070>;tag=ea0e5c79
To: "85285523133"<sip:[EMAIL PROTECTED]:5070>;tag=as7903fabe
Call-ID: e408742adf675949YmQxNjQ4NDA1OTU1ZDgwYjg0ZTNmYjEzNjY2NWU5MGY.
CSeq: 1 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0


Mar 25 21:42:23 [4001] DBG:tm:set_timer: relative timeout is 500000
Mar 25 21:42:23 [4001] DBG:tm:insert_timer_unsafe: [4]: 0xb5e834d8 (1129200000)
Mar 25 21:42:23 [4001] DBG:tm:set_timer: relative timeout is 30
Mar 25 21:42:23 [4001] DBG:tm:insert_timer_unsafe: [0]: 0xb5e834f4 (1158)
Mar 25 21:42:23 [4001] DBG:tm:relay_reply: sent buf=0x818a4a8: SIP/2.0 4..., 
shmem=0xb5e851a0: SIP/2.0 4
Mar 25 21:42:23 [4001] DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Mar 25 21:42:23 [4001] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Mar 25 21:42:23 [4001] DBG:core:destroy_avp_list: destroying list (nil)
Mar 25 21:42:23 [4001] DBG:core:receive_msg: cleaning up
Mar 25 21:42:23 [4001] DBG:core:parse_msg: SIP Request:
Mar 25 21:42:23 [4001] DBG:core:parse_msg:  method:  <ACK>
Mar 25 21:42:23 [4001] DBG:core:parse_msg:  uri:     <sip:[EMAIL 
PROTECTED]:5070>
Mar 25 21:42:23 [4001] DBG:core:parse_msg:  version: <SIP/2.0>
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=2
Mar 25 21:42:23 [4001] DBG:core:parse_via_param: found param type 232, <branch> 
= <z9hG4bK-d87543-912ace5f9f7da033-1--d87543->; state=6
Mar 25 21:42:23 [4001] DBG:core:parse_via_param: found param type 235, <rport> 
= <n/a>; state=17
Mar 25 21:42:23 [4001] DBG:core:parse_via: end of header reached, state=5
Mar 25 21:42:23 [4001] DBG:core:parse_headers: via found, flags=2
Mar 25 21:42:23 [4001] DBG:core:parse_headers: this is the first via
Mar 25 21:42:23 [4001] DBG:core:receive_msg: After parse_msg...
Mar 25 21:42:23 [4001] DBG:core:receive_msg: preparing to run routing scripts...
Mar 25 21:42:23 [4001] DBG:sl:sl_filter_ACK: to late to be a local ACK!
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=100
Mar 25 21:42:23 [4001] DBG:core:parse_to_param: tag=as7903fabe
Mar 25 21:42:23 [4001] DBG:core:parse_to: end of header reached, state=29
Mar 25 21:42:23 [4001] DBG:core:parse_to: display={"85285523133"}, 
ruri={sip:[EMAIL PROTECTED]:5070}
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: <To> [65]; uri=[sip:[EMAIL 
PROTECTED]:5070]
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: to body 
["85285523133"<sip:[EMAIL PROTECTED]:5070>]
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: cseq <CSeq>: <1> <ACK>
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: content_length=0
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: found end of header
Mar 25 21:42:23 [4001] DBG:maxfwd:is_maxfwd_present: max_forwards header not 
found!
Method: ACK
Mar 25 21:42:23 [4001] DBG:core:parse_to_param: tag=ea0e5c79
Mar 25 21:42:23 [4001] DBG:core:parse_to: end of header reached, state=29
Mar 25 21:42:23 [4001] DBG:core:parse_to: display={"laobai"}, ruri={sip:[EMAIL 
PROTECTED]:5070}
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=200
Mar 25 21:42:23 [4001] DBG:rr:find_first_route: No Route headers found
Mar 25 21:42:23 [4001] DBG:rr:loose_route: There is no Route HF
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if host==us: 14==9 &&  
[172.19.172.101] == [127.0.0.1]
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if host==us: 14==14 && 
 [172.19.172.101] == [172.19.172.101]
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:23 [4001] DBG:registrar:lookup: '85285523133' Not found in usrloc
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if host==us: 14==9 &&  
[172.19.172.101] == [127.0.0.1]
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if host==us: 14==14 && 
 [172.19.172.101] == [172.19.172.101]
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if host==us: 14==9 &&  
[172.19.172.101] == [127.0.0.1]
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if host==us: 14==14 && 
 [172.19.172.101] == [172.19.172.101]
Mar 25 21:42:23 [4001] DBG:core:grep_sock_info: checking if port 5070 matches 
port 5070
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=78
Mar 25 21:42:23 [4001] DBG:tm:t_lookup_request: start searching: hash=55692, 
isACK=1
Mar 25 21:42:23 [4001] DBG:tm:matching_3261: RFC3261 transaction matched, 
tid=-d87543-912ace5f9f7da033-1--d87543-
Mar 25 21:42:23 [4001] DBG:tm:t_lookup_request: REF_UNSAFE: after is 1
Mar 25 21:42:23 [4001] DBG:tm:t_lookup_request: transaction found (T=0xb5e83410)
ACK
route 1 reached
Mar 25 21:42:23 [4001] DBG:tm:cleanup_uac_timers: RETR/FR timers reset
Mar 25 21:42:23 [4001] DBG:tm:insert_timer_unsafe: [2]: 0xb5e83458 (1133)
Mar 25 21:42:23 [4001] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Mar 25 21:42:23 [4001] DBG:core:destroy_avp_list: destroying list (nil)
Mar 25 21:42:23 [4001] DBG:core:receive_msg: cleaning up
Mar 25 21:42:23 [4001] DBG:core:parse_msg: SIP Reply  (status):
Mar 25 21:42:23 [4001] DBG:core:parse_msg:  version: <SIP/2.0>
Mar 25 21:42:23 [4001] DBG:core:parse_msg:  status:  <200>
Mar 25 21:42:23 [4001] DBG:core:parse_msg:  reason:  <OK>
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=2
Mar 25 21:42:23 [4001] DBG:core:parse_via_param: found param type 232, <branch> 
= <z9hG4bKc89d.f721b532.0>; state=6
Mar 25 21:42:23 [4001] DBG:core:parse_via_param: found param type 234, 
<received> = <172.19.172.101>; state=16
Mar 25 21:42:23 [4001] DBG:core:parse_via: end of header reached, state=5
Mar 25 21:42:23 [4001] DBG:core:parse_headers: via found, flags=2
Mar 25 21:42:23 [4001] DBG:core:parse_headers: this is the first via
Mar 25 21:42:23 [4001] DBG:core:receive_msg: After parse_msg...
Mar 25 21:42:23 [4001] DBG:core:forward_reply: found module tm, passing reply 
to it
Mar 25 21:42:23 [4001] DBG:tm:t_check: start=0xffffffff
Mar 25 21:42:23 [4001] DBG:core:parse_headers: flags=22
Mar 25 21:42:23 [4001] DBG:core:parse_to_param: tag=as7903fabe
Mar 25 21:42:23 [4001] DBG:core:parse_to: end of header reached, state=29
Mar 25 21:42:23 [4001] DBG:core:parse_to: display={"85285523133"}, 
ruri={sip:[EMAIL PROTECTED]:5070}
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: <To> [65]; uri=[sip:[EMAIL 
PROTECTED]:5070]
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: to body 
["85285523133"<sip:[EMAIL PROTECTED]:5070>]
Mar 25 21:42:23 [4001] DBG:core:get_hdr_field: cseq <CSeq>: <1> <CANCEL>
Mar 25 21:42:23 [4001] DBG:tm:t_reply_matching: hash 55692 label 593171071 
branch 0
Mar 25 21:42:23 [4001] DBG:tm:t_reply_matching: REF_UNSAFE: after is 1
Mar 25 21:42:23 [4001] DBG:tm:t_reply_matching: reply matched (T=0xb5e83410)!
Mar 25 21:42:23 [4001] DBG:tm:t_check: end=0xb5e83410
Mar 25 21:42:23 [4001] DBG:tm:reply_received: org. status uas=487, uac[0]=487 
local=0 is_invite=1)
Mar 25 21:42:23 [4001] DBG:tm:reply_received: reply to local CANCEL processed
Mar 25 21:42:23 [4001] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
Mar 25 21:42:23 [4001] DBG:core:destroy_avp_list: destroying list (nil)
Mar 25 21:42:23 [4001] DBG:core:receive_msg: cleaning up
Mar 25 21:42:23 [4002] DBG:tm:utimer_routine: timer routine:4,tl=0xb5e835d8 
next=0xb5e834d8, timeout=1129200000
Mar 25 21:42:23 [4002] DBG:tm:utimer_routine: timer routine:4,tl=0xb5e834d8 
next=(nil), timeout=1129200000
Mar 25 21:42:27 [4002] DBG:tm:timer_routine: timer routine:2,tl=0xb5e85cf0 
next=0xb5e83458, timeout=1133
Mar 25 21:42:27 [4002] DBG:tm:wait_handler: removing 0xb5e85ca8 from table
Mar 25 21:42:27 [4002] DBG:tm:delete_cell: delete transaction 0xb5e85ca8
Mar 25 21:42:27 [4002] DBG:tm:wait_handler: done
Mar 25 21:42:27 [4002] DBG:tm:timer_routine: timer routine:2,tl=0xb5e83458 
next=(nil), timeout=1133
Mar 25 21:42:27 [4002] DBG:tm:wait_handler: removing 0xb5e83410 from table
Mar 25 21:42:27 [4002] DBG:tm:delete_cell: delete transaction 0xb5e83410
Mar 25 21:42:27 [4002] DBG:tm:wait_handler: done

_______________________________________________
Users mailing list
Users@lists.openser.org
http://lists.openser.org/cgi-bin/mailman/listinfo/users

Reply via email to