Problème de redirection au logout

julienroy03 · June 28, 2023, 9:23am

Request description

Bonjour,

Quand on clique sur le bouton Quitter, la redirection me renvoie une erreur 500 qui disparait lorsqu’on rafraichit la page.
Il semble que la redirection de l’URL de base vers l’URL de connexion LDAP ne fonctionne pas au moment du Quit.

Pouvez-vous nous aider ?

Merci.

Julien

Technical information

Instance /health

Status=OK
Version=5.3.4
BuiltOn=2023-06-03 17:10

david · June 28, 2023, 9:34am

Oui si vous nous fournissez plus d’éléments pour qu’on cerne plus précisément dans quel cas vous êtes

quelle est la configuration de votre authentification (typiquement la valeur du param système AUTH_PROVIDER en masquant les infos sensibles)
avez vous mis en place des choses particulières liées à la session (ex: du code dans le PlatformHooks)

Merci de nous fournir les logs serveur pertinentes (notamment après avoir activé le log event DAUTHSC001) ainsi que les copies d’écran de l’onglet “Console” du navigateur (si vous y voyez des choses pertinentes) et de l’onglet “Network” (pour voir la sequence de redirects)

PS: la révision 5.3.4 n’est pas la dernière (elle date d’il y a ~1 mois et est en retard de ~25 commits). Merci de toujours commencer par vous mettre à jour (en l’occurrence en 5.3.6 = la dernière révision de la 5.3) avant de solliciter notre support, il n’est jamais impossible qu’un pb ait déjà été corrigé.

julienroy03 · June 29, 2023, 9:34am

Bonjour,

Merci pour votre réponse.

On a pullé la dernière version de simplicité 5.3.6 et le problème se reproduit toujours :

[Platform]
Status=OK
Version=5.3.6
BuiltOn=2023-06-22 15:34

Voila une copie d’écran de l’onglet network :

et voici la capture d’écran de la console :

Et voila pour le param système AUTH_PROVIDER :

Ce qu’on a dans le PlateformHooks :

Et on ne voit rien dans les logs systems même avec le DAUTHSC001 activé.

david · June 29, 2023, 10:33am

Nous ne reproduisons pas ce symptôme décrit sur une 5.3 à jour et avec une authent LDAP basique :

AUTH_PROVIDERS:

[
	{ "name": "simplicite", "type": "internal" },
	{ "name": "ldap", "type": "ldap", "sync": false }
]

et LDAP_AUTH_CONFIG:

{
    "url": "ldap://localhost:389",
    "dnpattern": "uid=[USERNAME],ou=People,dc=simplicite,dc=com"
}

Que vaut ce param système dans votre cas ? Auriez vous configuré d’autres params systèmes particuliers (ex: en *LDAP* et/ou en *URL*) ? etc.

Ce qui me semble spécifique/anormal dans votre onglet Network c’est les redirects 302 vers des URLs absolue alors que dans une séquence de logout LDAP nominale on a une suite de redirects relatifs:

Il faudrait voir si le reverse proxy / load balancer que vous avez peut être en amont de votre instance ne fait pas quelque chose de particulier. Typiquement s’il ne gère pas le transfert du hostname/port public à Tomcat ça peut avoir des effets inattendus… Avez vous bien cablé vos ports en fct de l’exposition en SSL ou pas (cf. Simplicité® documentation/90-operation/docker) ?

Il faudrait regarder de près les headers/contenus des différents appels d’URL, ex:

En tout cas la page qui finit en HTTP 500 doit surement générer au moins une trace d’erreur et/ou un stacktrace dans la log simplicité (dans /usr/local/tomcat/webapps/ROOT/WEB-INF/log/simplicite.log) et/ou sur la console Docker (en tout cas si vous n’avez pas customisé la config Log4J) car ce qui finit en HTTP 500 dans Simplicité ce sont les erreurs non prévues trappées dans le try/catch de premier niveau et à ce niveau il y a normalement systématiquement un AppLog.error(...)

PS: Mettez systématiquement des try/catch dans vos platform hooks pour mieux gérer un éventuel pb non prévu à ce niveau

julienroy03 · July 3, 2023, 2:24pm

Bonjour,

Voici le détail des headers au moment de l’erreur 500 :

L’erreur disparait si on ajoute une nouvelle méthode d’authentification, car on est redirigé correctement vers l’écran permettant le choix de l’authentification. Par exemple dans notre cas on avait LDAP, en ajoutant OKTA on a plus ce problème de redirection.

