search

kagemomiji / airsonic-advanced

airsonic-advanced
GNU General Public License v3.0
143 stars 13 forks source link

[Bug]: Error creating bean with name 'playerService' and 'playQueueWSController' #345

Closed shutterbug79 closed 5 months ago

shutterbug79 commented 6 months ago

What happened?

Airsonic Advanced crashes on start after a server reboot. Was working like a charm prior to the issue;

2024-01-06 18:03:29.367 INFO --- o.a.player.service.PlayerService : Deleting old players 2024-01-06 18:03:29.569 WARN --- ConfigServletWebServerApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'playQueueWSController': Unsatisfied dependency expressed through field 'playerService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'playerService': Invocation of init method failed; nested exception is org.springframework.dao.InvalidDataAccessApiUsageException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call; nested exception is javax.persistence.TransactionRequiredException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call 2024-01-06 18:03:29.796 ERROR --- o.s.boot.SpringApplication : Application run failed

org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'playQueueWSController': Unsatisfied dependency expressed through field 'playerService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'playerService': Invocation of init method failed; nested exception is org.springframework.dao.InvalidDataAccessApiUsageException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call; nested exception is javax.persistence.TransactionRequiredException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call

Have tried with an old restored database dump, but the error persist.

Help much appreciated!

Steps to reproduce

Sorry, no clue ...

Version

11.1.x (Edge)

Version Detail

airsonic-advanced-11.1.3-SNAPSHOT.20231022132225

Operating System

Ubuntu 22.04.3 LTS

Java Version

OpenJDK Runtime Environment (build 17.0.9+9-Ubuntu-122.04)

Database

PostgreSQL 14.x

DB Detail

No response

Configuration paramter

DatabaseConfigType=embed DatabaseConfigEmbedDriver=org.postgresql.Driver DatabaseConfigEmbedUrl=jdbc:postgresql://localhost:5432/airsonicdb?stringtype=unspecified

Proxy Server

No response

client detail

No response

language

None

Relevant log output

2024-01-06 18:03:00.244  INFO --- org.airsonic.player.Application          : Starting Application v11.1.3-SNAPSHOT using Java 17.0.9 on zoe with PID 65802 (/var/airsonic/airsonic48_20231009.war started by airsonic in /)
2024-01-06 18:03:00.265  INFO --- org.airsonic.player.Application          : No active profile set, falling back to 1 default profile: "default"
2024-01-06 18:03:06.054  INFO --- o.a.p.service.SettingsService            : Java: 17.0.9+9-Ubuntu-122.04, OS: Linux, Memory (max bytes): 709558272
2024-01-06 18:03:06.287  INFO --- org.airsonic.player.Application          : Detected Tomcat web server
2024-01-06 18:03:17.302  INFO --- l.database.core.PostgresDatabase         : Set default schema name to public
2024-01-06 18:03:17.589  INFO --- l.l.StandardLockService                  : Successfully acquired change log lock
2024-01-06 18:03:20.065  INFO --- liquibase.Liquibase                      : Parsed changelog file 'classpath:liquibase/db-changelog.xml'
2024-01-06 18:03:20.161  INFO --- l.c.StandardChangeLogHistoryService      : Reading from public.databasechangelog
2024-01-06 18:03:20.607  INFO --- l.l.StandardLockService                  : Successfully released change log lock
2024-01-06 18:03:20.778  INFO --- l.l.StandardLockService                  : Successfully acquired change log lock
2024-01-06 18:03:21.956  INFO --- l.c.StandardChangeLogHistoryService      : Reading from public.databasechangelog
2024-01-06 18:03:22.201  INFO --- l.c.StandardChangeLogHistoryService      : Reading from public.databasechangelog
2024-01-06 18:03:22.325  INFO --- liquibase.util.ShowSummaryUtil           : UPDATE SUMMARY
2024-01-06 18:03:22.326  INFO --- liquibase.util.ShowSummaryUtil           : Run:                          0
2024-01-06 18:03:22.326  INFO --- liquibase.util.ShowSummaryUtil           : Previously run:             270
2024-01-06 18:03:22.326  INFO --- liquibase.util.ShowSummaryUtil           : Filtered out:                 0
2024-01-06 18:03:22.327  INFO --- liquibase.util.ShowSummaryUtil           : -------------------------------
2024-01-06 18:03:22.328  INFO --- liquibase.util.ShowSummaryUtil           : Total change sets:          270

2024-01-06 18:03:22.331  INFO --- liquibase.util.ShowSummaryUtil           : Update summary generated
2024-01-06 18:03:22.338  INFO --- l.l.StandardLockService                  : Successfully released change log lock
2024-01-06 18:03:22.350  INFO --- l.l.StandardLockService                  : Successfully released change log lock
2024-01-06 18:03:22.352  INFO --- liquibase.command.CommandScope           : Command execution complete
2024-01-06 18:03:29.131  INFO --- o.a.p.s.TaskSchedulingService            : Task podcast-channel-refresh--1 scheduled
2024-01-06 18:03:29.134  INFO --- o.a.p.service.PodcastService             : Automatic default Podcast update scheduled to run every 24 hour(s), starting at 2024-01-06T17:08:29.113853289Z
2024-01-06 18:03:29.167  INFO --- o.a.p.s.TaskSchedulingService            : Task remote-playstatus-cleanup scheduled
2024-01-06 18:03:29.367  INFO --- o.a.player.service.PlayerService         : Deleting old players
2024-01-06 18:03:29.569  WARN --- ConfigServletWebServerApplicationContext : Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'playQueueWSController': Unsatisfied dependency expressed through field 'playerService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'playerService': Invocation of init method failed; nested exception is org.springframework.dao.InvalidDataAccessApiUsageException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call; nested exception is javax.persistence.TransactionRequiredException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call
2024-01-06 18:03:29.796 ERROR --- o.s.boot.SpringApplication               : Application run failed

