Warn if a task takes a long time to poll

[tomaka]

This should help detect small freezes.

Before merging this PR, the freezes should actually be fixed, so as to not start printing warnings to the users.

[github-actions]

twiggy diff report

Difference in .wasm size before and after this pull request.

---

 Delta Bytes │ Item
─────────────┼─────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────
        +410 ┊ <smoldot_light_wasm::init::init::{{closure}}::FutureAdapter<F> as core::future::future::Future>::poll::h3d2cf17ee8b39776
        +192 ┊ data[0]
         +17 ┊ <&mut T as core::fmt::Display>::fmt::hb5c15821b68b5c77
          +5 ┊ elem[0]
        +709 ┊ Σ [4 Total Rows]

[tomaka]

One freeze probably comes from here:

smoldot/lib/src/sync/all.rs

Lines 1172 to 1220 in b7bf5b9

	warp_sync::ProcessOne::BuildRuntime(inner) => {
	// TODO: errors not reported to upper layer
	// TODO: make these parameters configurable
	match inner.build(ExecHint::CompileAheadOfTime, false).0 {
	warp_sync::WarpSync::InProgress(inner) => {
	self.inner = AllSyncInner::GrandpaWarpSync { inner };
	ProcessOne::AllSync(self)
	}
	warp_sync::WarpSync::Finished(success) => {
	let (
	new_inner,
	finalized_block_runtime,
	finalized_storage_code,
	finalized_storage_heap_pages,
	) = self.shared.transition_grandpa_warp_sync_all_forks(success);
	self.inner = AllSyncInner::AllForks(new_inner);
	ProcessOne::WarpSyncFinished {
	sync: self,
	finalized_block_runtime,
	finalized_storage_code,
	finalized_storage_heap_pages,
	}
	}
	}
	}
	warp_sync::ProcessOne::BuildChainInformation(inner) => {
	match inner.build().0 {
	// TODO: errors not reported to upper layer
	warp_sync::WarpSync::InProgress(inner) => {
	self.inner = AllSyncInner::GrandpaWarpSync { inner };
	ProcessOne::AllSync(self)
	}
	warp_sync::WarpSync::Finished(success) => {
	let (
	new_inner,
	finalized_block_runtime,
	finalized_storage_code,
	finalized_storage_heap_pages,
	) = self.shared.transition_grandpa_warp_sync_all_forks(success);
	self.inner = AllSyncInner::AllForks(new_inner);
	ProcessOne::WarpSyncFinished {
	sync: self,
	finalized_block_runtime,
	finalized_storage_code,
	finalized_storage_heap_pages,
	}
	}
	}
	}

[tomaka]

When in the browser, this prints a lot of warnings about tasks taking exactly 16ms to poll, even very light tasks such as memory-printer. I have no idea why. EDIT: happens only on Firefox, not Chrome
It could be the case that performance.now() has a low precision, but the docs mention 5µs or 100µs, which is pretty far from 16ms: https://developer.mozilla.org/en-US/docs/Web/API/Performance/now#security_requirements

[tomaka]

It could be the case that performance.now() has a low precision

When printing the values returned by performance.now(), it seems that this is not the explanation.
The time elapsed is never actually precisely 16ms, but 16.2ms, 16.8ms, 16.4ms, etc.
I suppose that it's the browser doing something magic here and interrupting the Wasm execution for 16ms for some reason.

[tomaka]

state_getKeysPaged seems to take a long time to decode the proof and run the prefix_proof system.
It seems that decoding a proof should be split into stages.

[tomaka]

Verifying a finality proof should also be split into stages.

[tomaka]

I'm going to merge this PR, but not mention that an issue should be opened.