Высокая загрузка процессора из веб-сокета в Rouille - PullRequest
Новая
       24

Высокая загрузка процессора из веб-сокета в Rouille

1 голос
/ 16 мая 2019

У меня есть небольшой сервер веб-приложений, написанный на Rust, код доступен здесь .

Все это работает должным образом, однако после активного использования в течение «некоторого времени» загрузка ЦП процесса будет на уровне 100% (как сообщает top) и будет оставаться там до перезапуска.

Проблема в том, что я не могу понять, что вызывает использование этого ЦП, или как эффективно отлаживать его - главным образом, поскольку я не могу воссоздать использование ЦП локально. Это происходит как во FreeBSD (где к процессу был получен прямой доступ), так и на новом сервере под управлением Ubuntu 18.10 (где он был перенаправлен через Nginx); однако я не могу воссоздать это на моей локальной машине под управлением macOS (возможно, из-за ОС, но возможен просто другой доступ

Если я запускаю perf record, отчет показывает это: 

Samples: 44K of event 'cpu-clock', Event count (approx.): 11073000000
Overhead  Command          Shared Object               Symbol
  21.92%  juke             [kernel.kallsyms]           [k] do_syscall_64
  17.52%  juke             libpthread-2.23.so          [.] __libc_recv
   5.53%  juke             [kernel.kallsyms]           [k] inet_diag_table+0x800000004df0
   4.13%  juke             [kernel.kallsyms]           [k] tcp_recvmsg
   3.59%  juke             [kernel.kallsyms]           [k] __fget
   3.31%  juke             [kernel.kallsyms]           [k] inet_recvmsg
   3.22%  juke             [kernel.kallsyms]           [k] seccomp_run_filters
   3.10%  juke             [kernel.kallsyms]           [k] aa_profile_af_perm
   3.05%  juke             [kernel.kallsyms]           [k] aa_label_sk_perm
   2.27%  juke             [kernel.kallsyms]           [k] aa_sk_perm
   1.94%  juke             [kernel.kallsyms]           [k] __sys_recvfrom
   1.75%  juke             [kernel.kallsyms]           [k] tcp_release_cb
   1.74%  juke             [kernel.kallsyms]           [k] __local_bh_enable_ip
   1.74%  juke             [kernel.kallsyms]           [k] syscall_trace_enter
   1.74%  juke             [kernel.kallsyms]           [k] __x64_sys_recvfrom
   1.63%  juke             libpthread-2.23.so          [.] __pthread_enable_asynccancel
   1.54%  juke             [kernel.kallsyms]           [k] release_sock
   1.44%  juke             [kernel.kallsyms]           [k] __seccomp_filter
   1.34%  juke             libpthread-2.23.so          [.] __pthread_disable_asynccancel
   1.31%  juke             juke                        [.] _ZN88_$LT$tiny_http..util..sequential..SequentialReader$LT$R$GT$$u20$as$u20$std..io..Read$GT$4read17h1ab62509f0eccd24E
   1.23%  juke             juke                        [.] _ZN71_$LT$std..io..buffered..BufReader$LT$R$GT$$u20$as$u20$std..io..Read$GT$4read17he719b00617f471fdE
   1.18%  juke             juke                        [.] _ZN91_$LT$rouille..websocket..websocket..Websocket$u20$as$u20$core..iter..iterator..Iterator$GT$4next17h0096bf051fcbfa61E
   1.09%  juke             [kernel.kallsyms]           [k] import_single_range
   0.98%  juke             [kernel.kallsyms]           [k] aa_label_next_confined
   0.94%  juke             [kernel.kallsyms]           [k] sock_recvmsg
   0.76%  juke             [kernel.kallsyms]           [k] apparmor_socket_recvmsg
   0.75%  juke             [kernel.kallsyms]           [k] _raw_spin_lock_bh
   0.70%  juke             [kernel.kallsyms]           [k] __fget_light
   0.63%  juke             [kernel.kallsyms]           [k] __indirect_thunk_start
   0.61%  juke             [kernel.kallsyms]           [k] rcu_all_qs
   0.55%  juke             juke                        [.] _ZN96_$LT$tiny_http..util..custom_stream..CustomStream$LT$R$C$$u20$W$GT$$u20$as$u20$std..io..Read$GT$4read17h4875891095ddc7f7E
   0.50%  juke             [kernel.kallsyms]           [k] security_socket_recvmsg
   0.44%  juke             [kernel.kallsyms]           [k] _raw_spin_unlock_bh

.. и если я присоединяю к нему gdb, есть несколько потоков (около 15?), Которые делают это: 

#0  0x00007f41cf58087f in recv () from target:/lib/x86_64-linux-gnu/libpthread.so.0
#1  0x00005598b9ef49ba in recv_with_flags () at src/libstd/sys/unix/net.rs:228
#2  read () at src/libstd/sys/unix/net.rs:237
#3  read () at src/libstd/sys_common/net.rs:255
#4  read () at src/libstd/net/tcp.rs:570
#5  0x00005598b9c3d6dc in <std::io::buffered::BufReader<R> as std::io::Read>::read ()
#6  0x00005598b9c30441 in <tiny_http::util::sequential::SequentialReader<R> as std::io::Read>::read ()
#7  0x00005598b9be94c2 in <tiny_http::util::custom_stream::CustomStream<R, W> as std::io::Read>::read ()
#8  0x00005598b9c0caad in <rouille::websocket::websocket::Websocket as core::iter::traits::iterator::Iterator>::next ()
#9  0x00005598b9bcf839 in juke::web::websocket_handling_thread ()
#10 0x00005598b9bc67b4 in std::sys_common::backtrace::__rust_begin_short_backtrace ()
#11 0x00005598b9bb109c in std::panicking::try::do_call ()
#12 0x00005598b9f0113a in __rust_maybe_catch_panic () at src/libpanic_unwind/lib.rs:87
#13 0x00005598b9bba0b0 in <F as alloc::boxed::FnBox<A>>::call_box ()
#14 0x00005598b9f004ce in call_once<(),()> () at /rustc/fc50f328b0353b285421b8ff5d4100966387a997/src/liballoc/boxed.rs:759
#15 start_thread () at src/libstd/sys_common/thread.rs:14
#16 thread_start () at src/libstd/sys/unix/thread.rs:81
#17 0x00007f41cf5776ba in start_thread () from target:/lib/x86_64-linux-gnu/libpthread.so.0
#18 0x00007f41cf09741d in clone () from target:/lib/x86_64-linux-gnu/libc.so.6

Эта обратная трассировка указывает на этот раздел в моем коде:

https://github.com/dbr/juke-rs/blob/f845e36402d7106dc4b2262adc165fb3e5f4c123/src/web.rs#L64

fn websocket_handling_thread(
    mut websocket: websocket::Websocket,
    global_status: &Arc<RwLock<PlaybackStatus>>,
    global_queue: &Arc<RwLock<TheList>>,
) {
    // We wait for a new message to come from the websocket.
    while let Some(message) = websocket.next() {

.. вызывается через: 

(GET) (/ws) => {
    let (response, websocket) = try_or_400!(websocket::start(&request, Some("juke")));
    let gs = global_status.clone();
    let gq = global_queue.clone();
    std::thread::spawn(move || {
        let ws = websocket.recv().unwrap();
        websocket_handling_thread(ws, &gs, &gq);
    });
    response
},

Однако все это, похоже, соответствует примерам Руилла - это ошибка в Руилле (или лежащая в основе библиотека tiny_http), или есть что-то очевидное, что я делаю неправильно?

1 Ответ

1 голос
/ 17 мая 2019

Когда @ ecstaticm0rse замечен в комментарии, проблема в Rouille 3.0.0, 

fn next(&mut self) -> Option<Message> {
    loop {
        [...snip...]
        let n = match self.socket.as_mut().unwrap().read(&mut buf) {
            Ok(n) => n,
            Err(ref err) if err.kind() == io::ErrorKind::Interrupted => 0,
            Err(_) => {
                self.socket = None;
                return None;
            },
        };
        [...snip...]
        for element in self.state_machine.feed(&buf[0 .. n]) {
        [...snip...]

Вызов read(...) может вернуть Ok(0) для обозначения EOF, если сокет закрыт (незакрыто через протокол websocket, но на уровне сети, например, устройство теряет соединение)

Так как n установлен в ноль, цикл for element ... в цикле из-за диапазона 0 .. n, а затемснова вызывает read(...), а затем возвращается к вызову read() (который снова возвращает Ok(0), и снова включается)

Воспроизведение ошибки заключалось в использовании клиента websocket, подобного websocat и подключиться к серверу и несколько раз убить клиента с помощью sigint (ctrl + c).

Я сообщил об этой ошибке на трекере проблем Rouille и создал запрос на удаление, чтобы исправить ее,

https://github.com/tomaka/rouille/issues/211

...