caiyu/nextpnr
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Formatting and display async path in json report

Browse Source
This commit is contained in:
rowanG077 2023-06-21 18:09:38 +02:00 committed by myrtle
parent cfd3a52a3c
commit b0820eeaaa
3 changed files with 87 additions and 113 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

96
common/kernel/timing.cc
View File

@ -48,9 +48,12 @@ TimingAnalyser::TimingAnalyser(Context *ctx) : ctx(ctx)
domain_to_id.emplace(key, 0); domain_to_id.emplace(key, 0);
domains.emplace_back(key); domains.emplace_back(key);
async_clock_id = 0; async_clock_id = 0;
domain_pair_id(async_clock_id, async_clock_id);
}; };
void TimingAnalyser::setup(bool update_net_timings, bool update_histogram, bool update_crit_paths, bool update_route_delays) void TimingAnalyser::setup(bool update_net_timings, bool update_histogram, bool update_crit_paths,
bool update_route_delays)
{ {
init_ports(); init_ports();
get_cell_delays(); get_cell_delays();
@ -60,7 +63,8 @@ void TimingAnalyser::setup(bool update_net_timings, bool update_histogram, bool
run(update_net_timings, update_histogram, update_crit_paths, update_route_delays); run(update_net_timings, update_histogram, update_crit_paths, update_route_delays);
} }
void TimingAnalyser::run(bool update_net_timings, bool update_histogram, bool update_crit_paths, bool update_route_delays) void TimingAnalyser::run(bool update_net_timings, bool update_histogram, bool update_crit_paths,
bool update_route_delays)
{ {
reset_times(); reset_times();
if (update_route_delays) if (update_route_delays)
@ -757,21 +761,11 @@ void TimingAnalyser::build_detailed_net_timing_report()
auto &capture = domains.at(req.first).key; auto &capture = domains.at(req.first).key;
NetSinkTiming sink_timing; NetSinkTiming sink_timing;
sink_timing.clock_pair = ClockPair { sink_timing.clock_pair = ClockPair{.start = ClockEvent{.clock = launch.clock, .edge = launch.edge},
.start = ClockEvent { .end = ClockEvent{.clock = capture.clock, .edge = capture.edge}};
.clock = launch.clock,
.edge = launch.edge
},
.end = ClockEvent {
.clock = capture.clock,
.edge = capture.edge
}
};
sink_timing.cell_port = std::make_pair(pd.cell_port.cell, pd.cell_port.port); sink_timing.cell_port = std::make_pair(pd.cell_port.cell, pd.cell_port.port);
sink_timing.delay = arr.second.value.max_delay; sink_timing.delay = arr.second.value.max_delay;
log_info("update net_timings: %s: %f\n", net->name.c_str(ctx), (float) sink_timing.delay);
net_timings[net->name].push_back(sink_timing); net_timings[net->name].push_back(sink_timing);
} }
} }
@ -806,6 +800,32 @@ std::vector<CellPortKey> TimingAnalyser::get_worst_eps(domain_id_t domain_pair,
return worst_eps; return worst_eps;
} }
static std::string tgp_to_string(TimingPortClass c)
{
switch (c) {
case TMG_CLOCK_INPUT:
return "TMG_CLOCK_INPUT";
case TMG_GEN_CLOCK:
return "TMG_GEN_CLOCK";
case TMG_REGISTER_INPUT:
return "TMG_REGISTER_INPUT";
case TMG_REGISTER_OUTPUT:
return "TMG_REGISTER_OUTPUT";
case TMG_COMB_INPUT:
return "TMG_COMB_INPUT";
case TMG_COMB_OUTPUT:
return "TMG_COMB_OUTPUT";
case TMG_STARTPOINT:
return "TMG_STARTPOINT";
case TMG_ENDPOINT:
return "TMG_ENDPOINT";
case TMG_IGNORE:
return "TMG_IGNORE";
}
return "UNKNOWN";
}
CriticalPath TimingAnalyser::build_critical_path_report(domain_id_t domain_pair, CellPortKey endpoint) CriticalPath TimingAnalyser::build_critical_path_report(domain_id_t domain_pair, CellPortKey endpoint)
{ {
CriticalPath report; CriticalPath report;
@ -814,16 +834,8 @@ CriticalPath TimingAnalyser::build_critical_path_report(domain_id_t domain_pair,
auto &launch = domains.at(dp.key.launch).key; auto &launch = domains.at(dp.key.launch).key;
auto &capture = domains.at(dp.key.capture).key; auto &capture = domains.at(dp.key.capture).key;
report.clock_pair = ClockPair { report.clock_pair = ClockPair{.start = ClockEvent{.clock = launch.clock, .edge = launch.edge},
.start = ClockEvent { .end = ClockEvent{.clock = capture.clock, .edge = capture.edge}};
.clock = launch.clock,
.edge = launch.edge
},
.end = ClockEvent {
.clock = capture.clock,
.edge = capture.edge
}
};
report.period = ctx->getDelayFromNS(1.0e9 / ctx->setting<float>("target_freq")); report.period = ctx->getDelayFromNS(1.0e9 / ctx->setting<float>("target_freq"));
if (launch.edge != capture.edge) { if (launch.edge != capture.edge) {
@ -842,19 +854,20 @@ CriticalPath TimingAnalyser::build_critical_path_report(domain_id_t domain_pair,
std::vector<PortRef> crit_path_rev; std::vector<PortRef> crit_path_rev;
auto cursor = endpoint; auto cursor = endpoint;
log_info("Analyzing %s -> %s\n", clock_event_name(ctx, launch).c_str(), clock_event_name(ctx, capture).c_str());
while (cursor != CellPortKey()) { while (cursor != CellPortKey()) {
auto cell = cell_info(cursor); auto cell = cell_info(cursor);
auto& port = port_info(cursor); auto &port = port_info(cursor);
int port_clocks; int port_clocks;
auto portClass = ctx->getPortTimingClass(cell, port.name, port_clocks); auto portClass = ctx->getPortTimingClass(cell, port.name, port_clocks);
if (portClass != TMG_CLOCK_INPUT && log_info("\tcursor at %s.%s tmg: %s, port dir: %s\n", cell->name.c_str(ctx), port.name.c_str(ctx),
portClass != TMG_ENDPOINT && tgp_to_string(portClass).c_str(), port.type == PortType::PORT_IN ? "PORT_IN" : "PORT_X");
portClass != TMG_IGNORE &&
port.type == PortType::PORT_IN) if (portClass != TMG_CLOCK_INPUT && portClass != TMG_IGNORE && port.type == PortType::PORT_IN) {
{ crit_path_rev.emplace_back(PortRef{cell, port.name});
crit_path_rev.emplace_back(PortRef { cell, port.name });
} }
if (!ports.at(cursor).arrival.count(dp.key.launch)) if (!ports.at(cursor).arrival.count(dp.key.launch))
break; break;
@ -959,15 +972,8 @@ void TimingAnalyser::build_crit_path_reports()
auto delay_by_domain = max_delay_by_domain_pairs(); auto delay_by_domain = max_delay_by_domain_pairs();
auto uq_doms = ctx->timing_result.empty_paths; for (int i = 0; i < int(domains.size()); i++) {
auto clock_pairs = std::vector<std::pair<ClockDomainKey, ClockDomainKey>>(); empty_clocks.insert(domains.at(i).key.clock);
for (int i = 0; i < int(domain_pairs.size()); i++) {
auto &dp = domain_pairs.at(i);
auto &launch = domains.at(dp.key.launch).key;
auto &capture = domains.at(dp.key.capture).key;
clock_pairs.emplace_back(std::make_pair(launch, capture));
} }
for (int i = 0; i < int(domain_pairs.size()); i++) { for (int i = 0; i < int(domain_pairs.size()); i++) {
@ -1005,9 +1011,15 @@ void TimingAnalyser::build_crit_path_reports()
auto &launch = domains.at(dp.key.launch).key; auto &launch = domains.at(dp.key.launch).key;
auto &capture = domains.at(dp.key.capture).key; auto &capture = domains.at(dp.key.capture).key;
if (launch.clock == capture.clock) log_info("testin testing %s -> %s\n", clock_event_name(ctx, launch).c_str(),
clock_event_name(ctx, capture).c_str());
if (launch.clock == capture.clock && !launch.is_async())
continue; continue;
log_info("testin testing2 %s -> %s\n", clock_event_name(ctx, launch).c_str(),
clock_event_name(ctx, capture).c_str());
auto worst_endpoint = get_worst_eps(i, 1).at(0); auto worst_endpoint = get_worst_eps(i, 1).at(0);
xclock_reports.emplace_back(build_critical_path_report(i, worst_endpoint)); xclock_reports.emplace_back(build_critical_path_report(i, worst_endpoint));
} }
@ -1045,7 +1057,7 @@ void TimingAnalyser::build_crit_path_reports()
void TimingAnalyser::build_slack_histogram_report() void TimingAnalyser::build_slack_histogram_report()
{ {
auto& slack_histogram = ctx->timing_result.slack_histogram; auto &slack_histogram = ctx->timing_result.slack_histogram;
for (domain_id_t dom_id = 0; dom_id < domain_id_t(domains.size()); ++dom_id) { for (domain_id_t dom_id = 0; dom_id < domain_id_t(domains.size()); ++dom_id) {
for (auto &ep : domains.at(dom_id).endpoints) { for (auto &ep : domains.at(dom_id).endpoints) {

42
common/kernel/timing_old.cc
View File

@ -411,8 +411,6 @@ struct Timing
for (auto crit_pair : crit_nets) { for (auto crit_pair : crit_nets) {
NetInfo *crit_net = crit_pair.second.second; NetInfo *crit_net = crit_pair.second.second;
auto &cp_ports = (*crit_path)[crit_pair.first].ports; auto &cp_ports = (*crit_path)[crit_pair.first].ports;
log_info("// Walk backwards from the most critical net, start point: %s.%s\n",
cp_ports.at(0)->cell->name.c_str(ctx), cp_ports.at(0)->port.c_str(ctx));
while (crit_net) { while (crit_net) {
const PortInfo *crit_ipin = nullptr; const PortInfo *crit_ipin = nullptr;
delay_t max_arrival = std::numeric_limits<delay_t>::min(); delay_t max_arrival = std::numeric_limits<delay_t>::min();
@ -454,9 +452,7 @@ struct Timing
break; break;
// Now convert PortInfo* into a PortRef* // Now convert PortInfo* into a PortRef*
for (auto &usr : crit_ipin->net->users) { for (auto &usr : crit_ipin->net->users) {
log_info("critical pin user: %s.%s\n", usr.cell->name.c_str(ctx), usr.port.c_str(ctx));
if (usr.cell->name == crit_net->driver.cell->name && usr.port == crit_ipin->name) { if (usr.cell->name == crit_net->driver.cell->name && usr.port == crit_ipin->name) {
log_info("Adding %s.%s to critical path\n", usr.cell->name.c_str(ctx), usr.port.c_str(ctx));
cp_ports.push_back(&usr); cp_ports.push_back(&usr);
break; break;
} }
@ -470,32 +466,6 @@ struct Timing
} }
}; };
std::string tgp_to_string(TimingPortClass c)
{
switch (c) {
case TMG_CLOCK_INPUT:
return "TMG_CLOCK_INPUT";
case TMG_GEN_CLOCK:
return "TMG_GEN_CLOCK";
case TMG_REGISTER_INPUT:
return "TMG_REGISTER_INPUT";
case TMG_REGISTER_OUTPUT:
return "TMG_REGISTER_OUTPUT";
case TMG_COMB_INPUT:
return "TMG_COMB_INPUT";
case TMG_COMB_OUTPUT:
return "TMG_COMB_OUTPUT";
case TMG_STARTPOINT:
return "TMG_STARTPOINT";
case TMG_ENDPOINT:
return "TMG_ENDPOINT";
case TMG_IGNORE:
return "TMG_IGNORE";
}
return "UNKNOWN";
}
CriticalPath build_critical_path_report(Context *ctx, ClockPair &clocks, const PortRefVector &crit_path) CriticalPath build_critical_path_report(Context *ctx, ClockPair &clocks, const PortRefVector &crit_path)
{ {
CriticalPath report; CriticalPath report;
@ -524,9 +494,6 @@ CriticalPath build_critical_path_report(Context *ctx, ClockPair &clocks, const P
} }
} }
log_info("building critical path report for clocks: %s -> %s\n", clocks.start.clock.c_str(ctx),
clocks.end.clock.c_str(ctx));
for (auto sink : crit_path) { for (auto sink : crit_path) {
auto sink_cell = sink->cell; auto sink_cell = sink->cell;
@ -645,7 +612,6 @@ void timing_analysis(Context *ctx, bool print_histogram, bool print_fmax, bool p
const ClockEvent &b = path.first.end; const ClockEvent &b = path.first.end;
empty_clocks.insert(a.clock); empty_clocks.insert(a.clock);
empty_clocks.insert(b.clock); empty_clocks.insert(b.clock);
log_info("timing_old: clock pair: %s -> %s\n", a.clock.c_str(ctx), b.clock.c_str(ctx));
} }
for (auto path : crit_paths) { for (auto path : crit_paths) {
const ClockEvent &a = path.first.start; const ClockEvent &a = path.first.start;
@ -1018,14 +984,6 @@ void timing_analysis(Context *ctx, bool print_histogram, bool print_fmax, bool p
(bins[i] * bar_width) % max_freq > 0 ? '+' : ' '); (bins[i] * bar_width) % max_freq > 0 ? '+' : ' ');
} }
log_info("segments");
for (auto &r : clock_reports) {
log_info("clock: %s\n", r.first.c_str(ctx));
for (const auto &segment : r.second.segments) {
log_info("processing segment %s\n", segment.net.c_str(ctx));
}
}
// Update timing results in the context // Update timing results in the context
if (update_results) { if (update_results) {
auto &results = ctx->timing_result; auto &results = ctx->timing_result;

62
common/kernel/timing_report.cc
View File

@ -79,11 +79,10 @@ static void log_crit_paths(const Context *ctx)
segment.type == CriticalPath::Segment::Type::SETUP) { segment.type == CriticalPath::Segment::Type::SETUP) {
logic_total += segment.delay; logic_total += segment.delay;
const std::string type_name = const std::string type_name = (segment.type == CriticalPath::Segment::Type::SETUP) ? "Setup" : "Source";
(segment.type == CriticalPath::Segment::Type::SETUP) ? "Setup" : "Source";
log_info("%4.1f %4.1f %s %s.%s\n", ctx->getDelayNS(segment.delay), ctx->getDelayNS(total), log_info("%4.1f %4.1f %s %s.%s\n", ctx->getDelayNS(segment.delay), ctx->getDelayNS(total),
type_name.c_str(), segment.to.first.c_str(ctx), segment.to.second.c_str(ctx)); type_name.c_str(), segment.to.first.c_str(ctx), segment.to.second.c_str(ctx));
} else if (segment.type == CriticalPath::Segment::Type::ROUTING) { } else if (segment.type == CriticalPath::Segment::Type::ROUTING) {
route_total += segment.delay; route_total += segment.delay;
@ -94,8 +93,8 @@ static void log_crit_paths(const Context *ctx)
auto sink_loc = ctx->getBelLocation(sink->bel); auto sink_loc = ctx->getBelLocation(sink->bel);
log_info("%4.1f %4.1f Net %s (%d,%d) -> (%d,%d)\n", ctx->getDelayNS(segment.delay), log_info("%4.1f %4.1f Net %s (%d,%d) -> (%d,%d)\n", ctx->getDelayNS(segment.delay),
ctx->getDelayNS(total), segment.net.c_str(ctx), ctx->getDelayNS(total), segment.net.c_str(ctx), driver_loc.x, driver_loc.y, sink_loc.x,
driver_loc.x, driver_loc.y, sink_loc.x, sink_loc.y); sink_loc.y);
log_info(" Sink %s.%s\n", segment.to.first.c_str(ctx), segment.to.second.c_str(ctx)); log_info(" Sink %s.%s\n", segment.to.first.c_str(ctx), segment.to.second.c_str(ctx));
const NetInfo *net = ctx->nets.at(segment.net).get(); const NetInfo *net = ctx->nets.at(segment.net).get();
@ -109,8 +108,8 @@ static void log_crit_paths(const Context *ctx)
auto driver_wire = ctx->getNetinfoSourceWire(net); auto driver_wire = ctx->getNetinfoSourceWire(net);
auto sink_wire = ctx->getNetinfoSinkWire(net, sink_ref, 0); auto sink_wire = ctx->getNetinfoSinkWire(net, sink_ref, 0);
log_info(" prediction: %f ns estimate: %f ns\n", log_info(" prediction: %f ns estimate: %f ns\n",
ctx->getDelayNS(ctx->predictArcDelay(net, sink_ref)), ctx->getDelayNS(ctx->predictArcDelay(net, sink_ref)),
ctx->getDelayNS(ctx->estimateDelay(driver_wire, sink_wire))); ctx->getDelayNS(ctx->estimateDelay(driver_wire, sink_wire)));
auto cursor = sink_wire; auto cursor = sink_wire;
delay_t delay; delay_t delay;
while (driver_wire != cursor) { while (driver_wire != cursor) {
@ -139,12 +138,12 @@ static void log_crit_paths(const Context *ctx)
// Single domain paths // Single domain paths
for (auto &clock : ctx->timing_result.clock_paths) { for (auto &clock : ctx->timing_result.clock_paths) {
log_break(); log_break();
std::string start = clock.second.clock_pair.start.edge == FALLING_EDGE ? std::string("negedge") std::string start =
: std::string("posedge"); clock.second.clock_pair.start.edge == FALLING_EDGE ? std::string("negedge") : std::string("posedge");
std::string end = std::string end =
clock.second.clock_pair.end.edge == FALLING_EDGE ? std::string("negedge") : std::string("posedge"); clock.second.clock_pair.end.edge == FALLING_EDGE ? std::string("negedge") : std::string("posedge");
log_info("Critical path report for clock '%s' (%s -> %s):\n", clock.first.c_str(ctx), start.c_str(), log_info("Critical path report for clock '%s' (%s -> %s):\n", clock.first.c_str(ctx), start.c_str(),
end.c_str()); end.c_str());
auto &report = clock.second; auto &report = clock.second;
print_path_report(report); print_path_report(report);
} }
@ -176,18 +175,17 @@ static void log_fmax(Context *ctx, bool warn_on_failure)
bool passed = target < fmax; bool passed = target < fmax;
if (!warn_on_failure || passed) if (!warn_on_failure || passed)
log_info("Max frequency for clock %*s'%s': %.02f MHz (%s at %.02f MHz)\n", width, "", log_info("Max frequency for clock %*s'%s': %.02f MHz (%s at %.02f MHz)\n", width, "", clock_name.c_str(),
clock_name.c_str(), fmax, passed ? "PASS" : "FAIL", target); fmax, passed ? "PASS" : "FAIL", target);
else if (bool_or_default(ctx->settings, ctx->id("timing/allowFail"), false)) else if (bool_or_default(ctx->settings, ctx->id("timing/allowFail"), false))
log_warning("Max frequency for clock %*s'%s': %.02f MHz (%s at %.02f MHz)\n", width, "", log_warning("Max frequency for clock %*s'%s': %.02f MHz (%s at %.02f MHz)\n", width, "", clock_name.c_str(),
clock_name.c_str(), fmax, passed ? "PASS" : "FAIL", target); fmax, passed ? "PASS" : "FAIL", target);
else else
log_nonfatal_error("Max frequency for clock %*s'%s': %.02f MHz (%s at %.02f MHz)\n", width, "", log_nonfatal_error("Max frequency for clock %*s'%s': %.02f MHz (%s at %.02f MHz)\n", width, "",
clock_name.c_str(), fmax, passed ? "PASS" : "FAIL", target); clock_name.c_str(), fmax, passed ? "PASS" : "FAIL", target);
} }
log_break(); log_break();
// Clock to clock delays for xpaths // Clock to clock delays for xpaths
dict<ClockPair, delay_t> xclock_delays; dict<ClockPair, delay_t> xclock_delays;
for (auto &report : ctx->timing_result.xclock_paths) { for (auto &report : ctx->timing_result.xclock_paths) {
@ -256,15 +254,15 @@ static void log_fmax(Context *ctx, bool warn_on_failure)
auto ev_b = clock_event_name(ctx, report.clock_pair.end, max_width_xcb); auto ev_b = clock_event_name(ctx, report.clock_pair.end, max_width_xcb);
if (!warn_on_failure || passed) if (!warn_on_failure || passed)
log_info("Max frequency for %s -> %s: %.02f MHz (%s at %.02f MHz)\n", ev_a.c_str(), ev_b.c_str(), log_info("Max frequency for %s -> %s: %.02f MHz (%s at %.02f MHz)\n", ev_a.c_str(), ev_b.c_str(), fmax,
fmax, passed ? "PASS" : "FAIL", target); passed ? "PASS" : "FAIL", target);
else if (bool_or_default(ctx->settings, ctx->id("timing/allowFail"), false) || else if (bool_or_default(ctx->settings, ctx->id("timing/allowFail"), false) ||
bool_or_default(ctx->settings, ctx->id("timing/ignoreRelClk"), false)) bool_or_default(ctx->settings, ctx->id("timing/ignoreRelClk"), false))
log_warning("Max frequency for %s -> %s: %.02f MHz (%s at %.02f MHz)\n", ev_a.c_str(), log_warning("Max frequency for %s -> %s: %.02f MHz (%s at %.02f MHz)\n", ev_a.c_str(), ev_b.c_str(),
ev_b.c_str(), fmax, passed ? "PASS" : "FAIL", target); fmax, passed ? "PASS" : "FAIL", target);
else else
log_nonfatal_error("Max frequency for %s -> %s: %.02f MHz (%s at %.02f MHz)\n", ev_a.c_str(), log_nonfatal_error("Max frequency for %s -> %s: %.02f MHz (%s at %.02f MHz)\n", ev_a.c_str(),
ev_b.c_str(), fmax, passed ? "PASS" : "FAIL", target); ev_b.c_str(), fmax, passed ? "PASS" : "FAIL", target);
} }
log_break(); log_break();
} }
@ -280,8 +278,7 @@ static void log_fmax(Context *ctx, bool warn_on_failure)
delay /= 2; delay /= 2;
} }
log_info("Clock to clock delay %s -> %s: %0.02f ns\n", ev_a.c_str(), ev_b.c_str(), log_info("Clock to clock delay %s -> %s: %0.02f ns\n", ev_a.c_str(), ev_b.c_str(), ctx->getDelayNS(delay));
ctx->getDelayNS(delay));
} }
log_break(); log_break();
@ -312,7 +309,16 @@ static void log_fmax(Context *ctx, bool warn_on_failure)
log_break(); log_break();
} }
static void log_histogram(Context *ctx) { static void log_histogram(Context *ctx)
{
log_break();
log_info("Slack histogram:\n");
if (ctx->timing_result.slack_histogram.empty()) {
log_info(" No slack figures available\n");
return;
}
unsigned num_bins = 20; unsigned num_bins = 20;
unsigned bar_width = 60; unsigned bar_width = 60;
@ -341,14 +347,12 @@ static void log_histogram(Context *ctx) {
} }
bar_width = std::min(bar_width, max_freq); bar_width = std::min(bar_width, max_freq);
log_break();
log_info("Slack histogram:\n");
log_info(" legend: * represents %d endpoint(s)\n", max_freq / bar_width); log_info(" legend: * represents %d endpoint(s)\n", max_freq / bar_width);
log_info(" + represents [1,%d) endpoint(s)\n", max_freq / bar_width); log_info(" + represents [1,%d) endpoint(s)\n", max_freq / bar_width);
for (unsigned i = 0; i < num_bins; ++i) for (unsigned i = 0; i < num_bins; ++i)
log_info("[%6d, %6d) |%s%c\n", min_slack + bin_size * i, min_slack + bin_size * (i + 1), log_info("[%6d, %6d) |%s%c\n", min_slack + bin_size * i, min_slack + bin_size * (i + 1),
std::string(bins[i] * bar_width / max_freq, '*').c_str(), std::string(bins[i] * bar_width / max_freq, '*').c_str(),
(bins[i] * bar_width) % max_freq > 0 ? '+' : ' '); (bins[i] * bar_width) % max_freq > 0 ? '+' : ' ');
} }
void Context::log_timing_results(bool print_histogram, bool print_path, bool warn_on_failure) void Context::log_timing_results(bool print_histogram, bool print_path, bool warn_on_failure)