1. Messages
  2. bug 5173 - "deserialization failed" WARN messages

Re: bug 5173 - "deserialization failed" WARN messages

Bertrand Low <Bertrand.Low@...>
 

Hi Michal,

 

Thanks for your help on this. We have since tested the CSIT jobs with ODL distributions carrying the Bug 7071 fix and have not observed the “deserialization failed” WARN messages. Bug 7071 appears to have resolved the issue for us.

 

If we observe the “msgType: 300” or other similar erros in the future, we will let you know.

 

Cheers,

Bertrand

 

From: Michal Rehak -X (mirehak - PANTHEON TECHNOLOGIES at Cisco) [mailto:mirehak@...]
Sent: January 13, 2017 9:25 AM
To: Bertrand Low <Bertrand.Low@...>; michal.polkorab@...
Cc: Venkatrangan G - ERS, HCL Tech <venkatrangang@...>; openflowjava-dev@...; Vinh Nguyen <Vinh.Nguyen@...>
Subject: Re: [openflowjava-dev] bug 5173 - "deserialization failed" WARN messages

 

Hi Bertrand,

this is weird - in logs of odl1 machine I found:

 

2017-01-11 05:19:45,301 | INFO  | entLoopGroup-9-1 | ActionDeserializer               | 284 - org.opendaylight.openflowplugin.openflowjava-extension-nicira-api - 0.3.3.SNAPSHOT | No deserializer was found for key NiciraActionDeserializerKey [version=4, subtype=19]

 

This refers to FinTimeoutCodec which should be registered (unless you did not install feature odl-openflowplugin-nxm-extensions).

Nevertheless right after this we got:

2017-01-11 05:19:45,301 | WARN  | entLoopGroup-9-1 | OFDecoder                        | 270 - org.opendaylight.openflowjava.openflow-protocol-impl - 0.8.3.SNAPSHOT | Message deserialization failed
 java.lang.IllegalStateException: Deserializer for key: msgVersion: 4 objectClass: org.opendaylight.yang.gen.v1.urn.opendaylight.openflow.common.action.rev150203.actions.grouping.Action msgType: 300 experimenterID: null was not found - please verify that all needed deserializers ale loaded correctly

 

I am not sure if those 2 issues are connected but the second one claims there is type=300 which is not defined in OF-spec.

 

That's why I believe we need at least definitions of those flows (xml/json dump of config, if possible).  Traffic captures would help to detect which side is spoiling payload. If you could cover just flow installation phase it would greatly simplify reading. Honestly I went into real dark wood by crawling through the robot logs. Timestamps are shifted and source is huge. So finding pairs is hard for me.

 

 

Regards,

Michal

 

From: Bertrand Low <Bertrand.Low@...>
Sent: Friday, January 13, 2017 01:16
To: Michal Rehak -X (mirehak - PANTHEON TECHNOLOGIES at Cisco); michal.polkorab@...
Cc: Venkatrangan G - ERS, HCL Tech; openflowjava-dev@...; Vinh Nguyen
Subject: RE: [openflowjava-dev] bug 5173 - "deserialization failed" WARN messages

 

Hi Michal,

 

I’ve attached the dump-flow. This is actually from the following CSIT run:

https://logs.opendaylight.org/sandbox/jenkins091/netvirt-legacy-csit-3node-openstack-mitaka-upstream-boron/6/archives/log.html.gz

In that run, we observe the “deserialization failed” WARN messages.

 

Please let me know if the attached dump-flow helps to give you some clues as to which flows may be causing the WARN messages. If you need us to grab the corresponding traffic capture of the statistics reply and the xml/json and FLOW_MOD message for a particular flow, let me know and we will try and get those.

 

Thanks,

Bertrand

 

From: Michal Rehak -X (mirehak - PANTHEON TECHNOLOGIES at Cisco) [mailto:mirehak@...]
Sent: January 11, 2017 5:40 AM
To: Bertrand Low <Bertrand.Low@...>; michal.polkorab@...
Cc: Venkatrangan G - ERS, HCL Tech <venkatrangang@...>; openflowjava-dev@...; Vinh Nguyen <Vinh.Nguyen@...>
Subject: Re: [openflowjava-dev] bug 5173 - "deserialization failed" WARN messages

 

Hi Bertrand,

the ovs-ofctl dump would be helpful. Also traffic capture of statistics reply containing that flow would shed some light.

 

