strongswan IKEv2 disable reauth (NetworkManager)
Clash Royale CLAN TAG#URR8PPP
up vote
0
down vote
favorite
I've set up a VPN connection using IKEv2 to my Draytek router which works for one hour then just disconnects (and I can't reconnect unless I reboot). From what I found so far it might be related to IKEv2 rekeying which (according to https://wiki.strongswan.org/issues/852) doesn't work when using NetworkManager.
I can't prove it's the problem because my NetworkManager logs doesn't say anything about rekeying but if I connect to VPN at 12:26:46 and I get disconnected at 13:26:43 then I guess it's pretty obvious.
2018-11-17T12:26:46.490725+01:00 localhost NetworkManager[1937]: <info> [1542454006.4903] audit: op="connection-activate" uuid="7b78625f-5ba4-40bc-9915-63594471d282" name="NORDPRIM" pid=2780 uid=1000 result="success"
2018-11-17T12:26:46.510417+01:00 localhost NetworkManager[1937]: <info> [1542454006.5100] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Saw the service appear; activating connection
2018-11-17T12:26:46.553825+01:00 localhost NetworkManager[1937]: <info> [1542454006.5534] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: state changed: starting (3)
2018-11-17T12:26:46.664157+01:00 localhost NetworkManager[1937]: <info> [1542454006.6639] audit: op="statistics" arg="refresh-rate-ms" pid=2780 uid=1000 result="success"
2018-11-17T12:26:47.447069+01:00 localhost NetworkManager[1937]: <info> [1542454007.4449] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN connection: (IP4 Config Get) reply received from old-style plugin
2018-11-17T12:26:47.450333+01:00 localhost NetworkManager[1937]: <info> [1542454007.4489] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: VPN Gateway: xxx.xxx.xxx.xxx
2018-11-17T12:26:47.451473+01:00 localhost NetworkManager[1937]: <info> [1542454007.4491] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Tunnel Device: (null)
2018-11-17T12:26:47.452541+01:00 localhost NetworkManager[1937]: <info> [1542454007.4492] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: IPv4 configuration:
2018-11-17T12:26:47.454486+01:00 localhost NetworkManager[1937]: <info> [1542454007.4492] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal Address: 192.168.10.200
2018-11-17T12:26:47.455723+01:00 localhost NetworkManager[1937]: <info> [1542454007.4494] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal Prefix: 32
2018-11-17T12:26:47.456819+01:00 localhost NetworkManager[1937]: <info> [1542454007.4494] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal Point-to-Point Address: 192.168.10.200
2018-11-17T12:26:47.458186+01:00 localhost NetworkManager[1937]: <info> [1542454007.4495] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Static Route: 192.168.10.200/32 Next Hop: 0.0.0.0
2018-11-17T12:26:47.459736+01:00 localhost NetworkManager[1937]: <info> [1542454007.4496] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal DNS: 192.168.10.254
2018-11-17T12:26:47.461054+01:00 localhost NetworkManager[1937]: <info> [1542454007.4497] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: DNS Domain: '(none)'
2018-11-17T12:26:47.462320+01:00 localhost NetworkManager[1937]: <info> [1542454007.4498] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: No IPv6 configuration
2018-11-17T12:26:47.464758+01:00 localhost NetworkManager[1937]: <info> [1542454007.4552] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN connection: (IP Config Get) complete
2018-11-17T12:26:47.466061+01:00 localhost NetworkManager[1937]: <info> [1542454007.4565] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: state changed: started (4)
2018-11-17T12:26:48.157574+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T12:26:48.158068+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T12:26:48.170065+01:00 localhost nm-dispatcher: req:2 'vpn-up' [wlan0]: new request (4 scripts)
2018-11-17T12:26:48.170889+01:00 localhost nm-dispatcher: req:2 'vpn-up' [wlan0]: start running ordered scripts...
2018-11-17T12:26:48.275138+01:00 localhost NetworkManager[1937]: <info> [1542454008.2746] audit: op="statistics" arg="refresh-rate-ms" pid=2780 uid=1000 result="success"
2018-11-17T13:26:42.161130+01:00 localhost NetworkManager[1937]: <warn> [1542457602.1599] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: failed: connect-failed (1)
2018-11-17T13:26:42.161848+01:00 localhost NetworkManager[1937]: <info> [1542457602.1607] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: state changed: stopped (6)
2018-11-17T13:26:43.030375+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T13:26:43.031301+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T13:26:43.139098+01:00 localhost nm-dispatcher: req:1 'vpn-down' [wlan0]: new request (4 scripts)
2018-11-17T13:26:43.140352+01:00 localhost nm-dispatcher: req:1 'vpn-down' [wlan0]: start running ordered scripts...
2018-11-17T13:26:46.555364+01:00 localhost NetworkManager[1937]: <info> [1542457606.5551] dhcp4 (wlan0): address 192.168.1.109
2018-11-17T13:26:46.555873+01:00 localhost NetworkManager[1937]: <info> [1542457606.5552] dhcp4 (wlan0): plen 24 (255.255.255.0)
2018-11-17T13:26:46.556324+01:00 localhost NetworkManager[1937]: <info> [1542457606.5552] dhcp4 (wlan0): gateway 192.168.1.1
2018-11-17T13:26:46.556781+01:00 localhost NetworkManager[1937]: <info> [1542457606.5552] dhcp4 (wlan0): lease time 7200
2018-11-17T13:26:46.557225+01:00 localhost NetworkManager[1937]: <info> [1542457606.5553] dhcp4 (wlan0): nameserver '192.168.1.1'
2018-11-17T13:26:46.557687+01:00 localhost NetworkManager[1937]: <info> [1542457606.5553] dhcp4 (wlan0): state changed bound -> bound
2018-11-17T13:26:46.559480+01:00 localhost nm-dispatcher: req:2 'dhcp4-change' [wlan0]: new request (4 scripts)
2018-11-17T13:26:46.560084+01:00 localhost nm-dispatcher: req:2 'dhcp4-change' [wlan0]: start running ordered scripts...
Anyway, I can't work it out how to configure logging of NetworkManager's strongswan connections and neither I know where to disable rekeying (reauth) for those connections. Can anybody tell me that?
Using openSUSE Leap 15
EDIT:
syslog as asked in comments: https://pastebin.com/HG3VTrQg
EDIT2:
syslog from router: https://pastebin.com/VdcbhWM1
I've only filtered it by time so it's more or less the same as the logs from my computer. I don't see anything about disconnecting VPN around 13:26 so I've put all router's logs from that time.
There were 3 clients connecting with VPN to router - bartek, piotr and filip, we are looking at filip (bartek was connecting with Shrew VPN which works with no problem and piotr was using IKEv2 with strongSwan too, wasn't disconnected in the same time as me but would get disconnected eventually as he is using the same configuration as me)
networkmanager vpn strongswan
|
show 2 more comments
up vote
0
down vote
favorite
I've set up a VPN connection using IKEv2 to my Draytek router which works for one hour then just disconnects (and I can't reconnect unless I reboot). From what I found so far it might be related to IKEv2 rekeying which (according to https://wiki.strongswan.org/issues/852) doesn't work when using NetworkManager.
I can't prove it's the problem because my NetworkManager logs doesn't say anything about rekeying but if I connect to VPN at 12:26:46 and I get disconnected at 13:26:43 then I guess it's pretty obvious.
2018-11-17T12:26:46.490725+01:00 localhost NetworkManager[1937]: <info> [1542454006.4903] audit: op="connection-activate" uuid="7b78625f-5ba4-40bc-9915-63594471d282" name="NORDPRIM" pid=2780 uid=1000 result="success"
2018-11-17T12:26:46.510417+01:00 localhost NetworkManager[1937]: <info> [1542454006.5100] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Saw the service appear; activating connection
2018-11-17T12:26:46.553825+01:00 localhost NetworkManager[1937]: <info> [1542454006.5534] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: state changed: starting (3)
2018-11-17T12:26:46.664157+01:00 localhost NetworkManager[1937]: <info> [1542454006.6639] audit: op="statistics" arg="refresh-rate-ms" pid=2780 uid=1000 result="success"
2018-11-17T12:26:47.447069+01:00 localhost NetworkManager[1937]: <info> [1542454007.4449] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN connection: (IP4 Config Get) reply received from old-style plugin
2018-11-17T12:26:47.450333+01:00 localhost NetworkManager[1937]: <info> [1542454007.4489] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: VPN Gateway: xxx.xxx.xxx.xxx
2018-11-17T12:26:47.451473+01:00 localhost NetworkManager[1937]: <info> [1542454007.4491] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Tunnel Device: (null)
2018-11-17T12:26:47.452541+01:00 localhost NetworkManager[1937]: <info> [1542454007.4492] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: IPv4 configuration:
2018-11-17T12:26:47.454486+01:00 localhost NetworkManager[1937]: <info> [1542454007.4492] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal Address: 192.168.10.200
2018-11-17T12:26:47.455723+01:00 localhost NetworkManager[1937]: <info> [1542454007.4494] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal Prefix: 32
2018-11-17T12:26:47.456819+01:00 localhost NetworkManager[1937]: <info> [1542454007.4494] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal Point-to-Point Address: 192.168.10.200
2018-11-17T12:26:47.458186+01:00 localhost NetworkManager[1937]: <info> [1542454007.4495] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Static Route: 192.168.10.200/32 Next Hop: 0.0.0.0
2018-11-17T12:26:47.459736+01:00 localhost NetworkManager[1937]: <info> [1542454007.4496] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal DNS: 192.168.10.254
2018-11-17T12:26:47.461054+01:00 localhost NetworkManager[1937]: <info> [1542454007.4497] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: DNS Domain: '(none)'
2018-11-17T12:26:47.462320+01:00 localhost NetworkManager[1937]: <info> [1542454007.4498] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: No IPv6 configuration
2018-11-17T12:26:47.464758+01:00 localhost NetworkManager[1937]: <info> [1542454007.4552] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN connection: (IP Config Get) complete
2018-11-17T12:26:47.466061+01:00 localhost NetworkManager[1937]: <info> [1542454007.4565] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: state changed: started (4)
2018-11-17T12:26:48.157574+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T12:26:48.158068+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T12:26:48.170065+01:00 localhost nm-dispatcher: req:2 'vpn-up' [wlan0]: new request (4 scripts)
2018-11-17T12:26:48.170889+01:00 localhost nm-dispatcher: req:2 'vpn-up' [wlan0]: start running ordered scripts...
2018-11-17T12:26:48.275138+01:00 localhost NetworkManager[1937]: <info> [1542454008.2746] audit: op="statistics" arg="refresh-rate-ms" pid=2780 uid=1000 result="success"
2018-11-17T13:26:42.161130+01:00 localhost NetworkManager[1937]: <warn> [1542457602.1599] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: failed: connect-failed (1)
2018-11-17T13:26:42.161848+01:00 localhost NetworkManager[1937]: <info> [1542457602.1607] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: state changed: stopped (6)
2018-11-17T13:26:43.030375+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T13:26:43.031301+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T13:26:43.139098+01:00 localhost nm-dispatcher: req:1 'vpn-down' [wlan0]: new request (4 scripts)
2018-11-17T13:26:43.140352+01:00 localhost nm-dispatcher: req:1 'vpn-down' [wlan0]: start running ordered scripts...
2018-11-17T13:26:46.555364+01:00 localhost NetworkManager[1937]: <info> [1542457606.5551] dhcp4 (wlan0): address 192.168.1.109
2018-11-17T13:26:46.555873+01:00 localhost NetworkManager[1937]: <info> [1542457606.5552] dhcp4 (wlan0): plen 24 (255.255.255.0)
2018-11-17T13:26:46.556324+01:00 localhost NetworkManager[1937]: <info> [1542457606.5552] dhcp4 (wlan0): gateway 192.168.1.1
2018-11-17T13:26:46.556781+01:00 localhost NetworkManager[1937]: <info> [1542457606.5552] dhcp4 (wlan0): lease time 7200
2018-11-17T13:26:46.557225+01:00 localhost NetworkManager[1937]: <info> [1542457606.5553] dhcp4 (wlan0): nameserver '192.168.1.1'
2018-11-17T13:26:46.557687+01:00 localhost NetworkManager[1937]: <info> [1542457606.5553] dhcp4 (wlan0): state changed bound -> bound
2018-11-17T13:26:46.559480+01:00 localhost nm-dispatcher: req:2 'dhcp4-change' [wlan0]: new request (4 scripts)
2018-11-17T13:26:46.560084+01:00 localhost nm-dispatcher: req:2 'dhcp4-change' [wlan0]: start running ordered scripts...
Anyway, I can't work it out how to configure logging of NetworkManager's strongswan connections and neither I know where to disable rekeying (reauth) for those connections. Can anybody tell me that?
Using openSUSE Leap 15
EDIT:
syslog as asked in comments: https://pastebin.com/HG3VTrQg
EDIT2:
syslog from router: https://pastebin.com/VdcbhWM1
I've only filtered it by time so it's more or less the same as the logs from my computer. I don't see anything about disconnecting VPN around 13:26 so I've put all router's logs from that time.
There were 3 clients connecting with VPN to router - bartek, piotr and filip, we are looking at filip (bartek was connecting with Shrew VPN which works with no problem and piotr was using IKEv2 with strongSwan too, wasn't disconnected in the same time as me but would get disconnected eventually as he is using the same configuration as me)
networkmanager vpn strongswan
If you are actually using strongSwan, could you post the log fromcharon-nm
? Anything related to IKE (e.g. reauthentication or rekeying) would be logged by that daemon. It should log to syslog (daemon
facility), but you can change that.
– ecdsa
Nov 20 at 12:31
I edited my post with link to charon-nm log
– FilipK
Nov 20 at 13:25
Reauthentication is definitely not the problem as no reauthentication is scheduled. Instead the peer simply deletes the CHILD_SA after one hour (the client simply receives aDELETE
for it, there doesn't seem to be any attempt at rekeying it before that). You should check the log of the peer. Also, the client seems to have problems afterwards to get a response to the IKE_AUTH request (maybe the peer doesn't receive the request, ignores it, or the response does not reach the client). Again, logs of the peer might help.
– ecdsa
Nov 20 at 16:26
Edit with router logs
– FilipK
Nov 21 at 7:12
Note that the router's timestamps are in UTC (i.e. one hour behind the other). At 12:26:41 it logs that it deletes an IKEv2 CHILD_SA, unfortunately, without any indication why. Then when the client tries to reestablish the connection it seems to get confused with the still existing IKE_SA (at around 12:29:23). Regarding the CHILD_SA deletion, do you perhaps have an idle timeout configured on the router?
– ecdsa
Nov 21 at 9:02
|
show 2 more comments
up vote
0
down vote
favorite
up vote
0
down vote
favorite
I've set up a VPN connection using IKEv2 to my Draytek router which works for one hour then just disconnects (and I can't reconnect unless I reboot). From what I found so far it might be related to IKEv2 rekeying which (according to https://wiki.strongswan.org/issues/852) doesn't work when using NetworkManager.
I can't prove it's the problem because my NetworkManager logs doesn't say anything about rekeying but if I connect to VPN at 12:26:46 and I get disconnected at 13:26:43 then I guess it's pretty obvious.
2018-11-17T12:26:46.490725+01:00 localhost NetworkManager[1937]: <info> [1542454006.4903] audit: op="connection-activate" uuid="7b78625f-5ba4-40bc-9915-63594471d282" name="NORDPRIM" pid=2780 uid=1000 result="success"
2018-11-17T12:26:46.510417+01:00 localhost NetworkManager[1937]: <info> [1542454006.5100] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Saw the service appear; activating connection
2018-11-17T12:26:46.553825+01:00 localhost NetworkManager[1937]: <info> [1542454006.5534] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: state changed: starting (3)
2018-11-17T12:26:46.664157+01:00 localhost NetworkManager[1937]: <info> [1542454006.6639] audit: op="statistics" arg="refresh-rate-ms" pid=2780 uid=1000 result="success"
2018-11-17T12:26:47.447069+01:00 localhost NetworkManager[1937]: <info> [1542454007.4449] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN connection: (IP4 Config Get) reply received from old-style plugin
2018-11-17T12:26:47.450333+01:00 localhost NetworkManager[1937]: <info> [1542454007.4489] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: VPN Gateway: xxx.xxx.xxx.xxx
2018-11-17T12:26:47.451473+01:00 localhost NetworkManager[1937]: <info> [1542454007.4491] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Tunnel Device: (null)
2018-11-17T12:26:47.452541+01:00 localhost NetworkManager[1937]: <info> [1542454007.4492] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: IPv4 configuration:
2018-11-17T12:26:47.454486+01:00 localhost NetworkManager[1937]: <info> [1542454007.4492] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal Address: 192.168.10.200
2018-11-17T12:26:47.455723+01:00 localhost NetworkManager[1937]: <info> [1542454007.4494] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal Prefix: 32
2018-11-17T12:26:47.456819+01:00 localhost NetworkManager[1937]: <info> [1542454007.4494] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal Point-to-Point Address: 192.168.10.200
2018-11-17T12:26:47.458186+01:00 localhost NetworkManager[1937]: <info> [1542454007.4495] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Static Route: 192.168.10.200/32 Next Hop: 0.0.0.0
2018-11-17T12:26:47.459736+01:00 localhost NetworkManager[1937]: <info> [1542454007.4496] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal DNS: 192.168.10.254
2018-11-17T12:26:47.461054+01:00 localhost NetworkManager[1937]: <info> [1542454007.4497] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: DNS Domain: '(none)'
2018-11-17T12:26:47.462320+01:00 localhost NetworkManager[1937]: <info> [1542454007.4498] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: No IPv6 configuration
2018-11-17T12:26:47.464758+01:00 localhost NetworkManager[1937]: <info> [1542454007.4552] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN connection: (IP Config Get) complete
2018-11-17T12:26:47.466061+01:00 localhost NetworkManager[1937]: <info> [1542454007.4565] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: state changed: started (4)
2018-11-17T12:26:48.157574+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T12:26:48.158068+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T12:26:48.170065+01:00 localhost nm-dispatcher: req:2 'vpn-up' [wlan0]: new request (4 scripts)
2018-11-17T12:26:48.170889+01:00 localhost nm-dispatcher: req:2 'vpn-up' [wlan0]: start running ordered scripts...
2018-11-17T12:26:48.275138+01:00 localhost NetworkManager[1937]: <info> [1542454008.2746] audit: op="statistics" arg="refresh-rate-ms" pid=2780 uid=1000 result="success"
2018-11-17T13:26:42.161130+01:00 localhost NetworkManager[1937]: <warn> [1542457602.1599] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: failed: connect-failed (1)
2018-11-17T13:26:42.161848+01:00 localhost NetworkManager[1937]: <info> [1542457602.1607] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: state changed: stopped (6)
2018-11-17T13:26:43.030375+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T13:26:43.031301+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T13:26:43.139098+01:00 localhost nm-dispatcher: req:1 'vpn-down' [wlan0]: new request (4 scripts)
2018-11-17T13:26:43.140352+01:00 localhost nm-dispatcher: req:1 'vpn-down' [wlan0]: start running ordered scripts...
2018-11-17T13:26:46.555364+01:00 localhost NetworkManager[1937]: <info> [1542457606.5551] dhcp4 (wlan0): address 192.168.1.109
2018-11-17T13:26:46.555873+01:00 localhost NetworkManager[1937]: <info> [1542457606.5552] dhcp4 (wlan0): plen 24 (255.255.255.0)
2018-11-17T13:26:46.556324+01:00 localhost NetworkManager[1937]: <info> [1542457606.5552] dhcp4 (wlan0): gateway 192.168.1.1
2018-11-17T13:26:46.556781+01:00 localhost NetworkManager[1937]: <info> [1542457606.5552] dhcp4 (wlan0): lease time 7200
2018-11-17T13:26:46.557225+01:00 localhost NetworkManager[1937]: <info> [1542457606.5553] dhcp4 (wlan0): nameserver '192.168.1.1'
2018-11-17T13:26:46.557687+01:00 localhost NetworkManager[1937]: <info> [1542457606.5553] dhcp4 (wlan0): state changed bound -> bound
2018-11-17T13:26:46.559480+01:00 localhost nm-dispatcher: req:2 'dhcp4-change' [wlan0]: new request (4 scripts)
2018-11-17T13:26:46.560084+01:00 localhost nm-dispatcher: req:2 'dhcp4-change' [wlan0]: start running ordered scripts...
Anyway, I can't work it out how to configure logging of NetworkManager's strongswan connections and neither I know where to disable rekeying (reauth) for those connections. Can anybody tell me that?
Using openSUSE Leap 15
EDIT:
syslog as asked in comments: https://pastebin.com/HG3VTrQg
EDIT2:
syslog from router: https://pastebin.com/VdcbhWM1
I've only filtered it by time so it's more or less the same as the logs from my computer. I don't see anything about disconnecting VPN around 13:26 so I've put all router's logs from that time.
There were 3 clients connecting with VPN to router - bartek, piotr and filip, we are looking at filip (bartek was connecting with Shrew VPN which works with no problem and piotr was using IKEv2 with strongSwan too, wasn't disconnected in the same time as me but would get disconnected eventually as he is using the same configuration as me)
networkmanager vpn strongswan
I've set up a VPN connection using IKEv2 to my Draytek router which works for one hour then just disconnects (and I can't reconnect unless I reboot). From what I found so far it might be related to IKEv2 rekeying which (according to https://wiki.strongswan.org/issues/852) doesn't work when using NetworkManager.
I can't prove it's the problem because my NetworkManager logs doesn't say anything about rekeying but if I connect to VPN at 12:26:46 and I get disconnected at 13:26:43 then I guess it's pretty obvious.
2018-11-17T12:26:46.490725+01:00 localhost NetworkManager[1937]: <info> [1542454006.4903] audit: op="connection-activate" uuid="7b78625f-5ba4-40bc-9915-63594471d282" name="NORDPRIM" pid=2780 uid=1000 result="success"
2018-11-17T12:26:46.510417+01:00 localhost NetworkManager[1937]: <info> [1542454006.5100] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Saw the service appear; activating connection
2018-11-17T12:26:46.553825+01:00 localhost NetworkManager[1937]: <info> [1542454006.5534] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: state changed: starting (3)
2018-11-17T12:26:46.664157+01:00 localhost NetworkManager[1937]: <info> [1542454006.6639] audit: op="statistics" arg="refresh-rate-ms" pid=2780 uid=1000 result="success"
2018-11-17T12:26:47.447069+01:00 localhost NetworkManager[1937]: <info> [1542454007.4449] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN connection: (IP4 Config Get) reply received from old-style plugin
2018-11-17T12:26:47.450333+01:00 localhost NetworkManager[1937]: <info> [1542454007.4489] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: VPN Gateway: xxx.xxx.xxx.xxx
2018-11-17T12:26:47.451473+01:00 localhost NetworkManager[1937]: <info> [1542454007.4491] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Tunnel Device: (null)
2018-11-17T12:26:47.452541+01:00 localhost NetworkManager[1937]: <info> [1542454007.4492] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: IPv4 configuration:
2018-11-17T12:26:47.454486+01:00 localhost NetworkManager[1937]: <info> [1542454007.4492] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal Address: 192.168.10.200
2018-11-17T12:26:47.455723+01:00 localhost NetworkManager[1937]: <info> [1542454007.4494] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal Prefix: 32
2018-11-17T12:26:47.456819+01:00 localhost NetworkManager[1937]: <info> [1542454007.4494] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal Point-to-Point Address: 192.168.10.200
2018-11-17T12:26:47.458186+01:00 localhost NetworkManager[1937]: <info> [1542454007.4495] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Static Route: 192.168.10.200/32 Next Hop: 0.0.0.0
2018-11-17T12:26:47.459736+01:00 localhost NetworkManager[1937]: <info> [1542454007.4496] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: Internal DNS: 192.168.10.254
2018-11-17T12:26:47.461054+01:00 localhost NetworkManager[1937]: <info> [1542454007.4497] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: DNS Domain: '(none)'
2018-11-17T12:26:47.462320+01:00 localhost NetworkManager[1937]: <info> [1542454007.4498] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: Data: No IPv6 configuration
2018-11-17T12:26:47.464758+01:00 localhost NetworkManager[1937]: <info> [1542454007.4552] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN connection: (IP Config Get) complete
2018-11-17T12:26:47.466061+01:00 localhost NetworkManager[1937]: <info> [1542454007.4565] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: state changed: started (4)
2018-11-17T12:26:48.157574+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T12:26:48.158068+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T12:26:48.170065+01:00 localhost nm-dispatcher: req:2 'vpn-up' [wlan0]: new request (4 scripts)
2018-11-17T12:26:48.170889+01:00 localhost nm-dispatcher: req:2 'vpn-up' [wlan0]: start running ordered scripts...
2018-11-17T12:26:48.275138+01:00 localhost NetworkManager[1937]: <info> [1542454008.2746] audit: op="statistics" arg="refresh-rate-ms" pid=2780 uid=1000 result="success"
2018-11-17T13:26:42.161130+01:00 localhost NetworkManager[1937]: <warn> [1542457602.1599] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: failed: connect-failed (1)
2018-11-17T13:26:42.161848+01:00 localhost NetworkManager[1937]: <info> [1542457602.1607] vpn-connection[0x55801e07a300,7b78625f-5ba4-40bc-9915-63594471d282,"NORDPRIM",0]: VPN plugin: state changed: stopped (6)
2018-11-17T13:26:43.030375+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T13:26:43.031301+01:00 localhost NetworkManager[1937]: nisdomainname: you must be root to change the domain name
2018-11-17T13:26:43.139098+01:00 localhost nm-dispatcher: req:1 'vpn-down' [wlan0]: new request (4 scripts)
2018-11-17T13:26:43.140352+01:00 localhost nm-dispatcher: req:1 'vpn-down' [wlan0]: start running ordered scripts...
2018-11-17T13:26:46.555364+01:00 localhost NetworkManager[1937]: <info> [1542457606.5551] dhcp4 (wlan0): address 192.168.1.109
2018-11-17T13:26:46.555873+01:00 localhost NetworkManager[1937]: <info> [1542457606.5552] dhcp4 (wlan0): plen 24 (255.255.255.0)
2018-11-17T13:26:46.556324+01:00 localhost NetworkManager[1937]: <info> [1542457606.5552] dhcp4 (wlan0): gateway 192.168.1.1
2018-11-17T13:26:46.556781+01:00 localhost NetworkManager[1937]: <info> [1542457606.5552] dhcp4 (wlan0): lease time 7200
2018-11-17T13:26:46.557225+01:00 localhost NetworkManager[1937]: <info> [1542457606.5553] dhcp4 (wlan0): nameserver '192.168.1.1'
2018-11-17T13:26:46.557687+01:00 localhost NetworkManager[1937]: <info> [1542457606.5553] dhcp4 (wlan0): state changed bound -> bound
2018-11-17T13:26:46.559480+01:00 localhost nm-dispatcher: req:2 'dhcp4-change' [wlan0]: new request (4 scripts)
2018-11-17T13:26:46.560084+01:00 localhost nm-dispatcher: req:2 'dhcp4-change' [wlan0]: start running ordered scripts...
Anyway, I can't work it out how to configure logging of NetworkManager's strongswan connections and neither I know where to disable rekeying (reauth) for those connections. Can anybody tell me that?
Using openSUSE Leap 15
EDIT:
syslog as asked in comments: https://pastebin.com/HG3VTrQg
EDIT2:
syslog from router: https://pastebin.com/VdcbhWM1
I've only filtered it by time so it's more or less the same as the logs from my computer. I don't see anything about disconnecting VPN around 13:26 so I've put all router's logs from that time.
There were 3 clients connecting with VPN to router - bartek, piotr and filip, we are looking at filip (bartek was connecting with Shrew VPN which works with no problem and piotr was using IKEv2 with strongSwan too, wasn't disconnected in the same time as me but would get disconnected eventually as he is using the same configuration as me)
networkmanager vpn strongswan
networkmanager vpn strongswan
edited Nov 21 at 7:12
asked Nov 20 at 9:25
FilipK
487
487
If you are actually using strongSwan, could you post the log fromcharon-nm
? Anything related to IKE (e.g. reauthentication or rekeying) would be logged by that daemon. It should log to syslog (daemon
facility), but you can change that.
– ecdsa
Nov 20 at 12:31
I edited my post with link to charon-nm log
– FilipK
Nov 20 at 13:25
Reauthentication is definitely not the problem as no reauthentication is scheduled. Instead the peer simply deletes the CHILD_SA after one hour (the client simply receives aDELETE
for it, there doesn't seem to be any attempt at rekeying it before that). You should check the log of the peer. Also, the client seems to have problems afterwards to get a response to the IKE_AUTH request (maybe the peer doesn't receive the request, ignores it, or the response does not reach the client). Again, logs of the peer might help.
– ecdsa
Nov 20 at 16:26
Edit with router logs
– FilipK
Nov 21 at 7:12
Note that the router's timestamps are in UTC (i.e. one hour behind the other). At 12:26:41 it logs that it deletes an IKEv2 CHILD_SA, unfortunately, without any indication why. Then when the client tries to reestablish the connection it seems to get confused with the still existing IKE_SA (at around 12:29:23). Regarding the CHILD_SA deletion, do you perhaps have an idle timeout configured on the router?
– ecdsa
Nov 21 at 9:02
|
show 2 more comments
If you are actually using strongSwan, could you post the log fromcharon-nm
? Anything related to IKE (e.g. reauthentication or rekeying) would be logged by that daemon. It should log to syslog (daemon
facility), but you can change that.
– ecdsa
Nov 20 at 12:31
I edited my post with link to charon-nm log
– FilipK
Nov 20 at 13:25
Reauthentication is definitely not the problem as no reauthentication is scheduled. Instead the peer simply deletes the CHILD_SA after one hour (the client simply receives aDELETE
for it, there doesn't seem to be any attempt at rekeying it before that). You should check the log of the peer. Also, the client seems to have problems afterwards to get a response to the IKE_AUTH request (maybe the peer doesn't receive the request, ignores it, or the response does not reach the client). Again, logs of the peer might help.
– ecdsa
Nov 20 at 16:26
Edit with router logs
– FilipK
Nov 21 at 7:12
Note that the router's timestamps are in UTC (i.e. one hour behind the other). At 12:26:41 it logs that it deletes an IKEv2 CHILD_SA, unfortunately, without any indication why. Then when the client tries to reestablish the connection it seems to get confused with the still existing IKE_SA (at around 12:29:23). Regarding the CHILD_SA deletion, do you perhaps have an idle timeout configured on the router?
– ecdsa
Nov 21 at 9:02
If you are actually using strongSwan, could you post the log from
charon-nm
? Anything related to IKE (e.g. reauthentication or rekeying) would be logged by that daemon. It should log to syslog (daemon
facility), but you can change that.– ecdsa
Nov 20 at 12:31
If you are actually using strongSwan, could you post the log from
charon-nm
? Anything related to IKE (e.g. reauthentication or rekeying) would be logged by that daemon. It should log to syslog (daemon
facility), but you can change that.– ecdsa
Nov 20 at 12:31
I edited my post with link to charon-nm log
– FilipK
Nov 20 at 13:25
I edited my post with link to charon-nm log
– FilipK
Nov 20 at 13:25
Reauthentication is definitely not the problem as no reauthentication is scheduled. Instead the peer simply deletes the CHILD_SA after one hour (the client simply receives a
DELETE
for it, there doesn't seem to be any attempt at rekeying it before that). You should check the log of the peer. Also, the client seems to have problems afterwards to get a response to the IKE_AUTH request (maybe the peer doesn't receive the request, ignores it, or the response does not reach the client). Again, logs of the peer might help.– ecdsa
Nov 20 at 16:26
Reauthentication is definitely not the problem as no reauthentication is scheduled. Instead the peer simply deletes the CHILD_SA after one hour (the client simply receives a
DELETE
for it, there doesn't seem to be any attempt at rekeying it before that). You should check the log of the peer. Also, the client seems to have problems afterwards to get a response to the IKE_AUTH request (maybe the peer doesn't receive the request, ignores it, or the response does not reach the client). Again, logs of the peer might help.– ecdsa
Nov 20 at 16:26
Edit with router logs
– FilipK
Nov 21 at 7:12
Edit with router logs
– FilipK
Nov 21 at 7:12
Note that the router's timestamps are in UTC (i.e. one hour behind the other). At 12:26:41 it logs that it deletes an IKEv2 CHILD_SA, unfortunately, without any indication why. Then when the client tries to reestablish the connection it seems to get confused with the still existing IKE_SA (at around 12:29:23). Regarding the CHILD_SA deletion, do you perhaps have an idle timeout configured on the router?
– ecdsa
Nov 21 at 9:02
Note that the router's timestamps are in UTC (i.e. one hour behind the other). At 12:26:41 it logs that it deletes an IKEv2 CHILD_SA, unfortunately, without any indication why. Then when the client tries to reestablish the connection it seems to get confused with the still existing IKE_SA (at around 12:29:23). Regarding the CHILD_SA deletion, do you perhaps have an idle timeout configured on the router?
– ecdsa
Nov 21 at 9:02
|
show 2 more comments
active
oldest
votes
active
oldest
votes
active
oldest
votes
active
oldest
votes
active
oldest
votes
Sign up or log in
StackExchange.ready(function ()
StackExchange.helpers.onClickDraftSave('#login-link');
);
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Post as a guest
Required, but never shown
StackExchange.ready(
function ()
StackExchange.openid.initPostLogin('.new-post-login', 'https%3a%2f%2funix.stackexchange.com%2fquestions%2f482919%2fstrongswan-ikev2-disable-reauth-networkmanager%23new-answer', 'question_page');
);
Post as a guest
Required, but never shown
Sign up or log in
StackExchange.ready(function ()
StackExchange.helpers.onClickDraftSave('#login-link');
);
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Post as a guest
Required, but never shown
Sign up or log in
StackExchange.ready(function ()
StackExchange.helpers.onClickDraftSave('#login-link');
);
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Post as a guest
Required, but never shown
Sign up or log in
StackExchange.ready(function ()
StackExchange.helpers.onClickDraftSave('#login-link');
);
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Sign up using Google
Sign up using Facebook
Sign up using Email and Password
Post as a guest
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
Required, but never shown
If you are actually using strongSwan, could you post the log from
charon-nm
? Anything related to IKE (e.g. reauthentication or rekeying) would be logged by that daemon. It should log to syslog (daemon
facility), but you can change that.– ecdsa
Nov 20 at 12:31
I edited my post with link to charon-nm log
– FilipK
Nov 20 at 13:25
Reauthentication is definitely not the problem as no reauthentication is scheduled. Instead the peer simply deletes the CHILD_SA after one hour (the client simply receives a
DELETE
for it, there doesn't seem to be any attempt at rekeying it before that). You should check the log of the peer. Also, the client seems to have problems afterwards to get a response to the IKE_AUTH request (maybe the peer doesn't receive the request, ignores it, or the response does not reach the client). Again, logs of the peer might help.– ecdsa
Nov 20 at 16:26
Edit with router logs
– FilipK
Nov 21 at 7:12
Note that the router's timestamps are in UTC (i.e. one hour behind the other). At 12:26:41 it logs that it deletes an IKEv2 CHILD_SA, unfortunately, without any indication why. Then when the client tries to reestablish the connection it seems to get confused with the still existing IKE_SA (at around 12:29:23). Regarding the CHILD_SA deletion, do you perhaps have an idle timeout configured on the router?
– ecdsa
Nov 21 at 9:02