0

Experts,      Our Mendix app was recently upgraded from Studio pro 8.18 to 9.6.1. Since then, we are not able to deploy the latest app changes to Mindsphere. The “cf push -p <appname>” command initially indicates that the app is deployed successfully and trying to start. However, in a few secs the app status says “Crashed”. Upon running the “cf logs <app name>” command, it showed the  below errors. Appreciate if someone can suggest on how to get past this issue.   Retrieving logs for app coldbrewcoffeeplant in org presdev / space AM_Presales as kalyan.guda@siemens.com...    2021-12-08T11:37:22.53-0500 [CELL/0] OUT Downloaded droplet (387.1M)    2021-12-08T11:37:22.53-0500 [CELL/0] OUT Starting health monitoring of container    2021-12-08T11:37:23.13-0500 [APP/PROC/WEB/0] OUT INFO: Mendix Cloud Foundry Buildpack v4.16.1 [5e9443e] starting...    2021-12-08T11:37:23.14-0500 [APP/PROC/WEB/0] OUT INFO: Fixing up permissions of directory 'model' with mode 700    2021-12-08T11:37:23.14-0500 [APP/PROC/WEB/0] OUT INFO: Fixing up permissions of directory 'data' with mode 700    2021-12-08T11:37:23.14-0500 [APP/PROC/WEB/0] OUT WARNING: External file store not configured, uploaded files in the app will not persist across restarts. See https://github.com/mendix/cf-mendix-buildpack for file store configuration details.    2021-12-08T11:37:23.25-0500 [APP/PROC/WEB/0] OUT INFO: Using Java version:    2021-12-08T11:37:23.25-0500 [APP/PROC/WEB/0] OUT INFO: openjdk version "11.0.10" 2021-01-19    2021-12-08T11:37:23.25-0500 [APP/PROC/WEB/0] OUT INFO: OpenJDK Runtime Environment AdoptOpenJDK (build 11.0.10+9)    2021-12-08T11:37:23.25-0500 [APP/PROC/WEB/0] OUT INFO: OpenJDK 64-Bit Server VM AdoptOpenJDK (build 11.0.10+9, mixed mode)    2021-12-08T11:37:23.25-0500 [APP/PROC/WEB/0] OUT INFO: The buildpack is starting the runtime...    2021-12-08T11:37:23.25-0500 [APP/PROC/WEB/0] OUT INFO: Trying to start the MxRuntime...    2021-12-08T11:37:26.95-0500 [APP/PROC/WEB/0] ERR Dec 08, 2021 4:37:26 PM java.util.prefs.FileSystemPreferences$6 run    2021-12-08T11:37:26.95-0500 [APP/PROC/WEB/0] ERR WARNING: Prefs file removed in background /home/vcap/.java/.userPrefs/com/mendix/core/prefs.xml    2021-12-08T11:37:27.41-0500 [APP/PROC/WEB/0] OUT WARNING - Core: The runtime has been started using a trial license, the framework will be terminated when the maximum time is exceeded!    2021-12-08T11:37:27.41-0500 [APP/PROC/WEB/0] OUT INFO - M2EE: Added admin request handler '/prometheus' with servlet class 'com.mendix.metrics.prometheus.PrometheusServlet'    2021-12-08T11:37:27.41-0500 [APP/PROC/WEB/0] OUT INFO - Logging: Logging to file: /home/vcap/app/log/out.log, max size: 1099511627776KiB, max rotation: 10    2021-12-08T11:37:27.42-0500 [APP/PROC/WEB/0] OUT INFO - M2EE: Initializing runtime...    2021-12-08T11:37:27.43-0500 [APP/PROC/WEB/0] OUT INFO - Core: Mendix Runtime 9.6.3.32292 (build 32292). Copyright © 2003-2021 Mendix bv. All rights reserved.    2021-12-08T11:37:27.44-0500 [APP/PROC/WEB/0] OUT INFO - M2EE: Initialized runtime.    2021-12-08T11:37:27.44-0500 [APP/PROC/WEB/0] OUT INFO - M2EE: Creating Runtime server...    2021-12-08T11:37:27.57-0500 [APP/PROC/WEB/0] OUT INFO - M2EE: Setting MaxFormContentSize for Runtime Server to 10485760    2021-12-08T11:37:27.57-0500 [APP/PROC/WEB/0] OUT INFO - M2EE: Runtime server started.    2021-12-08T11:37:27.57-0500 [APP/PROC/WEB/0] OUT INFO - Configuration: Updating configuration...    2021-12-08T11:37:28.15-0500 [APP/PROC/WEB/0] OUT INFO - Metrics: Started metrics on Micrometer    2021-12-08T11:37:28.23-0500 [APP/PROC/WEB/0] OUT INFO - Services: Adding 0 authority certificate(s)    2021-12-08T11:37:28.24-0500 [APP/PROC/WEB/0] OUT INFO - Configuration: Configuration updated.    2021-12-08T11:37:28.54-0500 [CELL/0] OUT Container became healthy    2021-12-08T11:37:29.05-0500 [APP/PROC/WEB/0] OUT INFO - Core: Initializing InternalCore and Modules...    2021-12-08T11:37:30.09-0500 [APP/PROC/WEB/0] OUT INFO - Core: Initialized InternalCore and Modules.    2021-12-08T11:37:30.09-0500 [APP/PROC/WEB/0] OUT INFO - Core: Initializing ConnectionBus...    2021-12-08T11:37:30.53-0500 [APP/PROC/WEB/0] OUT INFO - Core: Initialized ConnectionBus.    2021-12-08T11:37:30.56-0500 [APP/PROC/WEB/0] OUT INFO - ConnectionBus: Database product information: PostgreSQL 10.18    2021-12-08T11:37:30.56-0500 [APP/PROC/WEB/0] OUT INFO - ConnectionBus: Database engine version: 10.18    2021-12-08T11:37:30.72-0500 [APP/PROC/WEB/0] OUT INFO - ConnectionBus: Starting uniqueness constraint violation diagnostics...    2021-12-08T11:37:30.72-0500 [APP/PROC/WEB/0] OUT INFO - ConnectionBus: Uniqueness constraint violation diagnostics has been successfully finished. No violations are found.    2021-12-08T11:37:30.76-0500 [APP/PROC/WEB/0] ERR ERROR: Executing start did not succeed: result: 3, message: The database has to be updated. (301 database change queries needed)    2021-12-08T11:37:30.76-0500 [APP/PROC/WEB/0] OUT INFO - Core: Executing DDL commands...    2021-12-08T11:37:30.76-0500 [APP/PROC/WEB/0] OUT INFO - ConnectionBus: Executing 301 database synchronization command(s)...    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT ERROR - M2EE: An error occurred while executing action 'Execute DDL commands'.    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT ERROR - M2EE: com.mendix.m2ee.api.AdminException: Executing DDL commands failed.    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT     at com.mendix.basis.component.internal.LocalComponentImpl.executeDDLCommands(LocalComponentImpl.scala:120)    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT Caused by: com.mendix.basis.connectionbus.ConnectionBusException: Error (SQL State: 54011, Error Code: 0) on executing:    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT ALTER TABLE "system$image" ADD "submetaobjectname" varchar(255) NULL DEFAULT 'System.Image'    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT All changes are rolled back.    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT     at com.mendix.connectionbus.modelsynchronization.DdlCommandExecutor.handleCommandExecutionException(DdlCommandExecutor.scala:149)    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT Caused by: org.postgresql.util.PSQLException: ERROR: tables can have at most 1600 columns    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT     at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2552)    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT     at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2284)    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT     at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:322)    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT     at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:481)    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT     at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:401)    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT     at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:322)    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT     at org.postgresql.jdbc.PgStatement.executeCachedSql(PgStatement.java:308)    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT     at org.postgresql.jdbc.PgStatement.executeWithFlags(PgStatement.java:284)    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT     at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:279)    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT     at org.apache.commons.dbcp2.DelegatingStatement.execute(DelegatingStatement.java:193)    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] ERR ERROR: Executing execute_ddl_commands did not succeed: result: 1, message: Executing DDL commands failed., caused by: Error (SQL State: 54011, Error Code: 0) on executing:    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] ERR ALTER TABLE "system$image" ADD "submetaobjectname" varchar(255) NULL DEFAULT 'System.Image'    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] ERR All changes are rolled back.    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT     at org.apache.commons.dbcp2.DelegatingStatement.execute(DelegatingStatement.java:193)    2021-12-08T11:37:30.82-0500 [APP/PROC/WEB/0] OUT WARNING: Application start failed, stopping the Mendix Runtime...    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at com.mendix.connectionbus.modelsynchronization.DdlCommandExecutor.$anonfun$executeCommandWithConnection$2(DdlCommandExecutor.scala:97)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT INFO: Waiting for the application to shutdown...    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at com.mendix.connectionbus.modelsynchronization.DdlCommandExecutor.$anonfun$executeCommandWithConnection$2$adapted(DdlCommandExecutor.scala:96)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at scala.util.Using$.resource(Using.scala:261)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at com.mendix.connectionbus.modelsynchronization.DdlCommandExecutor.executeCommandWithConnection(DdlCommandExecutor.scala:96)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at com.mendix.connectionbus.modelsynchronization.DdlCommandExecutor.$anonfun$execute$4(DdlCommandExecutor.scala:49)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at com.mendix.connectionbus.modelsynchronization.DdlCommandExecutor.$anonfun$execute$4$adapted(DdlCommandExecutor.scala:27)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at scala.collection.IterableOnceOps.foreach(IterableOnce.scala:563)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at scala.collection.IterableOnceOps.foreach$(IterableOnce.scala:561)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at scala.collection.AbstractIterable.foreach(Iterable.scala:919)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at scala.collection.IterableOps$WithFilter.foreach(Iterable.scala:889)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at com.mendix.connectionbus.modelsynchronization.DdlCommandExecutor.execute(DdlCommandExecutor.scala:27)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at com.mendix.connectionbus.modelsynchronization.SynchronizationManager.synchronizeModel(SynchronizationManager.scala:200)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at com.mendix.connectionbus.modelsynchronization.SynchronizationManager.execute(SynchronizationManager.scala:137)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at com.mendix.connectionbus.ConnectionBusImpl.execute$1(ConnectionBusImpl.scala:248)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at com.mendix.connectionbus.ConnectionBusImpl.executeDDLCommands(ConnectionBusImpl.scala:269)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at com.mendix.basis.component.internal.LocalComponentImpl.executeDDLCommands(LocalComponentImpl.scala:112)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at com.mendix.basis.impl.MxRuntimeImplBase.executeDDLCommands(MxRuntimeImplBase.java:902)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at com.mendix.basis.action.admin.ExecuteDDLCommandsAction.execute(ExecuteDDLCommandsAction.scala:21)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at com.mendix.m2ee.appcontainer.server.handler.HttpAdminHandlerBase.service(HttpAdminHandlerBase.java:126)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1434)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1349)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.server.Server.handle(Server.java:516)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:386)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT     at java.base/java.lang.Thread.run(Unknown Source)    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT INFO - Core: Mendix Runtime is shutting down now...    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT ERROR - M2EE: An exception occurred during Runtime Shutdown.    2021-12-08T11:37:30.83-0500 [APP/PROC/WEB/0] OUT ERROR - M2EE: java.lang.NullPointerException: null  

asked 2021-12-08

0 answers