java.util.concurrent.CancellationException: Task was cancelled. on osgi console

When running mininet against the distribution built in

openflowplugin/distributions/base/

(mininet command:

sudo mn --topo tree,3 --controller 'remote,ip=192.168.195.157:6653' --switch ovsk,protocols=OpenFlow13
)

I see the following exception:

2013-11-23 16:09:32.541 PST [pool-327-thread-1] INFO o.o.o.o.md.core.HandshakeManagerImpl - handshake STARTED
2013-11-23 16:09:32.542 PST [nioEventLoopGroup-5-7] INFO o.o.o.p.impl.core.OFFrameDecoder - OF Protocol message received, type:3
2013-11-23 16:09:32.543 PST [nioEventLoopGroup-5-3] INFO o.o.o.p.i.c.DelegatingInboundHandler - Channel inactive
2013-11-23 16:09:32.543 PST [nioEventLoopGroup-5-3] WARN o.o.o.o.m.c.s.SessionManagerOFImpl - context for invalidation not found
2013-11-23 16:09:32.543 PST [nioEventLoopGroup-5-3] WARN o.o.o.p.i.c.ConnectionAdapterImpl - rpc response discarded: RpcResultKey [xid=880, outputClazz=interface org.opendaylight.yang.gen.v1.urn.opendaylight.openflow.protocol.rev130731.GetFeaturesOutput]
2013-11-23 16:09:32.543 PST [nioEventLoopGroup-5-3] INFO o.o.o.p.i.c.DelegatingInboundHandler - Channel unregistered
2013-11-23 16:09:32.543 PST [pool-327-thread-1] ERROR o.o.o.o.md.core.HandshakeManagerImpl - issuing disconnect during handshake, reason: Task was cancelled.
2013-11-23 16:09:32.543 PST [pool-327-thread-1] INFO o.o.o.o.md.core.HandshakeManagerImpl - handshake STARTED
2013-11-23 16:09:32.543 PST [pool-327-thread-1] ERROR o.o.o.o.md.core.HandshakeManagerImpl - issuing disconnect during handshake, reason: rpcError:null;
2013-11-23 16:09:32.546 PST [Thread-26] ERROR o.o.o.o.m.core.ErrorHandlerQueueImpl - IN THREAD: pool-327-thread-1; session:null -> Task was cancelled.
java.util.concurrent.CancellationException: Task was cancelled.
at com.google.common.util.concurrent.AbstractFuture.cancellationExceptionWithCause(AbstractFuture.java:399) ~[na:na]
at com.google.common.util.concurrent.AbstractFuture$Sync.getValue(AbstractFuture.java:313) ~[na:na]
at com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:279) ~[na:na]
at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:96) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeManagerImpl.postHandshake(HandshakeManagerImpl.java:285) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeManagerImpl.handleVersionBitmapNegotiation(HandshakeManagerImpl.java:158) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeManagerImpl.run(HandshakeManagerImpl.java:100) ~[na:na]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_25]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_25]
at java.lang.Thread.run(Thread.java:724) ~[na:1.7.0_25]
Caused by: java.util.concurrent.CancellationException: Future.cancel() was called.
at com.google.common.util.concurrent.AbstractFuture$Sync.complete(AbstractFuture.java:385) ~[na:na]
at com.google.common.util.concurrent.AbstractFuture$Sync.cancel(AbstractFuture.java:362) ~[na:na]
at com.google.common.util.concurrent.AbstractFuture.cancel(AbstractFuture.java:131) ~[na:na]
at org.opendaylight.openflowjava.protocol.impl.connection.ConnectionAdapterImpl$ResponseRemovalListener.onRemoval(ConnectionAdapterImpl.java:532) ~[na:na]
at com.google.common.cache.LocalCache.processPendingNotifications(LocalCache.java:2016) ~[na:na]
at com.google.common.cache.LocalCache$Segment.runUnlockedCleanup(LocalCache.java:3521) ~[na:na]
at com.google.common.cache.LocalCache$Segment.postWriteCleanup(LocalCache.java:3497) ~[na:na]
at com.google.common.cache.LocalCache$Segment.clear(LocalCache.java:3302) ~[na:na]
at com.google.common.cache.LocalCache.clear(LocalCache.java:4270) ~[na:na]
at com.google.common.cache.LocalCache$LocalManualCache.invalidateAll(LocalCache.java:4825) ~[na:na]
at org.opendaylight.openflowjava.protocol.impl.connection.ConnectionAdapterImpl.consume(ConnectionAdapterImpl.java:253) ~[na:na]
at org.opendaylight.openflowjava.protocol.impl.core.DelegatingInboundHandler.channelInactive(DelegatingInboundHandler.java:48) ~[na:na]
at io.netty.channel.DefaultChannelHandlerContext.invokeChannelInactive(DefaultChannelHandlerContext.java:237) ~[na:na]
at io.netty.channel.DefaultChannelHandlerContext.fireChannelInactive(DefaultChannelHandlerContext.java:223) ~[na:na]
at io.netty.channel.ChannelInboundHandlerAdapter.channelInactive(ChannelInboundHandlerAdapter.java:75) ~[na:na]
at io.netty.channel.DefaultChannelHandlerContext.invokeChannelInactive(DefaultChannelHandlerContext.java:237) ~[na:na]
at io.netty.channel.DefaultChannelHandlerContext.fireChannelInactive(DefaultChannelHandlerContext.java:223) ~[na:na]
at io.netty.handler.codec.ByteToMessageDecoder.channelInactive(ByteToMessageDecoder.java:214) ~[na:na]
at io.netty.channel.DefaultChannelHandlerContext.invokeChannelInactive(DefaultChannelHandlerContext.java:237) ~[na:na]
at io.netty.channel.DefaultChannelHandlerContext.fireChannelInactive(DefaultChannelHandlerContext.java:223) ~[na:na]
at io.netty.handler.codec.ByteToMessageDecoder.channelInactive(ByteToMessageDecoder.java:214) ~[na:na]
at io.netty.channel.DefaultChannelHandlerContext.invokeChannelInactive(DefaultChannelHandlerContext.java:237) ~[na:na]
at io.netty.channel.DefaultChannelHandlerContext.fireChannelInactive(DefaultChannelHandlerContext.java:223) ~[na:na]
at io.netty.channel.ChannelInboundHandlerAdapter.channelInactive(ChannelInboundHandlerAdapter.java:75) ~[na:na]
at io.netty.handler.timeout.IdleStateHandler.channelInactive(IdleStateHandler.java:246) ~[na:na]
at io.netty.channel.DefaultChannelHandlerContext.invokeChannelInactive(DefaultChannelHandlerContext.java:237) ~[na:na]
at io.netty.channel.DefaultChannelHandlerContext.fireChannelInactive(DefaultChannelHandlerContext.java:223) ~[na:na]
at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:767) ~[na:na]
at io.netty.channel.AbstractChannel$AbstractUnsafe$5.run(AbstractChannel.java:558) ~[na:na]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:354) ~[na:na]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:348) ~[na:na]
at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:101) ~[na:na]
... 1 common frames omitted
2013-11-23 16:09:32.547 PST [Thread-26] ERROR o.o.o.o.m.core.ErrorHandlerQueueImpl - IN THREAD: pool-327-thread-1; session:null -> rpcError:null;
java.lang.Exception: rpcError:null;
at org.opendaylight.openflowplugin.openflow.md.core.RpcUtil.smokeRpc(RpcUtil.java:34) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeManagerImpl.postHandshake(HandshakeManagerImpl.java:287) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeManagerImpl.handleVersionBitmapNegotiation(HandshakeManagerImpl.java:158) ~[na:na]
at org.opendaylight.openflowplugin.openflow.md.core.HandshakeManagerImpl.run(HandshakeManagerImpl.java:100) ~[na:na]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_25]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_25]
at java.lang.Thread.run(Thread.java:724) ~[na:1.7.0_25]

