Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SpringApplication Application run failed after requesting cleanup routine #81

Open
robin0793 opened this issue Aug 18, 2024 · 1 comment

Comments

@robin0793
Copy link

I got an issue when I trigger a cleanup routine via mqtt (which routine doesn't matter). The routine does trigger, but the bridge shuts down with the following error.

Device is a Roborock QRevo Pro.
Issue is fully reproducible

2024-08-18T19:16:07.949+02:00  INFO 17422 --- [           main] d.k.r.RoborockBridgeApplicationKt        : Starting RoborockBridgeApplicationKt v0.0.7-SNAPSHOT using Java 17.0.11 with PID 17422 (/opt/roborock-bridge/roborock-bridge.jar started by openhabian in /opt/roborock-bridge)
2024-08-18T19:16:07.966+02:00  INFO 17422 --- [           main] d.k.r.RoborockBridgeApplicationKt        : The following 1 profile is active: "bridge"
2024-08-18T19:16:12.521+02:00  INFO 17422 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2024-08-18T19:16:12.833+02:00  INFO 17422 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 278 ms. Found 5 JPA repository interfaces.
2024-08-18T19:16:15.322+02:00  INFO 17422 --- [           main] o.hibernate.jpa.internal.util.LogHelper  : HHH000204: Processing PersistenceUnitInfo [name: default]
2024-08-18T19:16:15.656+02:00  INFO 17422 --- [           main] org.hibernate.Version                    : HHH000412: Hibernate ORM core version 6.4.4.Final
2024-08-18T19:16:15.851+02:00  INFO 17422 --- [           main] o.h.c.internal.RegionFactoryInitiator    : HHH000026: Second-level cache disabled
2024-08-18T19:16:17.282+02:00  INFO 17422 --- [           main] o.s.o.j.p.SpringPersistenceUnitInfo      : No LoadTimeWeaver setup: ignoring JPA class transformer
2024-08-18T19:16:17.433+02:00  INFO 17422 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Starting...
2024-08-18T19:16:18.122+02:00  INFO 17422 --- [           main] com.zaxxer.hikari.pool.HikariPool        : HikariPool-1 - Added connection conn0: url=jdbc:h2:mem:h2 user=SA
2024-08-18T19:16:18.131+02:00  INFO 17422 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Start completed.
2024-08-18T19:16:23.359+02:00  INFO 17422 --- [           main] o.h.e.t.j.p.i.JtaPlatformInitiator       : HHH000489: No JTA platform available (set 'hibernate.transaction.jta.platform' to enable JTA platform integration)
2024-08-18T19:16:23.682+02:00  INFO 17422 --- [           main] j.LocalContainerEntityManagerFactoryBean : Initialized JPA EntityManagerFactory for persistence unit 'default'
2024-08-18T19:16:26.640+02:00  INFO 17422 --- [           main] o.s.d.j.r.query.QueryEnhancerFactory     : Hibernate is in classpath; If applicable, HQL parser will be used.
2024-08-18T19:16:28.644+02:00  INFO 17422 --- [           main] d.k.r.remote.RoborockCredentials         : clientId not configured. Using auto-generated clientId 5Q2+aXjtO5qukg7yEoWu1Q==.
2024-08-18T19:16:32.075+02:00  INFO 17422 --- [           main] d.k.r.RoborockBridgeApplicationKt        : Started RoborockBridgeApplicationKt in 26.25 seconds (process running for 28.366)
2024-08-18T19:16:34.710+02:00  INFO 17422 --- [           main] d.k.roborockbridge.remote.rest.UserApi   : ok true
2024-08-18T19:16:35.077+02:00  INFO 17422 --- [           main] d.k.roborockbridge.bridge.BridgeMqtt     : Announcing new home with id '3659986'
2024-08-18T19:16:35.171+02:00  INFO 17422 --- [           main] d.k.roborockbridge.bridge.BridgeMqtt     : Announcing new robot with id '782w1Nhd37ltwdVbn1xc6O'
2024-08-18T19:16:35.534+02:00  INFO 17422 --- [           main] d.k.roborockbridge.bridge.BridgeMqtt     : Announcing 6 rooms.
2024-08-18T19:16:35.848+02:00  WARN 17422 --- [           main] d.k.r.remote.rest.dto.UnknownFieldsImpl  : ParamsForZonedCleanup: Found unknown extra property "auto_dry" with value: 1
2024-08-18T19:16:35.849+02:00  WARN 17422 --- [           main] d.k.r.remote.rest.dto.UnknownFieldsImpl  : ParamsForZonedCleanup: Found unknown extra property "auto_dustCollection" with value: 1
2024-08-18T19:16:35.849+02:00  WARN 17422 --- [           main] d.k.r.remote.rest.dto.UnknownFieldsImpl  : ParamsForZonedCleanup: Found unknown extra property "region_num" with value: 0
2024-08-18T19:16:35.854+02:00  WARN 17422 --- [           main] d.k.r.remote.rest.dto.UnknownFieldsImpl  : UserSceneParam: Found unknown extra property "tagId" with value: "1002"
2024-08-18T19:16:35.878+02:00  WARN 17422 --- [           main] d.k.r.remote.rest.dto.UnknownFieldsImpl  : ScenesAppStartParam: Found unknown extra property "auto_dustCollection" with value: 1
2024-08-18T19:16:35.879+02:00  WARN 17422 --- [           main] d.k.r.remote.rest.dto.UnknownFieldsImpl  : UserSceneParam: Found unknown extra property "tagId" with value: "1005"
2024-08-18T19:16:35.881+02:00  WARN 17422 --- [           main] d.k.r.remote.rest.dto.UnknownFieldsImpl  : ScenesAppStartParam: Found unknown extra property "auto_dustCollection" with value: 1
2024-08-18T19:16:35.883+02:00  WARN 17422 --- [           main] d.k.r.remote.rest.dto.UnknownFieldsImpl  : UserSceneParam: Found unknown extra property "tagId" with value: "1003"
2024-08-18T19:16:35.933+02:00  INFO 17422 --- [           main] d.k.roborockbridge.bridge.BridgeMqtt     : Announcing 3 schemas.
2024-08-18T19:16:36.571+02:00  INFO 17422 --- [       Thread-1] d.k.r.remote.mqtt.RoborockMqtt           : connected
2024-08-18T19:16:36.573+02:00  INFO 17422 --- [       Thread-1] d.k.r.remote.mqtt.RoborockMqtt           : Subscribing to topic rr/m/o/AbPEVCD9fOfam8Isumhyf/52163555/#
2024-08-18T19:16:37.493+02:00  INFO 17422 --- [           main] d.k.r.remote.mqtt.RoborockMqtt           : connected
2024-08-18T19:16:37.495+02:00  INFO 17422 --- [           main] d.k.r.remote.mqtt.RoborockMqtt           : Subscribing to topic rr/m/o/AbPEVCD9fOfam8Isumhyf/52163555/#
2024-08-18T19:16:37.498+02:00  WARN 17422 --- [Rec: rrb_POPa0n] d.k.r.remote.mqtt.RoborockMqtt           : Connection lost
2024-08-18T19:16:38.502+02:00  INFO 17422 --- [           main] d.k.r.remote.mqtt.RoborockMqtt           : Published 'get_room_mapping' request via topic 'rr/m/i/AbPEVCD9fOfam8Isumhyf/52163555/782w1Nhd37ltwdVbn1xc6O'.
2024-08-18T19:16:38.609+02:00  INFO 17422 --- [all: rrb_POPa0n] d.k.r.remote.mqtt.RoborockMqtt           : Lambda: New message for topic 'rr/m/o/AbPEVCD9fOfam8Isumhyf/52163555/782w1Nhd37ltwdVbn1xc6O' 0
2024-08-18T19:16:38.884+02:00  INFO 17422 --- [all: rrb_POPa0n] d.k.r.remote.mqtt.MessageDecoder         : Received response to request 1 with method 'GET_ROOM_MAPPING'.
2024-08-18T19:16:39.203+02:00  INFO 17422 --- [           main] d.k.roborockbridge.bridge.BridgeMqtt     : Announcing 6 rooms.
2024-08-18T19:17:32.132+02:00  INFO 17422 --- [   scheduling-1] d.k.r.remote.mqtt.RoborockMqtt           : disconnecting since bus idle
2024-08-18T19:17:32.180+02:00  INFO 17422 --- [   scheduling-1] d.k.r.remote.mqtt.RoborockMqtt           : disconnected
2024-08-18T19:17:39.248+02:00  INFO 17422 --- [           main] de.konqi.roborockbridge.BridgeService    : Requesting cleanup routine '3358614' via rest api.
2024-08-18T19:17:39.567+02:00 ERROR 17422 --- [           main] o.s.boot.SpringApplication               : Application run failed

org.hibernate.LazyInitializationException: failed to lazily initialize a collection of role: de.konqi.roborockbridge.persistence.entity.Routine.triggeredDeviceIds: could not initialize proxy - no Session
        at org.hibernate.collection.spi.AbstractPersistentCollection.throwLazyInitializationException(AbstractPersistentCollection.java:634) ~[hibernate-core-6.4.4.Final.jar!/:6.4.4.Final]
        at org.hibernate.collection.spi.AbstractPersistentCollection.withTemporarySessionIfNeeded(AbstractPersistentCollection.java:217) ~[hibernate-core-6.4.4.Final.jar!/:6.4.4.Final]
        at org.hibernate.collection.spi.AbstractPersistentCollection.initialize(AbstractPersistentCollection.java:613) ~[hibernate-core-6.4.4.Final.jar!/:6.4.4.Final]
        at org.hibernate.collection.spi.AbstractPersistentCollection.read(AbstractPersistentCollection.java:136) ~[hibernate-core-6.4.4.Final.jar!/:6.4.4.Final]
        at org.hibernate.collection.spi.PersistentSet.iterator(PersistentSet.java:169) ~[hibernate-core-6.4.4.Final.jar!/:6.4.4.Final]
        at de.konqi.roborockbridge.BridgeService.bridgeMqttProcessingLoop$lambda$16(BridgeService.kt:442) ~[!/:0.0.7-SNAPSHOT]
        at de.konqi.roborockbridge.BridgeService.bridgeMqttProcessingLoop$lambda$17(BridgeService.kt:295) ~[!/:0.0.7-SNAPSHOT]
        at java.base/java.util.Optional.ifPresent(Optional.java:178) ~[na:na]
        at de.konqi.roborockbridge.BridgeService.bridgeMqttProcessingLoop(BridgeService.kt:295) ~[!/:0.0.7-SNAPSHOT]
        at de.konqi.roborockbridge.BridgeService.worker(BridgeService.kt:130) ~[!/:0.0.7-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.context.event.ApplicationListenerMethodAdapter.doInvoke(ApplicationListenerMethodAdapter.java:365) ~[spring-context-6.1.6.jar!/:6.1.6]
        at org.springframework.context.event.ApplicationListenerMethodAdapter.processEvent(ApplicationListenerMethodAdapter.java:237) ~[spring-context-6.1.6.jar!/:6.1.6]
        at org.springframework.context.event.ApplicationListenerMethodAdapter.onApplicationEvent(ApplicationListenerMethodAdapter.java:168) ~[spring-context-6.1.6.jar!/:6.1.6]
        at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:185) ~[spring-context-6.1.6.jar!/:6.1.6]
        at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:178) ~[spring-context-6.1.6.jar!/:6.1.6]
        at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:156) ~[spring-context-6.1.6.jar!/:6.1.6]
        at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:451) ~[spring-context-6.1.6.jar!/:6.1.6]
        at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:384) ~[spring-context-6.1.6.jar!/:6.1.6]
        at org.springframework.boot.context.event.EventPublishingRunListener.ready(EventPublishingRunListener.java:109) ~[spring-boot-3.2.5.jar!/:3.2.5]
        at org.springframework.boot.SpringApplicationRunListeners.lambda$ready$6(SpringApplicationRunListeners.java:80) ~[spring-boot-3.2.5.jar!/:3.2.5]
        at java.base/java.lang.Iterable.forEach(Iterable.java:75) ~[na:na]
        at org.springframework.boot.SpringApplicationRunListeners.doWithListeners(SpringApplicationRunListeners.java:118) ~[spring-boot-3.2.5.jar!/:3.2.5]
        at org.springframework.boot.SpringApplicationRunListeners.doWithListeners(SpringApplicationRunListeners.java:112) ~[spring-boot-3.2.5.jar!/:3.2.5]
        at org.springframework.boot.SpringApplicationRunListeners.ready(SpringApplicationRunListeners.java:80) ~[spring-boot-3.2.5.jar!/:3.2.5]
        at org.springframework.boot.SpringApplication.run(SpringApplication.java:348) ~[spring-boot-3.2.5.jar!/:3.2.5]
        at de.konqi.roborockbridge.RoborockBridgeApplicationKt.main(RoborockBridgeApplication.kt:38) ~[!/:0.0.7-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.launch.Launcher.launch(Launcher.java:91) ~[roborock-bridge.jar:0.0.7-SNAPSHOT]
        at org.springframework.boot.loader.launch.Launcher.launch(Launcher.java:53) ~[roborock-bridge.jar:0.0.7-SNAPSHOT]
        at org.springframework.boot.loader.launch.JarLauncher.main(JarLauncher.java:58) ~[roborock-bridge.jar:0.0.7-SNAPSHOT]

2024-08-18T19:17:39.630+02:00  INFO 17422 --- [           main] de.konqi.roborockbridge.BridgeService    : Shutting down bridge service
2024-08-18T19:17:39.650+02:00  INFO 17422 --- [           main] j.LocalContainerEntityManagerFactoryBean : Closing JPA EntityManagerFactory for persistence unit 'default'
2024-08-18T19:17:39.657+02:00  INFO 17422 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown initiated...
2024-08-18T19:17:39.663+02:00  INFO 17422 --- [           main] com.zaxxer.hikari.HikariDataSource       : HikariPool-1 - Shutdown completed.

@robin0793
Copy link
Author

Just saw version 0.0.8 is out, but the issue does still occur.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant