[AAA-187] aaa datastore failures when writing domain during startup and authentication fails breaking CSIT Created: 22/Oct/19 Updated: 17/Jan/23 Resolved: 13/Jan/23 |
|
| Status: | Resolved |
| Project: | aaa |
| Component/s: | None |
| Affects Version/s: | Sodium |
| Fix Version/s: | None |
| Type: | Bug | Priority: | Medium |
| Reporter: | Jamo Luhrsen | Assignee: | Yaroslav Lastivka |
| Resolution: | Won't Do | Votes: | 0 |
| Labels: | pt | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Attachments: |
maven-tests-output.log
odl3_karaf.log
|
||||||||
| Issue Links: |
|
||||||||
| Description |
|
This seems intermittent and was seen once in a controller csit job that restarts the controllers attached is karaf log of the failing controller. |
| Comments |
| Comment by Robert Varga [ 22/Oct/19 ] |
2019-10-16T15:40:24,084 | INFO | Blueprint Extender: 3 | AbstractStore | 211 - org.opendaylight.aaa.shiro - 0.10.1 | Table DOMAINS does not exist, creating it 2019-10-16T15:40:24,137 | INFO | Blueprint Extender: 2 | FlowCapableTopologyProvider | 414 - org.opendaylight.openflowplugin.applications.topology-manager - 0.9.1 | Topology Manager service started. 2019-10-16T15:40:24,157 | ERROR | Blueprint Extender: 3 | H2Store | 211 - org.opendaylight.aaa.shiro - 0.10.1 | StoreException encountered while writing domain org.opendaylight.aaa.datastore.h2.StoreException: Cannot connect to database server at org.opendaylight.aaa.datastore.h2.IdmLightSimpleConnectionProvider.getConnection(IdmLightSimpleConnectionProvider.java:33) ~[211:org.opendaylight.aaa.shiro:0.10.1] at org.opendaylight.aaa.datastore.h2.AbstractStore.dbConnect(AbstractStore.java:68) ~[211:org.opendaylight.aaa.shiro:0.10.1] at org.opendaylight.aaa.datastore.h2.DomainStore.createDomain(DomainStore.java:100) ~[211:org.opendaylight.aaa.shiro:0.10.1] at org.opendaylight.aaa.datastore.h2.H2Store.writeDomain(H2Store.java:50) [211:org.opendaylight.aaa.shiro:0.10.1] at org.opendaylight.aaa.api.StoreBuilder.initDomainAndRolesWithoutUsers(StoreBuilder.java:84) [204:org.opendaylight.aaa.authn-api:0.10.1] at org.opendaylight.aaa.api.StoreBuilder.initWithDefaultUsers(StoreBuilder.java:114) [204:org.opendaylight.aaa.authn-api:0.10.1] at org.opendaylight.aaa.AAAShiroProvider.initializeIIDMStore(AAAShiroProvider.java:111) [211:org.opendaylight.aaa.shiro:0.10.1] at org.opendaylight.aaa.AAAShiroProvider.<init>(AAAShiroProvider.java:85) [211:org.opendaylight.aaa.shiro:0.10.1] at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:?] at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) [?:?] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) [?:?] at java.lang.reflect.Constructor.newInstance(Constructor.java:423) [?:?] at org.apache.aries.blueprint.utils.ReflectionUtils.newInstance(ReflectionUtils.java:369) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.newInstance(BeanRecipe.java:839) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromType(BeanRecipe.java:350) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.getInstance(BeanRecipe.java:283) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate2(BeanRecipe.java:685) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.java:666) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe$1.call(AbstractRecipe.java:81) [84:org.apache.aries.blueprint.core:1.10.1] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:90) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.RefRecipe.internalCreate(RefRecipe.java:62) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:108) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.getFactoryObj(BeanRecipe.java:309) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromFactory(BeanRecipe.java:289) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.getInstance(BeanRecipe.java:279) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate2(BeanRecipe.java:685) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.java:666) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:108) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.getInstance(BeanRecipe.java:268) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate2(BeanRecipe.java:685) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.java:666) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe$1.call(AbstractRecipe.java:81) [84:org.apache.aries.blueprint.core:1.10.1] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:90) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.RefRecipe.internalCreate(RefRecipe.java:62) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:108) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.getInstance(BeanRecipe.java:268) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate2(BeanRecipe.java:685) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.java:666) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe$1.call(AbstractRecipe.java:81) [84:org.apache.aries.blueprint.core:1.10.1] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:90) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.RefRecipe.internalCreate(RefRecipe.java:62) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:108) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.ServiceRecipe.createService(ServiceRecipe.java:285) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.ServiceRecipe.internalGetService(ServiceRecipe.java:252) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.ServiceRecipe.internalCreate(ServiceRecipe.java:149) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe$1.call(AbstractRecipe.java:81) [84:org.apache.aries.blueprint.core:1.10.1] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:90) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BlueprintRepository.createInstances(BlueprintRepository.java:360) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BlueprintRepository.createAll(BlueprintRepository.java:190) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BlueprintContainerImpl.instantiateEagerComponents(BlueprintContainerImpl.java:717) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BlueprintContainerImpl.doRun(BlueprintContainerImpl.java:413) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BlueprintContainerImpl.run(BlueprintContainerImpl.java:278) [84:org.apache.aries.blueprint.core:1.10.1] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at org.apache.aries.blueprint.container.ExecutorServiceWrapper.run(ExecutorServiceWrapper.java:106) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.utils.threading.impl.DiscardableRunnable.run(DiscardableRunnable.java:45) [84:org.apache.aries.blueprint.core:1.10.1] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?] at java.lang.Thread.run(Thread.java:748) [?:?] Caused by: org.h2.jdbc.JdbcSQLNonTransientException: General error: "java.lang.RuntimeException: Incompatible key type, expected org.h2.mvstore.db.ValueDataType@8ad7ca79 but got org.h2.mvstore.type.ObjectDataType@6036ebb6 for index CONSTRAINT_INDEX_9" [50000-199] at org.h2.message.DbException.getJdbcSQLException(DbException.java:502) ~[?:?] at org.h2.message.DbException.getJdbcSQLException(DbException.java:427) ~[?:?] at org.h2.message.DbException.get(DbException.java:194) ~[?:?] at org.h2.message.DbException.convert(DbException.java:347) ~[?:?] at org.h2.engine.Database.openDatabase(Database.java:345) ~[?:?] at org.h2.engine.Database.<init>(Database.java:313) ~[?:?] at org.h2.engine.Engine.openSession(Engine.java:69) ~[?:?] at org.h2.engine.Engine.openSession(Engine.java:201) ~[?:?] at org.h2.engine.Engine.createSessionAndValidate(Engine.java:178) ~[?:?] at org.h2.engine.Engine.createSession(Engine.java:161) ~[?:?] at org.h2.engine.Engine.createSession(Engine.java:31) ~[?:?] at org.h2.engine.SessionRemote.connectEmbeddedOrServer(SessionRemote.java:336) ~[?:?] at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:169) ~[?:?] at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:148) ~[?:?] at org.h2.Driver.connect(Driver.java:69) ~[?:?] at java.sql.DriverManager.getConnection(DriverManager.java:664) ~[?:?] at java.sql.DriverManager.getConnection(DriverManager.java:247) ~[?:?] at org.opendaylight.aaa.datastore.h2.IdmLightSimpleConnectionProvider.getConnection(IdmLightSimpleConnectionProvider.java:31) ~[?:?] ... 66 more Caused by: java.lang.RuntimeException: Incompatible key type, expected org.h2.mvstore.db.ValueDataType@8ad7ca79 but got org.h2.mvstore.type.ObjectDataType@6036ebb6 for index CONSTRAINT_INDEX_9 at org.h2.message.DbException.throwInternalError(DbException.java:293) ~[?:?] at org.h2.mvstore.db.MVSecondaryIndex.<init>(MVSecondaryIndex.java:74) ~[?:?] at org.h2.mvstore.db.MVTable.addIndex(MVTable.java:381) ~[?:?] at org.h2.command.ddl.CreateIndex.update(CreateIndex.java:107) ~[?:?] at org.h2.engine.MetaRecord.execute(MetaRecord.java:60) ~[?:?] at org.h2.engine.Database.open(Database.java:842) ~[?:?] at org.h2.engine.Database.openDatabase(Database.java:319) ~[?:?] at org.h2.engine.Database.<init>(Database.java:313) ~[?:?] at org.h2.engine.Engine.openSession(Engine.java:69) ~[?:?] at org.h2.engine.Engine.openSession(Engine.java:201) ~[?:?] at org.h2.engine.Engine.createSessionAndValidate(Engine.java:178) ~[?:?] at org.h2.engine.Engine.createSession(Engine.java:161) ~[?:?] at org.h2.engine.Engine.createSession(Engine.java:31) ~[?:?] at org.h2.engine.SessionRemote.connectEmbeddedOrServer(SessionRemote.java:336) ~[?:?] at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:169) ~[?:?] at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:148) ~[?:?] at org.h2.Driver.connect(Driver.java:69) ~[?:?] at java.sql.DriverManager.getConnection(DriverManager.java:664) ~[?:?] at java.sql.DriverManager.getConnection(DriverManager.java:247) ~[?:?] at org.opendaylight.aaa.datastore.h2.IdmLightSimpleConnectionProvider.getConnection(IdmLightSimpleConnectionProvider.java:31) ~[?:?] ... 66 more 2019-10-16T15:40:24,200 | ERROR | Blueprint Extender: 3 | AAAShiroProvider | 211 - org.opendaylight.aaa.shiro - 0.10.1 | Failed to initialize data in store org.opendaylight.aaa.api.IDMStoreException: org.opendaylight.aaa.datastore.h2.StoreException: Cannot connect to database server at org.opendaylight.aaa.datastore.h2.H2Store.writeDomain(H2Store.java:53) ~[?:?] at org.opendaylight.aaa.api.StoreBuilder.initDomainAndRolesWithoutUsers(StoreBuilder.java:84) ~[204:org.opendaylight.aaa.authn-api:0.10.1] at org.opendaylight.aaa.api.StoreBuilder.initWithDefaultUsers(StoreBuilder.java:114) ~[204:org.opendaylight.aaa.authn-api:0.10.1] at org.opendaylight.aaa.AAAShiroProvider.initializeIIDMStore(AAAShiroProvider.java:111) [211:org.opendaylight.aaa.shiro:0.10.1] at org.opendaylight.aaa.AAAShiroProvider.<init>(AAAShiroProvider.java:85) [211:org.opendaylight.aaa.shiro:0.10.1] at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) ~[?:?] at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) [?:?] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) [?:?] at java.lang.reflect.Constructor.newInstance(Constructor.java:423) [?:?] at org.apache.aries.blueprint.utils.ReflectionUtils.newInstance(ReflectionUtils.java:369) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.newInstance(BeanRecipe.java:839) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromType(BeanRecipe.java:350) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.getInstance(BeanRecipe.java:283) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate2(BeanRecipe.java:685) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.java:666) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe$1.call(AbstractRecipe.java:81) [84:org.apache.aries.blueprint.core:1.10.1] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:90) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.RefRecipe.internalCreate(RefRecipe.java:62) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:108) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.getFactoryObj(BeanRecipe.java:309) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.getInstanceFromFactory(BeanRecipe.java:289) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.getInstance(BeanRecipe.java:279) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate2(BeanRecipe.java:685) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.java:666) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:108) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.getInstance(BeanRecipe.java:268) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate2(BeanRecipe.java:685) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.java:666) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe$1.call(AbstractRecipe.java:81) [84:org.apache.aries.blueprint.core:1.10.1] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:90) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.RefRecipe.internalCreate(RefRecipe.java:62) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:108) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.getInstance(BeanRecipe.java:268) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate2(BeanRecipe.java:685) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BeanRecipe.internalCreate(BeanRecipe.java:666) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe$1.call(AbstractRecipe.java:81) [84:org.apache.aries.blueprint.core:1.10.1] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:90) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.RefRecipe.internalCreate(RefRecipe.java:62) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:108) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.ServiceRecipe.createService(ServiceRecipe.java:285) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.ServiceRecipe.internalGetService(ServiceRecipe.java:252) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.ServiceRecipe.internalCreate(ServiceRecipe.java:149) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.di.AbstractRecipe$1.call(AbstractRecipe.java:81) [84:org.apache.aries.blueprint.core:1.10.1] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at org.apache.aries.blueprint.di.AbstractRecipe.create(AbstractRecipe.java:90) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BlueprintRepository.createInstances(BlueprintRepository.java:360) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BlueprintRepository.createAll(BlueprintRepository.java:190) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BlueprintContainerImpl.instantiateEagerComponents(BlueprintContainerImpl.java:717) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BlueprintContainerImpl.doRun(BlueprintContainerImpl.java:413) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.container.BlueprintContainerImpl.run(BlueprintContainerImpl.java:278) [84:org.apache.aries.blueprint.core:1.10.1] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at org.apache.aries.blueprint.container.ExecutorServiceWrapper.run(ExecutorServiceWrapper.java:106) [84:org.apache.aries.blueprint.core:1.10.1] at org.apache.aries.blueprint.utils.threading.impl.DiscardableRunnable.run(DiscardableRunnable.java:45) [84:org.apache.aries.blueprint.core:1.10.1] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?] at java.lang.Thread.run(Thread.java:748) [?:?] Caused by: org.opendaylight.aaa.datastore.h2.StoreException: Cannot connect to database server at org.opendaylight.aaa.datastore.h2.IdmLightSimpleConnectionProvider.getConnection(IdmLightSimpleConnectionProvider.java:33) ~[?:?] at org.opendaylight.aaa.datastore.h2.AbstractStore.dbConnect(AbstractStore.java:68) ~[?:?] at org.opendaylight.aaa.datastore.h2.DomainStore.createDomain(DomainStore.java:100) ~[?:?] at org.opendaylight.aaa.datastore.h2.H2Store.writeDomain(H2Store.java:50) ~[?:?] ... 63 more Caused by: org.h2.jdbc.JdbcSQLNonTransientException: General error: "java.lang.RuntimeException: Incompatible key type, expected org.h2.mvstore.db.ValueDataType@8ad7ca79 but got org.h2.mvstore.type.ObjectDataType@6036ebb6 for index CONSTRAINT_INDEX_9" [50000-199] at org.h2.message.DbException.getJdbcSQLException(DbException.java:502) ~[?:?] at org.h2.message.DbException.getJdbcSQLException(DbException.java:427) ~[?:?] at org.h2.message.DbException.get(DbException.java:194) ~[?:?] at org.h2.message.DbException.convert(DbException.java:347) ~[?:?] at org.h2.engine.Database.openDatabase(Database.java:345) ~[?:?] at org.h2.engine.Database.<init>(Database.java:313) ~[?:?] at org.h2.engine.Engine.openSession(Engine.java:69) ~[?:?] at org.h2.engine.Engine.openSession(Engine.java:201) ~[?:?] at org.h2.engine.Engine.createSessionAndValidate(Engine.java:178) ~[?:?] at org.h2.engine.Engine.createSession(Engine.java:161) ~[?:?] at org.h2.engine.Engine.createSession(Engine.java:31) ~[?:?] at org.h2.engine.SessionRemote.connectEmbeddedOrServer(SessionRemote.java:336) ~[?:?] at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:169) ~[?:?] at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:148) ~[?:?] at org.h2.Driver.connect(Driver.java:69) ~[?:?] at java.sql.DriverManager.getConnection(DriverManager.java:664) ~[?:?] at java.sql.DriverManager.getConnection(DriverManager.java:247) ~[?:?] at org.opendaylight.aaa.datastore.h2.IdmLightSimpleConnectionProvider.getConnection(IdmLightSimpleConnectionProvider.java:31) ~[?:?] at org.opendaylight.aaa.datastore.h2.AbstractStore.dbConnect(AbstractStore.java:68) ~[?:?] at org.opendaylight.aaa.datastore.h2.DomainStore.createDomain(DomainStore.java:100) ~[?:?] at org.opendaylight.aaa.datastore.h2.H2Store.writeDomain(H2Store.java:50) ~[?:?] ... 63 more Caused by: java.lang.RuntimeException: Incompatible key type, expected org.h2.mvstore.db.ValueDataType@8ad7ca79 but got org.h2.mvstore.type.ObjectDataType@6036ebb6 for index CONSTRAINT_INDEX_9 at org.h2.message.DbException.throwInternalError(DbException.java:293) ~[?:?] at org.h2.mvstore.db.MVSecondaryIndex.<init>(MVSecondaryIndex.java:74) ~[?:?] at org.h2.mvstore.db.MVTable.addIndex(MVTable.java:381) ~[?:?] at org.h2.command.ddl.CreateIndex.update(CreateIndex.java:107) ~[?:?] at org.h2.engine.MetaRecord.execute(MetaRecord.java:60) ~[?:?] at org.h2.engine.Database.open(Database.java:842) ~[?:?] at org.h2.engine.Database.openDatabase(Database.java:319) ~[?:?] at org.h2.engine.Database.<init>(Database.java:313) ~[?:?] at org.h2.engine.Engine.openSession(Engine.java:69) ~[?:?] at org.h2.engine.Engine.openSession(Engine.java:201) ~[?:?] at org.h2.engine.Engine.createSessionAndValidate(Engine.java:178) ~[?:?] at org.h2.engine.Engine.createSession(Engine.java:161) ~[?:?] at org.h2.engine.Engine.createSession(Engine.java:31) ~[?:?] at org.h2.engine.SessionRemote.connectEmbeddedOrServer(SessionRemote.java:336) ~[?:?] at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:169) ~[?:?] at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:148) ~[?:?] at org.h2.Driver.connect(Driver.java:69) ~[?:?] at java.sql.DriverManager.getConnection(DriverManager.java:664) ~[?:?] at java.sql.DriverManager.getConnection(DriverManager.java:247) ~[?:?] at org.opendaylight.aaa.datastore.h2.IdmLightSimpleConnectionProvider.getConnection(IdmLightSimpleConnectionProvider.java:31) ~[?:?] at org.opendaylight.aaa.datastore.h2.AbstractStore.dbConnect(AbstractStore.java:68) ~[?:?] at org.opendaylight.aaa.datastore.h2.DomainStore.createDomain(DomainStore.java:100) ~[?:?] at org.opendaylight.aaa.datastore.h2.H2Store.writeDomain(H2Store.java:50) ~[?:?] ... 63 more 2019-10-16T15:40:24,235 | INFO | Blueprint Extender: 3 | AAAShiroProvider | 211 - org.opendaylight.aaa.shiro - 0.10.1 | attempting registration of AAA moon servlet |
| Comment by Robert Varga [ 22/Oct/19 ] |
|
... and that results in repeated: 2019-10-16T15:40:37,468 | WARN | qtp2096944162-103 | AbstractAuthenticator | 138 - org.apache.shiro.core - 1.3.2 | Authentication failed for token submission [org.apache.shiro.authc.UsernamePasswordToken - admin, rememberMe=false]. Possible unexpected error? (Typical or expected login exceptions should extend from AuthenticationException). org.opendaylight.aaa.api.AuthenticationException: Domain :sdn does not exist at org.opendaylight.aaa.shiro.idm.IdmLightProxy.dbAuthenticate(IdmLightProxy.java:89) ~[?:?] at java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1660) ~[?:?] at org.opendaylight.aaa.shiro.idm.IdmLightProxy.authenticate(IdmLightProxy.java:67) ~[?:?] at org.opendaylight.aaa.shiro.idm.IdmLightProxy.authenticate(IdmLightProxy.java:40) ~[?:?] at org.opendaylight.aaa.shiro.tokenauthrealm.auth.HttpBasicAuth.generateAuthentication(HttpBasicAuth.java:102) ~[?:?] at org.opendaylight.aaa.shiro.tokenauthrealm.auth.HttpBasicAuth.validate(HttpBasicAuth.java:122) ~[?:?] at org.opendaylight.aaa.shiro.realm.TokenAuthRealm.doGetAuthenticationInfo(TokenAuthRealm.java:147) ~[?:?] at org.apache.shiro.realm.AuthenticatingRealm.getAuthenticationInfo(AuthenticatingRealm.java:568) ~[138:org.apache.shiro.core:1.3.2] at org.apache.shiro.authc.pam.ModularRealmAuthenticator.doSingleRealmAuthentication(ModularRealmAuthenticator.java:180) ~[138:org.apache.shiro.core:1.3.2] at org.apache.shiro.authc.pam.ModularRealmAuthenticator.doAuthenticate(ModularRealmAuthenticator.java:267) ~[138:org.apache.shiro.core:1.3.2] at org.apache.shiro.authc.AbstractAuthenticator.authenticate(AbstractAuthenticator.java:198) [138:org.apache.shiro.core:1.3.2] at org.apache.shiro.mgt.AuthenticatingSecurityManager.authenticate(AuthenticatingSecurityManager.java:106) [138:org.apache.shiro.core:1.3.2] at org.apache.shiro.mgt.DefaultSecurityManager.login(DefaultSecurityManager.java:270) [138:org.apache.shiro.core:1.3.2] at org.apache.shiro.subject.support.DelegatingSubject.login(DelegatingSubject.java:256) [138:org.apache.shiro.core:1.3.2] at org.opendaylight.aaa.authenticator.ODLAuthenticator.login(ODLAuthenticator.java:80) [211:org.opendaylight.aaa.shiro:0.10.1] at org.opendaylight.aaa.authenticator.ODLAuthenticator.authenticate(ODLAuthenticator.java:50) [211:org.opendaylight.aaa.shiro:0.10.1] at Proxy9feea8bd_64a3_446f_aae7_822e2d110560.authenticate(Unknown Source) [?:?] at org.jolokia.osgi.security.ServiceAuthenticationHttpContext.handleSecurity(ServiceAuthenticationHttpContext.java:72) [193:org.jolokia.osgi:1.6.2] at org.ops4j.pax.web.service.internal.WebContainerContextWrapper.handleSecurity(WebContainerContextWrapper.java:46) [499:org.ops4j.pax.web.pax-web-runtime:7.2.5] at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:69) [497:org.ops4j.pax.web.pax-web-jetty:7.2.5] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:146) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [154:org.eclipse.jetty.security:9.4.12.v20180830] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:257) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1340) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:293) [497:org.ops4j.pax.web.pax-web-jetty:7.2.5] at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [157:org.eclipse.jetty.servlet:9.4.12.v20180830] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1242) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) [497:org.ops4j.pax.web.pax-web-jetty:7.2.5] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.eclipse.jetty.server.Server.handle(Server.java:503) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) [156:org.eclipse.jetty.server:9.4.12.v20180830] at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305) [148:org.eclipse.jetty.io:9.4.12.v20180830] at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [148:org.eclipse.jetty.io:9.4.12.v20180830] at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) [148:org.eclipse.jetty.io:9.4.12.v20180830] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765) [159:org.eclipse.jetty.util:9.4.12.v20180830] at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683) [159:org.eclipse.jetty.util:9.4.12.v20180830] at java.lang.Thread.run(Thread.java:748) [?:?] |
| Comment by Robert Varga [ 22/Oct/19 ] |
|
This is coming from H2 quarters, which I know nothing about |
| Comment by Robert Varga [ 06/Jul/22 ] |
|
We need to check to see if this is still reproducible. |
| Comment by Oleksandr Zharov [ 11/Aug/22 ] |
|
I was not able to find in CSIT jobs logs for controller this error or some errors referring to H2. I tried reproducing it locally but not sure if it possible just though running auth requests(or I did it wrong). Looking at changes of H2 since 2019 I believe this problem went away. |
| Comment by Ivan Hrasko [ 29/Nov/22 ] |
|
Error has happened in cluster environment (broken link points to cluster tests). yaroslav.lastivka we need to investigate (make research on the internet) what can cause java.lang.RuntimeException: Incompatible key type error. |
| Comment by Ivan Hrasko [ 29/Nov/22 ] |
Caused by: org.h2.jdbc.JdbcSQLNonTransientException: General error: "java.lang.RuntimeException: Incompatible key type, expected org.h2.mvstore.db.ValueDataType@8ad7ca79 but got org.h2.mvstore.type.ObjectDataType@6036ebb6 for index CONSTRAINT_INDEX_9" [50000-199] Probably we have to investigate MoonRealm and MoonServlet in AAA. |
| Comment by Ivan Hrasko [ 29/Nov/22 ] |
|
Yes, IMO its because connection to database has not been established. |
| Comment by Ivan Hrasko [ 05/Jan/23 ] |
|
According to logs h2 version used was version 1.4.199. I have found similar issue in h2 but it has (just) been fixed in version [1.4.199|https://github.com/h2database/h2database/blob/version-1.4.199/h2/src/docsrc/html/changelog.html]. |
| Comment by Yaroslav Lastivka [ 12/Jan/23 ] |
|
I could reproduce h2 issue with version 1.4.199 of h2, Java 8 and maven heap size of 64 megabytes. But I was not able to reproduce it with Java 17 |
| Comment by Ivan Hrasko [ 13/Jan/23 ] |
|
OK, please provide the log from successful reproduction. |
| Comment by Ivan Hrasko [ 13/Jan/23 ] |
|
What h2 version have you used with Java 17? |
| Comment by Yaroslav Lastivka [ 13/Jan/23 ] |
|
I could not run the version 1.4.199 with Java 17, I have used latest version |
| Comment by Ivan Hrasko [ 13/Jan/23 ] |
|
Running `h2database/h2/temp> java -Xmx64m org.h2.test.synth.TestDiskFull -cp org/h2/` with version 1.4.199 produces no errors. |
| Comment by Ivan Hrasko [ 13/Jan/23 ] |
|
(h2 version 1.4.199) After running `h2database/h2/temp> for i in {1..1000}; do java -Xmx64m org.h2.test.synth.TestDiskFull -cp org/h2/; done` we get: Exception in thread "MVStore background writer unstable:memFS:/diskFull28.mv.db" java.lang.IllegalStateException: This store is closed [1.4.190/4] at org.h2.mvstore.DataUtils.newIllegalStateException(DataUtils.java:774) at org.h2.mvstore.MVStore.checkOpen(MVStore.java:2396) at org.h2.mvstore.MVStore.hasUnsavedChanges(MVStore.java:1552) at org.h2.mvstore.MVStore.writeInBackground(MVStore.java:2474) at org.h2.mvstore.MVStore$BackgroundWriterThread.run(MVStore.java:2689) Caused by: java.lang.IllegalStateException: Writing to cache:unstable:unstable:memFS:/diskFull28.mv.db failed; length 4096 at 16384 [1.4.190/2] at org.h2.mvstore.DataUtils.newIllegalStateException(DataUtils.java:774) at org.h2.mvstore.DataUtils.writeFully(DataUtils.java:466) at org.h2.mvstore.FileStore.writeFully(FileStore.java:113) at org.h2.mvstore.MVStore.write(MVStore.java:839) at org.h2.mvstore.MVStore.storeNowTry(MVStore.java:1199) at org.h2.mvstore.MVStore.storeNow(MVStore.java:1046) at org.h2.mvstore.MVStore.commitAndSave(MVStore.java:1035) at org.h2.mvstore.MVStore.commit(MVStore.java:996) at org.h2.mvstore.db.MVTableEngine$Store.flush(MVTableEngine.java:231) at org.h2.engine.Database.checkpoint(Database.java:2600) at org.h2.command.dml.TransactionCommand.update(TransactionCommand.java:53) at org.h2.command.CommandContainer.update(CommandContainer.java:78) at org.h2.command.Command.executeUpdate(Command.java:253) at org.h2.jdbc.JdbcStatement.executeInternal(JdbcStatement.java:184) at org.h2.jdbc.JdbcStatement.execute(JdbcStatement.java:158) at org.h2.test.synth.TestDiskFull.test(TestDiskFull.java:73) at org.h2.test.synth.TestDiskFull.test(TestDiskFull.java:45) at org.h2.test.synth.TestDiskFull.main(TestDiskFull.java:30) Caused by: java.io.IOException: Disk full at org.h2.test.utils.FilePathUnstable.<clinit>(FilePathUnstable.java:29) at org.h2.test.synth.TestDiskFull.test(TestDiskFull.java:35) ... 1 more |
| Comment by Ivan Hrasko [ 13/Jan/23 ] |
|
In general, I think that H2 can fails from time to time |
| Comment by Ivan Hrasko [ 13/Jan/23 ] |
|
Next occurrence in version 1.4.199 with command `for i in {1..1000}; do java -Xmx8m org.h2.test.synth.TestDiskFull -cp org/h2/; done`: Exception in thread "main" org.h2.jdbc.JdbcSQLException: Database may be already in use: "Waited for database closing longer than 1 minute". Possible solutions: close all other connection(s); use the server mode [90020-190] at org.h2.message.DbException.getJdbcSQLException(DbException.java:345) at org.h2.message.DbException.get(DbException.java:179) at org.h2.message.DbException.get(DbException.java:155) at org.h2.engine.Engine.openSession(Engine.java:183) at org.h2.engine.Engine.createSessionAndValidate(Engine.java:153) at org.h2.engine.Engine.createSession(Engine.java:136) at org.h2.engine.Engine.createSession(Engine.java:28) at org.h2.engine.SessionRemote.connectEmbeddedOrServer(SessionRemote.java:349) at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:107) at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:91) at org.h2.Driver.connect(Driver.java:72) at java.sql.DriverManager.getConnection(DriverManager.java:664) at java.sql.DriverManager.getConnection(DriverManager.java:270) at org.h2.test.synth.TestDiskFull.test(TestDiskFull.java:121) at org.h2.test.synth.TestDiskFull.test(TestDiskFull.java:45) at org.h2.test.synth.TestDiskFull.main(TestDiskFull.java:30) Exception in thread "main" org.h2.jdbc.JdbcSQLException: General error: "java.lang.RuntimeException: rowcount remaining=-1 SYS" [50000-190] at org.h2.message.DbException.getJdbcSQLException(DbException.java:345) at org.h2.message.DbException.get(DbException.java:168) at org.h2.message.DbException.convert(DbException.java:295) at org.h2.engine.Database.openDatabase(Database.java:300) at org.h2.engine.Database.<init>(Database.java:263) at org.h2.engine.Engine.openSession(Engine.java:65) at org.h2.engine.Engine.openSession(Engine.java:175) at org.h2.engine.Engine.createSessionAndValidate(Engine.java:153) at org.h2.engine.Engine.createSession(Engine.java:136) at org.h2.engine.Engine.createSession(Engine.java:28) at org.h2.engine.SessionRemote.connectEmbeddedOrServer(SessionRemote.java:349) at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:107) at org.h2.jdbc.JdbcConnection.<init>(JdbcConnection.java:91) at org.h2.Driver.connect(Driver.java:72) at java.sql.DriverManager.getConnection(DriverManager.java:664) at java.sql.DriverManager.getConnection(DriverManager.java:270) at org.h2.test.synth.TestDiskFull.test(TestDiskFull.java:121) at org.h2.test.synth.TestDiskFull.test(TestDiskFull.java:45) at org.h2.test.synth.TestDiskFull.main(TestDiskFull.java:30) Caused by: java.lang.RuntimeException: rowcount remaining=-1 SYS at org.h2.message.DbException.throwInternalError(DbException.java:242) at org.h2.mvstore.db.MVTable.rebuildIndexBlockMerge(MVTable.java:596) at org.h2.mvstore.db.MVTable.rebuildIndex(MVTable.java:530) at org.h2.mvstore.db.MVTable.addIndex(MVTable.java:507) at org.h2.engine.Database.open(Database.java:723) at org.h2.engine.Database.openDatabase(Database.java:269) ... 15 more |
| Comment by Ivan Hrasko [ 13/Jan/23 ] |
|
As seen in recent comments some problems are still reproducible in 1.4.199 when running, for example: `h2database/h2/temp> for i in {1..1000}; do java -Xmx8m org.h2.test.synth.TestDiskFull -cp org/h2/; done`. |
| Comment by Ivan Hrasko [ 13/Jan/23 ] |
|
Its difficult to determine what [^h2-output.log]means. |
| Comment by Ivan Hrasko [ 13/Jan/23 ] |
|
In addition, h2 version 2.1.214 runs command `h2database/h2/temp> for i in {1..1000}; do java -Xmx8m org.h2.test.synth.TestDiskFull -cp org/h2/; done` successfully without any errors/exceptions. |
| Comment by Ivan Hrasko [ 13/Jan/23 ] |
|
No, MoonRealm and MoonServlet have most probably nothing to do with the issue. |
| Comment by Ivan Hrasko [ 13/Jan/23 ] |
|
The problems are caused by h2 database (version 1.4.199) used by ODL Sodium thus this bug is invalid. IN addition we have proven that the most recent version used in ODL (h2 version 2.1.214) is more stable. |
| Comment by Ivan Hrasko [ 13/Jan/23 ] |
|
This is problem in older h2 database version. We have nothing to do in ODL. |
why are we not keeping it in the datastore? (we do in other places)
.. thus this issue is not bug in ODL at all.