And if you have xml/json of configured flow (or rpc input) and capture of corresponding flow-mod message then the circle would be complete I guess.

 

 

Regards,

Michal

 

 

From: Bertrand Low <Bertrand.Low@...>
Sent: Wednesday, January 11, 2017 05:52
To: Michal Rehak -X (mirehak - PANTHEON TECHNOLOGIES at Cisco); michal.polkorab@...
Cc: Venkatrangan G - ERS, HCL Tech; openflowjava-dev@...; Vinh Nguyen
Subject: RE: [openflowjava-dev] bug 5173 - "deserialization failed" WARN messages

 

Hi Michal,

 

What kind of wireshark traffic or flow information on the device would help?

For the flow information, would a simple ovs-ofctl dump-flows do?

 

Thanks,

Bertrand

 

From: Michal Rehak -X (mirehak - PANTHEON TECHNOLOGIES at Cisco) [mailto:mirehak@...]
Sent: January 10, 2017 6:07 AM
To: Bertrand Low <Bertrand.Low@...>; michal.polkorab@...
Cc: Venkatrangan G - ERS, HCL Tech <venkatrangang@...>; openflowjava-dev@...; Vinh Nguyen <Vinh.Nguyen@...>
Subject: Re: [openflowjava-dev] bug 5173 - "deserialization failed" WARN messages

 

Hi Bertrand,

my bad - experimenterId == null is normal state for standard action (declared in OFP spec). Logs you provided contain action of type 60. Standard action types go up to 27 (OF-1.3).

 

Could you inspect your traffic with wireshark?

Could you inspect directly flows on your device?

 

 

Regards,

Michal

 

From: Bertrand Low <Bertrand.Low@...>
Sent: Tuesday, January 10, 2017 07:38
To: Michal Rehak -X (mirehak - PANTHEON TECHNOLOGIES at Cisco); michal.polkorab@...
Cc: Venkatrangan G - ERS, HCL Tech; openflowjava-dev@...; Vinh Nguyen
Subject: RE: [openflowjava-dev] bug 5173 - "deserialization failed" WARN messages

 

Thanks for the response, Michal.

 

I’ve copied another similar, but different message below (longer snippet of the log); this is also an example of the type of messages we would like to remove/reduce from the log:

 

2016-11-07 19:46:32,794 | WARN  | entLoopGroup-9-2 | OFDecoder                        | 294 - org.opendaylight.openflowjava.openflow-protocol-impl - 0.8.1.Boron-SR1 | Message deserialization failed

java.lang.IllegalStateException: Deserializer for key: msgVersion: 4 objectClass: org.opendaylight.yang.gen.v1.urn.opendaylight.openflow.common.action.rev150203.actions.grouping.Action msgType: 60 experimenterID: null was not found - please verify that all needed deserializers ale loaded correctly

        at org.opendaylight.openflowjava.protocol.impl.deserialization.DeserializerRegistryImpl.getDeserializer(DeserializerRegistryImpl.java:69)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.util.ListDeserializer.deserializeList(ListDeserializer.java:52)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.instruction.AbstractActionInstructionDeserializer.deserializeActions(AbstractActionInstructionDeserializer.java:38)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.instruction.ApplyActionsInstructionDeserializer.deserialize(ApplyActionsInstructionDeserializer.java:36)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.instruction.ApplyActionsInstructionDeserializer.deserialize(ApplyActionsInstructionDeserializer.java:25)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.util.ListDeserializer.deserializeList(ListDeserializer.java:53)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.factories.MultipartReplyMessageFactory.setFlow(MultipartReplyMessageFactory.java:304)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.factories.MultipartReplyMessageFactory.deserialize(MultipartReplyMessageFactory.java:198)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.factories.MultipartReplyMessageFactory.deserialize(MultipartReplyMessageFactory.java:148)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.DeserializationFactory.deserialize(DeserializationFactory.java:59)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.core.OFDecoder.decode(OFDecoder.java:55)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.core.OFDecoder.decode(OFDecoder.java:28)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:88)[140:io.netty.codec:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:293)[140:io.netty.codec:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:267)[140:io.netty.codec:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:293)[140:io.netty.codec:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:267)[140:io.netty.codec:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.handler.timeout.ReadTimeoutHandler.channelRead(ReadTimeoutHandler.java:152)[142:io.netty.handler:4.0.37.Final]

        at org.opendaylight.openflowjava.protocol.impl.core.IdleHandler.channelRead(IdleHandler.java:39)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1280)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:890)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:879)[143:io.netty.transport-native-epoll:4.0.37.Final]

        at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:387)[143:io.netty.transport-native-epoll:4.0.37.Final]

        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:296)[143:io.netty.transport-native-epoll:4.0.37.Final]

        at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)[138:io.netty.common:4.0.37.Final]

        at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:145)[138:io.netty.common:4.0.37.Final]

        at java.lang.Thread.run(Thread.java:745)[:1.8.0_91]

