Skip to content

fix(audit): record what ran — plus the outstanding follow-ups - #215

Merged
kuny0707 merged 6 commits into
tronprotocol:developfrom
barbatos2011:fix/audit-what-ran
Aug 6, 2026
Merged

fix(audit): record what ran — plus the outstanding follow-ups#215
kuny0707 merged 6 commits into
tronprotocol:developfrom
barbatos2011:fix/audit-what-ran

Conversation

@barbatos2011

@barbatos2011 barbatos2011 commented Aug 6, 2026

Copy link
Copy Markdown

Six commits, each self-contained and independently revertable. The first two are the audit work this PR opened with; the rest are the follow-ups called out across #211#214, folded in on request.

commit what
fix(audit) a recipe run left nothing in the log; AuditEntry had nowhere to say what a command acted on
feat(audit) correlate a run with the steps it re-execs (run_id)
feat(audit) record which path files get read off a node
fix(wait) --http must be a URL, not a curl option
fix(build) stop re-downloading the Go toolchain on every make
fix(txgen) generated transactions collided on txID, shrinking the applied load

1–2. Audit: what ran, and what caused it

A recipe run could act and leave no trace. Command steps re-exec trond so the child logs itself, but nothing recorded the run, and kind: host steps never re-enter trond — making a recipe the most capable command in the tool and the only one invisible to the log.

AuditEntry also had nowhere to say what a command acted on. For stop n0 the verb is the whole story; for the three commands that run caller-supplied content it is not. This was flagged as a follow-up in #211 and is now paid off, together with a run_id that ties a run to the steps it spawns:

run_id=aa51fc58  recipe host-step  detail=touch-host: true
run_id=aa51fc58  stop
run_id=aa51fc58  recipe run        detail=./mix.yaml

That middle line is a separate trond process. Detail carries an identifier, never a payload — the program but not the argv, the destination but not the bytes. Full argv and file contents are where a caller is most likely to have put a token, and an audit log is the wrong place to learn one. run_id travels in an environment variable rather than a flag: every command writes audit entries, and threading a parameter through all of them to serve one caller is the wrong shape.

Refused and dry-run steps write no step entry — they did not run, and claiming otherwise is worse than silence — while the run itself is still recorded as a failure.

3. files get

Reads an arbitrary path off a node. Not a mutation, so deliberately still not gated — the gate is for mutation, and blocking reads makes it something people switch off. But a jar node's config.conf carries the block-signing key in localwitness, so the path read is worth recording even when reading it was legitimate. files put already left an entry; its read counterpart left none.

4. wait --http

The value becomes an argv item for curl on the node, unvalidated — so -K/etc/shadow or -o/tmp/x is an option rather than a URL and curl reads it as one. It is argv rather than a shell, so this is narrow, but the check costs one comparison. Validated once before the poll loop, so a bad value fails immediately rather than on every attempt until the timeout.

Correcting something I said earlier: I had listed health as having the same problem. It does not — it builds its URL from a port stored in state, and is unchanged here.

5. Toolchain

bootstrap-go asked the installed toolchain its version with go env GOVERSION, which reports the effective toolchain — and Go 1.21+ auto-upgrades to whatever go.mod's toolchain line names. This repo pins toolchain go1.25.11 while GO_VERSION is 1.25.9, so an installed 1.25.9 reported itself as 1.25.11, never matched, and every make deleted and re-downloaded 55 MB. GOTOOLCHAIN=local makes the check ask what is installed rather than what the repo would prefer. Fast path: 0.18s → 0.04s.

6. txgen duplicates

The node stamps raw_data.timestamp with its own clock, so transactions built in the same millisecond with the same sender, receiver and amount are byte-identical — one txID — and all but the first are rejected as DUP_TRANSACTION_ERROR. The report showed the full generated count beside a quietly smaller accepted count, reading as node backpressure rather than a generator bug.

Measured against a private chain, identical configuration either side, load held below the node's intake ceiling so SERVER_BUSY could not mask the effect:

