Debugging by symptom
Go from how a run ended to its cause: read the ledger, pick the library tool for that symptom, and read its output to find a config mismatch, a factory bypass, a broken connection or a missing objection.
- Lesson
- U15.2
- Time
- 35 min
- Runs on
- Verilator with UVM
- Check
- 5 questions
A colleague's poison-injection test ran to completion with three ledger errors and nothing else in the log. The sequence sent four beats instead of eight, no poisoned beat reached the design, and the scoreboard checked nothing. Three different mistakes caused those three lines, and each one is found fastest by starting from its symptom.
items: requested 8, driver sent 4
poisoned beats: driver is inc_driver, injected 0
scoreboard: 0 checks, 0 errors seen, 0 mismatchesStart from how the run ended
- Ended at 0 ns
Nothing held the run phase open, so it ended before the first clock edge. The objection trace shows no
run_objectionraised by the test.More context
The quiz program without a raise prints "run ended at 0 ns: driver sent 0, scoreboard checked 0": report_phase runs at 0 ns, before the first clock edge at 10 ns.
Follow the calls, values and waits
- data run ended at 0 ns: Read the last lines → Ended at 0 ns
- data run ended at 0 ns: Ended at 0 ns → +UVM_OBJECTION_TRACE
- Stopped by the timeout
Something raised an objection and is still waiting. With phase tracing on, the timeout prints the outstanding objections by component; then ask what that component is waiting for.
More context
Without
item_done, the example stops with "Explicit timeout of 500 hit", and the outstanding-objection table names only the test: it is waiting inseq.start.Follow the calls, values and waits
- data PH_TIMEOUT fatal: Read the last lines → Stopped by the timeout
- data PH_TIMEOUT fatal: Stopped by the timeout → +UVM_TIMEOUT, +UVM_PHASE_TRACE
- Ended on time, numbers wrong
The run completed, so look at the ledger. Each short count names the boundary to inspect: items requested vs sent, errors asked for vs injected, beats sent vs checked.
More context
In the example, "items: requested 8, driver sent 4" leads to the config trace: a SET of
n_items, then a GET of it that fails.Follow the calls, values and waits
- data requested 8, driver sent 4: Read the last lines → Ended on time, ledger short
- data requested 8, driver sent 4: Ended on time, ledger short → Config, factory, port tools
Read the diagram as text
- Read the last lines: End time, summary counts, ledger
- Ended at 0 ns: No run_phase objection was raised
- Stopped by the timeout: An objection was never dropped
- Ended on time, ledger short: Work was lost between two parts
- +UVM_OBJECTION_TRACE: No run_objection raised line
- +UVM_TIMEOUT, +UVM_PHASE_TRACE: Lists who still holds an objection
- Config, factory, port tools: Chosen by which ledger line is short
- Read the last lines → Ended at 0 ns: time 0
- Read the last lines → Stopped by the timeout: PH_TIMEOUT fatal
- Read the last lines → Ended on time, ledger short: normal end
- Ended at 0 ns → +UVM_OBJECTION_TRACE: confirm
- Stopped by the timeout → +UVM_TIMEOUT, +UVM_PHASE_TRACE: find the holder
- Ended on time, ledger short → Config, factory, port tools: follow the line
The way a run ends narrows the cause before any trace is switched on.
Before turning on any trace, read the end of the log: the time of the last message, the severity counts and the bench's own ledger. A ledger is a short set of counts the test prints at the end, comparing work requested, driven, observed and checked (U7.3, U8.4). It turns a silent failure into a short count.
The example runs with +UVM_CONFIG_DB_TRACE, +UVM_OBJECTION_TRACE and a switch of its own, +n_items=8, on its command line, and its end_of_elaboration_phase calls the topology, factory and connection tools. The next three sections follow its three short ledger lines to their causes; a full symptom table follows them.
Bug 1: the sequence sent four of eight
- Build: the test stores n_items0 ns (illustrative)
The test stores
n_itemsasint unsigned, at the sequence's scope.More context
The value 8 comes from
+n_items=8. TheCFGDB/SETline at @ 0 records scopeuvm_test_top.env.agent.sqr.seqand namen_items.Follow the calls, values and waits
- data n_items = 8 (int unsigned): err_test → config_db
- Run: sent 4 of 80 ns (illustrative)
The sequence asks for an
intat the same scope and name. The lookup fails and the default of 4 stands.More context
The
CFGDB/GETline, when the sequence starts at 0 ns, ends "(failed lookup)": the type is part of the key. The ledger reads "items: requested 8, driver sent 4".Follow the calls, values and waits
- call get #(int) n_items: inc_seq → config_db
- return failed lookup: keep 4: config_db → inc_seq
- Injected 0
The override is registered, but the agent builds its driver with
new, so the factory is never asked and aninc_driveris built.More context
The factory dump still says "The factory will produce an object of type 'inc_err_driver'": the override is in place but unused. The ledger reads "driver is inc_driver, injected 0".
Follow the calls, values and waits
- data inc_driver → inc_err_driver: err_test → Factory
- Checked 00 ns (illustrative)
The scoreboard is connected to the agent's port, but nothing connects the monitor's port to it. The monitor writes into a port with no listeners.
More context
Nothing moves here, and that is the bug. At @ 0 the connection report for
agent.mon.apreads "Connected implementations: none"; the ledger reads "scoreboard: 0 checks".
Read the diagram as text
- err_test: n_items = 8, override to inc_err_driver
- config_db: Entries keyed by scope, name and type
- inc_seq: get #(int) n_items, default 4
- Factory: inc_driver → inc_err_driver
- agent.drv: Built by the agent
- agent.mon.ap: Writes every result
- agent.ap: The agent's outward port
- sb.obs_imp: Counts checks
- err_test → config_db: set #(int unsigned)
- config_db → inc_seq: get #(int): no match
- err_test → Factory: set_type_override
- Factory → agent.drv: never asked: new()
- agent.mon.ap → agent.ap: connect missing
- agent.ap → sb.obs_imp: connected
Each bug breaks one hand-off, and each leaves its own count short.
A short item count points at configuration: the sequence reads n_items with a default of 4. The config trace prints every set and get. Two of its lines settle the question.
[CFGDB/SET] Configuration scope='uvm_test_top.env.agent.sqr.seq' name='n_items' (type PARAMTYPEDTYPE 'T') set accessor=uvm_test_top = (int) 6
[CFGDB/GET] Configuration scope='uvm_test_top.env.agent.sqr.seq' name='n_items' (type PARAMTYPEDTYPE 'T') read accessor= = null (failed lookup)Check three things for a failed get: was a matching set made before it, does the set's scope match the get's path, and do the types agree? Matching is not string equality: a wildcard scope such as env.agent.sqr.* prints differently and still matches. Here the set came first and its exact scope and name match, so the types explain the failure. The test stored an int unsigned, and a lookup only matches an entry of exactly the requested type. Setting with uvm_config_db #(int) fixes it.
Two in-code views help when the trace is too long: print_config(1) on a component lists the entries visible to it and its children, and uvm_config_db #(int)::dump() prints the whole resource pool.
Bug 2: the override that never happened
The ledger names the driver's type: inc_driver, not the inc_err_driver the test asked for. Three tools, read in order, locate the fault.
# print_topology
drv inc_driver - @417
# debug_create_by_type
The factory will produce an object of type 'inc_err_driver'
# factory.print(0)
inc_driver inc_err_driverThe override is registered, and the factory would honour it for that exact path now. Yet the built component has the original type. So the factory was never asked for this driver, or was asked before the override existed. The agent's build has drv = new("drv", this).
Bypasses the factory
drv = new("drv", this);
Always an inc_driver. No override, type or instance, can reach it, and nothing warns.
Asks the factory
drv = inc_driver::type_id::create("drv", this);
Returns inc_err_driver while the override is registered before this line runs.
Bug 3: an analysis chain with a gap
Zero checks with four beats sent means observations never reached the scoreboard. debug_connected_to on each port of the path shows where the chain stops.
uvm_test_top.env.agent.mon.ap [debug_connected_to] Connected implementations: none
uvm_test_top.env.agent.ap [debug_connected_to] This port's fanout network:
uvm_test_top.env.agent.ap (uvm_analysis_port)
|_uvm_test_top.env.sb.obs_imp (uvm_analysis_imp)The env connected agent.ap to the scoreboard, but the agent never connected mon.ap to ap. The missing line is mon.ap.connect(ap) in the agent's connect_phase.
No connection error appeared because an analysis port may legally have no listeners. A port that requires a provider, such as a uvm_blocking_put_port (minimum 1), reports connection count of 0 does not meet required minimum of 1 when bindings are resolved at the start of end_of_elaboration. The driver's seq_item_port has a minimum of 0, so an unconnected driver is silent too: it waits in get_next_item. For analysis paths, debug_connected_to finds the gap once you look, and the ledger's comparison of beats sent with beats checked makes the run fail without anyone looking.
Hangs and early ends
Remove item_done from the driver and the run hangs instead. The driver asks for the next item while the sequence is still waiting in finish_item for the first one to complete. The sequencer reports Get_next_item called twice without item_done or get in between and hands back the same item, every 20 ns. The example sets a 500 ns timeout in tb for this experiment, so the run stops with a PH_TIMEOUT fatal, and its objection trace shows the test's raise with no drop.
UVM_ERROR @ 20: uvm_test_top.env.agent.sqr [...] Get_next_item called twice without item_done or get in between
... the same error every 20 ns ...
[PH/TRC/TIMEOUT/OBJCTN] Phase 'common.run' (id=179) Phase 'common.run' has outstanding objections:
The total objection count is 1
Source Total
Count Count Object
0 1 uvm_top
1 1 uvm_test_top
UVM_FATAL ... [PH_TIMEOUT] Explicit timeout of 500 hit, indicating a probable testbench issueThe table shows the test holds the only objection, so the question becomes what the test is waiting for: seq.start, which waits for the sequence, which waits for item_done. A short timeout during debugging reaches this point quickly instead of waiting for the default. Set it in code or with +UVM_TIMEOUT=500, whose value is read in the UVM package's time unit (1 ns in this build).
The opposite symptom, a run that ends at 0 ns, has one usual cause: no objection was raised in the run phase, so nothing held it open. The phase ends before the first clock edge, and the run phase's processes stop with it.
Reading the objection and phase traces from this library version
In uvm-core 2020.3.1 the objection trace also reports the library's own phase_hopper_objection as it schedules each phase: 136 of the example's trace lines. Read the run_objection lines. count is the object's own objections and total includes its children's; the test's raise shows count=1 total=1, then uvm_top adds it to its total.
The phase trace prints SCHEDULED, STRT and DONE for every phase, and SKIP for each run-time sub-phase with no objection. In the example, pre_reset through post_shutdown all print No objections raised, skipping phase, while common.run lasts from 0 to 100 ns.
SKIP does not mean a phase's task never started. The library starts the phase's tasks and gives them a chance to raise; with no objection at that check, nothing holds the phase open and its unfinished work is stopped.
The symptom map, for lookup
| Symptom | Usual cause | Tool, and what to look for | Taught in |
|---|---|---|---|
| Test ends at 0 ns | run_phase raised no objection | +UVM_OBJECTION_TRACE: no run_objection raised line | U1.3 |
| Hangs until the timeout | An objection never dropped: a sequence blocked in finish_item, a missing item_done, a sequence waiting for a grant | +UVM_TIMEOUT with +UVM_PHASE_TRACE: outstanding objections at the timeout | U1.3, U4.1, U5.1, U5.2 |
| Config get returns the default | Scope, name or type differs from the set | +UVM_CONFIG_DB_TRACE: a SET and a failed GET; print_config, uvm_config_db #(T)::dump() | U2.3 |
| Override ignored | Built with new, or created before the override | print_topology type column; factory.print; debug_create_by_type | U2.2 |
| Wrong component built | An instance override path matched another instance | print_topology; debug_create_by_type with that path | U2.2, U11.3 |
| Port not connected | A link missing in a hierarchical chain | debug_connected_to, debug_provided_to; a connection error for a required port | U3.2 |
| Scoreboard silent | No observations arrive, or checks never run | The ledger: checks against beats sent; zero work is an error | U7.3, U8.4 |
| Phase order surprise | Work placed in the wrong phase, or a phase skipped | +UVM_PHASE_TRACE: STRT, SKIP and DONE lines per phase | U1.2 |
| Objection count wrong | Unbalanced raise and drop, or an extra raise | +UVM_OBJECTION_TRACE; display_objections() | U1.3 |
Plusargs go on the run command; the method calls go in end_of_elaboration_phase or wherever the state is complete.
Keep this table as a lookup. Each row gives the first tool to run, not a proof: the output still has to be read against the bench, as the three bugs above were.
Switches of your own
The library's plusargs control its own tracing. A test can read switches of its own from the same command line through uvm_cmdline_processor. The example's test reads +n_items=N. A regression can then change the item count without editing code.
int requested = 6;
function void build_phase(uvm_phase phase);
string arg;
int found = uvm_cmdline_processor::get_inst().get_arg_value("+n_items=", arg);
if (found > 1) `uvm_warning("ARGS", "several +n_items= arguments; using the first")
if (found > 0) requested = arg.atoi(); // the example also rejects a count below 1
uvm_config_db #(int)::set(this, "env.agent.sqr.seq", "n_items", requested);The example runs with +n_items=8, so the ledger asks for 8; without the argument the test uses 6, as the quiz programs do. get_arg_value returns how many arguments matched and gives the first one's value. The example's test warns when there are several and stops when the value is not a positive count.
Read such switches once, in the test, and pass them on as configuration. A switch read deep inside a component is a hidden input that no config trace shows. $value$plusargs("n_items=%d", n) does the same in plain SystemVerilog.
Try it
The run carries all three bugs. Find the lines quoted in the sections: the config SET near the top, the topology and factory dumps, the two connection reports, then the failed GET when the sequence starts at 0 ns.
Fix them one at a time and rerun: uvm_config_db #(int) in the test, inc_driver::type_id::create in the agent, and mon.ap.connect(ap); in the agent's connect_phase. The ledger then reads 8 sent, 2 injected, 8 checks with 2 errors seen and 0 mismatches, and the run has no UVM_ERROR. The ledger also fails a run whose results are wrong or whose poisoned beats get no error response, not only one that does too little work.
UVM_INFO uvm/base/uvm_config_db_implementation.svh(485) @ 0: reporter [CFGDB/SET] Configuration scope='uvm_test_top.env.agent.sqr.seq' name='n_items' (type PARAMTYPEDTYPE 'T') set accessor=uvm_test_top = (int) 8 The factory will produce an object of type 'inc_err_driver' inc_driver inc_err_driver UVM_INFO @ 0: uvm_test_top.env.agent.mon.ap [debug_connected_to] Connected implementations: none UVM_INFO @ 0: run_objection [OBJTN_TRC] Object uvm_test_top raised 1 run_objection objection(s): count=1 total=1 UVM_INFO uvm/base/uvm_config_db_implementation.svh(485) @ 0: reporter [CFGDB/GET] Configuration scope='uvm_test_top.env.agent.sqr.seq' name='n_items' (type PARAMTYPEDTYPE 'T') read accessor= = null (failed lookup) items: requested 8, driver sent 4 poisoned beats: driver is inc_driver, injected 0 scoreboard: 0 checks, 0 errors seen, 0 mismatches UVM_ERROR : 3Check yourself
Remember
- Read how the run ended first: at 0 ns, at the timeout, or on time with a short ledger; each points to a different family of causes.
- For a failed config GET, check that a SET came first, that its scope matches the path (wildcards print differently), and that the types agree.
- A topology that shows the original type while
debug_create_by_typereports the override means the component bypassed the factory or was created first. - Analysis ports may have no listeners, so a missing connect is silent;
debug_connected_tofinds it and a ledger check makes it fail. - At a timeout, the outstanding-objection table names who is waiting; follow what that component is blocked on.
Practice
- The poison test with a short ledger Fix · Medium