[Bug Fix] - Incorrect trace caused by use of Span::enter in asynchronous code

[patrickkuo]

jsonrpsee is emitting incorrect trace because of incorrect use of Span::enter in async code

Symtoms:

logs are very spammy as the trace is entering incorrect span

_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_executeTransaction}:method_call{method=sui_transferObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_executeTransaction}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_executeTransaction}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_getObject}:method_call{method=sui_executeTransaction}:method_call{method=sui_transferObject}:method_call{method=sui_transferObject}:method_call{method=sui_transferObject}:method_call{method=sui_executeTransaction}:method_call{method=sui_splitCoin}:method_call{method=sui_transferObject}:method_call{method=sui_executeTransaction}:method_call{method=sui_syncAccountState}:method_call{method=sui_getObject}:method_call{method=sui_executeTransaction}:method_call{method=sui_transferObject}:method_call{method=sui_splitCoin}:method_call{method=sui_transferObject}:method_call{method=sui_executeTransaction}:method_call{method=sui_executeTransaction}:method_call{method=sui_executeTransaction}:method_call{method=sui_transferObject}:method_call{method=sui_executeTransaction}:method_call{method=sui_executeTransaction}:method_call{method=sui_transferObject}:method_call{method=sui_executeTransaction}:method_call{method=sui_transferSui}:method_call{method=sui_executeTransaction}:method_call{method=sui_executeTransaction}:method_call{method=sui_executeTransaction}:method_call{method=sui_executeTransaction}:gateway_execute_transaction{tx_digest=VXrf5dF9bFPlPQsyxOXhvXRZ+5zZneS2t90nhI+6WCM= tx_kind="Single"}:execute_transaction{tx_digest=VXrf5dF9bFPlPQsyxOXhvXRZ+5zZneS2t90nhI+6WCM= tx_kind="Single"}:process_tx: sui_core::safe_client: Client error error=PairwiseSyncFailed { xsource: k#e97638a9e10b9cc46d85b81191a60a6a6fcae63dacd811c07502db9c5cfc55b5, destination: k#89cafd721eeb1b13483d5fb0968500e78103e8146b45edb30d93781d946d0aeb, tx_digest: VXrf5dF9bFPlPQsyxOXhvXRZ+5zZneS2t90nhI+6WCM=, error: RpcError("Timeout expired") } authority=k#e97638a9e10b9cc46d85b81191a60a6a6fcae63dacd811c07502db9c5cfc55b5

this PR replace the use of Span::enter with async {...}.instrument(span).await as suggested by the tracing doc
https://docs.rs/tracing/latest/tracing/struct.Span.html#in-asynchronous-code

[niklasad1]

Can't params, name & id be extracted outside the async block?

[niklasad1]

nice catch and work, looks good

[jsdw]

Thanks for the PR!

This does make it clear that it can be quite hard to get tracing right when we need a span to cover multiple await points properly; perhaps we should be using the attribute suggested in the docs on these functions instead (#[tracing::instrument(level = "info")]) so that we don't need to litter the code with async {} blocks and worry about this sort of thing.

I also noted that in a couple of cases in the PR we were making an async {} block around places which only had a single await. Not a big deal but not necessary.

So I'm happy to merge this, but let's consider simplifying the code a bit and using the macro, unless it has some downsides?