regime unique txIDs broadcast OK fail
1200 tx, 50 receivers, conc 16 before 1192 1192 8 — all Dup transaction.
after 1200 1200 0
repeat before 1154 1154 46 — all Dup transaction.
after 1200 1200 0
1200 tx, 5 receivers, conc 32 before 855 28.75% of the run lost
after 1200 0%

broadcast OK equals unique txIDs exactly in every pre-fix run: the duplicates are not correlated with the lost load, they are it, one for one. The rate swings 0.67% → 28.75% with fan-out and concurrency, which is why it read as noise.

Duplicates were counted at the source — distinct txIDs in the generated CSVs — rather than from the broadcast log, which only samples the first 20 failures. That makes the count exact rather than extrapolated.

A first attempt at this comparison was discarded: it ran both variants back to back at saturating load, so the second inherited a full mempool and its extra failures were all SERVER_BUSY. The numbers above come from a fresh chain with the load dropped below saturation.

Each transaction now takes a distinct expiration offset from a process-global counter, riding the rewrite txgen already does before signing. Bounded at 60s so it cannot walk expiration toward java-tron's 24h ceiling.

Testing

  • make test -race — 25 packages, 0 failures
  • make lint — no findings
  • Audit behaviour verified end to end against a real binary: the run_id correlation above is actual output, including the child-process line
  • txgen: measured end to end on a live private chain (table above), plus unit tests for the property — different offsets → different txIDs, same offset → deterministic, so the fix is not hiding collisions behind randomness

Still open

Nothing from the earlier list. verify-config can also read arbitrary paths off a node; it is the same disclosure shape as files get and would want the same entry, but it reads through a different path and is left for a change that can test it properly.

Two gaps, both widened by the recipe work that just landed.

