Hi Nikos, Thanks for your reply. I did some tests with two users trying to connect at the same time, and ocserv is not blocking at username/password/LDAP stages, but only when duo has sent its notification to user's device. So as you said, it may be a limitation of the duo PAM module. Here is a debugging output from ocserv (2 users trying to connect). # 1st user connection attempt Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: accepted connection Jan 13 14:47:20 ocserv[14915]: worker: accepted connection Jan 13 14:47:20 ocserv[14663]: ocserv[14664]: sec-mod: received request from pid 14915 and uid 988 Jan 13 14:47:20 ocserv[14664]: sec-mod: received request from pid 14915 and uid 988 Jan 13 14:47:20 ocserv[14663]: ocserv[14664]: sec-mod: cmd [size=57] sm: sign Jan 13 14:47:20 ocserv[14664]: sec-mod: cmd [size=57] sm: sign Jan 13 14:47:20 ocserv[14915]: worker: client certificate verification succeeded Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: client certificate verification succeeded Jan 13 14:47:20 ocserv[14915]: worker: sending message 'resume data store request' to secmod Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: sending message 'resume data store request' to secmod Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: TLS handshake completed Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: sending message 'session info' to main Jan 13 14:47:20 ocserv[14915]: worker: TLS handshake completed Jan 13 14:47:20 ocserv[14663]: ocserv[14664]: sec-mod: received request from pid 14915 and uid 988 Jan 13 14:47:20 ocserv[14915]: worker: sending message 'session info' to main Jan 13 14:47:20 ocserv[14663]: ocserv[14663]: main:91.X.X.236:50244 main received worker's message 'session info' of 50 bytes Jan 13 14:47:20 ocserv[14664]: sec-mod: received request from pid 14915 and uid 988 Jan 13 14:47:20 ocserv[14663]: ocserv[14664]: sec-mod: cmd [size=1174] resume data store request Jan 13 14:47:20 ocserv[14663]: ocserv[14664]: sec-mod: TLS session DB storing f091e670fb87b993ffe9313123ec93ad8dcd042c13cb7ad5cae71f877366393e Jan 13 14:47:20 ocserv[14663]: main:91.X.X.236:50244 main received worker's message 'session info' of 50 bytes Jan 13 14:47:20 ocserv[14664]: sec-mod: cmd [size=1174] resume data store request Jan 13 14:47:20 ocserv[14664]: sec-mod: TLS session DB storing f091e670fb87b993ffe9313123ec93ad8dcd042c13cb7ad5cae71f877366393e Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 HTTP processing: Host: 178.X.X.192 Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 HTTP processing: Host: 178.X.X.192 Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 HTTP processing: User-Agent: Open AnyConnect VPN Agent v8.05 Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 User-agent: 'Open AnyConnect VPN Agent v8.05' Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 HTTP processing: Accept: */* Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 HTTP processing: Accept-Encoding: identity Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 HTTP processing: X-Transcend-Version: 1 Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 HTTP processing: X-Aggregate-Auth: 1 Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 HTTP processing: X-AnyConnect-Platform: linux-64 Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 HTTP processing: X-Support-HTTP-Auth: true Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 HTTP processing: X-Pad: 000000000000000000000000000000000000000000000000000 Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 HTTP processing: Content-Type: application/x-www-form-urlencoded Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 HTTP processing: Content-Length: 205 Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 HTTP POST /auth Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 POST body: '<?xml version="1.0" encoding="UTF-8"?> Jan 13 14:47:20 ocserv[14663]: <config-auth client="vpn" type="auth-reply"><version who="vpn">v8.05</version><device-id>linux-64</device-id><auth><username>f.domain</username></auth></config-auth> Jan 13 14:47:20 ocserv[14663]: ' Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 cannot find 'group-select' in client XML message Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 cannot find 'group-select' in client XML message Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker: 91.X.X.236 failed reading groupname Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 sending message 'sm: auth init' to secmod Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 HTTP processing: User-Agent: Open AnyConnect VPN Agent v8.05 Jan 13 14:47:20 ocserv[14663]: ocserv[14664]: sec-mod: received request from pid 14915 and uid 988 Jan 13 14:47:20 ocserv[14663]: ocserv[14664]: sec-mod: cmd [size=88] sm: auth init Jan 13 14:47:20 ocserv[14663]: ocserv[14664]: sec-mod: using 'certificate+pam' authentication to authenticate user (session: Vo/YtK) Jan 13 14:47:20 ocserv[14663]: ocserv[14664]: sec-mod: auth init (with cert) for user 'f.domain' (session: Vo/YtK) of group: '' from '91.X.X.236' Jan 13 14:47:20 ocserv[14663]: ocserv[14664]: PAM-auth conv: echo-off, msg: 'Password: ' Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 User-agent: 'Open AnyConnect VPN Agent v8.05' Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 received auth reply message (value: 2) Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 continuing authentication for 'f.domain' Jan 13 14:47:20 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP sending: 200 OK Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 HTTP processing: Accept: */* Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 HTTP processing: Accept-Encoding: identity Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 HTTP processing: X-Transcend-Version: 1 Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 HTTP processing: X-Aggregate-Auth: 1 Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 HTTP processing: X-AnyConnect-Platform: linux-64 Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 HTTP processing: X-Support-HTTP-Auth: true Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 HTTP processing: X-Pad: 000000000000000000000000000000000000000000000000000 Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 HTTP processing: Content-Type: application/x-www-form-urlencoded Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 HTTP processing: Content-Length: 205 Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 HTTP POST /auth Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 POST body: '<?xml version="1.0" encoding="UTF-8"?>#012<config-auth client="vpn" type="auth-reply"><version who="vpn">v8.05</version><device-id>linux-64</device-id><auth><username>f.domain</username></auth></config-auth>#012' Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 cannot find 'group-select' in client XML message Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 cannot find 'group-select' in client XML message Jan 13 14:47:20 ocserv[14915]: worker: 91.X.X.236 failed reading groupname Jan 13 14:47:20 ocserv[14915]: worker[f.domain]: 91.X.X.236 sending message 'sm: auth init' to secmod Jan 13 14:47:20 ocserv[14664]: sec-mod: received request from pid 14915 and uid 988 Jan 13 14:47:20 ocserv[14664]: sec-mod: cmd [size=88] sm: auth init Jan 13 14:47:20 ocserv[14664]: sec-mod: using 'certificate+pam' authentication to authenticate user (session: Vo/YtK) Jan 13 14:47:20 ocserv[14664]: sec-mod: auth init (with cert) for user 'f.domain' (session: Vo/YtK) of group: '' from '91.X.X.236' Jan 13 14:47:20 ocserv[14664]: PAM-auth conv: echo-off, msg: 'Password: ' Jan 13 14:47:20 ocserv[14915]: worker[f.domain]: 91.X.X.236 received auth reply message (value: 2) Jan 13 14:47:20 ocserv[14915]: worker[f.domain]: 91.X.X.236 continuing authentication for 'f.domain' Jan 13 14:47:20 ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP sending: 200 OK Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: Host: 178.X.X.192 Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: Host: 178.X.X.192 Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: User-Agent: Open AnyConnect VPN Agent v8.05 Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 User-agent: 'Open AnyConnect VPN Agent v8.05' Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: Cookie: (censored) Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: Accept: */* Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: Accept-Encoding: identity Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: X-Transcend-Version: 1 Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: X-Aggregate-Auth: 1 Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: X-AnyConnect-Platform: linux-64 Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: X-Support-HTTP-Auth: true Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: X-Pad: 00000000000000000000000000000000000000000000000000 Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: Content-Type: application/x-www-form-urlencoded Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: Content-Length: 206 Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP POST /auth Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 POST body: '<?xml version="1.0" encoding="UTF-8"?> Jan 13 14:47:22 ocserv[14663]: <config-auth client="vpn" type="auth-reply"><version who="vpn">v8.05</version><device-id>linux-64</device-id><auth><password></password></auth></config-auth> Jan 13 14:47:22 ocserv[14663]: ' Jan 13 14:47:22 ocserv[14663]: ocserv[14915]: worker[f.domain]: 91.X.X.236 sending message 'sm: auth cont' to secmod Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: User-Agent: Open AnyConnect VPN Agent v8.05 Jan 13 14:47:22 ocserv[14663]: ocserv[14664]: sec-mod: received request from pid 14915 and uid 988 Jan 13 14:47:22 ocserv[14663]: ocserv[14664]: sec-mod: cmd [size=61] sm: auth cont Jan 13 14:47:22 ocserv[14663]: ocserv[14664]: sec-mod: auth cont for user 'f.domain' (session: Vo/YtK) Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 User-agent: 'Open AnyConnect VPN Agent v8.05' Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: Cookie: (censored) Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: Accept: */* Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: Accept-Encoding: identity Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: X-Transcend-Version: 1 Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: X-Aggregate-Auth: 1 Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: X-AnyConnect-Platform: linux-64 Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: X-Support-HTTP-Auth: true Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: X-Pad: 00000000000000000000000000000000000000000000000000 Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: Content-Type: application/x-www-form-urlencoded Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP processing: Content-Length: 206 Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 HTTP POST /auth Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 POST body: '<?xml version="1.0" encoding="UTF-8"?>#012<config-auth client="vpn" type="auth-reply"><version who="vpn">v8.05</version><device-id>linux-64</device-id><auth><password></password></auth></config-auth>#012' Jan 13 14:47:22 ocserv[14915]: worker[f.domain]: 91.X.X.236 sending message 'sm: auth cont' to secmod Jan 13 14:47:22 ocserv[14664]: sec-mod: received request from pid 14915 and uid 988 Jan 13 14:47:22 ocserv[14664]: sec-mod: cmd [size=61] sm: auth cont Jan 13 14:47:22 ocserv[14664]: sec-mod: auth cont for user 'f.domain' (session: Vo/YtK) # pam_sss is called to perform LDAP authentication and then pam_duo for the second factor Jan 13 14:47:22 ocserv[14664]: pam_sss(ocserv:auth): authentication success; logname= uid=0 euid=0 tty= ruser= rhost=91.X.X.236 user=f.domain Jan 13 14:47:22 ocserv[14663]: ocserv[14664]: pam_sss(ocserv:auth): authentication success; logname= uid=0 euid=0 tty= ruser= rhost=91.X.X.236 user=f.domain Jan 13 14:47:22 ocserv[14664]: PAM-auth conv info: Autopushing login request to phone... Jan 13 14:47:22 ocserv[14663]: ocserv[14664]: PAM-auth conv info: Autopushing login request to phone... Jan 13 14:47:22 ocserv[14664]: PAM-auth conv info: Jan 13 14:47:22 ocserv[14663]: ocserv[14664]: PAM-auth conv info: Jan 13 14:47:23 ocserv[14664]: PAM-auth conv info: Pushed a login request to your device... Jan 13 14:47:23 ocserv[14663]: ocserv[14664]: PAM-auth conv info: Pushed a login request to your device... # once Duo push notification has been sent to the device (not approved yet), a 2nd user tries to connect Jan 13 14:47:26 ocserv[14663]: main: added 1 points (total 6) for IP '91.X.X.236' to ban list Jan 13 14:47:26 ocserv[14663]: ocserv[14663]: main: added 1 points (total 6) for IP '91.X.X.236' to ban list Jan 13 14:47:26 ocserv[14922]: worker: accepted connection Jan 13 14:47:26 ocserv[14663]: ocserv[14922]: worker: accepted connection # 10 seconds later, this 2nd user receives a connection timed out Jan 13 14:47:36 ocserv[14922]: common/common.c:653: recvmsg: Connection timed out Jan 13 14:47:36 ocserv[14663]: ocserv[14922]: common/common.c:653: recvmsg: Connection timed out Jan 13 14:47:36 ocserv[14663]: ocserv[14922]: error receiving sec-mod reply: Connection timed out Jan 13 14:47:36 ocserv[14663]: ocserv[14922]: GnuTLS error (at worker-vpn.c:795): GnuTLS internal error. Jan 13 14:47:36 ocserv[14922]: error receiving sec-mod reply: Connection timed out Jan 13 14:47:36 ocserv[14922]: GnuTLS error (at worker-vpn.c:795): GnuTLS internal error. Jan 13 14:47:36 ocserv[14663]: ocserv[14663]: main:91.X.X.236:50250 worker terminated Jan 13 14:47:36 ocserv[14663]: ocserv[14663]: main:91.X.X.236:50250 user disconnected (reason: unspecified, rx: 0, tx: 0) Jan 13 14:47:36 ocserv[14663]: main:91.X.X.236:50250 worker terminated Jan 13 14:47:36 ocserv[14663]: main:91.X.X.236:50250 user disconnected (reason: unspecified, rx: 0, tx: 0) # Duo push notification is approved by 1st user Jan 13 14:47:40 ocserv[14664]: PAM-auth conv info: Success. Logging you in... Jan 13 14:47:40 ocserv[14663]: ocserv[14664]: PAM-auth conv info: Success. Logging you in... Jan 13 14:47:40 ocserv[14663]: [6] Successful Duo login for 'f.domain' from 91.X.X.236 Regards, Florian D. Le lun. 13 janv. 2020 à 15:25, Nikos Mavrogiannopoulos <n.mavrogiannopoulos@xxxxxxxxx> a écrit : > > On Fri, Jan 10, 2020 at 1:30 PM Florian Domain <domain.florian@xxxxxxxxx> wrote: > > > > Hi all, > > > > We're using ocserv with 2 factor authentication (LDAP and Duo, very > > similar to what is described here > > https://ocserv.gitlab.io/www/recipes-ocserv-2fa.html#Duo). > > > > I found out that on a single ocserv server, when a login process is in > > progress for a user and waiting for Duo user's approval on a > > smartphone, ocserv is not able to handle a second user authentication > > during this period, and it has to wait for the first authentication to > > end. > > Login process for this 2nd user will never prompt and the connection > > will just be aborted after a few seconds. > > Do you have some debugging output of that case, i.e., two users trying > to connect and one stalling for long? It could be that this is a > limitation of the PAM handling in duo or so rather than ocserv. > > > Has anyone experienced a similar issue ? Is it due to ocserv design ? > > Maybe not allowing parallelism in user authentication ? > > A single process is handling authentication and there are certain > limitations in auth b/w due to that, but it is not blocking in any way > waiting for user input. Once input is necessary it requests for it, > and context switches to the next user. > > regards, > Nikos _______________________________________________ openconnect-devel mailing list openconnect-devel@xxxxxxxxxxxxxxxxxxx http://lists.infradead.org/mailman/listinfo/openconnect-devel
