From 9440c030487d0d09ed75eddba849ed3442b1c548 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Adrien=20B=C3=A9raud?= <adrien.beraud@savoirfairelinux.com> Date: Sun, 16 Oct 2016 22:13:12 -0400 Subject: [PATCH] dht: log cleanup --- include/opendht/dht.h | 3 +- include/opendht/network_engine.h | 4 +- src/dht.cpp | 39 +++++++--------- src/network_engine.cpp | 27 ++++------- tools/tools_common.h | 78 +------------------------------- 5 files changed, 30 insertions(+), 121 deletions(-) diff --git a/include/opendht/dht.h b/include/opendht/dht.h index fe3e3ef9..e2768a1d 100644 --- a/include/opendht/dht.h +++ b/include/opendht/dht.h @@ -14,8 +14,7 @@ * GNU General Public License for more details. * * You should have received a copy of the GNU General Public License - * along with this program; if not, write to the Free Software - * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + * along with this program. If not, see <http://www.gnu.org/licenses/>. */ #pragma once diff --git a/include/opendht/network_engine.h b/include/opendht/network_engine.h index a24e7ff7..60f9a3fb 100644 --- a/include/opendht/network_engine.h +++ b/include/opendht/network_engine.h @@ -14,11 +14,9 @@ * GNU General Public License for more details. * * You should have received a copy of the GNU General Public License - * along with this program; if not, write to the Free Software - * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + * along with this program. If not, see <http://www.gnu.org/licenses/>. */ - #pragma once #include "node_cache.h" diff --git a/src/dht.cpp b/src/dht.cpp index 6b719650..49590284 100644 --- a/src/dht.cpp +++ b/src/dht.cpp @@ -14,8 +14,7 @@ * GNU General Public License for more details. * * You should have received a copy of the GNU General Public License - * along with this program; if not, write to the Free Software - * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + * along with this program. If not, see <http://www.gnu.org/licenses/>. */ @@ -769,7 +768,7 @@ Dht::sendCachedPing(Bucket& b) if (!b.cached) return 0; - DHT_LOG.DEBUG("Sending ping to cached node."); + DHT_LOG.DEBUG("[node %s] Sending ping to cached node.", b.cached->toString().c_str()); network_engine.sendPing(b.cached, nullptr, nullptr); b.cached = {}; return 0; @@ -871,7 +870,7 @@ Dht::onNewNode(const std::shared_ptr<Node>& node, int confirm) if (not n->isGood(now)) { dubious = true; if (not n->isPendingMessage()) { - DHT_LOG.DEBUG("Sending ping to dubious node %s.", n->toString().c_str()); + DHT_LOG.DEBUG("[node %s] Sending ping to dubious node.", n->toString().c_str()); network_engine.sendPing(n, nullptr, nullptr); break; } @@ -1162,9 +1161,8 @@ Dht::searchSendGetValues(std::shared_ptr<Search> sr, SearchNode* pn, bool update if (not n) return nullptr; - DHT_LOG.WARN("[search %s IPv%c] [node %s] sending 'find_node'", - sr->id.toString().c_str(), sr->af == AF_INET ? '4' : '6', - n->node->toString().c_str()); + DHT_LOG.WARN("[search %s] [node %s] sending 'find_node'", + sr->id.toString().c_str(), n->node->toString().c_str()); n->getStatus[query] = network_engine.sendFindNode(n->node, sr->id, -1, @@ -1177,9 +1175,8 @@ Dht::searchSendGetValues(std::shared_ptr<Search> sr, SearchNode* pn, bool update if (query and not query->select.getSelection().empty()) { /* The request contains a select. No need to paginate... */ - DHT_LOG.WARN("[search %s IPv%c] [node %s] sending 'get'", - sr->id.toString().c_str(), sr->af == AF_INET ? '4' : '6', - n->node->toString().c_str()); + DHT_LOG.WARN("[search %s] [node %s] sending 'get'", + sr->id.toString().c_str(), n->node->toString().c_str()); n->getStatus[query] = network_engine.sendGetValues(n->node, sr->id, *query, @@ -1351,10 +1348,8 @@ Dht::searchStep(std::shared_ptr<Search> sr) for (const auto& l : sr->listeners) { const auto& query = l.second.query; if (n.getListenTime(query) <= now) { - DHT_LOG.WARN("[search %s IPv%c] [node %s] sending 'listen'", - sr->id.toString().c_str(), sr->af == AF_INET ? '4' : '6', - n.node->toString().c_str()); - //std::cout << "Sending listen to " << n.node->id << " " << print_addr(n.node->ss, n.node->sslen) << std::endl; + DHT_LOG.WARN("[search %s] [node %s] sending 'listen'", + sr->id.toString().c_str(), n.node->toString().c_str()); const auto& r = n.listenStatus.find(query); auto last_req = r != n.listenStatus.end() ? r->second : std::shared_ptr<Request> {}; @@ -2752,7 +2747,7 @@ Dht::bucketMaintenance(RoutingTable& list) want = WANT4 | WANT6; } - DHT_LOG.DEBUG("[find %s IPv%c] sending for bucket maintenance.", id.toString().c_str(), q->af == AF_INET6 ? '6' : '4'); + DHT_LOG.DEBUG("[node %s] sending find %s for bucket maintenance.", n->toString().c_str(), id.toString().c_str()); network_engine.sendFindNode(n, id, want, nullptr, nullptr); /* In order to avoid sending queries back-to-back, give up for now and reschedule us soon. */ @@ -3121,8 +3116,8 @@ void Dht::onGetValuesDone(const Request& status, return; } - DHT_LOG.DEBUG("[search %s IPv%c] got reply to 'get' from %s with %u nodes", - sr->id.toString().c_str(), sr->af == AF_INET ? '4' : '6', status.node->toString().c_str(), a.nodes4.size()); + DHT_LOG.DEBUG("[search %s] [node %s] got reply to 'get' with %u nodes", + sr->id.toString().c_str(), status.node->toString().c_str(), a.nodes4.size()); if (not a.ntoken.empty()) { if (not a.values.empty() or not a.fields.empty()) { @@ -3187,7 +3182,7 @@ NetworkEngine::RequestAnswer Dht::onListen(std::shared_ptr<Node> node, InfoHash& hash, Blob& token, size_t rid, Query&& query) { if (hash == zeroes) { - DHT_LOG.WARN("Listen with no info_hash."); + DHT_LOG.WARN("[node %s] Listen with no info_hash.", node->toString().c_str()); throw DhtProtocolException { DhtProtocolException::NON_AUTHORITATIVE_INFORMATION, DhtProtocolException::LISTEN_NO_INFOHASH @@ -3207,7 +3202,7 @@ Dht::onListenDone(const Request& status, std::shared_ptr<Search>& sr, const std::shared_ptr<Query>& orig_query) { - DHT_LOG.DEBUG("[search %s] Got reply to listen.", sr->id.toString().c_str()); + DHT_LOG.DEBUG("[search %s] [node %s] Got reply to listen.", sr->id.toString().c_str(), status.node->toString().c_str()); if (sr) { if (not answer.values.empty()) { /* got new values from listen request */ DHT_LOG.DEBUG("[listen %s] Got new values.", sr->id.toString().c_str()); @@ -3292,11 +3287,11 @@ Dht::onAnnounce(std::shared_ptr<Node> node, } void -Dht::onAnnounceDone(const Request&, NetworkEngine::RequestAnswer& answer, std::shared_ptr<Search>& sr) +Dht::onAnnounceDone(const Request& req, NetworkEngine::RequestAnswer& answer, std::shared_ptr<Search>& sr) { const auto& now = scheduler.time(); - DHT_LOG.DEBUG("[search %s IPv%c] got reply to put!", - sr->id.toString().c_str(), sr->af == AF_INET ? '4' : '6'); + DHT_LOG.DEBUG("[search %s] [node %s] got reply to put!", + sr->id.toString().c_str(), req.node->toString().c_str()); searchSendGetValues(sr); sr->checkAnnounced(types, now, answer.vid); } diff --git a/src/network_engine.cpp b/src/network_engine.cpp index 62c432c5..a7d84816 100644 --- a/src/network_engine.cpp +++ b/src/network_engine.cpp @@ -14,8 +14,7 @@ * GNU General Public License for more details. * * You should have received a copy of the GNU General Public License - * along with this program; if not, write to the Free Software - * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + * along with this program. If not, see <http://www.gnu.org/licenses/>. */ @@ -442,7 +441,7 @@ NetworkEngine::process(std::unique_ptr<ParsedMessage>&& msg, const SockAddr& fro // received reply from unexpected node node->received(now, req); onNewNode(node, 2); - DHT_LOG.WARN("Message received from unexpected ndoe %s", node->toString().c_str()); + DHT_LOG.WARN("[node %s] Message received from unexpected node.", node->toString().c_str()); return; } } else @@ -502,8 +501,7 @@ NetworkEngine::process(std::unique_ptr<ParsedMessage>&& msg, const SockAddr& fro sendPong(from, msg->tid); break; case MessageType::FindNode: { - DHT_LOG.DEBUG("[node %s %s] got 'find' request (%d).", - msg->id.toString().c_str(), from.toString().c_str(), msg->want); + DHT_LOG.DEBUG("[node %s] got 'find' request (%d).", node->toString().c_str(), msg->want); ++in_stats.find; RequestAnswer answer = onFindNode(node, msg->target, msg->want); auto nnodes = bufferNodes(from.getFamily(), msg->target, msg->want, answer.nodes4, answer.nodes6); @@ -511,8 +509,7 @@ NetworkEngine::process(std::unique_ptr<ParsedMessage>&& msg, const SockAddr& fro break; } case MessageType::GetValues: { - DHT_LOG.DEBUG("[node %s %s] got 'get' request for %s.", - msg->id.toString().c_str(), from.toString().c_str(), msg->info_hash.toString().c_str()); + DHT_LOG.DEBUG("[node %s] got 'get' request for %s.", node->toString().c_str(), msg->info_hash.toString().c_str()); ++in_stats.get; RequestAnswer answer = onGetValues(node, msg->info_hash, msg->want, msg->query); auto nnodes = bufferNodes(from.getFamily(), msg->info_hash, msg->want, answer.nodes4, answer.nodes6); @@ -520,9 +517,7 @@ NetworkEngine::process(std::unique_ptr<ParsedMessage>&& msg, const SockAddr& fro break; } case MessageType::AnnounceValue: { - DHT_LOG.DEBUG("[node %s %s] got 'put' request for %s.", - msg->id.toString().c_str(), from.toString().c_str(), - msg->info_hash.toString().c_str()); + DHT_LOG.DEBUG("[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); @@ -535,8 +530,7 @@ NetworkEngine::process(std::unique_ptr<ParsedMessage>&& msg, const SockAddr& fro break; } case MessageType::Listen: { - DHT_LOG.DEBUG("[node %s %s] got 'listen' request for %s.", - msg->id.toString().c_str(), from.toString().c_str(), msg->info_hash.toString().c_str()); + DHT_LOG.DEBUG("[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->tid.getTid(), std::move(msg->query)); sendListenConfirmation(from, msg->tid); @@ -613,7 +607,7 @@ NetworkEngine::sendPing(std::shared_ptr<Node> node, RequestCb on_done, RequestEx Blob b {buffer.data(), buffer.data() + buffer.size()}; std::shared_ptr<Request> req(new Request {tid.getTid(), node, std::move(b), [=](const Request& req_status, ParsedMessage&&) { - DHT_LOG.DEBUG("Got pong from %s", req_status.node->toString().c_str()); + DHT_LOG.DEBUG("[node %s] Got pong !", req_status.node->toString().c_str()); if (on_done) { on_done(req_status, {}); } @@ -877,11 +871,10 @@ NetworkEngine::sendNodesValues(const SockAddr& addr, TransId tid, const Blob& no pk.pack(std::string("v")); pk.pack_array(st.size()*fields.size()); for (const auto& v : st) v->msgpack_pack_fields(fields, pk); - DHT_LOG.DEBUG("sending closest nodes (%d+%d nodes.), %u value headers containing %u fields", - nodes.size(), nodes6.size(), st.size(), fields.size()); + //DHT_LOG.DEBUG("sending closest nodes (%d+%d nodes.), %u value headers containing %u fields", + // nodes.size(), nodes6.size(), st.size(), fields.size()); } - } else - DHT_LOG.DEBUG("sending closest nodes (%d+%d nodes.)", nodes.size(), nodes6.size()); + } pk.pack(std::string("t")); pk.pack_bin(tid.size()); pk.pack_bin_body((const char*)tid.data(), tid.size()); diff --git a/tools/tools_common.h b/tools/tools_common.h index 9682b069..9f918b89 100644 --- a/tools/tools_common.h +++ b/tools/tools_common.h @@ -14,8 +14,7 @@ * GNU General Public License for more details. * * You should have received a copy of the GNU General Public License - * along with this program; if not, write to the Free Software - * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA. + * along with this program. If not, see <http://www.gnu.org/licenses/>. */ // Common utility methods used by C++ OpenDHT tools. @@ -37,81 +36,6 @@ #include <sstream> #include <fstream> -/** - * Terminal colors for logging - */ -namespace Color { - enum Code { - FG_RED = 31, - FG_GREEN = 32, - FG_YELLOW = 33, - FG_BLUE = 34, - FG_DEFAULT = 39, - BG_RED = 41, - BG_GREEN = 42, - BG_BLUE = 44, - BG_DEFAULT = 49 - }; - class Modifier { - const Code code; - public: - constexpr Modifier(Code pCode) : code(pCode) {} - friend std::ostream& - operator<<(std::ostream& os, const Modifier& mod) { - return os << "\033[" << mod.code << 'm'; - } - }; -} - -constexpr const Color::Modifier def(Color::FG_DEFAULT); -constexpr const Color::Modifier red(Color::FG_RED); -constexpr const Color::Modifier yellow(Color::FG_YELLOW); - -/** - * Print va_list to std::ostream (used for logging). - */ -void -printLog(std::ostream& s, char const* m, va_list args) { - static constexpr int BUF_SZ = 8192; - char buffer[BUF_SZ]; - int ret = vsnprintf(buffer, sizeof(buffer), m, args); - if (ret < 0) - return; - s.write(buffer, std::min(ret, BUF_SZ)); - if (ret >= BUF_SZ) - s << "[[TRUNCATED]]"; - s.put('\n'); -} - -void -enableLogging(dht::DhtRunner& dht) -{ - dht.setLoggers( - [](char const* m, va_list args){ std::cerr << red; printLog(std::cerr, m, args); std::cerr << def; }, - [](char const* m, va_list args){ std::cout << yellow; printLog(std::cout, m, args); std::cout << def; }, - [](char const* m, va_list args){ printLog(std::cout, m, args); } - ); -} - -void -enableFileLogging(dht::DhtRunner& dht, const std::string& path) -{ - auto logfile = std::make_shared<std::fstream>(); - logfile->open(path, std::ios::out); - - dht.setLoggers( - [=](char const* m, va_list args){ printLog(*logfile, m, args); }, - [=](char const* m, va_list args){ printLog(*logfile, m, args); }, - [=](char const* m, va_list args){ printLog(*logfile, m, args); } - ); -} - -void -disableLogging(dht::DhtRunner& dht) -{ - dht.setLoggers(dht::NOLOG, dht::NOLOG, dht::NOLOG); -} - /** * Split "[host]:port" or "host:port" to pair<"host", "port">. */ -- GitLab