-
-
Notifications
You must be signed in to change notification settings - Fork 13
Open
Description
With following code I see an unusal high cpu load (constantly around 5-8%) for a simple server application, which I do not think is acceptable for this kind of application in idle mode.
I experimented with the epoll_wait call and tried passing -1 instead of 0 for the last argument with leads to the expected behaviour of epoll'ling. But then all the other nodepp relevant parts like timers or even information about connection closing do not arrive at the application logic.
Perhaps I am doing something wrong or is this by design?
server code:
#include <nodepp/tcp.h>
#include <nodepp/json.h>
#include <nodepp/timer.h>
#include <apify/apify.h>
using namespace nodepp;
void onMain() {
using socket = socket_t;
auto server = tcp::server();
auto app = apify::add<socket>();
// Logging Middleware executes before any subsequent route logic
auto logger_middleware = [=]( apify_t<socket> cli, function_t<void> next ) {
console::log("[LOG]", cli.method, "\"", cli.path, "\"", " \"", cli.message, "\"");
next();
};
app.add( logger_middleware );
app.on("PINGREQ",nullptr,[=]( apify_t<socket> cli ){
cli.emit( cli.method, cli.path, cli.message );
});
app.on("PINGACK",nullptr,[=]( apify_t<socket> cli ){
cli.done();
});
app.on("AUTH", "/login", [=]( apify_t<socket> cli ) {
console::log("-> Login message received:", cli.message);
cli.emit("SUCCESS", nullptr, "Authentication successful.");
});
app.on("GET", "/user/:id", [=]( apify_t<socket> cli ) {
string_t user_id = cli.params["id"];
console::log("-> Request for user:", user_id);
const object_t ppt({ {"id", user_id} });
cli.emit("USER_DATA", nullptr, json::stringify(ppt));
});
app.on(nullptr, nullptr, [=]( apify_t<socket> cli ) {
console::warning("-> Unmatched Route:", cli.method, cli.path);
cli.emit("ERROR", nullptr, "Route or Method not supported.");
});
server.onConnect([=]( socket cli ){
console::log("connected", cli.get_peername() );
cli.set_timeout(0);
ptr_t<ulong> last_ping = new ulong(process::millis());
cli.onData([=]( string_t data ){
console::log("data: ", data );
*last_ping = process::millis();
app.next(cli, data);
});
cli.onDrain.once([=](){
console::log("closed", cli.get_peername());
});
timer::add( [=]() -> int {
if(cli.is_closed()) {
console::log("client disconnected");
return -1;
}
if((process::millis() - *last_ping) < 5000){
return 1;
}
if((process::millis() - *last_ping) < 10000){
auto app_cli = apify::add( cli );
app_cli.emit("PINGREQ", nullptr, nullptr);
return 1;
}
console::log("client timed out");
cli.close();
return -1;
}, 1000 );
stream::pipe( cli );
});
server.listen("localhost", 8000,[=](socket){
console::log( "tcp://localhost:8000");
});
console::log( "Started" );
}
client code:
#include <nodepp/nodepp.h>
#include <nodepp/tcp.h>
#include <nodepp/timer.h>
#include <apify/apify.h>
using namespace nodepp;
namespace dummy {
// inline tcp_t client( const string_t& uri, uint port, agent_t* opt = nullptr ){
inline tcp_t client( agent_t* opt = nullptr ){
tcp_t skt ( nullptr, opt );
// skt.onSocket.once([=]( socket_t cli ){
// // auto hrv = type::cast<http_t> (cli);
// // if( !generator::ws::client( hrv, uri ) )
// // { skt.onConnect.skip(); return; }
// process::add([=](){
// skt.onConnect.resume( );
// skt.onConnect.emit(cli);
// return -1;
// });
// });
skt.onConnect.once([=]( socket_t cli ){
cli.onDrain.once([=](){ cli.free(); });
cli.set_timeout(0);
cli.resume();
stream::pipe(cli);
});
// skt.connect( uri, port );
// skt.connect( url::hostname(uri), url::port(uri) );
return skt;
}
}
void onMain() {
using socket = socket_t;
auto client = dummy::client();
auto app = apify::add<socket>();
// Logging Middleware executes before any subsequent route logic
auto logger_middleware = [=]( apify_t<socket> cli, function_t<void> next ) {
console::log("[LOG]", cli.method, "\"", cli.path, "\"", " \"", cli.message, "\"");
next();
};
app.add( logger_middleware );
app.on("PINGREQ",nullptr,[=]( apify_t<socket> cli ){
cli.emit( "PINGACK", nullptr, nullptr );
});
app.on("SUCCESS", nullptr, [=]( apify_t<socket> res ) {
console::done("Login Successful:", res.message );
res.done();
});
app.on("USER_DATA", nullptr, [=]( apify_t<socket> res ) {
console::done("user data:", res.message );
res.done();
});
app.on("ERROR", nullptr, [=]( apify_t<socket> res ) {
console::error("Error:", res.message );
res.done();
});
app.on(nullptr, nullptr, [=]( apify_t<socket> cli ) {
console::warning("-> Unmatched Route:", cli.method, cli.path );
});
client.onConnect([=]( socket cli ){
cli.onData([=]( string_t data ){
// console::log("data: ", data );
app.next( cli, data );
});
cli.onDrain.once([=](){
console::log("closed", cli.get_peername());
});
auto app_cli = apify::add( cli );
app_cli.emit("AUTH", "/login", "user:pass");
app_cli.emit("GET", "/user/16", "fetch");
timer::add( [=]() -> int {
console::log("client forced shutdown");
cli.close();
return -1;
}, 100 );
});
client.connect( "localhost", 8000, []( socket_t cli ){
console::log("-> tcp://localhost:8000");
});
console::log( "Started" );
}
strace ./server (added process::delay(500) before if((obj->len=epoll_wait( obj->pd, &obj->ev, obj->ev.size(), 0 ))<=0 ) in posix/epoll.h for better readability)
write(1, "Started \n\33[0m", 13Started
) = 13
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
socket(AF_INET, SOCK_STREAM, IPPROTO_TCP) = 4
setsockopt(4, SOL_SOCKET, SO_SNDBUF, [65536], 4) = 0
setsockopt(4, SOL_SOCKET, SO_RCVBUF, [65536], 4) = 0
fcntl(4, F_GETFL) = 0x2 (flags O_RDWR)
fcntl(4, F_SETFL, O_RDWR|O_NONBLOCK) = 0
setsockopt(4, SOL_IPV6, IPV6_V6ONLY, [0], 4) = -1 ENOPROTOOPT (Protocol not available)
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_SNDBUF, [65536], 4) = 0
setsockopt(4, SOL_SOCKET, SO_RCVBUF, [65536], 4) = 0
brk(0x56314f625000) = 0x56314f625000
setsockopt(4, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(4, SOL_SOCKET, SO_KEEPALIVE, [0], 4) = 0
setsockopt(4, SOL_SOCKET, SO_BROADCAST, [0], 4) = 0
bind(4, {sa_family=AF_INET, sin_port=htons(8000), sin_addr=inet_addr("127.0.0.1")}, 16) = 0
prlimit64(0, RLIMIT_NOFILE, NULL, {rlim_cur=1024, rlim_max=512*1024}) = 0
listen(4, 1024) = 0
write(1, "tcp://localhost:8000 \n\33[0m", 26tcp://localhost:8000
) = 26
epoll_ctl(3, EPOLL_CTL_ADD, 4, {events=EPOLLIN, data=0x56314f5e3c80}) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [], 1024, 0) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [], 1024, 0) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [], 1024, 0) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [], 1024, 0) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [], 1024, 0) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [{events=EPOLLIN, data=0x56314f5e3c80}], 1024, 0) = 1
accept(4, {sa_family=AF_INET, sin_port=htons(36212), sin_addr=inet_addr("127.0.0.1")}, [16]) = 5
fcntl(5, F_GETFL) = 0x2 (flags O_RDWR)
fcntl(5, F_SETFL, O_RDWR|O_NONBLOCK) = 0
setsockopt(5, SOL_SOCKET, SO_REUSEADDR, [1], 4) = 0
setsockopt(5, SOL_SOCKET, SO_SNDBUF, [65536], 4) = 0
setsockopt(5, SOL_SOCKET, SO_RCVBUF, [65536], 4) = 0
setsockopt(5, SOL_SOCKET, SO_REUSEPORT, [1], 4) = 0
setsockopt(5, SOL_SOCKET, SO_KEEPALIVE, [0], 4) = 0
setsockopt(5, SOL_SOCKET, SO_BROADCAST, [0], 4) = 0
getpeername(5, 0x7fff79a1f468, [0 => 16]) = 0
write(1, "connected 0.0.0.0\0\0\0\0\0\0\0\0 \n\33[0m", 31connected 0.0.0.0
) = 31
recvfrom(5, "QVVUSA==.L2xvZ2lu.dXNlcjpwYXNz.R"..., 65536, 0, NULL, NULL) = 58
write(1, "data: QVVUSA==.L2xvZ2lu.dXNlcjp"..., 71data: QVVUSA==.L2xvZ2lu.dXNlcjpwYXNz.R0VU.L3VzZXIvMTY=.ZmV0Y2g=.
) = 71
write(1, "[LOG] AUTH \" /login \" \" user:p"..., 43[LOG] AUTH " /login " " user:pass "
) = 43
write(1, "-> Login message received: user:"..., 42-> Login message received: user:pass
) = 42
sendto(5, "U1VDQ0VTUw==..QXV0aGVudGljYXRpb2"..., 51, 0, NULL, 0) = 51
write(1, "[LOG] GET \" /user/16 \" \" fetch"..., 40[LOG] GET " /user/16 " " fetch "
) = 40
write(1, "-> Request for user: 16 \n\33[0m", 29-> Request for user: 16
) = 29
sendto(5, "VVNFUl9EQVRB..eyJpZCI6IjE2In0=.", 31, 0, NULL, 0) = 31
recvfrom(5, 0x56314f6141f0, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
accept(4, 0x56314f5e4098, [16]) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(5, 0x56314f6141f0, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(5, 0x56314f6141f0, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [], 1024, 0) = 0
recvfrom(5, 0x56314f6141f0, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [], 1024, 0) = 0
recvfrom(5, "", 65536, 0, NULL, NULL) = 0
getpeername(5, {sa_family=AF_INET, sin_port=htons(36212), sin_addr=inet_addr("127.0.0.1")}, [16]) = 0
write(1, "closed 127.0.0.1\0\0\0\0\0\0 \n\33[0m", 28closed 127.0.0.1
) = 28
shutdown(5, SHUT_RDWR) = 0
close(5) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [], 1024, 0) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [], 1024, 0) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [], 1024, 0) = 0
write(1, "client disconnected \n\33[0m", 25client disconnected
) = 25
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [], 1024, 0) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [], 1024, 0) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [], 1024, 0) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}, NULL) = 0
epoll_wait(3, [], 1024, 0) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=500000000}^Cstrace: Process 541056 detached
<detached ...>
SIGINT: Signal Interrupt
strace ./client
[...]
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=1000000}, NULL) = 0
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
recvfrom(4, 0x565142fa4270, 65536, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
write(1, "client forced shutdown \n\33[0m", 28client forced shutdown
) = 28
shutdown(4, SHUT_RDWR) = 0
close(4) = 0
getpeername(4, 0x7ffd57ef2248, [16]) = -1 EBADF (Bad file descriptor)
write(1, "closed 127.0.0.1 \n\33[0m", 22closed 127.0.0.1
) = 22
brk(0x565142fc5000) = 0x565142fc5000
close(3) = 0
exit_group(0) = ?
+++ exited with 0 +++
EDBCREPO
Metadata
Metadata
Assignees
Labels
No labels