[OPNFLWPLUG-505] stats for 80k fows not collected properly after mininet restart Created: 17/Jun/15  Updated: 27/Sep/21  Due: 18/Dec/15  Resolved: 27/Jan/16

Status: Resolved
Project: OpenFlowPlugin
Component/s: General
Affects Version/s: None
Fix Version/s: None

Type: Bug
Reporter: Peter Gubka Assignee: Michal Rehak
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: Linux
Platform: PC


Attachments: File karaf.log.RC2_He     Zip Archive karaf.log.zip    
External issue ID: 3774
Priority: Normal

 Description   

odl: https://nexus.opendaylight.org/content/repositories/automatedweeklyreleases-1065/org/opendaylight/integration/distribution-karaf/0.3.0-Lithium-RC1-v201506170015/distribution-karaf-0.3.0-Lithium-RC1-v201506170015.tar.gz

features: odl-openflowplugin-flow-services-ui

steps to reproduce:
1) connect mininet with 63 switches
sudo mn --controller=remote,ip=10.25.2.9 --topo tree,6 --switch ovsk,protocols=OpenFlow13

2) configure 80k flows using
test/tools/odl-mdsal-clustering-tests/clustering-performance-test/flow_stats_stability_monitor.py --host 10.25.2.9 --auth --fpr 20 --config_monitor 750 --deconfig_monitor 200 --monitor_period 30 --flows 16000 --threads 5 --bulk-delete

3) once flows are configured you can restart mininet

the script output looks like

      • Test summary:
        Elapsed time: 87.66s
        Peak requests/s: 46.98 OK, 46.98 Total
        Peak flows/s: 939.62 OK, 939.62 Total
        Avg. requests/s: 45.63 OK, 45.63 Total (97.13% of peak total)
        Avg. flows/s: 912.67 OK, 912.67 Total (97.13% of peak total)
      • Total flows added: 80000
        HTTP[OK] results: 4000

(1434538519.780677, 63, 29767, 26360)
(1434538547.42563, 63, 39727, 35980)
(1434538579.425267, 63, 52067, 48660)
(1434538611.199114, 63, 63947, 60860)
(1434538647.436588, 63, 74727, 72600)
(1434538679.702498, 63, 80567, 80000)
(1434538709.464098, 63, 80567, 80000)
Could not retrieve inventory, response not in JSON format HERE MINIENT WAS RESTARTED
(1434538721.380539, 0, 0, 0)
Could not retrieve inventory, response not in JSON format
(1434538751.394594, 0, 0, 0)
Could not retrieve inventory, response not in JSON format
(1434538781.423616, 0, 0, 0)
Could not retrieve inventory, response not in JSON format
(1434538811.434752, 0, 0, 0)
(1434538841.66587, 30, 1289, 1280)
(1434538873.432987, 54, 11801, 13020)
(1434538904.859306, 63, 18286, 22440)
(1434538936.936223, 63, 35583, 33900)
(1434538968.239737, 63, 43110, 42813)
(1434539000.265855, 63, 53202, 54133)
(1434539031.529655, 63, 62934, 62493)
(1434539063.868791, 63, 74335, 73813)
(1434539102.517058, 63, 80560, 79993) only 79993 out of 80k present in the inventory
(1434539129.367053, 63, 80560, 79993)
(1434539159.691142, 63, 80560, 79993)
(1434539189.831279, 63, 80560, 79993)
(1434539219.873444, 63, 80560, 79993)
(1434539249.604617, 63, 80560, 79993)
(1434539279.611363, 63, 80560, 79993)

Deleting all flows in bulk:
All flows deleted.
(1434539299.211172, 63, 80560, 79993)
(1434539314.711525, 63, 567, 0)
(1434539344.687325, 63, 567, 0)
(1434539374.741245, 63, 567, 0)
(1434539404.618388, 63, 567, 0)
(1434539434.671081, 63, 567, 0)
(1434539464.632976, 63, 567, 0)
(1434539494.923816, 63, 567, 0)

And the log is full of warnings like this:

2015-06-17 10:58:22,292 | WARN | nPool-7-worker-3 | StatRpcMsgManagerImpl | 195 - org.opendaylight.openflowplugin.applications.statistics-manager - 0.1.0.Lithium-RC1-v201506170015 | Response Registration for Statistics RPC call fail!
org.opendaylight.controller.md.sal.dom.api.DOMRpcImplementationNotAvailableException: No local or remote implementation available for rpc AbsoluteSchemaPath

{path=[(urn:opendaylight:flow:statistics?revision=2013-08-19)get-aggregate-flow-statistics-from-flow-table-for-all-flows]}

