mirror
/
transmission
mirror of https://github.com/transmission/transmission
1
0
Fork 0
Code Issues Releases Wiki Activity

refactor: set logging levels (#2755)

This commit is contained in:
Charles Kerr 2022-03-11 15:09:22 -06:00 committed by GitHub
parent af339a15ed
commit d2f8e1d4e0
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
31 changed files with 392 additions and 367 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

36
daemon/daemon.cc
View File

@ -54,6 +54,28 @@ static void sd_notifyf(int /*status*/, char const* /*fmt*/, ...)
using namespace std::literals; using namespace std::literals;
/***
****
***/
static auto constexpr CodeName = "daemon"sv;
#undef tr_logAddError
#undef tr_logAddWarn
#undef tr_logAddInfo
#undef tr_logAddDebug
#undef tr_logAddTrace
#define tr_logAddError(...) tr_logAddNamedError(CodeName, __VA_ARGS__)
#define tr_logAddWarn(...) tr_logAddNamedWarn(CodeName, __VA_ARGS__)
#define tr_logAddInfo(...) tr_logAddNamedInfo(CodeName, __VA_ARGS__)
#define tr_logAddDebug(...) tr_logAddNamedDebug(CodeName, __VA_ARGS__)
#define tr_logAddTrace(...) tr_logAddNamedTrace(CodeName, __VA_ARGS__)
/***
****
***/
static char constexpr MyName[] = "transmission-daemon"; static char constexpr MyName[] = "transmission-daemon";
static char constexpr Usage[] = "Transmission " LONG_VERSION_STRING static char constexpr Usage[] = "Transmission " LONG_VERSION_STRING
" https://transmissionbt.com/\n" " https://transmissionbt.com/\n"
@ -270,17 +292,17 @@ static char const* levelName(tr_log_level level)
switch (level) switch (level)
{ {
case TR_LOG_CRITICAL: case TR_LOG_CRITICAL:
return "CRIT "; return "CRT";
case TR_LOG_ERROR: case TR_LOG_ERROR:
return "ERR "; return "ERR";
case TR_LOG_WARN: case TR_LOG_WARN:
return "WARN "; return "WRN";
case TR_LOG_DEBUG: case TR_LOG_DEBUG:
return "DEBUG"; return "dbg";
case TR_LOG_TRACE: case TR_LOG_TRACE:
return "TRACE"; return "trc";
default: default:
return "INFO "; return "inf";
} }
} }
@ -678,7 +700,7 @@ static int daemon_start(void* varg, [[maybe_unused]] bool foreground)
tr_formatter_speed_init(SpeedK, SpeedKStr, SpeedMStr, SpeedGStr, SpeedTStr); tr_formatter_speed_init(SpeedK, SpeedKStr, SpeedMStr, SpeedGStr, SpeedTStr);
session = tr_sessionInit(configDir, true, settings); session = tr_sessionInit(configDir, true, settings);
tr_sessionSetRPCCallback(session, on_rpc_callback, nullptr); tr_sessionSetRPCCallback(session, on_rpc_callback, nullptr);
tr_logAddNamedInfo(nullptr, "Using settings from \"%s\"", configDir); tr_logAddNamedInfo(MyName, "Using settings from \"%s\"", configDir);
tr_sessionSaveSettings(session, configDir, settings); tr_sessionSaveSettings(session, configDir, settings);
auto sv = std::string_view{}; auto sv = std::string_view{};

4
libtransmission/announcer-http.cc
View File

@ -443,7 +443,7 @@ void tr_announcerParseHttpScrapeResponse(tr_scrape_response& response, std::stri
transmission::benc::parse(benc, stack, handler, nullptr, &error); transmission::benc::parse(benc, stack, handler, nullptr, &error);
if (error != nullptr) if (error != nullptr)
{ {
tr_logAddMessage(__FILE__, __LINE__, TR_LOG_WARN, log_name, "%s (%d)", error->message, error->code); tr_logAddMessage(__FILE__, __LINE__, TR_LOG_WARN, log_name, "scrape response: %s (%d)", error->message, error->code);
tr_error_clear(&error); tr_error_clear(&error);
} }
} }
@ -473,7 +473,7 @@ static void onScrapeDone(tr_web::FetchResponse const& web_response)
auto const* const response_str = tr_webGetResponseStr(status); auto const* const response_str = tr_webGetResponseStr(status);
response.errmsg = tr_strvJoin("Tracker HTTP response "sv, std::to_string(status), " ("sv, response_str, ")"sv); response.errmsg = tr_strvJoin("Tracker HTTP response "sv, std::to_string(status), " ("sv, response_str, ")"sv);
} }
else else if (!std::empty(body))
{ {
tr_announcerParseHttpScrapeResponse(response, body, data->log_name); tr_announcerParseHttpScrapeResponse(response, body, data->log_name);
} }

80
libtransmission/announcer.cc
View File

@ -38,21 +38,10 @@
using namespace std::literals; using namespace std::literals;
#define logimpl(tier, level, ...) \ #define tr_logAddErrorTier(tier, ...) tr_logAddNamedError(tier->buildLogName().c_str(), __VA_ARGS__)
do \ #define tr_logAddWarnTier(tier, ...) tr_logAddNamedWarn(tier->buildLogName().c_str(), __VA_ARGS__)
{ \ #define tr_logAddDebugTier(tier, ...) tr_logAddNamedDebug(tier->buildLogName().c_str(), __VA_ARGS__)
if (tr_logLevelIsActive(level)) \ #define tr_logAddTraceTier(tier, ...) tr_logAddNamedTrace(tier->buildLogName().c_str(), __VA_ARGS__)
{ \
auto name = std::array<char, 512>{}; \
tier->buildLogName(std::data(name), std::size(name)); \
tr_logAddMessage(__FILE__, __LINE__, level, std::data(name), __VA_ARGS__); \
} \
} while (0)
#define logerr(io, ...) logimpl(io, TR_LOG_ERROR, __VA_ARGS__)
#define logwarn(io, ...) logimpl(io, TR_LOG_WARN, __VA_ARGS__)
#define logdbg(io, ...) logimpl(io, TR_LOG_DEBUG, __VA_ARGS__)
#define logtrace(io, ...) logimpl(io, TR_LOG_TRACE, __VA_ARGS__)
/* unless the tracker says otherwise, rescrape this frequently */ /* unless the tracker says otherwise, rescrape this frequently */
static auto constexpr DefaultScrapeIntervalSec = int{ 60 * 30 }; static auto constexpr DefaultScrapeIntervalSec = int{ 60 * 30 };
@ -401,12 +390,19 @@ struct tr_tier
return std::nullopt; return std::nullopt;
} }
[[nodiscard]] std::string buildLogName() const
{
auto buf = std::array<char, 512>{};
buildLogName(std::data(buf), std::size(buf));
return std::string{ std::data(buf) };
}
void buildLogName(char* buf, size_t buflen) const void buildLogName(char* buf, size_t buflen) const
{ {
auto const* const torrent_name = tr_torrentName(tor); auto const* const torrent_name = tr_torrentName(tor);
auto const* const current_tracker = currentTracker(); auto const* const current_tracker = currentTracker();
auto const host_sv = current_tracker == nullptr ? "?"sv : current_tracker->host.sv(); auto const host_sv = current_tracker == nullptr ? "?"sv : current_tracker->host.sv();
tr_snprintf(buf, buflen, "[%s---%" TR_PRIsv "]", torrent_name, TR_PRIsv_ARG(host_sv)); tr_snprintf(buf, buflen, "%s at %" TR_PRIsv, torrent_name, TR_PRIsv_ARG(host_sv));
} }
[[nodiscard]] bool canManualAnnounce() const [[nodiscard]] bool canManualAnnounce() const
@ -658,7 +654,7 @@ static void publishPeerCounts(tr_tier* tier, int seeders, int leechers)
e.messageType = TR_TRACKER_COUNTS; e.messageType = TR_TRACKER_COUNTS;
e.seeders = seeders; e.seeders = seeders;
e.leechers = leechers; e.leechers = leechers;
logdbg(tier, "peer counts: %d seeders, %d leechers.", seeders, leechers); tr_logAddDebugTier(tier, "peer counts: %d seeders, %d leechers.", seeders, leechers);
(*tier->tor->torrent_announcer->callback)(tier->tor, &e, nullptr); (*tier->tor->torrent_announcer->callback)(tier->tor, &e, nullptr);
} }
@ -673,7 +669,7 @@ static void publishPeersPex(tr_tier* tier, int seeders, int leechers, std::vecto
e.seeders = seeders; e.seeders = seeders;
e.leechers = leechers; e.leechers = leechers;
e.pex = pex; e.pex = pex;
logdbg( tr_logAddDebugTier(
tier, tier,
"tracker knows of %d seeders and %d leechers and gave a list of %zu peers.", "tracker knows of %d seeders and %d leechers and gave a list of %zu peers.",
seeders, seeders,
@ -725,16 +721,13 @@ time_t tr_announcerNextManualAnnounce(tr_torrent const* tor)
return ret; return ret;
} }
static void logtrace_tier_announce_queue(tr_tier const* tier) static void tr_logAddTrace_tier_announce_queue(tr_tier const* tier)
{ {
if (!tr_logLevelIsActive(TR_LOG_TRACE)) if (!tr_logLevelIsActive(TR_LOG_TRACE))
{ {
return; return;
} }
auto name = std::array<char, 512>{};
tier->buildLogName(std::data(name), std::size(name));
auto* const buf = evbuffer_new(); auto* const buf = evbuffer_new();
for (size_t i = 0, n = std::size(tier->announce_events); i < n; ++i) for (size_t i = 0, n = std::size(tier->announce_events); i < n; ++i)
{ {
@ -743,8 +736,8 @@ static void logtrace_tier_announce_queue(tr_tier const* tier)
evbuffer_add_printf(buf, "[%zu:%s]", i, str); evbuffer_add_printf(buf, "[%zu:%s]", i, str);
} }
auto const message = evbuffer_free_to_str(buf); auto const str = evbuffer_free_to_str(buf);
tr_logAddMessage(__FILE__, __LINE__, TR_LOG_TRACE, std::data(name), "%s", message.c_str()); tr_logAddTraceTier(tier, "%s", str.c_str());
} }
// higher priorities go to the front of the announce queue // higher priorities go to the front of the announce queue
@ -774,8 +767,8 @@ static void tier_announce_event_push(tr_tier* tier, tr_announce_event e, time_t
{ {
TR_ASSERT(tier != nullptr); TR_ASSERT(tier != nullptr);
logtrace_tier_announce_queue(tier); tr_logAddTrace_tier_announce_queue(tier);
logtrace(tier, "queued \"%s\"", tr_announce_event_get_string(e)); tr_logAddTraceTier(tier, "queued \"%s\"", tr_announce_event_get_string(e));
auto& events = tier->announce_events; auto& events = tier->announce_events;
if (!std::empty(events)) if (!std::empty(events))
@ -804,8 +797,8 @@ static void tier_announce_event_push(tr_tier* tier, tr_announce_event e, time_t
tier->announceAt = announceAt; tier->announceAt = announceAt;
tier_update_announce_priority(tier); tier_update_announce_priority(tier);
logtrace_tier_announce_queue(tier); tr_logAddTrace_tier_announce_queue(tier);
logtrace(tier, "announcing in %d seconds", (int)difftime(announceAt, tr_time())); tr_logAddTraceTier(tier, "announcing in %d seconds", (int)difftime(announceAt, tr_time()));
} }
static auto tier_announce_event_pull(tr_tier* tier) static auto tier_announce_event_pull(tr_tier* tier)
@ -961,18 +954,15 @@ static void on_announce_error(tr_tier* tier, char const* err, tr_announce_event
/* switch to the next tracker */ /* switch to the next tracker */
current_tracker = tier->useNextTracker(); current_tracker = tier->useNextTracker();
auto const* const host_cstr = current_tracker->host.c_str();
if (isUnregistered(err)) if (isUnregistered(err))
{ {
logerr(tier, "Tracker '%s' announce error: %s", host_cstr, err); tr_logAddErrorTier(tier, "announce error: %s", err);
tr_logAddTorInfo(tier->tor, "Tracker '%s' announce error: %s", host_cstr, err);
} }
else else
{ {
/* schedule a reannounce */ /* schedule a reannounce */
int const interval = current_tracker->getRetryInterval(); int const interval = current_tracker->getRetryInterval();
logwarn(tier, "Tracker '%s' announce error: %s (Retrying in %d seconds)", host_cstr, err, interval); tr_logAddWarnTier(tier, "announce error: %s (Retrying in %d seconds)", err, interval);
tr_logAddTorInfo(tier->tor, "Tracker '%s' announce error: %s (Retrying in %d seconds)", host_cstr, err, interval);
tier_announce_event_push(tier, e, tr_time() + interval); tier_announce_event_push(tier, e, tr_time() + interval);
} }
} }
@ -988,7 +978,7 @@ static void on_announce_done(tr_announce_response const* response, void* vdata)
if (tier != nullptr) if (tier != nullptr)
{ {
logtrace( tr_logAddTraceTier(
tier, tier,
"Got announce response: " "Got announce response: "
"connected:%d " "connected:%d "
@ -1089,7 +1079,7 @@ static void on_announce_done(tr_announce_response const* response, void* vdata)
if (auto const& warning = response->warning; !std::empty(warning)) if (auto const& warning = response->warning; !std::empty(warning))
{ {
tier->last_announce_str = warning; tier->last_announce_str = warning;
logtrace(tier, "tracker gave \"%s\"", warning.c_str()); tr_logAddTraceTier(tier, "tracker gave \"%s\"", warning.c_str());
publishWarning(tier, warning); publishWarning(tier, warning);
} }
else else
@ -1125,10 +1115,9 @@ static void on_announce_done(tr_announce_response const* response, void* vdata)
then a separate scrape isn't needed */ then a separate scrape isn't needed */
if (scrape_fields >= 3 || (scrape_fields >= 1 && tracker->scrape_info == nullptr)) if (scrape_fields >= 3 || (scrape_fields >= 1 && tracker->scrape_info == nullptr))
{ {
tr_logAddTorDbg( tr_logAddTraceTier(
tier->tor, tier,
"Announce response contained scrape info; " "Announce response has scrape info; bumping next scrape to %d seconds from now.",
"rescheduling next scrape to %d seconds from now.",
tier->scrapeIntervalSec); tier->scrapeIntervalSec);
tier->scheduleNextScrape(); tier->scheduleNextScrape();
tier->lastScrapeTime = now; tier->lastScrapeTime = now;
@ -1156,7 +1145,7 @@ static void on_announce_done(tr_announce_response const* response, void* vdata)
{ {
/* the queue is empty, so enqueue a perodic update */ /* the queue is empty, so enqueue a perodic update */
int const i = tier->announceIntervalSec; int const i = tier->announceIntervalSec;
logtrace(tier, "Sending periodic reannounce in %d seconds", i); tr_logAddTraceTier(tier, "Sending periodic reannounce in %d seconds", i);
tier_announce_event_push(tier, TR_ANNOUNCE_EVENT_NONE, now + i); tier_announce_event_push(tier, TR_ANNOUNCE_EVENT_NONE, now + i);
} }
} }
@ -1194,7 +1183,7 @@ static void announce_request_delegate(
} }
else else
{ {
tr_logAddError("Unsupported url: %" TR_PRIsv, TR_PRIsv_ARG(announce_sv)); tr_logAddWarn("Unsupported url: %" TR_PRIsv, TR_PRIsv_ARG(announce_sv));
delete callback_data; delete callback_data;
} }
@ -1261,8 +1250,7 @@ static void on_scrape_error(tr_session const* /*session*/, tr_tier* tier, char c
// schedule a rescrape // schedule a rescrape
auto const interval = current_tracker->getRetryInterval(); auto const interval = current_tracker->getRetryInterval();
auto const* const host_cstr = current_tracker->host.c_str(); auto const* const host_cstr = current_tracker->host.c_str();
logtrace(tier, "Tracker '%s' scrape error: %s (Retrying in %zu seconds)", host_cstr, errmsg, (size_t)interval); tr_logAddDebugTier(tier, "Tracker '%s' scrape error: %s (Retrying in %zu seconds)", host_cstr, errmsg, (size_t)interval);
tr_logAddTorInfo(tier->tor, "Tracker '%s' error: %s (Retrying in %zu seconds)", host_cstr, errmsg, (size_t)interval);
tier->lastScrapeSucceeded = false; tier->lastScrapeSucceeded = false;
tier->scheduleNextScrape(interval); tier->scheduleNextScrape(interval);
} }
@ -1325,7 +1313,7 @@ static void on_scrape_done(tr_scrape_response const* response, void* vsession)
auto const scrape_url_sv = response->scrape_url.sv(); auto const scrape_url_sv = response->scrape_url.sv();
logtrace( tr_logAddTraceTier(
tier, tier,
"scraped url:%" TR_PRIsv "scraped url:%" TR_PRIsv
" -- " " -- "
@ -1369,7 +1357,7 @@ static void on_scrape_done(tr_scrape_response const* response, void* vsession)
tier->lastScrapeSucceeded = true; tier->lastScrapeSucceeded = true;
tier->scrapeIntervalSec = std::max(int{ DefaultScrapeIntervalSec }, response->min_request_interval); tier->scrapeIntervalSec = std::max(int{ DefaultScrapeIntervalSec }, response->min_request_interval);
tier->scheduleNextScrape(); tier->scheduleNextScrape();
tr_logAddTorDbg(tier->tor, "Scrape successful. Rescraping in %d seconds.", tier->scrapeIntervalSec); tr_logAddTraceTier(tier, "Scrape successful. Rescraping in %d seconds.", tier->scrapeIntervalSec);
if (tr_tracker* const tracker = tier->currentTracker(); tracker != nullptr) if (tr_tracker* const tracker = tier->currentTracker(); tracker != nullptr)
{ {
@ -1578,7 +1566,7 @@ static void scrapeAndAnnounceMore(tr_announcer* announcer)
for (auto*& tier : announce_me) for (auto*& tier : announce_me)
{ {
tr_logAddTorDbg(tier->tor, "%s", "Announcing to tracker"); tr_logAddTraceTier(tier, "%s", "Announcing to tracker");
tierAnnounce(announcer, tier); tierAnnounce(announcer, tier);
} }
} }

2
libtransmission/bandwidth.cc
View File

@ -14,7 +14,7 @@
#include "tr-assert.h" #include "tr-assert.h"
#include "utils.h" #include "utils.h"
#define logtrace(...) tr_logAddMessage(__FILE__, __LINE__, TR_LOG_TRACE, nullptr, __VA_ARGS__) #define logtrace(...) tr_logAddMessage(__FILE__, __LINE__, TR_LOG_TRACE, "", __VA_ARGS__)
/*** /***
**** ****

2
libtransmission/benc.h
View File

@ -378,7 +378,7 @@ bool parse(
if (stack.stack[0].n_children_walked == 0) if (stack.stack[0].n_children_walked == 0)
{ {
err = EILSEQ; err = EILSEQ;
tr_error_set(error, err, "no data found"); tr_error_set(error, err, "no bencoded data to parse");
errno = err; errno = err;
return false; return false;
} }

13
libtransmission/blocklist.cc
View File

@ -9,6 +9,7 @@
#include <cstring> #include <cstring>
#include "transmission.h" #include "transmission.h"
#include "blocklist.h" #include "blocklist.h"
#include "error.h" #include "error.h"
#include "file.h" #include "file.h"
@ -72,7 +73,7 @@ static void blocklistLoad(tr_blocklistFile* b)
auto const fd = tr_sys_file_open(b->filename, TR_SYS_FILE_READ, 0, &error); auto const fd = tr_sys_file_open(b->filename, TR_SYS_FILE_READ, 0, &error);
if (fd == TR_BAD_SYS_FILE) if (fd == TR_BAD_SYS_FILE)
{ {
tr_logAddError(err_fmt, b->filename, error->message); tr_logAddWarn(err_fmt, b->filename, error->message);
tr_error_free(error); tr_error_free(error);
return; return;
} }
@ -80,7 +81,7 @@ static void blocklistLoad(tr_blocklistFile* b)
b->rules = static_cast<struct tr_ipv4_range*>(tr_sys_file_map_for_reading(fd, 0, byteCount, &error)); b->rules = static_cast<struct tr_ipv4_range*>(tr_sys_file_map_for_reading(fd, 0, byteCount, &error));
if (b->rules == nullptr) if (b->rules == nullptr)
{ {
tr_logAddError(err_fmt, b->filename, error->message); tr_logAddWarn(err_fmt, b->filename, error->message);
tr_sys_file_close(fd, nullptr); tr_sys_file_close(fd, nullptr);
tr_error_free(error); tr_error_free(error);
return; return;
@ -370,7 +371,7 @@ int tr_blocklistFileSetContent(tr_blocklistFile* b, char const* filename)
auto const in = tr_sys_file_open(filename, TR_SYS_FILE_READ, 0, &error); auto const in = tr_sys_file_open(filename, TR_SYS_FILE_READ, 0, &error);
if (in == TR_BAD_SYS_FILE) if (in == TR_BAD_SYS_FILE)
{ {
tr_logAddError(err_fmt, filename, error->message); tr_logAddWarn(err_fmt, filename, error->message);
tr_error_free(error); tr_error_free(error);
return 0; return 0;
} }
@ -380,7 +381,7 @@ int tr_blocklistFileSetContent(tr_blocklistFile* b, char const* filename)
auto const out = tr_sys_file_open(b->filename, TR_SYS_FILE_WRITE | TR_SYS_FILE_CREATE | TR_SYS_FILE_TRUNCATE, 0666, &error); auto const out = tr_sys_file_open(b->filename, TR_SYS_FILE_WRITE | TR_SYS_FILE_CREATE | TR_SYS_FILE_TRUNCATE, 0666, &error);
if (out == TR_BAD_SYS_FILE) if (out == TR_BAD_SYS_FILE)
{ {
tr_logAddError(err_fmt, b->filename, error->message); tr_logAddWarn(err_fmt, b->filename, error->message);
tr_error_free(error); tr_error_free(error);
tr_sys_file_close(in, nullptr); tr_sys_file_close(in, nullptr);
return 0; return 0;
@ -396,7 +397,7 @@ int tr_blocklistFileSetContent(tr_blocklistFile* b, char const* filename)
if (!parseLine(line, &range)) if (!parseLine(line, &range))
{ {
/* don't try to display the actual lines - it causes issues */ /* don't try to display the actual lines - it causes issues */
tr_logAddError(_("blocklist skipped invalid address at line %d"), inCount); tr_logAddWarn(_("blocklist skipped invalid address at line %d"), inCount);
continue; continue;
} }
@ -453,7 +454,7 @@ int tr_blocklistFileSetContent(tr_blocklistFile* b, char const* filename)
if (!tr_sys_file_write(out, ranges, sizeof(struct tr_ipv4_range) * ranges_count, nullptr, &error)) if (!tr_sys_file_write(out, ranges, sizeof(struct tr_ipv4_range) * ranges_count, nullptr, &error))
{ {
tr_logAddError(_("Couldn't save file \"%1$s\": %2$s"), b->filename, error->message); tr_logAddWarn(_("Couldn't save file \"%1$s\": %2$s"), b->filename, error->message);
tr_error_free(error); tr_error_free(error);
} }
else else

15
libtransmission/cache.cc
View File

@ -18,9 +18,7 @@
#include "trevent.h" #include "trevent.h"
#include "utils.h" #include "utils.h"
static char constexpr MyName[] = "Cache"; auto constexpr CodeName = std::string_view{ "cache" };
#define logtrace(...) tr_logAddMessage(__FILE__, __LINE__, TR_LOG_TRACE, nullptr, __VA_ARGS__)
/**** /****
***** *****
@ -244,8 +242,8 @@ int tr_cacheSetLimit(tr_cache* cache, int64_t max_bytes)
cache->max_bytes = max_bytes; cache->max_bytes = max_bytes;
cache->max_blocks = getMaxBlocks(max_bytes); cache->max_blocks = getMaxBlocks(max_bytes);
tr_logAddNamedDbg( tr_logAddNamedDebug(
MyName, CodeName,
"Maximum cache size set to %s (%d blocks)", "Maximum cache size set to %s (%d blocks)",
tr_formatter_mem_B(cache->max_bytes).c_str(), tr_formatter_mem_B(cache->max_bytes).c_str(),
cache->max_blocks); cache->max_blocks);
@ -409,7 +407,12 @@ int tr_cacheFlushFile(tr_cache* cache, tr_torrent* torrent, tr_file_index_t i)
auto const [begin, end] = tr_torGetFileBlockSpan(torrent, i); auto const [begin, end] = tr_torGetFileBlockSpan(torrent, i);
int pos = findBlockPos(cache, torrent, torrent->blockLoc(begin)); int pos = findBlockPos(cache, torrent, torrent->blockLoc(begin));
logtrace("flushing file %d from cache to disk: blocks [%zu...%zu)", (int)i, (size_t)begin, (size_t)end); tr_logAddNamedTrace(
CodeName,
"flushing file %d from cache to disk: blocks [%zu...%zu)",
(int)i,
(size_t)begin,
(size_t)end);
/* flush out all the blocks in that file */ /* flush out all the blocks in that file */
int err = 0; int err = 0;

35
libtransmission/fdlimit.cc
View File

@ -21,11 +21,6 @@
#include "tr-assert.h" #include "tr-assert.h"
#include "utils.h" // tr_time() #include "utils.h" // tr_time()
#define logerr(...) tr_logAddNamed(TR_LOG_ERROR, nullptr, __VA_ARGS__)
#define logwarn(...) tr_logAddNamed(TR_LOG_WARN, nullptr, __VA_ARGS__)
#define logdbg(...) tr_logAddNamed(TR_LOG_DEBUG, nullptr, __VA_ARGS__)
#define logtrace(...) tr_logAddNamed(TR_LOG_TRACE, nullptr, __VA_ARGS__)
/*** /***
**** ****
**** Local Files **** Local Files
@ -46,7 +41,7 @@ static bool preallocate_file_sparse(tr_sys_file_t fd, uint64_t length, tr_error*
return true; return true;
} }
logdbg("Preallocating (sparse, normal) failed (%d): %s", my_error->code, my_error->message); tr_logAddDebug("Preallocating (sparse, normal) failed (%d): %s", my_error->code, my_error->message);
if (!TR_ERROR_IS_ENOSPC(my_error->code)) if (!TR_ERROR_IS_ENOSPC(my_error->code))
{ {
@ -60,7 +55,7 @@ static bool preallocate_file_sparse(tr_sys_file_t fd, uint64_t length, tr_error*
return true; return true;
} }
logdbg("Preallocating (sparse, fallback) failed (%d): %s", my_error->code, my_error->message); tr_logAddDebug("Preallocating (sparse, fallback) failed (%d): %s", my_error->code, my_error->message);
} }
tr_error_propagate(error, &my_error); tr_error_propagate(error, &my_error);
@ -81,7 +76,7 @@ static bool preallocate_file_full(tr_sys_file_t fd, uint64_t length, tr_error**
return true; return true;
} }
logdbg("Preallocating (full, normal) failed (%d): %s", my_error->code, my_error->message); tr_logAddDebug("Preallocating (full, normal) failed (%d): %s", my_error->code, my_error->message);
if (!TR_ERROR_IS_ENOSPC(my_error->code)) if (!TR_ERROR_IS_ENOSPC(my_error->code))
{ {
@ -104,7 +99,7 @@ static bool preallocate_file_full(tr_sys_file_t fd, uint64_t length, tr_error**
return true; return true;
} }
logdbg("Preallocating (full, fallback) failed (%d): %s", my_error->code, my_error->message); tr_logAddDebug("Preallocating (full, fallback) failed (%d): %s", my_error->code, my_error->message);
} }
tr_error_propagate(error, &my_error); tr_error_propagate(error, &my_error);
@ -171,13 +166,13 @@ static int cached_file_open(
if (dir == nullptr) if (dir == nullptr)
{ {
logerr(_("Couldn't get directory for \"%1$s\": %2$s"), filename, error->message); tr_logAddError(_("Couldn't get directory for \"%1$s\": %2$s"), filename, error->message);
goto FAIL; goto FAIL;
} }
if (!tr_sys_dir_create(dir, TR_SYS_DIR_CREATE_PARENTS, 0777, &error)) if (!tr_sys_dir_create(dir, TR_SYS_DIR_CREATE_PARENTS, 0777, &error))
{ {
logerr(_("Couldn't create \"%1$s\": %2$s"), dir, error->message); tr_logAddError(_("Couldn't create \"%1$s\": %2$s"), dir, error->message);
tr_free(dir); tr_free(dir);
goto FAIL; goto FAIL;
} }
@ -198,7 +193,7 @@ static int cached_file_open(
if (fd == TR_BAD_SYS_FILE) if (fd == TR_BAD_SYS_FILE)
{ {
logerr(_("Couldn't open \"%1$s\": %2$s"), filename, error->message); tr_logAddError(_("Couldn't open \"%1$s\": %2$s"), filename, error->message);
goto FAIL; goto FAIL;
} }
@ -222,7 +217,7 @@ static int cached_file_open(
if (!success) if (!success)
{ {
logwarn( tr_logAddWarn(
_("Couldn't preallocate file \"%1$s\" (%2$s, size: %3$" PRIu64 "): %4$s"), _("Couldn't preallocate file \"%1$s\" (%2$s, size: %3$" PRIu64 "): %4$s"),
filename, filename,
type, type,
@ -231,7 +226,7 @@ static int cached_file_open(
goto FAIL; goto FAIL;
} }
logdbg(_("Preallocated file \"%1$s\" (%2$s, size: %3$" PRIu64 ")"), filename, type, file_size); tr_logAddDebug(_("Preallocated file \"%1$s\" (%2$s, size: %3$" PRIu64 ")"), filename, type, file_size);
} }
/* If the file already exists and it's too large, truncate it. /* If the file already exists and it's too large, truncate it.
@ -242,7 +237,7 @@ static int cached_file_open(
*/ */
if (resize_needed && !tr_sys_file_truncate(fd, file_size, &error)) if (resize_needed && !tr_sys_file_truncate(fd, file_size, &error))
{ {
logwarn(_("Couldn't truncate \"%1$s\": %2$s"), filename, error->message); tr_logAddWarn(_("Couldn't truncate \"%1$s\": %2$s"), filename, error->message);
goto FAIL; goto FAIL;
} }
@ -482,11 +477,11 @@ tr_sys_file_t tr_fdFileCheckout(
return TR_BAD_SYS_FILE; return TR_BAD_SYS_FILE;
} }
logtrace("opened '%s' writable %c", filename, writable ? 'y' : 'n'); tr_logAddTrace("opened '%s' writable %c", filename, writable ? 'y' : 'n');
o->is_writable = writable; o->is_writable = writable;
} }
logtrace("checking out '%s'", filename); tr_logAddTrace("checking out '%s'", filename);
o->torrent_id = torrent_id; o->torrent_id = torrent_id;
o->file_index = i; o->file_index = i;
o->used_at = tr_time(); o->used_at = tr_time();
@ -514,7 +509,7 @@ tr_socket_t tr_fdSocketCreate(tr_session* session, int domain, int type)
if ((s == TR_BAD_SOCKET) && (sockerrno != EAFNOSUPPORT)) if ((s == TR_BAD_SOCKET) && (sockerrno != EAFNOSUPPORT))
{ {
logwarn(_("Couldn't create socket: %s"), tr_net_strerror(sockerrno).c_str()); tr_logAddWarn(_("Couldn't create socket: %s"), tr_net_strerror(sockerrno).c_str());
} }
} }
@ -536,7 +531,7 @@ tr_socket_t tr_fdSocketCreate(tr_session* session, int domain, int type)
if (getsockopt(s, SOL_SOCKET, SO_SNDBUF, reinterpret_cast<char*>(&i), &size) != -1) if (getsockopt(s, SOL_SOCKET, SO_SNDBUF, reinterpret_cast<char*>(&i), &size) != -1)
{ {
logtrace("SO_SNDBUF size is %d", i); tr_logAddTrace("SO_SNDBUF size is %d", i);
} }
i = 0; i = 0;
@ -544,7 +539,7 @@ tr_socket_t tr_fdSocketCreate(tr_session* session, int domain, int type)
if (getsockopt(s, SOL_SOCKET, SO_RCVBUF, reinterpret_cast<char*>(&i), &size) != -1) if (getsockopt(s, SOL_SOCKET, SO_RCVBUF, reinterpret_cast<char*>(&i), &size) != -1)
{ {
logtrace("SO_RCVBUF size is %d", i); tr_logAddTrace("SO_RCVBUF size is %d", i);
} }
buf_logged = true; buf_logged = true;

108
libtransmission/handshake.cc
View File

@ -131,16 +131,7 @@ struct tr_handshake
*** ***
**/ **/
#define logtrace(handshake, ...) \ #define tr_logAddTraceHand(handshake, ...) tr_logAddNamedTrace(handshake->io->addrStr(), __VA_ARGS__)
do \
{ \
if (tr_logLevelIsActive(TR_LOG_TRACE)) \
{ \
auto addrstr = std::array<char, TR_ADDRSTRLEN>{}; \
tr_peerIoGetAddrStr(handshake->io, std::data(addrstr), std::size(addrstr)); \
tr_logAddMessage(__FILE__, __LINE__, TR_LOG_TRACE, std::data(addrstr), __VA_ARGS__); \
} \
} while (0)
static char const* getStateName(handshake_state_t const state) static char const* getStateName(handshake_state_t const state)
{ {
@ -164,7 +155,7 @@ static char const* getStateName(handshake_state_t const state)
static void setState(tr_handshake* handshake, handshake_state_t state) static void setState(tr_handshake* handshake, handshake_state_t state)
{ {
logtrace(handshake, "setting to state [%s]", getStateName(state)); tr_logAddTraceHand(handshake, "setting to state [%s]", getStateName(state));
handshake->state = state; handshake->state = state;
} }
@ -223,7 +214,7 @@ static handshake_parse_err_t parseHandshake(tr_handshake* handshake, struct evbu
uint8_t name[HANDSHAKE_NAME_LEN]; uint8_t name[HANDSHAKE_NAME_LEN];
uint8_t reserved[HANDSHAKE_FLAGS_LEN]; uint8_t reserved[HANDSHAKE_FLAGS_LEN];
logtrace(handshake, "payload: need %d, got %zu", HANDSHAKE_SIZE, evbuffer_get_length(inbuf)); tr_logAddTraceHand(handshake, "payload: need %d, got %zu", HANDSHAKE_SIZE, evbuffer_get_length(inbuf));
if (evbuffer_get_length(inbuf) < HANDSHAKE_SIZE) if (evbuffer_get_length(inbuf) < HANDSHAKE_SIZE)
{ {
@ -246,7 +237,7 @@ static handshake_parse_err_t parseHandshake(tr_handshake* handshake, struct evbu
tr_peerIoReadBytes(handshake->io, inbuf, std::data(hash), std::size(hash)); tr_peerIoReadBytes(handshake->io, inbuf, std::data(hash), std::size(hash));
if (auto const torrent_hash = tr_peerIoGetTorrentHash(handshake->io); !torrent_hash || *torrent_hash != hash) if (auto const torrent_hash = tr_peerIoGetTorrentHash(handshake->io); !torrent_hash || *torrent_hash != hash)
{ {
logtrace(handshake, "peer returned the wrong hash. wtf?"); tr_logAddTraceHand(handshake, "peer returned the wrong hash. wtf?");
return HANDSHAKE_BAD_TORRENT; return HANDSHAKE_BAD_TORRENT;
} }
@ -256,11 +247,11 @@ static handshake_parse_err_t parseHandshake(tr_handshake* handshake, struct evbu
handshake->peer_id = peer_id; handshake->peer_id = peer_id;
/* peer id */ /* peer id */
logtrace(handshake, "peer-id is [%" TR_PRIsv "]", TR_PRIsv_ARG(peer_id)); tr_logAddTraceHand(handshake, "peer-id is [%" TR_PRIsv "]", TR_PRIsv_ARG(peer_id));
if (auto* const tor = handshake->session->torrents().get(hash); peer_id == tr_torrentGetPeerId(tor)) if (auto* const tor = handshake->session->torrents().get(hash); peer_id == tr_torrentGetPeerId(tor))
{ {
logtrace(handshake, "streuth! we've connected to ourselves."); tr_logAddTraceHand(handshake, "streuth! we've connected to ourselves.");
return HANDSHAKE_PEER_IS_SELF; return HANDSHAKE_PEER_IS_SELF;
} }
@ -384,7 +375,7 @@ static ReadState readYb(tr_handshake* handshake, struct evbuffer* inbuf)
} }
} }
logtrace(handshake, "got an %s handshake", (isEncrypted ? "encrypted" : "plain")); tr_logAddTraceHand(handshake, "got an %s handshake", (isEncrypted ? "encrypted" : "plain"));
tr_peerIoSetEncryption(handshake->io, isEncrypted ? PEER_ENCRYPTION_RC4 : PEER_ENCRYPTION_NONE); tr_peerIoSetEncryption(handshake->io, isEncrypted ? PEER_ENCRYPTION_RC4 : PEER_ENCRYPTION_NONE);
@ -413,7 +404,7 @@ static ReadState readYb(tr_handshake* handshake, struct evbuffer* inbuf)
auto const req1 = computeRequestHash(handshake, "req1"sv); auto const req1 = computeRequestHash(handshake, "req1"sv);
if (!req1) if (!req1)
{ {
logtrace(handshake, "error while computing req1 hash after Yb"); tr_logAddTraceHand(handshake, "error while computing req1 hash after Yb");
return tr_handshakeDone(handshake, false); return tr_handshakeDone(handshake, false);
} }
evbuffer_add(outbuf, std::data(*req1), std::size(*req1)); evbuffer_add(outbuf, std::data(*req1), std::size(*req1));
@ -425,7 +416,7 @@ static ReadState readYb(tr_handshake* handshake, struct evbuffer* inbuf)
auto const req3 = computeRequestHash(handshake, "req3"sv); auto const req3 = computeRequestHash(handshake, "req3"sv);
if (!req2 || !req3) if (!req2 || !req3)
{ {
logtrace(handshake, "error while computing req2/req3 hash after Yb"); tr_logAddTraceHand(handshake, "error while computing req2/req3 hash after Yb");
return tr_handshakeDone(handshake, false); return tr_handshakeDone(handshake, false);
} }
@ -491,7 +482,7 @@ static ReadState readVC(tr_handshake* handshake, struct evbuffer* inbuf)
{ {
if (evbuffer_get_length(inbuf) < VC_LENGTH) if (evbuffer_get_length(inbuf) < VC_LENGTH)
{ {
logtrace(handshake, "not enough bytes... returning read_more"); tr_logAddTraceHand(handshake, "not enough bytes... returning read_more");
return READ_LATER; return READ_LATER;
} }
@ -507,7 +498,7 @@ static ReadState readVC(tr_handshake* handshake, struct evbuffer* inbuf)
evbuffer_drain(inbuf, 1); evbuffer_drain(inbuf, 1);
} }
logtrace(handshake, "got it!"); tr_logAddTraceHand(handshake, "got it!");
evbuffer_drain(inbuf, key_len); evbuffer_drain(inbuf, key_len);
setState(handshake, AWAITING_CRYPTO_SELECT); setState(handshake, AWAITING_CRYPTO_SELECT);
return READ_NOW; return READ_NOW;
@ -525,21 +516,21 @@ static ReadState readCryptoSelect(tr_handshake* handshake, struct evbuffer* inbu
uint32_t crypto_select = 0; uint32_t crypto_select = 0;
tr_peerIoReadUint32(handshake->io, inbuf, &crypto_select); tr_peerIoReadUint32(handshake->io, inbuf, &crypto_select);
handshake->crypto_select = crypto_select; handshake->crypto_select = crypto_select;
logtrace(handshake, "crypto select is %d", (int)crypto_select); tr_logAddTraceHand(handshake, "crypto select is %d", (int)crypto_select);
if ((crypto_select & getCryptoProvide(handshake)) == 0) if ((crypto_select & getCryptoProvide(handshake)) == 0)
{ {
logtrace(handshake, "peer selected an encryption option we didn't offer"); tr_logAddTraceHand(handshake, "peer selected an encryption option we didn't offer");
return tr_handshakeDone(handshake, false); return tr_handshakeDone(handshake, false);
} }
uint16_t pad_d_len = 0; uint16_t pad_d_len = 0;
tr_peerIoReadUint16(handshake->io, inbuf, &pad_d_len); tr_peerIoReadUint16(handshake->io, inbuf, &pad_d_len);
logtrace(handshake, "pad_d_len is %d", (int)pad_d_len); tr_logAddTraceHand(handshake, "pad_d_len is %d", (int)pad_d_len);
if (pad_d_len > 512) if (pad_d_len > 512)
{ {
logtrace(handshake, "encryption handshake: pad_d_len is too long"); tr_logAddTraceHand(handshake, "encryption handshake: pad_d_len is too long");
return tr_handshakeDone(handshake, false); return tr_handshakeDone(handshake, false);
} }
@ -553,7 +544,7 @@ static ReadState readPadD(tr_handshake* handshake, struct evbuffer* inbuf)
{ {
size_t const needlen = handshake->pad_d_len; size_t const needlen = handshake->pad_d_len;
logtrace(handshake, "pad d: need %zu, got %zu", needlen, evbuffer_get_length(inbuf)); tr_logAddTraceHand(handshake, "pad d: need %zu, got %zu", needlen, evbuffer_get_length(inbuf));
if (evbuffer_get_length(inbuf) < needlen) if (evbuffer_get_length(inbuf) < needlen)
{ {
@ -576,7 +567,7 @@ static ReadState readPadD(tr_handshake* handshake, struct evbuffer* inbuf)
static ReadState readHandshake(tr_handshake* handshake, struct evbuffer* inbuf) static ReadState readHandshake(tr_handshake* handshake, struct evbuffer* inbuf)
{ {
logtrace(handshake, "payload: need %d, got %zu", INCOMING_HANDSHAKE_LEN, evbuffer_get_length(inbuf)); tr_logAddTraceHand(handshake, "payload: need %d, got %zu", INCOMING_HANDSHAKE_LEN, evbuffer_get_length(inbuf));
if (evbuffer_get_length(inbuf) < INCOMING_HANDSHAKE_LEN) if (evbuffer_get_length(inbuf) < INCOMING_HANDSHAKE_LEN)
{ {
@ -593,7 +584,7 @@ static ReadState readHandshake(tr_handshake* handshake, struct evbuffer* inbuf)
if (handshake->encryptionMode == TR_ENCRYPTION_REQUIRED) if (handshake->encryptionMode == TR_ENCRYPTION_REQUIRED)
{ {
logtrace(handshake, "peer is unencrypted, and we're disallowing that"); tr_logAddTraceHand(handshake, "peer is unencrypted, and we're disallowing that");
return tr_handshakeDone(handshake, false); return tr_handshakeDone(handshake, false);
} }
} }
@ -603,7 +594,7 @@ static ReadState readHandshake(tr_handshake* handshake, struct evbuffer* inbuf)
if (tr_peerIoIsIncoming(handshake->io)) if (tr_peerIoIsIncoming(handshake->io))
{ {
logtrace(handshake, "I think peer is sending us an encrypted handshake..."); tr_logAddTraceHand(handshake, "I think peer is sending us an encrypted handshake...");
setState(handshake, AWAITING_YA); setState(handshake, AWAITING_YA);
return READ_NOW; return READ_NOW;
} }
@ -612,7 +603,7 @@ static ReadState readHandshake(tr_handshake* handshake, struct evbuffer* inbuf)
if (pstrlen != 19) if (pstrlen != 19)
{ {
logtrace(handshake, "I think peer has sent us a corrupt handshake..."); tr_logAddTraceHand(handshake, "I think peer has sent us a corrupt handshake...");
return tr_handshakeDone(handshake, false); return tr_handshakeDone(handshake, false);
} }
} }
@ -650,7 +641,7 @@ static ReadState readHandshake(tr_handshake* handshake, struct evbuffer* inbuf)
{ {
if (!handshake->session->torrents().contains(hash)) if (!handshake->session->torrents().contains(hash))
{ {
logtrace(handshake, "peer is trying to connect to us for a torrent we don't have."); tr_logAddTraceHand(handshake, "peer is trying to connect to us for a torrent we don't have.");
return tr_handshakeDone(handshake, false); return tr_handshakeDone(handshake, false);
} }
@ -661,7 +652,7 @@ static ReadState readHandshake(tr_handshake* handshake, struct evbuffer* inbuf)
auto const torrent_hash = tr_peerIoGetTorrentHash(handshake->io); auto const torrent_hash = tr_peerIoGetTorrentHash(handshake->io);
if (!torrent_hash || *torrent_hash != hash) if (!torrent_hash || *torrent_hash != hash)
{ {
logtrace(handshake, "peer returned the wrong hash. wtf?"); tr_logAddTraceHand(handshake, "peer returned the wrong hash. wtf?");
return tr_handshakeDone(handshake, false); return tr_handshakeDone(handshake, false);
} }
} }
@ -700,7 +691,7 @@ static ReadState readPeerId(tr_handshake* handshake, struct evbuffer* inbuf)
char client[128] = {}; char client[128] = {};
tr_clientForId(client, sizeof(client), peer_id); tr_clientForId(client, sizeof(client), peer_id);
logtrace(handshake, "peer-id is [%s] ... isIncoming is %d", client, tr_peerIoIsIncoming(handshake->io)); tr_logAddTraceHand(handshake, "peer-id is [%s] ... isIncoming is %d", client, tr_peerIoIsIncoming(handshake->io));
// if we've somehow connected to ourselves, don't keep the connection // if we've somehow connected to ourselves, don't keep the connection
auto const hash = tr_peerIoGetTorrentHash(handshake->io); auto const hash = tr_peerIoGetTorrentHash(handshake->io);
@ -712,7 +703,7 @@ static ReadState readPeerId(tr_handshake* handshake, struct evbuffer* inbuf)
static ReadState readYa(tr_handshake* handshake, struct evbuffer* inbuf) static ReadState readYa(tr_handshake* handshake, struct evbuffer* inbuf)
{ {
logtrace(handshake, "in readYa... need %d, have %zu", KEY_LEN, evbuffer_get_length(inbuf)); tr_logAddTraceHand(handshake, "in readYa... need %d, have %zu", KEY_LEN, evbuffer_get_length(inbuf));
if (evbuffer_get_length(inbuf) < KEY_LEN) if (evbuffer_get_length(inbuf) < KEY_LEN)
{ {
@ -731,13 +722,13 @@ static ReadState readYa(tr_handshake* handshake, struct evbuffer* inbuf)
auto req1 = computeRequestHash(handshake, "req1"sv); auto req1 = computeRequestHash(handshake, "req1"sv);
if (!req1) if (!req1)
{ {
logtrace(handshake, "error while computing req1 hash after Ya"); tr_logAddTraceHand(handshake, "error while computing req1 hash after Ya");
return tr_handshakeDone(handshake, false); return tr_handshakeDone(handshake, false);
} }
handshake->myReq1 = *req1; handshake->myReq1 = *req1;
/* send our public key to the peer */ /* send our public key to the peer */
logtrace(handshake, "sending B->A: Diffie Hellman Yb, PadB"); tr_logAddTraceHand(handshake, "sending B->A: Diffie Hellman Yb, PadB");
uint8_t outbuf[KEY_LEN + PadB_MAXLEN]; uint8_t outbuf[KEY_LEN + PadB_MAXLEN];
uint8_t* walk = outbuf; uint8_t* walk = outbuf;
int len = 0; int len = 0;
@ -764,7 +755,7 @@ static ReadState readPadA(tr_handshake* handshake, struct evbuffer* inbuf)
if (ptr.pos != -1) /* match */ if (ptr.pos != -1) /* match */
{ {
evbuffer_drain(inbuf, ptr.pos); evbuffer_drain(inbuf, ptr.pos);
logtrace(handshake, "found it... looking setting to awaiting_crypto_provide"); tr_logAddTraceHand(handshake, "found it... looking setting to awaiting_crypto_provide");
setState(handshake, AWAITING_CRYPTO_PROVIDE); setState(handshake, AWAITING_CRYPTO_PROVIDE);
return READ_NOW; return READ_NOW;
} }
@ -799,14 +790,14 @@ static ReadState readCryptoProvide(tr_handshake* handshake, struct evbuffer* inb
/* This next piece is HASH('req2', SKEY) xor HASH('req3', S) ... /* This next piece is HASH('req2', SKEY) xor HASH('req3', S) ...
* we can get the first half of that (the obufscatedTorrentHash) * we can get the first half of that (the obufscatedTorrentHash)
* by building the latter and xor'ing it with what the peer sent us */ * by building the latter and xor'ing it with what the peer sent us */
logtrace(handshake, "reading obfuscated torrent hash..."); tr_logAddTraceHand(handshake, "reading obfuscated torrent hash...");
auto req2 = tr_sha1_digest_t{}; auto req2 = tr_sha1_digest_t{};
evbuffer_remove(inbuf, std::data(req2), std::size(req2)); evbuffer_remove(inbuf, std::data(req2), std::size(req2));
auto const req3 = computeRequestHash(handshake, "req3"sv); auto const req3 = computeRequestHash(handshake, "req3"sv);
if (!req3) if (!req3)
{ {
logtrace(handshake, "error while computing req3 hash after req2"); tr_logAddTraceHand(handshake, "error while computing req3 hash after req2");
return tr_handshakeDone(handshake, false); return tr_handshakeDone(handshake, false);
} }
@ -820,18 +811,18 @@ static ReadState readCryptoProvide(tr_handshake* handshake, struct evbuffer* inb
{ {
bool const clientIsSeed = tor->isDone(); bool const clientIsSeed = tor->isDone();
bool const peerIsSeed = tr_peerMgrPeerIsSeed(tor, tr_peerIoGetAddress(handshake->io, nullptr)); bool const peerIsSeed = tr_peerMgrPeerIsSeed(tor, tr_peerIoGetAddress(handshake->io, nullptr));
logtrace(handshake, "got INCOMING connection's encrypted handshake for torrent [%s]", tr_torrentName(tor)); tr_logAddTraceHand(handshake, "got INCOMING connection's encrypted handshake for torrent [%s]", tr_torrentName(tor));
tr_peerIoSetTorrentHash(handshake->io, tor->infoHash()); tr_peerIoSetTorrentHash(handshake->io, tor->infoHash());
if (clientIsSeed && peerIsSeed) if (clientIsSeed && peerIsSeed)
{ {
logtrace(handshake, "another seed tried to reconnect to us!"); tr_logAddTraceHand(handshake, "another seed tried to reconnect to us!");
return tr_handshakeDone(handshake, false); return tr_handshakeDone(handshake, false);
} }
} }
else else
{ {
logtrace(handshake, "can't find that torrent..."); tr_logAddTraceHand(handshake, "can't find that torrent...");
return tr_handshakeDone(handshake, false); return tr_handshakeDone(handshake, false);
} }
@ -843,10 +834,10 @@ static ReadState readCryptoProvide(tr_handshake* handshake, struct evbuffer* inb
tr_peerIoReadUint32(handshake->io, inbuf, &crypto_provide); tr_peerIoReadUint32(handshake->io, inbuf, &crypto_provide);
handshake->crypto_provide = crypto_provide; handshake->crypto_provide = crypto_provide;
logtrace(handshake, "crypto_provide is %d", (int)crypto_provide); tr_logAddTraceHand(handshake, "crypto_provide is %d", (int)crypto_provide);
tr_peerIoReadUint16(handshake->io, inbuf, &padc_len); tr_peerIoReadUint16(handshake->io, inbuf, &padc_len);
logtrace(handshake, "padc is %d", (int)padc_len); tr_logAddTraceHand(handshake, "padc is %d", (int)padc_len);
handshake->pad_c_len = padc_len; handshake->pad_c_len = padc_len;
setState(handshake, AWAITING_PAD_C); setState(handshake, AWAITING_PAD_C);
return READ_NOW; return READ_NOW;
@ -868,7 +859,7 @@ static ReadState readPadC(tr_handshake* handshake, struct evbuffer* inbuf)
/* read ia_len */ /* read ia_len */
tr_peerIoReadUint16(handshake->io, inbuf, &ia_len); tr_peerIoReadUint16(handshake->io, inbuf, &ia_len);
logtrace(handshake, "ia_len is %d", (int)ia_len); tr_logAddTraceHand(handshake, "ia_len is %d", (int)ia_len);
handshake->ia_len = ia_len; handshake->ia_len = ia_len;
setState(handshake, AWAITING_IA); setState(handshake, AWAITING_IA);
return READ_NOW; return READ_NOW;
@ -878,7 +869,7 @@ static ReadState readIA(tr_handshake* handshake, struct evbuffer const* inbuf)
{ {
size_t const needlen = handshake->ia_len; size_t const needlen = handshake->ia_len;
logtrace(handshake, "reading IA... have %zu, need %zu", evbuffer_get_length(inbuf), needlen); tr_logAddTraceHand(handshake, "reading IA... have %zu, need %zu", evbuffer_get_length(inbuf), needlen);
if (evbuffer_get_length(inbuf) < needlen) if (evbuffer_get_length(inbuf) < needlen)
{ {
@ -897,7 +888,7 @@ static ReadState readIA(tr_handshake* handshake, struct evbuffer const* inbuf)
uint8_t vc[VC_LENGTH]; uint8_t vc[VC_LENGTH];
memset(vc, 0, VC_LENGTH); memset(vc, 0, VC_LENGTH);
evbuffer_add(outbuf, vc, VC_LENGTH); evbuffer_add(outbuf, vc, VC_LENGTH);
logtrace(handshake, "sending vc"); tr_logAddTraceHand(handshake, "sending vc");
} }
/* send crypto_select */ /* send crypto_select */
@ -905,17 +896,17 @@ static ReadState readIA(tr_handshake* handshake, struct evbuffer const* inbuf)
if (crypto_select != 0) if (crypto_select != 0)
{ {
logtrace(handshake, "selecting crypto mode '%d'", (int)crypto_select); tr_logAddTraceHand(handshake, "selecting crypto mode '%d'", (int)crypto_select);
evbuffer_add_uint32(outbuf, crypto_select); evbuffer_add_uint32(outbuf, crypto_select);
} }
else else
{ {
logtrace(handshake, "peer didn't offer an encryption mode we like."); tr_logAddTraceHand(handshake, "peer didn't offer an encryption mode we like.");
evbuffer_free(outbuf); evbuffer_free(outbuf);
return tr_handshakeDone(handshake, false); return tr_handshakeDone(handshake, false);
} }
logtrace(handshake, "sending pad d"); tr_logAddTraceHand(handshake, "sending pad d");
/* ENCRYPT(VC, crypto_provide, len(PadD), PadD /* ENCRYPT(VC, crypto_provide, len(PadD), PadD
* PadD is reserved for future extensions to the handshake... * PadD is reserved for future extensions to the handshake...
@ -932,7 +923,7 @@ static ReadState readIA(tr_handshake* handshake, struct evbuffer const* inbuf)
tr_peerIoSetEncryption(handshake->io, PEER_ENCRYPTION_NONE); tr_peerIoSetEncryption(handshake->io, PEER_ENCRYPTION_NONE);
} }
logtrace(handshake, "sending handshake"); tr_logAddTraceHand(handshake, "sending handshake");
/* send our handshake */ /* send our handshake */
{ {
@ -960,7 +951,7 @@ static ReadState readPayloadStream(tr_handshake* handshake, struct evbuffer* inb
{ {
size_t const needlen = HANDSHAKE_SIZE; size_t const needlen = HANDSHAKE_SIZE;
logtrace(handshake, "reading payload stream... have %zu, need %zu", evbuffer_get_length(inbuf), needlen); tr_logAddTraceHand(handshake, "reading payload stream... have %zu, need %zu", evbuffer_get_length(inbuf), needlen);
if (evbuffer_get_length(inbuf) < needlen) if (evbuffer_get_length(inbuf) < needlen)
{ {
@ -969,7 +960,7 @@ static ReadState readPayloadStream(tr_handshake* handshake, struct evbuffer* inb
/* parse the handshake ... */ /* parse the handshake ... */
handshake_parse_err_t const i = parseHandshake(handshake, inbuf); handshake_parse_err_t const i = parseHandshake(handshake, inbuf);
logtrace(handshake, "parseHandshake returned %d", i); tr_logAddTraceHand(handshake, "parseHandshake returned %d", i);
if (i != HANDSHAKE_OK) if (i != HANDSHAKE_OK)
{ {
@ -998,7 +989,7 @@ static ReadState canRead(tr_peerIo* io, void* vhandshake, size_t* piece)
/* no piece data in handshake */ /* no piece data in handshake */
*piece = 0; *piece = 0;
logtrace(handshake, "handling canRead; state is [%s]", getStateName(handshake->state)); tr_logAddTraceHand(handshake, "handling canRead; state is [%s]", getStateName(handshake->state));
ReadState ret = READ_NOW; ReadState ret = READ_NOW;
while (readyForMore) while (readyForMore)
@ -1109,7 +1100,7 @@ static void tr_handshakeFree(tr_handshake* handshake)
static ReadState tr_handshakeDone(tr_handshake* handshake, bool isOK) static ReadState tr_handshakeDone(tr_handshake* handshake, bool isOK)
{ {
logtrace(handshake, "handshakeDone: %s", isOK ? "connected" : "aborting"); tr_logAddTraceHand(handshake, "handshakeDone: %s", isOK ? "connected" : "aborting");
tr_peerIoSetIOFuncs(handshake->io, nullptr, nullptr, nullptr, nullptr); tr_peerIoSetIOFuncs(handshake->io, nullptr, nullptr, nullptr, nullptr);
bool const success = fireDoneFunc(handshake, isOK); bool const success = fireDoneFunc(handshake, isOK);
@ -1161,7 +1152,7 @@ static void gotError(tr_peerIo* io, short what, void* vhandshake)
{ {
uint8_t msg[HANDSHAKE_SIZE]; uint8_t msg[HANDSHAKE_SIZE];
logtrace(handshake, "handshake failed, trying plaintext..."); tr_logAddTraceHand(handshake, "handshake failed, trying plaintext...");
buildHandshakeMessage(handshake, msg); buildHandshakeMessage(handshake, msg);
handshake->haveSentBitTorrentHandshake = true; handshake->haveSentBitTorrentHandshake = true;
setReadState(handshake, AWAITING_HANDSHAKE); setReadState(handshake, AWAITING_HANDSHAKE);
@ -1169,7 +1160,12 @@ static void gotError(tr_peerIo* io, short what, void* vhandshake)
} }
else else
{ {
logtrace(handshake, "libevent got an error what==%d, errno=%d (%s)", (int)what, errcode, tr_strerror(errcode)); tr_logAddTraceHand(
handshake,
"libevent got an error what==%d, errno=%d (%s)",
(int)what,
errcode,
tr_strerror(errcode));
tr_handshakeDone(handshake, false); tr_handshakeDone(handshake, false);
} }
} }

6
libtransmission/inout.cc
View File

@ -131,7 +131,7 @@ int readOrWriteBytes(
if (fd == TR_BAD_SYS_FILE) if (fd == TR_BAD_SYS_FILE)
{ {
err = errno; err = errno;
tr_logAddTorErr(tor, "tr_fdFileCheckout failed for \"%s\": %s", filename.c_str(), tr_strerror(err)); tr_logAddErrorTor(tor, "tr_fdFileCheckout failed for \"%s\": %s", filename.c_str(), tr_strerror(err));
} }
else if (doWrite) else if (doWrite)
{ {
@ -160,7 +160,7 @@ int readOrWriteBytes(
if (!readEntireBuf(fd, file_offset, buf, buflen, &error)) if (!readEntireBuf(fd, file_offset, buf, buflen, &error))
{ {
err = error->code; err = error->code;
tr_logAddTorErr(tor, "read failed for \"%s\": %s", tor->fileSubpath(file_index).c_str(), error->message); tr_logAddErrorTor(tor, "read failed for \"%s\": %s", tor->fileSubpath(file_index).c_str(), error->message);
tr_error_free(error); tr_error_free(error);
} }
break; break;
@ -169,7 +169,7 @@ int readOrWriteBytes(
if (!writeEntireBuf(fd, file_offset, buf, buflen, &error)) if (!writeEntireBuf(fd, file_offset, buf, buflen, &error))
{ {
err = error->code; err = error->code;
tr_logAddTorErr(tor, "write failed for \"%s\": %s", tor->fileSubpath(file_index).c_str(), error->message); tr_logAddErrorTor(tor, "write failed for \"%s\": %s", tor->fileSubpath(file_index).c_str(), error->message);
tr_error_free(error); tr_error_free(error);
} }
break; break;

10
libtransmission/log.cc
View File

@ -43,7 +43,7 @@ tr_log_level tr_logGetLevel()
static std::recursive_mutex message_mutex_; static std::recursive_mutex message_mutex_;
tr_sys_file_t tr_logGetFile() static tr_sys_file_t tr_logGetFile()
{ {
static bool initialized = false; static bool initialized = false;
static tr_sys_file_t file = TR_BAD_SYS_FILE; static tr_sys_file_t file = TR_BAD_SYS_FILE;
@ -139,7 +139,7 @@ void tr_logAddMessage(
[[maybe_unused]] char const* file, [[maybe_unused]] char const* file,
[[maybe_unused]] int line, [[maybe_unused]] int line,
tr_log_level level, tr_log_level level,
[[maybe_unused]] char const* name, [[maybe_unused]] std::string_view name,
char const* fmt, char const* fmt,
...) ...)
{ {
@ -218,7 +218,7 @@ void tr_logAddMessage(
newmsg->message = tr_strndup(buf, buf_len); newmsg->message = tr_strndup(buf, buf_len);
newmsg->file = file; newmsg->file = file;
newmsg->line = line; newmsg->line = line;
newmsg->name = tr_strdup(name); newmsg->name = tr_strvDup(name);
*myQueueTail = newmsg; *myQueueTail = newmsg;
myQueueTail = &newmsg->next; myQueueTail = &newmsg->next;
@ -247,8 +247,8 @@ void tr_logAddMessage(
tr_logGetTimeStr(timestr, sizeof(timestr)); tr_logGetTimeStr(timestr, sizeof(timestr));
auto const out = name != nullptr ? tr_strvJoin("["sv, timestr, "] "sv, name, ": "sv, buf) : auto const out = !std::empty(name) ? tr_strvJoin("["sv, timestr, "] "sv, name, ": "sv, buf) :
tr_strvJoin("["sv, timestr, "] "sv, buf); tr_strvJoin("["sv, timestr, "] "sv, buf);
tr_sys_file_write_line(fp, out, nullptr); tr_sys_file_write_line(fp, out, nullptr);
tr_sys_file_flush(fp, nullptr); tr_sys_file_flush(fp, nullptr);
} }

40
libtransmission/log.h
View File

@ -5,51 +5,45 @@
#pragma once #pragma once
#include <stddef.h> /* size_t */ #include <string_view>
#include "file.h" /* tr_sys_file_t */
#include "transmission.h" #include "transmission.h"
#define TR_LOG_MAX_QUEUE_LENGTH 10000 #define TR_LOG_MAX_QUEUE_LENGTH 10000
tr_log_level tr_logGetLevel(void); [[nodiscard]] tr_log_level tr_logGetLevel(void);
static inline bool tr_logLevelIsActive(tr_log_level level) [[nodiscard]] static inline bool tr_logLevelIsActive(tr_log_level level)
{ {
return tr_logGetLevel() >= level; return tr_logGetLevel() >= level;
} }
void tr_logAddMessage(char const* file, int line, tr_log_level level, char const* torrent, char const* fmt, ...) void tr_logAddMessage(char const* file, int line, tr_log_level level, std::string_view name, char const* fmt, ...)
TR_GNUC_PRINTF(5, 6); TR_GNUC_PRINTF(5, 6);
#define tr_logAddNamed(level, name, ...) \ #define tr_logAddNamed(level, name, ...) \
do \ do \
{ \ { \
if (tr_logLevelIsActive(level)) \ if (tr_logGetLevel() >= level) \
{ \ { \
tr_logAddMessage(__FILE__, __LINE__, level, name, __VA_ARGS__); \ tr_logAddMessage(__FILE__, __LINE__, level, name, __VA_ARGS__); \
} \ } \
} while (0) } while (0)
#define tr_logAddNamedError(name, ...) tr_logAddNamed(TR_LOG_ERROR, name, __VA_ARGS__) #define tr_logAddNamedCritical(name, ...) tr_logAddNamed(TR_LOG_CRITICAL, (name), __VA_ARGS__)
#define tr_logAddNamedInfo(name, ...) tr_logAddNamed(TR_LOG_INFO, name, __VA_ARGS__) #define tr_logAddNamedError(name, ...) tr_logAddNamed(TR_LOG_ERROR, (name), __VA_ARGS__)
#define tr_logAddNamedDbg(name, ...) tr_logAddNamed(TR_LOG_DEBUG, name, __VA_ARGS__) #define tr_logAddNamedWarn(name, ...) tr_logAddNamed(TR_LOG_WARN, (name), __VA_ARGS__)
#define tr_logAddNamedInfo(name, ...) tr_logAddNamed(TR_LOG_INFO, (name), __VA_ARGS__)
#define tr_logAddNamedDebug(name, ...) tr_logAddNamed(TR_LOG_DEBUG, (name), __VA_ARGS__)
#define tr_logAddNamedTrace(name, ...) tr_logAddNamed(TR_LOG_TRACE, (name), __VA_ARGS__)
#define tr_logAddTor(level, tor, ...) tr_logAddNamed(level, tr_torrentName(tor), __VA_ARGS__) #define tr_logAddCritical(...) tr_logAddNamed(TR_LOG_CRITICAL, "", __VA_ARGS__)
#define tr_logAddError(...) tr_logAddNamed(TR_LOG_ERROR, "", __VA_ARGS__)
#define tr_logAddWarn(...) tr_logAddNamed(TR_LOG_WARN, "", __VA_ARGS__)
#define tr_logAddInfo(...) tr_logAddNamed(TR_LOG_INFO, "", __VA_ARGS__)
#define tr_logAddDebug(...) tr_logAddNamed(TR_LOG_DEBUG, "", __VA_ARGS__)
#define tr_logAddTrace(...) tr_logAddNamed(TR_LOG_TRACE, "", __VA_ARGS__)
#define tr_logAddTorErr(tor, ...) tr_logAddTor(TR_LOG_ERROR, tor, __VA_ARGS__)
#define tr_logAddTorInfo(tor, ...) tr_logAddTor(TR_LOG_INFO, tor, __VA_ARGS__)
#define tr_logAddTorDbg(tor, ...) tr_logAddTor(TR_LOG_DEBUG, tor, __VA_ARGS__)
#define tr_logAdd(level, ...) tr_logAddNamed(level, nullptr, __VA_ARGS__)
#define tr_logAddError(...) tr_logAdd(TR_LOG_ERROR, __VA_ARGS__)
#define tr_logAddInfo(...) tr_logAdd(TR_LOG_INFO, __VA_ARGS__)
#define tr_logAddDebug(...) tr_logAdd(TR_LOG_DEBUG, __VA_ARGS__)
tr_sys_file_t tr_logGetFile(void);
/** @brief set the buffer with the current time formatted for deep logging. */
char* tr_logGetTimeStr(char* buf, size_t buflen) TR_GNUC_NONNULL(1); char* tr_logGetTimeStr(char* buf, size_t buflen) TR_GNUC_NONNULL(1);
/** @} */ /** @} */

4
libtransmission/makemeta.cc
View File

@ -55,7 +55,7 @@ static struct FileList* getFiles(char const* dir, char const* base, struct FileL
tr_sys_path_info info; tr_sys_path_info info;
if (tr_error* error = nullptr; !tr_sys_path_get_info(buf.c_str(), 0, &info, &error)) if (tr_error* error = nullptr; !tr_sys_path_get_info(buf.c_str(), 0, &info, &error))
{ {
tr_logAddError(_("Torrent Creator is skipping file \"%s\": %s"), buf.c_str(), error->message); tr_logAddWarn(_("Torrent Creator is skipping file \"%s\": %s"), buf.c_str(), error->message);
tr_error_free(error); tr_error_free(error);
return list; return list;
} }
@ -200,7 +200,7 @@ bool tr_metaInfoBuilderSetPieceSize(tr_metainfo_builder* b, uint32_t bytes)
{ {
if (!isValidPieceSize(bytes)) if (!isValidPieceSize(bytes))
{ {
tr_logAddError( tr_logAddWarn(
_("Failed to set piece size to %s, leaving it at %s"), _("Failed to set piece size to %s, leaving it at %s"),
tr_formatter_mem_B(bytes).c_str(), tr_formatter_mem_B(bytes).c_str(),
tr_formatter_mem_B(b->pieceSize).c_str()); tr_formatter_mem_B(b->pieceSize).c_str());

18
libtransmission/natpmp.cc
View File

@ -6,6 +6,7 @@
#include <cerrno> #include <cerrno>
#include <ctime> #include <ctime>
#include <cinttypes> #include <cinttypes>
#include <string_view>
#include <event2/util.h> /* evutil_inet_ntop() */ #include <event2/util.h> /* evutil_inet_ntop() */
@ -22,10 +23,7 @@
static auto constexpr LifetimeSecs = uint32_t{ 3600 }; static auto constexpr LifetimeSecs = uint32_t{ 3600 };
static auto constexpr CommandWaitSecs = time_t{ 8 }; static auto constexpr CommandWaitSecs = time_t{ 8 };
static char const* getKey() static auto constexpr CodeName = std::string_view{ "nat-pmp" };
{
return _("Port Forwarding (NAT-PMP)");
}
/** /**
*** ***
@ -40,12 +38,12 @@ static void logVal(char const* func, int ret)
if (ret >= 0) if (ret >= 0)
{ {
tr_logAddNamedInfo(getKey(), _("%s succeeded (%d)"), func, ret); tr_logAddNamedInfo(CodeName, _("%s succeeded (%d)"), func, ret);
} }
else else
{ {
tr_logAddNamedDbg( tr_logAddNamedDebug(
getKey(), CodeName,
"%s failed. Natpmp returned %d (%s); errno is %d (%s)", "%s failed. Natpmp returned %d (%s); errno is %d (%s)",
func, func,
ret, ret,
@ -112,7 +110,7 @@ tr_port_forwarding tr_natpmpPulse(
{ {
char str[128]; char str[128];
evutil_inet_ntop(AF_INET, &response.pnu.publicaddress.addr, str, sizeof(str)); evutil_inet_ntop(AF_INET, &response.pnu.publicaddress.addr, str, sizeof(str));
tr_logAddNamedInfo(getKey(), _("Found public address \"%s\""), str); tr_logAddNamedInfo(CodeName, _("Found public address \"%s\""), str);
nat->state = TR_NATPMP_IDLE; nat->state = TR_NATPMP_IDLE;
} }
else if (val != NATPMP_TRYAGAIN) else if (val != NATPMP_TRYAGAIN)
@ -145,7 +143,7 @@ tr_port_forwarding tr_natpmpPulse(
{ {
int const unmapped_port = resp.pnu.newportmapping.privateport; int const unmapped_port = resp.pnu.newportmapping.privateport;
tr_logAddNamedInfo(getKey(), _("no longer forwarding port %d"), unmapped_port); tr_logAddNamedInfo(CodeName, _("no longer forwarding port %d"), unmapped_port);
if (nat->private_port == unmapped_port) if (nat->private_port == unmapped_port)
{ {
@ -194,7 +192,7 @@ tr_port_forwarding tr_natpmpPulse(
nat->renew_time = tr_time() + (resp.pnu.newportmapping.lifetime / 2); nat->renew_time = tr_time() + (resp.pnu.newportmapping.lifetime / 2);
nat->private_port = resp.pnu.newportmapping.privateport; nat->private_port = resp.pnu.newportmapping.privateport;
nat->public_port = resp.pnu.newportmapping.mappedpublicport; nat->public_port = resp.pnu.newportmapping.mappedpublicport;
tr_logAddNamedInfo(getKey(), _("Port %d forwarded successfully"), nat->private_port); tr_logAddNamedInfo(CodeName, _("Port %d forwarded successfully"), nat->private_port);
} }
else if (val != NATPMP_TRYAGAIN) else if (val != NATPMP_TRYAGAIN)
{ {

17
libtransmission/net.cc
View File

@ -137,6 +137,23 @@ std::optional<tr_address> tr_address::from_string(std::string_view str)
return addr; return addr;
} }
std::string tr_address::to_string() const
{
auto addrbuf = std::array<char, TR_ADDRSTRLEN>{};
tr_address_to_string_with_buf(this, std::data(addrbuf), std::size(addrbuf));
return std::data(addrbuf);
}
std::string tr_address::to_string(tr_port port) const
{
auto addrbuf = std::array<char, TR_ADDRSTRLEN>{};
tr_address_to_string_with_buf(this, std::data(addrbuf), std::size(addrbuf));
auto buf = std::array<char, TR_ADDRSTRLEN>{};
tr_snprintf(std::data(buf), std::size(buf), "[%s]:%u", std::data(addrbuf), ntohs(port));
return std::data(buf);
}
tr_address tr_address::from_4byte_ipv4(std::string_view in) tr_address tr_address::from_4byte_ipv4(std::string_view in)
{ {
TR_ASSERT(std::size(in) == 4); TR_ASSERT(std::size(in) == 4);

3
libtransmission/net.h
View File

@ -78,6 +78,9 @@ struct tr_address
static std::optional<tr_address> from_string(std::string_view str); static std::optional<tr_address> from_string(std::string_view str);
std::string to_string() const;
std::string to_string(tr_port port) const;
tr_address_type type; tr_address_type type;
union union
{ {

123
libtransmission/peer-io.cc
View File

@ -41,6 +41,11 @@
#define UTP_READ_BUFFER_SIZE (256 * 1024) #define UTP_READ_BUFFER_SIZE (256 * 1024)
#define tr_logAddErrorIo(io, ...) tr_logAddNamedError((io)->addrStr(), __VA_ARGS__)
#define tr_logAddWarnIo(io, ...) tr_logAddNamedWarn((io)->addrStr(), __VA_ARGS__)
#define tr_logAddDebugIo(io, ...) tr_logAddNamedDebug((io)->addrStr(), __VA_ARGS__)
#define tr_logAddTraceIo(io, ...) tr_logAddNamedTrace((io)->addrStr(), __VA_ARGS__)
static size_t guessPacketOverhead(size_t d) static size_t guessPacketOverhead(size_t d)
{ {
/** /**
@ -68,26 +73,6 @@ static size_t guessPacketOverhead(size_t d)
*** ***
**/ **/
#define logimpl(io, level, ...) \
do \
{ \
if (tr_logLevelIsActive(level)) \
{ \
auto name = std::array<char, TR_ADDRSTRLEN>{}; \
tr_peerIoGetAddrStr(io, std::data(name), std::size(name)); \
tr_logAddMessage(__FILE__, __LINE__, level, std::data(name), __VA_ARGS__); \
} \
} while (0)
#define logerr(io, ...) logimpl(io, TR_LOG_ERROR, __VA_ARGS__)
#define logwarn(io, ...) logimpl(io, TR_LOG_WARN, __VA_ARGS__)
#define logdbg(io, ...) logimpl(io, TR_LOG_DEBUG, __VA_ARGS__)
#define logtrace(io, ...) logimpl(io, TR_LOG_TRACE, __VA_ARGS__)
/**
***
**/
struct tr_datatype struct tr_datatype
{ {
struct tr_datatype* next; struct tr_datatype* next;
@ -193,7 +178,7 @@ static void didWriteWrapper(tr_peerIo* io, unsigned int bytes_transferred)
static void canReadWrapper(tr_peerIo* io) static void canReadWrapper(tr_peerIo* io)
{ {
logtrace(io, "canRead"); tr_logAddTraceIo(io, "canRead");
tr_peerIoRef(io); tr_peerIoRef(io);
@ -278,7 +263,7 @@ static void event_read_cb(evutil_socket_t fd, short /*event*/, void* vio)
unsigned int howmuch = curlen >= max ? 0 : max - curlen; unsigned int howmuch = curlen >= max ? 0 : max - curlen;
howmuch = io->bandwidth->clamp(TR_DOWN, howmuch); howmuch = io->bandwidth->clamp(TR_DOWN, howmuch);
logtrace(io, "libevent says this peer is ready to read"); tr_logAddTraceIo(io, "libevent says this peer is ready to read");
/* if we don't have any bandwidth left, stop reading */ /* if we don't have any bandwidth left, stop reading */
if (howmuch < 1) if (howmuch < 1)
@ -317,7 +302,7 @@ static void event_read_cb(evutil_socket_t fd, short /*event*/, void* vio)
what |= BEV_EVENT_ERROR; what |= BEV_EVENT_ERROR;
} }
logdbg(io, "event_read_cb err: res:%d, what:%hd, errno:%d (%s)", res, what, e, tr_net_strerror(e).c_str()); tr_logAddDebugIo(io, "event_read_cb err: res:%d, what:%hd, errno:%d (%s)", res, what, e, tr_net_strerror(e).c_str());
if (io->gotError != nullptr) if (io->gotError != nullptr)
{ {
@ -331,7 +316,7 @@ static int tr_evbuffer_write(tr_peerIo* io, int fd, size_t howmuch)
EVUTIL_SET_SOCKET_ERROR(0); EVUTIL_SET_SOCKET_ERROR(0);
int const n = evbuffer_write_atmost(io->outbuf, fd, howmuch); int const n = evbuffer_write_atmost(io->outbuf, fd, howmuch);
int const e = EVUTIL_SOCKET_ERROR(); int const e = EVUTIL_SOCKET_ERROR();
logtrace(io, "wrote %d to peer (%s)", n, (n == -1 ? tr_net_strerror(e).c_str() : "")); tr_logAddTraceIo(io, "wrote %d to peer (%s)", n, (n == -1 ? tr_net_strerror(e).c_str() : ""));
return n; return n;
} }
@ -349,7 +334,7 @@ static void event_write_cb(evutil_socket_t fd, short /*event*/, void* vio)
io->pendingEvents &= ~EV_WRITE; io->pendingEvents &= ~EV_WRITE;
logtrace(io, "libevent says this peer is ready to write"); tr_logAddTraceIo(io, "libevent says this peer is ready to write");
/* Write as much as possible, since the socket is non-blocking, write() will /* Write as much as possible, since the socket is non-blocking, write() will
* return if it can't write any more data without blocking */ * return if it can't write any more data without blocking */
@ -405,7 +390,7 @@ RESCHEDULE:
FAIL: FAIL:
auto const errmsg = tr_net_strerror(e); auto const errmsg = tr_net_strerror(e);
logdbg(io, "event_write_cb got an err. res:%d, what:%hd, errno:%d (%s)", res, what, e, errmsg.c_str()); tr_logAddDebugIo(io, "event_write_cb got an err. res:%d, what:%hd, errno:%d (%s)", res, what, e, errmsg.c_str());
if (io->gotError != nullptr) if (io->gotError != nullptr)
{ {
@ -435,7 +420,7 @@ static void utp_on_read(void* vio, unsigned char const* buf, size_t buflen)
TR_ASSERT(tr_isPeerIo(io)); TR_ASSERT(tr_isPeerIo(io));
int rc = evbuffer_add(io->inbuf, buf, buflen); int rc = evbuffer_add(io->inbuf, buf, buflen);
logtrace(io, "utp_on_read got %zu bytes", buflen); tr_logAddTraceIo(io, "utp_on_read got %zu bytes", buflen);
if (rc < 0) if (rc < 0)
{ {
@ -454,12 +439,12 @@ static void utp_on_write(void* vio, unsigned char* buf, size_t buflen)
TR_ASSERT(tr_isPeerIo(io)); TR_ASSERT(tr_isPeerIo(io));
int rc = evbuffer_remove(io->outbuf, buf, buflen); int rc = evbuffer_remove(io->outbuf, buf, buflen);
logtrace(io, "utp_on_write sending %zu bytes... evbuffer_remove returned %d", buflen, rc); tr_logAddTraceIo(io, "utp_on_write sending %zu bytes... evbuffer_remove returned %d", buflen, rc);
TR_ASSERT(rc == (int)buflen); /* if this fails, we've corrupted our bookkeeping somewhere */ TR_ASSERT(rc == (int)buflen); /* if this fails, we've corrupted our bookkeeping somewhere */
if (rc < (long)buflen) if (rc < (long)buflen)
{ {
logwarn(io, "Short write: %d < %ld", rc, (long)buflen); tr_logAddWarnIo(io, "Short write: %d < %ld", rc, (long)buflen);
} }
didWriteWrapper(io, buflen); didWriteWrapper(io, buflen);
@ -473,7 +458,7 @@ static size_t utp_get_rb_size(void* vio)
size_t bytes = io->bandwidth->clamp(TR_DOWN, UTP_READ_BUFFER_SIZE); size_t bytes = io->bandwidth->clamp(TR_DOWN, UTP_READ_BUFFER_SIZE);
logtrace(io, "utp_get_rb_size is saying it's ready to read %zu bytes", bytes); tr_logAddTraceIo(io, "utp_get_rb_size is saying it's ready to read %zu bytes", bytes);
return UTP_READ_BUFFER_SIZE - bytes; return UTP_READ_BUFFER_SIZE - bytes;
} }
@ -481,7 +466,7 @@ static int tr_peerIoTryWrite(tr_peerIo* io, size_t howmuch);
static void utp_on_writable(tr_peerIo* io) static void utp_on_writable(tr_peerIo* io)
{ {
logtrace(io, "libutp says this peer is ready to write"); tr_logAddTraceIo(io, "libutp says this peer is ready to write");
int const n = tr_peerIoTryWrite(io, SIZE_MAX); int const n = tr_peerIoTryWrite(io, SIZE_MAX);
tr_peerIoSetEnabled(io, TR_UP, n != 0 && evbuffer_get_length(io->outbuf) != 0); tr_peerIoSetEnabled(io, TR_UP, n != 0 && evbuffer_get_length(io->outbuf) != 0);
@ -495,12 +480,12 @@ static void utp_on_state_change(void* vio, int state)
if (state == UTP_STATE_CONNECT) if (state == UTP_STATE_CONNECT)
{ {
logdbg(io, "utp_on_state_change -- changed to connected"); tr_logAddDebugIo(io, "utp_on_state_change -- changed to connected");
io->utpSupported = true; io->utpSupported = true;
} }
else if (state == UTP_STATE_WRITABLE) else if (state == UTP_STATE_WRITABLE)
{ {
logdbg(io, "utp_on_state_change -- changed to writable"); tr_logAddDebugIo(io, "utp_on_state_change -- changed to writable");
if ((io->pendingEvents & EV_WRITE) != 0) if ((io->pendingEvents & EV_WRITE) != 0)
{ {
@ -516,12 +501,12 @@ static void utp_on_state_change(void* vio, int state)
} }
else if (state == UTP_STATE_DESTROYING) else if (state == UTP_STATE_DESTROYING)
{ {
logerr(io, "Impossible state UTP_STATE_DESTROYING"); tr_logAddErrorIo(io, "Impossible state UTP_STATE_DESTROYING");
return; return;
} }
else else
{ {
logerr(io, "Unknown state %d", state); tr_logAddErrorIo(io, "Unknown state %d", state);
} }
} }
@ -531,7 +516,7 @@ static void utp_on_error(void* vio, int errcode)
TR_ASSERT(tr_isPeerIo(io)); TR_ASSERT(tr_isPeerIo(io));
logdbg(io, "utp_on_error -- errcode is %d", errcode); tr_logAddDebugIo(io, "utp_on_error -- errcode is %d", errcode);
if (io->gotError != nullptr) if (io->gotError != nullptr)
{ {
@ -546,7 +531,7 @@ static void utp_on_overhead(void* vio, bool send, size_t count, int /*type*/)
TR_ASSERT(tr_isPeerIo(io)); TR_ASSERT(tr_isPeerIo(io));
logtrace(io, "utp_on_overhead -- count is %zu", count); tr_logAddTraceIo(io, "utp_on_overhead -- count is %zu", count);
io->bandwidth->notifyBandwidthConsumed(send ? TR_UP : TR_DOWN, count, false, tr_time_msec()); io->bandwidth->notifyBandwidthConsumed(send ? TR_UP : TR_DOWN, count, false, tr_time_msec());
} }
@ -569,7 +554,7 @@ static void dummy_write(void* /*closure*/, unsigned char* buf, size_t buflen)
{ {
/* This can very well happen if we've shut down a peer connection that /* This can very well happen if we've shut down a peer connection that
had unflushed buffers.Complain and send zeroes.*/ had unflushed buffers.Complain and send zeroes.*/
tr_logAddNamedDbg("UTP", "On_write called on closed socket"); tr_logAddNamedWarn("UTP", "On_write called on closed socket");
memset(buf, 0, buflen); memset(buf, 0, buflen);
} }
@ -627,12 +612,12 @@ static tr_peerIo* tr_peerIoNew(
io->socket = socket; io->socket = socket;
io->bandwidth = new Bandwidth(parent); io->bandwidth = new Bandwidth(parent);
io->bandwidth->setPeer(io); io->bandwidth->setPeer(io);
logtrace(io, "bandwidth is %p; its parent is %p", (void*)&io->bandwidth, (void*)parent); tr_logAddTraceIo(io, "bandwidth is %p; its parent is %p", (void*)&io->bandwidth, (void*)parent);
switch (socket.type) switch (socket.type)
{ {
case TR_PEER_SOCKET_TYPE_TCP: case TR_PEER_SOCKET_TYPE_TCP:
logtrace(io, "socket (tcp) is %" PRIdMAX, (intmax_t)socket.handle.tcp); tr_logAddTraceIo(io, "socket (tcp) is %" PRIdMAX, (intmax_t)socket.handle.tcp);
io->event_read = event_new(session->event_base, socket.handle.tcp, EV_READ, event_read_cb, io); io->event_read = event_new(session->event_base, socket.handle.tcp, EV_READ, event_read_cb, io);
io->event_write = event_new(session->event_base, socket.handle.tcp, EV_WRITE, event_write_cb, io); io->event_write = event_new(session->event_base, socket.handle.tcp, EV_WRITE, event_write_cb, io);
break; break;
@ -640,14 +625,14 @@ static tr_peerIo* tr_peerIoNew(
#ifdef WITH_UTP #ifdef WITH_UTP
case TR_PEER_SOCKET_TYPE_UTP: case TR_PEER_SOCKET_TYPE_UTP:
logtrace(io, "socket (utp) is %p", (void*)socket.handle.utp); tr_logAddTraceIo(io, "socket (utp) is %p", (void*)socket.handle.utp);
UTP_SetSockopt(socket.handle.utp, SO_RCVBUF, UTP_READ_BUFFER_SIZE); UTP_SetSockopt(socket.handle.utp, SO_RCVBUF, UTP_READ_BUFFER_SIZE);
logtrace(io, "%s", "calling UTP_SetCallbacks &utp_function_table"); tr_logAddTraceIo(io, "%s", "calling UTP_SetCallbacks &utp_function_table");
UTP_SetCallbacks(socket.handle.utp, &utp_function_table, io); UTP_SetCallbacks(socket.handle.utp, &utp_function_table, io);
if (!is_incoming) if (!is_incoming)
{ {
logtrace(io, "%s", "calling UTP_Connect"); tr_logAddTraceIo(io, "%s", "calling UTP_Connect");
UTP_Connect(socket.handle.utp); UTP_Connect(socket.handle.utp);
} }
@ -699,8 +684,7 @@ tr_peerIo* tr_peerIoNewOutgoing(
if (socket.type == TR_PEER_SOCKET_TYPE_NONE) if (socket.type == TR_PEER_SOCKET_TYPE_NONE)
{ {
socket = tr_netOpenPeerSocket(session, addr, port, is_seed); socket = tr_netOpenPeerSocket(session, addr, port, is_seed);
logdbg( tr_logAddDebug(
nullptr,
"tr_netOpenPeerSocket returned fd %" PRIdMAX, "tr_netOpenPeerSocket returned fd %" PRIdMAX,
(intmax_t)(socket.type != TR_PEER_SOCKET_TYPE_NONE ? socket.handle.tcp : TR_BAD_SOCKET)); (intmax_t)(socket.type != TR_PEER_SOCKET_TYPE_NONE ? socket.handle.tcp : TR_BAD_SOCKET));
} }
@ -733,7 +717,7 @@ static void event_enable(tr_peerIo* io, short event)
if ((event & EV_READ) != 0 && (io->pendingEvents & EV_READ) == 0) if ((event & EV_READ) != 0 && (io->pendingEvents & EV_READ) == 0)
{ {
logtrace(io, "enabling ready-to-read polling"); tr_logAddTraceIo(io, "enabling ready-to-read polling");
if (need_events) if (need_events)
{ {
@ -745,7 +729,7 @@ static void event_enable(tr_peerIo* io, short event)
if ((event & EV_WRITE) != 0 && (io->pendingEvents & EV_WRITE) == 0) if ((event & EV_WRITE) != 0 && (io->pendingEvents & EV_WRITE) == 0)
{ {
logtrace(io, "enabling ready-to-write polling"); tr_logAddTraceIo(io, "enabling ready-to-write polling");
if (need_events) if (need_events)
{ {
@ -772,7 +756,7 @@ static void event_disable(tr_peerIo* io, short event)
if ((event & EV_READ) != 0 && (io->pendingEvents & EV_READ) != 0) if ((event & EV_READ) != 0 && (io->pendingEvents & EV_READ) != 0)
{ {
logtrace(io, "disabling ready-to-read polling"); tr_logAddTraceIo(io, "disabling ready-to-read polling");
if (need_events) if (need_events)
{ {
@ -784,7 +768,7 @@ static void event_disable(tr_peerIo* io, short event)
if ((event & EV_WRITE) != 0 && (io->pendingEvents & EV_WRITE) != 0) if ((event & EV_WRITE) != 0 && (io->pendingEvents & EV_WRITE) != 0)
{ {
logtrace(io, "disabling ready-to-write polling"); tr_logAddTraceIo(io, "disabling ready-to-write polling");
if (need_events) if (need_events)
{ {
@ -839,7 +823,7 @@ static void io_close_socket(tr_peerIo* io)
#endif #endif
default: default:
logdbg(io, "unsupported peer socket type %d", io->socket.type); tr_logAddDebugIo(io, "unsupported peer socket type %d", io->socket.type);
} }
io->socket = {}; io->socket = {};
@ -863,7 +847,7 @@ static void io_dtor(tr_peerIo* const io)
TR_ASSERT(tr_amInEventThread(io->session)); TR_ASSERT(tr_amInEventThread(io->session));
TR_ASSERT(io->session->events != nullptr); TR_ASSERT(io->session->events != nullptr);
logdbg(io, "in tr_peerIo destructor"); tr_logAddDebugIo(io, "in tr_peerIo destructor");
event_disable(io, EV_READ | EV_WRITE); event_disable(io, EV_READ | EV_WRITE);
delete io->bandwidth; delete io->bandwidth;
io_close_socket(io); io_close_socket(io);
@ -881,7 +865,7 @@ static void tr_peerIoFree(tr_peerIo* io)
{ {
if (io != nullptr) if (io != nullptr)
{ {
logdbg(io, "in tr_peerIoFree"); tr_logAddDebugIo(io, "in tr_peerIoFree");
io->canRead = nullptr; io->canRead = nullptr;
io->didWrite = nullptr; io->didWrite = nullptr;
io->gotError = nullptr; io->gotError = nullptr;
@ -893,7 +877,7 @@ void tr_peerIoRefImpl(char const* file, int line, tr_peerIo* io)
{ {
TR_ASSERT(tr_isPeerIo(io)); TR_ASSERT(tr_isPeerIo(io));
logtrace(io, "%s:%d is incrementing the IO's refcount from %d to %d", file, line, io->refCount, io->refCount + 1); tr_logAddTraceIo(io, "%s:%d is incrementing the IO's refcount from %d to %d", file, line, io->refCount, io->refCount + 1);
++io->refCount; ++io->refCount;
} }
@ -902,7 +886,7 @@ void tr_peerIoUnrefImpl(char const* file, int line, tr_peerIo* io)
{ {
TR_ASSERT(tr_isPeerIo(io)); TR_ASSERT(tr_isPeerIo(io));
logtrace(io, "%s:%d is decrementing the IO's refcount from %d to %d", file, line, io->refCount, io->refCount - 1); tr_logAddTraceIo(io, "%s:%d is decrementing the IO's refcount from %d to %d", file, line, io->refCount, io->refCount - 1);
if (--io->refCount == 0) if (--io->refCount == 0)
{ {
@ -922,6 +906,11 @@ tr_address const* tr_peerIoGetAddress(tr_peerIo const* io, tr_port* port)
return &io->addr; return &io->addr;
} }
std::string tr_peerIo::addrStr() const
{
return tr_isPeerIo(this) ? this->addr.to_string(this->port) : "error";
}
char const* tr_peerIoGetAddrStr(tr_peerIo const* io, char* buf, size_t buflen) char const* tr_peerIoGetAddrStr(tr_peerIo const* io, char* buf, size_t buflen)
{ {
if (tr_isPeerIo(io)) if (tr_isPeerIo(io))
@ -1253,7 +1242,7 @@ static int tr_peerIoTryRead(tr_peerIo* io, size_t howmuch)
res = evbuffer_read(io->inbuf, io->socket.handle.tcp, (int)howmuch); res = evbuffer_read(io->inbuf, io->socket.handle.tcp, (int)howmuch);
int const e = EVUTIL_SOCKET_ERROR(); int const e = EVUTIL_SOCKET_ERROR();
logtrace(io, "read %d from peer (%s)", res, res == -1 ? tr_net_strerror(e).c_str() : ""); tr_logAddTraceIo(io, "read %d from peer (%s)", res, res == -1 ? tr_net_strerror(e).c_str() : "");
if (evbuffer_get_length(io->inbuf) != 0) if (evbuffer_get_length(io->inbuf) != 0)
{ {
@ -1269,7 +1258,13 @@ static int tr_peerIoTryRead(tr_peerIo* io, size_t howmuch)
what |= BEV_EVENT_EOF; what |= BEV_EVENT_EOF;
} }
logtrace(io, "tr_peerIoTryRead err: res:%d what:%hd, errno:%d (%s)", res, what, e, tr_net_strerror(e).c_str()); tr_logAddTraceIo(
io,
"tr_peerIoTryRead err: res:%d what:%hd, errno:%d (%s)",
res,
what,
e,
tr_net_strerror(e).c_str());
io->gotError(io, what, io->userData); io->gotError(io, what, io->userData);
} }
@ -1278,7 +1273,7 @@ static int tr_peerIoTryRead(tr_peerIo* io, size_t howmuch)
} }
default: default:
logdbg(io, "unsupported peer socket type %d", io->socket.type); tr_logAddDebugIo(io, "unsupported peer socket type %d", io->socket.type);
} }
return res; return res;
@ -1288,7 +1283,7 @@ static int tr_peerIoTryWrite(tr_peerIo* io, size_t howmuch)
{ {
auto const old_len = size_t{ evbuffer_get_length(io->outbuf) }; auto const old_len = size_t{ evbuffer_get_length(io->outbuf) };
logtrace(io, "in tr_peerIoTryWrite %zu", howmuch); tr_logAddTraceIo(io, "in tr_peerIoTryWrite %zu", howmuch);
howmuch = std::min(howmuch, old_len); howmuch = std::min(howmuch, old_len);
howmuch = io->bandwidth->clamp(TR_UP, howmuch); howmuch = io->bandwidth->clamp(TR_UP, howmuch);
if (howmuch == 0) if (howmuch == 0)
@ -1319,7 +1314,13 @@ static int tr_peerIoTryWrite(tr_peerIo* io, size_t howmuch)
{ {
short const what = BEV_EVENT_WRITING | BEV_EVENT_ERROR; short const what = BEV_EVENT_WRITING | BEV_EVENT_ERROR;
logtrace(io, "tr_peerIoTryWrite err: res:%d, what:%hd, errno:%d (%s)", n, what, e, tr_net_strerror(e).c_str()); tr_logAddTraceIo(
io,
"tr_peerIoTryWrite err: res:%d, what:%hd, errno:%d (%s)",
n,
what,
e,
tr_net_strerror(e).c_str());
io->gotError(io, what, io->userData); io->gotError(io, what, io->userData);
} }
@ -1327,7 +1328,7 @@ static int tr_peerIoTryWrite(tr_peerIo* io, size_t howmuch)
} }
default: default:
logdbg(io, "unsupported peer socket type %d", io->socket.type); tr_logAddDebugIo(io, "unsupported peer socket type %d", io->socket.type);
} }
return n; return n;
@ -1339,7 +1340,7 @@ int tr_peerIoFlush(tr_peerIo* io, tr_direction dir, size_t limit)
TR_ASSERT(tr_isDirection(dir)); TR_ASSERT(tr_isDirection(dir));
int const bytes_used = dir == TR_DOWN ? tr_peerIoTryRead(io, limit) : tr_peerIoTryWrite(io, limit); int const bytes_used = dir == TR_DOWN ? tr_peerIoTryRead(io, limit) : tr_peerIoTryWrite(io, limit);
logtrace(io, "flushing peer-io, direction:%d, limit:%zu, byte_used:%d", (int)dir, limit, bytes_used); tr_logAddTraceIo(io, "flushing peer-io, direction:%d, limit:%zu, byte_used:%d", (int)dir, limit, bytes_used);
return bytes_used; return bytes_used;
} }

2
libtransmission/peer-io.h
View File

@ -88,6 +88,8 @@ public:
evbuffer_free(inbuf); evbuffer_free(inbuf);
} }
std::string addrStr() const;
tr_crypto crypto; tr_crypto crypto;
tr_address const addr; tr_address const addr;

47
libtransmission/peer-mgr.cc
View File

@ -225,9 +225,8 @@ struct tr_peerMgr
event* atomTimer = nullptr; event* atomTimer = nullptr;
}; };
#define logdbgSwarm(swarm, ...) tr_logAddNamed(TR_LOG_DEBUG, tr_torrentName((swarm)->tor), __VA_ARGS__) #define tr_logAddDebugSwarm(swarm, ...) tr_logAddNamedDebug(tr_torrentName((swarm)->tor), __VA_ARGS__)
#define logtraceSwarm(swarm, ...) tr_logAddNamed(TR_LOG_TRACE, tr_torrentName((swarm)->tor), __VA_ARGS__) #define tr_logAddTraceSwarm(swarm, ...) tr_logAddNamedTrace(tr_torrentName((swarm)->tor), __VA_ARGS__)
#define logtrace(...) tr_logAddNamed(TR_LOG_TRACE, nullptr, __VA_ARGS__)
/** /**
*** tr_peer virtual functions *** tr_peer virtual functions
@ -447,7 +446,7 @@ static constexpr bool atomIsSeed(struct peer_atom const* atom)
static void atomSetSeed(tr_swarm* s, struct peer_atom* atom) static void atomSetSeed(tr_swarm* s, struct peer_atom* atom)
{ {
logtraceSwarm(s, "marking peer %s as a seed", tr_atomAddrStr(atom)); tr_logAddTraceSwarm(s, "marking peer %s as a seed", tr_atomAddrStr(atom));
atom->flags |= ADDED_F_SEED_FLAG; atom->flags |= ADDED_F_SEED_FLAG;
s->poolIsAllSeedsDirty = true; s->poolIsAllSeedsDirty = true;
} }
@ -665,14 +664,14 @@ static void refillUpkeep(evutil_socket_t /*fd*/, short /*what*/, void* vmgr)
static void addStrike(tr_swarm* s, tr_peer* peer) static void addStrike(tr_swarm* s, tr_peer* peer)
{ {
logtraceSwarm(s, "increasing peer %s strike count to %d", tr_atomAddrStr(peer->atom), peer->strikes + 1); tr_logAddTraceSwarm(s, "increasing peer %s strike count to %d", tr_atomAddrStr(peer->atom), peer->strikes + 1);
if (++peer->strikes >= MaxBadPiecesPerPeer) if (++peer->strikes >= MaxBadPiecesPerPeer)
{ {
struct peer_atom* atom = peer->atom; struct peer_atom* atom = peer->atom;
atom->flags2 |= MyflagBanned; atom->flags2 |= MyflagBanned;
peer->doPurge = true; peer->doPurge = true;
logtraceSwarm(s, "banning peer %s", tr_atomAddrStr(atom)); tr_logAddTraceSwarm(s, "banning peer %s", tr_atomAddrStr(atom));
} }
} }
@ -848,14 +847,14 @@ static void peerCallbackFunc(tr_peer* peer, tr_peer_event const* e, void* vs)
{ {
/* some protocol error from the peer */ /* some protocol error from the peer */
peer->doPurge = true; peer->doPurge = true;
logdbgSwarm( tr_logAddDebugSwarm(
s, s,
"setting %s doPurge flag because we got an ERANGE, EMSGSIZE, or ENOTCONN error", "setting %s doPurge flag because we got an ERANGE, EMSGSIZE, or ENOTCONN error",
tr_atomAddrStr(peer->atom)); tr_atomAddrStr(peer->atom));
} }
else else
{ {
logdbgSwarm(s, "unhandled error: %s", tr_strerror(e->err)); tr_logAddDebugSwarm(s, "unhandled error: %s", tr_strerror(e->err));
} }
break; break;
@ -922,7 +921,7 @@ static struct peer_atom* ensureAtomExists(
a->blocklisted = -1; a->blocklisted = -1;
tr_ptrArrayInsertSorted(&s->pool, a, compareAtomsByAddress); tr_ptrArrayInsertSorted(&s->pool, a, compareAtomsByAddress);
logtraceSwarm(s, "got a new atom: %s", tr_atomAddrStr(a)); tr_logAddTraceSwarm(s, "got a new atom: %s", tr_atomAddrStr(a));
} }
else else
{ {
@ -1012,7 +1011,7 @@ static bool on_handshake_done(tr_handshake_result const& result)
if (!result.readAnythingFromPeer) if (!result.readAnythingFromPeer)
{ {
logtraceSwarm( tr_logAddTraceSwarm(
s, s,
"marking peer %s as unreachable... numFails is %d", "marking peer %s as unreachable... numFails is %d",
tr_atomAddrStr(atom), tr_atomAddrStr(atom),
@ -1045,7 +1044,7 @@ static bool on_handshake_done(tr_handshake_result const& result)
if ((atom->flags2 & MyflagBanned) != 0) if ((atom->flags2 & MyflagBanned) != 0)
{ {
logtraceSwarm(s, "banned peer %s tried to reconnect", tr_atomAddrStr(atom)); tr_logAddTraceSwarm(s, "banned peer %s tried to reconnect", tr_atomAddrStr(atom));
} }
else if (tr_peerIoIsIncoming(result.io) && getPeerCount(s) >= getMaxPeerCount(s->tor)) else if (tr_peerIoIsIncoming(result.io) && getPeerCount(s) >= getMaxPeerCount(s->tor))
{ {
@ -1091,7 +1090,7 @@ void tr_peerMgrAddIncoming(tr_peerMgr* manager, tr_address const* addr, tr_port
if (tr_sessionIsAddressBlocked(session, addr)) if (tr_sessionIsAddressBlocked(session, addr))
{ {
tr_logAddDebug("Banned IP address \"%s\" tried to connect to us", tr_address_to_string(addr)); tr_logAddTrace("Banned IP address \"%s\" tried to connect to us", tr_address_to_string(addr));
tr_netClosePeerSocket(session, socket); tr_netClosePeerSocket(session, socket);
} }
else if (manager->incoming_handshakes.count(*addr) > 0) else if (manager->incoming_handshakes.count(*addr) > 0)
@ -1206,7 +1205,7 @@ void tr_peerMgrGotBadPiece(tr_torrent* tor, tr_piece_index_t pieceIndex)
if (peer->blame.test(pieceIndex)) if (peer->blame.test(pieceIndex))
{ {
logtraceSwarm( tr_logAddTraceSwarm(
s, s,
"peer %s contributed to corrupt piece (%d); now has %d strikes", "peer %s contributed to corrupt piece (%d); now has %d strikes",
tr_atomAddrStr(peer->atom), tr_atomAddrStr(peer->atom),
@ -1906,7 +1905,7 @@ static void rechokeDownloads(tr_swarm* s)
double const cancelRate = cancels / (double)(cancels + blocks); double const cancelRate = cancels / (double)(cancels + blocks);
double const mult = 1 - std::min(cancelRate, 0.5); double const mult = 1 - std::min(cancelRate, 0.5);
maxPeers = s->interestedCount * mult; maxPeers = s->interestedCount * mult;
logtraceSwarm( tr_logAddTraceSwarm(
s, s,
"cancel rate is %.3f -- reducing the number of peers we're interested in by %.0f percent", "cancel rate is %.3f -- reducing the number of peers we're interested in by %.0f percent",
cancelRate, cancelRate,
@ -1923,7 +1922,7 @@ static void rechokeDownloads(tr_swarm* s)
double const mult = std::min(timeSinceCancel, maxHistory) / (double)maxHistory; double const mult = std::min(timeSinceCancel, maxHistory) / (double)maxHistory;
int const inc = maxIncrease * mult; int const inc = maxIncrease * mult;
maxPeers = s->maxPeers + inc; maxPeers = s->maxPeers + inc;
logtraceSwarm( tr_logAddTraceSwarm(
s, s,
"time since last cancel is %jd -- increasing the number of peers we're interested in by %d", "time since last cancel is %jd -- increasing the number of peers we're interested in by %d",
(intmax_t)timeSinceCancel, (intmax_t)timeSinceCancel,
@ -2259,7 +2258,7 @@ static bool shouldPeerBeClosed(tr_swarm const* s, tr_peer const* peer, int peerC
/* if it's marked for purging, close it */ /* if it's marked for purging, close it */
if (peer->doPurge) if (peer->doPurge)
{ {
logtraceSwarm(s, "purging peer %s because its doPurge flag is set", tr_atomAddrStr(atom)); tr_logAddTraceSwarm(s, "purging peer %s because its doPurge flag is set", tr_atomAddrStr(atom));
return true; return true;
} }
@ -2284,7 +2283,7 @@ static bool shouldPeerBeClosed(tr_swarm const* s, tr_peer const* peer, int peerC
if (idleTime > limit) if (idleTime > limit)
{ {
logtraceSwarm( tr_logAddTraceSwarm(
s, s,
"purging peer %s because it's been %d secs since we shared anything", "purging peer %s because it's been %d secs since we shared anything",
tr_atomAddrStr(atom), tr_atomAddrStr(atom),
@ -2352,7 +2351,7 @@ static int getReconnectIntervalSecs(struct peer_atom const* atom, time_t const n
} }
} }
logtrace("reconnect interval for %s is %d seconds", tr_atomAddrStr(atom), sec); tr_logAddTrace("reconnect interval for %s is %d seconds", tr_atomAddrStr(atom), sec);
return sec; return sec;
} }
@ -2386,16 +2385,16 @@ static void closePeer(tr_peer* peer)
to them fruitlessly, so mark it as another fail */ to them fruitlessly, so mark it as another fail */
if (auto* const atom = peer->atom; atom->piece_data_time != 0) if (auto* const atom = peer->atom; atom->piece_data_time != 0)
{ {
logtraceSwarm(s, "resetting atom %s numFails to 0", tr_atomAddrStr(atom)); tr_logAddTraceSwarm(s, "resetting atom %s numFails to 0", tr_atomAddrStr(atom));
atom->numFails = 0; atom->numFails = 0;
} }
else else
{ {
++atom->numFails; ++atom->numFails;
logtraceSwarm(s, "incremented atom %s numFails to %d", tr_atomAddrStr(atom), int(atom->numFails)); tr_logAddTraceSwarm(s, "incremented atom %s numFails to %d", tr_atomAddrStr(atom), int(atom->numFails));
} }
logtraceSwarm(s, "removing bad peer %s", tr_atomAddrStr(peer->atom)); tr_logAddTraceSwarm(s, "removing bad peer %s", tr_atomAddrStr(peer->atom));
removePeer(peer); removePeer(peer);
} }
@ -2760,7 +2759,7 @@ static void atomPulse(evutil_socket_t /*fd*/, short /*what*/, void* vmgr)
tr_ptrArrayAppend(&s->pool, keep[i]); tr_ptrArrayAppend(&s->pool, keep[i]);
} }
logtraceSwarm(s, "max atom count is %d... pruned from %d to %d\n", maxAtomCount, atomCount, keepCount); tr_logAddTraceSwarm(s, "max atom count is %d... pruned from %d to %d\n", maxAtomCount, atomCount, keepCount);
/* cleanup */ /* cleanup */
tr_free(test); tr_free(test);
@ -3014,7 +3013,7 @@ static void initiateConnection(tr_peerMgr* mgr, tr_swarm* s, struct peer_atom* a
utp = utp && (atom->flags & ADDED_F_UTP_FLAGS) != 0; utp = utp && (atom->flags & ADDED_F_UTP_FLAGS) != 0;
} }
logtraceSwarm(s, "Starting an OUTGOING%s connection with %s", utp ? " µTP" : "", tr_atomAddrStr(atom)); tr_logAddTraceSwarm(s, "Starting an OUTGOING%s connection with %s", utp ? " µTP" : "", tr_atomAddrStr(atom));
tr_peerIo* const io = tr_peerIoNewOutgoing( tr_peerIo* const io = tr_peerIoNewOutgoing(
mgr->session, mgr->session,
@ -3028,7 +3027,7 @@ static void initiateConnection(tr_peerMgr* mgr, tr_swarm* s, struct peer_atom* a
if (io == nullptr) if (io == nullptr)
{ {
logtraceSwarm(s, "peerIo not created; marking peer %s as unreachable", tr_atomAddrStr(atom)); tr_logAddTraceSwarm(s, "peerIo not created; marking peer %s as unreachable", tr_atomAddrStr(atom));
atom->flags2 |= MyflagUnreachable; atom->flags2 |= MyflagUnreachable;
atom->numFails++; atom->numFails++;
} }

2
libtransmission/platform.cc
View File

@ -316,7 +316,7 @@ static bool isWebClientDir(std::string_view path)
{ {
auto tmp = tr_strvPath(path, "index.html"); auto tmp = tr_strvPath(path, "index.html");
bool const ret = tr_sys_path_exists(tmp.c_str(), nullptr); bool const ret = tr_sys_path_exists(tmp.c_str(), nullptr);
tr_logAddInfo(_("Searching for web interface file \"%s\""), tmp.c_str()); tr_logAddTrace("Searching for web interface file \"%s\"", tmp.c_str());
return ret; return ret;
} }

14
libtransmission/resume.cc
View File

@ -77,14 +77,14 @@ static auto loadPeers(tr_variant* dict, tr_torrent* tor)
if (tr_variantDictFindRaw(dict, TR_KEY_peers2, &str, &len)) if (tr_variantDictFindRaw(dict, TR_KEY_peers2, &str, &len))
{ {
size_t const numAdded = addPeers(tor, str, len); size_t const numAdded = addPeers(tor, str, len);
tr_logAddTorDbg(tor, "Loaded %zu IPv4 peers from resume file", numAdded); tr_logAddTraceTor(tor, "Loaded %zu IPv4 peers from resume file", numAdded);
ret = tr_resume::Peers; ret = tr_resume::Peers;
} }
if (tr_variantDictFindRaw(dict, TR_KEY_peers2_6, &str, &len)) if (tr_variantDictFindRaw(dict, TR_KEY_peers2_6, &str, &len))
{ {
size_t const numAdded = addPeers(tor, str, len); size_t const numAdded = addPeers(tor, str, len);
tr_logAddTorDbg(tor, "Loaded %zu IPv6 peers from resume file", numAdded); tr_logAddTraceTor(tor, "Loaded %zu IPv6 peers from resume file", numAdded);
ret = tr_resume::Peers; ret = tr_resume::Peers;
} }
@ -174,7 +174,7 @@ static auto loadDND(tr_variant* dict, tr_torrent* tor)
} }
else else
{ {
tr_logAddTorDbg( tr_logAddDebugTor(
tor, tor,
"Couldn't load DND flags. DND list (%p) has %zu" "Couldn't load DND flags. DND list (%p) has %zu"
" children; torrent has %d files", " children; torrent has %d files",
@ -564,7 +564,7 @@ static auto loadProgress(tr_variant* dict, tr_torrent* tor)
if (std::size(mtimes) != n_files) if (std::size(mtimes) != n_files)
{ {
tr_logAddTorErr(tor, "got %zu mtimes; expected %zu", std::size(mtimes), size_t(n_files)); tr_logAddWarnTor(tor, "got %zu mtimes; expected %zu", std::size(mtimes), size_t(n_files));
// if resizing grows the vector, we'll get 0 mtimes for the // if resizing grows the vector, we'll get 0 mtimes for the
// new items which is exactly what we want since the pieces // new items which is exactly what we want since the pieces
// in an unknown state should be treated as untested // in an unknown state should be treated as untested
@ -613,7 +613,7 @@ static auto loadProgress(tr_variant* dict, tr_torrent* tor)
if (err != nullptr) if (err != nullptr)
{ {
tr_logAddTorDbg(tor, "Torrent needs to be verified - %s", err); tr_logAddDebugTor(tor, "Torrent needs to be verified - %s", err);
} }
else else
{ {
@ -659,12 +659,12 @@ static auto loadFromFile(tr_torrent* tor, tr_resume::fields_t fieldsToLoad, bool
nullptr, nullptr,
&error)) &error))
{ {
tr_logAddTorDbg(tor, "Couldn't read \"%s\": %s", filename.c_str(), error->message); tr_logAddDebugTor(tor, "Couldn't read \"%s\": %s", filename.c_str(), error->message);
tr_error_clear(&error); tr_error_clear(&error);
return fields_loaded; return fields_loaded;
} }
tr_logAddTorDbg(tor, "Read resume file \"%s\"", filename.c_str()); tr_logAddDebugTor(tor, "Read resume file \"%s\"", filename.c_str());
auto boolVal = false; auto boolVal = false;
auto i = int64_t{}; auto i = int64_t{};

4
libtransmission/session-id.cc
View File

@ -91,7 +91,7 @@ static tr_sys_file_t create_session_id_lock_file(char const* session_id)
if (error != nullptr) if (error != nullptr)
{ {
tr_logAddError("Unable to create session lock file (%d): %s", error->code, error->message); tr_logAddWarn("Unable to create session lock file (%d): %s", error->code, error->message);
tr_error_free(error); tr_error_free(error);
} }
@ -194,7 +194,7 @@ bool tr_session_id_is_local(char const* session_id)
if (error != nullptr) if (error != nullptr)
{ {
tr_logAddError("Unable to open session lock file (%d): %s", error->code, error->message); tr_logAddWarn("Unable to open session lock file (%d): %s", error->code, error->message);
tr_error_free(error); tr_error_free(error);
} }
} }

26
libtransmission/session.cc
View File

@ -75,9 +75,6 @@ static auto constexpr DefaultPrefetchEnabled = bool{ true };
#endif #endif
static auto constexpr SaveIntervalSecs = int{ 360 }; static auto constexpr SaveIntervalSecs = int{ 360 };
#define logdbg(...) tr_logAddNamed(TR_LOG_DEBUG, nullptr, __VA_ARGS__)
#define logtrace(...) tr_logAddNamed(TR_LOG_TRACE, nullptr, __VA_ARGS__)
static tr_port getRandomPort(tr_session const* s) static tr_port getRandomPort(tr_session const* s)
{ {
return tr_port(tr_rand_int_weak(s->randomPortHigh - s->randomPortLow + 1) + s->randomPortLow); return tr_port(tr_rand_int_weak(s->randomPortHigh - s->randomPortLow + 1) + s->randomPortLow);
@ -232,7 +229,7 @@ static void accept_incoming_peer(evutil_socket_t fd, short /*what*/, void* vsess
{ {
char addrstr[TR_ADDRSTRLEN]; char addrstr[TR_ADDRSTRLEN];
tr_address_and_port_to_string(addrstr, sizeof(addrstr), &clientAddr, clientPort); tr_address_and_port_to_string(addrstr, sizeof(addrstr), &clientAddr, clientPort);
logtrace("new incoming connection %" PRIdMAX " (%s)", (intmax_t)clientSocket, addrstr); tr_logAddTrace("new incoming connection %" PRIdMAX " (%s)", (intmax_t)clientSocket, addrstr);
tr_peerMgrAddIncoming(session->peerMgr, &clientAddr, clientPort, tr_peer_socket_tcp_create(clientSocket)); tr_peerMgrAddIncoming(session->peerMgr, &clientAddr, clientPort, tr_peer_socket_tcp_create(clientSocket));
} }
@ -694,7 +691,7 @@ static void tr_sessionInitImpl(init_data* data)
TR_ASSERT(tr_amInEventThread(session)); TR_ASSERT(tr_amInEventThread(session));
TR_ASSERT(tr_variantIsDict(clientSettings)); TR_ASSERT(tr_variantIsDict(clientSettings));
logtrace("tr_sessionInit: the session's top-level bandwidth object is %p", (void*)&session->bandwidth); tr_logAddTrace("tr_sessionInit: the session's top-level bandwidth object is %p", (void*)&session->bandwidth);
tr_variant settings; tr_variant settings;
@ -1592,7 +1589,7 @@ unsigned int tr_sessionGetAltSpeed_KBps(tr_session const* s, tr_direction d)
static void userPokedTheClock(tr_session* s, struct tr_turtle_info* t) static void userPokedTheClock(tr_session* s, struct tr_turtle_info* t)
{ {
tr_logAddDebug("Refreshing the turtle mode clock due to user changes"); tr_logAddTrace("Refreshing the turtle mode clock due to user changes");
t->autoTurtleState = TR_AUTO_SWITCH_UNUSED; t->autoTurtleState = TR_AUTO_SWITCH_UNUSED;
@ -1928,18 +1925,15 @@ void tr_sessionClose(tr_session* session)
time_t const deadline = time(nullptr) + ShutdownMaxSeconds; time_t const deadline = time(nullptr) + ShutdownMaxSeconds;
logdbg( tr_logAddInfo("Shutting down transmission session %p", (void*)session);
"shutting down transmission session %p... now is %zu, deadline is %zu", tr_logAddDebug("now is %zu, deadline is %zu", (size_t)time(nullptr), (size_t)deadline);
(void*)session,
(size_t)time(nullptr),
(size_t)deadline);
/* close the session */ /* close the session */
tr_runInEventThread(session, sessionCloseImpl, session); tr_runInEventThread(session, sessionCloseImpl, session);
while (!session->isClosed && !deadlineReached(deadline)) while (!session->isClosed && !deadlineReached(deadline))
{ {
logtrace("waiting for the libtransmission thread to finish"); tr_logAddTrace("waiting for the libtransmission thread to finish");
tr_wait_msec(10); tr_wait_msec(10);
} }
@ -1951,7 +1945,7 @@ void tr_sessionClose(tr_session* session)
session->announcer_udp != nullptr) && session->announcer_udp != nullptr) &&
!deadlineReached(deadline)) !deadlineReached(deadline))
{ {
logtrace( tr_logAddTrace(
"waiting on port unmap (%p) or announcer (%p)... now %zu deadline %zu", "waiting on port unmap (%p) or announcer (%p)... now %zu deadline %zu",
(void*)session->shared, (void*)session->shared,
(void*)session->announcer, (void*)session->announcer,
@ -1968,7 +1962,7 @@ void tr_sessionClose(tr_session* session)
while (session->events != nullptr) while (session->events != nullptr)
{ {
static bool forced = false; static bool forced = false;
logtrace( tr_logAddTrace(
"waiting for libtransmission thread to finish... now %zu deadline %zu", "waiting for libtransmission thread to finish... now %zu deadline %zu",
(size_t)time(nullptr), (size_t)time(nullptr),
(size_t)deadline); (size_t)deadline);
@ -1976,14 +1970,14 @@ void tr_sessionClose(tr_session* session)
if (deadlineReached(deadline) && !forced) if (deadlineReached(deadline) && !forced)
{ {
logtrace("calling event_loopbreak()"); tr_logAddTrace("calling event_loopbreak()");
forced = true; forced = true;
event_base_loopbreak(session->event_base); event_base_loopbreak(session->event_base);
} }
if (deadlineReached(deadline + 3)) if (deadlineReached(deadline + 3))
{ {
logtrace("deadline+3 reached... calling break...\n"); tr_logAddTrace("deadline+3 reached... calling break...\n");
break; break;
} }
} }

6
libtransmission/torrent-metainfo.cc
View File

@ -538,11 +538,7 @@ bool tr_torrent_metainfo::migrateFile(
if (old_filename_exists && tr_sys_path_rename(old_filename.c_str(), new_filename.c_str(), nullptr)) if (old_filename_exists && tr_sys_path_rename(old_filename.c_str(), new_filename.c_str(), nullptr))
{ {
auto const name_sz = std::string{ name }; auto const name_sz = std::string{ name };
tr_logAddNamedError( tr_logAddNamedError(name_sz, "Migrated torrent file from \"%s\" to \"%s\"", old_filename.c_str(), new_filename.c_str());
name_sz.c_str(),
"Migrated torrent file from \"%s\" to \"%s\"",
old_filename.c_str(),
new_filename.c_str());
return true; return true;
} }

8
libtransmission/torrent.h
View File

@ -27,6 +27,7 @@
#include "file.h" #include "file.h"
#include "file-piece-map.h" #include "file-piece-map.h"
#include "interned-string.h" #include "interned-string.h"
#include "log.h"
#include "session.h" #include "session.h"
#include "torrent-metainfo.h" #include "torrent-metainfo.h"
#include "tr-macros.h" #include "tr-macros.h"
@ -777,3 +778,10 @@ tr_torrent_metainfo&& tr_ctorStealMetainfo(tr_ctor* ctor);
bool tr_ctorSetMetainfoFromFile(tr_ctor* ctor, std::string const& filename, tr_error** error); bool tr_ctorSetMetainfoFromFile(tr_ctor* ctor, std::string const& filename, tr_error** error);
bool tr_ctorSetMetainfoFromMagnetLink(tr_ctor* ctor, std::string const& filename, tr_error** error); bool tr_ctorSetMetainfoFromMagnetLink(tr_ctor* ctor, std::string const& filename, tr_error** error);
void tr_ctorSetLabels(tr_ctor* ctor, tr_labels_t&& labels); void tr_ctorSetLabels(tr_ctor* ctor, tr_labels_t&& labels);
#define tr_logAddCriticalTor(tor, ...) tr_logAddNamed(TR_LOG_CRITICAL, (tor)->name(), __VA_ARGS__)
#define tr_logAddErrorTor(tor, ...) tr_logAddNamed(TR_LOG_ERROR, (tor)->name(), __VA_ARGS__)
#define tr_logAddWarnTor(tor, ...) tr_logAddNamed(TR_LOG_WARN, (tor)->name(), __VA_ARGS__)
#define tr_logAddInfoTor(tor, ...) tr_logAddNamed(TR_LOG_INFO, (tor)->name(), __VA_ARGS__)
#define tr_logAddDebugTor(tor, ...) tr_logAddNamed(TR_LOG_DEBUG, (tor)->name(), __VA_ARGS__)
#define tr_logAddTraceTor(tor, ...) tr_logAddNamed(TR_LOG_TRACE, (tor)->name(), __VA_ARGS__)

54
libtransmission/tr-dht.cc
View File

@ -46,6 +46,14 @@
#include "utils.h" #include "utils.h"
#include "variant.h" #include "variant.h"
#define logdbg(...) tr_logAddNamed(TR_LOG_DEBUG, "dht", __VA_ARGS__)
#define logdbgTor(tor, ...) tr_logAddNamed(TR_LOG_DEBUG, tr_torrentName(tor), __VA_ARGS__)
#define loginfo(...) tr_logAddNamed(TR_LOG_INFO, "dht", __VA_ARGS__)
#define logtrace(...) tr_logAddNamed(TR_LOG_TRACE, "dht", __VA_ARGS__)
#define logtraceTor(tor, ...) tr_logAddNamed(TR_LOG_TRACE, tr_torrentName(tor), __VA_ARGS__)
#define logwarn(...) tr_logAddNamed(TR_LOG_WARN, "dht", __VA_ARGS__)
#define logwarnTor(tor, ...) tr_logAddNamed(TR_LOG_WARN, tr_torrentName(tor), __VA_ARGS__)
using namespace std::literals; using namespace std::literals;
static struct event* dht_timer = nullptr; static struct event* dht_timer = nullptr;
@ -109,7 +117,7 @@ static void bootstrap_from_name(char const* name, tr_port port, int af)
addrinfo* info = nullptr; addrinfo* info = nullptr;
if (int const rc = getaddrinfo(name, pp, &hints, &info); rc != 0) if (int const rc = getaddrinfo(name, pp, &hints, &info); rc != 0)
{ {
tr_logAddNamedError("DHT", "%s:%s: %s", name, pp, gai_strerror(rc)); logwarn("%s:%s: %s", name, pp, gai_strerror(rc));
return; return;
} }
@ -147,7 +155,7 @@ static void dht_boostrap_from_file(tr_session* session)
} }
// format is each line has address, a space char, and port number // format is each line has address, a space char, and port number
tr_logAddNamedInfo("DHT", "Attempting manual bootstrap"); logtrace("Attempting manual bootstrap");
auto line = std::string{}; auto line = std::string{};
while (!bootstrap_done(session, 0) && std::getline(in, line)) while (!bootstrap_done(session, 0) && std::getline(in, line))
{ {
@ -158,7 +166,7 @@ static void dht_boostrap_from_file(tr_session* session)
if (line_stream.bad() || std::empty(addrstr) || port <= 0) if (line_stream.bad() || std::empty(addrstr) || port <= 0)
{ {
tr_logAddNamedError("DHT", "Couldn't parse line: \"%s\"", line.c_str()); logwarn("Couldn't parse line: \"%s\"", line.c_str());
} }
else else
{ {
@ -180,12 +188,12 @@ static void dht_bootstrap(void* closure)
if (cl->len > 0) if (cl->len > 0)
{ {
tr_logAddNamedInfo("DHT", "Bootstrapping from %d IPv4 nodes", num); logdbg("Bootstrapping from %d IPv4 nodes", num);
} }
if (cl->len6 > 0) if (cl->len6 > 0)
{ {
tr_logAddNamedInfo("DHT", "Bootstrapping from %d IPv6 nodes", num6); logdbg("Bootstrapping from %d IPv6 nodes", num6);
} }
for (int i = 0; i < std::max(num, num6); ++i) for (int i = 0; i < std::max(num, num6); ++i)
@ -256,7 +264,7 @@ static void dht_bootstrap(void* closure)
if (i == 0) if (i == 0)
{ {
tr_logAddNamedInfo("DHT", "Attempting bootstrap from dht.transmissionbt.com"); logdbg("Attempting bootstrap from dht.transmissionbt.com");
} }
bootstrap_from_name("dht.transmissionbt.com", 6881, bootstrap_af(session_)); bootstrap_from_name("dht.transmissionbt.com", 6881, bootstrap_af(session_));
@ -274,7 +282,7 @@ static void dht_bootstrap(void* closure)
} }
tr_free(closure); tr_free(closure);
tr_logAddNamedDbg("DHT", "Finished bootstrapping"); logtrace("Finished bootstrapping");
} }
int tr_dhtInit(tr_session* ss) int tr_dhtInit(tr_session* ss)
@ -284,7 +292,7 @@ int tr_dhtInit(tr_session* ss)
return -1; return -1;
} }
tr_logAddNamedDbg("DHT", "Initializing DHT"); loginfo("Initializing DHT");
if (tr_env_key_exists("TR_DHT_VERBOSE")) if (tr_env_key_exists("TR_DHT_VERBOSE"))
{ {
@ -333,13 +341,13 @@ int tr_dhtInit(tr_session* ss)
if (have_id) if (have_id)
{ {
tr_logAddNamedInfo("DHT", "Reusing old id"); logtrace("Reusing old id");
} }
else else
{ {
/* Note that DHT ids need to be distributed uniformly, /* Note that DHT ids need to be distributed uniformly,
* so it should be something truly random. */ * so it should be something truly random. */
tr_logAddNamedInfo("DHT", "Generating new id"); logtrace("Generating new id");
tr_rand_buffer(myid, 20); tr_rand_buffer(myid, 20);
} }
@ -348,7 +356,7 @@ int tr_dhtInit(tr_session* ss)
tr_free(nodes6); tr_free(nodes6);
tr_free(nodes); tr_free(nodes);
tr_logAddNamedDbg("DHT", "DHT initialization failed (errno = %d)", errno); logdbg("DHT initialization failed (errno = %d)", errno);
session_ = nullptr; session_ = nullptr;
return -1; return -1;
} }
@ -366,7 +374,7 @@ int tr_dhtInit(tr_session* ss)
dht_timer = evtimer_new(session_->event_base, timer_callback, session_); dht_timer = evtimer_new(session_->event_base, timer_callback, session_);
tr_timerAdd(dht_timer, 0, tr_rand_int_weak(1000000)); tr_timerAdd(dht_timer, 0, tr_rand_int_weak(1000000));
tr_logAddNamedDbg("DHT", "DHT initialized"); logdbg("DHT initialized");
return 1; return 1;
} }
@ -378,7 +386,7 @@ void tr_dhtUninit(tr_session* ss)
return; return;
} }
tr_logAddNamedDbg("DHT", "Uninitializing DHT"); logtrace("Uninitializing DHT");
if (dht_timer != nullptr) if (dht_timer != nullptr)
{ {
@ -390,7 +398,7 @@ void tr_dhtUninit(tr_session* ss)
don't know enough nodes. */ don't know enough nodes. */
if (tr_dhtStatus(ss, AF_INET, nullptr) < TR_DHT_FIREWALLED && tr_dhtStatus(ss, AF_INET6, nullptr) < TR_DHT_FIREWALLED) if (tr_dhtStatus(ss, AF_INET, nullptr) < TR_DHT_FIREWALLED && tr_dhtStatus(ss, AF_INET6, nullptr) < TR_DHT_FIREWALLED)
{ {
tr_logAddNamedInfo("DHT", "Not saving nodes, DHT not ready"); logtrace("Not saving nodes, DHT not ready");
} }
else else
{ {
@ -406,7 +414,7 @@ void tr_dhtUninit(tr_session* ss)
int num = MaxNodes; int num = MaxNodes;
int num6 = MaxNodes; int num6 = MaxNodes;
int n = dht_get_nodes(sins, &num, sins6, &num6); int n = dht_get_nodes(sins, &num, sins6, &num6);
tr_logAddNamedInfo("DHT", "Saving %d (%d + %d) nodes", n, num, num6); logtrace("Saving %d (%d + %d) nodes", n, num, num6);
tr_variant benc; tr_variant benc;
tr_variantInitDict(&benc, 3); tr_variantInitDict(&benc, 3);
@ -448,7 +456,7 @@ void tr_dhtUninit(tr_session* ss)
} }
dht_uninit(); dht_uninit();
tr_logAddNamedDbg("DHT", "Done uninitializing DHT"); logtrace("Done uninitializing DHT");
session_ = nullptr; session_ = nullptr;
} }
@ -607,7 +615,7 @@ static void callback(void* /*ignore*/, int event, unsigned char const* info_hash
auto const pex = event == DHT_EVENT_VALUES ? tr_peerMgrCompactToPex(data, data_len, nullptr, 0) : auto const pex = event == DHT_EVENT_VALUES ? tr_peerMgrCompactToPex(data, data_len, nullptr, 0) :
tr_peerMgrCompact6ToPex(data, data_len, nullptr, 0); tr_peerMgrCompact6ToPex(data, data_len, nullptr, 0);
tr_peerMgrAddPex(tor, TR_PEER_FROM_DHT, std::data(pex), std::size(pex)); tr_peerMgrAddPex(tor, TR_PEER_FROM_DHT, std::data(pex), std::size(pex));
tr_logAddTorDbg(tor, "Learned %zu %s peers from DHT", std::size(pex), event == DHT_EVENT_VALUES6 ? "IPv6" : "IPv4"); logdbgTor(tor, "Learned %zu %s peers from DHT", std::size(pex), event == DHT_EVENT_VALUES6 ? "IPv6" : "IPv4");
} }
} }
else if (event == DHT_EVENT_SEARCH_DONE || event == DHT_EVENT_SEARCH_DONE6) else if (event == DHT_EVENT_SEARCH_DONE || event == DHT_EVENT_SEARCH_DONE6)
@ -616,12 +624,12 @@ static void callback(void* /*ignore*/, int event, unsigned char const* info_hash
{ {
if (event == DHT_EVENT_SEARCH_DONE) if (event == DHT_EVENT_SEARCH_DONE)
{ {
tr_logAddTorInfo(tor, "%s", "IPv4 DHT announce done"); logtraceTor(tor, "%s", "IPv4 DHT announce done");
tor->dhtAnnounceInProgress = false; tor->dhtAnnounceInProgress = false;
} }
else else
{ {
tr_logAddTorInfo(tor, "%s", "IPv6 DHT announce done"); logtraceTor(tor, "%s", "IPv6 DHT announce done");
tor->dhtAnnounce6InProgress = false; tor->dhtAnnounce6InProgress = false;
} }
} }
@ -652,7 +660,7 @@ static AnnounceResult tr_dhtAnnounce(tr_torrent* tor, int af, bool announce)
if (status < TR_DHT_POOR) if (status < TR_DHT_POOR)
{ {
tr_logAddTorDbg( logtraceTor(
tor, tor,
"%s DHT not ready (%s, %d nodes)", "%s DHT not ready (%s, %d nodes)",
af == AF_INET6 ? "IPv6" : "IPv4", af == AF_INET6 ? "IPv6" : "IPv4",
@ -665,7 +673,7 @@ static AnnounceResult tr_dhtAnnounce(tr_torrent* tor, int af, bool announce)
int const rc = dht_search(dht_hash, announce ? tr_sessionGetPeerPort(session_) : 0, af, callback, nullptr); int const rc = dht_search(dht_hash, announce ? tr_sessionGetPeerPort(session_) : 0, af, callback, nullptr);
if (rc < 0) if (rc < 0)
{ {
tr_logAddTorErr( logwarnTor(
tor, tor,
"%s DHT announce failed (%s, %d nodes): %s", "%s DHT announce failed (%s, %d nodes): %s",
af == AF_INET6 ? "IPv6" : "IPv4", af == AF_INET6 ? "IPv6" : "IPv4",
@ -675,7 +683,7 @@ static AnnounceResult tr_dhtAnnounce(tr_torrent* tor, int af, bool announce)
return AnnounceResult::FAILED; return AnnounceResult::FAILED;
} }
tr_logAddTorInfo( logtraceTor(
tor, tor,
"Starting %s DHT announce (%s, %d nodes)", "Starting %s DHT announce (%s, %d nodes)",
af == AF_INET6 ? "IPv6" : "IPv4", af == AF_INET6 ? "IPv6" : "IPv4",
@ -743,7 +751,7 @@ void tr_dhtCallback(unsigned char* buf, int buflen, struct sockaddr* from, sockl
} }
else else
{ {
tr_logAddNamedError("DHT", "dht_periodic failed: %s", tr_strerror(errno)); logwarn("dht_periodic failed: %s", tr_strerror(errno));
if (errno == EINVAL || errno == EFAULT) if (errno == EINVAL || errno == EFAULT)
{ {

42
libtransmission/upnp.cc
View File

@ -29,6 +29,18 @@ namespace
char constexpr Key[] = "Port Forwarding (UPnP)"; char constexpr Key[] = "Port Forwarding (UPnP)";
#undef tr_logAddError
#undef tr_logAddWarn
#undef tr_logAddInfo
#undef tr_logAddDebug
#undef tr_logAddTrace
#define tr_logAddError(...) tr_logAddNamedError(Key, __VA_ARGS__)
#define tr_logAddWarn(...) tr_logAddNamedWarn(Key, __VA_ARGS__)
#define tr_logAddInfo(...) tr_logAddNamedInfo(Key, __VA_ARGS__)
#define tr_logAddDebug(...) tr_logAddNamedDebug(Key, __VA_ARGS__)
#define tr_logAddTrace(...) tr_logAddNamedTrace(Key, __VA_ARGS__)
enum class UpnpState enum class UpnpState
{ {
IDLE, IDLE,
@ -129,7 +141,7 @@ static struct UPNPDev* tr_upnpDiscover(int msec, char const* bindaddr)
if (have_err) if (have_err)
{ {
tr_logAddNamedDbg(Key, "upnpDiscover failed (errno %d - %s)", errno, tr_strerror(errno)); tr_logAddDebug("upnpDiscover failed (errno %d - %s)", errno, tr_strerror(errno));
} }
return ret; return ret;
@ -215,13 +227,7 @@ static int tr_upnpAddPortMapping(tr_upnp const* handle, char const* proto, tr_po
if (err != 0) if (err != 0)
{ {
tr_logAddNamedDbg( tr_logAddDebug("%s Port forwarding failed with error %d (errno %d - %s)", proto, err, errno, tr_strerror(errno));
Key,
"%s Port forwarding failed with error %d (errno %d - %s)",
proto,
err,
errno,
tr_strerror(errno));
} }
errno = old_errno; errno = old_errno;
@ -285,16 +291,16 @@ tr_port_forwarding tr_upnpPulse(tr_upnp* handle, tr_port port, bool isEnabled, b
if (UPNP_GetValidIGD(devlist, &handle->urls, &handle->data, handle->lanaddr, sizeof(handle->lanaddr)) == if (UPNP_GetValidIGD(devlist, &handle->urls, &handle->data, handle->lanaddr, sizeof(handle->lanaddr)) ==
UPNP_IGD_VALID_CONNECTED) UPNP_IGD_VALID_CONNECTED)
{ {
tr_logAddNamedInfo(Key, _("Found Internet Gateway Device \"%s\""), handle->urls.controlURL); tr_logAddInfo(_("Found Internet Gateway Device \"%s\""), handle->urls.controlURL);
tr_logAddNamedInfo(Key, _("Local Address is \"%s\""), handle->lanaddr); tr_logAddInfo(_("Local Address is \"%s\""), handle->lanaddr);
handle->state = UpnpState::IDLE; handle->state = UpnpState::IDLE;
handle->hasDiscovered = true; handle->hasDiscovered = true;
} }
else else
{ {
handle->state = UpnpState::FAILED; handle->state = UpnpState::FAILED;
tr_logAddNamedDbg(Key, "UPNP_GetValidIGD failed (errno %d - %s)", errno, tr_strerror(errno)); tr_logAddDebug("UPNP_GetValidIGD failed (errno %d - %s)", errno, tr_strerror(errno));
tr_logAddNamedDbg(Key, "If your router supports UPnP, please make sure UPnP is enabled!"); tr_logAddDebug("If your router supports UPnP, please make sure UPnP is enabled!");
} }
freeUPNPDevlist(devlist); freeUPNPDevlist(devlist);
@ -309,7 +315,7 @@ tr_port_forwarding tr_upnpPulse(tr_upnp* handle, tr_port port, bool isEnabled, b
((tr_upnpGetSpecificPortMappingEntry(handle, "TCP") != UPNPCOMMAND_SUCCESS) || ((tr_upnpGetSpecificPortMappingEntry(handle, "TCP") != UPNPCOMMAND_SUCCESS) ||
(tr_upnpGetSpecificPortMappingEntry(handle, "UDP") != UPNPCOMMAND_SUCCESS))) (tr_upnpGetSpecificPortMappingEntry(handle, "UDP") != UPNPCOMMAND_SUCCESS)))
{ {
tr_logAddNamedInfo(Key, _("Port %d isn't forwarded"), handle->port); tr_logAddInfo(_("Port %d isn't forwarded"), handle->port);
handle->isMapped = false; handle->isMapped = false;
} }
@ -318,8 +324,7 @@ tr_port_forwarding tr_upnpPulse(tr_upnp* handle, tr_port port, bool isEnabled, b
tr_upnpDeletePortMapping(handle, "TCP", handle->port); tr_upnpDeletePortMapping(handle, "TCP", handle->port);
tr_upnpDeletePortMapping(handle, "UDP", handle->port); tr_upnpDeletePortMapping(handle, "UDP", handle->port);
tr_logAddNamedInfo( tr_logAddInfo(
Key,
_("Stopping port forwarding through \"%s\", service \"%s\""), _("Stopping port forwarding through \"%s\", service \"%s\""),
handle->urls.controlURL, handle->urls.controlURL,
handle->data.first.servicetype); handle->data.first.servicetype);
@ -353,8 +358,7 @@ tr_port_forwarding tr_upnpPulse(tr_upnp* handle, tr_port port, bool isEnabled, b
handle->isMapped = err_tcp == 0 || err_udp == 0; handle->isMapped = err_tcp == 0 || err_udp == 0;
} }
tr_logAddNamedInfo( tr_logAddInfo(
Key,
_("Port forwarding through \"%s\", service \"%s\". (local address: %s:%d)"), _("Port forwarding through \"%s\", service \"%s\". (local address: %s:%d)"),
handle->urls.controlURL, handle->urls.controlURL,
handle->data.first.servicetype, handle->data.first.servicetype,
@ -363,13 +367,13 @@ tr_port_forwarding tr_upnpPulse(tr_upnp* handle, tr_port port, bool isEnabled, b
if (handle->isMapped) if (handle->isMapped)
{ {
tr_logAddNamedInfo(Key, "%s", _("Port forwarding successful!")); tr_logAddInfo("%s", _("Port forwarding successful!"));
handle->port = port; handle->port = port;
handle->state = UpnpState::IDLE; handle->state = UpnpState::IDLE;
} }
else else
{ {
tr_logAddNamedDbg(Key, "If your router supports UPnP, please make sure UPnP is enabled!"); tr_logAddInfo("%s", _("If your router supports UPnP, please make sure UPnP is enabled!"));
handle->port = -1; handle->port = -1;
handle->state = UpnpState::FAILED; handle->state = UpnpState::FAILED;
} }

24
libtransmission/utils.cc
View File

@ -41,6 +41,7 @@
#include "error-types.h" #include "error-types.h"
#include "error.h" #include "error.h"
#include "file.h"
#include "log.h" #include "log.h"
#include "mime-types.h" #include "mime-types.h"
#include "net.h" // ntohl() #include "net.h" // ntohl()
@ -51,8 +52,6 @@
using namespace std::literals; using namespace std::literals;
#define logtrace(...) tr_logAddNamed(TR_LOG_TRACE, nullptr, __VA_ARGS__)
time_t __tr_current_time = 0; time_t __tr_current_time = 0;
/*** /***
@ -227,21 +226,19 @@ void tr_timerAddMsec(struct event* timer, int msec)
uint8_t* tr_loadFile(char const* path, size_t* size, tr_error** error) uint8_t* tr_loadFile(char const* path, size_t* size, tr_error** error)
{ {
char const* const err_fmt = _("Couldn't read \"%1$s\": %2$s");
/* try to stat the file */ /* try to stat the file */
auto info = tr_sys_path_info{}; auto info = tr_sys_path_info{};
tr_error* my_error = nullptr; tr_error* my_error = nullptr;
if (!tr_sys_path_get_info(path, 0, &info, &my_error)) if (!tr_sys_path_get_info(path, 0, &info, &my_error))
{ {
tr_logAddDebug(err_fmt, path, my_error->message); tr_logAddError("Couldn't read \"%1$s\": %2$s", path, my_error->message);
tr_error_propagate(error, &my_error); tr_error_propagate(error, &my_error);
return nullptr; return nullptr;
} }
if (info.type != TR_SYS_PATH_IS_FILE) if (info.type != TR_SYS_PATH_IS_FILE)
{ {
tr_logAddError(err_fmt, path, _("Not a regular file")); tr_logAddError("Couldn't read \"%1$s\": Not a regular file", path);
tr_error_set(error, TR_ERROR_EISDIR, "Not a regular file"sv); tr_error_set(error, TR_ERROR_EISDIR, "Not a regular file"sv);
return nullptr; return nullptr;
} }
@ -256,7 +253,7 @@ uint8_t* tr_loadFile(char const* path, size_t* size, tr_error** error)
auto const fd = tr_sys_file_open(path, TR_SYS_FILE_READ | TR_SYS_FILE_SEQUENTIAL, 0, &my_error); auto const fd = tr_sys_file_open(path, TR_SYS_FILE_READ | TR_SYS_FILE_SEQUENTIAL, 0, &my_error);
if (fd == TR_BAD_SYS_FILE) if (fd == TR_BAD_SYS_FILE)
{ {
tr_logAddError(err_fmt, path, my_error->message); tr_logAddError("Couldn't read \"%1$s\": %2$s", path, my_error->message);
tr_error_propagate(error, &my_error); tr_error_propagate(error, &my_error);
return nullptr; return nullptr;
} }
@ -264,7 +261,7 @@ uint8_t* tr_loadFile(char const* path, size_t* size, tr_error** error)
auto* buf = static_cast<uint8_t*>(tr_malloc(info.size + 1)); auto* buf = static_cast<uint8_t*>(tr_malloc(info.size + 1));
if (!tr_sys_file_read(fd, buf, info.size, nullptr, &my_error)) if (!tr_sys_file_read(fd, buf, info.size, nullptr, &my_error))
{ {
tr_logAddError(err_fmt, path, my_error->message); tr_logAddError("Couldn't read \"%1$s\": %2$s", path, my_error->message);
tr_sys_file_close(fd, nullptr); tr_sys_file_close(fd, nullptr);
tr_free(buf); tr_free(buf);
tr_error_propagate(error, &my_error); tr_error_propagate(error, &my_error);
@ -279,7 +276,6 @@ uint8_t* tr_loadFile(char const* path, size_t* size, tr_error** error)
bool tr_loadFile(std::vector<char>& setme, std::string const& path, tr_error** error) bool tr_loadFile(std::vector<char>& setme, std::string const& path, tr_error** error)
{ {
char const* const err_fmt = _("Couldn't read \"%1$s\": %2$s");
auto const* const path_sz = path.c_str(); auto const* const path_sz = path.c_str();
/* try to stat the file */ /* try to stat the file */
@ -287,14 +283,14 @@ bool tr_loadFile(std::vector<char>& setme, std::string const& path, tr_error** e
tr_error* my_error = nullptr; tr_error* my_error = nullptr;
if (!tr_sys_path_get_info(path_sz, 0, &info, &my_error)) if (!tr_sys_path_get_info(path_sz, 0, &info, &my_error))
{ {
tr_logAddDebug(err_fmt, path_sz, my_error->message); tr_logAddError(_("Couldn't read \"%1$s\": %2$s"), path_sz, my_error->message);
tr_error_propagate(error, &my_error); tr_error_propagate(error, &my_error);
return false; return false;
} }
if (info.type != TR_SYS_PATH_IS_FILE) if (info.type != TR_SYS_PATH_IS_FILE)
{ {
tr_logAddError(err_fmt, path_sz, _("Not a regular file")); tr_logAddError(_("Couldn't read \"%1$s\": Not a regular file"), path_sz);
tr_error_set(error, TR_ERROR_EISDIR, "Not a regular file"sv); tr_error_set(error, TR_ERROR_EISDIR, "Not a regular file"sv);
return false; return false;
} }
@ -303,7 +299,7 @@ bool tr_loadFile(std::vector<char>& setme, std::string const& path, tr_error** e
auto const fd = tr_sys_file_open(path_sz, TR_SYS_FILE_READ | TR_SYS_FILE_SEQUENTIAL, 0, &my_error); auto const fd = tr_sys_file_open(path_sz, TR_SYS_FILE_READ | TR_SYS_FILE_SEQUENTIAL, 0, &my_error);
if (fd == TR_BAD_SYS_FILE) if (fd == TR_BAD_SYS_FILE)
{ {
tr_logAddError(err_fmt, path_sz, my_error->message); tr_logAddError(_("Couldn't read \"%1$s\": %2$s"), path_sz, my_error->message);
tr_error_propagate(error, &my_error); tr_error_propagate(error, &my_error);
return false; return false;
} }
@ -311,7 +307,7 @@ bool tr_loadFile(std::vector<char>& setme, std::string const& path, tr_error** e
setme.resize(info.size); setme.resize(info.size);
if (!tr_sys_file_read(fd, std::data(setme), info.size, nullptr, &my_error)) if (!tr_sys_file_read(fd, std::data(setme), info.size, nullptr, &my_error))
{ {
tr_logAddError(err_fmt, path_sz, my_error->message); tr_logAddError(_("Couldn't read \"%1$s\": %2$s"), path_sz, my_error->message);
tr_sys_file_close(fd, nullptr); tr_sys_file_close(fd, nullptr);
tr_error_propagate(error, &my_error); tr_error_propagate(error, &my_error);
return false; return false;
@ -364,7 +360,7 @@ bool tr_saveFile(std::string const& filename, std::string_view contents, tr_erro
return false; return false;
} }
logtrace("Saved \"%s\"", filename.c_str()); tr_logAddTrace("Saved \"%s\"", filename.c_str());
return true; return true;
} }

8
libtransmission/verify.cc
View File

@ -43,7 +43,7 @@ static bool verifyTorrent(tr_torrent* tor, bool const* stopFlag)
auto buffer = std::vector<std::byte>(1024 * 256); auto buffer = std::vector<std::byte>(1024 * 256);
auto sha = tr_sha1_init(); auto sha = tr_sha1_init();
tr_logAddTorDbg(tor, "%s", "verifying torrent..."); tr_logAddDebugTor(tor, "%s", "verifying torrent...");
tor->verify_progress = 0; tor->verify_progress = 0;
while (!*stopFlag && piece < tor->pieceCount()) while (!*stopFlag && piece < tor->pieceCount())
@ -144,7 +144,7 @@ static bool verifyTorrent(tr_torrent* tor, bool const* stopFlag)
/* stopwatch */ /* stopwatch */
time_t const end = tr_time(); time_t const end = tr_time();
tr_logAddTorDbg( tr_logAddDebugTor(
tor, tor,
"Verification is done. It took %d seconds to verify %" PRIu64 " bytes (%" PRIu64 " bytes per second)", "Verification is done. It took %d seconds to verify %" PRIu64 " bytes (%" PRIu64 " bytes per second)",
(int)(end - begin), (int)(end - begin),
@ -225,7 +225,7 @@ static void verifyThreadFunc()
} }
tr_torrent* tor = currentNode.torrent; tr_torrent* tor = currentNode.torrent;
tr_logAddTorInfo(tor, "%s", _("Verifying torrent")); tr_logAddTraceTor(tor, "%s", _("Verifying torrent"));
tor->setVerifyState(TR_VERIFY_NOW); tor->setVerifyState(TR_VERIFY_NOW);
auto const changed = verifyTorrent(tor, &stopCurrent); auto const changed = verifyTorrent(tor, &stopCurrent);
tor->setVerifyState(TR_VERIFY_NONE); tor->setVerifyState(TR_VERIFY_NONE);
@ -246,7 +246,7 @@ static void verifyThreadFunc()
void tr_verifyAdd(tr_torrent* tor, tr_verify_done_func callback_func, void* callback_data) void tr_verifyAdd(tr_torrent* tor, tr_verify_done_func callback_func, void* callback_data)
{ {
TR_ASSERT(tr_isTorrent(tor)); TR_ASSERT(tr_isTorrent(tor));
tr_logAddTorInfo(tor, "%s", _("Queued for verification")); tr_logAddTraceTor(tor, "%s", _("Queued for verification"));
auto node = verify_node{}; auto node = verify_node{};
node.torrent = tor; node.torrent = tor;

2
macosx/Torrent.mm
View File

@ -354,7 +354,7 @@ bool trashDataFile(char const* filename, tr_error** error)
{ {
if (self.fResumeOnWake) if (self.fResumeOnWake)
{ {
tr_logAddNamedInfo(tr_torrentName(self.fHandle), "restarting because of wakeUp"); tr_logAddNamedTrace(tr_torrentName(self.fHandle), "restarting because of wakeUp");
tr_torrentStart(self.fHandle); tr_torrentStart(self.fHandle);
} }
} }

4
utils/remote.cc
View File

@ -2000,7 +2000,7 @@ static int processResponse(char const* rpcurl, std::string_view response)
if (!tr_variantFromBuf(&top, TR_VARIANT_PARSE_JSON | TR_VARIANT_PARSE_INPLACE, response)) if (!tr_variantFromBuf(&top, TR_VARIANT_PARSE_JSON | TR_VARIANT_PARSE_INPLACE, response))
{ {
tr_logAddNamedError(MyName, "Unable to parse response \"%" TR_PRIsv "\"", TR_PRIsv_ARG(response)); tr_logAddNamedWarn(MyName, "Unable to parse response \"%" TR_PRIsv "\"", TR_PRIsv_ARG(response));
status |= EXIT_FAILURE; status |= EXIT_FAILURE;
} }
else else
@ -2172,7 +2172,7 @@ static int flush(char const* rpcurl, tr_variant** benc)
auto const res = curl_easy_perform(curl); auto const res = curl_easy_perform(curl);
if (res != CURLE_OK) if (res != CURLE_OK)
{ {
tr_logAddNamedError(MyName, " (%s) %s", rpcurl_http.c_str(), curl_easy_strerror(res)); tr_logAddNamedWarn(MyName, " (%s) %s", rpcurl_http.c_str(), curl_easy_strerror(res));
status |= EXIT_FAILURE; status |= EXIT_FAILURE;
} }
else else