Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_msg: SIP Request:
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_msg:  method:  <ACK>
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_msg:  uri:     <sip:1.1.1.1:5068;did=05b.a11250a7>
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_msg:  version: <SIP/2.0>
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_headers: flags=2
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK-524287-1---eb7554506f089608>; state=6
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_via_param: found param type 235, <rport> = <n/a>; state=17
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_via: end of header reached, state=5
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_headers: via found, flags=2
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_headers: this is the first via
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:receive_msg: After parse_msg...
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:receive_msg: preparing to run routing scripts...
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:sl:sl_filter_ACK: too late to be a local ACK!
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialplan:dp_translate_f: dpid is 20007 partition is default
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialplan:dp_get_svalue: searching 34
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialplan:dp_translate_f: input is 2.2.2.2
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialplan:dp_translate_f: Checking with dpid 20007
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialplan:translate: Regex operator testing. Got result: -1
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: message repeated 73 times: [ DBG:dialplan:translate: Regex operator testing. Got result: -1]
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1422]: DBG:nathelper:nh_timer: resolving next hop: '2.2.2.2'
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialplan:translate: Regex operator testing. Got result: -1
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: message repeated 99 times: [ DBG:dialplan:translate: Regex operator testing. Got result: -1]
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialplan:translate: No matching rule for input 2.2.2.2
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialplan:dp_translate_f: could not translate 2.2.2.2 with dpid 20007
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:pike:mark_node: search on branch 192 (top=0x7f698ab1e370)
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:pike:mark_node: only first 1 were matched!
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:pike:pike_check_req: src IP [2.2.2.2],node=0x7f698ab1e370; hits=[2,1],[0,0] node_flags=2 func_flags=8
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:cachedb_fetch: from script [local] - no grp
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_headers: flags=8
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_to_param: tag=B456E0-7A5
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_to: end of header reached, state=29
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_to: display={}, ruri={sip:3364021@1.1.1.1:5068}
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:get_hdr_field: <To> [47]; uri=[sip:3364021@1.1.1.1:5068]
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:get_hdr_field: to body [<sip:3364021@1.1.1.1:5068>]
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:uri:has_totag: totag found
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_headers: flags=200
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:get_hdr_field: cseq <CSeq>: <2> <ACK>
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:get_hdr_field: content_length=0
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:get_hdr_field: found end of header
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:grep_sock_info: checking if host==us: 11==11 &&  [1.1.1.1] == [1.1.1.1]
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:grep_sock_info: checking if port 5060 matches port 5068
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:grep_sock_info: checking if host==us: 11==11 &&  [1.1.1.1] == [1.1.1.1]
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:grep_sock_info: checking if port 5068 matches port 5068
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:w_match_dialog: We found DID param in R-URI with value of 05b.a11250a7
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:dlg_onroute: route param is '05b.a11250a7' (len=12)
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:lookup_dlg: ref dlg 0x7f698ab1eb68 with 1 -> 4
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:lookup_dlg: dialog id=2047156506 found on entry 2896
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_headers: flags=58
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_to_param: tag=1d6f501a
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_to: end of header reached, state=29
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_to: display={"Denis"}, ruri={sip:8123092186@1.1.1.1:5068}
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:evi_param_set: adding string param
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:evi_param_set: adding string param
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:evi_param_set: adding int param
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:evi_param_set: adding int param
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:destroy_avp_list: destroying list (nil)
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:next_state_dlg: dialog 0x7f698ab1eb68 changed from state 3 to state 4, due event 6
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:dlg_onroute: sequential request successfully processed (dst_leg=1)
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:run_dlg_callbacks: dialog=0x7f698ab1eb68, type=16
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_headers: flags=ffffffffffffffff
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_headers: flags=ffffffffffffffff
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:topology_hiding:topo_delete_vias: Delete via [Via: SIP/2.0/UDP 2.2.2.2:59874;branch=z9hG4bK-524287-1---eb7554506f089608;rport#015#012]
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:fix_route_dialog: Next params [lr;ftag=1d6f501a;did=013.a495ba3]
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:fix_route_dialog: Fixing message. Next hop is Loose router
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:fix_route_dialog: Setting new URI to  <sip:3364021@3.3.3.3:5068>
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_headers: flags=ffffffffffffffff
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:fix_route_dialog: Setting route  header to <Route: <sip:3.3.3.3:5068;lr;ftag=1d6f501a;did=013.a495ba3>#015#012>
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:fix_route_dialog: setting dst_uri to <sip:3.3.3.3:5068;lr;ftag=1d6f501a;did=013.a495ba3>
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:ref_dlg: ref dlg 0x7f698ab1eb68 with 1 -> 5
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:topology_hiding:topo_dlg_onroute: forcing send socket for req going to callee
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:dlg_onroute: dialog_timeout: 10
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:set_final_update_cols: DLG vals and profiles should not be saved[1a:1]
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:write_dialog_profiles: profile string is <lbXcalls#1|>(11)
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_do_prepared_query: conn=0x7f698e000a18 (tail=140091330659136) MC=0x7f698e0003e0
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_do_prepared_query: new query=|update dialog set state=?,timeout=?,caller_cseq=?,callee_cseq=?,caller_ping_cseq=?,callee_ping_cseq=?,flags=?,vars=?,profiles=?,script_flags=?,module_flags=? where dlg_id=?|
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:re_init_statement:  query  is <update dialog set state=?,timeout=?,caller_cseq=?,callee_cseq=?,caller_ping_cseq=?,callee_ping_cseq=?,flags=?,vars=?,profiles=?,script_flags=?,module_flags=? where dlg_id=?>, ptr=(nil)
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_do_prepared_query: new statement(0x7f698e011098) on connection: (0x7f698e000a18) 0x7f698e000340
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_val2bind: added val (0): len=4; type=3; is_null=0
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_val2bind: added val (1): len=4; type=3; is_null=0
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_val2bind: added val (2): len=1; type=254; is_null=0
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_val2bind: added val (3): len=1; type=254; is_null=0
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_val2bind: added val (4): len=4; type=3; is_null=0
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_val2bind: added val (5): len=4; type=3; is_null=0
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_val2bind: added val (6): len=4; type=3; is_null=0
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_val2bind: added val (8): len=11; type=254; is_null=0
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_val2bind: added val (9): len=4; type=3; is_null=0
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_val2bind: added val (10): len=4; type=3; is_null=0
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_val2bind: added val (11): len=8; type=8; is_null=0
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:db_mysql:mysql_raise_event: MySQL status has not changed: connected
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:buf_init: initializing...
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:pv_get_authattr: no [Proxy-]Authorization header
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: Route0:ACK was received (IPS=2.2.2.2, IPD=3.3.3.3, CALLID=82158YjQ5YWE4OGZkNDk5NTAwZjk2ZTA3ZDFkYWVmZTRhZjA, FROMTAG=1d6f501a, TOTAG=B456E0-7A5, AUTH=<null>) and RURI = sip:3364021@3.3.3.3:5068/3.3.3.3
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:pv_get_authattr: no [Proxy-]Authorization header
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:tm:t_newtran: transaction on entrance=0xffffffffffffffff
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_headers: flags=ffffffffffffffff
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_headers: flags=78
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:tm:t_lookup_request: start searching: hash=31620, isACK=1
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:parse_headers: flags=38
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:tm:t_lookup_request: REF_UNSAFE:[0x7f698ab1fb88] after is 1
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:tm:t_lookup_request: e2e proxy ACK found
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:tm:t_newtran: building branch for end2end ACK - flags=1
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:tm:t_relay_to: forwarding ACK
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:mk_proxy: doing DNS lookup...
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:forward_request: sending:#012ACK sip:3364021@3.3.3.3:5068 SIP/2.0#015#012Route: <sip:3.3.3.3:5068;lr;ftag=1d6f501a;did=013.a495ba3>#015#012Via: SIP/2.0/UDP 1.1.1.1:5068;branch=z9hG4bK48b7.ecbeb277.2#015#012Max-Forwards: 70#015#012Contact: <sip:1.1.1.1:5068;did=05b.a11250a7>#015#012To: <sip:3364021@1.1.1.1:5068>;tag=B456E0-7A5#015#012From: "Denis"<sip:8123092186@1.1.1.1:5068>;tag=1d6f501a#015#012Call-ID: 82158YjQ5YWE4OGZkNDk5NTAwZjk2ZTA3ZDFkYWVmZTRhZjA#015#012CSeq: 2 ACK#015#012User-Agent: X-Lite release 4.9.6 stamp 82158#015#012Content-Length: 0#015#012#015#012.
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:forward_request: orig. len=483, new_len=498, proto=1
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:unref_dlg: unref dlg 0x7f698ab1eb68 with 1 -> 4 in entry 0x7f6987691a80
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:tm:t_unref_cell: UNREF_UNSAFE: [0x7f698ab1fb88] after is 0
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:dialog:unref_dlg: unref dlg 0x7f698ab1eb68 with 1 -> 3 in entry 0x7f6987691a80
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:destroy_avp_list: destroying list (nil)
Nov 15 09:25:58 ubuntu-amd64 /usr/local/opensipslb/sbin/opensips[1423]: DBG:core:receive_msg: cleaning up