Apr 27 04:24:15 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:15 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 14==9 && [sip2.demo.com] == [127.0.0.1] Apr 27 04:24:15 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:15 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 14==11 && [sip2.demo.com] == [OpenSER] Apr 27 04:24:15 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:15 log /usr/local/sbin/openser[2833]: lookup(): '' Not found in usrloc Apr 27 04:24:15 log /usr/local/sbin/openser[2833]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:15 log /usr/local/sbin/openser[2833]: check_via_address(71.220.244.225, 192.168.1.170, 0) Apr 27 04:24:15 log /usr/local/sbin/openser[2833]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:15 log /usr/local/sbin/openser[2833]: receive_msg: cleaning up Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: SIP Request: Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: method: Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: uri: Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: version: Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: parse_headers: flags=2 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=16 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=2 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: parse_headers: this is the first via Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: After parse_msg... Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: preparing to run routing scripts... Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: parse_headers: flags=100 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: DEBUG:parse_to:end of header reached, state=10 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: DBUG:parse_to: display={}, ruri={sip:sip2.demo.com} Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: DEBUG: get_hdr_field: [22]; uri=[sip:sip2.demo.com] Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: DEBUG: to body [ ] Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: get_hdr_field: cseq : <5428> Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: DEBUG:maxfwd:is_maxfwd_present: value = 70 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: check_via_address(70.245.76.121, 70.245.76.121, 0) Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: parse_headers: flags=80 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: DEBUG: get_hdr_body : content_length=0 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: found end of header Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: DEBUG: add_param: tag=263a7e17dbc77445o0 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: DBUG:parse_to: display={Timothy Dick}, ruri={sip:5618530300@sip2.demo.com} Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: parse_headers: flags=200 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: find_first_route: No Route headers found Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: loose_route: There is no Route HF Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==9 && [sip2.demo.com] == [127.0.0.1] Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==11 && [sip2.demo.com] == [OpenSER] Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==9 && [sip2.demo.com] == [127.0.0.1] Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==11 && [sip2.demo.com] == [OpenSER] Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==9 && [sip2.demo.com] == [127.0.0.1] Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==11 && [sip2.demo.com] == [OpenSER] Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==9 && [sip2.demo.com] == [127.0.0.1] Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==11 && [sip2.demo.com] == [OpenSER] Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: lookup(): '' Not found in usrloc Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: check_via_address(70.245.76.121, 70.245.76.121, 0) Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:24 log /usr/local/sbin/openser[2828]: receive_msg: cleaning up Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: SIP Request: Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: method: Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: uri: Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: version: Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: flags=2 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=16 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=2 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: this is the first via Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: After parse_msg... Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: preparing to run routing scripts... Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: flags=100 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: Found param type 235, = <5060>; state=6 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=16 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=100 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: this is the second via Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=6 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: Found param type 235, = <5060>; state=16 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=100 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:parse_to:end of header reached, state=10 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: get_hdr_field: [31]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: to body [ ] Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: get_hdr_field: cseq : <102> Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:maxfwd:is_maxfwd_present: value = 68 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: check_via_address(Gateway, Gateway, 0) Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: flags=80 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: add_param: tag=as710aca5e Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DBUG:parse_to: display={"7135178240"}, ruri={sip:7135178240@64.24.35.73} Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: flags=200 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: get_hdr_body : content_length=232 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: found end of header Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: find_first_route: No Route headers found Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: loose_route: There is no Route HF Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==9 && [sip2.demo.com] == [127.0.0.1] Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==11 && [sip2.demo.com] == [OpenSER] Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==9 && [sip2.demo.com] == [127.0.0.1] Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==11 && [sip2.demo.com] == [OpenSER] Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==9 && [sip2.demo.com] == [127.0.0.1] Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==11 && [sip2.demo.com] == [OpenSER] Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==9 && [sip2.demo.com] == [127.0.0.1] Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 14==11 && [sip2.demo.com] == [OpenSER] Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: rewrite_uri: Rewriting Request-URI with 'sip:9492666205@192.168.1.102:5060' Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: subst_run: running. r=1 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: subst_str: no match Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:check_content_type: type found valid Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: flags=40 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: t_newtran: T on entrance=0xffffffffffffffff Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: flags=78 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: t_lookup_request: start searching: hash=52201, isACK=0 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: RFC3261 transaction matching failed Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: t_lookup_request: no transaction found Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: check_via_address(Gateway, Gateway, 0) Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: WARNING:vqm_resize: resize(0) called Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:tm:_reply_light: reply sent out. buf=0x64c318: SIP/2.0 1..., shmem=0x2b16c2136018: SIP/2.0 1 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:tm:_reply_light: finished Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: mk_proxy: doing DNS lookup... Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: check_via_address(Gateway, Gateway, 0) Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DBG:check_against_rule_list: using list dns Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:tm:set_timer: relative timeout is 500000 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: add_to_tail_of_timer[4]: 0x2b16c2133118 (152100000) Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:tm:set_timer: relative timeout is 30 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: add_to_tail_of_timer[0]: 0x2b16c2133148 (181) Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:tm:t_relay_to: new transaction fwd'ed Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:tm:UNREF_UNSAFE: after is 0 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: receive_msg: cleaning up Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: SIP Reply (status): Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: version: Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: status: <100> Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: reason: Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: parse_headers: flags=2 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG:parse_to:end of header reached, state=10 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG: get_hdr_field: [31]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG: to body [ ] Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: get_hdr_field: cseq : <102> Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: Found param type 232, = ; state=16 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: end of header reached, state=5 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: parse_headers: Via found, flags=2 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: parse_headers: this is the first via Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: After parse_msg... Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG:forward_reply: found module nathelper, passing reply to it Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG:forward_reply: found module tm, passing reply to it Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG: t_check: start=0xffffffffffffffff Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: parse_headers: flags=22 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: parse_headers: flags=8 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG: t_reply_matching: hash 52201 label 1327305443 branch 0 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG:tm:REF_UNSAFE: after is 1 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG: t_reply_matching: reply matched (T=0x2b16c2132ef8)! Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG: t_check: end=0x2b16c2132ef8 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG:tm:reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1) Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: parse_headers: flags=80 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: Found param type 235, = <5060>; state=6 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: Found param type 232, = ; state=16 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: end of header reached, state=5 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: parse_headers: Via found, flags=80 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: parse_headers: this is the second via Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: Found param type 235, = <5060>; state=6 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: Found param type 232, = ; state=16 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: end of header reached, state=5 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: parse_headers: Via found, flags=80 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: Found param type 232, = ; state=6 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: Found param type 235, = <5060>; state=16 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: end of header reached, state=5 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: parse_headers: Via found, flags=80 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG: get_hdr_body : content_length=0 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: found end of header Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG:tm:t_should_relay_response: T_code=100, new_code=100 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG:tm:relay_reply: branch=0, save=0, relay=-1 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG:tm:set_timer: relative timeout is 120 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG: add_to_tail_of_timer[1]: 0x2b16c2133148 (271) Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG:tm:UNREF_UNSAFE: after is 0 Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:28 log /usr/local/sbin/openser[2830]: receive_msg: cleaning up Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: SIP Reply (status): Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: version: Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: status: <180> Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: reason: Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: flags=2 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: add_param: tag=b79970d0a6a94debi0 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: get_hdr_field: [54]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: to body [] Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: get_hdr_field: cseq : <102> Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=16 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=2 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: this is the first via Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: After parse_msg... Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:forward_reply: found module nathelper, passing reply to it Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:forward_reply: found module tm, passing reply to it Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: t_check: start=0xffffffffffffffff Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: flags=22 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: flags=8 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: t_reply_matching: hash 52201 label 1327305443 branch 0 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:tm:REF_UNSAFE: after is 1 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: t_reply_matching: reply matched (T=0x2b16c2132ef8)! Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: t_check: end=0x2b16c2132ef8 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:tm:reply_received: org. status uas=100, uac[0]=100 local=0 is_invite=1) Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: flags=80 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: Found param type 235, = <5060>; state=6 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=16 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=80 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: this is the second via Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: Found param type 235, = <5060>; state=6 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=16 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=80 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=6 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: Found param type 235, = <5060>; state=16 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=80 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: get_hdr_body : content_length=0 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: found end of header Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:tm:t_should_relay_response: T_code=100, new_code=180 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:tm:relay_reply: branch=0, save=0, relay=0 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: old size: 708, new size: 648 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: build_res_from_sip_res: copied size: orig:276, new: 216, rest: 432 msg= SIP/2.0 180 Ringing To: ;tag=b79970d0a6a94debi0 From: "7135178240" ;tag=as710aca5e Call-ID: 5cf60b7c7e68b6be0b61893352ba53ea@64.24.35.73 CSeq: 102 INVITE Via: SIP/2.0/UDP Gateway;rport=5060;branch=z9hG4bK9ebc.e6c38f54.0 Via: SIP/2.0/UDP 64.24.35.216;rport=5060;branch=z9hG4bK9ebc.9c70fae1.0 Via: SIP/2.0/UDP 64.24.35.73:5060;branch=z9hG4bK75fe20c9;rport=5060 Record-Route: Record-Route: Record-Route: Server: Linksys/PAP2-3.1.9(LSa) Content-Length: 0 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:tm:relay_reply: sent buf=0x64c018: SIP/2.0 1..., shmem=0x2b16c21367a8: SIP/2.0 1 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:tm:set_timer: relative timeout is 120 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG: add_to_tail_of_timer[1]: 0x2b16c2133148 (271) Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:tm:UNREF_UNSAFE: after is 0 Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:28 log /usr/local/sbin/openser[2828]: receive_msg: cleaning up Apr 27 04:24:28 log /usr/local/sbin/openser[2835]: DEBUG: timer routine:4,tl=0x2b16c2133118 next=(nil), timeout=152100000 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: SIP Reply (status): Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: version: Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: status: <200> Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: reason: Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=2 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: add_param: tag=b79970d0a6a94debi0 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: get_hdr_field: [54]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: to body [] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: get_hdr_field: cseq : <102> Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=2 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: this is the first via Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: After parse_msg... Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:forward_reply: found module nathelper, passing reply to it Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:forward_reply: found module tm, passing reply to it Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: t_check: start=0xffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=22 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=8 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: t_reply_matching: hash 52201 label 1327305443 branch 0 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:tm:REF_UNSAFE: after is 1 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: t_reply_matching: reply matched (T=0x2b16c2132ef8)! Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: t_check: end=0x2b16c2132ef8 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:tm:reply_received: org. status uas=180, uac[0]=180 local=0 is_invite=1) Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: this is the second via Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: get_hdr_body : content_length=235 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: found end of header Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:check_content_type: type found valid Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=40 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: add_param: tag=as710aca5e Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DBUG:parse_to: display={"7135178240"}, ruri={sip:7135178240@64.24.35.73} Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: ERROR: send_rtpp_command: can't send command to a RTP proxy Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: send_rtpp_command(): proxy does not responding, disable it Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: WARNING: rtpp_test: can't get version of the RTP proxy Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: WARNING: rtpp_test: support for RTP proxy has been disabled temporarily Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: ERROR: force_rtp_proxy2: no available proxies Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=80 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:tm:t_should_relay_response: T_code=180, new_code=200 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:tm:relay_reply: branch=0, save=0, relay=0 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: old size: 1118, new size: 1065 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: build_res_from_sip_res: copied size: orig:709, new: 656, rest: 409 msg= SIP/2.0 200 OK To: ;tag=b79970d0a6a94debi0 From: "7135178240" ;tag=as710aca5e Call-ID: 5cf60b7c7e68b6be0b61893352ba53ea@64.24.35.73 CSeq: 102 INVITE Via: SIP/2.0/UDP Gateway;rport=5060;branch=z9hG4bK9ebc.e6c38f54.0 Via: SIP/2.0/UDP 64.24.35.216;rport=5060;branch=z9hG4bK9ebc.9c70fae1.0 Via: SIP/2.0/UDP 64.24.35.73:5060;branch=z9hG4bK75fe20c9;rport=5060 Record-Route: Record-Route: Record-Route: Contact: John Doe Server: Linksys/PAP2-3.1.9(LSa) Content-Length: 235 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp v=0 o=- 218620 218620 IN IP4 192.168.1.102 s=- c=IN IP4 192.168.1.102 t=0 0 m=audio 16388 RTP/AVP 0 100 101 a=rtpmap:0 PCMU/8000 a=rtpmap:100 NSE/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: add_to_tail_of_timer[2]: 0x2b16c2132f78 (158) Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:tm:relay_reply: sent buf=0x64c1c8: SIP/2.0 2..., shmem=0x2b16c2136ae0: SIP/2.0 2 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: cleanup_uac_timers: RETR/FR timers reset Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:tm:UNREF_UNSAFE: after is 0 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: receive_msg: cleaning up Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: SIP Request: Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: method: Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: uri: Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: version: Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: parse_headers: flags=2 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=2 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: parse_headers: this is the first via Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: After parse_msg... Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: preparing to run routing scripts... Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG : sl_filter_ACK: to late to be a local ACK! Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: parse_headers: flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: Found param type 235, = <5060>; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: parse_headers: this is the second via Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: Found param type 235, = <5060>; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG: add_param: tag=b79970d0a6a94debi0 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG: get_hdr_field: [54]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG: to body [] Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: get_hdr_field: cseq : <102> Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG:maxfwd:is_maxfwd_present: value = 68 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: check_via_address(Gateway, Gateway, 0) Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: parse_headers: flags=80 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG: add_param: tag=as710aca5e Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DBUG:parse_to: display={"7135178240"}, ruri={sip:7135178240@64.24.35.73} Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: parse_headers: flags=200 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: is_preloaded: No Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 11==9 && [OpenSER] == [127.0.0.1] Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 11==11 && [OpenSER] == [OpenSER] Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: after_strict: Next hop: 'sip:OpenSER;lr=on;ftag=as710aca5e' is loose router Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG: get_hdr_body : content_length=0 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: found end of header Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: rewrite_uri: Rewriting Request-URI with 'sip:OpenSER;lr=on;ftag=as710aca5e' Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: after_strict: The last route URI: 'sip:OpenSER;lr=on;ftag=as710aca5e' Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: subst_run: running. r=1 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: subst_str: no match Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG: t_newtran: T on entrance=0xffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: parse_headers: flags=78 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: t_lookup_request: start searching: hash=52201, isACK=1 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: parse_headers: flags=38 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG:tm:REF_UNSAFE: after is 1 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG: t_lookup_request: e2e proxy ACK found Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG:tm:t_newtran: building branch for end2end ACK Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG:tm:t_relay: forwarding ACK Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG: mk_proxy: doing DNS lookup... Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: check_via_address(Gateway, Gateway, 0) Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DBG:check_against_rule_list: using list dns Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG:forward_request: sending: ACK sip:OpenSER;lr=on;ftag=as710aca5e SIP/2.0 Record-Route: Record-Route: Via: SIP/2.0/UDP OpenSER;branch=z9hG4bK9ebc.3e21d1f4.2 Via: SIP/2.0/UDP Gateway;rport=5060;branch=z9hG4bK9ebc.e6c38f54.2 Via: SIP/2.0/UDP 64.24.35.216;rport=5060;branch=z9hG4bK9ebc.9c70fae1.2 Via: SIP/2.0/UDP 64.24.35.73:5060;branch=z9hG4bK5b365f0e;rport=5060 From: "7135178240" ;tag=as710aca5e To: ;tag=b79970d0a6a94debi0 Contact: Call-ID: 5cf60b7c7e68b6be0b61893352ba53ea@64.24.35.73 CSeq: 102 ACK Max-Forwards: 67 Content-Length: 0 P-hint: rr-enforced P-hint: rr-enforced . Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG:forward_request: orig. len=648, new_len=745, proto=1 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: SIP Request: Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: method: Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: uri: Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: version: Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=2 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=2 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: this is the first via Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: After parse_msg... Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: preparing to run routing scripts... Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG : sl_filter_ACK: to late to be a local ACK! Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: this is the second via Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: add_param: tag=b79970d0a6a94debi0 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: get_hdr_field: [54]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: to body [] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: get_hdr_field: cseq : <102> Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:maxfwd:is_maxfwd_present: value = 67 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: check_via_address(OpenSER, OpenSER, 0) Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=80 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: add_param: tag=as710aca5e Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DBUG:parse_to: display={"7135178240"}, ruri={sip:7135178240@64.24.35.73} Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=200 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: get_hdr_body : content_length=0 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: found end of header Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: find_first_route: No Route headers found Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: loose_route: There is no Route HF Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 11==9 && [OpenSER] == [127.0.0.1] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 11==11 && [OpenSER] == [OpenSER] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 11==9 && [OpenSER] == [127.0.0.1] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 11==11 && [OpenSER] == [OpenSER] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: lookup(): '' Not found in usrloc Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: receive_msg: cleaning up Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG:tm:UNREF_UNSAFE: after is 0 Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:30 log /usr/local/sbin/openser[2828]: receive_msg: cleaning up Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: SIP Reply (status): Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: version: Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: status: <200> Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: reason: Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: parse_headers: flags=2 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG: add_param: tag=b79970d0a6a94debi0 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG: get_hdr_field: [54]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG: to body [] Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: get_hdr_field: cseq : <102> Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: parse_headers: Via found, flags=2 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: parse_headers: this is the first via Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: After parse_msg... Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG:forward_reply: found module nathelper, passing reply to it Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG:forward_reply: found module tm, passing reply to it Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG: t_check: start=0xffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: parse_headers: flags=22 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: parse_headers: flags=8 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG: t_reply_matching: hash 52201 label 1327305443 branch 0 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG:tm:REF_UNSAFE: after is 1 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG: t_reply_matching: reply matched (T=0x2b16c2132ef8)! Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG: t_check: end=0x2b16c2132ef8 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG:tm:reply_received: org. status uas=200, uac[0]=200 local=0 is_invite=1) Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: Found param type 235, = <5060>; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: parse_headers: Via found, flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: parse_headers: this is the second via Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: Found param type 235, = <5060>; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: parse_headers: Via found, flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: Found param type 232, = ; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: Found param type 235, = <5060>; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: parse_headers: Via found, flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG: get_hdr_body : content_length=235 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: found end of header Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG:check_content_type: type found valid Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: parse_headers: flags=40 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG: add_param: tag=as710aca5e Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DBUG:parse_to: display={"7135178240"}, ruri={sip:7135178240@64.24.35.73} Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: ERROR: send_rtpp_command: can't send command to a RTP proxy Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: send_rtpp_command(): proxy does not responding, disable it Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: WARNING: rtpp_test: can't get version of the RTP proxy Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: WARNING: rtpp_test: support for RTP proxy has been disabled temporarily Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: ERROR: force_rtp_proxy2: no available proxies Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: parse_headers: flags=80 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG:tm:t_should_relay_response: T_code=200, new_code=200 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG:tm:t_should_relay_response: 200 OK for INVITE after final sent Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG:tm:relay_reply: branch=0, save=0, relay=0 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: old size: 1118, new size: 1065 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: build_res_from_sip_res: copied size: orig:709, new: 656, rest: 409 msg= SIP/2.0 200 OK To: ;tag=b79970d0a6a94debi0 From: "7135178240" ;tag=as710aca5e Call-ID: 5cf60b7c7e68b6be0b61893352ba53ea@64.24.35.73 CSeq: 102 INVITE Via: SIP/2.0/UDP Gateway;rport=5060;branch=z9hG4bK9ebc.e6c38f54.0 Via: SIP/2.0/UDP 64.24.35.216;rport=5060;branch=z9hG4bK9ebc.9c70fae1.0 Via: SIP/2.0/UDP 64.24.35.73:5060;branch=z9hG4bK75fe20c9;rport=5060 Record-Route: Record-Route: Record-Route: Contact: John Doe Server: Linksys/PAP2-3.1.9(LSa) Content-Length: 235 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp v=0 o=- 218620 218620 IN IP4 192.168.1.102 s=- c=IN IP4 192.168.1.102 t=0 0 m=audio 16388 RTP/AVP 0 100 101 a=rtpmap:0 PCMU/8000 a=rtpmap:100 NSE/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG:tm:relay_reply: sent buf=0x64b9f0: SIP/2.0 2..., shmem=0x2b16c2136ae0: SIP/2.0 2 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG:tm:UNREF_UNSAFE: after is 0 Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:30 log /usr/local/sbin/openser[2830]: receive_msg: cleaning up Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: SIP Request: Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: method: Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: uri: Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: version: Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=2 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=2 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: this is the first via Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: After parse_msg... Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: preparing to run routing scripts... Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG : sl_filter_ACK: to late to be a local ACK! Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: this is the second via Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: add_param: tag=b79970d0a6a94debi0 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: get_hdr_field: [54]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: to body [] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: get_hdr_field: cseq : <102> Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:maxfwd:is_maxfwd_present: value = 68 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: check_via_address(Gateway, Gateway, 0) Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=80 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: add_param: tag=as710aca5e Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DBUG:parse_to: display={"7135178240"}, ruri={sip:7135178240@64.24.35.73} Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=200 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: is_preloaded: No Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 11==9 && [OpenSER] == [127.0.0.1] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 11==11 && [OpenSER] == [OpenSER] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: after_strict: Next hop: 'sip:OpenSER;lr=on;ftag=as710aca5e' is loose router Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: get_hdr_body : content_length=0 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: found end of header Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: rewrite_uri: Rewriting Request-URI with 'sip:OpenSER;lr=on;ftag=as710aca5e' Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: after_strict: The last route URI: 'sip:OpenSER;lr=on;ftag=as710aca5e' Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: subst_run: running. r=1 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: subst_str: no match Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: t_newtran: T on entrance=0xffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=78 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: t_lookup_request: start searching: hash=52201, isACK=1 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=38 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:tm:REF_UNSAFE: after is 1 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: t_lookup_request: e2e proxy ACK found Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:tm:t_newtran: building branch for end2end ACK Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:tm:t_relay: forwarding ACK Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: mk_proxy: doing DNS lookup... Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: check_via_address(Gateway, Gateway, 0) Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DBG:check_against_rule_list: using list dns Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:forward_request: sending: ACK sip:OpenSER;lr=on;ftag=as710aca5e SIP/2.0 Record-Route: Record-Route: Via: SIP/2.0/UDP OpenSER;branch=z9hG4bK9ebc.3e21d1f4.2 Via: SIP/2.0/UDP Gateway;rport=5060;branch=z9hG4bK9ebc.e6c38f54.2 Via: SIP/2.0/UDP 64.24.35.216;rport=5060;branch=z9hG4bK9ebc.9c70fae1.2 Via: SIP/2.0/UDP 64.24.35.73:5060;branch=z9hG4bK12d9f918;rport=5060 From: "7135178240" ;tag=as710aca5e To: ;tag=b79970d0a6a94debi0 Contact: Call-ID: 5cf60b7c7e68b6be0b61893352ba53ea@64.24.35.73 CSeq: 102 ACK Max-Forwards: 67 Content-Length: 0 P-hint: rr-enforced P-hint: rr-enforced . Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:forward_request: orig. len=648, new_len=745, proto=1 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:tm:UNREF_UNSAFE: after is 0 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: receive_msg: cleaning up Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: SIP Request: Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: method: Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: uri: Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: version: Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=2 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=2 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: this is the first via Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: After parse_msg... Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: preparing to run routing scripts... Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG : sl_filter_ACK: to late to be a local ACK! Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: this is the second via Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=6 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: add_param: tag=b79970d0a6a94debi0 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: get_hdr_field: [54]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: to body [] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: get_hdr_field: cseq : <102> Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:maxfwd:is_maxfwd_present: value = 67 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: check_via_address(OpenSER, OpenSER, 0) Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=80 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: add_param: tag=as710aca5e Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DBUG:parse_to: display={"7135178240"}, ruri={sip:7135178240@64.24.35.73} Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: parse_headers: flags=200 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG: get_hdr_body : content_length=0 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: found end of header Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: find_first_route: No Route headers found Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: loose_route: There is no Route HF Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 11==9 && [OpenSER] == [127.0.0.1] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 11==11 && [OpenSER] == [OpenSER] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 11==9 && [OpenSER] == [127.0.0.1] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 11==11 && [OpenSER] == [OpenSER] Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: lookup(): '' Not found in usrloc Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:30 log /usr/local/sbin/openser[2833]: receive_msg: cleaning up Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: SIP Request: Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: method: Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: uri: Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: version: Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: parse_headers: flags=2 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: Found param type 232, = ; state=16 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: end of header reached, state=5 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: parse_headers: Via found, flags=2 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: parse_headers: this is the first via Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: After parse_msg... Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: preparing to run routing scripts... Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: parse_headers: flags=100 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: DEBUG:parse_to:end of header reached, state=10 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: DBUG:parse_to: display={}, ruri={sip:sip2.demo.com} Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: DEBUG: get_hdr_field: [22]; uri=[sip:sip2.demo.com] Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: DEBUG: to body [ ] Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: get_hdr_field: cseq : <471> Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: DEBUG:maxfwd:is_maxfwd_present: value = 70 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: parse_headers: flags=80 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: DEBUG: get_hdr_body : content_length=0 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: found end of header Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: DEBUG: add_param: tag=afbb92f48b3b9d9bo0 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: DBUG:parse_to: display={demo NM}, ruri={sip:5057965751@sip2.demo.com} Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: parse_headers: flags=200 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: find_first_route: No Route headers found Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: loose_route: There is no Route HF Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if host==us: 14==9 && [sip2.demo.com] == [127.0.0.1] Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if host==us: 14==11 && [sip2.demo.com] == [OpenSER] Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if host==us: 14==9 && [sip2.demo.com] == [127.0.0.1] Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if host==us: 14==11 && [sip2.demo.com] == [OpenSER] Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if host==us: 14==9 && [sip2.demo.com] == [127.0.0.1] Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if host==us: 14==11 && [sip2.demo.com] == [OpenSER] Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if host==us: 14==9 && [sip2.demo.com] == [127.0.0.1] Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if host==us: 14==11 && [sip2.demo.com] == [OpenSER] Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: lookup(): '' Not found in usrloc Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: check_via_address(71.220.244.225, 192.168.1.170, 0) Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:30 log /usr/local/sbin/openser[2826]: receive_msg: cleaning up Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: SIP Reply (status): Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: version: Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: status: <200> Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: reason: Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: flags=2 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG: add_param: tag=b79970d0a6a94debi0 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG: get_hdr_field: [54]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG: to body [] Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: get_hdr_field: cseq : <102> Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=2 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: this is the first via Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: After parse_msg... Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:forward_reply: found module nathelper, passing reply to it Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:forward_reply: found module tm, passing reply to it Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG: t_check: start=0xffffffffffffffff Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: flags=22 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: flags=8 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG: t_reply_matching: hash 52201 label 1327305443 branch 0 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:tm:REF_UNSAFE: after is 1 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG: t_reply_matching: reply matched (T=0x2b16c2132ef8)! Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG: t_check: end=0x2b16c2132ef8 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:tm:reply_received: org. status uas=200, uac[0]=200 local=0 is_invite=1) Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=6 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=ffffffffffffffff Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: this is the second via Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=6 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=ffffffffffffffff Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=6 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=16 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=ffffffffffffffff Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG: get_hdr_body : content_length=235 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: found end of header Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:check_content_type: type found valid Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: flags=40 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG: add_param: tag=as710aca5e Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DBUG:parse_to: display={"7135178240"}, ruri={sip:7135178240@64.24.35.73} Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: ERROR: force_rtp_proxy2: no available proxies Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: flags=80 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:tm:t_should_relay_response: T_code=200, new_code=200 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:tm:t_should_relay_response: 200 OK for INVITE after final sent Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:tm:relay_reply: branch=0, save=0, relay=0 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: old size: 1118, new size: 1065 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: build_res_from_sip_res: copied size: orig:709, new: 656, rest: 409 msg= SIP/2.0 200 OK To: ;tag=b79970d0a6a94debi0 From: "7135178240" ;tag=as710aca5e Call-ID: 5cf60b7c7e68b6be0b61893352ba53ea@64.24.35.73 CSeq: 102 INVITE Via: SIP/2.0/UDP Gateway;rport=5060;branch=z9hG4bK9ebc.e6c38f54.0 Via: SIP/2.0/UDP 64.24.35.216;rport=5060;branch=z9hG4bK9ebc.9c70fae1.0 Via: SIP/2.0/UDP 64.24.35.73:5060;branch=z9hG4bK75fe20c9;rport=5060 Record-Route: Record-Route: Record-Route: Contact: John Doe Server: Linksys/PAP2-3.1.9(LSa) Content-Length: 235 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp v=0 o=- 218620 218620 IN IP4 192.168.1.102 s=- c=IN IP4 192.168.1.102 t=0 0 m=audio 16388 RTP/AVP 0 100 101 a=rtpmap:0 PCMU/8000 a=rtpmap:100 NSE/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:tm:relay_reply: sent buf=0x64c1c8: SIP/2.0 2..., shmem=0x2b16c2136ae0: SIP/2.0 2 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:tm:UNREF_UNSAFE: after is 0 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: receive_msg: cleaning up Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: SIP Request: Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: method: Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: uri: Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: version: Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: flags=2 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: Found param type 232, = ; state=16 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: end of header reached, state=5 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: Via found, flags=2 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: this is the first via Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: After parse_msg... Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: preparing to run routing scripts... Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: flags=8 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: Found param type 235, = <5060>; state=6 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: Found param type 232, = ; state=16 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: end of header reached, state=5 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: Via found, flags=8 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: this is the second via Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: Found param type 232, = ; state=6 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: Found param type 235, = <5060>; state=16 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: end of header reached, state=5 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: Via found, flags=8 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG: add_param: tag=b79970d0a6a94debi0 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG: get_hdr_field: [54]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG: to body [] Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: flags=100 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: get_hdr_field: cseq : <102> Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG:maxfwd:is_maxfwd_present: value = 68 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: check_via_address(Gateway, Gateway, 0) Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: flags=80 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG: add_param: tag=as710aca5e Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DBUG:parse_to: display={"7135178240"}, ruri={sip:7135178240@64.24.35.73} Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: flags=200 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: is_preloaded: No Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if host==us: 11==9 && [OpenSER] == [127.0.0.1] Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if host==us: 11==11 && [OpenSER] == [OpenSER] Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: after_strict: Next hop: 'sip:OpenSER;lr=on;ftag=as710aca5e' is loose router Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG: get_hdr_body : content_length=0 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: found end of header Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: rewrite_uri: Rewriting Request-URI with 'sip:OpenSER;lr=on;ftag=as710aca5e' Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: after_strict: The last route URI: 'sip:OpenSER;lr=on;ftag=as710aca5e' Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: subst_run: running. r=1 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: subst_str: no match Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG: t_newtran: T on entrance=0xffffffffffffffff Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: flags=78 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: t_lookup_request: start searching: hash=52201, isACK=1 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: parse_headers: flags=38 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG:tm:REF_UNSAFE: after is 1 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG: t_lookup_request: e2e proxy ACK found Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG:tm:t_newtran: building branch for end2end ACK Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG:tm:t_relay: forwarding ACK Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG: mk_proxy: doing DNS lookup... Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: check_via_address(Gateway, Gateway, 0) Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DBG:check_against_rule_list: using list dns Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG:forward_request: sending: ACK sip:OpenSER;lr=on;ftag=as710aca5e SIP/2.0 Record-Route: Record-Route: Via: SIP/2.0/UDP OpenSER;branch=z9hG4bK9ebc.3e21d1f4.2 Via: SIP/2.0/UDP Gateway;rport=5060;branch=z9hG4bK9ebc.e6c38f54.2 Via: SIP/2.0/UDP 64.24.35.216;rport=5060;branch=z9hG4bK9ebc.9c70fae1.2 Via: SIP/2.0/UDP 64.24.35.73:5060;branch=z9hG4bK2026c162;rport=5060 From: "7135178240" ;tag=as710aca5e To: ;tag=b79970d0a6a94debi0 Contact: Call-ID: 5cf60b7c7e68b6be0b61893352ba53ea@64.24.35.73 CSeq: 102 ACK Max-Forwards: 67 Content-Length: 0 P-hint: rr-enforced P-hint: rr-enforced . Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG:forward_request: orig. len=648, new_len=745, proto=1 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: SIP Request: Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: method: Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: uri: Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: version: Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: flags=2 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=2 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: this is the first via Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: After parse_msg... Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: preparing to run routing scripts... Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: flags=8 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=6 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=8 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: this is the second via Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=6 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=16 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=8 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: Found param type 232, = ; state=6 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: Found param type 235, = <5060>; state=16 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: end of header reached, state=5 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: Via found, flags=8 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG: add_param: tag=b79970d0a6a94debi0 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG: get_hdr_field: [54]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG: to body [] Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: flags=100 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: get_hdr_field: cseq : <102> Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:maxfwd:is_maxfwd_present: value = 67 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: check_via_address(OpenSER, OpenSER, 0) Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: flags=80 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG: add_param: tag=as710aca5e Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DBUG:parse_to: display={"7135178240"}, ruri={sip:7135178240@64.24.35.73} Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: parse_headers: flags=200 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG: get_hdr_body : content_length=0 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: found end of header Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: find_first_route: No Route headers found Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: loose_route: There is no Route HF Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 11==9 && [OpenSER] == [127.0.0.1] Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 11==11 && [OpenSER] == [OpenSER] Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 11==9 && [OpenSER] == [127.0.0.1] Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if host==us: 11==11 && [OpenSER] == [OpenSER] Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: lookup(): '' Not found in usrloc Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:31 log /usr/local/sbin/openser[2833]: receive_msg: cleaning up Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG:tm:UNREF_UNSAFE: after is 0 Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:31 log /usr/local/sbin/openser[2826]: receive_msg: cleaning up Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: SIP Reply (status): Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: version: Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: status: <200> Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: reason: Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: flags=2 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG: add_param: tag=b79970d0a6a94debi0 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG: get_hdr_field: [54]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG: to body [] Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: get_hdr_field: cseq : <102> Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=16 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=2 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: this is the first via Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: After parse_msg... Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:forward_reply: found module nathelper, passing reply to it Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:forward_reply: found module tm, passing reply to it Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG: t_check: start=0xffffffffffffffff Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: flags=22 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: flags=8 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG: t_reply_matching: hash 52201 label 1327305443 branch 0 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:tm:REF_UNSAFE: after is 1 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG: t_reply_matching: reply matched (T=0x2b16c2132ef8)! Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG: t_check: end=0x2b16c2132ef8 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:tm:reply_received: org. status uas=200, uac[0]=200 local=0 is_invite=1) Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: Found param type 235, = <5060>; state=6 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=16 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=ffffffffffffffff Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: this is the second via Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: Found param type 235, = <5060>; state=6 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=16 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=ffffffffffffffff Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=6 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: Found param type 235, = <5060>; state=16 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=ffffffffffffffff Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG: get_hdr_body : content_length=235 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: found end of header Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:check_content_type: type found valid Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: flags=40 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG: add_param: tag=as710aca5e Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DBUG:parse_to: display={"7135178240"}, ruri={sip:7135178240@64.24.35.73} Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: ERROR: send_rtpp_command: can't send command to a RTP proxy Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: send_rtpp_command(): proxy does not responding, disable it Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: WARNING: rtpp_test: can't get version of the RTP proxy Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: WARNING: rtpp_test: support for RTP proxy has been disabled temporarily Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: ERROR: force_rtp_proxy2: no available proxies Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: flags=80 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:tm:t_should_relay_response: T_code=200, new_code=200 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:tm:t_should_relay_response: 200 OK for INVITE after final sent Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:tm:relay_reply: branch=0, save=0, relay=0 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: old size: 1118, new size: 1065 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: build_res_from_sip_res: copied size: orig:709, new: 656, rest: 409 msg= SIP/2.0 200 OK To: ;tag=b79970d0a6a94debi0 From: "7135178240" ;tag=as710aca5e Call-ID: 5cf60b7c7e68b6be0b61893352ba53ea@64.24.35.73 CSeq: 102 INVITE Via: SIP/2.0/UDP Gateway;rport=5060;branch=z9hG4bK9ebc.e6c38f54.0 Via: SIP/2.0/UDP 64.24.35.216;rport=5060;branch=z9hG4bK9ebc.9c70fae1.0 Via: SIP/2.0/UDP 64.24.35.73:5060;branch=z9hG4bK75fe20c9;rport=5060 Record-Route: Record-Route: Record-Route: Contact: John Doe Server: Linksys/PAP2-3.1.9(LSa) Content-Length: 235 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura Content-Type: application/sdp v=0 o=- 218620 218620 IN IP4 192.168.1.102 s=- c=IN IP4 192.168.1.102 t=0 0 m=audio 16388 RTP/AVP 0 100 101 a=rtpmap:0 PCMU/8000 a=rtpmap:100 NSE/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:tm:relay_reply: sent buf=0x64ca50: SIP/2.0 2..., shmem=0x2b16c2136ae0: SIP/2.0 2 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:tm:UNREF_UNSAFE: after is 0 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: receive_msg: cleaning up Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: SIP Request: Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: method: Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: uri: Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: version: Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: parse_headers: flags=2 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: Found param type 232, = ; state=16 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: end of header reached, state=5 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: parse_headers: Via found, flags=2 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: parse_headers: this is the first via Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: After parse_msg... Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: preparing to run routing scripts... Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG : sl_filter_ACK: to late to be a local ACK! Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: parse_headers: flags=100 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: Found param type 235, = <5060>; state=6 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: Found param type 232, = ; state=16 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: end of header reached, state=5 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: parse_headers: Via found, flags=100 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: parse_headers: this is the second via Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: Found param type 232, = ; state=6 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: Found param type 235, = <5060>; state=16 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: end of header reached, state=5 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: parse_headers: Via found, flags=100 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG: add_param: tag=b79970d0a6a94debi0 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG: get_hdr_field: [54]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG: to body [] Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: get_hdr_field: cseq : <102> Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG:maxfwd:is_maxfwd_present: value = 68 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: check_via_address(Gateway, Gateway, 0) Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: parse_headers: flags=80 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG: add_param: tag=as710aca5e Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DBUG:parse_to: display={"7135178240"}, ruri={sip:7135178240@64.24.35.73} Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: parse_headers: flags=200 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: is_preloaded: No Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if host==us: 11==9 && [OpenSER] == [127.0.0.1] Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if host==us: 11==11 && [OpenSER] == [OpenSER] Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: after_strict: Next hop: 'sip:OpenSER;lr=on;ftag=as710aca5e' is loose router Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG: get_hdr_body : content_length=0 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: found end of header Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: rewrite_uri: Rewriting Request-URI with 'sip:OpenSER;lr=on;ftag=as710aca5e' Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: after_strict: The last route URI: 'sip:OpenSER;lr=on;ftag=as710aca5e' Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: subst_run: running. r=1 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: subst_str: no match Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG: t_newtran: T on entrance=0xffffffffffffffff Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: parse_headers: flags=ffffffffffffffff Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: parse_headers: flags=78 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: t_lookup_request: start searching: hash=52201, isACK=1 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: parse_headers: flags=38 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG:tm:REF_UNSAFE: after is 1 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG: t_lookup_request: e2e proxy ACK found Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG:tm:t_newtran: building branch for end2end ACK Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG:tm:t_relay: forwarding ACK Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG: mk_proxy: doing DNS lookup... Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: check_via_address(Gateway, Gateway, 0) Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DBG:check_against_rule_list: using list dns Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG:forward_request: sending: ACK sip:OpenSER;lr=on;ftag=as710aca5e SIP/2.0 Record-Route: Record-Route: Via: SIP/2.0/UDP OpenSER;branch=z9hG4bK9ebc.3e21d1f4.2 Via: SIP/2.0/UDP Gateway;rport=5060;branch=z9hG4bK9ebc.e6c38f54.2 Via: SIP/2.0/UDP 64.24.35.216;rport=5060;branch=z9hG4bK9ebc.9c70fae1.2 Via: SIP/2.0/UDP 64.24.35.73:5060;branch=z9hG4bK4603c7ad;rport=5060 From: "7135178240" ;tag=as710aca5e To: ;tag=b79970d0a6a94debi0 Contact: Call-ID: 5cf60b7c7e68b6be0b61893352ba53ea@64.24.35.73 CSeq: 102 ACK Max-Forwards: 67 Content-Length: 0 P-hint: rr-enforced P-hint: rr-enforced . Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG:forward_request: orig. len=648, new_len=745, proto=1 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: SIP Request: Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: method: Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: uri: Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: version: Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: flags=2 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=16 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=2 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: this is the first via Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: After parse_msg... Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: preparing to run routing scripts... Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG : sl_filter_ACK: to late to be a local ACK! Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: flags=100 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: Found param type 235, = <5060>; state=6 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=16 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=100 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: this is the second via Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: Found param type 235, = <5060>; state=6 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=16 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=100 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: Found param type 232, = ; state=6 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: Found param type 235, = <5060>; state=16 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: end of header reached, state=5 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: Via found, flags=100 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG: add_param: tag=b79970d0a6a94debi0 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DBUG:parse_to: display={}, ruri={sip:9492666205@64.24.35.216} Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG: get_hdr_field: [54]; uri=[sip:9492666205@64.24.35.216] Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG: to body [] Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: get_hdr_field: cseq : <102> Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:maxfwd:is_maxfwd_present: value = 67 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: check_via_address(OpenSER, OpenSER, 0) Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: flags=80 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG: add_param: tag=as710aca5e Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:parse_to:end of header reached, state=29 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DBUG:parse_to: display={"7135178240"}, ruri={sip:7135178240@64.24.35.73} Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: parse_headers: flags=200 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG: get_hdr_body : content_length=0 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: found end of header Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: find_first_route: No Route headers found Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: loose_route: There is no Route HF Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 11==9 && [OpenSER] == [127.0.0.1] Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 11==11 && [OpenSER] == [OpenSER] Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 11==9 && [OpenSER] == [127.0.0.1] Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if host==us: 11==11 && [OpenSER] == [OpenSER] Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: grep_sock_info - checking if port 5060 matches port 5060 Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: lookup(): '' Not found in usrloc Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:33 log /usr/local/sbin/openser[2828]: receive_msg: cleaning up Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG:tm:UNREF_UNSAFE: after is 0 Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: DEBUG:destroy_avp_list: destroying list (nil) Apr 27 04:24:33 log /usr/local/sbin/openser[2826]: receive_msg: cleaning up Apr 27 04:24:34 log /usr/local/sbin/openser[2835]: DEBUG: timer routine:2,tl=0x2b16c2132f78 next=(nil), timeout=158 Apr 27 04:24:34 log /usr/local/sbin/openser[2835]: DEBUG: wait_handler : removing 0x2b16c2132ef8 from table Apr 27 04:24:34 log /usr/local/sbin/openser[2835]: DEBUG: delete transaction 0x2b16c2132ef8 Apr 27 04:24:34 log /usr/local/sbin/openser[2835]: DEBUG: wait_handler : done