Mise à jour vers 5.1.16 - login impossible "ERR_INACTIVE_USER"

Bonjour,

Suite à l’upgrade de l’appli pch vers la version 5.1.16, on a constaté qu’il n’est plus possible de se connecter avec l’utilisateur designer.
Voici le message d’erreur: “ERR_INACTIVE_USER”.
La log Tomcat est très courte et présente ces exceptions:

2021-12-16T12:26:52.658597215Ze[me[31m2021-12-16 12:26:52,361|SIMPLICITE|ERROR||http://pch-api-7587b56578-lhr6w:8080||ERROR|system|com.simplicite.util.engine.CoreCache|load||Exception:Cannot invoke “com.simplicite.util.View.addGroup(String)” because the return value of “java.util.Map.get(Object)” is null||Core cache error
2021-12-16T12:26:52.658653571Zjava.lang.NullPointerException: Cannot invoke “com.simplicite.util.View.addGroup(String)” because the return value of “java.util.Map.get(Object)” is null at com.simplicite.util.engine.CoreCache.loadViews(CoreCache.java:2203) at com.simplicite.util.engine.CoreCache.load(CoreCache.java:283) at com.simplicite.util.engine.CoreCache.init(CoreCache.java:179) at com.simplicite.util.engine.CoreCache.setInstance(CoreCache.java:109) at com.simplicite.util.engine.GrantManager.initGrantCache(GrantManager.java:462) at com.simplicite.util.engine.GrantManager.loadGrant(GrantManager.java:709) at com.simplicite.util.engine.GrantDirect.init(GrantDirect.java:46) at com.simplicite.util.Grant.init(Grant.java:368) at com.simplicite.util.Grant.getAdmin(Grant.java:575) at com.simplicite.util.Grant.getSystemAdmin(Grant.java:520) at com.simplicite.util.engine.Platform.init(Platform.java:230) at com.simplicite.webapp.listeners.ApplicationListener.contextInitialized(ApplicationListener.java:38) at org.apache.catalina.core.StandardContext.listenerStart(StandardContext.java:4768) at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5230) at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:726) at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:698) at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:696) at org.apache.catalina.startup.HostConfig.deployDirectory(HostConfig.java:1185) at org.apache.catalina.startup.HostConfig$DeployDirectory.run(HostConfig.java:1933) at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75) at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:123) at org.apache.catalina.startup.HostConfig.deployDirectories(HostConfig.java:1095) at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:477) at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1618) at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:319) at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123) at org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:423) at org.apache.catalina.util.LifecycleBase.setState(LifecycleBase.java:366) at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:946) at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:835) at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1396) at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1386) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75) at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:145) at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:919) at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:263) at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) at org.apache.catalina.core.StandardService.startInternal(StandardService.java:432) at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:927) at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) at org.apache.catalina.startup.Catalina.start(Catalina.java:772) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:568) at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:345) at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:476)
2021-12-16T12:28:00.760361372Ze[33m2021-12-16 12:28:00,167|SIMPLICITE|WARN|User ‘system’ has not been created.

L’utilisateur existe dans la base de donnée, dans la table m_user et la colonne user_active est égale à 1.
On a deux environnements impactés; la recette et la production.

Cordialement,
Yassine.

Bonjour Yassine,

j’ai fait le point avec Marwa hier sur ce problème : peux-tu confirmer qu’aucun des users technique socle n’a été supprimé “par erreur” par un membre de l’équipe PACHA ?

Les users techniques socle à ne surtout pas bidouiller sont designer / public / system.

Par ailleurs, l’éditeur a ajouté dans le socle des garde fous pour garantir que ce genre de situation n’arrive pas (dont le fait de ne pas utiliser l’instance en étant connecté en tant que ‘designer’ mais avec un compte personnel habilité au juste nécessaire).

De plus, si l’équipe projet a supprimé des éléments socle de manière non maîtrisée (et dans un mode d’usage non recommandé), je suggère que vous procédiez à une restauration des bases de données depuis une sauvegarde antérieure à l’upgrade (qui a priori n’a rien à voir avec le problème car l’environnement de DEV ne présente pas le problème avec la même image).

Cette erreur ne me dit trop rien.

Vu qu’elle se produit visiblement au niveau le chargement des vues (loadViews) dans le core cache je soupçonne plus un pb de page d’accueil vide ou erronée sur le user designer ou des vues/groupes supprimées, ou dans le genre. @Francois une idée ?

Mais sinon je suis d’accord avec @bmo il faut éviter d’utiliser designer autant que possible (designer est à Simplicité ce que root est à Linux) mais plutôt utiliser des users habilités simplement au paramétrage = au groupe ADMIN ou APP_DESIGNER

Jamais vu,

Avez vous des “definition error in view xxxx” juste avant ?

là où ça plante indique qu’une de vos Vues habilitées à un Groupe ne peut pas être chargées.
Ca sort en exception non gérée, et du coup je pense que le droit system n’est pas chargé non plus.
La plateforme ne démarre pas.

Revenez à la version précédente dans un premier temps.
mais je ne vois pas ce que ça changera au moindre clear-cache ça se reproduira.

On va ajouter un try/catch pour sécuriser cette partie, mais regardez vos vues et vos habilitations :

select v.viw_name, g.grp_name 
from m_view v, m_group g, m_view_group a 
where a.vig_view_id=v.row_id 
and a.vig_group_id=g.row_id
and g.grp_name in ('xxx','yyy'...)

Cette requete ramene des Vues qui n’ont pas pu se charger en mémoire avant et plante quand ça leur affecte des groupes.

Supprimez-les temporairement de la table m_view_group (sans la vider completement, juste vos Vues) pour au moins charger le core cache, pour corriger vos Vues.

NB: si vous avez changé le nom logique ou physique d’un attribut ou d’un objet système les loaders ne pourront plus fonctionner correctement et le symptôme visible ne sera sans doute pas très explicite car on est alors dans le domaine des erreurs “bas niveau” non prévues et impossible à prévoir.

D’où l’intérêt de ne jamais travailler avec le user designer car lui seul à la possibilité de faire ce genre de modifications potentiellement destructrices (c’est légitime qu’il puisse le faire car c’est lui qui applique les mises à jour système).

Si c’est ce genre de choses que vous avez faite le plus sain est de revenir à un backup de base datant d’avant cette modif destructrice (sinon trouvez un moyen de faire la modif inverse manuellement au niveau de la base de données avec le risque de faire empirer les choses).

La log n’indique pas d’erreur SQL / column not found…

Je pense plutôt à un dead-link en base.
Du genre une vue a été supprimée mais pas ses habilitations en cascade (plantage, arret brutal, pb de droits, delete à la main?..).

Et du coup Simplicité cherche à habiliter une vue qui n’a pas été chargée (d’où ma question si pas de log “definition error in view xxxx”)

Donc il faut faire le ménage dans votre table “m_view_group” à la main.

Lister son contenu est vérifier toutes les vues pointées.
si elle existe encore dans la table m_view

  • si oui, voir pourquoi elle ne se charge pas dans la log
  • si non, c’est un lien mort à dégager.

Liens morts =

select * from m_view_group
where vig_view_id not in (select row_id from m_view)

La prochaine version aura un try/catch pour ne pas planter à cet étage, mais ne corrigera pas le problème de définition.

Après plusieurs vérifications dans la BD (users, views, resps, groups, view_group, etc.) nous n’avons pas trouvé d’anomalie (record manquant ou dead-link). Nous avons donc stoppé tous les services pour redémarrer - a priori - proprement mais le reboot semble tourner court…

Voici la log produite :

Info 2021-12-17 09:06:33.582 CET pch-api  ___ _ _ _ _ _ __ _
Info 2021-12-17 09:06:33.582 CET pch-api / __(_)_ __ _ __| (_)__(_) |_ /_/ (_)___
Info 2021-12-17 09:06:33.582 CET pch-api \__ \ | ' \| '_ \ | / _| | _/ -_)_| / _ \
Info 2021-12-17 09:06:33.582 CET pch-api |___/_|_|_|_| .__/_|_\__|_|\__\___(_)_\___/
Info 2021-12-17 09:06:33.582 CET pch-api |_| Running on centos7
Info 2021-12-17 09:06:33.582 CET pch-api 
Info 2021-12-17 09:06:33.684 CET  pch-api Tomcat root: /usr/local/tomcat
Info 2021-12-17 09:06:33.684 CET pch-api Tomcat webapp: ROOT
Info 2021-12-17 09:06:33.802 CET pch-api Cleaning work files/dirs... Done
Info 2021-12-17 09:06:33.977 CET pch-api Database vendor: postgresql
Info 2021-12-17 09:06:33.981 CET pch-api PostgreSQL database: localhost / 5432 / pch_01_db / pch_01_adm
Info 2021-12-17 09:06:35.290 CET pch-api Tomcat started.
Info 2021-12-17 09:06:36.294 CET pch-api NOTE: Picked up JDK_JAVA_OPTIONS: --add-opens=java.base/java.lang=ALL-UNNAMED --add-opens=java.base/java.io=ALL-UNNAMED --add-opens=java.base/java.util=ALL-UNNAMED --add-opens=java.base/java.util.concurrent=ALL-UNNAMED --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED --add-exports jdk.compiler/com.sun.tools.javac.api=ALL-UNNAMED --add-exports jdk.compiler/com.sun.tools.javac.file=ALL-UNNAMED --add-exports jdk.compiler/com.sun.tools.javac.parser=ALL-UNNAMED --add-exports jdk.compiler/com.sun.tools.javac.tree=ALL-UNNAMED --add-exports jdk.compiler/com.sun.tools.javac.util=ALL-UNNAMED
Info 2021-12-17 09:06:52.376 CET pch-api 2021-12-17 08:06:51,984|CATALINA|WARNING|Match [Server/Service/Connector] failed to set property [maxHttpHeaderSize] to [8192]
Info 2021-12-17 09:06:54.376 CET pch-api 2021-12-17 08:06:53,577|CATALINA|INFO|Server version name: Apache Tomcat/9.0.56
Info 2021-12-17 09:06:54.376 CET pch-api 2021-12-17 08:06:53,577|CATALINA|INFO|Server built: Dec 2 2021 14:30:07 UTC
Info 2021-12-17 09:06:54.376 CET pch-api 2021-12-17 08:06:53,577|CATALINA|INFO|Server version number: 9.0.56.0 
Info 2021-12-17 09:06:54.377 CET pch-api 2021-12-17 08:06:53,578|CATALINA|INFO|OS Name: Linux
Info 2021-12-17 09:06:54.377 CET pch-api 2021-12-17 08:06:53,578|CATALINA|INFO|OS Version: 5.4.120+
Info 2021-12-17 09:06:54.377 CET pch-api 2021-12-17 08:06:53,578|CATALINA|INFO|Architecture: amd64
Info 2021-12-17 09:06:54.377 CET pch-api 2021-12-17 08:06:53,579|CATALINA|INFO|Java Home: /usr/local/jdk
Info 2021-12-17 09:06:54.377 CET pch-api 2021-12-17 08:06:53,579|CATALINA|INFO|JVM Version: 17.0.1+12
Info 2021-12-17 09:06:54.377 CET pch-api 2021-12-17 08:06:53,579|CATALINA|INFO|JVM Vendor: Eclipse Adoptium
Info 2021-12-17 09:06:54.377 CET pch-api 2021-12-17 08:06:53,580|CATALINA|INFO|CATALINA_BASE: /usr/local/tomcat
Info 2021-12-17 09:06:54.377 CET pch-api 2021-12-17 08:06:53,580|CATALINA|INFO|CATALINA_HOME: /usr/local/tomcat
Info 2021-12-17 09:06:54.377 CET pch-api 2021-12-17 08:06:53,587|CATALINA|INFO|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]
Info 2021-12-17 09:07:03.378 CET pch-api 2021-12-17 08:07:03,181|CATALINA|INFO|The ["http-nio-8080"] connector has been configured to support HTTP upgrade to [h2c]
Info 2021-12-17 09:07:03.378 CET  pch-api 2021-12-17 08:07:03,181|CATALINA|INFO|Initializing ProtocolHandler ["http-nio-8080"]
Info 2021-12-17 09:17:00.803 CET pch-api 2021-12-17 08:17:00,199|SIMPLICITE|WARN|User 'system' has not been created
Info 2021-12-17 09:17:00.803 CET pch-api 2021-12-17 08:17:00,298|SIMPLICITE|WARN|User 'system' has not been created
Info 2021-12-17 09:17:00.803 CET pch-api 2021-12-17 08:17:00,337|SIMPLICITE|WARN|User 'system' has not been created
Info 2021-12-17 09:17:00.803 CET pch-api 2021-12-17 08:17:00,411|SIMPLICITE|WARN|User 'system' has not been created
Info 2021-12-17 09:18:00.809 CET pch-api 2021-12-17 08:18:00,034|SIMPLICITE|WARN|User 'system' has not been created
Info 2021-12-17 09:18:00.809 CET pch-api 2021-12-17 08:18:00,078|SIMPLICITE|WARN|User 'system' has not been created
Info 2021-12-17 09:18:00.809 CET pch-api 2021-12-17 08:18:00,121|SIMPLICITE|WARN|User 'system' has not been created
Info 2021-12-17 09:18:00.809 CET pch-api 2021-12-17 08:18:00,203|SIMPLICITE|WARN|User 'system' has not been created
Info 2021-12-17 09:18:00.809 CET pch-api 2021-12-17 08:18:00,380|SIMPLICITE|WARN|User 'system' has not been created
Info 2021-12-17 09:18:00.809 CET pch-api 2021-12-17 08:18:00,696|SIMPLICITE|WARN|User 'system' has not been created

