mbentley / docker-omada-controller

Docker image to run TP-Link Omada Controller
690 stars 126 forks source link

[Bug]: 5.14.x (beta & GA) does not start up #418

Open IAmKonni opened 5 months ago

IAmKonni commented 5 months ago

🚨If you're experiencing this issue🚨

Feel free to add to this thread but please also post on the TP-Link Forums in this thread. There is only so much I can do and this appears to be a software related issue that I can't do anything about. If 5.14 never successfully ran for you, you can manually remove the version check file and specify the 5.13 tag to get back to a running controller. See this post in this thread for more info.

I will update this first thread as more information becomes available from TP-Link as well but subscribing to that forum thread would be a good idea too.

Update 2024-07-18: TP-Link acknowledged the issue - see this comment in this thread or directly to this TP-Link forum post

Update 2024-07-26: There is now a beta version available where the issue appears to be fixed. Images have been pushed and the tags are now available on Docker Hub. I would only suggest running the beta if you know what you're doing when it comes to running beta software or if you're stuck with a broken controller that can't be downgraded to 5.13 because 5.14 has already started at some point. If you're not having problems, I would suggest staying on 5.13.

The image tag is beta-5.14.30.7 for multi-arch and then there are specific tags for each architecture + the build with chromium if you use the report generation feature.

-mbentley


Controller Version

5.14.0.11

Describe the Bug

I switched from tag 5.13 to beta to test the newest pre-release. I never had any problems in updating to newer versions, this is the very first time i'm facing a problem. The controller does not start up, it runs into a boot loop (see logs).

Expected Behavior

Starting like always. =)

Steps to Reproduce

Change tag in compose file from 5.13 to beta and run docker-compose up -d

How You're Launching the Container

version: "3"

services:
  omada-controller:
    container_name: omada-controller
    image: mbentley/omada-controller:beta
    ports:
      - "8043:8043/tcp"
      - "443:443/tcp"
      - "8488:8488/tcp"
      - "8443:8443/tcp"
      - "8483:8483/tcp"
      - "29810:29810/udp"
      - "29811:29811"
      - "29812:29812"
      - "29813:29813"
      - "29814:29814"

    environment:
      MANAGE_HTTP_PORT: 8488
      MANAGE_HTTPS_PORT: 8443
      PORTAL_HTTP_PORT: 8488
      PORTAL_HTTPS_PORT: 8483
      SHOW_SERVER_LOGS: 'true'
      SHOW_MONGODB_LOGS: 'false'
      SSL_CERT_NAME: 'tls.crt'
      SSL_KEY_NAME: 'tls.key'
      TZ: 'Europe/Berlin'
    volumes:
      - ./data:/opt/tplink/EAPController/data
      - ./work:/opt/tplink/EAPController/work
      - ./logs:/opt/tplink/EAPController/logs
    restart: unless-stopped

Container Logs

03-25-2024 18:32:38.365 ERROR [main] [] c.t.s.o.s.t.SpringBootStartUpTask(): Cannot retry start up springboot. reson:Error creating bean with name 'com.tplink.smb.omada.identityaccess.domain.model.openapi.c.q': Unsatisfied dependency expressed through field 'e'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.common.a.a': Unsatisfied dependency expressed through field 'c'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.common.e.a': Unsatisfied dependency expressed through field 'b'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.b.p': Unsatisfied dependency expressed through field 'm'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.domain.model.user.A': Unsatisfied dependency expressed through field 'c'; nested exception is org.springframework.beans.factory.BeanCurrentlyInCreationException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a': Bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a' has been injected into other beans [com.tplink.smb.omada.identityaccess.domain.model.d.q] in its raw version as part of a circular reference, but has eventually been wrapped. This means that said other beans do not use the final version of the bean. This is often the result of over-eager type matching - consider using 'getBeanNamesForType' with the 'allowEagerInit' flag turned off, for example.
03-25-2024 18:32:38.365 ERROR [main] [] c.t.s.o.s.t.FailExitTask(): Failed to start omada controller, going to exit
03-25-2024 18:32:38.366 INFO [Thread-0] [] c.t.s.o.s.OmadaBootstrap(): Failed to shutdown customThread.
java.lang.ExceptionInInitializerError: null
    at com.tplink.smb.omada.common.concurrent.thread.a.a(SourceFile:243) ~[omada-common-5.14.0.11.jar:5.14.0.11]
    at com.tplink.smb.omada.starter.OmadaBootstrap.b(SourceFile:195) ~[local-starter-5.14.0.11.jar:5.14.0.11]
    at com.tplink.smb.omada.starter.OmadaLinuxMain.b(SourceFile:87) ~[local-starter-5.14.0.11.jar:5.14.0.11]
    at java.lang.Thread.run(Thread.java:840) [?:?]
Caused by: java.lang.IllegalStateException: org.springframework.boot.web.servlet.context.AnnotationConfigServletWebServerApplicationContext@398f2bd3 has not been refreshed yet
    at org.springframework.context.support.AbstractApplicationContext.assertBeanFactoryActive(AbstractApplicationContext.java:1147) ~[spring-context-5.3.30.jar:5.3.30]
    at org.springframework.context.support.AbstractApplicationContext.getBean(AbstractApplicationContext.java:1159) ~[spring-context-5.3.30.jar:5.3.30]
    at com.tplink.smb.omada.common.spring.a.a(SourceFile:28) ~[omada-common-5.14.0.11.jar:5.14.0.11]
    at com.tplink.smb.omada.common.concurrent.thread.a$a.<clinit>(SourceFile:55) ~[omada-common-5.14.0.11.jar:5.14.0.11]
    ... 4 more