org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'playQueueWSController': Unsatisfied dependency expressed through field 'playerService'; nested exception is org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'playerService': Invocation of init method failed; nested exception is org.springframework.dao.InvalidDataAccessApiUsageException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call; nested exception is javax.persistence.TransactionRequiredException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.resolveFieldValue(AutowiredAnnotationBeanPostProcessor.java:713) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.inject(AutowiredAnnotationBeanPostProcessor.java:693) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.annotation.InjectionMetadata.inject(InjectionMetadata.java:119) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor.postProcessProperties(AutowiredAnnotationBeanPostProcessor.java:408) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.populateBean(AbstractAutowireCapableBeanFactory.java:1431) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:619) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:335) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.preInstantiateSingletons(DefaultListableBeanFactory.java:955) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.context.support.AbstractApplicationContext.finishBeanFactoryInitialization(AbstractApplicationContext.java:921) ~[spring-context-5.3.30.jar!/:5.3.30]
    at org.springframework.context.support.AbstractApplicationContext.refresh(AbstractApplicationContext.java:583) ~[spring-context-5.3.30.jar!/:5.3.30]
    at org.springframework.boot.web.servlet.context.ServletWebServerApplicationContext.refresh(ServletWebServerApplicationContext.java:147) ~[spring-boot-2.7.16.jar!/:2.7.16]
    at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:731) ~[spring-boot-2.7.16.jar!/:2.7.16]
    at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:408) ~[spring-boot-2.7.16.jar!/:2.7.16]
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:307) ~[spring-boot-2.7.16.jar!/:2.7.16]
    at org.springframework.boot.builder.SpringApplicationBuilder.run(SpringApplicationBuilder.java:164) ~[spring-boot-2.7.16.jar!/:2.7.16]
    at org.airsonic.player.Application.main(Application.java:70) ~[classes!/:11.1.3-SNAPSHOT]
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[na:na]
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
    at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na]
    at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:49) ~[airsonic48_20231009.war:11.1.3-SNAPSHOT]
    at org.springframework.boot.loader.Launcher.launch(Launcher.java:108) ~[airsonic48_20231009.war:11.1.3-SNAPSHOT]
    at org.springframework.boot.loader.Launcher.launch(Launcher.java:58) ~[airsonic48_20231009.war:11.1.3-SNAPSHOT]
    at org.springframework.boot.loader.WarLauncher.main(WarLauncher.java:59) ~[airsonic48_20231009.war:11.1.3-SNAPSHOT]
Caused by: org.springframework.beans.factory.BeanCreationException: Error creating bean with name 'playerService': Invocation of init method failed; nested exception is org.springframework.dao.InvalidDataAccessApiUsageException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call; nested exception is javax.persistence.TransactionRequiredException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call
    at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor.postProcessBeforeInitialization(InitDestroyAnnotationBeanPostProcessor.java:160) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsBeforeInitialization(AbstractAutowireCapableBeanFactory.java:440) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1796) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.doCreateBean(AbstractAutowireCapableBeanFactory.java:620) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:542) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.AbstractBeanFactory.lambda$doGetBean$0(AbstractBeanFactory.java:335) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.DefaultSingletonBeanRegistry.getSingleton(DefaultSingletonBeanRegistry.java:234) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.AbstractBeanFactory.doGetBean(AbstractBeanFactory.java:333) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.AbstractBeanFactory.getBean(AbstractBeanFactory.java:208) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.config.DependencyDescriptor.resolveCandidate(DependencyDescriptor.java:276) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.doResolveDependency(DefaultListableBeanFactory.java:1391) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.support.DefaultListableBeanFactory.resolveDependency(DefaultListableBeanFactory.java:1311) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor$AutowiredFieldElement.resolveFieldValue(AutowiredAnnotationBeanPostProcessor.java:710) ~[spring-beans-5.3.30.jar!/:5.3.30]
    ... 27 common frames omitted
Caused by: org.springframework.dao.InvalidDataAccessApiUsageException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call; nested exception is javax.persistence.TransactionRequiredException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call
    at org.springframework.orm.jpa.EntityManagerFactoryUtils.convertJpaAccessExceptionIfPossible(EntityManagerFactoryUtils.java:403) ~[spring-orm-5.3.30.jar!/:5.3.30]
    at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:235) ~[spring-orm-5.3.30.jar!/:5.3.30]
    at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.translateExceptionIfPossible(AbstractEntityManagerFactoryBean.java:551) ~[spring-orm-5.3.30.jar!/:5.3.30]
    at org.springframework.dao.support.ChainedPersistenceExceptionTranslator.translateExceptionIfPossible(ChainedPersistenceExceptionTranslator.java:61) ~[spring-tx-5.3.30.jar!/:5.3.30]
    at org.springframework.dao.support.DataAccessUtils.translateIfNecessary(DataAccessUtils.java:243) ~[spring-tx-5.3.30.jar!/:5.3.30]
    at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:152) ~[spring-tx-5.3.30.jar!/:5.3.30]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.30.jar!/:5.3.30]
    at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:145) ~[spring-data-jpa-2.7.16.jar!/:2.7.16]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.30.jar!/:5.3.30]
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97) ~[spring-aop-5.3.30.jar!/:5.3.30]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.30.jar!/:5.3.30]
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:241) ~[spring-aop-5.3.30.jar!/:5.3.30]
    at jdk.proxy2/jdk.proxy2.$Proxy219.deleteAllByNameIsNullAndClientIdIsNullAndLastSeenBefore(Unknown Source) ~[na:na]
    at org.airsonic.player.service.PlayerService.deleteOldPlayers(PlayerService.java:115) ~[classes!/:11.1.3-SNAPSHOT]
    at org.airsonic.player.service.PlayerService.init_aroundBody0(PlayerService.java:88) ~[classes!/:11.1.3-SNAPSHOT]
    at org.airsonic.player.service.PlayerService$AjcClosure1.run(PlayerService.java:1) ~[classes!/:11.1.3-SNAPSHOT]
    at org.springframework.transaction.aspectj.AbstractTransactionAspect.ajc$around$org_springframework_transaction_aspectj_AbstractTransactionAspect$1$2a73e96cproceed(AbstractTransactionAspect.aj:67) ~[spring-aspects-5.3.30.jar!/:5.3.30]
    at org.springframework.transaction.aspectj.AbstractTransactionAspect$AbstractTransactionAspect$1.proceedWithInvocation(AbstractTransactionAspect.aj:73) ~[spring-aspects-5.3.30.jar!/:5.3.30]
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388) ~[spring-tx-5.3.30.jar!/:5.3.30]
    at org.springframework.transaction.aspectj.AbstractTransactionAspect.ajc$around$org_springframework_transaction_aspectj_AbstractTransactionAspect$1$2a73e96c(AbstractTransactionAspect.aj:71) ~[spring-aspects-5.3.30.jar!/:5.3.30]
    at org.airsonic.player.service.PlayerService.init(PlayerService.java:86) ~[classes!/:11.1.3-SNAPSHOT]
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[na:na]
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
    at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na]
    at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleElement.invoke(InitDestroyAnnotationBeanPostProcessor.java:389) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor$LifecycleMetadata.invokeInitMethods(InitDestroyAnnotationBeanPostProcessor.java:333) ~[spring-beans-5.3.30.jar!/:5.3.30]
    at org.springframework.beans.factory.annotation.InitDestroyAnnotationBeanPostProcessor.postProcessBeforeInitialization(InitDestroyAnnotationBeanPostProcessor.java:157) ~[spring-beans-5.3.30.jar!/:5.3.30]
    ... 39 common frames omitted