This is against:

hagbard@ubuntu:~/git/controller$ git log -2
commit 83cb4c6ab99c57f6c564a0e7c1a2d6d0666c1cf2
Author: Tony Tkacik <ttkacik@cisco.com>
Date: Tue Nov 19 08:27:07 2013 +0100

Added configuration options to MD-SAL

Added default configuration to distribution
which wires MD-SAL components together.

Support for configuring wiring of following services:

• Binding Aware Broker
• Binding Aware Notification Service
• Binding Aware Data Broker Service
• Mapping service
• Binding Independent Broker
• Data Store

Default configuration wires BA Broker, BA Notification service
BA Data Broker and BI Broker together.

BA Broker requires now BI Broker to be loaded in order to
provide datastore functionality right from the beginning.

Updated integration tests, added new test cases for BA to BI
integration

Change-Id: I7776bb9b2ed75bd5589757633c17f2466b86a04c
Signed-off-by: Tony Tkacik <ttkacik@cisco.com>

commit 8bb8f71a9cbe2134c76d78aa2f8846b147c8b7f8
Author: Maros Marsalek <mmarsale@cisco.com>
Date: Fri Nov 22 14:42:38 2013 +0100

Allow multiple services provided from same namespace parsed from netconf message

Change-Id: I4ba7cf7d3e728be447066abc3a3c9f871faba954
Signed-off-by: Maros Marsalek <mmarsale@cisco.com>

