Duplicate session with Kerberos in Combination
Environment
LemonLDAP::NG version: 2.0.8
Operating system: Debian 9.12
Web server: nginx/1.10.3
Summary
Hello, since yesterday, my portal has been loading with around 1000 more users, and I observe an error that I had not seen on the first 600 users. this error occurred 5 or 6 times yesterday. it's as if the data was written twice at the same time, but finally the session is created and psession seems update.
seems to match this issue : 1720
Logs
# syslog
Jun 3 07:08:12 server LLNG[85343]: [debug] Initialize Kerberos dialog
Jun 3 07:08:12 server LLNG[85343]: [debug] Returned status: -4 (PE_SENDRESPONSE)
Jun 3 07:08:12 server LLNG[85342]: [debug] VH portal.example.com is HTTPS
Jun 3 07:08:12 server LLNG[85342]: [info] No cookie found
Jun 3 07:08:12 server LLNG[85342]: [debug] Build URL https://portal.example.com/?kerberos=1
Jun 3 07:08:12 server LLNG[85342]: [debug] Redirect X.X.116.133 to portal (url was /?kerberos=1)
Jun 3 07:08:12 server LLNG[85342]: [debug] User not authenticated, Try in use, cancel redirection
Jun 3 07:08:12 server LLNG[85342]: [debug] Start routing default route
Jun 3 07:08:12 server LLNG[85342]: [debug] Processing controlUrl
Jun 3 07:08:12 server LLNG[85342]: [debug] Required URL (param: urldc | value: https://application.example.com/ | alias: http://application.example.com)
Jun 3 07:08:12 server LLNG[85342]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85342]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85342]: [debug] Launching ::Issuer::SAML::storeEnv
Jun 3 07:08:12 server LLNG[85342]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85342]: [debug] Launching ::Issuer::CAS::storeEnvAndCheckGateway
Jun 3 07:08:12 server LLNG[85342]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85342]: [debug] Launching ::Issuer::OpenIDConnect::exportRequestParameters
Jun 3 07:08:12 server LLNG[85342]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85342]: [debug] Launching ::Plugins::AutoSignin::check
Jun 3 07:08:12 server LLNG[85342]: [debug] Processing extractFormInfo
Jun 3 07:08:12 server LLNG[85342]: [debug] Kerberos ticket received: YIIHwQYGKwYBBQUCoIIHtTCCB7GgMDAuBgkqhkiC9xIBAgIGCSqGSIb3EgECAgYK...
Jun 3 07:08:12 server LLNG[85342]: [debug] Set KRB5_KTNAME env to FILE:/etc/lemonldap-ng/llng.keytab
Jun 3 07:08:12 server LLNG[85342]: [debug] Processing getUser
Jun 3 07:08:12 server slapd[602]: conn=1257738 op=186 SRCH attr=supportedLDAPVersion
Jun 3 07:08:12 server slapd[602]: conn=1257738 op=187 SRCH attr=supportedLDAPVersion
Jun 3 07:08:12 server slapd[602]: conn=1257738 op=188 BIND anonymous mech=implicit ssf=0
Jun 3 07:08:12 server slapd[602]: conn=1257738 op=188 BIND dn="cn=admin,dc=meta,dc=xxx" method=128
Jun 3 07:08:12 server slapd[602]: conn=1257738 op=188 BIND dn="cn=admin,dc=meta,dc=xxx" mech=SIMPLE ssf=0
Jun 3 07:08:12 server slapd[602]: conn=1257738 op=189 SRCH base="dc=meta,dc=xxx" scope=2 deref=2 filter="(&(uid=userlogin)(objectClass=person))"
Jun 3 07:08:12 server slapd[602]: conn=1257738 op=189 SRCH attr=cn sn employeeNumber givenName telephoneNumber physicalDeliveryOfficeName title UserPrincipalName memberOf uid employeeNumber mail cn memberOf
Jun 3 07:08:12 server LLNG[85341]: [debug] User not authenticated, Try in use, cancel redirection
Jun 3 07:08:12 server LLNG[85341]: [debug] Start routing default route
Jun 3 07:08:12 server LLNG[85341]: [debug] Processing controlUrl
Jun 3 07:08:12 server LLNG[85341]: [debug] Required URL (param: urldc | value: https://application.example.com/ | alias: http://application.example.com)
Jun 3 07:08:12 server LLNG[85341]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85341]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85341]: [debug] Launching ::Issuer::SAML::storeEnv
Jun 3 07:08:12 server LLNG[85341]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85341]: [debug] Launching ::Issuer::CAS::storeEnvAndCheckGateway
Jun 3 07:08:12 server LLNG[85341]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85341]: [debug] Launching ::Issuer::OpenIDConnect::exportRequestParameters
Jun 3 07:08:12 server LLNG[85341]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85341]: [debug] Launching ::Plugins::AutoSignin::check
Jun 3 07:08:12 server LLNG[85341]: [debug] Processing extractFormInfo
Jun 3 07:08:12 server LLNG[85341]: [debug] Initialize Kerberos dialog
Jun 3 07:08:12 server LLNG[85341]: [debug] Returned status: -4 (PE_SENDRESPONSE)
Jun 3 07:08:12 server LLNG[85345]: [debug] VH portal.example.com is HTTPS
Jun 3 07:08:12 server LLNG[85345]: [info] No cookie found
Jun 3 07:08:12 server LLNG[85345]: [debug] Build URL https://portal.example.com/?kerberos=1
Jun 3 07:08:12 server LLNG[85345]: [debug] Redirect X.X.116.133 to portal (url was /?kerberos=1)
Jun 3 07:08:12 server LLNG[85345]: [debug] User not authenticated, Try in use, cancel redirection
Jun 3 07:08:12 server LLNG[85345]: [debug] Start routing default route
Jun 3 07:08:12 server LLNG[85345]: [debug] Processing controlUrl
Jun 3 07:08:12 server LLNG[85345]: [debug] Required URL (param: urldc | value: https://application.example.com/ | alias: http://application.example.com)
Jun 3 07:08:12 server LLNG[85345]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85345]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85345]: [debug] Launching ::Issuer::SAML::storeEnv
Jun 3 07:08:12 server LLNG[85345]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85345]: [debug] Launching ::Issuer::CAS::storeEnvAndCheckGateway
Jun 3 07:08:12 server LLNG[85345]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85345]: [debug] Launching ::Issuer::OpenIDConnect::exportRequestParameters
Jun 3 07:08:12 server LLNG[85345]: [debug] Processing code ref
Jun 3 07:08:12 server LLNG[85345]: [debug] Launching ::Plugins::AutoSignin::check
Jun 3 07:08:12 server LLNG[85345]: [debug] Processing extractFormInfo
Jun 3 07:08:12 server LLNG[85345]: [debug] Kerberos ticket received: YIIHwQYGKwYBBQUCoIIHtTCCB7GgMDAuBgkqhkiC9xIBAgIGCSqGSIb3EgECAgYKKw...
Jun 3 07:08:12 server LLNG[85345]: [debug] Set KRB5_KTNAME env to FILE:/etc/lemonldap-ng/llng.keytab
Jun 3 07:08:12 server LLNG[85345]: [debug] Processing getUser
...
Jun 3 07:08:12 server LLNG[85345]: [debug] Session cannot be tied: DBD::Pg::st execute failed: ERREUR: la valeur d'une clé dupliquée rompt la contrainte unique « psessions_pkey »#012DÉTAIL : La clé « (id)=(38111bce4464fa66e8f96000bc98094f) » existe déjà. at /usr/share/perl5/Apache/Session/Browseable/Store/DBI.pm line 37.
...
# postgresql.log
ERREUR: la valeur d'une clé dupliquée rompt la contrainte unique « psessions_pkey »
DÉTAIL: La clé « (id)=(0bf69ecff1b995cf07a58d6aad45073f) » existe déjà.
INSTRUCTION : INSERT INTO psessions (id,a_session,_session_uid) VALUES ($1,$2,$3)
ERREUR: la transaction est annulée, les commandes sont ignorées jusqu'à la fin du bloc de la transaction
INSTRUCTION : INSERT INTO psessions (id,a_session,_session_uid) VALUES ($1,$2,$3)
more logs : logs.log
Backends used
Backend configuration/session : Postgresql
Backend users : LDAP - OpenLDAP meta > AD, ADLDS
Combination : [Kerberos,LDAP] or [LDAP]
Kerberos parameters : Use AJAX request : ON