Qu’est-ce qui pourrait bloquer ?

J’ai deux causes possibles en tête:

  1. La BD n’est plus accessible par le user admin configuré (techniquement ok mais fonctionnellement ko)
  2. Je n’exclue pas des manips non maîtrisées d’un “designer” qui ne s’est pas manifesté… Je n’ai aucune piste qui me permettrait de confirmer qu’il y a bien eu une altération de la doc

Est il possible de nous fournir le dump de cette base (sans le contenu des tables métier si ça pose un pb) ?

L’idée est de pouvoir debugger pas à pas le démarrage (notamment le chargement du core cache et l’instanciation du user system) pour voir précisément où ça coince.

Il n’y a plus de stack java comme la 1ere fois dans le chargement du core cache ?

User ‘system’ has not been created
Pb de core cache ou d’accès à la table m_user.
une erreur SQL devrait se voir dans les logs.

@david
Peut ton livrer la 5.1.18, elle contient le contournement de ce null pointer qui n’est pas sensé exister.

Ensuite effectivement pas d’autre choix que du pas à pas au démarrage.

Autre piste : activez les traces SQL dans LOG_SQL_USER=yes et LOG_SQL_SYSTEM=yes
pour savoir après quelle requête ça coupe au chargement.

update m_system set sys_value='yes' 
where sys_code in ('LOG_SQL_USER','LOG_SQL_SYSTEM')