2016-11-07 19:46:33,291 | INFO  | entLoopGroup-9-2 | MultipartRequestOnTheFlyCallback | 299 - org.opendaylight.openflowplugin.impl - 0.3.1.Boron-SR1 | Ofheader was null.

2016-11-07 19:46:34,349 | WARN  | entLoopGroup-9-5 | StatisticsGatheringUtils         | 299 - org.opendaylight.openflowplugin.impl - 0.3.1.Boron-SR1 | Skip write statistics. Flow hash: 1127177399 not present in DeviceFlowRegistry

2016-11-07 19:46:34,349 | WARN  | entLoopGroup-9-5 | StatisticsGatheringUtils         | 299 - org.opendaylight.openflowplugin.impl - 0.3.1.Boron-SR1 | Skip write statistics. Flow hash: -355999137 not present in DeviceFlowRegistry

2016-11-07 19:46:36,304 | INFO  | entLoopGroup-9-2 | ActionDeserializer               | 308 - org.opendaylight.openflowplugin.openflowjava-extension-nicira-api - 0.3.1.Boron-SR1 | No deserializer was found for key NiciraActionDeserializerKey [version=4, subtype=19]

2016-11-07 19:46:36,304 | WARN  | entLoopGroup-9-2 | OFDecoder                        | 294 - org.opendaylight.openflowjava.openflow-protocol-impl - 0.8.1.Boron-SR1 | Message deserialization failed

java.lang.IllegalStateException: Deserializer for key: msgVersion: 4 objectClass: org.opendaylight.yang.gen.v1.urn.opendaylight.openflow.common.action.rev150203.actions.grouping.Action msgType: 60 experimenterID: null was not found - please verify that all needed deserializers ale loaded correctly

        at org.opendaylight.openflowjava.protocol.impl.deserialization.DeserializerRegistryImpl.getDeserializer(DeserializerRegistryImpl.java:69)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.util.ListDeserializer.deserializeList(ListDeserializer.java:52)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.instruction.AbstractActionInstructionDeserializer.deserializeActions(AbstractActionInstructionDeserializer.java:38)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.instruction.ApplyActionsInstructionDeserializer.deserialize(ApplyActionsInstructionDeserializer.java:36)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.instruction.ApplyActionsInstructionDeserializer.deserialize(ApplyActionsInstructionDeserializer.java:25)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.util.ListDeserializer.deserializeList(ListDeserializer.java:53)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.factories.MultipartReplyMessageFactory.setFlow(MultipartReplyMessageFactory.java:304)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.factories.MultipartReplyMessageFactory.deserialize(MultipartReplyMessageFactory.java:198)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.factories.MultipartReplyMessageFactory.deserialize(MultipartReplyMessageFactory.java:148)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.DeserializationFactory.deserialize(DeserializationFactory.java:59)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.core.OFDecoder.decode(OFDecoder.java:55)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.core.OFDecoder.decode(OFDecoder.java:28)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:88)[140:io.netty.codec:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:293)[140:io.netty.codec:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:267)[140:io.netty.codec:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:293)[140:io.netty.codec:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:267)[140:io.netty.codec:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.handler.timeout.ReadTimeoutHandler.channelRead(ReadTimeoutHandler.java:152)[142:io.netty.handler:4.0.37.Final]

        at org.opendaylight.openflowjava.protocol.impl.core.IdleHandler.channelRead(IdleHandler.java:39)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1280)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:890)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:879)[143:io.netty.transport-native-epoll:4.0.37.Final]

        at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:387)[143:io.netty.transport-native-epoll:4.0.37.Final]

        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:296)[143:io.netty.transport-native-epoll:4.0.37.Final]

        at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)[138:io.netty.common:4.0.37.Final]

        at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:145)[138:io.netty.common:4.0.37.Final]

        at java.lang.Thread.run(Thread.java:745)[:1.8.0_91]

