Échec au chargement du modèle documentaire après mise à jour 4.0.4-final.202301161907-324

Bonjour à tous,
je viens de mettre à jour Opale avec la dernière version disponible via apt sous ubuntu mais l’atelier que j’ouvrais encore ce matin (et les autres) ne s’ouvre plus avec le message « Échec au chargement du modèle documentaire ». J’utilise le modèle Opale 4 FR avec le module linéaire Emeraude 4 FR.

Une idée svp ?

Arnaud

Bonjour,

Je n’arrive pas à reproduire votre problème, j’ai téléchargé Opale 4.0.3 (en Appimage) puis j’ai ouvert un atelier, et téléchargé le contenu d’exemple. J’ai ensuite installé Opale 4.0.4 avec apt qui a pu ouvrir l’atelier 4.0.3 sans problèmes.

Si vous démarrez Opale en ligne de commande (opale4) vous devez voir les logs de la partie Java de l’application, vous devez avoir quelque-chose comme ceci :

$ opale4
2023-01-17 17:35:22.691:INFO::main: Logging initialized @148ms to eu.scenari.jetty.util.log.StdErrLog
[124266:0117/173522.890035:ERROR:sandbox_linux.cc(374)] InitializeSandbox() called with multiple threads in process gpu-process.
2023-01-17 17:35:22.943:INFO:esjs.Server:main: jetty-9.4.z-SNAPSHOT; built: unknown; git: unknown; jvm 11.0.17+8-post-Ubuntu-1ubuntu220.04
2023-01-17 17:35:23.064:INFO:esjw.StandardDescriptorProcessor:main: NO JSP Support for /, did not find eu.scenari.jetty.jsp.JettyJspServlet
2023-01-17 17:35:23.081:INFO:esjs.session:main: DefaultSessionIdManager workerName=node0
2023-01-17 17:35:23.081:INFO:esjs.session:main: No SessionScavenger set, using defaults
2023-01-17 17:35:23.083:INFO:esjs.session:main: node0 Scavenging every 660000ms
(node:124215) electron: The default of nativeWindowOpen is deprecated and will be changing from false to true in Electron 15.  See https://github.com/electron/electron/issues/28511 for more information.
(Use `opale4 --trace-warnings ...` to show where the warning was created)
1--- Info : Tue Jan 17 17:35:23 CET 2023[202] (main) ---
================================================================================
Starting Serveur local 4 : Local server 4.0.4 202301161907 on OpenJDK 64-Bit Server VM 11.0.17+8-post-Ubuntu-1ubuntu220.04 / Linux amd64


1--- Info : Tue Jan 17 17:35:23 CET 2023[217] (main) ---
OpenDocument editor found by env. var. 'PATH' in: /usr/lib/libreoffice/program


