[ONOS-2999] NPEs at OpenFlowRuleProvider.executeBatch after deactivate proxyARP - Jira

XML

Word

Printable

Details

Type: Bug
Status: Closed (View Workflow)
Priority: Critical
Resolution: Done
Affects Version/s: 1.4.0
Fix Version/s: 1.4.0
Component/s: None
Labels:
- Test

Epic Link:
Southbound
Sprint:
Emu Sprint 1 (9/21-10/9), Emu Sprint 2 (10/12-10/30)

Description

Steps:

Start 3-node ONOS cluster (proxy ARP enabled)
Bringup a topology from Mininet
Verify all default flows are added to switches along with ARP flow)
Restart the Mininet topology
Before assigning the switches back to ONOS cotroller, deactiavte proxyARP on ONOS.
Now notice that even though proxyARP is deactivated when the switches come back up we still notice the arp flows on ONOS with below NPEs logged.

********************************
onos> summary
node=10.128.20.11, version=1.4.0.admin~2015/09/24@16:16
nodes=3, devices=25, links=114, hosts=0, SCC(s)=1, flows=75, intents=0
onos>
onos> summary
node=10.128.20.11, version=1.4.0.admin~2015/09/24@16:16
nodes=3, devices=25, links=114, hosts=0, SCC(s)=1, flows=75, intents=0
onos> flows | grep Count
deviceId=of:0000000000000001, flowRuleCount=3
deviceId=of:0000000000000002, flowRuleCount=3
deviceId=of:0000000000000003, flowRuleCount=3
deviceId=of:0000000000000004, flowRuleCount=3
deviceId=of:0000000000000005, flowRuleCount=3
deviceId=of:0000000000000006, flowRuleCount=3
deviceId=of:0000000000000007, flowRuleCount=3
deviceId=of:0000000000000008, flowRuleCount=3
deviceId=of:0000000000000009, flowRuleCount=3
deviceId=of:000000000000000a, flowRuleCount=3
deviceId=of:000000000000000b, flowRuleCount=3
deviceId=of:000000000000000c, flowRuleCount=3
deviceId=of:000000000000000d, flowRuleCount=3
deviceId=of:000000000000000e, flowRuleCount=3
deviceId=of:000000000000000f, flowRuleCount=3
deviceId=of:0000000000000010, flowRuleCount=3
deviceId=of:0000000000000011, flowRuleCount=3
deviceId=of:0000000000000012, flowRuleCount=3
deviceId=of:0000000000000013, flowRuleCount=3
deviceId=of:0000000000000014, flowRuleCount=3
deviceId=of:0000000000000015, flowRuleCount=3
deviceId=of:0000000000000016, flowRuleCount=3
deviceId=of:0000000000000017, flowRuleCount=3
deviceId=of:0000000000000018, flowRuleCount=3
deviceId=of:0000000000000019, flowRuleCount=3
onos>
onos>
onos>
onos> apps | grep arp