at org.opendaylight.controller.remote.rpc.RemoteRpcImplementation$1.onComplete(RemoteRpcImplementation.java:57)[178:org.opendaylight.controller.sal-remoterpc-connector:1.2.0.Lithium-RC1-v201506170015]
at org.opendaylight.controller.remote.rpc.RemoteRpcImplementation$1.onComplete(RemoteRpcImplementation.java:48)[178:org.opendaylight.controller.sal-remoterpc-connector:1.2.0.Lithium-RC1-v201506170015]
at akka.dispatch.OnComplete.internal(Future.scala:248)[164:com.typesafe.akka.actor:2.3.10]
at akka.dispatch.OnComplete.internal(Future.scala:245)[164:com.typesafe.akka.actor:2.3.10]
at akka.dispatch.japi$CallbackBridge.apply(Future.scala:175)[164:com.typesafe.akka.actor:2.3.10]
at akka.dispatch.japi$CallbackBridge.apply(Future.scala:172)[164:com.typesafe.akka.actor:2.3.10]
at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:32)[161:org.scala-lang.scala-library:2.10.4.v20140209-180020-VFINAL-b66a39653b]
at scala.concurrent.impl.ExecutionContextImpl$$anon$3.exec(ExecutionContextImpl.scala:107)[161:org.scala-lang.scala-library:2.10.4.v20140209-180020-VFINAL-b66a39653b]
at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)[161:org.scala-lang.scala-library:2.10.4.v20140209-180020-VFINAL-b66a39653b]
at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1339)[161:org.scala-lang.scala-library:2.10.4.v20140209-180020-VFINAL-b66a39653b]
at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)[161:org.scala-lang.scala-library:2.10.4.v20140209-180020-VFINAL-b66a39653b]
at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)[161:org.scala-lang.scala-library:2.10.4.v20140209-180020-VFINAL-b66a39653b]



 Comments   
Comment by Peter Gubka [ 17/Jun/15 ]

Attachment karaf.log.zip has been added with description: karaf log

Comment by Tony Tkacik [ 19/Jun/15 ]

org.opendaylight.controller.md.sal.dom.api.DOMRpcImplementationNotAvailableException: No local or remote implementation available for rpc AbsoluteSchemaPath

{path=[(urn:opendaylight:flow:statistics?revision=2013-08-19)get-aggregate-flow-statistics-from-flow-table-for-all-flows]}

at

Openflow RPC service for statistics was deregistered / removed - that probably means connection with device was lost.

Comment by Peter Gubka [ 22/Jun/15 ]

This happened to the non-redesign openflow plugin on Lithiun RC2-June22 build

installed feature: odl-openflowplugin-flow-services-ui

(1434965020.012154, 63, 80567, 80000)
(1434965049.882792, 63, 80567, 80000) BEFORE MININET RESTART ALL 80k collected
(1434965064.716717, 18, 23042, 22880)
Could not retrieve inventory, response not in JSON format
(1434965091.104716, 0, 0, 0)
Could not retrieve inventory, response not in JSON format
(1434965121.131391, 0, 0, 0)
Could not retrieve inventory, response not in JSON format
(1434965151.161517, 0, 0, 0)
(1434965182.064277, 41, 2758, 5660)
(1434965213.734086, 58, 10972, 15786)
(1434965244.836881, 63, 18508, 23042)
(1434965276.703612, 63, 34385, 34142)
(1434965308.134891, 63, 44780, 44465)
(1434965339.957712, 63, 51405, 53145)
(1434965372.153158, 63, 59728, 64265)
(1434965403.825408, 63, 71149, 73485)
(1434965441.924653, 63, 80172, 79605) AFTER MININET RESTART only 79605 out of 80k collected
(1434965470.254282, 63, 80172, 79605)

Deleting all flows in bulk:
All flows deleted.
(1434965491.599416, 63, 78972, 79605)
(1434965508.314167, 63, 763, 196) ADDITIONALLY after delete all flow from config, 196 flows still appearing in operational
(1434965538.112324, 63, 763, 196)
(1434965568.359745, 63, 763, 196)
(1434965598.340699, 63, 763, 196)
(1434965628.328266, 63, 763, 196)
(1434965658.237726, 63, 763, 196)
(1434965688.384579, 63, 763, 196)

Comment by Peter Gubka [ 22/Jun/15 ]

Attachment karaf.log.RC2_He has been added with description: karaf log

Comment by Abhijit Kumbhare [ 25/Sep/15 ]

Kavitha,

Do you intend to fix this after M5 or before?

Thanks,
Abhijit

Comment by Abhijit Kumbhare [ 09/Oct/15 ]

Changed the deadline to be after M5

Comment by Abhijit Kumbhare [ 01/Dec/15 ]

Michal will be working on this at a higher priority

Comment by Michal Rehak [ 08/Jan/16 ]

master: https://git.opendaylight.org/gerrit/#/c/31604
https://git.opendaylight.org/gerrit/#/c/30968
lithium: https://git.opendaylight.org/gerrit/#/c/31533
https://git.opendaylight.org/gerrit/#/c/30981

Comment by Abhijit Kumbhare [ 25/Jan/16 ]

Michal - since this is merged - can you mark it resolved fixed?

Comment by Michal Rehak [ 27/Jan/16 ]

Testing is still in progress but there is already extraordinary amount of successful consequent test runs.

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