2023-01-17 17:35:23.495:INFO:esjsh.ContextHandler:main: Started e.s.j.w.WebAppContext@32c8e539{/,file:///opt/Opale%204/resources/app/srv/,AVAILABLE}{/opt/Opale 4/resources/app/srv}
2023-01-17 17:35:23.507:INFO:esjs.AbstractConnector:main: Started ServerConnector@a7e666{HTTP/1.1,[http/1.1]}{127.0.0.1:8200}
2023-01-17 17:35:23.509:INFO:esjs.Server:main: Started @974ms

Vous avez quoi ?

Bonjour,
voici ci-dessous l’exception qui s’affiche au démarrage. C’est peut-être lié à ma version de java ? Ce qui est étrange c’est qu’elle n’a pas changé entre la version précédente d’Opale et l’actuelle à ma connaissance, or je démarrais Opale sans problème le matin même.
J’utilise la version installée par APT du dépot https://deb.scenari.software stable InRelease
L’atelier cité est propre car j’arrive à l’ouvrir via Scenari+wspack Opale.

2023-01-19 07:32:57.743:INFO::main: Logging initialized @311ms to eu.scenari.jetty.util.log.StdErrLog
libva error: vaGetDriverNameByIndex() failed with unknown libva error, driver_name = (null)
[231175:0119/073257.991929:ERROR:sandbox_linux.cc(374)] InitializeSandbox() called with multiple threads in process gpu-process.
2023-01-19 07:32:58.225:INFO:esjs.Server:main: jetty-9.4.z-SNAPSHOT; built: unknown; git: unknown; jvm 11.0.17+8-post-Ubuntu-1ubuntu222.04
2023-01-19 07:32:58.417:INFO:esjw.StandardDescriptorProcessor:main: NO JSP Support for /, did not find eu.scenari.jetty.jsp.JettyJspServlet
2023-01-19 07:32:58.449:INFO:esjs.session:main: DefaultSessionIdManager workerName=node0
2023-01-19 07:32:58.449:INFO:esjs.session:main: No SessionScavenger set, using defaults
2023-01-19 07:32:58.455:INFO:esjs.session:main: node0 Scavenging every 660000ms
(node:231123) electron: The default of nativeWindowOpen is deprecated and will be changing from false to true in Electron 15. See Make nativeWindowOpen: true the default · Issue #28511 · electron/electron · GitHub for more information.
(Use opale4 --trace-warnings ... to show where the warning was created)
1— Info : Thu Jan 19 07:32:58 CET 2023[753] (main) —
================================================================================
Starting Serveur local 4 : Local server 4.0.4 202301161907 on OpenJDK 64-Bit Server VM 11.0.17+8-post-Ubuntu-1ubuntu222.04 / Linux amd64

1— Info : Thu Jan 19 07:32:58 CET 2023[785] (main) —
OpenDocument editor found by env. var. ‹ PATH › in: /usr/lib/libreoffice/program

2023-01-19 07:32:59.578:INFO:esjsh.ContextHandler:main: Started e.s.j.w.WebAppContext@3a3e4aff{/,file:///opt/Opale%204/resources/app/srv/,AVAILABLE}{/opt/Opale 4/resources/app/srv}
*2023-01-19 07:32:59.601:WARN:esjx.XmlConfiguration:main: *
java.security.PrivilegedActionException: java.io.IOException: Failed to bind to /127.0.0.1:8200

  • at java.base/java.security.AccessController.doPrivileged(Native Method)*
  • at eu.scenari.jetty.xml.XmlConfiguration.main(XmlConfiguration.java:1773)*
    *Caused by: *
    java.io.IOException: Failed to bind to /127.0.0.1:8200
  • at eu.scenari.jetty.server.ServerConnector.openAcceptChannel(ServerConnector.java:346)*
  • at eu.scenari.jetty.server.ServerConnector.open(ServerConnector.java:307)*
  • at eu.scenari.jetty.server.AbstractNetworkConnector.doStart(AbstractNetworkConnector.java:80)*
  • at eu.scenari.jetty.server.ServerConnector.doStart(ServerConnector.java:231)*
  • at eu.scenari.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:72)*
  • at eu.scenari.jetty.server.Server.doStart(Server.java:385)*
  • at eu.scenari.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:72)*
  • at eu.scenari.jetty.xml.XmlConfiguration.lambda$main$0(XmlConfiguration.java:1824)*
  • at java.base/java.security.AccessController.doPrivileged(Native Method)*
  • at eu.scenari.jetty.xml.XmlConfiguration.main(XmlConfiguration.java:1773)*
    *Caused by: *
    java.net.BindException: Adresse déjà utilisée
  • at java.base/sun.nio.ch.Net.bind0(Native Method)*
  • at java.base/sun.nio.ch.Net.bind(Net.java:459)*
  • at java.base/sun.nio.ch.Net.bind(Net.java:448)*
  • at java.base/sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:227)*
  • at java.base/sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:80)*
  • at eu.scenari.jetty.server.ServerConnector.openAcceptChannel(ServerConnector.java:342)*
  • at eu.scenari.jetty.server.ServerConnector.open(ServerConnector.java:307)*
  • at eu.scenari.jetty.server.AbstractNetworkConnector.doStart(AbstractNetworkConnector.java:80)*
  • at eu.scenari.jetty.server.ServerConnector.doStart(ServerConnector.java:231)*
  • at eu.scenari.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:72)*
  • at eu.scenari.jetty.server.Server.doStart(Server.java:385)*
  • at eu.scenari.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:72)*
  • at eu.scenari.jetty.xml.XmlConfiguration.lambda$main$0(XmlConfiguration.java:1824)*
  • at java.base/java.security.AccessController.doPrivileged(Native Method)*
  • at eu.scenari.jetty.xml.XmlConfiguration.main(XmlConfiguration.java:1773)*
    Exception in thread « main » java.security.PrivilegedActionException: java.io.IOException: Failed to bind to /127.0.0.1:8200
  • at java.base/java.security.AccessController.doPrivileged(Native Method)*
  • at eu.scenari.jetty.xml.XmlConfiguration.main(XmlConfiguration.java:1773)*
    Caused by: java.io.IOException: Failed to bind to /127.0.0.1:8200
  • at eu.scenari.jetty.server.ServerConnector.openAcceptChannel(ServerConnector.java:346)*
  • at eu.scenari.jetty.server.ServerConnector.open(ServerConnector.java:307)*
  • at eu.scenari.jetty.server.AbstractNetworkConnector.doStart(AbstractNetworkConnector.java:80)*
  • at eu.scenari.jetty.server.ServerConnector.doStart(ServerConnector.java:231)*
  • at eu.scenari.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:72)*
  • at eu.scenari.jetty.server.Server.doStart(Server.java:385)*
  • at eu.scenari.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:72)*
  • at eu.scenari.jetty.xml.XmlConfiguration.lambda$main$0(XmlConfiguration.java:1824)*
  • … 2 more*
    Caused by: java.net.BindException: Adresse déjà utilisée
  • at java.base/sun.nio.ch.Net.bind0(Native Method)*
  • at java.base/sun.nio.ch.Net.bind(Net.java:459)*
  • at java.base/sun.nio.ch.Net.bind(Net.java:448)*
  • at java.base/sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:227)*
  • at java.base/sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:80)*
  • at eu.scenari.jetty.server.ServerConnector.openAcceptChannel(ServerConnector.java:342)*
  • … 9 more*
    opale4