Ci -joint, également notre sys param pour LDAP :

Merci par avance.

david · July 3, 2023, 3:00pm

Les redirects semblent OK et la config LDAP et le AUTH_PROVIDERS n’ont visiblement rien de différent de notre cas de test où l’on n’obtient pas de réponse HTTP 500

Vérifiez si vous n’avez pas de stacktrace dans les logs car une réponse en HTTP 500 signifie forcément soit un catch explicite avec une trace d’erreur dans la log Simplicité soit un catch implicite niveau Tomcat et donc un stacktrace dans la log Tomcat.

Essayez d’inhiber votre code dans votre PlatformHooks pour vous assurer que le pb n’est pas à ce niveau.

Au passage, outre son indentation plutôt bizarre qui le rend pas très lisible, votre code n’est pas idéal:

Vous ne checkez pas si votre save fonctionne, idéalement vous devriez faire un user.getTool().validateAndSave() sous try/catch en gérant les cas d’erreur
Il présente un usage d’AppLog incorrect:

Vous référencez une classe legacy GrantHooks au lieu de la classe de votre code
Vous ne mettez pas le nom de votre méthode dans votre 2ème argument

Utilisez plutôt la version simplifiée : AppLog.info(<message>, <grant>) qui détermine toute seule la classe et la méthode d’où on l’appelle

Emmanuelle · July 7, 2023, 9:16am

Bonjour David,

Nous avons commenté le code du PlatformHooks (j’admets qu’il est un peu tout pourri, on va le revoir) et l’erreur se produit toujours.
Je n’ai rien dans les logs Simplicité et dans les logs Catalina je ne vois que ça

10.40.0.25 - - [07/Jul/2023:09:12:12 +0000] "GET /logout HTTP/1.1" 302 -
10.40.0.25 - - [07/Jul/2023:09:12:12 +0000] "GET / HTTP/1.1" 302 -
10.40.0.25 - - [07/Jul/2023:09:12:12 +0000] "GET /ui/ HTTP/1.1" 500 548

C’est un problème assez récent mais je ne sais pas identifier le déclencheur. On a changé d’adresse LDAP décemment ainsi que migré en 5.3, entre autres choses.

david · July 7, 2023, 9:27am

Visiblement ta log est un access log, ça ne dit rien de plus que la console “Network” du navigateur…

Je dis de regarder dans la log applicative Simplicite : <tomcat root>/webapps/ROOT/WEB-INF/log/simplicite.log et dans la log Tomcat <tomcat root>/logs/catalina.out à la recherche du stacktrace qui permettrait de savoir quelle erreur aboutit à ce HTTP 500.

Comme dit plus haut dans le code Simplicité en général un HTTP 500 est retourné en cas de “unexpected error” donc il nous est impossible de deviner le cas d’erreur sans un stacktrace qui dit où ça se produit. D’autant que nous ne constatons pas de pb avec une connexion LDAP sur une 5.3

Essayez de voir via des outils bas niveau (ex: nmap et/ou un CLI natif LDAP) si votre nouveau LDAP tel que configuré au niveau applicatif est bien accessible depuis le serveur (i.e. depuis le container si vous êtes en Docker)

Emmanuelle · July 7, 2023, 9:57am

Dans les logs Simplicité je ne vois pas de stacktrace

