Recently I got strange behavior on my app, it can stuck with 100% cpu usage forever, a

Is it enough? <a href="https://github.com/warp-tech/russh/files/1497

100% cpu usage when send data with channel.data about russh HOT 6 OPEN

VladTheJunior commented on July 23, 2024

100% cpu usage when send data with channel.data

from russh.

Comments (6)

ondt commented on July 23, 2024 1

I'm facing the same issue - 100% CPU usage (single core) when awaiting russh::Channel::data.

In comparison, ssh [email protected] "cat > /dev/null" < /dev/urandom consumes barely any CPU.

Minimal example:

use async_trait::async_trait;
use russh::client;
use russh::client::Config;
use russh_keys::key;
use std::sync::Arc;

#[tokio::main]
async fn main() -> anyhow::Result<()> {
    let addrs = ("10.0.0.123", 22);

    let mut session = client::connect(Arc::new(Config::default()), addrs, Client).await?;

    let auth_ok = session.authenticate_password("user", "pass").await?;
    if !auth_ok {
        anyhow::bail!("auth failed");
    }

    let channel = session.channel_open_session().await?;
    channel.exec(true, "cat > /dev/null").await?;

    let infinite_data = tokio::io::repeat(b'A');

    println!("sending data");
    channel.data(infinite_data).await?;

    unreachable!();
}

struct Client;

#[async_trait]
impl client::Handler for Client {
    type Error = russh::Error;

    async fn check_server_key(
        &mut self,
        _server_public_key: &key::PublicKey,
    ) -> Result<bool, Self::Error> {
        Ok(true)
    }
}

(I'm using russh 0.44.0-beta.2)

Flamegraph: flamegraph.svg.gz
(russh is highlighted)

I generated the flamegraph using cargo flamegraph --release. I had to let it run for a few minutes to make the data method more apparent in the perf data.

I also turned on debuginfo in the release profile:

# Cargo.toml

[profile.release]
debug = true

from russh.

Eugeny commented on July 23, 2024

Could you please take a profile of your program to see where it's looping?

from russh.

VladTheJunior commented on July 23, 2024

How can I do that?

from russh.

Eugeny commented on July 23, 2024

https://nnethercote.github.io/perf-book/profiling.html

from russh.

VladTheJunior commented on July 23, 2024

Is it enough?

perf.zip

   7.79%  tokio-runtime-w  test_agent         [.] memcpy
   7.77%  tokio-runtime-w  test_agent         [.] <russh::channels::io::tx::ChannelTx<S> as tokio::io::async_write::AsyncWrite>::poll_write
   6.62%  tokio-runtime-w  test_agent         [.] tokio::runtime::scheduler::multi_thread::worker::Context::run
   5.77%  tokio-runtime-w  test_agent         [.] tokio::runtime::scheduler::multi_thread::worker::<impl tokio::runtime::scheduler::multi_thread::ha   5.11%  tokio-runtime-w  test_agent         [.] tokio::sync::batch_semaphore::Semaphore::add_permits_locked
   4.53%  tokio-runtime-w  test_agent         [.] tokio::sync::mutex::Mutex<T>::lock_owned::{{closure}}
   4.52%  tokio-runtime-w  test_agent         [.] <tokio::sync::batch_semaphore::Acquire as core::future::future::Future>::poll
   3.76%  tokio-runtime-w  test_agent         [.] __libc_free
   3.42%  tokio-runtime-w  test_agent         [.] tokio::runtime::context::with_scheduler
   3.16%  tokio-runtime-w  test_agent         [.] __unlock
   2.95%  tokio-runtime-w  test_agent         [.] <tokio::io::util::copy::Copy<R,W> as core::future::future::Future>::poll
   2.79%  tokio-runtime-w  test_agent         [.] tokio::sync::batch_semaphore::Semaphore::release
   2.78%  tokio-runtime-w  test_agent         [.] __lock
   2.77%  tokio-runtime-w  test_agent         [.] tokio::runtime::task::state::State::transition_to_running
   2.46%  tokio-runtime-w  test_agent         [.] tokio::runtime::scheduler::multi_thread::worker::Context::run_task
   2.45%  tokio-runtime-w  test_agent         [.] tokio::runtime::task::state::State::transition_to_idle
   2.14%  tokio-runtime-w  test_agent         [.] tokio::runtime::task::waker::wake_by_ref
   2.04%  tokio-runtime-w  test_agent         [.] tokio::runtime::task::state::State::ref_dec
   1.81%  tokio-runtime-w  test_agent         [.] agent::ssh::SshSession::execute::{{closure}}
   1.80%  tokio-runtime-w  test_agent         [.] sccp
   1.77%  tokio-runtime-w  test_agent         [.] __libc_malloc_impl
   1.70%  tokio-runtime-w  test_agent         [.] tokio::runtime::task::harness::Harness<T,S>::poll
   1.59%  tokio-runtime-w  test_agent         [.] tokio::runtime::context::scoped::Scoped<T>::with
   1.53%  tokio-runtime-w  test_agent         [.] alloc_slot
   1.51%  tokio-runtime-w  test_agent         [.] enframe
   1.42%  tokio-runtime-w  test_agent         [.] get_meta
   1.30%  tokio-runtime-w  test_agent         [.] tokio::runtime::task::core::Core<T,S>::poll

from russh.

VladTheJunior commented on July 23, 2024

There is also additional context of this problem. Probably root reason is target device.
I trying to execute command which sends ~200KB of data. But for unknown reason it recieves just 40KB and then I met 100% cpu usage on my side and stacked process on device with command (sh -c /cat > /some/file). BUT when I restarted this device problem is gone.
So I can't catch this bug now, but behavior of 100% cpu is bad and can break my app again in the next time (it happened rarely some times before, but I could detect it only yesterday since I have thousands of devices where this command is executing). It should generate some error instead or at least react to timeout

from russh.

100% cpu usage when send data with channel.data about russh HOT 6 OPEN

Comments (6)

Related Issues (20)

Recommend Projects

React

Vue.js

Typescript

TensorFlow

Django

Laravel

D3

Recommend Topics

javascript

web

server

Machine learning

Visualization

Game

Recommend Org

Facebook

Microsoft

Google

Alibaba

D3

Tencent