Implement debugging tools for site router.

 - Finishes implementation of SiteArch::nameOfPip and SiteArch::nameOfWire
 - Adds "explain_bel_status", which should be an exhaustive diagnostic
   of the status of a BEL placement.

Signed-off-by: Keith Rothman <537074+litghost@users.noreply.github.com>

7 files changed, 166 insertions, 23 deletions

diff --git a/fpga_interchange/arch.cc b/fpga_interchange/arch.cc
index e6e784f7..09e539e2 100644
--- a/fpga_interchange/arch.cc
+++ b/fpga_interchange/arch.cc
@@ -1861,6 +1861,36 @@ void Arch::remove_site_routing()
     }
 }
 
+void Arch::explain_bel_status(BelId bel) const
+{
+    if (isBelLocationValid(bel)) {
+        log_info("BEL %s is valid!\n", nameOfBel(bel));
+        return;
+    }
+
+    auto iter = tileStatus.find(bel.tile);
+    NPNR_ASSERT(iter != tileStatus.end());
+    const TileStatus &tile_status = iter->second;
+    const CellInfo *cell = tile_status.boundcells[bel.index];
+    if (!dedicated_interconnect.isBelLocationValid(bel, cell)) {
+        dedicated_interconnect.explain_bel_status(bel, cell);
+        return;
+    }
+
+    if (io_port_types.count(cell->type)) {
+        return;
+    }
+
+    if (!is_cell_valid_constraints(cell, tile_status, /*explain_constraints=*/true)) {
+        return;
+    }
+
+    auto &bel_data = bel_info(chip_info, bel);
+    const SiteRouter &site = get_site_status(tile_status, bel_data);
+    NPNR_ASSERT(!site.checkSiteRouting(getCtx(), tile_status));
+    site.explain(getCtx());
+}
+
 // Instance constraint templates.
 template void Arch::ArchConstraints::bindBel(Arch::ArchConstraints::TagState *, const Arch::ConstraintRange);
 template void Arch::ArchConstraints::unbindBel(Arch::ArchConstraints::TagState *, const Arch::ConstraintRange);
diff --git a/fpga_interchange/arch.h b/fpga_interchange/arch.h
index f6a8f0eb..642060cc 100644
--- a/fpga_interchange/arch.h
+++ b/fpga_interchange/arch.h
@@ -1087,6 +1087,8 @@ struct Arch : ArchAPI<ArchRanges>
 
     // This unmasks any BEL pins that were masked when site routing was bound.
     void unmask_bel_pins();
+
+    void explain_bel_status(BelId bel) const;
 };
 
 NEXTPNR_NAMESPACE_END
diff --git a/fpga_interchange/dedicated_interconnect.cc b/fpga_interchange/dedicated_interconnect.cc
index 988b13ab..1038ed1f 100644
--- a/fpga_interchange/dedicated_interconnect.cc
+++ b/fpga_interchange/dedicated_interconnect.cc
@@ -365,6 +365,35 @@ bool DedicatedInterconnect::isBelLocationValid(BelId bel, const CellInfo *cell)
     return true;
 }
 
