2023-03-21 14:08:45Z 10[NET] <7457> received packet: from aaa.aaa.aaa.aaa[500] to xxx.xxx.xxx.xxx[500] (468 bytes) 2023-03-21 14:08:45Z 10[ENC] <7457> parsed ID_PROT request 0 [ SA V V V V V V V V V V V V V ] 2023-03-21 14:08:45Z 10[IKE] <7457> received NAT-T (RFC 3947) vendor ID 2023-03-21 14:08:45Z 10[IKE] <7457> received draft-ietf-ipsec-nat-t-ike-08 vendor ID 2023-03-21 14:08:45Z 10[IKE] <7457> received draft-ietf-ipsec-nat-t-ike-07 vendor ID 2023-03-21 14:08:45Z 10[IKE] <7457> received draft-ietf-ipsec-nat-t-ike-06 vendor ID 2023-03-21 14:08:45Z 10[IKE] <7457> received draft-ietf-ipsec-nat-t-ike-05 vendor ID 2023-03-21 14:08:45Z 10[IKE] <7457> received draft-ietf-ipsec-nat-t-ike-04 vendor ID 2023-03-21 14:08:45Z 10[IKE] <7457> received draft-ietf-ipsec-nat-t-ike-03 vendor ID 2023-03-21 14:08:45Z 10[IKE] <7457> received draft-ietf-ipsec-nat-t-ike-02 vendor ID 2023-03-21 14:08:45Z 10[IKE] <7457> received draft-ietf-ipsec-nat-t-ike-02\n vendor ID 2023-03-21 14:08:45Z 10[ENC] <7457> received unknown vendor ID: 16:f6:ca:16:e4:a4:06:6d:83:82:1a:0f:0a:ea:a8:62 2023-03-21 14:08:45Z 10[IKE] <7457> received draft-ietf-ipsec-nat-t-ike-00 vendor ID 2023-03-21 14:08:45Z 10[IKE] <7457> received Cisco Unity vendor ID 2023-03-21 14:08:45Z 10[IKE] <7457> received DPD vendor ID 2023-03-21 14:08:45Z 10[IKE] <7457> aaa.aaa.aaa.aaa is initiating a Main Mode IKE_SA 2023-03-21 14:08:45Z 10[ENC] <7457> generating ID_PROT response 0 [ SA V V V V ] 2023-03-21 14:08:45Z 10[NET] <7457> sending packet: from xxx.xxx.xxx.xxx[500] to aaa.aaa.aaa.aaa[500] (160 bytes) 2023-03-21 14:08:45Z 32[NET] <7457> received packet: from aaa.aaa.aaa.aaa[500] to xxx.xxx.xxx.xxx[500] (388 bytes) 2023-03-21 14:08:45Z 32[ENC] <7457> parsed ID_PROT request 0 [ KE No NAT-D NAT-D ] 2023-03-21 14:08:45Z 32[IKE] <7457> remote host is behind NAT 2023-03-21 14:08:45Z 32[ENC] <7457> generating ID_PROT response 0 [ KE No NAT-D NAT-D ] 2023-03-21 14:08:45Z 32[NET] <7457> sending packet: from xxx.xxx.xxx.xxx[500] to aaa.aaa.aaa.aaa[500] (396 bytes) 2023-03-21 14:08:46Z 23[NET] <7457> received packet: from aaa.aaa.aaa.aaa[4500] to xxx.xxx.xxx.xxx[4500] (92 bytes) 2023-03-21 14:08:46Z 23[ENC] <7457> parsed ID_PROT request 0 [ ID HASH ] 2023-03-21 14:08:46Z 23[CFG] <7457> looking for pre-shared key peer configs matching xxx.xxx.xxx.xxx...aaa.aaa.aaa.aaa[192.168.99.112] 2023-03-21 14:08:46Z 23[CFG] <7457> selected peer config "HO_MKR_22-1" 2023-03-21 14:08:46Z 23[IKE] IKE_SA HO_MKR_22-1[7457] established between xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]...aaa.aaa.aaa.aaa[192.168.99.112] 2023-03-21 14:08:46Z 23[IKE] scheduling reauthentication in 1490s 2023-03-21 14:08:46Z 23[IKE] maximum IKE_SA lifetime 1670s 2023-03-21 14:08:46Z 23[ENC] generating ID_PROT response 0 [ ID HASH ] 2023-03-21 14:08:46Z 23[NET] sending packet: from xxx.xxx.xxx.xxx[4500] to aaa.aaa.aaa.aaa[4500] (92 bytes) 2023-03-21 14:08:46Z 08[NET] received packet: from aaa.aaa.aaa.aaa[4500] to xxx.xxx.xxx.xxx[4500] (396 bytes) 2023-03-21 14:08:46Z 08[ENC] parsed QUICK_MODE request 2837507934 [ HASH SA No KE ID ID NAT-OA NAT-OA ] 2023-03-21 14:08:46Z 08[IKE] ### process_request invoking quick_mode_create 2023-03-21 14:08:46Z 08[IKE] ### quick_mode_create: 0x7fdb10005400 config (nil) 2023-03-21 14:08:46Z 08[IKE] ### process_r: 0x7fdb10005400 QM_INIT 2023-03-21 14:08:46Z 08[IKE] ### build_r: 0x7fdb10005400 QM_INIT 2023-03-21 14:08:46Z 08[ENC] generating QUICK_MODE response 2837507934 [ HASH SA No KE ID ID NAT-OA NAT-OA ] 2023-03-21 14:08:46Z 08[NET] sending packet: from xxx.xxx.xxx.xxx[4500] to aaa.aaa.aaa.aaa[4500] (348 bytes) 2023-03-21 14:08:46Z 16[NET] received packet: from aaa.aaa.aaa.aaa[4500] to xxx.xxx.xxx.xxx[4500] (76 bytes) 2023-03-21 14:08:46Z 16[ENC] parsed QUICK_MODE request 2837507934 [ HASH ] 2023-03-21 14:08:46Z 16[IKE] ### process_r: 0x7fdb10005400 QM_NEGOTIATED 2023-03-21 14:08:46Z 16[IKE] CHILD_SA HO_MKR_22-1{120} established with SPIs ca38a56d_i 08609a77_o and TS xxx.xxx.xxx.xxx/32[udp/1701] === aaa.aaa.aaa.aaa/32[udp/1701] 2023-03-21 14:08:46Z 16[APP] [COP-UPDOWN] (ref_counting) ref_count: 0 to 1 ++ up ++ (xxx.xxx.xxx.xxx/32#aaa.aaa.aaa.aaa/32) 2023-03-21 14:08:46Z 16[APP] [COP-UPDOWN] (ref_counting_remote) ref_count_remote: 0 to 1 ++ up ++ (xxx.xxx.xxx.xxx#aaa.aaa.aaa.aaa#n) 2023-03-21 14:08:46Z 16[APP] [COP-UPDOWN] (cop_updown_invoke_once) UID: 7457 Net: Local xxx.xxx.xxx.xxx Remote aaa.aaa.aaa.aaa Connection: HO_MKR_22 Fullname: HO_MKR_22-1 2023-03-21 14:08:46Z 16[APP] [COP-UPDOWN] (cop_updown_invoke_once) Tunnel: User '' Peer-IP '' my-IP '' up-host 2023-03-21 14:08:46Z 16[IKE] ### destroy: 0x7fdb10005400 2023-03-21 14:08:46Z 20[APP] [COP-UPDOWN][DB] (db_conn_info) hostname: 'HO_MKR_22' result --> id: '22', mode: 'hth', tunnel_type: '1', subnet_family:'0' 2023-03-21 14:08:46Z 20[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) ---- exec remote updown ++ up ++ 2023-03-21 14:08:46Z 20[APP] [COP-UPDOWN][SHELL] (run_shell) '/bin/service fwm:vpn_gateway_chains -t json -s nosync -b '{"local_server":"xxx.xxx.xxx.xxx","remote_server":"aaa.aaa.aaa.aaa","action":"enable","family":"0","conntype":"hth","compress":"0"}'': success 0 2023-03-21 14:08:46Z 20[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) ---- exec subnet updown ++ up ++ 2023-03-21 14:08:46Z 20[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) connection 'HO_MKR_22' using interface 'ipsec0' 2023-03-21 14:08:46Z 20[APP] [COP-UPDOWN][NET] (get_src_ip) source address for xxx.xxx.xxx.xxx is IP: 178.255.138.226 2023-03-21 14:08:46Z 20[APP] 2023-03-21 14:08:46Z 20[APP] [COP-UPDOWN][SHELL] (run_shell) 'ip route add aaa.aaa.aaa.aaa/32 dev ipsec0 src 178.255.138.226 table 220': success 0 2023-03-21 14:08:46Z 20[APP] [COP-UPDOWN] (add_routes) no routes to add for HO_MKR_22 on interface ipsec0 2023-03-21 14:08:46Z 20[APP] [COP-UPDOWN][SHELL] (run_shell) '/bin/service fwm:vpn_connection_chains -t json -s nosync -b '{"me":"xxx.xxx.xxx.xxx","peer":"aaa.aaa.aaa.aaa","mynet":"xxx.xxx.xxx.xxx/32","peernet":"aaa.aaa.aaa.aaa/32","connop":"1","iface":"Port2","myproto":"17","myport":"1701","peerproto":"17","peerport":"1701","conntype":"hth","actnet":"","compress":"0","conn_id":"22"}'': error returned 255 2023-03-21 14:08:46Z 20[APP] [COP-UPDOWN][SHELL] (run_shell) '/bin/opcode set_timer_mail_updown -s nosync -t json -b '{"event":"up","conn":"HO_MKR_22","local_net":"xxx.xxx.xxx.xxx","remote_net":"aaa.aaa.aaa.aaa","reason":"0"}'': success 0 2023-03-21 14:08:47Z 27[KNL] interface ppp0 deleted 2023-03-21 14:08:48Z 28[NET] received packet: from aaa.aaa.aaa.aaa[4500] to xxx.xxx.xxx.xxx[4500] (92 bytes) 2023-03-21 14:08:48Z 28[ENC] parsed INFORMATIONAL_V1 request 4229190814 [ HASH D ] 2023-03-21 14:08:48Z 28[IKE] received DELETE for ESP CHILD_SA with SPI 08609a77 2023-03-21 14:08:48Z 28[IKE] closing CHILD_SA HO_MKR_22-1{120} with SPIs ca38a56d_i (522 bytes) 08609a77_o (911 bytes) and TS xxx.xxx.xxx.xxx/32[udp/1701] === aaa.aaa.aaa.aaa/32[udp/1701] 2023-03-21 14:08:48Z 28[APP] [COP-UPDOWN] (ref_counting) ref_count: 1 to 0 -- down -- (xxx.xxx.xxx.xxx/32#aaa.aaa.aaa.aaa/32) 2023-03-21 14:08:48Z 28[APP] [COP-UPDOWN] (ref_counting_remote) ref_count_remote: 1 to 0 -- down -- (xxx.xxx.xxx.xxx#aaa.aaa.aaa.aaa#n) 2023-03-21 14:08:48Z 28[APP] [COP-UPDOWN] (cop_updown_invoke_once) UID: 7457 Net: Local xxx.xxx.xxx.xxx Remote aaa.aaa.aaa.aaa Connection: HO_MKR_22 Fullname: HO_MKR_22-1 2023-03-21 14:08:48Z 28[APP] [COP-UPDOWN] (cop_updown_invoke_once) Tunnel: User '' Peer-IP '' my-IP '' down-host 2023-03-21 14:08:48Z 07[APP] [COP-UPDOWN][DB] (db_conn_info) hostname: 'HO_MKR_22' result --> id: '22', mode: 'hth', tunnel_type: '1', subnet_family:'0' 2023-03-21 14:08:48Z 07[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) ---- exec remote updown -- down -- 2023-03-21 14:08:48Z 09[NET] received packet: from aaa.aaa.aaa.aaa[4500] to xxx.xxx.xxx.xxx[4500] (108 bytes) 2023-03-21 14:08:48Z 09[ENC] parsed INFORMATIONAL_V1 request 3127051963 [ HASH D ] 2023-03-21 14:08:48Z 09[IKE] received DELETE for IKE_SA HO_MKR_22-1[7457] 2023-03-21 14:08:48Z 09[IKE] deleting IKE_SA HO_MKR_22-1[7457] between xxx.xxx.xxx.xxx[xxx.xxx.xxx.xxx]...aaa.aaa.aaa.aaa[192.168.99.112] 2023-03-21 14:08:48Z 07[APP] [COP-UPDOWN][SHELL] (run_shell) '/bin/service fwm:vpn_gateway_chains -t json -s nosync -b '{"local_server":"xxx.xxx.xxx.xxx","remote_server":"aaa.aaa.aaa.aaa","action":"disable","family":"0","conntype":"hth","compress":"0"}'': success 0 2023-03-21 14:08:48Z 07[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) ---- exec subnet updown -- down -- 2023-03-21 14:08:48Z 07[APP] [COP-UPDOWN] (do_cop_updown_invoke_once) connection 'HO_MKR_22' using interface 'ipsec0' 2023-03-21 14:08:48Z 07[APP] [COP-UPDOWN][NET] (get_src_ip) source address for xxx.xxx.xxx.xxx is IP: 178.255.138.226 2023-03-21 14:08:48Z 07[APP] 2023-03-21 14:08:48Z 07[APP] [COP-UPDOWN][SHELL] (run_shell) 'ip route del aaa.aaa.aaa.aaa/32 dev ipsec0 src 178.255.138.226 table 220': success 0 2023-03-21 14:08:48Z 07[APP] [COP-UPDOWN] (add_routes) no routes to del for HO_MKR_22 on interface ipsec0 2023-03-21 14:08:48Z 07[APP] [COP-UPDOWN][SHELL] (run_shell) '/bin/service fwm:vpn_connection_chains -t json -s nosync -b '{"me":"xxx.xxx.xxx.xxx","peer":"aaa.aaa.aaa.aaa","mynet":"xxx.xxx.xxx.xxx/32","peernet":"aaa.aaa.aaa.aaa/32","connop":"0","iface":"unknown","myproto":"17","myport":"1701","peerproto":"17","peerport":"1701","conntype":"hth","actnet":"","compress":"0","conn_id":"22"}'': error returned 255 2023-03-21 14:08:48Z 07[APP] [COP-UPDOWN][SHELL] (run_shell) '/bin/opcode set_timer_mail_updown -s nosync -t json -b '{"event":"down","conn":"HO_MKR_22","local_net":"xxx.xxx.xxx.xxx","remote_net":"aaa.aaa.aaa.aaa","reason":"0"}'': success 0