2016-11-07 19:46:36,801 | INFO  | entLoopGroup-9-2 | MultipartRequestOnTheFlyCallback | 299 - org.opendaylight.openflowplugin.impl - 0.3.1.Boron-SR1 | Ofheader was null.

2016-11-07 19:46:37,369 | WARN  | entLoopGroup-9-5 | StatisticsGatheringUtils         | 299 - org.opendaylight.openflowplugin.impl - 0.3.1.Boron-SR1 | Skip write statistics. Flow hash: 1127177399 not present in DeviceFlowRegistry

2016-11-07 19:46:37,369 | WARN  | entLoopGroup-9-5 | StatisticsGatheringUtils         | 299 - org.opendaylight.openflowplugin.impl - 0.3.1.Boron-SR1 | Skip write statistics. Flow hash: -355999137 not present in DeviceFlowRegistry

2016-11-07 19:46:39,815 | INFO  | entLoopGroup-9-2 | ActionDeserializer               | 308 - org.opendaylight.openflowplugin.openflowjava-extension-nicira-api - 0.3.1.Boron-SR1 | No deserializer was found for key NiciraActionDeserializerKey [version=4, subtype=19]

2016-11-07 19:46:39,815 | WARN  | entLoopGroup-9-2 | OFDecoder                        | 294 - org.opendaylight.openflowjava.openflow-protocol-impl - 0.8.1.Boron-SR1 | Message deserialization failed

java.lang.IllegalStateException: Deserializer for key: msgVersion: 4 objectClass: org.opendaylight.yang.gen.v1.urn.opendaylight.openflow.common.action.rev150203.actions.grouping.Action msgType: 60 experimenterID: null was not found - please verify that all needed deserializers ale loaded correctly

        at org.opendaylight.openflowjava.protocol.impl.deserialization.DeserializerRegistryImpl.getDeserializer(DeserializerRegistryImpl.java:69)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.util.ListDeserializer.deserializeList(ListDeserializer.java:52)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.instruction.AbstractActionInstructionDeserializer.deserializeActions(AbstractActionInstructionDeserializer.java:38)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.instruction.ApplyActionsInstructionDeserializer.deserialize(ApplyActionsInstructionDeserializer.java:36)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.instruction.ApplyActionsInstructionDeserializer.deserialize(ApplyActionsInstructionDeserializer.java:25)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.util.ListDeserializer.deserializeList(ListDeserializer.java:53)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.factories.MultipartReplyMessageFactory.setFlow(MultipartReplyMessageFactory.java:304)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.factories.MultipartReplyMessageFactory.deserialize(MultipartReplyMessageFactory.java:198)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.factories.MultipartReplyMessageFactory.deserialize(MultipartReplyMessageFactory.java:148)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.DeserializationFactory.deserialize(DeserializationFactory.java:59)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.core.OFDecoder.decode(OFDecoder.java:55)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.core.OFDecoder.decode(OFDecoder.java:28)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:88)[140:io.netty.codec:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:293)[140:io.netty.codec:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:267)[140:io.netty.codec:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:293)[140:io.netty.codec:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:267)[140:io.netty.codec:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.handler.timeout.ReadTimeoutHandler.channelRead(ReadTimeoutHandler.java:152)[142:io.netty.handler:4.0.37.Final]

        at org.opendaylight.openflowjava.protocol.impl.core.IdleHandler.channelRead(IdleHandler.java:39)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1280)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:890)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:879)[143:io.netty.transport-native-epoll:4.0.37.Final]

        at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:387)[143:io.netty.transport-native-epoll:4.0.37.Final]

        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:296)[143:io.netty.transport-native-epoll:4.0.37.Final]

        at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)[138:io.netty.common:4.0.37.Final]

        at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:145)[138:io.netty.common:4.0.37.Final]

        at java.lang.Thread.run(Thread.java:745)[:1.8.0_91]

2016-11-07 19:46:40,311 | INFO  | entLoopGroup-9-2 | MultipartRequestOnTheFlyCallback | 299 - org.opendaylight.openflowplugin.impl - 0.3.1.Boron-SR1 | Ofheader was null.

