Skip to content

Commit 6273dde

Browse files
seldridgeseldridge
authored
[OM] Add debug logging to the Evaluator (#10266)
Add debug logging to the OM Evaluator. I keep running into issues with this and it is very difficult to reason about what it is doing. Assisted-by: Claude Code:claude-sonnet-4-6 Signed-off-by: Schuyler Eldridge <schuyler.eldridge@sifive.com>
1 parent bbc77a7 commit 6273dde

2 files changed

Lines changed: 115 additions & 12 deletions

File tree

‎include/circt/Dialect/OM/Evaluator/Evaluator.h‎

Lines changed: 47 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -23,6 +23,7 @@
2323
#include "mlir/Support/LogicalResult.h"
2424
#include "llvm/ADT/SmallPtrSet.h"
2525
#include "llvm/ADT/SmallString.h"
26+
#include "llvm/Support/Debug.h"
2627

2728
#include <queue>
2829
#include <utility>
@@ -483,6 +484,26 @@ class Evaluator {
483484
/// Evaluator value storage. Return an evaluator value for the given
484485
/// instantiation context (a pair of Value and parameters).
485486
DenseMap<ObjectKey, std::shared_ptr<evaluator::EvaluatorValue>> objects;
487+
488+
#ifndef NDEBUG
489+
/// Current nesting depth for debug output indentation.
490+
unsigned debugNesting = 0;
491+
492+
/// RAII helper to increment/decrement debugNesting.
493+
struct DebugNesting {
494+
unsigned &depth;
495+
DebugNesting(unsigned &depth) : depth(depth) { ++depth; }
496+
~DebugNesting() { --depth; }
497+
};
498+
499+
raw_ostream &dbgs(unsigned extra = 0) {
500+
return llvm::dbgs().indent(debugNesting * 2 + extra * 2);
501+
}
502+
503+
llvm::indent indent(unsigned extra = 0) {
504+
return llvm::indent(debugNesting, 2) + extra;
505+
}
506+
#endif
486507
};
487508

488509
/// Helper to enable printing objects in Diagnostics.
@@ -496,6 +517,9 @@ operator<<(mlir::Diagnostic &diag,
496517
diag << "Object(" << object->getType() << ")";
497518
else if (auto *list = llvm::dyn_cast<evaluator::ListValue>(&evaluatorValue))
498519
diag << "List(" << list->getType() << ")";
520+
else if (auto *ref =
521+
llvm::dyn_cast<evaluator::ReferenceValue>(&evaluatorValue))
522+
diag << "Reference(" << ref->getValueType() << ")";
499523
else if (llvm::isa<evaluator::BasePathValue>(&evaluatorValue))
500524
diag << "BasePath()";
501525
else if (llvm::isa<evaluator::PathValue>(&evaluatorValue))
@@ -515,6 +539,29 @@ operator<<(mlir::Diagnostic &diag, const EvaluatorValuePtr &evaluatorValue) {
515539
return diag << *evaluatorValue.get();
516540
}
517541

542+
#ifndef NDEBUG
543+
/// Helper to enable printing objects to raw_ostream (e.g., llvm::dbgs()).
544+
/// Delegates to the Diagnostic overload via an intermediate string.
545+
static inline llvm::raw_ostream &
546+
operator<<(llvm::raw_ostream &os,
547+
const evaluator::EvaluatorValue &evaluatorValue) {
548+
std::string buf;
549+
llvm::raw_string_ostream ss(buf);
550+
mlir::Diagnostic diag(UnknownLoc::get(evaluatorValue.getContext()),
551+
mlir::DiagnosticSeverity::Note);
552+
diag << evaluatorValue;
553+
ss << diag;
554+
return os << ss.str();
555+
}
556+
557+
static inline llvm::raw_ostream &
558+
operator<<(llvm::raw_ostream &os, const EvaluatorValuePtr &evaluatorValue) {
559+
if (evaluatorValue)
560+
return os << *evaluatorValue.get();
561+
return os << "<null>";
562+
}
563+
#endif // NDEBUG
564+
518565
} // namespace om
519566
} // namespace circt
520567

‎lib/Dialect/OM/Evaluator/Evaluator.cpp‎

