rendered paste body 0(18918) SIP Request:
0(18918) method: <INVITE>
0(18918) uri: <sip:01125614265@10.10.3.190>
0(18918) version: <SIP/2.0>
0(18918) parse_headers: flags=2
0(18918) get_hdr_field: cseq <CSeq>: <1> <INVITE>
0(18918) Found param type 232, <branch> = <z9hG4bK16edfc0f-5035-dc11-82b5-0013d44f0ad0>; state=6
0(18918) Found param type 235, <rport> = <n/a>; state=17
0(18918) end of header reached, state=5
0(18918) parse_headers: Via found, flags=2
0(18918) parse_headers: this is the first via
0(18918) After parse_msg...
0(18918) preparing to run routing scripts...
0(18918) parse_headers: flags=100
0(18918) DEBUG:parse_to:end of header reached, state=10
0(18918) DBUG:parse_to: display={}, ruri={sip:01125614265@10.10.3.190}
0(18918) DEBUG: get_hdr_field: <To> [31]; uri=[sip:01125614265@10.10.3.190]
0(18918) DEBUG: to body [<sip:01125614265@10.10.3.190>
]
0(18918) DEBUG: get_hdr_body : content_length=383
0(18918) DEBUG:maxfwd:is_maxfwd_present: value = 70
0(18918) parse_headers: flags=200
0(18918) is_preloaded: Yes
0(18918) grep_sock_info - checking if host==us: 11==11 && [10.10.3.190] == [10.10.3.190]
0(18918) grep_sock_info - checking if port 5060 matches port 5060
0(18918) after_loose: Topmost route URI: 'sip:10.10.3.190:5060;lr' is me
0(18918) parse_headers: flags=200
0(18918) found end of header
0(18918) find_next_route: No next Route HF found
0(18918) after_loose: No next URI found
0(18918) CALL: Call to international number
0(18918) DEBUG: add_param: tag=a02cfc0f-5035-dc11-82b5-0013d44f0ad0
0(18918) DEBUG:parse_to:end of header reached, state=29
0(18918) DBUG:parse_to: display={"paulo arruda"}, ruri={sip:paulo@10.10.3.190}
0(18918) DEBUG: t_newtran: T on entrance=0xffffffff
0(18918) parse_headers: flags=ffffffffffffffff
0(18918) parse_headers: flags=78
0(18918) t_lookup_request: start searching: hash=613, isACK=0
0(18918) DEBUG: RFC3261 transaction matching failed
0(18918) DEBUG: t_lookup_request: no transaction found
0(18918) parse_headers: flags=ffffffffffffffff
0(18918) check_via_address(10.10.2.33, 10.10.2.33, 0)
0(18918) WARNING:vqm_resize: resize(0) called
0(18918) DEBUG:tm:_reply_light: reply sent out. buf=0x817da60: SIP/2.0 1..., shmem=0xb5c1c668: SIP/2.0 1
0(18918) DEBUG:tm:_reply_light: finished
0(18918) DEBUG: mk_proxy: doing DNS lookup...
0(18918) check_via_address(10.10.2.33, 10.10.2.33, 0)
0(18918) DBG:check_against_rule_list: using list dns
0(18918) DEBUG:tm:set_timer: relative timeout is 500000
0(18918) DEBUG: add_to_tail_of_timer[4]: 0xb5c1ac94 (47000000)
0(18918) DEBUG:tm:set_timer: relative timeout is 25
0(18918) DEBUG: add_to_tail_of_timer[0]: 0xb5c1acb0 (71)
0(18918) DEBUG:tm:t_relay_to: new transaction fwd'ed
0(18918) DEBUG:tm:UNREF_UNSAFE: after is 0
0(18918) DEBUG:destroy_avp_list: destroying list (nil)
0(18918) receive_msg: cleaning up
0(18918) SIP Reply (status):
0(18918) version: <SIP/2.0>
0(18918) status: <404>
0(18918) reason: <Not Found>
0(18918) parse_headers: flags=2
0(18918) Found param type 232, <branch> = <z9hG4bK562.62eceb23.0>; state=6
0(18918) Found param type 234, <received> = <10.10.3.190>; state=16
0(18918) end of header reached, state=5
0(18918) parse_headers: Via found, flags=2
0(18918) parse_headers: this is the first via
0(18918) After parse_msg...
0(18918) DEBUG:forward_reply: found module tm, passing reply to it
0(18918) DEBUG: t_check: start=0xffffffff
0(18918) parse_headers: flags=22
0(18918) Found param type 232, <branch> = <z9hG4bK16edfc0f-5035-dc11-82b5-0013d44f0ad0>; state=6
0(18918) Found param type 235, <rport> = <5063>; state=16
0(18918) end of header reached, state=5
0(18918) parse_headers: Via found, flags=22
0(18918) parse_headers: this is the second via
0(18918) DEBUG: add_param: tag=as004357fd
0(18918) DEBUG:parse_to:end of header reached, state=29
0(18918) DBUG:parse_to: display={}, ruri={sip:01125614265@10.10.3.190}
0(18918) DEBUG: get_hdr_field: <To> [46]; uri=[sip:01125614265@10.10.3.190]
0(18918) DEBUG: to body [<sip:01125614265@10.10.3.190>]
0(18918) get_hdr_field: cseq <CSeq>: <1> <INVITE>
0(18918) parse_headers: flags=8
0(18918) DEBUG: t_reply_matching: hash 613 label 851365414 branch 0
0(18918) DEBUG:tm:REF_UNSAFE: after is 1
0(18918) DEBUG: t_reply_matching: reply matched (T=0xb5c1ab48)!
0(18918) DEBUG: t_check: end=0xb5c1ab48
0(18918) DEBUG:tm:reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1)
0(18918) parse_headers: flags=8
0(18918) DEBUG:tm:build_local: using FROM=<From: "paulo arruda" <sip:paulo@10.10.3.190>;tag=a02cfc0f-5035-dc11-82b5-0013d44f0ad0
>, TO=<To: <sip:01125614265@10.10.3.190>;tag=as004357fd
>, CSEQ_N=<CSeq: 1>
0(18918) DEBUG:tm:t_should_relay_response: T_code=100, new_code=404
0(18918) DEBUG:tm:t_pick_branch: picked branch 0, code 404
0(18918) DEBUG:tm:t_should_relay_response: dns-failover test: branch=0, last_recv=404, flags=2
0(18918) ******* setting for branch 0 flags 0
0(18918) INFO: CALL TO VOICEMAIL 0(18918) DEBUG: mk_proxy: doing DNS lookup...
0(18918) check_via_address(10.10.2.33, 10.10.2.33, 0)
0(18918) DBG:check_against_rule_list: using list dns
0(18918) DEBUG:tm:set_timer: relative timeout is 500000
0(18918) DEBUG: add_to_tail_of_timer[4]: 0xb5c1ada4 (47000000)
0(18918) DEBUG:tm:set_timer: relative timeout is 25
0(18918) DEBUG: add_to_tail_of_timer[0]: 0xb5c1adc0 (71)
0(18918) DEBUG:tm:relay_reply: branch=0, save=1, relay=-1
0(18918) DEBUG:tm:UNREF_UNSAFE: after is 0
0(18918) DEBUG:destroy_avp_list: destroying list (nil)
0(18918) receive_msg: cleaning up
0(18918) SIP Reply (status):
0(18918) version: <SIP/2.0>
0(18918) status: <404>
0(18918) reason: <Not Found>
0(18918) parse_headers: flags=2
0(18918) Found param type 232, <branch> = <z9hG4bK562.62eceb23.1>; state=6
0(18918) Found param type 234, <received> = <10.10.3.190>; state=16
0(18918) end of header reached, state=5
0(18918) parse_headers: Via found, flags=2
0(18918) parse_headers: this is the first via
0(18918) After parse_msg...
0(18918) DEBUG:forward_reply: found module tm, passing reply to it
0(18918) DEBUG: t_check: start=0xffffffff
0(18918) parse_headers: flags=22
0(18918) Found param type 232, <branch> = <z9hG4bK16edfc0f-5035-dc11-82b5-0013d44f0ad0>; state=6
0(18918) Found param type 235, <rport> = <5063>; state=16
0(18918) end of header reached, state=5
0(18918) parse_headers: Via found, flags=22
0(18918) parse_headers: this is the second via
0(18918) DEBUG: add_param: tag=as2437f64c
0(18918) DEBUG:parse_to:end of header reached, state=29
0(18918) DBUG:parse_to: display={}, ruri={sip:01125614265@10.10.3.190}
0(18918) DEBUG: get_hdr_field: <To> [46]; uri=[sip:01125614265@10.10.3.190]
0(18918) DEBUG: to body [<sip:01125614265@10.10.3.190>]
0(18918) get_hdr_field: cseq <CSeq>: <1> <INVITE>
0(18918) parse_headers: flags=8
0(18918) DEBUG: t_reply_matching: hash 613 label 851365414 branch 1
0(18918) DEBUG:tm:REF_UNSAFE: after is 1
0(18918) DEBUG: t_reply_matching: reply matched (T=0xb5c1ab48)!
0(18918) DEBUG: t_check: end=0xb5c1ab48
0(18918) DEBUG:tm:reply_received: org. status uas=100, uac[1]=0 local=0 is_invite=1)
0(18918) parse_headers: flags=8
0(18918) DEBUG:tm:build_local: using FROM=<From: "paulo arruda" <sip:paulo@10.10.3.190>;tag=a02cfc0f-5035-dc11-82b5-0013d44f0ad0
>, TO=<To: <sip:01125614265@10.10.3.190>;tag=as2437f64c
>, CSEQ_N=<CSeq: 1>
0(18918) DEBUG:tm:t_should_relay_response: T_code=100, new_code=404
0(18918) DEBUG:tm:t_pick_branch: picked branch 1, code 404
0(18918) DEBUG:tm:t_should_relay_response: dns-failover test: branch=1, last_recv=404, flags=2
0(18918) DEBUG:tm:relay_reply: branch=1, save=0, relay=1
0(18918) old size: 521, new size: 441
0(18918) build_res_from_sip_res: copied size: orig:103, new: 23, rest: 418 msg=
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP 10.10.2.33:5063;branch=z9hG4bK16edfc0f-5035-dc11-82b5-0013d44f0ad0;rport=5063
From: "paulo arruda" <sip:paulo@10.10.3.190>;tag=a02cfc0f-5035-dc11-82b5-0013d44f0ad0
To: <sip:01125614265@10.10.3.190>;tag=as2437f64c
Call-ID: 4c21fc0f-5035-dc11-82b5-0013d44f0ad0@gsl024
CSeq: 1 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Content-Length: 0
0(18918) DEBUG:tm:set_timer: relative timeout is 500000
0(18918) DEBUG: add_to_tail_of_timer[4]: 0xb5c1ac10 (47000000)
0(18918) DEBUG:tm:set_timer: relative timeout is 25
0(18918) DEBUG: add_to_tail_of_timer[0]: 0xb5c1ac2c (71)
0(18918) DEBUG:tm:relay_reply: sent buf=0x817da60: SIP/2.0 4..., shmem=0xb5c1c668: SIP/2.0 4
0(18918) DEBUG: cleanup_uac_timers: RETR/FR timers reset
0(18918) DEBUG:tm:UNREF_UNSAFE: after is 0
0(18918) DEBUG:destroy_avp_list: destroying list (nil)
0(18918) receive_msg: cleaning up
0(18918) SIP Request:
0(18918) method: <ACK>
0(18918) uri: <sip:01125614265@10.10.3.190>
0(18918) version: <SIP/2.0>
0(18918) parse_headers: flags=2
0(18918) get_hdr_field: cseq <CSeq>: <1> <ACK>
0(18918) Found param type 232, <branch> = <z9hG4bK16edfc0f-5035-dc11-82b5-0013d44f0ad0>; state=6
0(18918) Found param type 235, <rport> = <n/a>; state=17
0(18918) end of header reached, state=5
0(18918) parse_headers: Via found, flags=2
0(18918) parse_headers: this is the first via
0(18918) After parse_msg...
0(18918) preparing to run routing scripts...
0(18918) DEBUG : sl_filter_ACK: to late to be a local ACK!
0(18918) parse_headers: flags=100
0(18918) DEBUG: add_param: tag=as2437f64c
0(18918) DEBUG:parse_to:end of header reached, state=29
0(18918) DBUG:parse_to: display={}, ruri={sip:01125614265@10.10.3.190}
0(18918) DEBUG: get_hdr_field: <To> [46]; uri=[sip:01125614265@10.10.3.190]
0(18918) DEBUG: to body [<sip:01125614265@10.10.3.190>]
0(18918) DEBUG: get_hdr_body : content_length=0
0(18918) DEBUG:maxfwd:is_maxfwd_present: value = 70
0(18918) parse_headers: flags=200
0(18918) is_preloaded: No
0(18918) grep_sock_info - checking if host==us: 11==11 && [10.10.3.190] == [10.10.3.190]
0(18918) grep_sock_info - checking if port 5060 matches port 5060
0(18918) after_strict: Next hop: 'sip:10.10.3.190:5060;lr' is loose router
0(18918) parse_headers: flags=ffffffffffffffff
0(18918) found end of header
0(18918) rewrite_uri: Rewriting Request-URI with 'sip:10.10.3.190:5060;lr'
0(18918) after_strict: The last route URI: 'sip:10.10.3.190:5060;lr'
0(18918) DEBUG: t_newtran: T on entrance=0xffffffff
0(18918) parse_headers: flags=ffffffffffffffff
0(18918) parse_headers: flags=78
0(18918) t_lookup_request: start searching: hash=613, isACK=1
0(18918) DEBUG: RFC3261 transaction matched, tid=16edfc0f-5035-dc11-82b5-0013d44f0ad0
0(18918) DEBUG:tm:REF_UNSAFE: after is 1
0(18918) DEBUG: t_lookup_request: transaction found (T=0xb5c1ab48)
0(18918) DEBUG: cleanup_uac_timers: RETR/FR timers reset
0(18918) DEBUG: add_to_tail_of_timer[2]: 0xb5c1ab90 (51)
0(18918) DEBUG:tm:UNREF_UNSAFE: after is 0
0(18918) DEBUG:destroy_avp_list: destroying list (nil)
0(18918) receive_msg: cleaning up
1(18919) DEBUG: timer routine:4,tl=0xb5c1ac94 next=0xb5c1ada4, timeout=47000000
1(18919) DEBUG: timer routine:4,tl=0xb5c1ada4 next=0xb5c1ac10, timeout=47000000
1(18919) DEBUG: timer routine:4,tl=0xb5c1ac10 next=(nil), timeout=47000000
1(18919) DEBUG: timer routine:2,tl=0xb5c1ab90 next=(nil), timeout=51
1(18919) DEBUG: wait_handler : removing 0xb5c1ab48 from table
1(18919) DEBUG: delete transaction 0xb5c1ab48
1(18919) DEBUG: wait_handler : done