karaf.log
karaf.log
karaf.txt
[OPNFLWPLUG-881] Openflow plugin fails to control OF10 Switches Created: 18/Apr/17 Updated: 27/Sep/21 Resolved: 22/May/17 |
|
| Status: | Resolved |
| Project: | OpenFlowPlugin |
| Component/s: | General |
| Affects Version/s: | None |
| Fix Version/s: | None |
| Type: | Bug | ||
| Reporter: | Venkatrangan Govindarajan | Assignee: | Venkatrangan Govindarajan |
| Resolution: | Done | Votes: | 0 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Environment: |
Operating System: All |
||
| Attachments: |
karaf.log
karaf.log
karaf.txt
|
| External issue ID: | 8239 |
| Description |
|
Versions ODL: Carbon OVS : 2.0.2, Mininet: 2.2.1 on Ubuntu 14.0.4 Executed Mininet using the below command Feature Installed in ODL : odl-vtn-manager that uses odl-openflowplugin. Problems: a. VTN invokes statistics rpc that fails with the below Error Message ----------- start of log snippet java.lang.IllegalArgumentException: Metadata not available for modification NodeModification [identifier=(urn:opendaylight:inventory?revision=2013-08-19)node-connector[ {(urn:opendaylight:inventory?revision=2013-08-19)id=openflow:1:LOCAL}], modificationType=TOUCH, childModification={AugmentationIdentifier {childNames=[(urn:opendaylight:port:statistics?revision=2013-12-14)flow-capable-node-connector-statistics]}=NodeModification [identifier=AugmentationIdentifier {childNames=[(urn:opendaylight:port:statistics?revision=2013-12-14)flow-capable-node-connector-statistics]}, modificationType=TOUCH, childModification={(urn:opendaylight:port:statistics?revision=2013-12-14)flow-capable-node-connector-statistics=NodeModification [identifier=(urn:opendaylight:port:statistics?revision=2013-12-14)flow-capable-node-connector-statistics, modificationType=WRITE, childModification={}]}]}] ---------- end of log snippet b. openflowplugin fails to recover even after multiple mininet restarts. karaf log has been attached. |
| Comments |
| Comment by Venkatrangan Govindarajan [ 18/Apr/17 ] |
|
Attachment karaf.log has been added with description: Karaf Log with Errors. |
| Comment by Venkatrangan Govindarajan [ 18/Apr/17 ] |
|
Detailed analysis of the problem for fixing The issue occurs when statistics manager writes flow-capable-node-connector-statistics into DS before the target node-connector is created. When we use Mininet to generate switches, switches are generated without any ports firstly, then ports are generated. Therefore, the OFP needs to handle such a situation, but it doesn't right now. When the issue happened, that is, the OFP got connected with OF 1.0 switches, the OPF worked as follows: Step 1. Handshake with an OF 1.0 switch was done successfully. OFP got the result of the OFPT_FEATURES_REPLY. At that time, the result didn't contain port information. The postHandshake() of the HandshakeManagerImpl.java sent the FEATURES_REQUEST after the handshake. [openflowplugin/src/main/java/org/opendaylight/openflowplugin/openflow/md/core/HandshakeManagerImpl.java] /**
LOG.debug("version set: {}", proposedVersion); On the success, the onHandshakeSuccessful() of HandshakeListenerImpl.java was called with the result of the FEATURES_REPLY. [impl/src/main/java/org/opendaylight/openflowplugin/impl/connection/listener/HandshakeListenerImpl.java] new FutureCallback<RpcResult<GetFeaturesOutput>>() { LOG.debug("obtained features: datapathId={}", The onHandshakeSuccessful() method stored the result in ConnectionContextImpl.java. @Override Step 2. Ports on the OF 1.0 switch was generated, and OFPT_PORT_STATUS was notified to the OFP. However, the initialization of the target node information in the OFP was not completed yet, the OFP didn't write node-connector to the DS. Receiving PORT_STATUS, processPortStatusMessage() of DeviceContextImpl.java was called, and a node-connector was created. [impl/src/main/java/org/opendaylight/openflowplugin/impl/device/DeviceContextImpl.java] @Override final KeyedInstanceIdentifier<NodeConnector, NodeConnectorKey> iiToNodeConnector = provideIIToNodeConnector(portStatus.getPortNo(), portStatus.getVersion()); However, writeToTransaction() which write data into DS is implemented to do nothing when the initialized member variable is false. @Override } The initialized variable is modified to true by lazyTransactionManagerInitialization() which is called by onContextInstantiateService(). @VisibleForTesting Step 3. The OFP created the initial data for the OF 1.0 switch. At that time, the OFP used the result of the OFPT_FEATURES_REPLY which the OFP got immediately after handshake in order to create node-connector information. Thus, the OFP didn't create node-connector even though ports existed in the OF 1.0 switch. The initialization for each OF 1.0 version is implemented in DeviceContextImpl.onContextInstantiateService(). try { if (initializer.isPresent()) { final MultipartWriterProvider writerProvider = MultipartWriterProviderFactory.createDefaultProvider(this); initializer.get().initialize(this, switchFeaturesMandatory, writerProvider, convertorExecutor); }else { throw new ExecutionException(new ConnectionException("Unsupported version " + deviceInfo.getVersion())); } } catch (ExecutionException | InterruptedException e) { The instance of the OF10DeviceInitializer class was assigned into the initializer. (openflowplugin-impl/src/main/java/org/opendaylight/openflowplugin/impl/device/initialization/OF10DeviceInitializer.java) The OFPMP_DESC of multipart was acquired in OF10DeviceInitializer.initializeNodeInformation(). return Futures.transform(future, new Function<Boolean, Void>() { }); However, node-connector is created based on the result of FEATURES_REPLY which is stored in ConnectionContextImpl. private static void writePhyPortInformation(final DeviceContext deviceContext) { connectionContext.getFeatures().getPhyPort().forEach(port -> { Step 4. After the OFP waited the completion of the above step (step 3), its statistic manager got the initial data of statistics using OFPT_STATS_REQUEST. At this time, the OFP also got OFPST_PORT, and it wrote flow-capable-node-connector-statistics into DS. The initialize() of the AbstractDeviceInitializer.java waits the completion of the initialization. [openflowplugin-impl/src/main/java/org/opendaylight/openflowplugin/impl/device/initialization/AbstractDeviceInitializer.java] // Synchronously get information about device After that DeviceContextImpl.onContextInstantiateService() called onContextInstantiateService() of StatisticsContextImpl (openflowplugin-impl/src/main/java/org/opendaylight/openflowplugin/impl/statistics/StatisticsContextImpl.java). return this.clusterInitializationPhaseHandler.onContextInstantiateService(mastershipChangeListener); StatisticsContextImpl.onContextInstantiateService() calls the initialization procedure for statistics. @Override LOG.info("Starting statistics context cluster services for node {}", deviceInfo.getLOGValue()); this.statListForCollectingInitialization(); Step 5. When the OFP submitted the initial data to DS, it failed to submit, since the node-connector which was the parent of flow-capable-node-connector-statistics, which was wrote in the above step (step 4), didn't exist. Step 6. Since the initialization of the device failed, the OFP could not control the target switch at all. Please note that the above explanation is for the master and stable/carbon branch. On the stable/boron, the method which does specific initialization for each OF version is initializeNodeInformation() of openflowplugin-impl/src/main/java/org/opendaylight/openflowplugin/impl/util/DeviceInitializationUtils.java. if (OFConstants.OFP_VERSION_1_0 == version) { DeviceStateUtil.setDeviceStateBasedOnV10Capabilities(deviceState, capabilitiesV10); deviceFeaturesFuture = createDeviceFeaturesForOF10(deviceContext); final short ofVersion = deviceInfo.getVersion(); for (final PortGrouping port : connectionContext.getFeatures().getPhyPort()) { |
| Comment by Venkatrangan Govindarajan [ 18/Apr/17 ] |
|
The problem occurs much before VTN invoking any rpc. Please check the Comment 1 for more details. |
| Comment by Tomas Slusny [ 19/Apr/17 ] |
|
Isn't this really similar to |
| Comment by Venkatrangan Govindarajan [ 24/Apr/17 ] |
|
(In reply to Tomas Slusny from comment #3) Hi Thomas, Thanks for responding to the bug report. I tested the patches for |
| Comment by Venkatrangan Govindarajan [ 24/Apr/17 ] |
|
Please check the logs from 00:17 time. The errors weere created regularly after that time/. |
| Comment by Venkatrangan Govindarajan [ 24/Apr/17 ] |
|
Attachment karaf.log has been added with description: Logs with latest stable/carbon code. |
| Comment by Tomas Slusny [ 24/Apr/17 ] |
|
Can you test it with this patch? https://git.opendaylight.org/gerrit/#/c/55868/ |
| Comment by Tomas Slusny [ 24/Apr/17 ] |
|
Nevermind, need to make some changes on the patch. |
| Comment by Tomas Slusny [ 27/Apr/17 ] |
| Comment by Arthi Bhattacharjee [ 28/Apr/17 ] |
|
Tested the above patch in stable/carbon. Most of the time, issue is been reproduced when miminet is restarted. |
| Comment by Arthi Bhattacharjee [ 28/Apr/17 ] |
|
Attachment karaf.txt has been added with description: Karaf logs |
| Comment by Tomas Slusny [ 10/May/17 ] |
|
Can you try it again with latest version of patch please? Now it should handle all missed port statuses since open of connection. |
| Comment by Abhijit Kumbhare [ 22/May/17 ] |
|
Closing it as it is fixed as per Tomas Slusny - please reopen it if you still see an issue. |