[CONTROLLER-769] Clustering: Flow Delete fails with clustered data store large scale test Created: 04/Sep/14  Updated: 16/Sep/14  Resolved: 16/Sep/14

Status: Resolved
Project: controller
Component/s: mdsal
Affects Version/s: Helium
Fix Version/s: None

Type: Bug
Reporter: Jan Medved Assignee: Moiz Raja
Resolution: Cannot Reproduce Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: Mac OS
Platform: PC


Attachments: File config_cleanup.py     File flow_config_perf.py     File inventory_crawler.py    
External issue ID: 1708
Priority: Normal

 Description   

The MD-SAL data store performance test adds/deletes flows in the MD-SAL config data store. With 50k flows, the delete part fails, and the controller locks up. Attempts to restart the controller failed with the exceptions below.

The script to run the performance test is attached, and it was run with the following parameters:

python flow_config_perf.py --nflows 500 --nthreads=5 --ncycles 20

The exceptions seen on subsequent controller restarts are:

JMEDVED-M-304L:opendaylight jmedved$ ./run.sh -Xmx4G -XX:+UseG1GC -XX:MaxPermSize=512m
JVM maximum memory was set to -Xmx4G.
osgi> GossipRouter started at Wed Sep 03 22:57:01 PDT 2014
Listening on port 12001 bound on address 0.0.0.0/0.0.0.0
Backlog is 1000, linger timeout is 2000, and read timeout is 0
2014-09-03 22:57:06 PDT [org.apache.catalina.mbeans.GlobalResourcesLifecycleListener] SEVERE org.apache.catalina.mbeans.GlobalResourcesLifecycleListener createMBeans No global naming context defined for server
2014-09-03 22:57:13 PDT [com.sun.jersey.core.spi.component.ProviderServices] SEVERE com.sun.jersey.core.spi.component.ProviderServices getInstances The class org.opendaylight.aaa.sts.TokenAuthFilter could not be found. This class is ignored.
2014-09-03 22:57:13 PDT [com.sun.jersey.spi.inject.Errors] WARNING com.sun.jersey.spi.inject.Errors processErrorMessages The following warnings have been detected with resource and/or provider classes:
WARNING: Parameter 2 of type org.opendaylight.yangtools.yang.data.api.Node<?> from public abstract javax.ws.rs.core.Response org.opendaylight.controller.sal.rest.api.RestconfService.updateConfigurationData(java.lang.String,org.opendaylight.yangtools.yang.data.api.Node<?>) is not resolvable to a concrete type
WARNING: Parameter 2 of type org.opendaylight.yangtools.yang.data.api.Node<?> from public abstract javax.ws.rs.core.Response org.opendaylight.controller.sal.rest.api.RestconfService.createConfigurationData(java.lang.String,org.opendaylight.yangtools.yang.data.api.Node<?>) is not resolvable to a concrete type
WARNING: Parameter 1 of type org.opendaylight.yangtools.yang.data.api.Node<?> from public abstract javax.ws.rs.core.Response org.opendaylight.controller.sal.rest.api.RestconfService.createConfigurationData(org.opendaylight.yangtools.yang.data.api.Node<?>) is not resolvable to a concrete type
2014-09-03 22:57:33.351 PDT [CommitFutures-0] ERROR o.o.c.s.t.p.OpendaylightToaster - Failed to update toaster status
org.opendaylight.controller.md.sal.common.api.data.TransactionCommitFailedException: preCommit execution failed
at org.opendaylight.controller.md.sal.dom.broker.impl.TransactionCommitFailedExceptionMapper.newWithCause(TransactionCommitFailedExceptionMapper.java:37) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.TransactionCommitFailedExceptionMapper.newWithCause(TransactionCommitFailedExceptionMapper.java:18) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.ExceptionMapper.apply(ExceptionMapper.java:80) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.ExceptionMapper.apply(ExceptionMapper.java:31) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.MappingCheckedFuture.mapException(MappingCheckedFuture.java:60) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.MappingCheckedFuture.wrapInExecutionException(MappingCheckedFuture.java:64) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.MappingCheckedFuture.get(MappingCheckedFuture.java:77) ~[na:na]
at com.google.common.util.concurrent.AbstractCheckedFuture.checkedGet(AbstractCheckedFuture.java:78) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMDataCommitCoordinatorImpl$CommitCoordinationTask.canCommitBlocking(DOMDataCommitCoordinatorImpl.java:213) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMDataCommitCoordinatorImpl$CommitCoordinationTask.call(DOMDataCommitCoordinatorImpl.java:185) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMDataCommitCoordinatorImpl$CommitCoordinationTask.call(DOMDataCommitCoordinatorImpl.java:161) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.DeadlockDetectingListeningExecutorService$2.call(DeadlockDetectingListeningExecutorService.java:119) ~[na:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) ~[na:1.7.0_65]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_65]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_65]
at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
Caused by: org.opendaylight.controller.cluster.datastore.exceptions.TimeoutException: Sending message class org.opendaylight.controller.protobuff.messages.transaction.ShardTransactionMessages$CreateTransaction to actor ActorSelection[Anchor(akka://opendaylight-cluster-data/), Path(/user/shardmanager-operational/member-1-shard-toaster-operational)] failed
at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeRemoteOperation(ActorContext.java:188) ~[na:na]
at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeShardOperation(ActorContext.java:237) ~[na:na]
at org.opendaylight.controller.cluster.datastore.TransactionProxy.createTransactionIfMissing(TransactionProxy.java:355) ~[na:na]
at org.opendaylight.controller.cluster.datastore.TransactionProxy.write(TransactionProxy.java:262) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMForwardedWriteTransaction.put(DOMForwardedWriteTransaction.java:91) ~[na:na]
at org.opendaylight.controller.md.sal.binding.impl.AbstractWriteTransaction.put(AbstractWriteTransaction.java:53) ~[na:na]
at org.opendaylight.controller.md.sal.binding.impl.BindingDataWriteTransactionImpl.put(BindingDataWriteTransactionImpl.java:40) ~[na:na]
at org.opendaylight.controller.sample.toaster.provider.OpendaylightToaster.setToasterStatusUp(OpendaylightToaster.java:320) ~[na:na]
at org.opendaylight.controller.sample.toaster.provider.OpendaylightToaster.setDataProvider(OpendaylightToaster.java:91) ~[na:na]
at org.opendaylight.controller.config.yang.config.toaster_provider.impl.ToasterProviderModule.createInstance(ToasterProviderModule.java:57) ~[na:na]
at org.opendaylight.controller.config.yang.config.toaster_provider.impl.AbstractToasterProviderModule.getInstance(AbstractToasterProviderModule.java:102) ~[na:na]
at sun.reflect.GeneratedMethodAccessor156.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
at org.opendaylight.controller.config.manager.impl.dependencyresolver.DependencyResolverManager$1.handleInvocation(DependencyResolverManager.java:152) ~[na:na]
at com.google.common.reflect.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:70) ~[na:na]
at com.sun.proxy.$Proxy89.getInstance(Unknown Source) ~[na:na]
at org.opendaylight.controller.config.manager.impl.ConfigTransactionControllerImpl.secondPhaseCommit(ConfigTransactionControllerImpl.java:396) ~[na:na]
at org.opendaylight.controller.config.manager.impl.ConfigRegistryImpl.secondPhaseCommit(ConfigRegistryImpl.java:282) ~[na:na]
at org.opendaylight.controller.config.manager.impl.ConfigRegistryImpl.commitConfig(ConfigRegistryImpl.java:229) ~[na:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_65]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_65]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
at sun.reflect.misc.Trampoline.invoke(MethodUtil.java:75) ~[na:1.7.0_65]
at sun.reflect.GeneratedMethodAccessor160.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
at sun.reflect.misc.MethodUtil.invoke(MethodUtil.java:279) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.ConvertingMethod.invokeWithOpenReturn(ConvertingMethod.java:193) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.ConvertingMethod.invokeWithOpenReturn(ConvertingMethod.java:175) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.MXBeanIntrospector.invokeM2(MXBeanIntrospector.java:117) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.MXBeanIntrospector.invokeM2(MXBeanIntrospector.java:54) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:237) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:138) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:252) ~[na:1.7.0_65]
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:801) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.MXBeanProxy$InvokeHandler.invoke(MXBeanProxy.java:150) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.MXBeanProxy.invoke(MXBeanProxy.java:167) ~[na:1.7.0_65]
at javax.management.MBeanServerInvocationHandler.invoke(MBeanServerInvocationHandler.java:252) ~[na:1.7.0_65]
at com.sun.proxy.$Proxy87.commitConfig(Unknown Source) ~[na:na]
at org.opendaylight.controller.config.util.ConfigRegistryJMXClient.commitConfig(ConfigRegistryJMXClient.java:102) ~[na:na]
at org.opendaylight.controller.netconf.confignetconfconnector.transactions.TransactionProvider.commitTransaction(TransactionProvider.java:110) ~[na:na]
at org.opendaylight.controller.netconf.confignetconfconnector.operations.Commit.handleWithNoSubsequentOperations(Commit.java:55) ~[na:na]
at org.opendaylight.controller.netconf.util.mapping.AbstractLastNetconfOperation.handle(AbstractLastNetconfOperation.java:33) ~[na:na]
at org.opendaylight.controller.netconf.util.mapping.AbstractNetconfOperation.handle(AbstractNetconfOperation.java:105) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.ConfigPusherImpl.sendRequestGetResponseCheckIsOK(ConfigPusherImpl.java:287) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.ConfigPusherImpl.pushConfig(ConfigPusherImpl.java:246) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.ConfigPusherImpl.pushConfigWithConflictingVersionRetries(ConfigPusherImpl.java:135) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.ConfigPusherImpl.internalPushConfigs(ConfigPusherImpl.java:111) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.ConfigPusherImpl.process(ConfigPusherImpl.java:78) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.osgi.ConfigPersisterActivator$InnerCustomizer$1.run(ConfigPersisterActivator.java:178) ~[na:na]
... 1 common frames omitted
Caused by: java.util.concurrent.TimeoutException: Futures timed out after [5 seconds]
at scala.concurrent.impl.Promise$DefaultPromise.ready(Promise.scala:96) ~[na:na]
at scala.concurrent.impl.Promise$DefaultPromise.result(Promise.scala:100) ~[na:na]
at scala.concurrent.Await$$anonfun$result$1.apply(package.scala:107) ~[na:na]
at scala.concurrent.BlockContext$DefaultBlockContext$.blockOn(BlockContext.scala:53) ~[na:na]
at scala.concurrent.Await$.result(package.scala:107) ~[na:na]
at scala.concurrent.Await.result(package.scala) ~[na:na]
at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeRemoteOperation(ActorContext.java:186) ~[na:na]
... 53 common frames omitted
[INFO] [09/03/2014 22:57:34.111] [config-pusher] [Remoting] Starting remoting
[INFO] [09/03/2014 22:57:34.239] [config-pusher] [Remoting] Remoting started; listening on addresses :[akka.tcp://opendaylight-cluster-rpc@127.0.0.1:2551]
[INFO] [09/03/2014 22:57:34.252] [config-pusher] [Cluster(akka://opendaylight-cluster-rpc)] Cluster Node [akka.tcp://opendaylight-cluster-rpc@127.0.0.1:2551] - Starting up...
[INFO] [09/03/2014 22:57:34.275] [config-pusher] [Cluster(akka://opendaylight-cluster-rpc)] Cluster Node [akka.tcp://opendaylight-cluster-rpc@127.0.0.1:2551] - Started up successfully
[INFO] [09/03/2014 22:57:34.284] [opendaylight-cluster-rpc-akka.actor.default-dispatcher-2] [Cluster(akka://opendaylight-cluster-rpc)] Cluster Node [akka.tcp://opendaylight-cluster-rpc@127.0.0.1:2551] - Metrics will be retreived from MBeans, and may be incorrect on some platforms. To increase metric accuracy add the 'sigar.jar' to the classpath and the appropriate platform-specific native libary to 'java.library.path'. Reason: java.lang.ClassNotFoundException: org.hyperic.sigar.Sigar
[INFO] [09/03/2014 22:57:34.285] [opendaylight-cluster-rpc-akka.actor.default-dispatcher-2] [Cluster(akka://opendaylight-cluster-rpc)] Cluster Node [akka.tcp://opendaylight-cluster-rpc@127.0.0.1:2551] - Metrics collection has started successfully
[INFO] [09/03/2014 22:57:34.290] [opendaylight-cluster-rpc-akka.actor.default-dispatcher-4] [akka://opendaylight-cluster-rpc/user/termination-monitor] Message [org.opendaylight.controller.remote.rpc.messages.Monitor] from Actorakka://opendaylight-cluster-rpc/user/rpc#564566921 to Actor[akka://opendaylight-cluster-rpc/user/termination-monitor] was not delivered. [1] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
[INFO] [09/03/2014 22:57:34.292] [opendaylight-cluster-rpc-akka.actor.default-dispatcher-14] [Cluster(akka://opendaylight-cluster-rpc)] Cluster Node [akka.tcp://opendaylight-cluster-rpc@127.0.0.1:2551] - Node [akka.tcp://opendaylight-cluster-rpc@127.0.0.1:2551] is JOINING, roles []
[INFO] [09/03/2014 22:57:34.313] [opendaylight-cluster-rpc-akka.actor.default-dispatcher-2] [akka://opendaylight-cluster-rpc/user/rpc/rpc-registry] Bucket store path = akka://opendaylight-cluster-rpc/user/rpc/rpc-registry/store
[INFO] [09/03/2014 22:57:34.314] [opendaylight-cluster-rpc-akka.actor.default-dispatcher-14] [akka://opendaylight-cluster-rpc/user/termination-monitor] Message [org.opendaylight.controller.remote.rpc.messages.Monitor] from Actorakka://opendaylight-cluster-rpc/user/rpc/rpc-broker#-1467718542 to Actor[akka://opendaylight-cluster-rpc/user/termination-monitor] was not delivered. [2] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'.
2014-09-03 22:57:34 PDT [com.google.common.util.concurrent.Futures$ImmediateFuture] SEVERE com.google.common.util.concurrent.Futures$ImmediateFuture addListener RuntimeException while executing runnable com.google.common.util.concurrent.Futures$4@27087053 with executor com.google.common.util.concurrent.MoreExecutors$SameThreadExecutorService@1b066d2a
java.lang.NullPointerException
at org.opendaylight.controller.cluster.datastore.Shard$1.onSuccess(Shard.java:269)
at org.opendaylight.controller.cluster.datastore.Shard$1.onSuccess(Shard.java:266)
at com.google.common.util.concurrent.Futures$4.run(Futures.java:1149)
at com.google.common.util.concurrent.MoreExecutors$SameThreadExecutorService.execute(MoreExecutors.java:293)
at com.google.common.util.concurrent.Futures$ImmediateFuture.addListener(Futures.java:99)
at com.google.common.util.concurrent.Futures.addCallback(Futures.java:1152)
at com.google.common.util.concurrent.Futures.addCallback(Futures.java:1088)
at org.opendaylight.controller.cluster.datastore.Shard.commit(Shard.java:266)
at org.opendaylight.controller.cluster.datastore.Shard.applyState(Shard.java:361)
at org.opendaylight.controller.cluster.raft.RaftActor.onReceiveCommand(RaftActor.java:163)
at org.opendaylight.controller.cluster.datastore.Shard.onReceiveCommand(Shard.java:176)
at akka.persistence.UntypedPersistentActor.onReceive(Eventsourced.scala:430)
at akka.actor.UntypedActor$$anonfun$receive$1.applyOrElse(UntypedActor.scala:167)
at akka.persistence.Recovery$State$class.process(Recovery.scala:30)
at akka.persistence.ProcessorImpl$$anon$2.process(Processor.scala:103)
at akka.persistence.ProcessorImpl$$anon$2.aroundReceive(Processor.scala:114)
at akka.persistence.Recovery$class.aroundReceive(Recovery.scala:256)
at akka.persistence.UntypedPersistentActor.akka$persistence$Eventsourced$$super$aroundReceive(Eventsourced.scala:428)
at akka.persistence.Eventsourced$$anon$2.doAroundReceive(Eventsourced.scala:82)
at akka.persistence.Eventsourced$$anon$2.aroundReceive(Eventsourced.scala:78)
at akka.persistence.Eventsourced$class.aroundReceive(Eventsourced.scala:369)
at akka.persistence.UntypedPersistentActor.aroundReceive(Eventsourced.scala:428)
at akka.actor.ActorCell.receiveMessage(ActorCell.scala:516)
at akka.actor.ActorCell.invoke(ActorCell.scala:487)
at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:238)
at akka.dispatch.Mailbox.run(Mailbox.scala:220)
at akka.dispatch.ForkJoinExecutorConfigurator$AkkaForkJoinTask.exec(AbstractDispatcher.scala:393)
at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:262)
at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:975)
at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1478)
at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:104)

[INFO] [09/03/2014 22:57:35.300] [opendaylight-cluster-rpc-akka.actor.default-dispatcher-4] [Cluster(akka://opendaylight-cluster-rpc)] Cluster Node [akka.tcp://opendaylight-cluster-rpc@127.0.0.1:2551] - Leader is moving node [akka.tcp://opendaylight-cluster-rpc@127.0.0.1:2551] to [Up]
2014-09-03 22:57:44.499 PDT [CommitFutures-0] ERROR o.o.c.s.c.n.s.NetconfDeviceDatastoreAdapter - RemoteDevice

{controller-config}: Transaction(init) DOM-2 FAILED!
org.opendaylight.controller.md.sal.common.api.data.TransactionCommitFailedException: preCommit execution failed
at org.opendaylight.controller.md.sal.dom.broker.impl.TransactionCommitFailedExceptionMapper.newWithCause(TransactionCommitFailedExceptionMapper.java:37) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.TransactionCommitFailedExceptionMapper.newWithCause(TransactionCommitFailedExceptionMapper.java:18) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.ExceptionMapper.apply(ExceptionMapper.java:80) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.ExceptionMapper.apply(ExceptionMapper.java:31) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.MappingCheckedFuture.mapException(MappingCheckedFuture.java:60) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.MappingCheckedFuture.wrapInExecutionException(MappingCheckedFuture.java:64) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.MappingCheckedFuture.get(MappingCheckedFuture.java:77) ~[na:na]
at com.google.common.util.concurrent.AbstractCheckedFuture.checkedGet(AbstractCheckedFuture.java:78) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMDataCommitCoordinatorImpl$CommitCoordinationTask.canCommitBlocking(DOMDataCommitCoordinatorImpl.java:213) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMDataCommitCoordinatorImpl$CommitCoordinationTask.call(DOMDataCommitCoordinatorImpl.java:185) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMDataCommitCoordinatorImpl$CommitCoordinationTask.call(DOMDataCommitCoordinatorImpl.java:161) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.DeadlockDetectingListeningExecutorService$2.call(DeadlockDetectingListeningExecutorService.java:119) ~[na:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) ~[na:1.7.0_65]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [na:1.7.0_65]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [na:1.7.0_65]
at java.lang.Thread.run(Thread.java:745) [na:1.7.0_65]
Caused by: org.opendaylight.controller.cluster.datastore.exceptions.TimeoutException: Sending message class org.opendaylight.controller.protobuff.messages.transaction.ShardTransactionMessages$CreateTransaction to actor ActorSelection[Anchor(akka://opendaylight-cluster-data/), Path(/user/shardmanager-config/member-1-shard-inventory-config)] failed
at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeRemoteOperation(ActorContext.java:188) ~[na:na]
at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeShardOperation(ActorContext.java:237) ~[na:na]
at org.opendaylight.controller.cluster.datastore.TransactionProxy.createTransactionIfMissing(TransactionProxy.java:355) ~[na:na]
at org.opendaylight.controller.cluster.datastore.TransactionProxy.merge(TransactionProxy.java:274) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMForwardedWriteTransaction.merge(DOMForwardedWriteTransaction.java:103) ~[na:na]
at org.opendaylight.controller.md.sal.binding.impl.AbstractWriteTransaction.merge(AbstractWriteTransaction.java:69) ~[na:na]
at org.opendaylight.controller.md.sal.binding.impl.BindingDataWriteTransactionImpl.merge(BindingDataWriteTransactionImpl.java:46) ~[na:na]
at org.opendaylight.controller.sal.connect.netconf.sal.NetconfDeviceDatastoreAdapter.createNodesListIfNotPresent(NetconfDeviceDatastoreAdapter.java:100) ~[na:na]
at org.opendaylight.controller.sal.connect.netconf.sal.NetconfDeviceDatastoreAdapter.initDeviceData(NetconfDeviceDatastoreAdapter.java:80) ~[na:na]
at org.opendaylight.controller.sal.connect.netconf.sal.NetconfDeviceDatastoreAdapter.<init>(NetconfDeviceDatastoreAdapter.java:52) ~[na:na]
at org.opendaylight.controller.sal.connect.netconf.sal.NetconfDeviceSalProvider.onSessionInitiated(NetconfDeviceSalProvider.java:88) ~[na:na]
at org.opendaylight.controller.md.sal.binding.util.BindingContextUtils.createProviderContextAndInitialize(BindingContextUtils.java:57) ~[na:na]
at org.opendaylight.controller.sal.binding.impl.RootBindingAwareBroker.registerProvider(RootBindingAwareBroker.java:146) ~[na:na]
at org.opendaylight.controller.sal.connect.netconf.sal.NetconfDeviceSalFacade.registerToSal(NetconfDeviceSalFacade.java:55) ~[na:na]
at org.opendaylight.controller.sal.connect.netconf.sal.NetconfDeviceSalFacade.<init>(NetconfDeviceSalFacade.java:50) ~[na:na]
at org.opendaylight.controller.config.yang.md.sal.connector.netconf.NetconfConnectorModule.createInstance(NetconfConnectorModule.java:106) ~[na:na]
at org.opendaylight.controller.config.yang.md.sal.connector.netconf.AbstractNetconfConnectorModule.getInstance(AbstractNetconfConnectorModule.java:138) ~[na:na]
at sun.reflect.GeneratedMethodAccessor156.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
at org.opendaylight.controller.config.manager.impl.dependencyresolver.DependencyResolverManager$1.handleInvocation(DependencyResolverManager.java:152) ~[na:na]
at com.google.common.reflect.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:70) ~[na:na]
at com.sun.proxy.$Proxy93.getInstance(Unknown Source) ~[na:na]
at org.opendaylight.controller.config.manager.impl.ConfigTransactionControllerImpl.secondPhaseCommit(ConfigTransactionControllerImpl.java:396) ~[na:na]
at org.opendaylight.controller.config.manager.impl.ConfigRegistryImpl.secondPhaseCommit(ConfigRegistryImpl.java:282) ~[na:na]
at org.opendaylight.controller.config.manager.impl.ConfigRegistryImpl.commitConfig(ConfigRegistryImpl.java:229) ~[na:na]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_65]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_65]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
at sun.reflect.misc.Trampoline.invoke(MethodUtil.java:75) ~[na:1.7.0_65]
at sun.reflect.GeneratedMethodAccessor160.invoke(Unknown Source) ~[na:na]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_65]
at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_65]
at sun.reflect.misc.MethodUtil.invoke(MethodUtil.java:279) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.ConvertingMethod.invokeWithOpenReturn(ConvertingMethod.java:193) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.ConvertingMethod.invokeWithOpenReturn(ConvertingMethod.java:175) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.MXBeanIntrospector.invokeM2(MXBeanIntrospector.java:117) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.MXBeanIntrospector.invokeM2(MXBeanIntrospector.java:54) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.MBeanIntrospector.invokeM(MBeanIntrospector.java:237) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.PerInterface.invoke(PerInterface.java:138) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.MBeanSupport.invoke(MBeanSupport.java:252) ~[na:1.7.0_65]
at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.invoke(DefaultMBeanServerInterceptor.java:819) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.JmxMBeanServer.invoke(JmxMBeanServer.java:801) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.MXBeanProxy$InvokeHandler.invoke(MXBeanProxy.java:150) ~[na:1.7.0_65]
at com.sun.jmx.mbeanserver.MXBeanProxy.invoke(MXBeanProxy.java:167) ~[na:1.7.0_65]
at javax.management.MBeanServerInvocationHandler.invoke(MBeanServerInvocationHandler.java:252) ~[na:1.7.0_65]
at com.sun.proxy.$Proxy87.commitConfig(Unknown Source) ~[na:na]
at org.opendaylight.controller.config.util.ConfigRegistryJMXClient.commitConfig(ConfigRegistryJMXClient.java:102) ~[na:na]
at org.opendaylight.controller.netconf.confignetconfconnector.transactions.TransactionProvider.commitTransaction(TransactionProvider.java:110) ~[na:na]
at org.opendaylight.controller.netconf.confignetconfconnector.operations.Commit.handleWithNoSubsequentOperations(Commit.java:55) ~[na:na]
at org.opendaylight.controller.netconf.util.mapping.AbstractLastNetconfOperation.handle(AbstractLastNetconfOperation.java:33) ~[na:na]
at org.opendaylight.controller.netconf.util.mapping.AbstractNetconfOperation.handle(AbstractNetconfOperation.java:105) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.ConfigPusherImpl.sendRequestGetResponseCheckIsOK(ConfigPusherImpl.java:287) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.ConfigPusherImpl.pushConfig(ConfigPusherImpl.java:246) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.ConfigPusherImpl.pushConfigWithConflictingVersionRetries(ConfigPusherImpl.java:135) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.ConfigPusherImpl.internalPushConfigs(ConfigPusherImpl.java:111) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.ConfigPusherImpl.process(ConfigPusherImpl.java:78) ~[na:na]
at org.opendaylight.controller.netconf.persist.impl.osgi.ConfigPersisterActivator$InnerCustomizer$1.run(ConfigPersisterActivator.java:178) ~[na:na]
... 1 common frames omitted
Caused by: java.util.concurrent.TimeoutException: Futures timed out after [5 seconds]
at scala.concurrent.impl.Promise$DefaultPromise.ready(Promise.scala:96) ~[na:na]
at scala.concurrent.impl.Promise$DefaultPromise.result(Promise.scala:100) ~[na:na]
at scala.concurrent.Await$$anonfun$result$1.apply(package.scala:107) ~[na:na]
at scala.concurrent.BlockContext$DefaultBlockContext$.blockOn(BlockContext.scala:53) ~[na:na]
at scala.concurrent.Await$.result(package.scala:107) ~[na:na]
at scala.concurrent.Await.result(package.scala) ~[na:na]
at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeRemoteOperation(ActorContext.java:186) ~[na:na]
... 59 common frames omitted
2014-09-03 22:57:44.515 PDT [CommitFutures-0] ERROR o.o.c.l.b.i.UncaughtExceptionPolicy - Thread Thread[CommitFutures-0,5,main] died because of an uncaught exception
java.lang.IllegalStateException: RemoteDevice{controller-config}

Transaction(init) not committed correctly
at org.opendaylight.controller.sal.connect.netconf.sal.NetconfDeviceDatastoreAdapter$1.onFailure(NetconfDeviceDatastoreAdapter.java:117) ~[na:na]
at com.google.common.util.concurrent.Futures$4.run(Futures.java:1140) ~[na:na]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_65]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_65]
at java.lang.Thread.run(Thread.java:745) ~[na:1.7.0_65]
Caused by: org.opendaylight.controller.md.sal.common.api.data.TransactionCommitFailedException: preCommit execution failed
at org.opendaylight.controller.md.sal.dom.broker.impl.TransactionCommitFailedExceptionMapper.newWithCause(TransactionCommitFailedExceptionMapper.java:37) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.TransactionCommitFailedExceptionMapper.newWithCause(TransactionCommitFailedExceptionMapper.java:18) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.ExceptionMapper.apply(ExceptionMapper.java:80) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.ExceptionMapper.apply(ExceptionMapper.java:31) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.MappingCheckedFuture.mapException(MappingCheckedFuture.java:60) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.MappingCheckedFuture.wrapInExecutionException(MappingCheckedFuture.java:64) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.MappingCheckedFuture.get(MappingCheckedFuture.java:77) ~[na:na]
at com.google.common.util.concurrent.AbstractCheckedFuture.checkedGet(AbstractCheckedFuture.java:78) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMDataCommitCoordinatorImpl$CommitCoordinationTask.canCommitBlocking(DOMDataCommitCoordinatorImpl.java:213) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMDataCommitCoordinatorImpl$CommitCoordinationTask.call(DOMDataCommitCoordinatorImpl.java:185) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMDataCommitCoordinatorImpl$CommitCoordinationTask.call(DOMDataCommitCoordinatorImpl.java:161) ~[na:na]
at org.opendaylight.yangtools.util.concurrent.DeadlockDetectingListeningExecutorService$2.call(DeadlockDetectingListeningExecutorService.java:119) ~[na:na]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) ~[na:1.7.0_65]
... 3 common frames omitted
Caused by: org.opendaylight.controller.cluster.datastore.exceptions.TimeoutException: Sending message class org.opendaylight.controller.protobuff.messages.transaction.ShardTransactionMessages$CreateTransaction to actor ActorSelection[Anchor(akka://opendaylight-cluster-data/), Path(/user/shardmanager-config/member-1-shard-inventory-config)] failed
at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeRemoteOperation(ActorContext.java:188) ~[na:na]
at org.opendaylight.controller.cluster.datastore.utils.ActorContext.executeShardOperation(ActorContext.java:237) ~[na:na]
at org.opendaylight.controller.cluster.datastore.TransactionProxy.createTransactionIfMissing(TransactionProxy.java:355) ~[na:na]
at org.opendaylight.controller.cluster.datastore.TransactionProxy.merge(TransactionProxy.java:274) ~[na:na]
at org.opendaylight.controller.md.sal.dom.broker.impl.DOMForwardedWriteTransaction.merge(DOMForwardedWriteTransaction.java:103) ~[na:na]
at org.opendaylight.controller.md.sal.binding.impl.AbstractWriteTransaction.merge(AbstractWriteTransaction.java:69) ~[na:na]
at org.opendaylight.controller.md.sal.binding.impl.BindingDataWriteTransactionImpl.merge(BindingDataWriteTransactionImpl.java:46) ~[na:na]
at org.opendaylight.controller.sal.connect.netconf.sal.NetconfDeviceDatastoreAdapter.createNodesListIfNotPresent(NetconfDeviceDatastoreAdapter.java:100) ~[na:na]
at org.opendaylight.controller.sal.connect.netconf.sal.NetconfDeviceDatastoreAdapter.initDeviceData(NetconfDeviceDatastoreAdapter.java:80) ~[na:na]
at org.opendaylight.controller.sal.connect.netconf.sal.NetconfDeviceDatastoreAdapter.<init>(NetconfDeviceDatastoreAdapter.java:52) ~[na:na]
at org.opendaylight.controller.sal.connect.netconf.sal.NetconfDeviceSalProvider.onSessionInitiated(NetconfDeviceSalProvider.java:88) ~[na:na]
at org.opendaylight.controller.md.sal.binding.util.BindingContextUtils.createProviderContextAndInitialize(BindingContextUtils.java:57) ~[na:na]
at org.opendaylight.controller.sal.binding.impl.RootBindingAwareBroker.registerProvider(RootBindingAwareBroker.java:146) ~[na:na]
at org.opendaylight.controller.sal.connect.netconf.sal.NetconfDeviceSalFacade.registerToSal(NetconfDeviceSalFacade.java:55) ~[na:na]
at org.opendaylight.controller.sal.connect.netconf.sal.NetconfDeviceSalFacade.<init>(NetconfDeviceSalFacade.java:50) ~[na:na]
at org.opendaylight.controller.config.yang.md.sal.connector.netconf.NetconfConnectorModule.createInstance(NetconfConnectorModule.java:106) ~[na:na]
at org.opendaylight.controller.config.yang.md.sal.connector.netconf.AbstractNetconfConnecto...



 Comments   
Comment by Jan Medved [ 04/Sep/14 ]

Attachment flow_config_perf.py has been added with description: Flow config script

Comment by Jan Medved [ 04/Sep/14 ]

Attachment config_cleanup.py has been added with description: config cleanup script

Comment by Jan Medved [ 04/Sep/14 ]

Attachment inventory_crawler.py has been added with description: Flow dump script

Comment by Moiz Raja [ 12/Sep/14 ]

Jan, I do not believe this is reproducible with the exact same steps.

Comment by Moiz Raja [ 16/Sep/14 ]

The 50K test is working just fine. I also tried running a test with 150K flows twice without issues.

Generated at Wed Feb 07 21:51:32 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.