Page 1 of 1
Hourly "daemon.notice openvpn"
Posted: Mon Jan 06, 2020 2:17 am
by rseiler
Just a curiosity, but I noticed that OpenVPN is a bit more chatty in the log in 1.12 compared to 1.10. If a client is connected a lot, it really adds up.
On a router where a client is connected continuously (and that is reflected in OpenVPN status: it's not disconnecting/reconnecting), the system log shows about 20 lines of essentially redunctant and not very useful activity for the client every hour. The info is very similar to, but slightly different from, what's recorded upon initial connection.
I'm guessing that it ties to this default:
–reneg-sec n
Renegotiate data channel key after n seconds (default=3600).
Short of increasing that (adjustments on both the client and the server), I wonder if there's a way of just suppressing the openvpn daemon notices for this renegotiation.
Re: Hourly "daemon.notice openvpn"
Posted: Mon Jan 06, 2020 3:58 am
by Lantis
In /etc/openvpn/server.conf, "verb" is set to "3".
Can you try lowering it to 2, and then 1 if these message don't disappear please, and report back?
Re: Hourly "daemon.notice openvpn"
Posted: Mon Jan 06, 2020 4:06 pm
by rseiler
2 didn't, but 1 roughly cut it in half, down to this (not the real IP):
Mon Jan 6 14:22:32 2020 user.notice ovpn-cn-check: control verified OK
Mon Jan 6 14:22:32 2020 daemon.notice openvpn(custom_config)[763]: control/1.2.3.4:56699 peer info: IV_VER=2.4.8
Mon Jan 6 14:22:32 2020 daemon.notice openvpn(custom_config)[763]: control/1.2.3.4:56699 peer info: IV_PLAT=win
Mon Jan 6 14:22:32 2020 daemon.notice openvpn(custom_config)[763]: control/1.2.3.4:56699 peer info: IV_PROTO=2
Mon Jan 6 14:22:32 2020 daemon.notice openvpn(custom_config)[763]: control/1.2.3.4:56699 peer info: IV_LZ4=1
Mon Jan 6 14:22:32 2020 daemon.notice openvpn(custom_config)[763]: control/1.2.3.4:56699 peer info: IV_LZ4v2=1
Mon Jan 6 14:22:32 2020 daemon.notice openvpn(custom_config)[763]: control/1.2.3.4:56699 peer info: IV_LZO=1
Mon Jan 6 14:22:32 2020 daemon.notice openvpn(custom_config)[763]: control/1.2.3.4:56699 peer info: IV_COMP_STUB=1
Mon Jan 6 14:22:32 2020 daemon.notice openvpn(custom_config)[763]: control/1.2.3.4:56699 peer info: IV_COMP_STUBv2=1
Mon Jan 6 14:22:32 2020 daemon.notice openvpn(custom_config)[763]: control/1.2.3.4:56699 peer info: IV_TCPNL=1
Is this maybe just a natural artifact of the new tls-verify and crl-verify lines?
Re: Hourly "daemon.notice openvpn"
Posted: Mon Jan 06, 2020 5:50 pm
by Lantis
Quite possibly.
I don't really want to reduce it to 1 by default. You lose a bit of diagnostic data.
Openvpn recommends 3 or 4 for operations.
Re: Hourly "daemon.notice openvpn"
Posted: Mon Jan 06, 2020 11:05 pm
by rseiler
That reneg-sec setting I mentioned earlier turns out not to have been involved, as setting it higher had no effect. It was just a guess based on it being the only thing in the manual mentioning an hour.
So, when on 3, here's the rest of the log not quoted above (when it was on 1), just in case anything jumps out. Since it makes even more mentions of "verify," and since tls and crl verify are the two notable differences in the file, it seems very likely that one or both are why.
Mon Jan 6 21:39:13 2020 daemon.notice openvpn(custom_config)[7498]: control/1.2.3.4:63067 VERIFY SCRIPT OK: depth=1, C=??, ST=UnknownProvince, L=UnknownCity, O=UnknownOrg, OU=UnknownOrgUnit, CN=bwzfuszgflmlmff, name=bwzfuszgflmlmff, emailAddress=
bwzfuszgflmlmff@inapgvcdejnmwib.com
Mon Jan 6 21:39:13 2020 daemon.notice openvpn(custom_config)[7498]: control/1.2.3.4:63067 VERIFY OK: depth=1, C=??, ST=UnknownProvince, L=UnknownCity, O=UnknownOrg, OU=UnknownOrgUnit, CN=bwzfuszgflmlmff, name=bwzfuszgflmlmff, emailAddress=
bwzfuszgflmlmff@inapgvcdejnmwib.com
[above-quoted log goes here]
Mon Jan 6 21:39:13 2020 daemon.notice openvpn(custom_config)[7498]: control/1.2.3.4:63067 TLS: Username/Password authentication succeeded for username 'control'
Mon Jan 6 21:39:13 2020 daemon.notice openvpn(custom_config)[7498]: control/1.2.3.4:63067 Outgoing Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Mon Jan 6 21:39:13 2020 daemon.notice openvpn(custom_config)[7498]: control/1.2.3.4:63067 Incoming Data Channel: Cipher 'AES-256-GCM' initialized with 256 bit key
Mon Jan 6 21:39:13 2020 daemon.notice openvpn(custom_config)[7498]: control/1.2.3.4:63067 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, 1024 bit RSA
Success