9 May
2007
9 May
'07
11:54 p.m.
I am having a problem forwarding calls to asterisk for voice mail
handling. What I am trying to do:
When a call times out for no answer, change the address of the call by
prepending 777 to the extension number. Then forward the call to
asterisk, where the 777 prefix tells asterisk that it just sends this
call to voicemail.
Here is my openser.cfg file:
...
modparam("tm", "fr_inv_timer", 20)
...
route[1] {
# # send it out now; use stateful forwarding as it works reliably
# # even for UDP2TCP
t_on_failure("2");
if (!t_relay()) {
sl_reply_error();
};
exit;
}
failure_route[2]
{
if ( t_check_status("408"))
if the call fails for timeout, send me a message and go to route(3)
{
xlog("L_ERR","rrreeeeeeeeeeeeeeeeeecalling froute2
<$rm><$ru>\n");
route(3);
exit;
}
exit;
}
route[3]
{
rewrite the uri to prepend 777
if (subst_uri('/^sip:([0-9]+)@(.*)$/sip:777\1@\2/i'))
{
rewritehostport("66.xxx.20.50:5060"); the asterisk box
append_branch();
xlog("L_ERR","3333333333333333333333333333333333333333after substr
<$rm><$ru>\n");
if (!t_relay("udp:66.xxx.20.50:5060"))
{
sl_send_reply("500", "Relaying failed");
}
}
exit;
}
What happens is that the call gets forwarded to Asterisk, but asterisk
does not seem to recognize that the call is destined for 777xxxxxxx, but
instead tries to send it to xxxxxxx, which causes the call to be
transferred back to openser. This loop goes around and around until I
kill it.
Here is portion of log file:
1(7856) rrreeeeeeeeeeeeeeeeeecalling froute2
<INVITE><sip:1020101@67.188.231.188:42749;rinstance=1e89b57f830c50f7>
1(7856) subst_run: running. r=0
1(7856) subst_run: matched (0, 59):
[sip:1020101@67.188.231.188:42749;rinstance=1e89b57f830c50f7]
1(7856) textops: subst_uri_f: match - old uri=
[sip:1020101@67.188.231.188:42749;rinstance=1e89b57f830c50f7], new uri=
[sip:7771020101@67.188.231.188:42749;rinstance=1e89b57f830c50f7]
1(7856) ******* setting for branch 0 flags 0
1(7856) 3333333333333333333333333333333333333333after substr
<INVITE><sip:7771020101@66.224.20.50:5060;rinstance=1e89b57f830c50f7>
1(7856) check_via_address(67.188.231.188, 67.188.231.188, 0)
1(7856) DBG:check_against_rule_list: using list dns
1(7856) DEBUG:tm:set_timer: relative timeout is 500000
1(7856) DEBUG: add_to_tail_of_timer[4]: 0x801f4b4b0 (49500000)
1(7856) DEBUG:tm:set_timer: relative timeout is 30
1(7856) DEBUG: add_to_tail_of_timer[0]: 0x801f4b4e0 (79)
1(7856) DEBUG:tm:relay_reply: branch=0, save=1, relay=-1
1(7856) DEBUG:tm:build_local: using FROM=<From:
"Xantek"<sip:1020101@67.102.229.3>;tag=045b4172
, TO=<To:
"1020101"<sip:1020101@67.102.229.3>
, CSEQ_N=<CSeq: 1>
1(7856) DEBUG: cancel_branch: sending cancel...
1(7856) DEBUG:tm:set_timer: relative timeout is 500000
1(7856) DEBUG: add_to_tail_of_timer[4]: 0x801f4b3c0 (49500000)
1(7856) DEBUG:tm:set_timer: relative timeout is 30
1(7856) DEBUG: add_to_tail_of_timer[0]: 0x801f4b3f0 (79)
1(7856) DEBUG: final_response_handler : done
0(7855) udp_rcv_loop: probing packet received from 24.5.58.18 53652
0(7855) SIP Reply (status):
0(7855) version: <SIP/2.0>
0(7855) status: <407>
0(7855) reason: <Proxy Authentication Required>
0(7855) parse_headers: flags=2
0(7855) Found param type 232, <branch> = <z9hG4bK5988.480944e.1>; state=6
0(7855) Found param type 234, <received> = <67.102.229.3>; state=16
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=2
0(7855) parse_headers: this is the first via
0(7855) After parse_msg...
0(7855) DEBUG:forward_reply: found module tm, passing reply to it
0(7855) DEBUG: t_check: start=0xffffffffffffffff
0(7855) parse_headers: flags=22
0(7855) Found param type 232, <branch> =
<z9hG4bK-d87543-e004ef19dd229e0e-1--d87543->; state=6
0(7855) Found param type 235, <rport> = <42749>; state=16
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=22
0(7855) parse_headers: this is the second via
0(7855) DEBUG: add_param: tag=as499a9c72
0(7855) DEBUG:parse_to:end of header reached, state=29
0(7855) DBUG:parse_to: display={"1020101"}, ruri={sip:1020101@67.102.229.3}
0(7855) DEBUG: get_hdr_field: <To> [52]; uri=[sip:1020101@67.102.229.3]
0(7855) DEBUG: to body ["1020101"<sip:1020101@67.102.229.3>]
0(7855) get_hdr_field: cseq <CSeq>: <1> <INVITE>
0(7855) parse_headers: flags=8
0(7855) DEBUG: t_reply_matching: hash 34965 label 239374468 branch 1
0(7855) DEBUG:tm:REF_UNSAFE: after is 1
0(7855) DEBUG: t_reply_matching: reply matched (T=0x801f4b0d8)!
0(7855) DEBUG: t_check: end=0x801f4b0d8
0(7855) DEBUG:tm:reply_received: org. status uas=180, uac[1]=0 local=0
is_invite=1)
0(7855) parse_headers: flags=8
0(7855) DEBUG:tm:build_local: using FROM=<From:
"Xantek"<sip:1020101@67.102.229.3>;tag=045b4172
, TO=<To:
"1020101"<sip:1020101@67.102.229.3>;tag=as499a9c72
, CSEQ_N=<CSeq: 1>
0(7855) DEBUG:tm:t_should_relay_response: T_code=180,
new_code=407
0(7855) DEBUG:tm:t_pick_branch: picked branch 1, code 407
0(7855) DEBUG:tm:relay_reply: branch=1, save=0, relay=1
0(7855) old size: 631, new size: 549
0(7855) build_res_from_sip_res: copied size: orig:125, new: 43, rest:
506 msg=
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP
67.188.231.188:42749;branch=z9hG4bK-d87543-e004ef19dd229e0e-1--d87543-;rport=42749
From: "Xantek"<sip:1020101@67.102.229.3>;tag=045b4172
To: "1020101"<sip:1020101@67.102.229.3>;tag=as499a9c72
Call-ID: YjgxM2RlZmM4MjRhMDYxN2YwYjI2MDdmZWZjMGY4NTY.
CSeq: 1 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Contact: <sip:7771020101@66.224.20.50>
Proxy-Authenticate: Digest realm="sip.xantek.cc", nonce="1aebadb3"
Content-Length: 0
0(7855) DEBUG:tm:set_timer: relative timeout is 500000
0(7855) DEBUG: add_to_tail_of_timer[4]: 0x801f4b220 (49500000)
0(7855) DEBUG:tm:set_timer: relative timeout is 30
0(7855) DEBUG: add_to_tail_of_timer[0]: 0x801f4b250 (79)
0(7855) DEBUG:tm:relay_reply: sent buf=0x62deb0: SIP/2.0 4...,
shmem=0x801f4aea0: SIP/2.0 4
0(7855) DEBUG: cleanup_uac_timers: RETR/FR timers reset
0(7855) DEBUG:tm:UNREF_UNSAFE: after is 0
0(7855) DEBUG:destroy_avp_list: destroying list 0x0
0(7855) receive_msg: cleaning up
0(7855) SIP Reply (status):
0(7855) version: <SIP/2.0>
0(7855) status: <200>
0(7855) reason: <OK>
0(7855) parse_headers: flags=2
0(7855) Found param type 232, <branch> = <z9hG4bK5988.480944e.0>; state=16
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=2
0(7855) parse_headers: this is the first via
0(7855) After parse_msg...
0(7855) DEBUG:forward_reply: found module tm, passing reply to it
0(7855) DEBUG: t_check: start=0xffffffffffffffff
0(7855) parse_headers: flags=22
0(7855) DEBUG: add_param: tag=03422a48
0(7855) DEBUG:parse_to:end of header reached, state=29
0(7855) DBUG:parse_to: display={"1020101"}, ruri={sip:1020101@67.102.229.3}
0(7855) DEBUG: get_hdr_field: <To> [50]; uri=[sip:1020101@67.102.229.3]
0(7855) DEBUG: to body ["1020101"<sip:1020101@67.102.229.3>]
0(7855) get_hdr_field: cseq <CSeq>: <1> <CANCEL>
0(7855) DEBUG: t_reply_matching: hash 34965 label 239374468 branch 0
0(7855) DEBUG:tm:REF_UNSAFE: after is 1
0(7855) DEBUG: t_reply_matching: reply matched (T=0x801f4b0d8)!
0(7855) DEBUG: t_check: end=0x801f4b0d8
0(7855) DEBUG:tm:reply_received: org. status uas=407, uac[0]=408 local=0
is_invite=1)
0(7855) DEBUG:tm:reply_received: reply to local CANCEL processed
0(7855) DEBUG:tm:UNREF_UNSAFE: after is 0
0(7855) DEBUG:destroy_avp_list: destroying list 0x0
0(7855) receive_msg: cleaning up
0(7855) SIP Reply (status):
0(7855) version: <SIP/2.0>
0(7855) status: <487>
0(7855) reason: <Request Terminated>
0(7855) parse_headers: flags=2
0(7855) Found param type 232, <branch> = <z9hG4bK5988.480944e.0>; state=16
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=2
0(7855) parse_headers: this is the first via
0(7855) After parse_msg...
0(7855) DEBUG:forward_reply: found module tm, passing reply to it
0(7855) DEBUG: t_check: start=0xffffffffffffffff
0(7855) parse_headers: flags=22
0(7855) Found param type 232, <branch> =
<z9hG4bK-d87543-e004ef19dd229e0e-1--d87543->; state=6
0(7855) Found param type 235, <rport> = <42749>; state=16
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=22
0(7855) parse_headers: this is the second via
0(7855) DEBUG: add_param: tag=03422a48
0(7855) DEBUG:parse_to:end of header reached, state=29
0(7855) DBUG:parse_to: display={"1020101"}, ruri={sip:1020101@67.102.229.3}
0(7855) DEBUG: get_hdr_field: <To> [50]; uri=[sip:1020101@67.102.229.3]
0(7855) DEBUG: to body ["1020101"<sip:1020101@67.102.229.3>]
0(7855) get_hdr_field: cseq <CSeq>: <1> <INVITE>
0(7855) parse_headers: flags=8
0(7855) DEBUG: t_reply_matching: hash 34965 label 239374468 branch 0
0(7855) DEBUG:tm:REF_UNSAFE: after is 1
0(7855) DEBUG: t_reply_matching: reply matched (T=0x801f4b0d8)!
0(7855) DEBUG: t_check: end=0x801f4b0d8
0(7855) DEBUG:tm:reply_received: org. status uas=407, uac[0]=408 local=0
is_invite=1)
0(7855) parse_headers: flags=8
0(7855) DEBUG:tm:build_local: using FROM=<From:
"Xantek"<sip:1020101@67.102.229.3>;tag=045b4172
, TO=<To:
"1020101"<sip:1020101@67.102.229.3>;tag=03422a48
, CSEQ_N=<CSeq: 1>
0(7855) DEBUG:tm:t_should_relay_response: T_code=407,
new_code=487
0(7855) DEBUG:tm:relay_reply: branch=0, save=0, relay=-1
0(7855) DEBUG:tm:UNREF_UNSAFE: after is 0
0(7855) DEBUG:destroy_avp_list: destroying list 0x0
0(7855) receive_msg: cleaning up
0(7855) SIP Request:
0(7855) method: <ACK>
0(7855) uri: <sip:1020101@67.102.229.3>
0(7855) version: <SIP/2.0>
0(7855) parse_headers: flags=2
0(7855) Found param type 232, <branch> =
<z9hG4bK-d87543-e004ef19dd229e0e-1--d87543->; state=6
0(7855) Found param type 235, <rport> = <n/a>; state=17
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=2
0(7855) parse_headers: this is the first via
0(7855) After parse_msg...
0(7855) preparing to run routing scripts...
0(7855) DEBUG : sl_filter_ACK: to late to be a local ACK!
0(7855) parse_headers: flags=100
0(7855) DEBUG: add_param: tag=as499a9c72
0(7855) DEBUG:parse_to:end of header reached, state=29
0(7855) DBUG:parse_to: display={"1020101"}, ruri={sip:1020101@67.102.229.3}
0(7855) DEBUG: get_hdr_field: <To> [52]; uri=[sip:1020101@67.102.229.3]
0(7855) DEBUG: to body ["1020101"<sip:1020101@67.102.229.3>]
0(7855) get_hdr_field: cseq <CSeq>: <1> <ACK>
0(7855) DEBUG: get_hdr_body : content_length=0
0(7855) found end of header
0(7855) DEBUG: is_maxfwd_present: max_forwards header not found!
0(7855) DEBUG: add_param: tag=045b4172
0(7855) DEBUG:parse_to:end of header reached, state=29
0(7855) DBUG:parse_to: display={"Xantek"}, ruri={sip:1020101@67.102.229.3}
0(7855) parse_headers: flags=200
0(7855) find_first_route: No Route headers found
0(7855) loose_route: There is no Route HF
0(7855) grep_sock_info - checking if host==us: 12==12 && [67.102.229.3]
== [67.102.229.3]
0(7855) grep_sock_info - checking if port 5060 matches port 5060
0(7855) grep_sock_info - checking if host==us: 12==12 && [67.102.229.3]
== [67.102.229.3]
0(7855) grep_sock_info - checking if port 5060 matches port 5060
0(7855) lookup(): '1020101' Not found in usrloc
0(7855) grep_sock_info - checking if host==us: 12==12 && [67.102.229.3]
== [67.102.229.3]
0(7855) grep_sock_info - checking if port 5060 matches port 5060
0(7855) rewrite_uri: Rewriting Request-URI with
'sip:1020101@67.188.231.188:42749;rinstance=1e89b57f830c50f7'
0(7855) parse_headers: flags=ffffffffffffffff
0(7855) DEBUG: t_newtran: T on entrance=0xffffffffffffffff
0(7855) parse_headers: flags=ffffffffffffffff
0(7855) parse_headers: flags=78
0(7855) t_lookup_request: start searching: hash=34965, isACK=1
0(7855) DEBUG: RFC3261 transaction matched,
tid=-d87543-e004ef19dd229e0e-1--d87543-
0(7855) DEBUG:tm:REF_UNSAFE: after is 1
0(7855) DEBUG: t_lookup_request: transaction found (T=0x801f4b0d8)
0(7855) DEBUG: cleanup_uac_timers: RETR/FR timers reset
0(7855) DEBUG: add_to_tail_of_timer[2]: 0x801f4b158 (54)
0(7855) DEBUG:tm:UNREF_UNSAFE: after is 0
0(7855) DEBUG:destroy_avp_list: destroying list 0x0
0(7855) receive_msg: cleaning up
0(7855) SIP Request:
0(7855) method: <INVITE>
0(7855) uri: <sip:1020101@67.102.229.3>
0(7855) version: <SIP/2.0>
0(7855) parse_headers: flags=2
0(7855) Found param type 232, <branch> =
<z9hG4bK-d87543-c535a22e8d568d14-1--d87543->; state=6
0(7855) Found param type 235, <rport> = <n/a>; state=17
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=2
0(7855) parse_headers: this is the first via
0(7855) After parse_msg...
0(7855) preparing to run routing scripts...
0(7855) parse_headers: flags=100
0(7855) DEBUG:maxfwd:is_maxfwd_present: value = 70
0(7855) parse_headers: flags=10
0(7855) DEBUG:parse_to:end of header reached, state=10
0(7855) DBUG:parse_to: display={"1020101"}, ruri={sip:1020101@67.102.229.3}
0(7855) DEBUG: get_hdr_field: <To> [37]; uri=[sip:1020101@67.102.229.3]
0(7855) DEBUG: to body ["1020101"<sip:1020101@67.102.229.3>
]
0(7855) DEBUG: add_param: tag=045b4172
0(7855) DEBUG:parse_to:end of header reached, state=29
0(7855) DBUG:parse_to: display={"Xantek"}, ruri={sip:1020101@67.102.229.3}
0(7855) parse_headers: flags=200
0(7855) get_hdr_field: cseq <CSeq>: <2> <INVITE>
0(7855) DEBUG: get_hdr_body : content_length=476
0(7855) found end of header
0(7855) find_first_route: No Route headers found
0(7855) loose_route: There is no Route HF
0(7855) grep_sock_info - checking if host==us: 12==12 && [67.102.229.3]
== [67.102.229.3]
0(7855) grep_sock_info - checking if port 5060 matches port 5060
0(7855) grep_sock_info - checking if host==us: 12==12 && [67.102.229.3]
== [67.102.229.3]
0(7855) grep_sock_info - checking if port 5060 matches port 5060
0(7855) lookup(): '1020101' Not found in usrloc
0(7855) grep_sock_info - checking if host==us: 12==12 && [67.102.229.3]
== [67.102.229.3]
0(7855) grep_sock_info - checking if port 5060 matches port 5060
0(7855) rewrite_uri: Rewriting Request-URI with
'sip:1020101@67.188.231.188:42749;rinstance=1e89b57f830c50f7'
0(7855) parse_headers: flags=ffffffffffffffff
0(7855) DEBUG: t_newtran: T on entrance=0xffffffffffffffff
0(7855) parse_headers: flags=ffffffffffffffff
0(7855) parse_headers: flags=78
0(7855) t_lookup_request: start searching: hash=34962, isACK=0
0(7855) DEBUG: RFC3261 transaction matching failed
0(7855) DEBUG: t_lookup_request: no transaction found
0(7855) parse_headers: flags=ffffffffffffffff
0(7855) check_via_address(67.188.231.188, 67.188.231.188, 0)
0(7855) WARNING:vqm_resize: resize(0) called
0(7855) DEBUG:tm:_reply_light: reply sent out. buf=0x62dcf8: SIP/2.0
1..., shmem=0x801f4e420: SIP/2.0 1
0(7855) DEBUG:tm:_reply_light: finished
0(7855) DEBUG: mk_proxy: doing DNS lookup...
0(7855) check_via_address(67.188.231.188, 67.188.231.188, 0)
0(7855) DBG:check_against_rule_list: using list dns
0(7855) DEBUG:tm:set_timer: relative timeout is 500000
0(7855) DEBUG: add_to_tail_of_timer[4]: 0x801f550c8 (49600000)
0(7855) DEBUG:tm:set_timer: relative timeout is 30
0(7855) DEBUG: add_to_tail_of_timer[0]: 0x801f550f8 (79)
0(7855) DEBUG:tm:t_relay_to: new transaction fwd'ed
0(7855) DEBUG:tm:UNREF_UNSAFE: after is 0
0(7855) DEBUG:destroy_avp_list: destroying list 0x0
0(7855) receive_msg: cleaning up
1(7856) DEBUG: timer routine:4,tl=0x801f4b4b0 next=0x801f4b3c0,
timeout=49500000
1(7856) DEBUG: timer routine:4,tl=0x801f4b3c0 next=0x801f4b220,
timeout=49500000
1(7856) DEBUG: timer routine:4,tl=0x801f4b220 next=0x0, timeout=49500000
0(7855) SIP Reply (status):
0(7855) version: <SIP/2.0>
0(7855) status: <180>
0(7855) reason: <Ringing>
0(7855) parse_headers: flags=2
0(7855) Found param type 232, <branch> = <z9hG4bK2988.3de53f62.0>; state=16
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=2
0(7855) parse_headers: this is the first via
0(7855) After parse_msg...
0(7855) DEBUG:forward_reply: found module tm, passing reply to it
0(7855) DEBUG: t_check: start=0xffffffffffffffff
0(7855) parse_headers: flags=22
0(7855) Found param type 232, <branch> =
<z9hG4bK-d87543-c535a22e8d568d14-1--d87543->; state=6
0(7855) Found param type 235, <rport> = <42749>; state=16
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=22
0(7855) parse_headers: this is the second via
0(7855) DEBUG: add_param: tag=2a63bc63
0(7855) DEBUG:parse_to:end of header reached, state=29
0(7855) DBUG:parse_to: display={"1020101"}, ruri={sip:1020101@67.102.229.3}
0(7855) DEBUG: get_hdr_field: <To> [50]; uri=[sip:1020101@67.102.229.3]
0(7855) DEBUG: to body ["1020101"<sip:1020101@67.102.229.3>]
0(7855) get_hdr_field: cseq <CSeq>: <2> <INVITE>
0(7855) parse_headers: flags=8
0(7855) DEBUG: t_reply_matching: hash 34962 label 653483731 branch 0
0(7855) DEBUG:tm:REF_UNSAFE: after is 1
0(7855) DEBUG: t_reply_matching: reply matched (T=0x801f54ea8)!
0(7855) DEBUG: t_check: end=0x801f54ea8
0(7855) DEBUG:tm:reply_received: org. status uas=100, uac[0]=0 local=0
is_invite=1)
0(7855) DEBUG:tm:t_should_relay_response: T_code=100, new_code=180
0(7855) DEBUG:tm:relay_reply: branch=0, save=0, relay=0
0(7855) old size: 554, new size: 493
0(7855) build_res_from_sip_res: copied size: orig:82, new: 21, rest: 472
msg=
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP
67.188.231.188:42749;branch=z9hG4bK-d87543-c535a22e8d568d14-1--d87543-;rport=42749
Record-Route: <sip:67.102.229.3;lr;ftag=045b4172>
Contact: <sip:1020101@67.188.231.188:42749;rinstance=1e89b57f830c50f7>
To: "1020101"<sip:1020101@67.102.229.3>;tag=2a63bc63
From: "Xantek"<sip:1020101@67.102.229.3>;tag=045b4172
Call-ID: YjgxM2RlZmM4MjRhMDYxN2YwYjI2MDdmZWZjMGY4NTY.
CSeq: 2 INVITE
User-Agent: eyeBeam release 1009l stamp 37966
Content-Length: 0
0(7855) DEBUG:tm:relay_reply: sent buf=0x62d678: SIP/2.0 1...,
shmem=0x801f4e420: SIP/2.0 1
0(7855) DEBUG:tm:set_timer: relative timeout is 20
0(7855) DEBUG: add_to_tail_of_timer[1]: 0x801f550f8 (69)
0(7855) DEBUG:tm:UNREF_UNSAFE: after is 0
0(7855) DEBUG:destroy_avp_list: destroying list 0x0
0(7855) receive_msg: cleaning up
1(7856) DEBUG: timer routine:4,tl=0x801f550c8 next=0x0, timeout=49600000
0(7855) SIP Request:
0(7855) method: <CANCEL>
0(7855) uri: <sip:1020101@67.102.229.3>
0(7855) version: <SIP/2.0>
0(7855) parse_headers: flags=2
0(7855) Found param type 232, <branch> =
<z9hG4bK-d87543-c535a22e8d568d14-1--d87543->; state=6
0(7855) Found param type 235, <rport> = <n/a>; state=17
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=2
0(7855) parse_headers: this is the first via
0(7855) After parse_msg...
0(7855) preparing to run routing scripts...
0(7855) parse_headers: flags=100
0(7855) DEBUG:parse_to:end of header reached, state=10
0(7855) DBUG:parse_to: display={"1020101"}, ruri={sip:1020101@67.102.229.3}
0(7855) DEBUG: get_hdr_field: <To> [37]; uri=[sip:1020101@67.102.229.3]
0(7855) DEBUG: to body ["1020101"<sip:1020101@67.102.229.3>
]
0(7855) get_hdr_field: cseq <CSeq>: <2> <CANCEL>
0(7855) DEBUG: get_hdr_body : content_length=0
0(7855) found end of header
0(7855) DEBUG: is_maxfwd_present: max_forwards header not found!
0(7855) DEBUG: add_param: tag=045b4172
0(7855) DEBUG:parse_to:end of header reached, state=29
0(7855) DBUG:parse_to: display={"Xantek"}, ruri={sip:1020101@67.102.229.3}
0(7855) parse_headers: flags=200
0(7855) find_first_route: No Route headers found
0(7855) loose_route: There is no Route HF
0(7855) grep_sock_info - checking if host==us: 12==12 && [67.102.229.3]
== [67.102.229.3]
0(7855) grep_sock_info - checking if port 5060 matches port 5060
0(7855) grep_sock_info - checking if host==us: 12==12 && [67.102.229.3]
== [67.102.229.3]
0(7855) grep_sock_info - checking if port 5060 matches port 5060
0(7855) lookup(): '1020101' Not found in usrloc
0(7855) grep_sock_info - checking if host==us: 12==12 && [67.102.229.3]
== [67.102.229.3]
0(7855) grep_sock_info - checking if port 5060 matches port 5060
0(7855) rewrite_uri: Rewriting Request-URI with
'sip:1020101@67.188.231.188:42749;rinstance=1e89b57f830c50f7'
0(7855) parse_headers: flags=ffffffffffffffff
0(7855) DEBUG: t_newtran: T on entrance=0xffffffffffffffff
0(7855) parse_headers: flags=ffffffffffffffff
0(7855) parse_headers: flags=78
0(7855) t_lookup_request: start searching: hash=34962, isACK=0
0(7855) DEBUG: RFC3261 transaction matching failed
0(7855) DEBUG: t_lookup_request: no transaction found
0(7855) DEBUG: t_lookupOriginalT: searching on hash entry 34962
0(7855) DEBUG: RFC3261 transaction matched,
tid=-d87543-c535a22e8d568d14-1--d87543-
0(7855) DEBUG: t_lookupOriginalT: canceled transaction found (0x801f54ea8)!
0(7855) DEBUG:tm:REF_UNSAFE: after is 1
0(7855) DEBUG: t_lookupOriginalT completed
0(7855) check_via_address(67.188.231.188, 67.188.231.188, 0)
0(7855) DEBUG:tm:set_timer: relative timeout is 500000
0(7855) DEBUG: add_to_tail_of_timer[4]: 0x801f583f8 (50600000)
0(7855) DEBUG:tm:set_timer: relative timeout is 30
0(7855) DEBUG: add_to_tail_of_timer[0]: 0x801f58428 (80)
0(7855) DEBUG: e2e_cancel: e2e cancel proceeding
0(7855) parse_headers: flags=ffffffffffffffff
0(7855) check_via_address(67.188.231.188, 67.188.231.188, 0)
0(7855) WARNING:vqm_resize: resize(0) called
0(7855) DEBUG:tm:_reply_light: reply sent out. buf=0x62dcf8: SIP/2.0
2..., shmem=0x801f57da0: SIP/2.0 2
0(7855) DEBUG:tm:_reply_light: finished
0(7855) DEBUG:tm:t_relay_to: new transaction fwd'ed
0(7855) DEBUG:tm:UNREF_UNSAFE: after is 0
0(7855) DEBUG:tm:UNREF_UNSAFE: after is 0
0(7855) DEBUG:destroy_avp_list: destroying list 0x0
0(7855) receive_msg: cleaning up
0(7855) SIP Reply (status):
0(7855) version: <SIP/2.0>
0(7855) status: <200>
0(7855) reason: <OK>
0(7855) parse_headers: flags=2
0(7855) Found param type 232, <branch> = <z9hG4bK2988.3de53f62.0>; state=16
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=2
0(7855) parse_headers: this is the first via
0(7855) After parse_msg...
0(7855) DEBUG:forward_reply: found module tm, passing reply to it
0(7855) DEBUG: t_check: start=0xffffffffffffffff
0(7855) parse_headers: flags=22
0(7855) Found param type 232, <branch> =
<z9hG4bK-d87543-c535a22e8d568d14-1--d87543->; state=6
0(7855) Found param type 235, <rport> = <42749>; state=16
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=22
0(7855) parse_headers: this is the second via
0(7855) DEBUG: add_param: tag=2a63bc63
0(7855) DEBUG:parse_to:end of header reached, state=29
0(7855) DBUG:parse_to: display={"1020101"}, ruri={sip:1020101@67.102.229.3}
0(7855) DEBUG: get_hdr_field: <To> [50]; uri=[sip:1020101@67.102.229.3]
0(7855) DEBUG: to body ["1020101"<sip:1020101@67.102.229.3>]
0(7855) get_hdr_field: cseq <CSeq>: <2> <CANCEL>
0(7855) DEBUG: t_reply_matching: hash 34962 label 653483731 branch 0
0(7855) DEBUG:tm:REF_UNSAFE: after is 1
0(7855) DEBUG: t_reply_matching: reply matched (T=0x801f581d8)!
0(7855) DEBUG: t_check: end=0x801f581d8
0(7855) DEBUG:tm:reply_received: org. status uas=200, uac[0]=0 local=0
is_invite=0)
0(7855) DEBUG:tm:t_should_relay_response: T_code=200, new_code=200
0(7855) DEBUG:tm:relay_reply: branch=0, save=0, relay=-1
0(7855) DEBUG: add_to_tail_of_timer[2]: 0x801f58258 (55)
0(7855) DEBUG: cleanup_uac_timers: RETR/FR timers reset
0(7855) DEBUG:tm:UNREF_UNSAFE: after is 0
0(7855) DEBUG:destroy_avp_list: destroying list 0x0
0(7855) receive_msg: cleaning up
0(7855) SIP Reply (status):
0(7855) version: <SIP/2.0>
0(7855) status: <487>
0(7855) reason: <Request Terminated>
0(7855) parse_headers: flags=2
0(7855) Found param type 232, <branch> = <z9hG4bK2988.3de53f62.0>; state=16
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=2
0(7855) parse_headers: this is the first via
0(7855) After parse_msg...
0(7855) DEBUG:forward_reply: found module tm, passing reply to it
0(7855) DEBUG: t_check: start=0xffffffffffffffff
0(7855) parse_headers: flags=22
0(7855) Found param type 232, <branch> =
<z9hG4bK-d87543-c535a22e8d568d14-1--d87543->; state=6
0(7855) Found param type 235, <rport> = <42749>; state=16
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=22
0(7855) parse_headers: this is the second via
0(7855) DEBUG: add_param: tag=2a63bc63
0(7855) DEBUG:parse_to:end of header reached, state=29
0(7855) DBUG:parse_to: display={"1020101"}, ruri={sip:1020101@67.102.229.3}
0(7855) DEBUG: get_hdr_field: <To> [50]; uri=[sip:1020101@67.102.229.3]
0(7855) DEBUG: to body ["1020101"<sip:1020101@67.102.229.3>]
0(7855) get_hdr_field: cseq <CSeq>: <2> <INVITE>
0(7855) parse_headers: flags=8
0(7855) DEBUG: t_reply_matching: hash 34962 label 653483731 branch 0
0(7855) DEBUG:tm:REF_UNSAFE: after is 1
0(7855) DEBUG: t_reply_matching: reply matched (T=0x801f54ea8)!
0(7855) DEBUG: t_check: end=0x801f54ea8
0(7855) DEBUG:tm:reply_received: org. status uas=180, uac[0]=180 local=0
is_invite=1)
0(7855) parse_headers: flags=8
0(7855) DEBUG:tm:build_local: using FROM=<From:
"Xantek"<sip:1020101@67.102.229.3>;tag=045b4172
, TO=<To:
"1020101"<sip:1020101@67.102.229.3>;tag=2a63bc63
, CSEQ_N=<CSeq: 2>
0(7855) DEBUG:tm:t_should_relay_response: T_code=180,
new_code=487
0(7855) DEBUG:tm:t_pick_branch: picked branch 0, code 487
0(7855) DEBUG:t_check_status: checked status is <487>
0(7855) DEBUG:tm:relay_reply: branch=0, save=0, relay=0
0(7855) old size: 442, new size: 381
0(7855) build_res_from_sip_res: copied size: orig:93, new: 32, rest: 349
msg=
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP
67.188.231.188:42749;branch=z9hG4bK-d87543-c535a22e8d568d14-1--d87543-;rport=42749
To: "1020101"<sip:1020101@67.102.229.3>;tag=2a63bc63
From: "Xantek"<sip:1020101@67.102.229.3>;tag=045b4172
Call-ID: YjgxM2RlZmM4MjRhMDYxN2YwYjI2MDdmZWZjMGY4NTY.
CSeq: 2 INVITE
User-Agent: eyeBeam release 1009l stamp 37966
Content-Length: 0
0(7855) DEBUG:tm:set_timer: relative timeout is 500000
0(7855) DEBUG: add_to_tail_of_timer[4]: 0x801f54ff0 (50700000)
0(7855) DEBUG:tm:set_timer: relative timeout is 30
0(7855) DEBUG: add_to_tail_of_timer[0]: 0x801f55020 (80)
0(7855) DEBUG:tm:relay_reply: sent buf=0x62dcf8: SIP/2.0 4...,
shmem=0x801f546f8: SIP/2.0 4
0(7855) DEBUG: cleanup_uac_timers: RETR/FR timers reset
0(7855) DEBUG:tm:UNREF_UNSAFE: after is 0
0(7855) DEBUG:destroy_avp_list: destroying list 0x0
0(7855) receive_msg: cleaning up
0(7855) SIP Request:
0(7855) method: <ACK>
0(7855) uri: <sip:1020101@67.102.229.3>
0(7855) version: <SIP/2.0>
0(7855) parse_headers: flags=2
0(7855) Found param type 232, <branch> =
<z9hG4bK-d87543-c535a22e8d568d14-1--d87543->; state=6
0(7855) Found param type 235, <rport> = <n/a>; state=17
0(7855) end of header reached, state=5
0(7855) parse_headers: Via found, flags=2
0(7855) parse_headers: this is the first via
0(7855) After parse_msg...
0(7855) preparing to run routing scripts...
0(7855) DEBUG : sl_filter_ACK: to late to be a local ACK!
0(7855) parse_headers: flags=100
0(7855) DEBUG: add_param: tag=2a63bc63
0(7855) DEBUG:parse_to:end of header reached, state=29
0(7855) DBUG:parse_to: display={"1020101"}, ruri={sip:1020101@67.102.229.3}
0(7855) DEBUG: get_hdr_field: <To> [50]; uri=[sip:1020101@67.102.229.3]
0(7855) DEBUG: to body ["1020101"<sip:1020101@67.102.229.3>]
0(7855) get_hdr_field: cseq <CSeq>: <2> <ACK>
0(7855) DEBUG: get_hdr_body : content_length=0
0(7855) found end of header
0(7855) DEBUG: is_maxfwd_present: max_forwards header not found!
0(7855) DEBUG: add_param: tag=045b4172
0(7855) DEBUG:parse_to:end of header reached, state=29
0(7855) DBUG:parse_to: display={"Xantek"}, ruri={sip:1020101@67.102.229.3}
0(7855) parse_headers: flags=200
0(7855) find_first_route: No Route headers found
0(7855) loose_route: There is no Route HF
0(7855) grep_sock_info - checking if host==us: 12==12 && [67.102.229.3]
== [67.102.229.3]
0(7855) grep_sock_info - checking if port 5060 matches port 5060
0(7855) grep_sock_info - checking if host==us: 12==12 && [67.102.229.3]
== [67.102.229.3]
0(7855) grep_sock_info - checking if port 5060 matches port 5060
0(7855) lookup(): '1020101' Not found in usrloc
0(7855) grep_sock_info - checking if host==us: 12==12 && [67.102.229.3]
== [67.102.229.3]
0(7855) grep_sock_info - checking if port 5060 matches port 5060
0(7855) rewrite_uri: Rewriting Request-URI with
'sip:1020101@67.188.231.188:42749;rinstance=1e89b57f830c50f7'
0(7855) parse_headers: flags=ffffffffffffffff
0(7855) DEBUG: t_newtran: T on entrance=0xffffffffffffffff
0(7855) parse_headers: flags=ffffffffffffffff
0(7855) parse_headers: flags=78
0(7855) t_lookup_request: start searching: hash=34962, isACK=1
0(7855) DEBUG: RFC3261 transaction matched,
tid=-d87543-c535a22e8d568d14-1--d87543-
0(7855) DEBUG:tm:REF_UNSAFE: after is 1
0(7855) DEBUG: t_lookup_request: transaction found (T=0x801f54ea8)
0(7855) DEBUG: cleanup_uac_timers: RETR/FR timers reset
0(7855) DEBUG: add_to_tail_of_timer[2]: 0x801f54f28 (55)
0(7855) DEBUG:tm:UNREF_UNSAFE: after is 0
0(7855) DEBUG:destroy_avp_list: destroying list 0x0
0(7855) receive_msg: cleaning up
1(7856) DEBUG: timer routine:4,tl=0x801f583f8 next=0x0, timeout=50600000
1(7856) DEBUG: timer routine:4,tl=0x801f54ff0 next=0x0, timeout=50700000
^C 0(7855) INT received, program terminates
0(7855) INFO: signal 2 received
0(7855) Memory status (pkg):
0(7855) fm_status (0x615be0):
0(7855) heap size= 1048576
0(7855) used= 56472, used+overhead=95544, free=953032
0(7855) max used (+overhead)= 95544
Anybody see what I an doing wrong?
--
Bill Neely
Xantek, Inc.
1-866-553-3833
1-702-874-3833