Solved: OpenVPN filling server log

ninevoltz

I have a Netgear R7000 wireless router running the latest (3.5-140) AdvancedTomato firmware. This firmware includes OpenVPN 2.4.1, which I am using to connect to my home network from my workplace. I've noticed that it takes a few minutes to connect in the morning, and I can see a string of messages repeating in the system log. These log messages repeat forever until I connect to the server. Anyone know why this is happening?

The full OpenVPN version string:

OpenVPN 2.4.1 arm-unknown-linux-gnu [SSL (OpenSSL)] [LZO] [LZ4] [EPOLL] [MH/PKTINFO] [AEAD] built on Nov 17 2017

# Automatically generated configuration
daemon
proto udp
port 1194
dev tap21
cipher AES-256-CBC
comp-lzo yes
keepalive 15 60
verb 3
secret static.key
status-version 2
status status

remote x.x.x.x
port 1194
dev tap
secret staticvpn.key
proto udp4
comp-lzo
route-gateway 192.168.1.1
route-method exe
route-delay 2
cipher AES-256-CBC
ncp-disable
auth-nocache

The repeating log messages:

Aug 12 12:32:30 NightHawk daemon.notice openvpn[2133]: Outgoing Static Key Encryption: Cipher 'AES-256-CBC' initialized with 256 bit key
Aug 12 12:32:30 NightHawk daemon.notice openvpn[2133]: Outgoing Static Key Encryption: Using 160 bit message hash 'SHA1' for HMAC authentication
Aug 12 12:32:30 NightHawk daemon.notice openvpn[2133]: Incoming Static Key Encryption: Cipher 'AES-256-CBC' initialized with 256 bit key
Aug 12 12:32:30 NightHawk daemon.notice openvpn[2133]: Incoming Static Key Encryption: Using 160 bit message hash 'SHA1' for HMAC authentication
Aug 12 12:32:30 NightHawk daemon.notice openvpn[2133]: TUN/TAP device tap21 opened
Aug 12 12:32:30 NightHawk daemon.notice openvpn[2133]: TUN/TAP TX queue length set to 100
Aug 12 12:32:30 NightHawk daemon.warn openvpn[2133]: Could not determine IPv4/IPv6 protocol. Using AF_INET6
Aug 12 12:32:30 NightHawk daemon.notice openvpn[2133]: Socket Buffers: R=[120832->120832] S=[120832->120832]
Aug 12 12:32:30 NightHawk daemon.notice openvpn[2133]: setsockopt(IPV6_V6ONLY=0)
Aug 12 12:32:30 NightHawk daemon.notice openvpn[2133]: UDPv6 link local (bound): [AF_INET6][undef]:1194
Aug 12 12:32:30 NightHawk daemon.notice openvpn[2133]: UDPv6 link remote: [AF_UNSPEC]
Aug 12 12:32:30 NightHawk kern.info kernel: br0: port 4(tap21) entering forwarding state
Aug 12 12:32:30 NightHawk kern.info kernel: br0: port 4(tap21) entering forwarding state
Aug 12 12:33:30 NightHawk daemon.notice openvpn[2133]: Inactivity timeout (--ping-restart), restarting
Aug 12 12:33:30 NightHawk daemon.notice openvpn[2133]: Closing TUN/TAP interface
Aug 12 12:33:30 NightHawk daemon.notice openvpn[2133]: SIGUSR1[soft,ping-restart] received, process restarting
Aug 12 12:33:30 NightHawk daemon.notice openvpn[2133]: Restart pause, 300 second(s)
Aug 12 12:33:30 NightHawk kern.info kernel: br0: port 4(tap21) entering forwarding state
Aug 12 12:38:30 NightHawk daemon.notice openvpn[2133]: Outgoing Static Key Encryption: Cipher 'AES-256-CBC' initialized with 256 bit key
Aug 12 12:38:30 NightHawk daemon.notice openvpn[2133]: Outgoing Static Key Encryption: Using 160 bit message hash 'SHA1' for HMAC authentication
Aug 12 12:38:30 NightHawk daemon.notice openvpn[2133]: Incoming Static Key Encryption: Cipher 'AES-256-CBC' initialized with 256 bit key
Aug 12 12:38:30 NightHawk daemon.notice openvpn[2133]: Incoming Static Key Encryption: Using 160 bit message hash 'SHA1' for HMAC authentication
Aug 12 12:38:30 NightHawk daemon.notice openvpn[2133]: TUN/TAP device tap21 opened
Aug 12 12:38:30 NightHawk daemon.notice openvpn[2133]: TUN/TAP TX queue length set to 100
Aug 12 12:38:30 NightHawk daemon.warn openvpn[2133]: Could not determine IPv4/IPv6 protocol. Using AF_INET6
Aug 12 12:38:30 NightHawk daemon.notice openvpn[2133]: Socket Buffers: R=[120832->120832] S=[120832->120832]
Aug 12 12:38:30 NightHawk daemon.notice openvpn[2133]: setsockopt(IPV6_V6ONLY=0)
Aug 12 12:38:30 NightHawk daemon.notice openvpn[2133]: UDPv6 link local (bound): [AF_INET6][undef]:1194
Aug 12 12:38:30 NightHawk daemon.notice openvpn[2133]: UDPv6 link remote: [AF_UNSPEC]
Aug 12 12:38:30 NightHawk kern.info kernel: br0: port 4(tap21) entering forwarding state
Aug 12 12:38:30 NightHawk kern.info kernel: br0: port 4(tap21) entering forwarding state
Aug 12 12:39:30 NightHawk daemon.notice openvpn[2133]: Inactivity timeout (--ping-restart), restarting
Aug 12 12:39:30 NightHawk daemon.notice openvpn[2133]: Closing TUN/TAP interface
Aug 12 12:39:30 NightHawk daemon.notice openvpn[2133]: SIGUSR1[soft,ping-restart] received, process restarting
Aug 12 12:39:30 NightHawk daemon.notice openvpn[2133]: Restart pause, 300 second(s)

