Hi Robby/Chaya, Have you ever seen these issues, or know what could be the cause?
Thanks, William Reehil Principal Member of Technical Staff | A&AI ONAP PTL AT&T ECOMP PLATFORM AND SYSTEMS (C) 732 865-5333 | (O) 732 420-7806 From: Ankit Goel <[email protected]> Sent: Wednesday, October 20, 2021 8:12 AM To: REEHIL, WILLIAM E <[email protected]>; MAHARAJH, ROBBY <[email protected]> Cc: Vivekanandan Muthukrishnan <[email protected]>; Kavitha Papanna <[email protected]> Subject: Need help in ONAP AAI 3 node Cassandra issue Hi WILLIAM and ROBBY, I am trying to set up onap aai with 3 replica's of Cassandra running on 3 worker nodes.But dev-aai-graphadmin-create-db-schema-lb4z6 is failing. ubuntu@nodez00b06:~$ kubectl get pods -n onap -o wide | grep -i aai dev-aai-7bc84c8fb4-s5trm 0/1 Init:2/3 13 142m 10.42.3.53 k8s-worker-2 <none> <none> dev-aai-graphadmin-679d8c779c-tlvj7 0/2 Init:0/1 14 142m 10.42.1.31 k8s-worker-3 <none> <none> dev-aai-graphadmin-create-db-schema-29277 0/1 Error 0 34m 10.42.3.69 k8s-worker-2 <none> <none> dev-aai-graphadmin-create-db-schema-4hr2k 0/1 Error 0 142m 10.42.1.32 k8s-worker-3 <none> <none> dev-aai-graphadmin-create-db-schema-4w29h 0/1 Error 0 55m 10.42.3.67 k8s-worker-2 <none> <none> dev-aai-graphadmin-create-db-schema-7n7fb 0/1 Error 0 93m 10.42.1.38 k8s-worker-3 <none> <none> dev-aai-graphadmin-create-db-schema-dm67m 0/1 Error 0 114m 10.42.1.37 k8s-worker-3 <none> <none> dev-aai-graphadmin-create-db-schema-lb4z6 1/1 Running 0 12m 10.42.3.72 k8s-worker-2 <none> <none> dev-aai-graphadmin-create-db-schema-nbbxv 0/1 Error 0 72m 10.42.3.65 k8s-worker-2 <none> <none> dev-aai-resources-5576b6644b-76846 0/2 Init:2/3 13 142m 10.42.1.33 k8s-worker-3 <none> <none> dev-aai-schema-service-575b7c749b-m7rll 2/2 Running 0 142m 10.42.2.26 k8s-worker-1 <none> <none> dev-aai-traversal-b858db758-mdpvx 0/2 Init:2/3 13 142m 10.42.2.27 k8s-worker-1 <none> <none> ubuntu@nodez00b06:~$ ubuntu@nodez00b06:~$ kubectl get pods -n onap -o wide | grep -i cass dev-aaf-cass-6985b6fb7-rb7fb 1/1 Running 0 143m 10.42.1.30 k8s-worker-3 <none> <none> dev-cassandra-0 1/1 Running 0 143m 10.42.3.51 k8s-worker-2 <none> <none> dev-cassandra-1 1/1 Running 0 140m 10.42.1.36 k8s-worker-3 <none> <none> dev-cassandra-2 1/1 Running 0 138m 10.42.2.31 k8s-worker-1 <none> <none> ubuntu@nodez00b06:~$ Below is a snippet from pod console logs for dev-aai-graphadmin-create-db-schema-dm67m pod. 2021-10-20 11:25:08.199 ERROR --- [ main] o.j.graphdb.database.StandardJanusGraph : Could not commit transaction [1] due to storage exception in system-commit org.janusgraph.core.JanusGraphException: Could not execute operation due to backend exception at org.janusgraph.diskstorage.util.BackendOperation.execute(BackendOperation.java:57) at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction.persist(CacheTransaction.java:95) at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction.flushInternal(CacheTransaction.java:137) at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction.commit(CacheTransaction.java:200) at org.janusgraph.diskstorage.BackendTransaction.commit(BackendTransaction.java:151) at org.janusgraph.graphdb.database.StandardJanusGraph.commit(StandardJanusGraph.java:718) at org.janusgraph.graphdb.transaction.StandardJanusGraphTx.commit(StandardJanusGraphTx.java:1377) at org.janusgraph.graphdb.database.management.ManagementSystem.commit(ManagementSystem.java:244) at org.onap.aai.dbgen.SchemaGenerator.loadSchemaIntoJanusGraph(SchemaGenerator.java:168) at org.onap.aai.schema.GenTester.main(GenTester.java:148) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:48) at org.springframework.boot.loader.Launcher.launch(Launcher.java:87) at org.springframework.boot.loader.Launcher.launch(Launcher.java:50) at org.springframework.boot.loader.PropertiesLauncher.main(PropertiesLauncher.java:595) Caused by: org.janusgraph.diskstorage.TemporaryBackendException: Could not successfully complete backend operation due to repeated temporary exceptions after PT1M40S at org.janusgraph.diskstorage.util.BackendOperation.executeDirect(BackendOperation.java:101) at org.janusgraph.diskstorage.util.BackendOperation.execute(BackendOperation.java:55) ... 17 common frames omitted Caused by: org.janusgraph.diskstorage.locking.consistentkey.ExpiredLockException: Expired lock on KeyColumn [k=0x 16-165-160-103-105- 30-115-121-115-116-101-109- 45-105-112-118-180, c=0x 0]: lock timestamp 2021-10-20T11:20:07.024Z Micros is older than storage.lock.expiry-time=PT5M at org.janusgraph.diskstorage.locking.consistentkey.ConsistentKeyLocker.checkSingleLock(ConsistentKeyLocker.java:442) at org.janusgraph.diskstorage.locking.consistentkey.ConsistentKeyLocker.checkSingleLock(ConsistentKeyLocker.java:119) at org.janusgraph.diskstorage.locking.AbstractLocker.checkLocks(AbstractLocker.java:351) at org.janusgraph.diskstorage.locking.consistentkey.ExpectedValueCheckingTransaction.checkAllLocks(ExpectedValueCheckingTransaction.java:178) at org.janusgraph.diskstorage.locking.consistentkey.ExpectedValueCheckingTransaction.prepareForMutations(ExpectedValueCheckingTransaction.java:157) at org.janusgraph.diskstorage.locking.consistentkey.ExpectedValueCheckingStoreManager.mutateMany(ExpectedValueCheckingStoreManager.java:72) at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction$1.call(CacheTransaction.java:98) at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction$1.call(CacheTransaction.java:95) at org.janusgraph.diskstorage.util.BackendOperation.executeDirect(BackendOperation.java:69) ... 18 common frames omitted 2021-10-20 11:25:08.201 ERROR --- [ main] o.j.graphdb.database.StandardJanusGraph : Could not commit transaction [1] due to exception org.janusgraph.core.JanusGraphException: Could not execute operation due to backend exception at org.janusgraph.diskstorage.util.BackendOperation.execute(BackendOperation.java:57) at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction.persist(CacheTransaction.java:95) at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction.flushInternal(CacheTransaction.java:137) at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction.commit(CacheTransaction.java:200) at org.janusgraph.diskstorage.BackendTransaction.commit(BackendTransaction.java:151) at org.janusgraph.graphdb.database.StandardJanusGraph.commit(StandardJanusGraph.java:718) at org.janusgraph.graphdb.transaction.StandardJanusGraphTx.commit(StandardJanusGraphTx.java:1377) at org.janusgraph.graphdb.database.management.ManagementSystem.commit(ManagementSystem.java:244) at org.onap.aai.dbgen.SchemaGenerator.loadSchemaIntoJanusGraph(SchemaGenerator.java:168) at org.onap.aai.schema.GenTester.main(GenTester.java:148) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.springframework.boot.loader.MainMethodRunner.run(MainMethodRunner.java:48) at org.springframework.boot.loader.Launcher.launch(Launcher.java:87) at org.springframework.boot.loader.Launcher.launch(Launcher.java:50) at org.springframework.boot.loader.PropertiesLauncher.main(PropertiesLauncher.java:595) Caused by: org.janusgraph.diskstorage.TemporaryBackendException: Could not successfully complete backend operation due to repeated temporary exceptions after PT1M40S at org.janusgraph.diskstorage.util.BackendOperation.executeDirect(BackendOperation.java:101) at org.janusgraph.diskstorage.util.BackendOperation.execute(BackendOperation.java:55) ... 17 common frames omitted Caused by: org.janusgraph.diskstorage.locking.consistentkey.ExpiredLockException: Expired lock on KeyColumn [k=0x 16-165-160-103-105- 30-115-121-115-116-101-109- 45-105-112-118-180, c=0x 0]: lock timestamp 2021-10-20T11:20:07.024Z Micros is older than storage.lock.expiry-time=PT5M at org.janusgraph.diskstorage.locking.consistentkey.ConsistentKeyLocker.checkSingleLock(ConsistentKeyLocker.java:442) at org.janusgraph.diskstorage.locking.consistentkey.ConsistentKeyLocker.checkSingleLock(ConsistentKeyLocker.java:119) at org.janusgraph.diskstorage.locking.AbstractLocker.checkLocks(AbstractLocker.java:351) at org.janusgraph.diskstorage.locking.consistentkey.ExpectedValueCheckingTransaction.checkAllLocks(ExpectedValueCheckingTransaction.java:178) at org.janusgraph.diskstorage.locking.consistentkey.ExpectedValueCheckingTransaction.prepareForMutations(ExpectedValueCheckingTransaction.java:157) at org.janusgraph.diskstorage.locking.consistentkey.ExpectedValueCheckingStoreManager.mutateMany(ExpectedValueCheckingStoreManager.java:72) at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction$1.call(CacheTransaction.java:98) at org.janusgraph.diskstorage.keycolumnvalue.cache.CacheTransaction$1.call(CacheTransaction.java:95) at org.janusgraph.diskstorage.util.BackendOperation.executeDirect(BackendOperation.java:69) ... 18 common frames omitted 2021-10-20 11:25:08.217 ERROR --- [ main] org.onap.aai.logging.ErrorLogHelper : ERR.5.4.4000 ex=org.onap.aai.exceptions.AAIException: Could not commit transaction due to exception during persistence ClassName- org.onap.aai.logging.ErrorLogHelper :LineNumber- 616 :MethodName- logError ClassName- org.onap.aai.schema.GenTester :LineNumber- 163 :MethodName- main ClassName- sun.reflect.NativeMethodAccessorImpl :LineNumber- -2 :MethodName- invoke0 ClassName- sun.reflect.NativeMethodAccessorImpl :LineNumber- 62 :MethodName- invoke ClassName- sun.reflect.DelegatingMethodAccessorImpl :LineNumber- 43 :MethodName- invoke ClassName- java.lang.reflect.Method :LineNumber- 498 :MethodName- invoke ClassName- org.springframework.boot.loader.MainMethodRunner :LineNumber- 48 :MethodName- run ClassName- org.springframework.boot.loader.Launcher :LineNumber- 87 :MethodName- launch ClassName- org.springframework.boot.loader.Launcher :LineNumber- 50 :MethodName- launch ClassName- org.springframework.boot.loader.PropertiesLauncher :LineNumber- 595 :MethodName- main 2021-10-20 11:25:09.026 DEBUG --- [ main] com.datastax.driver.core.Connection : Connection[/10.42.2.31:9042-1, inFlight=0, closed=true] closing connection 2021-10-20 11:25:09.026 DEBUG --- [ main] com.datastax.driver.core.Host.STATES : [/10.42.2.31:9042<https://urldefense.com/v3/__http:/10.42.2.31:9042__;!!BhdT!2YWHxDO1v6Ic2_GGrqoDT3n8YiNiZ8AJ3o2t9U-xJZHOqThy5DxldgG4Ci6Eyw$>] Connection[/10.42.2.31:9042-1, inFlight=0, closed=true] closed, remaining = 0 2021-10-20 11:25:09.027 DEBUG --- [ main] com.datastax.driver.core.Connection : Connection[/10.42.1.36:9042-1, inFlight=0, closed=true] closing connection 2021-10-20 11:25:09.027 DEBUG --- [ main] com.datastax.driver.core.Host.STATES : [/10.42.1.36:9042<https://urldefense.com/v3/__http:/10.42.1.36:9042__;!!BhdT!2YWHxDO1v6Ic2_GGrqoDT3n8YiNiZ8AJ3o2t9U-xJZHOqThy5DxldgGFABCSvg$>] Connection[/10.42.1.36:9042-1, inFlight=0, closed=true] closed, remaining = 0 2021-10-20 11:25:09.029 DEBUG --- [ main] com.datastax.driver.core.Connection : Connection[cassandra/10.42.3.51:9042-2, inFlight=0, closed=true] closing connection 2021-10-20 11:25:09.029 DEBUG --- [ main] com.datastax.driver.core.Host.STATES : [cassandra/10.42.3.51:9042<https://urldefense.com/v3/__http:/10.42.3.51:9042__;!!BhdT!2YWHxDO1v6Ic2_GGrqoDT3n8YiNiZ8AJ3o2t9U-xJZHOqThy5DxldgH4wku-mA$>] Connection[cassandra/10.42.3.51:9042-2, inFlight=0, closed=true] closed, remaining = 1 2021-10-20 11:25:09.030 DEBUG --- [ main] com.datastax.driver.core.Cluster : Shutting down 2021-10-20 11:25:09.032 DEBUG --- [ main] com.datastax.driver.core.Connection : Connection[cassandra/10.42.3.51:9042-1, inFlight=0, closed=true] closing connection 2021-10-20 11:25:09.032 DEBUG --- [ main] com.datastax.driver.core.Host.STATES : [cassandra/10.42.3.51:9042<https://urldefense.com/v3/__http:/10.42.3.51:9042__;!!BhdT!2YWHxDO1v6Ic2_GGrqoDT3n8YiNiZ8AJ3o2t9U-xJZHOqThy5DxldgH4wku-mA$>] Connection[cassandra/10.42.3.51:9042-1, inFlight=0, closed=true] closed, remaining = 0 2021-10-20 11:25:11.254 DEBUG --- [er-nio-worker-0] io.netty.buffer.PoolThreadCache : Freed 66 thread-local buffer(s) from thread: JanusGraph Cluster-nio-worker-0 2021-10-20 11:25:11.254 DEBUG --- [er-nio-worker-2] io.netty.buffer.PoolThreadCache : Freed 31 thread-local buffer(s) from thread: JanusGraph Cluster-nio-worker-2 Failed to run the tool /opt/app/aai-graphadmin/bin/createDBSchema.sh successfully Failed to run the createDBSchema.sh I suspected this to be a storage lock wait time issue thus I increased it's value and redeployed it but it did not resolve the issue. It looks like cassandra is not reachable to aai. Can you please suggest what can be the issue. Your help is much appreciated. Note: It is working fine for me when I just have one worker node and all the 3 replica's of cassandra are running on that node. Best Regards, Ankit Goel -=-=-=-=-=-=-=-=-=-=-=- Links: You receive all messages sent to this group. View/Reply Online (#23625): https://lists.onap.org/g/onap-discuss/message/23625 Mute This Topic: https://lists.onap.org/mt/86601871/21656 Group Owner: [email protected] Unsubscribe: https://lists.onap.org/g/onap-discuss/unsub [[email protected]] -=-=-=-=-=-=-=-=-=-=-=-
