Spring Occasional ClassNotFoundException on startup on Azure AppService

Affects: \~5.3.0.RELEASE - at least 5.3.7

About a year ago we noticed through our monitoring that we get occasional ClassNotFoundException's. If I had to guess I would say about every 50th startup or so. Then it went quite for a few months (which might have been because our monitoring was kinda broken). About 4 months back we noticed it again and even a bit more frequent about every 20th startup.

Until today we were unable to reproduce it locally (which might just be lack of effort). We are working closley with Azure on this issue, but I thought it might be a good idea to open an issue as I was unable to find anything specifically about this on the web.

Please note the log line at 2021-07-01 13:54:50.519 the class thats not found differs from startup to startup What is consistent is the NoClassDefFoundError: org/apache/logging/log4j/core/impl/ThrowableProxy, we switched from logback to log4j to see if it makes any difference, but it does not.

Log output 1

2021-07-01T13:53:29.948258903Z   _____                               
2021-07-01T13:53:29.948285404Z   /  _  \ __________ _________   ____  
2021-07-01T13:53:29.948290104Z  /  /_\  \___   /  |  \_  __ \_/ __ \ 
2021-07-01T13:53:29.948294104Z /    |    \/    /|  |  /|  | \/\  ___/ 
2021-07-01T13:53:29.948297904Z \____|__  /_____ \____/ |__|    \___  >
2021-07-01T13:53:29.948301704Z         \/      \/                  \/ 
2021-07-01T13:53:29.948305305Z A P P   S E R V I C E   O N   L I N U X
2021-07-01T13:53:29.948308605Z Documentation: http://aka.ms/webapp-linux
2021-07-01T13:53:29.948312105Z 
2021-07-01T13:53:29.948315405Z **NOTE**: No files or system changes outside of /home will persist beyond your application's current session. /home is your application's persistent storage and is shared across all the server instances.
2021-07-01T13:53:29.948321605Z 
2021-07-01T13:53:29.948324905Z 
2021-07-01T13:53:29.948328305Z Setup openrc ...
2021-07-01T13:53:30.990429843Z  * Caching service dependencies ... [ ok ]
2021-07-01T13:53:31.001125061Z Updating /etc/ssh/sshd_config to use PORT 2222
2021-07-01T13:53:31.018362035Z Starting ssh service...
2021-07-01T13:53:33.246392033Z ssh-keygen: generating new host keys: RSA DSA ECDSA ED25519 
2021-07-01T13:53:35.989078422Z  * Starting sshd ... [ ok ]
2021-07-01T13:53:36.056129835Z ## Printing build info...
2021-07-01T13:53:36.079171033Z                                            PACKAGE |                             VERSION | COMMIT
2021-07-01T13:53:36.083812814Z        Microsoft.AppService.WebsitesExtensionsJava |        1.0.012910002-alpha-ca976a99 | ca976a99
2021-07-01T13:53:36.083819514Z                                               self |        1.0.012910002-alpha-65e49f85 | 65e49f85
2021-07-01T13:53:36.084121226Z ## Done printing build info.
2021-07-01T13:53:36.137581810Z Add public certificates to keystore if exists...
2021-07-01T13:53:36.138302938Z Add private certificates to keystore if exists...
2021-07-01T13:53:36.138640251Z Configuring max heap = 2761 MB
2021-07-01T13:53:36.171484031Z STARTUP_FILE=
2021-07-01T13:53:36.171638437Z STARTUP_COMMAND=java -Xmx512m -jar -Dspring.profiles.active=sqlserver /home/site/wwwroot/kundenmanagement.jar
2021-07-01T13:53:36.176204415Z No STARTUP_FILE available.
2021-07-01T13:53:36.176526828Z Running STARTUP_COMMAND: java -Xmx512m -jar -Dspring.profiles.active=sqlserver /home/site/wwwroot/kundenmanagement.jar
2021-07-01T13:53:36.781679715Z Picked up JAVA_TOOL_OPTIONS: -Xmx2761M -Djava.net.preferIPv4Stack=true -javaagent:/agents/java/applicationinsights-agent-codeless.jar
2021-07-01T13:53:40.680684989Z OpenJDK 64-Bit Server VM warning: Sharing is only supported for boot loader classes because bootstrap classpath has been appended
2021-07-01T13:53:50.759398711Z OpenJDK 64-Bit Server VM warning: Sharing is only supported for boot loader classes because bootstrap classpath has been appended
2021-07-01T13:53:50.772178510Z OpenJDK 64-Bit Server VM warning: Sharing is only supported for boot loader classes because bootstrap classpath has been appended
2021-07-01T13:53:51.515825336Z OpenJDK 64-Bit Server VM warning: Sharing is only supported for boot loader classes because bootstrap classpath has been appended
2021-07-01T13:53:51.534522766Z OpenJDK 64-Bit Server VM warning: Sharing is only supported for boot loader classes because bootstrap classpath has been appended
2021-07-01T13:53:51.536305635Z OpenJDK 64-Bit Server VM warning: Sharing is only supported for boot loader classes because bootstrap classpath has been appended
2021-07-01T13:53:52.026560730Z OpenJDK 64-Bit Server VM warning: Sharing is only supported for boot loader classes because bootstrap classpath has been appended
2021-07-01T13:53:52.849019956Z 2021-07-01 13:53:52.841Z INFO  c.m.applicationinsights.agent - ApplicationInsights Java Agent 3.0.4-BETA started successfully
2021-07-01T13:53:52.849043057Z 2021-07-01 13:53:52.843Z INFO  a.extension.diagnostics - Application Insights Codeless Agent 3.0.4-BETA Attach Successful
2021-07-01T13:53:53.230397860Z 2021-07-01 13:53:53.224Z INFO  c.m.a.a.b.d.status.StatusFile - Wrote status to file: /root/LogFiles/ApplicationInsights/status/status_RD0050F2721466_122.json
2021-07-01T13:53:58.105449699Z OpenJDK 64-Bit Server VM warning: Sharing is only supported for boot loader classes because bootstrap classpath has been appended
2021-07-01T13:54:02.192300176Z 
2021-07-01T13:54:02.192736593Z   .   ____          _            __ _ _
2021-07-01T13:54:02.193027005Z  /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
2021-07-01T13:54:02.193332817Z ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
2021-07-01T13:54:02.193656229Z  \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
2021-07-01T13:54:02.193935240Z   '  |____| .__|_| |_|_| |_\__, | / / / /
2021-07-01T13:54:02.194194850Z  =========|_|==============|___/=/_/_/_/
2021-07-01T13:54:02.222154838Z  :: Spring Boot ::                (v2.4.6)
2021-07-01T13:54:02.222417049Z 
2021-07-01T13:54:04.180034740Z 2021-07-01 13:54:04.142  INFO 122 --- [           main] c.e.e.KundenmanagementApplicationKt      : Starting KundenmanagementApplicationKt v0.0.1-SNAPSHOT using Java 11.0.7 on 020bc6d29462 with PID 122 (/home/site/wwwroot/kundenmanagement.jar started by root in /)
2021-07-01T13:54:04.230306696Z 2021-07-01 13:54:04.228  INFO 122 --- [           main] c.e.e.KundenmanagementApplicationKt      : The following profiles are active: sqlserver
2021-07-01T13:54:16.404356713Z 2021-07-01 13:54:16.398  INFO 122 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2021-07-01T13:54:18.842346616Z 2021-07-01 13:54:18.840  INFO 122 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 2377 ms. Found 1 JPA repository interfaces.
2021-07-01T13:54:23.567334325Z 2021-07-01 13:54:23.561  INFO 122 --- [           main] o.s.b.w.e.t.TomcatWebServer              : Tomcat initialized with port(s): 80 (http)
2021-07-01T13:54:23.681727192Z 2021-07-01 13:54:23.681  INFO 122 --- [           main] o.a.c.c.StandardService                  : Starting service [Tomcat]
2021-07-01T13:54:23.689397092Z 2021-07-01 13:54:23.682  INFO 122 --- [           main] o.a.c.c.StandardEngine                   : Starting Servlet engine: [Apache Tomcat/9.0.46]
2021-07-01T13:54:23.929447565Z 2021-07-01 13:54:23.924  INFO 122 --- [           main] o.a.c.c.C.[.[.[/]                        : Initializing Spring embedded WebApplicationContext
2021-07-01T13:54:23.929475967Z 2021-07-01 13:54:23.924  INFO 122 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 19135 ms
2021-07-01T13:54:24.060149869Z 2021-07-01 13:54:24.056  INFO 122 --- [           main] i.m.c.i.p.PushMeterRegistry              : publishing metrics for AzureMonitorMeterRegistry every 1m
2021-07-01T13:54:27.833248590Z 2021-07-01 13:54:27.831  INFO 122 --- [           main] o.f.c.i.l.VersionPrinter                 : Flyway Community Edition 7.1.1 by Redgate
2021-07-01T13:54:27.902907309Z 2021-07-01 13:54:27.902  INFO 122 --- [           main] c.z.h.HikariDataSource                   : HikariPool-1 - Starting...
2021-07-01T13:54:32.609608622Z 2021-07-01 13:54:32.609  INFO 122 --- [           main] c.z.h.HikariDataSource                   : HikariPool-1 - Start completed.
2021-07-01T13:54:37.398175782Z 2021-07-01 13:54:37.384  INFO 122 --- [           main] o.f.c.i.d.b.DatabaseType                 : Database: jdbc:sqlserver://emma-netzebw-dev-sql-server.database.windows.net:1433;sendTemporalDataTypesAsStringForBulkCopy=true;delayLoadingLobs=true;useFmtOnly=false;useBulkCopyForBatchInsert=false;cancelQueryTimeout=-1;sslProtocol=TLS;jaasConfigurationName=SQLJDBCDriver;statementPoolingCacheSize=0;serverPreparedStatementDiscardThreshold=10;enablePrepareOnFirstPreparedStatementCall=false;fips=false;socketTimeout=0;authentication=NotSpecified;authenticationScheme=nativeAuthentication;xopenStates=false;sendTimeAsDatetime=true;trustStoreType=JKS;trustServerCertificate=false;TransparentNetworkIPResolution=true;serverNameAsACE=false;sendStringParametersAsUnicode=true;selectMethod=direct;responseBuffering=adaptive;queryTimeout=-1;packetSize=8000;multiSubnetFailover=false;loginTimeout=10;lockTimeout=-1;lastUpdateCount=true;encrypt=false;disableStatementPooling=true;databaseName=emma-netzebw-dev-db;columnEncryptionSetting=Disabled;applicationName=Microsoft JDBC Driver for SQL Server;applicationIntent=readwrite; (Microsoft SQL Server 12.0)
2021-07-01T13:54:40.125759903Z 2021-07-01 13:54:40.119  INFO 122 --- [           main] o.f.c.i.c.DbValidate                     : Successfully validated 6 migrations (execution time 00:01.940s)
2021-07-01T13:54:40.420252450Z 2021-07-01 13:54:40.184  INFO 122 --- [           main] o.f.c.i.c.DbMigrate                      : Current version of schema [kundenmanagement]: 1.0.5
2021-07-01T13:54:40.420271851Z 2021-07-01 13:54:40.206  INFO 122 --- [           main] o.f.c.i.c.DbMigrate                      : Schema [kundenmanagement] is up to date. No migration necessary.
2021-07-01T13:54:40.773094489Z 2021-07-01 13:54:40.766  INFO 122 --- [           main] o.h.j.i.u.LogHelper                      : HHH000204: Processing PersistenceUnitInfo [name: default]
2021-07-01T13:54:42.153271918Z 2021-07-01 13:54:42.123  INFO 122 --- [           main] o.h.Version                              : HHH000412: Hibernate ORM core version 5.4.31.Final
2021-07-01T13:54:44.269000294Z 2021-07-01 13:54:44.268  INFO 122 --- [           main] o.h.a.c.Version                          : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2021-07-01T13:54:48.332904278Z 2021-07-01 13:54:48.327  INFO 122 --- [           main] o.h.d.Dialect                            : HHH000400: Using dialect: org.hibernate.dialect.SQLServer2012Dialect
2021-07-01T13:54:50.521236953Z 2021-07-01 13:54:50.519  WARN 122 --- [           main] ConfigServletWebServerApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'entityManagerFactory' defined in class path resource [org/springframework/boot/autoconfigure/orm/jpa/HibernateJpaConfiguration.class]: Invocation of init method failed; nested exception is java.lang.NoClassDefFoundError: javax/persistence/OrderColumn
2021-07-01T13:54:50.521264754Z 2021-07-01 13:54:50.520  INFO 122 --- [           main] c.z.h.HikariDataSource                   : HikariPool-1 - Shutdown initiated...
2021-07-01T13:54:50.619502209Z 2021-07-01 13:54:50.619  INFO 122 --- [           main] c.z.h.HikariDataSource                   : HikariPool-1 - Shutdown completed.
2021-07-01T13:54:51.122025030Z Exception in thread "main" java.lang.reflect.InvocationTargetException
2021-07-01T13:54:51.124806639Z  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2021-07-01T13:54:51.131244991Z  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
2021-07-01T13:54:51.131510402Z  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2021-07-01T13:54:51.131693609Z  at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2021-07-01T13:54:51.132071324Z  at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49)
2021-07-01T13:54:51.132283932Z  at org.springframework.boot.loader.Launcher.launch(Launcher.java:108)
2021-07-01T13:54:51.132547242Z  at org.springframework.boot.loader.Launcher.launch(Launcher.java:58)
2021-07-01T13:54:51.133028661Z  at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88)
2021-07-01T13:54:51.133491380Z Caused by: java.lang.NoClassDefFoundError: org/apache/logging/log4j/core/impl/ThrowableProxy
2021-07-01T13:54:51.133672987Z  at org.apache.logging.log4j.core.impl.Log4jLogEvent.getThrownProxy(Log4jLogEvent.java:629)
2021-07-01T13:54:51.133852294Z  at org.apache.logging.log4j.core.pattern.ExtendedThrowablePatternConverter.format(ExtendedThrowablePatternConverter.java:63)
2021-07-01T13:54:51.134029701Z  at org.springframework.boot.logging.log4j2.ExtendedWhitespaceThrowablePatternConverter.format(ExtendedWhitespaceThrowablePatternConverter.java:50)
2021-07-01T13:54:51.134207708Z  at org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:38)
2021-07-01T13:54:51.134386615Z  at org.apache.logging.log4j.core.layout.PatternLayout$PatternSerializer.toSerializable(PatternLayout.java:345)
2021-07-01T13:54:51.134563622Z  at org.apache.logging.log4j.core.layout.PatternLayout.toText(PatternLayout.java:244)
2021-07-01T13:54:51.134741329Z  at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:229)
2021-07-01T13:54:51.134994639Z  at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:59)
2021-07-01T13:54:51.164539798Z  at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:197)
2021-07-01T13:54:51.164563099Z  at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:190)
2021-07-01T13:54:51.164568799Z  at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:181)
2021-07-01T13:54:51.164573199Z  at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
2021-07-01T13:54:51.164577599Z  at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
2021-07-01T13:54:51.164582000Z  at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
2021-07-01T13:54:51.164586300Z  at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
2021-07-01T13:54:51.164590700Z  at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:543)
2021-07-01T13:54:51.164594700Z  at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:502)
2021-07-01T13:54:51.164598800Z  at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:485)
2021-07-01T13:54:51.164602800Z  at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:460)
2021-07-01T13:54:51.164606901Z  at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:82)
2021-07-01T13:54:51.164611101Z  at org.apache.logging.log4j.core.Logger.log(Logger.java:161)
2021-07-01T13:54:51.164615101Z  at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2198)
2021-07-01T13:54:51.164619201Z  at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2152)
2021-07-01T13:54:51.164623201Z  at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2135)
2021-07-01T13:54:51.164627201Z  at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2011)
2021-07-01T13:54:51.164631102Z  at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1983)
2021-07-01T13:54:51.164635202Z  at org.apache.commons.logging.LogAdapter$Log4jLog.log(LogAdapter.java:263)
2021-07-01T13:54:51.164639102Z  at org.apache.commons.logging.LogAdapter$Log4jLog.error(LogAdapter.java:215)
2021-07-01T13:54:51.164643102Z  at org.springframework.boot.SpringApplication.reportFailure(SpringApplication.java:860)
2021-07-01T13:54:51.164647702Z  at org.springframework.boot.SpringApplication.handleRunFailure(SpringApplication.java:825)
2021-07-01T13:54:51.164651702Z  at org.springframework.boot.SpringApplication.run(SpringApplication.java:349)
2021-07-01T13:54:51.164664503Z  at org.springframework.boot.SpringApplication.run(SpringApplication.java:1329)
2021-07-01T13:54:51.164668603Z  at org.springframework.boot.SpringApplication.run(SpringApplication.java:1318)
2021-07-01T13:54:51.164672603Z  at com.enbw.emma.KundenmanagementApplicationKt.main(KundenmanagementApplication.kt:16)
2021-07-01T13:54:51.164676603Z  ... 8 more
2021-07-01T13:54:51.164680703Z Caused by: java.lang.ClassNotFoundException: org.apache.logging.log4j.core.impl.ThrowableProxy
2021-07-01T13:54:51.164684804Z  at java.base/java.net.URLClassLoader.findClass(Unknown Source)
2021-07-01T13:54:51.164688704Z  at java.base/java.lang.ClassLoader.loadClass(Unknown Source)
2021-07-01T13:54:51.164692704Z  at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:151)
2021-07-01T13:54:51.164696704Z  at java.base/java.lang.ClassLoader.loadClass(Unknown Source)
2021-07-01T13:54:51.164700604Z  ... 42 more