+void DedicatedInterconnect::explain_bel_status(BelId bel, const CellInfo *cell) const
+{
+    NPNR_ASSERT(bel != BelId());
+
+    for (const auto &port_pair : cell->ports) {
+        IdString port_name = port_pair.first;
+        NetInfo *net = port_pair.second.net;
+        if (net == nullptr) {
+            continue;
+        }
+
+        // This net doesn't have a driver, probably not valid?
+        NPNR_ASSERT(net->driver.cell != nullptr);
+
+        // Only check sink BELs.
+        if (net->driver.cell == cell && net->driver.port == port_name) {
+            if (!is_driver_on_net_valid(bel, cell, port_name, net)) {
+                log_info("Driver %s/%s is not valid on net '%s'", cell->name.c_str(ctx), port_name.c_str(ctx),
+                         net->name.c_str(ctx));
+            }
+        } else {
+            if (!is_sink_on_net_valid(bel, cell, port_name, net)) {
+                log_info("Sink %s/%s is not valid on net '%s'", cell->name.c_str(ctx), port_name.c_str(ctx),
+                         net->name.c_str(ctx));
+            }
+        }
+    }
+}
+
 void DedicatedInterconnect::print_dedicated_interconnect() const
 {
     log_info("Found %zu sinks with dedicated interconnect\n", sinks.size());
diff --git a/fpga_interchange/dedicated_interconnect.h b/fpga_interchange/dedicated_interconnect.h
index 41adea15..900a82f3 100644
--- a/fpga_interchange/dedicated_interconnect.h
+++ b/fpga_interchange/dedicated_interconnect.h
@@ -133,6 +133,7 @@ struct DedicatedInterconnect
     //
     // Note: Only BEL pin sinks are checked.
     bool isBelLocationValid(BelId bel, const CellInfo *cell) const;
+    void explain_bel_status(BelId bel, const CellInfo *cell) const;
 
     void find_dedicated_interconnect();
     void print_dedicated_interconnect() const;
diff --git a/fpga_interchange/site_arch.cc b/fpga_interchange/site_arch.cc
index 711bef44..9cf7fa0c 100644
--- a/fpga_interchange/site_arch.cc
+++ b/fpga_interchange/site_arch.cc
@@ -59,6 +59,10 @@ bool SiteArch::bindPip(const SitePip &pip, SiteNetInfo *net)
         result.first->second.count += 1;
     }
 
+    if (debug()) {
+        log_info("Bound pip %s to wire %s\n", nameOfPip(pip), nameOfWire(dst));
+    }
+
     return true;
 }
 
@@ -67,6 +71,10 @@ void SiteArch::unbindPip(const SitePip &pip)
     SiteWire src = getPipSrcWire(pip);
     SiteWire dst = getPipDstWire(pip);
 
+    if (debug()) {
+        log_info("Unbinding pip %s from wire %s\n", nameOfPip(pip), nameOfWire(dst));
+    }
+
     SiteNetInfo *src_net = unbindWire(src);
     SiteNetInfo *dst_net = unbindWire(dst);
     NPNR_ASSERT(src_net == dst_net);
@@ -280,10 +288,16 @@ const char *SiteArch::nameOfWire(const SiteWire &wire) const
         return ctx->nameOfWire(wire.wire);
     case SiteWire::SITE_PORT_SOURCE:
         return ctx->nameOfWire(wire.wire);
-    case SiteWire::OUT_OF_SITE_SOURCE:
-        return "out of site source, implement me!";
-    case SiteWire::OUT_OF_SITE_SINK:
-        return "out of site sink, implement me!";
+    case SiteWire::OUT_OF_SITE_SOURCE: {
+        std::string &str = ctx->log_strs.next();
+        str = stringf("Out of site source for net %s", wire.net->name.c_str(ctx));
+        return str.c_str();
+    }
+    case SiteWire::OUT_OF_SITE_SINK: {
+        std::string &str = ctx->log_strs.next();
+        str = stringf("Out of sink source for net %s", wire.net->name.c_str(ctx));
+        return str.c_str();
+    }
     default:
         // Unreachable!
         NPNR_ASSERT(false);
@@ -297,12 +311,24 @@ const char *SiteArch::nameOfPip(const SitePip &pip) const
         return ctx->nameOfPip(pip.pip);
     case SitePip::SITE_PORT:
         return ctx->nameOfPip(pip.pip);
