Part 6 · Testbench Architecture · Intermediate

Logging & Verbosity Strategy

Leveled logger class, component-scoped prefixes, timestamp discipline, log-size control, and grep-able conventions.

Logs are written for scripts first, humans second

In a 500-run regression nobody reads logs top to bottom — triage scripts grep them . That inverts the design priorities: fixed field order, one record per line, a severity tag that scripts can key on, and a verbosity system so the same TB can whisper in regression and shout during replay. Raw $display calls scattered through components give you none of this.

systemverilog
typedef enum int { LOG_ERROR = 0, LOG_WARN = 1,
                   LOG_INFO  = 2, LOG_DEBUG = 3 } log_level_e;

class logger;
  static log_level_e threshold = LOG_INFO;  // set from +VERBOSITY

  string scope;  // component prefix, e.g. "ENV.AGT0.DRV"

  function new(string scope);
    this.scope = scope;
  endfunction

  function void log(log_level_e lvl, string msg);
    static string tag[4] = '{"ERROR", "WARN ", "INFO ", "DEBUG"};
    if (lvl > threshold) return;
    $display("[%0t] %s [%s] %s", $time, tag[lvl], scope, msg);
    if (lvl == LOG_ERROR)
      tb_status::report_error(scope, msg);  // ties into PASS/FAIL
  endfunction

  // convenience wrappers
  function void error(string m); log(LOG_ERROR, m); endfunction
  function void info (string m); log(LOG_INFO,  m); endfunction
  function void debug(string m); log(LOG_DEBUG, m); endfunction
endclass

Note the coupling: LOG_ERROR routes into the central error counter, so logging an error and failing the test are the same act — a checker cannot complain in the log yet let the test pass.


Scoped prefixes and the timestamp+id discipline

Every component constructs its logger with a hierarchical scope (ENV.AGT0.MON), and every transaction-related message carries the transaction id . With those two conventions, the life of any transaction can be reconstructed from a flat log with a single grep.

diagram
LOG LINE ANATOMY (fixed field order)

  [12450] INFO  [ENV.AGT0.DRV] txn#0042 sent  : WR addr=0x1040 data=0xDEAD
  [12480] INFO  [ENV.AGT0.MON] txn#0042 seen  : WR addr=0x1040 data=0xDEAD
  [12490] ERROR [ENV.SCB]      txn#0042 mismatch: exp=0xDEAD act=0xBEEF
    │       │        │             │
    time  severity  scope     transaction id

  triage greps:
    grep "ERROR"           run.log    all failures
    grep "txn#0042"        run.log    full life of the failing txn
    grep "\[ENV.SCB\]"     run.log    all scoreboard activity
    grep -m1 "ERROR"       run.log    first-error signature for bucketing

Conventions that keep logs grep-able

  • Fixed field order — time, severity, scope, message — never reordered per component.

  • One record per line; multi-line dumps only behind DEBUG level.

  • Zero-padded transaction ids (txn#0042) so sort and grep behave predictably.

  • First ERROR line must carry the diagnosis — triage buckets cluster on that one line.


Log size control

A DEBUG-level log of a million-transaction soak run can reach gigabytes and slow the simulation itself — formatting strings costs real CPU. Regression runs at INFO with per-transaction chatter at DEBUG, which costs almost nothing when filtered because the level check happens before formatting:

systemverilog
// GOOD: sformatf only runs when DEBUG is enabled
if (logger::threshold >= LOG_DEBUG)
  log.debug($sformatf("raw beat: %p", beat));

// BAD: builds the giant string every call, then throws it away
log.debug($sformatf("raw beat: %p", beat));

// Periodic heartbeat instead of per-txn INFO noise:
if (txn_id % 1000 == 0)
  log.info($sformatf("progress: %0d/%0d txns", txn_id, cfg.num_txns));

Interview angle

  • "How is your TB logging organized?" — leveled logger class, scoped prefixes, error level wired to the PASS/FAIL counter.

  • "How do triage scripts bucket failures?" — grep the first ERROR line; its fixed format is the failure signature.

  • "Why not raw $display everywhere?" — no levels, no scopes, no machine-parsable structure, no size control.

Key takeaways

  • Design log lines for grep: fixed fields — time, severity, scope, txn id, message.

  • Route ERROR-level messages into the central error counter — log and verdict cannot diverge.

  • Verbosity threshold from a plusarg: INFO for regression, DEBUG for replay.

  • Guard expensive $sformatf calls behind the level check — formatting costs sim time.

Common pitfalls

  • Free-form messages with shuffled field order — triage scripts cannot bucket failures.

  • Per-beat INFO messages — multi-GB logs that slow simulation and fill disks.

  • Errors printed via plain $display that never reach the error counter — log says fail, banner says pass.

  • Missing transaction ids — no way to correlate driver, monitor, and scoreboard lines.