[BGPCEP-633] ODL unable to parse path request message for new LSP Created: 17/Feb/17  Updated: 03/Mar/19  Resolved: 21/Feb/17

Status: Resolved
Project: bgpcep
Component/s: PCEP
Affects Version/s: Bugzilla Migration
Fix Version/s: Bugzilla Migration

Type: Bug
Reporter: Giles Heron Assignee: Dana Kutenicsova
Resolution: Won't Do Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

Operating System: All
Platform: All

External issue ID: 7819

 Description   

When ODL (I've verified this on Boron-SR2 and on 0.5.3-SNAPSHOT) first connects to an IOS XR node (XR 6.1.2) it receives the list of LSPs on the node, and that works fine. However if a new LSP is added on XR then ODL is unable to parse the PCE-P message from XR announcing the LSP.

In the logs I see:
2017-02-17 11:18:47,980 | TRACE | entLoopGroup-8-1 | PCEPByteToMessageDecoder | 119 - org.opendaylight.bgpcep.pcep-impl - 0.6.3.SNAPSHOT | Received to decode: 20030060021200140000008000000002001c0004000000000412000cc0a86402c0a86401201000140000000000110008504345505f425547091000140000000000000000000000000707000005100008000000000610000c0000000200000000
2017-02-17 11:18:47,985 | TRACE | entLoopGroup-8-1 | AbstractObjectWithTlvsParser | 117 - org.opendaylight.bgpcep.pcep-spi - 0.6.3.SNAPSHOT | Parsing PCEP TLV : 00000000
2017-02-17 11:18:47,987 | TRACE | entLoopGroup-8-1 | AbstractObjectWithTlvsParser | 117 - org.opendaylight.bgpcep.pcep-spi - 0.6.3.SNAPSHOT | Parsed PCEP TLV PathSetupType [_pst=0, augmentation=[]].
2017-02-17 11:18:47,996 | TRACE | entLoopGroup-8-1 | AbstractObjectWithTlvsParser | 117 - org.opendaylight.bgpcep.pcep-spi - 0.6.3.SNAPSHOT | Parsing PCEP TLV : 504345505f425547
2017-02-17 11:18:47,996 | TRACE | entLoopGroup-8-1 | AbstractObjectWithTlvsParser | 117 - org.opendaylight.bgpcep.pcep-spi - 0.6.3.SNAPSHOT | Parsed PCEP TLV SymbolicPathName [_pathName=SymbolicPathName [_value=[80, 67, 69, 80, 95, 66, 85, 71]], augmentation=[]].
2017-02-17 11:18:48,026 | DEBUG | entLoopGroup-8-1 | PCEPByteToMessageDecoder | 119 - org.opendaylight.bgpcep.pcep-impl - 0.6.3.SNAPSHOT | Failed to decode protocol message
org.opendaylight.protocol.pcep.spi.PCEPDeserializerException: Unprocessed Objects: [Lsp [_operational=Down, _plspId=PlspId [_value=0], _tlvs=Tlvs [_symbolicPathName=SymbolicPathName [_pathName=SymbolicPathName [_value=[80, 67, 69, 80, 95, 66, 85, 71]], augmentation=[]], augmentation=[Tlvs1 []]], _administrative=false, _delegate=false, _ignore=false, _processingRule=false, _remove=false, _sync=false, augmentation=[Lsp1 [_create=false]]], Lspa [_excludeAny=AttributeFilter [_value=0], _holdPriority=7, _includeAll=AttributeFilter [_value=0], _includeAny=AttributeFilter [_value=0], _setupPriority=7, _tlvs=Tlvs [augmentation=[]], _ignore=false, _localProtectionDesired=false, _processingRule=false, augmentation=[]], Bandwidth [_bandwidth=Float32 [_value=[0, 0, 0, 0]], _ignore=false, _processingRule=false, augmentation=[]], Metric [_metricType=2, _value=Float32 [_value=[0, 0, 0, 0]], _bound=false, _computed=false, _ignore=false, _processingRule=false, augmentation=[]]]
at org.opendaylight.protocol.pcep.parser.message.PCEPRequestMessageParser.validate(PCEPRequestMessageParser.java:174)[118:org.opendaylight.bgpcep.pcep-base-parser:0.6.3.SNAPSHOT]
at org.opendaylight.protocol.pcep.spi.AbstractMessageParser.parseMessage(AbstractMessageParser.java:132)[117:org.opendaylight.bgpcep.pcep-spi:0.6.3.SNAPSHOT]
at org.opendaylight.protocol.pcep.spi.pojo.SimpleMessageRegistry.parseMessage(SimpleMessageRegistry.java:50)[117:org.opendaylight.bgpcep.pcep-spi:0.6.3.SNAPSHOT]
at org.opendaylight.protocol.pcep.impl.PCEPByteToMessageDecoder.parse(PCEPByteToMessageDecoder.java:85)[119:org.opendaylight.bgpcep.pcep-impl:0.6.3.SNAPSHOT]
at org.opendaylight.protocol.pcep.impl.PCEPByteToMessageDecoder.decode(PCEPByteToMessageDecoder.java:51)[119:org.opendaylight.bgpcep.pcep-impl:0.6.3.SNAPSHOT]
at io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:411)[69:io.netty.codec:4.0.44.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:248)[69:io.netty.codec:4.0.44.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:357)[68:io.netty.transport:4.0.44.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:343)[68:io.netty.transport:4.0.44.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:336)[68:io.netty.transport:4.0.44.Final]
at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:293)[69:io.netty.codec:4.0.44.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:267)[69:io.netty.codec:4.0.44.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:357)[68:io.netty.transport:4.0.44.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:343)[68:io.netty.transport:4.0.44.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:336)[68:io.netty.transport:4.0.44.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1294)[68:io.netty.transport:4.0.44.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:357)[68:io.netty.transport:4.0.44.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:343)[68:io.netty.transport:4.0.44.Final]
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:911)[68:io.netty.transport:4.0.44.Final]
at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:934)[72:io.netty.transport-native-epoll:4.0.44.Final]
at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:397)[72:io.netty.transport-native-epoll:4.0.44.Final]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:302)[72:io.netty.transport-native-epoll:4.0.44.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:131)[67:io.netty.common:4.0.44.Final]
at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:144)[67:io.netty.common:4.0.44.Final]
at java.lang.Thread.run(Thread.java:745)[:1.8.0_91]
2017-02-17 11:18:48,028 | TRACE | entLoopGroup-8-1 | PCEPMessageToByteEncoder | 119 - org.opendaylight.bgpcep.pcep-impl - 0.6.3.SNAPSHOT | Encoded : 2006000c0d10000800000601
2017-02-17 11:18:48,029 | TRACE | entLoopGroup-8-1 | PCEPByteToMessageDecoder | 119 - org.opendaylight.bgpcep.pcep-impl - 0.6.3.SNAPSHOT | Message Pcerr [_pcerrMessage=PcerrMessage [_errors=[Errors [_errorObject=ErrorObject [_type=6, _value=1, augmentation=[]], augmentation=[]]], augmentation=[]], augmentation=[]] sent to socket [id: 0x18323da7, L:/10.195.94.43:4189 - R:/10.195.94.68:27382]
2017-02-17 11:18:48,029 | TRACE | entLoopGroup-8-1 | PCEPMessageToByteEncoder | 119 - org.opendaylight.bgpcep.pcep-impl - 0.6.3.SNAPSHOT | Encoded : 2006000c0d10000800000601
2017-02-17 11:18:48,029 | TRACE | entLoopGroup-8-1 | PCEPByteToMessageDecoder | 119 - org.opendaylight.bgpcep.pcep-impl - 0.6.3.SNAPSHOT | Message Pcerr [_pcerrMessage=PcerrMessage [_errors=[Errors [_errorObject=ErrorObject [_type=6, _value=1, augmentation=[]], augmentation=[]]], augmentation=[]], augmentation=[]] sent to socket [id: 0x18323da7, L:/10.195.94.43:4189 - R:/10.195.94.68:27382]

