[BGPCEP-722] NullPointerException Created: 15/Nov/17 Updated: 18/Apr/18 Resolved: 11/Dec/17 |
|
| Status: | Verified |
| Project: | bgpcep |
| Component/s: | PCEP |
| Affects Version/s: | None |
| Fix Version/s: | Oxygen |
| Type: | Bug | Priority: | Medium |
| Reporter: | Claudio David Gasparini | Assignee: | Claudio David Gasparini |
| Resolution: | Won't Do | Votes: | 0 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Description |
|
seen under org.opendaylight.bgpcep.pcep.topology.provider.PCEPTriggeredReSynchronizationProcedureTest-output.txt 13:11:19.765 [pool-57-thread-1] DEBUG o.o.b.p.t.p.ServerSessionManager - Topology KeyedInstanceIdentifier {targetType=interface org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology, path=[org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.NetworkTopology, org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology[key=TopologyKey [_topologyId=Uri [_value=testtopo]]]]} removed13:11:20.046 [pool-60-thread-1] DEBUG o.o.b.p.t.p.ServerSessionManager - PCEP Topology testtopo created successfully. 13:11:20.047 [main] INFO o.o.p.pcep.impl.PCEPSessionImpl - Session /127.76.206.79:36786[0] <-> /127.76.206.79:4189[0] started 13:11:20.047 [main] DEBUG o.o.b.p.t.p.ServerSessionManager - Node Uri [_value=pcc://127.76.206.79] requested by listener org.opendaylight.bgpcep.pcep.topology.provider.Stateful07TopologySessionListener@5a41b8f4 13:11:20.047 [main] DEBUG o.o.b.p.t.p.ServerSessionManager - Created topology node org.opendaylight.bgpcep.pcep.topology.provider.TopologyNodeState@725ad0aa for id Uri [_value=pcc://127.76.206.79] at KeyedInstanceIdentifier{targetType=interface org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node, path=[org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.NetworkTopology, org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology[key=TopologyKey [_topologyId=Uri [_value=testtopo]]], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey [_nodeId=Uri [_value=pcc://127.76.206.79]]]]} 13:11:20.047 [main] DEBUG o.o.b.p.t.p.ServerSessionManager - Node Uri [_value=pcc://127.76.206.79] bound to listener org.opendaylight.bgpcep.pcep.topology.provider.Stateful07TopologySessionListener@5a41b8f4 13:11:20.050 [main] INFO o.o.b.p.t.p.AbstractTopologySessionListener - Session with /127.76.206.79 attached to topology node KeyedInstanceIdentifier{targetType=interface org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node, path=[org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.NetworkTopology, org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology[key=TopologyKey [_topologyId=Uri [_value=testtopo]]], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey [_nodeId=Uri [_value=pcc://127.76.206.79]]]]} 13:11:20.051 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - Saved LSP PlspId [_value=1] with name test 13:11:20.053 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - LSP test updated to MD-SAL 13:11:20.054 [main] DEBUG o.o.b.p.t.p.Stateful07TopologySessionListener - LSP Lsp [_operational=Active, _plspId=PlspId [_value=1], _tlvs=Tlvs [_lspIdentifiers=LspIdentifiers [_lspId=LspId [_value=1], augmentation=[]], _symbolicPathName=SymbolicPathName [_pathName=SymbolicPathName [_value=[116, 101, 115, 116]], augmentation=[]], augmentation=[Tlvs1 [_lspDbVersion=LspDbVersion [_lspDbVersionValue=1, augmentation=[]]]]], _remove=false, _sync=true, augmentation=[]] updated 13:11:20.057 [main] DEBUG o.o.p.pcep.impl.PCEPSessionImpl - PCEP Message enqueued: Pcupd [_pcupdMessage=PcupdMessage [_updates=[Updates [_lsp=Lsp [_plspId=PlspId [_value=0], _sync=true, augmentation=[]], _path=Path [_ero=Ero [augmentation=[]], augmentation=[]], _srp=Srp [_operationId=SrpIdNumber [_value=1], augmentation=[]], augmentation=[]]], _version=ProtocolVersion [_value=1], augmentation=[]], augmentation=[]] 13:11:20.058 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - LSP test removed 13:11:20.058 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - Session PCEPSessionImpl{channel=TestingChannel, localOpen=Open [_deadTimer=30, _keepalive=10, _sessionId=0, _tlvs=Tlvs [augmentation=[Tlvs1 [_stateful=Stateful [augmentation=[Stateful1 [_includeDbVersion=true, _triggeredResync=true], Stateful1 [_initiation=true]]]], Tlvs3 [_lspDbVersion=LspDbVersion [_lspDbVersionValue=1, augmentation=[]], ]]], augmentation=[]], remoteOpen=Open [_deadTimer=30, _keepalive=10, _sessionId=0, _tlvs=Tlvs [augmentation=[Tlvs1 [_stateful=Stateful [augmentation=[Stateful1 [_includeDbVersion=true, _triggeredResync=true], Stateful1 [_initiation=true]]]], Tlvs3 [_lspDbVersion=LspDbVersion [_lspDbVersionValue=1, augmentation=[]], ]]], augmentation=[]]} achieved synchronized state 13:11:20.060 [pool-60-thread-1] DEBUG o.o.b.p.t.provider.PCEPRequest - Request went from UNSENT to DONE 13:11:20.060 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - Saved LSP PlspId [_value=1] with name test 13:11:20.061 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - LSP test updated to MD-SAL 13:11:20.061 [main] DEBUG o.o.b.p.t.p.Stateful07TopologySessionListener - LSP Lsp [_operational=Active, _plspId=PlspId [_value=1], _tlvs=Tlvs [_lspIdentifiers=LspIdentifiers [_lspId=LspId [_value=1], augmentation=[]], _symbolicPathName=SymbolicPathName [_pathName=SymbolicPathName [_value=[116, 101, 115, 116]], augmentation=[]], augmentation=[Tlvs1 [_lspDbVersion=LspDbVersion [_lspDbVersionValue=1, augmentation=[]]]]], _remove=false, _sync=true, augmentation=[]] updated 13:11:20.062 [main] DEBUG o.o.p.pcep.impl.PCEPSessionImpl - PCEP Message enqueued: Pcupd [_pcupdMessage=PcupdMessage [_updates=[Updates [_lsp=Lsp [_plspId=PlspId [_value=0], _sync=true, augmentation=[]], _path=Path [_ero=Ero [augmentation=[]], augmentation=[]], _srp=Srp [_operationId=SrpIdNumber [_value=2], augmentation=[]], augmentation=[]]], _version=ProtocolVersion [_value=1], augmentation=[]], augmentation=[]] 13:11:20.064 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - Saved LSP PlspId [_value=1] with name test 13:11:20.064 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - Found previous paths [Path [_ero=Ero [_subobject=[], augmentation=[]], _key=PathKey [_lspId=LspId [_value=1]], _lspId=LspId [_value=1], augmentation=[Path1 [_lsp=Lsp [_operational=Active, _plspId=PlspId [_value=1], _tlvs=Tlvs [_lspIdentifiers=LspIdentifiers [_lspId=LspId [_value=1], augmentation=[]], _symbolicPathName=SymbolicPathName [_pathName=SymbolicPathName [_value=[116, 101, 115, 116]], augmentation=[]], augmentation=[Tlvs1 [_lspDbVersion=LspDbVersion [_lspDbVersionValue=1, augmentation=[]]]]], _remove=false, _sync=true, augmentation=[]], ]]]] to this lsp name test 13:11:20.064 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - Match on lsp-id 1 13:11:20.064 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - Setting new paths [Path [_ero=Ero [_subobject=[], augmentation=[]], _key=PathKey [_lspId=LspId [_value=1]], _lspId=LspId [_value=1], augmentation=[Path1 [_lsp=Lsp [_operational=Active, _plspId=PlspId [_value=1], _tlvs=Tlvs [_lspIdentifiers=LspIdentifiers [_lspId=LspId [_value=1], augmentation=[]], _symbolicPathName=SymbolicPathName [_pathName=SymbolicPathName [_value=[116, 101, 115, 116]], augmentation=[]], augmentation=[Tlvs1 [_lspDbVersion=LspDbVersion [_lspDbVersionValue=1, augmentation=[]]]]], _remove=false, _sync=true, augmentation=[]], ]]]] to lsp test 13:11:20.065 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - LSP test updated to MD-SAL 13:11:20.065 [main] DEBUG o.o.b.p.t.p.Stateful07TopologySessionListener - LSP Lsp [_operational=Active, _plspId=PlspId [_value=1], _tlvs=Tlvs [_lspIdentifiers=LspIdentifiers [_lspId=LspId [_value=1], augmentation=[]], _symbolicPathName=SymbolicPathName [_pathName=SymbolicPathName [_value=[116, 101, 115, 116]], augmentation=[]], augmentation=[Tlvs1 [_lspDbVersion=LspDbVersion [_lspDbVersionValue=1, augmentation=[]]]]], _remove=false, _sync=true, augmentation=[]] updated 13:11:20.065 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - Session PCEPSessionImpl{channel=TestingChannel, localOpen=Open [_deadTimer=30, _keepalive=10, _sessionId=0, _tlvs=Tlvs [augmentation=[Tlvs1 [_stateful=Stateful [augmentation=[Stateful1 [_includeDbVersion=true, _triggeredResync=true], Stateful1 [_initiation=true]]]], Tlvs3 [_lspDbVersion=LspDbVersion [_lspDbVersionValue=1, augmentation=[]], ]]], augmentation=[]], remoteOpen=Open [_deadTimer=30, _keepalive=10, _sessionId=0, _tlvs=Tlvs [augmentation=[Tlvs1 [_stateful=Stateful [augmentation=[Stateful1 [_includeDbVersion=true, _triggeredResync=true], Stateful1 [_initiation=true]]]], Tlvs3 [_lspDbVersion=LspDbVersion [_lspDbVersionValue=1, augmentation=[]], ]]], augmentation=[]]} achieved synchronized state 13:11:20.066 [main] INFO o.o.p.pcep.impl.PCEPSessionImpl - Closing PCEP session with reason UNKNOWN: PCEPSessionImpl{channel=TestingChannel, localOpen=Open [_deadTimer=30, _keepalive=10, _sessionId=0, _tlvs=Tlvs [augmentation=[Tlvs1 [_stateful=Stateful [augmentation=[Stateful1 [_includeDbVersion=true, _triggeredResync=true], Stateful1 [_initiation=true]]]], Tlvs3 [_lspDbVersion=LspDbVersion [_lspDbVersionValue=1, augmentation=[]], ]]], augmentation=[]], remoteOpen=Open [_deadTimer=30, _keepalive=10, _sessionId=0, _tlvs=Tlvs [augmentation=[Tlvs1 [_stateful=Stateful [augmentation=[Stateful1 [_includeDbVersion=true, _triggeredResync=true], Stateful1 [_initiation=true]]]], Tlvs3 [_lspDbVersion=LspDbVersion [_lspDbVersionValue=1, augmentation=[]], ]]], augmentation=[]]} 13:11:20.067 [main] DEBUG o.o.p.pcep.impl.PCEPSessionImpl - PCEP Message enqueued: Close [_cCloseMessage=CCloseMessage [_cClose=CClose [_reason=1, augmentation=[]], augmentation=[]], augmentation=[]] 13:11:20.067 [main] INFO o.o.p.pcep.impl.PCEPSessionImpl - Closing PCEP session channel: TestingChannel 13:11:20.067 [main] INFO o.o.b.p.t.provider.TopologyNodeState - Node KeyedInstanceIdentifier{targetType=interface org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node, path=[org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.NetworkTopology, org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology[key=TopologyKey [_topologyId=Uri [_value=testtopo]]], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey [_nodeId=Uri [_value=pcc://127.76.206.79]]]]} shutdown successfully Nov 15, 2017 1:11:20 PM com.google.common.util.concurrent.AbstractFuture executeListener SEVERE: RuntimeException while executing runnable CallbackListener{org.opendaylight.bgpcep.pcep.topology.provider.AbstractTopologySessionListener$4@550f80f5} with executor MoreExecutors.directExecutor() java.lang.NullPointerException at org.opendaylight.bgpcep.pcep.topology.provider.AbstractTopologySessionListener$MessageContext.notifyRequests(AbstractTopologySessionListener.java:95) at org.opendaylight.bgpcep.pcep.topology.provider.AbstractTopologySessionListener$MessageContext.access$400(AbstractTopologySessionListener.java:81) at org.opendaylight.bgpcep.pcep.topology.provider.AbstractTopologySessionListener$4.onSuccess(AbstractTopologySessionListener.java:337) at org.opendaylight.bgpcep.pcep.topology.provider.AbstractTopologySessionListener$4.onSuccess(AbstractTopologySessionListener.java:333) at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1237) at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:399) at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:911) at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:822) at com.google.common.util.concurrent.AbstractFuture.set(AbstractFuture.java:664) at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:111) at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:58) at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:75) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 13:11:20.070 [pool-60-thread-1] DEBUG o.o.b.p.t.p.ServerSessionManager - Topology KeyedInstanceIdentifier{targetType=interface org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology, path=[org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.NetworkTopology, org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology[key=TopologyKey [_topologyId=Uri [_value=testtopo]]]]} removed 13:11:20.331 [main] DEBUG o.o.b.p.t.p.ServerSessionManager - Node Uri [_value=pcc://127.75.88.190] bound to listener org.opendaylight.bgpcep.pcep.topology.provider.Stateful07TopologySessionListener@6938d886 13:11:20.334 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - Saved LSP PlspId [_value=1] with name test 13:11:20.544 [pool-63-thread-1] DEBUG o.o.b.p.t.provider.PCEPRequest - Request went from UNSENT to DONE 13:11:20.545 [main] DEBUG o.o.p.pcep.impl.PCEPSessionImpl - PCEP Message enqueued: Pcupd [_pcupdMessage=PcupdMessage [_updates=[Updates [_lsp=Lsp [_plspId=PlspId [_value=1], _sync=true, augmentation=[]], _path=Path [augmentation=[]], _srp=Srp [_operationId=SrpIdNumber [_value=2], _processingRule=true, augmentation=[]], augmentation=[]]], _version=ProtocolVersion [_value=1], augmentation=[]], augmentation=[]] 13:11:20.545 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - LSP test removed 13:11:20.546 [main] DEBUG o.o.b.p.t.p.AbstractTopologySessionListener - Session PCEPSessionImpl{channel=TestingChannel, localOpen=Open [_deadTimer=30, _keepalive=10, _sessionId=0, _tlvs=Tlvs [augmentation=[Tlvs1 [_stateful=Stateful [augmentation=[Stateful1 [_includeDbVersion=true, _triggeredResync=true], Stateful1 [_initiation=true]]]], Tlvs3 [_lspDbVersion=LspDbVersion [_lspDbVersionValue=1, augmentation=[]], ]]], augmentation=[]], remoteOpen=Open [_deadTimer=30, _keepalive=10, _sessionId=0, _tlvs=Tlvs [augmentation=[Tlvs1 [_stateful=Stateful [augmentation=[Stateful1 [_includeDbVersion=true, _triggeredResync=true], Stateful1 [_initiation=true]]]], Tlvs3 [_lspDbVersion=LspDbVersion [_lspDbVersionValue=1, augmentation=[]], ]]], augmentation=[]]} achieved synchronized state 13:11:20.547 [main] DEBUG o.o.p.pcep.impl.PCEPSessionImpl - PCEP Message enqueued: Close [_cCloseMessage=CCloseMessage [_cClose=CClose [_reason=1, augmentation=[]], augmentation=[]], augmentation=[]] with executor MoreExecutors.directExecutor() 13:11:20.548 [main] INFO o.o.b.p.t.provider.TopologyNodeState - Node KeyedInstanceIdentifier {targetType=interface org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node, path=[org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.NetworkTopology, org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.Topology[key=TopologyKey [_topologyId=Uri [_value=testtopo]]], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey [_nodeId=Uri [_value=pcc://127.75.88.190]]]]}shutdown successfully |