Hourly "daemon.notice openvpn"

Report wireless and/or network connectivity problems in this forum.

Moderator: Moderators

Post Reply
rseiler
Posts: 208
Joined: Sun Dec 15, 2013 12:31 am

Hourly "daemon.notice openvpn"

Post 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.

Lantis
Moderator
Posts: 6924
Joined: Mon Jan 05, 2015 5:33 am
Location: Australia

Re: Hourly "daemon.notice openvpn"

Post 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?
https://lantisproject.com/downloads/gargoylebuilds for the latest releases
Please be respectful when posting. I do this in my free time on a volunteer basis.

rseiler
Posts: 208
Joined: Sun Dec 15, 2013 12:31 am

Re: Hourly "daemon.notice openvpn"

Post 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?

Lantis
Moderator
Posts: 6924
Joined: Mon Jan 05, 2015 5:33 am
Location: Australia

Re: Hourly "daemon.notice openvpn"

Post 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.
https://lantisproject.com/downloads/gargoylebuilds for the latest releases
Please be respectful when posting. I do this in my free time on a volunteer basis.

rseiler
Posts: 208
Joined: Sun Dec 15, 2013 12:31 am

Re: Hourly "daemon.notice openvpn"

Post 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

Post Reply