la vue n’existe pas :

ERROR: relation “m_view_group” does not exist
LINE 1: select * from m_view_group
^
SQL state: 42P01
Character: 15

Oui là c’est bloquant…

Sans connaitre l’étendu des dégats, il faudrait repartir d’une sauvegarde.

Simplicité ne “drop” jamais de table même si on supprime par erreur un objet ou un attribut. Donc vous avez cassé votre base je ne sais pas comment mais pas via la UI.

@bmo disait que la base semblait correcte, et comme le dit @Francois, Simplicite ne droppe jamais de table => bref êtes vous sûr de faire la requête au bon endroit (sur la bonne base, dans le bon schema, etc.) ?

Je réitère ma demande d’avoir un dump de votre base car sinon c’est vraiment compliqué pour nous d’investiguer ce genre de choses (= une erreur inconnue liée à un pb sans doute non prévu) “en aveugle”

Le contrôle sur la table m_view_group n’a peut-être pas été fait comme on le pensait, on vérifie ça…
En // on déploie la 5.1.17 (merci bcp pour votre réactivité) car ça permettra peut-être de terminer le start et de faire plus de vérifications on-line…

Attention le fix de robustesse dont parle @Francois n’a pas encore été releasé => c’est prévu dans le cadre de la révision 5.1.18 qu’on prévoyait de pousser ce soir.

PI, la 5.1.17 date du début de semaine (cf.Simplicité® 5/releasenote/releasenote-5.1) et a été justifiée par la mise à dispo par la fondation Apache d’une version finale corrigée de Log4J2 (la version qu’on a embarqué dans la 5.1.16 n’était à priori qu’un “drity quick fix” qui résolvait la vulnérabilité mais pas de manière idéale), bref rien à voir…

1 Like

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.