Skip to main content

Read a failing trace

The problem​

CI reports a failing check, but its summary may omit the surrounding calls. These traces let you inspect the failed comparison alongside the request and response it judged.

This lesson reads the failures from the last lesson as if they were your own.

Do it​

1. Open the two traces of one pair​

Each pair compares a deliberate failure with a different test that addresses it. The panes show selected evidence from saved sample traces, not the whole operation tree.

Who moves the clock?

The drillfailed
ARealWaitDoesNotCloseTheDueWindow1.25 s
Recorded operations (3)
  • data.createCreate · IssueInvoiceRequestsucceeded152.2 ms, provisioned in the test tenant
  • http.requestREST · GET /api/v1/organizationsucceeded74.0 ms, HTTP 200
  • assert.json.shapeAssert response shapefailedShape mismatch failed with 1 error(s): • [$.status]: Values did not match. (Expected: "past_due", Actual: "active")
Download this run's archive
The test that holdssucceeded
TheTestClockClosesTheDueWindow286.8 ms
Recorded operations (6)
  • data.createCreate · IssueInvoiceRequestsucceeded165.8 ms, provisioned in the test tenant
  • clock.advanceClock advanced by 8:0:00:00event on test.execution, from the test side
  • http.requestREST · GET /api/v1/organizationsucceeded65.3 ms, HTTP 200
  • assert.json.shapeAssert response shapesucceededthe same property, now past_due
  • http.requestREST · POST /api/v1/invoices/{invoiceId}/paysucceeded35.0 ms, HTTP 200
  • assert.json.shapeAssert response shapesucceededstatus paid
Download this run's archive

What changesMove the test clock instead of waiting on real time.

Every name, duration and message is from a recording of samples/Northstar.ProtoTest with the drills enabled. The drill failed on purpose; the test beside it runs the same journey and passes. Each pane links that test's own archive.

Pick the Time pair and expand each pane's recorded operations. Each pane links its own archive, which you can open in the viewer. Select the named test and open Execution to inspect the full sequence.

2. Ask four questions of the failed entry​

  1. Which check failed? Find the failed assertion, such as Assert response shape, beneath the failed test execution.
  2. What did it expect, and what did it read? The message carries both. A shape check adds the JSON path: [$.status]: Values did not match. (Expected: "past_due", Actual: "active").
  3. Which call did it judge? These REST checks are children of the request they judge. Open that parent for its status, duration and attachments.
  4. What differs in the paired test? Compare its setup, actions and expectations with the failing test's source.

3. Compare the pair​

For the time pair, the important change is advancing the test clock before reading the organization. The passing test also continues to pay the invoice:

The failing testThe test that holds
Before the readan invoice is provisionedan invoice is provisioned, then the clock moves eight days
The callREST GET /api/v1/organization, 74.0 ms, HTTP 200the same call, 65.3 ms, HTTP 200
The checkshape failed: $.status expected past_due, read activeshape succeeded, then the invoice is paid

Both requests returned HTTP 200, so the status checks passed. The failing test received active, while the passing test received past_due. A successful request operation does not mean every assertion on its response succeeded.

4. Read a trace that is silent​

Open the Environment pair. Its saved failing execution lasted about 2 seconds and contains no request operation. The execution error names the address and connection failure. Setup and teardown still appear elsewhere in the archive.

What happened​

The time failure waited a real second, but that did not advance the test clock. The fix advanced it eight days before making the request. The application evaluated the overdue invoice during that request, and the same status shape check passed. Advancing the clock alone does not execute the application's billing logic.

The environment drill used a plain HttpClient with a hardcoded address. It ran inside the test, but bypassed ProtoTest's REST request instrumentation. The trace records the resulting test failure without a separate request operation. The fix uses Proto.Context.Rest(), which resolves the configured application and records the request and checks.

A missing operation is a clue, not proof. Check the source: the call may have been skipped, may have failed before ProtoTest started recording, or may have used a client ProtoTest does not record. Here, the raw client explains the missing entry.

Check yourself​

The visibility failure starts with "Expected HTTP status 201 (Created), but received 400 (BadRequest)" and includes the response body. What expectation does the paired test change?

Verify
Read the Visibility pair above, then download l0-visibility-drill.prototrace and l0-visibility-fix.prototrace and open both in the viewer.

Remember​

  • Follow a failed REST check to its parent request and inspect the response.
  • Compare the paired tests' actions and expectations, not only their durations.
  • A missing request entry needs a source check before you decide why it is absent.

Go deeper​