merged logging cleanup from RC_0_16

This commit is contained in:
Arvid Norberg 2012-09-27 23:04:51 +00:00
parent 19e4cbec46
commit 5e2ff1a246
7 changed files with 151 additions and 122 deletions

View File

@ -1204,7 +1204,7 @@ namespace libtorrent
void tracker_warning(tracker_request const& req void tracker_warning(tracker_request const& req
, std::string const& str) , std::string const& str)
{ {
debug_log("*** tracker warning: " + str); debug_log("*** tracker warning: %s", str.c_str());
} }
void tracker_response(tracker_request const& void tracker_response(tracker_request const&
@ -1235,7 +1235,7 @@ namespace libtorrent
} }
snprintf(tmp, 200, "external ip: %s\n", print_address(external_ip).c_str()); snprintf(tmp, 200, "external ip: %s\n", print_address(external_ip).c_str());
s += tmp; s += tmp;
debug_log(s); debug_log("%s", s.c_str());
} }
void tracker_request_timed_out( void tracker_request_timed_out(
@ -1248,15 +1248,23 @@ namespace libtorrent
, int response_code, error_code const& ec, const std::string& str , int response_code, error_code const& ec, const std::string& str
, int retry_interval) , int retry_interval)
{ {
char msg[256]; debug_log("*** tracker error: %d: %s %s"
snprintf(msg, sizeof(msg), "*** tracker error: %d: %s %s"
, response_code, ec.message().c_str(), str.c_str()); , response_code, ec.message().c_str(), str.c_str());
debug_log(msg);
} }
void debug_log(const std::string& line) void debug_log(const char* fmt, ...) const
{ {
(*m_ses.m_logger) << time_now_string() << " " << line << "\n"; if (!m_ses.m_logger) return;
va_list v;
va_start(v, fmt);
char usr[1024];
vsnprintf(usr, sizeof(usr), fmt, v);
va_end(v);
char buf[1280];
snprintf(buf, sizeof(buf), "%s: %s\n", time_now_string(), usr);
(*m_ses.m_logger) << buf;
} }
session_impl& m_ses; session_impl& m_ses;
}; };

View File

@ -745,7 +745,7 @@ namespace libtorrent
// LOGGING // LOGGING
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
virtual void debug_log(const std::string& line); virtual void debug_log(const char* fmt, ...) const;
#endif #endif
// DEBUG // DEBUG

View File

@ -168,7 +168,7 @@ namespace libtorrent
union_endpoint m_tracker_address; union_endpoint m_tracker_address;
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
virtual void debug_log(const std::string& line) = 0; virtual void debug_log(const char* fmt, ...) const = 0;
#else #else
private: private:
#endif #endif

View File

@ -243,7 +243,7 @@ namespace libtorrent
boost::shared_ptr<request_callback> cb = requester(); boost::shared_ptr<request_callback> cb = requester();
if (cb) if (cb)
{ {
cb->debug_log("==> TRACKER_REQUEST [ url: " + url + " ]"); cb->debug_log("==> TRACKER_REQUEST [ url: %s ]", url.c_str());
} }
#endif #endif
} }

View File

