Guest

Preview Tool

Cisco Bug: CSCup95861 - ASR9000 - MPLS FRR protection switching takes too long (more than 50ms)

Last Modified

May 13, 2018

Products (1)

  • Cisco ASR 9000 Series Aggregation Services Routers

Known Affected Releases

5.1.0.BASE 5.1.11.MPLS

Description (partial)

Symptom:
For this issue, as the below logs indicate, when fib sends a request to uidb (through lwm), uidb server is processing uidb_set_feature_batch (called by vlan ea here). Since uidb is a single thread, it cannot process this fib request.

RP/0/RP0/CPU0:ASR9k-2#show mpls traffic-eng fast-reroute log location 0/1/CPU0 

Wed Jul 16 17:17:35.460 PDT

Location Protected              When                   Switching Time
         Interface                                         (usec)    
-------- ---------------------- ---------------------- --------------
0/1/CPU0 BE4(Te0/1/0/23)        Jul 16 17:16:50.076708     3000
0/1/CPU0 BE4(Te0/1/0/21)        Jul 16 17:16:50.100708        0
0/1/CPU0 BE4(Te0/1/0/22)        Jul 16 17:16:50.107708        0
0/1/CPU0 BE4                    Jul 16 17:16:50.107708   176000      <<<< FRR event LC1

LC/0/1/CPU0:Jul 16 17:16:50.096 : uidb_server[356]: uidb_get_gen_feature: Type 105 
LC/0/1/CPU0:Jul 16 17:16:50.096 : uidb_server[356]: uidb_feature_batch_write: Enter
LC/0/1/CPU0:Jul 16 17:16:50.096 : uidb_server[356]: uidb_hardware_write: Enter
LC/0/1/CPU0:Jul 16 17:16:50.108 : fib_mgr[179]: uidb_set_generic_feature: uidb_data feature = 117, val 0x1  <<<< PDFIB execute FRR and invoked uidb API, still in FIB context.
LC/0/1/CPU0:Jul 16 17:16:50.130 : ipv6_ea[241]: uidb_set_feature_batch: Enter, num_features 1, msg_size 52
LC/0/1/CPU0:Jul 16 17:16:50.136 : ipv6_ea[241]: uidb_set_feature_batch: small message, sending as-is
LC/0/1/CPU0:Jul 16 17:16:50.269 : uidb_server[356]: close_dirty_list: node count = 1
LC/0/1/CPU0:Jul 16 17:16:50.269 : uidb_server[356]: close_dirty_list: clean count = 1
LC/0/1/CPU0:Jul 16 17:16:50.269 : uidb_server[356]: uidb_feature_set_generic: Enter   <<<< generic feature set not execute about 161ms about FIB invoked the API
LC/0/1/CPU0:Jul 16 17:16:50.269 : uidb_server[356]: uidb_feature_set_generic: received feature set event. feature 117 val 0x1.
LC/0/1/CPU0:Jul 16 17:16:50.269 : uidb_server[356]: uidb_set_gen_feature: Type 117, value 0x1 
LC/0/1/CPU0:Jul 16 17:16:50.270 : vlan_ea[365]: uidb_set_feature_batch: Enter, num_features 1, msg_size 52
LC/0/1/CPU0:Jul 16 17:16:50.270 : vlan_ea[365]: uidb_set_feature_batch: small message, sending as-is
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: Enter       <<<<< port-sram programming happened here
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 0, np 0, port 6 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 1, np 0, port 5 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 2, np 0, port 4 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 3, np 1, port 6 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 4, np 1, port 5 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 5, np 1, port 4 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 6, np 2, port 6 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 7, np 2, port 5 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 8, np 2, port 4 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 9, np 3, port 6 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 10, np 3, port 5 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 11, np 3, port 4 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 12, np 4, port 6 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 13, np 4, port 5 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 14, np 4, port 4 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 15, np 5, port 6 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 16, np 5, port 5 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 17, np 5, port 4 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 18, np 6, port 6 
LC/0/1/CPU0:Jul 16 17:16:50.272 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 19, np 6, port 5 
LC/0/1/CPU0:Jul 16 17:16:50.273 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 20, np 6, port 4 
LC/0/1/CPU0:Jul 16 17:16:50.273 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 21, np 7, port 6 
LC/0/1/CPU0:Jul 16 17:16:50.273 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 22, np 7, port 5 
LC/0/1/CPU0:Jul 16 17:16:50.273 : uidb_server[356]: uidb_write_global_to_hardware: writing to pp 23, np 7, port 4 
LC/0/1/CPU0:Jul 16 17:16:50.273 : uidb_server[356]: uidb_write_global_to_hardware: sram call complete
LC/0/1/CPU0:Jul 16 17:16:50.273 : uidb_server[356]: uidb_write_global_to_hardware: program fabric_port on np 0
LC/0/1/CPU0:Jul 16 17:16:50.273 : uidb_server[356]: uidb_write_global_to_hardware: program fabric_port on np 1
LC/0/1/CPU0:Jul 16 17:16:50.273 : uidb_server[356]: uidb_write_global_to_hardware: program fabric_port on np 2
LC/0/1/CPU0:Jul 16 17:16:50.273 : uidb_server[356]: uidb_write_global_to_hardware: program fabric_port on np 3
LC/0/1/CPU0:Jul 16 17:16:50.273 : uidb_server[356]: uidb_write_global_to_hardware: program fabric_port on np 4
LC/0/1/CPU0:Jul 16 17:16:50.273 : uidb_server[356]: uidb_write_global_to_hardware: program fabric_port on np 5
LC/0/1/CPU0:Jul 16 17:16:50.273 : uidb_server[356]: uidb_write_global_to_hardware: program fabric_port on np 6
LC/0/1/CPU0:Jul 16 17:16:50.273 : uidb_server[356]: uidb_write_global_to_hardware: program fabric_port on np 7
LC/0/1/CPU0:Jul 16 17:16:50.274 : fib_mgr[179]: uidb_set_generic_feature: uidb svr returned succ   <<<<< All the port sram got to PRM 166ms after FIB invoked the API.

Conditions:
FRR is triggered by shutting down a bundle with multiple members and takes a long time to finish the protection switch.
Bug details contain sensitive information and therefore require a Cisco.com account to be viewed.

Bug Details Include

  • Full Description (including symptoms, conditions and workarounds)
  • Status
  • Severity
  • Known Fixed Releases
  • Related Community Discussions
  • Number of Related Support Cases
Bug information is viewable for customers and partners who have a service contract. Registered users can view up to 200 bugs per month without a service contract.