2016-11-07 19:46:40,388 | WARN  | entLoopGroup-9-5 | StatisticsGatheringUtils         | 299 - org.opendaylight.openflowplugin.impl - 0.3.1.Boron-SR1 | Skip write statistics. Flow hash: 1127177399 not present in DeviceFlowRegistry

2016-11-07 19:46:40,389 | WARN  | entLoopGroup-9-5 | StatisticsGatheringUtils         | 299 - org.opendaylight.openflowplugin.impl - 0.3.1.Boron-SR1 | Skip write statistics. Flow hash: -355999137 not present in DeviceFlowRegistry

2016-11-07 19:46:43,324 | INFO  | entLoopGroup-9-2 | ActionDeserializer               | 308 - org.opendaylight.openflowplugin.openflowjava-extension-nicira-api - 0.3.1.Boron-SR1 | No deserializer was found for key NiciraActionDeserializerKey [version=4, subtype=19]

2016-11-07 19:46:43,324 | WARN  | entLoopGroup-9-2 | OFDecoder                        | 294 - org.opendaylight.openflowjava.openflow-protocol-impl - 0.8.1.Boron-SR1 | Message deserialization failed

java.lang.IllegalStateException: Deserializer for key: msgVersion: 4 objectClass: org.opendaylight.yang.gen.v1.urn.opendaylight.openflow.common.action.rev150203.actions.grouping.Action msgType: 60 experimenterID: null was not found - please verify that all needed deserializers ale loaded correctly

        at org.opendaylight.openflowjava.protocol.impl.deserialization.DeserializerRegistryImpl.getDeserializer(DeserializerRegistryImpl.java:69)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.util.ListDeserializer.deserializeList(ListDeserializer.java:52)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.instruction.AbstractActionInstructionDeserializer.deserializeActions(AbstractActionInstructionDeserializer.java:38)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.instruction.ApplyActionsInstructionDeserializer.deserialize(ApplyActionsInstructionDeserializer.java:36)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.instruction.ApplyActionsInstructionDeserializer.deserialize(ApplyActionsInstructionDeserializer.java:25)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.util.ListDeserializer.deserializeList(ListDeserializer.java:53)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.factories.MultipartReplyMessageFactory.setFlow(MultipartReplyMessageFactory.java:304)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.factories.MultipartReplyMessageFactory.deserialize(MultipartReplyMessageFactory.java:198)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.factories.MultipartReplyMessageFactory.deserialize(MultipartReplyMessageFactory.java:148)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.deserialization.DeserializationFactory.deserialize(DeserializationFactory.java:59)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.core.OFDecoder.decode(OFDecoder.java:55)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at org.opendaylight.openflowjava.protocol.impl.core.OFDecoder.decode(OFDecoder.java:28)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:88)[140:io.netty.codec:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:293)[140:io.netty.codec:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:267)[140:io.netty.codec:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:293)[140:io.netty.codec:4.0.37.Final]

        at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:267)[140:io.netty.codec:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.handler.timeout.ReadTimeoutHandler.channelRead(ReadTimeoutHandler.java:152)[142:io.netty.handler:4.0.37.Final]

        at org.opendaylight.openflowjava.protocol.impl.core.IdleHandler.channelRead(IdleHandler.java:39)[294:org.opendaylight.openflowjava.openflow-protocol-impl:0.8.1.Boron-SR1]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:321)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1280)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:342)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:328)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:890)[139:io.netty.transport:4.0.37.Final]

        at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:879)[143:io.netty.transport-native-epoll:4.0.37.Final]

        at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:387)[143:io.netty.transport-native-epoll:4.0.37.Final]

        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:296)[143:io.netty.transport-native-epoll:4.0.37.Final]

        at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:112)[138:io.netty.common:4.0.37.Final]

        at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:145)[138:io.netty.common:4.0.37.Final]

        at java.lang.Thread.run(Thread.java:745)[:1.8.0_91]

 

Thanks,

Bertrand

 

From: Michal Rehak -X (mirehak - PANTHEON TECHNOLOGIES at Cisco) [mailto:mirehak@...]
Sent: January 9, 2017 5:27 AM
To: Bertrand Low <Bertrand.Low@...>; michal.polkorab@...
Cc: Venkatrangan G - ERS, HCL Tech <venkatrangang@...>; openflowjava-dev@...; Vinh Nguyen <Vinh.Nguyen@...>
Subject: Re: [openflowjava-dev] bug 5173 - "deserialization failed" WARN messages

 

