search

YosysHQ / nextpnr

nextpnr portable FPGA place and route tool
ISC License
1.31k stars 243 forks source link

Improve clarity of timing report critical path format #551

Open bl0x opened 3 years ago

bl0x commented 3 years ago

The current output format of the timing report showing the critical path can be improved in terms of clarity.

Issues with current output format

Related issue is perhaps #470.

Example for current output format

Info: Critical path report for clock 'clock_$glb_clk' (posedge -> posedge):
Info: curr total
Info:  0.8  0.8  Source clock_receiver.sp.track_stream.add_full_SB_DFFSS_Q_D_SB_LUT4_O_LC.O
Info:  1.9  2.7    Net clock_receiver.sp.track_stream.add_full budget 0.000000 ns (7,30) -> (9,29)
Info:                Sink clock_receiver.sp.track_stream.counter_add_full_SB_LUT4_O_15_LC.I2
Info:  0.6  3.2  Source clock_receiver.sp.track_stream.counter_add_full_SB_LUT4_O_15_LC.O
Info:  1.9  5.1    Net clock_receiver.sp.track_stream.counter_add_full[0] budget 0.000000 ns (9,29) -> (7,28)
Info:                Sink clock_receiver.sp.track_stream.counter_add_half_SB_CARRY_I0_14$CARRY.I2
Info:  0.3  5.5  Source clock_receiver.sp.track_stream.counter_add_half_SB_CARRY_I0_14$CARRY.COUT
Info:  0.4  5.8    Net clock_receiver.sp.track_stream.counter_add_SB_LUT4_O_I3[1] budget 0.380000 ns (7,28) -> (7,28)
Info:                Sink clock_receiver.sp.track_stream.counter_add_SB_LUT4_O_8_LC.I3
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.5  6.3  Source clock_receiver.sp.track_stream.counter_add_SB_LUT4_O_8_LC.O
Info:  0.9  7.2    Net clock_receiver.sp.track_stream.counter_add[1] budget 0.000000 ns (7,28) -> (6,27)
Info:                Sink clock_receiver.sp.track_stream.counter_next_SB_LUT4_O_8_LC.I1
Info:  0.4  7.5  Source clock_receiver.sp.track_stream.counter_next_SB_LUT4_O_8_LC.COUT
Info:  0.4  7.9    Net clock_receiver.sp.track_stream.counter_next_SB_LUT4_O_I3[2] budget 0.380000 ns (6,27) -> (6,27)
Info:                Sink clock_receiver.sp.track_stream.counter_next_SB_LUT4_O_7_LC.I3
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.5  8.4  Source clock_receiver.sp.track_stream.counter_next_SB_LUT4_O_7_LC.O
Info:  1.9 10.3    Net clock_receiver.sp.track_stream.counter_next[2] budget 0.576000 ns (6,27) -> (9,26)
Info:                Sink clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3_SB_CARRY_CO_4$CARRY.I1
Info:  0.4 10.7  Source clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3_SB_CARRY_CO_4$CARRY.COUT
Info:  0.0 10.7    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[3] budget 0.000000 ns (9,26) -> (9,26)
Info:                Sink clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3_SB_CARRY_CO_3$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 10.8  Source clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3_SB_CARRY_CO_3$CARRY.COUT
Info:  0.0 10.8    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[4] budget 0.000000 ns (9,26) -> (9,26)
Info:                Sink clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3_SB_CARRY_CO_2$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 11.0  Source clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3_SB_CARRY_CO_2$CARRY.COUT
Info:  0.0 11.0    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[5] budget 0.000000 ns (9,26) -> (9,26)
Info:                Sink clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3_SB_CARRY_CO_1$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 11.2  Source clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3_SB_CARRY_CO_1$CARRY.COUT
Info:  0.0 11.2    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[6] budget 0.000000 ns (9,26) -> (9,26)
Info:                Sink clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3_SB_CARRY_CO$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 11.4  Source clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3_SB_CARRY_CO$CARRY.COUT
Info:  0.0 11.4    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[7] budget 0.000000 ns (9,26) -> (9,26)
Info:                Sink clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_2$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 11.6  Source clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_2$CARRY.COUT
Info:  0.3 11.9    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[8] budget 0.290000 ns (9,26) -> (9,27)
Info:                Sink clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_1$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 12.1  Source clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_1$CARRY.COUT
Info:  0.0 12.1    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[9] budget 0.000000 ns (9,27) -> (9,27)
Info:                Sink clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 12.2  Source clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1$CARRY.COUT
Info:  0.0 12.2    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[10] budget 0.000000 ns (9,27) -> (9,27)
Info:                Sink clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_9$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 12.4  Source clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_9$CARRY.COUT
Info:  0.0 12.4    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[11] budget 0.000000 ns (9,27) -> (9,27)
Info:                Sink clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_8$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 12.6  Source clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_8$CARRY.COUT
Info:  0.0 12.6    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[12] budget 0.000000 ns (9,27) -> (9,27)
Info:                Sink clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_7$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 12.8  Source clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_7$CARRY.COUT
Info:  0.0 12.8    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[13] budget 0.000000 ns (9,27) -> (9,27)
Info:                Sink clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_6$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 13.0  Source clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_6$CARRY.COUT
Info:  0.0 13.0    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[14] budget 0.000000 ns (9,27) -> (9,27)
Info:                Sink clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_5$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 13.2  Source clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_5$CARRY.COUT
Info:  0.0 13.2    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[15] budget 0.000000 ns (9,27) -> (9,27)
Info:                Sink clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_4$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 13.4  Source clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_4$CARRY.COUT
Info:  0.3 13.7    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[16] budget 0.290000 ns (9,27) -> (9,28)
Info:                Sink clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_3$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 13.8  Source clock_receiver.sp.track_stream.target_period_SB_LUT4_I3_O_SB_CARRY_I1_3$CARRY.COUT
Info:  0.0 13.8    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[17] budget 0.000000 ns (9,28) -> (9,28)
Info:                Sink clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3_SB_CARRY_CO_6$CARRY.CIN
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.2 14.0  Source clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3_SB_CARRY_CO_6$CARRY.COUT
Info:  0.4 14.4    Net clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_I3[18] budget 0.380000 ns (9,28) -> (9,28)
Info:                Sink clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_LC.I3
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/arith_map.v:51.21-51.22
Info:  0.5 14.9  Source clock_receiver.sp.track_stream.counter_next_wrap_half_SB_LUT4_O_LC.O
Info:  1.9 16.8    Net clock_receiver.sp.track_stream.counter_next_wrap_half[18] budget 0.242000 ns (9,28) -> (7,31)
Info:                Sink clock_receiver.sp.track_stream.counter_next_wrapped_half_SB_LUT4_O_LC.I2
Info:  0.6 17.3  Source clock_receiver.sp.track_stream.counter_next_wrapped_half_SB_LUT4_O_LC.O
Info:  0.9 18.2    Net clock_receiver.sp.track_stream.counter_next_wrapped_half budget -0.065000 ns (7,31) -> (7,31)
Info:                Sink clock_receiver.sp.track_stream.counter_next_wrapped_half_SB_LUT4_I3_LC.I3
Info:  0.5 18.6  Source clock_receiver.sp.track_stream.counter_next_wrapped_half_SB_LUT4_I3_LC.O
Info:  1.3 20.0    Net clock_receiver.sp.track_stream.counter_next_wrapped_half_SB_LUT4_I3_O[3] budget 0.349000 ns (7,31) -> (10,31)
Info:                Sink clock_receiver.sp.track_stream.transitions_8_hist_SB_DFFE_Q_E_SB_LUT4_O_LC.I0
Info:                Defined in:
Info:                  /usr/bin/../share/yosys/ice40/cells_map.v:6.21-6.22
Info:  0.7 20.6  Source clock_receiver.sp.track_stream.transitions_8_hist_SB_DFFE_Q_E_SB_LUT4_O_LC.O
Info:  2.2 22.8    Net clock_receiver.sp.track_stream.transitions_8_hist_SB_DFFE_Q_E budget 0.237000 ns (10,31) -> (10,30)
Info:                Sink clock_receiver.sp.track_stream.transitions_8_hist_SB_DFFE_Q_D_SB_LUT4_O_LC.CEN
Info:  0.1 22.9  Setup clock_receiver.sp.track_stream.transitions_8_hist_SB_DFFE_Q_D_SB_LUT4_O_LC.CEN
Info: 8.4 ns logic, 14.5 ns routing