id=33, name=org.onosproject.proxyarp, version=1.4.0.SNAPSHOT, origin=ON.Lab, description=Proxy ARP/NDP application, features=[onos-app-proxyarp], featuresRepo=mvn:org.onosproject/onos-app-proxyarp/1.4.0-SNAPSHOT/xml/features, permissions=[]
onos>
onos> flows | grep Count
deviceId=of:0000000000000001, flowRuleCount=0
deviceId=of:0000000000000002, flowRuleCount=0
deviceId=of:0000000000000003, flowRuleCount=0
deviceId=of:0000000000000004, flowRuleCount=0
deviceId=of:0000000000000005, flowRuleCount=0
deviceId=of:0000000000000006, flowRuleCount=0
deviceId=of:0000000000000007, flowRuleCount=0
deviceId=of:0000000000000008, flowRuleCount=0
deviceId=of:0000000000000009, flowRuleCount=0
deviceId=of:000000000000000a, flowRuleCount=0
deviceId=of:000000000000000b, flowRuleCount=0
deviceId=of:000000000000000c, flowRuleCount=0
deviceId=of:000000000000000d, flowRuleCount=0
deviceId=of:000000000000000e, flowRuleCount=0
deviceId=of:000000000000000f, flowRuleCount=0
deviceId=of:0000000000000010, flowRuleCount=0
deviceId=of:0000000000000011, flowRuleCount=0
deviceId=of:0000000000000012, flowRuleCount=0
deviceId=of:0000000000000013, flowRuleCount=0
deviceId=of:0000000000000014, flowRuleCount=0
deviceId=of:0000000000000015, flowRuleCount=0
deviceId=of:0000000000000016, flowRuleCount=0
deviceId=of:0000000000000017, flowRuleCount=0
deviceId=of:0000000000000018, flowRuleCount=0
deviceId=of:0000000000000019, flowRuleCount=0
onos>
onos> summary
node=10.128.20.11, version=1.4.0.admin~2015/09/24@16:16
nodes=3, devices=25, links=0, hosts=0, SCC(s)=1, flows=0, intents=0
onos>
onos> app deactivate org.onosproject.
org.onosproject.drivers org.onosproject.mobility org.onosproject.openflow org.onosproject.proxyarp
onos> app deactivate org.onosproject.proxyarp
onos>
onos> apps | grep arp
id=33, name=org.onosproject.proxyarp, version=1.4.0.SNAPSHOT, origin=ON.Lab, description=Proxy ARP/NDP application, features=[onos-app-proxyarp], featuresRepo=mvn:org.onosproject/onos-app-proxyarp/1.4.0-SNAPSHOT/xml/features, permissions=[]
onos>
onos>
onos> summary
node=10.128.20.11, version=1.4.0.admin~2015/09/24@16:16
nodes=3, devices=25, links=114, hosts=0, SCC(s)=1, flows=75, intents=0
onos>
onos> flows | grep Count
deviceId=of:0000000000000001, flowRuleCount=3
deviceId=of:0000000000000002, flowRuleCount=3
deviceId=of:0000000000000003, flowRuleCount=3
deviceId=of:0000000000000004, flowRuleCount=3
deviceId=of:0000000000000005, flowRuleCount=3
deviceId=of:0000000000000006, flowRuleCount=3
deviceId=of:0000000000000007, flowRuleCount=3
deviceId=of:0000000000000008, flowRuleCount=3
deviceId=of:0000000000000009, flowRuleCount=3
deviceId=of:000000000000000a, flowRuleCount=3
deviceId=of:000000000000000b, flowRuleCount=3
deviceId=of:000000000000000c, flowRuleCount=3
deviceId=of:000000000000000d, flowRuleCount=3
deviceId=of:000000000000000e, flowRuleCount=3
deviceId=of:000000000000000f, flowRuleCount=3
deviceId=of:0000000000000010, flowRuleCount=3
deviceId=of:0000000000000011, flowRuleCount=3
deviceId=of:0000000000000012, flowRuleCount=3
deviceId=of:0000000000000013, flowRuleCount=3
deviceId=of:0000000000000014, flowRuleCount=3
deviceId=of:0000000000000015, flowRuleCount=3
deviceId=of:0000000000000016, flowRuleCount=3
deviceId=of:0000000000000017, flowRuleCount=3
deviceId=of:0000000000000018, flowRuleCount=3
deviceId=of:0000000000000019, flowRuleCount=3
onos>
onos> flows | grep ADD
id=10000488d6556, state=ADDED, bytes=25272, packets=312, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000488d73a0, state=ADDED, bytes=25272, packets=312, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489ccd5c, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000488dd9b5, state=ADDED, bytes=12555, packets=155, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000488de7ff, state=ADDED, bytes=12555, packets=155, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489d41bb, state=ADDED, bytes=0, packets=0, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000488e4e14, state=ADDED, bytes=56781, packets=701, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000488e5c5e, state=ADDED, bytes=56781, packets=701, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489db61a, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000488ec273, state=ADDED, bytes=25191, packets=311, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000488ed0bd, state=ADDED, bytes=25191, packets=311, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489e2a79, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000488f36d2, state=ADDED, bytes=12636, packets=156, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000488f451c, state=ADDED, bytes=12636, packets=156, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489e9ed8, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000488fab31, state=ADDED, bytes=37908, packets=468, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000488fb97b, state=ADDED, bytes=37908, packets=468, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489f1337, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048901f90, state=ADDED, bytes=31266, packets=386, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048902dda, state=ADDED, bytes=31266, packets=386, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489f8796, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489093ef, state=ADDED, bytes=25029, packets=309, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=100004890a239, state=ADDED, bytes=25029, packets=309, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489ffbf5, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=100004891084e, state=ADDED, bytes=25110, packets=310, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048911698, state=ADDED, bytes=25110, packets=310, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048a07054, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048a33726, state=ADDED, bytes=43983, packets=543, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048a34570, state=ADDED, bytes=43983, packets=543, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048b29f2c, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048a3ab85, state=ADDED, bytes=18954, packets=234, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048a3b9cf, state=ADDED, bytes=18954, packets=234, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048b3138b, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048a41fe4, state=ADDED, bytes=25191, packets=311, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048a42e2e, state=ADDED, bytes=25191, packets=311, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048b387ea, state=ADDED, bytes=0, packets=0, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048a49443, state=ADDED, bytes=18954, packets=234, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048a4a28d, state=ADDED, bytes=18954, packets=234, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048b3fc49, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048a508a2, state=ADDED, bytes=62775, packets=775, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048a516ec, state=ADDED, bytes=62775, packets=775, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048b470a8, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048a57d01, state=ADDED, bytes=18711, packets=231, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048a58b4b, state=ADDED, bytes=18711, packets=231, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048b4e507, state=ADDED, bytes=0, packets=0, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489b0878, state=ADDED, bytes=31428, packets=388, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489b16c2, state=ADDED, bytes=31428, packets=388, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048aa707e, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489b7cd7, state=ADDED, bytes=31266, packets=386, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489b8b21, state=ADDED, bytes=31266, packets=386, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048aae4dd, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489bf136, state=ADDED, bytes=56619, packets=699, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489bff80, state=ADDED, bytes=56619, packets=699, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048ab593c, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489c6595, state=ADDED, bytes=12636, packets=156, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489c73df, state=ADDED, bytes=12636, packets=156, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048abcd9b, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489cd9f4, state=ADDED, bytes=12474, packets=154, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489ce83e, state=ADDED, bytes=12474, packets=154, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048ac41fa, state=ADDED, bytes=0, packets=0, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489d4e53, state=ADDED, bytes=18792, packets=232, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489d5c9d, state=ADDED, bytes=18792, packets=232, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048acb659, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489dc2b2, state=ADDED, bytes=31266, packets=386, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489dd0fc, state=ADDED, bytes=31266, packets=386, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048ad2ab8, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489e3711, state=ADDED, bytes=43659, packets=539, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489e455b, state=ADDED, bytes=43659, packets=539, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048ad9f17, state=ADDED, bytes=0, packets=0, duration=240, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489eab70, state=ADDED, bytes=12636, packets=156, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489eb9ba, state=ADDED, bytes=12636, packets=156, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048ae1376, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489f1fcf, state=ADDED, bytes=25110, packets=310, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=10000489f2e19, state=ADDED, bytes=25110, packets=310, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
id=1000048ae87d5, state=ADDED, bytes=0, packets=0, duration=241, priority=40000, tableId=0 appId=org.onosproject.core, payLoad=null
onos> flows | grep ADD | wc
75 675 11700
onos>
onos> log:exception-display
java.lang.NullPointerException
at org.onosproject.provider.of.flow.impl.OpenFlowRuleProvider.executeBatch(OpenFlowRuleProvider.java:325)[171:org.onosproject.onos-of-provider-flow:1.4.0.SNAPSHOT]
at org.onosproject.net.flow.impl.FlowRuleManager$InternalStoreDelegate.notify(FlowRuleManager.java:493)[143:org.onosproject.onos-core-net:1.4.0.SNAPSHOT]
at org.onosproject.net.flow.impl.FlowRuleManager$InternalStoreDelegate.notify(FlowRuleManager.java:454)[143:org.onosproject.onos-core-net:1.4.0.SNAPSHOT]
at org.onosproject.store.AbstractStore.notifyDelegate(AbstractStore.java:58)[75:org.onosproject.onos-api:1.4.0.SNAPSHOT]
at org.onosproject.store.flow.impl.NewDistributedFlowRuleStore.storeBatchInternal(NewDistributedFlowRuleStore.java:439)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.flow.impl.NewDistributedFlowRuleStore.access$500(NewDistributedFlowRuleStore.java:99)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.flow.impl.NewDistributedFlowRuleStore$OnStoreBatch.handle(NewDistributedFlowRuleStore.java:591)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.cluster.messaging.impl.ClusterCommunicationManager$InternalClusterMessageHandler.apply(ClusterCommunicationManager.java:223)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.cluster.messaging.impl.ClusterCommunicationManager$InternalClusterMessageHandler.apply(ClusterCommunicationManager.java:213)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onlab.netty.NettyMessaging.lambda$null$4(NettyMessaging.java:214)[147:org.onosproject.onlab-netty:1.4.0.SNAPSHOT]
at org.onlab.netty.NettyMessaging$$Lambda$400/1764825051.run(Unknown Source)[147:org.onosproject.onlab-netty:1.4.0.SNAPSHOT]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_25]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_25]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_25]