Log output 2

2021-07-01T18:06:47.867637445Z   _____                               
2021-07-01T18:06:47.867661545Z   /  _  \ __________ _________   ____  
2021-07-01T18:06:47.867677546Z  /  /_\  \___   /  |  \_  __ \_/ __ \ 
2021-07-01T18:06:47.867682446Z /    |    \/    /|  |  /|  | \/\  ___/ 
2021-07-01T18:06:47.867686446Z \____|__  /_____ \____/ |__|    \___  >
2021-07-01T18:06:47.867690547Z         \/      \/                  \/ 
2021-07-01T18:06:47.867694647Z A P P   S E R V I C E   O N   L I N U X
2021-07-01T18:06:47.867698247Z Documentation: http://aka.ms/webapp-linux
2021-07-01T18:06:47.867702047Z 
2021-07-01T18:06:47.867705647Z **NOTE**: No files or system changes outside of /home will persist beyond your application's current session. /home is your application's persistent storage and is shared across all the server instances.
2021-07-01T18:06:47.867711947Z 
2021-07-01T18:06:47.867715448Z 
2021-07-01T18:06:47.867935956Z Setup openrc ...
2021-07-01T18:06:48.600991583Z  * Caching service dependencies ... [ ok ]
2021-07-01T18:06:48.653284218Z Updating /etc/ssh/sshd_config to use PORT 2222
2021-07-01T18:06:48.767113948Z Starting ssh service...
2021-07-01T18:06:51.212808215Z ssh-keygen: generating new host keys: RSA DSA ECDSA ED25519 
2021-07-01T18:06:53.944253101Z  * Starting sshd ... [ ok ]
2021-07-01T18:06:53.949351799Z ## Printing build info...
2021-07-01T18:06:53.952437319Z                                            PACKAGE |                             VERSION | COMMIT
2021-07-01T18:06:53.952453020Z        Microsoft.AppService.WebsitesExtensionsJava |        1.0.012910002-alpha-ca976a99 | ca976a99
2021-07-01T18:06:53.952458720Z                                               self |        1.0.012910002-alpha-65e49f85 | 65e49f85
2021-07-01T18:06:53.957951134Z ## Done printing build info.
2021-07-01T18:06:53.977600799Z Add public certificates to keystore if exists...
2021-07-01T18:06:53.991389835Z Add private certificates to keystore if exists...
2021-07-01T18:06:53.991566242Z Configuring max heap = 2761 MB
2021-07-01T18:06:54.009072623Z STARTUP_FILE=
2021-07-01T18:06:54.009089724Z STARTUP_COMMAND=java -Xmx512m -jar /home/site/wwwroot/kundenmanagement.jar
2021-07-01T18:06:54.009095424Z No STARTUP_FILE available.
2021-07-01T18:06:54.011410814Z Running STARTUP_COMMAND: java -Xmx512m -jar /home/site/wwwroot/kundenmanagement.jar
2021-07-01T18:06:54.503346556Z Picked up JAVA_TOOL_OPTIONS: -Xmx2761M -Djava.net.preferIPv4Stack=true 
2021-07-01T18:07:02.273745543Z 
2021-07-01T18:07:02.276051033Z   .   ____          _            __ _ _
2021-07-01T18:07:02.276135436Z  /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
2021-07-01T18:07:02.283949940Z ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
2021-07-01T18:07:02.293876726Z  \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
2021-07-01T18:07:02.294647056Z   '  |____| .__|_| |_|_| |_\__, | / / / /
2021-07-01T18:07:02.294956668Z  =========|_|==============|___/=/_/_/_/
2021-07-01T18:07:02.304069623Z  :: Spring Boot ::                (v2.4.6)
2021-07-01T18:07:02.304314032Z 
2021-07-01T18:07:02.828567625Z 2021-07-01 18:07:02.809  INFO 122 --- [           main] c.e.e.KundenmanagementApplicationKt      : Starting KundenmanagementApplicationKt v0.0.1-SNAPSHOT using Java 11.0.7 on a47a28b639cf with PID 122 (/home/site/wwwroot/kundenmanagement.jar started by root in /)
2021-07-01T18:07:02.861303298Z 2021-07-01 18:07:02.861  INFO 122 --- [           main] c.e.e.KundenmanagementApplicationKt      : No active profile set, falling back to default profiles: default
2021-07-01T18:07:13.209115317Z 2021-07-01 18:07:13.188  INFO 122 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2021-07-01T18:07:14.380734062Z 2021-07-01 18:07:14.380  INFO 122 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 1142 ms. Found 1 JPA repository interfaces.
2021-07-01T18:07:17.977222478Z 2021-07-01 18:07:17.976  INFO 122 --- [           main] o.s.b.w.e.t.TomcatWebServer              : Tomcat initialized with port(s): 80 (http)
2021-07-01T18:07:18.107988972Z 2021-07-01 18:07:18.055  INFO 122 --- [           main] o.a.c.c.StandardService                  : Starting service [Tomcat]
2021-07-01T18:07:18.108020673Z 2021-07-01 18:07:18.057  INFO 122 --- [           main] o.a.c.c.StandardEngine                   : Starting Servlet engine: [Apache Tomcat/9.0.46]
2021-07-01T18:07:18.480554487Z 2021-07-01 18:07:18.461  INFO 122 --- [           main] o.a.c.c.C.[.[.[/]                        : Initializing Spring embedded WebApplicationContext
2021-07-01T18:07:18.490919791Z 2021-07-01 18:07:18.461  INFO 122 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 14970 ms
2021-07-01T18:07:20.270841135Z 2021-07-01 18:07:20.270  INFO 122 --- [           main] o.f.c.i.l.VersionPrinter                 : Flyway Community Edition 7.1.1 by Redgate
2021-07-01T18:07:20.349806911Z 2021-07-01 18:07:20.349  INFO 122 --- [           main] c.z.h.HikariDataSource                   : HikariPool-1 - Starting...
2021-07-01T18:07:21.783929404Z 2021-07-01 18:07:21.783  INFO 122 --- [           main] c.z.h.HikariDataSource                   : HikariPool-1 - Start completed.
2021-07-01T18:07:21.986398800Z 2021-07-01 18:07:21.986  INFO 122 --- [           main] o.f.c.i.d.b.DatabaseType                 : Database: jdbc:h2:mem:1d744965-59e3-4f9b-8429-3b2bc6136b2a (H2 1.4)
2021-07-01T18:07:22.350355293Z 2021-07-01 18:07:22.350  INFO 122 --- [           main] o.f.c.i.c.DbValidate                     : Successfully validated 6 migrations (execution time 00:00.136s)
2021-07-01T18:07:22.421189755Z 2021-07-01 18:07:22.420  INFO 122 --- [           main] o.f.c.i.s.JdbcTableSchemaHistory         : Creating Schema History table "PUBLIC"."flyway_schema_history" ...
2021-07-01T18:07:22.659193636Z 2021-07-01 18:07:22.658  INFO 122 --- [           main] o.f.c.i.c.DbMigrate                      : Current version of schema "PUBLIC": << Empty Schema >>
2021-07-01T18:07:22.687858954Z 2021-07-01 18:07:22.687  INFO 122 --- [           main] o.f.c.i.c.DbMigrate                      : Migrating schema "PUBLIC" to version "1.0.0 - Initial"
2021-07-01T18:07:22.910783448Z 2021-07-01 18:07:22.908  INFO 122 --- [           main] o.f.c.i.c.DbMigrate                      : Migrating schema "PUBLIC" to version "1.0.1 - Add AppUserFilter KundenId"
2021-07-01T18:07:23.132132579Z 2021-07-01 18:07:23.108  INFO 122 --- [           main] o.f.c.i.c.DbMigrate                      : Migrating schema "PUBLIC" to version "1.0.2 - Rename AppUserFilter KundeId to KundenId"
2021-07-01T18:07:23.309238986Z 2021-07-01 18:07:23.280  INFO 122 --- [           main] o.f.c.i.c.DbMigrate                      : Migrating schema "PUBLIC" to version "1.0.3 - Add Kostenstelle"
2021-07-01T18:07:23.434052653Z 2021-07-01 18:07:23.400  INFO 122 --- [           main] o.f.c.i.c.DbMigrate                      : Migrating schema "PUBLIC" to version "1.0.4 - Make Kostenstelle KundeId Nullable"
2021-07-01T18:07:23.515268920Z 2021-07-01 18:07:23.487  INFO 122 --- [           main] o.f.c.i.c.DbMigrate                      : Migrating schema "PUBLIC" to version "1.0.5 - Make AppUserFilter KundeId Nullable"
2021-07-01T18:07:23.685202147Z 2021-07-01 18:07:23.648  INFO 122 --- [           main] o.f.c.i.c.DbMigrate                      : Successfully applied 6 migrations to schema "PUBLIC" (execution time 00:01.012s)
2021-07-01T18:07:24.307466913Z 2021-07-01 18:07:24.303  INFO 122 --- [           main] o.h.j.i.u.LogHelper                      : HHH000204: Processing PersistenceUnitInfo [name: default]
2021-07-01T18:07:24.798758672Z 2021-07-01 18:07:24.798  INFO 122 --- [           main] o.h.Version                              : HHH000412: Hibernate ORM core version 5.4.31.Final
2021-07-01T18:07:25.917935216Z 2021-07-01 18:07:25.917  INFO 122 --- [           main] o.h.a.c.Version                          : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2021-07-01T18:07:26.675494259Z 2021-07-01 18:07:26.674  INFO 122 --- [           main] o.h.d.Dialect                            : HHH000400: Using dialect: org.hibernate.dialect.H2Dialect
2021-07-01T18:07:39.373112947Z 2021-07-01 18:07:39.365  INFO 122 --- [           main] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2021-07-01T18:07:39.476474481Z 2021-07-01 18:07:39.476  INFO 122 --- [           main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2021-07-01T18:07:52.065407620Z 2021-07-01 18:07:52.061 DEBUG 122 --- [           main] o.s.w.c.RestTemplate                     : HTTP GET https://login.emma-dev.netze-bw.de/.well-known/openid-configuration
2021-07-01T18:07:52.124693746Z 2021-07-01 18:07:52.121 DEBUG 122 --- [           main] o.s.w.c.RestTemplate                     : Accept=[application/json, application/*+json]
2021-07-01T18:07:54.937816800Z 2021-07-01 18:07:54.916  WARN 122 --- [           main] ConfigServletWebServerApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'webSecurityConfiguration': Unsatisfied dependency expressed through method 'setContentNegotationStrategy' parameter 0; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'org.springframework.boot.autoconfigure.web.servlet.WebMvcAutoConfiguration$EnableWebMvcConfiguration': Unsatisfied dependency expressed through method 'setConfigurers' parameter 0; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'org.springframework.security.config.annotation.web.configuration.OAuth2ClientConfiguration$OAuth2ClientWebMvcSecurityConfiguration': Unsatisfied dependency expressed through method 'setClientRegistrationRepository' parameter 0; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'clientRegistrationRepository' defined in class path resource [org/springframework/boot/autoconfigure/security/oauth2/client/servlet/OAuth2ClientRegistrationRepositoryConfiguration.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [org.springframework.security.oauth2.client.registration.InMemoryClientRegistrationRepository]: Factory method 'clientRegistrationRepository' threw exception; nested exception is java.lang.NoClassDefFoundError: org/springframework/http/client/SimpleClientHttpResponse
2021-07-01T18:07:54.937872902Z 2021-07-01 18:07:54.931  INFO 122 --- [           main] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'default'
2021-07-01T18:07:54.953147798Z 2021-07-01 18:07:54.952  WARN 122 --- [           main] o.s.b.f.s.DisposableBeanAdapter          : Invocation of destroy method failed on bean with name 'entityManagerFactory': java.lang.NoClassDefFoundError: org/springframework/orm/hibernate5/SpringBeanContainer$SpringContainedBean
2021-07-01T18:07:54.953612817Z 2021-07-01 18:07:54.953  INFO 122 --- [           main] c.z.h.HikariDataSource                   : HikariPool-1 - Shutdown initiated...
2021-07-01T18:07:54.965245471Z 2021-07-01 18:07:54.964  INFO 122 --- [           main] c.z.h.HikariDataSource                   : HikariPool-1 - Shutdown completed.
2021-07-01T18:07:54.995597956Z 2021-07-01 18:07:54.994  INFO 122 --- [           main] o.a.c.c.StandardService                  : Stopping service [Tomcat]
2021-07-01T18:07:55.401809015Z Exception in thread "main" java.lang.reflect.InvocationTargetException
2021-07-01T18:07:55.401837516Z  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2021-07-01T18:07:55.401843516Z  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
2021-07-01T18:07:55.401848117Z  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2021-07-01T18:07:55.401852517Z  at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2021-07-01T18:07:55.401856817Z  at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49)
2021-07-01T18:07:55.401861117Z  at org.springframework.boot.loader.Launcher.launch(Launcher.java:108)
2021-07-01T18:07:55.401865117Z  at org.springframework.boot.loader.Launcher.launch(Launcher.java:58)
2021-07-01T18:07:55.401869117Z  at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88)
2021-07-01T18:07:55.402840455Z Caused by: java.lang.NoClassDefFoundError: org/apache/logging/log4j/core/impl/ThrowableProxy
2021-07-01T18:07:55.402891657Z  at org.apache.logging.log4j.core.impl.Log4jLogEvent.getThrownProxy(Log4jLogEvent.java:629)
2021-07-01T18:07:55.402901058Z  at org.apache.logging.log4j.core.pattern.ExtendedThrowablePatternConverter.format(ExtendedThrowablePatternConverter.java:63)
2021-07-01T18:07:55.402996561Z  at org.springframework.boot.logging.log4j2.ExtendedWhitespaceThrowablePatternConverter.format(ExtendedWhitespaceThrowablePatternConverter.java:50)
2021-07-01T18:07:55.403039263Z  at org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:38)
2021-07-01T18:07:55.403047463Z  at org.apache.logging.log4j.core.layout.PatternLayout$PatternSerializer.toSerializable(PatternLayout.java:345)
2021-07-01T18:07:55.403053764Z  at org.apache.logging.log4j.core.layout.PatternLayout.toText(PatternLayout.java:244)
2021-07-01T18:07:55.403079165Z  at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:229)
2021-07-01T18:07:55.403087365Z  at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:59)
2021-07-01T18:07:55.403093565Z  at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:197)
2021-07-01T18:07:55.403591185Z  at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:190)
2021-07-01T18:07:55.403609385Z  at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:181)
2021-07-01T18:07:55.403616286Z  at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
2021-07-01T18:07:55.403622886Z  at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
2021-07-01T18:07:55.403629086Z  at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
2021-07-01T18:07:55.403635486Z  at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
2021-07-01T18:07:55.403641787Z  at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:543)
2021-07-01T18:07:55.403648087Z  at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:502)
2021-07-01T18:07:55.403654287Z  at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:485)
2021-07-01T18:07:55.403660487Z  at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:460)
2021-07-01T18:07:55.403668788Z  at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:82)
2021-07-01T18:07:55.403675488Z  at org.apache.logging.log4j.core.Logger.log(Logger.java:161)
2021-07-01T18:07:55.403681688Z  at org.apache.logging.log4j.spi.AbstractLogger.tryLogMessage(AbstractLogger.java:2198)
2021-07-01T18:07:55.403687988Z  at org.apache.logging.log4j.spi.AbstractLogger.logMessageTrackRecursion(AbstractLogger.java:2152)
2021-07-01T18:07:55.403701189Z  at org.apache.logging.log4j.spi.AbstractLogger.logMessageSafely(AbstractLogger.java:2135)
2021-07-01T18:07:55.403707689Z  at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2011)
2021-07-01T18:07:55.403713889Z  at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1983)
2021-07-01T18:07:55.403719990Z  at org.apache.commons.logging.LogAdapter$Log4jLog.log(LogAdapter.java:263)
2021-07-01T18:07:55.403726190Z  at org.apache.commons.logging.LogAdapter$Log4jLog.error(LogAdapter.java:215)
2021-07-01T18:07:55.403732290Z  at org.springframework.boot.SpringApplication.reportFailure(SpringApplication.java:860)
2021-07-01T18:07:55.403738490Z  at org.springframework.boot.SpringApplication.handleRunFailure(SpringApplication.java:825)
2021-07-01T18:07:55.403744791Z  at org.springframework.boot.SpringApplication.run(SpringApplication.java:349)
2021-07-01T18:07:55.403750891Z  at org.springframework.boot.SpringApplication.run(SpringApplication.java:1329)
2021-07-01T18:07:55.403757091Z  at org.springframework.boot.SpringApplication.run(SpringApplication.java:1318)
2021-07-01T18:07:55.403763291Z  at com.enbw.emma.KundenmanagementApplicationKt.main(KundenmanagementApplication.kt:16)
2021-07-01T18:07:55.403769492Z  ... 8 more
2021-07-01T18:07:55.405252249Z Caused by: java.lang.ClassNotFoundException: org.apache.logging.log4j.core.impl.ThrowableProxy
2021-07-01T18:07:55.405271350Z  at java.base/java.net.URLClassLoader.findClass(Unknown Source)
2021-07-01T18:07:55.405279550Z  at java.base/java.lang.ClassLoader.loadClass(Unknown Source)
2021-07-01T18:07:55.405286651Z  at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:151)
2021-07-01T18:07:55.405293851Z  at java.base/java.lang.ClassLoader.loadClass(Unknown Source)
2021-07-01T18:07:55.417326721Z  ... 42 more

We are working on a minimal example to reproduce this, I will update the issue as soon as there are any news on this.

Comment From: patrick-dedication

Disabling Jar checking with -Dsun.misc.URLClassPath.disableJarChecking=true as mentioned in here has little to no effect.

Log output 1

2021-07-02T21:26:18.670501479Z   _____
2021-07-02T21:26:18.670549779Z   /  _  \ __________ _________   ____
2021-07-02T21:26:18.670767982Z  /  /_\  \___   /  |  \_  __ \_/ __ \
2021-07-02T21:26:18.670791182Z /    |    \/    /|  |  /|  | \/\  ___/
2021-07-02T21:26:18.670799382Z \____|__  /_____ \____/ |__|    \___  >
2021-07-02T21:26:18.670807082Z         \/      \/                  \/
2021-07-02T21:26:18.670814382Z A P P   S E R V I C E   O N   L I N U X
2021-07-02T21:26:18.670821383Z Documentation: http://aka.ms/webapp-linux
2021-07-02T21:26:18.670841783Z
2021-07-02T21:26:18.670849883Z **NOTE**: No files or system changes outside of /home will persist beyond your application's current session. /home is your application's persistent storage and is shared across all the server instances.
2021-07-02T21:26:18.670865383Z
2021-07-02T21:26:18.670871883Z
2021-07-02T21:26:18.690802114Z Setup openrc ...
2021-07-02T21:26:22.030099680Z  * Caching service dependencies ... [ ok ]
2021-07-02T21:26:22.090482880Z Updating /etc/ssh/sshd_config to use PORT 2222
2021-07-02T21:26:22.127707711Z Starting ssh service...
2021-07-02T21:26:25.519602654Z ssh-keygen: generating new host keys: RSA DSA ECDSA ED25519
2021-07-02T21:26:30.629836869Z  * Starting sshd ... [ ok ]
2021-07-02T21:26:30.829585694Z ## Printing build info...
2021-07-02T21:26:30.920142003Z                                            PACKAGE |                             VERSION | COMMIT
2021-07-02T21:26:30.920167203Z        Microsoft.AppService.WebsitesExtensionsJava |        1.0.012910002-alpha-ca976a99 | ca976a99
2021-07-02T21:26:30.920179003Z                                               self |        1.0.012910002-alpha-65e49f85 | 65e49f85
2021-07-02T21:26:30.920507707Z ## Done printing build info.
2021-07-02T21:26:31.079997783Z Add public certificates to keystore if exists...
2021-07-02T21:26:31.120335632Z Add private certificates to keystore if exists...
2021-07-02T21:26:31.121628247Z Configuring max heap = 2761 MB
2021-07-02T21:26:31.192828540Z STARTUP_FILE=
2021-07-02T21:26:31.193010442Z STARTUP_COMMAND=java -Xmx512m -Dsun.misc.URLClassPath.disableJarChecking=true -jar -Dspring.profiles.active=sqlserver /home/site/wwwroot/kundenmanagement.jar
2021-07-02T21:26:31.193324445Z No STARTUP_FILE available.
2021-07-02T21:26:31.193675749Z Running STARTUP_COMMAND: java -Xmx512m -Dsun.misc.URLClassPath.disableJarChecking=true -jar -Dspring.profiles.active=sqlserver /home/site/wwwroot/kundenmanagement.jar
2021-07-02T21:26:32.858927843Z Picked up JAVA_TOOL_OPTIONS: -Xmx2761M -Djava.net.preferIPv4Stack=true
2021-07-02T21:27:22.749399928Z
2021-07-02T21:27:22.750039137Z   .   ____          _            __ _ _
2021-07-02T21:27:22.750050037Z  /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
2021-07-02T21:27:22.750295440Z ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
2021-07-02T21:27:22.797002561Z  \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
2021-07-02T21:27:22.798349979Z   '  |____| .__|_| |_|_| |_\__, | / / / /
2021-07-02T21:27:22.798569282Z  =========|_|==============|___/=/_/_/_/
2021-07-02T21:27:22.847773837Z  :: Spring Boot ::                (v2.4.6)
2021-07-02T21:27:22.848362945Z
2021-07-02T21:27:26.523191835Z 2021-07-02 21:27:26.305  INFO 122 --- [           main] c.e.emma.KundenmanagementApplicationKt   : Starting KundenmanagementApplicationKt v0.0.1-SNAPSHOT using Java 11.0.7 on 6dfb866d209d with PID 122 (/home/site/wwwroot/kundenmanagement.jar started by root in /)
2021-07-02T21:27:26.656528509Z 2021-07-02 21:27:26.624  INFO 122 --- [           main] c.e.emma.KundenmanagementApplicationKt   : The following profiles are active: sqlserver
2021-07-02T21:27:27.900054510Z Exception in thread "background-preinit" java.lang.NoClassDefFoundError: org/springframework/boot/autoconfigure/BackgroundPreinitializer$MessageConverterInitializer
2021-07-02T21:27:27.900081611Z  at org.springframework.boot.autoconfigure.BackgroundPreinitializer$1.run(BackgroundPreinitializer.java:103)
2021-07-02T21:27:27.900951321Z  at java.base/java.lang.Thread.run(Unknown Source)
2021-07-02T21:27:27.900966121Z Caused by: java.lang.ClassNotFoundException: org.springframework.boot.autoconfigure.BackgroundPreinitializer$MessageConverterInitializer
2021-07-02T21:27:27.900971821Z  at java.base/java.net.URLClassLoader.findClass(Unknown Source)
2021-07-02T21:27:27.900976521Z  at java.base/java.lang.ClassLoader.loadClass(Unknown Source)
2021-07-02T21:27:27.900981321Z  at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:151)
2021-07-02T21:27:27.901556128Z  at java.base/java.lang.ClassLoader.loadClass(Unknown Source)
2021-07-02T21:27:27.901570328Z  ... 2 more
2021-07-02T21:29:41.160838633Z 2021-07-02 21:29:41.160  INFO 122 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2021-07-02T21:29:48.086599124Z 2021-07-02 21:29:48.086  INFO 122 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 6681 ms. Found 1 JPA repository interfaces.
2021-07-02T21:30:23.853251188Z 2021-07-02 21:30:23.852  INFO 122 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 80 (http)
2021-07-02T21:30:24.160158909Z 2021-07-02 21:30:24.159  INFO 122 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2021-07-02T21:30:24.160585714Z 2021-07-02 21:30:24.160  INFO 122 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.46]
2021-07-02T21:30:27.095723690Z 2021-07-02 21:30:27.095  INFO 122 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2021-07-02T21:30:27.095762591Z 2021-07-02 21:30:27.095  INFO 122 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 166401 ms
2021-07-02T21:31:10.094320182Z 2021-07-02 21:31:10.094  INFO 122 --- [           main] o.f.c.internal.license.VersionPrinter    : Flyway Community Edition 7.1.1 by Redgate
2021-07-02T21:31:11.496915128Z 2021-07-02 21:31:11.486  INFO 122 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2021-07-02T21:31:14.472682250Z 2021-07-02 21:31:14.472  INFO 122 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2021-07-02T21:31:26.914085537Z 2021-07-02 21:31:26.913  INFO 122 --- [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2021-07-02T21:31:33.601212265Z 2021-07-02 21:31:33.600  INFO 122 --- [           main] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 5.4.31.Final
2021-07-02T21:31:38.759283520Z 2021-07-02 21:31:38.758  INFO 122 --- [           main] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2021-07-02T21:31:43.947315968Z 2021-07-02 21:31:43.946  INFO 122 --- [           main] org.hibernate.dialect.Dialect            : HHH000400: Using dialect: org.hibernate.dialect.SQLServer2012Dialect
2021-07-02T21:31:49.285054025Z 2021-07-02 21:31:49.283 ERROR 122 --- [           main] j.LocalContainerEntityManagerFactoryBean : Failed to initialize JPA EntityManagerFactory: [PersistenceUnit: default] Unable to build Hibernate SessionFactory; nested exception is org.hibernate.cfg.beanvalidation.IntegrationException: Error activating Bean Validation integration
2021-07-02T21:31:49.295495848Z 2021-07-02 21:31:49.285  WARN 122 --- [           main] ConfigServletWebServerApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'entityManagerFactory' defined in class path resource [org/springframework/boot/autoconfigure/orm/jpa/HibernateJpaConfiguration.class]: Invocation of init method failed; nested exception is javax.persistence.PersistenceException: [PersistenceUnit: default] Unable to build Hibernate SessionFactory; nested exception is org.hibernate.cfg.beanvalidation.IntegrationException: Error activating Bean Validation integration
2021-07-02T21:31:49.295518648Z 2021-07-02 21:31:49.286  INFO 122 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
2021-07-02T21:31:49.305578467Z 2021-07-02 21:31:49.305  INFO 122 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.
2021-07-02T21:31:49.357556779Z 2021-07-02 21:31:49.357  INFO 122 --- [           main] o.apache.catalina.core.StandardService   : Stopping service [Tomcat]

Log output 2

2021-07-02T21:38:35.287041827Z   _____
2021-07-02T21:38:35.287074727Z   /  _  \ __________ _________   ____
2021-07-02T21:38:35.287080927Z  /  /_\  \___   /  |  \_  __ \_/ __ \
2021-07-02T21:38:35.287085427Z /    |    \/    /|  |  /|  | \/\  ___/
2021-07-02T21:38:35.287089627Z \____|__  /_____ \____/ |__|    \___  >
2021-07-02T21:38:35.287093927Z         \/      \/                  \/
2021-07-02T21:38:35.287098027Z A P P   S E R V I C E   O N   L I N U X
2021-07-02T21:38:35.287101928Z Documentation: http://aka.ms/webapp-linux
2021-07-02T21:38:35.287105828Z
2021-07-02T21:38:35.287109628Z **NOTE**: No files or system changes outside of /home will persist beyond your application's current session. /home is your application's persistent storage and is shared across all the server instances.
2021-07-02T21:38:35.287114728Z
2021-07-02T21:38:35.287118428Z
2021-07-02T21:38:35.287395830Z Setup openrc ...
2021-07-02T21:38:36.090892872Z  * Caching service dependencies ... [ ok ]
2021-07-02T21:38:36.093711991Z Updating /etc/ssh/sshd_config to use PORT 2222
2021-07-02T21:38:36.102805153Z Starting ssh service...
2021-07-02T21:38:37.807242997Z ssh-keygen: generating new host keys: RSA DSA ECDSA ED25519
2021-07-02T21:38:40.946237459Z  * Starting sshd ... [ ok ]
2021-07-02T21:38:40.957697437Z ## Printing build info...
2021-07-02T21:38:40.967974206Z                                            PACKAGE |                             VERSION | COMMIT
2021-07-02T21:38:40.967992807Z        Microsoft.AppService.WebsitesExtensionsJava |        1.0.012910002-alpha-ca976a99 | ca976a99
2021-07-02T21:38:40.967999007Z                                               self |        1.0.012910002-alpha-65e49f85 | 65e49f85
2021-07-02T21:38:40.974611651Z ## Done printing build info.
2021-07-02T21:38:40.988567846Z Add public certificates to keystore if exists...
2021-07-02T21:38:40.994427586Z Add private certificates to keystore if exists...
2021-07-02T21:38:40.994728488Z Configuring max heap = 2761 MB
2021-07-02T21:38:41.025184994Z STARTUP_FILE=
2021-07-02T21:38:41.025466696Z STARTUP_COMMAND=java -Xmx512m -Dsun.misc.URLClassPath.disableJarChecking=true -jar -Dspring.profiles.active=sqlserver /home/site/wwwroot/kundenmanagement.jar
2021-07-02T21:38:41.025738098Z No STARTUP_FILE available.
2021-07-02T21:38:41.026211201Z Running STARTUP_COMMAND: java -Xmx512m -Dsun.misc.URLClassPath.disableJarChecking=true -jar -Dspring.profiles.active=sqlserver /home/site/wwwroot/kundenmanagement.jar
2021-07-02T21:38:41.379058591Z Picked up JAVA_TOOL_OPTIONS: -Xmx2761M -Djava.net.preferIPv4Stack=true
2021-07-02T21:38:47.911333604Z
2021-07-02T21:38:47.911363004Z   .   ____          _            __ _ _
2021-07-02T21:38:47.911368204Z  /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
2021-07-02T21:38:47.911384004Z ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
2021-07-02T21:38:47.911388104Z  \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
2021-07-02T21:38:47.911391804Z   '  |____| .__|_| |_|_| |_\__, | / / / /
2021-07-02T21:38:47.939844099Z  =========|_|==============|___/=/_/_/_/
2021-07-02T21:38:47.963502561Z  :: Spring Boot ::                (v2.4.6)
2021-07-02T21:38:47.963748963Z
2021-07-02T21:38:49.025230530Z 2021-07-02 21:38:48.990  INFO 122 --- [           main] c.e.emma.KundenmanagementApplicationKt   : Starting KundenmanagementApplicationKt v0.0.1-SNAPSHOT using Java 11.0.7 on 70166834b909 with PID 122 (/home/site/wwwroot/kundenmanagement.jar started by root in /)
2021-07-02T21:38:49.025260230Z 2021-07-02 21:38:49.015  INFO 122 --- [           main] c.e.emma.KundenmanagementApplicationKt   : The following profiles are active: sqlserver
2021-07-02T21:38:59.496415980Z 2021-07-02 21:38:59.495  INFO 122 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2021-07-02T21:39:00.364377431Z 2021-07-02 21:39:00.364  INFO 122 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 830 ms. Found 1 JPA repository interfaces.
2021-07-02T21:39:04.916250593Z 2021-07-02 21:39:04.915  INFO 122 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 80 (http)
2021-07-02T21:39:04.964755414Z 2021-07-02 21:39:04.964  INFO 122 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2021-07-02T21:39:04.964966316Z 2021-07-02 21:39:04.964  INFO 122 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.46]
2021-07-02T21:39:05.251010611Z 2021-07-02 21:39:05.250  INFO 122 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2021-07-02T21:39:05.251041911Z 2021-07-02 21:39:05.250  INFO 122 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 15648 ms
2021-07-02T21:39:06.970050722Z 2021-07-02 21:39:06.968  INFO 122 --- [           main] o.f.c.internal.license.VersionPrinter    : Flyway Community Edition 7.1.1 by Redgate
2021-07-02T21:39:07.012765824Z 2021-07-02 21:39:07.010  INFO 122 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2021-07-02T21:39:08.692664967Z 2021-07-02 21:39:08.692  INFO 122 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2021-07-02T21:39:09.999939848Z 2021-07-02 21:39:09.999  INFO 122 --- [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2021-07-02T21:39:10.490530468Z 2021-07-02 21:39:10.481  INFO 122 --- [           main] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 5.4.31.Final
2021-07-02T21:39:11.197695612Z 2021-07-02 21:39:11.196  INFO 122 --- [           main] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2021-07-02T21:39:12.022649412Z 2021-07-02 21:39:12.016  INFO 122 --- [           main] org.hibernate.dialect.Dialect            : HHH000400: Using dialect: org.hibernate.dialect.SQLServer2012Dialect
2021-07-02T21:39:15.117261000Z 2021-07-02 21:39:15.112  INFO 122 --- [           main] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2021-07-02T21:39:15.278336073Z 2021-07-02 21:39:15.272  INFO 122 --- [           main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2021-07-02T21:39:28.304597817Z 2021-07-02 21:39:28.300 DEBUG 122 --- [           main] o.s.web.client.RestTemplate              : HTTP GET https://login.emma-dev.netze-bw.de/.well-known/openid-configuration
2021-07-02T21:39:28.425273847Z 2021-07-02 21:39:28.419 DEBUG 122 --- [           main] o.s.web.client.RestTemplate              : Accept=[application/json, application/*+json]
2021-07-02T21:39:29.581102881Z 2021-07-02 21:39:29.576 DEBUG 122 --- [           main] o.s.web.client.RestTemplate              : Response 200 OK
2021-07-02T21:39:29.581130481Z 2021-07-02 21:39:29.579 DEBUG 122 --- [           main] o.s.web.client.RestTemplate              : Reading to [java.util.Map<java.lang.String, java.lang.Object>]
2021-07-02T21:39:44.193958391Z 2021-07-02 21:39:44.193  WARN 122 --- [           main] ConfigServletWebServerApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'springSecurityFilterChain' defined in class path resource [org/springframework/security/config/annotation/web/configuration/WebSecurityConfiguration.class]: Bean instantiation via factory method failed; nested exception is org.springframework.beans.BeanInstantiationException: Failed to instantiate [javax.servlet.Filter]: Factory method 'springSecurityFilterChain' threw exception; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'mvcHandlerMappingIntrospector' defined in class path resource [org/springframework/boot/autoconfigure/web/servlet/WebMvcAutoConfiguration$EnableWebMvcConfiguration.class]: Post-processing of merged bean definition failed; nested exception is java.lang.IllegalStateException: Failed to introspect Class [org.springframework.web.servlet.handler.HandlerMappingIntrospector] from ClassLoader [org.springframework.boot.loader.LaunchedURLClassLoader@31cefde0]
2021-07-02T21:39:44.203148550Z 2021-07-02 21:39:44.202  INFO 122 --- [           main] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'default'
2021-07-02T21:39:44.221241266Z 2021-07-02 21:39:44.214  WARN 122 --- [           main] o.s.b.f.support.DisposableBeanAdapter    : Invocation of destroy method failed on bean with name 'entityManagerFactory': java.lang.NoClassDefFoundError: org/springframework/orm/hibernate5/SpringBeanContainer$SpringContainedBean
2021-07-02T21:39:44.221270367Z 2021-07-02 21:39:44.214  INFO 122 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
2021-07-02T21:39:44.303798196Z 2021-07-02 21:39:44.255  INFO 122 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.
2021-07-02T21:39:44.342734946Z 2021-07-02 21:39:44.342  INFO 122 --- [           main] o.apache.catalina.core.StandardService   : Stopping service [Tomcat]
2021-07-02T21:39:44.762909941Z Exception in thread "main" java.lang.reflect.InvocationTargetException
2021-07-02T21:39:44.762971742Z  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2021-07-02T21:39:44.765061455Z  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
2021-07-02T21:39:44.765577758Z  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2021-07-02T21:39:44.766191962Z  at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2021-07-02T21:39:44.766518964Z  at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49)
2021-07-02T21:39:44.766833366Z  at org.springframework.boot.loader.Launcher.launch(Launcher.java:108)
2021-07-02T21:39:44.767143168Z  at org.springframework.boot.loader.Launcher.launch(Launcher.java:58)
2021-07-02T21:39:44.767446470Z  at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88)
2021-07-02T21:39:44.768008174Z Caused by: java.lang.NoClassDefFoundError: ch/qos/logback/classic/spi/ThrowableProxy
2021-07-02T21:39:44.773423709Z  at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:119)
2021-07-02T21:39:44.774435515Z  at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:419)
2021-07-02T21:39:44.774983919Z  at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383)
2021-07-02T21:39:44.775652023Z  at ch.qos.logback.classic.Logger.log(Logger.java:765)
2021-07-02T21:39:44.781992364Z  at org.apache.commons.logging.LogAdapter$Slf4jLocationAwareLog.error(LogAdapter.java:433)
2021-07-02T21:39:44.782009364Z  at org.springframework.boot.SpringApplication.reportFailure(SpringApplication.java:860)
2021-07-02T21:39:44.782014364Z  at org.springframework.boot.SpringApplication.handleRunFailure(SpringApplication.java:825)
2021-07-02T21:39:44.782018264Z  at org.springframework.boot.SpringApplication.run(SpringApplication.java:349)
2021-07-02T21:39:44.782022264Z  at org.springframework.boot.SpringApplication.run(SpringApplication.java:1329)
2021-07-02T21:39:44.782026164Z  at org.springframework.boot.SpringApplication.run(SpringApplication.java:1318)
2021-07-02T21:39:44.782073664Z  at com.enbw.emma.KundenmanagementApplicationKt.main(KundenmanagementApplication.kt:16)
2021-07-02T21:39:44.782078764Z  ... 8 more
2021-07-02T21:39:44.782082764Z Caused by: java.lang.ClassNotFoundException: ch.qos.logback.classic.spi.ThrowableProxy
2021-07-02T21:39:44.782086664Z  at java.base/java.net.URLClassLoader.findClass(Unknown Source)
2021-07-02T21:39:44.782090464Z  at java.base/java.lang.ClassLoader.loadClass(Unknown Source)
2021-07-02T21:39:44.782094664Z  at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:151)
2021-07-02T21:39:44.782098764Z  at java.base/java.lang.ClassLoader.loadClass(Unknown Source)
2021-07-02T21:39:44.782102564Z  ... 19 more

Log output 3

2021-07-02T21:53:23.970648359Z   _____
2021-07-02T21:53:23.970837260Z   /  _  \ __________ _________   ____
2021-07-02T21:53:23.970844160Z  /  /_\  \___   /  |  \_  __ \_/ __ \
2021-07-02T21:53:23.970848260Z /    |    \/    /|  |  /|  | \/\  ___/
2021-07-02T21:53:23.970851860Z \____|__  /_____ \____/ |__|    \___  >
2021-07-02T21:53:23.970855560Z         \/      \/                  \/
2021-07-02T21:53:23.970859060Z A P P   S E R V I C E   O N   L I N U X
2021-07-02T21:53:23.970862560Z Documentation: http://aka.ms/webapp-linux
2021-07-02T21:53:23.970865960Z
2021-07-02T21:53:23.970869360Z **NOTE**: No files or system changes outside of /home will persist beyond your application's current session. /home is your application's persistent storage and is shared across all the server instances.
2021-07-02T21:53:23.970874360Z
2021-07-02T21:53:23.970877560Z
2021-07-02T21:53:23.970880760Z Setup openrc ...
2021-07-02T21:53:24.799368515Z  * Caching service dependencies ... [ ok ]
2021-07-02T21:53:24.799418516Z Updating /etc/ssh/sshd_config to use PORT 2222
2021-07-02T21:53:24.809966181Z Starting ssh service...
2021-07-02T21:53:26.788826895Z ssh-keygen: generating new host keys: RSA DSA ECDSA ED25519
2021-07-02T21:53:29.401102551Z  * Starting sshd ... [ ok ]
2021-07-02T21:53:29.441509202Z ## Printing build info...
2021-07-02T21:53:29.493961628Z                                            PACKAGE |                             VERSION | COMMIT
2021-07-02T21:53:29.493985029Z        Microsoft.AppService.WebsitesExtensionsJava |        1.0.012910002-alpha-ca976a99 | ca976a99
2021-07-02T21:53:29.493991829Z                                               self |        1.0.012910002-alpha-65e49f85 | 65e49f85
2021-07-02T21:53:29.494255130Z ## Done printing build info.
2021-07-02T21:53:29.590818231Z Add public certificates to keystore if exists...
2021-07-02T21:53:29.595540260Z Add private certificates to keystore if exists...
2021-07-02T21:53:29.595976063Z Configuring max heap = 2761 MB
2021-07-02T21:53:29.609507547Z STARTUP_FILE=
2021-07-02T21:53:29.615928887Z STARTUP_COMMAND=java -Xmx512m -Dsun.misc.URLClassPath.disableJarChecking=true -jar -Dspring.profiles.active=sqlserver /home/site/wwwroot/kundenmanagement.jar
2021-07-02T21:53:29.615946287Z No STARTUP_FILE available.
2021-07-02T21:53:29.616025188Z Running STARTUP_COMMAND: java -Xmx512m -Dsun.misc.URLClassPath.disableJarChecking=true -jar -Dspring.profiles.active=sqlserver /home/site/wwwroot/kundenmanagement.jar
2021-07-02T21:53:30.728602511Z Picked up JAVA_TOOL_OPTIONS: -Xmx2761M -Djava.net.preferIPv4Stack=true
2021-07-02T21:53:38.868047158Z
2021-07-02T21:53:38.868112359Z   .   ____          _            __ _ _
2021-07-02T21:53:38.878643428Z  /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
2021-07-02T21:53:38.878682328Z ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
2021-07-02T21:53:38.878688828Z  \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
2021-07-02T21:53:38.878693428Z   '  |____| .__|_| |_|_| |_\__, | / / / /
2021-07-02T21:53:38.887079683Z  =========|_|==============|___/=/_/_/_/
2021-07-02T21:53:38.927210847Z  :: Spring Boot ::                (v2.4.6)
2021-07-02T21:53:38.927233447Z
2021-07-02T21:53:39.864447203Z 2021-07-02 21:53:39.805  INFO 122 --- [           main] c.e.emma.KundenmanagementApplicationKt   : Starting KundenmanagementApplicationKt v0.0.1-SNAPSHOT using Java 11.0.7 on 09392a701c77 with PID 122 (/home/site/wwwroot/kundenmanagement.jar started by root in /)
2021-07-02T21:53:39.866134220Z 2021-07-02 21:53:39.865  INFO 122 --- [           main] c.e.emma.KundenmanagementApplicationKt   : The following profiles are active: sqlserver
2021-07-02T21:53:51.649214525Z 2021-07-02 21:53:51.648  INFO 122 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2021-07-02T21:53:52.623865340Z 2021-07-02 21:53:52.617  INFO 122 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 913 ms. Found 1 JPA repository interfaces.
2021-07-02T21:53:57.678029389Z 2021-07-02 21:53:57.670  INFO 122 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 80 (http)
2021-07-02T21:53:57.727310745Z 2021-07-02 21:53:57.720  INFO 122 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2021-07-02T21:53:57.727860947Z 2021-07-02 21:53:57.727  INFO 122 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.46]
2021-07-02T21:53:57.949040346Z 2021-07-02 21:53:57.948  INFO 122 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2021-07-02T21:53:57.949717348Z 2021-07-02 21:53:57.949  INFO 122 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 17580 ms
2021-07-02T21:54:00.111175583Z 2021-07-02 21:54:00.110  INFO 122 --- [           main] o.f.c.internal.license.VersionPrinter    : Flyway Community Edition 7.1.1 by Redgate
2021-07-02T21:54:00.274248598Z 2021-07-02 21:54:00.262  INFO 122 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2021-07-02T21:54:03.322759819Z 2021-07-02 21:54:03.322  INFO 122 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2021-07-02T21:54:04.773253642Z 2021-07-02 21:54:04.746  INFO 122 --- [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2021-07-02T21:54:05.188742106Z 2021-07-02 21:54:05.186  INFO 122 --- [           main] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 5.4.31.Final
2021-07-02T21:54:06.334040475Z 2021-07-02 21:54:06.332  INFO 122 --- [           main] o.hibernate.annotations.common.Version   : HCANN000001: Hibernate Commons Annotations {5.1.2.Final}
2021-07-02T21:54:07.137336505Z 2021-07-02 21:54:07.137  INFO 122 --- [           main] org.hibernate.dialect.Dialect            : HHH000400: Using dialect: org.hibernate.dialect.SQLServer2012Dialect
2021-07-02T21:54:12.325416053Z 2021-07-02 21:54:12.325  INFO 122 --- [           main] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000490: Using JtaPlatform implementation: [org.hibernate.engine.transaction.jta.platform.internal.NoJtaPlatform]
2021-07-02T21:54:12.557798686Z 2021-07-02 21:54:12.545  INFO 122 --- [           main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2021-07-02T21:54:34.172535414Z 2021-07-02 21:54:34.166 DEBUG 122 --- [           main] o.s.web.client.RestTemplate              : HTTP GET https://login.emma-dev.netze-bw.de/.well-known/openid-configuration
2021-07-02T21:54:34.224487762Z 2021-07-02 21:54:34.224 DEBUG 122 --- [           main] o.s.web.client.RestTemplate              : Accept=[application/json, application/*+json]
2021-07-02T21:54:35.451926787Z 2021-07-02 21:54:35.451 DEBUG 122 --- [           main] o.s.web.client.RestTemplate              : Response 200 OK
2021-07-02T21:54:35.459615939Z 2021-07-02 21:54:35.459 DEBUG 122 --- [           main] o.s.web.client.RestTemplate              : Reading to [java.util.Map<java.lang.String, java.lang.Object>]
2021-07-02T21:54:40.173756389Z 2021-07-02 21:54:40.173  WARN 122 --- [           main] ConfigServletWebServerApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'org.springframework.security.config.annotation.web.configuration.WebSecurityConfiguration': Unsatisfied dependency expressed through method 'setFilterChainProxySecurityConfigurer' parameter 1; nested exception is org.springframework.beans.factory.BeanExpressionException: Expression parsing failed; nested exception is java.lang.NoClassDefFoundError: org/springframework/expression/spel/ast/BooleanLiteral
2021-07-02T21:54:40.191674372Z 2021-07-02 21:54:40.191  INFO 122 --- [           main] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'default'
2021-07-02T21:54:40.240942701Z 2021-07-02 21:54:40.240  WARN 122 --- [           main] o.s.b.f.support.DisposableBeanAdapter    : Invocation of destroy method failed on bean with name 'entityManagerFactory': java.lang.NoClassDefFoundError: org/springframework/orm/hibernate5/SpringBeanContainer$SpringContainedBean
2021-07-02T21:54:40.242034206Z 2021-07-02 21:54:40.241  INFO 122 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
2021-07-02T21:54:40.271804944Z 2021-07-02 21:54:40.271  INFO 122 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.
2021-07-02T21:54:40.279955182Z 2021-07-02 21:54:40.279  INFO 122 --- [           main] o.apache.catalina.core.StandardService   : Stopping service [Tomcat]
2021-07-02T21:54:40.743084934Z Exception in thread "main" java.lang.reflect.InvocationTargetException
2021-07-02T21:54:40.757261600Z  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2021-07-02T21:54:40.757276800Z  at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
2021-07-02T21:54:40.757280800Z  at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
2021-07-02T21:54:40.757284300Z  at java.base/java.lang.reflect.Method.invoke(Unknown Source)
2021-07-02T21:54:40.757295000Z  at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49)
2021-07-02T21:54:40.757298600Z  at org.springframework.boot.loader.Launcher.launch(Launcher.java:108)
2021-07-02T21:54:40.757301800Z  at org.springframework.boot.loader.Launcher.launch(Launcher.java:58)
2021-07-02T21:54:40.757305100Z  at org.springframework.boot.loader.JarLauncher.main(JarLauncher.java:88)
2021-07-02T21:54:40.757308300Z Caused by: java.lang.NoClassDefFoundError: ch/qos/logback/classic/spi/ThrowableProxy
2021-07-02T21:54:40.757311600Z  at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:119)
2021-07-02T21:54:40.766612443Z  at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:419)
2021-07-02T21:54:40.766641043Z  at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:383)
2021-07-02T21:54:40.766646343Z  at ch.qos.logback.classic.Logger.log(Logger.java:765)
2021-07-02T21:54:40.766650243Z  at org.apache.commons.logging.LogAdapter$Slf4jLocationAwareLog.error(LogAdapter.java:433)
2021-07-02T21:54:40.766662243Z  at org.springframework.boot.SpringApplication.reportFailure(SpringApplication.java:860)
2021-07-02T21:54:40.766666243Z  at org.springframework.boot.SpringApplication.handleRunFailure(SpringApplication.java:825)
2021-07-02T21:54:40.769955059Z  at org.springframework.boot.SpringApplication.run(SpringApplication.java:349)
2021-07-02T21:54:40.769982159Z  at org.springframework.boot.SpringApplication.run(SpringApplication.java:1329)
2021-07-02T21:54:40.769987459Z  at org.springframework.boot.SpringApplication.run(SpringApplication.java:1318)
2021-07-02T21:54:40.769991659Z  at com.enbw.emma.KundenmanagementApplicationKt.main(KundenmanagementApplication.kt:16)
2021-07-02T21:54:40.769995759Z  ... 8 more
2021-07-02T21:54:40.776839391Z Caused by: java.lang.ClassNotFoundException: ch.qos.logback.classic.spi.ThrowableProxy
2021-07-02T21:54:40.776873991Z  at java.base/java.net.URLClassLoader.findClass(Unknown Source)
2021-07-02T21:54:40.776887891Z  at java.base/java.lang.ClassLoader.loadClass(Unknown Source)
2021-07-02T21:54:40.776898991Z  at org.springframework.boot.loader.LaunchedURLClassLoader.loadClass(LaunchedURLClassLoader.java:151)
2021-07-02T21:54:40.776909191Z  at java.base/java.lang.ClassLoader.loadClass(Unknown Source)
2021-07-02T21:54:40.776918991Z  ... 19 more

Comment From: patrick-dedication

It is quite hard to reproduce this consistently, any ideas what could lead to this problem?

Comment From: snicoll

Have you noticed that the application is shutting down. It should do so because something has requested it. Perhaps the redeployment is causing some issues? See http://mailman.qos.ch/pipermail/logback-user/2015-August/004630.html.

I am going to close this now as the Spring Framework issue tracker is not the right place to ask for this. There's some discussion on the Spring Boot issue tracker as well, see https://github.com/spring-projects/spring-boot/issues/6151. If you manage to find a way to reproduce the problem and you believe this is a bug in Spring Boot, please add a comment on that issue. Thank you.