RP/0/RP0/CPU0:PE2#show mpls traffic-eng trace head-end Tue Sep 15 04:57:12.229 UTC 254 wrapping entries (264256 possible, 576 allocated, 0 filtered, 254 total) Sep 15 02:28:37.222 mpls_te/head-end 0/RP0/CPU0 t4602 [PCALC-ECMP] Max BWV Allocated: 20 Sep 15 02:28:37.222 mpls_te/head-end 0/RP0/CPU0 t4602 [PCALC-ECMP] Max BWVE Allocated: 15 Sep 15 02:28:40.820 mpls_te/head-end 0/RP0/CPU0 t4602 NOTFN OwnedResEnd Sep 15 02:28:42.123 mpls_te/head-end 0/RP0/CPU0 t4602 Validating ifindexes for all vifs Sep 15 02:34:06.526 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Start sync retry timer Sep 15 02:34:06.526 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op IF CREATE with 1 items Sep 15 02:34:06.532 mpls_te/head-end 0/RP0/CPU0 t4602 ifh:0x1c, NOTFN INITIAL; caps ; proto NONE; state not ready Sep 15 02:34:06.532 mpls_te/head-end 0/RP0/CPU0 t4602 ifh:0x1c, NOTFN INITIAL; caps mpls_te; proto NONE; state not ready Sep 15 02:34:06.533 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op CAPS ADD with 1 items Sep 15 02:34:06.533 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, ifh:0x1c, NOTFN STATE, caps ; proto NONE; state down Sep 15 02:34:06.610 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op STATE UPDATE with 1 items Sep 15 02:34:06.612 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op STATE UPDATE for Unknown (ifhndl 0x1c) Sep 15 02:34:06.613 mpls_te/head-end 0/RP0/CPU0 t4602 ifh:0x1c, NOTFN INITIAL; caps mpls; proto mpls; state not ready Sep 15 02:34:06.613 mpls_te/head-end 0/RP0/CPU0 t4602 ifh:0x1c, NOTFN MTU; caps mpls; proto mpls; mtu 1500 Sep 15 02:34:06.613 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op CAPS ADD for Unknown (ifhndl 0x1c) Sep 15 02:34:06.613 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op CAPS ADD with 1 items Sep 15 02:34:06.613 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op MTU UPDATE with 1 items Sep 15 02:34:06.625 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op CAPS ADD for Unknown (ifhndl 0x1c) Sep 15 02:34:06.711 mpls_te/head-end 0/RP0/CPU0 t4602 ifh:0x1c, NOTFN CREATE; caps ipv4; proto ipv4; Sep 15 02:34:06.711 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IP address is now available Sep 15 02:34:06.711 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_CHECK Sep 15 02:34:06.755 mpls_te/head-end 0/RP0/CPU0 t4602 Unknown (ifhndl 0x1c) : queued IM dest update: 11.11.11.11 Sep 15 02:34:06.755 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Send IM attribute: old dest = 0.0.0.0, new dest = 11.11.11.11 Sep 15 02:34:06.756 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Start sync retry timer Sep 15 02:34:06.756 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Start sync retry timer Sep 15 02:34:06.756 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:0, Holddown:0 Sep 15 02:34:06.757 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Start sync retry timer Sep 15 02:34:06.757 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, L:2, LL:1048577, TE rewrite delete queueing succeeded Sep 15 02:34:06.757 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IFH:0x01C, moving state to down Sep 15 02:34:06.757 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:0, Holddown:0 Sep 15 02:34:06.759 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_CHECK Sep 15 02:34:06.759 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_MODIFY_IN_PLACE Sep 15 02:34:06.811 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op STATE UPDATE with 1 items Sep 15 02:34:06.812 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op STATE UPDATE for Unknown (ifhndl 0x1c) Sep 15 02:34:06.917 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, L:3, LL:24016, TE rewrite queueing succeeded Sep 15 02:34:06.918 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [CURRENT] L:3, ifh:0x1c, TE rewrite returned TRUE Sep 15 02:34:06.918 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IFH:0x01C, moving state to up Sep 15 02:34:06.918 mpls_te/head-end 0/RP0/CPU0 t4602 Created autoroute entry 11.11.11.11, area 2 0; total AA entries 1 Sep 15 02:34:06.918 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, added AA, D:11.11.11.11, IGP: 2, area 0 Sep 15 02:34:06.918 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op STATE UPDATE with 1 items Sep 15 02:34:06.919 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op STATE UPDATE for Unknown (ifhndl 0x1c) Sep 15 02:34:06.919 mpls_te/head-end 0/RP0/CPU0 t4602 Sent autoroute-announce tunnel list for 11.11.11.11 to IGP: OSPF, area 0: 1 tunnels Sep 15 02:34:07.526 mpls_te/head-end 0/RP0/CPU0 t4602 Validating ifindexes for all vifs Sep 15 02:34:07.526 mpls_te/head-end 0/RP0/CPU0 t4602 Bulk ifindex lookup for 1 vifs Sep 15 02:34:07.529 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, ifindex set to 9 Sep 15 02:34:21.758 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Sync retry timer expired Sep 15 02:42:03.277 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, L:3, LL:24016, TE rewrite delete queueing succeeded Sep 15 02:42:03.277 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IFH:0x01C, moving state to down Sep 15 02:42:03.277 mpls_te/head-end 0/RP0/CPU0 t4602 Removed tunnel T:0, D:11.11.11.11 from autoroute list for IGP: OSPF, area 0 Sep 15 02:42:03.277 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_CHECK Sep 15 02:42:03.277 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:0, Holddown:0 Sep 15 02:42:03.278 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:20, POType:1, ComputationType:0, Holddown:0 Sep 15 02:42:03.279 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op STATE UPDATE with 1 items Sep 15 02:42:03.281 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op STATE UPDATE for Unknown (ifhndl 0x1c) Sep 15 02:42:03.281 mpls_te/head-end 0/RP0/CPU0 t4602 Sent autoroute-announce tunnel list for 11.11.11.11 to IGP: OSPF, area 0: 0 tunnels Sep 15 02:42:03.281 mpls_te/head-end 0/RP0/CPU0 t4602 Deleted autoroute entry 11.11.11.11, area 2 0; total AA entries 0 Sep 15 02:42:03.619 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, L:4, LL:24016, TE rewrite queueing succeeded Sep 15 02:42:03.620 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [CURRENT] L:4, ifh:0x1c, TE rewrite returned TRUE Sep 15 02:42:03.620 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IFH:0x01C, moving state to up Sep 15 02:42:03.620 mpls_te/head-end 0/RP0/CPU0 t4602 Created autoroute entry 11.11.11.11, area 2 0; total AA entries 1 Sep 15 02:42:03.620 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, added AA, D:11.11.11.11, IGP: 2, area 0 Sep 15 02:42:03.620 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op STATE UPDATE with 1 items Sep 15 02:42:03.621 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op STATE UPDATE for Unknown (ifhndl 0x1c) Sep 15 02:42:03.621 mpls_te/head-end 0/RP0/CPU0 t4602 Sent autoroute-announce tunnel list for 11.11.11.11 to IGP: OSPF, area 0: 1 tunnels Sep 15 02:51:15.831 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_MODIFY_IN_PLACE Sep 15 02:51:16.828 mpls_te/head-end 0/RP0/CPU0 t4602 Validating ifindexes for all vifs Sep 15 02:51:54.237 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACTION_REOPTIMIZE_CLI Sep 15 02:51:54.237 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:1, Holddown:0 Sep 15 02:51:54.238 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, working-reopt initiated: trigger: CLI request, reason: better path option indices Sep 15 02:51:54.238 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:5, better path option indices Sep 15 02:51:54.333 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, started install timer:20 secs, 100 msec, [CURRENT] L:4, [REOPT] L:5 Sep 15 02:52:14.433 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Timer[0] expired; install RW for [REOPT] L:5 and start cleanup timer:20 secs Sep 15 02:52:14.434 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:5, TE rewrite returned TRUE Sep 15 02:52:14.435 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:5, ifh:0x1c, TE rewrite returned TRUE Sep 15 02:52:34.535 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, cleanup timer expired; destroying [CLEAN] L:4 Sep 15 03:06:40.099 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACTION_REOPTIMIZE_FRR Sep 15 03:06:40.099 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:1, Holddown:0 Sep 15 03:06:40.099 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:20, POType:1, ComputationType:1, Holddown:0 Sep 15 03:06:40.099 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, working-reopt initiated: trigger: FRR, reason: recovery from FRR Sep 15 03:06:40.099 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:6, recovery from FRR Sep 15 03:06:40.263 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, D:11.11.11.11, PO_IDX:20 PO holddown timer started for 2 seconds Sep 15 03:06:40.263 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_CHECK Sep 15 03:06:40.289 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACTION_REOPTIMIZE_FRR Sep 15 03:06:40.289 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:1, Holddown:0 Sep 15 03:06:40.289 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:20, POType:1, ComputationType:1, Holddown:1 Sep 15 03:06:40.289 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:7, LSP not signalled, has no S2Ls Sep 15 03:06:42.499 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:1, Holddown:0 Sep 15 03:06:42.499 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:20, POType:1, ComputationType:1, Holddown:1 Sep 15 03:06:43.263 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, D:11.11.11.11, PO_IDX:20, PO holddown timer expired Sep 15 03:06:43.263 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:1, Holddown:0 Sep 15 03:06:43.264 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:20, POType:1, ComputationType:1, Holddown:0 Sep 15 03:06:43.264 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, working-reopt initiated: trigger: FRR, reason: recovery from FRR Sep 15 03:06:43.264 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:7, recovery from FRR Sep 15 03:06:43.469 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, started install timer:20 secs, 100 msec, [CURRENT] L:5, [REOPT] L:7 Sep 15 03:07:03.569 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Timer[0] expired; install RW for [REOPT] L:7 and start cleanup timer:20 secs Sep 15 03:07:03.569 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:7, TE rewrite returned TRUE Sep 15 03:07:03.570 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:7, ifh:0x1c, TE rewrite returned TRUE Sep 15 03:07:23.671 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, cleanup timer expired; destroying [CLEAN] L:5 Sep 15 03:17:20.362 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACTION_REOPTIMIZE_CLI Sep 15 03:17:20.363 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:1, Holddown:0 Sep 15 03:17:20.363 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, working-reopt initiated: trigger: CLI request, reason: better path option indices Sep 15 03:17:20.363 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:8, better path option indices Sep 15 03:17:20.512 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, started install timer:20 secs, 100 msec, [CURRENT] L:7, [REOPT] L:8 Sep 15 03:17:40.613 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Timer[0] expired; install RW for [REOPT] L:8 and start cleanup timer:20 secs Sep 15 03:17:40.613 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:8, TE rewrite returned TRUE Sep 15 03:17:40.614 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:8, ifh:0x1c, TE rewrite returned TRUE Sep 15 03:18:00.715 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, cleanup timer expired; destroying [CLEAN] L:7 Sep 15 03:24:39.122 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, FRR Protection Flags changed: Old Node/BW: Not Set/Not Set, New Node/BW: Set/Not Set Sep 15 03:24:39.122 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_MODIFY_IN_PLACE Sep 15 03:24:40.119 mpls_te/head-end 0/RP0/CPU0 t4602 Validating ifindexes for all vifs Sep 15 03:28:39.228 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACTION_REOPTIMIZE_PCE Sep 15 03:28:39.228 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:1, Holddown:0 Sep 15 03:28:39.228 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:9, LSP not signalled, identical to the [CURRENT] LSP Sep 15 03:32:03.488 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACTION_REOPTIMIZE_FRR Sep 15 03:32:03.488 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:1, Holddown:0 Sep 15 03:32:03.488 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:20, POType:1, ComputationType:1, Holddown:0 Sep 15 03:32:03.488 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:9, LSP not signalled, has no S2Ls Sep 15 03:32:03.886 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:1, Holddown:0 Sep 15 03:32:03.887 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:20, POType:1, ComputationType:1, Holddown:0 Sep 15 03:32:03.887 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, working-reopt initiated: trigger: FRR, reason: recovery from FRR Sep 15 03:32:03.887 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:9, recovery from FRR Sep 15 03:32:06.197 mpls_te/head-end 0/RP0/CPU0 t4602 Type:p2p, head, REOPT, T:0, L:9, S:22.22.22.22, E:22.22.22.22, D:11.11.11.11, [REOPT] S2L path verify failed Sep 15 03:32:34.379 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:1, Holddown:0 Sep 15 03:32:34.379 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:20, POType:1, ComputationType:1, Holddown:0 Sep 15 03:32:34.379 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, working-reopt initiated: trigger: FRR, reason: recovery from FRR Sep 15 03:32:34.379 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:10, recovery from FRR Sep 15 03:32:34.569 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, started install timer:20 secs, 100 msec, [CURRENT] L:8, [REOPT] L:10 Sep 15 03:32:54.669 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Timer[0] expired; install RW for [REOPT] L:10 and start cleanup timer:20 secs Sep 15 03:32:54.670 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:10, TE rewrite returned TRUE Sep 15 03:32:54.672 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:10, ifh:0x1c, TE rewrite returned TRUE Sep 15 03:33:14.772 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, cleanup timer expired; destroying [CLEAN] L:8 Sep 15 03:41:35.040 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, L:10, LL:24016, TE rewrite delete queueing succeeded Sep 15 03:41:35.040 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IFH:0x01C, moving state to down Sep 15 03:41:35.040 mpls_te/head-end 0/RP0/CPU0 t4602 Removed tunnel T:0, D:11.11.11.11 from autoroute list for IGP: OSPF, area 0 Sep 15 03:41:35.040 mpls_te/head-end 0/RP0/CPU0 t4602 Unknown (ifhndl 0x1c) : queued IM dest update: 0.0.0.0 Sep 15 03:41:35.041 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op STATE UPDATE with 1 items Sep 15 03:41:35.043 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op STATE UPDATE for Unknown (ifhndl 0x1c) Sep 15 03:41:35.043 mpls_te/head-end 0/RP0/CPU0 t4602 Sent autoroute-announce tunnel list for 11.11.11.11 to IGP: OSPF, area 0: 0 tunnels Sep 15 03:41:35.043 mpls_te/head-end 0/RP0/CPU0 t4602 Deleted autoroute entry 11.11.11.11, area 2 0; total AA entries 0 Sep 15 03:41:35.046 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_CHECK Sep 15 03:41:35.046 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_MODIFY_IN_PLACE Sep 15 03:41:35.046 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_MODIFY_IN_PLACE Sep 15 03:41:35.129 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM interface delete operation queued Sep 15 03:41:35.129 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op IF DELETE with 1 items Sep 15 03:41:35.221 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op IF DELETE for Unknown (ifhndl 0x1c) Sep 15 03:41:35.221 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, deleted; new tunnel count = 0 Sep 15 03:41:35.312 mpls_te/head-end 0/RP0/CPU0 t4602 ifh:0x1c, NOTFN DELETE; caps ipv4; proto ipv4; Sep 15 03:41:35.312 mpls_te/head-end 0/RP0/CPU0 t4602 Unable to find tunnel with handle: ifh 0x1c Sep 15 03:51:41.422 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Start sync retry timer Sep 15 03:51:41.422 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op IF CREATE with 1 items Sep 15 03:51:41.428 mpls_te/head-end 0/RP0/CPU0 t4602 ifh:0x24, NOTFN INITIAL; caps ; proto NONE; state not ready Sep 15 03:51:41.428 mpls_te/head-end 0/RP0/CPU0 t4602 ifh:0x24, NOTFN INITIAL; caps mpls_te; proto NONE; state not ready Sep 15 03:51:41.429 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op CAPS ADD with 1 items Sep 15 03:51:41.430 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, ifh:0x24, NOTFN STATE, caps ; proto NONE; state down Sep 15 03:51:41.430 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op STATE UPDATE with 1 items Sep 15 03:51:41.432 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op STATE UPDATE for Unknown (ifhndl 0x24) Sep 15 03:51:41.433 mpls_te/head-end 0/RP0/CPU0 t4602 ifh:0x24, NOTFN INITIAL; caps mpls; proto mpls; state not ready Sep 15 03:51:41.433 mpls_te/head-end 0/RP0/CPU0 t4602 ifh:0x24, NOTFN MTU; caps mpls; proto mpls; mtu 1500 Sep 15 03:51:41.434 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op CAPS ADD for Unknown (ifhndl 0x24) Sep 15 03:51:41.434 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op CAPS ADD with 1 items Sep 15 03:51:41.434 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op MTU UPDATE with 1 items Sep 15 03:51:41.434 mpls_te/head-end 0/RP0/CPU0 t4602 ifh:0x24, NOTFN CREATE; caps ipv4; proto ipv4; Sep 15 03:51:41.434 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IP address is now available Sep 15 03:51:41.434 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_CHECK Sep 15 03:51:41.525 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op CAPS ADD for Unknown (ifhndl 0x24) Sep 15 03:51:41.717 mpls_te/head-end 0/RP0/CPU0 t4602 Unknown (ifhndl 0x24) : queued IM dest update: 11.11.11.11 Sep 15 03:51:41.717 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Send IM attribute: old dest = 0.0.0.0, new dest = 11.11.11.11 Sep 15 03:51:41.718 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Start sync retry timer Sep 15 03:51:41.718 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Start sync retry timer Sep 15 03:51:41.718 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:0, Holddown:0 Sep 15 03:51:41.718 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Start sync retry timer Sep 15 03:51:41.718 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, L:2, LL:1048577, TE rewrite delete queueing succeeded Sep 15 03:51:41.718 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IFH:0x024, moving state to down Sep 15 03:51:41.718 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:0, Holddown:0 Sep 15 03:51:41.720 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_CHECK Sep 15 03:51:41.720 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_MODIFY_IN_PLACE Sep 15 03:51:41.720 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_MODIFY_IN_PLACE Sep 15 03:51:41.722 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op STATE UPDATE with 1 items Sep 15 03:51:41.722 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op STATE UPDATE for Unknown (ifhndl 0x24) Sep 15 03:51:41.817 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, L:3, LL:24017, TE rewrite queueing succeeded Sep 15 03:51:41.818 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [CURRENT] L:3, ifh:0x24, TE rewrite returned TRUE Sep 15 03:51:41.818 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IFH:0x024, moving state to up Sep 15 03:51:41.818 mpls_te/head-end 0/RP0/CPU0 t4602 Created autoroute entry 11.11.11.11, area 2 0; total AA entries 1 Sep 15 03:51:41.818 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, added AA, D:11.11.11.11, IGP: 2, area 0 Sep 15 03:51:41.818 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op STATE UPDATE with 1 items Sep 15 03:51:41.819 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op STATE UPDATE for Unknown (ifhndl 0x24) Sep 15 03:51:41.819 mpls_te/head-end 0/RP0/CPU0 t4602 Sent autoroute-announce tunnel list for 11.11.11.11 to IGP: OSPF, area 0: 1 tunnels Sep 15 03:51:42.422 mpls_te/head-end 0/RP0/CPU0 t4602 Validating ifindexes for all vifs Sep 15 03:51:42.422 mpls_te/head-end 0/RP0/CPU0 t4602 Bulk ifindex lookup for 1 vifs Sep 15 03:51:42.424 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, ifindex set to 9 Sep 15 03:51:56.719 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Sync retry timer expired Sep 15 04:22:20.458 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, L:3, LL:24017, TE rewrite delete queueing succeeded Sep 15 04:22:20.458 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IFH:0x024, moving state to down Sep 15 04:22:20.458 mpls_te/head-end 0/RP0/CPU0 t4602 Removed tunnel T:0, D:11.11.11.11 from autoroute list for IGP: OSPF, area 0 Sep 15 04:22:20.458 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_CHECK Sep 15 04:22:20.459 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:0, Holddown:0 Sep 15 04:22:20.459 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:20, POType:1, ComputationType:0, Holddown:0 Sep 15 04:22:20.459 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op STATE UPDATE with 1 items Sep 15 04:22:20.463 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op STATE UPDATE for Unknown (ifhndl 0x24) Sep 15 04:22:20.463 mpls_te/head-end 0/RP0/CPU0 t4602 Sent autoroute-announce tunnel list for 11.11.11.11 to IGP: OSPF, area 0: 0 tunnels Sep 15 04:22:20.463 mpls_te/head-end 0/RP0/CPU0 t4602 Deleted autoroute entry 11.11.11.11, area 2 0; total AA entries 0 Sep 15 04:22:20.719 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, L:4, LL:24017, TE rewrite queueing succeeded Sep 15 04:22:20.720 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [CURRENT] L:4, ifh:0x24, TE rewrite returned TRUE Sep 15 04:22:20.720 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IFH:0x024, moving state to up Sep 15 04:22:20.720 mpls_te/head-end 0/RP0/CPU0 t4602 Created autoroute entry 11.11.11.11, area 2 0; total AA entries 1 Sep 15 04:22:20.720 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, added AA, D:11.11.11.11, IGP: 2, area 0 Sep 15 04:22:20.720 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op STATE UPDATE with 1 items Sep 15 04:22:20.721 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op STATE UPDATE for Unknown (ifhndl 0x24) Sep 15 04:22:20.721 mpls_te/head-end 0/RP0/CPU0 t4602 Sent autoroute-announce tunnel list for 11.11.11.11 to IGP: OSPF, area 0: 1 tunnels Sep 15 04:28:37.222 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Reoptimizing due to different generation, tunnel gen=0, current gen=56 Sep 15 04:28:37.222 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:1, Holddown:0 Sep 15 04:28:37.222 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:20, POType:1, ComputationType:1, Holddown:0 Sep 15 04:28:37.223 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:5, LSP not signalled, identical to the [CURRENT] LSP Sep 15 04:28:39.228 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACTION_REOPTIMIZE_PCE Sep 15 04:28:39.228 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:1, Holddown:0 Sep 15 04:28:39.228 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:20, POType:1, ComputationType:1, Holddown:0 Sep 15 04:28:39.228 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:5, LSP not signalled, identical to the [CURRENT] LSP Sep 15 04:33:08.638 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACTION_REOPTIMIZE_CLI Sep 15 04:33:08.638 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:1, Holddown:0 Sep 15 04:33:08.639 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, working-reopt initiated: trigger: CLI request, reason: better path option indices Sep 15 04:33:08.639 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:5, better path option indices Sep 15 04:33:08.736 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, started install timer:20 secs, 100 msec, [CURRENT] L:4, [REOPT] L:5 Sep 15 04:33:28.836 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Timer[0] expired; install RW for [REOPT] L:5 and start cleanup timer:20 secs Sep 15 04:33:28.836 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:5, TE rewrite returned TRUE Sep 15 04:33:28.838 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:5, ifh:0x24, TE rewrite returned TRUE Sep 15 04:33:48.938 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, cleanup timer expired; destroying [CLEAN] L:4 Sep 15 04:41:05.069 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACTION_REOPTIMIZE_FRR Sep 15 04:41:05.069 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:10, POType:2, ComputationType:1, Holddown:0 Sep 15 04:41:05.070 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, POIndex:20, POType:1, ComputationType:1, Holddown:0 Sep 15 04:41:05.070 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, working-reopt initiated: trigger: FRR, reason: recovery from FRR Sep 15 04:41:05.070 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:6, recovery from FRR Sep 15 04:41:05.430 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, started install timer:20 secs, 100 msec, [CURRENT] L:5, [REOPT] L:6 Sep 15 04:41:25.530 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, Timer[0] expired; install RW for [REOPT] L:6 and start cleanup timer:20 secs Sep 15 04:41:25.530 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:6, TE rewrite returned TRUE Sep 15 04:41:25.531 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, [REOPT] L:6, ifh:0x24, TE rewrite returned TRUE Sep 15 04:41:45.633 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, cleanup timer expired; destroying [CLEAN] L:5 Sep 15 04:49:34.013 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, L:6, LL:24017, TE rewrite delete queueing succeeded Sep 15 04:49:34.013 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IFH:0x024, moving state to down Sep 15 04:49:34.013 mpls_te/head-end 0/RP0/CPU0 t4602 Removed tunnel T:0, D:11.11.11.11 from autoroute list for IGP: OSPF, area 0 Sep 15 04:49:34.013 mpls_te/head-end 0/RP0/CPU0 t4602 Unknown (ifhndl 0x24) : queued IM dest update: 0.0.0.0 Sep 15 04:49:34.015 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op STATE UPDATE with 1 items Sep 15 04:49:34.017 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op STATE UPDATE for Unknown (ifhndl 0x24) Sep 15 04:49:34.017 mpls_te/head-end 0/RP0/CPU0 t4602 Sent autoroute-announce tunnel list for 11.11.11.11 to IGP: OSPF, area 0: 0 tunnels Sep 15 04:49:34.017 mpls_te/head-end 0/RP0/CPU0 t4602 Deleted autoroute entry 11.11.11.11, area 2 0; total AA entries 0 Sep 15 04:49:34.019 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_CHECK Sep 15 04:49:34.019 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_MODIFY_IN_PLACE Sep 15 04:49:34.019 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, handling vif (0x31ea1d38) scheduled action ACT_MODIFY_IN_PLACE Sep 15 04:49:34.118 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM interface delete operation queued Sep 15 04:49:34.118 mpls_te/head-end 0/RP0/CPU0 t4602 Batch op IF DELETE with 1 items Sep 15 04:49:34.212 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, IM op IF DELETE for Unknown (ifhndl 0x24) Sep 15 04:49:34.212 mpls_te/head-end 0/RP0/CPU0 t4602 T:0, Type:TE, deleted; new tunnel count = 0 Sep 15 04:49:34.214 mpls_te/head-end 0/RP0/CPU0 t4602 ifh:0x24, NOTFN DELETE; caps ipv4; proto ipv4; Sep 15 04:49:34.214 mpls_te/head-end 0/RP0/CPU0 t4602 Unable to find tunnel with handle: ifh 0x24 RP/0/RP0/CPU0:PE2#show mpls traffic-eng trace link Tue Sep 15 04:57:12.365 UTC 132 wrapping entries (67648 possible, 320 allocated, 0 filtered, 132 total) Sep 15 02:28:37.222 mpls_te/link 0/RP0/CPU0 t4602 DS-TE mode change: prev - 0, new - 1 Sep 15 02:28:37.222 mpls_te/link 0/RP0/CPU0 t4602 TE process restarting; aborting DS-TE mode change Sep 15 02:28:38.724 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:381: lm_iarm_control_cb_fn: connection to IARM established. Sep 15 02:28:40.939 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:1534: mpls_lcac_ifrs_add: Added new IFRS entry Sep 15 02:28:40.939 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:1128: rrr_lm_list_link: Inserted link GigabitEthernet0/0/0/0 (ifh 0x10) into db based on name and handle Sep 15 02:28:40.940 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/0 (ifh 0x10), flood 0, force 0, Nbr cnt 0 Sep 15 02:28:40.940 mpls_te/link 0/RP0/CPU0 t4602 RSI: Registering interface GigabitEthernet0/0/0/0 (ifhndl 0x10) (0x10) for SRLG Notification Sep 15 02:28:40.940 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:2544: rrr_lm_create_link: link GigabitEthernet0/0/0/0 (ifh 0x10) Created [1 links total], enable 0 Sep 15 02:28:40.941 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_idb_capacity: link GigabitEthernet0/0/0/0 (ifh 0x10) BW attribute 0 kbps Sep 15 02:28:40.941 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_link_capacity: link GigabitEthernet0/0/0/0 (ifh 0x10) physical_bw 125000000 Bps Sep 15 02:28:40.945 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/0 (ifh 0x10) max_bw 1000000 (Kbps), pool0_bw 1000000 (Kbps) Sep 15 02:28:40.945 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/0 (ifh 0x10) pool1_bw 0 (Kbps) Sep 15 02:28:40.945 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/0 (ifh 0x10), max_res_bw 1000000 (Kbps), Old max_res_bw 0 (Kbps), IP addr 0.0.0.0 Sep 15 02:28:40.945 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/0 (ifh 0x10), Pool0* max_bw 1000000 (Kbps), Old max_bw 0 (Kbps), IP addr 0.0.0.0 Sep 15 02:28:40.945 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/0 (ifh 0x10), max_res_bw 1000000 (Kbps), Old max_res_bw 0 (Kbps), IP addr 0.0.0.0 Sep 15 02:28:40.945 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/0 (ifh 0x10), Pool0* max_bw 1000000 (Kbps), Old max_bw 0 (Kbps), IP addr 0.0.0.0 Sep 15 02:28:40.945 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:518: Bandwidth update handling ignored, link GigabitEthernet0/0/0/0 (ifh 0x10) state down Sep 15 02:28:40.948 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:741: lm_iarm_reg_ipv4_add: added IPv4 register(True) request for interface GigabitEthernet0/0/0/0 (ifh 0x10) to IARM batch Sep 15 02:28:40.948 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:756: lm_iarm_reg_ipv4_add: sent pulse (0) to flush IARM IPv4 registration batch. Sep 15 02:28:40.951 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3722: lm_im_handler: link GigabitEthernet0/0/0/0 (ifh 0x10), state 17, proto 0, opcode 35 (CREATE/DEL) Sep 15 02:28:40.951 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3727: lm_im_handler: link GigabitEthernet0/0/0/0 (ifh 0x10), intf_type 15, parent i/f None (ifh 0x0), caps 0 Sep 15 02:28:40.951 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3808: lm_im_handler: IM_CREATE: link GigabitEthernet0/0/0/0 (ifh 0x10), state 17, proto 0, opcode 35 Sep 15 02:28:40.951 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3881: lm_im_handler: Updating link GigabitEthernet0/0/0/0 (ifh 0x10), intf_type 15, data_parent i/f None (ifh 0x0) (IM_CREATE) Sep 15 02:28:40.951 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_idb_capacity: link GigabitEthernet0/0/0/0 (ifh 0x10) BW attribute 0 kbps Sep 15 02:28:40.951 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_link_capacity: link GigabitEthernet0/0/0/0 (ifh 0x10) physical_bw 125000000 Bps Sep 15 02:28:40.951 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/0 (ifh 0x10) max_bw 1000000 (Kbps), pool0_bw 1000000 (Kbps) Sep 15 02:28:40.951 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/0 (ifh 0x10) pool1_bw 0 (Kbps) Sep 15 02:28:40.951 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/0 (ifh 0x10) max_bw 0 (Kbps), pool0_bw 0 (Kbps) Sep 15 02:28:40.951 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/0 (ifh 0x10) pool1_bw 0 (Kbps) Sep 15 02:28:40.951 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:5281: Flooding on link GigabitEthernet0/0/0/0 (ifh 0x10) suppressed, system not ready Sep 15 02:28:40.952 mpls_te/link 0/RP0/CPU0 t4602 RSI: Synchronous batch handler: 1 items Sep 15 02:28:40.952 mpls_te/link 0/RP0/CPU0 t4602 RSI: Event Update with 0 SRLG values for GigabitEthernet0/0/0/0 (ifhndl 0x10) (0x10) [change: NO, old count 0] Sep 15 02:28:40.952 mpls_te/link 0/RP0/CPU0 t4602 RSI: Sent registration for 1 interfaces (Success 1, failure 0) Sep 15 02:28:40.952 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_im_attr_capacity_handler: link MgmtEth0/RP0/CPU0/0 (ifh 0x8),bw 1000000 (kbps), bw2 125000000 (Bps), event 0 Sep 15 02:28:40.953 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_im_attr_capacity_handler: link GigabitEthernet0/0/0/0 (ifh 0x10),bw 1000000 (kbps), bw2 125000000 (Bps), event 0 Sep 15 02:28:40.953 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_process_link_capacity(): capacity not changed link GigabitEthernet0/0/0/0 (ifh 0x10), current bw 125000000 (Kbps), new bw 125000000 (Kbps) Sep 15 02:28:40.953 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/0 (ifh 0x10) max_bw 1000000 (Kbps), pool0_bw 1000000 (Kbps) Sep 15 02:28:40.953 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/0 (ifh 0x10) pool1_bw 0 (Kbps) Sep 15 02:28:40.953 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/0 (ifh 0x10) max_bw 0 (Kbps), pool0_bw 0 (Kbps) Sep 15 02:28:40.953 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/0 (ifh 0x10) pool1_bw 0 (Kbps) Sep 15 02:28:40.953 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_im_attr_capacity_handler: link GigabitEthernet0/0/0/1 (ifh 0x18),bw 1000000 (kbps), bw2 125000000 (Bps), event 0 Sep 15 02:28:40.953 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_im_attr_capacity_handler: link GigabitEthernet0/0/0/2 (ifh 0x20),bw 1000000 (kbps), bw2 125000000 (Bps), event 0 Sep 15 02:28:40.953 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_im_attr_capacity_handler: link GigabitEthernet0/0/0/3 (ifh 0x28),bw 1000000 (kbps), bw2 125000000 (Bps), event 0 Sep 15 02:28:40.953 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:279: lm_iarm_handle_pulse: received pulse (0), flushing IARM IPv4 registration batch. Sep 15 02:28:40.954 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:623: lm_iarm_flush: sent 1 IPv4 (un)register requests to IARM. Sep 15 02:28:41.312 mpls_te/link 0/RP0/CPU0 t4602 SRLG-producer connected Sep 15 02:28:41.313 mpls_te/link 0/RP0/CPU0 t4602 RSI SRLG-producer registration done successfully Sep 15 02:28:41.313 mpls_te/link 0/RP0/CPU0 t4602 Replaying learned SRLGs on all links to RSI Sep 15 02:28:41.313 mpls_te/link 0/RP0/CPU0 t4602 Replaying learned SRLGs on all termination interfaces to RSI Sep 15 02:28:41.940 mpls_te/link 0/RP0/CPU0 t4602 Validating ifindexes for all links Sep 15 02:28:41.940 mpls_te/link 0/RP0/CPU0 t4602 Bulk ifindex lookup for 1 links Sep 15 02:28:42.010 mpls_te/link 0/RP0/CPU0 t4602 Link GigabitEthernet0/0/0/0 (ifhndl 0x10) (0x10) ifindex set to 4 Sep 15 02:28:42.010 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/0 (ifh 0x10), flood 0, force 1, Nbr cnt 0 Sep 15 02:28:42.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:119: Unable to process adj-change from IGP OSPFarea 0 on link Loopback0 (ifh 0x14) with handle 0x14, reverting to name Sep 15 02:28:42.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:145: Unable to process adj-change from IGP OSPF area 0 on link Loopback0 (ifh 0x14) (0 nbrs): link not found Sep 15 02:28:44.510 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:2611: Handling area change: IGP OSPF area 0, is_up = 1, router-id 22.22.22.22 Sep 15 02:28:44.510 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/0 (ifh 0x10), flood 0, force 0, Nbr cnt 0 Sep 15 02:28:44.510 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:5406: Periodic Flooding for igp-type: 2 area: 0 0 seconds Sep 15 02:28:44.510 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:5214: System change: flooding to all links/areas: reason area state change Sep 15 02:28:47.522 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3722: lm_im_handler: link GigabitEthernet0/0/0/0 (ifh 0x10), state 17, proto 12, opcode 35 (CREATE/DEL) Sep 15 02:28:47.522 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3727: lm_im_handler: link GigabitEthernet0/0/0/0 (ifh 0x10), intf_type 15, parent i/f None (ifh 0x0), caps 26 Sep 15 02:28:47.522 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3808: lm_im_handler: IM_CREATE: link GigabitEthernet0/0/0/0 (ifh 0x10), state 17, proto 12, opcode 35 Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:875: mpls_lcac_if_state_register: link GigabitEthernet0/0/0/0 (ifh 0x10), add True Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:741: lm_iarm_reg_ipv4_add: added IPv4 register(True) request for interface GigabitEthernet0/0/0/0 (ifh 0x10) to IARM batch Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:756: lm_iarm_reg_ipv4_add: sent pulse (0) to flush IARM IPv4 registration batch. Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3881: lm_im_handler: Updating link GigabitEthernet0/0/0/0 (ifh 0x10), intf_type 15, data_parent i/f None (ifh 0x0) (IM_CREATE) Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_idb_capacity: link GigabitEthernet0/0/0/0 (ifh 0x10) BW attribute 0 kbps Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_link_capacity: link GigabitEthernet0/0/0/0 (ifh 0x10) physical_bw 125000000 Bps Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/0 (ifh 0x10) max_bw 1000000 (Kbps), pool0_bw 1000000 (Kbps) Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/0 (ifh 0x10) pool1_bw 0 (Kbps) Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/0 (ifh 0x10) max_bw 0 (Kbps), pool0_bw 0 (Kbps) Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/0 (ifh 0x10) pool1_bw 0 (Kbps) Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:5304: Flooding on link GigabitEthernet0/0/0/0 (ifh 0x10) suppressed, no change Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3700: lm_im_handler: link GigabitEthernet0/0/0/0 (ifh 0x10), state 1, proto 12, caps 26, opcode=STATE_VALUE Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3765: lm_im_handler: IFSTATE_VAL: link GigabitEthernet0/0/0/0 (ifh 0x10), state 1, proto 12, opcode 37 Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:279: lm_iarm_handle_pulse: received pulse (0), flushing IARM IPv4 registration batch. Sep 15 02:28:47.524 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:623: lm_iarm_flush: sent 1 IPv4 (un)register requests to IARM. Sep 15 02:28:47.622 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:797: lm_ipv4_addr_callback: link GigabitEthernet0/0/0/0 (ifh 0x10), ct=0x0, ps=0x0, addr 10.3.22.22 Sep 15 02:28:48.319 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3700: lm_im_handler: link GigabitEthernet0/0/0/0 (ifh 0x10), state 2, proto 12, caps 26, opcode=STATE_VALUE Sep 15 02:28:48.319 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3765: lm_im_handler: IFSTATE_VAL: link GigabitEthernet0/0/0/0 (ifh 0x10), state 2, proto 12, opcode 37 Sep 15 02:28:48.623 mpls_te/link 0/RP0/CPU0 t4602 Validating ifindexes for all links Sep 15 02:28:48.625 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3700: lm_im_handler: link GigabitEthernet0/0/0/0 (ifh 0x10), state 3, proto 12, caps 26, opcode=STATE_VALUE Sep 15 02:28:48.625 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3765: lm_im_handler: IFSTATE_VAL: link GigabitEthernet0/0/0/0 (ifh 0x10), state 3, proto 12, opcode 37 Sep 15 02:28:48.625 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/0 (ifh 0x10), flood 0, force 0, Nbr cnt 0 Sep 15 02:28:48.625 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:5494: Request link adjacencies for link GigabitEthernet0/0/0/0 (ifh 0x10), area 0, IGP OSPF Sep 15 02:28:48.719 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:2565: Processing adj-change for link GigabitEthernet0/0/0/0 (ifh 0x10) (0 nbrs) in area 0, IGP OSPF Sep 15 02:28:48.719 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:2451: rrr_lm_handle_igp_link_info_change: OSPF- link GigabitEthernet0/0/0/0 (ifh 0x10), tot_nbrs 0, subnet type 0, flags 0x2 Sep 15 02:28:48.719 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:2471: rrr_lm_handle_igp_link_info_change: link GigabitEthernet0/0/0/0 (ifh 0x10) new igp admin weight 10, prev. isis wt 0, ospf wt 0 Sep 15 02:28:48.719 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:935: Link GigabitEthernet0/0/0/0 (ifh 0x10): Added area 0 IGP OSPF Sep 15 02:28:48.719 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:1019: Link GigabitEthernet0/0/0/0 (ifh 0x10): Update nbrs for area 0 IGP OSPF Sep 15 02:28:48.719 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:1345: setting IGP cost for link GigabitEthernet0/0/0/0 (ifh 0x10), area 0, protocol OSPF, weight 10 Sep 15 02:28:48.719 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:2523: link GigabitEthernet0/0/0/0 (ifh 0x10), IGP OSPF area 0: no neighbor changes Sep 15 02:28:48.719 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:5295: Flooding on link GigabitEthernet0/0/0/0 (ifh 0x10) data changed Sep 15 02:28:48.719 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:2565: Processing adj-change for link GigabitEthernet0/0/0/0 (ifh 0x10) (0 nbrs) in area 0, IGP OSPF Sep 15 02:28:48.719 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:2451: rrr_lm_handle_igp_link_info_change: OSPF- link GigabitEthernet0/0/0/0 (ifh 0x10), tot_nbrs 0, subnet type 0, flags 0x2 Sep 15 02:28:48.719 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:2471: rrr_lm_handle_igp_link_info_change: link GigabitEthernet0/0/0/0 (ifh 0x10) new igp admin weight 10, prev. isis wt 0, ospf wt 0 Sep 15 02:28:48.719 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:2523: link GigabitEthernet0/0/0/0 (ifh 0x10), IGP OSPF area 0: no neighbor changes Sep 15 02:28:49.628 mpls_te/link 0/RP0/CPU0 t4602 Validating ifindexes for all links Sep 15 02:28:58.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:2565: Processing adj-change for link GigabitEthernet0/0/0/0 (ifh 0x10) (0 nbrs) in area 0, IGP OSPF Sep 15 02:28:58.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:2451: rrr_lm_handle_igp_link_info_change: OSPF- link GigabitEthernet0/0/0/0 (ifh 0x10), tot_nbrs 0, subnet type 1, flags 0xb Sep 15 02:28:58.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:1019: Link GigabitEthernet0/0/0/0 (ifh 0x10): Update nbrs for area 0 IGP OSPF Sep 15 02:28:58.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:1515: setting subnet type for link GigabitEthernet0/0/0/0 (ifh 0x10), area 0, protocol 2, subnet type 1 Sep 15 02:28:58.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:2471: rrr_lm_handle_igp_link_info_change: link GigabitEthernet0/0/0/0 (ifh 0x10) new igp admin weight 10, prev. isis wt 0, ospf wt 0 Sep 15 02:28:58.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:2498: Link GigabitEthernet0/0/0/0 (ifh 0x10): update DB for 1 neighbors Sep 15 02:28:58.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:1559: Received neighbor 10.3.22.3 on link GigabitEthernet0/0/0/0 (ifh 0x10), IGP OSPF area 0 Sep 15 02:28:58.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:1578: Rcvd nbr node ID 3.3.3.3, state 1 Sep 15 02:28:58.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:1596: Matching existing neighbor found? False Sep 15 02:28:58.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:1714: Neighbor unknown: creating new one Sep 15 02:28:58.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:1286: link GigabitEthernet0/0/0/0 (ifh 0x10): setting IGP cost: 10, in area 0, protocol OSPF Sep 15 02:28:58.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:1429: link GigabitEthernet0/0/0/0 (ifh 0x10), IGP OSPF area 0: subnet type changed to 1 Sep 15 02:28:58.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:1825: Neighbor created link GigabitEthernet0/0/0/0 (ifh 0x10) nbr addr 10.3.22.3, count 1, nbr state 1 Sep 15 02:28:58.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:5295: Flooding on link GigabitEthernet0/0/0/0 (ifh 0x10) data changed Sep 15 02:31:41.041 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:5471: Forced Flooding for IGP OSPF, area 0 Sep 15 02:34:06.612 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_im_attr_capacity_handler: link Unknown (ifh 0x1c),bw 0 (kbps), bw2 0 (Bps), event 0 Sep 15 02:34:06.710 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3722: lm_im_handler: link Unknown (ifh 0x1c), state 17, proto 12, opcode 35 (CREATE/DEL) Sep 15 02:34:06.710 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3727: lm_im_handler: link Unknown (ifh 0x1c), intf_type 36, parent i/f None (ifh 0x0), caps 26 Sep 15 02:34:06.711 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3808: lm_im_handler: IM_CREATE: link Unknown (ifh 0x1c), state 17, proto 12, opcode 35 Sep 15 02:42:03.276 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:18474: Link:10.1.2.2, IGP OSPF, area 0 helddown in topology for 10 secs (due to path error) Sep 15 03:06:40.099 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:18474: Link:10.2.3.2, IGP OSPF, area 0 helddown in topology for 10 secs (due to path error) Sep 15 03:32:03.488 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:18474: Link:10.3.22.3, IGP OSPF, area 0 helddown in topology for 10 secs (due to path error) Sep 15 03:41:35.312 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3722: lm_im_handler: link Unknown (ifh 0x1c), state 17, proto 12, opcode 36 (CREATE/DEL) Sep 15 03:41:35.312 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3727: lm_im_handler: link Unknown (ifh 0x1c), intf_type 36, parent i/f None (ifh 0x0), caps 26 Sep 15 03:41:35.312 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3939: lm_im_handler: IM_DEL: link Unknown (ifh 0x1c), state 17, proto 12, opcode 36 Sep 15 03:51:41.433 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK: rrr_lm_im_attr_capacity_handler: link Unknown (ifh 0x24),bw 0 (kbps), bw2 0 (Bps), event 0 Sep 15 03:51:41.434 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3722: lm_im_handler: link Unknown (ifh 0x24), state 17, proto 12, opcode 35 (CREATE/DEL) Sep 15 03:51:41.434 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3727: lm_im_handler: link Unknown (ifh 0x24), intf_type 36, parent i/f None (ifh 0x0), caps 26 Sep 15 03:51:41.434 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3808: lm_im_handler: IM_CREATE: link Unknown (ifh 0x24), state 17, proto 12, opcode 35 Sep 15 04:22:20.458 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:18474: Link:10.1.2.2, IGP OSPF, area 0 helddown in topology for 10 secs (due to path error) Sep 15 04:41:05.069 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:18474: Link:10.2.3.2, IGP OSPF, area 0 helddown in topology for 10 secs (due to path error) Sep 15 04:49:34.214 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3722: lm_im_handler: link Unknown (ifh 0x24), state 17, proto 12, opcode 36 (CREATE/DEL) Sep 15 04:49:34.214 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3727: lm_im_handler: link Unknown (ifh 0x24), intf_type 36, parent i/f None (ifh 0x0), caps 26 Sep 15 04:49:34.214 mpls_te/link 0/RP0/CPU0 t4602 LM_LINK:3939: lm_im_handler: IM_DEL: link Unknown (ifh 0x24), state 17, proto 12, opcode 36 RP/0/RP0/CPU0:PE2#show mpls traffic-eng trace bselect Tue Sep 15 04:57:12.563 UTC 170 wrapping entries (67648 possible, 320 allocated, 0 filtered, 170 total) Sep 15 02:28:44.517 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.610 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.610 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.611 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.611 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.611 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.611 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.611 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.611 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.611 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.611 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.611 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.611 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.611 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.611 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.612 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.612 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.612 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.612 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.612 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.612 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.613 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.613 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.618 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.967 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:28:58.967 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:31:11.320 mpls_te/bselect 0/RP0/CPU0 t4602 tebm_verify_bkup_db: Verifying existing bkup data Sep 15 02:42:03.276 mpls_te/bselect 0/RP0/CPU0 t4602 frr_event_lsp_down: T:0, L:3, prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , NH:10.3.22.3 Sep 15 02:49:36.068 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:49:36.101 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 02:51:15.832 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6987: frr_event_reroute_added: T:0, L:4, prot_des 0, NH:10.3.22.3 Sep 15 02:51:15.832 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:4 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 02:51:15.832 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6883: te_frr_add_new_plsp: adding T:0, in no_bkup Sep 15 02:51:15.832 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 02:51:54.331 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:5, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 02:51:54.331 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:5 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 02:51:54.331 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6883: te_frr_add_new_plsp: adding T:0, in no_bkup Sep 15 02:51:54.331 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 02:51:54.331 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:5, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 02:51:54.331 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:5 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 02:51:54.331 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6818: te_frr_add_new_plsp: T:0, is already in nobackup database Sep 15 02:51:54.331 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 02:52:34.536 mpls_te/bselect 0/RP0/CPU0 t4602 frr_event_lsp_down: T:0, L:4, prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , NH:10.3.22.3 Sep 15 02:54:46.102 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 02:54:46.102 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4296: frr_event_promote_intf_plsp: All intf processed: promotion complete .. Sep 15 02:59:46.102 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 02:59:50.568 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7331: frr_event_rro_changed: T:0, L:5, prot_if GigabitEthernet0/0/0/0 (ifh 0x10), NH:10.3.22.3 Sep 15 02:59:50.569 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 03:04:46.102 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 03:06:40.263 mpls_te/bselect 0/RP0/CPU0 t4602 frr_event_lsp_down: T:0, L:6, prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , NH:10.3.22.3 Sep 15 03:06:43.468 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:7, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 03:06:43.468 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:7 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 03:06:43.468 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6883: te_frr_add_new_plsp: adding T:0, in no_bkup Sep 15 03:06:43.468 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 03:06:43.468 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:7, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 03:06:43.468 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:7 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 03:06:43.468 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6818: te_frr_add_new_plsp: T:0, is already in nobackup database Sep 15 03:06:43.468 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 03:06:47.894 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7331: frr_event_rro_changed: T:0, L:5, prot_if GigabitEthernet0/0/0/0 (ifh 0x10), NH:10.3.22.3 Sep 15 03:06:47.894 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 03:07:23.671 mpls_te/bselect 0/RP0/CPU0 t4602 frr_event_lsp_down: T:0, L:5, prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , NH:10.3.22.3 Sep 15 03:09:46.103 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 03:14:46.103 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 03:15:44.915 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 03:15:44.947 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 03:15:54.947 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 03:15:54.947 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4296: frr_event_promote_intf_plsp: All intf processed: promotion complete .. Sep 15 03:17:20.511 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:8, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 03:17:20.511 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:8 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 03:17:20.511 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6883: te_frr_add_new_plsp: adding T:0, in no_bkup Sep 15 03:17:20.511 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 03:17:20.511 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:8, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 03:17:20.511 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:8 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 03:17:20.511 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6818: te_frr_add_new_plsp: T:0, is already in nobackup database Sep 15 03:17:20.511 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 03:18:00.715 mpls_te/bselect 0/RP0/CPU0 t4602 frr_event_lsp_down: T:0, L:7, prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , NH:10.3.22.3 Sep 15 03:20:54.948 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 03:24:56.809 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7331: frr_event_rro_changed: T:0, L:8, prot_if GigabitEthernet0/0/0/0 (ifh 0x10), NH:10.3.22.3 Sep 15 03:24:56.809 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 03:25:54.948 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 03:30:54.948 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 03:32:06.198 mpls_te/bselect 0/RP0/CPU0 t4602 frr_event_lsp_down: T:0, L:9, prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , NH:10.3.22.3 Sep 15 03:32:08.989 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7331: frr_event_rro_changed: T:0, L:8, prot_if GigabitEthernet0/0/0/0 (ifh 0x10), NH:10.3.22.3 Sep 15 03:32:08.989 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 03:32:34.567 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:10, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 03:32:34.567 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:10 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 03:32:34.567 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6883: te_frr_add_new_plsp: adding T:0, in no_bkup Sep 15 03:32:34.567 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 03:32:34.567 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:10, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 03:32:34.567 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:10 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 03:32:34.567 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6818: te_frr_add_new_plsp: T:0, is already in nobackup database Sep 15 03:32:34.567 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 03:33:14.773 mpls_te/bselect 0/RP0/CPU0 t4602 frr_event_lsp_down: T:0, L:8, prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , NH:10.3.22.3 Sep 15 03:35:54.948 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 03:39:24.495 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 03:39:24.672 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 03:39:24.672 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 03:39:32.208 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 03:39:32.241 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 03:39:41.956 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 03:39:41.956 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 03:39:51.956 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 03:39:51.956 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4296: frr_event_promote_intf_plsp: All intf processed: promotion complete .. Sep 15 03:41:35.044 mpls_te/bselect 0/RP0/CPU0 t4602 frr_event_lsp_down: T:0, L:10, prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , NH:10.3.22.3 Sep 15 03:44:51.957 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 03:49:51.957 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 03:51:41.815 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:3, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 03:51:41.815 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:3 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 03:51:41.815 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6883: te_frr_add_new_plsp: adding T:0, in no_bkup Sep 15 03:51:41.815 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 03:51:41.815 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:3, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 03:51:41.815 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:3 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 03:51:41.815 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6818: te_frr_add_new_plsp: T:0, is already in nobackup database Sep 15 03:51:41.815 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 03:54:51.957 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 03:59:51.958 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 04:00:39.912 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7331: frr_event_rro_changed: T:0, L:3, prot_if GigabitEthernet0/0/0/0 (ifh 0x10), NH:10.3.22.3 Sep 15 04:00:39.912 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 04:04:51.958 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 04:09:51.958 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 04:14:51.959 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 04:19:51.959 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 04:22:20.458 mpls_te/bselect 0/RP0/CPU0 t4602 frr_event_lsp_down: T:0, L:3, prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , NH:10.3.22.3 Sep 15 04:22:20.717 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:4, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 04:22:20.717 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:4 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 04:22:20.717 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6883: te_frr_add_new_plsp: adding T:0, in no_bkup Sep 15 04:22:20.717 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 04:22:20.718 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:4, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 04:22:20.718 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:4 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 04:22:20.718 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6818: te_frr_add_new_plsp: T:0, is already in nobackup database Sep 15 04:22:20.718 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 04:24:51.959 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 04:29:51.960 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 04:30:55.967 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 04:30:55.999 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 04:30:56.885 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 04:30:56.885 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 04:31:06.885 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 04:31:06.885 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4296: frr_event_promote_intf_plsp: All intf processed: promotion complete .. Sep 15 04:33:08.735 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:5, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 04:33:08.735 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:5 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 04:33:08.735 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6883: te_frr_add_new_plsp: adding T:0, in no_bkup Sep 15 04:33:08.735 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 04:33:08.735 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:5, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 04:33:08.735 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:5 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 04:33:08.735 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6818: te_frr_add_new_plsp: T:0, is already in nobackup database Sep 15 04:33:08.735 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 04:33:48.939 mpls_te/bselect 0/RP0/CPU0 t4602 frr_event_lsp_down: T:0, L:4, prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , NH:10.3.22.3 Sep 15 04:36:06.885 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 04:41:05.428 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:6, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 04:41:05.428 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:6 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 04:41:05.428 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6883: te_frr_add_new_plsp: adding T:0, in no_bkup Sep 15 04:41:05.428 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 04:41:05.428 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7058: frr_event_resv_arrive: T:0, L:6, backup None (ifh 0x0), NH:10.3.22.3 Sep 15 04:41:05.428 mpls_te/bselect 0/RP0/CPU0 t4602 te_frr_add_new_plsp: T:0, L:6 prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , backup_if None (ifhndl 0x0) , protection None Sep 15 04:41:05.428 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:6818: te_frr_add_new_plsp: T:0, is already in nobackup database Sep 15 04:41:05.428 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 04:41:06.886 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 04:41:11.403 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7331: frr_event_rro_changed: T:0, L:5, prot_if GigabitEthernet0/0/0/0 (ifh 0x10), NH:10.3.22.3 Sep 15 04:41:11.403 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 04:41:45.633 mpls_te/bselect 0/RP0/CPU0 t4602 frr_event_lsp_down: T:0, L:5, prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , NH:10.3.22.3 Sep 15 04:46:06.886 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... Sep 15 04:49:11.100 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 04:49:11.132 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 04:49:11.677 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 04:49:11.710 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:7897: frr_plsp_promote_backup: cur promo timer 300, delay 10 sec, 0 ms Sep 15 04:49:21.710 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:3665: te_frr_find_backup: find backup bw 0, bw_type 2 Sep 15 04:49:21.710 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4296: frr_event_promote_intf_plsp: All intf processed: promotion complete .. Sep 15 04:49:34.018 mpls_te/bselect 0/RP0/CPU0 t4602 frr_event_lsp_down: T:0, L:6, prot_if GigabitEthernet0/0/0/0 (ifhndl 0x10) , NH:10.3.22.3 Sep 15 04:54:21.710 mpls_te/bselect 0/RP0/CPU0 t4602 FRR:4620: frr_event_promote_intf: All intf processed: promotion complete ...... RP/0/RP0/CPU0:PE2#show rsvp trace signalling Tue Sep 15 04:57:12.697 UTC 335 wrapping entries (264256 possible, 576 allocated, 0 filtered, 335 total) Sep 15 02:33:59.183 rsvp/sig 0/RP0/CPU0 t4435 SIG:4549: PATH creating network: GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 224, IP src: 11.11.11.11 IP dst: 22.22.22.22, psbs: 0, rsbs: 0 Sep 15 02:33:59.184 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:3) Sep 15 02:33:59.201 rsvp/sig 0/RP0/CPU0 t4435 SIG:4649: RESV creating tail: local/nbor (22.22.22.22/3.3.3.3), obj len: 80, None (ifh 0x0), psbs: 1, rsbs: 0 Sep 15 02:33:59.201 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xd0000005, psb flags: 0xc0000008, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 02:33:59.201 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:3) Sep 15 02:33:59.201 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:3) Sep 15 02:34:06.811 rsvp/sig 0/RP0/CPU0 t4435 SIG:4545: PATH creating head: local/nbor/nhop (22.22.22.22/3.3.3.3/10.3.22.3), GigabitEthernet0/0/0/0 (ifh 0x10), psbs: 0, rsbs: 0 Sep 15 02:34:06.812 rsvp/sig 0/RP0/CPU0 t4435 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:22.22.22.22, nbor:3.3.3.3, nhop:10.3.22.3, next_ifh:GigabitEthernet0/0/0/0 (ifh 0x10), obj_len: 0 Sep 15 02:34:06.812 rsvp/sig 0/RP0/CPU0 t4435 SIG:887: PATH Tunnel IPv4 outgoing: dst (11.11.11.11:0), src (22.22.22.22:3) Sep 15 02:34:06.812 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:3) Sep 15 02:34:06.911 rsvp/sig 0/RP0/CPU0 t4435 SIG:4654: RESV creating network: GigabitEthernet0/0/0/0 (ifh 0x10), in GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 148, IP src: 10.3.22.3, psbs: 1, rsbs: 0 Sep 15 02:34:06.911 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 3 Sep 15 02:34:06.911 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0x94, wedged 0 Sep 15 02:34:06.911 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:3) Sep 15 02:34:06.920 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:3) Sep 15 02:34:45.724 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000004, psb flags: 0xc0000018, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 02:34:45.724 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:3) Sep 15 02:34:45.724 rsvp/sig 0/RP0/CPU0 t4435 SIG:804: PATH Tunnel IPv4 changed: dst (22.22.22.22:0), src (11.11.11.11:3) Sep 15 02:42:03.271 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (22.22.22.22:0), src (11.11.11.11:3) reason: (2): State deleted due to signaling Sep 15 02:42:03.271 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000018, pfc flags 0x0 Sep 15 02:42:03.271 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (22.22.22.22:0), src (11.11.11.11:3) reason: (2): State deleted due to signaling Sep 15 02:42:03.271 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x190000, rsb flags 0xc0000004, request flags 0x86001846 Sep 15 02:42:03.272 rsvp/sig 0/RP0/CPU0 t4435 SIG:9276: PathErr: from network for dst (11.11.11.11:0), src (22.22.22.22:3); PSB flags: 0xc0000004 Sep 15 02:42:03.272 rsvp/sig 0/RP0/CPU0 t4435 SIG:9279: PathErr: (24, 5)-(Error: routing (24), Suberror: no route to dest (5)) at 10.1.2.2; flags: 0x4 Sep 15 02:42:03.272 rsvp/sig 0/RP0/CPU0 t4435 SIG:3904: Head PATH destroy pending : dst (11.11.11.11:0), src (22.22.22.22:3) reason: (16): State deleted due to PERR w/ PSR from network Sep 15 02:42:03.272 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (11.11.11.11:0), src (22.22.22.22:3) reason: (2): State deleted due to signaling Sep 15 02:42:03.272 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x0, rsb flags 0xc0000030, request flags 0x0 Sep 15 02:42:03.272 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 3 Sep 15 02:42:03.272 rsvp/sig 0/RP0/CPU0 t4435 SIG:3904: Head PATH destroy pending : dst (11.11.11.11:0), src (22.22.22.22:3) reason: (2): State deleted due to signaling Sep 15 02:42:03.280 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (11.11.11.11:0), src (22.22.22.22:3) reason: (5): State deleted due to client app Sep 15 02:42:03.280 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180009 Sep 15 02:42:03.284 rsvp/sig 0/RP0/CPU0 t4435 SIG:4545: PATH creating head: local/nbor/nhop (22.22.22.22/3.3.3.3/10.3.22.3), GigabitEthernet0/0/0/0 (ifh 0x10), psbs: 0, rsbs: 0 Sep 15 02:42:03.284 rsvp/sig 0/RP0/CPU0 t4435 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:22.22.22.22, nbor:3.3.3.3, nhop:10.3.22.3, next_ifh:GigabitEthernet0/0/0/0 (ifh 0x10), obj_len: 0 Sep 15 02:42:03.284 rsvp/sig 0/RP0/CPU0 t4435 SIG:887: PATH Tunnel IPv4 outgoing: dst (11.11.11.11:0), src (22.22.22.22:4) Sep 15 02:42:03.284 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:4) Sep 15 02:42:03.367 rsvp/sig 0/RP0/CPU0 t4435 SIG:4549: PATH creating network: GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 252, IP src: 3.3.3.3 IP dst: 10.3.22.22, psbs: 0, rsbs: 0 Sep 15 02:42:03.368 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:4) Sep 15 02:42:03.374 rsvp/sig 0/RP0/CPU0 t4435 SIG:4649: RESV creating tail: local/nbor (22.22.22.22/3.3.3.3), obj len: 80, None (ifh 0x0), psbs: 1, rsbs: 0 Sep 15 02:42:03.374 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xd0000005, psb flags: 0xc0000018, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 02:42:03.374 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:4) Sep 15 02:42:03.374 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:4) Sep 15 02:42:03.612 rsvp/sig 0/RP0/CPU0 t4435 SIG:4654: RESV creating network: GigabitEthernet0/0/0/0 (ifh 0x10), in GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 308, IP src: 10.3.22.3, psbs: 1, rsbs: 0 Sep 15 02:42:03.613 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 4 Sep 15 02:42:03.613 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0x134, wedged 0 Sep 15 02:42:03.613 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:4) Sep 15 02:42:03.622 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:4) Sep 15 02:51:09.795 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000004, psb flags: 0xc0000218, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 02:51:09.795 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:4) Sep 15 02:51:09.795 rsvp/sig 0/RP0/CPU0 t4435 SIG:804: PATH Tunnel IPv4 changed: dst (22.22.22.22:0), src (11.11.11.11:4) Sep 15 02:51:09.813 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (22.22.22.22:0), src (11.11.11.11:4) Sep 15 02:51:15.835 rsvp/sig 0/RP0/CPU0 t4435 SIG:2836: PATH outgoing creating: flags:0xc0000204, local_rid:0.0.0.0, nbor:3.3.3.3, nhop:10.3.22.3, next_ifh:GigabitEthernet0/0/0/0 (ifh 0x10), obj_len: 0 Sep 15 02:51:15.835 rsvp/sig 0/RP0/CPU0 t4435 SIG:887: PATH Tunnel IPv4 outgoing: dst (11.11.11.11:0), src (22.22.22.22:4) Sep 15 02:51:15.835 rsvp/sig 0/RP0/CPU0 t4435 SIG:804: PATH Tunnel IPv4 changed: dst (11.11.11.11:0), src (22.22.22.22:4) Sep 15 02:51:15.835 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:4) Sep 15 02:51:28.965 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 4 Sep 15 02:51:28.965 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000130, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0x134, wedged 0 Sep 15 02:51:28.965 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (11.11.11.11:0), src (22.22.22.22:4) Sep 15 02:51:36.312 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 4 Sep 15 02:51:36.312 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000130, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0x134, wedged 0 Sep 15 02:51:36.312 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (11.11.11.11:0), src (22.22.22.22:4) Sep 15 02:51:50.630 rsvp/sig 0/RP0/CPU0 t4435 SIG:4549: PATH creating network: GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 236, IP src: 10.3.22.3 IP dst: 10.3.22.22, psbs: 1, rsbs: 1 Sep 15 02:51:50.630 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:5) Sep 15 02:51:50.636 rsvp/sig 0/RP0/CPU0 t4435 SIG:4649: RESV creating tail: local/nbor (22.22.22.22/3.3.3.3), obj len: 80, None (ifh 0x0), psbs: 2, rsbs: 1 Sep 15 02:51:50.636 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xd0000005, psb flags: 0xc0000018, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 02:51:50.637 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:5) Sep 15 02:51:50.637 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:5) Sep 15 02:51:54.241 rsvp/sig 0/RP0/CPU0 t4435 SIG:4545: PATH creating head: local/nbor/nhop (22.22.22.22/3.3.3.3/10.3.22.3), GigabitEthernet0/0/0/0 (ifh 0x10), psbs: 1, rsbs: 1 Sep 15 02:51:54.241 rsvp/sig 0/RP0/CPU0 t4435 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:22.22.22.22, nbor:3.3.3.3, nhop:10.3.22.3, next_ifh:GigabitEthernet0/0/0/0 (ifh 0x10), obj_len: 0 Sep 15 02:51:54.241 rsvp/sig 0/RP0/CPU0 t4435 SIG:887: PATH Tunnel IPv4 outgoing: dst (11.11.11.11:0), src (22.22.22.22:5) Sep 15 02:51:54.242 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:5) Sep 15 02:51:54.326 rsvp/sig 0/RP0/CPU0 t4435 SIG:4654: RESV creating network: GigabitEthernet0/0/0/0 (ifh 0x10), in GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 244, IP src: 10.3.22.3, psbs: 2, rsbs: 1 Sep 15 02:51:54.327 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 5 Sep 15 02:51:54.327 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0xf4, wedged 0 Sep 15 02:51:54.327 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:5) Sep 15 02:51:54.336 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:5) Sep 15 02:52:30.930 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (22.22.22.22:0), src (11.11.11.11:4) reason: (2): State deleted due to signaling Sep 15 02:52:30.930 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000018, pfc flags 0x0 Sep 15 02:52:30.931 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (22.22.22.22:0), src (11.11.11.11:4) reason: (2): State deleted due to signaling Sep 15 02:52:30.931 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x190000, rsb flags 0xc0000004, request flags 0x86003846 Sep 15 02:52:34.538 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (11.11.11.11:0), src (22.22.22.22:4) reason: (5): State deleted due to client app Sep 15 02:52:34.538 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180009 Sep 15 02:52:34.538 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (11.11.11.11:0), src (22.22.22.22:4) reason: (5): State deleted due to client app Sep 15 02:52:34.538 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x180000, rsb flags 0xc0000030, request flags 0x0 Sep 15 02:52:34.538 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 4 Sep 15 02:59:50.566 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 5 Sep 15 02:59:50.566 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0200330, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0xf4, wedged 0 Sep 15 02:59:50.566 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (11.11.11.11:0), src (22.22.22.22:5) Sep 15 02:59:50.571 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:5) Sep 15 03:06:40.095 rsvp/sig 0/RP0/CPU0 t4435 SIG:9276: PathErr: from network for dst (11.11.11.11:0), src (22.22.22.22:5); PSB flags: 0xc0000004 Sep 15 03:06:40.095 rsvp/sig 0/RP0/CPU0 t4435 SIG:9279: PathErr: (25, 3)-(Error: notify (25), Suberror: local repair (3)) at 10.2.3.2; flags: 0x0 Sep 15 03:06:40.101 rsvp/sig 0/RP0/CPU0 t4435 SIG:4545: PATH creating head: local/nbor/nhop (22.22.22.22/3.3.3.3/10.3.22.3), GigabitEthernet0/0/0/0 (ifh 0x10), psbs: 1, rsbs: 1 Sep 15 03:06:40.101 rsvp/sig 0/RP0/CPU0 t4435 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:22.22.22.22, nbor:3.3.3.3, nhop:10.3.22.3, next_ifh:GigabitEthernet0/0/0/0 (ifh 0x10), obj_len: 0 Sep 15 03:06:40.101 rsvp/sig 0/RP0/CPU0 t4435 SIG:887: PATH Tunnel IPv4 outgoing: dst (11.11.11.11:0), src (22.22.22.22:6) Sep 15 03:06:40.101 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:6) Sep 15 03:06:40.260 rsvp/sig 0/RP0/CPU0 t4435 SIG:9276: PathErr: from network for dst (11.11.11.11:0), src (22.22.22.22:6); PSB flags: 0xc0000004 Sep 15 03:06:40.260 rsvp/sig 0/RP0/CPU0 t4435 SIG:9279: PathErr: (24, 5)-(Error: routing (24), Suberror: no route to dest (5)) at 10.2.5.2; flags: 0x4 Sep 15 03:06:40.260 rsvp/sig 0/RP0/CPU0 t4435 SIG:3904: Head PATH destroy pending : dst (11.11.11.11:0), src (22.22.22.22:6) reason: (16): State deleted due to PERR w/ PSR from network Sep 15 03:06:40.266 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (11.11.11.11:0), src (22.22.22.22:6) reason: (5): State deleted due to client app Sep 15 03:06:40.266 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180209 Sep 15 03:06:42.563 rsvp/sig 0/RP0/CPU0 t4435 SIG:4549: PATH creating network: GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 252, IP src: 10.3.22.3 IP dst: 10.3.22.22, psbs: 1, rsbs: 1 Sep 15 03:06:42.563 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:6) Sep 15 03:06:42.569 rsvp/sig 0/RP0/CPU0 t4435 SIG:4649: RESV creating tail: local/nbor (22.22.22.22/3.3.3.3), obj len: 80, None (ifh 0x0), psbs: 2, rsbs: 1 Sep 15 03:06:42.569 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xd0000005, psb flags: 0xc0000018, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 03:06:42.569 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:6) Sep 15 03:06:42.569 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:6) Sep 15 03:06:43.267 rsvp/sig 0/RP0/CPU0 t4435 SIG:4545: PATH creating head: local/nbor/nhop (22.22.22.22/3.3.3.3/10.3.22.3), GigabitEthernet0/0/0/0 (ifh 0x10), psbs: 1, rsbs: 1 Sep 15 03:06:43.268 rsvp/sig 0/RP0/CPU0 t4435 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:22.22.22.22, nbor:3.3.3.3, nhop:10.3.22.3, next_ifh:GigabitEthernet0/0/0/0 (ifh 0x10), obj_len: 0 Sep 15 03:06:43.268 rsvp/sig 0/RP0/CPU0 t4435 SIG:887: PATH Tunnel IPv4 outgoing: dst (11.11.11.11:0), src (22.22.22.22:7) Sep 15 03:06:43.268 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:7) Sep 15 03:06:43.463 rsvp/sig 0/RP0/CPU0 t4435 SIG:4654: RESV creating network: GigabitEthernet0/0/0/0 (ifh 0x10), in GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 308, IP src: 10.3.22.3, psbs: 2, rsbs: 1 Sep 15 03:06:43.463 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 7 Sep 15 03:06:43.463 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0x134, wedged 0 Sep 15 03:06:43.463 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:7) Sep 15 03:06:43.471 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:7) Sep 15 03:06:46.366 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000004, psb flags: 0xc0000218, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 03:06:46.366 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:5) Sep 15 03:06:46.366 rsvp/sig 0/RP0/CPU0 t4435 SIG:804: PATH Tunnel IPv4 changed: dst (22.22.22.22:0), src (11.11.11.11:5) Sep 15 03:06:46.372 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (22.22.22.22:0), src (11.11.11.11:5) Sep 15 03:06:47.891 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 5 Sep 15 03:06:47.891 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0200330, psb flags: 0xc0100004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0xf4, wedged 0 Sep 15 03:06:47.891 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (11.11.11.11:0), src (22.22.22.22:5) Sep 15 03:06:47.897 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:5) Sep 15 03:07:22.922 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (22.22.22.22:0), src (11.11.11.11:5) reason: (2): State deleted due to signaling Sep 15 03:07:22.922 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000018, pfc flags 0x0 Sep 15 03:07:22.922 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (22.22.22.22:0), src (11.11.11.11:5) reason: (2): State deleted due to signaling Sep 15 03:07:22.922 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x190000, rsb flags 0xc0000004, request flags 0x86003846 Sep 15 03:07:23.674 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (11.11.11.11:0), src (22.22.22.22:5) reason: (5): State deleted due to client app Sep 15 03:07:23.674 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0100004, pfc flags 0x80180009 Sep 15 03:07:23.674 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (11.11.11.11:0), src (22.22.22.22:5) reason: (5): State deleted due to client app Sep 15 03:07:23.674 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x180000, rsb flags 0xc0200030, request flags 0x0 Sep 15 03:07:23.674 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 5 Sep 15 03:17:16.541 rsvp/sig 0/RP0/CPU0 t4435 SIG:4549: PATH creating network: GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 236, IP src: 10.3.22.3 IP dst: 10.3.22.22, psbs: 1, rsbs: 1 Sep 15 03:17:16.541 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:7) Sep 15 03:17:16.547 rsvp/sig 0/RP0/CPU0 t4435 SIG:4649: RESV creating tail: local/nbor (22.22.22.22/3.3.3.3), obj len: 80, None (ifh 0x0), psbs: 2, rsbs: 1 Sep 15 03:17:16.547 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xd0000005, psb flags: 0xc0000018, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 03:17:16.548 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:7) Sep 15 03:17:16.548 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:7) Sep 15 03:17:20.367 rsvp/sig 0/RP0/CPU0 t4435 SIG:4545: PATH creating head: local/nbor/nhop (22.22.22.22/3.3.3.3/10.3.22.3), GigabitEthernet0/0/0/0 (ifh 0x10), psbs: 1, rsbs: 1 Sep 15 03:17:20.367 rsvp/sig 0/RP0/CPU0 t4435 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:22.22.22.22, nbor:3.3.3.3, nhop:10.3.22.3, next_ifh:GigabitEthernet0/0/0/0 (ifh 0x10), obj_len: 0 Sep 15 03:17:20.367 rsvp/sig 0/RP0/CPU0 t4435 SIG:887: PATH Tunnel IPv4 outgoing: dst (11.11.11.11:0), src (22.22.22.22:8) Sep 15 03:17:20.367 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:8) Sep 15 03:17:20.490 rsvp/sig 0/RP0/CPU0 t4435 SIG:4654: RESV creating network: GigabitEthernet0/0/0/0 (ifh 0x10), in GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 244, IP src: 10.3.22.3, psbs: 2, rsbs: 1 Sep 15 03:17:20.490 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 8 Sep 15 03:17:20.490 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0xf4, wedged 0 Sep 15 03:17:20.490 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:8) Sep 15 03:17:20.515 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:8) Sep 15 03:17:56.844 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (22.22.22.22:0), src (11.11.11.11:6) reason: (2): State deleted due to signaling Sep 15 03:17:56.844 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000018, pfc flags 0x0 Sep 15 03:17:56.844 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (22.22.22.22:0), src (11.11.11.11:6) reason: (2): State deleted due to signaling Sep 15 03:17:56.844 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x190000, rsb flags 0xc0000004, request flags 0x86003846 Sep 15 03:18:00.718 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (11.11.11.11:0), src (22.22.22.22:7) reason: (5): State deleted due to client app Sep 15 03:18:00.718 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180009 Sep 15 03:18:00.718 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (11.11.11.11:0), src (22.22.22.22:7) reason: (5): State deleted due to client app Sep 15 03:18:00.718 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x180000, rsb flags 0xc0000030, request flags 0x0 Sep 15 03:18:00.718 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 7 Sep 15 03:24:32.756 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000004, psb flags: 0xc0000218, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 03:24:32.756 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:7) Sep 15 03:24:32.756 rsvp/sig 0/RP0/CPU0 t4435 SIG:804: PATH Tunnel IPv4 changed: dst (22.22.22.22:0), src (11.11.11.11:7) Sep 15 03:24:32.762 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (22.22.22.22:0), src (11.11.11.11:7) Sep 15 03:24:39.126 rsvp/sig 0/RP0/CPU0 t4435 SIG:2836: PATH outgoing creating: flags:0xc0000204, local_rid:0.0.0.0, nbor:3.3.3.3, nhop:10.3.22.3, next_ifh:GigabitEthernet0/0/0/0 (ifh 0x10), obj_len: 0 Sep 15 03:24:39.126 rsvp/sig 0/RP0/CPU0 t4435 SIG:887: PATH Tunnel IPv4 outgoing: dst (11.11.11.11:0), src (22.22.22.22:8) Sep 15 03:24:39.126 rsvp/sig 0/RP0/CPU0 t4435 SIG:804: PATH Tunnel IPv4 changed: dst (11.11.11.11:0), src (22.22.22.22:8) Sep 15 03:24:49.392 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 8 Sep 15 03:24:49.392 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000130, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0xf4, wedged 0 Sep 15 03:24:49.392 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (11.11.11.11:0), src (22.22.22.22:8) Sep 15 03:24:56.806 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 8 Sep 15 03:24:56.806 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0200330, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0xf4, wedged 0 Sep 15 03:24:56.806 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (11.11.11.11:0), src (22.22.22.22:8) Sep 15 03:24:56.812 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:8) Sep 15 03:32:03.484 rsvp/sig 0/RP0/CPU0 t4435 SIG:9276: PathErr: from network for dst (11.11.11.11:0), src (22.22.22.22:8); PSB flags: 0xc0000004 Sep 15 03:32:03.484 rsvp/sig 0/RP0/CPU0 t4435 SIG:9279: PathErr: (25, 3)-(Error: notify (25), Suberror: local repair (3)) at 10.3.22.3; flags: 0x0 Sep 15 03:32:03.890 rsvp/sig 0/RP0/CPU0 t4435 SIG:4545: PATH creating head: local/nbor/nhop (22.22.22.22/3.3.3.3/10.3.22.3), GigabitEthernet0/0/0/0 (ifh 0x10), psbs: 1, rsbs: 1 Sep 15 03:32:03.890 rsvp/sig 0/RP0/CPU0 t4435 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:22.22.22.22, nbor:3.3.3.3, nhop:10.3.22.3, next_ifh:GigabitEthernet0/0/0/0 (ifh 0x10), obj_len: 0 Sep 15 03:32:03.890 rsvp/sig 0/RP0/CPU0 t4435 SIG:887: PATH Tunnel IPv4 outgoing: dst (11.11.11.11:0), src (22.22.22.22:9) Sep 15 03:32:03.890 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:9) Sep 15 03:32:06.200 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (11.11.11.11:0), src (22.22.22.22:9) reason: (5): State deleted due to client app Sep 15 03:32:06.200 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180009 Sep 15 03:32:06.238 rsvp/sig 0/RP0/CPU0 t4435 SIG:4549: PATH creating network: GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 252, IP src: 10.3.22.3 IP dst: 10.3.22.22, psbs: 1, rsbs: 1 Sep 15 03:32:06.238 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:8) Sep 15 03:32:06.244 rsvp/sig 0/RP0/CPU0 t4435 SIG:4649: RESV creating tail: local/nbor (22.22.22.22/3.3.3.3), obj len: 80, None (ifh 0x0), psbs: 2, rsbs: 1 Sep 15 03:32:06.244 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xd0000005, psb flags: 0xc0000018, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 03:32:06.244 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:8) Sep 15 03:32:06.244 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:8) Sep 15 03:32:08.986 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 8 Sep 15 03:32:08.986 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0200330, psb flags: 0xc0100004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0xd4, wedged 0 Sep 15 03:32:08.986 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (11.11.11.11:0), src (22.22.22.22:8) Sep 15 03:32:08.992 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:8) Sep 15 03:32:12.511 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000004, psb flags: 0xc0000218, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 03:32:12.511 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:7) Sep 15 03:32:12.511 rsvp/sig 0/RP0/CPU0 t4435 SIG:804: PATH Tunnel IPv4 changed: dst (22.22.22.22:0), src (11.11.11.11:7) Sep 15 03:32:12.517 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (22.22.22.22:0), src (11.11.11.11:7) Sep 15 03:32:34.382 rsvp/sig 0/RP0/CPU0 t4435 SIG:4545: PATH creating head: local/nbor/nhop (22.22.22.22/3.3.3.3/10.3.22.3), GigabitEthernet0/0/0/0 (ifh 0x10), psbs: 1, rsbs: 1 Sep 15 03:32:34.382 rsvp/sig 0/RP0/CPU0 t4435 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:22.22.22.22, nbor:3.3.3.3, nhop:10.3.22.3, next_ifh:GigabitEthernet0/0/0/0 (ifh 0x10), obj_len: 0 Sep 15 03:32:34.382 rsvp/sig 0/RP0/CPU0 t4435 SIG:887: PATH Tunnel IPv4 outgoing: dst (11.11.11.11:0), src (22.22.22.22:10) Sep 15 03:32:34.382 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:10) Sep 15 03:32:34.562 rsvp/sig 0/RP0/CPU0 t4435 SIG:4654: RESV creating network: GigabitEthernet0/0/0/0 (ifh 0x10), in GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 308, IP src: 10.3.22.3, psbs: 2, rsbs: 1 Sep 15 03:32:34.562 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 10 Sep 15 03:32:34.562 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0x134, wedged 0 Sep 15 03:32:34.562 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:10) Sep 15 03:32:34.571 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:10) Sep 15 03:32:46.550 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (22.22.22.22:0), src (11.11.11.11:7) reason: (2): State deleted due to signaling Sep 15 03:32:46.550 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000018, pfc flags 0x0 Sep 15 03:32:46.550 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (22.22.22.22:0), src (11.11.11.11:7) reason: (2): State deleted due to signaling Sep 15 03:32:46.550 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x190000, rsb flags 0xc0000004, request flags 0x86003846 Sep 15 03:33:14.777 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (11.11.11.11:0), src (22.22.22.22:8) reason: (5): State deleted due to client app Sep 15 03:33:14.777 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0100004, pfc flags 0x80180009 Sep 15 03:33:14.777 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (11.11.11.11:0), src (22.22.22.22:8) reason: (5): State deleted due to client app Sep 15 03:33:14.777 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x180000, rsb flags 0xc0200030, request flags 0x0 Sep 15 03:33:14.777 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 8 Sep 15 03:41:28.424 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (22.22.22.22:0), src (11.11.11.11:8) reason: (2): State deleted due to signaling Sep 15 03:41:28.424 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000018, pfc flags 0x0 Sep 15 03:41:28.425 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (22.22.22.22:0), src (11.11.11.11:8) reason: (2): State deleted due to signaling Sep 15 03:41:28.425 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x190000, rsb flags 0xc0000004, request flags 0x86003846 Sep 15 03:41:35.049 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (11.11.11.11:0), src (22.22.22.22:10) reason: (5): State deleted due to client app Sep 15 03:41:35.049 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180009 Sep 15 03:41:35.049 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (11.11.11.11:0), src (22.22.22.22:10) reason: (5): State deleted due to client app Sep 15 03:41:35.049 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x180000, rsb flags 0xc0000030, request flags 0x0 Sep 15 03:41:35.049 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 10 Sep 15 03:51:34.762 rsvp/sig 0/RP0/CPU0 t4435 SIG:4549: PATH creating network: GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 236, IP src: 10.3.22.3 IP dst: 10.3.22.22, psbs: 0, rsbs: 0 Sep 15 03:51:34.762 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:3) Sep 15 03:51:34.768 rsvp/sig 0/RP0/CPU0 t4435 SIG:4649: RESV creating tail: local/nbor (22.22.22.22/3.3.3.3), obj len: 80, None (ifh 0x0), psbs: 1, rsbs: 0 Sep 15 03:51:34.768 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xd0000005, psb flags: 0xc0000018, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 03:51:34.768 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:3) Sep 15 03:51:34.768 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:3) Sep 15 03:51:41.723 rsvp/sig 0/RP0/CPU0 t4435 SIG:4545: PATH creating head: local/nbor/nhop (22.22.22.22/3.3.3.3/10.3.22.3), GigabitEthernet0/0/0/0 (ifh 0x10), psbs: 0, rsbs: 0 Sep 15 03:51:41.724 rsvp/sig 0/RP0/CPU0 t4435 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:22.22.22.22, nbor:3.3.3.3, nhop:10.3.22.3, next_ifh:GigabitEthernet0/0/0/0 (ifh 0x10), obj_len: 0 Sep 15 03:51:41.724 rsvp/sig 0/RP0/CPU0 t4435 SIG:887: PATH Tunnel IPv4 outgoing: dst (11.11.11.11:0), src (22.22.22.22:3) Sep 15 03:51:41.724 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:3) Sep 15 03:51:41.811 rsvp/sig 0/RP0/CPU0 t4435 SIG:4654: RESV creating network: GigabitEthernet0/0/0/0 (ifh 0x10), in GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 244, IP src: 10.3.22.3, psbs: 1, rsbs: 0 Sep 15 03:51:41.811 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 3 Sep 15 03:51:41.811 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0xf4, wedged 0 Sep 15 03:51:41.811 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:3) Sep 15 03:51:41.820 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:3) Sep 15 04:00:39.909 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 3 Sep 15 04:00:39.909 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0200330, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0xf4, wedged 0 Sep 15 04:00:39.909 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (11.11.11.11:0), src (22.22.22.22:3) Sep 15 04:00:39.915 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:3) Sep 15 04:22:20.454 rsvp/sig 0/RP0/CPU0 t4435 SIG:9276: PathErr: from network for dst (11.11.11.11:0), src (22.22.22.22:3); PSB flags: 0xc0000004 Sep 15 04:22:20.454 rsvp/sig 0/RP0/CPU0 t4435 SIG:9279: PathErr: (24, 5)-(Error: routing (24), Suberror: no route to dest (5)) at 10.1.2.2; flags: 0x0 Sep 15 04:22:20.455 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (11.11.11.11:0), src (22.22.22.22:3) reason: (2): State deleted due to signaling Sep 15 04:22:20.455 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x0, rsb flags 0xc0200030, request flags 0x0 Sep 15 04:22:20.455 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 3 Sep 15 04:22:20.455 rsvp/sig 0/RP0/CPU0 t4435 SIG:3904: Head PATH destroy pending : dst (11.11.11.11:0), src (22.22.22.22:3) reason: (2): State deleted due to signaling Sep 15 04:22:20.465 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (11.11.11.11:0), src (22.22.22.22:3) reason: (5): State deleted due to client app Sep 15 04:22:20.465 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180009 Sep 15 04:22:20.468 rsvp/sig 0/RP0/CPU0 t4435 SIG:4545: PATH creating head: local/nbor/nhop (22.22.22.22/3.3.3.3/10.3.22.3), GigabitEthernet0/0/0/0 (ifh 0x10), psbs: 0, rsbs: 0 Sep 15 04:22:20.468 rsvp/sig 0/RP0/CPU0 t4435 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:22.22.22.22, nbor:3.3.3.3, nhop:10.3.22.3, next_ifh:GigabitEthernet0/0/0/0 (ifh 0x10), obj_len: 0 Sep 15 04:22:20.468 rsvp/sig 0/RP0/CPU0 t4435 SIG:887: PATH Tunnel IPv4 outgoing: dst (11.11.11.11:0), src (22.22.22.22:4) Sep 15 04:22:20.468 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:4) Sep 15 04:22:20.713 rsvp/sig 0/RP0/CPU0 t4435 SIG:4654: RESV creating network: GigabitEthernet0/0/0/0 (ifh 0x10), in GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 308, IP src: 10.3.22.3, psbs: 1, rsbs: 0 Sep 15 04:22:20.713 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 4 Sep 15 04:22:20.713 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0x134, wedged 0 Sep 15 04:22:20.713 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:4) Sep 15 04:22:20.722 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:4) Sep 15 04:22:22.832 rsvp/sig 0/RP0/CPU0 t4435 SIG:4549: PATH creating network: GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 252, IP src: 10.3.22.3 IP dst: 10.3.22.22, psbs: 1, rsbs: 1 Sep 15 04:22:22.832 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:4) Sep 15 04:22:22.839 rsvp/sig 0/RP0/CPU0 t4435 SIG:4649: RESV creating tail: local/nbor (22.22.22.22/3.3.3.3), obj len: 80, None (ifh 0x0), psbs: 2, rsbs: 1 Sep 15 04:22:22.839 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xd0000005, psb flags: 0xc0000018, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 04:22:22.839 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:4) Sep 15 04:22:22.839 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:4) Sep 15 04:22:28.564 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000004, psb flags: 0xc0000218, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 04:22:28.564 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:3) Sep 15 04:22:28.565 rsvp/sig 0/RP0/CPU0 t4435 SIG:804: PATH Tunnel IPv4 changed: dst (22.22.22.22:0), src (11.11.11.11:3) Sep 15 04:22:28.570 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (22.22.22.22:0), src (11.11.11.11:3) Sep 15 04:23:03.191 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (22.22.22.22:0), src (11.11.11.11:3) reason: (2): State deleted due to signaling Sep 15 04:23:03.191 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000018, pfc flags 0x0 Sep 15 04:23:03.192 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (22.22.22.22:0), src (11.11.11.11:3) reason: (2): State deleted due to signaling Sep 15 04:23:03.192 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x190000, rsb flags 0xc0000004, request flags 0x86003846 Sep 15 04:33:05.062 rsvp/sig 0/RP0/CPU0 t4435 SIG:4549: PATH creating network: GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 236, IP src: 10.3.22.3 IP dst: 10.3.22.22, psbs: 1, rsbs: 1 Sep 15 04:33:05.063 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:5) Sep 15 04:33:05.069 rsvp/sig 0/RP0/CPU0 t4435 SIG:4649: RESV creating tail: local/nbor (22.22.22.22/3.3.3.3), obj len: 80, None (ifh 0x0), psbs: 2, rsbs: 1 Sep 15 04:33:05.069 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xd0000005, psb flags: 0xc0000018, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 04:33:05.069 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:5) Sep 15 04:33:05.069 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:5) Sep 15 04:33:08.642 rsvp/sig 0/RP0/CPU0 t4435 SIG:4545: PATH creating head: local/nbor/nhop (22.22.22.22/3.3.3.3/10.3.22.3), GigabitEthernet0/0/0/0 (ifh 0x10), psbs: 1, rsbs: 1 Sep 15 04:33:08.642 rsvp/sig 0/RP0/CPU0 t4435 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:22.22.22.22, nbor:3.3.3.3, nhop:10.3.22.3, next_ifh:GigabitEthernet0/0/0/0 (ifh 0x10), obj_len: 0 Sep 15 04:33:08.642 rsvp/sig 0/RP0/CPU0 t4435 SIG:887: PATH Tunnel IPv4 outgoing: dst (11.11.11.11:0), src (22.22.22.22:5) Sep 15 04:33:08.642 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:5) Sep 15 04:33:08.730 rsvp/sig 0/RP0/CPU0 t4435 SIG:4654: RESV creating network: GigabitEthernet0/0/0/0 (ifh 0x10), in GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 244, IP src: 10.3.22.3, psbs: 2, rsbs: 1 Sep 15 04:33:08.730 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 5 Sep 15 04:33:08.730 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0xf4, wedged 0 Sep 15 04:33:08.730 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:5) Sep 15 04:33:08.738 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:5) Sep 15 04:33:45.352 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (22.22.22.22:0), src (11.11.11.11:4) reason: (2): State deleted due to signaling Sep 15 04:33:45.352 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000018, pfc flags 0x0 Sep 15 04:33:45.352 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (22.22.22.22:0), src (11.11.11.11:4) reason: (2): State deleted due to signaling Sep 15 04:33:45.352 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x190000, rsb flags 0xc0000004, request flags 0x86003846 Sep 15 04:33:48.941 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (11.11.11.11:0), src (22.22.22.22:4) reason: (5): State deleted due to client app Sep 15 04:33:48.941 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180009 Sep 15 04:33:48.941 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (11.11.11.11:0), src (22.22.22.22:4) reason: (5): State deleted due to client app Sep 15 04:33:48.941 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x180000, rsb flags 0xc0000030, request flags 0x0 Sep 15 04:33:48.941 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 4 Sep 15 04:41:05.065 rsvp/sig 0/RP0/CPU0 t4435 SIG:9276: PathErr: from network for dst (11.11.11.11:0), src (22.22.22.22:5); PSB flags: 0xc0000004 Sep 15 04:41:05.065 rsvp/sig 0/RP0/CPU0 t4435 SIG:9279: PathErr: (25, 3)-(Error: notify (25), Suberror: local repair (3)) at 10.2.3.2; flags: 0x0 Sep 15 04:41:05.072 rsvp/sig 0/RP0/CPU0 t4435 SIG:4545: PATH creating head: local/nbor/nhop (22.22.22.22/3.3.3.3/10.3.22.3), GigabitEthernet0/0/0/0 (ifh 0x10), psbs: 1, rsbs: 1 Sep 15 04:41:05.072 rsvp/sig 0/RP0/CPU0 t4435 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:22.22.22.22, nbor:3.3.3.3, nhop:10.3.22.3, next_ifh:GigabitEthernet0/0/0/0 (ifh 0x10), obj_len: 0 Sep 15 04:41:05.072 rsvp/sig 0/RP0/CPU0 t4435 SIG:887: PATH Tunnel IPv4 outgoing: dst (11.11.11.11:0), src (22.22.22.22:6) Sep 15 04:41:05.072 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:6) Sep 15 04:41:05.423 rsvp/sig 0/RP0/CPU0 t4435 SIG:4654: RESV creating network: GigabitEthernet0/0/0/0 (ifh 0x10), in GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 308, IP src: 10.3.22.3, psbs: 2, rsbs: 1 Sep 15 04:41:05.424 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 6 Sep 15 04:41:05.424 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0x134, wedged 0 Sep 15 04:41:05.424 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (11.11.11.11:0), src (22.22.22.22:6) Sep 15 04:41:05.432 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:6) Sep 15 04:41:07.432 rsvp/sig 0/RP0/CPU0 t4435 SIG:4549: PATH creating network: GigabitEthernet0/0/0/0 (ifh 0x10), obj len: 252, IP src: 10.3.22.3 IP dst: 10.3.22.22, psbs: 1, rsbs: 1 Sep 15 04:41:07.432 rsvp/sig 0/RP0/CPU0 t4435 SIG:721: PATH Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:6) Sep 15 04:41:07.438 rsvp/sig 0/RP0/CPU0 t4435 SIG:4649: RESV creating tail: local/nbor (22.22.22.22/3.3.3.3), obj len: 80, None (ifh 0x0), psbs: 2, rsbs: 1 Sep 15 04:41:07.438 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xd0000005, psb flags: 0xc0000018, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 04:41:07.438 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:6) Sep 15 04:41:07.438 rsvp/sig 0/RP0/CPU0 t4435 SIG:362: RESV Tunnel IPv4 created: dst (22.22.22.22:0), src (11.11.11.11:6) Sep 15 04:41:11.194 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000004, psb flags: 0xc0000218, local/nbor 22.22.22.22/3.3.3.3, obj len: 0x50, wedged 0 Sep 15 04:41:11.194 rsvp/sig 0/RP0/CPU0 t4435 SIG:528: RESV Tunnel IPv4 outgoing: dst (22.22.22.22:0), src (11.11.11.11:5) Sep 15 04:41:11.194 rsvp/sig 0/RP0/CPU0 t4435 SIG:804: PATH Tunnel IPv4 changed: dst (22.22.22.22:0), src (11.11.11.11:5) Sep 15 04:41:11.210 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (22.22.22.22:0), src (11.11.11.11:5) Sep 15 04:41:11.400 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 5 Sep 15 04:41:11.400 rsvp/sig 0/RP0/CPU0 t4435 SIG:2881: RESV outgoing creating: rsb flags: 0xc0200330, psb flags: 0xc0100004, local/nbor 22.22.22.22/0.0.0.0, obj len: 0xf4, wedged 0 Sep 15 04:41:11.400 rsvp/sig 0/RP0/CPU0 t4435 SIG:445: RESV Tunnel IPv4 changed: dst (11.11.11.11:0), src (22.22.22.22:5) Sep 15 04:41:11.406 rsvp/sig 0/RP0/CPU0 t4435 SIG:492: Assigned backup None (ifh 0x0): dst (11.11.11.11:0), src (22.22.22.22:5) Sep 15 04:41:45.636 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (11.11.11.11:0), src (22.22.22.22:5) reason: (5): State deleted due to client app Sep 15 04:41:45.636 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0100004, pfc flags 0x80180009 Sep 15 04:41:45.636 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (11.11.11.11:0), src (22.22.22.22:5) reason: (5): State deleted due to client app Sep 15 04:41:45.636 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x180000, rsb flags 0xc0200030, request flags 0x0 Sep 15 04:41:45.636 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 5 Sep 15 04:41:47.815 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (22.22.22.22:0), src (11.11.11.11:5) reason: (2): State deleted due to signaling Sep 15 04:41:47.815 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000018, pfc flags 0x0 Sep 15 04:41:47.815 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (22.22.22.22:0), src (11.11.11.11:5) reason: (2): State deleted due to signaling Sep 15 04:41:47.815 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x190000, rsb flags 0xc0000004, request flags 0x86003846 Sep 15 04:49:27.820 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (22.22.22.22:0), src (11.11.11.11:6) reason: (2): State deleted due to signaling Sep 15 04:49:27.820 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000018, pfc flags 0x0 Sep 15 04:49:27.820 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (22.22.22.22:0), src (11.11.11.11:6) reason: (2): State deleted due to signaling Sep 15 04:49:27.820 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x190000, rsb flags 0xc0000004, request flags 0x86003846 Sep 15 04:49:34.022 rsvp/sig 0/RP0/CPU0 t4435 SIG:3929: PATH destroy: dst (11.11.11.11:0), src (22.22.22.22:6) reason: (5): State deleted due to client app Sep 15 04:49:34.022 rsvp/sig 0/RP0/CPU0 t4435 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180009 Sep 15 04:49:34.022 rsvp/sig 0/RP0/CPU0 t4435 SIG:1214: RESV destroy: dst (11.11.11.11:0), src (22.22.22.22:6) reason: (5): State deleted due to client app Sep 15 04:49:34.022 rsvp/sig 0/RP0/CPU0 t4435 SIG:1216: RESV destroy: flags 0x180000, rsb flags 0xc0000030, request flags 0x0 Sep 15 04:49:34.022 rsvp/sig 0/RP0/CPU0 t4435 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/0 (ifh 0x10), current (0 Bps), port 0, src 22.22.22.22 id 6