onos>
onos> log:display
2015-09-24 19:20:49,579 | INFO | w I/O worker #11 | NewAdaptiveFlowStatsCollector | 171 - org.onosproject.onos-of-provider-flow - 1.4.0.SNAPSHOT | Started
2015-09-24 19:20:49,579 | INFO | w I/O worker #11 | OFChannelHandler | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | Processing 0 pending port status messages for 00:00:00:00:00:00:00:02
2015-09-24 19:20:49,581 | INFO | w I/O worker #11 | ntrollerImpl$OpenFlowSwitchAgent | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | Transitioned switch 00:00:00:00:00:00:00:02 to EQUAL
2015-09-24 19:20:49,585 | INFO | w I/O worker #13 | OFChannelHandler | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | New switch connection from /10.128.10.11:34167
2015-09-24 19:20:49,585 | INFO | w I/O worker #13 | OFChannelHandler | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | Sending OF_13 Hello to /10.128.10.11:34167
2015-09-24 19:20:49,587 | INFO | w I/O worker #13 | OFChannelHandler | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | Received port desc reply for switch at [/10.128.10.11:34167 DPID[00:00:00:00:00:00:00:04]]
2015-09-24 19:20:49,589 | INFO | w I/O worker #13 | OFChannelHandler | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | Received switch description reply OFDescStatsReplyVer13(xid=4294967289, flags=[], mfrDesc=Nicira, Inc., hwDesc=Open vSwitch, swDesc=2.3.0, serialNum=None, dpDesc=None) from switch at /10.128.10.11:34167
2015-09-24 19:20:49,589 | INFO | w I/O worker #13 | Controller | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | OpenFlow handshaker found for device 4: org.onosproject.driver.handshaker.NiciraSwitchHandshaker [? DPID[00:00:00:00:00:00:00:04]]
2015-09-24 19:20:49,589 | INFO | w I/O worker #13 | ntrollerImpl$OpenFlowSwitchAgent | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | Added switch 00:00:00:00:00:00:00:04
2015-09-24 19:20:49,596 | INFO | w I/O worker #13 | DeviceManager | 143 - org.onosproject.onos-core-net - 1.4.0.SNAPSHOT | Local role is MASTER for of:0000000000000004
2015-09-24 19:20:49,596 | INFO | w I/O worker #13 | DeviceManager | 143 - org.onosproject.onos-core-net - 1.4.0.SNAPSHOT | Device of:0000000000000004 connected
2015-09-24 19:20:49,597 | INFO | w I/O worker #13 | PortStatsCollector | 169 - org.onosproject.onos-of-provider-device - 1.4.0.SNAPSHOT | Starting Port Stats collection thread for 00:00:00:00:00:00:00:04
2015-09-24 19:20:49,597 | INFO | w I/O worker #13 | GroupStatsCollector | 172 - org.onosproject.onos-of-provider-group - 1.4.0.SNAPSHOT | Starting Group Stats collection thread for 00:00:00:00:00:00:00:04
2015-09-24 19:20:49,597 | INFO | w I/O worker #13 | MeterStatsCollector | 173 - org.onosproject.onos-of-provider-meter - 1.4.0.SNAPSHOT | Starting Meter Stats collection thread for 00:00:00:00:00:00:00:04
2015-09-24 19:20:49,598 | INFO | w I/O worker #13 | NewAdaptiveFlowStatsCollector | 171 - org.onosproject.onos-of-provider-flow - 1.4.0.SNAPSHOT | Started
2015-09-24 19:20:49,598 | INFO | w I/O worker #13 | OFChannelHandler | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | Processing 0 pending port status messages for 00:00:00:00:00:00:00:04
2015-09-24 19:20:49,598 | INFO | w I/O worker #13 | ntrollerImpl$OpenFlowSwitchAgent | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | Transitioned switch 00:00:00:00:00:00:00:04 to MASTER
2015-09-24 19:20:49,598 | INFO | event-dispatch-0 | FlowObjectiveManager | 143 - org.onosproject.onos-core-net - 1.4.0.SNAPSHOT | Driver ovs bound to device of:0000000000000004 ... initializing driver
2015-09-24 19:20:49,601 | WARN | message-handlers | PacketManager | 143 - org.onosproject.onos-core-net - 1.4.0.SNAPSHOT | Failed to install packet request DefaultPacketRequest{selector=DefaultTrafficSelector{criteria=[ETH_TYPE

{ethType=arp}]}, priority=40000, appId=DefaultApplicationId{id=42, name=org.onosproject.provider.host}} to of:0000000000000013: FLOWINSTALLATIONFAILED
2015-09-24 19:20:49,601 | WARN | message-handlers | PacketManager | 143 - org.onosproject.onos-core-net - 1.4.0.SNAPSHOT | Failed to install packet request DefaultPacketRequest{selector=DefaultTrafficSelector{criteria=[ETH_TYPE{ethType=lldp}]}, priority=40000, appId=DefaultApplicationId{id=41, name=org.onosproject.provider.lldp}} to of:0000000000000013: FLOWINSTALLATIONFAILED
2015-09-24 19:20:49,602 | WARN | message-handlers | PacketManager | 143 - org.onosproject.onos-core-net - 1.4.0.SNAPSHOT | Failed to install packet request DefaultPacketRequest{selector=DefaultTrafficSelector{criteria=[ETH_TYPE{ethType=arp}

]}, priority=40000, appId=DefaultApplicationId{id=33, name=org.onosproject.proxyarp}} to of:0000000000000013: FLOWINSTALLATIONFAILED
2015-09-24 19:20:49,603 | WARN | ice-installer-10 | PacketManager | 143 - org.onosproject.onos-core-net - 1.4.0.SNAPSHOT | Failed to install packet request DefaultPacketRequest{selector=DefaultTrafficSelector{criteria=[ETH_TYPE

{ethType=bddp}

]}, priority=40000, appId=DefaultApplicationId{id=41, name=org.onosproject.provider.lldp}} to of:0000000000000013: FLOWINSTALLATIONFAILED
2015-09-24 19:20:49,617 | INFO | nos-topo-build-2 | TopologyManager | 143 - org.onosproject.onos-core-net - 1.4.0.SNAPSHOT | Topology DefaultTopology

