[CONTROLLER-852] IllegalStateExceptions observed when flows are being added to the controller Created: 17/Sep/14  Updated: 19/Oct/17  Resolved: 05/May/15

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

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

Operating System: All
Platform: All

Attachments: File flow_config_perf.py    
External issue ID: 1940

 Description   

The following java.lang.IllegalStateException exceptions are being observed while flows are being added to the controller via the REST API:

Exception in thread "CommitFutures-181" java.lang.IllegalStateException: Illegal state - listener for org.opendaylight.controller.md.sal.dom.broker.impl.DOMDataBrokerTransactionChainImpl@5d89004d was invoked for incorrect chain org.opendaylight.controller.md.sal.binding.impl.BindingTranslatedTransactionChain@4d72ef34.
at com.google.common.base.Preconditions.checkState(Preconditions.java:176)
at org.opendaylight.controller.md.sal.binding.impl.BindingTranslatedTransactionChain$DelegateChainListener.onTransactionChainFailed(BindingTranslatedTransactionChain.java:126)
at org.opendaylight.controller.md.sal.binding.impl.BindingTranslatedTransactionChain.failTransactionChain(BindingTranslatedTransactionChain.java:113)
at org.opendaylight.controller.md.sal.binding.impl.BindingTranslatedTransactionChain.access$200(BindingTranslatedTransactionChain.java:31)
at org.opendaylight.controller.md.sal.binding.impl.BindingTranslatedTransactionChain$3.onFailure(BindingTranslatedTransactionChain.java:94)
at com.google.common.util.concurrent.Futures$4.run(Futures.java:1140)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)

To reproduce, start mininet with:
sudo mn --controller=remote,ip=192.168.162.1:6653 --topo tree,3 --switch ovsk,protocols=OpenFlow13

Then use the attached script with the following command line:
python flow_config_perf.py --nflows 1000 --nthreads=5 --ncycles 10 --delay=60

The script will first add then delete 50k flows into the controller.

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

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

Comment by Jan Medved [ 18/Sep/14 ]

The delete rate is progressively slowing down:
Cycle 0:
Thread 2: Deleting 1000 flows on 7 nodes
Thread 4: Deleting 1000 flows on 7 nodes
Thread 1: Deleting 1000 flows on 7 nodes
Thread 0: Deleting 1000 flows on 7 nodes
Thread 3: Deleting 1000 flows on 7 nodes

Thread 4:
Delete time: 580.74,
Delete success rate: 1.72, Delete total rate: 1.72
Delete Results:

{200: 1000}

Thread 2:
Delete time: 583.39,
Delete success rate: 1.71, Delete total rate: 1.71
Delete Results:

{200: 1000}

Thread 3:
Delete time: 588.14,
Delete success rate: 1.70, Delete total rate: 1.70
Delete Results:

{200: 1000}

Thread 1:
Delete time: 589.78,
Delete success rate: 1.70, Delete total rate: 1.70
Delete Results:

{200: 1000}

Thread 0:
Delete time: 589.40,
Delete success rate: 1.70, Delete total rate: 1.70
Delete Results:

{200: 1000}

Overall success rate: 8.53, Overall rate: 8.53

Cycle 1:
Thread 0: Deleting 1000 flows on 7 nodes
Thread 3: Deleting 1000 flows on 7 nodes
Thread 1: Deleting 1000 flows on 7 nodes
Thread 2: Deleting 1000 flows on 7 nodes
Thread 4: Deleting 1000 flows on 7 nodes
Thread 2:
Delete time: 1145.62,
Delete success rate: 0.87, Delete total rate: 0.87
Delete Results:

{200: 1000}

Thread 0:
Delete time: 1147.30,
Delete success rate: 0.87, Delete total rate: 0.87
Delete Results:

{200: 1000}

Thread 4:
Delete time: 1148.48,
Delete success rate: 0.87, Delete total rate: 0.87
Delete Results:

{200: 1000}

Thread 3:
Delete time: 1149.67,
Delete success rate: 0.87, Delete total rate: 0.87
Delete Results:

{200: 1000}

Thread 1:
Delete time: 1149.85,
Delete success rate: 0.87, Delete total rate: 0.87
Delete Results:

{200: 1000}

Overall success rate: 4.35, Overall rate: 4.35

Cycle 2:
Thread 3: Deleting 1000 flows on 7 nodes
Thread 1: Deleting 1000 flows on 7 nodes
Thread 2: Deleting 1000 flows on 7 nodes
Thread 0: Deleting 1000 flows on 7 nodes
Thread 4: Deleting 1000 flows on 7 nodes

Thread 1:
Delete time: 1363.80,
Delete success rate: 0.73, Delete total rate: 0.73
Delete Results:

{200: 1000}

Thread 3:
Delete time: 1363.81,
Delete success rate: 0.73, Delete total rate: 0.73
Delete Results:

{200: 1000}

Thread 2:
Delete time: 1363.92,
Delete success rate: 0.73, Delete total rate: 0.73
Delete Results:

{200: 1000}

Thread 0:
Delete time: 1364.04,
Delete success rate: 0.73, Delete total rate: 0.73
Delete Results:

{200: 1000}

Thread 4:
Delete time: 1364.04,
Delete success rate: 0.73, Delete total rate: 0.73
Delete Results:

{200: 1000}

Overall success rate: 3.67, Overall rate: 3.67

Comment by Naresh kumar [ 10/Nov/14 ]

From which repo did you clone the controller in which you are getting this error?

Comment by Jan Hajnar [ 25/Nov/14 ]

Hi,

I tested this today with latest stable helium build and I didn't see exceptions mentioned in the first comment. I think this bug is fixed.

Delete slowdowns are mentioned in OPNFLWPLUG-281 and it is already being worked on.

Jan.

Comment by Carol Sanders [ 04/May/15 ]

This bug is part of the project to Move all ADSAL associated component bugs to ADSAL.

Comment by Tony Tkacik [ 05/May/15 ]

Fixed in Helium.

Generated at Wed Feb 07 19:54:02 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.