diff --git a/src/host/main.cpp b/src/host/main.cpp index 925fcbe20d61..f6eae847a803 100644 --- a/src/host/main.cpp +++ b/src/host/main.cpp @@ -48,8 +48,12 @@ using namespace std::chrono_literals; using ResolvedAddresses = std:: map; -size_t asynchost::TCPImpl::remaining_read_quota; -size_t asynchost::UDPImpl::remaining_read_quota; +size_t asynchost::TCPImpl::remaining_read_quota = + asynchost::TCPImpl::max_read_quota; +bool asynchost::TCPImpl::alloc_quota_logged = false; + +size_t asynchost::UDPImpl::remaining_read_quota = + asynchost::UDPImpl::max_read_quota; std::chrono::microseconds asynchost::TimeBoundLogger::default_max_time(10'000); diff --git a/src/host/tcp.h b/src/host/tcp.h index 18cf169dcafc..0f0fbf92fc56 100644 --- a/src/host/tcp.h +++ b/src/host/tcp.h @@ -29,6 +29,7 @@ namespace asynchost // Each uv iteration, read only a capped amount from all sockets. static constexpr auto max_read_quota = max_read_size * 4; static size_t remaining_read_quota; + static bool alloc_quota_logged; enum Status { @@ -127,6 +128,7 @@ namespace asynchost static void reset_read_quota() { remaining_read_quota = max_read_quota; + alloc_quota_logged = false; } void set_behaviour(std::unique_ptr> b) @@ -743,10 +745,13 @@ namespace asynchost alloc_size = std::min(alloc_size, remaining_read_quota); remaining_read_quota -= alloc_size; - LOG_TRACE_FMT( - "Allocating {} bytes for TCP read ({} of quota remaining)", - alloc_size, - remaining_read_quota); + if (alloc_size != 0) + { + LOG_TRACE_FMT( + "Allocating {} bytes for TCP read ({} of quota remaining)", + alloc_size, + remaining_read_quota); + } buf->base = new char[alloc_size]; buf->len = alloc_size; @@ -772,7 +777,11 @@ namespace asynchost if (sz == UV_ENOBUFS) { - LOG_DEBUG_FMT("TCP on_read reached allocation quota"); + if (!alloc_quota_logged) + { + LOG_DEBUG_FMT("TCP on_read reached allocation quota"); + alloc_quota_logged = true; + } on_free(buf); return; } diff --git a/tests/fuzzing.py b/tests/fuzzing.py index afb63c1d7007..887ed8891c51 100644 --- a/tests/fuzzing.py +++ b/tests/fuzzing.py @@ -14,6 +14,7 @@ def __init__(self, print_period=datetime.timedelta(seconds=3), keep_lines=50): self.print_period = print_period self.last_printed = None self.keep_lines = keep_lines + self.last_fuzzed_count = 0 self.session = None @@ -24,10 +25,15 @@ def _store_line(self, s): if self.session is not None: now = datetime.datetime.now() if self.last_printed is None or now - self.last_printed > self.print_period: + fuzzed_this_period = ( + self.session.num_cases_actually_fuzzed - self.last_fuzzed_count + ) + fuzzing_rate = fuzzed_this_period / self.print_period.seconds LOG.info( - f"Fuzzed {self.session.num_cases_actually_fuzzed} total cases in {self.session.runtime:.2f}s (rate={self.session.exec_speed:.2f}/s)" + f"Fuzzed {self.session.num_cases_actually_fuzzed} total cases in {self.session.runtime:.2f}s (current rate={fuzzing_rate:.2f}/s)" ) self.last_printed = now + self.last_fuzzed_count = self.session.num_cases_actually_fuzzed def open_test_case(self, test_case_id, name, index, *args, **kwargs): self._store_line(f"Test case: {name} ({index=})") @@ -149,6 +155,7 @@ def fuzz_node_to_node(network, args): ) fuzz_logger.session = session + LOG.info(f"Loggers before monkey-patch: {session._fuzz_data_logger._fuzz_loggers}") # Monkey-patch: Remove any Db loggers from the boofuzz session. We never # use them, and they're reliant on disk IO (for db commits) so sometimes very slow session._fuzz_data_logger._fuzz_loggers = [ @@ -156,6 +163,8 @@ def fuzz_node_to_node(network, args): for logger in session._fuzz_data_logger._fuzz_loggers if not isinstance(logger, boofuzz.fuzz_logger_db.FuzzLoggerDb) ] + session._db_logger = None + LOG.info(f"Loggers after monkey-patch: {session._fuzz_data_logger._fuzz_loggers}") session.connect(req)