Hi Bertrand,

unfortunately I would need more details on this. Bug-5173 is about table-features update where actions and matches are encoded a bit differently than in a flow. This produces plenty of warnings after handshake when table-features are processed. And this is of no issue for devices where table-features is not supported.

 

From here on I am just guessing:

if you sent an experimenter action from device to controller (e.g.: packed inside of flow/group statistics) then this message complains about missing deserializer. Finding appropriate deserializer takes 2 steps:

 - compute lookup key (based on first bytes of experimenter element - action in this case) and

 - find deserializer in map using the key

 

First thing - in the message key.toString() shows that experimenterId is null. This is presumably a bug. Every experimenter element shall be owned by a particular vendor with assigned experimenterId. Could you provide stacktrace?

If you have registered appropriate custom deserializer then it is not found because of that null value in key. If you have not registered one then ofJava got no clue on how to handle your action.

 

Another complication ahead: deserializers of experimenter elements in ofJava consists of 2 steps - first the experimenterId is parsed out of byte-stream and then custom amount of next bytes is parsed in order to detect type and pick appropriate final deserializer.

 

Could you please provide more details on your message and stacktrace and eventually deserializer?

 

 

Regards,

Michal

 

 

From: openflowjava-dev-bounces@... <openflowjava-dev-bounces@...> on behalf of Bertrand Low <Bertrand.Low@...>
Sent: Thursday, December 29, 2016 21:36
To: michal.polkorab@...
Cc: Venkatrangan G - ERS, HCL Tech; openflowjava-dev@...; Vinh Nguyen
Subject: Re: [openflowjava-dev] bug 5173 - "deserialization failed" WARN messages

 

Hi Michal and openflowjava team,

 

Just wanted to follow-up with you on the email below in case it was missed due to the holidays. We would appreciate your guidance to know that we are taking the right approach to fix the bug. Thank you.

 

Bertrand

 

From: Bertrand Low
Sent: December 24, 2016 6:24 PM
To: michal.polkorab@...
Cc: Venkatrangan G - ERS, HCL Tech <venkatrangang@...>; openflowjava-dev@...
Subject: bug 5173 - "deserialization failed" WARN messages

 

Hi Michal and openflowjava team,

 

Regarding bug 5173, my team has found that the following kind of WARN log message creates unnecessary confusion to the end user and makes it hard to debug other issues in the log (due to the large number of such messages):

 

2016-12-18 01:35:18,356 | WARN  | entLoopGroup-7-1 | OFDecoder                        | 296 - org.opendaylight.openflowjava.openflow-protocol-impl - 0.8.2.SNAPSHOT | Message deserialization failed

java.lang.IllegalStateException: Deserializer for key: msgVersion: 4 objectClass: org.opendaylight.yang.gen.v1.urn.opendaylight.openflow.common.action.rev150203.actions.grouping.Action msgType: 300 experimenterID: null was not found - please verify that all needed deserializers ale loaded correctl

 

Are you or someone from the team able to help us with the removal of these messages?

 

If no one is able to help us at this time, any implementation guidance you can provide would be much-appreciated. My understanding is that we need to implement the respective serializer and deserializer for the ovs nicira extensions for all those objectClasses in order to remove these WARN messages – do you have any alternative suggestions?

 

Thanks,

Bertrand



::DISCLAIMER::
----------------------------------------------------------------------------------------------------------------------------------------------------

The contents of this e-mail and any attachment(s) are confidential and intended for the named recipient(s) only.
E-mail transmission is not guaranteed to be secure or error-free as information could be intercepted, corrupted,
lost, destroyed, arrive late or incomplete, or may contain viruses in transmission. The e mail and its contents
(with or without referred errors) shall therefore not attach any liability on the originator or HCL or its affiliates.
Views or opinions, if any, presented in this email are solely those of the author and may not necessarily reflect the
views or opinions of HCL or its affiliates. Any form of reproduction, dissemination, copying, disclosure, modification,
distribution and / or publication of this message without the prior written consent of authorized representative of
HCL is strictly prohibited. If you have received this email in error please delete it and notify the sender immediately.
Before opening any email and/or attachments, please check them for viruses and other defects.

----------------------------------------------------------------------------------------------------------------------------------------------------
Join {z.archive.openflowjava-dev@lists.opendaylight.org to automatically receive all group messages.