2021-01-13 09:03:17,266 ERROR [com.simplicite.util.engine.CoreCache] SIMPLICITE|https://Prod-sim-2:10028/forpro|/forpro|ERROR|08254|com.simplicite.util.engine.CoreCache|instantiateObject||Evénement: Class not found for CrbFopIndividu: checks definition and script compilation.
2021-01-13 09:03:17,265 WARN [com.simplicite.util.engine.DynamicClassLoader] SIMPLICITE|https://Prod-sim-2:10028/forpro|/forpro|WARN|system|com.simplicite.util.engine.DynamicClassLoader|loadClass||Evénement: Unable to load class: com.simplicite.objects.CrbForpro.CrbFopIndividu
2021-01-13 09:03:14,368 INFO [com.simplicite.util.Grant] SIMPLICITE|https://Prod-sim-2:10028/forpro|/forpro|ICORED0001|public|com.simplicite.util.Grant|init||Info : public connected, session ID: 7D447EA7C58406DE5D6B4A58BE0284EE, timeout: 5 min , user agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:84.0) Gecko/20100101 Firefox/84.0
2021-01-13 09:03:14,238 INFO [com.simplicite.util.UserSession] LOGOUT|37662242D0AD90C7860F0C14B7612B14|SIVY22|20|0:00:20
2021-01-13 09:03:10,736 INFO [com.simplicite.util.Grant] SIMPLICITE|https://Prod-sim-2:10028/forpro|/forpro|ICORED0001|public|com.simplicite.util.Grant|init||Info : public connected, session ID: 9445CA6DA72C016417B6363405CD0D11, timeout: 5 min , user agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/87.0.4280.141 Safari/537.36
2021-01-13 09:03:10,733 WARN [com.simplicite.webapp.servlets.ui.JSONServlet] SIMPLICITE|https://Prod-sim-2:10028/forpro|/forpro|WARN|system|com.simplicite.webapp.servlets.ui.JSONServlet|service||Evénement: Service error
java.lang.NullPointerException
at com.simplicite.webapp.ObjectJson.metadata(ObjectJson.java:79)
at com.simplicite.webapp.tools.JSONServletTool.businessObjectService(JSONServletTool.java:536)
at com.simplicite.webapp.servlets.AbstractJSONServlet.service(AbstractJSONServlet.java:68)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:733)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.simplicite.webapp.filters.RewriteFilter.doFilter(RewriteFilter.java:77)
at com.simplicite.webapp.filters.AbstractFilter.doFilter(AbstractFilter.java:37)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at com.simplicite.webapp.filters.AuthMethodFilter.doFilter(AuthMethodFilter.java:138)
at com.simplicite.webapp.filters.AbstractFilter.doFilter(AbstractFilter.java:37)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542)
at com.simplicite.tomcat.valves.APISessionValve.invoke(APISessionValve.java:192)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:690)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:374)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:888)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1597)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.base/java.lang.Thread.run(Thread.java:830)
L’endroit où cette erreur se produit est très étrange (c’est un synchronize(obj) sur un objet sur lequel on vient juste de faire un getObject après avoir vérifié les droits) ce n’est donc sans doute pas la cause initiale du pb, merci de nous envoyer les logs complètes (Tomcat + Simplicite) depuis le dernier démarrage pour qu’on analyse ce qui a pu se passer avant.
On a livré des petits correctifs hier en V4 mais rien qui peut faire ce genre de chose.
Je vois un “Class not found for CrbFopIndividu”
Problème de compilation des objets à un moment donné, votre clear-cache a visiblement pu rebuilder les classes.
Si l’objet est nul c’est que le cache a du mal se reconstruire. Il faut donc effectivement voir ce qui s’est passé lors de l’upgrade et faire de votre côté les vérifications de base : espace disque suffisant, un upgrade system/jdk … ?
Normalement on devrait voir les pb bas niveau dans les logs Tomcat (pas forcement simplicité qui reste un couche applicative).
Par acquis de conscience, outre les logs complètes, pourrait on voir ce que vous faites exactement dans vos hooks du SIM (/var/simplicite/hooks/pre|post-*.sh) ?
Ainsi que la configuration de votre SIM: sim config
L’idée est ici de savoir ce qui se passe exactement et dans quel ordre lors de vos upgrades
C’était pas une commande mais un emplacement de fichiers => ls -alF /var/simplicite/hooks/
Les hooks du SIM sont des *.sh qui contiennent des customisations vis à vis du comportement standard du SIM, de mémoire vous en avez implémenté, nous voudrions savoir ce que vous y faites exactement.
OK dans quel(s) hooks ce script est il appelé ?
De mémoire il y avait d’autres choses dans ces hooks (genre des ajouts de JARs, etc)
Peut on avoir le contenu de tous les fichiers du répertoire hooks ? ce qu’on cherche ici à savoir c’est s’il y a quelque chose de nature à “perturber” le process d’upgrade et/ou plus généralement le fonctionnement de la plateforme. Peut être n’y a-t-il rien mais on voudrait en être sûr.
Peut on aussi avoir le contenu du fichier .simplicite de l’instance en question : sim sh moninstance puis cat .simplicite ? Ici l’objectif est de vérifier la manière dont est configurée le passage des patches sur cette instance
OK pour le .simplicite on est bien en mode “auto patch”
Pour les hooks du SIM il y en a plusieurs qui sont implémentés et qui sont sollicités pendant le process d’upgrade => il nous faudrait le contenu de ces scripts
OK nous voulions vérifier qu’aucune “sollicitation” de la plateforme (genre des appels curl pour importer du paramérage ou autre) ne vient perturber le démarrage (et donc le chargement intial du cache). Ce n’est visiblement pas le cas, tant mieux.
Pour préciser : le mode auto-patch est “asynchrone” vis à vis du SIM, sur upgrade l’instance “rend la main” au SIM avant d’avoir fini son processus de démarrage et notamment son auto-patch, donc par exemple solliciter les services de l’instance dans le hook post-upgrade.sh ou le post-start.sh peut donc aboutir à des choses aléatoires et imprévisibles.
Donc pour avancer dans l’investigation il nous faut les logs complètes depuis le démarrage. Pas sous forme de copies d’écran ou par copier/coller textuels laborieux pour vous et risquant d’être incomplets => récupérez les fichiers complets par scp/sftp
13-Jan-2021 05:02:42.090 INFOS [http-nio-10023-exec-1] org.apache.coyote.http11.Http11Processor.service Erreur lors de l'analyse d'un en-tête de requête HTTP Note : les occurrences suivantes d'erreurs d'analyse de requête HTTP seront enregistrées au niveau DEBUG.
java.lang.IllegalArgumentException: Caractère invalide trouvé dans le nom de méthode. Les noms HTTP doivent être des "token".
at org.apache.coyote.http11.Http11InputBuffer.parseRequestLine(Http11InputBuffer.java:417)
at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:261)
at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:888)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1597)
at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.base/java.lang.Thread.run(Thread.java:830)
Rien à voir à priori avec Simplicité, c’est le connecteur HTTP Tomcat qui râle ici, mais je pense que vous devez faire des requêtes HTTP “atypiques” qu’il n’aime pas (“pings” de supervision peut être ?)
Dans le simplicite.log il y a:
a) des erreurs d’exécution Rhino:
2021-01-13 06:00:02,672 ERROR [com.simplicite.util.RhinoScriptInterpreter] SIMPLICITE|https://Prod-sim-2:10028/forpro|/forpro|ECORESC002|system|com.simplicite.util.RhinoScriptInterpreter|CrbFopStagiaire.preSave||Erreur évaluation script: CrbFopStagiaire
org.mozilla.javascript.EcmaError: TypeError: Impossible dappeler la méthode "{1}" de {0} (CrbFopStagiaire#87) in CrbFopStagiaire at line number 87
line 82: if(this.getFieldValue("fopStagiaireDtSortie")!==""){
line 83: var tmpStgBilan=this.getGrant().getTmpObject("CrbFopStgBilan");
line 84: tmpStgBilan.resetFilters();
line 85: tmpStgBilan.getField("fopStgBilanStagiaire_fk").setFilter(this.getRowId());
line 86: var rows = tmpStgBilan.search();
error87: for (var k = 0; k < rows.size(); k++) {
line 88: var row=rows.get(k);
line 89: tmpStgBilan.setValues(row);
line 90: var id=tmpStgBilan.getRowId();
Comme c’est du Rhino, ca n’a sans doute pas d’impact sur le démarrage mais il y a un truc à regarder
b) des traces relatives à des classes Java non trouvées:
2021-01-13 06:00:02,830 WARN [com.simplicite.util.engine.DynamicClassLoader] SIMPLICITE|https://Prod-sim-2:10028/forpro|/forpro|WARN|system|com.simplicite.util.engine.DynamicClassLoader|loadClass||Evénement: Unable to load class: com.simplicite.objects.CrbForpro.CrbFopSession
2021-01-13 06:00:02,830 ERROR [com.simplicite.util.engine.CoreCache] SIMPLICITE|https://Prod-sim-2:10028/forpro|/forpro|ERROR|system|com.simplicite.util.engine.CoreCache|instantiateObject||Evénement: Class not found for CrbFopSession: checks definition and script compilation.
2021-01-13 06:00:02,830 WARN [com.simplicite.util.engine.CoreCache] SIMPLICITE|https://Prod-sim-2:10028/forpro|/forpro|WARN|system|com.simplicite.util.engine.CoreCache|instantiateObject||Evénement: Designer can fix temporarily the object as a simple ObjectDB.
2021-01-13 06:00:02,831 WARN [com.simplicite.util.engine.DynamicClassLoader] SIMPLICITE|https://Prod-sim-2:10028/forpro|/forpro|WARN|system|com.simplicite.util.engine.DynamicClassLoader|loadClass||Evénement: Unable to load class: com.simplicite.objects.CrbForpro.CrbFopSession
2021-01-13 06:00:02,833 ERROR [com.simplicite.util.Tool] SIMPLICITE|https://Prod-sim-2:10028/forpro|/forpro|ECORED0001|system|com.simplicite.util.Tool|streamToObject||Erreur Error during deserialization: com.simplicite.objects.CrbForpro.CrbFopSession
java.lang.ClassNotFoundException: com.simplicite.objects.CrbForpro.CrbFopSession
at com.simplicite.util.engine.DynamicClassLoader.loadClass(DynamicClassLoader.java:71)
at java.base/java.lang.Class.forName0(Native Method)
at java.base/java.lang.Class.forName(Class.java:416)
at com.simplicite.util.engine.DynamicObjectInputStream.resolveClass(DynamicObjectInputStream.java:26)
at java.base/java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1941)
at java.base/java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1827)
at java.base/java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:2115)
at java.base/java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1646)
at java.base/java.io.ObjectInputStream.readObject(ObjectInputStream.java:464)
at java.base/java.io.ObjectInputStream.readObject(ObjectInputStream.java:422)
at com.simplicite.util.Tool.streamToObject(Tool.java:4955)
at com.simplicite.util.Tool.bytesToObject(Tool.java:4942)
at com.simplicite.util.engine.MemoryCache.cloneDefinition(MemoryCache.java:138)
at com.simplicite.util.engine.ObjectLoader.getClone(ObjectLoader.java:121)
at com.simplicite.util.engine.ObjectLoader.load(ObjectLoader.java:87)
at com.simplicite.util.ObjectDirect.init(ObjectDirect.java:41)
at com.simplicite.util.ObjectDB.init(ObjectDB.java:238)
at com.simplicite.util.ObjectDB.load(ObjectDB.java:216)
at com.simplicite.util.engine.CoreCache.instantiateObject(CoreCache.java:3631)
at com.simplicite.util.engine.CoreCache.getObject(CoreCache.java:3564)
at com.simplicite.util.engine.GrantManager.getObject(GrantManager.java:96)
at com.simplicite.util.GrantDirect.getObject(GrantDirect.java:578)
at com.simplicite.util.Grant.getObject(Grant.java:1886)
at com.simplicite.util.Grant.getTmpObject(Grant.java:1998)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:567)
at org.mozilla.javascript.MemberBox.invoke(MemberBox.java:138)
at org.mozilla.javascript.NativeJavaMethod.call(NativeJavaMethod.java:226)
at org.mozilla.javascript.Interpreter.interpretLoop(Interpreter.java:1670)
at org.mozilla.javascript.Interpreter.interpret(Interpreter.java:1010)
at org.mozilla.javascript.InterpretedFunction.exec(InterpretedFunction.java:124)
at org.mozilla.javascript.Context.evaluateReader(Context.java:1296)
at de.christophkraemer.rhino.javascript.RhinoScriptEngine.eval(RhinoScriptEngine.java:229)
at de.christophkraemer.rhino.javascript.RhinoScriptEngine.eval(RhinoScriptEngine.java:255)
at java.scripting/javax.script.AbstractScriptEngine.eval(AbstractScriptEngine.java:233)
at com.simplicite.util.ScriptedObjectDB.callFunction(ScriptedObjectDB.java:241)
at com.simplicite.util.ScriptedObjectDB.callFunction(ScriptedObjectDB.java:214)
at com.simplicite.util.ScriptedObjectDB.postSave(ScriptedObjectDB.java:630)
at com.simplicite.util.engine.ObjectManager.save(ObjectManager.java:2955)
D’après le stacktrace, visiblement on est dans le contexte d’un appel de classe Java depuis du script Rhino
@Francois, peut être un pb d’ “oeuf et de poule” entre Rhino et du Java ?
D’après les logs à 6h du matin il y a une tache qui travaille sur un objet en Rhino, qui invoque un objet Java dont la classe n’a pas été remise dans le class-loader (suite surement à un pb de clear-cache suite à upgrade de 2h). Les objets ne pouvant être instanciés ça génère des NPE.
Sur la question d’oeuf et de poule entre du code Rhino/Java, je ne vois pas pourquoi un clear-cache à 8h fonctionnerait mieux qu’un à 2h du matin. Les 2 cohabitent très bien, les problèmes seraient plus sur un objet à héritage qui mélangerait Rhino et Java, fortement déconseillé.
A titre préventif, il va falloir arrêter l’auto-upgrade de nuit le temps de trouver la cause de votre problème. Et tester le process d’auto-upgrade depuis une serveur de test/recette qu’on puisse analyser à chaud le comportement avec vos scripts SIM.
Et pour ne pas chercher des pb parasites au niveau applicatif, il faudrait aussi nous envoyer les logs d’une autre instance ou application pour comparer.
nous n’avons rien changé sur les serveurs. Nos 7 sim sont concernées.
Sur la question Rhino/java, j’ai comme un doute. L’application Gestion des ressources a ce pb alors que les scripts sont tous en rhino. je n’ai encore rien migré en java.
c’est l’upgrade de la nuit du 12 au 13 qui a généré ce pb.
je vous envoie les logs d’une autre appli par mail.
