Upgrade instance BCSI interne (Intranet Renault) 4.0-latest -> 5-latest KO

,

Bonjour,
l’upgrade de l’instance BCSI interne (dev) plante au démarrage (a priori dès le début donc les actions d’upgrade en BD ne sont pas engagées).
Voici la log:


Time	message
	Oct 13, 2021 @ 11:31:50.059	2021-10-13 11:31:49,329|CATALINA|INFO|Server startup in [19888] milliseconds
	Oct 13, 2021 @ 11:31:50.048	2021-10-13 11:31:49,326|CATALINA|INFO|Starting ProtocolHandler ["https-jsse-nio-8444"]
	Oct 13, 2021 @ 11:31:50.021	2021-10-13 11:31:49,325|CATALINA|INFO|Starting ProtocolHandler ["ajp-nio-0.0.0.0-8009"]
	Oct 13, 2021 @ 11:31:49.995	2021-10-13 11:31:49,324|CATALINA|INFO|Starting ProtocolHandler ["http-nio-8443"]
	Oct 13, 2021 @ 11:31:49.985	2021-10-13 11:31:49,299|CATALINA|INFO|Starting ProtocolHandler ["http-nio-8080"]
	Oct 13, 2021 @ 11:31:49.973	2021-10-13 11:31:49,287|CATALINA|INFO|Deployment of web application directory [/usr/local/tomcat/webapps/ROOT] has finished in [19,755] ms
	Oct 13, 2021 @ 11:31:49.952	e[m2021-10-13 11:31:49,243|GLOBAL|INFO|SIMPLICITE: Platform on endpoint [http://2f3e813fa156:8080] stopped
	Oct 13, 2021 @ 11:31:49.931	e[me[32m2021-10-13 11:31:49,242|SIMPLICITE|INFO|Platform on endpoint [http://2f3e813fa156:8080] stopped
	Oct 13, 2021 @ 11:31:49.914	e[me[32m2021-10-13 11:31:49,146|SIMPLICITE|INFO||http://2f3e813fa156:8080||INFO|system|com.simplicite.util.engine.DynamicClassLoader|DynamicClassLoader||Instanciate DynamicClassLoader@582a6d04
	Oct 13, 2021 @ 11:31:49.901	e[33m2021-10-13 11:31:49,112|SIMPLICITE|WARN|User 'system' has not been created
	Oct 13, 2021 @ 11:31:49.877	e[m2021-10-13 11:31:49,053|GLOBAL|INFO|SIMPLICITE: Platform on endpoint [http://2f3e813fa156:8080] has (re)started
	Oct 13, 2021 @ 11:31:49.864	e[me[32m2021-10-13 11:31:49,053|SIMPLICITE|INFO|Platform on endpoint [http://2f3e813fa156:8080] has (re)started
	Oct 13, 2021 @ 11:31:49.852		at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:476)
...
	Oct 13, 2021 @ 11:31:49.746		at com.simplicite.util.engine.CoreCache.loadViews(CoreCache.java:2203)
	Oct 13, 2021 @ 11:31:49.745	e[me[31m2021-10-13 11:31:49,050|SIMPLICITE|ERROR||http://2f3e813fa156: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
	Oct 13, 2021 @ 11:31:49.745	java.lang.NullPointerException: Cannot invoke "com.simplicite.util.View.addGroup(String)" because the return value of "java.util.Map.get(Object)" is null
	Oct 13, 2021 @ 11:31:45.750	e[me[32m2021-10-13 11:31:45,205|SIMPLICITE|INFO||http://2f3e813fa156:8080||INFO|system|com.simplicite.util.engine.CoreCache|initProcessCache||PROCESS_CACHE_SIZE=10000
	Oct 13, 2021 @ 11:31:45.749	e[me[32m2021-10-13 11:31:45,198|SIMPLICITE|INFO||http://2f3e813fa156:8080||INFO|system|com.simplicite.util.engine.CoreCache|initObjectCache||OBJECT_CACHE_SIZE=10000
	Oct 13, 2021 @ 11:31:45.749	e[32m2021-10-13 11:31:45,094|SIMPLICITE|INFO|Project dir: /usr/local/tomcat/webapps/ROOT/WEB-INF
	Oct 13, 2021 @ 11:31:45.749	e[m2021-10-13 11:31:45,082|GLOBAL|INFO|SIMPLICITE: Platform on endpoint [http://2f3e813fa156:8080] is (re)starting...
	Oct 13, 2021 @ 11:31:45.748	2021-10-13 11:31:44,955|CATALINA|SEVERE|Context [] startup failed due to previous errors
	Oct 13, 2021 @ 11:31:45.748	e[me[32m2021-10-13 11:31:45,025|SIMPLICITE|INFO|Platform on endpoint [http://2f3e813fa156:8080] is stopping...
	Oct 13, 2021 @ 11:31:45.748	e[me[32m2021-10-13 11:31:45,082|SIMPLICITE|INFO|Platform on endpoint [http://2f3e813fa156:8080] is (re)starting...
	Oct 13, 2021 @ 11:31:45.748	e[31m2021-10-13 11:31:45,025|SIMPLICITE|ERROR|Unable to unregister the platform management bean
	Oct 13, 2021 @ 11:31:45.747	2021-10-13 11:31:44,949|CATALINA|SEVERE|One or more listeners failed to start. Full details will be found in the appropriate container log file
	Oct 13, 2021 @ 11:31:45.747	2021-10-13 11:31:44,944|GLOBAL|SEVERE|Exception sending context initialized event to listener instance of class [com.simplicite.webapp.listeners.ApplicationListener]
	Oct 13, 2021 @ 11:31:45.746	e[m2021-10-13 11:31:44,943|GLOBAL|SEVERE|SIMPLICITE: The database version (4.25) is more recent than the platform version (5.1)
	Oct 13, 2021 @ 11:31:45.746	e[me[32m2021-10-13 11:31:44,937|SIMPLICITE|INFO|Current database version = 4, patch level = 25, patch level files MD5 hash = 7df1743d94f2866e8c3f7fc8b7e2a828
	Oct 13, 2021 @ 11:31:45.746	e[me[35m2021-10-13 11:31:44,943|SIMPLICITE|FATAL|The database version (4.25) is more recent than the platform version (5.1)
	Oct 13, 2021 @ 11:31:45.745	e[m2021-10-13 11:31:44,902|GLOBAL|INFO|SIMPLICITE: Database is ready
	Oct 13, 2021 @ 11:31:45.745	e[me[32m2021-10-13 11:31:44,902|SIMPLICITE|INFO|Database is ready
	Oct 13, 2021 @ 11:31:45.745	e[32m2021-10-13 11:31:44,936|SIMPLICITE|INFO|Platform version = 5, patch level = 1, patch level files MD5 hash = 4f256b3538a3883dc4cbd2cf292c5279
	Oct 13, 2021 @ 11:31:45.744	e[me[32m2021-10-13 11:31:44,778|SIMPLICITE|INFO|Initializing datasource jdbc/simplicite with database product name = [mysql]
	Oct 13, 2021 @ 11:31:44.748	e[32m2021-10-13 11:31:44,142|SIMPLICITE|INFO|Autoupgrade lock
	Oct 13, 2021 @ 11:31:44.747	e[me[32m2021-10-13 11:31:44,141|SIMPLICITE|INFO|Data directory is ready
	Oct 13, 2021 @ 11:31:44.747	e[m2021-10-13 11:31:44,141|GLOBAL|INFO|SIMPLICITE: Data directory is ready
	Oct 13, 2021 @ 11:31:44.746	e[me[32m2021-10-13 11:31:44,141|SIMPLICITE|INFO|Endpoint: IP=21.0.9.3, URL=http://2f3e813fa156:8080
	Oct 13, 2021 @ 11:31:44.746	e[me[32m2021-10-13 11:31:44,141|SIMPLICITE|INFO|Base data directory from webapp environment [/usr/local/tomcat/webapps/ROOT/WEB-INF]
	Oct 13, 2021 @ 11:31:44.746	e[me[32m2021-10-13 11:31:44,141|SIMPLICITE|INFO|Data directory: /usr/local/tomcat/webapps/ROOT/WEB-INF
	Oct 13, 2021 @ 11:31:44.745	e[m2021-10-13 11:31:43,960|GLOBAL|SEVERE|SIMPLICITE: Checksum verification failed on [libs] directory ([0cf0b127d38c72dd3249b273f7c0ae68] vs [954ebf5790b06b098aedf2d60cf3682f]), some core system files have been altered or files have been removed or added. This may have unpredictable effects!
	Oct 13, 2021 @ 11:31:44.745	e[32m2021-10-13 11:31:44,131|SIMPLICITE|INFO|Checksum verification: failed
	Oct 13, 2021 @ 11:31:44.744	e[me[31m2021-10-13 11:31:43,960|SIMPLICITE|ERROR|Checksum verification failed on [libs] directory ([0cf0b127d38c72dd3249b273f7c0ae68] vs [954ebf5790b06b098aedf2d60cf3682f]), some core system files have been altered or files have been removed or added. This may have unpredictable effects!
	Oct 13, 2021 @ 11:31:43.748	e[me[32m2021-10-13 11:31:43,260|SIMPLICITE|INFO|Using Java version: 17
	Oct 13, 2021 @ 11:31:43.748	e[me[32m2021-10-13 11:31:43,260|SIMPLICITE|INFO|Using Git base dir: /usr/local/tomcat/webapps/ROOT/WEB-INF/git
	Oct 13, 2021 @ 11:31:43.747	e[me[32m2021-10-13 11:31:43,256|SIMPLICITE|INFO|Platform: Simplicite 5.P01 2021-10-12 18:34 (revision 7) / UTF-8
	Oct 13, 2021 @ 11:31:43.747	e[32m2021-10-13 11:31:43,238|SIMPLICITE|INFO|Application name:
	Oct 13, 2021 @ 11:31:43.747	e[me[32m2021-10-13 11:31:43,245|SIMPLICITE|INFO|Server: tomcat 9 (WEB), websockets: false
	Oct 13, 2021 @ 11:31:43.746	e[me[32m2021-10-13 11:31:43,232|SIMPLICITE|INFO|Webapp for context path [] is initializing...
	Oct 13, 2021 @ 11:31:43.746	e[m2021-10-13 11:31:43,233|GLOBAL|INFO|SIMPLICITE: Webapp for context path [] is initializing...
	Oct 13, 2021 @ 11:31:43.746	            |_|
	Oct 13, 2021 @ 11:31:43.745	\__ \ | '  \| '_ \ | / _| |  _/ -_)
	Oct 13, 2021 @ 11:31:43.745	/ __(_)_ __  _ __| (_)__(_) |_ /_/
	Oct 13, 2021 @ 11:31:43.745	|___/_|_|_|_| .__/_|_\__|_|\__\___|
	Oct 13, 2021 @ 11:31:43.744	 ___ _            _ _    _ _    __
	Oct 13, 2021 @ 11:31:43.744	e[32m2021-10-13 11:31:43,223|SIMPLICITE|INFO|
	Oct 13, 2021 @ 11:31:42.744	2021-10-13 11:31:42,390|GLOBAL|INFO|At least one JAR was scanned for TLDs yet contained no TLDs. Enable debug logging for this logger for a complete list of JARs that were scanned but no TLDs were found in them. Skipping unneeded JARs during scanning can improve startup time and JSP compilation time.
	Oct 13, 2021 @ 11:31:29.744	2021-10-13 11:31:29,529|CATALINA|INFO|Deploying web application directory [/usr/local/tomcat/webapps/ROOT]
	Oct 13, 2021 @ 11:31:29.744	2021-10-13 11:31:29,513|CATALINA|INFO|Starting Servlet engine: [Apache Tomcat/9.0.54]
	Oct 13, 2021 @ 11:31:29.743	2021-10-13 11:31:29,435|CATALINA|INFO|Server initialization in [2020] milliseconds
	Oct 13, 2021 @ 11:31:29.743	2021-10-13 11:31:29,512|CATALINA|INFO|Starting service [Catalina]
	Oct 13, 2021 @ 11:31:29.743	2021-10-13 11:31:28,915|CATALINA|INFO|The ["https-jsse-nio-8444"] connector has been configured to support negotiation to [h2] via ALPN
	Oct 13, 2021 @ 11:31:29.743	2021-10-13 11:31:28,916|CATALINA|INFO|Initializing ProtocolHandler ["https-jsse-nio-8444"]
	Oct 13, 2021 @ 11:31:29.742	2021-10-13 11:31:28,896|CATALINA|INFO|Initializing ProtocolHandler ["ajp-nio-0.0.0.0-8009"]
	Oct 13, 2021 @ 11:31:29.742	2021-10-13 11:31:28,854|CATALINA|INFO|Initializing ProtocolHandler ["http-nio-8080"]
	Oct 13, 2021 @ 11:31:29.742	2021-10-13 11:31:28,894|CATALINA|INFO|The ["http-nio-8443"] connector has been configured to support HTTP upgrade to [h2c]
	Oct 13, 2021 @ 11:31:29.742	2021-10-13 11:31:28,895|CATALINA|INFO|Initializing ProtocolHandler ["http-nio-8443"]
	Oct 13, 2021 @ 11:31:29.741	2021-10-13 11:31:28,853|CATALINA|INFO|The ["http-nio-8080"] connector has been configured to support HTTP upgrade to [h2c]
	Oct 13, 2021 @ 11:31:28.746	2021-10-13 11:31:27,893|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]
	Oct 13, 2021 @ 11:31:28.745	2021-10-13 11:31:27,891|CATALINA|INFO|CATALINA_HOME:         /usr/local/tomcat
	Oct 13, 2021 @ 11:31:28.745	2021-10-13 11:31:27,890|CATALINA|INFO|CATALINA_BASE:         /usr/local/tomcat
	Oct 13, 2021 @ 11:31:28.745	2021-10-13 11:31:27,890|CATALINA|INFO|JVM Vendor:            Eclipse Adoptium
	Oct 13, 2021 @ 11:31:28.744	2021-10-13 11:31:27,889|CATALINA|INFO|Architecture:          amd64
	Oct 13, 2021 @ 11:31:28.744	2021-10-13 11:31:27,889|CATALINA|INFO|JVM Version:           17+35
	Oct 13, 2021 @ 11:31:28.744	2021-10-13 11:31:27,889|CATALINA|INFO|Java Home:             /usr/local/jdk
	Oct 13, 2021 @ 11:31:28.744	2021-10-13 11:31:27,888|CATALINA|INFO|OS Version:            3.10.0-1160.42.2.el7.x86_64
	Oct 13, 2021 @ 11:31:28.743	2021-10-13 11:31:27,888|CATALINA|INFO|OS Name:               Linux
	Oct 13, 2021 @ 11:31:28.743	2021-10-13 11:31:27,887|CATALINA|INFO|Server built:          Sep 28 2021 13:51:49 UTC
	Oct 13, 2021 @ 11:31:28.743	2021-10-13 11:31:27,887|CATALINA|INFO|Server version number: 9.0.54.0
	Oct 13, 2021 @ 11:31:28.742	2021-10-13 11:31:27,791|CATALINA|WARNING|Match [Server/Service/Connector] failed to set property [maxHttpHeaderSize] to [16384]
	Oct 13, 2021 @ 11:31:28.742	2021-10-13 11:31:27,886|CATALINA|INFO|Server version name:   Apache Tomcat/9.0.54
	Oct 13, 2021 @ 11:31:25.741	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
	Oct 13, 2021 @ 11:31:25.737	Tomcat started.
	Oct 13, 2021 @ 11:31:25.668	MySQL database: s2946ads.mc2.renault.fr / 11043 / bca_db_01 / bca_adm
	Oct 13, 2021 @ 11:31:25.664	Database vendor: mysql
	Oct 13, 2021 @ 11:31:25.661	Cleaning work files/dirs... Done
	Oct 13, 2021 @ 11:31:25.623	Tomcat root: /usr/local/tomcat
	Oct 13, 2021 @ 11:31:25.623	Tomcat webapp: ROOT
	Oct 13, 2021 @ 11:31:25.602	             |_| Running on centos7
	Oct 13, 2021 @ 11:31:25.602	 |___/_|_|_|_| .__/_|_\__|_|\__\___(_)_\___/
	Oct 13, 2021 @ 11:31:25.601	 \__ \ | '  \| '_ \ | / _| |  _/ -_)_| / _ \
	Oct 13, 2021 @ 11:31:25.601	 / __(_)_ __  _ __| (_)__(_) |_ /_/  (_)___
	Oct 13, 2021 @ 11:31:25.600	  ___ _            _ _    _ _    __   _

C’est le pb => je ne sais pas pourquoi mais le check de version qu’on a ajouté pour ne plus autoriser les downgrades “sauvages” ne marche visiblement pas dans ce cas. On va regarder.

En attendant il est temporairement possible de bypasser ce check (quand on sait ce qu’on fait car un downgrade reste une source inépuisables de pbs inexplicables, d’où l’ajout légitime de ce check) en passant la property JVM platform.ignorecheckolder=true

Ok merci c’est en cours…

C’est reparti :slight_smile: voici quelques warnings récoltés dans les logs:

Oct 13, 2021 @ 12:26:07.194	e[me[33m2021-10-13 12:26:06,382|SIMPLICITE|WARN|Database patch SQL request = delete from m_grant g where not exists (select 1 from m_function f where g.grt_function_id = f.row_id) / warning = You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'g where not exists (select 1 from m_function f where g.grt_function_id = f.row_i' at line 1
...
Oct 13, 2021 @ 12:26:07.193	e[me[33m2021-10-13 12:26:06,358|SIMPLICITE|WARN|Database patch SQL request = ALTER TABLE web_news ALTER COLUMN web_lang varchar(3) NOT NULL / warning = You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'varchar(3) NOT NULL' at line 1

ps: j’éditerai de post pour ajouter les autres le cas échéant

OK il doit y avoir un pb de syntaxe MySQL sur cet alter (alter column vs modify), c’est quoi votre version de MySQL ?

On est en MySQL 5.6.

Ce sont les seuls warnings de “syntaxe” ?

NB: Les warnings qui râlent sur des add/drop column/indexes déjà faits ne sont pas graves

Ce sont les seuls que j’ai repéré [EDIT] (j’ai gardé pour moi les erreurs de compil de nos propres codes :hugs:)

OK je vais faire des tests avec cette version de MySQL.

A priori dans ce cas précis, ce n’est pas grave car il s’agit d’un warning sur les patches 5.0 or cette commande existe aussi et est écrite différemment dans les patches 5.1

Bon, tout semble OK.

à nouveau, merci beaucoup pour ton support efficace.

Les seules réserves sont:

  • les deux warnings partagés
  • le fait de devoir ajouter platform.ignorecheckolder=true dans les properties de la JVM (fait dans notre stack mais a retirer dès que c’est corrigé)
  • l’instance bcsi.simplicite.io à réparer (restore backup < hier midi + upgrade ou reset complet)

Si nous tenons notre planning, la BCSI sera 5-latest en production S47 (recettes métiers en cours avec nos 4 Products Owners principaux)

Bon tant mieux,

On va regarder ce pb de check de version, lors de nos tests ça marchait, il doit y avoir une subtilité.
Idem pour les pbs SQL avec MySQL 5.x

Le pb du check de version est résolu.

Les pbs de SQL MySQL aussi:

  • celui sur le alter était effectivement une grossière erreur de syntaxe (MySQL ne reconnait pas le ALTER COLUMN standard mais utilise une syntaxe propriétaire MODIFY => celui-ci nous avait échappé)
  • celui sur le delete était plus subtil car ça marchait bien sur MySQL 8 et MySQL 5.7 mais effectivement pas sur MySQL 5.6 (cette version ne supportait visiblement pas les alias de table dans ce genre de cas)

Ce sera livré dans le 5.1.8 qui sera buildée ce soir ou demain

1 Like