Allow Tokio Console support #517

b-yap · 2024-04-29T11:17:00Z

This does not completely close #512, but it helps with tracking.

But if we can see which threads have been running the longest; which ones are idle for a long time, it could help determine where/when a vault gets stuck.

The tokio-console is described as:

a debugging and profiling tool for asynchronous Rust applications, which collects and displays in-depth diagnostic data on the asynchronous tasks, resources, and operations in an application.

^ From using tokio-console, a zombie task was found.
When the vault restarts, it shuts down all running tasks except for 1:

spacewalk/clients/wallet/src/resubmissions.rs

Lines 40 to 47 in e7a672b

    
           tokio::spawn(async move { 
        
           	let me_clone = Arc::clone(&me); 
        
           	loop { 
        
           		pause_process_in_secs(interval_in_seconds).await; 
        
           		me_clone._resubmit_transactions_from_cache().await; 
        
           	} 
        
           });

Aside from this, I found out that the stream also gets stuck:

spacewalk/clients/stellar-relay-lib/src/connection/connector/message_reader.rs

Line 82 in e7a672b

match connector.tcp_stream.read(&mut buff_for_reading).await {

Requires a timeout to trigger reconnection.

How to begin the review:

I have added comments to help with the review.

all affected toml files:
- tracing feature of tokio is necessary for tokio-console
- console-subscriber dependency is necessary for tokio-console

clients/wallet/src/stellar_wallet.rs:

I needed a channel to stop the task, the reason for a new field of StellarWallet:

      /// a sender to 'stop' a scheduled resubmission task
  pub(crate) resubmission_end_signal: Option<mpsc::Sender<()>>,

clients/wallet/src/resubmissions.rs:
- Added a fn stop_periodic_resubmission_of_transactions(&mut self)
- Update inside fn start_periodic_resubmission_of_transactions_from_cache(...):
  - create a new channel and store the sender in StellarWallet's resubmission_end_signal field.
  - inside the spawned task, break the loop once the receiver receives a shutdown signal
```
     loop {
   // a shutdown message was sent. Stop the loop.
   if let Some(_) = receiver.recv().await {
   	break;
   }
...		
```

clients/vault/src/system.rs:

calls the fn stop_periodic_resubmission_of_transactions(...) from the wallet field of VaultService:

     /// shuts down the resubmission task running in the background
 async fn shutdown_wallet(&self) {
  ...
  let mut wallet = self.stellar_wallet.write().await;
  wallet.stop_periodic_resubmission_of_transactions().await;
 ...
}

calls the fn shutdown_wallet(...) when the service stops.

    	async fn start(&mut self) -> Result<(), ServiceError<Error>> {
  let result = self.run_service().await;

  self.shutdown_wallet().await;
  ...

clients/stellar-relay-lib/src/connection/connector/message_reader.rs:
- introduce READ_TIMEOUT_IN_SECS; how long to wait on reading from the stream.
- add a timeout to reading the stream
```
     timeout(
  	 Duration::from_secs(READ_TIMEOUT_IN_SECS),
  	 connector.tcp_stream.read(&mut buff_for_reading),
      ).await
```
clients/README.md:
- documentation on how to use tokio-console

add `tracing` feature of tokio, and the console-subscriber

tokio-rs/console#345 (comment)

add necessary logs; add timeout in `read_message_from_stellar` because it gets stuck

b-yap · 2024-05-13T07:00:14Z

clients/runner/Cargo.toml

@@ -7,7 +7,7 @@ edition = "2021"
 [dependencies]
 clap = { version = "4.0.17", features = ["derive"]}
 hex = "0.4.3"
-tokio = { version = "1.8", features = ["rt-multi-thread", "macros", "time"] }


latest tokio vresion is 1.37.

b-yap · 2024-05-13T07:01:12Z

clients/runtime/Cargo.toml

@@ -31,7 +31,7 @@ log = "0.4.0"
 serde = { version = "1.0.136", features = ["derive"] }
 serde_json = "1.0.71"
 thiserror = "1.0"
-tokio = { version = "1.0", features = ["full"] }
+tokio = { version = "1.37", features = ["full"] }


The reason for this is the "lost its waker" issue in tokio, fixed in the newer versions.

b-yap · 2024-05-13T07:03:08Z

clients/stellar-relay-lib/Cargo.toml

@@ -16,7 +16,7 @@ wallet = { path = "../wallet", features = ["testing-utils"] }

 [dependencies]
 hex = "0.4.3"
-log = {version = "0.4.14"}
+tracing = { version = "0.1", features = ["log"] }


helps with tokio-console and instrumentation:

the console-subscriber crate in this repository contains an implementation of the instrumentation-side API as a tracing-subscriber Layer, for projects using Tokio and tracing.

b-yap · 2024-05-13T07:04:32Z

.cargo/config.toml

@@ -0,0 +1,2 @@
+[build]
+rustflags = ["--cfg", "tokio_unstable"]


to make tokio-console work::

in order to collect task data from Tokio, the tokio_unstable cfg must be enabled.

With the Rust stable version, there hasn't been any problems. The tokio-console command displays just fine, although I was not able to see the histogram.

The worst it could do would be returning a blank view.

This doesn't work for me, unfortunately I have to explicitly pass the RUSTFLAGS="--cfg tokio_unstable" when trying to run or build the client.

I assume it's because I do have a ~/.cargo/config.toml file where I already specify some rust flags

[target.aarch64-apple-darwin] rustflags = ["-C", "link-arg=-fuse-ld=/opt/homebrew/opt/llvm/bin/ld64.lld"]

and this might override the workspace configuration.

I confirmed this by removing my 'global' config.toml and then recompiling. This worked.

Generally I would prefer if we could enable this tokio-console thing with an extra feature flag and have it disabled by default. Do you think this would be possible @b-yap?

See e77d7ac

I tried to set it through [env] .cargo/config.toml, and it didn't work. All RUSTFLAGS, CARGO_ENCODED_RUSTFLAGS and CARGO_BUILD_FLAGS won't work.

I also tried to do it through a build script and didn't work:

fn main(){ cfg_if::cfg_if! { if #[cfg(feature = "allow-debugger")] { println!("cargo:rustc-env=RUSTFLAGS=\"--cfg tokio_unstable\""); } } }

and
println!("cargo:rustc-flags=\"--cfg tokio_unstable\"");
as explained in rust-lang/cargo#10141.

In the end I updated the doc to tell the user to set the rustflags themselves.

b-yap · 2024-05-13T07:08:28Z

clients/stellar-relay-lib/src/connection/connector/connector.rs

 			"verify_auth(): remote sequence: {}, auth message sequence: {}",
 			remote_info.sequence(),
 			auth_msg.sequence
 		);

-		let auth_msg_xdr = auth_msg.to_base64_xdr();


I decided to remove this because the xdr was huge and may not be helpful at all.

b-yap · 2024-05-13T07:10:01Z

clients/stellar-relay-lib/src/connection/connector/message_handler.rs

 			other => {
-				log::trace!(


we are only interested on messages that will be processed by the vault.
Logging should be done over there than here.

b-yap · 2024-05-13T07:12:20Z

clients/vault/src/main.rs

@@ -147,6 +147,7 @@ async fn start() -> Result<(), ServiceError<Error>> {

 #[tokio::main]
 async fn main() {
+	console_subscriber::init();


To use the tokio-console.

add documentation of the `tokio-console`.

b-yap · 2024-05-13T10:53:35Z

clients/vault/src/system.rs

@@ -679,15 +682,6 @@ impl VaultService {

 		tasks.append(&mut replace_tasks);

-		tasks.push((


😱 removing this duplicate, as it is also found in

spacewalk/clients/vault/src/system.rs

Lines 623 to 630 in e7a672b

(

"Parachain Block Listener",

run(active_block_listener(

self.spacewalk_parachain.clone(),

issue_event_tx,

replace_event_tx,

)),

),

inside fn create_initial_tasks(...

Originally it runs after Replace Cancellation Scheduler and before Redeem Request Listener:

spacewalk/clients/vault/src/system.rs

Lines 619 to 639 in 31df183

),

(

"Parachain Block Listener",

run(active_block_listener(

self.spacewalk_parachain.clone(),

issue_event_tx.clone(),

replace_event_tx.clone(),

)),

),

(

"Redeem Request Listener",

run(listen_for_redeem_requests(

self.shutdown.clone(),

self.spacewalk_parachain.clone(),

self.vault_id_manager.clone(),

self.config.payment_margin_minutes,

oracle_agent.clone(),

)),

),

(

"Bridge Metrics Listener",

ebma

The code looks good to me overall, nice job and great feature @b-yap 🚀
I left some comments.

clients/stellar-relay-lib/src/connection/connector/message_sender.rs

clients/vault/src/system.rs

clients/wallet/src/resubmissions.rs

ebma · 2024-05-14T15:42:01Z

.cargo/config.toml

@@ -0,0 +1,2 @@
+[build]
+rustflags = ["--cfg", "tokio_unstable"]


This doesn't work for me, unfortunately I have to explicitly pass the RUSTFLAGS="--cfg tokio_unstable" when trying to run or build the client.

I assume it's because I do have a ~/.cargo/config.toml file where I already specify some rust flags

[target.aarch64-apple-darwin] rustflags = ["-C", "link-arg=-fuse-ld=/opt/homebrew/opt/llvm/bin/ld64.lld"]

and this might override the workspace configuration.

I confirmed this by removing my 'global' config.toml and then recompiling. This worked.

Generally I would prefer if we could enable this tokio-console thing with an extra feature flag and have it disabled by default. Do you think this would be possible @b-yap?

…209035, #517 (comment),

…ob/24994504193?pr=517

…9314/job/24998905803?pr=517

…ob/25003758078?pr=517

…ob/25007476694?pr=517

…ob/25040418069?pr=517

ebma

Tested it locally again, can confirm it works with the new feature flag.

Great changes, thanks a lot @b-yap 👌

b-yap · 2024-05-22T11:57:31Z

@ebma Would be great if we have the vaults running with this feature. I bet it'll look very different (and interesting).

ebma · 2024-05-22T14:10:02Z

True, but I'm not sure if we can easily connect to the clients with tokio-console if they are running in a docker container.

@zoveress in this PR we added support for a profiling tool that lets us investigate resource consumption of tasks within our process. As you can see here, it's fairly simple to run. As far as I understand, the changes we made to the client will make it expose a new endpoint (by default) on port 6669 that is used by the tokio-console tool for accessing the debug information. Using this setup would be very easy to do in the EC2 instances but maybe not in our Kubernetes cluster. @zoveress do you have an idea how we could be able to access it also on Kubernetes?

This is not super important but would be nice to have.

zoveress · 2024-05-22T15:43:07Z

Is the endpoint password secured?

ebma · 2024-05-22T15:48:59Z

No it's not and I think it's only supposed to be used locally. Can we expose it to the GitLab runner only and access it from there somehow?

b-yap force-pushed the 512-investigate-occasional-high-cpu-usage-of-vault-clients branch from 74c01ca to 16cc8e1 Compare May 9, 2024 08:55

b-yap added 5 commits May 13, 2024 14:57

first iteration:

7f65090

add `tracing` feature of tokio, and the console-subscriber

update on tokio version, based on:

08ae810

tokio-rs/console#345 (comment)

use tracing library, instead of log.

191ecc5

remove unnecessary logs;

f042087

add necessary logs; add timeout in `read_message_from_stellar` because it gets stuck

cleanup zombie task

87ad4d5

b-yap force-pushed the 512-investigate-occasional-high-cpu-usage-of-vault-clients branch from db588a5 to 87ad4d5 Compare May 13, 2024 06:57

b-yap commented May 13, 2024

View reviewed changes

b-yap added 2 commits May 13, 2024 18:44

Update README.md

a0d233d

add documentation of the `tokio-console`.

remove duplicate Parachain Block Listener

c6d5e25

b-yap commented May 13, 2024

View reviewed changes

b-yap marked this pull request as ready for review May 13, 2024 10:56

b-yap requested a review from a team May 13, 2024 10:56

ebma reviewed May 14, 2024

View reviewed changes

b-yap added 7 commits May 15, 2024 17:58

https://github.com/pendulum-chain/spacewalk/pull/517/files#r1600267305

e77d7ac

https://github.com/pendulum-chain/spacewalk/pull/517#discussion_r1600…

bd13f8f

…209035, #517 (comment),

https://github.com/pendulum-chain/spacewalk/actions/runs/9094123182/j…

a02b192

…ob/24994504193?pr=517

remocehttps://github.com/pendulum-chain/spacewalk/actions/runs/909551…

102f58c

…9314/job/24998905803?pr=517

https://github.com/pendulum-chain/spacewalk/actions/runs/9096987912/j…

5507a2a

…ob/25003758078?pr=517

https://github.com/pendulum-chain/spacewalk/actions/runs/9098087121/j…

6ef16b1

…ob/25007476694?pr=517

https://github.com/pendulum-chain/spacewalk/actions/runs/9108826563/j…

ff168c6

…ob/25040418069?pr=517

b-yap requested a review from ebma May 21, 2024 05:13

ebma approved these changes May 22, 2024

View reviewed changes

b-yap merged commit 93ddbce into main May 22, 2024
2 checks passed

b-yap deleted the 512-investigate-occasional-high-cpu-usage-of-vault-clients branch May 22, 2024 11:52

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Allow Tokio Console support #517

Allow Tokio Console support #517

b-yap commented Apr 29, 2024 •

edited

Loading

b-yap May 13, 2024

b-yap May 13, 2024

b-yap May 13, 2024

b-yap May 13, 2024

b-yap May 13, 2024

ebma May 14, 2024

b-yap May 15, 2024

b-yap May 13, 2024

b-yap May 13, 2024

b-yap May 13, 2024

b-yap May 13, 2024 •

edited

Loading

ebma left a comment

ebma May 14, 2024

ebma left a comment

b-yap commented May 22, 2024

ebma commented May 22, 2024

zoveress commented May 22, 2024

ebma commented May 22, 2024

	tokio::spawn(async move {
	let me_clone = Arc::clone(&me);
	loop {
	pause_process_in_secs(interval_in_seconds).await;

	me_clone._resubmit_transactions_from_cache().await;
	}
	});

		@@ -0,0 +1,2 @@
		[build]
		rustflags = ["--cfg", "tokio_unstable"]

		@@ -679,15 +682,6 @@ impl VaultService {

		tasks.append(&mut replace_tasks);

		tasks.push((

	(
	"Parachain Block Listener",
	run(active_block_listener(
	self.spacewalk_parachain.clone(),
	issue_event_tx,
	replace_event_tx,
	)),
	),

Allow Tokio Console support #517

Allow Tokio Console support #517

Conversation

b-yap commented Apr 29, 2024 • edited Loading

How to begin the review:

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

b-yap May 13, 2024 • edited Loading

Choose a reason for hiding this comment

ebma left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ebma left a comment

Choose a reason for hiding this comment

b-yap commented May 22, 2024

ebma commented May 22, 2024

zoveress commented May 22, 2024

ebma commented May 22, 2024

b-yap commented Apr 29, 2024 •

edited

Loading

b-yap May 13, 2024 •

edited

Loading