Caused by: javax.persistence.TransactionRequiredException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call
    at org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:299) ~[spring-orm-5.3.30.jar!/:5.3.30]
    at jdk.proxy2/jdk.proxy2.$Proxy195.remove(Unknown Source) ~[na:na]
    at org.springframework.data.jpa.repository.query.JpaQueryExecution$DeleteExecution.doExecute(JpaQueryExecution.java:277) ~[spring-data-jpa-2.7.16.jar!/:2.7.16]
    at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:90) ~[spring-data-jpa-2.7.16.jar!/:2.7.16]
    at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:156) ~[spring-data-jpa-2.7.16.jar!/:2.7.16]
    at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:144) ~[spring-data-jpa-2.7.16.jar!/:2.7.16]
    at org.springframework.data.repository.core.support.RepositoryMethodInvoker.doInvoke(RepositoryMethodInvoker.java:137) ~[spring-data-commons-2.7.16.jar!/:2.7.16]
    at org.springframework.data.repository.core.support.RepositoryMethodInvoker.invoke(RepositoryMethodInvoker.java:121) ~[spring-data-commons-2.7.16.jar!/:2.7.16]
    at org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.doInvoke(QueryExecutorMethodInterceptor.java:160) ~[spring-data-commons-2.7.16.jar!/:2.7.16]
    at org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.invoke(QueryExecutorMethodInterceptor.java:139) ~[spring-data-commons-2.7.16.jar!/:2.7.16]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.30.jar!/:5.3.30]
    at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:76) ~[spring-data-commons-2.7.16.jar!/:2.7.16]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.30.jar!/:5.3.30]
    at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123) ~[spring-tx-5.3.30.jar!/:5.3.30]
    at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388) ~[spring-tx-5.3.30.jar!/:5.3.30]
    at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.30.jar!/:5.3.30]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.30.jar!/:5.3.30]
    at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:137) ~[spring-tx-5.3.30.jar!/:5.3.30]
    ... 61 common frames omitted
kagemomiji commented 6 months ago

@shutterbug79

It seems that this error is similar to the #306. According to the indicated version, the issue should have been resolved already.

In that version, the log should display "Started Application in xx seconds" followed by "Deleting old players." However, in the provided log, "Deleting old players" appears before the "Application run failed" log. Could you please confirm if there is no mistake in the version being used?

Here's the expected log sequence for reference:

2024-01-09 22:20:27.111 [main]  INFO --- org.airsonic.player.Application          : Started Application in 22.461 seconds (JVM running for 23.146)
2024-01-09 22:20:27.132 [main]  INFO --- o.a.player.service.PlayerService         : Deleting old players
2024-01-09 22:20:27.204 [main]  INFO --- o.a.player.service.PlayerService         : Complete Deleting old players
masterblaster79 commented 6 months ago

Hi. I don't have the exact same error, but also here airsonic is not starting anymore and I see "org.springframework.dao.InvalidDataAccessApiUsageException: No EntityManager with actual transaction available for current thread":

catalina.out:

