2023-01-08 13:02:47Z 32[NET] <1003> sending packet: from sophos.xyz.net[4500] to other_sophos.xyz.net[4500] (96 bytes)
2023-01-08 13:03:08Z 29[NET] <1004> received packet: from other_sophos.xyz.net[500] to sophos.xyz.net[500] (1434 bytes)
2023-01-08 13:03:08Z 29[ENC] <1004> parsed IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG) N(REDIR_SUP) ]
2023-01-08 13:03:08Z 29[IKE] <1004> other_sophos.xyz.net is initiating an IKE_SA
2023-01-08 13:03:08Z 29[IKE] <1004> remote host is behind NAT
2023-01-08 13:03:08Z 29[ENC] <1004> generating IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(FRAG_SUP) N(HASH_ALG) N(MULT_AUTH) ]
2023-01-08 13:03:08Z 29[NET] <1004> sending packet: from sophos.xyz.net[500] to other_sophos.xyz.net[500] (242 bytes)
2023-01-08 13:03:08Z 05[NET] <1004> received packet: from other_sophos.xyz.net[4500] to sophos.xyz.net[4500] (512 bytes)
2023-01-08 13:03:08Z 05[ENC] <1004> parsed IKE_AUTH request 1 [ IDi IDr AUTH SA TSi TSr N(MULT_AUTH) N(EAP_ONLY) N(MSG_ID_SYN_SUP) ]
2023-01-08 13:03:08Z 05[CFG] <1004> looking for peer configs matching sophos.xyz.net[[email protected]]...other_sophos.xyz.net[[email protected]]
2023-01-08 13:03:08Z 05[CFG] <TESTCON-1|1004> selected peer config 'TESTCON-1'
2023-01-08 13:03:08Z 05[IKE] <TESTCON-1|1004> authentication of '[email protected]' with pre-shared key successful
2023-01-08 13:03:08Z 05[IKE] <TESTCON-1|1004> authentication of '[email protected]' (myself) with pre-shared key
2023-01-08 13:03:08Z 05[IKE] <TESTCON-1|1004> IKE_SA TESTCON-1[1004] established between sophos.xyz.net[[email protected]]...other_sophos.xyz.net[[email protected]]
2023-01-08 13:03:08Z 05[IKE] <TESTCON-1|1004> scheduling rekeying in 5008s
2023-01-08 13:03:08Z 05[IKE] <TESTCON-1|1004> maximum IKE_SA lifetime 5368s
2023-01-08 13:03:08Z 05[IKE] <TESTCON-1|1004> CHILD_SA TESTCON-2{1186} established with SPIs c7b8957d_i c38ddeb9_o and TS 192.168.56.0/24 === 192.168.40.0/24
2023-01-08 13:03:08Z 05[APP] <TESTCON-1|1004> [COP-UPDOWN] (ref_counting) ref_count: 0 to 1 ++ up ++ (192.168.56.0/24#192.168.40.0/24)
2023-01-08 13:03:08Z 05[APP] <TESTCON-1|1004> [COP-UPDOWN] (ref_counting_remote) ref_count_remote: 0 to 1 ++ up ++ (sophos.xyz.net#other_sophos.xyz.net#n)
2023-01-08 13:03:08Z 05[APP] <TESTCON-1|1004> [COP-UPDOWN] (cop_updown_invoke_once) UID: 1004 Net: Local sophos.xyz.net Remote other_sophos.xyz.net Connection: TESTCON Fullname: TESTCON-1
2023-01-08 13:03:08Z 05[APP] <TESTCON-1|1004> [COP-UPDOWN] (cop_updown_invoke_once) Tunnel: User '' Peer-IP '' my-IP '' up-client
2023-01-08 13:03:08Z 05[ENC] <TESTCON-1|1004> generating IKE_AUTH response 1 [ IDr AUTH SA TSi TSr ]
2023-01-08 13:03:08Z 05[NET] <TESTCON-1|1004> sending packet: from sophos.xyz.net[4500] to other_sophos.xyz.net[4500] (288 bytes)
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][DB] (db_conn_info) hostname: 'TESTCON' result --> id: '3', mode: 'ntn', tunnel_type: '0', subnet_family:'0'
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) ---- exec remote updown ++ up ++
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][SHELL] (run_shell) '/bin/service fwm:vpn_gateway_chains -t json -s nosync -b '{"local_server":"sophos.xyz.net","remote_server":"other_sophos.xyz.net","action":"enable","family":"0","conntype":"ntn","compress":"0"}'': success 0
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) ---- exec subnet updown ++ up ++
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) [NTN] NTN get actual...
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][DB] (db_query) No data retrieved from query: 'SELECT ( nath.netid || '/' || nath.netmask ) AS natedlan FROM tblvpnconnhostrel AS rel JOIN tblhost AS h ON h.hostid = rel.hostid JOIN tblhost AS nath ON rel .natedhost = nath.hostid WHERE rel.connectionid = $1 AND rel.hostlocation = 'L' AND h.netid = $2 AND h.netmask = $3 LIMIT 1;' status: 2 rows: 0
2023-01-08 13:03:08Z 14[APP]
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) connection 'TESTCON' using interface 'ipsec0'
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][NET] (get_src_ip) source address for 192.168.56.0 is IP: 192.168.55.1
2023-01-08 13:03:08Z 14[APP]
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][SHELL] (run_shell) 'ip route add 192.168.40.0/24 dev ipsec0 src 192.168.55.1 table 220': success 0
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (add_routes) no routes to add for TESTCON on interface ipsec0
2023-01-08 13:03:08Z 16[NET] <TESTCON-1|1004> received packet: from other_sophos.xyz.net[4500] to sophos.xyz.net[4500] (1168 bytes)
2023-01-08 13:03:08Z 16[ENC] <TESTCON-1|1004> parsed CREATE_CHILD_SA request 2 [ SA No KE TSi TSr ]
2023-01-08 13:03:08Z 16[IKE] <TESTCON-1|1004> CHILD_SA TESTCON-1{1187} established with SPIs c1137571_i c42994e0_o and TS 192.168.56.0/24 === 192.168.37.0/24
2023-01-08 13:03:08Z 16[APP] <TESTCON-1|1004> [COP-UPDOWN] (ref_counting) ref_count: 0 to 1 ++ up ++ (192.168.56.0/24#192.168.37.0/24)
2023-01-08 13:03:08Z 16[APP] <TESTCON-1|1004> [COP-UPDOWN] (ref_counting_remote) ref_count_remote: 1 to 2 ++ up ++ (sophos.xyz.net#other_sophos.xyz.net#n)
2023-01-08 13:03:08Z 16[APP] <TESTCON-1|1004> [COP-UPDOWN] (cop_updown_invoke_once) UID: 1004 Net: Local sophos.xyz.net Remote other_sophos.xyz.net Connection: TESTCON Fullname: TESTCON-1
2023-01-08 13:03:08Z 16[APP] <TESTCON-1|1004> [COP-UPDOWN] (cop_updown_invoke_once) Tunnel: User '' Peer-IP '' my-IP '' up-client
2023-01-08 13:03:08Z 16[ENC] <TESTCON-1|1004> generating CREATE_CHILD_SA response 2 [ SA No KE TSi TSr ]
2023-01-08 13:03:08Z 16[NET] <TESTCON-1|1004> sending packet: from sophos.xyz.net[4500] to other_sophos.xyz.net[4500] (272 bytes)
2023-01-08 13:03:08Z 22[NET] <TESTCON-1|1004> received packet: from other_sophos.xyz.net[4500] to sophos.xyz.net[4500] (1168 bytes)
2023-01-08 13:03:08Z 22[ENC] <TESTCON-1|1004> parsed CREATE_CHILD_SA request 3 [ SA No KE TSi TSr ]
2023-01-08 13:03:08Z 22[IKE] <TESTCON-1|1004> CHILD_SA TESTCON-3{1188} established with SPIs ca8d59f8_i c69ac2d1_o and TS 192.168.56.0/24 === 192.168.39.0/24
2023-01-08 13:03:08Z 22[APP] <TESTCON-1|1004> [COP-UPDOWN] (ref_counting) ref_count: 0 to 1 ++ up ++ (192.168.56.0/24#192.168.39.0/24)
2023-01-08 13:03:08Z 22[APP] <TESTCON-1|1004> [COP-UPDOWN] (ref_counting_remote) ref_count_remote: 2 to 3 ++ up ++ (sophos.xyz.net#other_sophos.xyz.net#n)
2023-01-08 13:03:08Z 22[APP] <TESTCON-1|1004> [COP-UPDOWN] (cop_updown_invoke_once) UID: 1004 Net: Local sophos.xyz.net Remote other_sophos.xyz.net Connection: TESTCON Fullname: TESTCON-1
2023-01-08 13:03:08Z 22[APP] <TESTCON-1|1004> [COP-UPDOWN] (cop_updown_invoke_once) Tunnel: User '' Peer-IP '' my-IP '' up-client
2023-01-08 13:03:08Z 22[ENC] <TESTCON-1|1004> generating CREATE_CHILD_SA response 3 [ SA No KE TSi TSr ]
2023-01-08 13:03:08Z 22[NET] <TESTCON-1|1004> sending packet: from sophos.xyz.net[4500] to other_sophos.xyz.net[4500] (272 bytes)
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][SHELL] (run_shell) '/bin/service fwm:vpn_connection_chains -t json -s nosync -b '{"me":"sophos.xyz.net","peer":"other_sophos.xyz.net","mynet":"192.168.56.0/24","peernet":"192.168.40.0/24","connop":"1","iface":"Port2","myproto":"0","myport":"0","peerproto":"0","peerport":"0","conntype":"ntn","actnet":"","compress":"0","conn_id":"3"}'': success 0
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][DB] (db_conn_info) hostname: 'TESTCON' result --> id: '3', mode: 'ntn', tunnel_type: '0', subnet_family:'0'
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) !!SKIP!! IPsec IKE for remotes (sophos.xyz.net to other_sophos.xyz.net) already set up
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) ---- exec subnet updown ++ up ++
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) [NTN] NTN get actual...
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][DB] (db_query) No data retrieved from query: 'SELECT ( nath.netid || '/' || nath.netmask ) AS natedlan FROM tblvpnconnhostrel AS rel JOIN tblhost AS h ON h.hostid = rel.hostid JOIN tblhost AS nath ON rel .natedhost = nath.hostid WHERE rel.connectionid = $1 AND rel.hostlocation = 'L' AND h.netid = $2 AND h.netmask = $3 LIMIT 1;' status: 2 rows: 0
2023-01-08 13:03:08Z 14[APP]
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) connection 'TESTCON' using interface 'ipsec0'
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][NET] (get_src_ip) source address for 192.168.56.0 is IP: 192.168.55.1
2023-01-08 13:03:08Z 14[APP]
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][SHELL] (run_shell) 'ip route add 192.168.37.0/24 dev ipsec0 src 192.168.55.1 table 220': success 0
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (add_routes) no routes to add for TESTCON on interface ipsec0
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][SHELL] (run_shell) '/bin/service fwm:vpn_connection_chains -t json -s nosync -b '{"me":"sophos.xyz.net","peer":"other_sophos.xyz.net","mynet":"192.168.56.0/24","peernet":"192.168.37.0/24","connop":"1","iface":"Port2","myproto":"0","myport":"0","peerproto":"0","peerport":"0","conntype":"ntn","actnet":"","compress":"0","conn_id":"3"}'': success 0
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][DB] (db_conn_info) hostname: 'TESTCON' result --> id: '3', mode: 'ntn', tunnel_type: '0', subnet_family:'0'
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) !!SKIP!! IPsec IKE for remotes (sophos.xyz.net to other_sophos.xyz.net) already set up
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) ---- exec subnet updown ++ up ++
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) [NTN] NTN get actual...
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][DB] (db_query) No data retrieved from query: 'SELECT ( nath.netid || '/' || nath.netmask ) AS natedlan FROM tblvpnconnhostrel AS rel JOIN tblhost AS h ON h.hostid = rel.hostid JOIN tblhost AS nath ON rel .natedhost = nath.hostid WHERE rel.connectionid = $1 AND rel.hostlocation = 'L' AND h.netid = $2 AND h.netmask = $3 LIMIT 1;' status: 2 rows: 0
2023-01-08 13:03:08Z 14[APP]
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) connection 'TESTCON' using interface 'ipsec0'
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][NET] (get_src_ip) source address for 192.168.56.0 is IP: 192.168.55.1
2023-01-08 13:03:08Z 14[APP]
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][SHELL] (run_shell) 'ip route add 192.168.39.0/24 dev ipsec0 src 192.168.55.1 table 220': success 0
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN] (add_routes) no routes to add for TESTCON on interface ipsec0
2023-01-08 13:03:08Z 14[APP] [COP-UPDOWN][SHELL] (run_shell) '/bin/service fwm:vpn_connection_chains -t json -s nosync -b '{"me":"sophos.xyz.net","peer":"other_sophos.xyz.net","mynet":"192.168.56.0/24","peernet":"192.168.39.0/24","connop":"1","iface":"Port2","myproto":"0","myport":"0","peerproto":"0","peerport":"0","conntype":"ntn","actnet":"","compress":"0","conn_id":"3"}'': success 0