{time=17510250378360, creationTime=1443136849615, computeCost=137282, clusters=5, devices=5, links=2}

{time=17510278410540, creationTime=1443136849643, computeCost=75367, clusters=6, devices=6, links=2}

{time=17510319932273, creationTime=1443136849685, computeCost=81264, clusters=7, devices=7, links=2}

{time=17510331656401, creationTime=1443136849696, computeCost=69054, clusters=7, devices=7, links=3}

{time=17510358714310, creationTime=1443136849723, computeCost=85382, clusters=7, devices=8, links=5}

{time=17510399504645, creationTime=1443136849764, computeCost=159993, clusters=8, devices=9, links=5}

{time=17510451731753, creationTime=1443136849816, computeCost=152915, clusters=8, devices=10, links=14}

{time=17510468843005, creationTime=1443136849834, computeCost=120989, clusters=9, devices=11, links=14}

{time=17510510035477, creationTime=1443136849875, computeCost=163303, clusters=10, devices=12, links=14}

changed
2015-09-24 19:20:49,888 | INFO | ew I/O worker #5 | OFChannelHandler | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | New switch connection from /10.128.10.11:34192
2015-09-24 19:20:49,889 | INFO | ew I/O worker #5 | OFChannelHandler | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | Sending OF_13 Hello to /10.128.10.11:34192
2015-09-24 19:20:49,890 | INFO | dcast-trees-fg-3 | DistributedTopologyStore | 145 - org.onosproject.onos-core-dist - 1.4.0.SNAPSHOT | Cluster rooted at of:0000000000000005 has 2 broadcast-points; #-489164137
2015-09-24 19:20:49,890 | INFO | dcast-trees-fg-3 | DistributedTopologyStore | 145 - org.onosproject.onos-core-dist - 1.4.0.SNAPSHOT | Cluster rooted at of:0000000000000007 has 2 broadcast-points; #-489164006
2015-09-24 19:20:49,894 | INFO | ew I/O worker #5 | OFChannelHandler | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | Received port desc reply for switch at [/10.128.10.11:34192 DPID[00:00:00:00:00:00:00:0c]]
2015-09-24 19:20:49,895 | INFO | ew I/O worker #5 | OFChannelHandler | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | Received switch description reply OFDescStatsReplyVer13(xid=4294967289, flags=[], mfrDesc=Nicira, Inc., hwDesc=Open vSwitch, swDesc=2.3.0, serialNum=None, dpDesc=None) from switch at /10.128.10.11:34192
2015-09-24 19:20:49,896 | INFO | ew I/O worker #5 | Controller | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | OpenFlow handshaker found for device 12: org.onosproject.driver.handshaker.NiciraSwitchHandshaker [? DPID[00:00:00:00:00:00:00:0c]]
2015-09-24 19:20:49,896 | INFO | ew I/O worker #5 | ntrollerImpl$OpenFlowSwitchAgent | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | Added switch 00:00:00:00:00:00:00:0c
2015-09-24 19:20:49,902 | INFO | ew I/O worker #5 | DeviceManager | 143 - org.onosproject.onos-core-net - 1.4.0.SNAPSHOT | Local role is MASTER for of:000000000000000c
2015-09-24 19:20:49,902 | INFO | ew I/O worker #5 | DeviceManager | 143 - org.onosproject.onos-core-net - 1.4.0.SNAPSHOT | Device of:000000000000000c connected
2015-09-24 19:20:49,902 | INFO | ew I/O worker #5 | PortStatsCollector | 169 - org.onosproject.onos-of-provider-device - 1.4.0.SNAPSHOT | Starting Port Stats collection thread for 00:00:00:00:00:00:00:0c
2015-09-24 19:20:49,902 | INFO | ew I/O worker #5 | GroupStatsCollector | 172 - org.onosproject.onos-of-provider-group - 1.4.0.SNAPSHOT | Starting Group Stats collection thread for 00:00:00:00:00:00:00:0c
2015-09-24 19:20:49,902 | INFO | ew I/O worker #5 | MeterStatsCollector | 173 - org.onosproject.onos-of-provider-meter - 1.4.0.SNAPSHOT | Starting Meter Stats collection thread for 00:00:00:00:00:00:00:0c
2015-09-24 19:20:49,903 | INFO | event-dispatch-0 | FlowObjectiveManager | 143 - org.onosproject.onos-core-net - 1.4.0.SNAPSHOT | Driver ovs bound to device of:000000000000000c ... initializing driver
2015-09-24 19:20:49,903 | INFO | event-dispatch-0 | FlowObjectiveManager | 143 - org.onosproject.onos-core-net - 1.4.0.SNAPSHOT | Driver ovs bound to device of:000000000000000c ... initializing driver
2015-09-24 19:20:49,904 | INFO | ew I/O worker #5 | NewAdaptiveFlowStatsCollector | 171 - org.onosproject.onos-of-provider-flow - 1.4.0.SNAPSHOT | Started
2015-09-24 19:20:49,904 | INFO | ew I/O worker #5 | OFChannelHandler | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | Processing 0 pending port status messages for 00:00:00:00:00:00:00:0c
2015-09-24 19:20:49,904 | INFO | ew I/O worker #5 | ntrollerImpl$OpenFlowSwitchAgent | 166 - org.onosproject.onos-of-ctl - 1.4.0.SNAPSHOT | Transitioned switch 00:00:00:00:00:00:00:0c to MASTER
2015-09-24 19:20:49,905 | ERROR | message-handlers | Tools | 73 - org.onosproject.onlab-misc - 1.4.0.SNAPSHOT | Uncaught exception on onos-store-flow-message-handlers
java.lang.NullPointerException
at org.onosproject.provider.of.flow.impl.OpenFlowRuleProvider.executeBatch(OpenFlowRuleProvider.java:325)[171:org.onosproject.onos-of-provider-flow:1.4.0.SNAPSHOT]
at org.onosproject.net.flow.impl.FlowRuleManager$InternalStoreDelegate.notify(FlowRuleManager.java:493)[143:org.onosproject.onos-core-net:1.4.0.SNAPSHOT]
at org.onosproject.net.flow.impl.FlowRuleManager$InternalStoreDelegate.notify(FlowRuleManager.java:454)[143:org.onosproject.onos-core-net:1.4.0.SNAPSHOT]
at org.onosproject.store.AbstractStore.notifyDelegate(AbstractStore.java:58)[75:org.onosproject.onos-api:1.4.0.SNAPSHOT]
at org.onosproject.store.flow.impl.NewDistributedFlowRuleStore.storeBatchInternal(NewDistributedFlowRuleStore.java:439)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.flow.impl.NewDistributedFlowRuleStore.access$500(NewDistributedFlowRuleStore.java:99)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.flow.impl.NewDistributedFlowRuleStore$OnStoreBatch.handle(NewDistributedFlowRuleStore.java:591)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.cluster.messaging.impl.ClusterCommunicationManager$InternalClusterMessageHandler.apply(ClusterCommunicationManager.java:223)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.cluster.messaging.impl.ClusterCommunicationManager$InternalClusterMessageHandler.apply(ClusterCommunicationManager.java:213)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onlab.netty.NettyMessaging.lambda$null$4(NettyMessaging.java:214)[147:org.onosproject.onlab-netty:1.4.0.SNAPSHOT]
at org.onlab.netty.NettyMessaging$$Lambda$400/1764825051.run(Unknown Source)[147:org.onosproject.onlab-netty:1.4.0.SNAPSHOT]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_25]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_25]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_25]
2015-09-24 19:20:49,914 | ERROR | message-handlers | Tools | 73 - org.onosproject.onlab-misc - 1.4.0.SNAPSHOT | Uncaught exception on onos-store-flow-message-handlers
java.lang.NullPointerException
at org.onosproject.provider.of.flow.impl.OpenFlowRuleProvider.executeBatch(OpenFlowRuleProvider.java:325)[171:org.onosproject.onos-of-provider-flow:1.4.0.SNAPSHOT]
at org.onosproject.net.flow.impl.FlowRuleManager$InternalStoreDelegate.notify(FlowRuleManager.java:493)[143:org.onosproject.onos-core-net:1.4.0.SNAPSHOT]
at org.onosproject.net.flow.impl.FlowRuleManager$InternalStoreDelegate.notify(FlowRuleManager.java:454)[143:org.onosproject.onos-core-net:1.4.0.SNAPSHOT]
at org.onosproject.store.AbstractStore.notifyDelegate(AbstractStore.java:58)[75:org.onosproject.onos-api:1.4.0.SNAPSHOT]
at org.onosproject.store.flow.impl.NewDistributedFlowRuleStore.storeBatchInternal(NewDistributedFlowRuleStore.java:439)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.flow.impl.NewDistributedFlowRuleStore.access$500(NewDistributedFlowRuleStore.java:99)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.flow.impl.NewDistributedFlowRuleStore$OnStoreBatch.handle(NewDistributedFlowRuleStore.java:591)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.cluster.messaging.impl.ClusterCommunicationManager$InternalClusterMessageHandler.apply(ClusterCommunicationManager.java:223)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.cluster.messaging.impl.ClusterCommunicationManager$InternalClusterMessageHandler.apply(ClusterCommunicationManager.java:213)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onlab.netty.NettyMessaging.lambda$null$4(NettyMessaging.java:214)[147:org.onosproject.onlab-netty:1.4.0.SNAPSHOT]
at org.onlab.netty.NettyMessaging$$Lambda$400/1764825051.run(Unknown Source)[147:org.onosproject.onlab-netty:1.4.0.SNAPSHOT]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_25]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_25]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_25]
2015-09-24 19:20:49,914 | ERROR | message-handlers | Tools | 73 - org.onosproject.onlab-misc - 1.4.0.SNAPSHOT | Uncaught exception on onos-store-flow-message-handlers
java.lang.NullPointerException
at org.onosproject.provider.of.flow.impl.OpenFlowRuleProvider.executeBatch(OpenFlowRuleProvider.java:325)[171:org.onosproject.onos-of-provider-flow:1.4.0.SNAPSHOT]
at org.onosproject.net.flow.impl.FlowRuleManager$InternalStoreDelegate.notify(FlowRuleManager.java:493)[143:org.onosproject.onos-core-net:1.4.0.SNAPSHOT]
at org.onosproject.net.flow.impl.FlowRuleManager$InternalStoreDelegate.notify(FlowRuleManager.java:454)[143:org.onosproject.onos-core-net:1.4.0.SNAPSHOT]
at org.onosproject.store.AbstractStore.notifyDelegate(AbstractStore.java:58)[75:org.onosproject.onos-api:1.4.0.SNAPSHOT]
at org.onosproject.store.flow.impl.NewDistributedFlowRuleStore.storeBatchInternal(NewDistributedFlowRuleStore.java:439)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.flow.impl.NewDistributedFlowRuleStore.access$500(NewDistributedFlowRuleStore.java:99)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.flow.impl.NewDistributedFlowRuleStore$OnStoreBatch.handle(NewDistributedFlowRuleStore.java:591)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.cluster.messaging.impl.ClusterCommunicationManager$InternalClusterMessageHandler.apply(ClusterCommunicationManager.java:223)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onosproject.store.cluster.messaging.impl.ClusterCommunicationManager$InternalClusterMessageHandler.apply(ClusterCommunicationManager.java:213)[145:org.onosproject.onos-core-dist:1.4.0.SNAPSHOT]
at org.onlab.netty.NettyMessaging.lambda$null$4(NettyMessaging.java:214)[147:org.onosproject.onlab-netty:1.4.0.SNAPSHOT]
at org.onlab.netty.NettyMessaging$$Lambda$400/1764825051.run(Unknown Source)[147:org.onosproject.onlab-netty:1.4.0.SNAPSHOT]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_25]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_25]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_25]
2015-09-24 19:20:49,930 | INFO | nos-topo-build-3 | TopologyManager | 143 - org.onosproject.onos-core-net - 1.4.0.SNAPSHOT | Topology DefaultTopology