[2024-01-11 08:58:14] [info] 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
[2024-01-11 08:58:15] [info] Server version name:   Apache Tomcat/9.0.58 (Ubuntu)
[2024-01-11 08:58:15] [info] Server built:          Jan 6 1970 15:09:28 UTC
[2024-01-11 08:58:15] [info] Server version number: 9.0.58.0
[2024-01-11 08:58:15] [info] OS Name:               Linux
[2024-01-11 08:58:15] [info] OS Version:            6.5.11-7-pve
[2024-01-11 08:58:15] [info] Architecture:          amd64
[2024-01-11 08:58:15] [info] Java Home:             /usr/lib/jvm/java-17-openjdk-amd64
[2024-01-11 08:58:15] [info] JVM Version:           17.0.9+9-Ubuntu-122.04
[2024-01-11 08:58:15] [info] JVM Vendor:            Private Build
[2024-01-11 08:58:15] [info] CATALINA_BASE:         /var/lib/tomcat9
[2024-01-11 08:58:15] [info] CATALINA_HOME:         /usr/share/tomcat9
[2024-01-11 08:58:15] [info] Command line argument: --add-opens=java.base/java.lang=ALL-UNNAMED
[2024-01-11 08:58:15] [info] Command line argument: --add-opens=java.base/java.io=ALL-UNNAMED
[2024-01-11 08:58:15] [info] Command line argument: --add-opens=java.base/java.util=ALL-UNNAMED
[2024-01-11 08:58:15] [info] Command line argument: --add-opens=java.base/java.util.concurrent=ALL-UNNAMED
[2024-01-11 08:58:15] [info] Command line argument: --add-opens=java.rmi/sun.rmi.transport=ALL-UNNAMED
[2024-01-11 08:58:15] [info] Command line argument: -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.properties
[2024-01-11 08:58:15] [info] Command line argument: -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
[2024-01-11 08:58:15] [info] Command line argument: -Djava.awt.headless=true
[2024-01-11 08:58:15] [info] Command line argument: -Xmx1024m
[2024-01-11 08:58:15] [info] Command line argument: -Xms1024m
[2024-01-11 08:58:15] [info] Command line argument: -Djdk.tls.ephemeralDHKeySize=2048
[2024-01-11 08:58:15] [info] Command line argument: -Djava.protocol.handler.pkgs=org.apache.catalina.webresources
[2024-01-11 08:58:15] [info] Command line argument: -Dorg.apache.catalina.security.SecurityListener.UMASK=0027
[2024-01-11 08:58:15] [info] Command line argument: -Dignore.endorsed.dirs=
[2024-01-11 08:58:15] [info] Command line argument: -Dcatalina.base=/var/lib/tomcat9
[2024-01-11 08:58:15] [info] Command line argument: -Dcatalina.home=/usr/share/tomcat9
[2024-01-11 08:58:15] [info] Command line argument: -Djava.io.tmpdir=/tmp
[2024-01-11 08:58:15] [info] Loaded Apache Tomcat Native library [1.2.31] using APR version [1.7.0].
[2024-01-11 08:58:15] [info] APR capabilities: IPv6 [true], sendfile [true], accept filters [false], random [true], UDS [true].
[2024-01-11 08:58:15] [info] APR/OpenSSL configuration: useAprConnector [false], useOpenSSL [true]
[2024-01-11 08:58:15] [info] OpenSSL successfully initialized [OpenSSL 3.0.2 15 Mar 2022]
[2024-01-11 08:58:15] [info] Initializing ProtocolHandler ["http-nio-8080"]
[2024-01-11 08:58:15] [info] Server initialization in [590] milliseconds
[2024-01-11 08:58:15] [info] Starting service [Catalina]
[2024-01-11 08:58:15] [info] Starting Servlet engine: [Apache Tomcat/9.0.58 (Ubuntu)]
[2024-01-11 08:58:15] [info] Deploying web application archive [/var/lib/tomcat9/webapps/airsonic.war]
[2024-01-11 08:58:21] [warning] Name = jpsonicDB Property maxActive is not used in DBCP2, use maxTotal instead. maxTotal default value is 8. You have set value of "20" for "maxActive" property, which is being ignored.
[2024-01-11 08:58:21] [warning] Name = jpsonicDB Property maxWait is not used in DBCP2 , use maxWaitMillis instead. maxWaitMillis default value is PT-0.001S. You have set value of "10000" for "maxWait" property, which is being ignored.
[2024-01-11 08:58:21] [warning] Name = airsonicDB Property maxActive is not used in DBCP2, use maxTotal instead. maxTotal default value is 8. You have set value of "20" for "maxActive" property, which is being ignored.
[2024-01-11 08:58:21] [warning] Name = airsonicDB Property maxWait is not used in DBCP2 , use maxWaitMillis instead. maxWaitMillis default value is PT-0.001S. You have set value of "10000" for "maxWait" property, which is being ignored.
[2024-01-11 08:58:21] [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.
[2024-01-11 08:58:23] [info]            _                       _
[2024-01-11 08:58:23] [info]      /\   (_)                     (_)
[2024-01-11 08:58:23] [info]     /  \   _ _ __  ___  ___  _ __  _  ___
[2024-01-11 08:58:23] [info]    / /\ \ | | '__|/ __|/ _ \| '_ \| |/ __|
[2024-01-11 08:58:23] [info]   / ____ \| | |   \__ \ (_) | | | | | (__
[2024-01-11 08:58:23] [info]  /_/    \_\_|_|   |___/\___/|_| |_|_|\___|
[2024-01-11 08:58:23] [info]                                                
[2024-01-11 08:58:23] [info]                         11.1.3-SNAPSHOT
[2024-01-11 08:58:23] [info] 2024-01-11 08:58:23.443  INFO --- org.airsonic.player.Application          : Starting Application v11.1.3-SNAPSHOT using Java 17.0.9 on music with PID 909 (/var/lib/tomcat9/webapps/airsonic/WEB-INF/classes started by tomcat in /var/lib/tomcat9)
[2024-01-11 08:58:23] [info] 2024-01-11 08:58:23.446  INFO --- org.airsonic.player.Application          : No active profile set, falling back to 1 default profile: "default"
[2024-01-11 08:58:26] [info] 2024-01-11 08:58:26.558  INFO --- o.a.p.service.SettingsService            : Java: 17.0.9+9-Ubuntu-122.04, OS: Linux, Memory (max bytes): 1073741824
[2024-01-11 08:58:29] [info] 2024-01-11 08:58:29.002  INFO --- l.database.core.PostgresDatabase         : Set default schema name to public
[2024-01-11 08:58:29] [info] 2024-01-11 08:58:29.100  INFO --- l.l.StandardLockService                  : Successfully acquired change log lock
[2024-01-11 08:58:30] [info] 2024-01-11 08:58:30.646  INFO --- liquibase.Liquibase                      : Parsed changelog file 'classpath:liquibase/db-changelog.xml'
[2024-01-11 08:58:30] [info] 2024-01-11 08:58:30.694  INFO --- l.c.StandardChangeLogHistoryService      : Reading from public.databasechangelog
[2024-01-11 08:58:30] [info] 2024-01-11 08:58:30.929  INFO --- l.l.StandardLockService                  : Successfully released change log lock
[2024-01-11 08:58:31] [info] 2024-01-11 08:58:31.046  INFO --- l.l.StandardLockService                  : Successfully acquired change log lock
[2024-01-11 08:58:31] [info] 2024-01-11 08:58:31.676  INFO --- l.c.StandardChangeLogHistoryService      : Reading from public.databasechangelog
[2024-01-11 08:58:31] [info] Database is up to date, no changesets to execute
[2024-01-11 08:58:31] [info] 2024-01-11 08:58:31.819  INFO --- l.c.StandardChangeLogHistoryService      : Reading from public.databasechangelog
[2024-01-11 08:58:31] [info] 2024-01-11 08:58:31.898  INFO --- liquibase.util.ShowSummaryUtil           : UPDATE SUMMARY
[2024-01-11 08:58:31] [info] 2024-01-11 08:58:31.898  INFO --- liquibase.util.ShowSummaryUtil           : Run:                          0
[2024-01-11 08:58:31] [info] 2024-01-11 08:58:31.899  INFO --- liquibase.util.ShowSummaryUtil           : Previously run:             275
[2024-01-11 08:58:31] [info] 2024-01-11 08:58:31.899  INFO --- liquibase.util.ShowSummaryUtil           : Filtered out:                 0
[2024-01-11 08:58:31] [info] 2024-01-11 08:58:31.899  INFO --- liquibase.util.ShowSummaryUtil           : -------------------------------
[2024-01-11 08:58:31] [info] 2024-01-11 08:58:31.899  INFO --- liquibase.util.ShowSummaryUtil           : Total change sets:          275
[2024-01-11 08:58:31] [info] UPDATE SUMMARY
[2024-01-11 08:58:31] [info] Run:                          0
[2024-01-11 08:58:31] [info] Previously run:             275
[2024-01-11 08:58:31] [info] Filtered out:                 0
[2024-01-11 08:58:31] [info] -------------------------------
[2024-01-11 08:58:31] [info] Total change sets:          275
[2024-01-11 08:58:31] [info] 2024-01-11 08:58:31.900  INFO --- liquibase.util.ShowSummaryUtil           : Update summary generated
[2024-01-11 08:58:31] [info] 2024-01-11 08:58:31.938  INFO --- l.l.StandardLockService                  : Successfully released change log lock
[2024-01-11 08:58:31] [info] 2024-01-11 08:58:31.946  INFO --- l.l.StandardLockService                  : Successfully released change log lock
[2024-01-11 08:58:31] [info] 2024-01-11 08:58:31.948  INFO --- liquibase.command.CommandScope           : Command execution complete
[2024-01-11 08:58:37] [info] 2024-01-11 08:58:37.083  INFO --- o.a.player.service.UPnPService           : Starting UPnP service...
[2024-01-11 08:58:37] [info] 2024-01-11 08:58:37.172  INFO --- o.a.player.service.UPnPService           : Successfully started UPnP service on port 4041!
[2024-01-11 08:58:37] [info] 2024-01-11 08:58:37.243  INFO --- o.a.player.service.UPnPService           : Enabling UPnP/DLNA media server
[2024-01-11 08:58:37] [info] 2024-01-11 08:58:37.264  INFO --- o.a.p.service.DatabaseService            : Automatic DB backup disabled
[2024-01-11 08:58:37] [info] 2024-01-11 08:58:37.397  INFO --- o.a.p.s.search.IndexManager              : Index was found (index version 19).
[2024-01-11 08:58:37] [info] 2024-01-11 08:58:37.406  INFO --- o.a.p.s.TaskSchedulingService            : Task mediascanner-IndexingTask scheduled
[2024-01-11 08:58:37] [info] 2024-01-11 08:58:37.406  INFO --- o.a.p.s.MediaScannerService              : Automatic media library scanning scheduled to run every 1 day(s), starting at 2024-01-12T03:00:00.400124040
[2024-01-11 08:58:39] [info] 2024-01-11 08:58:39.575  INFO --- org.airsonic.player.Application          : Detected Tomcat web server
[2024-01-11 08:58:40] [info] 2024-01-11 08:58:40.256  INFO --- org.airsonic.player.Application          : Started Application in 17.988 seconds (JVM running for 25.503)
[2024-01-11 08:58:40] [info] 2024-01-11 08:58:40.275  INFO --- o.a.player.service.PlayerService         : Deleting old players
[2024-01-11 08:58:40] [info] 2024-01-11 08:58:40.441 ERROR --- o.s.boot.SpringApplication               : Application run failed
[2024-01-11 08:58:40] [info] org.springframework.dao.InvalidDataAccessApiUsageException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call; nested exception is javax.persistence.TransactionRequiredException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call
[2024-01-11 08:58:40] [info] #011at org.springframework.orm.jpa.EntityManagerFactoryUtils.convertJpaAccessExceptionIfPossible(EntityManagerFactoryUtils.java:403) ~[spring-orm-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:235) ~[spring-orm-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.translateExceptionIfPossible(AbstractEntityManagerFactoryBean.java:551) ~[spring-orm-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.dao.support.ChainedPersistenceExceptionTranslator.translateExceptionIfPossible(ChainedPersistenceExceptionTranslator.java:61) ~[spring-tx-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.dao.support.DataAccessUtils.translateIfNecessary(DataAccessUtils.java:243) ~[spring-tx-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:152) ~[spring-tx-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:145) ~[spring-data-jpa-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97) ~[spring-aop-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:241) ~[spring-aop-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at jdk.proxy3/jdk.proxy3.$Proxy223.deleteAllByNameIsNullAndClientIdIsNullAndLastSeenBefore(Unknown Source) ~[na:na]
[2024-01-11 08:58:40] [info] #011at org.airsonic.player.service.PlayerService.deleteOldPlayers(PlayerService.java:112) ~[classes/:11.1.3-SNAPSHOT]
[2024-01-11 08:58:40] [info] #011at org.airsonic.player.service.PlayerService.onApplicationEvent(PlayerService.java:85) ~[classes/:11.1.3-SNAPSHOT]
[2024-01-11 08:58:40] [info] #011at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
[2024-01-11 08:58:40] [info] #011at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[na:na]
[2024-01-11 08:58:40] [info] #011at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
[2024-01-11 08:58:40] [info] #011at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na]
[2024-01-11 08:58:40] [info] #011at org.springframework.context.event.ApplicationListenerMethodAdapter.doInvoke(ApplicationListenerMethodAdapter.java:344) ~[spring-context-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.context.event.ApplicationListenerMethodAdapter.processEvent(ApplicationListenerMethodAdapter.java:229) ~[spring-context-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.context.event.ApplicationListenerMethodAdapter.onApplicationEvent(ApplicationListenerMethodAdapter.java:166) ~[spring-context-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:178) ~[spring-context-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:171) ~[spring-context-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:145) ~[spring-context-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:429) ~[spring-context-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:386) ~[spring-context-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.boot.context.event.EventPublishingRunListener.ready(EventPublishingRunListener.java:114) ~[spring-boot-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.boot.SpringApplicationRunListeners.lambda$ready$6(SpringApplicationRunListeners.java:82) ~[spring-boot-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at java.base/java.util.ArrayList.forEach(ArrayList.java:1511) ~[na:na]
[2024-01-11 08:58:40] [info] #011at org.springframework.boot.SpringApplicationRunListeners.doWithListeners(SpringApplicationRunListeners.java:120) ~[spring-boot-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.boot.SpringApplicationRunListeners.doWithListeners(SpringApplicationRunListeners.java:114) ~[spring-boot-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.boot.SpringApplicationRunListeners.ready(SpringApplicationRunListeners.java:82) ~[spring-boot-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.boot.SpringApplication.run(SpringApplication.java:323) ~[spring-boot-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.boot.web.servlet.support.SpringBootServletInitializer.run(SpringBootServletInitializer.java:175) ~[spring-boot-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.boot.web.servlet.support.SpringBootServletInitializer.createRootApplicationContext(SpringBootServletInitializer.java:155) ~[spring-boot-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.boot.web.servlet.support.SpringBootServletInitializer.onStartup(SpringBootServletInitializer.java:97) ~[spring-boot-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.web.SpringServletContainerInitializer.onStartup(SpringServletContainerInitializer.java:174) ~[spring-web-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5219) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:726) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:698) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:696) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:1024) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1911) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) ~[na:na]
[2024-01-11 08:58:40] [info] #011at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[na:na]
[2024-01-11 08:58:40] [info] #011at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75) ~[tomcat9-util-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:123) ~[na:na]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:825) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:475) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1618) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:319) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:423) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.util.LifecycleBase.setState(LifecycleBase.java:366) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:946) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:835) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1396) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1386) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[na:na]
[2024-01-11 08:58:40] [info] #011at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75) ~[tomcat9-util-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:145) ~[na:na]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:919) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:263) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.core.StandardService.startInternal(StandardService.java:432) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:927) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.startup.Catalina.start(Catalina.java:772) ~[tomcat9-catalina-9.0.58.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
[2024-01-11 08:58:40] [info] #011at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[na:na]
[2024-01-11 08:58:40] [info] #011at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
[2024-01-11 08:58:40] [info] #011at java.base/java.lang.reflect.Method.invoke(Method.java:568) ~[na:na]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:345) ~[bootstrap.jar:9.0.58]
[2024-01-11 08:58:40] [info] #011at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:480) ~[bootstrap.jar:9.0.58]
[2024-01-11 08:58:40] [info] Caused by: javax.persistence.TransactionRequiredException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call
[2024-01-11 08:58:40] [info] #011at org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:299) ~[spring-orm-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at jdk.proxy3/jdk.proxy3.$Proxy198.remove(Unknown Source) ~[na:na]
[2024-01-11 08:58:40] [info] #011at org.springframework.data.jpa.repository.query.JpaQueryExecution$DeleteExecution.doExecute(JpaQueryExecution.java:277) ~[spring-data-jpa-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:90) ~[spring-data-jpa-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:156) ~[spring-data-jpa-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:144) ~[spring-data-jpa-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.data.repository.core.support.RepositoryMethodInvoker.doInvoke(RepositoryMethodInvoker.java:137) ~[spring-data-commons-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.data.repository.core.support.RepositoryMethodInvoker.invoke(RepositoryMethodInvoker.java:121) ~[spring-data-commons-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.doInvoke(QueryExecutorMethodInterceptor.java:160) ~[spring-data-commons-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.invoke(QueryExecutorMethodInterceptor.java:139) ~[spring-data-commons-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:76) ~[spring-data-commons-2.7.18.jar:2.7.18]
[2024-01-11 08:58:40] [info] #011at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123) ~[spring-tx-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388) ~[spring-tx-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:137) ~[spring-tx-5.3.31.jar:5.3.31]
[2024-01-11 08:58:40] [info] #011... 72 common frames omitted
[2024-01-11 08:58:40] [crit] Error deploying web application archive [/var/lib/tomcat9/webapps/airsonic.war]
[2024-01-11 08:58:40] [crit] java.lang.IllegalStateException: Error starting child
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:729)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.core.ContainerBase.addChild(ContainerBase.java:698)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.core.StandardHost.addChild(StandardHost.java:696)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.startup.HostConfig.deployWAR(HostConfig.java:1024)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.startup.HostConfig$DeployWar.run(HostConfig.java:1911)
[2024-01-11 08:58:40] [crit]     at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
[2024-01-11 08:58:40] [crit]     at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
[2024-01-11 08:58:40] [crit]     at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
[2024-01-11 08:58:40] [crit]     at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:123)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.startup.HostConfig.deployWARs(HostConfig.java:825)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.startup.HostConfig.deployApps(HostConfig.java:475)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.startup.HostConfig.start(HostConfig.java:1618)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.startup.HostConfig.lifecycleEvent(HostConfig.java:319)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.util.LifecycleBase.fireLifecycleEvent(LifecycleBase.java:123)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.util.LifecycleBase.setStateInternal(LifecycleBase.java:423)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.util.LifecycleBase.setState(LifecycleBase.java:366)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:946)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.core.StandardHost.startInternal(StandardHost.java:835)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1396)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.core.ContainerBase$StartChild.call(ContainerBase.java:1386)
[2024-01-11 08:58:40] [crit]     at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
[2024-01-11 08:58:40] [crit]     at org.apache.tomcat.util.threads.InlineExecutorService.execute(InlineExecutorService.java:75)
[2024-01-11 08:58:40] [crit]     at java.base/java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:145)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.core.ContainerBase.startInternal(ContainerBase.java:919)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.core.StandardEngine.startInternal(StandardEngine.java:263)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.core.StandardService.startInternal(StandardService.java:432)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.core.StandardServer.startInternal(StandardServer.java:927)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.startup.Catalina.start(Catalina.java:772)
[2024-01-11 08:58:40] [crit]     at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2024-01-11 08:58:40] [crit]     at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
[2024-01-11 08:58:40] [crit]     at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2024-01-11 08:58:40] [crit]     at java.base/java.lang.reflect.Method.invoke(Method.java:568)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:345)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:480)
[2024-01-11 08:58:40] [crit] Caused by: org.apache.catalina.LifecycleException: Failed to start component [StandardEngine[Catalina].StandardHost[localhost].StandardContext[/airsonic]]
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.util.LifecycleBase.handleSubClassException(LifecycleBase.java:440)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:198)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.core.ContainerBase.addChildInternal(ContainerBase.java:726)
[2024-01-11 08:58:40] [crit]     ... 37 more
[2024-01-11 08:58:40] [crit] Caused by: org.springframework.dao.InvalidDataAccessApiUsageException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call; nested exception is javax.persistence.TransactionRequiredException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call
[2024-01-11 08:58:40] [crit]     at org.springframework.orm.jpa.EntityManagerFactoryUtils.convertJpaAccessExceptionIfPossible(EntityManagerFactoryUtils.java:403)
[2024-01-11 08:58:40] [crit]     at org.springframework.orm.jpa.vendor.HibernateJpaDialect.translateExceptionIfPossible(HibernateJpaDialect.java:235)
[2024-01-11 08:58:40] [crit]     at org.springframework.orm.jpa.AbstractEntityManagerFactoryBean.translateExceptionIfPossible(AbstractEntityManagerFactoryBean.java:551)
[2024-01-11 08:58:40] [crit]     at org.springframework.dao.support.ChainedPersistenceExceptionTranslator.translateExceptionIfPossible(ChainedPersistenceExceptionTranslator.java:61)
[2024-01-11 08:58:40] [crit]     at org.springframework.dao.support.DataAccessUtils.translateIfNecessary(DataAccessUtils.java:243)
[2024-01-11 08:58:40] [crit]     at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:152)
[2024-01-11 08:58:40] [crit]     at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
[2024-01-11 08:58:40] [crit]     at org.springframework.data.jpa.repository.support.CrudMethodMetadataPostProcessor$CrudMethodMetadataPopulatingMethodInterceptor.invoke(CrudMethodMetadataPostProcessor.java:145)
[2024-01-11 08:58:40] [crit]     at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
[2024-01-11 08:58:40] [crit]     at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:97)
[2024-01-11 08:58:40] [crit]     at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
[2024-01-11 08:58:40] [crit]     at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:241)
[2024-01-11 08:58:40] [crit]     at jdk.proxy3/jdk.proxy3.$Proxy223.deleteAllByNameIsNullAndClientIdIsNullAndLastSeenBefore(Unknown Source)
[2024-01-11 08:58:40] [crit]     at org.airsonic.player.service.PlayerService.deleteOldPlayers(PlayerService.java:112)
[2024-01-11 08:58:40] [crit]     at org.airsonic.player.service.PlayerService.onApplicationEvent(PlayerService.java:85)
[2024-01-11 08:58:40] [crit]     at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[2024-01-11 08:58:40] [crit]     at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
[2024-01-11 08:58:40] [crit]     at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[2024-01-11 08:58:40] [crit]     at java.base/java.lang.reflect.Method.invoke(Method.java:568)
[2024-01-11 08:58:40] [crit]     at org.springframework.context.event.ApplicationListenerMethodAdapter.doInvoke(ApplicationListenerMethodAdapter.java:344)
[2024-01-11 08:58:40] [crit]     at org.springframework.context.event.ApplicationListenerMethodAdapter.processEvent(ApplicationListenerMethodAdapter.java:229)
[2024-01-11 08:58:40] [crit]     at org.springframework.context.event.ApplicationListenerMethodAdapter.onApplicationEvent(ApplicationListenerMethodAdapter.java:166)
[2024-01-11 08:58:40] [crit]     at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:178)
[2024-01-11 08:58:40] [crit]     at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:171)
[2024-01-11 08:58:40] [crit]     at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:145)
[2024-01-11 08:58:40] [crit]     at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:429)
[2024-01-11 08:58:40] [crit]     at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:386)
[2024-01-11 08:58:40] [crit]     at org.springframework.boot.context.event.EventPublishingRunListener.ready(EventPublishingRunListener.java:114)
[2024-01-11 08:58:40] [crit]     at org.springframework.boot.SpringApplicationRunListeners.lambda$ready$6(SpringApplicationRunListeners.java:82)
[2024-01-11 08:58:40] [crit]     at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
[2024-01-11 08:58:40] [crit]     at org.springframework.boot.SpringApplicationRunListeners.doWithListeners(SpringApplicationRunListeners.java:120)
[2024-01-11 08:58:40] [crit]     at org.springframework.boot.SpringApplicationRunListeners.doWithListeners(SpringApplicationRunListeners.java:114)
[2024-01-11 08:58:40] [crit]     at org.springframework.boot.SpringApplicationRunListeners.ready(SpringApplicationRunListeners.java:82)
[2024-01-11 08:58:40] [crit]     at org.springframework.boot.SpringApplication.run(SpringApplication.java:323)
[2024-01-11 08:58:40] [crit]     at org.springframework.boot.web.servlet.support.SpringBootServletInitializer.run(SpringBootServletInitializer.java:175)
[2024-01-11 08:58:40] [crit]     at org.springframework.boot.web.servlet.support.SpringBootServletInitializer.createRootApplicationContext(SpringBootServletInitializer.java:155)
[2024-01-11 08:58:40] [crit]     at org.springframework.boot.web.servlet.support.SpringBootServletInitializer.onStartup(SpringBootServletInitializer.java:97)
[2024-01-11 08:58:40] [crit]     at org.springframework.web.SpringServletContainerInitializer.onStartup(SpringServletContainerInitializer.java:174)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.core.StandardContext.startInternal(StandardContext.java:5219)
[2024-01-11 08:58:40] [crit]     at org.apache.catalina.util.LifecycleBase.start(LifecycleBase.java:183)
[2024-01-11 08:58:40] [crit]     ... 38 more
[2024-01-11 08:58:40] [crit] Caused by: javax.persistence.TransactionRequiredException: No EntityManager with actual transaction available for current thread - cannot reliably process 'remove' call
[2024-01-11 08:58:40] [crit]     at org.springframework.orm.jpa.SharedEntityManagerCreator$SharedEntityManagerInvocationHandler.invoke(SharedEntityManagerCreator.java:299)
[2024-01-11 08:58:40] [crit]     at jdk.proxy3/jdk.proxy3.$Proxy198.remove(Unknown Source)
[2024-01-11 08:58:40] [crit]     at org.springframework.data.jpa.repository.query.JpaQueryExecution$DeleteExecution.doExecute(JpaQueryExecution.java:277)
[2024-01-11 08:58:40] [crit]     at org.springframework.data.jpa.repository.query.JpaQueryExecution.execute(JpaQueryExecution.java:90)
[2024-01-11 08:58:40] [crit]     at org.springframework.data.jpa.repository.query.AbstractJpaQuery.doExecute(AbstractJpaQuery.java:156)
[2024-01-11 08:58:40] [crit]     at org.springframework.data.jpa.repository.query.AbstractJpaQuery.execute(AbstractJpaQuery.java:144)
[2024-01-11 08:58:40] [crit]     at org.springframework.data.repository.core.support.RepositoryMethodInvoker.doInvoke(RepositoryMethodInvoker.java:137)
[2024-01-11 08:58:40] [crit]     at org.springframework.data.repository.core.support.RepositoryMethodInvoker.invoke(RepositoryMethodInvoker.java:121)
[2024-01-11 08:58:40] [crit]     at org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.doInvoke(QueryExecutorMethodInterceptor.java:160)
[2024-01-11 08:58:40] [crit]     at org.springframework.data.repository.core.support.QueryExecutorMethodInterceptor.invoke(QueryExecutorMethodInterceptor.java:139)
[2024-01-11 08:58:40] [crit]     at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
[2024-01-11 08:58:40] [crit]     at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:76)
[2024-01-11 08:58:40] [crit]     at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
[2024-01-11 08:58:40] [crit]     at org.springframework.transaction.interceptor.TransactionInterceptor$1.proceedWithInvocation(TransactionInterceptor.java:123)
[2024-01-11 08:58:40] [crit]     at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:388)
[2024-01-11 08:58:40] [crit]     at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119)
[2024-01-11 08:58:40] [crit]     at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
[2024-01-11 08:58:40] [crit]     at org.springframework.dao.support.PersistenceExceptionTranslationInterceptor.invoke(PersistenceExceptionTranslationInterceptor.java:137)
[2024-01-11 08:58:40] [crit]     ... 72 more
[2024-01-11 08:58:40] [info] Deployment of web application archive [/var/lib/tomcat9/webapps/airsonic.war] has finished in [24,874] ms
[2024-01-11 08:58:40] [info] Deploying web application directory [/var/lib/tomcat9/webapps/ROOT]
[2024-01-11 08:58:41] [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.
[2024-01-11 08:58:41] [info] Deployment of web application directory [/var/lib/tomcat9/webapps/ROOT] has finished in [654] ms
[2024-01-11 08:58:41] [info] Starting ProtocolHandler ["http-nio-8080"]
[2024-01-11 08:58:41] [info] Server startup in [25603] milliseconds

This is an lxc container on Proxmox and everything was fine until now.

root@music:~# cat /etc/lsb-release 
DISTRIB_ID=Ubuntu
DISTRIB_RELEASE=22.04
DISTRIB_CODENAME=jammy
DISTRIB_DESCRIPTION="Ubuntu 22.04.3 LTS"
root@music:~# dpkg -l | grep -Ei jdk\|tomcat
ii  default-jdk                       2:1.11-72build2                         amd64        Standard Java or Java compatible Development Kit
ii  default-jdk-headless              2:1.11-72build2                         amd64        Standard Java or Java compatible Development Kit (headless)
ii  libtcnative-1:amd64               1.2.31-1build1                          amd64        Tomcat native library using the Apache Portable Runtime
ii  libtomcat9-java                   9.0.58-1ubuntu0.1                       all          Apache Tomcat 9 - Servlet and JSP engine -- core libraries
ii  openjdk-11-jdk:amd64              11.0.21+9-0ubuntu1~22.04                amd64        OpenJDK Development Kit (JDK)
ii  openjdk-11-jdk-headless:amd64     11.0.21+9-0ubuntu1~22.04                amd64        OpenJDK Development Kit (JDK) (headless)
ii  openjdk-11-jre:amd64              11.0.21+9-0ubuntu1~22.04                amd64        OpenJDK Java runtime, using Hotspot JIT
ii  openjdk-11-jre-headless:amd64     11.0.21+9-0ubuntu1~22.04                amd64        OpenJDK Java runtime, using Hotspot JIT (headless)
ii  openjdk-17-jdk-headless:amd64     17.0.9+9-1~22.04                        amd64        OpenJDK Development Kit (JDK) (headless)
ii  openjdk-17-jre-headless:amd64     17.0.9+9-1~22.04                        amd64        OpenJDK Java runtime, using Hotspot JIT (headless)
ii  tomcat9                           9.0.58-1ubuntu0.1                       all          Apache Tomcat 9 - Servlet and JSP engine
ii  tomcat9-common                    9.0.58-1ubuntu0.1                       all          Apache Tomcat 9 - Servlet and JSP engine -- common files
root@music:~# uname -a
Linux music 6.5.11-7-pve #1 SMP PREEMPT_DYNAMIC PMX 6.5.11-7 (2023-12-05T09:44Z) x86_64 x86_64 x86_64 GNU/Linux
root@music:~# ps aux | grep ^tomcat
tomcat       909  0.0 25.8 4830184 1085348 ?     Ssl  08:58   1:15 /usr/lib/jvm/java-17-openjdk-amd64/bin/java -Djava.util.logging.config.file=/var/lib/tomcat9/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.awt.headless=true -Xmx1024m -Xms1024m -Djdk.tls.ephemeralDHKeySize=2048 -Djava.protocol.handler.pkgs=org.apache.catalina.webresources -Dorg.apache.catalina.security.SecurityListener.UMASK=0027 -Dignore.endorsed.dirs= -classpath /usr/share/tomcat9/bin/bootstrap.jar:/usr/share/tomcat9/bin/tomcat-juli.jar -Dcatalina.base=/var/lib/tomcat9 -Dcatalina.home=/usr/share/tomcat9 -Djava.io.tmpdir=/tmp org.apache.catalina.startup.Bootstrap start

Forgot to mention, I am using tomcat with an external Postgresql database:

<Context>
    <!-- Default set of monitored resources. If one of these changes, the    -->
    <!-- web application will be reloaded.                                   -->
    <WatchedResource>WEB-INF/web.xml</WatchedResource>
    <WatchedResource>WEB-INF/tomcat-web.xml</WatchedResource>
    <WatchedResource>${catalina.base}/conf/web.xml</WatchedResource>

    <Manager pathname="" />
    <Resource name="jdbc/airsonicDB" auth="Container"
    type="javax.sql.DataSource"
    maxActive="20"
    maxIdle="30"
    maxWait="10000"
    username="airsonic"
    password="XXXXXXXXXXXXXXXXXXXXXXXXXXX"
    driverClassName="org.postgresql.Driver"
    url='jdbc:postgresql://postgres/airsonic?stringtype=unspecified'/>
</Context>
kagemomiji commented 5 months ago

@shutterbug79 @masterblaster79 I have created a release for experimental purposes. Could you please download the WAR file from there and give it a try? https://github.com/kagemomiji/airsonic-advanced/releases/tag/11.1.3-experimental-pr346

masterblaster79 commented 5 months ago

For me it works just fine now. Thanks a lot!