From 5e2ff1a2464d0123fad346a6b494e37efedd51aa Mon Sep 17 00:00:00 2001 From: Arvid Norberg Date: Thu, 27 Sep 2012 23:04:51 +0000 Subject: [PATCH] merged logging cleanup from RC_0_16 --- include/libtorrent/aux_/session_impl.hpp | 22 ++- include/libtorrent/torrent.hpp | 2 +- include/libtorrent/tracker_manager.hpp | 2 +- src/http_tracker_connection.cpp | 2 +- src/torrent.cpp | 209 +++++++++++++---------- src/tracker_manager.cpp | 2 +- src/udp_tracker_connection.cpp | 34 ++-- 7 files changed, 151 insertions(+), 122 deletions(-) diff --git a/include/libtorrent/aux_/session_impl.hpp b/include/libtorrent/aux_/session_impl.hpp index c37982e5d..5676ea8c2 100644 --- a/include/libtorrent/aux_/session_impl.hpp +++ b/include/libtorrent/aux_/session_impl.hpp @@ -1204,7 +1204,7 @@ namespace libtorrent void tracker_warning(tracker_request const& req , std::string const& str) { - debug_log("*** tracker warning: " + str); + debug_log("*** tracker warning: %s", str.c_str()); } 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()); s += tmp; - debug_log(s); + debug_log("%s", s.c_str()); } void tracker_request_timed_out( @@ -1248,15 +1248,23 @@ namespace libtorrent , int response_code, error_code const& ec, const std::string& str , int retry_interval) { - char msg[256]; - snprintf(msg, sizeof(msg), "*** tracker error: %d: %s %s" + debug_log("*** tracker error: %d: %s %s" , 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; }; diff --git a/include/libtorrent/torrent.hpp b/include/libtorrent/torrent.hpp index e6f5a8d6d..4709b12b1 100644 --- a/include/libtorrent/torrent.hpp +++ b/include/libtorrent/torrent.hpp @@ -745,7 +745,7 @@ namespace libtorrent // 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 // DEBUG diff --git a/include/libtorrent/tracker_manager.hpp b/include/libtorrent/tracker_manager.hpp index 470116f9a..d0f68f85c 100644 --- a/include/libtorrent/tracker_manager.hpp +++ b/include/libtorrent/tracker_manager.hpp @@ -168,7 +168,7 @@ namespace libtorrent union_endpoint m_tracker_address; #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 private: #endif diff --git a/src/http_tracker_connection.cpp b/src/http_tracker_connection.cpp index ff9bc157c..d281f274b 100644 --- a/src/http_tracker_connection.cpp +++ b/src/http_tracker_connection.cpp @@ -243,7 +243,7 @@ namespace libtorrent boost::shared_ptr cb = requester(); if (cb) { - cb->debug_log("==> TRACKER_REQUEST [ url: " + url + " ]"); + cb->debug_log("==> TRACKER_REQUEST [ url: %s ]", url.c_str()); } #endif } diff --git a/src/torrent.cpp b/src/torrent.cpp index 6722d236a..d53c4ca53 100644 --- a/src/torrent.cpp +++ b/src/torrent.cpp @@ -462,16 +462,16 @@ namespace libtorrent error_code ec; lazy_entry tmp; lazy_entry const* info = 0; -#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_ses.m_logger) << time_now_string() << " adding magnet link with resume data\n"; +#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING + debug_log("adding magnet link with resume data"); #endif if (lazy_bdecode(&(*p.resume_data)[0], &(*p.resume_data)[0] + p.resume_data->size(), tmp, ec, &pos) == 0 && tmp.type() == lazy_entry::dict_t && (info = tmp.dict_find_dict("info"))) { -#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_ses.m_logger) << time_now_string() << " found metadata in resume data\n"; +#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING + debug_log("found metadata in resume data"); #endif // verify the info-hash of the metadata stored in the resume file matches // the torrent we're loading @@ -483,36 +483,36 @@ namespace libtorrent // torrent, but the hash of the URL, until we have the full torrent if (resume_ih == info_hash || !p.url.empty()) { -#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_ses.m_logger) << time_now_string() << " info-hash matched\n"; +#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING + debug_log("info-hash matched"); #endif m_torrent_file = (p.ti ? p.ti : new torrent_info(resume_ih)); if (!m_torrent_file->parse_info_section(*info, ec, 0)) { #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: " - << ec.message() << "\n"; + debug_log("failed to load metadata from resume file: %s" + , ec.message().c_str()); #endif } -#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING +#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING else { - (*m_ses.m_logger) << time_now_string() << " successfully loaded metadata from resume file\n"; + debug_log("successfully loaded metadata from resume file"); } #endif } #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING else { - (*m_ses.m_logger) << time_now_string() << " metadata info-hash failed\n"; + debug_log("metadata info-hash failed"); } #endif } #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING else { - (*m_ses.m_logger) << time_now_string() << " no metadata found\n"; + debug_log("no metadata found"); } #endif } @@ -537,8 +537,7 @@ namespace libtorrent TORRENT_ASSERT(m_ses.is_network_thread()); #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_ses.m_logger) << time_now_string() << " creating torrent: " - << torrent_file().name() << "\n"; + debug_log("creating torrent: %s", torrent_file().name().c_str()); #endif m_net_interfaces.push_back(tcp::endpoint(net_interface.address(), 0)); @@ -865,9 +864,8 @@ namespace libtorrent void torrent::start() { TORRENT_ASSERT(m_ses.is_network_thread()); -#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_ses.m_logger) << time_now_string() << " starting torrent: " - << torrent_file().name() << "\n"; +#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING + debug_log("starting torrent"); #endif TORRENT_ASSERT(!m_picker); @@ -886,9 +884,7 @@ namespace libtorrent std::vector().swap(m_resume_data); lazy_entry().swap(m_resume_entry); #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_ses.m_logger) << time_now_string() << " fastresume data for " - << torrent_file().name() << " rejected: " << ec.message() - << " pos: " << pos << "\n"; + debug_log("resume data rejected: %s pos: %d", ec.message().c_str(), pos); #endif if (m_ses.m_alerts.should_post()) { @@ -1128,10 +1124,8 @@ namespace libtorrent if (!j.error) return; #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_ses.m_logger) << "disk error: '" << j.error.message() - << " in file " << j.error_file - << " in torrent " << torrent_file().name() - << "\n"; + debug_log("disk error: (%d) %s in file: %d", j.error.value(), j.error.message().c_str() + , j.error_file.c_str()); #endif TORRENT_ASSERT(j.piece >= 0); @@ -1442,10 +1436,9 @@ namespace libtorrent } } -#if defined(TORRENT_VERBOSE_LOGGING) || defined(TORRENT_LOGGING) - (*m_ses.m_logger) << time_now_string() << " <== INCOMING SSL CONNECTION [ torrent: " - << m_torrent_file->name() << " | n: " << names << " | match: " << (match?"yes":"no") - << " ]\n"; +#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING + debug_log("<== incoming SSL CONNECTION [ n: %s | match: %s ]" + , names.c_str(), match?"yes":"no"); return match; #endif @@ -1681,9 +1674,8 @@ namespace libtorrent if (ev) { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_ses.m_logger) << time_now_string() << " fastresume data for " - << torrent_file().name() << " rejected: " - << error_code(ev, get_libtorrent_category()).message() << "\n"; + debug_log("fastresume data rejected: %s" + , error_code(ev, get_libtorrent_category()).message().c_str()); #endif std::vector().swap(m_resume_data); lazy_entry().swap(m_resume_entry); @@ -1898,9 +1890,15 @@ namespace libtorrent } #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_ses.m_logger) << time_now_string() << " fastresume data for " - << torrent_file().name() << " rejected: " - << j.error.message() << " ret:" << ret << "\n"; + if (ret != 0) + { + 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 // 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)); } #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_ses.m_logger) << time_now_string() << ": fatal disk error [" - " error: " << j.error.message() << - " torrent: " << torrent_file().name() << - " ]\n"; + debug_log("fatal disk error: (%d) %s", j.error.value(), j.error.message().c_str()); #endif pause(); set_error(j.error, j.error_file); @@ -2418,10 +2413,12 @@ namespace libtorrent } } #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING - (*m_ses.m_logger) << time_now_string() << " ==> TACKER REQUEST " << req.url - << " event=" << (req.event==tracker_request::stopped?"stopped" + debug_log(" ==> TRACKER REQUEST \"%s\" event: %s abort: %d" + , req.url.c_str() + , (req.event==tracker_request::stopped?"stopped" :req.event==tracker_request::started?"started":"") - << " abort=" << m_abort << "\n"; + , m_abort); + if (m_abort) { boost::shared_ptr tl(new aux::tracker_logger(m_ses)); @@ -2430,8 +2427,11 @@ namespace libtorrent } else #endif - m_ses.m_tracker_manager.queue_request(m_ses.m_io_service, m_ses.m_half_open, req - , tracker_login() , shared_from_this()); + { + m_ses.m_tracker_manager.queue_request(m_ses.m_io_service, m_ses.m_half_open, req + , tracker_login() , shared_from_this()); + } + ae.updating = true; ae.next_announce = now + seconds(20); ae.min_announce = now + seconds(10); @@ -2579,7 +2579,7 @@ namespace libtorrent std::copy(tracker_ips.begin(), tracker_ips.end(), std::ostream_iterator
(s, " ")); s << "\n"; s << "we connected to: " << tracker_ip << "\n"; - debug_log(s.str()); + debug_log("%s", s.str().c_str()); #endif // for each of the peers we got from the tracker for (std::vector::iterator i = peer_list.begin(); @@ -2676,8 +2676,8 @@ namespace libtorrent :m_ses.m_ipv4_interface.address(); announce_with_tracker(r.event, bind_interface); #if (defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING) && TORRENT_USE_IOSTREAM - debug_log("announce again using " + print_address(bind_interface) - + " as the bind interface"); + debug_log("announce again using %s as the bind interface" + , print_address(bind_interface).c_str()); #endif } } @@ -2743,7 +2743,7 @@ namespace libtorrent #if defined TORRENT_LOGGING 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 if (ec || m_ses.is_aborted()) return; @@ -2764,7 +2764,7 @@ namespace libtorrent #if defined TORRENT_LOGGING 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 if (e || host == tcp::resolver::iterator() || m_ses.is_aborted()) return; @@ -2774,7 +2774,7 @@ namespace libtorrent { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING 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 if (m_ses.m_alerts.should_post()) 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()); #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING - (*m_ses.m_logger) << time_now_string() << " *** PIECE_FINISHED [ p: " - << index << " chk: " << ((passed_hash_check == 0) + debug_log("*** PIECE_FINISHED [ p: %d | chk: %s | size: %d ]" + , index, ((passed_hash_check == 0) ?"passed":passed_hash_check == -1 - ?"disk failed":"failed") << " size: " - << m_torrent_file->piece_size(index) << " ]\n"; + ?"disk failed":"failed") + , m_torrent_file->piece_size(index)); #endif TORRENT_ASSERT(valid_metadata()); @@ -3439,12 +3439,11 @@ namespace libtorrent if (p->connection) { #ifdef TORRENT_LOGGING - (*m_ses.m_logger) << time_now_string() << " *** BANNING PEER [ " << p->ip() - << " ] 'too many corrupt pieces'\n"; + debug_log("*** BANNING PEER: \"%s\" Too many corrupt pieces" + , print_endpoint(p->ip()).c_str()); #endif #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*p->connection->m_logger) << "*** BANNING PEER [ " << p->ip() - << " ] 'too many corrupt pieces'\n"; + p->connection->peer_log("*** BANNING PEER: Too many corrupt pieces"); #endif p->connection->disconnect(errors::too_many_corrupt_pieces); } @@ -4435,7 +4434,7 @@ namespace libtorrent return; #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 std::string protocol; @@ -4449,8 +4448,8 @@ namespace libtorrent if (ec) { -#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING - (*m_ses.m_logger) << time_now_string() << " failed to parse web seed url: " << ec.message() << "\n"; +#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING + debug_log("failed to parse web seed url: %s", ec.message().c_str()); #endif if (m_ses.m_alerts.should_post()) { @@ -4465,7 +4464,7 @@ namespace libtorrent if (web->peer_info.banned) { #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 if (m_ses.m_alerts.should_post()) { @@ -4571,16 +4570,18 @@ namespace libtorrent TORRENT_ASSERT(web->resolving == true); #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) - *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 web->resolving = false; if (web->removed) { #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 remove_web_seed(web); return; @@ -4659,13 +4660,13 @@ namespace libtorrent TORRENT_ASSERT(web->resolving == true); #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 web->resolving = false; if (web->removed) { #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 remove_web_seed(web); return; @@ -4678,8 +4679,8 @@ namespace libtorrent if (m_ses.m_alerts.should_post()) 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 - (*m_ses.m_logger) << " ** HOSTNAME LOOKUP FAILED!**: " << web->url - << " " << e.message() << "\n"; + debug_log("*** HOSTNAME LOOKUP FAILED: %s: (%d) %s" + , web->url.c_str(), e.value(), e.message().c_str()); #endif // unavailable, retry in 30 minutes @@ -4820,7 +4821,7 @@ namespace libtorrent web->peer_info.prev_amount_download = 0; web->peer_info.prev_amount_upload = 0; #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 c->start(); @@ -4835,7 +4836,7 @@ namespace libtorrent TORRENT_DECLARE_DUMMY(std::exception, e); (void)e; #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 c->disconnect(errors::no_error, 1); } @@ -4974,7 +4975,8 @@ namespace libtorrent // unknown country! p->set_country("!!"); #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 return; } @@ -5937,8 +5939,8 @@ namespace libtorrent if (!m_policy.new_connection(*p, m_ses.session_time())) { #if defined TORRENT_LOGGING - (*m_ses.m_logger) << time_now_string() << " CLOSING CONNECTION " - << p->remote() << " policy::new_connection returned false (i.e. peer list full)\n"; + debug_log("CLOSING CONNECTION \"%s\" peer list full" + , print_endpoint(p->remote()).c_str()); #endif p->disconnect(errors::too_many_connections); return false; @@ -5949,8 +5951,8 @@ namespace libtorrent TORRENT_DECLARE_DUMMY(std::exception, e); (void)e; #if defined TORRENT_LOGGING - (*m_ses.m_logger) << time_now_string() << " CLOSING CONNECTION " - << p->remote() << " policy::new_connection threw: " << e.what() << "\n"; + debug_log("CLOSING CONNECTION \"%s\" caught exception: %s" + , print_endpoint(p->remote()).c_str(), e.what()); #endif p->disconnect(errors::no_error); return false; @@ -5998,7 +6000,7 @@ namespace libtorrent TORRENT_ASSERT(p->associated_torrent().lock().get() == this); #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 #if defined TORRENT_DEBUG || TORRENT_RELEASE_ASSERTS std::size_t size = m_connections.size(); @@ -6127,7 +6129,7 @@ namespace libtorrent if (p->upload_only()) { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*p->m_logger) << "*** SEED, CLOSING CONNECTION\n"; + p->peer_log("*** SEED, CLOSING CONNECTION"); #endif seeds.push_back(p); } @@ -6232,7 +6234,13 @@ namespace libtorrent TORRENT_ASSERT(m_ses.is_network_thread()); 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 // not switch to downloading mode. If all files are @@ -7161,7 +7169,7 @@ namespace libtorrent } #endif - (*m_ses.m_logger) << time_now_string() << " " << message << "\n"; + debug_log("%s", message); } #endif @@ -7329,11 +7337,23 @@ namespace libtorrent void torrent::start_announcing() { 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 // before checking files, to get peers to // 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; m_announcing = true; @@ -8005,7 +8025,7 @@ namespace libtorrent TORRENT_ASSERT(i->resolving == false); #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 TORRENT_ASSERT(i->peer_info.connection); i->peer_info.connection = 0; @@ -8308,6 +8328,10 @@ namespace libtorrent m_state = s; +#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING + debug_log("set_state() %d", m_state); +#endif + // update finished and downloading counters 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(); @@ -8602,7 +8626,7 @@ namespace libtorrent INVARIANT_CHECK; #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 if (r.kind == tracker_request::announce_request) { @@ -8614,8 +8638,7 @@ namespace libtorrent ae->message = msg; int tracker_index = ae - &m_trackers[0]; #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING - debug_log("*** increment tracker fail count [" - + std::string(to_string(ae->fails).elems) + "]"); + debug_log("*** increment tracker fail count [%d]", ae->fails); #endif deprioritize_tracker(tracker_index); } @@ -8640,10 +8663,20 @@ namespace libtorrent #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()); - (*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: %s\n", time_now_string() + , to_hex(info_hash().to_string()).substr(0, 6).c_str(), usr); + (*m_ses.m_logger) << buf; } #endif diff --git a/src/tracker_manager.cpp b/src/tracker_manager.cpp index b5e22bb05..db7d90891 100644 --- a/src/tracker_manager.cpp +++ b/src/tracker_manager.cpp @@ -325,7 +325,7 @@ namespace libtorrent #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING boost::shared_ptr rc = c->requester(); - if (rc) rc->debug_log("aborting: " + req.url); + if (rc) rc->debug_log("aborting: %s", req.url.c_str()); #endif } l.unlock(); diff --git a/src/udp_tracker_connection.cpp b/src/udp_tracker_connection.cpp index 8930db7f6..964400f74 100644 --- a/src/udp_tracker_connection.cpp +++ b/src/udp_tracker_connection.cpp @@ -121,7 +121,8 @@ namespace libtorrent &udp_tracker_connection::name_lookup, self(), _1, _2)); #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING boost::shared_ptr 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 } @@ -173,7 +174,8 @@ namespace libtorrent if (m_ses.m_ip_filter.access(k->address()) == ip_filter::blocked) { #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 k = m_endpoints.erase(k); } @@ -261,9 +263,7 @@ namespace libtorrent #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING boost::shared_ptr cb = requester(); - char msg[200]; - snprintf(msg, 200, "*** UDP_TRACKER [ timed out url: %s ]", tracker_req().url.c_str()); - if (cb) cb->debug_log(msg); + if (cb) cb->debug_log("*** UDP_TRACKER [ timed out url: %s ]", tracker_req().url.c_str()); #endif m_abort = true; fail(error_code(errors::timed_out)); @@ -305,9 +305,7 @@ namespace libtorrent boost::shared_ptr cb = requester(); if (cb) { - char msg[200]; - snprintf(msg, 200, "<== UDP_TRACKER_PACKET [ size: %d ]", size); - cb->debug_log(msg); + cb->debug_log("<== UDP_TRACKER_PACKET [ size: %d ]", size); } #endif @@ -321,9 +319,7 @@ namespace libtorrent #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING if (cb) { - char msg[200]; - snprintf(msg, 200, "*** UDP_TRACKER_PACKET [ action: %d ]", action); - cb->debug_log(msg); + cb->debug_log("*** UDP_TRACKER_PACKET [ action: %d ]", action); } #endif @@ -344,10 +340,8 @@ namespace libtorrent #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING if (cb) { - char msg[200]; - snprintf(msg, 200, "*** UDP_TRACKER_RESPONSE [ tid: %x ]" + cb->debug_log("*** UDP_TRACKER_RESPONSE [ tid: %x ]" , int(transaction)); - cb->debug_log(msg); } #endif @@ -397,9 +391,7 @@ namespace libtorrent { char hex_ih[41]; to_hex((char const*)&tracker_req().info_hash[0], 20, hex_ih); - char msg[200]; - snprintf(msg, 200, "==> UDP_TRACKER_CONNECT [%s]", hex_ih); - cb->debug_log(msg); + cb->debug_log("==> UDP_TRACKER_CONNECT [%s]", hex_ih); } #endif if (m_abort) return; @@ -500,9 +492,7 @@ namespace libtorrent if (cb) { boost::shared_ptr cb = requester(); - char msg[200]; - snprintf(msg, 200, "<== UDP_TRACKER_RESPONSE [ url: %s ]", tracker_req().url.c_str()); - cb->debug_log(msg); + cb->debug_log("<== UDP_TRACKER_RESPONSE [ url: %s ]", tracker_req().url.c_str()); } #endif @@ -662,9 +652,7 @@ namespace libtorrent { char hex_ih[41]; to_hex((char const*)&req.info_hash[0], 20, hex_ih); - char msg[200]; - snprintf(msg, 200, "==> UDP_TRACKER_ANNOUNCE [%s]", hex_ih); - cb->debug_log(msg); + cb->debug_log("==> UDP_TRACKER_ANNOUNCE [%s]", hex_ih); } #endif