{time=17510561254975, creationTime=1443136849926, computeCost=343964, clusters=10, devices=13, links=21}

{time=17510588004931, creationTime=1443136849953, computeCost=189160, clusters=11, devices=14, links=21}

{time=17510651789961, creationTime=1443136850017, computeCost=251289, clusters=11, devices=15, links=25}

{time=17510664097468, creationTime=1443136850029, computeCost=302468, clusters=11, devices=16, links=31}

{time=17510709874245, creationTime=1443136850075, computeCost=375274, clusters=12, devices=17, links=31}

{time=17510758189228, creationTime=1443136850123, computeCost=151078, clusters=13, devices=18, links=36}

{time=17510789712576, creationTime=1443136850154, computeCost=141916, clusters=14, devices=19, links=36}

{time=17510829963451, creationTime=1443136850195, computeCost=143895, clusters=15, devices=20, links=36}

{time=17510851336965, creationTime=1443136850216, computeCost=207617, clusters=13, devices=20, links=47}

{time=17510868952381, creationTime=1443136850234, computeCost=141602, clusters=14, devices=21, links=47}

{time=17510908836306, creationTime=1443136850274, computeCost=193270, clusters=15, devices=22, links=47}

{time=17510951346514, creationTime=1443136850316, computeCost=254110, clusters=16, devices=23, links=51}

