IPSEC/L2TP соединение: не доходит до ppp авторизации
Доброго дня, Коллеги.
После обновления до Fedora 32 перестало подключаться одно VPN-соединение. Сложности были на всем пути, но в итоге что-то не то происходит на этапе pppd.
Вводные данные: Подключаемся к довольно старому vpn-серверу (циска или винда). L2TP/IPSEC. Авторизация через PSK (IKE первой версии, v2 сервером не поддерживается), плюс «доменная» авторизация через MsChapV2 (обычные PAP и CHAP по словам администраторов отключены). Первая фаза - 3des-sha1-modp1024, вторая - 3des-sha1.
Настраивается все это сейчас через NetworkManager (т.к. было настроено в 30ой версии федоры и работало)
«Рекомендуемый» libreswan в 32ой федоре сразу сдался из-за выпиливания федорой поддержки modp1024 из него. Переключился на strongswan. Отмечу, что откат до libreswan<3.30 в итоге приводит к идентичному результату - валюсь на этапе pppd.
Если я правильно понимаю происходящее в логах, то запускается pppd, но до авторизации дело не доходит - появляется sigint. Для меня не очевидны два момента:
- Кто посылает sigint - pppd или x2ltpd?
- Как можно подойти ближе к пониманию причины ситуации, что ppp0 поднимается, но отваливается до начала авторизации.
Полный лог попытки соединения (снизу вверх)
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.3024] device[800d0c3c21317646] (p2p-dev-wlp4s0): add_pending_action (1): 'autoactivate'
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.3017] active-connection[0x560cc2eb84d0]: disposing
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.2983] agent-manager: agent[cbcd65a1dac75a5b,:1.536/nmcli-connect/0]: agent unregistered or disappeared
May 31 13:03:04 raypad NetworkManager[91583]: <info> [1590919384.2855] vpn-connection[0x560cc2eb84d0,f054844c-70c6-45f1-8d1c-ecc1127a188b,"vpn-con",0]: VPN service disappeared
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.2806] device[05a75d3145659c6b] (wlp4s0): remove_pending_action (0): 'activation-13'
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.2805] active-connection[0x560cc2eb84d0]: check-master-ready: not signalling (state deactivated, no master)
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.2800] active-connection[0x560cc2eb84d0]: set state deactivated (was activating)
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.2794] ++ vpn.secrets = ((GHashTable*) 0x560cc2e4b360) < ((GHashTable*) 0x560cc2e604c0)
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.2793] ++ vpn [ 0x560cc2e4b1c0 < 0x560cc2e3c740 ]
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.2793] ++ connection 'update connection' (0x560cc2e48640/NMSimpleConnection/"vpn" < 0x560cc2da1700/NMSimpleConnection/"vpn") [/org/freedesktop/NetworkManager/Settings/9]:
May 31 13:03:04 raypad NetworkManager[91583]: <info> [1590919384.2759] vpn-connection[0x560cc2eb84d0,f054844c-70c6-45f1-8d1c-ecc1127a188b,"vpn-con",0]: VPN plugin: state changed: stopped (6)
May 31 13:03:04 raypad nm-l2tp-service[166256]: ipsec shut down
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1980] platform-linux: udev-remove: IFINDEX=44
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1980] platform-linux: UDEV event: action 'remove' subsys 'net' device 'ppp0' (44); seqnum=5494
May 31 13:03:04 raypad ipsec_starter[166326]: ipsec starter stopped
May 31 13:03:04 raypad ipsec_starter[166326]: charon stopped after 200 ms
May 31 13:03:04 raypad ipsec_starter[166326]:
May 31 13:03:04 raypad ipsec_starter[166326]: child 166327 (charon) has quit (exit code 0)
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1794] platform-linux: UDEV event: action 'add' subsys 'net' device 'ppp0' (44); seqnum=5489
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1779] platform: signal: rt-rule removed: [6] 220: from all lookup 220
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1778] platform: signal: rt-rule removed: [4] 220: from all lookup 220
May 31 13:03:04 raypad pppd[166406]: Exit.
May 31 13:03:04 raypad charon[166327]: 00[NET] sending packet: from RIGHT_IP[4500] to LEFT_IP[4500] (84 bytes)
May 31 13:03:04 raypad charon[166327]: 00[ENC] generating INFORMATIONAL_V1 request 4280929317 [ HASH D ]
May 31 13:03:04 raypad charon[166327]: 00[IKE] sending DELETE for IKE_SA f054844c-70c6-45f1-8d1c-ecc1127a188b[1]
May 31 13:03:04 raypad charon[166327]: 00[IKE] deleting IKE_SA f054844c-70c6-45f1-8d1c-ecc1127a188b[1] between RIGHT_IP[RIGHT_IP]...LEFT_IP[IP_NAT (сервер за натом)]
May 31 13:03:04 raypad charon[166327]: 00[IKE] deleting IKE_SA f054844c-70c6-45f1-8d1c-ecc1127a188b[1] between RIGHT_IP[RIGHT_IP]...LEFT_IP[IP_NAT (сервер за натом)]
May 31 13:03:04 raypad charon[166327]: 00[NET] sending packet: from RIGHT_IP[4500] to LEFT_IP[4500] (76 bytes)
May 31 13:03:04 raypad charon[166327]: 00[ENC] generating INFORMATIONAL_V1 request 3217116315 [ HASH D ]
May 31 13:03:04 raypad charon[166327]: 00[IKE] sending DELETE for ESP CHILD_SA with SPI c1a5b0bf
May 31 13:03:04 raypad charon[166327]: 00[IKE] closing CHILD_SA f054844c-70c6-45f1-8d1c-ecc1127a188b{1} with SPIs c1a5b0bf_i (301 bytes) 6abf7b74_o (388 bytes) and TS RIGHT_IP/32[udp/l2tp] === LEFT_IP/32[udp/l2tp]
May 31 13:03:04 raypad audit: MAC_IPSEC_EVENT op=SAD-delete auid=4294967295 ses=4294967295 subj=system_u:system_r:ipsec_t:s0 src=RIGHT_IP dst=LEFT_IP spi=1790933876(0x6abf7b74) res=1
May 31 13:03:04 raypad audit: MAC_IPSEC_EVENT op=SAD-delete auid=4294967295 ses=4294967295 subj=system_u:system_r:ipsec_t:s0 src=LEFT_IP dst=RIGHT_IP spi=3248861375(0xc1a5b0bf) res=1
May 31 13:03:04 raypad audit: MAC_IPSEC_EVENT op=SPD-delete auid=4294967295 ses=4294967295 subj=system_u:system_r:ipsec_t:s0 res=1 src=LEFT_IP dst=RIGHT_IP
May 31 13:03:04 raypad audit: MAC_IPSEC_EVENT op=SPD-delete auid=4294967295 ses=4294967295 subj=system_u:system_r:ipsec_t:s0 res=1 src=RIGHT_IP dst=LEFT_IP
May 31 13:03:04 raypad charon[166327]: 00[IKE] closing CHILD_SA f054844c-70c6-45f1-8d1c-ecc1127a188b{1} with SPIs c1a5b0bf_i (301 bytes) 6abf7b74_o (388 bytes) and TS RIGHT_IP/32[udp/l2tp] === LEFT_IP/32[udp/l2tp]
May 31 13:03:04 raypad charon[166327]: 00[DMN] signal of type SIGINT received. Shutting down
May 31 13:03:04 raypad NetworkManager[166411]: Stopping strongSwan IPsec...
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1666] device[5287dbe269e131db] (ppp0): finalize(): NMDevicePpp
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1665] device[5287dbe269e131db] (ppp0): ip6-config: update (commit=1, new-config=(nil))
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1665] device[5287dbe269e131db] (ppp0): ip4-config: update (commit=1, new-config=(nil))
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1665] device[5287dbe269e131db] (ppp0): disposing
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1663] device[5287dbe269e131db] (ppp0): ip6-config: update (commit=0, new-config=(nil))
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1663] device[5287dbe269e131db] (ppp0): ip4-config: update (commit=0, new-config=(nil))
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1663] manager: (ppp0): removing device (managed 0, wol 0)
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1661] device[05a75d3145659c6b] (wlp4s0): ip4-config: update (commit=0, new-config=0x560cc2d6fe90)
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1657] device[5287dbe269e131db] (ppp0): state change: unmanaged -> unmanaged (reason 'unmanaged', sys-iface-state: 'removed')
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1656] device[5287dbe269e131db] (ppp0): unmanaged: flags set to [platform-init,!sleeping=0x10/0x11/unmanaged/unrealized], forget [parent,by-type,user-explicit,user-udev,external-down,is-slave=0x1c2c])
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1655] device[5287dbe269e131db] (ppp0): unrealize (ifindex 44)
May 31 13:03:04 raypad NetworkManager[91583]: <info> [1590919384.1654] vpn-connection[0x560cc2eb84d0,f054844c-70c6-45f1-8d1c-ecc1127a188b,"vpn-con",0]: VPN plugin: state changed: stopping (5)
May 31 13:03:04 raypad NetworkManager[91583]: <warn> [1590919384.1654] vpn-connection[0x560cc2eb84d0,f054844c-70c6-45f1-8d1c-ecc1127a188b,"vpn-con",0]: VPN plugin: failed: connect-failed (1)
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1652] device[05a75d3145659c6b] (wlp4s0): queued IP4 config change
May 31 13:03:04 raypad NetworkManager[166392]: xl2tpd[166392]: death_handler: Fatal signal 15 received
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1652] platform: (wlp4s0) signal: address 4 changed: RIGHT_IP/24 lft 83408sec pref 83408sec lifetime 2996-356[86048,86048] dev 4 flags noprefixroute src kernel
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1651] platform: signal: link removed: 44: ppp0 <NOARP,DOWN;pointopoint,multicast,noarp> mtu 1500 arp 512 ppp* not-init addrgenmode eui64 driver ppp rx:0,0 tx:0,0
May 31 13:03:04 raypad charon[166327]: 08[KNL] interface ppp0 deleted
May 31 13:03:04 raypad pppd[166406]: Connection terminated.
May 31 13:03:04 raypad pppd[166406]: Modem hangup
May 31 13:03:04 raypad pppd[166406]: Terminating on signal 15
May 31 13:03:04 raypad NetworkManager[166392]: xl2tpd[166392]: control_finish: Connection closed to LEFT_IP, serial 1 ()
May 31 13:03:04 raypad systemd-udevd[166409]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
May 31 13:03:04 raypad NetworkManager[91583]: <info> [1590919384.1566] manager: (ppp0): new Ppp device (/org/freedesktop/NetworkManager/Devices/18)
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1564] device[5287dbe269e131db] (ppp0): unmanaged: flags set to [platform-init,external-down,!sleeping,!by-type=0x810/0x819/unmanaged/unrealized], set-managed [sleeping=0x1])
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1563] device[5287dbe269e131db] (ppp0): unmanaged: flags set to [platform-init,external-down,!by-type=0x810/0x818/unmanaged/unrealized], set-managed [by-type=0x8])
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1563] device[5287dbe269e131db] (ppp0): unmanaged: flags set to [platform-init,external-down=0x810/0x810/unmanaged/unrealized], set-unmanaged [external-down=0x800])
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1563] platform-linux: error reading net:/sys/class/net/ppp0/device/sriov_totalvfs: Failed to open file "device/sriov_totalvfs" with openat: No such file or directory
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1561] platform-linux: error reading net:/sys/class/net/ppp0/phys_port_id: error reading 4096 bytes from file descriptor: Operation not supported
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1560] device[5287dbe269e131db] (ppp0): start setup of NMDevicePpp, kernel ifindex 44
May 31 13:03:04 raypad pppd[166406]: Connect: ppp0 <--> /dev/pts/28
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1560] device[5287dbe269e131db] (ppp0): constructed (NMDevicePpp)
May 31 13:03:04 raypad NetworkManager[91583]: <debug> [1590919384.1559] platform: (ppp0) signal: link added: 44: ppp0 <NOARP,DOWN;pointopoint,multicast,noarp> mtu 1500 arp 512 ppp* not-init addrgenmode eui64 driver ppp rx:0,0 tx:0,0
May 31 13:03:04 raypad pppd[166406]: Using interface ppp0
May 31 13:03:04 raypad pppd[166406]: pppd 2.4.7 started by root, uid 0
May 31 13:03:04 raypad pppd[166406]: Plugin /usr/lib64/pppd/2.4.7/nm-l2tp-pppd-plugin.so loaded.
May 31 13:03:04 raypad NetworkManager[166392]: xl2tpd[166392]: Call established with LEFT_IP, Local: 36228, Remote: 2, Serial: 1 (ref=0/0)
May 31 13:03:04 raypad NetworkManager[166392]: xl2tpd[166392]: Calling on tunnel 43375
May 31 13:03:04 raypad NetworkManager[166392]: xl2tpd[166392]: Connection established to LEFT_IP, 1701. Local: 43375, Remote: 7094 (ref=0/0).
May 31 13:03:04 raypad NetworkManager[166392]: xl2tpd[166392]: Connecting to host LEFT_IP, port 1701
May 31 13:03:04 raypad NetworkManager[166392]: xl2tpd[166392]: Listening on IP address 0.0.0.0, port 1701
May 31 13:03:04 raypad NetworkManager[166392]: xl2tpd[166392]: Forked again by Xelerance (www.xelerance.com) (C) 2006-2016
May 31 13:03:04 raypad NetworkManager[166392]: xl2tpd[166392]: Inherited by Jeff McAdams, (C) 2002
May 31 13:03:04 raypad NetworkManager[166392]: xl2tpd[166392]: Forked by Scott Balmos and David Stipp, (C) 2001
May 31 13:03:04 raypad NetworkManager[166392]: xl2tpd[166392]: Written by Mark Spencer, Copyright (C) 1998, Adtran, Inc.
May 31 13:03:04 raypad NetworkManager[166392]: xl2tpd[166392]: xl2tpd version xl2tpd-1.3.14 started on raypad PID:166392
May 31 13:03:04 raypad NetworkManager[166392]: xl2tpd[166392]: L2TP kernel support not detected (try modprobing l2tp_ppp and pppol2tp)
May 31 13:03:04 raypad NetworkManager[166392]: xl2tpd[166392]: Not looking for kernel SAref support.
May 31 13:03:04 raypad NetworkManager[91583]: <info> [1590919384.1190] vpn-connection[0x560cc2eb84d0,f054844c-70c6-45f1-8d1c-ecc1127a188b,"vpn-con",0]: VPN plugin: state changed: starting (3)
May 31 13:03:04 raypad nm-l2tp-service[166256]: xl2tpd started with pid 166392
May 31 13:03:03 raypad charon[166327]: 15[IKE] ignoring fourth Quick Mode message
May 31 13:03:03 raypad charon[166327]: 15[ENC] parsed QUICK_MODE response 663967856 [ HASH N(INIT_CONTACT) ]
May 31 13:03:03 raypad charon[166327]: 15[NET] received packet: from LEFT_IP[4500] to RIGHT_IP[4500] (76 bytes)
May 31 13:03:03 raypad NetworkManager[166376]: connection 'f054844c-70c6-45f1-8d1c-ecc1127a188b' established successfully
May 31 13:03:03 raypad NetworkManager[166376]: generating QUICK_MODE request 663967856 [ HASH ]
May 31 13:03:03 raypad NetworkManager[166376]: CHILD_SA f054844c-70c6-45f1-8d1c-ecc1127a188b{1} established with SPIs c1a5b0bf_i 6abf7b74_o and TS RIGHT_IP/32[udp/l2tp] === LEFT_IP/32[udp/l2tp]
May 31 13:03:03 raypad NetworkManager[166376]: selected proposal: ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ
May 31 13:03:03 raypad NetworkManager[166376]: parsed QUICK_MODE response 663967856 [ HASH SA No ID ID NAT-OA NAT-OA ]
May 31 13:03:03 raypad NetworkManager[166376]: received packet: from LEFT_IP[4500] to RIGHT_IP[4500] (212 bytes)
May 31 13:03:03 raypad NetworkManager[166376]: sending packet: from RIGHT_IP[4500] to LEFT_IP[4500] (220 bytes)
May 31 13:03:03 raypad NetworkManager[166376]: generating QUICK_MODE request 663967856 [ HASH SA No ID ID NAT-OA NAT-OA ]
May 31 13:03:03 raypad NetworkManager[166376]: maximum IKE_SA lifetime 10691s
May 31 13:03:03 raypad NetworkManager[166376]: scheduling reauthentication in 10151s
May 31 13:03:03 raypad NetworkManager[166376]: IKE_SA f054844c-70c6-45f1-8d1c-ecc1127a188b[1] established between RIGHT_IP[RIGHT_IP]...LEFT_IP[IP_NAT (сервер за натом)]
May 31 13:03:03 raypad NetworkManager[166376]: parsed ID_PROT response 0 [ ID HASH ]
May 31 13:03:03 raypad NetworkManager[166376]: received packet: from LEFT_IP[4500] to RIGHT_IP[4500] (68 bytes)
May 31 13:03:03 raypad NetworkManager[166376]: sending packet: from RIGHT_IP[4500] to LEFT_IP[4500] (100 bytes)
May 31 13:03:03 raypad NetworkManager[166376]: generating ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
May 31 13:03:03 raypad NetworkManager[166376]: remote host is behind NAT
May 31 13:03:03 raypad NetworkManager[166376]: local host is behind NAT, sending keep alives
May 31 13:03:03 raypad NetworkManager[166376]: parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
May 31 13:03:03 raypad NetworkManager[166376]: received packet: from LEFT_IP[500] to RIGHT_IP[500] (260 bytes)
May 31 13:03:03 raypad NetworkManager[166376]: sending packet: from RIGHT_IP[500] to LEFT_IP[500] (244 bytes)
May 31 13:03:03 raypad NetworkManager[166376]: generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
May 31 13:03:03 raypad NetworkManager[166376]: selected proposal: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
May 31 13:03:03 raypad NetworkManager[166376]: received unknown vendor ID: e3:a5:96:6a:76:37:9f:e7:07:22:82:31:e5:ce:86:52
May 31 13:03:03 raypad NetworkManager[166376]: received unknown vendor ID: fb:1d:e3:cd:f3:41:b7:ea:16:b7:e5:be:08:55:f1:20
May 31 13:03:03 raypad NetworkManager[166376]: received FRAGMENTATION vendor ID
May 31 13:03:03 raypad NetworkManager[166376]: received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
May 31 13:03:03 raypad NetworkManager[166376]: received NAT-T (RFC 3947) vendor ID
May 31 13:03:03 raypad NetworkManager[166376]: received MS NT5 ISAKMPOAKLEY vendor ID
May 31 13:03:03 raypad NetworkManager[166376]: parsed ID_PROT response 0 [ SA V V V V V V ]
May 31 13:03:03 raypad NetworkManager[166376]: received packet: from LEFT_IP[500] to RIGHT_IP[500] (208 bytes)
May 31 13:03:03 raypad NetworkManager[166376]: sending packet: from RIGHT_IP[500] to LEFT_IP[500] (236 bytes)
May 31 13:03:03 raypad NetworkManager[166376]: generating ID_PROT request 0 [ SA V V V V V ]
May 31 13:03:03 raypad NetworkManager[166376]: initiating Main Mode IKE_SA f054844c-70c6-45f1-8d1c-ecc1127a188b[1] to LEFT_IP
May 31 13:03:03 raypad charon[166327]: 01[NET] sending packet: from RIGHT_IP[4500] to LEFT_IP[4500] (60 bytes)
May 31 13:03:03 raypad charon[166327]: 01[ENC] generating QUICK_MODE request 663967856 [ HASH ]
May 31 13:03:03 raypad charon[166327]: 01[IKE] CHILD_SA f054844c-70c6-45f1-8d1c-ecc1127a188b{1} established with SPIs c1a5b0bf_i 6abf7b74_o and TS RIGHT_IP/32[udp/l2tp] === LEFT_IP/32[udp/l2tp]
May 31 13:03:03 raypad charon[166327]: 01[IKE] CHILD_SA f054844c-70c6-45f1-8d1c-ecc1127a188b{1} established with SPIs c1a5b0bf_i 6abf7b74_o and TS RIGHT_IP/32[udp/l2tp] === LEFT_IP/32[udp/l2tp]
May 31 13:03:03 raypad audit: MAC_IPSEC_EVENT op=SPD-add auid=4294967295 ses=4294967295 subj=system_u:system_r:ipsec_t:s0 res=1 src=RIGHT_IP dst=LEFT_IP
May 31 13:03:03 raypad audit: MAC_IPSEC_EVENT op=SPD-add auid=4294967295 ses=4294967295 subj=system_u:system_r:ipsec_t:s0 res=1 src=LEFT_IP dst=RIGHT_IP
May 31 13:03:03 raypad audit: MAC_IPSEC_EVENT op=SAD-add auid=4294967295 ses=4294967295 subj=system_u:system_r:ipsec_t:s0 src=RIGHT_IP dst=LEFT_IP spi=1790933876(0x6abf7b74) res=1
May 31 13:03:03 raypad audit: MAC_IPSEC_EVENT op=SAD-add auid=4294967295 ses=4294967295 subj=system_u:system_r:ipsec_t:s0 src=LEFT_IP dst=RIGHT_IP spi=3248861375(0xc1a5b0bf) res=1
May 31 13:03:03 raypad charon[166327]: 01[CFG] selected proposal: ESP:3DES_CBC/HMAC_SHA1_96/NO_EXT_SEQ
May 31 13:03:03 raypad charon[166327]: 01[ENC] parsed QUICK_MODE response 663967856 [ HASH SA No ID ID NAT-OA NAT-OA ]
May 31 13:03:03 raypad charon[166327]: 01[NET] received packet: from LEFT_IP[4500] to RIGHT_IP[4500] (212 bytes)
May 31 13:03:03 raypad charon[166327]: 12[NET] sending packet: from RIGHT_IP[4500] to LEFT_IP[4500] (220 bytes)
May 31 13:03:03 raypad charon[166327]: 12[ENC] generating QUICK_MODE request 663967856 [ HASH SA No ID ID NAT-OA NAT-OA ]
May 31 13:03:03 raypad charon[166327]: 12[IKE] maximum IKE_SA lifetime 10691s
May 31 13:03:03 raypad charon[166327]: 12[IKE] scheduling reauthentication in 10151s
May 31 13:03:03 raypad charon[166327]: 12[IKE] IKE_SA f054844c-70c6-45f1-8d1c-ecc1127a188b[1] established between RIGHT_IP[RIGHT_IP]...LEFT_IP[IP_NAT (сервер за натом)]
May 31 13:03:03 raypad charon[166327]: 12[IKE] IKE_SA f054844c-70c6-45f1-8d1c-ecc1127a188b[1] established between RIGHT_IP[RIGHT_IP]...LEFT_IP[IP_NAT (сервер за натом)]
May 31 13:03:03 raypad charon[166327]: 12[ENC] parsed ID_PROT response 0 [ ID HASH ]
May 31 13:03:03 raypad charon[166327]: 12[NET] received packet: from LEFT_IP[4500] to RIGHT_IP[4500] (68 bytes)
May 31 13:03:03 raypad charon[166327]: 14[NET] sending packet: from RIGHT_IP[4500] to LEFT_IP[4500] (100 bytes)
May 31 13:03:03 raypad charon[166327]: 14[ENC] generating ID_PROT request 0 [ ID HASH N(INITIAL_CONTACT) ]
May 31 13:03:03 raypad charon[166327]: 14[IKE] remote host is behind NAT
May 31 13:03:03 raypad charon[166327]: 14[IKE] local host is behind NAT, sending keep alives
May 31 13:03:03 raypad charon[166327]: 14[ENC] parsed ID_PROT response 0 [ KE No NAT-D NAT-D ]
May 31 13:03:03 raypad charon[166327]: 14[NET] received packet: from LEFT_IP[500] to RIGHT_IP[500] (260 bytes)
May 31 13:03:03 raypad charon[166327]: 13[NET] sending packet: from RIGHT_IP[500] to LEFT_IP[500] (244 bytes)
May 31 13:03:03 raypad charon[166327]: 13[ENC] generating ID_PROT request 0 [ KE No NAT-D NAT-D ]
May 31 13:03:03 raypad charon[166327]: 13[CFG] selected proposal: IKE:3DES_CBC/HMAC_SHA1_96/PRF_HMAC_SHA1/MODP_1024
May 31 13:03:03 raypad charon[166327]: 13[ENC] received unknown vendor ID: e3:a5:96:6a:76:37:9f:e7:07:22:82:31:e5:ce:86:52
May 31 13:03:03 raypad charon[166327]: 13[ENC] received unknown vendor ID: fb:1d:e3:cd:f3:41:b7:ea:16:b7:e5:be:08:55:f1:20
May 31 13:03:03 raypad charon[166327]: 13[IKE] received FRAGMENTATION vendor ID
May 31 13:03:03 raypad charon[166327]: 13[IKE] received draft-ietf-ipsec-nat-t-ike-02\n vendor ID
May 31 13:03:03 raypad charon[166327]: 13[IKE] received NAT-T (RFC 3947) vendor ID
May 31 13:03:03 raypad charon[166327]: 13[IKE] received MS NT5 ISAKMPOAKLEY vendor ID
May 31 13:03:03 raypad charon[166327]: 13[ENC] parsed ID_PROT response 0 [ SA V V V V V V ]
May 31 13:03:03 raypad charon[166327]: 13[NET] received packet: from LEFT_IP[500] to RIGHT_IP[500] (208 bytes)
May 31 13:03:03 raypad charon[166327]: 11[NET] sending packet: from RIGHT_IP[500] to LEFT_IP[500] (236 bytes)
May 31 13:03:03 raypad charon[166327]: 11[ENC] generating ID_PROT request 0 [ SA V V V V V ]
May 31 13:03:03 raypad charon[166327]: 11[IKE] initiating Main Mode IKE_SA f054844c-70c6-45f1-8d1c-ecc1127a188b[1] to LEFT_IP
May 31 13:03:03 raypad charon[166327]: 11[IKE] initiating Main Mode IKE_SA f054844c-70c6-45f1-8d1c-ecc1127a188b[1] to LEFT_IP
May 31 13:03:03 raypad charon[166327]: 09[CFG] received stroke: initiate 'f054844c-70c6-45f1-8d1c-ecc1127a188b'
May 31 13:03:03 raypad charon[166327]: 08[CFG] loaded IKE secret for IP_NAT (сервер за натом)
May 31 13:03:03 raypad charon[166327]: 08[CFG] loading secrets from '/etc/strongswan/ipsec.d/ipsec.nm-l2tp.secrets'
May 31 13:03:03 raypad charon[166327]: 08[CFG] loaded IKE secret for LEFT_IP
May 31 13:03:03 raypad charon[166327]: 08[CFG] loaded IKE secret for IP_NAT (сервер за натом)
May 31 13:03:03 raypad charon[166327]: 08[CFG] loading secrets from '/etc/strongswan/ipsec.secrets'
May 31 13:03:03 raypad charon[166327]: 08[CFG] rereading secrets
May 31 13:03:02 raypad charon[166327]: 05[CFG] added configuration 'f054844c-70c6-45f1-8d1c-ecc1127a188b'
May 31 13:03:02 raypad charon[166327]: 05[CFG] received stroke: add connection 'f054844c-70c6-45f1-8d1c-ecc1127a188b'
May 31 13:03:02 raypad ipsec_starter[166326]: charon (166327) started after 60 ms
May 31 13:03:02 raypad charon[166327]: 00[JOB] spawning 16 worker threads
May 31 13:03:02 raypad charon[166327]: 00[LIB] loaded plugins: charon pkcs11 tpm aesni aes des rc2 sha2 sha1 md4 md5 mgf1 random nonce x509 revocation constraints acert pubkey pkcs1 pkcs7 pkcs8 pkcs12 pgp dnskey sshkey pem openssl gcrypt fips-prf gmp curve25519 chapoly xcb>
May 31 13:03:02 raypad charon[166327]: 00[CFG] no script for ext-auth script defined, disabled
May 31 13:03:02 raypad charon[166327]: 00[CFG] HA config misses local/remote address
May 31 13:03:02 raypad charon[166327]: 00[CFG] loaded 0 RADIUS server configurations
May 31 13:03:02 raypad charon[166327]: 00[CFG] opening triplet file /etc/strongswan/ipsec.d/triplets.dat failed: No such file or directory
May 31 13:03:02 raypad charon[166327]: 00[CFG] loaded IKE secret for IP_NAT (сервер за натом)
May 31 13:03:02 raypad charon[166327]: 00[CFG] loading secrets from '/etc/strongswan/ipsec.d/ipsec.nm-l2tp.secrets'
May 31 13:03:02 raypad charon[166327]: 00[CFG] loaded IKE secret for LEFT_IP
May 31 13:03:02 raypad charon[166327]: 00[CFG] loaded IKE secret for IP_NAT (сервер за натом)
May 31 13:03:02 raypad charon[166327]: 00[CFG] loading secrets from '/etc/strongswan/ipsec.secrets'
May 31 13:03:02 raypad charon[166327]: 00[CFG] loading crls from '/etc/strongswan/ipsec.d/crls'
May 31 13:03:02 raypad charon[166327]: 00[CFG] loading attribute certificates from '/etc/strongswan/ipsec.d/acerts'
May 31 13:03:02 raypad charon[166327]: 00[CFG] loading ocsp signer certificates from '/etc/strongswan/ipsec.d/ocspcerts'
May 31 13:03:02 raypad charon[166327]: 00[CFG] loading aa certificates from '/etc/strongswan/ipsec.d/aacerts'
May 31 13:03:02 raypad charon[166327]: 00[CFG] loading ca certificates from '/etc/strongswan/ipsec.d/cacerts'
May 31 13:03:02 raypad NetworkManager[91583]: <debug> [1590919382.8483] platform: signal: rt-rule added: [6] 220: from all lookup 220
May 31 13:03:02 raypad NetworkManager[91583]: <debug> [1590919382.8481] platform: signal: rt-rule added: [4] 220: from all lookup 220
May 31 13:03:02 raypad charon[166327]: 00[LIB] openssl FIPS mode(2) - enabled
May 31 13:03:02 raypad charon[166327]: 00[CFG] PKCS11 module '<name>' lacks library path
May 31 13:03:02 raypad charon[166327]: 00[DMN] Starting IKE charon daemon (strongSwan 5.8.4, Linux 5.6.14-300.fc32.x86_64, x86_64)
May 31 13:03:02 raypad ipsec_starter[166326]: Attempting to start charon...
May 31 13:03:02 raypad ipsec_starter[166267]: Loading conn 'f054844c-70c6-45f1-8d1c-ecc1127a188b'
May 31 13:03:02 raypad ipsec_starter[166267]: Loading config setup
May 31 13:03:02 raypad ipsec_starter[166267]: Starting strongSwan 5.8.4 IPsec [starter]...
May 31 13:03:02 raypad NetworkManager[166267]: Loading conn 'f054844c-70c6-45f1-8d1c-ecc1127a188b'
May 31 13:03:02 raypad NetworkManager[166267]: Loading config setup
May 31 13:03:02 raypad NetworkManager[166267]: Starting strongSwan 5.8.4 IPsec [starter]...
May 31 13:03:00 raypad NetworkManager[166270]: Stopping strongSwan IPsec failed: starter is not running
May 31 13:03:00 raypad nm-l2tp-service[166256]: Check port 1701
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7754] vpn-connection[0x560cc2eb84d0,f054844c-70c6-45f1-8d1c-ecc1127a188b,"vpn-con",0]: VPN connection: falling back to non-interactive connect
May 31 13:03:00 raypad NetworkManager[91583]: <info> [1590919380.7753] vpn-connection[0x560cc2eb84d0,f054844c-70c6-45f1-8d1c-ecc1127a188b,"vpn-con",0]: VPN connection: (ConnectInteractive) reply received
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7747] device[800d0c3c21317646] (p2p-dev-wlp4s0): remove_pending_action (0): 'autoactivate'
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7745] device[800d0c3c21317646] (p2p-dev-wlp4s0): add_pending_action (1): 'autoactivate'
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7743] vpn-connection[0x560cc2eb84d0,f054844c-70c6-45f1-8d1c-ecc1127a188b,"vpn-con",0]: Allowing interactive secrets as all agents have that capability
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7741] vpn-connection[0x560cc2eb84d0,f054844c-70c6-45f1-8d1c-ecc1127a188b,"vpn-con",0]: service indicated no additional secrets required
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7720] vpn-connection[0x560cc2eb84d0,f054844c-70c6-45f1-8d1c-ecc1127a188b,"vpn-con",0]: asking service if additional secrets are required
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7708] settings-connection[3b12d61357701335,f054844c-70c6-45f1-8d1c-ecc1127a188b]: (vpn:0x560cc2dc1190) new agent secrets processed
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7706] settings-connection[3b12d61357701335,f054844c-70c6-45f1-8d1c-ecc1127a188b]: (vpn:0x560cc2dc1190) secrets request completed
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7706] settings-connection[3b12d61357701335,f054844c-70c6-45f1-8d1c-ecc1127a188b]: (vpn:0x560cc2dc1190) existing secrets returned
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7702] agent-manager: ([6188a4ce4f5653d9/"vpn-con"/"vpn"]) system settings secrets sufficient
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7700] settings-connection[3b12d61357701335,f054844c-70c6-45f1-8d1c-ecc1127a188b]: (vpn:0x560cc2e98030) secrets requested flags 0x80000004 hints '(none)'
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7699] Secrets requested for connection /org/freedesktop/NetworkManager/Settings/9 (vpn-con/vpn)
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7693] vpn-connection[0x560cc2eb84d0,f054844c-70c6-45f1-8d1c-ecc1127a188b,"vpn-con",0]: requesting VPN secrets pass #1
May 31 13:03:00 raypad NetworkManager[91583]: <info> [1590919380.7689] vpn-connection[0x560cc2eb84d0,f054844c-70c6-45f1-8d1c-ecc1127a188b,"vpn-con",0]: Saw the service appear; activating connection
May 31 13:03:00 raypad NetworkManager[91583]: <info> [1590919380.7584] vpn-connection[0x560cc2eb84d0,f054844c-70c6-45f1-8d1c-ecc1127a188b,"vpn-con",0]: Started the VPN service, PID 166256
May 31 13:03:00 raypad NetworkManager[91583]: <info> [1590919380.7540] audit: op="connection-activate" uuid="f054844c-70c6-45f1-8d1c-ecc1127a188b" name="vpn-con" pid=166250 uid=0 result="success"
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7530] active-connection[0x560cc2eb84d0]: check-master-ready: not signalling (state activating, no master)
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7527] active-connection[0x560cc2eb84d0]: set state activating (was unknown)
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7523] active-connection[0x560cc2eb84d0]: constructed (NMVpnConnection, version-id 13, type managed)
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7520] device[05a75d3145659c6b] (wlp4s0): add_pending_action (1): 'activation-13'
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7520] active-connection[0x560cc2eb84d0]: set device "wlp4s0" [0x560cc2e01e20]
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7511] policy: re-enabling autoconnect for all connections (only clear no-secrets flag)
May 31 13:03:00 raypad NetworkManager[91583]: <info> [1590919380.7510] agent-manager: agent[cbcd65a1dac75a5b,:1.536/nmcli-connect/0]: agent registered
May 31 13:03:00 raypad NetworkManager[91583]: <debug> [1590919380.7508] agent-manager: agent[cbcd65a1dac75a5b,:1.536/nmcli-connect/0]: requesting permissions
Заранее спасибо за совет или подсказку куда копать дальше.