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@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(): '3560072@o-matrix.org' 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(): '3560072@o-matrix.org' 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@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(): '2303940@o-matrix.org' 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@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@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