Le problème est que Opale n’arrive pas à démarré sa couche Java car le port demandé (8200) est déjà ouvert par un autre processus. La question maintenant est : lequel ?
C’est peut-être un autre programme mais ça peut aussi être une ancienne instance de Opale dont le processus Java est planté et ne s’est pas auto-tué.
Sans avoir Opale démarré pouvez-vous lancer la commande ps -ef | grep 8200 :

$ ps -ef | grep 8200
sam       335968  335950 12 09:17 pts/0    00:00:16 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -classpath /opt/Opale 4/resources/app/srvLibs/* -Dscenari.app.port=8200 -Dscenari.app.wa.dir=/opt/Opale 4/resources/app/srv -Dscenari.app.data.dir=/home/sam/Documents/Opale 4 -Dscenari.app.repo.gens.dir=/home/sam/Documents/Opale 4/~gens -Dscenari.app.addons.dir=/home/sam/.config/opale4/srv/emdFix/add -Dscenari.app.logs.dir=/home/sam/.config/opale4/srv/emdFix/logs -Dscenari.app.temp.dir=/tmp/opale4 -Djava.net.useSystemProxies=true -Dscenari.tools.imagemagick.path= -Dscenari.tools.ffmpeg.path=ffmpeg -Dpostscriptum.path=/opt/Opale 4/opale4 eu.scenari.jetty.xml.XmlConfiguration /opt/Opale 4/resources/app/srvInit.xml
sam       337223  336170  0 09:19 pts/3    00:00:00 grep --color=auto 8200

Dans mon exemple si-dessus on voit bien le processus Java d’Opale démarré avec le port 8200 (-Dscenari.app.port=8200).

  • Si vous avez la même chose que ci-dessus veuillez simplement tuer le processus en question (dans mon exemple kill -9 335968)
  • Si vous arrivez à identifier un autre processus qui utilise le port 8200 vous pouvez paramétrer Opale pour utiliser un autre port : dans le menu de l’application (image) :
    image

Dans tout les cas nous sommes intéressés de savoir lequel des deux hypothèses est la bonne.

Effectivement, il restait un zombie d’Opale:

aleleve 29794 22029 0 janv.17 ? 00:02:45 /usr/lib/jvm/java-11-openjdk-amd64/bin/java -classpath /opt/Opale 4/resources/app/srvLibs/* -Dscenari.app.port=8200 -Dscenari.app.wa.dir=/opt/Opale 4/resources/app/srv -Dscenari.app.data.dir=/home/aleleve/Documents/Opale 4 -Dscenari.app.repo.gens.dir=/home/aleleve/Documents/Opale 4/~gens -Dscenari.app.addons.dir=/home/aleleve/.config/opale4/srv/emdFix/add -Dscenari.app.logs.dir=/home/aleleve/.config/opale4/srv/emdFix/logs -Dscenari.app.temp.dir=/tmp/opale4 -Djava.net.useSystemProxies=true -Dscenari.tools.imagemagick.path= -Dscenari.tools.ffmpeg.path=ffmpeg -Dpostscriptum.path=/opt/Opale 4/opale4 eu.scenari.jetty.xml.XmlConfiguration /opt/Opale 4/resources/app/srvInit.xml
aleleve 249887 233395 0 13:17 pts/4 00:00:00 grep --color=auto 8200

Après l’avoir tué, j’ai pu lancer opale4 sans soucis.
Scenari+wspack opale n’utilise pas le même port ?

Merci pour votre aide.
Bonne journée

Chaque application utilise un port différent par défaut. Vous pouvez le voir dans les paramètres.
Par-contre lors de la MAJ de Opale en deb aviez-vous l’application ouvert en même temps ?

Non. J’ai installé scenari+app opale après coup pour pouvoir utiliser mes ressources pédagogiques.

Je ne parle pas de SCENARI +wsppack Opale. Je parle la MAJ de l’application Opale au départ : quand apt à fait la MAJ, l’application était-elle lancée ?

Aucune idée. 50% de (mal)chances que oui.