[Serusers] cpl won't cancel call transaction

9 Jul 2004

Hi,

I have the attached cpl script. It rings the IP phone
first, if not answer, then send to a pstn phone. The
script was working, but is broken now. I am not sure
if it is the script or any latest development breaks
it.

A couple of issues,
If the call is canceled when still ringing ip phone,
the call is forwarded to the pstn phone. So pstn phone
rings for nothing. It looks like cancel didn't cancel
the original transaction in cpl.

A brand new call... If the call is sent to PSTN phone
eventually, PSTN phone picks up. But didn't hear
anything, the original phone still hears the ringing
until a few seconds later. Then they can talk.

Thanks for your help in advance.
Richard

__________________________________
Do you Yahoo!?
New and Improved Yahoo! Mail - Send 10MB messages!
http://promotions.yahoo.com/new_mail 

Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: SIP Request:
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]:  method:  <CANCEL>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]:  uri:    
<sip:3560072@o-matrix.org>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]:  version: <SIP/2.0>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: Found param type 232, <branch>
= <z9hG4bK260b3dd2>; state=16
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: end of header reached, state=5
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: Via found, flags=1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: this is the first
via
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: After parse_msg...
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: preparing to run routing scripts...
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=8
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: add_param:
tag=000ed7109b1401477a53f248-38198f5f
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: end of header reached, state=29
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=4
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: end of header reached, state=9
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: get_hdr_field: <To>
[28]; uri=[sip:3560072@o-matrix.org]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: to body
[<sip:3560072@o-matrix.org>^M ]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=64
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: get_hdr_field: cseq <CSeq>:
<102> <CANCEL>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: get_hdr_body :
content_length=0
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: found end of header
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_get_contact: no contact
header!
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 757
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: Start processing: m CANCEL from
<sip:3560073@o-matrix.org>@66.135.241.170 to sip:3560072@o-matrix.org contact
<null> Message flag 0 len 609 buffer CANCEL sip:3560072@o-matrix.org SIP/2.0^M Via:
SIP/2.0/UDP 66.135.241.170:5060;branch=z9hG4bK260b3dd2^M From: "060"
<sip:3560073@o-matrix.org>;tag=000ed7109b1401477a53f248-38198f5f^M To:
<sip:3560072@o-matrix.org>^M Call-ID:
000ed710-9b14012e-7a68a6a0-53fa9d5b(a)66.135.241.170^M Date: Fri, 09 Jul 2004 10:29:44 GMT^M
CSeq: 102 CANCEL^M User-Agent: CSCO/7^M Content-Length: 0^M Proxy-Authorization: Digest
username="3560073",realm="o-matrix.org",uri="sip:66.135.241.128",response="505e0b601f708b39b1dcce2c81a0d68e",nonce="40ee74bcd14f19ae18c428c27ea1ceaf4571e5e1",cnonce="338e3f99",qop=auth,nc=00000002,algorithm=md5^M
^M
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG : is_maxfwd_present: searching
for max_forwards header
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=128
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: is_maxfwd_present:
max_forwards header not found!
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if host==us:
12==14 &&  [o-matrix.org] == [66.135.241.128]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if port 5060
matches port 5060
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if host==us:
12==14 &&  [o-matrix.org] == [66.135.241.128]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if port 5060
matches port 5060
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self: host != me
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=256
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: find_first_route(): No Route headers
found
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: loose_route(): There is no Route HF
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 43
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: About to check if it is to local or
myself
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if host==us:
12==14 &&  [o-matrix.org] == [66.135.241.128]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if port 5060
matches port 5060
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if host==us:
12==14 &&  [o-matrix.org] == [66.135.241.128]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if port 5060
matches port 5060
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self: host != me
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 36
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: About to checking uri for voicemail
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: lookup():
&#39;3560072(a)o-matrix.org&#39; Not found in usrloc
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 51
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: About to proxy challenge before
further processing
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 35
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: No challenge due to ACK/BYE/CANCEL
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 48
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: About to domain mapping according to
the number
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 23
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: About to lookup aliases
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: lookup():
&#39;3560072(a)o-matrix.org&#39; Not found in usrloc
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 22
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: About to check INVITE
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 22
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: about to check number
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: is_user_in(): User is not in group
'novoicemail'
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 37
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: About to look in user location
table
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: rewrite(): Rewriting Request-URI
with 'sip:3560072@66.135.241.171:5060'
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 44
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: About to forward the message to
destination
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 17
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: Entering route 1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: t_newtran: msg id=24 , global
msg id=20 , T on entrance=0xffffffff
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=-1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=60
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: t_lookup_request: start searching:
hash=57757, isACK=0
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: RFC3261 transaction matching
failed
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: t_lookup_request: no
transaction found
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DBG: trans=0x402ede00, callback type
1, id 0 entered
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=44
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: t_lookupOriginalT: searching
on hash entry 57757
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: RFC3261 transaction matched,
tid=260b3dd2
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: t_lookupOriginalT: canceled
transaction found (0x402ed300)!
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: t_lookupOriginalT completed
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_via_address(66.135.241.170,
66.135.241.170, 0)
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: add_timer_unsafe[4]:
0x402edf18
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: add_timer_unsafe[0]:
0x402edf28
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: e2e_cancel: e2e cancel
proceeding
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=-1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_via_address(66.135.241.170,
66.135.241.170, 0)
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: WARNING:vqm_resize: resize(0)
called
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DBG: trans=0x402ede00, callback type
128, id 0 entered
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: cleanup_uac_timers: RETR/FR
timers reset
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: add_timer_unsafe[2]:
0x402ede48
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: reply sent out.
buf=0x80fe018: SIP/2.0 2..., shmem=0x402f2310: SIP/2.0 2
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: _reply_light: finished
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: SER: new transaction fwd'ed
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: receive_msg: cleaning up
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: SIP Reply  (status):
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]:  version: <SIP/2.0>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]:  status:  <200>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]:  reason:  <OK>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: parse_headers: flags=1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: Found param type 232, <branch>
= <z9hG4bKd91e.4d817a06.0>; state=9
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: parse_via: next_via
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: Found param type 232, <branch>
= <z9hG4bK260b3dd2>; state=16
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: end of header reached, state=5
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: parse_headers: Via found, flags=1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: parse_headers: this is the first
via
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: After parse_msg...
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: forward_reply: found module tm,
passing reply to it
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: t_check: msg id=26 global
id=25 T start=0xffffffff
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: parse_headers: flags=17
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: add_param:
tag=000e84c05de700027d4d3f30-5e57d662
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: end of header reached, state=29
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: get_hdr_field: <To>
[66]; uri=[sip:3560072@o-matrix.org]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: to body
[<sip:3560072@o-matrix.org>]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: get_hdr_field: cseq <CSeq>:
<102> <CANCEL>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: t_reply_matching: hash 57757
label 1621563604 branch 0
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: t_reply_matching: reply
matched (T=0x402ede00)!
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DBG: trans=0x402ede00, callback type
2, id 0 entered
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: t_check: msg id=26 global
id=26 T end=0x402ede00
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: reply_received: org. status
uas=200, uac[0]=0 local=0 is_invite=0)
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]:
->>>>>>>>> T_code=200, new_code=200
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: relay_reply: branch=0,
save=0, relay=-1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: receive_msg: cleaning up
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: SIP Reply  (status):
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]:  version: <SIP/2.0>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]:  status:  <487>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]:  reason:  <Request Cancelled>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: parse_headers: flags=1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: Found param type 232, <branch>
= <z9hG4bKd91e.4d817a06.0>; state=9
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: parse_via: next_via
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: Found param type 232, <branch>
= <z9hG4bK260b3dd2>; state=16
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: end of header reached, state=5
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: parse_headers: Via found, flags=1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: parse_headers: this is the first
via
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: After parse_msg...
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: forward_reply: found module tm,
passing reply to it
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG: t_check: msg id=24 global
id=23 T start=0xffffffff
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: parse_headers: flags=17
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG: add_param:
tag=000e84c05de700027d4d3f30-5e57d662
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: end of header reached, state=29
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG: get_hdr_field: <To>
[66]; uri=[sip:3560072@o-matrix.org]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG: to body
[<sip:3560072@o-matrix.org>]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: get_hdr_field: cseq <CSeq>:
<102> <INVITE>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: parse_headers: flags=4
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG: t_reply_matching: hash 57757
label 1621563604 branch 0
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG: t_reply_matching: reply
matched (T=0x402ed300)!
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DBG: trans=0x402ed300, callback type
2, id 0 entered
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: parse_headers: flags=4
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG: t_check: msg id=24 global
id=24 T end=0x402ed300
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG: reply_received: org. status
uas=180, uac[0]=180 local=0 is_invite=1)
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: parse_headers: flags=4
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]:
->>>>>>>>> T_code=180, new_code=487
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DBG: trans=0x402ed300, callback type
64, id 1 entered
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG:cpl-c:negativ_reply:
------------------------------>  ---------------------------------> negativ reply
received
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]:
DEBUG:cpl-c:failed_reply:final_reply: got a final 487
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG:cpl_run_script: processing sub
node
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG:cpl_run_script: processing
location node
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG:cpl_run_script: processing
proxy node
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG:cpl_c:cpl_proxy_to_loc_set:
appending brach <sip:2303940@o-matrix.org>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG: t_check: msg id=20 global
id=20 T start=0x402ed300
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG: t_check: T alredy found!
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG: mk_proxy: doing DNS
lookup...
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: sip_resolvehost:
SRV(_sip._udp.o-matrix.org) = sip01.o-matrix.org:5060
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: check_via_address(66.135.241.170,
66.135.241.170, 0)
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG: add_timer_unsafe[4]:
0x402ed4e8
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG: add_timer_unsafe[0]:
0x402ed4f8
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: SIP Request:
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG:cpl_c:cpl_run_script: done for
the moment; waiting after signaling!
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]:  method:  <INVITE>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: DEBUG: relay_reply: branch=0,
save=1, relay=-1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]:  uri:    
<sip:2303940@o-matrix.org>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21860]: receive_msg: cleaning up
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]:  version: <SIP/2.0>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: Found param type 232, <branch>
= <z9hG4bKd91e.4d817a06.1>; state=16
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: end of header reached, state=5
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: Via found, flags=1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: this is the first
via
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: After parse_msg...
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: preparing to run routing scripts...
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=8
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: Found param type 232, <branch>
= <z9hG4bK260b3dd2>; state=16
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: end of header reached, state=5
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: Via found, flags=8
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: this is the second
via
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: add_param:
tag=000ed7109b1401477a53f248-38198f5f
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: end of header reached, state=29
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=4
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: end of header reached, state=9
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: get_hdr_field: <To>
[28]; uri=[sip:3560072@o-matrix.org]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: to body
[<sip:3560072@o-matrix.org>^M ]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=64
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: get_hdr_field: cseq <CSeq>:
<102> <INVITE>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 1397
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: Start processing: m INVITE from
<sip:3560073@o-matrix.org>@66.135.241.128 to sip:3560072@o-matrix.org contact
<sip:3560073@66.135.241.170:5060> Message flag 0 len 1221 buffer INVITE
sip:2303940@o-matrix.org SIP/2.0^M Max-Forwards: 10^M Record-Route:
<sip:66.135.241.128;ftag=000ed7109b1401477a53f248-38198f5f;lr=on>^M Via: SIP/2.0/UDP
66.135.241.128;branch=z9hG4bKd91e.4d817a06.1^M Via: SIP/2.0/UDP
66.135.241.170:5060;branch=z9hG4bK260b3dd2^M From: "060"
<sip:3560073@o-matrix.org>;tag=000ed7109b1401477a53f248-38198f5f^M To:
<sip:3560072@o-matrix.org>^M Call-ID:
000ed710-9b14012e-7a68a6a0-53fa9d5b(a)66.135.241.170^M Date: Fri, 09 Jul 2004 10:29:36 GMT^M
CSeq: 102 INVITE^M User-Agent: CSCO/7^M Contact: <sip:3560073@66.135.241.170:5060>^M
Proxy-Authorization: Digest
username="3560073",realm="o-matrix.org",uri="sip:66.135.241.128",response="5551c14946435407bde1fd3bb6645208",nonce="40ee74bcd14f19ae18c428c27ea1ceaf4571e5e1",cnonce="10d8637b",qop=auth,nc=00000001,algorithm=m
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG : is_maxfwd_present:
max_forward header already found!
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: is_maxfwd_present: value =
10
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if host==us:
12==14 &&  [o-matrix.org] == [66.135.241.128]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if port 5060
matches port 5060
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if host==us:
12==14 &&  [o-matrix.org] == [66.135.241.128]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if port 5060
matches port 5060
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self: host != me
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=256
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: get_hdr_body :
content_length=251
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: found end of header
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: find_first_route(): No Route headers
found
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: loose_route(): There is no Route HF
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 43
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: About to check if it is to local or
myself
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if host==us:
12==14 &&  [o-matrix.org] == [66.135.241.128]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if port 5060
matches port 5060
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if host==us:
12==14 &&  [o-matrix.org] == [66.135.241.128]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self - checking if port 5060
matches port 5060
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_self: host != me
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 36
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: About to checking uri for voicemail
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: lookup():
&#39;2303940(a)o-matrix.org&#39; Not found in usrloc
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 51
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: About to proxy challenge before
further processing
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 53
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: No challenge due to from PSTN or
myself (due of cpl)
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 48
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: About to domain mapping according to
the number
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 37
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: Number is for PSTN, send it to
there
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 21
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: Going into pstn call
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: is_rpid_user_e164(): Empty rpid
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 22
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: is rpid user e164, no
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=-1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=-1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: append_rpid_hf(): rpid is empty,
nothing to append
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 17
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: Entering route 1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: t_newtran: msg id=25 , global
msg id=24 , T on entrance=0xffffffff
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=-1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=60
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: t_lookup_request: start searching:
hash=57757, isACK=0
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: RFC3261 transaction matching
failed
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: t_lookup_request: no
transaction found
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DBG: trans=0x402f47c8, callback type
1, id 0 entered
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=44
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: noisy_timer set for
accounting
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: SER: new INVITE
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=-1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_via_address(66.135.241.128,
66.135.241.128, 0)
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: WARNING:vqm_resize: resize(0)
called
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: reply sent out.
buf=0x80fe3f0: SIP/2.0 1..., shmem=0x402f1708: SIP/2.0 1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: SIP Reply  (status):
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: _reply_light: finished
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]:  version: <SIP/2.0>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: mk_proxy: doing DNS
lookup...
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]:  status:  <100>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: check_via_address(66.135.241.128,
66.135.241.128, 0)
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]:  reason:  <trying -- your call is
important to us>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: add_timer_unsafe[4]:
0x402f48e0
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: parse_headers: flags=1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: DEBUG: add_timer_unsafe[0]:
0x402f48f0
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: Found param type 232, <branch>
= <z9hG4bKd91e.4d817a06.1>; state=16
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: SER: new transaction fwd'ed
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: end of header reached, state=5
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: XLOG: xl_print_log: final buffer
length 83
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: parse_headers: Via found, flags=1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: pstn gateway
<sip:3560073@o-matrix.org>@66.135.241.128 to sip:3560072@o-matrix.org
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: parse_headers: this is the first
via
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21858]: receive_msg: cleaning up
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: After parse_msg...
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: forward_reply: found module tm,
passing reply to it
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: t_check: msg id=27 global
id=26 T start=0xffffffff
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: parse_headers: flags=17
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: Found param type 232, <branch>
= <z9hG4bK260b3dd2>; state=16
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: end of header reached, state=5
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: parse_headers: Via found, flags=17
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: parse_headers: this is the second
via
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: end of header reached, state=9
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: get_hdr_field: <To>
[28]; uri=[sip:3560072@o-matrix.org]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: to body
[<sip:3560072@o-matrix.org>^M ]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: get_hdr_field: cseq <CSeq>:
<102> <INVITE>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: parse_headers: flags=4
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: t_reply_matching: hash 57757
label 1621563604 branch 1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: t_reply_matching: reply
matched (T=0x402ed300)!
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DBG: trans=0x402ed300, callback type
2, id 0 entered
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: t_check: msg id=27 global
id=27 T end=0x402ed300
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: reply_received: org. status
uas=180, uac[1]=0 local=0 is_invite=1)
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]:
->>>>>>>>> T_code=180, new_code=100
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: relay_reply: branch=1,
save=0, relay=-1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: DEBUG: add_timer_unsafe[1]:
0x402ed4f8
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21861]: receive_msg: cleaning up
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: SIP Reply  (status):
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]:  version: <SIP/2.0>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]:  status:  <100>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]:  reason:  <Trying>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: parse_headers: flags=1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: Found param type 232, <branch>
= <z9hG4bKd91e.6d817a06.0>; state=9
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: parse_via: next_via
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: Found param type 232, <branch>
= <z9hG4bKd91e.4d817a06.1>; state=9
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: parse_via: next_via
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: Found param type 232, <branch>
= <z9hG4bK260b3dd2>; state=16
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: end of header reached, state=5
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: parse_headers: Via found, flags=1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: parse_headers: this is the first
via
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: After parse_msg...
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: forward_reply: found module tm,
passing reply to it
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: DEBUG: t_check: msg id=23 global
id=22 T start=0xffffffff
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: parse_headers: flags=17
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: DEBUG: add_param: tag=1EEC0F2-162C
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: end of header reached, state=29
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: DEBUG: get_hdr_field: <To>
[45]; uri=[sip:3560072@o-matrix.org]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: DEBUG: to body
[<sip:3560072@o-matrix.org>]
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: get_hdr_field: cseq <CSeq>:
<102> <INVITE>
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: parse_headers: flags=4
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: DEBUG: t_reply_matching: hash 57757
label 1621563606 branch 0
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: DEBUG: t_reply_matching: reply
matched (T=0x402f47c8)!
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: DBG: trans=0x402f47c8, callback type
2, id 0 entered
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: DEBUG: t_check: msg id=23 global
id=23 T end=0x402f47c8
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: DEBUG: reply_received: org. status
uas=100, uac[0]=0 local=0 is_invite=1)
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]:
->>>>>>>>> T_code=100, new_code=100
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: DEBUG: relay_reply: branch=0,
save=0, relay=-1
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: DEBUG: add_timer_unsafe[1]:
0x402f48f0
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21859]: receive_msg: cleaning up
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21863]: DEBUG: timer routine:0,tl=0x402edf28
next=(nil)
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21863]: DEBUG: timer routine:1,tl=0x402ed428
next=(nil)
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21863]: DEBUG: timer routine:4,tl=0x402edf18
next=0x402ed4e8
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21863]: DEBUG: timer routine:4,tl=0x402ed4e8
next=0x402f48e0
Jul  9 00:29:44 localhost /usr/local/sbin/ser[21863]: DEBUG: timer routine:4,tl=0x402f48e0
next=(nil)
Jul  9 00:29:48 localhost /usr/local/sbin/ser[21863]: DEBUG: timer routine:2,tl=0x402ede48
next=(nil)
Jul  9 00:29:48 localhost /usr/local/sbin/ser[21863]: DEBUG: wait_handler : removing
0x402ede00 from table
Jul  9 00:29:48 localhost /usr/local/sbin/ser[21863]: DEBUG: delete transaction
0x402ede00
Jul  9 00:29:48 localhost /usr/local/sbin/ser[21863]: DEBUG: wait_handler : done
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: SIP Reply  (status):
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]:  version: <SIP/2.0>
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]:  status:  <183>
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]:  reason:  <Session Progress>
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: parse_headers: flags=1
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: Found param type 232, <branch>
= <z9hG4bKd91e.6d817a06.0>; state=9
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: parse_via: next_via
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: Found param type 232, <branch>
= <z9hG4bKd91e.4d817a06.1>; state=9
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: parse_via: next_via
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: Found param type 232, <branch>
= <z9hG4bK260b3dd2>; state=16
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: end of header reached, state=5
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: parse_headers: Via found, flags=1
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: parse_headers: this is the first
via
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: After parse_msg...
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: forward_reply: found module tm,
passing reply to it
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: DEBUG: t_check: msg id=25 global
id=24 T start=0xffffffff
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: parse_headers: flags=17
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: DEBUG: add_param: tag=1EEC0F2-162C
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: end of header reached, state=29
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: DEBUG: get_hdr_field: <To>
[45]; uri=[sip:3560072@o-matrix.org]
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: DEBUG: to body
[<sip:3560072@o-matrix.org>]
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: get_hdr_field: cseq <CSeq>:
<102> <INVITE>
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: parse_headers: flags=4
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: DEBUG: t_reply_matching: hash 57757
label 1621563606 branch 0
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: DEBUG: t_reply_matching: reply
matched (T=0x402f47c8)!
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: DBG: trans=0x402f47c8, callback type
2, id 0 entered
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: DEBUG: t_check: msg id=25 global
id=25 T end=0x402f47c8
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: DEBUG: reply_received: org. status
uas=100, uac[0]=100 local=0 is_invite=1)
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]:
->>>>>>>>> T_code=100, new_code=183
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: DEBUG: relay_reply: branch=0,
save=0, relay=0
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]:  old size: 1028, new size: 971
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: build_res_from_sip_res: copied size:
orig:92, new: 35, rest: 936 msg= SIP/2.0 183 Session Progress^M Via: SIP/2.0/UDP
66.135.241.128;branch=z9hG4bKd91e.4d817a06.1,SIP/2.0/UDP
66.135.241.170:5060;branch=z9hG4bK260b3dd2^M From: "060"
<sip:3560073@o-matrix.org>;tag=000ed7109b1401477a53f248-38198f5f^M To:
<sip:3560072@o-matrix.org>;tag=1EEC0F2-162C^M Date: Fri, 09 Jul 2004 10:29:44 GMT^M
Call-ID: 000ed710-9b14012e-7a68a6a0-53fa9d5b(a)66.135.241.170^M Server:
Cisco-SIPGateway/IOS-12.x^M CSeq: 102 INVITE^M Allow: UPDATE^M Allow-Events:
telephone-event^M Contact: <sip:2303940@66.135.241.189:5060>^M Record-Route:
<sip:66.135.241.128;ftag=000ed7109b1401477a53f248-38198f5f;lr=on>,<sip:66.135.241.128;ftag=000ed7109b1401477a53f248-38198f5f;lr=on>^M
Content-Disposition: session;handling=required^M Content-Type: application/sdp^M
Content-Length: 206^M ^M v=0^M o=CiscoSystemsSIP-GW-UserAgent 4801 7509 IN IP4
66.135.241.189^M s=SIP Call^M c=IN IP4 66.135.241.189^M t=0 0^M m=audio
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: DEBUG: reply relayed. buf=0x81014a8:
SIP/2.0 1..., shmem=0x402f6280: SIP/2.0 1
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: SIP Reply  (status):
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: DBG: trans=0x402f47c8, callback type
128, id 0 entered
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]:  version: <SIP/2.0>
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: DEBUG: add_timer_unsafe[1]:
0x402f48f0
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]:  status:  <183>
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21860]: receive_msg: cleaning up
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]:  reason:  <Session Progress>
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=1
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: Found param type 232, <branch>
= <z9hG4bKd91e.4d817a06.1>; state=9
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: parse_via: next_via
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: Found param type 232, <branch>
= <z9hG4bK260b3dd2>; state=16
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: end of header reached, state=5
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: parse_headers: Via found, flags=1
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: parse_headers: this is the first
via
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: After parse_msg...
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: forward_reply: found module tm,
passing reply to it
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: DEBUG: t_check: msg id=26 global
id=25 T start=0xffffffff
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=17
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: DEBUG: add_param: tag=1EEC0F2-162C
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: end of header reached, state=29
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: DEBUG: get_hdr_field: <To>
[45]; uri=[sip:3560072@o-matrix.org]
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: DEBUG: to body
[<sip:3560072@o-matrix.org>]
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: get_hdr_field: cseq <CSeq>:
<102> <INVITE>
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: parse_headers: flags=4
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: DEBUG: t_reply_matching: hash 57757
label 1621563604 branch 1
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: DEBUG: t_reply_matching: reply
matched (T=0x402ed300)!
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: DBG: trans=0x402ed300, callback type
2, id 0 entered
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: DEBUG: t_check: msg id=26 global
id=26 T end=0x402ed300
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: DEBUG: reply_received: org. status
uas=180, uac[1]=100 local=0 is_invite=1)
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]:
->>>>>>>>> T_code=180, new_code=183
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: DEBUG: relay_reply: branch=1,
save=0, relay=1
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]:  old size: 971, new size: 914
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: build_res_from_sip_res: copied size:
orig:92, new: 35, rest: 879 msg= SIP/2.0 183 Session Progress^M Via: SIP/2.0/UDP
66.135.241.170:5060;branch=z9hG4bK260b3dd2^M From: "060"
<sip:3560073@o-matrix.org>;tag=000ed7109b1401477a53f248-38198f5f^M To:
<sip:3560072@o-matrix.org>;tag=1EEC0F2-162C^M Date: Fri, 09 Jul 2004 10:29:44 GMT^M
Call-ID: 000ed710-9b14012e-7a68a6a0-53fa9d5b(a)66.135.241.170^M Server:
Cisco-SIPGateway/IOS-12.x^M CSeq: 102 INVITE^M Allow: UPDATE^M Allow-Events:
telephone-event^M Contact: <sip:2303940@66.135.241.189:5060>^M Record-Route:
<sip:66.135.241.128;ftag=000ed7109b1401477a53f248-38198f5f;lr=on>,<sip:66.135.241.128;ftag=000ed7109b1401477a53f248-38198f5f;lr=on>^M
Content-Disposition: session;handling=required^M Content-Type: application/sdp^M
Content-Length: 206^M ^M v=0^M o=CiscoSystemsSIP-GW-UserAgent 4801 7509 IN IP4
66.135.241.189^M s=SIP Call^M c=IN IP4 66.135.241.189^M t=0 0^M m=audio 17270 RTP/AVP 0^M
c=IN IP4 66.135.241.189^M a=rtpmap:0 PC
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: DEBUG: reply relayed. buf=0x81013b0:
SIP/2.0 1..., shmem=0x402eeba8: SIP/2.0 1
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: DBG: trans=0x402ed300, callback type
128, id 1 entered
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: DBG: trans=0x402ed300, callback type
128, id 0 entered
Jul  9 00:29:49 localhost /usr/local/sbin/ser[21858]: DEBUG: add_timer_unsafe[1]:
0x402ed4f8
Jul  9 00:29:50 localhost /usr/local/sbin/ser[21858]: receive_msg: cleaning up

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

2005

2004

2003

2002

[Serusers] cpl won't cancel call transaction