From c0e376e15a3465dce82c565499bc90751ec40b50 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Adrien=20B=C3=A9raud?= Date: Fri, 28 Dec 2018 01:41:10 -0500 Subject: [PATCH] dht: reduce log verbosity --- include/opendht/network_engine.h | 2 ++ src/dht.cpp | 27 ++++++++------------------- src/network_engine.cpp | 27 +++++++++++++++++---------- 3 files changed, 27 insertions(+), 29 deletions(-) diff --git a/include/opendht/network_engine.h b/include/opendht/network_engine.h index 06ec41be..1ab0b010 100644 --- a/include/opendht/network_engine.h +++ b/include/opendht/network_engine.h @@ -531,6 +531,8 @@ private: std::set blacklist {}; Scheduler& scheduler; + + bool logIncoming_ {false}; }; } /* namespace net */ diff --git a/src/dht.cpp b/src/dht.cpp index 9e455096..b8451197 100644 --- a/src/dht.cpp +++ b/src/dht.cpp @@ -282,7 +282,7 @@ void Dht::paginate(std::weak_ptr ws, Sp query, SearchNode* n) { if (vid == Value::INVALID_ID) continue; auto query_for_vid = std::make_shared(Select {}, Where {}.id(vid)); sn->pagination_queries[query].push_back(query_for_vid); - DHT_LOG.w(id, sn->node->id, "[search %s] [node %s] sending %s", + DHT_LOG.d(id, sn->node->id, "[search %s] [node %s] sending %s", id.toString().c_str(), sn->node->toString().c_str(), query_for_vid->toString().c_str()); sn->getStatus[query_for_vid] = network_engine.sendGetValues(status.node, id, @@ -301,7 +301,7 @@ void Dht::paginate(std::weak_ptr ws, Sp query, SearchNode* n) { /* add pagination query key for tracking ongoing requests. */ n->pagination_queries[query].push_back(select_q); - DHT_LOG.w(sr->id, n->node->id, "[search %s] [node %s] sending %s", + DHT_LOG.d(sr->id, n->node->id, "[search %s] [node %s] sending %s", sr->id.toString().c_str(), n->node->toString().c_str(), select_q->toString().c_str()); n->getStatus[select_q] = network_engine.sendGetValues(n->node, sr->id, @@ -435,7 +435,7 @@ void Dht::searchSendAnnounceValue(const Sp& sr) { auto next_refresh_time = now + getType(a.value->type).expiration; /* only put the value if the node doesn't already have it */ if (not hasValue or seq_no < a.value->seq) { - DHT_LOG.w(sr->id, sn->node->id, "[search %s] [node %s] sending 'put' (vid: %d)", + DHT_LOG.d(sr->id, sn->node->id, "[search %s] [node %s] sending 'put' (vid: %d)", sr->id.toString().c_str(), sn->node->toString().c_str(), a.value->id); sn->acked[a.value->id] = std::make_pair(network_engine.sendAnnounceValue(sn->node, sr->id, @@ -503,7 +503,7 @@ void Dht::searchSendAnnounceValue(const Sp& sr) { if (sendQuery) { if (not probe_query) probe_query = std::make_shared(Select {}.field(Value::Field::Id).field(Value::Field::SeqNum)); - DHT_LOG.w(sr->id, n.node->id, "[search %s] [node %s] sending %s", + DHT_LOG.d(sr->id, n.node->id, "[search %s] [node %s] sending %s", sr->id.toString().c_str(), n.node->toString().c_str(), probe_query->toString().c_str()); n.probe_query = probe_query; n.getStatus[probe_query] = network_engine.sendGetValues(n.node, @@ -598,9 +598,9 @@ Dht::searchStep(Sp sr) if (not sr or sr->expired or sr->done) return; const auto& now = scheduler.time(); - if (auto req_count = sr->currentlySolicitedNodeCount()) + /*if (auto req_count = sr->currentlySolicitedNodeCount()) DHT_LOG.d(sr->id, "[search %s IPv%c] step (%d requests)", - sr->id.toString().c_str(), sr->af == AF_INET ? '4' : '6', req_count); + sr->id.toString().c_str(), sr->af == AF_INET ? '4' : '6', req_count);*/ sr->step_time = now; if (sr->refill_time + Node::NODE_EXPIRE_TIME < now and sr->nodes.size()-sr->getNumberOfBadNodes() < SEARCH_NODES) @@ -659,18 +659,7 @@ Dht::searchStep(Sp sr) sr->setDone(); } - if (sr->currentlySolicitedNodeCount() < MAX_REQUESTED_SEARCH_NODES) { - unsigned i = 0; - SearchNode* sent; - do { - sent = searchSendGetValues(sr); - if (sent and not sent->candidate) - i++; - } - while (sent and sr->currentlySolicitedNodeCount() < MAX_REQUESTED_SEARCH_NODES); - /*DHT_LOG_DBG("[search %s IPv%c] step: sent %u requests (total %u).", - sr->id.toString().c_str(), sr->af == AF_INET ? '4' : '6', i, sr->currentlySolicitedNodeCount());*/ - } + while (sr->currentlySolicitedNodeCount() < MAX_REQUESTED_SEARCH_NODES and searchSendGetValues(sr)); if (sr->getNumberOfConsecutiveBadNodes() >= std::min(sr->nodes.size(), static_cast(SEARCH_MAX_BAD_NODES))) @@ -2359,7 +2348,7 @@ Dht::onAnnounce(Sp n, // Allow the value to be edited by the storage policy const auto& type = getType(vc->type); if (type.storePolicy(hash, vc, node.id, node.getAddr())) { - DHT_LOG.d(hash, node.id, "[store %s] storing %s", hash.toString().c_str(), vc->toString().c_str()); + //DHT_LOG.d(hash, node.id, "[store %s] storing %s", hash.toString().c_str(), std::to_string(vc->id).c_str()); storageStore(hash, vc, created, node.getAddr()); } else { DHT_LOG.d(hash, node.id, "[store %s] rejecting storage of %s", diff --git a/src/network_engine.cpp b/src/network_engine.cpp index 8e480fa9..0ff7d7c4 100644 --- a/src/network_engine.cpp +++ b/src/network_engine.cpp @@ -434,7 +434,8 @@ NetworkEngine::processMessage(const uint8_t *buf, size_t buflen, const SockAddr& if (msg->type == MessageType::ValueData) { auto pmsg_it = partial_messages.find(msg->tid); if (pmsg_it == partial_messages.end()) { - DHT_LOG.d("Can't find partial message"); + if (logIncoming_) + DHT_LOG.d("Can't find partial message"); rateLimit(from); return; } @@ -544,19 +545,21 @@ NetworkEngine::process(std::unique_ptr&& msg, const SockAddr& fro req->reply_time = time_point::min(); onError(req, DhtProtocolException {msg->error_code}); } else { - DHT_LOG.w(msg->id, "[node %s %s] received unknown error message %u", + if (logIncoming_) + DHT_LOG.w(msg->id, "[node %s %s] received unknown error message %u", msg->id.toString().c_str(), from.toString().c_str(), msg->error_code); } break; } case MessageType::Reply: if (req) { /* request reply */ - if (req->getType() == MessageType::AnnounceValue or req->getType() == MessageType::Listen) - req->node->authSuccess(); - req->reply_time = scheduler.time(); + auto& r = *req; + if (r.getType() == MessageType::AnnounceValue or r.getType() == MessageType::Listen) + r.node->authSuccess(); + r.reply_time = scheduler.time(); deserializeNodes(*msg, from); - req->setDone(std::move(*msg)); + r.setDone(std::move(*msg)); break; } else { /* request socket data */ deserializeNodes(*msg, from); @@ -574,7 +577,8 @@ NetworkEngine::process(std::unique_ptr&& msg, const SockAddr& fro switch (msg->type) { case MessageType::Ping: ++in_stats.ping; - DHT_LOG.d(node->id, "[node %s] sending pong", node->toString().c_str()); + if (logIncoming_) + DHT_LOG.d(node->id, "[node %s] sending pong", node->toString().c_str()); onPing(node); sendPong(from, msg->tid); break; @@ -595,7 +599,8 @@ NetworkEngine::process(std::unique_ptr&& msg, const SockAddr& fro break; } case MessageType::AnnounceValue: { - DHT_LOG.d(msg->info_hash, node->id, "[node %s] got 'put' request for %s", node->toString().c_str(), msg->info_hash.toString().c_str()); + if (logIncoming_) + DHT_LOG.d(msg->info_hash, node->id, "[node %s] got 'put' request for %s", node->toString().c_str(), msg->info_hash.toString().c_str()); ++in_stats.put; onAnnounce(node, msg->info_hash, msg->token, msg->values, msg->created); @@ -608,13 +613,15 @@ NetworkEngine::process(std::unique_ptr&& msg, const SockAddr& fro break; } case MessageType::Refresh: - DHT_LOG.d(msg->info_hash, node->id, "[node %s] got 'refresh' request for %s", node->toString().c_str(), msg->info_hash.toString().c_str()); + if (logIncoming_) + DHT_LOG.d(msg->info_hash, node->id, "[node %s] got 'refresh' request for %s", node->toString().c_str(), msg->info_hash.toString().c_str()); onRefresh(node, msg->info_hash, msg->token, msg->value_id); /* Same note as above in MessageType::AnnounceValue applies. */ sendValueAnnounced(from, msg->tid, msg->value_id); break; case MessageType::Listen: { - DHT_LOG.d(msg->info_hash, node->id, "[node %s] got 'listen' request for %s", node->toString().c_str(), msg->info_hash.toString().c_str()); + if (logIncoming_) + DHT_LOG.d(msg->info_hash, node->id, "[node %s] got 'listen' request for %s", node->toString().c_str(), msg->info_hash.toString().c_str()); ++in_stats.listen; RequestAnswer answer = onListen(node, msg->info_hash, msg->token, msg->socket_id, std::move(msg->query)); auto nnodes = bufferNodes(from.getFamily(), msg->info_hash, msg->want, answer.nodes4, answer.nodes6);