@ -462,16 +462,16 @@ namespace libtorrent
error_code ec; error_code ec;
lazy_entry tmp; lazy_entry tmp;
lazy_entry const* info = 0; lazy_entry const* info = 0;
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " adding magnet link with resume data\n"; debug_log("adding magnet link with resume data");
#endif #endif
if (lazy_bdecode(&(*p.resume_data)[0], &(*p.resume_data)[0] if (lazy_bdecode(&(*p.resume_data)[0], &(*p.resume_data)[0]
+ p.resume_data->size(), tmp, ec, &pos) == 0 + p.resume_data->size(), tmp, ec, &pos) == 0
&& tmp.type() == lazy_entry::dict_t && tmp.type() == lazy_entry::dict_t
&& (info = tmp.dict_find_dict("info"))) && (info = tmp.dict_find_dict("info")))
{ {
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " found metadata in resume data\n"; debug_log("found metadata in resume data");
#endif #endif
// verify the info-hash of the metadata stored in the resume file matches // verify the info-hash of the metadata stored in the resume file matches
// the torrent we're loading // the torrent we're loading
@ -483,36 +483,36 @@ namespace libtorrent
// torrent, but the hash of the URL, until we have the full torrent // torrent, but the hash of the URL, until we have the full torrent
if (resume_ih == info_hash || !p.url.empty()) if (resume_ih == info_hash || !p.url.empty())
{ {
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " info-hash matched\n"; debug_log("info-hash matched");
#endif #endif
m_torrent_file = (p.ti ? p.ti : new torrent_info(resume_ih)); m_torrent_file = (p.ti ? p.ti : new torrent_info(resume_ih));
if (!m_torrent_file->parse_info_section(*info, ec, 0)) if (!m_torrent_file->parse_info_section(*info, ec, 0))
{ {
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
(*m_ses.m_logger) << time_now_string() << " failed to load metadata from resume file: " debug_log("failed to load metadata from resume file: %s"
<< ec.message() << "\n"; , ec.message().c_str());
#endif #endif
} }
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
else else
{ {
(*m_ses.m_logger) << time_now_string() << " successfully loaded metadata from resume file\n"; debug_log("successfully loaded metadata from resume file");
} }
#endif #endif
} }
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
else else
{ {
(*m_ses.m_logger) << time_now_string() << " metadata info-hash failed\n"; debug_log("metadata info-hash failed");
} }
#endif #endif
} }
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
else else
{ {
(*m_ses.m_logger) << time_now_string() << " no metadata found\n"; debug_log("no metadata found");
} }
#endif #endif
} }
@ -537,8 +537,7 @@ namespace libtorrent
TORRENT_ASSERT(m_ses.is_network_thread()); TORRENT_ASSERT(m_ses.is_network_thread());
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
(*m_ses.m_logger) << time_now_string() << " creating torrent: " debug_log("creating torrent: %s", torrent_file().name().c_str());
<< torrent_file().name() << "\n";
#endif #endif
m_net_interfaces.push_back(tcp::endpoint(net_interface.address(), 0)); m_net_interfaces.push_back(tcp::endpoint(net_interface.address(), 0));
@ -865,9 +864,8 @@ namespace libtorrent
void torrent::start() void torrent::start()
{ {
TORRENT_ASSERT(m_ses.is_network_thread()); TORRENT_ASSERT(m_ses.is_network_thread());
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " starting torrent: " debug_log("starting torrent");
<< torrent_file().name() << "\n";
#endif #endif
TORRENT_ASSERT(!m_picker); TORRENT_ASSERT(!m_picker);
@ -886,9 +884,7 @@ namespace libtorrent
std::vector<char>().swap(m_resume_data); std::vector<char>().swap(m_resume_data);
lazy_entry().swap(m_resume_entry); lazy_entry().swap(m_resume_entry);
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
(*m_ses.m_logger) << time_now_string() << " fastresume data for " debug_log("resume data rejected: %s pos: %d", ec.message().c_str(), pos);
<< torrent_file().name() << " rejected: " << ec.message()
<< " pos: " << pos << "\n";
#endif #endif
if (m_ses.m_alerts.should_post<fastresume_rejected_alert>()) if (m_ses.m_alerts.should_post<fastresume_rejected_alert>())
{ {
@ -1128,10 +1124,8 @@ namespace libtorrent
if (!j.error) return; if (!j.error) return;
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
(*m_ses.m_logger) << "disk error: '" << j.error.message() debug_log("disk error: (%d) %s in file: %d", j.error.value(), j.error.message().c_str()
<< " in file " << j.error_file , j.error_file.c_str());
<< " in torrent " << torrent_file().name()
<< "\n";
#endif #endif
TORRENT_ASSERT(j.piece >= 0); TORRENT_ASSERT(j.piece >= 0);
@ -1442,10 +1436,9 @@ namespace libtorrent
} }
} }
#if defined(TORRENT_VERBOSE_LOGGING) || defined(TORRENT_LOGGING) #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " <== INCOMING SSL CONNECTION [ torrent: " debug_log("<== incoming SSL CONNECTION [ n: %s | match: %s ]"
<< m_torrent_file->name() << " | n: " << names << " | match: " << (match?"yes":"no") , names.c_str(), match?"yes":"no");
<< " ]\n";
return match; return match;
#endif #endif
@ -1681,9 +1674,8 @@ namespace libtorrent
if (ev) if (ev)
{ {
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
(*m_ses.m_logger) << time_now_string() << " fastresume data for " debug_log("fastresume data rejected: %s"
<< torrent_file().name() << " rejected: " , error_code(ev, get_libtorrent_category()).message().c_str());
<< error_code(ev, get_libtorrent_category()).message() << "\n";
#endif #endif
std::vector<char>().swap(m_resume_data); std::vector<char>().swap(m_resume_data);
lazy_entry().swap(m_resume_entry); lazy_entry().swap(m_resume_entry);
@ -1898,9 +1890,15 @@ namespace libtorrent
} }
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
(*m_ses.m_logger) << time_now_string() << " fastresume data for " if (ret != 0)
<< torrent_file().name() << " rejected: " {
<< j.error.message() << " ret:" << ret << "\n"; debug_log("fastresume data rejected: ret: %d (%d) %s"
, ret, j.error.value(), j.error.message().c_str());
}
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
else
debug_log("fastresume data rejected accepted");
#endif
#endif #endif
// if ret != 0, it means we need a full check. We don't necessarily need // if ret != 0, it means we need a full check. We don't necessarily need
@ -2105,10 +2103,7 @@ namespace libtorrent
m_ses.m_alerts.post_alert(file_error_alert(j.error_file, get_handle(), j.error)); m_ses.m_alerts.post_alert(file_error_alert(j.error_file, get_handle(), j.error));
} }
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
(*m_ses.m_logger) << time_now_string() << ": fatal disk error [" debug_log("fatal disk error: (%d) %s", j.error.value(), j.error.message().c_str());
" error: " << j.error.message() <<
" torrent: " << torrent_file().name() <<
" ]\n";
#endif #endif
pause(); pause();
set_error(j.error, j.error_file); set_error(j.error, j.error_file);
@ -2418,10 +2413,12 @@ namespace libtorrent
} }
} }
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " ==> TACKER REQUEST " << req.url debug_log(" ==> TRACKER REQUEST \"%s\" event: %s abort: %d"
<< " event=" << (req.event==tracker_request::stopped?"stopped" , req.url.c_str()
, (req.event==tracker_request::stopped?"stopped"
:req.event==tracker_request::started?"started":"") :req.event==tracker_request::started?"started":"")
<< " abort=" << m_abort << "\n"; , m_abort);
if (m_abort) if (m_abort)
{ {
boost::shared_ptr<aux::tracker_logger> tl(new aux::tracker_logger(m_ses)); boost::shared_ptr<aux::tracker_logger> tl(new aux::tracker_logger(m_ses));
@ -2430,8 +2427,11 @@ namespace libtorrent
} }
else else
#endif #endif
{
m_ses.m_tracker_manager.queue_request(m_ses.m_io_service, m_ses.m_half_open, req m_ses.m_tracker_manager.queue_request(m_ses.m_io_service, m_ses.m_half_open, req
, tracker_login() , shared_from_this()); , tracker_login() , shared_from_this());
}
ae.updating = true; ae.updating = true;
ae.next_announce = now + seconds(20); ae.next_announce = now + seconds(20);
ae.min_announce = now + seconds(10); ae.min_announce = now + seconds(10);
@ -2579,7 +2579,7 @@ namespace libtorrent
std::copy(tracker_ips.begin(), tracker_ips.end(), std::ostream_iterator<address>(s, " ")); std::copy(tracker_ips.begin(), tracker_ips.end(), std::ostream_iterator<address>(s, " "));
s << "\n"; s << "\n";
s << "we connected to: " << tracker_ip << "\n"; s << "we connected to: " << tracker_ip << "\n";
debug_log(s.str()); debug_log("%s", s.str().c_str());
#endif #endif
// for each of the peers we got from the tracker // for each of the peers we got from the tracker
for (std::vector<peer_entry>::iterator i = peer_list.begin(); for (std::vector<peer_entry>::iterator i = peer_list.begin();
@ -2676,8 +2676,8 @@ namespace libtorrent
:m_ses.m_ipv4_interface.address(); :m_ses.m_ipv4_interface.address();
announce_with_tracker(r.event, bind_interface); announce_with_tracker(r.event, bind_interface);
#if (defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING) && TORRENT_USE_IOSTREAM #if (defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING) && TORRENT_USE_IOSTREAM
debug_log("announce again using " + print_address(bind_interface) debug_log("announce again using %s as the bind interface"
+ " as the bind interface"); , print_address(bind_interface).c_str());
#endif #endif
} }
} }
@ -2743,7 +2743,7 @@ namespace libtorrent
#if defined TORRENT_LOGGING #if defined TORRENT_LOGGING
if (ec) if (ec)
*m_ses.m_logger << time_now_string() << " on_i2p_resolve: " << ec.message() << "\n"; debug_log("i2p_resolve error: %s", ec.message().c_str());
#endif #endif
if (ec || m_ses.is_aborted()) return; if (ec || m_ses.is_aborted()) return;
@ -2764,7 +2764,7 @@ namespace libtorrent
#if defined TORRENT_LOGGING #if defined TORRENT_LOGGING
if (e) if (e)
*m_ses.m_logger << time_now_string() << " on_peer_name_lookup: " << e.message() << "\n"; debug_log("peer name lookup error: %s", e.message().c_str());
#endif #endif
if (e || host == tcp::resolver::iterator() || if (e || host == tcp::resolver::iterator() ||
m_ses.is_aborted()) return; m_ses.is_aborted()) return;
@ -2774,7 +2774,7 @@ namespace libtorrent
{ {
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
error_code ec; error_code ec;
debug_log("blocked ip from tracker: " + host->endpoint().address().to_string(ec)); debug_log("blocked ip from tracker: %s", host->endpoint().address().to_string(ec).c_str());
#endif #endif
if (m_ses.m_alerts.should_post<peer_blocked_alert>()) if (m_ses.m_alerts.should_post<peer_blocked_alert>())
m_ses.m_alerts.post_alert(peer_blocked_alert(get_handle(), host->endpoint().address())); m_ses.m_alerts.post_alert(peer_blocked_alert(get_handle(), host->endpoint().address()));
@ -3088,11 +3088,11 @@ namespace libtorrent
{ {
TORRENT_ASSERT(m_ses.is_network_thread()); TORRENT_ASSERT(m_ses.is_network_thread());
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " *** PIECE_FINISHED [ p: " debug_log("*** PIECE_FINISHED [ p: %d | chk: %s | size: %d ]"
<< index << " chk: " << ((passed_hash_check == 0) , index, ((passed_hash_check == 0)
?"passed":passed_hash_check == -1 ?"passed":passed_hash_check == -1
?"disk failed":"failed") << " size: " ?"disk failed":"failed")
<< m_torrent_file->piece_size(index) << " ]\n"; , m_torrent_file->piece_size(index));
#endif #endif
TORRENT_ASSERT(valid_metadata()); TORRENT_ASSERT(valid_metadata());
@ -3439,12 +3439,11 @@ namespace libtorrent
if (p->connection) if (p->connection)
{ {
#ifdef TORRENT_LOGGING #ifdef TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " *** BANNING PEER [ " << p->ip() debug_log("*** BANNING PEER: \"%s\" Too many corrupt pieces"
<< " ] 'too many corrupt pieces'\n"; , print_endpoint(p->ip()).c_str());
#endif #endif
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING
(*p->connection->m_logger) << "*** BANNING PEER [ " << p->ip() p->connection->peer_log("*** BANNING PEER: Too many corrupt pieces");
<< " ] 'too many corrupt pieces'\n";
#endif #endif
p->connection->disconnect(errors::too_many_corrupt_pieces); p->connection->disconnect(errors::too_many_corrupt_pieces);
} }
@ -4435,7 +4434,7 @@ namespace libtorrent
return; return;
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " resolving web seed: " << web->url << "\n"; debug_log("resolving web seed: %s", web->url.c_str());
#endif #endif
std::string protocol; std::string protocol;
@ -4449,8 +4448,8 @@ namespace libtorrent
if (ec) if (ec)
{ {
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
(*m_ses.m_logger) << time_now_string() << " failed to parse web seed url: " << ec.message() << "\n"; debug_log("failed to parse web seed url: %s", ec.message().c_str());
#endif #endif
if (m_ses.m_alerts.should_post<url_seed_alert>()) if (m_ses.m_alerts.should_post<url_seed_alert>())
{ {
@ -4465,7 +4464,7 @@ namespace libtorrent
if (web->peer_info.banned) if (web->peer_info.banned)
{ {
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << "banned web seed: " << web->url << "\n"; debug_log("banned web seed: %s", web->url.c_str());
#endif #endif
if (m_ses.m_alerts.should_post<url_seed_alert>()) if (m_ses.m_alerts.should_post<url_seed_alert>())
{ {
@ -4571,16 +4570,18 @@ namespace libtorrent
TORRENT_ASSERT(web->resolving == true); TORRENT_ASSERT(web->resolving == true);
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " completed resolve proxy hostname for: " << web->url << "\n"; debug_log("completed resolve proxy hostname for: %s", web->url.c_str());
#endif
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
if (e) if (e)
*m_ses.m_logger << time_now_string() << " on_proxy_name_lookup: " << e.message() << "\n"; debug_log("proxy name lookup error: %s", e.message().c_str());
#endif #endif
web->resolving = false; web->resolving = false;
if (web->removed) if (web->removed)
{ {
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " removed web seed\n"; debug_log("removed web seed");
#endif #endif
remove_web_seed(web); remove_web_seed(web);
return; return;
@ -4659,13 +4660,13 @@ namespace libtorrent
TORRENT_ASSERT(web->resolving == true); TORRENT_ASSERT(web->resolving == true);
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " completed resolve: " << web->url << "\n"; debug_log("completed resolve: %s", web->url.c_str());
#endif #endif
web->resolving = false; web->resolving = false;
if (web->removed) if (web->removed)
{ {
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " removed web seed\n"; debug_log("removed web seed");
#endif #endif
remove_web_seed(web); remove_web_seed(web);
return; return;
@ -4678,8 +4679,8 @@ namespace libtorrent
if (m_ses.m_alerts.should_post<url_seed_alert>()) if (m_ses.m_alerts.should_post<url_seed_alert>())
m_ses.m_alerts.post_alert(url_seed_alert(get_handle(), web->url, e)); m_ses.m_alerts.post_alert(url_seed_alert(get_handle(), web->url, e));
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
(*m_ses.m_logger) << " ** HOSTNAME LOOKUP FAILED!**: " << web->url debug_log("*** HOSTNAME LOOKUP FAILED: %s: (%d) %s"
<< " " << e.message() << "\n"; , web->url.c_str(), e.value(), e.message().c_str());
#endif #endif
// unavailable, retry in 30 minutes // unavailable, retry in 30 minutes
@ -4820,7 +4821,7 @@ namespace libtorrent
web->peer_info.prev_amount_download = 0; web->peer_info.prev_amount_download = 0;
web->peer_info.prev_amount_upload = 0; web->peer_info.prev_amount_upload = 0;
#if defined TORRENT_VERBOSE_LOGGING #if defined TORRENT_VERBOSE_LOGGING
(*m_ses.m_logger) << time_now_string() << " web seed connection started " << web->url << "\n"; debug_log("web seed connection started: %s", web->url.c_str());
#endif #endif
c->start(); c->start();
@ -4835,7 +4836,7 @@ namespace libtorrent
TORRENT_DECLARE_DUMMY(std::exception, e); TORRENT_DECLARE_DUMMY(std::exception, e);
(void)e; (void)e;
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
(*m_ses.m_logger) << " ** HOSTNAME LOOKUP FAILED!**: " << e.what() << "\n"; debug_log("*** HOST NAME LOOKUP FAILED: %s", e.what());
#endif #endif
c->disconnect(errors::no_error, 1); c->disconnect(errors::no_error, 1);
} }
@ -4974,7 +4975,8 @@ namespace libtorrent
// unknown country! // unknown country!
p->set_country("!!"); p->set_country("!!");
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
(*m_ses.m_logger) << "IP " << p->remote().address() << " was mapped to unknown country: " << country << "\n"; debug_log("IP \"%s\" was mapped to unknown country: %d"
, print_address(p->remote().address()).c_str(), country);
#endif #endif
return; return;
} }
@ -5937,8 +5939,8 @@ namespace libtorrent
if (!m_policy.new_connection(*p, m_ses.session_time())) if (!m_policy.new_connection(*p, m_ses.session_time()))
{ {
#if defined TORRENT_LOGGING #if defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " CLOSING CONNECTION " debug_log("CLOSING CONNECTION \"%s\" peer list full"
<< p->remote() << " policy::new_connection returned false (i.e. peer list full)\n"; , print_endpoint(p->remote()).c_str());
#endif #endif
p->disconnect(errors::too_many_connections); p->disconnect(errors::too_many_connections);
return false; return false;
@ -5949,8 +5951,8 @@ namespace libtorrent
TORRENT_DECLARE_DUMMY(std::exception, e); TORRENT_DECLARE_DUMMY(std::exception, e);
(void)e; (void)e;
#if defined TORRENT_LOGGING #if defined TORRENT_LOGGING
(*m_ses.m_logger) << time_now_string() << " CLOSING CONNECTION " debug_log("CLOSING CONNECTION \"%s\" caught exception: %s"
<< p->remote() << " policy::new_connection threw: " << e.what() << "\n"; , print_endpoint(p->remote()).c_str(), e.what());
#endif #endif
p->disconnect(errors::no_error); p->disconnect(errors::no_error);
return false; return false;
@ -5998,7 +6000,7 @@ namespace libtorrent
TORRENT_ASSERT(p->associated_torrent().lock().get() == this); TORRENT_ASSERT(p->associated_torrent().lock().get() == this);
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING
(*p->m_logger) << "*** CLOSING CONNECTION: " << ec.message() << "\n"; p->peer_log("*** CLOSING CONNECTION \"%s\"", ec.message().c_str());
#endif #endif
#if defined TORRENT_DEBUG || TORRENT_RELEASE_ASSERTS #if defined TORRENT_DEBUG || TORRENT_RELEASE_ASSERTS
std::size_t size = m_connections.size(); std::size_t size = m_connections.size();
@ -6127,7 +6129,7 @@ namespace libtorrent
if (p->upload_only()) if (p->upload_only())
{ {
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING
(*p->m_logger) << "*** SEED, CLOSING CONNECTION\n"; p->peer_log("*** SEED, CLOSING CONNECTION");
#endif #endif
seeds.push_back(p); seeds.push_back(p);
} }
@ -6232,7 +6234,13 @@ namespace libtorrent
TORRENT_ASSERT(m_ses.is_network_thread()); TORRENT_ASSERT(m_ses.is_network_thread());
TORRENT_ASSERT(m_torrent_file->is_valid()); TORRENT_ASSERT(m_torrent_file->is_valid());
if (m_abort) return; if (m_abort)
{
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
debug_log("files_checked(), paused");
#endif
return;
}
// we might be finished already, in which case we should // we might be finished already, in which case we should
// not switch to downloading mode. If all files are // not switch to downloading mode. If all files are
@ -7161,7 +7169,7 @@ namespace libtorrent
} }
#endif #endif
(*m_ses.m_logger) << time_now_string() << " " << message << "\n"; debug_log("%s", message);
} }
#endif #endif
@ -7329,11 +7337,23 @@ namespace libtorrent
void torrent::start_announcing() void torrent::start_announcing()
{ {
TORRENT_ASSERT(m_ses.is_network_thread()); TORRENT_ASSERT(m_ses.is_network_thread());
if (is_paused()) return; if (is_paused())
{
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
debug_log("start_announcing(), paused");
#endif
return;
}
// if we don't have metadata, we need to announce // if we don't have metadata, we need to announce
// before checking files, to get peers to // before checking files, to get peers to
// request the metadata from // request the metadata from
if (!m_files_checked && valid_metadata()) return; if (!m_files_checked && valid_metadata())
{
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
debug_log("start_announcing(), files not checked (with valid metadata)");
#endif
return;
}
if (m_announcing) return; if (m_announcing) return;
m_announcing = true; m_announcing = true;
@ -8005,7 +8025,7 @@ namespace libtorrent
TORRENT_ASSERT(i->resolving == false); TORRENT_ASSERT(i->resolving == false);
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING
(*m_ses.m_logger) << time_now_string() << " disconnect_web_seed: " << i->url << "\n"; debug_log("disconnect web seed: \"%s\"", i->url.c_str());
#endif #endif
TORRENT_ASSERT(i->peer_info.connection); TORRENT_ASSERT(i->peer_info.connection);
i->peer_info.connection = 0; i->peer_info.connection = 0;
@ -8308,6 +8328,10 @@ namespace libtorrent
m_state = s; m_state = s;
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
debug_log("set_state() %d", m_state);
#endif
// update finished and downloading counters // update finished and downloading counters
if (was_active_download && !is_active_download()) m_ses.dec_active_downloading(); if (was_active_download && !is_active_download()) m_ses.dec_active_downloading();
else if (!was_active_download && is_active_download()) m_ses.inc_active_downloading(); else if (!was_active_download && is_active_download()) m_ses.inc_active_downloading();
@ -8602,7 +8626,7 @@ namespace libtorrent
INVARIANT_CHECK; INVARIANT_CHECK;
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
debug_log("*** tracker error: " + ec.message() + " " + msg); debug_log("*** tracker error: (%d) %s %s", ec.value(), ec.message().c_str(), msg.c_str());
#endif #endif
if (r.kind == tracker_request::announce_request) if (r.kind == tracker_request::announce_request)
{ {
@ -8614,8 +8638,7 @@ namespace libtorrent
ae->message = msg; ae->message = msg;
int tracker_index = ae - &m_trackers[0]; int tracker_index = ae - &m_trackers[0];
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
debug_log("*** increment tracker fail count [" debug_log("*** increment tracker fail count [%d]", ae->fails);
+ std::string(to_string(ae->fails).elems) + "]");
#endif #endif
deprioritize_tracker(tracker_index); deprioritize_tracker(tracker_index);
} }
@ -8640,10 +8663,20 @@ namespace libtorrent
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
void torrent::debug_log(const std::string& line) void torrent::debug_log(const char* fmt, ...) const
{ {
TORRENT_ASSERT(m_ses.is_network_thread()); if (!m_ses.m_logger) return;
(*m_ses.m_logger) << time_now_string() << " " << line << "\n";
va_list v;
va_start(v, fmt);
char usr[1024];
vsnprintf(usr, sizeof(usr), fmt, v);
va_end(v);
char buf[1280];
snprintf(buf, sizeof(buf), "%s: %s: %s\n", time_now_string()
, to_hex(info_hash().to_string()).substr(0, 6).c_str(), usr);
(*m_ses.m_logger) << buf;
} }
#endif #endif

View File

@ -325,7 +325,7 @@ namespace libtorrent
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
boost::shared_ptr<request_callback> rc = c->requester(); boost::shared_ptr<request_callback> rc = c->requester();
if (rc) rc->debug_log("aborting: " + req.url); if (rc) rc->debug_log("aborting: %s", req.url.c_str());
#endif #endif
} }
l.unlock(); l.unlock();

View File

@ -121,7 +121,8 @@ namespace libtorrent
&udp_tracker_connection::name_lookup, self(), _1, _2)); &udp_tracker_connection::name_lookup, self(), _1, _2));
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
boost::shared_ptr<request_callback> cb = requester(); boost::shared_ptr<request_callback> cb = requester();
if (cb) cb->debug_log(("*** UDP_TRACKER [ initiating name lookup: " + hostname + " ]").c_str()); if (cb) cb->debug_log("*** UDP_TRACKER [ initiating name lookup: \"%s\" ]"
, hostname.c_str());
#endif #endif
} }
@ -173,7 +174,8 @@ namespace libtorrent
if (m_ses.m_ip_filter.access(k->address()) == ip_filter::blocked) if (m_ses.m_ip_filter.access(k->address()) == ip_filter::blocked)
{ {
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
if (cb) cb->debug_log("*** UDP_TRACKER [ IP blocked by filter: " + print_address(k->address()) + " ]"); if (cb) cb->debug_log("*** UDP_TRACKER [ IP blocked by filter: %s ]"
, print_address(k->address()).c_str());
#endif #endif
k = m_endpoints.erase(k); k = m_endpoints.erase(k);
} }
@ -261,9 +263,7 @@ namespace libtorrent
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING
boost::shared_ptr<request_callback> cb = requester(); boost::shared_ptr<request_callback> cb = requester();
char msg[200]; if (cb) cb->debug_log("*** UDP_TRACKER [ timed out url: %s ]", tracker_req().url.c_str());
snprintf(msg, 200, "*** UDP_TRACKER [ timed out url: %s ]", tracker_req().url.c_str());
if (cb) cb->debug_log(msg);
#endif #endif
m_abort = true; m_abort = true;
fail(error_code(errors::timed_out)); fail(error_code(errors::timed_out));
@ -305,9 +305,7 @@ namespace libtorrent
boost::shared_ptr<request_callback> cb = requester(); boost::shared_ptr<request_callback> cb = requester();
if (cb) if (cb)
{ {
char msg[200]; cb->debug_log("<== UDP_TRACKER_PACKET [ size: %d ]", size);
snprintf(msg, 200, "<== UDP_TRACKER_PACKET [ size: %d ]", size);
cb->debug_log(msg);
} }
#endif #endif
@ -321,9 +319,7 @@ namespace libtorrent
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
if (cb) if (cb)
{ {
char msg[200]; cb->debug_log("*** UDP_TRACKER_PACKET [ action: %d ]", action);
snprintf(msg, 200, "*** UDP_TRACKER_PACKET [ action: %d ]", action);
cb->debug_log(msg);
} }
#endif #endif
@ -344,10 +340,8 @@ namespace libtorrent
#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING
if (cb) if (cb)
{ {
char msg[200]; cb->debug_log("*** UDP_TRACKER_RESPONSE [ tid: %x ]"
snprintf(msg, 200, "*** UDP_TRACKER_RESPONSE [ tid: %x ]"
, int(transaction)); , int(transaction));
cb->debug_log(msg);
} }
#endif #endif
@ -397,9 +391,7 @@ namespace libtorrent
{ {
char hex_ih[41]; char hex_ih[41];
to_hex((char const*)&tracker_req().info_hash[0], 20, hex_ih); to_hex((char const*)&tracker_req().info_hash[0], 20, hex_ih);
char msg[200]; cb->debug_log("==> UDP_TRACKER_CONNECT [%s]", hex_ih);
snprintf(msg, 200, "==> UDP_TRACKER_CONNECT [%s]", hex_ih);
cb->debug_log(msg);
} }
#endif #endif
if (m_abort) return; if (m_abort) return;
@ -500,9 +492,7 @@ namespace libtorrent
if (cb) if (cb)
{ {
boost::shared_ptr<request_callback> cb = requester(); boost::shared_ptr<request_callback> cb = requester();
char msg[200]; cb->debug_log("<== UDP_TRACKER_RESPONSE [ url: %s ]", tracker_req().url.c_str());
snprintf(msg, 200, "<== UDP_TRACKER_RESPONSE [ url: %s ]", tracker_req().url.c_str());
cb->debug_log(msg);
} }
#endif #endif
@ -662,9 +652,7 @@ namespace libtorrent
{ {
char hex_ih[41]; char hex_ih[41];
to_hex((char const*)&req.info_hash[0], 20, hex_ih); to_hex((char const*)&req.info_hash[0], 20, hex_ih);
char msg[200]; cb->debug_log("==> UDP_TRACKER_ANNOUNCE [%s]", hex_ih);
snprintf(msg, 200, "==> UDP_TRACKER_ANNOUNCE [%s]", hex_ih);
cb->debug_log(msg);
} }
#endif #endif