And

commit 736a680c9e03a09a954acd36b8c5f568fb073caa
Author: Ed Warnicke <eaw@cisco.com>
Date: Fri Nov 22 13:46:16 2013 +0100

Support for reporting PortDesc and PortStatus changes

Also cleaned up logging in MultipartMessageDescToNodeUpdatedTranslator
Expanded functions in InventoryDataServiceUtil
Added PortTranslatorUtil to expose reusable translator methods.

Change-Id: I4a5e1a5b12bab46a08ce2aafb9cb3e64240be3bd
Signed-off-by: Ed Warnicke <eaw@cisco.com>
Signed-off-by: Tony Tkacik <ttkacik@cisco.com>

commit a5993f74626063c163ce529436a13cbbd46f6e7b
Author: Ed Warnicke <eaw@cisco.com>
Date: Sat Nov 23 08:00:56 2013 -0800

Switched to using IMDMessageTranslator<OfHeader, List<DataObject>>> in MDController

Switched to using IMDMessageTranslator<OfHeader, List<DataObject>>> in MDController
from IMDMessageTranslator<OfHeader,<DataObject>>.

This was required because when you unpack a MultiPartReply, you may need
to translate it into many resulting MD-SAL DataObjects. For example
a MultiPartReply with body MultipartReplyPortDesc would result in
many NodeConnectorUpdated messages.

The change cascaded through several places that presumed on
dealing with IMDMessageTranslator<OfHeader, DataObject>>,
but with small exceptions it was only a signature change.

Also taught the TicketProcessorFactory to ignore translations
that return null (as that has become the convention when you
can't really translate a message for whatever reason). Now
TicketProcessorFactory just drops null translations.
Ideally, we would throw and catch an exception for this case...
but maybe later.

This is done in preparation for commits to handle various
MultipartReply messages.

Change-Id: I387c96d1d064d3128622a27e262954812ee31836
Signed-off-by: Ed Warnicke <eaw@cisco.com>

Conflicts:

openflowplugin/src/main/java/org/opendaylight/openflowplugin/openflow/md/core/MDController.java
openflowplugin/src/main/java/org/opendaylight/openflowplugin/openflow/md/core/translator/PortStatusMessageToNodeConnectorUpdatedTranslator.java
openflowplugin/src/main/java/org/opendaylight/openflowplugin/openflow/md/util/InventoryDataServiceUtil.java

Signed-off-by: Ed Warnicke <eaw@cisco.com>