[BGPCEP-981] pccmock is failing during CSIT runs Created: 28/Sep/21 Updated: 28/Sep/21 Resolved: 28/Sep/21 |
|
| Status: | Resolved |
| Project: | bgpcep |
| Component/s: | PCEP |
| Affects Version/s: | 0.16.6 |
| Fix Version/s: | 0.16.7 |
| Type: | Bug | Priority: | Highest |
| Reporter: | Robert Varga | Assignee: | Robert Varga |
| Resolution: | Done | Votes: | 0 |
| Labels: | pt | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Description |
|
We have some CSIT failures reported here: https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/bgpcep-csit-1node-userfeatures-all-phosphorus/179/robot-plugin/log.html.gz There seems to be some sort of a mismatch between pccmock and ODL w.r.t encoding of PCInitiate (or thereabout, see https://logs.opendaylight.org/releng/vex-yul-odl-jenkins-1/bgpcep-csit-1node-userfeatures-all-phosphorus/179/robot-plugin/log.html.gz#s1-s2-k2-k3 ): 09:24:00.992 [epollEventLoopGroup-2-1] ERROR org.opendaylight.protocol.pcep.impl.PCEPSessionImpl - Exception captured for session PCEPSessionImpl{channel=[id: 0x0d6906c7, L:/10.30.170.250:44779 - R:10.30.170.242/10.30.170.242:4189], localOpen=Open{deadTimer=120, keepalive=30, sessionId=1, tlvs=Tlvs{augmentation=[Tlvs1{stateful=Stateful{lspUpdateCapability=true, augmentation=[Stateful1{deltaLspSyncCapability=false, includeDbVersion=false, triggeredInitialSync=false, triggeredResync=false}, Stateful1{initiation=true}]}}, Tlvs3{lspDbVersion=LspDbVersion{lspDbVersionValue=1, augmentation=[]}}]}, augmentation=[]}, remoteOpen=Open{deadTimer=120, ignore=false, keepalive=30, processingRule=false, sessionId=1, tlvs=Tlvs{augmentation=[Tlvs1{stateful=Stateful{lspUpdateCapability=true, augmentation=[Stateful1{deltaLspSyncCapability=true, includeDbVersion=true, triggeredInitialSync=true, triggeredResync=true}, Stateful1{initiation=true}]}}, Tlvs3{}]}, version=ProtocolVersion{_value=1}, augmentation=[]}}, closing session.
io.netty.handler.codec.DecoderException: java.lang.ClassCastException: class org.opendaylight.protocol.pcep.spi.UnknownObject cannot be cast to class org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.ietf.stateful.rev200720.srp.object.Srp (org.opendaylight.protocol.pcep.spi.UnknownObject and org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.ietf.stateful.rev200720.srp.object.Srp are in unnamed module of loader 'app')
at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:477)
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:795)
at io.netty.channel.epoll.AbstractEpollChannel$AbstractEpollUnsafe$1.run(AbstractEpollChannel.java:425)
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469)
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384)
at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986)
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.ClassCastException: class org.opendaylight.protocol.pcep.spi.UnknownObject cannot be cast to class org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.ietf.stateful.rev200720.srp.object.Srp (org.opendaylight.protocol.pcep.spi.UnknownObject and org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.ietf.stateful.rev200720.srp.object.Srp are in unnamed module of loader 'app')
at org.opendaylight.protocol.pcep.ietf.initiated.InitiatedPCInitiateMessageParser.getValidRequest(InitiatedPCInitiateMessageParser.java:89)
at org.opendaylight.protocol.pcep.ietf.initiated.InitiatedPCInitiateMessageParser.validate(InitiatedPCInitiateMessageParser.java:81)
at org.opendaylight.protocol.pcep.spi.AbstractMessageParser.parseMessage(AbstractMessageParser.java:135)
at org.opendaylight.protocol.pcep.spi.pojo.SimpleMessageRegistry.parseMessage(SimpleMessageRegistry.java:51)
at org.opendaylight.protocol.pcep.impl.PCEPByteToMessageDecoder.parse(PCEPByteToMessageDecoder.java:82)
at org.opendaylight.protocol.pcep.impl.PCEPByteToMessageDecoder.decode(PCEPByteToMessageDecoder.java:51)
at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:507)
at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:446)
... 22 common frames omitted
|
| Comments |
| Comment by Robert Varga [ 28/Sep/21 ] |
|
Comparing the run with Silicon, the problem seems to be this message: 2021-09-28T09:24:00,999 | DEBUG | qtp1921875606-283 | PCEPSessionImpl | 249 - org.opendaylight.bgpcep.pcep-impl - 0.16.6 | PCEP Message enqueued: Pcinitiate{pcinitiateMessage=PcinitiateMessage{requests=[Requests{endpointsObj=EndpointsObj{addressFamily=Ipv4Case{ipv4=Ipv4{destinationIpv4Address=Ipv4Address{_value=1.1.1.1}, sourceIpv4Address=Ipv4Address{_value=10.30.170.250}, augmentation=[]}, augmentation=[]}, ignore=false, processingRule=false, augmentation=[]}, ero=Ero{ignore=false, processingRule=false, subobject=[Subobject{loose=false, subobjectType=IpPrefixCase{ipPrefix=IpPrefix{ipPrefix=IpPrefix{_ipv4Prefix=Ipv4Prefix{_value=1.1.1.1/32}}, augmentation=[]}, augmentation=[]}, augmentation=[]}], augmentation=[]}, lsp=Lsp{administrative=true, delegate=true, plspId=PlspId{_value=0}, tlvs=Tlvs{symbolicPathName=SymbolicPathName{pathName=SymbolicPathName{_value=[73, 110, 115, 116, 97, 110, 116, 105, 97, 116, 101, 100, 32,
116, 117, 110, 110, 101, 108]}, augmentation=[]}, augmentation=[]}, augmentation=[]}, srp=Srp{operationId=SrpIdNumber{_value=3}, processingRule=true, augmentation=[]}, augmentation=[]}], version=ProtocolVersion{_value=1}, augmentation=[]}, augmentation=[]}
which on Silicon gets formatted into: 2021-09-28T13:28:29,990 | TRACE | epollEventLoopGroup-6-2 | PCEPMessageToByteEncoder | 255 - org.opendaylight.bgpcep.pcep-impl - 0.15.3 | Encoded : 200c0048 2112000c 00000000 00000003 20100020 00000009 00110013 496e7374 616e7469 61746564 2074756e 6e656c00 0410000c 0a1eaa50 01010101 0710000c 01080101 01012000 and on Phosphorus into: 2021-09-28T09:24:01,000 | TRACE | epollEventLoopGroup-10-2 | PCEPMessageToByteEncoder | 249 - org.opendaylight.bgpcep.pcep-impl - 0.16.6 | Encoded : 200c0048 2112000c 00000000 00000003 20100020 00000009 00110013 496e7374 616e7469 61746564 2074756e 6e656c00 0410000c 0a1eaafa 01010101 0710000c 01080101 01012000 i.e. we are emitting 0x0a1eaafa instead of 0x0a1eaa50. Let me try to understand what that byte means.
|
| Comment by Robert Varga [ 28/Sep/21 ] |
|
Ah, right, it's the difference between sourceIpv4Address=Ipv4Address{_value=10.30.170.80} and sourceIpv4Address=Ipv4Address{_value=10.30.170.250}. So this is something going wrong in pccmock wiring. I think I saw something strange thereabout. |
| Comment by Robert Varga [ 28/Sep/21 ] |
|
So it was a mistake in packaging, PCCActivator was not correctly tagged as a ServiceLoader service. |