Example for improved (clearer) format

coord  block  block  logic    net  signal
------ ------ ------ -----  -----  ------------------------------
x7y30                  0.8    1.9  clock_receiver.sp.track_stream.add_full
x9y29                  0.6    1.9  clock_receiver.sp.track_stream.counter_add_full[0]
x7y28  LUT4            0.3    0.4  clock_receiver.sp.track_stream.counter_add[1]
x7y28                  0.5    0.9  clock_receiver.sp.track_stream.counter_add[1]
x6y27  LUT4            0.4    0.4  clock_receiver.sp.track_stream.counter_next[2]
x6y27                  0.5    1.9  clock_receiver.sp.track_stream.counter_next[2]
x9y26  LUT4            0.4    0.0  clock_receiver.sp.track_stream.counter_next_wrap_half[3]
x9y26  LUT4            0.2    0.0  clock_receiver.sp.track_stream.counter_next_wrap_half[4]
x9y26  LUT4            0.2    0.0  clock_receiver.sp.track_stream.counter_next_wrap_half[5]
x9y26  LUT4            0.2    0.0  clock_receiver.sp.track_stream.counter_next_wrap_half[6]
x9y26  LUT4            0.2    0.0  clock_receiver.sp.track_stream.counter_next_wrap_half[7]
x9y26  LUT4            0.2    0.3  clock_receiver.sp.track_stream.counter_next_wrap_half[8]
x9y27  LUT4            0.2    0.0  clock_receiver.sp.track_stream.counter_next_wrap_half[9]
x9y27  LUT4            0.2    0.0  clock_receiver.sp.track_stream.counter_next_wrap_half[10]
x9y27  LUT4            0.2    0.0  clock_receiver.sp.track_stream.counter_next_wrap_half[11]
x9y27  LUT4            0.2    0.0  clock_receiver.sp.track_stream.counter_next_wrap_half[12]
x9y27  LUT4            0.2    0.0  clock_receiver.sp.track_stream.counter_next_wrap_half[13]
x9y27  LUT4            0.2    0.0  clock_receiver.sp.track_stream.counter_next_wrap_half[14]
x9y27  LUT4            0.2    0.0  clock_receiver.sp.track_stream.counter_next_wrap_half[15]
x9y27  LUT4            0.2    0.3  clock_receiver.sp.track_stream.counter_next_wrap_half[16]
x9y28  LUT4            0.2    0.0  clock_receiver.sp.track_stream.counter_next_wrap_half[17]
x9y28  LUT4            0.2    0.4  clock_receiver.sp.track_stream.counter_next_wrap_half[18]
x9y28                  0.5    1.9  clock_receiver.sp.track_stream.counter_next_wrap_half[18]
x7y31                  0.6    0.9  clock_receiver.sp.track_stream.counter_next_wrapped_half
x7y31  LUT4            0.5    1.3  clock_receiver.sp.track_stream.counter_next_wrapped_half[3]
x10y31 DFFE            0.7    2.2  clock_receiver.sp.track_stream.transitions_8_hist
x10y30 DFFE   LUT4     0.1         clock_receiver.sp.track_stream.transitions_8_hist
------ ------ ------ -----  -----  ------------------------------
                       8.4   14.5  = 22.9