TinCanTech

Please post your Windows log.

ninevoltz

Mon Aug 13 07:17:54 2018 OpenVPN 2.4.6 x86_64-w64-mingw32 [SSL (OpenSSL)] [LZO] [LZ4] [PKCS11] [AEAD] built on Apr 26 2018
Mon Aug 13 07:17:54 2018 Windows version 6.2 (Windows 8 or greater) 64bit
Mon Aug 13 07:17:54 2018 library versions: OpenSSL 1.1.0h  27 Mar 2018, LZO 2.10
Enter Management Password:
Mon Aug 13 07:17:54 2018 open_tun
Mon Aug 13 07:17:54 2018 TAP-WIN32 device [Ethernet 3] opened: \\.\Global\{E797189B-99F8-4080-A389-8ADD2A05D021}.tap
Mon Aug 13 07:17:54 2018 Successful ARP Flush on interface [18] {E797189B-99F8-4080-A389-8ADD2A05D021}
Mon Aug 13 07:17:54 2018 TCP/UDP: Preserving recently used remote address: [AF_INET]x.x.x.x:1194
Mon Aug 13 07:17:54 2018 UDPv4 link local (bound): [AF_INET][undef]:1194
Mon Aug 13 07:17:54 2018 UDPv4 link remote: [AF_INET]x.x.x.x:1194
Mon Aug 13 07:19:22 2018 Peer Connection Initiated with [AF_INET]x.x.x.x:1194
Mon Aug 13 07:19:25 2018 Initialization Sequence Completed

ninevoltz

Is there some reason the server daemon keeps restarting itself when there is no connection? Is there a configuration setting to prevent that?

ninevoltz

After some furious Googling, I found the answer to my question, I added

ping-timer-rem

to the Custom Configuration on the router.

TinCanTech

You do understand that, according to what you have posted, you are never connected to your VPN.

ninevoltz

TinCanTech wrote You do understand that, according to what you have posted, you are never connected to your VPN.

Correct, those messages were forever repeating while I was disconnected. I don't have a connectivity problem, it was the messages piling up in the log. And also it takes several minutes to connect in the morning because of the restart wait.

TinCanTech

Are the config files you have posted the complete files or have you left some details out ?

ninevoltz

TinCanTech wrote Are the config files you have posted the complete files or have you left some details out ?

Nothing was left out, I redacted the IP address in the client config with x.x.x.x.

TinCanTech

So, are you using static IP addresses for the TAP adaptor ?

ninevoltz

TinCanTech wrote So, are you using static IP addresses for the TAP adaptor ?

Yes. Also, I am not using the VPN to re-route my internet traffic, only to access other computers on my home network.

TinCanTech

OK.

ninevoltz wrote Is there some reason the server daemon keeps restarting itself when there is no connection?

Because your "server" is not a server it is just an end point.

That is also the reason why it takes some time to connect. You see this in your "server" log:

ninevoltz wrote Aug 12 12:33:30 NightHawk daemon.notice openvpn[2133]: SIGUSR1[soft,ping-restart] received, process restarting Aug 12 12:33:30 NightHawk daemon.notice openvpn[2133]: Restart pause, 300 second(s)

Your "client" end is waiting for the other side to complete this pause, you can use --connect-retry to control this ..

Also, if you are not actively using the VPN then it will timeout every couple of minutes ..

You can setup the server correctly to solve these problems ..

The way you have set it up is not recommended because you are disabling the new security features.