R19以降のASR5500ではUDPCにおけるCRCエラー発生時にカードリブートは発生せず、DDF(DPC Data FPGA)のリロードのみを行い復旧対処を行います。このDDFのリロードは約2秒程度かかるため、その間、DDF-CPU間の通信が行えない状態となります。
bgpやdiamproxyのtaskはDPCのCPUにアサインされているため、CPUへの通信が一時的に途絶える事でDiameter/BGP peerのDown/Upが発生します。
DDF、CPU経路の概要: DDF0 <===> CPU0(bgp/diamproxy) DDF1 <===> CPU1(bgp/diamproxy)
確認方法: 発生箇所(Card/CPU/DDF)を確認し、当該箇所のCPUにdiamproxy/bgpのタスクがアサインされている状況であれば本事象であると判断できます。
① Diameter/BGP peerのDown/Upの発生の直前にCRCエラーが発生しているかを確認します。syslog上ではCRCエラー発生時に下記のようなログが出力されます。
Card8 CPU0側(DDF0)での発生例:
YYYY-MM-DD+HH:MM:SS.sss [drvctrl 39200 warning] [8/0/5490 <hwmgr:80> hw_common_lib.c:433] [software internal system syslog] hw_mon_elem_changed: Dectected kernel card failure event on card 8, send CARD FAIL to Hat
Card1 CPU1側(DDF1)での発生例:
YYYY-MM-DD+HH:MM:SS.sss [drvctrl 39200 warning] [1/1/5508 <hwmgr:11> hw_common_lib.c:433] [software internal system syslog] hw_mon_elem_changed: Dectected kernel card failure event on card 1, send CARD FAIL to Hat
※本syslogはwarningレベルですので、以下のようなdrvctrlのログレベルがwarning以上に設定されていないと出力されません。
logging filter runtime facility drvctrl level warning critical-info
② debug consoleのログよりDDFのリロードが発生したことを確認します。
Card8 CPU0側(DDF0)での発生例:
******** debug console card 8 cpu 0 tail 10000 only ******* ...snip... YYYY-MM-DD+22:00:28.912 card 8-cpu0: [2704129.632209] DF0 Program CRC error detected on SAD183200C0, reloading fpga! YYYY-MM-DD+22:00:28.912 card 8-cpu0: [2704129.639244] DF_VERSION 0x50a0001 YYYY-MM-DD+22:00:28.912 card 8-cpu0: [2704129.642645] EDCRC_RAW_ERR_CNT 8 YYYY-MM-DD+22:00:28.912 card 8-cpu0: [2704129.646042] EDCRC_MSK_ERR_CNT 0 YYYY-MM-DD+22:00:28.912 card 8-cpu0: [2704129.649441] EDCRC_CRC_ERR_CNT 1 YYYY-MM-DD+22:00:28.912 card 8-cpu0: [2704129.652840] EDCRC_EMR_INFO_CNT 8 YYYY-MM-DD+22:00:28.912 card 8-cpu0: [2704129.656327] EDCRC_EMR_INFO_HI 10914dd EDCRC_EMR_INFO_LO 6d024b85 YYYY-MM-DD+22:00:28.912 card 8-cpu0: [2704129.662579] EDCRC_EMR_INFO_HI 10814dd EDCRC_EMR_INFO_LO 6d024b85 YYYY-MM-DD+22:00:28.912 card 8-cpu0: [2704129.668829] EDCRC_EMR_INFO_HI 10714dd EDCRC_EMR_INFO_LO 6d024b85 YYYY-MM-DD+22:00:28.912 card 8-cpu0: [2704129.675084] EDCRC_EMR_INFO_HI 10614dd EDCRC_EMR_INFO_LO 6d024b85 YYYY-MM-DD+22:00:28.912 card 8-cpu0: [2704129.681343] EDCRC_EMR_INFO_HI 10514dd EDCRC_EMR_INFO_LO 6d024b85 YYYY-MM-DD+22:00:28.912 card 8-cpu0: [2704129.687600] EDCRC_EMR_INFO_HI 10414dd EDCRC_EMR_INFO_LO 6d024b85 YYYY-MM-DD+22:00:28.912 card 8-cpu0: [2704129.693852] EDCRC_EMR_INFO_HI 10314dd EDCRC_EMR_INFO_LO 6d024b85 YYYY-MM-DD+22:00:28.912 card 8-cpu0: [2704129.700132] EDCRC_EMR_INFO_HI 10214dd EDCRC_EMR_INFO_LO 6d024b85 YYYY-MM-DD+22:00:29.012 card 8-cpu0: [2704129.706399] EDCRC_EMR_INFO_HI 10114dd EDCRC_EMR_INFO_LO 6d024b85 YYYY-MM-DD+22:00:29.012 card 8-cpu0: [2704129.712732] DDF Reloading Started...... YYYY-MM-DD+22:00:29.012 card 8-cpu0: [2704129.716747] DDF Reloading ddf_reload_callback called with opcode 0...... YYYY-MM-DD+22:00:29.012 card 8-cpu0: hw_common_lib.c:[2704129.723619] DF: Reloading FPGA 5 YYYY-MM-DD+22:00:29.012 card 8-cpu0: DDF RELOAD CRC error received YYYY-MM-DD+22:00:29.012 card 8-cpu0: [2704129.731739] DF Loading image.. YYYY-MM-DD+22:00:30.112 card 8-cpu0: [2704130.872634] DF Done loading image. YYYY-MM-DD+22:00:30.212 card 8-cpu0: [2704130.975452] DF Ready (took 100ms) YYYY-MM-DD+22:00:30.912 card 8-cpu0: [2704131.654482] DF Interlaken Link UP YYYY-MM-DD+22:00:30.912 card 8-cpu0: [2704131.657984] DDF Reloading Ended...... YYYY-MM-DD+22:00:30.912 card 8-cpu0: [2704131.661840] DDF Reloading ddf_reload_callback called with opcode 1...... YYYY-MM-DD+22:00:31.012 card 8-cpu0: hat_common_lib.c:DDF CRC error timer received /sys/bus/boxer/drivers/df_prog/fpga_load8/prog_reload 0000
③ リロードが発生したDDFと通信しているCPUにdiamproxy/bgpのタスクがアサインされていることを確認します。
******** show task resources ******* ...snip... 1/1 bgp 2 0.2% 80% 22.14M 80.00M 15 500 -- -- - good # Card1 CPU1にbgpのタスクがアサインされている。 ...snip... 8/0 diamproxy 4 1.5% 90% 28.43M 250.0M 219 2500 -- -- - good # Card8 CPU0にdiamproxyがアサインされている。
|