May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: SIP Request: May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: method: May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: uri: May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: version: May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: parse_headers: flags=2 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: Found param type 235, = ; state=6 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: Found param type 232, = ; state=16 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: end of header reached, state=5 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: parse_headers: Via found, flags=2 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: parse_headers: this is the first via May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: After parse_msg... May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: preparing to run routing scripts... May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: parse_headers: flags=100 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: DEBUG: get_hdr_body : content_length=339 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: get_hdr_field: cseq : <1> May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: DEBUG:maxfwd:is_maxfwd_present: value = 70 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: comp_scriptvar: str 20 : UAC May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: parse_headers: flags=8 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: DEBUG:parse_to:end of header reached, state=10 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: DBUG:parse_to: display={}, ruri={sip:*721111111111@sip.demo.com:5060} May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: DEBUG: get_hdr_field: [41]; uri=[sip:*721111111111@sip.demo.com:5060] May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: DEBUG: to body [ ] May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: comp_scriptvar: str 20 : 13 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: DEBUG: add_param: tag=2140826409449 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: DEBUG:parse_to:end of header reached, state=29 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: DBUG:parse_to: display={"unknown"}, ruri={sip:9492666205@sip.demo.com:5060} May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: comp_scriptvar: str 20 : 10 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: check_via_address(UAC, 192.168.0.126, 0) May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: found end of header May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: DEBUG:check_content_type: type found valid May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: parse_headers: flags=40 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: force_rtp_proxy2: proxy reply: 37950 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: parse_headers: flags=200 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: find_first_route: No Route headers found May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: loose_route: There is no Route HF May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if host==us: 14==9 && [sip.demo.com] == [127.0.0.1] May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if host==us: 14==11 && [sip.demo.com] == [OpenSER] May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if host==us: 14==9 && [sip.demo.com] == [127.0.0.1] May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if host==us: 14==11 && [sip.demo.com] == [OpenSER] May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: lookup(): '*721111111111' Not found in usrloc May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if host==us: 14==9 && [sip.demo.com] == [127.0.0.1] May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if host==us: 14==11 && [sip.demo.com] == [OpenSER] May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if host==us: 14==9 && [sip.demo.com] == [127.0.0.1] May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if host==us: 14==11 && [sip.demo.com] == [OpenSER] May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: does_uri_exit(): User in request uri does not exist May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: parse_headers: flags=80 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: parse_headers: flags=10000 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: pre_auth(): Credentials with given realm not found May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: build_auth_hf(): 'Proxy-Authenticate: Digest realm="sip.demo.com", nonce="464b120f8ef9308ce7ad57d2d140ad4a24d7462f", qop="auth" ' May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: check_via_address(UAC, 192.168.0.126, 0) May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: DEBUG:destroy_avp_list: destroying list 0x2b2b3a9caf20 May 16 09:10:43 hostname /usr/local/sbin/openser[19433]: receive_msg: cleaning up May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: SIP Request: May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: method: May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: uri: May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: version: May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: parse_headers: flags=2 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: Found param type 235, = ; state=6 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: Found param type 232, = ; state=16 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: end of header reached, state=5 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: parse_headers: Via found, flags=2 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: parse_headers: this is the first via May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: After parse_msg... May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: preparing to run routing scripts... May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: parse_headers: flags=8 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DEBUG: get_hdr_body : content_length=0 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: get_hdr_field: cseq : <1> May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DEBUG: add_param: tag=329cfeaa6ded039da25ff8cbb8668bd2.1c03 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DEBUG:parse_to:end of header reached, state=29 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DBUG:parse_to: display={}, ruri={sip:*721111111111@sip.demo.com:5060} May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DEBUG: get_hdr_field: [83]; uri=[sip:*721111111111@sip.demo.com:5060] May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DEBUG: to body [] May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DEBUG: sl_filter_ACK : local ACK found -> dropping it! May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DEBUG:destroy_avp_list: destroying list (nil) May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: receive_msg: cleaning up May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: SIP Request: May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: method: May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: uri: May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: version: May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=2 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: Found param type 235, = ; state=6 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: Found param type 232, = ; state=16 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: end of header reached, state=5 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: Via found, flags=2 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: this is the first via May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: After parse_msg... May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: preparing to run routing scripts... May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=100 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: get_hdr_body : content_length=339 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: get_hdr_field: cseq : <2> May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:maxfwd:is_maxfwd_present: value = 70 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: comp_scriptvar: str 20 : UAC May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=8 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:parse_to:end of header reached, state=10 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DBUG:parse_to: display={}, ruri={sip:*721111111111@sip.demo.com:5060} May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: get_hdr_field: [41]; uri=[sip:*721111111111@sip.demo.com:5060] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: to body [ ] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: comp_scriptvar: str 20 : 13 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: add_param: tag=2140826409449 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:parse_to:end of header reached, state=29 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DBUG:parse_to: display={"unknown"}, ruri={sip:9492666205@sip.demo.com:5060} May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: comp_scriptvar: str 20 : 10 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: check_via_address(UAC, 192.168.0.126, 0) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: found end of header May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:check_content_type: type found valid May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=40 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: force_rtp_proxy2: proxy reply: 37950 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=200 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: find_first_route: No Route headers found May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: loose_route: There is no Route HF May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if host==us: 14==9 && [sip.demo.com] == [127.0.0.1] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if host==us: 14==11 && [sip.demo.com] == [OpenSER] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if host==us: 14==9 && [sip.demo.com] == [127.0.0.1] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if host==us: 14==11 && [sip.demo.com] == [OpenSER] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: lookup(): '*721111111111' Not found in usrloc May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if host==us: 14==9 && [sip.demo.com] == [127.0.0.1] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if host==us: 14==11 && [sip.demo.com] == [OpenSER] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if host==us: 14==9 && [sip.demo.com] == [127.0.0.1] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if host==us: 14==11 && [sip.demo.com] == [OpenSER] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: grep_sock_info - checking if port 5060 matches port 5060 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: does_uri_exit(): User in request uri does not exist May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=80 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: check_nonce(): comparing [464b120f8ef9308ce7ad57d2d140ad4a24d7462f] and [464b120f8ef9308ce7ad57d2d140ad4a24d7462f] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: check_response(): Our result = '2d9de0c9d943461637cb74427d67de5b' May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: check_response(): Authorization is OK May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: avpops:ops_dbquery_avps: query [SELECT id FROM accounts WHERE username = '9492666205'] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: avpops:db_query_avp: rows [1] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: avpops:db_query_avp: row [0] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: close avp query May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: tr_eval_string: i=0 j=3 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: tr_eval_string: i=3 j=0 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: avpops:ops_dbquery_avps: query [UPDATE table.accounts_features SET value = '1', date = NOW() WHERE account_id = '25' AND `key` = 'forward_type'] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: avpops:db_query_avp: no result after query May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: close avp query May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: avpops:ops_dbquery_avps: query [UPDATE table.accounts_features SET value = '1111111111', date = NOW() WHERE account_id = '25' AND `key` = 'forward_phone_num'] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: avpops:db_query_avp: no result after query May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: close avp query May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: MY RU IS sip:call_forward_enable@OpenSER:5070 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: t_newtran: T on entrance=0xffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=78 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: t_lookup_request: start searching: hash=37830, isACK=0 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: RFC3261 transaction matching failed May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: t_lookup_request: no transaction found May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DBG: trans=0x2b2b3a9cafd0, callback type 1, id 0 entered May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=78 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: noisy_timer set for accounting May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:rr:is_direction: param ftag not found May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: check_via_address(UAC, 192.168.0.126, 0) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: WARNING:vqm_resize: resize(0) called May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:_reply_light: reply sent out. buf=0x667728: SIP/2.0 1..., shmem=0x2b2b3a9ce110: SIP/2.0 1 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:_reply_light: finished May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: mk_proxy: doing DNS lookup... May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=2000 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: clen_builder: content-length: 355 (355) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: check_via_address(UAC, 192.168.0.126, 0) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DBG:check_against_rule_list: using list dns May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:set_timer: relative timeout is 500000 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: add_to_tail_of_timer[4]: 0x2b2b3a9cb1f0 (10400000) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:set_timer: relative timeout is 30 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: add_to_tail_of_timer[0]: 0x2b2b3a9cb220 (39) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:t_relay_to: new transaction fwd'ed May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: comp_scriptvar: str 20 : 13 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: ERROR:tm:t_forward_nonack: no branch for forwarding May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: ERROR:tm:w_t_relay: t_forward_nonack failed May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:sl:sl_reply_error: error text is Server error occurred (1/SL) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: check_via_address(UAC, 192.168.0.126, 0) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:UNREF_UNSAFE: after is 0 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:destroy_avp_list: destroying list (nil) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: receive_msg: cleaning up May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: SIP Reply (status): May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: version: May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: status: <100> May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: reason: May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=2 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: Found param type 232, = ; state=6 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: Found param type 234, = ; state=16 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: end of header reached, state=5 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: Via found, flags=2 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: this is the first via May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: After parse_msg... May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:forward_reply: found module nathelper, passing reply to it May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=20 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: Found param type 234, = ; state=6 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: Found param type 235, = <5060>; state=6 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: Found param type 232, = ; state=16 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: end of header reached, state=5 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: Via found, flags=20 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: this is the second via May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:parse_to:end of header reached, state=10 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DBUG:parse_to: display={}, ruri={sip:*721111111111@sip.demo.com:5060} May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: get_hdr_field: [41]; uri=[sip:*721111111111@sip.demo.com:5060] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: to body [ ] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: get_hdr_field: cseq : <2> May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:forward_reply: found module tm, passing reply to it May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: t_check: start=0xffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=22 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=8 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: t_reply_matching: hash 37830 label 543289505 branch 0 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:REF_UNSAFE: after is 1 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: t_reply_matching: reply matched (T=0x2b2b3a9cafd0)! May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DBG: trans=0x2b2b3a9cafd0, callback type 2, id 0 entered May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: t_check: end=0x2b2b3a9cafd0 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:reply_received: org. status uas=100, uac[0]=0 local=0 is_invite=1) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=80 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:t_should_relay_response: T_code=100, new_code=100 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:relay_reply: branch=0, save=0, relay=-1 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:reply_received: FR_INV_TIMER = 60 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:set_timer: relative timeout is 60 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: add_to_tail_of_timer[1]: 0x2b2b3a9cb220 (69) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:UNREF_UNSAFE: after is 0 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:destroy_avp_list: destroying list (nil) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: receive_msg: cleaning up May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: SIP Reply (status): May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: version: May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: status: <200> May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: reason: May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=2 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: Found param type 232, = ; state=6 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: Found param type 234, = ; state=16 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: end of header reached, state=5 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: Via found, flags=2 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: this is the first via May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: After parse_msg... May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:forward_reply: found module nathelper, passing reply to it May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=20 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: Found param type 234, = ; state=6 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: Found param type 235, = <5060>; state=6 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: Found param type 232, = ; state=16 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: end of header reached, state=5 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: Via found, flags=20 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: this is the second via May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: add_param: tag=as750bde97 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:parse_to:end of header reached, state=29 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DBUG:parse_to: display={}, ruri={sip:*721111111111@sip.demo.com:5060} May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: get_hdr_field: [56]; uri=[sip:*721111111111@sip.demo.com:5060] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: to body [] May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: get_hdr_field: cseq : <2> May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:forward_reply: found module tm, passing reply to it May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: t_check: start=0xffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=22 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=8 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: t_reply_matching: hash 37830 label 543289505 branch 0 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:REF_UNSAFE: after is 1 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: t_reply_matching: reply matched (T=0x2b2b3a9cafd0)! May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=8 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DBG: trans=0x2b2b3a9cafd0, callback type 2, id 0 entered May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=8 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: t_check: end=0x2b2b3a9cafd0 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:reply_received: org. status uas=100, uac[0]=100 local=0 is_invite=1) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=80 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: get_hdr_body : content_length=285 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: found end of header May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:check_content_type: type found valid May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=40 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: add_param: tag=2140826409449 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:parse_to:end of header reached, state=29 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DBUG:parse_to: display={"unknown"}, ruri={sip:9492666205@sip.demo.com:5060} May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: force_rtp_proxy2: proxy reply: 37952 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:t_should_relay_response: T_code=100, new_code=200 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:relay_reply: branch=0, save=0, relay=0 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=2000 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: parse_headers: flags=ffffffffffffffff May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: clen_builder: content-length: 303 (303) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: old size: 992, new size: 929 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: build_res_from_sip_res: copied size: orig:992, new: 929, rest: 0 msg= SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.126;received=UAC;rport=5060;branch=z9hG4bKc0a8007e000000ae464b1024000028270000062c Record-Route: From: "unknown";tag=2140826409449 To: ;tag=as750bde97 Call-ID: 86463016-91CB-495B-99A5-91C369DAC7AD@192.168.0.126 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 303 v=0 o=root 15109 15109 IN IP4 OpenSER s=session c=IN IP4 OpenSER t=0 0 m=audio 37952 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv a=nortpproxy:yes May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: update_totag_set: new totag May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: add_to_tail_of_timer[2]: 0x2b2b3a9cb050 (14) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:relay_reply: sent buf=0x667b38: SIP/2.0 2..., shmem=0x2b2b3a9ce8b8: SIP/2.0 2 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DBG: trans=0x2b2b3a9cafd0, callback type 128, id 0 entered May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: flat_get_connection: Connection not found in the pool May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG: cleanup_uac_timers: RETR/FR timers reset May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:tm:UNREF_UNSAFE: after is 0 May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: DEBUG:destroy_avp_list: destroying list (nil) May 16 09:10:43 hostname /usr/local/sbin/openser[19427]: receive_msg: cleaning up May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: SIP Request: May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: method: May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: uri: May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: version: May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: parse_headers: flags=2 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: Found param type 235, = ; state=6 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: Found param type 232, = ; state=16 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: end of header reached, state=5 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: parse_headers: Via found, flags=2 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: parse_headers: this is the first via May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: After parse_msg... May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: preparing to run routing scripts... May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: parse_headers: flags=8 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DEBUG: get_hdr_body : content_length=0 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: get_hdr_field: cseq : <2> May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DEBUG: add_param: tag=329cfeaa6ded039da25ff8cbb8668bd2.4605 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DEBUG:parse_to:end of header reached, state=29 May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DBUG:parse_to: display={}, ruri={sip:*721111111111@sip.demo.com:5060} May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DEBUG: get_hdr_field: [83]; uri=[sip:*721111111111@sip.demo.com:5060] May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DEBUG: to body [] May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DEBUG: sl_filter_ACK : local ACK found -> dropping it! May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: DEBUG:destroy_avp_list: destroying list (nil) May 16 09:10:43 hostname /usr/local/sbin/openser[19435]: receive_msg: cleaning up