2023-07-07 09:53:34,845|SIMPLICITE|WARN||http://simplicite-dev-744945966c-bjwnj:8080||WARN|system|com.simplicite.webapp.servlets.ui.DefaultServlet|service||Event: /events is not requested with websocket protocol. The request is ignored.
2023-07-07 09:53:33,733|SIMPLICITE|INFO||http://simplicite-dev-744945966c-bjwnj:8080||ICORED0001|designer|com.simplicite.util.Grant|init||Info: designer connected, session ID: 335EB37E2F3812E0ADBF632ECF759FA1, timeout: 30 min , user agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Safari/537.36, from: 10.252.251.5
2023-07-07 09:53:33,553|SIMPLICITE|INFO||http://simplicite-dev-744945966c-bjwnj:8080||INFO|system|com.simplicite.util.GrantHooks|login||Event: designer
2023-07-07 09:53:33,553|SIMPLICITE|INFO||http://simplicite-dev-744945966c-bjwnj:8080||INFO|system|com.simplicite.util.GrantHooks|parseAuth||Event: Session info: {"method":1,"provider":"simplicite","groups":[],"attributes":{"state":"SJTYWzShP2iEIOVN0nZjvfV1EDPi6rDpUrkU5RcsoogQARNveX9VDo50Lmsy7r2l"},"login":"designer","token":"oqAG6Xm7sP9MVhPW11FO4cZGKBfpi8xWoEbdktM9cWN79Df2Sz"}
2023-07-07 09:52:00,919|SIMPLICITE|WARN||http://simplicite-dev-744945966c-bjwnj:8080||WARN|system|com.simplicite.webapp.servlets.ui.DefaultServlet|service||Event: /events is not requested with websocket protocol. The request is ignored.
2023-07-07 09:51:59,804|SIMPLICITE|INFO||http://simplicite-dev-744945966c-bjwnj:8080||ICORED0001|designer|com.simplicite.util.Grant|init||Info: designer connected, session ID: 81676FA73E9BDEC24AC88DAF4EACB422, timeout: 30 min , user agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/114.0.0.0 Safari/537.36, from: 10.252.251.5
2023-07-07 09:51:59,648|SIMPLICITE|INFO||http://simplicite-dev-744945966c-bjwnj:8080||INFO|system|com.simplicite.util.GrantHooks|login||Event: designer
2023-07-07 09:51:59,648|SIMPLICITE|INFO||http://simplicite-dev-744945966c-bjwnj:8080||INFO|system|com.simplicite.util.GrantHooks|parseAuth||Event: Session info: {"method":1,"provider":"simplicite","groups":[],"attributes":{"state":"ZsLKTB4T7KQSUYBYyxcBS1eoRM50dV317r0bgNmo0ie3lJja2LWO0a7Zg8hOWila"},"login":"designer","token":"I8uZVBx8Q28PoDKFXjhwRCM6W5MkM9ABpgCbhWZGCAlo1vWkvH"}
2023-07-07 09:51:23,741|SIMPLICITE|INFO||http://simplicite-dev-744945966c-bjwnj:8080||INFO|system|com.simplicite.util.engine.CoreCleaner|cleaner||Event: GC: DynamicClassLoader@2919976e has been removed from memory.

Dans le catalina.log non plus

07-Jul-2023 09:50:47.913 INFO [main] org.apache.catalina.core.AprLifecycleListener.lifecycleEvent The Apache Tomcat Native library which allows using OpenSSL was not found on the java.library.path: [/usr/java/packages/lib:/usr/lib64:/lib64:/lib:/usr/lib]
07-Jul-2023 09:50:48.473 INFO [main] org.apache.coyote.http11.AbstractHttp11Protocol.configureUpgradeProtocol The ["http-nio-8080"] connector has been configured to support HTTP upgrade to [h2c]
07-Jul-2023 09:50:48.473 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8080"]
07-Jul-2023 09:50:48.493 INFO [main] org.apache.coyote.http11.AbstractHttp11Protocol.configureUpgradeProtocol The ["http-nio-8443"] connector has been configured to support HTTP upgrade to [h2c]
07-Jul-2023 09:50:48.493 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["http-nio-8443"]
07-Jul-2023 09:50:48.495 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["ajp-nio-0.0.0.0-8009"]
07-Jul-2023 09:50:48.513 INFO [main] org.apache.coyote.http11.AbstractHttp11Protocol.configureUpgradeProtocol The ["https-jsse-nio-8444"] connector has been configured to support negotiation to [h2] via ALPN
07-Jul-2023 09:50:48.513 INFO [main] org.apache.coyote.AbstractProtocol.init Initializing ProtocolHandler ["https-jsse-nio-8444"]
07-Jul-2023 09:50:48.827 INFO [main] org.apache.tomcat.util.net.AbstractEndpoint.logCertificate Connector [https-jsse-nio-8444], TLS virtual host [_default_], certificate type [UNDEFINED] configured from [conf/server.jks] using alias [tomcat] and with trust store [null]
07-Jul-2023 09:50:48.829 INFO [main] org.apache.catalina.startup.Catalina.load Server initialization in [1187] milliseconds
07-Jul-2023 09:50:48.866 INFO [main] org.apache.catalina.core.StandardService.startInternal Starting service [Catalina]
07-Jul-2023 09:50:48.866 INFO [main] org.apache.catalina.core.StandardEngine.startInternal Starting Servlet engine: [Apache Tomcat/9.0.76]
07-Jul-2023 09:50:48.873 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deploying web application directory [/usr/local/tomcat/webapps/ROOT]
07-Jul-2023 09:51:10.718 INFO [main] org.apache.catalina.startup.HostConfig.deployDirectory Deployment of web application directory [/usr/local/tomcat/webapps/ROOT] has finished in [21,842] ms
07-Jul-2023 09:51:10.724 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8080"]
07-Jul-2023 09:51:10.747 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["http-nio-8443"]
07-Jul-2023 09:51:10.795 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["ajp-nio-0.0.0.0-8009"]
07-Jul-2023 09:51:10.815 INFO [main] org.apache.coyote.AbstractProtocol.start Starting ProtocolHandler ["https-jsse-nio-8444"]
07-Jul-2023 09:51:10.868 INFO [main] org.apache.catalina.startup.Catalina.start Server startup in [22038] milliseconds

