[CONTROLLER-1885] VerifyException during transaction close Created: 20/Feb/19  Updated: 20/Feb/19  Resolved: 20/Feb/19

Status: Resolved
Project: controller
Component/s: clustering
Affects Version/s: Neon, Fluorine SR1, Sodium
Fix Version/s: Neon, Fluorine SR2, Sodium

Type: Bug Priority: Medium
Reporter: Robert Varga Assignee: Robert Varga
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified


 Description   

During validation of tell-based protocol with openflowplugin, the following splat occurred:

2019-02-19T18:12:22,772 | ERROR | Framework stop   | BeanRecipe                       | 69 - org.apache.aries.blueprint.core - 1.10.1 | The blueprint bean flowCapableTopologyProvider in bundle org.opendaylight.openflowplugin.applications.topology-manager/0.9.0.SNAPSHOT incorrectly threw an exception from its destroy
 method.
java.lang.IllegalStateException: Uncaught exception occured during closing transaction
        at org.opendaylight.controller.cluster.databroker.AbstractDOMBrokerTransaction.closeSubtransactions(AbstractDOMBrokerTransaction.java:91) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.AbstractDOMBrokerWriteTransaction.cancel(AbstractDOMBrokerWriteTransaction.java:110) ~[?:?]
        at org.opendaylight.controller.sal.core.compat.LegacyDOMDataBrokerAdapter$DOMDataTransactionAdapter.cancel(LegacyDOMDataBrokerAdapter.java:287) ~[?:?]
        at org.opendaylight.controller.md.sal.dom.broker.impl.PingPongTransactionChain.cancelTransaction(PingPongTransactionChain.java:346) ~[?:?]
        at org.opendaylight.controller.md.sal.dom.broker.impl.PingPongTransactionChain$4.cancel(PingPongTransactionChain.java:463) ~[?:?]
        at org.opendaylight.controller.md.sal.binding.impl.AbstractWriteTransaction.doCancel(AbstractWriteTransaction.java:133) ~[?:?]
        at org.opendaylight.controller.md.sal.binding.impl.BindingDOMWriteTransactionAdapter.cancel(BindingDOMWriteTransactionAdapter.java:76) ~[?:?]
        at org.opendaylight.openflowplugin.common.txchain.TransactionChainManager.closeTransactionChain(TransactionChainManager.java:150) ~[?:?]
        at org.opendaylight.openflowplugin.common.txchain.TransactionChainManager.close(TransactionChainManager.java:355) ~[?:?]
        at org.opendaylight.openflowplugin.applications.topology.manager.FlowCapableTopologyProvider.close(FlowCapableTopologyProvider.java:86) ~[?:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
        at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
        at org.apache.aries.blueprint.utils.ReflectionUtils.invoke(ReflectionUtils.java:337) ~[69:org.apache.aries.blueprint.core:1.10.1]
        at org.apache.aries.blueprint.container.BeanRecipe.invoke(BeanRecipe.java:835) ~[69:org.apache.aries.blueprint.core:1.10.1]
        at org.apache.aries.blueprint.container.BeanRecipe.destroy(BeanRecipe.java:742) [69:org.apache.aries.blueprint.core:1.10.1]
        at org.apache.aries.blueprint.container.BlueprintRepository.destroy(BlueprintRepository.java:434) [69:org.apache.aries.blueprint.core:1.10.1]
        at org.apache.aries.blueprint.container.BlueprintContainerImpl.destroyComponents(BlueprintContainerImpl.java:758) [69:org.apache.aries.blueprint.core:1.10.1]
        at org.apache.aries.blueprint.container.BlueprintContainerImpl.tidyupComponents(BlueprintContainerImpl.java:967) [69:org.apache.aries.blueprint.core:1.10.1]
        at org.apache.aries.blueprint.container.BlueprintContainerImpl.destroy(BlueprintContainerImpl.java:903) [69:org.apache.aries.blueprint.core:1.10.1]
        at org.apache.aries.blueprint.container.BlueprintExtender$3.run(BlueprintExtender.java:324) [69:org.apache.aries.blueprint.core:1.10.1]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
        at org.apache.aries.blueprint.container.BlueprintExtender.destroyContainer(BlueprintExtender.java:345) [69:org.apache.aries.blueprint.core:1.10.1]
        at org.apache.aries.blueprint.container.BlueprintExtender.access$400(BlueprintExtender.java:68) [69:org.apache.aries.blueprint.core:1.10.1]
        at org.apache.aries.blueprint.container.BlueprintExtender$BlueprintContainerServiceImpl.destroyContainer(BlueprintExtender.java:631) [69:org.apache.aries.blueprint.core:1.10.1]
        at org.opendaylight.controller.blueprint.BlueprintBundleTracker.shutdownAllContainers(BlueprintBundleTracker.java:292) [198:org.opendaylight.controller.blueprint:0.11.0.SNAPSHOT]
        at org.opendaylight.controller.blueprint.BlueprintBundleTracker.bundleChanged(BlueprintBundleTracker.java:192) [198:org.opendaylight.controller.blueprint:0.11.0.SNAPSHOT]
        at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) [?:?]
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) [?:?]
        at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) [?:?]
        at org.eclipse.osgi.container.Module.doStop(Module.java:634) [?:?]
        at org.eclipse.osgi.container.Module.stop(Module.java:498) [?:?]
        at org.eclipse.osgi.container.SystemModule.stop(SystemModule.java:202) [?:?]
        at org.eclipse.osgi.internal.framework.EquinoxBundle$SystemBundle$EquinoxSystemModule$1.run(EquinoxBundle.java:165) [?:?]
        at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: com.google.common.base.VerifyException: Attempted to replay seal on RemoteProxyTransaction{identifier=member-3-datastore-operational-fe-0-chn-2-txn-0-2, state=SUCCESSOR}
        at com.google.common.base.Verify.verify(Verify.java:181) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.actors.dds.AbstractProxyTransaction.sealOnly(AbstractProxyTransaction.java:369) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.actors.dds.RemoteProxyTransaction.handleForwardedModifyTransactionRequest(RemoteProxyTransaction.java:350) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.actors.dds.RemoteProxyTransaction.handleForwardedRequest(RemoteProxyTransaction.java:305) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.actors.dds.RemoteProxyTransaction.forwardToRemote(RemoteProxyTransaction.java:300) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.actors.dds.AbstractProxyTransaction.forwardToSuccessor(AbstractProxyTransaction.java:780) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.actors.dds.AbstractProxyTransaction.forwardRequest(AbstractProxyTransaction.java:772) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.actors.dds.ProxyHistory$ReconnectCohort.forwardEntry(ProxyHistory.java:291) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.actors.dds.BouncingReconnectForwarder.forwardEntry(BouncingReconnectForwarder.java:61) ~[?:?]
        at org.opendaylight.controller.cluster.access.client.TransmitQueue.enqueueOrForward(TransmitQueue.java:266) ~[?:?]
        at org.opendaylight.controller.cluster.access.client.AbstractClientConnection.enqueueOrForward(AbstractClientConnection.java:182) ~[?:?]
        at org.opendaylight.controller.cluster.access.client.AbstractClientConnection.sendEntry(AbstractClientConnection.java:256) ~[?:?]
        at org.opendaylight.controller.cluster.access.client.SimpleReconnectForwarder.forwardEntry(SimpleReconnectForwarder.java:18) ~[?:?]
        at org.opendaylight.controller.cluster.access.client.TransmitQueue.enqueueOrForward(TransmitQueue.java:266) ~[?:?]
        at org.opendaylight.controller.cluster.access.client.AbstractClientConnection.enqueueOrForward(AbstractClientConnection.java:182) ~[?:?]
        at org.opendaylight.controller.cluster.access.client.AbstractClientConnection.sendEntry(AbstractClientConnection.java:256) ~[?:?]
        at org.opendaylight.controller.cluster.access.client.AbstractClientConnection.sendRequest(AbstractClientConnection.java:158) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.actors.dds.ProxyHistory.sendRequest(ProxyHistory.java:448) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.actors.dds.AbstractProxyTransaction.sendRequest(AbstractProxyTransaction.java:325) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.actors.dds.AbstractProxyTransaction.abort(AbstractProxyTransaction.java:436) ~[?:?]
        at java.util.concurrent.ConcurrentHashMap$ValuesView.forEach(ConcurrentHashMap.java:4707) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.actors.dds.AbstractClientHandle.commonAbort(AbstractClientHandle.java:81) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.actors.dds.AbstractClientHandle.abort(AbstractClientHandle.java:67) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.ClientBackedTransaction.close(ClientBackedTransaction.java:78) ~[?:?]
        at org.opendaylight.controller.cluster.databroker.AbstractDOMBrokerTransaction.closeSubtransactions(AbstractDOMBrokerTransaction.java:87) ~[?:?]
        ... 41 more


 Comments   
Comment by Robert Varga [ 20/Feb/19 ]

This looks like a reconnect race, where the RemoteProxyTransaction.handleForwardedRequest() path does not account for the possibility of a successor being present. Unlike "replay" methods, which are invoked from the thread handling reconnect, "forward" methods are executed in application threads and therefore need to properly handle synchronization.

Comment by Robert Varga [ 20/Feb/19 ]

Since the forward path already uses sendRequest(), which handles the propagation towards the successor, we should be fine with just removing the assertion from that path.

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