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@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