the received PCE-P message decodes as:

11:18:47.980118 IP 10.195.94.68.27382 > i2ss-c2202.cisco.com.4189: Flags [P.], seq 785:881, ack 57, win 63996, length 96
0x0000: 0010 18f8 72c0 e8ed f331 fd42 0800 4500 ....r....1.B..E.
0x0010: 0088 cbd1 0000 ff06 1da9 0ac3 5e44 0ac3 ............^D..
0x0020: 5e2b 6af6 105d ab6b 3f49 844a 4c32 5018 ^+j..].k?I.JL2P.
0x0030: f9fc b69b 0000 2003 0060 0212 0014 0000 .........`......
0x0040: 0080 0000 0002 001c 0004 0000 0000 0412 ................
0x0050: 000c c0a8 6402 c0a8 6401 2010 0014 0000 ....d...d.......
0x0060: 0000 0011 0008 5043 4550 5f42 5547 0910 ......PCEP_BUG..
0x0070: 0014 0000 0000 0000 0000 0000 0000 0707 ................
0x0080: 0000 0510 0008 0000 0000 0610 000c 0000 ................
0x0090: 0002 0000 0000 ......

the message from ODL back to XR indicates that the RP object was missing (error type 6, value 1) - but there's an RP object in the message sent by XR (that's the "021200140000008000000006001c0004000000000" in the received message...)

XR debug is:

RP/0/RSP0/CPU0:Feb 17 12:18:05.107 : te_control[1176]: DBG-PCE-CONFIG[1]: mte_verify_p2p_destination:7011: configuring destination
RP/0/RSP0/CPU0:Feb 17 12:18:05.107 : te_control[1176]: DBG-PCE-CONFIG[1]: te_verify_tunnel_pce_delegation:18270: delegation enable
RP/0/RSP0/CPU0:Feb 17 12:18:05.109 : te_control[1176]: DBG-PCE-CONFIG[1]: mte_apply_p2p_destination:7208: tunnel-te2: configure destination (verified 1)
RP/0/RSP0/CPU0:Feb 17 12:18:05.109 : te_control[1176]: DBG-PCE-CONFIG[1]: mte_path_option_set_pce_info:3677: Creating dynamic-pce popt: idx = 1 addr 0.0.0.0
RP/0/RSP0/CPU0:Feb 17 12:18:05.109 : te_control[1176]: DBG-PCE-TUNNEL[1]: te_pce_is_classic_tunnel:7466 (Tunnel ID: 2): CLASSIC tunnel
RP/0/RSP0/CPU0:Feb 17 12:18:05.110 : te_control[1176]: DBG-PCE-TUNNEL[1]: mte_path_option_pce_popt_has_path:4016 (Tunnel ID: 2): tunnel-te2: popt does not have new path, flag 0
RP/0/RSP0/CPU0:Feb 17 12:18:05.110 : te_control[1176]: DBG-PCE-DETAIL[1]: te_pce_get_rid:112: global_rid 192.168.100.2
RP/0/RSP0/CPU0:Feb 17 12:18:05.110 : te_control[1176]: DBG-PCE-DETAIL[1]: te_pce_get_rid:120: cfg_igp_rtr_id 192.168.100.2, igp_rtr_id_inuse 192.168.100.2
RP/0/RSP0/CPU0:Feb 17 12:18:05.110 : te_control[1176]: DBG-PCE-DETAIL[1]: te_pce_get_rid:112: global_rid 192.168.100.2
RP/0/RSP0/CPU0:Feb 17 12:18:05.110 : te_control[1176]: DBG-PCE-DETAIL[1]: te_pce_get_rid:120: cfg_igp_rtr_id 192.168.100.2, igp_rtr_id_inuse 192.168.100.2
RP/0/RSP0/CPU0:Feb 17 12:18:05.110 : te_control[1176]: DBG-PCE-TUNNEL[1]: te_pce_request_primary_path:6244 (Tunnel ID: 2): PCE primary path request: Tun tunnel-te2, LSP ID 2 po_idx = 1, pce_addr = 0.0.0.0 src = 192.168.100.2 dst = 192.168.100.1 bw = 0 affinity value/mask = 0/ffff setup_priority = 7 hold_priority = 7, Segment-Routing: FALSE
RP/0/RSP0/CPU0:Feb 17 12:18:05.110 : te_control[1176]: DBG-PCE-TUNNEL[1]: te_pce_request_primary_path:6257 (Tunnel ID: 2): tunnel-te2: PCE primary path request: metric TE
RP/0/RSP0/CPU0:Feb 17 12:18:05.110 : te_control[1176]: DBG-PCE-DETAIL[1]: te_pce_get_rid:112: global_rid 192.168.100.2
RP/0/RSP0/CPU0:Feb 17 12:18:05.110 : te_control[1176]: DBG-PCE-DETAIL[1]: te_pce_get_rid:120: cfg_igp_rtr_id 192.168.100.2, igp_rtr_id_inuse 192.168.100.2
RP/0/RSP0/CPU0:Feb 17 12:18:05.110 : te_control[1176]: DBG-PCE-DETAIL[1]: te_pce_get_rid:112: global_rid 192.168.100.2
RP/0/RSP0/CPU0:Feb 17 12:18:05.110 : te_control[1176]: DBG-PCE-DETAIL[1]: te_pce_get_rid:120: cfg_igp_rtr_id 192.168.100.2, igp_rtr_id_inuse 192.168.100.2
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-DETAIL[1]: te_pce_get_rid:112: global_rid 192.168.100.2
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-DETAIL[1]: te_pce_get_rid:120: cfg_igp_rtr_id 192.168.100.2, igp_rtr_id_inuse 192.168.100.2
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-TUNNEL[1]: te_pce_request_primary_path:6343 (Tunnel ID: 2): tunnel-te2: Destination 192.168.100.1 directly reachable
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-TUNNEL[1]: te_pce_hold_non_pce_path_options:3993 (Tunnel ID: 2): Holding down non-PCE popts
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-DETAIL[10]: te_pce_process_pce_thread_event:5109: Process TE_PCE_WORK_TYPE_FWD_TO_PCE
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-IGP[10]: te_pce_process_pce_thread_event:5113: Enable and poll all IGPs.....
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-CONFIG[1]: te_apply_tunnel_pce_delegation:18357: enable
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-IGP[10]: te_pce_igp_enable:1298: te_pce_igp_enable
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-CONFIG[1]: te_apply_tunnel_pce_delegation:18392: Enabling per tunnel delegation for tunnel-te2
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-IGP[10]: te_pce_igp_enable:1313: te_pce_igp_enable: Enabling listen. Disabling flooding.
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-CONFIG[1]: te_pce_stage_delegation:368: te_pce_stage_delegation: Enable
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-IGP[10]: te_pce_igp_poll_all:1262: te_pce_igp_poll_all
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-DEVELOP[1]: te_pce_stage_delegation:372: tunnel_deleg 1, global_deleg 0
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-PATH[10]: te_pce_get_req_by_tun_id:654: Checking req by Tunnel ID: 2
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-CONFIG[1]: te_pce_stage_delegation:382: Tunnel not ready -> starting report/delegation timer
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-PATH[10]: te_pce_create_in_req_entry:478: src_addr = 192.168.100.2 dst_addr = 192.168.100.1 in_req_id = 1
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-CONFIG[1]: te_pce_lsp_delegate_timer_start:275: lsp delegation timer start: 60
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-PATH[10]: te_pce_update_dst_thread:634: Updating dst thread, dst = 192.168.100.1
RP/0/RSP0/CPU0:Feb 17 12:18:05.111 : te_control[1176]: DBG-PCE-PATH[10]: te_pce_update_out_req_id_thread:605: Update out_id thread, out_req_id = 2
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-PATH[10]: te_pce_update_req_tun_id_thread:684: Updating tunnel_id thread, tun_id = 2
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DETAIL[10]: te_pce_process_pce_thread_event:5256: Choosing PCE excluding 0.0.0.0
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-PATH[10]: te_pce_process_pce_thread_event:5319: fwd'ing PRIMARY req to peer 10.195.94.43: in ID = 1 out ID = 2
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DEVELOP[10]: te_pce_process_pce_thread_event:5376: te_pce_process_pce_thread_event: No ASSOCIATION
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_enqueue_path_req_msg:11324: ******* setup 7 hold 7
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-PATH[10]: pce_enqueue_path_req_msg:11415: pce_enqueue_path_req_msg: Request has ASSOCIATION, type 0, id 0, source 0.0.0.0
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_enqueue_path_req_msg:11488: Added an RP object,len = 20
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-TUNNEL[1]: te_pce_is_classic_tunnel:7466 (Tunnel ID: 2): CLASSIC tunnel
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_enqueue_path_req_msg:11507: REQ ID: [2]
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: ERR-PCE[1]: te_pce_report_tunnel:5474: tunnel-te2 is not eligible for report
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_enqueue_path_req_msg:11535: Path-setup-type TLV added into RP object, path_setup_type: RSVP
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_enqueue_path_req_msg:11645: Added an LSPA_LONG object, affinity = 0, setup priority = 0 hold priority = 0, prot = 0
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_enqueue_path_req_msg:11662: Added req BW object,len = 8 val = 0
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_enqueue_path_req_msg:11748: Added a METRIC object (type 2),len = 12
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_enqueue_path_req_msg:11899: Total msg len = 96
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-PATH[10]: pce_enqueue_path_req_msg:11908: Transmit Req: src 192.168.100.2 dst 192.168.100.1 req_id 2
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DEVELOP[10]: pce_update_tx_stats:3482: Updating statistics: TX Request
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1150: MSG_HDR: [0x20030060]
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1150: VER: [0x1]
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1150: FLAGS: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1150: MSG_TYPE: [0x3]
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1150: LEN: [0x60]
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_HDR: [0x02120014]
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_CLASS: [0x2]
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_TYPE: [0x1]
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: RSRVD: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: P_FLAG: [0x1]
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: I_FLAG: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.112 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: LEN: [0x14]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_dump_message_obj:987: DUMP: RP obj
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_rp:354: RP_OBJ_P1: [0x00000080]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_rp:354: RSRVD: [0x00]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_rp:354: FLAGS: [0x01]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_rp:354: N: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_rp:354: O: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_rp:354: B: [0x0]
RP/0/RSP0/CPU0:i2ss-asr9k2#RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_rp:354: R: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_rp:354: PRIO: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_rp:355: RP_OBJ_P2: [0x00000002]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_rp:355: REQ_ID: [0x0002]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_rp:363: PATH_SETUP_TYPE_TLV: [0x001C0004]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_rp:363: RSRVD: [0x001C00]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_rp:363: TYPE: [0x04]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_HDR: [0x0412000C]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_CLASS: [0x4]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_TYPE: [0x1]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: RSRVD: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: P_FLAG: [0x1]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-TUNNEL[1]: mte_path_option_pce_popt_has_path:4016 (Tunnel ID: 2): tunnel-te2: popt does not have new path, flag 8
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: I_FLAG: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DETAIL[1]: te_pce_get_rid:112: global_rid 192.168.100.2
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: LEN: [0x0C]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DETAIL[1]: te_pce_get_rid:120: cfg_igp_rtr_id 192.168.100.2, igp_rtr_id_inuse 192.168.100.2
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_dump_message_obj:987: DUMP: EndPoint obj
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_endpoint:397: ENDPOINT OBJ: [0xC0A86402] [0xC0A86401]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DETAIL[1]: te_pce_request_primary_path:6151: Primary request for tunnel-te2 po_idx 1: Pending request exists for po_idx 0
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_endpoint:399: SRC: [192.168.100.2]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-PATH[1]: te_pce_request_primary_path:6156: Next primary candidate po_idx 1 (6156)
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_endpoint:401: DST: [192.168.100.1]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_HDR: [0x20100014]
RP/0/RSP0/CPU0:Feb 17 12:18:05.113 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_CLASS: [0x20]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_TYPE: [0x1]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: RSRVD: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: P_FLAG: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: I_FLAG: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: LEN: [0x14]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_dump_message_obj:987: DUMP: LSP obj
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lsp:877: LSP_OBJ: [0x00000000]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lsp:877: LSP-ID: [0x00000]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lsp:877: FLAG_D: [.......0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lsp:877: FLAG_S: [......0.]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lsp:877: FLAG_R: [.....0..]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lsp:877: FLAG_A: [....0...]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lsp:877: FLAG_O: [.000....]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lsp:877: FLAG_C: [0.......]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message_tlvs:297: TLV_HDR: [0x00110008]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message_tlvs:297: TYPE: [0x0011]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message_tlvs:297: LEN: [0x0008]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message_tlv:203: SYMBOLIC_PATH_NAME_TLV:
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message_tlv:203: NAME: [PCEP_BUG]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_HDR: [0x09100014]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_CLASS: [0x9]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_TYPE: [0x1]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: RSRVD: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: P_FLAG: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: I_FLAG: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: LEN: [0x14]
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_dump_message_obj:987: DUMP: LSPA obj
RP/0/RSP0/CPU0:Feb 17 12:18:05.114 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lspa:766: LSPA_LONG_OBJ_P1: [0x00000000]
RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lspa:766: EXCL_ANY: [0x0000]

RP/0/RSP0/CPU0:i2ss-asr9k2#RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lspa:767: LSPA_LONG_OBJ_P2: [0x00000000]
RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lspa:767: INCL_ANY: [0x0000]
RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lspa:768: LSPA_LONG_OBJ_P3: [0x00000000]
RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lspa:768: INCL_ALL: [0x0000]
RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lspa:769: LSPA_LONG_OBJ_P4: [0x07070000]
RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lspa:769: SETUP: [0x7]
RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lspa:769: HOLD: [0x7]
RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lspa:769: FLAGS: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lspa:769: L: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_lspa:769: RSRVD: [0x00]
RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_HDR: [0x05100008]
RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_CLASS: [0x5]
RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_TYPE: [0x1]
RP/0/RSP0/CPU0:Feb 17 12:18:05.115 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: RSRVD: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: P_FLAG: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: I_FLAG: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: LEN: [0x08]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_dump_message_obj:987: DUMP: BW obj
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_bw:415: BW_OBJ: [0x00000000]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_bw:415: VAL: [0x0000]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_HDR: [0x0610000C]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_CLASS: [0x6]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: OBJ_TYPE: [0x1]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: RSRVD: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: P_FLAG: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: I_FLAG: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_message:1181: LEN: [0x0C]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_dump_message_obj:987: DUMP: Metric obj
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_metric:428: METRIC_OBJ_P1: [0x00000002]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_metric:428: RSRVD: [0x00]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_metric:428: FLAGS: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_metric:428: C: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_metric:428: B: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_metric:428: T: [0x2]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_metric:429: METRIC_OBJ_P2: [0x00000000]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DUMP-REQ-OUT[10]: pce_dump_obj_class_metric:429: VALUE: [0x0000]
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_tx_msg:3591: Sending Request to 10.195.94.43.
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DEVELOP[10]: pce_tx_msg:3601: TX msg at 1487333885
RP/0/RSP0/CPU0:Feb 17 12:18:05.116 : te_control[1176]: DBG-PCE-DETAIL[10]: pce_transmit:1755: peer 10.195.94.43 (fd 137) msg_type = Request priority 1
RP/0/RSP0/CPU0:Feb 17 12:18:05.117 : te_control[1176]: DBG-PCE-DEVELOP[10]: pce_flush_tcp_buffer:1680: Tranmitted 96 bytes, no pending data
RP/0/RSP0/CPU0:Feb 17 12:18:05.166 : te_control[1176]: DBG-PCE-DEVELOP[10]: pce_update_rx_buffer:1410: bytes_to_read = 512000 bytes_read = 12
RP/0/RSP0/CPU0:Feb 17 12:18:05.166 : te_control[1176]: DBG-PCE-DEVELOP[10]: pce_read_msg:9475: msg_size = 12, type = Error [6]
RP/0/RSP0/CPU0:Feb 17 12:18:05.166 : te_control[1176]: DBG-PCE-DEVELOP[10]: pce_free_rx_pdu:9363: Moving 0 bytes in the Rx buffer of peer 10.195.94.43
RP/0/RSP0/CPU0:Feb 17 12:18:05.166 : te_control[1176]: DBG-PCE-DEVELOP[10]: pce_read_msg:9406: No data in Rx buffer of 10.195.94.43
RP/0/RSP0/CPU0:Feb 17 12:18:05.166 : te_control[1176]: DBG-PCE-DEVELOP[10]: pce_update_rx_stats:3466: Updating statistics: RX Error
RP/0/RSP0/CPU0:Feb 17 12:18:05.166 : te_control[1176]: DBG-PCE-DUMP-ERR-IN[10]: pce_dump_message:1150: MSG_HDR: [0x2006000C]
RP/0/RSP0/CPU0:Feb 17 12:18:05.166 : te_control[1176]: DBG-PCE-DUMP-ERR-IN[10]: pce_dump_message:1150: VER: [0x1]
RP/0/RSP0/CPU0:Feb 17 12:18:05.167 : te_control[1176]: DBG-PCE-DUMP-ERR-IN[10]: pce_dump_message:1150: FLAGS: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.167 : te_control[1176]: DBG-PCE-DUMP-ERR-IN[10]: pce_dump_message:1150: MSG_TYPE: [0x6]
RP/0/RSP0/CPU0:Feb 17 12:18:05.167 : te_control[1176]: DBG-PCE-DUMP-ERR-IN[10]: pce_dump_message:1150: LEN: [0x0C]
RP/0/RSP0/CPU0:Feb 17 12:18:05.167 : te_control[1176]: DBG-PCE-DUMP-ERR-IN[10]: pce_dump_message:1181: OBJ_HDR: [0x0D100008]
RP/0/RSP0/CPU0:Feb 17 12:18:05.167 : te_control[1176]: DBG-PCE-DUMP-ERR-IN[10]: pce_dump_message:1181: OBJ_CLASS: [0xD]
RP/0/RSP0/CPU0:Feb 17 12:18:05.167 : te_control[1176]: DBG-PCE-DUMP-ERR-IN[10]: pce_dump_message:1181: OBJ_TYPE: [0x1]
RP/0/RSP0/CPU0:Feb 17 12:18:05.167 : te_control[1176]: DBG-PCE-DUMP-ERR-IN[10]: pce_dump_message:1181: RSRVD: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.167 : te_control[1176]: DBG-PCE-DUMP-ERR-IN[10]: pce_dump_message:1181: P_FLAG: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.167 : te_control[1176]: DBG-PCE-DUMP-ERR-IN[10]: pce_dump_message:1181: I_FLAG: [0x0]
RP/0/RSP0/CPU0:Feb 17 12:18:05.167 : te_con...

 Comments   
Comment by Dana Kutenicsova [ 21/Feb/17 ]

tl;dr - PcepRequestMessage with LSP object as updated by stateful draft is not part of ODL implementation, as it requires PCE implementation in the backend, which we don't have in ODL.

long - The error is correct. Stateful draft updates PcepRequest message so that it adds also LSP object. Since we don't have this implementation (that would count with LSP object present), we leave this object out of parsing of requests.
This message consists of one request only, where the request gets parsed correctly, however since there are objects left (the mentioned LSP), the parser looks for another mandatory RP object to acompany the leftover one. The second RP object is not found, hence the error.

Generated at Wed Feb 07 19:13:40 UTC 2024 using Jira 8.20.10#820010-sha1:ace47f9899e9ee25d7157d59aa17ab06aee30d3d.