**A recipe run left nothing behind.** Command steps re-exec trond, so
each child writes its own entry under its own verb — but nothing recorded
the run itself, and `kind: host` steps (tronprotocol#214) never re-enter trond at
all. That made a recipe the most capable single command trond has and the
only one that could act without appearing in the log.

`recipe run` now writes one entry for the run, with the recipe's source
as its detail, and one per host step that actually executed. A step
refused by `--allow-host-exec` or the private gate gets no step entry —
it did not run, and claiming otherwise is worse than silence — while the
run itself is still recorded, as a failure. `--dry-run` records nothing:
a preview executed nothing.

The runner takes a callback rather than writing the log itself. The audit
log's location and policy belong to the CLI, and internal/recipe should
not grow an opinion about either.

**AuditEntry had nowhere to say what a command acted on.** For most verbs
the verb is the whole story: `stop` on node n0 has no other detail worth
keeping. But three commands run caller-supplied content, and for those an
entry saying only that they happened cannot answer the question an audit
log exists to answer. This was flagged as a follow-up when `exec` and
`files put` were gated and is now paid off:

    exec              node=n0  detail=/bin/echo
    files put         node=n0  detail=/srv/tron/conf/node.conf
    recipe host-step           detail=stage: touch
    recipe run                 detail=./deploy.yaml

Detail carries an identifier, never a payload — the program name but not
the argv, the destination path but not the bytes, the step's program but
not the script body. Full argv and file contents are exactly where a
caller is most likely to have put a token or key, and an audit log is the
wrong place to learn one. That boundary is stated on the field so the
next person adding a detail knows which side of it they are on.

SchemaVersion 1.13.0 -> 1.14.0 (one additive optional property), both
schema copies updated, baseline re-snapshotted.
A recipe's command steps re-exec trond, so each child writes its own
audit entry under its own verb. Correct, but it left the log showing
`stop n0` with nothing to say a recipe drove it, and no way to tell two
concurrent runs apart.

`recipe run` now mints a random id and exports it into every step's
environment; writeAudit picks it up, so parent and children share a
run_id:

    run_id=aa51fc58  recipe host-step  detail=touch-host: true
    run_id=aa51fc58  stop
    run_id=aa51fc58  recipe run        detail=./mix.yaml

An environment variable rather than a flag: every trond command writes
audit entries, and threading a parameter through all of them to serve one
caller is the wrong shape. internal/recipe takes the variable's name from
the caller rather than hard-coding a convention that belongs to the audit
log.

SchemaVersion 1.14.0 -> 1.15.0, one additive optional property.
`files get` reads an arbitrary path from a managed node. That is not a
mutation, so it is deliberately not gated by --require-private — the gate
is for mutation, and blocking reads makes it something people switch off.

But a jar node's config.conf carries the block-signing key in
localwitness, so which path was read is worth recording even when reading
it was entirely legitimate. `files put` already leaves an entry; its read
counterpart left none.

Detail is the source path — what was read, never its contents.
`wait --exec` runs on the node via `sh -c`, and --http's value becomes an
argv item for curl there. It was unvalidated, so a value like
"-K/etc/shadow" or "-o/tmp/x" is an option rather than a URL and curl
reads it as one.

It is argv rather than a shell, so this is a narrow hole — but "starts
with http:// or https://" costs one comparison and closes it. Validated
once before the poll loop rather than inside it, so a bad value fails
immediately instead of on every attempt until the timeout expires.

`health` builds its URL from a port stored in state and was never
exposed; it is unchanged.
bootstrap-go's fast path asked the installed toolchain for its version
with `go env GOVERSION`. That reports the EFFECTIVE toolchain, and Go
1.21+ auto-upgrades to whatever go.mod's `toolchain` line names — this
repo pins `toolchain go1.25.11` while GO_VERSION is 1.25.9.

So an installed go1.25.9 reported itself as go1.25.11, never matched, and
every make invocation deleted the toolchain and re-downloaded 55 MB:

    bootstrap-go: existing .go-toolchain/1.25.9 reports go1.25.11,
                  expected go1.25.9 — refreshing

GOTOOLCHAIN=local makes the check ask what is installed here rather than
what this repo would rather use. make test / make lint / make e2e each
drop about ten seconds and a 55 MB download; the script's fast path goes
from 0.18s to 0.04s.
@barbatos2011 barbatos2011 changed the title fix(audit): record what ran, not just that something ran fix(audit): record what ran — plus the outstanding follow-ups Aug 6, 2026
The node stamps raw_data.timestamp with its own clock. Transactions built
in the same millisecond with the same sender, receiver and amount
therefore have byte-identical raw_data — one txID — and the node accepts
the first while rejecting the rest with DUP_TRANSACTION_ERROR.

Nothing said so. The report showed the full generated count next to a
quietly smaller accepted count, which reads as node backpressure rather
than a generator bug.

Measured against a private chain, identical configuration either side,
load held below the node's intake ceiling so SERVER_BUSY could not mask
the effect:

    1200 tx, 50 receivers, concurrency 16
      before  unique txIDs 1192  broadcast ok 1192  fail 8   (all DUP)
      after   unique txIDs 1200  broadcast ok 1200  fail 0
      before  unique txIDs 1154  broadcast ok 1154  fail 46  (all DUP)
      after   unique txIDs 1200  broadcast ok 1200  fail 0

    1200 tx, 5 receivers, concurrency 32   (maximal collision pressure)
      before  unique txIDs 855   28.75% of the run lost
      after   unique txIDs 1200  0%

`broadcast ok` equals the number of unique txIDs exactly in every
pre-fix run: the duplicates are the lost load, one for one. The rate is
regime-dependent — 0.67% to 28.75% across these runs — which is why it
read as noise rather than as a bug.

Each transaction now takes a distinct expiration offset from a
process-global counter. txgen already rewrites raw_data.expiration and
recomputes raw_data_hex and txID before signing, so this rides an
existing step. The offset is bounded at 60s so it cannot walk expiration
toward java-tron's 24h ceiling, and expiration is a deadline — moving it
by milliseconds changes nothing a load test cares about.

Tests pin both halves: different offsets give different txIDs, and the
same offset stays deterministic, so the fix is not hiding collisions
behind randomness.
@kuny0707
kuny0707 merged commit 2f54909 into tronprotocol:develop Aug 6, 2026
13 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants