From bd32edc6c5813c069005db761fda3fa95894e47e Mon Sep 17 00:00:00 2001
From: Seva <seva@binarytrails.net>
Date: Tue, 25 Jun 2019 17:04:38 -0400
Subject: [PATCH] dhtproxy: uniform client logging
---
src/dht_proxy_client.cpp | 74 ++++++++++++++++++++--------------------
1 file changed, 37 insertions(+), 37 deletions(-)
diff --git a/src/dht_proxy_client.cpp b/src/dht_proxy_client.cpp
index 36046f80..c00513cc 100644
--- a/src/dht_proxy_client.cpp
+++ b/src/dht_proxy_client.cpp
@@ -86,16 +86,16 @@ DhtProxyClient::DhtProxyClient(std::function<void()> signal, const std::string &
httpClientThread_ = std::thread([this](){
try {
if (logger_)
- logger_->d("Starting the HTTP Client io_context");
+ logger_->d("[proxy:client] starting io context");
// Ensures the httpContext_ won't run out of work
auto work = asio::make_work_guard(httpContext_);
httpContext_.run();
if (logger_)
- logger_->d("HTTP Client io_context stopped");
+ logger_->d("[proxy:client] http client io context stopped");
}
catch(const std::exception &ex){
if (logger_)
- logger_->e("Error starting the HTTP Client io_context");
+ logger_->e("[proxy:client] error starting io context");
}
});
@@ -121,7 +121,7 @@ DhtProxyClient::startProxy()
return;
if (logger_)
- logger_->w("Staring proxy client to %s", serverHost_.c_str());
+ logger_->d("[proxy:client] staring proxy with %s", serverHost_.c_str());
nextProxyConfirmationTimer_ = std::make_shared<asio::steady_timer>(
httpContext_, std::chrono::steady_clock::now());
@@ -176,7 +176,7 @@ DhtProxyClient::cancelAllListeners()
{
std::lock_guard<std::mutex> lock(searchLock_);
if (logger_)
- logger_->w("[proxy:client] [listeners:cancel:all] [%zu searches]", searches_.size());
+ logger_->d("[proxy:client] [listeners:cancel:all] [%zu searches]", searches_.size());
for (auto& s: searches_) {
s.second.ops.cancelAll([&](size_t token){
auto l = s.second.listeners.find(token);
@@ -188,7 +188,7 @@ DhtProxyClient::cancelAllListeners()
httpClient_->close_connection(l->second.connId);
} catch (const std::exception& e) {
if (logger_)
- logger_->w("[proxy:client] [listeners:cancel:all] error closing socket: %s", e.what());
+ logger_->e("[proxy:client] [listeners:cancel:all] error closing socket: %s", e.what());
}
l->second.connId = 0;
}
@@ -267,7 +267,7 @@ DhtProxyClient::get(const InfoHash& key, GetCallback cb, DoneCallback donecb,
Value::Filter&& f, Where&& w)
{
if (logger_)
- logger_->d(key, "[search %s]: get", key.to_c_str());
+ logger_->d("[proxy:client] [get] [search %s]", key.to_c_str());
restinio::http_request_header_t header;
header.request_target("/" + key.toString());
header.method(restinio::http_method_get());
@@ -324,7 +324,7 @@ DhtProxyClient::get(const InfoHash& key, GetCallback cb, DoneCallback donecb,
auto context = static_cast<GetContext*>(parser->data);
if (parser->status_code != 200){
if (context->logger)
- context->logger->e("[proxy:client] get status error: %i", parser->status_code);
+ context->logger->e("[proxy:client] [get] status error: %i", parser->status_code);
context->ok = true;
}
return 0;
@@ -348,7 +348,7 @@ DhtProxyClient::get(const InfoHash& key, GetCallback cb, DoneCallback donecb,
}
} catch(const std::exception& e) {
if (context->logger)
- context->logger->e("[proxy:client] get body parsing error: %s", e.what());
+ context->logger->e("[proxy:client] [get] body parsing error: %s", e.what());
context->ok = false;
return 1;
}
@@ -361,7 +361,7 @@ DhtProxyClient::get(const InfoHash& key, GetCallback cb, DoneCallback donecb,
context->donecb(context->ok);
} catch(const std::exception& e) {
if (context->logger)
- context->logger->e("[proxy:client] get message complete parsing error: %i",
+ context->logger->e("[proxy:client] [get] message complete parsing error: %i",
parser->status_code);
return 1;
}
@@ -375,7 +375,7 @@ DhtProxyClient::put(const InfoHash& key, Sp<Value> val, DoneCallback cb,
time_point created, bool permanent)
{
if (logger_)
- logger_->d(key, "[search %s]: put", key.to_c_str());
+ logger_->d("[proxy:client] [put] [search %s]", key.to_c_str());
if (not val){
if (cb)
cb(false, {});
@@ -397,7 +397,7 @@ DhtProxyClient::put(const InfoHash& key, Sp<Value> val, DoneCallback cb,
refreshTimer->async_wait([this, key, id, ok](const asio::error_code &ec){
if (ec){
if (logger_)
- logger_->d("[listener:refresh] error key=%s", key.toString().c_str());
+ logger_->e("[proxy:client] [listener:refresh] error key=%s", key.toString().c_str());
return;
}
std::lock_guard<std::mutex> lock(searchLock_);
@@ -426,7 +426,7 @@ void
DhtProxyClient::doPut(const InfoHash& key, Sp<Value> val, DoneCallback cb, time_point /*created*/, bool permanent)
{
if (logger_)
- logger_->d(key, "[search %s] performing put of %s", key.to_c_str(), val->toString().c_str());
+ logger_->d("[proxy:client] [put] [search %s] executing for %s", key.to_c_str(), val->toString().c_str());
restinio::http_request_header_t header;
header.request_target("/" + key.toString());
header.method(restinio::http_method_post());
@@ -486,7 +486,7 @@ DhtProxyClient::doPut(const InfoHash& key, Sp<Value> val, DoneCallback cb, time_
context->ok = true;
} else {
if (context->logger)
- context->logger->e("[proxy:client] put status error: %i", parser->status_code);
+ context->logger->e("[proxy:client] [put] status error: %i", parser->status_code);
}
return 0;
};
@@ -497,7 +497,7 @@ DhtProxyClient::doPut(const InfoHash& key, Sp<Value> val, DoneCallback cb, time_
context->donecb(context->ok);
} catch(const std::exception& e) {
if (context->logger)
- context->logger->e("[proxy:client] put message complete error: %s", e.what());
+ context->logger->e("[proxy:client] [put] message complete error: %s", e.what());
return 1;
}
return 0;
@@ -545,7 +545,7 @@ DhtProxyClient::cancelPut(const InfoHash& key, const Value::Id& id)
if (search == searches_.end())
return false;
if (logger_)
- logger_->d(key, "[search %s] cancel put", key.to_c_str());
+ logger_->d("[proxy:client] [put:cancel] [search %s]", key.to_c_str());
return search->second.puts.erase(id) > 0;
}
@@ -559,7 +559,7 @@ void
DhtProxyClient::getProxyInfos()
{
if (logger_)
- logger_->d("Requesting proxy server node information");
+ logger_->d("[proxy:client] [info] requesting proxy server node information");
std::lock_guard<std::mutex> l(statusLock_);
auto infoState = std::make_shared<InfoState>();
@@ -730,7 +730,7 @@ DhtProxyClient::onProxyInfos(const Json::Value& proxyInfos, sa_family_t family)
publicAddressV6_ = publicIp;
} catch (const std::exception& e) {
if (logger_)
- logger_->w("[proxy:client] [info] error processing: %s", e.what());
+ logger_->e("[proxy:client] [info] error processing: %s", e.what());
}
}
auto newStatus = std::max(statusIpv4_, statusIpv6_);
@@ -771,7 +771,7 @@ DhtProxyClient::getPublicAddress(sa_family_t family)
size_t
DhtProxyClient::listen(const InfoHash& key, ValueCallback cb, Value::Filter filter, Where where) {
if (logger_)
- logger_->d(key, "[search %s]: listen", key.to_c_str());
+ logger_->d("[proxy:client] [listen] [search %s]", key.to_c_str());
auto& search = searches_[key];
auto query = std::make_shared<Query>(Select{}, where);
@@ -781,11 +781,11 @@ DhtProxyClient::listen(const InfoHash& key, ValueCallback cb, Value::Filter filt
auto search = searches_.find(key);
if (search == searches_.end()) {
if (logger_)
- logger_->e(key, "[search %s] listen: search not found", key.to_c_str());
+ logger_->e("[proxy:client] [listen] [search %s] search not found", key.to_c_str());
return 0;
}
if (logger_)
- logger_->d("[search %s] sending %s", key.to_c_str(),
+ logger_->d("[proxy:client] [listen] [search %s] sending %s", key.to_c_str(),
deviceKey_.empty() ? "listen" : "subscribe");
auto token = ++listenerToken_;
@@ -832,7 +832,7 @@ DhtProxyClient::listen(const InfoHash& key, ValueCallback cb, Value::Filter filt
{
if (ec){
if (logger_)
- logger_->d("[listener:refresh] error key=%s", key.toString().c_str());
+ logger_->d("[proxy:client] [listen] refresh error key=%s", key.toString().c_str());
return;
}
if (state->cancel)
@@ -951,7 +951,7 @@ DhtProxyClient::sendListen(const restinio::http_request_header_t header,
auto context = static_cast<ListenContext*>(parser->data);
if (parser->status_code != 200){
if (context->logger)
- context->logger->e("[proxy:client] listen status error: %i", parser->status_code);
+ context->logger->e("[proxy:client] [listen] status error: %i", parser->status_code);
context->state->ok = false;
}
return 0;
@@ -979,7 +979,7 @@ DhtProxyClient::sendListen(const restinio::http_request_header_t header,
}
} catch(const std::exception& e) {
if (context->logger)
- context->logger->e("Error in listen parsing: %s", e.what());
+ context->logger->e("[proxy:client] [listen] error in parsing: %s", e.what());
context->state->ok = false;
return 1;
}
@@ -1003,7 +1003,7 @@ DhtProxyClient::doCancelListen(const InfoHash& key, size_t ltoken)
return false;
if (logger_)
- logger_->d(key, "[search %s] cancel listen", key.to_c_str());
+ logger_->d("[proxy:client] [listen:cancel] [search %s]", key.to_c_str());
auto& listener = it->second;
listener.state->cancel = true;
@@ -1026,7 +1026,7 @@ DhtProxyClient::doCancelListen(const InfoHash& key, size_t ltoken)
auto request = httpClient_->create_request(header, header_fields,
restinio::http_connection_header_t::keep_alive, content);
if (logger_)
- logger_->w(request.c_str());
+ logger_->d(request.c_str());
// define context
struct UnsubscribeContext {
InfoHash key;
@@ -1061,13 +1061,13 @@ DhtProxyClient::doCancelListen(const InfoHash& key, size_t ltoken)
}
catch (const std::exception& e){
if (logger_)
- logger_->w("Error closing socket: %s", e.what());
+ logger_->e("[proxy:client] [listen:cancel] error closing socket: %s", e.what());
}
}
}
search->second.listeners.erase(it);
if (logger_)
- logger_->d(key, "[search %s] cancelListen: %zu listener remaining",
+ logger_->d("[proxy:client] [listen:cancel] [search %s] %zu listener remaining",
key.to_c_str(), search->second.listeners.size());
if (search->second.listeners.empty()){
searches_.erase(search);
@@ -1079,7 +1079,7 @@ void
DhtProxyClient::opFailed()
{
if (logger_)
- logger_->e("Proxy request failed");
+ logger_->e("[proxy:client] proxy request failed");
{
std::lock_guard<std::mutex> l(lockCurrentProxyInfos_);
statusIpv4_ = NodeStatus::Disconnected;
@@ -1102,7 +1102,7 @@ DhtProxyClient::restartListeners()
if (isDestroying_) return;
std::lock_guard<std::mutex> lock(searchLock_);
if (logger_)
- logger_->d("Refresh permanent puts");
+ logger_->d("[proxy:client] [listeners:restart] refresh permanent puts");
for (auto& search : searches_) {
for (auto& put : search.second.puts) {
if (!*put.second.ok) {
@@ -1122,7 +1122,7 @@ DhtProxyClient::restartListeners()
}
if (not deviceKey_.empty()) {
if (logger_)
- logger_->d("resubscribe due to a connectivity change");
+ logger_->d("[proxy:client] [listeners:restart] resubscribe due to a connectivity change");
// Connectivity changed, refresh all subscribe
for (auto& search : searches_)
for (auto& listener : search.second.listeners)
@@ -1131,7 +1131,7 @@ DhtProxyClient::restartListeners()
return;
}
if (logger_)
- logger_->d("Restarting listeners");
+ logger_->d("[proxy:client] [listeners:restart] restarting listeners");
for (auto& search: searches_) {
for (auto& l: search.second.listeners) {
auto& listener = l.second;
@@ -1142,7 +1142,7 @@ DhtProxyClient::restartListeners()
httpClient_->close_connection(listener.connId);
} catch (const std::exception& e) {
if (logger_)
- logger_->w("Error closing socket: %s", e.what());
+ logger_->e("[proxy:client] [listeners:restart] error closing socket: %s", e.what());
}
l.second.connId = 0;
}
@@ -1206,7 +1206,7 @@ DhtProxyClient::pushNotificationReceived(const std::map<std::string, std::string
if (list.second.state->cancel)
continue;
if (logger_)
- logger_->d(key, "[search %s] handling push notification", key.to_c_str());
+ logger_->d("[proxy:client] [push:received] [search %s] handling", key.to_c_str());
auto expired = notification.find("exp");
auto token = list.first;
auto state = list.second.state;
@@ -1251,7 +1251,7 @@ DhtProxyClient::pushNotificationReceived(const std::map<std::string, std::string
}
} catch (const std::exception& e) {
if (logger_)
- logger_->e("Error handling push notification: %s", e.what());
+ logger_->e("[proxy:client] [push:received] error handling: %s", e.what());
}
#else
(void) notification;
@@ -1265,7 +1265,7 @@ DhtProxyClient::resubscribe(const InfoHash& key, Listener& listener)
if (deviceKey_.empty())
return;
if (logger_)
- logger_->d(key, "[search %s] resubscribe push listener", key.to_c_str());
+ logger_->d("[proxy:client] [resubscribe] [search %s] resubscribe push listener", key.to_c_str());
// Subscribe
auto state = listener.state;
state->cancel = true;
@@ -1274,7 +1274,7 @@ DhtProxyClient::resubscribe(const InfoHash& key, Listener& listener)
httpClient_->close_connection(listener.connId);
} catch (const std::exception& e) {
if (logger_)
- logger_->w("[resubscribe] error closing socket: %s", e.what());
+ logger_->e("[proxy:client] [resubscribe] error closing socket: %s", e.what());
}
}
state->cancel = false;
--
GitLab