Attached is karaf.log from a fresh boot with TRACE enabled for 'org.opendaylight.openflowplugin.impl'

the cbench command used was:

cbench -c 10.1.154.174 -m 3000 -M 1 -s 2 -l 2 -D 3000 -p 6633

notice the -s 2 for a switch count of 2. The CSIT job uses much more, but I was trying to reduce the number
of variables involved and when I only used a single (-s 1) switch the issue did not show up. Increasing it to
2 seems to hit it every time. hopefully that is a worthwhile clue.

gobinath@ericsson.com will get back on the analysis by tomorrow

jluhrsen I want to add some logging in openflowplugin project and re-run this cbench test for debugging. Any way I could start this job on a openflowplugin review?

Also I could see the following errors in the karaf log:

"2020-02-11T12:46:26,913 | INFO | opendaylight-cluster-data-akka.actor.default-dispatcher-37 | RoleContextImpl | 310 - org.opendaylight.openflowplugin.impl - 0.10.0 | Device: openflow:6 with version: 1 does not support role BECOMEMASTER"

What is the openflow version used by the switches in cbench?

Once this patch is merged, you can add the comment:

test-openflowplugin-cbench

to the patch you are adding debug logs to and it should give you what you want. You'll want to make sure your
debugs are all INFO level though. If you want a job that runs with higher debug levels for some module, we can
do that to, but it'll be a more manual process that I can do in the sandbox.

yes, IIRC, cbench got stuck on OF1.1 and never made it to 1.3.

thanks.

thanks a lot jluhrsen

I have raised a review & triggered the job but the job seem to be waiting with no available executor for too long.

https://git.opendaylight.org/gerrit/c/openflowplugin/+/88084

Job link:

https://jenkins.opendaylight.org/releng/job/openflowplugin-patch-test-cbench-magnesium/1/

Alternately could you please send the steps to set up cbench in local. (couldn't find complete working steps anywhere)

I had added some logging and rerun the tests. From the logs, it was found that the "flownodereconciliation" service was throwing an uncaught exception (ConcurrentModificationException) which had resulted in the reconciliation framework.

Logs:

2020-02-27T11:48:31,071 | ERROR | ofppool-2 | ContextChainHolderImpl | 310 - org.opendaylight.openflowplugin.impl - 0.10.0.SNAPSHOT | Reconciliation framework failure for device openflow:1 with error
java.util.ConcurrentModificationException: null
at java.util.HashMap.computeIfAbsent(HashMap.java:1134) ~[?:?]
at org.opendaylight.openflowplugin.applications.frm.impl.FlowNodeReconciliationImpl.startReconciliation(FlowNodeReconciliationImpl.java:302) ~[?:?]
at org.opendaylight.openflowplugin.applications.reconciliation.impl.ReconciliationManagerImpl.lambda$reconcileServices$4(ReconciliationManagerImpl.java:135) ~[?:?] 

I have fixed this and added some logs to debug similar issues.

https://git.opendaylight.org/gerrit/c/openflowplugin/+/88084

Note:

The "flownodereconciliation" task completes fast when the switch connects initially (no flows are present in inventory config for the node). So the race condition would be more probable in this case and we see might be seeing the cbench failures only during initial connection.

Great debugging and thanks for the quick fix, gobinath. the patch test job is passing now and I have merged the stable/magnesium patch.

does this need to be cherry-picked to sodium?

I assume it should be in master, so I already made that cherry pick

Yes. This has to be cherry-picked to Sodium too. Cherry-picked here https://git.opendaylight.org/gerrit/c/openflowplugin/+/87965

It is surprising that the cbench is passing in Sodium however.

actually, now that I think about it, I think I was able to reproduce this locally with sodium. Just didn't spend much time double checking. Maybe upstream CSIT is slightly slow enough in sodium + that shared cloud environment compared to my local laptop that the race condition isn't hit.