Je vais tester l’accès au LDAP depuis le serveur mais je ne pense pas que le problème vienne de là car après un F5, on accède correctement à la page et le LDAP fonctionne.

david · July 7, 2023, 10:13am

Désolé sans stacktrace et sans reproduire je n’ai plus d’idée…

Emmanuelle · July 7, 2023, 10:17am

Pour moi c’est vraiment un souci de redirect, si j’entre https://ear.k8s-prod.grouperci.com/ui dans le navigateur, je suis bien redirigée vers https://ear.k8s-prod.grouperci.com/ldapauth?_provider=ldap

Mais quand je quitte, je reste sur https://ear.k8s-prod.grouperci.com/ui/ (avec un slash en plus) et c’est là que j’ai la 500

Je vais demander aux DEVOPS s’ils ont une idée …

david · July 7, 2023, 10:19am

Peut être une subtilité dans le reverse proxy car de notre coté /ui et /ui/ arrivent au même endroit

Emmanuelle · July 11, 2023, 10:22am

Bonjour,

C’est encore moi …
Y a-t-il moyen de debugger ce qu’il se passe avant le login ? Au moment où Simplicité va chercher les infos de AUTH_PROVIDER pour rediriger vers l’écran de login.

Je ne comprends pas comment je peux avoir une 500 sans erreur dans aucun des fichiers de logs.

Merci !

Emmanuelle · July 11, 2023, 12:53pm

Ah et en mode DEBUG, même si je n’ai pas de stacktrace j’ai quand même ceci

2023-07-11 12:51:46,543|SIMPLICITE|DEBUG||http://simplicite-int-696bfb67b8-drmwx:8080||DAUTHCS001|system|com.simplicite.webapp.filters.AuthMethodFilter|methodLDAP||Authentication debug: LDAP requested URI = [/ui/]
2023-07-11 12:51:46,544|SIMPLICITE|DEBUG||http://simplicite-int-696bfb67b8-drmwx:8080||DEBUG|system|com.simplicite.webapp.tools.ServletTool|setHTTPHeaders||Event: [REQUEST] method GET on /error from 10.252.251.5 with session C8DBB4567346913DE5EAA1BBC7646D2C, [RESPONSE]  MIME type: text/html; charset=UTF-8 max age: 0 seconds

david · July 11, 2023, 7:15pm

Visiblement il y a un moment où une erreur gérée se produit d’où l’appel au /error qui correspond à la 2ème trace.

Mais dans cette page si une erreur non prévue se produit ça renvoie un HTTP 500 sans générer de stacktrace dans les logs.

On va ajouter un stacktrace à ce niveau dans les prochaines revision pour y voir plus clair.

Emmanuelle · July 19, 2023, 7:59am

Bonjour David,

Aurais-tu une idée de la date de livraison du prochain patch ?

Merci !
Emmanuelle

david · July 19, 2023, 8:19am

La 5.3.9 devrait être releasée d’ici la semaine prochaine. Sans doute vendredi, mais au pire lundi ou mardi.

Emmanuelle · July 19, 2023, 8:27am

Génial merci beaucoup, c’est parfait

Emmanuelle · July 24, 2023, 6:44am

Bonjour David,

J’ai pullé la 5.3.9 mais je n’ai toujours pas de stacktrace, est-ce qu’elle a été ajoutée ?

Merci !

david · July 24, 2023, 7:10am

Oui en 5.3.9 une stacktrace a été ajoutée à la servlet d’erreur.
SI ça ne donne rien de plus, je ne vois plus comment aider.