OpenvpnAS stops passing traffic

Business solution to host your own OpenVPN server with web management interface and bundled clients.
Post Reply
xeonz
OpenVpn Newbie
Posts: 10
Joined: Mon Jan 17, 2022 1:06 pm

OpenvpnAS stops passing traffic

Post by xeonz » Tue Oct 18, 2022 10:04 am

Hello.

We have two high load servers (up to 1000-2000 users) v.2.11.0 with radius auth method. They works for a 5-10 hours then something happens. Traffic usage decreases, users cannot login (timeouts). In server's logs I found only these warning:

Code: Select all

2022-10-18T13:26:46+0400 [stdout#info] Warning: OpenVPN daemon job Queue size (~48015) at or above limit (auth.module.max_jobs_in_parallel=8).
2022-10-18T13:26:46+0400 [stdout#info] Warning: OpenVPN daemon job Queue size (~48016) at or above limit (auth.module.max_jobs_in_parallel=8).
2022-10-18T13:26:46+0400 [stdout#info] Warning: OpenVPN daemon job Queue size (~48017) at or above limit (auth.module.max_jobs_in_parallel=8).
If I restart the servers, everything become ok for the next 5-10 hours, then it happens again.

What should I do to stop this problem?

User avatar
openvpn_inc
OpenVPN Inc.
Posts: 1333
Joined: Tue Feb 16, 2021 10:41 am

Re: OpenvpnAS stops passing traffic

Post by openvpn_inc » Tue Oct 18, 2022 10:42 am

Hello xeonz,

You seem to have a situation where the RADIUS servers are slow in responding or are being slowed down by some action (like an MFA action handled outside of Access Server, on the RADIUS backend, which causes it to wait). That results in authentication requests hanging in the queue, and if it's busy enough, the authentication queue going over its normal limit. In your case you would increase the queue size until you no longer have this problem. Unfortunately in version 2.11.0 that message about auth.module.max_jobs_in_parallel has a mistake - the real parameter name is actually auth.module.max_parallel. This mistake is going to be fixed in 2.11.1 by the way.

With these commands run as a root user you can change this parameter to increase the queue size;
cd /usr/local/openvpn_as/scripts/
./sacli --key "auth.module.max_parallel" --value "32" configput
./sacli start

Good luck,
Johan
Image OpenVPN Inc.
Answers provided by OpenVPN Inc. staff members here are provided on a voluntary best-effort basis, and no rights can be claimed on the basis of answers posted in this public forum. If you wish to get official support from OpenVPN Inc. please use the official support ticket system: https://openvpn.net/support

xeonz
OpenVpn Newbie
Posts: 10
Joined: Mon Jan 17, 2022 1:06 pm

Re: OpenvpnAS stops passing traffic

Post by xeonz » Tue Oct 18, 2022 11:00 am

Thank you. I will try it. I hope it can help.

Also I noticed the servers send many radius accounting messages to the radius server. We have to use radius accounting to be able to limit users with parallel sessions (for example no more that 2 active sessions for all our servers). Is it possible to increase radius accounting update period? Seems it is 5 minutes for every session now. And I cannot find such option in settings. Other vpn servers usually allow to configure radius accounting update period.
Last edited by xeonz on Tue Oct 18, 2022 11:05 am, edited 1 time in total.

User avatar
openvpn_inc
OpenVPN Inc.
Posts: 1333
Joined: Tue Feb 16, 2021 10:41 am

Re: OpenvpnAS stops passing traffic

Post by openvpn_inc » Tue Oct 18, 2022 11:04 am

Hello xeonz,

There is no such option in Access Server, sorry.

Kind regards,
Johan
Image OpenVPN Inc.
Answers provided by OpenVPN Inc. staff members here are provided on a voluntary best-effort basis, and no rights can be claimed on the basis of answers posted in this public forum. If you wish to get official support from OpenVPN Inc. please use the official support ticket system: https://openvpn.net/support

xeonz
OpenVpn Newbie
Posts: 10
Joined: Mon Jan 17, 2022 1:06 pm

Re: OpenvpnAS stops passing traffic

Post by xeonz » Tue Oct 18, 2022 1:57 pm

openvpn_inc wrote:
Tue Oct 18, 2022 10:42 am
With these commands run as a root user you can change this parameter to increase the queue size;
cd /usr/local/openvpn_as/scripts/
./sacli --key "auth.module.max_parallel" --value "32" configput
./sacli start
Ok, I got the issue again and applied this setting. And seems it helped, the server has started to work correctly again without restart. I am keeping an eye on it.

xeonz
OpenVpn Newbie
Posts: 10
Joined: Mon Jan 17, 2022 1:06 pm

Re: OpenvpnAS stops passing traffic

Post by xeonz » Tue Oct 18, 2022 6:19 pm

Seems 32 is not enough. I've got teh issue again. Trying to set it to 64.

User avatar
openvpn_inc
OpenVPN Inc.
Posts: 1333
Joined: Tue Feb 16, 2021 10:41 am

Re: OpenvpnAS stops passing traffic

Post by openvpn_inc » Tue Oct 18, 2022 6:40 pm

Hello xeonz,

Do you by any chance use anything on the RADIUS server that does MFA outside of Access Server? As in, the RADIUS server itself does some MFA action that must complete before the authentication completes? That could explain lingering authentication threads. It might also be good to look at the RADIUS server itself to see if that complains about running into problems (rate limits?).

Kind regards,
Johan
Image OpenVPN Inc.
Answers provided by OpenVPN Inc. staff members here are provided on a voluntary best-effort basis, and no rights can be claimed on the basis of answers posted in this public forum. If you wish to get official support from OpenVPN Inc. please use the official support ticket system: https://openvpn.net/support

xeonz
OpenVpn Newbie
Posts: 10
Joined: Mon Jan 17, 2022 1:06 pm

Re: OpenvpnAS stops passing traffic

Post by xeonz » Wed Oct 19, 2022 5:34 am

We don't have any kind of MFA. Radius is ok, all other (non openvpnas) our servers have no problems. Also I checked radius answers using tcpdump at openvpnas, I saw ~15ms time of answers. At the time the server is in this strange state, there is almost no radius requests I see in tcpdump.

In the server log it looks so:

Code: Select all

2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: "2022-10-19 04:10:55 10.255.255.150:32650 PUSH: Received control message: 'PUSH_REQUEST'"
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 peer info: IV_VER=3.git::081bfebe'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 peer info: IV_PLAT=ios'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 peer info: IV_NCP=2'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 peer info: IV_TCPNL=1'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 peer info: IV_PROTO=30'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 peer info: IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305:AES-256-CBC'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 peer info: UV_ASCLI_VER=3.3.2-5086'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 peer info: UV_PLAT_REL=16.0.2'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 peer info: UV_UUID=D6D361A8-E7DF-4ECF-9306-A7A64A6208F5'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 peer info: IV_GUI_VER=net.openvpn.connect.ios_3.3.2-5086'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 peer info: IV_SSO=webauth,openurl,crtext'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 peer info: IV_HWADDR=D6D361A8-E7DF-4ECF-9306-A7A64A6208F5'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 peer info: IV_SSL=OpenSSL_1.1.1n__15_Mar_2022'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: "2022-10-19 04:10:55 10.255.255.150:58979 TLS: Username/Password authentication deferred for username 'XXXXXXXXXX' "
2022-10-19T08:10:55+0400 [stdout#info] Warning: OpenVPN daemon job Queue size (~156085) at or above limit (auth.module.max_jobs_in_parallel=64).
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:54545 peer info: IV_VER=3.git::081bfebe'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:54545 peer info: IV_PLAT=ios'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:54545 peer info: IV_NCP=2'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:54545 peer info: IV_TCPNL=1'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:54545 peer info: IV_PROTO=30'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:54545 peer info: IV_CIPHERS=AES-256-GCM:AES-128-GCM:CHACHA20-POLY1305:AES-256-CBC'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:54545 peer info: UV_ASCLI_VER=3.3.2-5086'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:54545 peer info: UV_PLAT_REL=15.6.1'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:54545 peer info: UV_UUID=3F53FE1C-D40C-4AC6-B5A4-C5A7E0004043'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:54545 peer info: IV_GUI_VER=net.openvpn.connect.ios_3.3.2-5086'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:54545 peer info: IV_SSO=webauth,openurl,crtext'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:54545 peer info: IV_HWADDR=3F53FE1C-D40C-4AC6-B5A4-C5A7E0004043'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:54545 peer info: IV_SSL=OpenSSL_1.1.1n__15_Mar_2022'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: "2022-10-19 04:10:55 10.255.255.150:54545 TLS: Username/Password authentication deferred for username 'XXXXXXXXXXX' "
2022-10-19T08:10:55+0400 [stdout#info] Warning: OpenVPN daemon job Queue size (~156086) at or above limit (auth.module.max_jobs_in_parallel=64).
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 0] OUT: "2022-10-19 04:10:55 10.255.255.150:4488 PUSH: Received control message: 'PUSH_REQUEST'"
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 0] OUT: '2022-10-19 04:10:55 10.255.255.150:49291 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, peer certificate: 2048 bit RSA, signature: RSA-SHA256'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 0] OUT: '2022-10-19 04:10:55 10.255.255.150:49291 [XXXXXXXX] Peer Connection Initiated with [AF_INET]10.255.255.150:49291'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 0] OUT: "2022-10-19 04:10:55 10.255.255.150:49291 PUSH: Received control message: 'PUSH_REQUEST'"
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, peer certificate: 2048 bit RSA, signature: RSA-SHA256'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:55 10.255.255.150:58979 [XXXXXXXXX] Peer Connection Initiated with [AF_INET]10.255.255.150:58979 (via [AF_INET]XX.XX.XX.XX%ens224)'
2022-10-19T08:10:55+0400 [stdout#info] [OVPN 4] OUT: "2022-10-19 04:10:55 10.255.255.150:58979 PUSH: Received control message: 'PUSH_REQUEST'"
2022-10-19T08:10:56+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:56 10.255.255.150:54545 Control Channel: TLSv1.2, cipher TLSv1/SSLv3 ECDHE-RSA-AES256-GCM-SHA384, peer certificate: 2048 bit RSA, signature: RSA-SHA256'
2022-10-19T08:10:56+0400 [stdout#info] [OVPN 4] OUT: '2022-10-19 04:10:56 10.255.255.150:54545 [XXXXXXXX] Peer Connection Initiated with [AF_INET]10.255.255.150:54545 (via [AF_INET]XX.XX.XX.XX%ens224)'
2022-10-19T08:10:56+0400 [stdout#info] [OVPN 4] OUT: "2022-10-19 04:10:56 10.255.255.150:54545 PUSH: Received control message: 'PUSH_REQUEST'"
2022-10-19T08:10:56+0400 [stdout#info] [OVPN 5] OUT: "2022-10-19 04:10:56 10.255.255.150:39174 PUSH: Received control message: 'PUSH_REQUEST'"
2022-10-19T08:10:56+0400 [stdout#info] [OVPN 4] OUT: "2022-10-19 04:10:56 10.255.255.150:47584 PUSH: Received control message: 'PUSH_REQUEST'"
2022-10-19T08:10:56+0400 [stdout#info] [OVPN 4] OUT: "2022-10-19 04:10:56 10.255.255.150:63825 PUSH: Received control message: 'PUSH_REQUEST'"
2022-10-19T08:10:56+0400 [stdout#info] [OVPN 6] OUT: "2022-10-19 04:10:56 10.255.255.150:56525 PUSH: Received control message: 'PUSH_REQUEST'"
2022-10-19T08:10:56+0400 [stdout#info] [OVPN 7] OUT: '2022-10-19 04:10:56 10.255.255.150:61082 SIGTERM[soft,delayed-exit] received, client-instance exiting'
2022-10-19T08:10:56+0400 [stdout#info] Warning: OpenVPN daemon job Queue size (~156087) at or above limit (auth.module.max_jobs_in_parallel=64).
2022-10-19T08:10:56+0400 [stdout#info] [OVPN 4] OUT: "2022-10-19 04:10:56 10.255.255.150:61126 PUSH: Received control message: 'PUSH_REQUEST'"
2022-10-19T08:10:56+0400 [stdout#info] [OVPN 4] OUT: "2022-10-19 04:10:56 10.255.255.150:47726 PUSH: Received control message: 'PUSH_REQUEST'"
As soon as I restarted the server I see high rate of radius request-answers in tcpdump with 15ms answer time. It looks like something was freezed inside the server, without any external signs. Even cpu has low load in this freezed state.

User avatar
openvpn_inc
OpenVPN Inc.
Posts: 1333
Joined: Tue Feb 16, 2021 10:41 am

Re: OpenvpnAS stops passing traffic

Post by openvpn_inc » Wed Oct 19, 2022 9:09 am

Hello xeonz,

Yeah something really odd is going on here. To be honest I don't know what, this is a very unusual situation. A job queue size of 156087 is insane.

I suggest you open a support ticket at https://openvpn.net/support and we'll try to figure out some further debugging steps to try to get a handle on what's going on. We're now at a point where we need more than what we can safely do on a public forum (getting logs and such).

Kind regards,
Johan
Image OpenVPN Inc.
Answers provided by OpenVPN Inc. staff members here are provided on a voluntary best-effort basis, and no rights can be claimed on the basis of answers posted in this public forum. If you wish to get official support from OpenVPN Inc. please use the official support ticket system: https://openvpn.net/support

xeonz
OpenVpn Newbie
Posts: 10
Joined: Mon Jan 17, 2022 1:06 pm

Re: OpenvpnAS stops passing traffic

Post by xeonz » Thu Oct 20, 2022 7:52 am

Well, I guess I will configure auto-restart of the servers, it will be easier for me at the current time. Also it would be great if openvpnas can gracefully do shutdown/restart and send radius disconnect messages for each connected user. Current versions don't send such messages and I have to manually close users sessions in the radius server after restarting openvpnas servers.

Thank you anyway for trying to help me. I hope you can fix these issues in future versions.

xeonz
OpenVpn Newbie
Posts: 10
Joined: Mon Jan 17, 2022 1:06 pm

Re: OpenvpnAS stops passing traffic

Post by xeonz » Sat Oct 22, 2022 8:54 pm

I think I managed to fix the issue.

If someone has the same one, these options helped me:

Code: Select all

/usr/local/openvpn_as/scripts/sacli --key "auth.module.max_parallel" --value "1000" configput
/usr/local/openvpn_as/scripts/confdba -mk auth.radius.0.per_server_timeout -v 5
/usr/local/openvpn_as/scripts/sacli start
Our radius server and openvpnas servers are located in different data centers and we are using public internet link between them. I think sometimes accounting packets are dropped and openvpnas waits for reply for quite a long time. And while it is waiting, auth job(thread?) is busy and cannot serve another requests. So I set short waiting period and set maximum number of jobs (1000). I have no repeat of the problem after I set these settings.

User avatar
openvpn_inc
OpenVPN Inc.
Posts: 1333
Joined: Tue Feb 16, 2021 10:41 am

Re: OpenvpnAS stops passing traffic

Post by openvpn_inc » Sun Oct 23, 2022 1:26 pm

Hello xeonz,

Glad to hear you were able to resolve the issue, and thanks for reporting back on your findings. It may help someone in the future.

Kind regards,
Johan
Image OpenVPN Inc.
Answers provided by OpenVPN Inc. staff members here are provided on a voluntary best-effort basis, and no rights can be claimed on the basis of answers posted in this public forum. If you wish to get official support from OpenVPN Inc. please use the official support ticket system: https://openvpn.net/support

Post Reply