Lines changed: 68 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -100,6 +100,8 @@ circt::om::Evaluator::getPartiallyEvaluatedValue(Type type, Location loc) {
100100

101101
FailureOr<evaluator::EvaluatorValuePtr> circt::om::Evaluator::getOrCreateValue(
102102
Value value, ActualParameters actualParams, Location loc) {
103+
LLVM_DEBUG(dbgs() << "- get: " << value << "\n");
104+
103105
auto it = objects.find({value, actualParams});
104106
if (it != objects.end()) {
105107
auto evalVal = it->second;
@@ -193,6 +195,15 @@ circt::om::Evaluator::evaluateObjectInstance(StringAttr className,
193195
ActualParameters actualParams,
194196
Location loc,
195197
ObjectKey instanceKey) {
198+
#ifndef NDEBUG
199+
DebugNesting nestOne(debugNesting);
200+
#endif
201+
LLVM_DEBUG(dbgs() << "object:\n");
202+
#ifndef NDEBUG
203+
DebugNesting nestTwo(debugNesting);
204+
#endif
205+
LLVM_DEBUG(dbgs() << "name: " << className << "\n");
206+
196207
auto classDef = symbolTable.lookup<ClassLike>(className);
197208
if (!classDef)
198209
return symbolTable.getOp()->emitError("unknown class name ") << className;
@@ -202,6 +213,7 @@ circt::om::Evaluator::evaluateObjectInstance(StringAttr className,
202213
evaluator::EvaluatorValuePtr result =
203214
std::make_shared<evaluator::ObjectValue>(classDef, loc);
204215
result->markUnknown();
216+
LLVM_DEBUG(dbgs(1) << "extern: <unknown-value>\n");
205217
return result;
206218
}
207219

@@ -258,37 +270,52 @@ circt::om::Evaluator::evaluateObjectInstance(StringAttr className,
258270
evaluator::ObjectFields fields;
259271

260272
auto *context = cls.getContext();
261-
for (auto &op : cls.getOps())
262-
for (auto result : op.getResults()) {
263-
// Allocate the value, with unknown loc. It will be later set when
264-
// evaluating the fields.
265-
if (failed(
266-
getOrCreateValue(result, actualParams, UnknownLoc::get(context))))
267-
return failure();
268-
// Add to the worklist.
269-
worklist.push({result, actualParams});
270-
}
273+
{
274+
LLVM_DEBUG(dbgs() << "ops:\n");
275+
#ifndef NDEBUG
276+
DebugNesting nestOne(debugNesting);
277+
#endif
278+
for (auto &op : cls.getOps())
279+
for (auto result : op.getResults()) {
280+
// Allocate the value, with unknown loc. It will be later set when
281+
// evaluating the fields.
282+
if (failed(getOrCreateValue(result, actualParams,
283+
UnknownLoc::get(context))))
284+
return failure();
285+
// Add to the worklist.
286+
worklist.push({result, actualParams});
287+
}
288+
}
271289

290+
LLVM_DEBUG(dbgs() << "fields:\n");
272291
auto fieldNames = cls.getFieldNames();
273292
auto operands = cls.getFieldsOp()->getOperands();
274293
for (size_t i = 0; i < fieldNames.size(); ++i) {
275294
auto name = fieldNames[i];
276295
auto value = operands[i];
277296
auto fieldLoc = cls.getFieldLocByIndex(i);
297+
LLVM_DEBUG(dbgs() << "- name: " << name << "\n"
298+
<< indent(1) << "evaluate:\n");
299+
#ifndef NDEBUG
300+
DebugNesting nestOne(debugNesting);
301+
#endif
278302
FailureOr<evaluator::EvaluatorValuePtr> result =
279303
evaluateValue(value, actualParams, fieldLoc);
280304
if (failed(result))
281305
return result;
282306

307+
LLVM_DEBUG(dbgs() << "value: " << result.value() << "\n");
283308
fields[cast<StringAttr>(name)] = result.value();
284309
}
285310

286311
// Evaluate property assertions.
312+
LLVM_DEBUG(dbgs() << "asserts:\n");
287313
for (auto assertOp : cls.getOps<PropertyAssertOp>())
288314
if (failed(evaluatePropertyAssert(assertOp, actualParams)))
289315
return failure();
290316

291317
// If the there is an instance, we must update the object value.
318+
LLVM_DEBUG(dbgs() << "object value:\n");
292319
if (instanceKey.first) {
293320
auto result =
294321
getOrCreateValue(instanceKey.first, instanceKey.second, loc).value();
@@ -307,6 +334,16 @@ circt::om::Evaluator::evaluateObjectInstance(StringAttr className,
307334
FailureOr<std::shared_ptr<evaluator::EvaluatorValue>>
308335
circt::om::Evaluator::instantiate(
309336
StringAttr className, ArrayRef<evaluator::EvaluatorValuePtr> actualParams) {
337+
LLVM_DEBUG(dbgs() << "instantiate:\n");
338+
#ifndef NDEBUG
339+
DebugNesting nest(debugNesting);
340+
#endif
341+
LLVM_DEBUG({
342+
dbgs() << "class: " << className << "\n" << indent() << "params:\n";
343+
for (auto &param : actualParams)
344+
dbgs() << "- " << param << "\n";
345+
});
346+
310347
auto classDef = symbolTable.lookup<ClassLike>(className);
311348
if (!classDef)
312349
return symbolTable.getOp()->emitError("unknown class name ") << className;
@@ -317,6 +354,7 @@ circt::om::Evaluator::instantiate(
317354
std::make_shared<evaluator::ObjectValue>(
318355
classDef, UnknownLoc::get(classDef.getContext()));
319356
result->markUnknown();
357+
LLVM_DEBUG(dbgs(1) << "result: <unknown extern>\n");
320358
return result;
321359
}
322360

@@ -330,6 +368,7 @@ circt::om::Evaluator::instantiate(
330368
actualParametersBuffers.push_back(std::move(parameters));
331369

332370
auto loc = cls.getLoc();
371+
LLVM_DEBUG(dbgs() << "evaluate object:\n");
333372
auto result = evaluateObjectInstance(
334373
className, actualParametersBuffers.back().get(), loc);
335374

@@ -338,6 +377,7 @@ circt::om::Evaluator::instantiate(
338377

339378
// `evaluateObjectInstance` has populated the worklist. Continue evaluations
340379
// unless there is a partially evaluated value.
380+
LLVM_DEBUG(dbgs() << "worklist:\n");
341381
while (!worklist.empty()) {
342382
auto [value, args] = worklist.front();
343383
worklist.pop();
@@ -355,9 +395,11 @@ circt::om::Evaluator::instantiate(
355395
auto &object = result.value();
356396
// Finalize the value. This will eliminate intermidiate ReferenceValue used as
357397
// a placeholder in the initialization.
398+
LLVM_DEBUG(dbgs() << "finalizing\n");
358399
if (failed(object->finalize()))
359400
return cls.emitError() << "failed to finalize evaluation. Probably the "
360401
"class contains a dataflow cycle";
402+
LLVM_DEBUG(dbgs() << "result: " << object << "\n");
361403
return object;
362404
}
363405

@@ -366,9 +408,13 @@ circt::om::Evaluator::evaluateValue(Value value, ActualParameters actualParams,
366408
Location loc) {
367409
auto evaluatorValue = getOrCreateValue(value, actualParams, loc).value();
368410

411+
LLVM_DEBUG(dbgs() << "- eval: " << value << "\n");
412+
369413
// Return if the value is already evaluated.
370-
if (evaluatorValue->isFullyEvaluated())
414+
if (evaluatorValue->isFullyEvaluated()) {
415+
LLVM_DEBUG(dbgs(1) << "fully evaluated: " << evaluatorValue << "\n");
371416
return evaluatorValue;
417+
}
372418

373419
return llvm::TypeSwitch<Value, FailureOr<evaluator::EvaluatorValuePtr>>(value)
374420
.Case([&](BlockArgument arg) {
@@ -530,19 +576,29 @@ circt::om::Evaluator::evaluateIntegerBinaryArithmetic(
530576
LogicalResult
531577
circt::om::Evaluator::evaluatePropertyAssert(PropertyAssertOp op,
532578
ActualParameters actualParams) {
579+
#ifndef NDEBUG
580+
DebugNesting nest(debugNesting);
581+
#endif
582+
533583
auto loc = op.getLoc();
534584

535585
// Evaluate the condition, returning early if it isn't ready yet.
586+
LLVM_DEBUG(dbgs() << "op: " << op << "\n"
587+
<< indent() << "evaluate condition: \n");
536588
auto condResult = evaluateValue(op.getCondition(), actualParams, loc);
537589
if (failed(condResult))
538590
return failure();
539-
if (!condResult.value()->isFullyEvaluated())
591+
if (!condResult.value()->isFullyEvaluated()) {
592+
LLVM_DEBUG(dbgs() << "evaluate condition: <not fully evaluated>\n");
540593
return success();
594+
}
541595

542596
// If the condition is unknown, skip silently (best-effort).
543597
if (condResult.value()->isUnknown())
544598
return success();
545599

600+
LLVM_DEBUG(dbgs() << "condition: " << condResult.value() << "\n");
601+
546602
// Extract the attribute from the condition value, handling the case where
547603
// the condition resolves through a ReferenceValue (e.g. an ObjectFieldOp or
548604
// a parameter that participates in cycle resolution).

0 commit comments

Comments
 (0)