3

I am trying to achieve logging of extrinsic execution time traces on parachain nodes i run myself during block import. I'm doing this through tracing instead of by weights so that I can collect data on long-term trends in actual execution times on the actual mainnet TXN composition instead of benchmarking's worst-case assumption.

Looking through the docs, most references to in-runtime tracing are 12months or older.

I have found

My runtime forwards block building calls directly to executive, which runs init_tracing https://github.com/paritytech/substrate/blob/polkadot-v0.9.26/frame/executive/src/lib.rs#L435 so as long as sp-io is built with-tracing I get the PassingTracingSubscriber and should see log output of recorded spans from what I gather reading these docs.

I have tried RT cargo.toml

with-tracing = [
  "sp-tracing/with-tracing",
  "polkadot-runtime-metrics/runtime-metrics",
  "frame-executive/with-tracing",
  "sp-io/with-tracing"
]

cargo b --release --features=with-tracing

But I cannot get any trace output to show up in the logs. Client-side Trace-level logs show normally when the bin is run with -ltrace:

2022-12-02 11:09:42.063 TRACE tokio-runtime-worker executor: [Parachain] Executing function method=BlockBuilder_apply_extrinsic
2022-12-02 11:09:42.069 TRACE tokio-runtime-worker executor: [Parachain] Executing function method=BlockBuilder_apply_extrinsic

I would expect these to be interspersed with the recorded spans from apply_extrinsic produced here.

Is sp-tracing still supported and am I missing something? e.g. some client-side configuration to receive/enable the traces from the PassingTracingSubscriber. I did find reference in the docs to having to call set_tracing_subscriber somewhere in the RT, but 0.9.26 substrate code does not seem to have this fn anymore.

One caveat with this chain (in case it's relevant) is that I do not have to option of using the native runtime as we force WASM execution even in the case of matching versions.

1 Answer 1

1

You need to run with:

--tracing-targets target=level,target2=level2

Tracing targets are handled differently than logging targets.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.