INFO: Validating user/group (omada:omada) exists with correct UID/GID (508:508)
INFO: Group (omada) exists; skipping creation
INFO: User (omada) exists; skipping creation
INFO: Time zone set to 'Europe/Berlin'
INFO: Value of 'manage.http.port' already set to 8488 in omada.properties
INFO: Value of 'manage.https.port' already set to 8443 in omada.properties
INFO: Value of 'portal.http.port' already set to 8488 in omada.properties
INFO: Value of 'portal.https.port' already set to 8483 in omada.properties
INFO: Value of 'port.adopt.v1' already set to 29812 in omada.properties
INFO: Value of 'port.app.discovery' already set to 27001 in omada.properties
INFO: Value of 'port.upgrade.v1' already set to 29813 in omada.properties
INFO: Value of 'port.manager.v1' already set to 29811 in omada.properties
INFO: Value of 'port.manager.v2' already set to 29814 in omada.properties
INFO: Value of 'port.discovery' already set to 29810 in omada.properties
INFO: Value of 'port.transfer.v2' already set to 29815 in omada.properties
INFO: Value of 'port.rtty' already set to 29816 in omada.properties
INFO: Value of 'mongo.external' already set to false in omada.properties
INFO: Value of 'eap.mongod.uri' already set to mongodb://127.0.0.1:27217/omada in omada.properties
INFO: Version check passed; image version (5.14.0.11) >= the last version ran (5.14.0.11); writing image version to last ran file...
INFO: userland/kernel check passed
INFO: Starting Omada Controller as user omada
03-25-2024 18:32:47.525 INFO [main] [] c.t.s.o.s.OmadaLinuxMain(): record: start the omada controller
03-25-2024 18:32:47.528 INFO [main] [] c.t.s.o.s.OmadaLinuxMain(): record: set property finished
03-25-2024 18:32:47.530 INFO [main] [] c.t.s.o.s.OmadaLinuxMain(): record: configure log finished
03-25-2024 18:32:47.532 INFO [main] [] c.t.s.o.s.OmadaBootstrap(): record: bootstrap prepare
03-25-2024 18:32:47.538 INFO [log4j-thread] [] c.t.s.o.c.o.a.b(): success to load configuration omada.properties
03-25-2024 18:32:47.539 INFO [log4j-thread] [] c.t.s.o.c.o.OmadacType(): omadacType: Local Controller
03-25-2024 18:32:47.556 INFO [main] [] c.t.s.o.s.OmadaBootstrap(): going to start local mongod.
03-25-2024 18:32:50.068 INFO [main] [] c.t.s.o.s.s.b(): mongodb process id is 155
03-25-2024 18:32:50.071 ERROR [main] [] c.t.s.f.c.FacadeUtils(): facadeMsgEnable is not enable, msg: Mongo DB server started
03-25-2024 18:32:50.071 INFO [main] [] c.t.s.o.s.s.b(): Mongo DB server started
03-25-2024 18:32:50.327 INFO [main] [] c.t.s.o.s.OmadaBootstrap(): record: bootstrap record finished
03-25-2024 18:32:50.327 INFO [main] [] c.t.s.o.s.OmadaBootstrap(): record: bootstrap startup
03-25-2024 18:32:50.380 INFO [main] [] c.t.s.o.s.OmadaBootstrap(): record: start run omada tasks
03-25-2024 18:32:50.380 INFO [main] [] c.t.s.o.s.t.SpringBootStartUpTask(): record: task SpringBootStartupTask start
  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::               (v2.7.17)
03-25-2024 18:32:50.837 INFO [main] [] c.t.s.o.s.OmadaLinuxMain(): Starting OmadaLinuxMain v5.14.0.11 using Java 17.0.10 on 3c8dd90b3952 with PID 1 (/opt/tplink/EAPController/lib/local-starter-5.14.0.11.jar started by omada in /opt/tplink/EAPController/lib)
03-25-2024 18:32:50.839 INFO [main] [] c.t.s.o.s.OmadaLinuxMain(): No active profile set, falling back to 1 default profile: "default"
03-25-2024 18:32:56.974 WARN [main] [] o.s.d.c.CustomConversions(): Registering converter from class java.time.LocalDateTime to class org.joda.time.LocalDateTime as reading converter although it doesn't convert from a store-supported type; You might want to check your annotation setup at the converter implementation
03-25-2024 18:32:58.664 WARN [main] [] o.s.b.w.s.c.AnnotationConfigServletWebServerApplicationContext(): Exception encountered during context initialization - cancelling refresh attempt: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.domain.model.openapi.c.q': Unsatisfied dependency expressed through field 'e'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.common.a.a': Unsatisfied dependency expressed through field 'c'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.common.e.a': Unsatisfied dependency expressed through field 'b'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.b.p': Unsatisfied dependency expressed through field 'm'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.domain.model.user.A': Unsatisfied dependency expressed through field 'c'; nested exception is org.springframework.beans.factory.BeanCurrentlyInCreationException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a': Bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a' has been injected into other beans [com.tplink.smb.omada.identityaccess.domain.model.d.q] in its raw version as part of a circular reference, but has eventually been wrapped. This means that said other beans do not use the final version of the bean. This is often the result of over-eager type matching - consider using 'getBeanNamesForType' with the 'allowEagerInit' flag turned off, for example.
03-25-2024 18:32:58.700 ERROR [main] [] o.s.b.SpringApplication(): Application run failed
org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.domain.model.openapi.c.q': Unsatisfied dependency expressed through field 'e'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.common.a.a': Unsatisfied dependency expressed through field 'c'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.common.e.a': Unsatisfied dependency expressed through field 'b'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.b.p': Unsatisfied dependency expressed through field 'm'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.domain.model.user.A': Unsatisfied dependency expressed through field 'c'; nested exception is org.springframework.beans.factory.BeanCurrentlyInCreationException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a': Bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a' has been injected into other beans [com.tplink.smb.omada.identityaccess.domain.model.d.q] in its raw version as part of a circular reference, but has eventually been wrapped. This means that said other beans do not use the final version of the bean. This is often the result of over-eager type matching - consider using 'getBeanNamesForType' with the 'allowEagerInit' flag turned off, for example.
    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.17.jar:2.7.17]
    at org.springframework.boot.SpringApplication.refresh(SpringApplication.java:732) ~[spring-boot-2.7.17.jar:2.7.17]
    at org.springframework.boot.SpringApplication.refreshContext(SpringApplication.java:409) ~[spring-boot-2.7.17.jar:2.7.17]
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:308) ~[spring-boot-2.7.17.jar:2.7.17]
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1300) ~[spring-boot-2.7.17.jar:2.7.17]
    at org.springframework.boot.SpringApplication.run(SpringApplication.java:1289) ~[spring-boot-2.7.17.jar:2.7.17]
    at com.tplink.smb.omada.starter.task.SpringBootStartUpTask.execute(SourceFile:33) ~[local-starter-5.14.0.11.jar:5.14.0.11]
    at com.tplink.smb.omada.starter.task.c.a(SourceFile:20) ~[local-starter-5.14.0.11.jar:5.14.0.11]
    at com.tplink.smb.omada.starter.OmadaBootstrap.f(SourceFile:356) ~[local-starter-5.14.0.11.jar:5.14.0.11]
    at com.tplink.smb.omada.starter.OmadaLinuxMain.a(SourceFile:99) ~[local-starter-5.14.0.11.jar:5.14.0.11]
    at com.tplink.smb.omada.starter.OmadaLinuxMain.main(SourceFile:42) ~[local-starter-5.14.0.11.jar:5.14.0.11]
Caused by: org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.common.a.a': Unsatisfied dependency expressed through field 'c'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.common.e.a': Unsatisfied dependency expressed through field 'b'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.b.p': Unsatisfied dependency expressed through field 'm'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.domain.model.user.A': Unsatisfied dependency expressed through field 'c'; nested exception is org.springframework.beans.factory.BeanCurrentlyInCreationException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a': Bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a' has been injected into other beans [com.tplink.smb.omada.identityaccess.domain.model.d.q] in its raw version as part of a circular reference, but has eventually been wrapped. This means that said other beans do not use the final version of the bean. This is often the result of over-eager type matching - consider using 'getBeanNamesForType' with the 'allowEagerInit' flag turned off, for example.
    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.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]

MongoDB Logs

2024-03-25T18:29:13.220+0100 I STORAGE  [signalProcessingThread] shutdown: removing fs lock...
2024-03-25T18:29:13.220+0100 I CONTROL  [signalProcessingThread] now exiting
2024-03-25T18:29:13.220+0100 I CONTROL  [signalProcessingThread] shutting down with code:0
2024-03-25T18:29:33.908+0100 I CONTROL  [main] ***** SERVER RESTARTED *****
2024-03-25T18:29:33.919+0100 I CONTROL  [initandlisten] MongoDB starting : pid=175 port=27217 dbpath=../data/db 64-bit host=28242437eafe
2024-03-25T18:29:33.920+0100 I CONTROL  [initandlisten] db version v3.6.8
2024-03-25T18:29:33.920+0100 I CONTROL  [initandlisten] git version: 8e540c0b6db93ce994cc548f000900bdc740f80a
2024-03-25T18:29:33.920+0100 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.1.1f  31 Mar 2020
2024-03-25T18:29:33.920+0100 I CONTROL  [initandlisten] allocator: tcmalloc
2024-03-25T18:29:33.920+0100 I CONTROL  [initandlisten] modules: none
2024-03-25T18:29:33.920+0100 I CONTROL  [initandlisten] build environment:
2024-03-25T18:29:33.920+0100 I CONTROL  [initandlisten]     distarch: x86_64
2024-03-25T18:29:33.920+0100 I CONTROL  [initandlisten]     target_arch: x86_64
2024-03-25T18:29:33.920+0100 I CONTROL  [initandlisten] options: { net: { bindIp: "127.0.0.1", port: 27217 }, processManagement: { pidFilePath: "../data/mongo.pid" }, storage: { dbPath: "../data/db", journal: { enabled: true } }, systemLog: { destination: "file", logAppend: true, path: "../logs/mongod.log" } }
2024-03-25T18:29:33.920+0100 I -        [initandlisten] Detected data files in ../data/db created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2024-03-25T18:29:33.920+0100 I STORAGE  [initandlisten]
2024-03-25T18:29:33.920+0100 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2024-03-25T18:29:33.920+0100 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
2024-03-25T18:29:33.920+0100 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=11315M,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),cache_cursors=false,compatibility=(release="3.0",require_max="3.0"),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),statistics_log=(wait=0),verbose=(recovery_progress),
2024-03-25T18:29:34.589+0100 I STORAGE  [initandlisten] WiredTiger message [1711387774:589205][175:0x7f1f3c986ac0], txn-recover: Main recovery loop: starting at 232/36004352
2024-03-25T18:29:34.638+0100 I STORAGE  [initandlisten] WiredTiger message [1711387774:638685][175:0x7f1f3c986ac0], txn-recover: Recovering log 232 through 233
2024-03-25T18:29:34.662+0100 I STORAGE  [initandlisten] WiredTiger message [1711387774:662948][175:0x7f1f3c986ac0], txn-recover: Recovering log 233 through 233
2024-03-25T18:29:34.691+0100 I STORAGE  [initandlisten] WiredTiger message [1711387774:691597][175:0x7f1f3c986ac0], txn-recover: Set global recovery timestamp: 0
2024-03-25T18:29:34.857+0100 I CONTROL  [initandlisten]
2024-03-25T18:29:34.857+0100 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
2024-03-25T18:29:34.857+0100 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
2024-03-25T18:29:34.857+0100 I CONTROL  [initandlisten]
2024-03-25T18:29:35.907+0100 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '../data/db/diagnostic.data'
2024-03-25T18:29:35.908+0100 I NETWORK  [initandlisten] waiting for connections on port 27217
2024-03-25T18:29:36.575+0100 I NETWORK  [listener] connection accepted from 127.0.0.1:41382 #1 (1 connection now open)
2024-03-25T18:29:36.575+0100 I NETWORK  [listener] connection accepted from 127.0.0.1:41380 #2 (2 connections now open)

Additional Context

The mongo db log is the first iteration after switching to 5.14 beta. There are more following Exceptions and stack traces in the log, but all seem to be of missing dependencies.

org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.domain.model.user.A': Unsatisfied dependency expressed through field 'c'; nested exception is org.springframework.beans.factory.BeanCurrentlyInCreationException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a': Bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a' has been injected into other beans [com.tplink.smb.omada.identityaccess.domain.model.d.q] in its raw version as part of a circular reference, but has eventually been wrapped. This means that said other beans do not use the final version of the bean. This is often the result of over-eager type matching - consider using 'getBeanNamesForType' with the 'allowEagerInit' flag turned off, for example.

org.springframework.beans.factory.BeanCurrentlyInCreationException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a': Bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a' has been injected into other beans [com.tplink.smb.omada.identityaccess.domain.model.d.q] in its raw version as part of a circular reference, but has eventually been wrapped. This means that said other beans do not use the final version of the bean. This is often the result of over-eager type matching - consider using 'getBeanNamesForType' with the 'allowEagerInit' flag turned off, for example.

lxe commented 1 month ago

Downgraded to mbentley/omada-controller:5.13-arm64 on raspberry pi.

I had to do

sudo docker run -it --rm  -v {the existing data volume):/opt/tplink/EAPController/data  ubuntu /bin/bash

Then

rm -rf /opt/tplink/EAPController/data/LAST_RAN_OMADA_VER.txt
fanto237 commented 1 month ago

I didn't back up my config performing the upgrade so, I can't delete the Omaha volume otherwise I will lose everything :(

Omada automatically creates a backup, it's stored in the 'data' persistent volume /data/autobackup - Unless you changed settings, you should see 7 backups with various dates.

There is no folder named autobackup in my data volumes. Is there may be another directory where Omaha stores those backups `? image

mbentley commented 1 month ago

No, unfortunately it would be right there:

# ls -l
total 176
drwxr-xr-x 2 omada omada   4096 Jul 24 01:15 autobackup/
drwxr-xr-x 4 omada omada 151552 Jul 24 17:04 db/
drwxr-xr-x 4 omada omada   4096 Jul 19 17:27 device-firmware/
drwxr-xr-x 2 omada omada   4096 Jul 11  2022 html/
drwxr-xr-x 2 omada omada   4096 Jul 22 06:25 keystore/
-rw-r--r-- 1 root  root      10 Jul 22 06:25 LAST_RAN_OMADA_VER.txt
drwxr-xr-x 2 omada omada   4096 Jul 11  2022 pdf/
amansarroha commented 1 month ago

Tp-link released new beta firmware, when can we expect an update?

mbentley commented 1 month ago

Love the inconsistency of how they notify (or don't) about updates. I didn't get any notifications about it and I only see it in the edited forum post about new updates. They did post another thread but I am not subscribing to every single new post to get notifications.

I will have builds available ASAP and will post when I do. Hopefully they didn't do anything funky in the builds this time that needs changes to the install process.

amansarroha commented 1 month ago

I have added a keyword monitor in uptime kuma with "hours" on tp-link's controller forums page.🫢

mbentley commented 1 month ago

They're absolutely killing me with the inconsistency of their builds yet again. They really need to stop building these archives by hand and use some actual automation... Every release is different and there is no consistency which makes it damn near impossible to keep up with in any sane manner. They can't even name the files consistently let alone the structure of the files in the archives.

mbentley commented 1 month ago

OK, good news for this latest beta - my quick test against all of my systems where I could only reproduce the issue on one all started fine. Here's the PR to put in the fixes for their inconsistency. It will take a little bit to rebuild all of the images because changing the install.sh will force all of the images I build to be rebuilt due to invalidated image caches. I'll post again when there is a beta version available if anyone wants to try that but please remember it's a beta!

mbentley commented 1 month ago

OK, looks like everything has built fine and the beta version tags are now available on Docker Hub.

beta-5.14.30.7 for multi-arch and then there are specific tags for each architecture + the build with chromium if you use the report generation feature.

mooglestiltzkin commented 1 month ago

beta-5.14.30.7

i updated from

5.13 to beta-5.14.30.7

seems to be working. I can confirm it worked for me. The previous issue where 5.14 didn't work seems to be resolved at least for me.

I recommend others who want to try, to first BACKUP your omada settings, before updating. In case you have to roll back.

Don't know what magic you did mbentley, but it worked. ty so much.

mooglestiltzkin commented 1 month ago

only bug i still get is the "Failed to optimize device because of no scan result." when using wlan optimization :(

Other than that it works.

haraldkoch commented 1 month ago

beta-5.14.30.7 is working for me on arm64. yay!

chriexpe commented 1 month ago

Love the inconsistency of how they notify (or don't) about updates. I didn't get any notifications about it and I only see it in the edited forum post about new updates. They did post another thread but I am not subscribing to every single new post to get notifications.

I will have builds available ASAP and will post when I do. Hopefully they didn't do anything funky in the builds this time that needs changes to the install process.

Correct me if I'm wrong but they used to leave the thread open for feedback right?

CoronaExtra commented 1 month ago

In 5.14 they change the syslog format :-( not working anymore for me. I was using forwarding to telegraf.

I asked in their forum ref. this [https://community.tp-link.com/en/business/forum/topic/677984]

They responded with a message that it was not under their control because it was dependant on JWC or something but later that message was removed.. :-)

I tried with my limited skills to get rsyslog to convert it but no go yet.

New version (not working) Facility local3 (19), Severity warning (4) Msg: 1 2024-07-24 10:00:58 Omada Controller - - - asada failed to log in to the controller from 10.110.0.178.

Old version (working): Facility local3 (19), Severity warning (4) Msg: 1 2024-07-24T09:05:53.803Z Omada Controller - - - asada failed to log in to the controller from 10.110.0.178.

mbentley commented 1 month ago

Don't know what magic you did mbentley, but it worked. ty so much.

Well, they must have done something to address the issue even though I did not see any sort of message in the changelog. No other changes happened on my end 😄

Love the inconsistency of how they notify (or don't) about updates. I didn't get any notifications about it and I only see it in the edited forum post about new updates. They did post another thread but I am not subscribing to every single new post to get notifications. I will have builds available ASAP and will post when I do. Hopefully they didn't do anything funky in the builds this time that needs changes to the install process.

Correct me if I'm wrong but they used to leave the thread open for feedback right?

Good point - I shouldn't complain unless I've let them know about it so I created a thread: https://community.tp-link.com/en/business/forum/topic/679112?page=1. I could have posted on the beta thread but at this point, it's not urgent, just annoying.

microdockman commented 1 month ago

At present, it seems that any image of v5.14.26.1 will start incorrectly, other versions are normal

johnthomas00 commented 1 month ago

What is the current recommended course of action please? I'm on 5.13 after reverting when 5.14 first came out. There also seems to be a DB update in various stages. What is a good way to proceed on both, please and many things for running this Mr. Bently!

mbentley commented 1 month ago

What is the current recommended course of action please? I'm on 5.13 after reverting when 5.14 first came out. There also seems to be a DB update in various stages. What is a good way to proceed on both, please and many things for running this Mr. Bently!

If you are currently running on 5.13 without an issues, I would stay on that for now and wait until there is a new GA version that is newer than the current, problematic 5.14.26.1. Moving to a beta version wouldn't be my recommendation if you have a working controller today.

johndotpub commented 1 month ago

If you are currently running on 5.13 without an issues, I would stay on that for now and wait until there is a new GA version that is newer than the current, problematic 5.14.26.1. Moving to a beta version wouldn't be my recommendation if you have a working controller today.

@mbentley For what it's worth I was hitting the start-up issue with v5.14.26.1 and just today updated to beta-5.14.30.7. I was able to get the controller restarted and so far the configuration and data looks fine. I'll lock this in until a new 5.14 GA comes along that is a higher version.

Hopefully, TP-Link will consider your feedback and develop some build standards!

Tom-246 commented 1 month ago

Hi!

I do have posted this at the unraid-forum as well but hope to get a faster response with this forum.

My controller would not start with the 5.14 version. I tried to get to 5.13 but there was no success. This was the error:

08-02-2024 11:57:00.770 INFO [main] [] c.t.s.o.m.c.d.a(): base db version  5.14.26 is bigger than compatible version 5.13.30
08-02-2024 11:57:00.770 ERROR [main] [] c.t.s.o.s.t.OmadacInitTask(): Data in db is not compatible with Omada Controller, please reinstall the software without keeping data in db.

I reinstalled 5.14 -> controller did not start I installed 5.14-beta -> new controller and all devices are controlled by another device I restored the controller data from an old backup (5.13.30.8) and the controller starts but is still a complete new controller. The log still shows messages that the devices being controlled by another device.

Is my controller/setup 'done'? Do I have to start from scratch?

Is there something else I do have to restore from the backup besides the data from appdata?

mbentley commented 1 month ago

Sorry, the notifications from the unraid forum sometimes do not make it to me for whatever reason. It looks like at some point, a 5.14.26 version did successfully start and performed a database migration. When you installed the 5.14-beta, did you use the same persistent data from your previous version?

If you're starting a controller and it's acting like a new installation, that means that the persistent data isn't being mapped correctly. Anything you can do to provide the details of how the container is being started would be helpful, specifically the persistent data volume mapping as that is where the problem seems to exist.

Tom-246 commented 1 month ago

Hi mbentley!

I hope you do mean this:

Container Path: /opt/tplink/EAPController/data -> /mnt/ssd_pool/appdata/omada-controller/data/ Container Path: /opt/tplink/EAPController/work -> /mnt/ssd_pool/appdata/omada-controller/work/ Container Path: /opt/tplink/EAPController/logs -> /mnt/ssd_pool/appdata/omada-controller/logs/

But exactly this folder 'omada-controller' I renamed and restored the folder/files from the backup that I do have. This backup shows version '5.13'. I don't get why there is still a database migration to 5.14 if this old files do not know anything about 5.14!?

What is it that I have to do?

1 'downgrade' omada-controller to 5.13

2 Restore the omada-controller-folder (appdata) from Backup

3 anything else?

mooglestiltzkin commented 1 month ago

not sure how you do things but i just simply in omada controller, backup settings. back that up elsewhere.

then if later got issue, just delete the docker container, install back as new, then login to omada, then import the settings you backed up. Done.

There was also another method for downgrading, you can follow instructions if you want to do it that way. I just prefer my way since it's simpler and clean.

My compose is setup like this

    #   volumes:
    #    - omada-data:/opt/tplink/EAPController/data
    #     - omada-logs:/opt/tplink/EAPController/logs

    volumes:
      - /mnt/docker/data/tplink/EAPController/omada-data:/opt/tplink/EAPController/data
      - /mnt/docker/data/tplink/EAPController/omada-logs:/opt/tplink/EAPController/logs

#volumes:
#  omada-data:
#  omada-logs:

Seems to work.

Also because i use dockge to deploy, the docker compose and .env files get saved to

/mnt/docker/compose/omada

Makes backing up and deploying from the docker compose easier. If the whole nas get nuked or something. I even tested this when factory reset nas, and it worked.

This worked for me (before i had issues with 5.14 until i tried this beta) image: mbentley/omada-controller:beta-5.14.30.7

Wifi seems to work, don't notice any big issues for me to be concerned with.

Tom-246 commented 1 month ago

Using 5.14.30.7 isn't working for me. I tried it again and this is the log after the controller started:

08-03-2024 16:06:45.272 ERROR [main] [] c.t.s.f.c.FacadeUtils(): facadeMsgEnable is not enable, msg: Device connector server started. 08-03-2024 16:06:45.272 ERROR [main] [] c.t.s.f.c.FacadeUtils(): facadeMsgEnable is not enable, msg: Omada Controller started 08-03-2024 16:06:45.272 INFO [main] [] c.t.s.o.s.t.SuccessExitTask(): Omada Controller started 08-03-2024 16:06:45.272 INFO [main] [] c.t.s.o.s.OmadaBootstrap(): record: finished run omada tasks 08-03-2024 16:06:45.670 INFO [discovery-work-group-0] [] c.t.s.o.m.d.d.m.d.a(): MANAGE_BY_OTHERS Device XX on omadac XX is discovered.

and so on with the other devices

I do not have a backup of the controller settings, as all of the relevant data of a docker-container is stored under 'appdata' with unraid. If a container crashes etc. you do have the option to install it from previous settings and everything is fine. Not this time...

Tom-246 commented 1 month ago

I created two new docker-container for Omada.

#1 6.13.30.8 log is attached. error seems to be: 08-03-2024 17:07:15.378 ERROR [main] [] c.t.s.o.s.t.SpringBootStartUpTask(): Cannot retry start up springboot. reson:Timed out after 30000 ms while waiting to connect. Client view of cluster state is {type=UNKNOWN, servers=[{address=127.0.0.1:27217, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused}}]; nested exception is com.mongodb.MongoTimeoutException: Timed out after 30000 ms while waiting to connect. Client view of cluster state is {type=UNKNOWN, servers=[{address=127.0.0.1:27217, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused}}] 08-03-2024 17:07:15.378 ERROR [main] [] c.t.s.o.s.t.FailExitTask(): Failed to start omada controller, going to exit 08-03-2024 17:07:15.380 INFO [Thread-0] [] c.t.s.o.s.OmadaBootstrap(): Failed to shutdown customThread.

#2 beta 6.14 as much as I see it's the same...

Is it possible, that it is unraid 7.0 which causes this error?

5.13.30.8.txt 5.14.30.7.txt

mbentley commented 1 month ago

Hi mbentley!

I hope you do mean this:

Container Path: /opt/tplink/EAPController/data -> /mnt/ssd_pool/appdata/omada-controller/data/ Container Path: /opt/tplink/EAPController/work -> /mnt/ssd_pool/appdata/omada-controller/work/ Container Path: /opt/tplink/EAPController/logs -> /mnt/ssd_pool/appdata/omada-controller/logs/

But exactly this folder 'omada-controller' I renamed and restored the folder/files from the backup that I do have. This backup shows version '5.13'. I don't get why there is still a database migration to 5.14 if this old files do not know anything about 5.14!?

What is it that I have to do? #1 'downgrade' omada-controller to 5.13 #2 Restore the omada-controller-folder (appdata) from Backup #3 anything else?

Yes, those are the paths. Versions as of 5.x no longer need the work directory at all so you can remove that from the mount and get rid of that data. It was just used to deploy the app before they made it a Spring Boot app.

If you're talking about backups that are taken at the filesystem level, the steps should be:

  1. Make sure the container isn't running
  2. Restore your previous data backup from a 5.13 version
  3. Start the 5.13 version of the container

To make sure your backup has the right data, you could take a look at the LAST_RAN_OMADA_VER.txt file in the data directory to see what version it shows was last ran. Assuming you hadn't modified it in your backup at all, it should show you the version it last knew about and the entrypoint will not let you run an older version so it should tell you the newest version you've ran.

If it goes through the new controller setup, you data isn't correctly mounted and for whatever reason, the controller in the container doesn't see it. You should not have to go through the new controller setup at any point if you have existing data.

mbentley commented 1 month ago

I created two new docker-container for Omada.

#1 6.13.30.8 log is attached. error seems to be: 08-03-2024 17:07:15.378 ERROR [main] [] c.t.s.o.s.t.SpringBootStartUpTask(): Cannot retry start up springboot. reson:Timed out after 30000 ms while waiting to connect. Client view of cluster state is {type=UNKNOWN, servers=[{address=127.0.0.1:27217, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused}}]; nested exception is com.mongodb.MongoTimeoutException: Timed out after 30000 ms while waiting to connect. Client view of cluster state is {type=UNKNOWN, servers=[{address=127.0.0.1:27217, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused}}] 08-03-2024 17:07:15.378 ERROR [main] [] c.t.s.o.s.t.FailExitTask(): Failed to start omada controller, going to exit 08-03-2024 17:07:15.380 INFO [Thread-0] [] c.t.s.o.s.OmadaBootstrap(): Failed to shutdown customThread.

#2 beta 6.14 as much as I see it's the same...

Is it possible, that it is unraid 7.0 which causes this error?

5.13.30.8.txt 5.14.30.7.txt

Those logs show when the MongoDB isn't running successfully. Check the mongodb logs in the logs directory to see why.

Tom-246 commented 1 month ago

I created two new docker-container for Omada. #1 6.13.30.8 log is attached. error seems to be: 08-03-2024 17:07:15.378 ERROR [main] [] c.t.s.o.s.t.SpringBootStartUpTask(): Cannot retry start up springboot. reson:Timed out after 30000 ms while waiting to connect. Client view of cluster state is {type=UNKNOWN, servers=[{address=127.0.0.1:27217, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused}}]; nested exception is com.mongodb.MongoTimeoutException: Timed out after 30000 ms while waiting to connect. Client view of cluster state is {type=UNKNOWN, servers=[{address=127.0.0.1:27217, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused}}] 08-03-2024 17:07:15.378 ERROR [main] [] c.t.s.o.s.t.FailExitTask(): Failed to start omada controller, going to exit 08-03-2024 17:07:15.380 INFO [Thread-0] [] c.t.s.o.s.OmadaBootstrap(): Failed to shutdown customThread. #2 beta 6.14 as much as I see it's the same... Is it possible, that it is unraid 7.0 which causes this error? 5.13.30.8.txt 5.14.30.7.txt

Those logs show when the MongoDB isn't running successfully. Check the mongodb logs in the logs directory to see why.

This is the mongodb log-error: 2024-08-03T17:20:57.045+0200 I CONTROL [main] SERVER RESTARTED 2024-08-03T17:20:57.050+0200 I CONTROL [initandlisten] MongoDB starting : pid=818 port=27217 dbpath=../data/db 64-bit host=UNAS 2024-08-03T17:20:57.050+0200 I CONTROL [initandlisten] db version v3.6.8 2024-08-03T17:20:57.050+0200 I CONTROL [initandlisten] git version: 8e540c0b6db93ce994cc548f000900bdc740f80a 2024-08-03T17:20:57.050+0200 I CONTROL [initandlisten] OpenSSL version: OpenSSL 1.1.1f 31 Mar 2020 2024-08-03T17:20:57.050+0200 I CONTROL [initandlisten] allocator: tcmalloc 2024-08-03T17:20:57.050+0200 I CONTROL [initandlisten] modules: none 2024-08-03T17:20:57.050+0200 I CONTROL [initandlisten] build environment: 2024-08-03T17:20:57.050+0200 I CONTROL [initandlisten] distarch: x86_64 2024-08-03T17:20:57.050+0200 I CONTROL [initandlisten] target_arch: x86_64 2024-08-03T17:20:57.050+0200 I CONTROL [initandlisten] options: { net: { bindIp: "127.0.0.1", port: 27217 }, processManagement: { pidFilePath: "../data/mongo.pid" }, storage: { dbPath: "../data/db" }, systemLog: { destination: "file", logAppend: true, path: "../logs/mongod.log" } } 2024-08-03T17:20:57.051+0200 I - [initandlisten] Detected data files in ../data/db created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'. 2024-08-03T17:20:57.051+0200 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=63846M,session_max=20000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),cache_cursors=false,compatibility=(release="3.0",require_max="3.0"),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),statistics_log=(wait=0),verbose=(recovery_progress), 2024-08-03T17:20:57.716+0200 E STORAGE [initandlisten] WiredTiger error (13) [1722698457:716219][818:0x154a24e2cac0], connection: ../data/db/journal/WiredTigerLog.0000000074: handle-open: open: Permission denied 2024-08-03T17:20:57.717+0200 E - [initandlisten] Assertion: 28595:13: Permission denied src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp 421 2024-08-03T17:20:57.718+0200 I STORAGE [initandlisten] exception in initAndListen: Location28595: 13: Permission denied, terminating 2024-08-03T17:20:57.718+0200 I NETWORK [initandlisten] shutdown: going to close listening sockets... 2024-08-03T17:20:57.718+0200 I NETWORK [initandlisten] removing socket file: /tmp/mongodb-27217.sock 2024-08-03T17:20:57.718+0200 I CONTROL [initandlisten] now exiting 2024-08-03T17:20:57.718+0200 I CONTROL [initandlisten] shutting down with code:100

Permission denied... Is it that I have to get my settings right or is this within the image?

mbentley commented 1 month ago

It's in your persistent data. Assuming you didn't modify the UID/GID when you started the container (which is done by environment variable so if you didn't include a PUID and PGID env var, it will be the default, you can do a chown -R 508:508 /mnt/ssd_pool/appdata/omada-controller/data based on the path you shared. I'm guessing when you restored the files the ownership just isn't set right. The entrypoint only makes sure the parent directory has the right ownership, not the files within.

Tom-246 commented 1 month ago

It's in your persistent data. Assuming you didn't modify the UID/GID when you started the container (which is done by environment variable so if you didn't include a PUID and PGID env var, it will be the default, you can do a chown -R 508:508 /mnt/ssd_pool/appdata/omada-controller/data based on the path you shared. I'm guessing when you restored the files the ownership just isn't set right. The entrypoint only makes sure the parent directory has the right ownership, not the files within.

I corrected the owner but still get errors:

This is the server log error:

08-04-2024 16:25:01.764 ERROR [main] [] c.t.s.f.c.FacadeUtils(): facadeMsgEnable is not enable, msg: Fail to start mongo DB server and 08-04-2024 16:26:59.229 ERROR [mongo-check-thread] [] c.t.s.f.c.FacadeUtils(): facadeMsgEnable is not enable, msg: An unexpected error occurred in MongoDb. Omada Controller will try to restart it.

08-04-2024 16:28:54.709 ERROR [mongo-check-thread] [] c.t.s.f.c.FacadeUtils(): facadeMsgEnable is not enable, msg: An unexpected error occurred in MongoDb. Omada Controller will try to restart it. 08-04-2024 16:28:57.541 WARN [main] [] c.t.s.o.s.a.b(): Mongo Client connect error while init Jetty.com.mongodb.MongoTimeoutException: Timed out after 30000 ms while waiting to connect. Client view of cluster state is {type=UNKNOWN, servers=[{address=127.0.0.1:27217, type=UNKNOWN, state=CONNECTING, exception={com.mongodb.MongoSocketOpenException: Exception opening socket}, caused by {java.net.ConnectException: Connection refused}}]

This is the mongod.log mongod.txt

mbentley commented 1 month ago

I would have to search further but it looks like it’s corrupt data, possibly from taking a backup or snapshot while the controller (more specifically MongoDB) was running.

Tom-246 commented 1 month ago

I would have to search further but it looks like it’s corrupt data, possibly from taking a backup or snapshot while the controller (more specifically MongoDB) was running.

So I have to prepare myself to configure it again...

mbentley commented 1 month ago

I would have to search further but it looks like it’s corrupt data, possibly from taking a backup or snapshot while the controller (more specifically MongoDB) was running.

So I have to prepare myself to configure it again...

Last ditch effort - try to run a MongoDB repair:

docker run -it --rm \
  -u 508:508 \
  -v omada-data:/opt/tplink/EAPController/data \
  --entrypoint /opt/tplink/EAPController/bin/mongod \
  mbentley/omada-controller:5.13 \
    --repair \
    --dbpath /opt/tplink/EAPController/data/db \
    --bind_ip 127.0.0.1 \
    --port 27217

Make sure that the image in my example mbentley/omada-controller:5.13 matches the version you're running and be certain there are no other controller containers running at the same time.

If you do end up reconfiguring, please make sure to configure automatic backups from the controller software itself. It will export backup files for you that can be easily restored that do not rely on file based backups. I wish they would enable it by default because it takes next to zero space.

Tom-246 commented 1 month ago

This is the output of the command:

2024-08-05T08:59:34.479+0000 I CONTROL  [initandlisten] MongoDB starting : pid=1 port=27217 dbpath=/opt/tplink/EAPController/data/db 64-bit host=39cb1fed8cee
2024-08-05T08:59:34.480+0000 I CONTROL  [initandlisten] db version v3.6.8
2024-08-05T08:59:34.480+0000 I CONTROL  [initandlisten] git version: 8e540c0b6db93ce994cc548f000900bdc740f80a
2024-08-05T08:59:34.480+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.1.1f  31 Mar 2020
2024-08-05T08:59:34.480+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2024-08-05T08:59:34.480+0000 I CONTROL  [initandlisten] modules: none
2024-08-05T08:59:34.480+0000 I CONTROL  [initandlisten] build environment:
2024-08-05T08:59:34.480+0000 I CONTROL  [initandlisten]     distarch: x86_64
2024-08-05T08:59:34.480+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2024-08-05T08:59:34.480+0000 I CONTROL  [initandlisten] options: { net: { bindIp: "127.0.0.1", port: 27217 }, repair: true, storage: { dbPath: "/opt/tplink/EAPController/data/db" } }
2024-08-05T08:59:34.481+0000 I STORAGE  [initandlisten] exception in initAndListen: IllegalOperation: Attempted to create a lock file on a read-only directory: /opt/tplink/EAPController/data/db, terminating
2024-08-05T08:59:34.481+0000 I CONTROL  [initandlisten] now exiting
2024-08-05T08:59:34.481+0000 I CONTROL  [initandlisten] shutting down with code:100

There is no write-permission just read-only for db-folder. Is this because of corrupt data or is there another option/setting I have to use?

I did not change the paths given by you as I think this is working 'within' the container, correct?

mbentley commented 1 month ago

I should have also made it clear that you need to update the volume to match your persistent storage.

Change -v omada-data:/opt/tplink/EAPController/data \ to -v /mnt/ssd_pool/appdata/omada-controller/data:/opt/tplink/EAPController/data in the repair command.

Tom-246 commented 1 month ago

No, there is not enough to repair it. There is just some data within chunk 1 of 4. Chunk 2 to 4 do only show '00'.

2024-08-05T13:46:23.287+0000 E STORAGE [initandlisten] WiredTiger error (0) [1722865583:287744][1:0x14ec46e24ac0], file:sizeStorer.wt, txn-recover: sizeStorer.wt: encountered an illegal file format or internal value: (__wt_block_read_off, 302) 2024-08-05T13:46:23.287+0000 E STORAGE [initandlisten] WiredTiger error (-31804) [1722865583:287772][1:0x14ec46e24ac0], file:sizeStorer.wt, txn-recover: the process must exit and restart: WT_PANIC: WiredTiger library panic 2024-08-05T13:46:23.287+0000 F - [initandlisten] Fatal Assertion 28558 at src/mongo/db/storage/wiredtiger/wiredtiger_util.cpp 366 2024-08-05T13:46:23.287+0000 F - [initandlisten]

***aborting after fassert() failure

2024-08-05T13:46:23.304+0000 F - [initandlisten] Got signal: 6 (Aborted).

Will wait for a day where I feel the energy to do it all again. Right now the network will have to stay the way it is.

@mbentley I thank you for your time and input!! Great support!

Chiller2019 commented 1 month ago

Same error ... I just have the "latest"-Tag and WatchTower ... now my controller wont start

2 Errors:

  1. Cannot start up sbringboot
  2. Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a': Bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a' has been injected into other beans [com.tplink.smb.omada.identityaccess.domain.model.d.q] in its raw version as part of a circular reference, but has eventually been wrapped. This means that said other beans do not use the final version of the bean. This is often the result of over-eager type matching - consider using 'getBeanNamesForType' with the 'allowEagerInit' flag turned off, for example.
mbentley commented 1 month ago

Just to make sure that you saw there are instructions to get back to a working state in the first post, it links to this comment: https://github.com/mbentley/docker-omada-controller/issues/418#issuecomment-2223732459

ftrueck commented 1 month ago

I followed the steps to downgrade. I had a database problem so I did the database repair that finished normally it seemed. The controller now will not start anyways.

08-08-2024 10:08:49.702 INFO [main] [] c.t.s.o.s.d.a(): succeed in initializing default omadac OmadacVO(id=ba78d90577b52ac6344cbcb72814d62c, name=Omada Controller Lautenbach, pattern=0) 08-08-2024 10:08:49.702 ERROR [main] [] c.t.s.o.s.d.a(): Controller install failed. Failed to start. 08-08-2024 10:08:49.702 ERROR [main] [] c.t.s.f.c.FacadeUtils(): facadeMsgEnable is not enable, msg: Data abnormal due to install failed. Failed to start. 08-08-2024 10:08:49.702 INFO [main] [] c.t.s.o.s.d.a(): record: after OmadacInitTask 08-08-2024 10:08:49.702 ERROR [main] [] c.t.s.o.s.t.FailExitTask(): Failed to start omada controller, going to exit 08-08-2024 10:08:49.707 INFO [Thread-0] [] c.t.s.o.s.s.b(): Going to stop mongod which pid is 187 08-08-2024 10:08:49.752 INFO [SpringApplicationShutdownHook] [] c.t.s.e.p.b.a(): going to shutdown proxy executors 08-08-2024 10:08:49.760 WARN [SpringApplicationShutdownHook] [] o.s.c.a.CommonAnnotationBeanPostProcessor(): Destroy method on bean with name 'com.tplink.smb.omada.client.port.mongo.data.history.i' threw an exception: java.lang.ExceptionInInitializerError 08-08-2024 10:08:49.773 INFO [SpringApplicationShutdownHook] [] c.t.s.e.p.a(): going to shutdown proxy thread pools.

mbentley commented 1 month ago

The Controller install failed error tends to mean that you tried to run an older version of a controller after a newer version had run successfully as seen in this issue. That was the issue that inspired the version check that blocks starting if you run a version that is older than previously started.

Did you take a backup at any point that you could roll back to or re-install with?

ftrueck commented 1 month ago

I have a backup with the version 5.14.26.1 from Jul 17th. But i can not import this into 5.13

mbentley commented 1 month ago

You can't go from a newer version to and older version - that's the reason for the version file because rolling back will break your install. If you're stuck and you do not have any other backups, you can use the beta version which is tagged as beta-5.14.30.7. I just added information that was buried in the middle of this thread about the beta tags to the first post. Then when the GA version comes out, you can switch to that.

ftrueck commented 1 month ago

ok that seemed to work so far. My controller was restored from the backup and the devices adopted so far. It seems to work for now. Hopefully the beta has no bad side effects. :-D

Bushrider commented 1 month ago

Do someone knows how to deploy the V5.13 in Truenas Scale ? i can only install the V5.14 ...which doesn't work. Thanks

chriexpe commented 1 month ago

Had the 5.14.0.11 running just fine for a couple of months, decided to give a try on 5.14.20.19 and got that "Unsatisfied dependency" error too, but thanks to that image digest from mbentley I was able to go back and get it working.

Ok I tried out 5.14.30.7 and it's working just fine!

jeffreydwalter commented 1 month ago

I can confirm that 5.14.30.7 works for me, but the latest 5.14 does not.

ftrueck commented 1 month ago

5.14.30.7 works. 5.14.26.1 broken.

Is there a time frame known when 5.14.30.7 will be moved to main release? Is there a way i can pin my docker to this version, so that I am only that long ahead until 30.7 will be moved to main? It would be bad if 5.14-beta stays always ahead of "stable".

mbentley commented 1 month ago

TP-Link hasn’t shared any info on release timeline. I’d you specify the tag ‘beta-5.14.30.7’, it will pin you to that beta version. Then you’ll have to update the tag when a new version is out. I’ll definitely post in this thread when it’s available.

mbentley commented 2 weeks ago

FYI, I did just post to the forums asking if they had any idea about the next GA release timeline. I'm still regularly getting issues and discussions created about people having problems after upgrading to 5.14.

muirdok commented 2 weeks ago

Just FYI:

  1. Run container from mbentley/omada-controller:5.13 (works fine)
  2. Stoped/removed container.
  3. Run new container from mbentley/omada-controller:latest it failed to run:
    
    08-30-2024 13:02:07.071 ERROR [main] [] c.t.s.o.s.t.SpringBootStartUpTask(): Cannot retry start up springboot. reson:Error creating bean with name 'com.tplink.smb.omada.identityaccess.domain.model.openapi.c.q': Unsatisfied dependency expressed through field 'e'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.common.a.a': Unsatisfied dependency expressed through field 'c'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.common.e.a': Unsatisfied dependency expressed through field 'b'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.b.p': Unsatisfied dependency expressed through field 'm'; nested exception is org.springframework.beans.factory.UnsatisfiedDependencyException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.domain.model.user.A': Unsatisfied dependency expressed through field 'c'; nested exception is org.springframework.beans.factory.BeanCurrentlyInCreationException: Error creating bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a': Bean with name 'com.tplink.smb.omada.identityaccess.port.mongo.adaptor.persistence.tenant.a' has been injected into other beans [com.tplink.smb.omada.identityaccess.domain.model.d.q] in its raw version as part of a circular reference, but has eventually been wrapped. This means that said other beans do not use the final version of the bean. This is often the result of over-eager type matching - consider using 'getBeanNamesForType' with the 'allowEagerInit' flag turned off, for example.
    08-30-2024 13:02:07.071 ERROR [main] [] c.t.s.o.s.t.FailExitTask(): Failed to start omada controller, going to exit