Workaround

Attached below is a perl script (by H.T. Johansson) that transforms from the current output format to the clearer format by invoking e.g.:

perl ./pretty_timing_pl.txt < timing1.txt > timing1_out.txt

pretty_timing_pl.txt

tommythorn commented 2 years ago

@bl0x That's a lot nicer, but does pretty_timing have a home? The attached version seems to have problems with the current verision of nextpnr.

kittennbfive commented 1 year ago

Hi,

quick fix to make this script work more or less: Comment die "Unhandled line: \"$line\""; by adding a # in front of it.

I agree that the current output from nextpnr is quite difficult to understand, but as pretty_timing.pl seems to be abandonware (if this word even exists...) i am trying to write a new version from scratch that works with current output of nextpnr. Currently it's just a hack and not even alpha-quality, but if i get something decent i will publish it.

I am working with Lattice ECP5 but as far as possible i am trying to make a generic helper/tool. However as i am a beginner i have some trouble with all these internals names like "SB_LUT4_O_I3_SB_CARRY_CO_6$CARRY.COUT"... I assume i have to look at the databases for the different architectures to figure out the exact naming schemes used?

Also i would appreciate if somebody could paste a recent timing report for ICE40 as i don't have Yosys/nextpnr compiled for this architecture currently.

And finally, if somebody has a good explanation regarding FPGA timing reports a link would be appreciated.

kittennbfive commented 1 year ago

Just learned that there will be major changes to the timing API of nextpnr soon: https://github.com/YosysHQ/nextpnr/pull/1149

I guess (hope) the timing report will be improved also. Considering this i'll probably wait before putting lot's of work in the rewrite of the script. EDIT: No, i won't change so i will continue my work.

kittennbfive commented 1 year ago

I hope this won't be considered as spam, but i released an early version of my script (as public domain) here: https://github.com/kittennbfive/5A-75B-tools/blob/master/beautify-timing-report.pl If you have any issues/ideas/... please comment/open PR/... in my repo and not here in this issue.

tommythorn commented 11 months ago

@kittennbfive I finally got around to trying it. It's definitely much nicer and readable, thanks.