[j-nsp] MX960: High CPU FPC
Evgeniy Aikashev
evgeniy at ip.datagroup.ua
Wed Feb 29 09:41:18 EST 2012
Hello Tomas,
> what junos version are you running ?
10.0R4.7
> sh sched
Here threads looks a root of my issue. What does this means?
Total uptime 0+06:38:59, (23939325 ms), 166489067 thread dispatches
CPU load is 100% (5 second), 91% (1 minute)
Total network interrupt time 0 (usec)
CPU Name Time(ms)
0% Idle 153550
96% Threads 23015410
3% ISR 770365
3% Level 1 738990
0% Level 2 28085
0% Level 3 5
0% Level 5 3285
> sh nvram
System NVRAM :
32751 available bytes, 2734 used, 30017 free
Contents:
[LOG] chassis_db_set_dpc_simulation: options = 0!!
[LOG] IPV4 Init: Set the IP IRI to 0x80000015
[LOG] otn_priodic ON
[LOG] if_notify_init: IF notify list already initialized
[LOG] chassis_db_set_dpc_simulation: options = 0!!
[LOG] IPV4 Init: Set the IP IRI to 0x80000015
[LOG] otn_priodic ON
[LOG] if_notify_init: IF notify list already initialized
[LOG] chassis_db_set_dpc_simulation: options = 0!!
[LOG] otn_priodic ON
[LOG] if_notify_init: IF notify list already initialized
[Oct 13 09:12:30.407 LOG: Emergency] <160>RDP: Remote side closed connection: rdp.(fpc0:62466).(serverRouter:chassis)
[LOG] chassis_db_set_dpc_simulation: options = 0!!
[LOG] otn_priodic ON
[LOG] if_notify_init: IF notify list already initialized
[Oct 13 09:52:22.298 LOG: Emergency] <160>RDP: Remote side closed connection: rdp.(fpc0:2050).(serverRouter:chassis)
[LOG] chassis_db_set_dpc_simulation: options = 0!!
[LOG] otn_priodic ON
[LOG] if_notify_init: IF notify list already initialized
[Jul 20 10:07:35.343 LOG: Emergency] <160>RDP: Remote side reset connection: rdp.(fpc0:46085).(serverRouter:ppm)
[Jul 20 10:07:35.873 LOG: Emergency] <160>RDP: Remote side reset connection: rdp.(fpc0:46083).(serverRouter:pfe)
[Jul 20 10:07:35.874 LOG: Emergency] <160>RDP: Remote side reset connection: rdp.(fpc0:46084).(serverRouter:985)
[Jul 20 10:07:35.875 LOG: Emergency] <160>RDP: Remote side reset connection: rdp.(fpc0:46081).(serverRouter:l2ald)
[Jul 20 10:07:35.876 LOG: Emergency] <160>RDP: Remote side reset connection: rdp.(fpc0:46082).(serverRouter:chassis)
[Jul 20 12:24:23.141 LOG: Emergency] <160>RDP: Remote side reset connection: rdp.(fpc0:46109).(serverRouter:985)
[Jul 20 12:24:23.184 LOG: Emergency] <160>RDP: Remote side reset connection: rdp.(fpc0:46116).(serverRouter:ppm)
[Jul 20 12:24:23.414 LOG: Emergency] <160>RDP: Remote side reset connection: rdp.(fpc0:46087).(serverRouter:pfe)
[Jul 20 12:24:23.416 LOG: Emergency] <160>RDP: Remote side reset connection: rdp.(fpc0:46088).(serverRouter:chassis)
[Jul 20 12:24:23.417 LOG: Emergency] <160>RDP: Remote side reset connection: rdp.(fpc0:46119).(serverRouter:l2ald)
[Oct 17 01:00:46.236 LOG: Emergency] <160>RDP: Remote side reset connection: rdp.(fpc0:46123).(serverRouter:chassis)
[Oct 17 01:00:46.249 LOG: Emergency] <160>RDP: Remote side reset connection: rdp.(fpc0:46122).(serverRouter:pfe)
[LOG] chassis_db_set_dpc_simulation: options = 0!!
[LOG] otn_priodic ON
[LOG] if_notify_init: IF notify list already initialized
[Feb 29 07:30:56.988 LOG: Emergency] <160>RDP: Remote side closed connection: rdp.(fpc0:34818).(serverRouter:chassis)
[LOG] chassis_db_set_dpc_simulation: options = 0!!
[LOG] otn_priodic ON
[LOG] if_notify_init: IF notify list already initialized
ROM NVRAM:
0 available bytes, 0 used, 0 free
> sh syslog messages
[LOG] issu_cmlc_fpc_common_issu_msg: Error BLOB, no handle for Blob DB Init
[LOG] chassis_db_set_dpc_simulation: options = 0!!
[LOG] otn_priodic ON
[LOG] if_notify_init: IF notify list already initialized
[0+00:00:10.715 LOG: Debug] pfesvcs_init: Module init done....
[0+00:00:11.185 LOG: Info] pic_system_init: total slot 1
[0+00:00:11.185 LOG: Info] pic_system_init: will call pic_periodic_init
[0+00:00:11.185 LOG: Info] pic_system_init: pic sys ready
[0+00:00:11.185 LOG: Info] ICMP: Init of per-iff rate to (500)
[0+00:00:11.185 LOG: Info] [cospic_qdpc_init] cosfpc_vectors initialized
[0+00:00:11.185 LOG: Info] [cospic_mt_init] cosfpc_vectors already initialized
[0+00:00:11.185 LOG: Info] cosman_fpc_init: FC based rewrite is ON for fpc
[0+00:00:11.185 LOG: Info] cos_module_init: FC based rewrite is ON for pfe
[0+00:00:11.185 LOG: Debug] SNTP: Daemon created
[0+00:00:11.190 LOG: Info] PPMAN: Established connection to ppmd
[0+00:00:11.190 LOG: Info] L2ALM: Established connection to Master, 0x417753a0
[0+00:00:11.190 LOG: Notice] L2ALM master RE connection made
[0+00:00:11.190 LOG: Debug] CMLC: Using IDR encoding
[0+00:00:11.190 LOG: Info] PFEMAN: Session manager active
[0+00:00:11.190 LOG: Info] PFEMAN: pfeman_start_service_bulkget
[0+00:00:11.190 LOG: Debug] COSFPC: Initializing periodic
[Feb 29 07:46:09.645 LOG: Info] SNTPD: Initial time of day set.
[Feb 29 07:46:09.645 LOG: Info] Version 10.0R4.7 by builder on 2010-08-22 03:32:27 UTC
[Feb 29 07:46:09.645 LOG: Info] On-board NVRAM contains diagnostic information.
[Feb 29 07:46:09.645 LOG: Info] cmsfpc_restart_normal: Connected to pfe_man after 1 retries
[Feb 29 07:46:09.645 LOG: Info] IA(0) base address =0xc0000000
[Feb 29 07:46:09.645 LOG: Info] Cannot locate jspec model for 'ia', v2.2: using best match: v1.0
[Feb 29 07:46:09.645 LOG: Info] Cannot locate jspec model for 'ia', v2.2: using best match: v1.0
[Feb 29 07:46:09.655 LOG: Info] ICHIP(0) base address =0xc0000000
[Feb 29 07:46:09.660 LOG: Debug] PPMAN: bfd conn ready
[Feb 29 07:46:09.660 LOG: Debug] ICHIP(0) Setup rldram bist
[Feb 29 07:46:11.602 LOG: Info] IA(1) base address =0xc0000000
[Feb 29 07:46:11.616 LOG: Info] ICHIP(1) base address =0xc4000000
[Feb 29 07:46:11.617 LOG: Debug] ICHIP(1) Setup rldram bist
[Feb 29 07:46:11.940 LOG: Debug] IA_RXIF(0, 1): fc_stat = 0x00000400
[Feb 29 07:46:13.557 LOG: Info] IA(2) base address =0xd0000000
[Feb 29 07:46:13.557 LOG: Info] Cannot locate jspec model for 'ia', v2.2: using best match: v1.0
[Feb 29 07:46:13.557 LOG: Info] Cannot locate jspec model for 'ia', v2.2: using best match: v1.0
[Feb 29 07:46:13.571 LOG: Info] ICHIP(2) base address =0xd0000000
[Feb 29 07:46:13.573 LOG: Debug] ICHIP(2) Setup rldram bist
[Feb 29 07:46:15.512 LOG: Info] IA(3) base address =0xd0000000
[Feb 29 07:46:15.526 LOG: Info] ICHIP(3) base address =0xd4000000
[Feb 29 07:46:15.527 LOG: Debug] ICHIP(3) Setup rldram bist
[Feb 29 07:46:17.467 LOG: Info] CMS: PFE ASIC initialization complete
[Feb 29 07:46:17.552 LOG: Info] cmsfpc_ready: Sending FPC ready mesg to master
[Feb 29 07:46:17.557 LOG: Debug] JTREE (0): mem size 32MB, num_seg 2, seg size 16MB
[Feb 29 07:46:17.610 LOG: Debug] JTREE (1): mem size 32MB, num_seg 2, seg size 16MB
[Feb 29 07:46:17.662 LOG: Debug] JTREE (2): mem size 32MB, num_seg 2, seg size 16MB
[Feb 29 07:46:17.715 LOG: Debug] JTREE (3): mem size 32MB, num_seg 2, seg size 16MB
[Feb 29 07:46:19.720 LOG: Info] CMX: Chassis has 12 slots
[Feb 29 07:46:19.720 LOG: Info] PFEMAN: sent Resync request to Master
[Feb 29 07:46:19.824 LOG: Info] Rate-limit-burst = 0
[Feb 29 07:47:30.067 LOG: Info] PFEMAN: received Resync complete.
[Feb 29 07:47:30.068 LOG: Info] bulkget manager init ...
[Feb 29 07:47:30.068 LOG: Info] bulkget manager thread creating...
[Feb 29 07:47:30.068 LOG: Info] BULKGET: connecting to serverRouter
[Feb 29 07:47:30.068 LOG: Info] bulkget_start_pfeman_transaction
[Feb 29 07:47:30.068 LOG: Info] BULKGET: connected to serverRouter
[Feb 29 07:47:30.156 LOG: Info] cmsfpc_sfpc_online_vector: Estd peering with pfe_man after 332 retries (200ms each)
[Feb 29 07:47:30.748 LOG: Debug] EZ: ezchip_channel_create[936] ALL BST CHECK ENABLED: 3f
[Feb 29 07:47:30.794 LOG: Debug] ezchip_load_microcode loading revB ucode without TM
[Feb 29 07:47:31.941 LOG: Debug] EZ: ezchip_init[755] ezchip 0 initialization done
[Feb 29 07:47:31.944 LOG: Debug] No PIC config TLV found for 0
[Feb 29 07:47:31.946 LOG: Debug] CMX: I(0) ASIC SPI4 init
[Feb 29 07:47:31.946 LOG: Info] CMXDPC: I-Chip(0) - EZ-Chip SPI4 training completed
[Feb 29 07:47:32.031 LOG: Debug] EZ: ezchip_channel_create[936] ALL BST CHECK ENABLED: 3f
[Feb 29 07:47:32.078 LOG: Debug] ezchip_load_microcode loading revB ucode without TM
[Feb 29 07:47:33.301 LOG: Debug] EZ: ezchip_init[755] ezchip 1 initialization done
[Feb 29 07:47:33.304 LOG: Debug] No PIC config TLV found for 1
[Feb 29 07:47:33.305 LOG: Debug] CMX: I(1) ASIC SPI4 init
[Feb 29 07:47:33.306 LOG: Info] CMXDPC: I-Chip(1) - EZ-Chip SPI4 training completed
[Feb 29 07:47:33.806 LOG: Debug] EZ: ezchip_channel_create[936] ALL BST CHECK ENABLED: 3f
[Feb 29 07:47:33.852 LOG: Debug] ezchip_load_microcode loading revB ucode without TM
[Feb 29 07:47:35.092 LOG: Debug] EZ: ezchip_init[755] ezchip 2 initialization done
[Feb 29 07:47:35.095 LOG: Debug] No PIC config TLV found for 2
[Feb 29 07:47:35.096 LOG: Debug] CMX: I(2) ASIC SPI4 init
[Feb 29 07:47:35.098 LOG: Info] CMXDPC: I-Chip(2) - EZ-Chip SPI4 training completed
[Feb 29 07:47:35.181 LOG: Debug] EZ: ezchip_channel_create[936] ALL BST CHECK ENABLED: 3f
[Feb 29 07:47:35.227 LOG: Debug] ezchip_load_microcode loading revB ucode without TM
[Feb 29 07:47:36.459 LOG: Debug] EZ: ezchip_init[755] ezchip 3 initialization done
[Feb 29 07:47:36.462 LOG: Debug] No PIC config TLV found for 3
[Feb 29 07:47:36.464 LOG: Debug] CMX: I(3) ASIC SPI4 init
[Feb 29 07:47:36.465 LOG: Info] CMXDPC: I-Chip(3) - EZ-Chip SPI4 training completed
[Feb 29 07:47:36.766 LOG: Debug] CMXDPC: Received spare plane mask: 0
[Feb 29 07:47:36.766 LOG: Debug] CMXDPC: Current plane state on DPC(online mask): f
[Feb 29 07:48:25.298 LOG: Notice] XETH(2/0): Link 0 XFP plugged in
[Feb 29 07:49:13.015 LOG: Notice] XETH(2/1): Link 0 XFP plugged in
[Feb 29 07:49:53.227 LOG: Notice] XETH(2/2): Link 0 XFP plugged in
[Feb 29 07:50:14.534 LOG: Notice] XETH(2/3): Link 0 XFP plugged in
[Feb 29 07:50:19.604 LOG: Debug] New lrid inserted lrid 0
[Feb 29 08:00:07.619 LOG: Info] PFE_NH_RESOLVE_THROTTLED: Next-hop resolution requests from interface 1200 throttled
[Feb 29 08:55:17.563 LOG: Info] PFE_NH_RESOLVE_THROTTLED: Next-hop resolution requests from interface 1200 throttled
[Feb 29 09:37:07.678 LOG: Info] PFE_NH_RESOLVE_THROTTLED: Next-hop resolution requests from interface 1200 throttled
[Feb 29 09:58:37.806 LOG: Info] PFE_NH_RESOLVE_THROTTLED: Next-hop resolution requests from interface 1200 throttled
[Feb 29 10:51:22.441 LOG: Info] PFE_NH_RESOLVE_THROTTLED: Next-hop resolution requests from interface 1200 throttled
[Feb 29 11:33:59.875 LOG: Info] PFE_NH_RESOLVE_THROTTLED: Next-hop resolution requests from interface 1200 throttled
[Feb 29 11:40:07.860 LOG: Info] PFE_NH_RESOLVE_THROTTLED: Next-hop resolution requests from interface 1200 throttled
[Feb 29 12:16:40.481 LOG: Info] PFE_NH_RESOLVE_THROTTLED: Next-hop resolution requests from interface 1200 throttled
[Feb 29 12:26:10.955 LOG: Info] PFE_NH_RESOLVE_THROTTLED: Next-hop resolution requests from interface 1200 throttled
[Feb 29 12:46:25.266 LOG: Info] PFE_NH_RESOLVE_THROTTLED: Next-hop resolution requests from interface 1200 throttled
best regards,
--
Evgeniy
Wednesday, February 29, 2012, 2:25:42 PM, Tomas wrote:
> Hi,
> what junos version are you running ?
> have a look on:
> caslat50 at prg-001-score-1-re0> start shell pfe network fpc2
> ADPC2(prg-001-score-1-re0 vty)#
> sh sched
> sh nvram
> sh syslog messages
> this should give you some hints what's going on
> Regards
> Tomas
> Dne 29-Feb-12 11:54, Evgeniy Aikashev napsal(a):
>> Good day,
>> I have MX960 with 2 RE.
>> Yesterday after switchover to backup RE (disk fail was the reason), I see high CPU utilization for fpc0 and fpc2 DPCE-R line cards.
>> I changed the cards, sfps but it not help. Also I found out if I disable pics xe-2/0/0 and xe-2/1/0 the CPU utilization for fpc2 decreases to normal ~10-15%.
>> Any ideas?
>>
>> evgeniy at mx960-slave> show chassis fpc
>> Temp CPU Utilization (%) Memory Utilization (%)
>> Slot State (C) Total Interrupt DRAM (MB) Heap Buffer
>> 0 Online 29 86 2 1024 46 31
>> 1 Online 27 10 0 1024 46 31
>> 2 Online 25 100 3 1024 46 30
>> 3 Online 24 12 0 1024 46 31
>> 4 Online 25 12 0 1024 46 31
>>
>> Regards,
>> Evgeniy
>>
>>
>> _______________________________________________
>> juniper-nsp mailing list juniper-nsp at puck.nether.net
>> https://puck.nether.net/mailman/listinfo/juniper-nsp
More information about the juniper-nsp
mailing list