RP/0/RP0/CPU0:PE1#show mpls traffic-eng trace head-end Sun Sep 13 07:08:36.363 UTC 217 wrapping entries (264256 possible, 320 allocated, 0 filtered, 217 total) Sep 13 05:46:43.416 mpls_te/head-end 0/RP0/CPU0 t4565 [PCALC-ECMP] Max BWV Allocated: 20 Sep 13 05:46:43.416 mpls_te/head-end 0/RP0/CPU0 t4565 [PCALC-ECMP] Max BWVE Allocated: 15 Sep 13 05:46:47.810 mpls_te/head-end 0/RP0/CPU0 t4565 NOTFN OwnedResEnd Sep 13 05:46:49.700 mpls_te/head-end 0/RP0/CPU0 t4565 Validating ifindexes for all vifs Sep 13 06:07:09.409 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, Start sync retry timer Sep 13 06:07:09.409 mpls_te/head-end 0/RP0/CPU0 t4565 Batch op IF CREATE with 1 items Sep 13 06:07:09.413 mpls_te/head-end 0/RP0/CPU0 t4565 ifh:0x1c, NOTFN INITIAL; caps ; proto NONE; state not ready Sep 13 06:07:09.413 mpls_te/head-end 0/RP0/CPU0 t4565 ifh:0x1c, NOTFN INITIAL; caps mpls_te; proto NONE; state not ready Sep 13 06:07:09.413 mpls_te/head-end 0/RP0/CPU0 t4565 Batch op CAPS ADD with 1 items Sep 13 06:07:09.414 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, ifh:0x1c, NOTFN STATE, caps ; proto NONE; state down Sep 13 06:07:09.414 mpls_te/head-end 0/RP0/CPU0 t4565 Batch op STATE UPDATE with 1 items Sep 13 06:07:09.415 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, IM op STATE UPDATE for tunnel-te0 (ifhndl 0x1c) Sep 13 06:07:09.415 mpls_te/head-end 0/RP0/CPU0 t4565 ifh:0x1c, NOTFN INITIAL; caps mpls; proto mpls; state not ready Sep 13 06:07:09.416 mpls_te/head-end 0/RP0/CPU0 t4565 ifh:0x1c, NOTFN MTU; caps mpls; proto mpls; mtu 1500 Sep 13 06:07:09.416 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, IM op CAPS ADD for tunnel-te0 (ifhndl 0x1c) Sep 13 06:07:09.416 mpls_te/head-end 0/RP0/CPU0 t4565 Batch op CAPS ADD with 1 items Sep 13 06:07:09.416 mpls_te/head-end 0/RP0/CPU0 t4565 Batch op MTU UPDATE with 1 items Sep 13 06:07:09.504 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, IM op CAPS ADD for tunnel-te0 (ifhndl 0x1c) Sep 13 06:07:09.508 mpls_te/head-end 0/RP0/CPU0 t4565 ifh:0x1c, NOTFN CREATE; caps ipv4; proto ipv4; Sep 13 06:07:09.508 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, IP address is now available Sep 13 06:07:09.508 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACT_CHECK Sep 13 06:07:09.633 mpls_te/head-end 0/RP0/CPU0 t4565 tunnel-te0 (ifhndl 0x1c) : queued IM dest update: 9.9.9.9 Sep 13 06:07:09.633 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, Send IM attribute: old dest = 0.0.0.0, new dest = 9.9.9.9 Sep 13 06:07:09.633 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, Start sync retry timer Sep 13 06:07:09.634 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, Start sync retry timer Sep 13 06:07:09.634 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:0, Holddown:0 Sep 13 06:07:09.636 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACT_CHECK Sep 13 06:07:09.636 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACT_MODIFY_IN_PLACE Sep 13 06:07:09.804 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, L:2, LL:24014, TE rewrite queueing succeeded Sep 13 06:07:09.805 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [CURRENT] L:2, ifh:0x1c, TE rewrite returned TRUE Sep 13 06:07:09.805 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, IFH:0x01C, moving state to up Sep 13 06:07:09.805 mpls_te/head-end 0/RP0/CPU0 t4565 Batch op STATE UPDATE with 1 items Sep 13 06:07:09.806 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, IM op STATE UPDATE for tunnel-te0 (ifhndl 0x1c) Sep 13 06:07:10.409 mpls_te/head-end 0/RP0/CPU0 t4565 Validating ifindexes for all vifs Sep 13 06:07:10.409 mpls_te/head-end 0/RP0/CPU0 t4565 Bulk ifindex lookup for 1 vifs Sep 13 06:07:10.411 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, ifindex set to 9 Sep 13 06:07:24.634 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, Sync retry timer expired Sep 13 06:16:58.024 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:16:58.024 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:16:58.025 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:16:59.021 mpls_te/head-end 0/RP0/CPU0 t4565 Validating ifindexes for all vifs Sep 13 06:17:06.699 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:17:06.699 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:17:06.699 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:17:36.699 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:17:36.699 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:17:36.699 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:18:06.700 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:18:06.700 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:18:06.700 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:18:36.700 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:18:36.700 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:18:36.700 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:19:06.700 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:19:06.700 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:19:06.701 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:19:36.701 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:19:36.701 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:19:36.701 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:20:06.701 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:20:06.701 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:20:06.701 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:20:36.702 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:20:36.702 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:20:36.702 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:21:06.702 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:21:06.702 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:21:06.702 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:21:36.702 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:21:36.702 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:21:36.703 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:22:06.703 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:22:06.703 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:22:06.703 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:22:36.703 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:22:36.703 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:22:36.704 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:23:06.704 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:23:06.704 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:23:06.704 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:23:36.704 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:23:36.704 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:23:36.704 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:24:06.704 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:24:06.704 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:24:06.704 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:24:36.705 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:24:36.705 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:24:36.705 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:25:06.705 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:25:06.705 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:25:06.705 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:25:36.705 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:25:36.705 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:25:36.705 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:26:06.706 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:26:06.706 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:26:06.706 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:26:36.706 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:26:36.706 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:26:36.706 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:27:06.706 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:27:06.706 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:27:06.707 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:27:36.707 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:27:36.707 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:27:36.707 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:28:06.707 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:28:06.707 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:28:06.707 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:28:36.708 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:28:36.708 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:28:36.708 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:29:06.708 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:29:06.708 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:29:06.708 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:29:36.708 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:29:36.708 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:29:36.708 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:30:06.709 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:30:06.709 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:30:06.709 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, LSP not signalled, has no S2Ls Sep 13 06:30:07.819 mpls_te/head-end 0/RP0/CPU0 t4565 T:0 Added Affinity constraint (count 1): type ignore, value 0x0, Fwd Ref value 0x0 Sep 13 06:30:08.816 mpls_te/head-end 0/RP0/CPU0 t4565 Validating ifindexes for all vifs Sep 13 06:30:36.709 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:30:36.709 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:30:36.709 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, working-reopt initiated: trigger: Bandwidth CLI Change, reason: applying bandwidth change Sep 13 06:30:36.709 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, applying bandwidth change Sep 13 06:30:36.839 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, started install timer:20 secs, 100 msec, [CURRENT] L:2, [REOPT] L:3 Sep 13 06:30:56.940 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, Timer[0] expired; install RW for [REOPT] L:3 and start cleanup timer:20 secs Sep 13 06:30:56.940 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, TE rewrite returned TRUE Sep 13 06:30:56.941 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:3, ifh:0x1c, TE rewrite returned TRUE Sep 13 06:31:17.042 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, cleanup timer expired; destroying [CLEAN] L:2 Sep 13 06:40:14.220 mpls_te/head-end 0/RP0/CPU0 t4565 T:0 Deleted Affinity constraint (count 0): type ignore, value 0x0, Fwd Ref value 0x0 Sep 13 06:40:14.238 mpls_te/head-end 0/RP0/CPU0 t4565 T:0 Configured classic Affinity: value 0x1 mask 0x1 Sep 13 06:40:14.238 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACT_CHECK Sep 13 06:40:14.238 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_VERIFY_SR Sep 13 06:40:15.236 mpls_te/head-end 0/RP0/CPU0 t4565 Validating ifindexes for all vifs Sep 13 06:40:38.965 mpls_te/head-end 0/RP0/CPU0 t4565 Type:p2p, head, CURRENT, T:0, L:3, S:2.2.2.2, E:2.2.2.2, D:9.9.9.9, path verify failed due to affinity change Sep 13 06:40:38.965 mpls_te/head-end 0/RP0/CPU0 t4565 T:0 L:3 path verify soft failure (affinity check fail, set start time:0) Sep 13 06:40:38.965 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_AFF_FAIL Sep 13 06:40:38.965 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:40:38.966 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, working-reopt initiated: trigger: Path affinity failed verification, reason: applying affinity change Sep 13 06:40:38.966 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:4, applying affinity change Sep 13 06:40:38.966 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_AFF_FAIL Sep 13 06:40:39.073 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, started install timer:20 secs, 100 msec, [CURRENT] L:3, [REOPT] L:4 Sep 13 06:40:59.174 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, Timer[0] expired; install RW for [REOPT] L:4 and start cleanup timer:20 secs Sep 13 06:40:59.174 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:4, TE rewrite returned TRUE Sep 13 06:40:59.176 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:4, ifh:0x1c, TE rewrite returned TRUE Sep 13 06:40:59.176 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, stop affinity failure delayed tear timer Sep 13 06:41:04.602 mpls_te/head-end 0/RP0/CPU0 t4565 T:0 Deleted classic Affinity: value 0x1 mask 0x1 Sep 13 06:41:04.605 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACT_CHECK Sep 13 06:41:04.605 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_VERIFY_SR Sep 13 06:41:04.622 mpls_te/head-end 0/RP0/CPU0 t4565 T:0 Added Affinity constraint (count 1): type ignore, value 0x0, Fwd Ref value 0x0 Sep 13 06:41:05.621 mpls_te/head-end 0/RP0/CPU0 t4565 Validating ifindexes for all vifs Sep 13 06:41:19.276 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, cleanup timer expired; destroying [CLEAN] L:3 Sep 13 06:42:25.318 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_CLI Sep 13 06:42:25.318 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:42:25.319 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, working-reopt initiated: trigger: CLI request, reason: better cumulative metric Sep 13 06:42:25.319 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:5, better cumulative metric Sep 13 06:42:25.396 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, started install timer:20 secs, 100 msec, [CURRENT] L:4, [REOPT] L:5 Sep 13 06:42:45.496 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, Timer[0] expired; install RW for [REOPT] L:5 and start cleanup timer:20 secs Sep 13 06:42:45.497 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:5, TE rewrite returned TRUE Sep 13 06:42:45.498 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:5, ifh:0x1c, TE rewrite returned TRUE Sep 13 06:43:05.598 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, cleanup timer expired; destroying [CLEAN] L:4 Sep 13 06:43:44.406 mpls_te/head-end 0/RP0/CPU0 t4565 T:0 Deleted Affinity constraint (count 0): type ignore, value 0x0, Fwd Ref value 0x0 Sep 13 06:43:44.407 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:43:44.407 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:43:44.408 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, working-reopt initiated: trigger: Bandwidth CLI Change, reason: applying bandwidth change Sep 13 06:43:44.408 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:6, applying bandwidth change Sep 13 06:43:44.495 mpls_te/head-end 0/RP0/CPU0 t4565 T:0 Configured classic Affinity: value 0x1 mask 0x1 Sep 13 06:43:44.495 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACT_CHECK Sep 13 06:43:44.495 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_VERIFY_SR Sep 13 06:43:44.502 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, started install timer:20 secs, 100 msec, [CURRENT] L:5, [REOPT] L:6 Sep 13 06:43:45.425 mpls_te/head-end 0/RP0/CPU0 t4565 Validating ifindexes for all vifs Sep 13 06:43:57.516 mpls_te/head-end 0/RP0/CPU0 t4565 Type:p2p, head, CURRENT, T:0, L:5, S:2.2.2.2, E:2.2.2.2, D:9.9.9.9, path verify failed due to affinity change Sep 13 06:43:57.516 mpls_te/head-end 0/RP0/CPU0 t4565 T:0 L:5 path verify soft failure (affinity check fail, set start time:0) Sep 13 06:43:57.517 mpls_te/head-end 0/RP0/CPU0 t4565 Type:p2p, head, REOPT, T:0, L:6, S:2.2.2.2, E:2.2.2.2, D:9.9.9.9, [REOPT] S2L path verify failed Sep 13 06:44:27.516 mpls_te/head-end 0/RP0/CPU0 t4565 Type:p2p, head, CURRENT, T:0, L:5, S:2.2.2.2, E:2.2.2.2, D:9.9.9.9, path verify failed due to affinity change Sep 13 06:44:27.516 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_AFF_FAIL Sep 13 06:44:27.517 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:44:27.517 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, working-reopt initiated: trigger: Path affinity failed verification, reason: applying affinity change Sep 13 06:44:27.517 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:7, applying affinity change Sep 13 06:44:27.517 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_BW Sep 13 06:44:27.518 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:44:27.518 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, working-reopt initiated: trigger: Bandwidth CLI Change, reason: applying affinity change Sep 13 06:44:27.518 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:8, applying affinity change Sep 13 06:44:27.584 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, started install timer:20 secs, 100 msec, [CURRENT] L:5, [REOPT] L:8 Sep 13 06:44:47.685 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, Timer[0] expired; install RW for [REOPT] L:8 and start cleanup timer:20 secs Sep 13 06:44:47.685 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:8, TE rewrite returned TRUE Sep 13 06:44:47.686 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:8, ifh:0x1c, TE rewrite returned TRUE Sep 13 06:44:47.686 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, stop affinity failure delayed tear timer Sep 13 06:45:07.786 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, cleanup timer expired; destroying [CLEAN] L:5 Sep 13 06:46:43.416 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, Reoptimizing due to different generation, tunnel gen=47, current gen=50 Sep 13 06:46:43.417 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:46:43.417 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:9, LSP not signalled, identical to the [CURRENT] LSP Sep 13 06:46:45.500 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_PCE Sep 13 06:46:45.500 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 06:46:45.500 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:9, LSP not signalled, identical to the [CURRENT] LSP Sep 13 06:56:05.008 mpls_te/head-end 0/RP0/CPU0 t4565 T:0 Deleted classic Affinity: value 0x1 mask 0x1 Sep 13 06:56:05.009 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACT_CHECK Sep 13 06:56:05.009 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_VERIFY_SR Sep 13 06:56:05.120 mpls_te/head-end 0/RP0/CPU0 t4565 T:0 Added Affinity constraint (count 1): type ignore, value 0x0, Fwd Ref value 0x0 Sep 13 06:56:06.117 mpls_te/head-end 0/RP0/CPU0 t4565 Validating ifindexes for all vifs Sep 13 07:00:13.492 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, handling vif (0x94828d38) scheduled action ACTION_REOPTIMIZE_CLI Sep 13 07:00:13.492 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, POIndex:10, POType:1, ComputationType:1, Holddown:0 Sep 13 07:00:13.493 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, working-reopt initiated: trigger: CLI request, reason: better cumulative metric Sep 13 07:00:13.493 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:9, better cumulative metric Sep 13 07:00:13.555 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, started install timer:20 secs, 100 msec, [CURRENT] L:8, [REOPT] L:9 Sep 13 07:00:33.655 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, Timer[0] expired; install RW for [REOPT] L:9 and start cleanup timer:20 secs Sep 13 07:00:33.655 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:9, TE rewrite returned TRUE Sep 13 07:00:33.657 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, [REOPT] L:9, ifh:0x1c, TE rewrite returned TRUE Sep 13 07:00:53.758 mpls_te/head-end 0/RP0/CPU0 t4565 T:0, Type:TE, cleanup timer expired; destroying [CLEAN] L:8 RP/0/RP0/CPU0:PE1#show mpls traffic-eng trace link Sun Sep 13 07:08:36.598 UTC 317 wrapping entries (67648 possible, 576 allocated, 0 filtered, 317 total) Sep 13 05:46:43.417 mpls_te/link 0/RP0/CPU0 t4565 DS-TE mode change: prev - 0, new - 1 Sep 13 05:46:43.417 mpls_te/link 0/RP0/CPU0 t4565 TE process restarting; aborting DS-TE mode change Sep 13 05:46:45.007 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:381: lm_iarm_control_cb_fn: connection to IARM established. Sep 13 05:46:48.296 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1534: mpls_lcac_ifrs_add: Added new IFRS entry Sep 13 05:46:48.297 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1128: rrr_lm_list_link: Inserted link GigabitEthernet0/0/0/1 (ifh 0x18) into db based on name and handle Sep 13 05:46:48.297 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/1 (ifh 0x18), flood 0, force 0, Nbr cnt 0 Sep 13 05:46:48.297 mpls_te/link 0/RP0/CPU0 t4565 RSI: Registering interface GigabitEthernet0/0/0/1 (ifhndl 0x18) (0x18) for SRLG Notification Sep 13 05:46:48.297 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2544: rrr_lm_create_link: link GigabitEthernet0/0/0/1 (ifh 0x18) Created [1 links total], enable 0 Sep 13 05:46:48.299 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_idb_capacity: link GigabitEthernet0/0/0/1 (ifh 0x18) BW attribute 0 kbps Sep 13 05:46:48.299 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_link_capacity: link GigabitEthernet0/0/0/1 (ifh 0x18) physical_bw 125000000 Bps Sep 13 05:46:48.303 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/1 (ifh 0x18) max_bw 1000000 (Kbps), pool0_bw 1000000 (Kbps) Sep 13 05:46:48.303 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/1 (ifh 0x18) pool1_bw 0 (Kbps) Sep 13 05:46:48.303 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/1 (ifh 0x18), max_res_bw 1000000 (Kbps), Old max_res_bw 0 (Kbps), IP addr 0.0.0.0 Sep 13 05:46:48.303 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/1 (ifh 0x18), Pool0* max_bw 1000000 (Kbps), Old max_bw 0 (Kbps), IP addr 0.0.0.0 Sep 13 05:46:48.303 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/1 (ifh 0x18), max_res_bw 1000000 (Kbps), Old max_res_bw 0 (Kbps), IP addr 0.0.0.0 Sep 13 05:46:48.303 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/1 (ifh 0x18), Pool0* max_bw 1000000 (Kbps), Old max_bw 0 (Kbps), IP addr 0.0.0.0 Sep 13 05:46:48.303 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:518: Bandwidth update handling ignored, link GigabitEthernet0/0/0/1 (ifh 0x18) state down Sep 13 05:46:48.307 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:741: lm_iarm_reg_ipv4_add: added IPv4 register(True) request for interface GigabitEthernet0/0/0/1 (ifh 0x18) to IARM batch Sep 13 05:46:48.307 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:756: lm_iarm_reg_ipv4_add: sent pulse (0) to flush IARM IPv4 registration batch. Sep 13 05:46:48.307 mpls_te/link 0/RP0/CPU0 t4565 Configured link (0x18) with classic affinity: value 0x1 Sep 13 05:46:48.308 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1534: mpls_lcac_ifrs_add: Added new IFRS entry Sep 13 05:46:48.308 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1128: rrr_lm_list_link: Inserted link GigabitEthernet0/0/0/2 (ifh 0x20) into db based on name and handle Sep 13 05:46:48.308 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/2 (ifh 0x20), flood 0, force 0, Nbr cnt 0 Sep 13 05:46:48.308 mpls_te/link 0/RP0/CPU0 t4565 RSI: Registering interface GigabitEthernet0/0/0/2 (ifhndl 0x20) (0x20) for SRLG Notification Sep 13 05:46:48.308 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2544: rrr_lm_create_link: link GigabitEthernet0/0/0/2 (ifh 0x20) Created [2 links total], enable 0 Sep 13 05:46:48.309 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_idb_capacity: link GigabitEthernet0/0/0/2 (ifh 0x20) BW attribute 0 kbps Sep 13 05:46:48.309 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_link_capacity: link GigabitEthernet0/0/0/2 (ifh 0x20) physical_bw 125000000 Bps Sep 13 05:46:48.313 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/2 (ifh 0x20) max_bw 100000 (Kbps), pool0_bw 100000 (Kbps) Sep 13 05:46:48.313 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/2 (ifh 0x20) pool1_bw 0 (Kbps) Sep 13 05:46:48.313 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/2 (ifh 0x20), max_res_bw 100000 (Kbps), Old max_res_bw 0 (Kbps), IP addr 0.0.0.0 Sep 13 05:46:48.313 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/2 (ifh 0x20), Pool0* max_bw 100000 (Kbps), Old max_bw 0 (Kbps), IP addr 0.0.0.0 Sep 13 05:46:48.313 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/2 (ifh 0x20), max_res_bw 100000 (Kbps), Old max_res_bw 0 (Kbps), IP addr 0.0.0.0 Sep 13 05:46:48.313 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/2 (ifh 0x20), Pool0* max_bw 100000 (Kbps), Old max_bw 0 (Kbps), IP addr 0.0.0.0 Sep 13 05:46:48.313 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:518: Bandwidth update handling ignored, link GigabitEthernet0/0/0/2 (ifh 0x20) state down Sep 13 05:46:48.317 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:741: lm_iarm_reg_ipv4_add: added IPv4 register(True) request for interface GigabitEthernet0/0/0/2 (ifh 0x20) to IARM batch Sep 13 05:46:48.317 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1534: mpls_lcac_ifrs_add: Added new IFRS entry Sep 13 05:46:48.317 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1128: rrr_lm_list_link: Inserted link GigabitEthernet0/0/0/3 (ifh 0x28) into db based on name and handle Sep 13 05:46:48.318 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/3 (ifh 0x28), flood 0, force 0, Nbr cnt 0 Sep 13 05:46:48.318 mpls_te/link 0/RP0/CPU0 t4565 RSI: Registering interface GigabitEthernet0/0/0/3 (ifhndl 0x28) (0x28) for SRLG Notification Sep 13 05:46:48.318 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2544: rrr_lm_create_link: link GigabitEthernet0/0/0/3 (ifh 0x28) Created [3 links total], enable 0 Sep 13 05:46:48.318 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_idb_capacity: link GigabitEthernet0/0/0/3 (ifh 0x28) BW attribute 0 kbps Sep 13 05:46:48.318 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_link_capacity: link GigabitEthernet0/0/0/3 (ifh 0x28) physical_bw 125000000 Bps Sep 13 05:46:48.397 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/3 (ifh 0x28) max_bw 1000000 (Kbps), pool0_bw 1000000 (Kbps) Sep 13 05:46:48.397 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/3 (ifh 0x28) pool1_bw 0 (Kbps) Sep 13 05:46:48.397 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/3 (ifh 0x28), max_res_bw 1000000 (Kbps), Old max_res_bw 0 (Kbps), IP addr 0.0.0.0 Sep 13 05:46:48.397 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/3 (ifh 0x28), Pool0* max_bw 1000000 (Kbps), Old max_bw 0 (Kbps), IP addr 0.0.0.0 Sep 13 05:46:48.397 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/3 (ifh 0x28), max_res_bw 1000000 (Kbps), Old max_res_bw 0 (Kbps), IP addr 0.0.0.0 Sep 13 05:46:48.397 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_set_link_bandwidth(): link GigabitEthernet0/0/0/3 (ifh 0x28), Pool0* max_bw 1000000 (Kbps), Old max_bw 0 (Kbps), IP addr 0.0.0.0 Sep 13 05:46:48.397 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:518: Bandwidth update handling ignored, link GigabitEthernet0/0/0/3 (ifh 0x28) state down Sep 13 05:46:48.401 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:741: lm_iarm_reg_ipv4_add: added IPv4 register(True) request for interface GigabitEthernet0/0/0/3 (ifh 0x28) to IARM batch Sep 13 05:46:48.401 mpls_te/link 0/RP0/CPU0 t4565 Configured link (0x28) with classic affinity: value 0x2 Sep 13 05:46:48.402 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3722: lm_im_handler: link GigabitEthernet0/0/0/1 (ifh 0x18), state 17, proto 0, opcode 35 (CREATE/DEL) Sep 13 05:46:48.402 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3727: lm_im_handler: link GigabitEthernet0/0/0/1 (ifh 0x18), intf_type 15, parent i/f None (ifh 0x0), caps 0 Sep 13 05:46:48.402 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3808: lm_im_handler: IM_CREATE: link GigabitEthernet0/0/0/1 (ifh 0x18), state 17, proto 0, opcode 35 Sep 13 05:46:48.402 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3881: lm_im_handler: Updating link GigabitEthernet0/0/0/1 (ifh 0x18), intf_type 15, data_parent i/f None (ifh 0x0) (IM_CREATE) Sep 13 05:46:48.402 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_idb_capacity: link GigabitEthernet0/0/0/1 (ifh 0x18) BW attribute 0 kbps Sep 13 05:46:48.402 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_link_capacity: link GigabitEthernet0/0/0/1 (ifh 0x18) physical_bw 125000000 Bps Sep 13 05:46:48.402 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/1 (ifh 0x18) max_bw 1000000 (Kbps), pool0_bw 1000000 (Kbps) Sep 13 05:46:48.402 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/1 (ifh 0x18) pool1_bw 0 (Kbps) Sep 13 05:46:48.402 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/1 (ifh 0x18) max_bw 0 (Kbps), pool0_bw 0 (Kbps) Sep 13 05:46:48.402 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/1 (ifh 0x18) pool1_bw 0 (Kbps) Sep 13 05:46:48.402 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5281: Flooding on link GigabitEthernet0/0/0/1 (ifh 0x18) suppressed, system not ready Sep 13 05:46:48.402 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3722: lm_im_handler: link GigabitEthernet0/0/0/2 (ifh 0x20), state 17, proto 0, opcode 35 (CREATE/DEL) Sep 13 05:46:48.402 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3727: lm_im_handler: link GigabitEthernet0/0/0/2 (ifh 0x20), intf_type 15, parent i/f None (ifh 0x0), caps 0 Sep 13 05:46:48.402 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3808: lm_im_handler: IM_CREATE: link GigabitEthernet0/0/0/2 (ifh 0x20), state 17, proto 0, opcode 35 Sep 13 05:46:48.403 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3881: lm_im_handler: Updating link GigabitEthernet0/0/0/2 (ifh 0x20), intf_type 15, data_parent i/f None (ifh 0x0) (IM_CREATE) Sep 13 05:46:48.403 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_idb_capacity: link GigabitEthernet0/0/0/2 (ifh 0x20) BW attribute 0 kbps Sep 13 05:46:48.403 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_link_capacity: link GigabitEthernet0/0/0/2 (ifh 0x20) physical_bw 125000000 Bps Sep 13 05:46:48.403 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/2 (ifh 0x20) max_bw 100000 (Kbps), pool0_bw 100000 (Kbps) Sep 13 05:46:48.403 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/2 (ifh 0x20) pool1_bw 0 (Kbps) Sep 13 05:46:48.403 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/2 (ifh 0x20) max_bw 0 (Kbps), pool0_bw 0 (Kbps) Sep 13 05:46:48.403 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/2 (ifh 0x20) pool1_bw 0 (Kbps) Sep 13 05:46:48.403 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5281: Flooding on link GigabitEthernet0/0/0/2 (ifh 0x20) suppressed, system not ready Sep 13 05:46:48.403 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3722: lm_im_handler: link GigabitEthernet0/0/0/3 (ifh 0x28), state 17, proto 0, opcode 35 (CREATE/DEL) Sep 13 05:46:48.403 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3727: lm_im_handler: link GigabitEthernet0/0/0/3 (ifh 0x28), intf_type 15, parent i/f None (ifh 0x0), caps 0 Sep 13 05:46:48.403 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3808: lm_im_handler: IM_CREATE: link GigabitEthernet0/0/0/3 (ifh 0x28), state 17, proto 0, opcode 35 Sep 13 05:46:48.404 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3881: lm_im_handler: Updating link GigabitEthernet0/0/0/3 (ifh 0x28), intf_type 15, data_parent i/f None (ifh 0x0) (IM_CREATE) Sep 13 05:46:48.404 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_idb_capacity: link GigabitEthernet0/0/0/3 (ifh 0x28) BW attribute 0 kbps Sep 13 05:46:48.404 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_link_capacity: link GigabitEthernet0/0/0/3 (ifh 0x28) physical_bw 125000000 Bps Sep 13 05:46:48.404 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/3 (ifh 0x28) max_bw 1000000 (Kbps), pool0_bw 1000000 (Kbps) Sep 13 05:46:48.404 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/3 (ifh 0x28) pool1_bw 0 (Kbps) Sep 13 05:46:48.404 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/3 (ifh 0x28) max_bw 0 (Kbps), pool0_bw 0 (Kbps) Sep 13 05:46:48.404 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/3 (ifh 0x28) pool1_bw 0 (Kbps) Sep 13 05:46:48.404 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5281: Flooding on link GigabitEthernet0/0/0/3 (ifh 0x28) suppressed, system not ready Sep 13 05:46:48.404 mpls_te/link 0/RP0/CPU0 t4565 RSI: Synchronous batch handler: 3 items Sep 13 05:46:48.404 mpls_te/link 0/RP0/CPU0 t4565 RSI: Event Update with 0 SRLG values for GigabitEthernet0/0/0/1 (ifhndl 0x18) (0x18) [change: NO, old count 0] Sep 13 05:46:48.404 mpls_te/link 0/RP0/CPU0 t4565 RSI: Event Update with 0 SRLG values for GigabitEthernet0/0/0/2 (ifhndl 0x20) (0x20) [change: NO, old count 0] Sep 13 05:46:48.404 mpls_te/link 0/RP0/CPU0 t4565 RSI: Event Update with 0 SRLG values for GigabitEthernet0/0/0/3 (ifhndl 0x28) (0x28) [change: NO, old count 0] Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 RSI: Sent registration for 3 interfaces (Success 3, failure 0) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_im_attr_capacity_handler: link MgmtEth0/RP0/CPU0/0 (ifh 0x8),bw 1000000 (kbps), bw2 125000000 (Bps), event 0 Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_im_attr_capacity_handler: link GigabitEthernet0/0/0/0 (ifh 0x10),bw 1000000 (kbps), bw2 125000000 (Bps), event 0 Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_im_attr_capacity_handler: link GigabitEthernet0/0/0/1 (ifh 0x18),bw 1000000 (kbps), bw2 125000000 (Bps), event 0 Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_process_link_capacity(): capacity not changed link GigabitEthernet0/0/0/1 (ifh 0x18), current bw 125000000 (Kbps), new bw 125000000 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/1 (ifh 0x18) max_bw 1000000 (Kbps), pool0_bw 1000000 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/1 (ifh 0x18) pool1_bw 0 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/1 (ifh 0x18) max_bw 0 (Kbps), pool0_bw 0 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/1 (ifh 0x18) pool1_bw 0 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_im_attr_capacity_handler: link GigabitEthernet0/0/0/2 (ifh 0x20),bw 1000000 (kbps), bw2 125000000 (Bps), event 0 Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_process_link_capacity(): capacity not changed link GigabitEthernet0/0/0/2 (ifh 0x20), current bw 125000000 (Kbps), new bw 125000000 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/2 (ifh 0x20) max_bw 100000 (Kbps), pool0_bw 100000 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/2 (ifh 0x20) pool1_bw 0 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/2 (ifh 0x20) max_bw 0 (Kbps), pool0_bw 0 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/2 (ifh 0x20) pool1_bw 0 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_im_attr_capacity_handler: link GigabitEthernet0/0/0/3 (ifh 0x28),bw 1000000 (kbps), bw2 125000000 (Bps), event 0 Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_process_link_capacity(): capacity not changed link GigabitEthernet0/0/0/3 (ifh 0x28), current bw 125000000 (Kbps), new bw 125000000 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/3 (ifh 0x28) max_bw 1000000 (Kbps), pool0_bw 1000000 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/3 (ifh 0x28) pool1_bw 0 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/3 (ifh 0x28) max_bw 0 (Kbps), pool0_bw 0 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/3 (ifh 0x28) pool1_bw 0 (Kbps) Sep 13 05:46:48.405 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:279: lm_iarm_handle_pulse: received pulse (0), flushing IARM IPv4 registration batch. Sep 13 05:46:48.406 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:623: lm_iarm_flush: sent 3 IPv4 (un)register requests to IARM. Sep 13 05:46:49.007 mpls_te/link 0/RP0/CPU0 t4565 SRLG-producer connected Sep 13 05:46:49.008 mpls_te/link 0/RP0/CPU0 t4565 RSI SRLG-producer registration done successfully Sep 13 05:46:49.008 mpls_te/link 0/RP0/CPU0 t4565 Replaying learned SRLGs on all links to RSI Sep 13 05:46:49.008 mpls_te/link 0/RP0/CPU0 t4565 Replaying learned SRLGs on all termination interfaces to RSI Sep 13 05:46:49.303 mpls_te/link 0/RP0/CPU0 t4565 Validating ifindexes for all links Sep 13 05:46:49.303 mpls_te/link 0/RP0/CPU0 t4565 Bulk ifindex lookup for 3 links Sep 13 05:46:49.305 mpls_te/link 0/RP0/CPU0 t4565 Link GigabitEthernet0/0/0/1 (ifhndl 0x18) (0x18) ifindex set to 5 Sep 13 05:46:49.305 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/1 (ifh 0x18), flood 0, force 1, Nbr cnt 0 Sep 13 05:46:49.394 mpls_te/link 0/RP0/CPU0 t4565 Link GigabitEthernet0/0/0/2 (ifhndl 0x20) (0x20) ifindex set to 6 Sep 13 05:46:49.394 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/2 (ifh 0x20), flood 0, force 1, Nbr cnt 0 Sep 13 05:46:49.394 mpls_te/link 0/RP0/CPU0 t4565 Link GigabitEthernet0/0/0/3 (ifhndl 0x28) (0x28) ifindex set to 7 Sep 13 05:46:49.394 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/3 (ifh 0x28), flood 0, force 1, Nbr cnt 0 Sep 13 05:46:50.712 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:119: Unable to process adj-change from IGP OSPFarea 0 on link Loopback0 (ifh 0x14) with handle 0x14, reverting to name Sep 13 05:46:50.713 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:145: Unable to process adj-change from IGP OSPF area 0 on link Loopback0 (ifh 0x14) (0 nbrs): link not found Sep 13 05:46:53.208 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2611: Handling area change: IGP OSPF area 0, is_up = 1, router-id 2.2.2.2 Sep 13 05:46:53.208 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/1 (ifh 0x18), flood 0, force 0, Nbr cnt 0 Sep 13 05:46:53.208 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/2 (ifh 0x20), flood 0, force 0, Nbr cnt 0 Sep 13 05:46:53.208 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/3 (ifh 0x28), flood 0, force 0, Nbr cnt 0 Sep 13 05:46:53.208 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5406: Periodic Flooding for igp-type: 2 area: 0 0 seconds Sep 13 05:46:53.209 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5214: System change: flooding to all links/areas: reason area state change Sep 13 05:46:56.195 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3722: lm_im_handler: link GigabitEthernet0/0/0/1 (ifh 0x18), state 17, proto 12, opcode 35 (CREATE/DEL) Sep 13 05:46:56.195 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3727: lm_im_handler: link GigabitEthernet0/0/0/1 (ifh 0x18), intf_type 15, parent i/f None (ifh 0x0), caps 26 Sep 13 05:46:56.195 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3808: lm_im_handler: IM_CREATE: link GigabitEthernet0/0/0/1 (ifh 0x18), state 17, proto 12, opcode 35 Sep 13 05:46:56.196 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:875: mpls_lcac_if_state_register: link GigabitEthernet0/0/0/1 (ifh 0x18), add True Sep 13 05:46:56.196 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:741: lm_iarm_reg_ipv4_add: added IPv4 register(True) request for interface GigabitEthernet0/0/0/1 (ifh 0x18) to IARM batch Sep 13 05:46:56.196 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:756: lm_iarm_reg_ipv4_add: sent pulse (0) to flush IARM IPv4 registration batch. Sep 13 05:46:56.196 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3881: lm_im_handler: Updating link GigabitEthernet0/0/0/1 (ifh 0x18), intf_type 15, data_parent i/f None (ifh 0x0) (IM_CREATE) Sep 13 05:46:56.196 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_idb_capacity: link GigabitEthernet0/0/0/1 (ifh 0x18) BW attribute 0 kbps Sep 13 05:46:56.196 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_link_capacity: link GigabitEthernet0/0/0/1 (ifh 0x18) physical_bw 125000000 Bps Sep 13 05:46:56.196 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/1 (ifh 0x18) max_bw 1000000 (Kbps), pool0_bw 1000000 (Kbps) Sep 13 05:46:56.196 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/1 (ifh 0x18) pool1_bw 0 (Kbps) Sep 13 05:46:56.196 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/1 (ifh 0x18) max_bw 0 (Kbps), pool0_bw 0 (Kbps) Sep 13 05:46:56.196 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/1 (ifh 0x18) pool1_bw 0 (Kbps) Sep 13 05:46:56.196 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5304: Flooding on link GigabitEthernet0/0/0/1 (ifh 0x18) suppressed, no change Sep 13 05:46:56.196 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3722: lm_im_handler: link GigabitEthernet0/0/0/2 (ifh 0x20), state 17, proto 12, opcode 35 (CREATE/DEL) Sep 13 05:46:56.196 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3727: lm_im_handler: link GigabitEthernet0/0/0/2 (ifh 0x20), intf_type 15, parent i/f None (ifh 0x0), caps 26 Sep 13 05:46:56.196 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3808: lm_im_handler: IM_CREATE: link GigabitEthernet0/0/0/2 (ifh 0x20), state 17, proto 12, opcode 35 Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:875: mpls_lcac_if_state_register: link GigabitEthernet0/0/0/2 (ifh 0x20), add True Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:741: lm_iarm_reg_ipv4_add: added IPv4 register(True) request for interface GigabitEthernet0/0/0/2 (ifh 0x20) to IARM batch Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3881: lm_im_handler: Updating link GigabitEthernet0/0/0/2 (ifh 0x20), intf_type 15, data_parent i/f None (ifh 0x0) (IM_CREATE) Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_idb_capacity: link GigabitEthernet0/0/0/2 (ifh 0x20) BW attribute 0 kbps Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_link_capacity: link GigabitEthernet0/0/0/2 (ifh 0x20) physical_bw 125000000 Bps Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/2 (ifh 0x20) max_bw 100000 (Kbps), pool0_bw 100000 (Kbps) Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/2 (ifh 0x20) pool1_bw 0 (Kbps) Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/2 (ifh 0x20) max_bw 0 (Kbps), pool0_bw 0 (Kbps) Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/2 (ifh 0x20) pool1_bw 0 (Kbps) Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5304: Flooding on link GigabitEthernet0/0/0/2 (ifh 0x20) suppressed, no change Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3722: lm_im_handler: link GigabitEthernet0/0/0/3 (ifh 0x28), state 17, proto 12, opcode 35 (CREATE/DEL) Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3727: lm_im_handler: link GigabitEthernet0/0/0/3 (ifh 0x28), intf_type 15, parent i/f None (ifh 0x0), caps 26 Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3808: lm_im_handler: IM_CREATE: link GigabitEthernet0/0/0/3 (ifh 0x28), state 17, proto 12, opcode 35 Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:875: mpls_lcac_if_state_register: link GigabitEthernet0/0/0/3 (ifh 0x28), add True Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:741: lm_iarm_reg_ipv4_add: added IPv4 register(True) request for interface GigabitEthernet0/0/0/3 (ifh 0x28) to IARM batch Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3881: lm_im_handler: Updating link GigabitEthernet0/0/0/3 (ifh 0x28), intf_type 15, data_parent i/f None (ifh 0x0) (IM_CREATE) Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_idb_capacity: link GigabitEthernet0/0/0/3 (ifh 0x28) BW attribute 0 kbps Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_link_capacity: link GigabitEthernet0/0/0/3 (ifh 0x28) physical_bw 125000000 Bps Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/3 (ifh 0x28) max_bw 1000000 (Kbps), pool0_bw 1000000 (Kbps) Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_rdm_apply: link GigabitEthernet0/0/0/3 (ifh 0x28) pool1_bw 0 (Kbps) Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/3 (ifh 0x28) max_bw 0 (Kbps), pool0_bw 0 (Kbps) Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: mpls_lcac_cfg_int_bandwidth_mam_apply: link GigabitEthernet0/0/0/3 (ifh 0x28) pool1_bw 0 (Kbps) Sep 13 05:46:56.197 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5304: Flooding on link GigabitEthernet0/0/0/3 (ifh 0x28) suppressed, no change Sep 13 05:46:56.198 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3700: lm_im_handler: link GigabitEthernet0/0/0/1 (ifh 0x18), state 1, proto 12, caps 26, opcode=STATE_VALUE Sep 13 05:46:56.198 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3765: lm_im_handler: IFSTATE_VAL: link GigabitEthernet0/0/0/1 (ifh 0x18), state 1, proto 12, opcode 37 Sep 13 05:46:56.198 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3700: lm_im_handler: link GigabitEthernet0/0/0/2 (ifh 0x20), state 1, proto 12, caps 26, opcode=STATE_VALUE Sep 13 05:46:56.198 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3765: lm_im_handler: IFSTATE_VAL: link GigabitEthernet0/0/0/2 (ifh 0x20), state 1, proto 12, opcode 37 Sep 13 05:46:56.198 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3700: lm_im_handler: link GigabitEthernet0/0/0/3 (ifh 0x28), state 1, proto 12, caps 26, opcode=STATE_VALUE Sep 13 05:46:56.198 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3765: lm_im_handler: IFSTATE_VAL: link GigabitEthernet0/0/0/3 (ifh 0x28), state 1, proto 12, opcode 37 Sep 13 05:46:56.198 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:279: lm_iarm_handle_pulse: received pulse (0), flushing IARM IPv4 registration batch. Sep 13 05:46:56.198 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:623: lm_iarm_flush: sent 3 IPv4 (un)register requests to IARM. Sep 13 05:46:56.301 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:797: lm_ipv4_addr_callback: link GigabitEthernet0/0/0/1 (ifh 0x18), ct=0x0, ps=0x0, addr 10.2.3.2 Sep 13 05:46:56.301 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:797: lm_ipv4_addr_callback: link GigabitEthernet0/0/0/2 (ifh 0x20), ct=0x0, ps=0x0, addr 10.2.5.2 Sep 13 05:46:56.301 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:797: lm_ipv4_addr_callback: link GigabitEthernet0/0/0/3 (ifh 0x28), ct=0x0, ps=0x0, addr 10.2.7.2 Sep 13 05:46:56.602 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3700: lm_im_handler: link GigabitEthernet0/0/0/1 (ifh 0x18), state 2, proto 12, caps 26, opcode=STATE_VALUE Sep 13 05:46:56.602 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3765: lm_im_handler: IFSTATE_VAL: link GigabitEthernet0/0/0/1 (ifh 0x18), state 2, proto 12, opcode 37 Sep 13 05:46:56.602 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3700: lm_im_handler: link GigabitEthernet0/0/0/2 (ifh 0x20), state 2, proto 12, caps 26, opcode=STATE_VALUE Sep 13 05:46:56.602 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3765: lm_im_handler: IFSTATE_VAL: link GigabitEthernet0/0/0/2 (ifh 0x20), state 2, proto 12, opcode 37 Sep 13 05:46:56.602 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3700: lm_im_handler: link GigabitEthernet0/0/0/3 (ifh 0x28), state 2, proto 12, caps 26, opcode=STATE_VALUE Sep 13 05:46:56.602 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3765: lm_im_handler: IFSTATE_VAL: link GigabitEthernet0/0/0/3 (ifh 0x28), state 2, proto 12, opcode 37 Sep 13 05:46:56.902 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3700: lm_im_handler: link GigabitEthernet0/0/0/1 (ifh 0x18), state 3, proto 12, caps 26, opcode=STATE_VALUE Sep 13 05:46:56.902 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3765: lm_im_handler: IFSTATE_VAL: link GigabitEthernet0/0/0/1 (ifh 0x18), state 3, proto 12, opcode 37 Sep 13 05:46:56.902 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/1 (ifh 0x18), flood 0, force 0, Nbr cnt 0 Sep 13 05:46:56.902 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5494: Request link adjacencies for link GigabitEthernet0/0/0/1 (ifh 0x18), area 0, IGP OSPF Sep 13 05:46:57.099 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3700: lm_im_handler: link GigabitEthernet0/0/0/2 (ifh 0x20), state 3, proto 12, caps 26, opcode=STATE_VALUE Sep 13 05:46:57.099 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3765: lm_im_handler: IFSTATE_VAL: link GigabitEthernet0/0/0/2 (ifh 0x20), state 3, proto 12, opcode 37 Sep 13 05:46:57.099 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/2 (ifh 0x20), flood 0, force 0, Nbr cnt 0 Sep 13 05:46:57.099 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5494: Request link adjacencies for link GigabitEthernet0/0/0/2 (ifh 0x20), area 0, IGP OSPF Sep 13 05:46:57.103 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2565: Processing adj-change for link GigabitEthernet0/0/0/1 (ifh 0x18) (0 nbrs) in area 0, IGP OSPF Sep 13 05:46:57.103 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2451: rrr_lm_handle_igp_link_info_change: OSPF- link GigabitEthernet0/0/0/1 (ifh 0x18), tot_nbrs 0, subnet type 0, flags 0x2 Sep 13 05:46:57.103 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2471: rrr_lm_handle_igp_link_info_change: link GigabitEthernet0/0/0/1 (ifh 0x18) new igp admin weight 30, prev. isis wt 0, ospf wt 0 Sep 13 05:46:57.103 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:935: Link GigabitEthernet0/0/0/1 (ifh 0x18): Added area 0 IGP OSPF Sep 13 05:46:57.103 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1019: Link GigabitEthernet0/0/0/1 (ifh 0x18): Update nbrs for area 0 IGP OSPF Sep 13 05:46:57.104 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1345: setting IGP cost for link GigabitEthernet0/0/0/1 (ifh 0x18), area 0, protocol OSPF, weight 30 Sep 13 05:46:57.104 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2523: link GigabitEthernet0/0/0/1 (ifh 0x18), IGP OSPF area 0: no neighbor changes Sep 13 05:46:57.104 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5295: Flooding on link GigabitEthernet0/0/0/1 (ifh 0x18) data changed Sep 13 05:46:57.104 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3700: lm_im_handler: link GigabitEthernet0/0/0/3 (ifh 0x28), state 3, proto 12, caps 26, opcode=STATE_VALUE Sep 13 05:46:57.104 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3765: lm_im_handler: IFSTATE_VAL: link GigabitEthernet0/0/0/3 (ifh 0x28), state 3, proto 12, opcode 37 Sep 13 05:46:57.104 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/3 (ifh 0x28), flood 0, force 0, Nbr cnt 0 Sep 13 05:46:57.104 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5494: Request link adjacencies for link GigabitEthernet0/0/0/3 (ifh 0x28), area 0, IGP OSPF Sep 13 05:46:57.106 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2565: Processing adj-change for link GigabitEthernet0/0/0/2 (ifh 0x20) (0 nbrs) in area 0, IGP OSPF Sep 13 05:46:57.106 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2451: rrr_lm_handle_igp_link_info_change: OSPF- link GigabitEthernet0/0/0/2 (ifh 0x20), tot_nbrs 0, subnet type 0, flags 0x2 Sep 13 05:46:57.106 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2471: rrr_lm_handle_igp_link_info_change: link GigabitEthernet0/0/0/2 (ifh 0x20) new igp admin weight 10, prev. isis wt 0, ospf wt 0 Sep 13 05:46:57.106 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:935: Link GigabitEthernet0/0/0/2 (ifh 0x20): Added area 0 IGP OSPF Sep 13 05:46:57.106 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1019: Link GigabitEthernet0/0/0/2 (ifh 0x20): Update nbrs for area 0 IGP OSPF Sep 13 05:46:57.106 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1345: setting IGP cost for link GigabitEthernet0/0/0/2 (ifh 0x20), area 0, protocol OSPF, weight 10 Sep 13 05:46:57.106 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2523: link GigabitEthernet0/0/0/2 (ifh 0x20), IGP OSPF area 0: no neighbor changes Sep 13 05:46:57.106 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5295: Flooding on link GigabitEthernet0/0/0/2 (ifh 0x20) data changed Sep 13 05:46:57.107 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2565: Processing adj-change for link GigabitEthernet0/0/0/1 (ifh 0x18) (0 nbrs) in area 0, IGP OSPF Sep 13 05:46:57.107 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2451: rrr_lm_handle_igp_link_info_change: OSPF- link GigabitEthernet0/0/0/1 (ifh 0x18), tot_nbrs 0, subnet type 0, flags 0x2 Sep 13 05:46:57.107 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2471: rrr_lm_handle_igp_link_info_change: link GigabitEthernet0/0/0/1 (ifh 0x18) new igp admin weight 30, prev. isis wt 0, ospf wt 0 Sep 13 05:46:57.107 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2523: link GigabitEthernet0/0/0/1 (ifh 0x18), IGP OSPF area 0: no neighbor changes Sep 13 05:46:57.107 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2565: Processing adj-change for link GigabitEthernet0/0/0/2 (ifh 0x20) (0 nbrs) in area 0, IGP OSPF Sep 13 05:46:57.107 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2451: rrr_lm_handle_igp_link_info_change: OSPF- link GigabitEthernet0/0/0/2 (ifh 0x20), tot_nbrs 0, subnet type 0, flags 0x2 Sep 13 05:46:57.107 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2471: rrr_lm_handle_igp_link_info_change: link GigabitEthernet0/0/0/2 (ifh 0x20) new igp admin weight 10, prev. isis wt 0, ospf wt 0 Sep 13 05:46:57.107 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2523: link GigabitEthernet0/0/0/2 (ifh 0x20), IGP OSPF area 0: no neighbor changes Sep 13 05:46:57.200 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2565: Processing adj-change for link GigabitEthernet0/0/0/3 (ifh 0x28) (0 nbrs) in area 0, IGP OSPF Sep 13 05:46:57.200 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2451: rrr_lm_handle_igp_link_info_change: OSPF- link GigabitEthernet0/0/0/3 (ifh 0x28), tot_nbrs 0, subnet type 0, flags 0x2 Sep 13 05:46:57.200 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2471: rrr_lm_handle_igp_link_info_change: link GigabitEthernet0/0/0/3 (ifh 0x28) new igp admin weight 20, prev. isis wt 0, ospf wt 0 Sep 13 05:46:57.200 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:935: Link GigabitEthernet0/0/0/3 (ifh 0x28): Added area 0 IGP OSPF Sep 13 05:46:57.200 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1019: Link GigabitEthernet0/0/0/3 (ifh 0x28): Update nbrs for area 0 IGP OSPF Sep 13 05:46:57.200 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1345: setting IGP cost for link GigabitEthernet0/0/0/3 (ifh 0x28), area 0, protocol OSPF, weight 20 Sep 13 05:46:57.200 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2523: link GigabitEthernet0/0/0/3 (ifh 0x28), IGP OSPF area 0: no neighbor changes Sep 13 05:46:57.200 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5295: Flooding on link GigabitEthernet0/0/0/3 (ifh 0x28) data changed Sep 13 05:46:57.200 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2565: Processing adj-change for link GigabitEthernet0/0/0/3 (ifh 0x28) (0 nbrs) in area 0, IGP OSPF Sep 13 05:46:57.200 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2451: rrr_lm_handle_igp_link_info_change: OSPF- link GigabitEthernet0/0/0/3 (ifh 0x28), tot_nbrs 0, subnet type 0, flags 0x2 Sep 13 05:46:57.200 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2471: rrr_lm_handle_igp_link_info_change: link GigabitEthernet0/0/0/3 (ifh 0x28) new igp admin weight 20, prev. isis wt 0, ospf wt 0 Sep 13 05:46:57.200 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2523: link GigabitEthernet0/0/0/3 (ifh 0x28), IGP OSPF area 0: no neighbor changes Sep 13 05:46:57.303 mpls_te/link 0/RP0/CPU0 t4565 Validating ifindexes for all links Sep 13 05:46:57.926 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2565: Processing adj-change for link GigabitEthernet0/0/0/2 (ifh 0x20) (0 nbrs) in area 0, IGP OSPF Sep 13 05:46:57.926 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2451: rrr_lm_handle_igp_link_info_change: OSPF- link GigabitEthernet0/0/0/2 (ifh 0x20), tot_nbrs 0, subnet type 1, flags 0xb Sep 13 05:46:57.926 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1019: Link GigabitEthernet0/0/0/2 (ifh 0x20): Update nbrs for area 0 IGP OSPF Sep 13 05:46:57.926 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1515: setting subnet type for link GigabitEthernet0/0/0/2 (ifh 0x20), area 0, protocol 2, subnet type 1 Sep 13 05:46:57.926 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2471: rrr_lm_handle_igp_link_info_change: link GigabitEthernet0/0/0/2 (ifh 0x20) new igp admin weight 10, prev. isis wt 0, ospf wt 0 Sep 13 05:46:57.926 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2498: Link GigabitEthernet0/0/0/2 (ifh 0x20): update DB for 1 neighbors Sep 13 05:46:57.926 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1559: Received neighbor 10.2.5.5 on link GigabitEthernet0/0/0/2 (ifh 0x20), IGP OSPF area 0 Sep 13 05:46:57.926 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1578: Rcvd nbr node ID 5.5.5.5, state 1 Sep 13 05:46:57.926 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1596: Matching existing neighbor found? False Sep 13 05:46:57.926 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1714: Neighbor unknown: creating new one Sep 13 05:46:57.926 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1286: link GigabitEthernet0/0/0/2 (ifh 0x20): setting IGP cost: 10, in area 0, protocol OSPF Sep 13 05:46:57.926 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1429: link GigabitEthernet0/0/0/2 (ifh 0x20), IGP OSPF area 0: subnet type changed to 1 Sep 13 05:46:57.927 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1825: Neighbor created link GigabitEthernet0/0/0/2 (ifh 0x20) nbr addr 10.2.5.5, count 1, nbr state 1 Sep 13 05:46:57.927 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5295: Flooding on link GigabitEthernet0/0/0/2 (ifh 0x20) data changed Sep 13 05:47:02.725 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2565: Processing adj-change for link GigabitEthernet0/0/0/3 (ifh 0x28) (0 nbrs) in area 0, IGP OSPF Sep 13 05:47:02.725 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2451: rrr_lm_handle_igp_link_info_change: OSPF- link GigabitEthernet0/0/0/3 (ifh 0x28), tot_nbrs 0, subnet type 1, flags 0xb Sep 13 05:47:02.725 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1019: Link GigabitEthernet0/0/0/3 (ifh 0x28): Update nbrs for area 0 IGP OSPF Sep 13 05:47:02.725 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1515: setting subnet type for link GigabitEthernet0/0/0/3 (ifh 0x28), area 0, protocol 2, subnet type 1 Sep 13 05:47:02.725 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2471: rrr_lm_handle_igp_link_info_change: link GigabitEthernet0/0/0/3 (ifh 0x28) new igp admin weight 20, prev. isis wt 0, ospf wt 0 Sep 13 05:47:02.725 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2498: Link GigabitEthernet0/0/0/3 (ifh 0x28): update DB for 1 neighbors Sep 13 05:47:02.725 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1559: Received neighbor 10.2.7.7 on link GigabitEthernet0/0/0/3 (ifh 0x28), IGP OSPF area 0 Sep 13 05:47:02.725 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1578: Rcvd nbr node ID 7.7.7.7, state 1 Sep 13 05:47:02.725 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1596: Matching existing neighbor found? False Sep 13 05:47:02.725 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1714: Neighbor unknown: creating new one Sep 13 05:47:02.725 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1286: link GigabitEthernet0/0/0/3 (ifh 0x28): setting IGP cost: 20, in area 0, protocol OSPF Sep 13 05:47:02.725 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1429: link GigabitEthernet0/0/0/3 (ifh 0x28), IGP OSPF area 0: subnet type changed to 1 Sep 13 05:47:02.725 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1825: Neighbor created link GigabitEthernet0/0/0/3 (ifh 0x28) nbr addr 10.2.7.7, count 2, nbr state 1 Sep 13 05:47:02.725 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5295: Flooding on link GigabitEthernet0/0/0/3 (ifh 0x28) data changed Sep 13 05:47:04.663 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2565: Processing adj-change for link GigabitEthernet0/0/0/1 (ifh 0x18) (0 nbrs) in area 0, IGP OSPF Sep 13 05:47:04.663 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2451: rrr_lm_handle_igp_link_info_change: OSPF- link GigabitEthernet0/0/0/1 (ifh 0x18), tot_nbrs 0, subnet type 1, flags 0xb Sep 13 05:47:04.663 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1019: Link GigabitEthernet0/0/0/1 (ifh 0x18): Update nbrs for area 0 IGP OSPF Sep 13 05:47:04.663 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1515: setting subnet type for link GigabitEthernet0/0/0/1 (ifh 0x18), area 0, protocol 2, subnet type 1 Sep 13 05:47:04.663 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2471: rrr_lm_handle_igp_link_info_change: link GigabitEthernet0/0/0/1 (ifh 0x18) new igp admin weight 30, prev. isis wt 0, ospf wt 0 Sep 13 05:47:04.663 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2498: Link GigabitEthernet0/0/0/1 (ifh 0x18): update DB for 1 neighbors Sep 13 05:47:04.663 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1559: Received neighbor 10.2.3.3 on link GigabitEthernet0/0/0/1 (ifh 0x18), IGP OSPF area 0 Sep 13 05:47:04.663 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1578: Rcvd nbr node ID 3.3.3.3, state 1 Sep 13 05:47:04.663 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1596: Matching existing neighbor found? False Sep 13 05:47:04.663 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1714: Neighbor unknown: creating new one Sep 13 05:47:04.663 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1286: link GigabitEthernet0/0/0/1 (ifh 0x18): setting IGP cost: 30, in area 0, protocol OSPF Sep 13 05:47:04.663 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1429: link GigabitEthernet0/0/0/1 (ifh 0x18), IGP OSPF area 0: subnet type changed to 1 Sep 13 05:47:04.663 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1825: Neighbor created link GigabitEthernet0/0/0/1 (ifh 0x18) nbr addr 10.2.3.3, count 3, nbr state 1 Sep 13 05:47:04.663 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5295: Flooding on link GigabitEthernet0/0/0/1 (ifh 0x18) data changed Sep 13 05:49:48.602 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5471: Forced Flooding for IGP OSPF, area 0 Sep 13 05:54:24.720 mpls_te/link 0/RP0/CPU0 t4565 RSI: Asynchronous batch handler: 1 items Sep 13 05:54:24.720 mpls_te/link 0/RP0/CPU0 t4565 RSI: Event Update with 1 SRLG values for GigabitEthernet0/0/0/3 (ifhndl 0x28) (0x28) [change: YES, old count 0] Sep 13 05:54:24.720 mpls_te/link 0/RP0/CPU0 t4565 RSI: Deleting all 0 SRLG values for GigabitEthernet0/0/0/3 (ifhndl 0x28) (0x28) Sep 13 05:54:24.720 mpls_te/link 0/RP0/CPU0 t4565 RSI: Adding all 1 SRLG values to GigabitEthernet0/0/0/3 (ifhndl 0x28) (0x28) Sep 13 05:54:24.720 mpls_te/link 0/RP0/CPU0 t4565 RSI: Added SRLG value 100 to GigabitEthernet0/0/0/3 (ifhndl 0x28) (0x28) => [Total SRLGs for link: 1] Sep 13 05:54:24.720 mpls_te/link 0/RP0/CPU0 t4565 RSI: Checkpointing 1 SRLG values for GigabitEthernet0/0/0/3 (ifhndl 0x28) (0x28) Sep 13 05:54:24.720 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5399: SRLG change, Flooding for igp-type:2 area:0 0 seconds Sep 13 06:07:09.415 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK: rrr_lm_im_attr_capacity_handler: link tunnel-te0 (ifh 0x1c),bw 0 (kbps), bw2 0 (Bps), event 0 Sep 13 06:07:09.508 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3722: lm_im_handler: link tunnel-te0 (ifh 0x1c), state 17, proto 12, opcode 35 (CREATE/DEL) Sep 13 06:07:09.508 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3727: lm_im_handler: link tunnel-te0 (ifh 0x1c), intf_type 36, parent i/f None (ifh 0x0), caps 26 Sep 13 06:07:09.508 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:3808: lm_im_handler: IM_CREATE: link tunnel-te0 (ifh 0x1c), state 17, proto 12, opcode 35 Sep 13 06:30:36.835 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:643: rrr_lm_threshold_triggering_flooding(): Flooding Up Pool0 on link GigabitEthernet0/0/0/3 (ifhndl 0x28) actual 20, flooded 0, threshold 15, pri 7 Sep 13 06:30:36.835 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:743: rrr_lm_threshold_triggering_flooding(): link GigabitEthernet0/0/0/3 (ifh 0x28), triggering flooding, reason_threshold_cross 3, keep_priority 7 Sep 13 06:40:39.069 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:643: rrr_lm_threshold_triggering_flooding(): Flooding Up Pool0 on link GigabitEthernet0/0/0/1 (ifhndl 0x18) actual 20, flooded 0, threshold 15, pri 7 Sep 13 06:40:39.069 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:743: rrr_lm_threshold_triggering_flooding(): link GigabitEthernet0/0/0/1 (ifh 0x18), triggering flooding, reason_threshold_cross 3, keep_priority 7 Sep 13 06:41:19.277 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:615: rrr_lm_threshold_triggering_flooding(): Flooding Down Pool0 on link GigabitEthernet0/0/0/3 (ifhndl 0x28) actual 0, flooded 20, threshold 15, pri 7 Sep 13 06:41:19.277 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:743: rrr_lm_threshold_triggering_flooding(): link GigabitEthernet0/0/0/3 (ifh 0x28), triggering flooding, reason_threshold_cross 4, keep_priority 7 Sep 13 06:42:25.385 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:643: rrr_lm_threshold_triggering_flooding(): Flooding Up Pool0 on link GigabitEthernet0/0/0/3 (ifhndl 0x28) actual 20, flooded 0, threshold 15, pri 7 Sep 13 06:42:25.385 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:743: rrr_lm_threshold_triggering_flooding(): link GigabitEthernet0/0/0/3 (ifh 0x28), triggering flooding, reason_threshold_cross 3, keep_priority 7 Sep 13 06:43:05.599 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:615: rrr_lm_threshold_triggering_flooding(): Flooding Down Pool0 on link GigabitEthernet0/0/0/1 (ifhndl 0x18) actual 0, flooded 20, threshold 15, pri 7 Sep 13 06:43:05.599 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:743: rrr_lm_threshold_triggering_flooding(): link GigabitEthernet0/0/0/1 (ifh 0x18), triggering flooding, reason_threshold_cross 4, keep_priority 7 Sep 13 06:45:07.787 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:615: rrr_lm_threshold_triggering_flooding(): Flooding Down Pool0 on link GigabitEthernet0/0/0/3 (ifhndl 0x28) actual 0, flooded 20, threshold 15, pri 7 Sep 13 06:45:07.787 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:743: rrr_lm_threshold_triggering_flooding(): link GigabitEthernet0/0/0/3 (ifh 0x28), triggering flooding, reason_threshold_cross 4, keep_priority 7 Sep 13 06:56:05.103 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5569: rrr_lm_update_link_neighbors(): link GigabitEthernet0/0/0/3 (ifh 0x28), flood 0, force 1, Nbr cnt 1 Sep 13 06:56:05.103 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5494: Request link adjacencies for link GigabitEthernet0/0/0/3 (ifh 0x28), area 0, IGP OSPF Sep 13 06:56:05.108 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2565: Processing adj-change for link GigabitEthernet0/0/0/3 (ifh 0x28) (0 nbrs) in area 0, IGP OSPF Sep 13 06:56:05.108 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2451: rrr_lm_handle_igp_link_info_change: OSPF- link GigabitEthernet0/0/0/3 (ifh 0x28), tot_nbrs 0, subnet type 0, flags 0x2 Sep 13 06:56:05.108 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2471: rrr_lm_handle_igp_link_info_change: link GigabitEthernet0/0/0/3 (ifh 0x28) new igp admin weight 20, prev. isis wt 0, ospf wt 0 Sep 13 06:56:05.108 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2523: link GigabitEthernet0/0/0/3 (ifh 0x28), IGP OSPF area 0: no neighbor changes Sep 13 06:56:05.108 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:5295: Flooding on link GigabitEthernet0/0/0/3 (ifh 0x28) data changed Sep 13 06:56:05.108 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2565: Processing adj-change for link GigabitEthernet0/0/0/3 (ifh 0x28) (0 nbrs) in area 0, IGP OSPF Sep 13 06:56:05.108 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2451: rrr_lm_handle_igp_link_info_change: OSPF- link GigabitEthernet0/0/0/3 (ifh 0x28), tot_nbrs 0, subnet type 1, flags 0xb Sep 13 06:56:05.108 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2471: rrr_lm_handle_igp_link_info_change: link GigabitEthernet0/0/0/3 (ifh 0x28) new igp admin weight 20, prev. isis wt 0, ospf wt 0 Sep 13 06:56:05.108 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:2498: Link GigabitEthernet0/0/0/3 (ifh 0x28): update DB for 1 neighbors Sep 13 06:56:05.108 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1559: Received neighbor 10.2.7.7 on link GigabitEthernet0/0/0/3 (ifh 0x28), IGP OSPF area 0 Sep 13 06:56:05.109 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1578: Rcvd nbr node ID 7.7.7.7, state 1 Sep 13 06:56:05.109 mpls_te/link 0/RP0/CPU0 t4565 LM_LINK:1596: Matching existing neighbor found? True RP/0/RP0/CPU0:PE1#show rsvp trace signalling Sun Sep 13 07:08:36.753 UTC 93 wrapping entries (264256 possible, 320 allocated, 0 filtered, 93 total) Sep 13 06:07:09.699 rsvp/sig 0/RP0/CPU0 t4392 SIG:4545: PATH creating head: local/nbor/nhop (2.2.2.2/5.5.5.5/10.2.5.5), GigabitEthernet0/0/0/2 (ifh 0x20), psbs: 0, rsbs: 0 Sep 13 06:07:09.699 rsvp/sig 0/RP0/CPU0 t4392 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:2.2.2.2, nbor:5.5.5.5, nhop:10.2.5.5, next_ifh:GigabitEthernet0/0/0/2 (ifh 0x20), obj_len: 0 Sep 13 06:07:09.699 rsvp/sig 0/RP0/CPU0 t4392 SIG:887: PATH Tunnel IPv4 outgoing: dst (9.9.9.9:0), src (2.2.2.2:2) Sep 13 06:07:09.700 rsvp/sig 0/RP0/CPU0 t4392 SIG:721: PATH Tunnel IPv4 created: dst (9.9.9.9:0), src (2.2.2.2:2) Sep 13 06:07:09.795 rsvp/sig 0/RP0/CPU0 t4392 SIG:4654: RESV creating network: GigabitEthernet0/0/0/2 (ifh 0x20), in GigabitEthernet0/0/0/2 (ifh 0x20), obj len: 140, IP src: 10.2.5.5, psbs: 1, rsbs: 0 Sep 13 06:07:09.796 rsvp/sig 0/RP0/CPU0 t4392 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/2 (ifh 0x20), current (0 Bps), port 0, src 2.2.2.2 id 2 Sep 13 06:07:09.796 rsvp/sig 0/RP0/CPU0 t4392 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 2.2.2.2/0.0.0.0, obj len: 0x8c, wedged 0 Sep 13 06:07:09.796 rsvp/sig 0/RP0/CPU0 t4392 SIG:362: RESV Tunnel IPv4 created: dst (9.9.9.9:0), src (2.2.2.2:2) Sep 13 06:07:09.807 rsvp/sig 0/RP0/CPU0 t4392 SIG:492: Assigned backup None (ifh 0x0): dst (9.9.9.9:0), src (2.2.2.2:2) Sep 13 06:30:36.715 rsvp/sig 0/RP0/CPU0 t4392 SIG:4545: PATH creating head: local/nbor/nhop (2.2.2.2/7.7.7.7/10.2.7.7), GigabitEthernet0/0/0/3 (ifh 0x28), psbs: 1, rsbs: 1 Sep 13 06:30:36.716 rsvp/sig 0/RP0/CPU0 t4392 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:2.2.2.2, nbor:7.7.7.7, nhop:10.2.7.7, next_ifh:GigabitEthernet0/0/0/3 (ifh 0x28), obj_len: 0 Sep 13 06:30:36.716 rsvp/sig 0/RP0/CPU0 t4392 SIG:887: PATH Tunnel IPv4 outgoing: dst (9.9.9.9:0), src (2.2.2.2:3) Sep 13 06:30:36.716 rsvp/sig 0/RP0/CPU0 t4392 SIG:721: PATH Tunnel IPv4 created: dst (9.9.9.9:0), src (2.2.2.2:3) Sep 13 06:30:36.832 rsvp/sig 0/RP0/CPU0 t4392 SIG:4654: RESV creating network: GigabitEthernet0/0/0/3 (ifh 0x28), in GigabitEthernet0/0/0/3 (ifh 0x28), obj len: 212, IP src: 10.2.7.7, psbs: 2, rsbs: 1 Sep 13 06:30:36.832 rsvp/sig 0/RP0/CPU0 t4392 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/3 (ifh 0x28), current (25000000 Bps), port 0, src 2.2.2.2 id 3 Sep 13 06:30:36.832 rsvp/sig 0/RP0/CPU0 t4392 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 2.2.2.2/0.0.0.0, obj len: 0xd4, wedged 0 Sep 13 06:30:36.832 rsvp/sig 0/RP0/CPU0 t4392 SIG:362: RESV Tunnel IPv4 created: dst (9.9.9.9:0), src (2.2.2.2:3) Sep 13 06:30:36.842 rsvp/sig 0/RP0/CPU0 t4392 SIG:492: Assigned backup None (ifh 0x0): dst (9.9.9.9:0), src (2.2.2.2:3) Sep 13 06:31:17.045 rsvp/sig 0/RP0/CPU0 t4392 SIG:3929: PATH destroy: dst (9.9.9.9:0), src (2.2.2.2:2) reason: (5): State deleted due to client app Sep 13 06:31:17.045 rsvp/sig 0/RP0/CPU0 t4392 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180009 Sep 13 06:31:17.045 rsvp/sig 0/RP0/CPU0 t4392 SIG:1214: RESV destroy: dst (9.9.9.9:0), src (2.2.2.2:2) reason: (5): State deleted due to client app Sep 13 06:31:17.045 rsvp/sig 0/RP0/CPU0 t4392 SIG:1216: RESV destroy: flags 0x180000, rsb flags 0xc0000030, request flags 0x0 Sep 13 06:31:17.045 rsvp/sig 0/RP0/CPU0 t4392 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/2 (ifh 0x20), current (0 Bps), port 0, src 2.2.2.2 id 2 Sep 13 06:40:38.968 rsvp/sig 0/RP0/CPU0 t4392 SIG:4545: PATH creating head: local/nbor/nhop (2.2.2.2/3.3.3.3/10.2.3.3), GigabitEthernet0/0/0/1 (ifh 0x18), psbs: 1, rsbs: 1 Sep 13 06:40:38.968 rsvp/sig 0/RP0/CPU0 t4392 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:2.2.2.2, nbor:3.3.3.3, nhop:10.2.3.3, next_ifh:GigabitEthernet0/0/0/1 (ifh 0x18), obj_len: 0 Sep 13 06:40:38.968 rsvp/sig 0/RP0/CPU0 t4392 SIG:887: PATH Tunnel IPv4 outgoing: dst (9.9.9.9:0), src (2.2.2.2:4) Sep 13 06:40:38.968 rsvp/sig 0/RP0/CPU0 t4392 SIG:721: PATH Tunnel IPv4 created: dst (9.9.9.9:0), src (2.2.2.2:4) Sep 13 06:40:39.066 rsvp/sig 0/RP0/CPU0 t4392 SIG:4654: RESV creating network: GigabitEthernet0/0/0/1 (ifh 0x18), in GigabitEthernet0/0/0/1 (ifh 0x18), obj len: 212, IP src: 10.2.3.3, psbs: 2, rsbs: 1 Sep 13 06:40:39.066 rsvp/sig 0/RP0/CPU0 t4392 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/1 (ifh 0x18), current (25000000 Bps), port 0, src 2.2.2.2 id 4 Sep 13 06:40:39.066 rsvp/sig 0/RP0/CPU0 t4392 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 2.2.2.2/0.0.0.0, obj len: 0xd4, wedged 0 Sep 13 06:40:39.066 rsvp/sig 0/RP0/CPU0 t4392 SIG:362: RESV Tunnel IPv4 created: dst (9.9.9.9:0), src (2.2.2.2:4) Sep 13 06:40:39.076 rsvp/sig 0/RP0/CPU0 t4392 SIG:492: Assigned backup None (ifh 0x0): dst (9.9.9.9:0), src (2.2.2.2:4) Sep 13 06:41:19.280 rsvp/sig 0/RP0/CPU0 t4392 SIG:3929: PATH destroy: dst (9.9.9.9:0), src (2.2.2.2:3) reason: (5): State deleted due to client app Sep 13 06:41:19.280 rsvp/sig 0/RP0/CPU0 t4392 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180009 Sep 13 06:41:19.280 rsvp/sig 0/RP0/CPU0 t4392 SIG:1214: RESV destroy: dst (9.9.9.9:0), src (2.2.2.2:3) reason: (5): State deleted due to client app Sep 13 06:41:19.280 rsvp/sig 0/RP0/CPU0 t4392 SIG:1216: RESV destroy: flags 0x180000, rsb flags 0xc0000030, request flags 0x0 Sep 13 06:41:19.280 rsvp/sig 0/RP0/CPU0 t4392 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/3 (ifh 0x28), current (0 Bps), port 0, src 2.2.2.2 id 3 Sep 13 06:42:25.322 rsvp/sig 0/RP0/CPU0 t4392 SIG:4545: PATH creating head: local/nbor/nhop (2.2.2.2/7.7.7.7/10.2.7.7), GigabitEthernet0/0/0/3 (ifh 0x28), psbs: 1, rsbs: 1 Sep 13 06:42:25.322 rsvp/sig 0/RP0/CPU0 t4392 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:2.2.2.2, nbor:7.7.7.7, nhop:10.2.7.7, next_ifh:GigabitEthernet0/0/0/3 (ifh 0x28), obj_len: 0 Sep 13 06:42:25.322 rsvp/sig 0/RP0/CPU0 t4392 SIG:887: PATH Tunnel IPv4 outgoing: dst (9.9.9.9:0), src (2.2.2.2:5) Sep 13 06:42:25.322 rsvp/sig 0/RP0/CPU0 t4392 SIG:721: PATH Tunnel IPv4 created: dst (9.9.9.9:0), src (2.2.2.2:5) Sep 13 06:42:25.382 rsvp/sig 0/RP0/CPU0 t4392 SIG:4654: RESV creating network: GigabitEthernet0/0/0/3 (ifh 0x28), in GigabitEthernet0/0/0/3 (ifh 0x28), obj len: 212, IP src: 7.7.7.7, psbs: 2, rsbs: 1 Sep 13 06:42:25.382 rsvp/sig 0/RP0/CPU0 t4392 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/3 (ifh 0x28), current (25000000 Bps), port 0, src 2.2.2.2 id 5 Sep 13 06:42:25.382 rsvp/sig 0/RP0/CPU0 t4392 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 2.2.2.2/0.0.0.0, obj len: 0xd4, wedged 0 Sep 13 06:42:25.382 rsvp/sig 0/RP0/CPU0 t4392 SIG:362: RESV Tunnel IPv4 created: dst (9.9.9.9:0), src (2.2.2.2:5) Sep 13 06:42:25.398 rsvp/sig 0/RP0/CPU0 t4392 SIG:492: Assigned backup None (ifh 0x0): dst (9.9.9.9:0), src (2.2.2.2:5) Sep 13 06:43:05.602 rsvp/sig 0/RP0/CPU0 t4392 SIG:3929: PATH destroy: dst (9.9.9.9:0), src (2.2.2.2:4) reason: (5): State deleted due to client app Sep 13 06:43:05.602 rsvp/sig 0/RP0/CPU0 t4392 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180009 Sep 13 06:43:05.603 rsvp/sig 0/RP0/CPU0 t4392 SIG:1214: RESV destroy: dst (9.9.9.9:0), src (2.2.2.2:4) reason: (5): State deleted due to client app Sep 13 06:43:05.603 rsvp/sig 0/RP0/CPU0 t4392 SIG:1216: RESV destroy: flags 0x180000, rsb flags 0xc0000030, request flags 0x0 Sep 13 06:43:05.603 rsvp/sig 0/RP0/CPU0 t4392 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/1 (ifh 0x18), current (0 Bps), port 0, src 2.2.2.2 id 4 Sep 13 06:43:44.411 rsvp/sig 0/RP0/CPU0 t4392 SIG:4545: PATH creating head: local/nbor/nhop (2.2.2.2/5.5.5.5/10.2.5.5), GigabitEthernet0/0/0/2 (ifh 0x20), psbs: 1, rsbs: 1 Sep 13 06:43:44.411 rsvp/sig 0/RP0/CPU0 t4392 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:2.2.2.2, nbor:5.5.5.5, nhop:10.2.5.5, next_ifh:GigabitEthernet0/0/0/2 (ifh 0x20), obj_len: 0 Sep 13 06:43:44.411 rsvp/sig 0/RP0/CPU0 t4392 SIG:887: PATH Tunnel IPv4 outgoing: dst (9.9.9.9:0), src (2.2.2.2:6) Sep 13 06:43:44.411 rsvp/sig 0/RP0/CPU0 t4392 SIG:721: PATH Tunnel IPv4 created: dst (9.9.9.9:0), src (2.2.2.2:6) Sep 13 06:43:44.496 rsvp/sig 0/RP0/CPU0 t4392 SIG:4654: RESV creating network: GigabitEthernet0/0/0/2 (ifh 0x20), in GigabitEthernet0/0/0/2 (ifh 0x20), obj len: 212, IP src: 5.5.5.5, psbs: 2, rsbs: 1 Sep 13 06:43:44.497 rsvp/sig 0/RP0/CPU0 t4392 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/2 (ifh 0x20), current (0 Bps), port 0, src 2.2.2.2 id 6 Sep 13 06:43:44.497 rsvp/sig 0/RP0/CPU0 t4392 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 2.2.2.2/0.0.0.0, obj len: 0xd4, wedged 0 Sep 13 06:43:44.497 rsvp/sig 0/RP0/CPU0 t4392 SIG:362: RESV Tunnel IPv4 created: dst (9.9.9.9:0), src (2.2.2.2:6) Sep 13 06:43:44.505 rsvp/sig 0/RP0/CPU0 t4392 SIG:492: Assigned backup None (ifh 0x0): dst (9.9.9.9:0), src (2.2.2.2:6) Sep 13 06:43:57.519 rsvp/sig 0/RP0/CPU0 t4392 SIG:3929: PATH destroy: dst (9.9.9.9:0), src (2.2.2.2:6) reason: (5): State deleted due to client app Sep 13 06:43:57.519 rsvp/sig 0/RP0/CPU0 t4392 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180009 Sep 13 06:43:57.520 rsvp/sig 0/RP0/CPU0 t4392 SIG:1214: RESV destroy: dst (9.9.9.9:0), src (2.2.2.2:6) reason: (5): State deleted due to client app Sep 13 06:43:57.520 rsvp/sig 0/RP0/CPU0 t4392 SIG:1216: RESV destroy: flags 0x180000, rsb flags 0xc0000030, request flags 0x0 Sep 13 06:43:57.520 rsvp/sig 0/RP0/CPU0 t4392 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/2 (ifh 0x20), current (0 Bps), port 0, src 2.2.2.2 id 6 Sep 13 06:44:27.520 rsvp/sig 0/RP0/CPU0 t4392 SIG:4545: PATH creating head: local/nbor/nhop (2.2.2.2/3.3.3.3/10.2.3.3), GigabitEthernet0/0/0/1 (ifh 0x18), psbs: 1, rsbs: 1 Sep 13 06:44:27.520 rsvp/sig 0/RP0/CPU0 t4392 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:2.2.2.2, nbor:3.3.3.3, nhop:10.2.3.3, next_ifh:GigabitEthernet0/0/0/1 (ifh 0x18), obj_len: 0 Sep 13 06:44:27.520 rsvp/sig 0/RP0/CPU0 t4392 SIG:887: PATH Tunnel IPv4 outgoing: dst (9.9.9.9:0), src (2.2.2.2:8) Sep 13 06:44:27.520 rsvp/sig 0/RP0/CPU0 t4392 SIG:721: PATH Tunnel IPv4 created: dst (9.9.9.9:0), src (2.2.2.2:8) Sep 13 06:44:27.580 rsvp/sig 0/RP0/CPU0 t4392 SIG:4654: RESV creating network: GigabitEthernet0/0/0/1 (ifh 0x18), in GigabitEthernet0/0/0/1 (ifh 0x18), obj len: 212, IP src: 3.3.3.3, psbs: 2, rsbs: 1 Sep 13 06:44:27.580 rsvp/sig 0/RP0/CPU0 t4392 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/1 (ifh 0x18), current (0 Bps), port 0, src 2.2.2.2 id 8 Sep 13 06:44:27.580 rsvp/sig 0/RP0/CPU0 t4392 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 2.2.2.2/0.0.0.0, obj len: 0xd4, wedged 0 Sep 13 06:44:27.580 rsvp/sig 0/RP0/CPU0 t4392 SIG:362: RESV Tunnel IPv4 created: dst (9.9.9.9:0), src (2.2.2.2:8) Sep 13 06:44:27.587 rsvp/sig 0/RP0/CPU0 t4392 SIG:492: Assigned backup None (ifh 0x0): dst (9.9.9.9:0), src (2.2.2.2:8) Sep 13 06:45:07.790 rsvp/sig 0/RP0/CPU0 t4392 SIG:3929: PATH destroy: dst (9.9.9.9:0), src (2.2.2.2:5) reason: (5): State deleted due to client app Sep 13 06:45:07.790 rsvp/sig 0/RP0/CPU0 t4392 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180009 Sep 13 06:45:07.790 rsvp/sig 0/RP0/CPU0 t4392 SIG:1214: RESV destroy: dst (9.9.9.9:0), src (2.2.2.2:5) reason: (5): State deleted due to client app Sep 13 06:45:07.790 rsvp/sig 0/RP0/CPU0 t4392 SIG:1216: RESV destroy: flags 0x180000, rsb flags 0xc0000030, request flags 0x0 Sep 13 06:45:07.790 rsvp/sig 0/RP0/CPU0 t4392 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/3 (ifh 0x28), current (0 Bps), port 0, src 2.2.2.2 id 5 Sep 13 07:00:13.496 rsvp/sig 0/RP0/CPU0 t4392 SIG:4545: PATH creating head: local/nbor/nhop (2.2.2.2/7.7.7.7/10.2.7.7), GigabitEthernet0/0/0/3 (ifh 0x28), psbs: 1, rsbs: 1 Sep 13 07:00:13.496 rsvp/sig 0/RP0/CPU0 t4392 SIG:2836: PATH outgoing creating: flags:0xc0000005, local_rid:2.2.2.2, nbor:7.7.7.7, nhop:10.2.7.7, next_ifh:GigabitEthernet0/0/0/3 (ifh 0x28), obj_len: 0 Sep 13 07:00:13.496 rsvp/sig 0/RP0/CPU0 t4392 SIG:887: PATH Tunnel IPv4 outgoing: dst (9.9.9.9:0), src (2.2.2.2:9) Sep 13 07:00:13.496 rsvp/sig 0/RP0/CPU0 t4392 SIG:721: PATH Tunnel IPv4 created: dst (9.9.9.9:0), src (2.2.2.2:9) Sep 13 07:00:13.550 rsvp/sig 0/RP0/CPU0 t4392 SIG:4654: RESV creating network: GigabitEthernet0/0/0/3 (ifh 0x28), in GigabitEthernet0/0/0/3 (ifh 0x28), obj len: 212, IP src: 7.7.7.7, psbs: 2, rsbs: 1 Sep 13 07:00:13.551 rsvp/sig 0/RP0/CPU0 t4392 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/3 (ifh 0x28), current (0 Bps), port 0, src 2.2.2.2 id 9 Sep 13 07:00:13.551 rsvp/sig 0/RP0/CPU0 t4392 SIG:2881: RESV outgoing creating: rsb flags: 0xc0000011, psb flags: 0xc0000004, local/nbor 2.2.2.2/0.0.0.0, obj len: 0xd4, wedged 0 Sep 13 07:00:13.551 rsvp/sig 0/RP0/CPU0 t4392 SIG:362: RESV Tunnel IPv4 created: dst (9.9.9.9:0), src (2.2.2.2:9) Sep 13 07:00:13.557 rsvp/sig 0/RP0/CPU0 t4392 SIG:492: Assigned backup None (ifh 0x0): dst (9.9.9.9:0), src (2.2.2.2:9) Sep 13 07:00:53.761 rsvp/sig 0/RP0/CPU0 t4392 SIG:3929: PATH destroy: dst (9.9.9.9:0), src (2.2.2.2:8) reason: (5): State deleted due to client app Sep 13 07:00:53.761 rsvp/sig 0/RP0/CPU0 t4392 SIG:3931: PATH destroy: flags 0x0, psb flags 0xc0000004, pfc flags 0x80180009 Sep 13 07:00:53.761 rsvp/sig 0/RP0/CPU0 t4392 SIG:1214: RESV destroy: dst (9.9.9.9:0), src (2.2.2.2:8) reason: (5): State deleted due to client app Sep 13 07:00:53.761 rsvp/sig 0/RP0/CPU0 t4392 SIG:1216: RESV destroy: flags 0x180000, rsb flags 0xc0000030, request flags 0x0 Sep 13 07:00:53.761 rsvp/sig 0/RP0/CPU0 t4392 TC:276: Bandwidth allocation: GigabitEthernet0/0/0/1 (ifh 0x18), current (0 Bps), port 0, src 2.2.2.2 id 8