[BGPCEP-889] NPE while updating PCC stats when session is coming up Created: 03/Dec/19 Updated: 09/Dec/19 Resolved: 09/Dec/19 |
|
| Status: | Resolved |
| Project: | bgpcep |
| Component/s: | PCEP |
| Affects Version/s: | Fluorine SR1 |
| Fix Version/s: | Neon SR3, Magnesium, Sodium SR2 |
| Type: | Bug | Priority: | Medium |
| Reporter: | Ajay Lele | Assignee: | Ajay Lele |
| Resolution: | Done | Votes: | 0 |
| Labels: | None | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Description |
2019-11-26T16:10:33,103 | WARN | pool-73-thread-1 | TopologyStatsProviderImpl | 267 - org.opendaylight.bgpcep.pcep-topology-stats - 0.10.1 | Failed to prepare Tx for BGP stats update
java.lang.NullPointerException: null
at org.opendaylight.bgpcep.pcep.topology.provider.session.stats.SessionStateImpl.getMessages(SessionStateImpl.java:139) [265:org.opendaylight.bgpcep.pcep-topology-provider:0.10.1]
at org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.stats.rev171113.pcep.session.state.grouping.PcepSessionStateBuilder.<init>(PcepSessionStateBuilder.java:49) [257:org.opendaylight.bgpcep.pcep-api:0.10.1]
at org.opendaylight.bgpcep.pcep.topology.stats.provider.TopologyStatsProviderImpl.updatePcepStats(TopologyStatsProviderImpl.java:85) [267:org.opendaylight.bgpcep.pcep-topology-stats:0.10.1]
at org.opendaylight.bgpcep.pcep.topology.stats.provider.TopologyStatsProviderImpl.access$000(TopologyStatsProviderImpl.java:46) [267:org.opendaylight.bgpcep.pcep-topology-stats:0.10.1]
at org.opendaylight.bgpcep.pcep.topology.stats.provider.TopologyStatsProviderImpl$1.run(TopologyStatsProviderImpl.java:70) [267:org.opendaylight.bgpcep.pcep-topology-stats:0.10.1]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:?]
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) [?:?]
|
| Comments |
| Comment by Ajay Lele [ 03/Dec/19 ] |
|
karag.log during session bring-up when issue is seen 2019-11-26T16:10:32,969 | INFO | epollEventLoopGroup-8-1 | AbstractPCEPSessionNegotiator | 261 - org.opendaylight.bgpcep.pcep-impl - 0.10.1 | PCEP peer [id: 0x71f1639d, L:/192.168.122.1:4189 - R:/192.168.122.136:49069] completed negotiation
2019-11-26T16:10:32,971 | INFO | epollEventLoopGroup-8-1 | PCEPSessionImpl | 261 - org.opendaylight.bgpcep.pcep-impl - 0.10.1 | Session /192.168.122.1:4189[0] <-> /192.168.122.136:49069[0] started
2019-11-26T16:10:33,103 | WARN | pool-73-thread-1 | TopologyStatsProviderImpl | 267 - org.opendaylight.bgpcep.pcep-topology-stats - 0.10.1 | Failed to prepare Tx for BGP stats update
java.lang.NullPointerException: null
at org.opendaylight.bgpcep.pcep.topology.provider.session.stats.SessionStateImpl.getMessages(SessionStateImpl.java:139) [265:org.opendaylight.bgpcep.pcep-topology-provider:0.10.1]
at org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.stats.rev171113.pcep.session.state.grouping.PcepSessionStateBuilder.<init>(PcepSessionStateBuilder.java:49) [257:org.opendaylight.bgpcep.pcep-api:0.10.1]
at org.opendaylight.bgpcep.pcep.topology.stats.provider.TopologyStatsProviderImpl.updatePcepStats(TopologyStatsProviderImpl.java:85) [267:org.opendaylight.bgpcep.pcep-topology-stats:0.10.1]
at org.opendaylight.bgpcep.pcep.topology.stats.provider.TopologyStatsProviderImpl.access$000(TopologyStatsProviderImpl.java:46) [267:org.opendaylight.bgpcep.pcep-topology-stats:0.10.1]
at org.opendaylight.bgpcep.pcep.topology.stats.provider.TopologyStatsProviderImpl$1.run(TopologyStatsProviderImpl.java:70) [267:org.opendaylight.bgpcep.pcep-topology-stats:0.10.1]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:?]
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) [?:?]
2019-11-26T16:10:33,202 | INFO | epollEventLoopGroup-8-1 | AbstractTopologySessionListener | 265 - org.opendaylight.bgpcep.pcep-topology-provider - 0.10.1 | Session with /192.168.122.136 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=pcep-topology}}], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey{_nodeId=Uri{_value=pcc://192.168.122.136}}]]}
|
| Comment by Ajay Lele [ 03/Dec/19 ] |
|
karag.log during session bring-up when issue is not seen 2019-12-02T15:14:49,784 | INFO | epollEventLoopGroup-9-1 | PCEPSessionNegotiator | 261 - org.opendaylight.bgpcep.pcep-impl - 0.10.1 | Replacing bootstrap negotiator for channel [id: 0x4351e94e, L:/192.168.122.1:4189 - R:/192.168.122.136:56547]
2019-12-02T15:14:49,814 | INFO | epollEventLoopGroup-9-1 | AbstractPCEPSessionNegotiator | 261 - org.opendaylight.bgpcep.pcep-impl - 0.10.1 | PCEP session with [id: 0x4351e94e, L:/192.168.122.1:4189 - R:/192.168.122.136:56547] started, sent proposal Open{_deadTimer=120, _keepalive=30, _sessionId=0, _tlvs=Tlvs{augmentation=[Tlvs1{_srPceCapability=SrPceCapability{_msd=0, augmentation=[]}}, Tlvs1{_stateful=Stateful{_lspUpdateCapability=true, augmentation=[Stateful1{_initiation=true}, Stateful1{_deltaLspSyncCapability=true, _includeDbVersion=true, _triggeredInitialSync=true, _triggeredResync=true}]}}]}, augmentation=[]}
2019-12-02T15:14:49,833 | INFO | epollEventLoopGroup-9-1 | AbstractPCEPSessionNegotiator | 261 - org.opendaylight.bgpcep.pcep-impl - 0.10.1 | PCEP peer [id: 0x4351e94e, L:/192.168.122.1:4189 - R:/192.168.122.136:56547] completed negotiation
2019-12-02T15:14:49,836 | INFO | epollEventLoopGroup-9-1 | PCEPSessionImpl | 261 - org.opendaylight.bgpcep.pcep-impl - 0.10.1 | Session /192.168.122.1:4189[0] <-> /192.168.122.136:56547[1] started
2019-12-02T15:14:49,849 | DEBUG | epollEventLoopGroup-9-1 | ServerSessionManager | 265 - org.opendaylight.bgpcep.pcep-topology-provider - 0.10.1 | Node Uri{_value=pcc://192.168.122.136} requested by listener org.opendaylight.bgpcep.pcep.topology.provider.Stateful07TopologySessionListener@55def3d
2019-12-02T15:14:49,850 | DEBUG | epollEventLoopGroup-9-1 | ServerSessionManager | 265 - org.opendaylight.bgpcep.pcep-topology-provider - 0.10.1 | Created topology node org.opendaylight.bgpcep.pcep.topology.provider.TopologyNodeState@6668aa00 for id Uri{_value=pcc://192.168.122.136} 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=pcep-topology}}], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey{_nodeId=Uri{_value=pcc://192.168.122.136}}]]}
2019-12-02T15:14:49,854 | DEBUG | epollEventLoopGroup-9-1 | ServerSessionManager | 265 - org.opendaylight.bgpcep.pcep-topology-provider - 0.10.1 | Node Uri{_value=pcc://192.168.122.136} bound to listener org.opendaylight.bgpcep.pcep.topology.provider.Stateful07TopologySessionListener@55def3d
2019-12-02T15:14:50,057 | INFO | epollEventLoopGroup-9-1 | AbstractTopologySessionListener | 265 - org.opendaylight.bgpcep.pcep-topology-provider - 0.10.1 | Session with /192.168.122.136 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=pcep-topology}}], org.opendaylight.yang.gen.v1.urn.tbd.params.xml.ns.yang.network.topology.rev131021.network.topology.topology.Node[key=NodeKey{_nodeId=Uri{_value=pcc://192.168.122.136}}]]}
2019-12-02T15:14:50,071 | DEBUG | epollEventLoopGroup-9-1 | AbstractTopologySessionListener | 265 - org.opendaylight.bgpcep.pcep-topology-provider - 0.10.1 | Session PCEPSessionImpl{channel=[id: 0x4351e94e, L:/192.168.122.1:4189 - R:/192.168.122.136:56547], localOpen=Open{_deadTimer=120, _keepalive=30, _sessionId=0, _tlvs=Tlvs{augmentation=[Tlvs1{_srPceCapability=SrPceCapability{_msd=0, augmentation=[]}}, Tlvs1{_stateful=Stateful{_lspUpdateCapability=true, augmentation=[Stateful1{_initiation=true}, Stateful1{_deltaLspSyncCapability=true, _includeDbVersion=true, _triggeredInitialSync=true, _triggeredResync=true}]}}]}, augmentation=[]}, remoteOpen=Open{_deadTimer=120, _keepalive=30, _sessionId=1, _tlvs=Tlvs{augmentation=[Tlvs1{}, Tlvs1{_stateful=Stateful{_lspUpdateCapability=true, augmentation=[Stateful1{_initiation=true}, Stateful1{}]}}, Tlvs3{}]}, _version=ProtocolVersion{_value=1}, _ignore=false, _processingRule=false, augmentation=[]}} achieved synchronized state
2019-12-02T15:14:51,408 | DEBUG | CommitFutures-0 | TopologyStatsProviderImpl | 267 - org.opendaylight.bgpcep.pcep-topology-stats - 0.10.1 | Successfully committed Topology stats update
|