-    case SitePip::SOURCE_TO_SITE_PORT:
-        return "source to site port, implement me!";
-    case SitePip::SITE_PORT_TO_SINK:
-        return "site port to sink, implement me!";
-    case SitePip::SITE_PORT_TO_SITE_PORT:
-        return "site port to site port, implement me!";
+    case SitePip::SOURCE_TO_SITE_PORT: {
+        std::string &str = ctx->log_strs.next();
+        str = stringf("Out of site source for net %s => %s", pip.wire.net->name.c_str(ctx),
+                      ctx->nameOfWire(ctx->getPipSrcWire(pip.pip)));
+        return str.c_str();
+    }
+    case SitePip::SITE_PORT_TO_SINK: {
+        std::string &str = ctx->log_strs.next();
+        str = stringf("%s => Out of site sink for net %s", ctx->nameOfWire(ctx->getPipDstWire(pip.pip)),
+                      pip.wire.net->name.c_str(ctx));
+        return str.c_str();
+    }
+    case SitePip::SITE_PORT_TO_SITE_PORT: {
+        std::string &str = ctx->log_strs.next();
+        str = stringf("%s => %s", ctx->nameOfWire(ctx->getPipSrcWire(pip.pip)),
+                      ctx->nameOfWire(ctx->getPipDstWire(pip.other_pip)));
+        return str.c_str();
+    }
     default:
         // Unreachable!
         NPNR_ASSERT(false);
diff --git a/fpga_interchange/site_router.cc b/fpga_interchange/site_router.cc
index 32c09dbe..962acc4b 100644
--- a/fpga_interchange/site_router.cc
+++ b/fpga_interchange/site_router.cc
@@ -328,7 +328,7 @@ void print_current_state(const SiteArch *site_arch)
 
     log_info(" Cells in site:\n");
     for (CellInfo *cell : cells_in_site) {
-        log_info("  - %s (%s)\n", cell->name.c_str(ctx), cell->type.c_str(ctx));
+        log_info("  - %s (%s) => %s\n", cell->name.c_str(ctx), cell->type.c_str(ctx), ctx->nameOfBel(cell->bel));
     }
 
     log_info(" Nets in site:\n");
