自作CPUの面積削減の試行をしている間、どこかの段階でサイクル性能がデグレードしてしまった。 デグレードする前のリビジョンを特定したので、デグレード前とデグレード後の実行ログは取得できたのだが、Dhrystoneの実行ログは非常に長いので、どこが原因なのか詳細を把握できない。
そこで、2つの実行ログを比較して、命令単位で最もサイクル数に差分が現れる場所を特定するためのPythonスクリプトを作成した。
../scripts/cycle_diff.py cycle1.log cycle2.log -n 10
ログ1.logとログ2.logを比較し、その中で最も両者のサイクル数が異なっている命令のトップ10を出力するスクリプトだ。
それぞれのログは、以下のフォーマットである。
5656 : 211 : PC=[00000000800036b6] (M,20,04) 0000f4ee c.sdsp s11, 104(sp) MW8(0x0000000080026da8)=>0000000000000000 5656 : 212 : PC=[00000000800036b8] (M,20,08) 00007139 c.addi16sp sp, -64 GPR[02](139) <= 0000000080026d00 5656 : 213 : PC=[00000000800036ba] (M,20,16) 0000880a c.mv a6, sp GPR[16](178) <= 0000000080026d00 22646 : L1D Load-In : 80003d40(00245) : 0000322e_32206e6f_69737265_56202c43_0000474e_49525453_20454d4f_53202c4d_4152474f_52502045_4e4f5453_59524844_00000000_00008082_0141557d_60a29ecf 22646 : Load ISS Check : 80003d40 : 0000322e_32206e6f_69737265_56202c43_0000474e_49525453_20454d4f_53202c4d_4152474f_52502045_4e4f5453_59524844_00000000_00008082_0141557d_60a29ecf 22650 : L1D Load-In : 80026e00(00440) : 00000000_00000000_00000000_00000000_00000000_00000000_00000000_00000000_00000000_00000000_00000000_00000000_00000000_80003546_00000000_80026e40 22650 : Load ISS Check : 80026e00 : 00000000_00000000_00000000_00000000_00000000_00000000_00000000_00000000_00000000_00000000_00000000_00000000_00000000_80003546_00000000_80026e40 5664 : 214 : PC=[00000000800036bc] (M,21,01) 00007139 c.addi16sp sp, -64 GPR[02](124) <= 0000000080026cc0 5664 : 215 : PC=[00000000800036be] (M,21,02) 0000860a c.mv a2, sp GPR[12](126) <= 0000000080026cc0 5664 : 216 : PC=[00000000800036c0] (M,21,04) 00004388 c.lw a0, 0(a5) MR4(0x0000000080003d50)=>0000000059524844 GPR[10](67) <= 0000000059524844 5664 : 217 : PC=[00000000800036c2] (M,21,08) 0000e60c c.sd a1, 8(a2) MW8(0x0000000080026cc8)=>0000000200000000 5664 : 218 : PC=[00000000800036c4] (M,21,16) 02800593 li a1, 40 GPR[11](179) <= 0000000000000028 22670 : L1D Load-In : 80004300(00268) : 4152474f_52502045_4e4f5453_59524844_0000474e_49525453_20545327_31202c4d_4152474f_52502045_4e4f5453_59524844_00000000_00000000_0a646c25_20202020 22670 : Load ISS Check : 80004300 : 4152474f_52502045_4e4f5453_59524844_0000474e_49525453_20545327_31202c4d_4152474f_52502045_4e4f5453_59524844_00000000_00000000_0a646c25_20202020 22674 : L1D Load-In : 80026dc0(00439) : 00000000_00000000_00000000_80006e90_00000000_80006eb0_00000000_00000000_00000000_80006ec0_00000000_00000000_00000000_00000000_00000000_00000000 22674 : Load ISS Check : 80026dc0 : 00000000_00000000_00000000_80006e90_00000000_80006eb0_00000000_00000000_00000000_80006ec0_00000000_00000000_00000000_00000000_00000000_00000000 5670 : 219 : PC=[00000000800036c8] (M,22,01) 0107a383 lw t2, 16(a5) MR4(0x0000000080003d60)=>0000000053202c4d GPR[07](9) <= 0000000053202c4d 5670 : 220 : PC=[00000000800036cc] (M,22,02) 0147a283 lw t0, 20(a5) MR4(0x0000000080003d64)=>0000000020454d4f GPR[05](68) <= 0000000020454d4f 5670 : 221 : PC=[00000000800036d0] (M,22,04) 0187af83 lw t6, 24(a5) MR4(0x0000000080003d68)=>0000000049525453 GPR[31](85) <= 0000000049525453
最終的に、以下のログが得られる。ロード命令が最も差分が大きく出ており、300サイクル程度の差分が出てしまっている。なんだこれは?
cycle[208702,149409] inst[219162,218360] PC=0000000080002f02 (M,03,01),(M,22,01) c.j pc + 0 cycle 208702, 149409 cycle[208703,149410] inst[219163,218361] PC=0000000080002f02 (M,04,01),(M,23,01) c.j pc + 0 cycle 208703, 149410 cycle[208704,149411] inst[219164,218362] PC=0000000080002f02 (M,05,01),(M,24,01) c.j pc + 0 cycle 208704, 149411 ---------------------------- Top ranked different cycles ---------------------------- diff=305 : cycle[196443,144302] inst[214525,213723] PC=0000000080002c3e (M,25,01),(M,03,01) lbu a1, 1(t3) cycle 196443, 144302 diff=305 : cycle[179119,136235] inst[206810,206008] PC=0000000080002652 (M,03,01),(M,18,01) lbu t3, 0(a0) cycle 179119, 136235 diff=304 : cycle[201851,145940] inst[216530,215728] PC=0000000080002652 (M,24,01),(M,54,01) lbu t3, 0(a0) cycle 201851, 145940 diff=304 : cycle[198795,144720] inst[215168,214366] PC=0000000080002652 (M,03,01),(M,17,01) lbu t3, 0(a0) cycle 198795, 144720 diff=304 : cycle[198113,144654] inst[215036,214234] PC=0000000080002652 (M,34,01),(M,48,01) lbu t3, 0(a0) cycle 198113, 144654 diff=304 : cycle[176964,134589] inst[206036,205234] PC=0000000080002652 (M,54,01),(M,42,01) lbu t3, 0(a0) cycle 176964, 134589 diff=303 : cycle[171197,132548] inst[204036,203234] PC=0000000080002c3e (M,06,01),(M,16,01) lbu a1, 1(t3) cycle 171197, 132548 diff=302 : cycle[197431,144590] inst[214904,214102] PC=0000000080002652 (M,01,01),(M,15,01) lbu t3, 0(a0) cycle 197431, 144590 diff=302 : cycle[183302,137930] inst[208448,207646] PC=0000000080002652 (M,58,01),(M,50,01) lbu t3, 0(a0) cycle 183302, 137930 diff=275 : cycle[154720,123591] inst[196744,195942] PC=0000000080002652 (M,38,01),(M,18,01) lbu t3, 0(a0) cycle 154720, 123591 ----------------------------
いろいろ調査した結果、LDQおよびSTQの物理アドレスの確定を示す信号に問題があることが分かった。これを修正すると、かなり性能の問題が解決されてきた気がする。
181000 : 217199 : IPC(recent) = 0.13, IPC(total) = 1.20 182000 : 217319 : IPC(recent) = 0.12, IPC(total) = 1.19 183000 : 217439 : IPC(recent) = 0.12, IPC(total) = 1.19 184000 : 217808 : IPC(recent) = 0.37, IPC(total) = 1.18 185000 : 218265 : IPC(recent) = 0.46, IPC(total) = 1.18 TOP.scariv_tb.u_scariv_subsystem_wrapper.u_scariv_subsystem.u_tile.u_lsu_top.u_st_buffer.entry_loop[4].u_entry Caution: ST-Buffer doesn't go back to Initial state 1 / 1 : dhrystone : CYCLE DEGRADED ERROR : Expected Cycle Different. RTL = 761854, EXPECTED = 569606. Diff = 25.23% {'pass': 0, 'match': 0, 'timeout': 0, 'error': 0, 'deadlock': 0, 'unknown': 0, 'cycle_deleg': 1}
それでもまだデグレードしている。まだ解析だ。