diff --git a/apps/EchoClient.cpp b/apps/EchoClient.cpp index 43dc49f35ee927cf833b895e529b64de57f08ab5..d42302355a46ae5680483f75afe17a05a4300064 100644 --- a/apps/EchoClient.cpp +++ b/apps/EchoClient.cpp @@ -19,6 +19,7 @@ #include <iostream> // for operator<<, basic_ostream, endl #include <string> // for allocator, string, char_traits #include <thread> +#include <utility> #include "Common.hpp" // for DIE_MSG_ERRNO, DIE_MSG, unli... #include "CountingPrivateSemaphore.hpp" // for CPS @@ -29,12 +30,15 @@ #include "emper.hpp" // for spawn #include "io.hpp" // for connectAndWait #include "io/Future.hpp" // for CloseFuture, RecvFuture, Sen... +#include "lib/math.hpp" using emper::Semaphore; using emper::io::CloseFuture; using emper::io::RecvFuture; using emper::io::SendFuture; +using emper::lib::math::RunningAverage; + using std::chrono::duration_cast; using std::chrono::high_resolution_clock; using std::chrono::nanoseconds; @@ -49,6 +53,8 @@ const size_t CLIENTS = 10000; const size_t SIZE = 32; const size_t SERVER_BACKLOG = 1024; +const seconds ONERROR_SLEEP(10); + // Globals std::string host = HOST; std::string port = PORT; @@ -66,6 +72,7 @@ std::atomic<size_t> client_ids = 0; struct ClientResult { size_t iterations; size_t avg_ns; + size_t unexpectedEchos; }; using ClientResult = struct ClientResult; @@ -73,14 +80,15 @@ struct ClientResult* clientResults; struct addrinfo* server; -static auto clientIteration(SendFuture& sendFuture, RecvFuture& recvFuture) -> nanoseconds { +static auto clientIteration(SendFuture& sendFuture, RecvFuture& recvFuture) + -> std::pair<nanoseconds, std::string> { + nanoseconds duration(0); auto send_start = high_resolution_clock::now(); int32_t bytes_send = sendFuture.submitAndWait(); auto send_end = high_resolution_clock::now(); if (bytes_send < 0) { - errno = -bytes_send; - DIE_MSG_ERRNO("send failed"); + return {duration, EMPER_BUILD_STR("send failed: " << strerror(-bytes_send))}; } auto recv_start = high_resolution_clock::now(); @@ -88,14 +96,16 @@ static auto clientIteration(SendFuture& sendFuture, RecvFuture& recvFuture) -> n auto recv_end = high_resolution_clock::now(); if (bytes_recv < 0) { - errno = -bytes_recv; - DIE_MSG_ERRNO("recv failed"); + return {duration, EMPER_BUILD_STR("recv failed: " << strerror(-bytes_recv))}; } - return duration_cast<nanoseconds>((send_end - send_start) + (recv_end - recv_start)); + duration = duration_cast<nanoseconds>((send_end - send_start) + (recv_end - recv_start)); + return {duration, ""}; } -static auto clientIterationLinked(SendFuture& sendFuture, RecvFuture& recvFuture) -> nanoseconds { +static auto clientIterationLinked(SendFuture& sendFuture, RecvFuture& recvFuture) + -> std::pair<nanoseconds, std::string> { + nanoseconds duration(0); recvFuture.setDependency(sendFuture); auto start = high_resolution_clock::now(); @@ -106,25 +116,24 @@ static auto clientIterationLinked(SendFuture& sendFuture, RecvFuture& recvFuture // recv failed if (res != -ECANCELED) { if (res == 0) { - DIE_MSG("server closed the connection"); + return {duration, "server closed the connection"}; } - errno = -res; - DIE_MSG_ERRNO("receive failed"); + return {duration, EMPER_BUILD_STR("receive failed: " << strerror(-res))}; } // send failed int32_t send_res = sendFuture.wait(); if (send_res < 0) { - errno = -send_res; - DIE_MSG_ERRNO("send failed"); + return {duration, EMPER_BUILD_STR("send failed: " << strerror(-send_res))}; } // send must send less than expected because recvFuture returned -ECANCELED - DIE_MSG("short send" << send_res); + return {duration, EMPER_BUILD_STR("short send: " << send_res)}; } - return duration_cast<nanoseconds>(end - start); + duration = duration_cast<nanoseconds>(end - start); + return {duration, ""}; } static void clientFunc(uint64_t client_id, Semaphore& readySem, Semaphore& startSem, CPS& cps) { @@ -151,7 +160,7 @@ static void clientFunc(uint64_t client_id, Semaphore& readySem, Semaphore& start auto* outBuf = new char[size]; auto* inBuf = new char[size]; - uint64_t avg_ns = 0; + RunningAverage avg_ns; readySem.release(); startSem.acquire(); @@ -161,22 +170,24 @@ static void clientFunc(uint64_t client_id, Semaphore& readySem, Semaphore& start SendFuture sendFuture(client_sock, outBuf, size, MSG_NOSIGNAL); RecvFuture recvFuture(client_sock, inBuf, size, MSG_WAITALL); - nanoseconds duration; + std::pair<nanoseconds, std::string> res; if (linked_futures) { - duration = clientIterationLinked(sendFuture, recvFuture); + res = clientIterationLinked(sendFuture, recvFuture); } else { - duration = clientIteration(sendFuture, recvFuture); + res = clientIteration(sendFuture, recvFuture); } - // TODO: replace with emper::math::RunningAverage when !127 is merged - uint64_t ns = duration.count(); - if (unlikely(avg_ns == 0)) { - avg_ns = ns; - } else { - avg_ns += ns; - avg_ns /= 2; + auto& duration = res.first; + auto& err = res.second; + + if (!err.empty()) { + LOGE("Client failed at iteration " << i << " with " << err); + std::this_thread::sleep_for(ONERROR_SLEEP); + DIE; } + avg_ns.update(duration.count()); + if (memcmp(outBuf, inBuf, size) != 0) { std::stringstream sst; sst << "got unexpected echo from server" << std::endl; @@ -192,8 +203,8 @@ static void clientFunc(uint64_t client_id, Semaphore& readySem, Semaphore& start sst << (unsigned)inBuf[i] << " "; } sst << std::endl; - std::cerr << sst.str(); - DIE; + LOGE(sst.str()); + clientResults[client_id].unexpectedEchos++; } i++; @@ -212,7 +223,7 @@ static void clientFunc(uint64_t client_id, Semaphore& readySem, Semaphore& start cf.wait(); - clientResults[client_id].avg_ns = avg_ns; + clientResults[client_id].avg_ns = avg_ns.getCounter(); clientResults[client_id].iterations = i; } @@ -352,16 +363,14 @@ auto main(int argc, char* argv[]) -> int { auto echo_end = high_resolution_clock::now(); - uint64_t avg_ns = clientResults[0].avg_ns; - uint64_t avg_iterations = clientResults[0].iterations; + RunningAverage avg_ns; + RunningAverage avg_iterations; + RunningAverage avg_unexpectedEchos; uint64_t total_iterations = 0; - for (size_t i = 1; i < clients; ++i) { - avg_ns += clientResults[i].avg_ns; - avg_ns /= 2; - - avg_iterations += clientResults[i].iterations; - avg_iterations /= 2; - + for (size_t i = 0; i < clients; ++i) { + avg_ns.update(clientResults[i].avg_ns); + avg_iterations.update(clientResults[i].iterations); + avg_unexpectedEchos.update(clientResults[i].unexpectedEchos); total_iterations += clientResults[i].iterations; } @@ -369,7 +378,6 @@ auto main(int argc, char* argv[]) -> int { auto echo_duration = duration_cast<nanoseconds>(echo_end - echo_start).count(); auto total_duration = duration_cast<nanoseconds>(echo_end - connect_start).count(); - std::stringstream sst; bool exists = true; if (output_file) { exists = access(output_file, W_OK) == 0; @@ -387,12 +395,14 @@ auto main(int argc, char* argv[]) -> int { } } + std::stringstream sst; if (!exists) { - sst << "clients,iterations,total_iterations,size,avg_ns,connect,echo,total" << std::endl; + sst << "clients,iterations,total_iterations,size,avg_ns,unexpected_echos,connect,echo,total" + << std::endl; } - sst << clients << "," << avg_iterations << "," << total_iterations << "," << size << "," - << avg_ns << "," << connect_duration << "," << echo_duration << "," << total_duration - << std::endl; + sst << clients << "," << avg_iterations.getAverage() << "," << total_iterations << "," << size + << "," << avg_ns.getAverage() << "," << avg_unexpectedEchos.getAverage() << "," + << connect_duration << "," << echo_duration << "," << total_duration << std::endl; auto output = sst.str(); if (emper::io::writeFileAndWait(out_fd, output.c_str(), output.size()) < 0) { diff --git a/emper/Debug.hpp b/emper/Debug.hpp index 3b207771e5f20663b0b03586b40253a601b1a33a..7b7a4faeb0030095c59fcb5c3bfd5481b78b8155 100644 --- a/emper/Debug.hpp +++ b/emper/Debug.hpp @@ -18,10 +18,10 @@ // The lamda should be fairly cheap/free because it will be inlined. // The use of a lambda here is the ISO C++ equivalent to GCC statement expressions. // NOLINTNEXTLINE(bugprone-macro-parentheses) -#define EMPER_BUILD_STR(x) [&]() -> std::string {std::stringstream sst; sst << x; return sst.str(); } +#define EMPER_BUILD_STR(x) [&]() -> std::string {std::stringstream sst; sst << x; return sst.str(); }() // NOLINTNEXTLINE(bugprone-macro-parentheses) -#define LOG(level, x, log_func) do { if constexpr (level <= EMPER_LOG_LEVEL) { log_func(EMPER_BUILD_STR(x)()); } } while (false) +#define LOG(level, x, log_func) do { if constexpr (level <= EMPER_LOG_LEVEL) { log_func(EMPER_BUILD_STR(x)); } } while (false) // NOLINTNEXTLINE(bugprone-macro-parentheses) #define DBG(x) LOG(Debug, x, emper_log_no_prefix);