{time=17511025267213, creationTime=1443136850390, computeCost=278122, clusters=17, devices=24, links=51}

{time=17511064052027, creationTime=1443136850429, computeCost=241184, clusters=18, devices=25, links=55}

{time=17511149756728, creationTime=1443136850514, computeCost=287967, clusters=18, devices=25, links=57}

{time=17511252072223, creationTime=1443136850617, computeCost=230348, clusters=18, devices=25, links=64}

{time=17513251022546, creationTime=1443136852616, computeCost=322046, clusters=14, devices=25, links=68}

{time=17513350956339, creationTime=1443136852716, computeCost=277773, clusters=8, devices=25, links=77}

{time=17513434343239, creationTime=1443136852799, computeCost=330880, clusters=8, devices=25, links=80}

{time=17513452824682, creationTime=1443136852818, computeCost=341244, clusters=6, devices=25, links=86}

{time=17513653460407, creationTime=1443136853018, computeCost=434331, clusters=3, devices=25, links=93}

{time=17513732791317, creationTime=1443136853098, computeCost=385306, clusters=3, devices=25, links=95}

{time=17513752829143, creationTime=1443136853118, computeCost=262187, clusters=3, devices=25, links=100}

{time=17513851458682, creationTime=1443136853216, computeCost=347744, clusters=3, devices=25, links=103}

{time=17513953155028, creationTime=1443136853318, computeCost=287076, clusters=2, devices=25, links=108}

{time=17514051258606, creationTime=1443136853416, computeCost=460507, clusters=2, devices=25, links=109}

{time=17514151309787, creationTime=1443136853516, computeCost=400996, clusters=1, devices=25, links=112}

{time=17514250397108, creationTime=1443136853615, computeCost=478252, clusters=1, devices=25, links=114}

onos>

Attachments

Options
- Issue Only
- Show All Reviews
- Show Open Reviews
- Show All Issues
- Show Open Issues

Gerrit Reviews

No reviews matched the request. Check your Options in the drop-down menu of this sections header.

Activity

People

Assignee:: ash

Reporter:: hari

Votes:: 0 Vote for this issue

Watchers:: 5 Start watching this issue

Dates

Created:: 24/Sep/15 11:32 PM

Updated:: 20/Oct/15 2:30 PM

Resolved:: 20/Oct/15 2:30 PM