@@ -490,7 +490,7 @@ struct SolutionPreference
 
 static bool find_solution_via_backtrack(SiteArch *ctx, std::vector<PossibleSolutions> *solutions,
                                         std::vector<std::vector<size_t>> sinks_to_solutions,
-                                        const std::vector<SiteWire> &sinks)
+                                        const std::vector<SiteWire> &sinks, bool explain)
 {
     std::vector<uint8_t> routed_sinks;
     std::vector<size_t> solution_indicies;
@@ -499,10 +499,20 @@ static bool find_solution_via_backtrack(SiteArch *ctx, std::vector<PossibleSolut
     solution_indicies.resize(sinks_to_solutions.size(), 0);
 
     // Scan solutions, and remove any solutions that are invalid immediately
-    for (auto &solution : *solutions) {
+    for (size_t solution_idx = 0; solution_idx < solutions->size(); ++solution_idx) {
+        PossibleSolutions &solution = (*solutions)[solution_idx];
+        if (verbose_site_router(ctx) || explain) {
+            log_info("Testing solution %zu\n", solution_idx);
+        }
         if (test_solution(ctx, solution.net, solution.pips_begin, solution.pips_end)) {
+            if (verbose_site_router(ctx) || explain) {
+                log_info("Solution %zu is good\n", solution_idx);
+            }
             remove_solution(ctx, solution.pips_begin, solution.pips_end);
         } else {
+            if (verbose_site_router(ctx) || explain) {
+                log_info("Solution %zu is not useable\n", solution_idx);
+            }
             solution.tested = true;
         }
     }
@@ -513,11 +523,15 @@ static bool find_solution_via_backtrack(SiteArch *ctx, std::vector<PossibleSolut
         std::vector<size_t> &solutions_for_sink = sinks_to_solutions.at(sink_idx);
         std::stable_sort(solutions_for_sink.begin(), solutions_for_sink.end(), SolutionPreference(ctx, *solutions));
 
-        if (verbose_site_router(ctx)) {
-            log_info("Solutions for sink %s\n", ctx->nameOfWire(sinks.at(sink_idx)));
+        if (verbose_site_router(ctx) || explain) {
+            log_info("Solutions for sink %s (%zu)\n", ctx->nameOfWire(sinks.at(sink_idx)), sink_idx);
             for (size_t solution_idx : solutions_for_sink) {
                 const PossibleSolutions &solution = solutions->at(solution_idx);
-                log_info("%zu: inverted = %d, can_invert = %d\n", solution_idx, solution.inverted, solution.can_invert);
+                log_info("%zu: inverted = %d, can_invert = %d, tested = %d\n", solution_idx, solution.inverted,
+                         solution.can_invert, solution.tested);
+                for (auto iter = solution.pips_begin; iter != solution.pips_end; ++iter) {
+                    log_info(" - %s\n", ctx->nameOfPip(*iter));
+                }
             }
         }
     }
@@ -531,6 +545,9 @@ static bool find_solution_via_backtrack(SiteArch *ctx, std::vector<PossibleSolut
         }
 
         if (solution_count == 0) {
+            if (verbose_site_router(ctx) || explain) {
+                log_info("Sink %s has no solution in site\n", ctx->nameOfWire(sinks.at(sink_idx)));
+            }
             return false;
         }
 
@@ -566,11 +583,14 @@ static bool find_solution_via_backtrack(SiteArch *ctx, std::vector<PossibleSolut
         size_t sink_idx = solution_order[solution_stack.size()].first;
 
         size_t next_solution_to_test = solution_indicies[sink_idx];
+        if (verbose_site_router(ctx) || explain) {
+            log_info("next %zu : %zu (of %zu)\n", sink_idx, next_solution_to_test, sinks_to_solutions[sink_idx].size());
+        }
         if (next_solution_to_test >= sinks_to_solutions[sink_idx].size()) {
             // We have exausted all solutions at this level of the stack!
             if (solution_stack.empty()) {
                 // Search is done, failed!!!
-                if (verbose_site_router(ctx)) {
+                if (verbose_site_router(ctx) || explain) {
                     log_info("No solution found via backtrace with %zu solutions and %zu sinks\n", solutions->size(),
                              sinks_to_solutions.size());
                 }
@@ -578,7 +598,11 @@ static bool find_solution_via_backtrack(SiteArch *ctx, std::vector<PossibleSolut
             } else {
                 // This level of the stack is completely tapped out, pop back
                 // to the next level up.
+                size_t sink_idx = solution_order[solution_stack.size() - 1].first;
                 size_t solution_idx = solution_stack.back();
+                if (verbose_site_router(ctx) || explain) {
+                    log_info("pop  %zu : %zu\n", sink_idx, solution_idx);
+                }
                 solution_stack.pop_back();
 
                 // Remove the now tested bad solution at the previous level of
@@ -588,7 +612,6 @@ static bool find_solution_via_backtrack(SiteArch *ctx, std::vector<PossibleSolut
 
                 // Because we had to pop up the stack, advance the index at
                 // the level below us and start again.
-                sink_idx = solution_order[solution_stack.size()].first;
                 solution_indicies[sink_idx] += 1;
                 continue;
             }
@@ -598,16 +621,26 @@ static bool find_solution_via_backtrack(SiteArch *ctx, std::vector<PossibleSolut
         auto &solution = solutions->at(solution_idx);
         if (solution.tested) {
             // This solution was already determined to be no good, skip it.
+            if (verbose_site_router(ctx) || explain) {
+                log_info("skip %zu : %zu\n", sink_idx, solution_idx);
+            }
             solution_indicies[sink_idx] += 1;
             continue;
         }
 
+        if (verbose_site_router(ctx) || explain) {
+            log_info("test %zu : %zu\n", sink_idx, solution_idx);
+        }
+
         if (!test_solution(ctx, solution.net, solution.pips_begin, solution.pips_end)) {
             // This solution was no good, try the next one at this level of
             // the stack.
             solution_indicies[sink_idx] += 1;
         } else {
             // This solution was good, push onto the stack.
+            if (verbose_site_router(ctx) || explain) {
+                log_info("push %zu : %zu\n", sink_idx, solution_idx);
+            }
             solution_stack.push_back(solution_idx);
             if (solution_stack.size() == sinks_to_solutions.size()) {
                 // Found a valid solution, done!
@@ -629,7 +662,7 @@ static bool find_solution_via_backtrack(SiteArch *ctx, std::vector<PossibleSolut
     NPNR_ASSERT(false);
 }
 
-bool route_site(SiteArch *ctx, SiteRoutingCache *site_routing_cache, RouteNodeStorage *node_storage)
+bool route_site(SiteArch *ctx, SiteRoutingCache *site_routing_cache, RouteNodeStorage *node_storage, bool explain)
 {
     std::vector<SiteExpansionLoop *> expansions;
     expansions.reserve(ctx->nets.size());
@@ -644,7 +677,7 @@ bool route_site(SiteArch *ctx, SiteRoutingCache *site_routing_cache, RouteNodeSt
 
         SiteExpansionLoop *router = expansions.back();
         if (!router->expand_net(ctx, site_routing_cache, net)) {
-            if (verbose_site_router(ctx)) {
+            if (verbose_site_router(ctx) || explain) {
                 log_info("Net %s expansion failed to reach all users, site is unroutable!\n", ctx->nameOfNet(net));
             }
 
@@ -706,7 +739,7 @@ bool route_site(SiteArch *ctx, SiteRoutingCache *site_routing_cache, RouteNodeSt
         }
     }
 
-    return find_solution_via_backtrack(ctx, &solutions, sinks_to_solutions, sinks);
+    return find_solution_via_backtrack(ctx, &solutions, sinks_to_solutions, sinks, explain);
 }
 
 void check_routing(const SiteArch &site_arch)
@@ -1010,7 +1043,7 @@ bool SiteRouter::checkSiteRouting(const Context *ctx, const TileStatus &tile_sta
     SiteArch site_arch(&site_info);
     // site_arch.archcheck();
 
-    site_ok = route_site(&site_arch, &ctx->site_routing_cache, &ctx->node_storage);
+    site_ok = route_site(&site_arch, &ctx->site_routing_cache, &ctx->node_storage, /*explain=*/false);
     if (verbose_site_router(ctx)) {
         if (site_ok) {
             log_info("Site %s is routable\n", ctx->get_site_name(tile, site));
@@ -1062,7 +1095,7 @@ void SiteRouter::bindSiteRouting(Context *ctx)
 
     SiteInformation site_info(ctx, tile, site, cells_in_site);
     SiteArch site_arch(&site_info);
-    NPNR_ASSERT(route_site(&site_arch, &ctx->site_routing_cache, &ctx->node_storage));
+    NPNR_ASSERT(route_site(&site_arch, &ctx->site_routing_cache, &ctx->node_storage, /*explain=*/false));
     check_routing(site_arch);
     apply_routing(ctx, site_arch);
     if (verbose_site_router(ctx)) {
@@ -1070,6 +1103,27 @@ void SiteRouter::bindSiteRouting(Context *ctx)
     }
 }
 
+void SiteRouter::explain(const Context *ctx) const
+{
+    NPNR_ASSERT(!dirty);
+    if (site_ok) {
+        return;
+    }
+
+    // Make sure all cells in this site belong!
+    auto iter = cells_in_site.begin();
+    NPNR_ASSERT((*iter)->bel != BelId());
+
+    auto tile = (*iter)->bel.tile;
+
+    SiteInformation site_info(ctx, tile, site, cells_in_site);
+    SiteArch site_arch(&site_info);
+    bool route_status = route_site(&site_arch, &ctx->site_routing_cache, &ctx->node_storage, /*explain=*/true);
+    if (!route_status) {
+        print_current_state(&site_arch);
+    }
+}
+
 ArchNetInfo::~ArchNetInfo() { delete loop; }
 
 Arch::~Arch()
diff --git a/fpga_interchange/site_router.h b/fpga_interchange/site_router.h
index ebdfbe3b..cf17026d 100644
--- a/fpga_interchange/site_router.h
+++ b/fpga_interchange/site_router.h
@@ -47,6 +47,7 @@ struct SiteRouter
     void unbindBel(CellInfo *cell);
     bool checkSiteRouting(const Context *ctx, const TileStatus &tile_status) const;
     void bindSiteRouting(Context *ctx);
+    void explain(const Context *ctx) const;
 };
 
 NEXTPNR_NAMESPACE_END