diff --git a/include/libtorrent/peer_connection.hpp b/include/libtorrent/peer_connection.hpp index 1bb317730..f74da5ef5 100644 --- a/include/libtorrent/peer_connection.hpp +++ b/include/libtorrent/peer_connection.hpp @@ -417,6 +417,7 @@ namespace libtorrent int est_reciprocation_rate() const { return m_est_reciprocation_rate; } #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING + void peer_log(char const* fmt, ...); boost::shared_ptr m_logger; #endif diff --git a/src/http_seed_connection.cpp b/src/http_seed_connection.cpp index 39b5a4cca..f5e3eb532 100644 --- a/src/http_seed_connection.cpp +++ b/src/http_seed_connection.cpp @@ -85,7 +85,7 @@ namespace libtorrent prefer_whole_pieces(1); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << "*** http_seed_connection\n"; + peer_log("*** http_seed_connection"); #endif } @@ -189,7 +189,7 @@ namespace libtorrent m_first_request = false; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << request << "\n"; + peer_log("==> %s", request.c_str()); #endif send_buffer(request.c_str(), request.size(), message_type_request); @@ -208,8 +208,7 @@ namespace libtorrent { m_statistics.received_bytes(0, bytes_transferred); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << "*** http_seed_connection error: " - << error.message() << "\n"; + peer_log("*** http_seed_connection error: %s", error.message().c_str()); #endif return; } @@ -373,8 +372,7 @@ namespace libtorrent else { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** parsed chunk: " << chunk_size - << " header_size: " << header_size << "\n"; + peer_log("*** parsed chunk: %d header_size: %d", chunk_size, header_size); #endif TORRENT_ASSERT(bytes_transferred >= header_size - m_partial_chunk_header); bytes_transferred -= header_size - m_partial_chunk_header; @@ -410,7 +408,7 @@ namespace libtorrent int retry_time = atol(std::string(recv_buffer.begin, recv_buffer.end).c_str()); if (retry_time <= 0) retry_time = 60; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << ": retrying in " << retry_time << " seconds\n"; + peer_log("retrying in %d seconds", retry_time); #endif m_statistics.received_bytes(0, bytes_transferred); diff --git a/src/peer_connection.cpp b/src/peer_connection.cpp index 40dc85bd9..ccc8d87c5 100644 --- a/src/peer_connection.cpp +++ b/src/peer_connection.cpp @@ -604,6 +604,23 @@ namespace libtorrent TORRENT_ASSERT(in_handshake() || is_interesting() == interested); } +#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING + void peer_connection::peer_log(char const* fmt, ...) + { + if (!m_logger) return; + + va_list v; + va_start(v, fmt); + + char usr[400]; + vsnprintf(usr, sizeof(usr), fmt, v); + va_end(v); + char buf[450]; + snprintf(buf, sizeof(buf), "%s: %s\n", time_now_string(), usr); + (*m_logger) << buf; + } +#endif + #ifndef TORRENT_DISABLE_EXTENSIONS void peer_connection::add_extension(boost::shared_ptr ext) { @@ -621,8 +638,7 @@ namespace libtorrent if (t->super_seeding()) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " *** SKIPPING ALLOWED SET BECAUSE OF SUPER SEEDING\n"; + peer_log("*** SKIPPING ALLOWED SET BECAUSE OF SUPER SEEDING"); #endif return; } @@ -630,8 +646,7 @@ namespace libtorrent if (upload_only()) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " *** SKIPPING ALLOWED SET BECAUSE PEER IS UPLOAD ONLY\n"; + peer_log("*** SKIPPING ALLOWED SET BECAUSE PEER IS UPLOAD ONLY"); #endif return; } @@ -653,8 +668,7 @@ namespace libtorrent if (has_piece(i)) continue; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " ==> ALLOWED_FAST [ " << i << " ]\n"; + peer_log("==> ALLOWED_FAST [ %d ]", i); #endif write_allow_fast(i); TORRENT_ASSERT(std::find(m_accept_fast.begin() @@ -693,8 +707,7 @@ namespace libtorrent == m_accept_fast.end()) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " ==> ALLOWED_FAST [ " << piece << " ]\n"; + peer_log("==> ALLOWED_FAST [ %d ]", piece); #endif write_allow_fast(piece); if (m_accept_fast.empty()) m_accept_fast.reserve(10); @@ -741,8 +754,7 @@ namespace libtorrent if (m_num_pieces == int(m_have_piece.size())) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " *** on_metadata(): THIS IS A SEED ***\n"; + peer_log("*** on_metadata(): THIS IS A SEED ***"); #endif // if this is a web seed. we don't have a peer_info struct t->get_policy().set_seed(m_peer_info, true); @@ -810,7 +822,7 @@ namespace libtorrent if (m_num_pieces == int(m_have_piece.size())) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** THIS IS A SEED ***\n"; + peer_log("*** THIS IS A SEED ***"); #endif // if this is a web seed. we don't have a peer_info struct t->get_policy().set_seed(m_peer_info, true); @@ -860,11 +872,7 @@ namespace libtorrent #endif #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - if (m_logger) - { - (*m_logger) << time_now_string() - << " *** CONNECTION CLOSED\n"; - } + peer_log("*** CONNECTION CLOSED"); #endif TORRENT_ASSERT(!m_ses.has_peer(this)); TORRENT_ASSERT(m_request_queue.empty()); @@ -966,16 +974,14 @@ namespace libtorrent if (!m_ses.settings().send_redundant_have) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " ==> HAVE [ piece: " << index << " ] SUPRESSED\n"; + peer_log("==> HAVE [ piece: %d ] SUPRESSED", index); #endif return; } } #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " ==> HAVE [ piece: " << index << "]\n"; + peer_log(" ==> HAVE [ piece: %d ]", index); #endif write_have(index); #ifdef TORRENT_DEBUG @@ -1125,7 +1131,7 @@ namespace libtorrent if (t && t->is_aborted()) { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << time_now_string() << " *** the torrent has been aborted\n"; + peer_log("*** the torrent has been aborted"); #endif t.reset(); } @@ -1134,14 +1140,12 @@ namespace libtorrent { // we couldn't find the torrent! #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << time_now_string() - << " *** couldn't find a torrent with the given info_hash: " << ih << "\n"; - (*m_logger) << " torrents:\n"; + peer_log("*** couldn't find a torrent with the given info_hash: %s torrents:", to_hex(ih.to_string()).c_str()); session_impl::torrent_map const& torrents = m_ses.m_torrents; for (session_impl::torrent_map::const_iterator i = torrents.begin() , end(torrents.end()); i != end; ++i) { - (*m_logger) << " " << i->second->torrent_file().info_hash() << "\n"; + peer_log(" %s", to_hex(i->second->torrent_file().info_hash().to_string()).c_str()); } #endif disconnect(errors::invalid_info_hash, 2); @@ -1158,7 +1162,7 @@ namespace libtorrent // torrents that have errors should always reject // incoming peers #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << time_now_string() << " rejected connection to paused torrent\n"; + peer_log("rejected connection to paused torrent"); #endif disconnect(errors::torrent_paused, 2); return; @@ -1171,7 +1175,7 @@ namespace libtorrent // the torrent is an i2p torrent, the peer is a regular peer // and we don't allow mixed mode. Disconnect the peer. #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << time_now_string() << " rejected regular connection to i2p torrent\n"; + peer_log("rejected regular connection to i2p torrent"); #endif disconnect(errors::peer_banned, 2); return; @@ -1223,7 +1227,7 @@ namespace libtorrent INVARIANT_CHECK; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " <== KEEPALIVE\n"; + peer_log("<== KEEPALIVE"); #endif } @@ -1245,7 +1249,7 @@ namespace libtorrent if (is_disconnecting()) return; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " <== CHOKE\n"; + peer_log("<== CHOKE"); #endif m_peer_choked = true; @@ -1311,8 +1315,8 @@ namespace libtorrent , t->block_size())); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " <== REJECT_PIECE [ piece: " << r.piece << " | s: " << r.start << " | l: " << r.length << " ]\n"; + peer_log("<== REJECT_PIECE [ piece: %d | s: %d | l: %d ]" + , r.piece, r.start, r.length); #endif if (i != m_download_queue.end()) @@ -1344,8 +1348,7 @@ namespace libtorrent #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING else { - (*m_logger) << time_now_string() - << " *** PIECE NOT IN REQUEST QUEUE\n"; + peer_log("*** PIECE NOT IN REQUEST QUEUE"); } #endif if (has_peer_choked()) @@ -1381,8 +1384,7 @@ namespace libtorrent INVARIANT_CHECK; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " <== SUGGEST_PIECE [ piece: " << index << " ]\n"; + peer_log("<== SUGGEST_PIECE [ piece: %d ]", index); #endif boost::shared_ptr t = m_torrent.lock(); if (!t) return; @@ -1399,7 +1401,7 @@ namespace libtorrent if (index < 0) { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << time_now_string() << " <== INVALID_SUGGEST_PIECE [ " << index << " ]\n"; + peer_log("<== INVALID_SUGGEST_PIECE [ %d ]", index); #endif return; } @@ -1409,8 +1411,8 @@ namespace libtorrent if (index >= int(m_have_piece.size())) { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << time_now_string() << " <== INVALID_ALLOWED_FAST [ " << index << " | s: " - << int(m_have_piece.size()) << " ]\n"; + peer_log("<== INVALID_ALLOWED_FAST [ %d | s: %d ]" + , index, int(m_have_piece.size())); #endif return; } @@ -1427,8 +1429,7 @@ namespace libtorrent m_suggested_pieces.push_back(index); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " ** SUGGEST_PIECE [ piece: " << index << " added to set: " << m_suggested_pieces.size() << " ]\n"; + peer_log("** SUGGEST_PIECE [ piece: %d added to set: %d ]", index, int(m_suggested_pieces.size())); #endif } @@ -1452,7 +1453,7 @@ namespace libtorrent #endif #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " <== UNCHOKE\n"; + peer_log("<== UNCHOKE"); #endif m_peer_choked = false; m_last_unchoked = time_now(); @@ -1485,7 +1486,7 @@ namespace libtorrent #endif #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " <== INTERESTED\n"; + peer_log("<== INTERESTED"); #endif m_peer_interested = true; if (is_disconnecting()) return; @@ -1521,18 +1522,15 @@ namespace libtorrent std::string reason; if (m_ses.num_uploads() >= m_ses.settings().unchoke_slots_limit) { - (*m_logger) << time_now_string() << " DID NOT UNCHOKE [ " - "the number of uploads (" << m_ses.num_uploads() << - ") is more than or equal to the limit (" - << m_ses.settings().unchoke_slots_limit << ") ]\n"; + peer_log("DID NOT UNCHOKE [ the number of uploads (%d)" + "is more than or equal to the limit (%d) ]" + , m_ses.num_uploads(), m_ses.settings().unchoke_slots_limit); } else { - (*m_logger) << time_now_string() << " DID NOT UNCHOKE [ " - "the share ratio (" << share_diff() << - ") is <= free_upload_amount (" << int(free_upload_amount) - << ") and we are not seeding and the ratio (" - << t->ratio() << ")is non-zero"; + peer_log("DID NOT UNCHOKE [ the share ratio (%d) is <= " + "free_upload_amount (%d) and we are not seeding and the ratio (%d) is non-zero" + , share_diff(), int(free_upload_amount), t->ratio()); } } #endif @@ -1558,7 +1556,7 @@ namespace libtorrent m_became_uninterested = time_now(); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " <== NOT_INTERESTED\n"; + peer_log("<== NOT_INTERESTED"); #endif m_peer_interested = false; if (is_disconnecting()) return; @@ -1632,8 +1630,7 @@ namespace libtorrent if (!m_bitfield_received) incoming_have_none(); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " <== HAVE [ piece: " << index << "]\n"; + peer_log("<== HAVE [ piece: %d ]", index); #endif if (is_disconnecting()) return; @@ -1680,7 +1677,7 @@ namespace libtorrent if (m_have_piece[index]) { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << " got redundant HAVE message for index: " << index << "\n"; + peer_log(" got redundant HAVE message for index: %d", index); #endif return; } @@ -1765,14 +1762,11 @@ namespace libtorrent if (is_disconnecting()) return; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " <== BITFIELD "; - + std::string bitfield_str; + bitfield_str.resize(bits.size()); for (int i = 0; i < int(bits.size()); ++i) - { - if (bits[i]) (*m_logger) << "1"; - else (*m_logger) << "0"; - } - (*m_logger) << "\n"; + bitfield_str[i] = bits[i] ? '1' : '0'; + peer_log("<== BITFIELD [ %s ]", bitfield_str.c_str()); #endif // if we don't have the metedata, we cannot @@ -1804,7 +1798,7 @@ namespace libtorrent if (num_pieces == int(m_have_piece.size())) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** THIS IS A SEED ***\n"; + peer_log("*** THIS IS A SEED ***"); #endif // if this is a web seed. we don't have a peer_info struct t->get_policy().set_seed(m_peer_info, true); @@ -1896,16 +1890,14 @@ namespace libtorrent { ++m_num_invalid_requests; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " <== INVALID_SUPER_SEED_REQUEST [ " - "piece: " << r.piece << " | " - "s: " << r.start << " | " - "l: " << r.length << " | " - "i: " << m_peer_interested << " | " - "t: " << (int)t->torrent_file().piece_size(r.piece) << " | " - "n: " << t->torrent_file().num_pieces() << " | " - "h: " << t->have_piece(r.piece) << " | " - "ss: " << m_superseed_piece << " ]\n"; + peer_log("<== INVALID_SUPER_SEED_REQUEST [ " + "piece: %d | s: %d | l: %d | i: %d | " + "t: %d | n: %d | h: %d | ss: %d ]" + , r.piece, r.start, r.length, m_peer_interested + , int(t->torrent_file().piece_size(r.piece)) + , t->torrent_file().num_pieces() + , t->have_piece(r.piece) + , m_superseed_piece); #endif if (t->alerts().should_post()) @@ -1994,8 +1986,8 @@ namespace libtorrent && r.length <= t->block_size()) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " <== REQUEST [ piece: " << r.piece << " | s: " << r.start << " | l: " << r.length << " ]\n"; + peer_log("<== REQUEST [ piece: %d | s: %d | l: %d ]" + , r.piece, r.start, r.length); #endif // if we have choked the client // ignore the request @@ -2005,13 +1997,9 @@ namespace libtorrent write_reject_request(r); ++m_choke_rejects; #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << time_now_string() - << " *** REJECTING REQUEST [ peer choked and piece not in allowed fast set ]\n"; - (*m_logger) << time_now_string() - << " ==> REJECT_PIECE [ " - "piece: " << r.piece << " | " - "s: " << r.start << " | " - "l: " << r.length << " ]\n"; + peer_log("*** REJECTING REQUEST [ peer choked and piece not in allowed fast set ]"); + peer_log(" ==> REJECT_PIECE [ piece: %d | s: %d | l: %d ]" + , r.piece, r.start, r.length); #endif if (m_choke_rejects > m_ses.settings().max_rejects) @@ -2142,8 +2130,7 @@ namespace libtorrent , m_peer_id, b.block_index, b.piece_index)); } #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << " *** The block we just got was not in the " - "request queue ***\n"; + peer_log("*** The block we just got was not in the request queue ***"); #endif TORRENT_ASSERT(m_download_queue.front().block == b); m_download_queue.front().not_wanted = true; @@ -2252,13 +2239,9 @@ namespace libtorrent #endif #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " <== PIECE [ piece: " << p.piece << " | " - "s: " << p.start << " | " - "l: " << p.length << " | " - "ds: " << statistics().download_rate() << " | " - "qs: " << int(m_desired_queue_size) << " | " - "q: " << int(m_download_queue.size()) << " ]\n"; + peer_log("<== PIECE [ piece: %d | s: %d | l: %d | ds: %d | qs: %d | q: %d ]" + , p.piece, p.start, p.length, statistics().download_rate() + , int(m_desired_queue_size), int(m_download_queue.size())); #endif if (p.length == 0) @@ -2309,8 +2292,7 @@ namespace libtorrent , m_peer_id, block_finished.block_index, block_finished.piece_index)); } #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << " *** The block we just got was not in the " - "request queue ***\n"; + peer_log("*** The block we just got was not in the request queue ***"); #endif #ifdef TORRENT_DEBUG TORRENT_ASSERT(m_received_in_piece == p.length); @@ -2534,8 +2516,7 @@ namespace libtorrent if (is_disconnecting()) return; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " <== CANCEL [ piece: " << r.piece << " | s: " << r.start << " | l: " << r.length << " ]\n"; + peer_log("<== CANCEL [ piece: %d | s: %d | l: %d ]", r.piece, r.start, r.length); #endif std::vector::iterator i @@ -2556,7 +2537,7 @@ namespace libtorrent else { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << time_now_string() << " *** GOT CANCEL NOT IN THE QUEUE\n"; + peer_log("*** GOT CANCEL NOT IN THE QUEUE"); #endif } } @@ -2570,8 +2551,7 @@ namespace libtorrent INVARIANT_CHECK; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " <== DHT_PORT [ p: " << listen_port << " ]\n"; + peer_log("<== DHT_PORT [ p: %d ]", listen_port); #endif #ifndef TORRENT_DISABLE_DHT m_ses.add_dht_node(udp::endpoint( @@ -2595,7 +2575,7 @@ namespace libtorrent TORRENT_ASSERT(m_in_constructor == false); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " <== HAVE_ALL\n"; + peer_log("<== HAVE_ALL"); #endif #ifndef TORRENT_DISABLE_EXTENSIONS @@ -2614,7 +2594,7 @@ namespace libtorrent m_bitfield_received = true; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " *** THIS IS A SEED ***\n"; + peer_log("*** THIS IS A SEED ***"); #endif // if we don't have metadata yet @@ -2656,7 +2636,7 @@ namespace libtorrent INVARIANT_CHECK; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " <== HAVE_NONE\n"; + peer_log("<== HAVE_NONE"); #endif boost::shared_ptr t = m_torrent.lock(); @@ -2692,7 +2672,7 @@ namespace libtorrent TORRENT_ASSERT(t); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " <== ALLOWED_FAST [ " << index << " ]\n"; + peer_log("<== ALLOWED_FAST [ %d ]", index); #endif #ifndef TORRENT_DISABLE_EXTENSIONS @@ -2706,7 +2686,7 @@ namespace libtorrent if (index < 0) { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << time_now_string() << " <== INVALID_ALLOWED_FAST [ " << " ]\n"; + peer_log("<== INVALID_ALLOWED_FAST [ %d ]", index); #endif return; } @@ -2716,8 +2696,8 @@ namespace libtorrent if (index >= int(m_have_piece.size())) { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << time_now_string() << " <== INVALID_ALLOWED_FAST [ " << index << " | s: " - << int(m_have_piece.size()) << " ]\n"; + peer_log("<== INVALID_ALLOWED_FAST [ %d | s: %d ]" + , index, int(m_have_piece.size())); #endif return; } @@ -2870,7 +2850,7 @@ namespace libtorrent TORRENT_ASSERT(t->valid_metadata()); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** CANCEL ALL REQUESTS\n"; + peer_log("*** CANCEL ALL REQUESTS"); #endif while (!m_request_queue.empty()) @@ -2985,7 +2965,7 @@ namespace libtorrent m_choked = true; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " ==> CHOKE\n"; + peer_log("==> CHOKE"); #endif #ifdef TORRENT_DEBUG m_last_choke = time_now(); @@ -3043,7 +3023,7 @@ namespace libtorrent m_choked = false; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " ==> UNCHOKE\n"; + peer_log("==> UNCHOKE"); #endif return true; } @@ -3057,7 +3037,7 @@ namespace libtorrent write_interested(); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " ==> INTERESTED\n"; + peer_log("==> INTERESTED"); #endif } @@ -3081,7 +3061,7 @@ namespace libtorrent m_became_uninteresting = time_now(); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " ==> NOT_INTERESTED\n"; + peer_log("==> NOT_INTERESTED"); #endif disconnect_if_redundant(); } @@ -3098,7 +3078,7 @@ namespace libtorrent return; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " ==> SUGGEST [ " << piece << " ]\n"; + peer_log("==> SUGGEST [ %d ]", piece); #endif write_suggest(piece); } @@ -3115,7 +3095,7 @@ namespace libtorrent if (t->graceful_pause() && m_outstanding_bytes == 0) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** GRACEFUL PAUSE [ NO MORE DOWNLOAD ]\n"; + peer_log("*** GRACEFUL PAUSE [ NO MORE DOWNLOAD ]"); #endif disconnect(errors::torrent_paused); return; @@ -3235,15 +3215,11 @@ namespace libtorrent } #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " ==> REQUEST [ " - "piece: " << r.piece << " | " - "s: " << r.start << " | " - "l: " << r.length << " | " - "ds: " << statistics().download_rate() << " B/s | " - "dqs: " << int(m_desired_queue_size) << " " - "rqs: " << int(m_download_queue.size()) << " " - "blk: " << (m_request_large_blocks?"large":"single") << " ]\n"; + peer_log("==> REQUEST [ piece: %d | s: %d | l: %d | ds: %d B/s | " + "dqs: %d rqs: %d blk: %s ]" + , r.piece, r.start, r.length, statistics().download_rate() + , int(m_desired_queue_size), int(m_download_queue.size()) + , m_request_large_blocks?"large":"single"); #endif } m_last_piece = time_now(); @@ -3262,11 +3238,7 @@ namespace libtorrent TORRENT_ASSERT(m_connecting); #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_ses.m_logger) << time_now_string() << " CONNECTION TIMED OUT: " << print_endpoint(m_remote) - << "\n"; -#endif -#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << time_now_string() << " CONNECTION TIMED OUT: " << print_endpoint(m_remote) << "\n"; + peer_log("CONNECTION TIMED OUT: %s", print_endpoint(m_remote).c_str()); #endif disconnect(errors::timed_out, 1); } @@ -3284,13 +3256,13 @@ namespace libtorrent switch (error) { case 0: - (*m_logger) << "*** CONNECTION CLOSED " << ec.message() << "\n"; + peer_log("*** CONNECTION CLOSED %s", ec.message().c_str()); break; case 1: - (*m_logger) << "*** CONNECTION FAILED " << ec.message() << "\n"; + peer_log("*** CONNECTION FAILED %s", ec.message().c_str()); break; case 2: - (*m_logger) << "*** PEER ERROR " << ec.message() << "\n"; + peer_log("*** PEER ERROR %s", ec.message().c_str()); break; } #endif @@ -3678,8 +3650,7 @@ namespace libtorrent m_superseed_piece = -1; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " *** ending super seed mode\n"; + peer_log("*** ending super seed mode"); #endif boost::shared_ptr t = m_torrent.lock(); assert(t); @@ -3688,7 +3659,7 @@ namespace libtorrent { if (m_have_piece[i] || !t->have_piece(i)) continue; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " ==> HAVE [ piece: " << i << "] (ending super seed)\n"; + peer_log("==> HAVE [ piece: %d] (ending super seed)", i); #endif write_have(i); } @@ -3699,8 +3670,7 @@ namespace libtorrent assert(!has_piece(index)); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() - << " ==> HAVE [ piece: " << index << "] (super seed)\n"; + peer_log("==> HAVE [ piece: %d ] (super seed)", index); #endif write_have(index); m_superseed_piece = index; @@ -3795,8 +3765,7 @@ namespace libtorrent if (d > seconds(m_timeout) && !m_connecting) { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << time_now_string() << " *** LAST ACTIVITY [ " - << total_seconds(d) << " seconds ago ] ***\n"; + peer_log("*** LAST ACTIVITY [ %d seconds ago ] ***", int(total_seconds(d))); #endif disconnect(errors::timed_out_inactivity); return; @@ -3808,8 +3777,7 @@ namespace libtorrent && d > seconds(m_ses.settings().handshake_timeout)) { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << time_now_string() << " *** NO HANDSHAKE [ waited " - << total_seconds(d) << " seconds ] ***\n"; + peer_log("*** NO HANDSHAKE [ waited %d seconds ] ***", int(total_seconds(d))); #endif disconnect(errors::timed_out_no_handshake); return; @@ -3828,8 +3796,7 @@ namespace libtorrent && d > seconds(20)) { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << time_now_string() << " *** NO REQUEST [ t: " - << total_seconds(d) << " ] ***\n"; + peer_log("*** NO REQUEST [ t: %d ] ***", int(total_seconds(d))); #endif disconnect(errors::timed_out_no_request); return; @@ -4252,7 +4219,8 @@ namespace libtorrent void peer_connection::assign_bandwidth(int channel, int amount) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << "bandwidth [ " << channel << " ] + " << amount << "\n"; + peer_log("%s ASSIGN BANDWIDHT [ bytes: %d ]" + , channel == upload_channel ? "==>" : "<==", amount); #endif TORRENT_ASSERT(amount > 0); @@ -4310,16 +4278,15 @@ namespace libtorrent , priority , bwc1, bwc2, bwc3, bwc4); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** REQUEST_BANDWIDTH [ " - "upload: " << m_send_buffer.size() - << " prio: " << priority - << " channels: " << bwc1 << " " << bwc2 << " " << bwc3 << " " << bwc4 - << " limits: " << (bwc1?bwc1->throttle():0) << " " - << (bwc2?bwc2->throttle():0) << " " - << (bwc3?bwc3->throttle():0) << " " - << (bwc4?bwc4->throttle():0) - << " ignore: " << m_ignore_bandwidth_limits - << " ]\n"; + peer_log("==> REQUEST_BANDWIDTH [ upload: %d prio: %d " + "channels: %p %p %p %p limits: %d %d %d %d ignore: %d ]" + , int(m_send_buffer.size()), priority + , bwc1, bwc2, bwc3, bwc4 + , (bwc1?bwc1->throttle():0) + , (bwc2?bwc2->throttle():0) + , (bwc3?bwc3->throttle():0) + , (bwc4?bwc4->throttle():0) + , m_ignore_bandwidth_limits); #endif } @@ -4332,14 +4299,17 @@ namespace libtorrent shared_ptr t = m_torrent.lock(); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** REQUEST_BANDWIDTH [ " - "download: " << (m_download_queue.size() * 16 * 1024 + 30) - << " limits: " << (bwc1?bwc1->throttle():0) << " " - << (bwc2?bwc2->throttle():0) << " " - << (bwc3?bwc3->throttle():0) << " " - << (bwc4?bwc4->throttle():0) - << " prio: " << m_priority << " ]\n"; + peer_log("<== REQUEST_BANDWIDTH [ download: %d prio: %d " + "channels: %p %p %p %p limits: %d %d %d %d ignore: %d ]" + , int(m_download_queue.size() * 16 * 1024 + 30), m_priority + , bwc1, bwc2, bwc3, bwc4 + , (bwc1?bwc1->throttle():0) + , (bwc2?bwc2->throttle():0) + , (bwc3?bwc3->throttle():0) + , (bwc4?bwc4->throttle():0) + , m_ignore_bandwidth_limits); #endif + TORRENT_ASSERT(m_priority <= 255); int priority = m_priority + (t->priority() << 8); @@ -4424,25 +4394,19 @@ namespace libtorrent #ifdef TORRENT_VERBOSE_LOGGING if (m_send_buffer.empty()) { - (*m_logger) << time_now_string() << " *** SEND BUFFER DEPLETED [" - " quota: " << m_quota[upload_channel] << - " ignore: " << (m_ignore_bandwidth_limits?"yes":"no") << - " buf: " << m_send_buffer.size() << - " connecting: " << (m_connecting?"yes":"no") << - " disconnecting: " << (m_disconnecting?"yes":"no") << - " pending_disk: " << m_reading_bytes << - " ]\n"; + peer_log("==> SEND BUFFER DEPLETED [" + " quota: %d ignore: %s buf: %d connecting: %s disconnecting: %s pending_disk: %d ]" + , m_quota[upload_channel], m_ignore_bandwidth_limits?"yes":"no" + , int(m_send_buffer.size()), m_connecting?"yes":"no" + , m_disconnecting?"yes":"no", m_reading_bytes); } else { - (*m_logger) << time_now_string() << " *** CANNOT WRITE [" - " quota: " << m_quota[upload_channel] << - " ignore: " << (m_ignore_bandwidth_limits?"yes":"no") << - " buf: " << m_send_buffer.size() << - " connecting: " << (m_connecting?"yes":"no") << - " disconnecting: " << (m_disconnecting?"yes":"no") << - " pending_disk: " << m_reading_bytes << - " ]\n"; + peer_log("==> CANNOT WRITE [" + " quota: %d ignore: %s buf: %d connecting: %s disconnecting: %s pending_disk: %d ]" + , m_quota[upload_channel], m_ignore_bandwidth_limits?"yes":"no" + , int(m_send_buffer.size()), m_connecting?"yes":"no" + , m_disconnecting?"yes":"no", m_reading_bytes); } #endif return; @@ -4456,7 +4420,7 @@ namespace libtorrent TORRENT_ASSERT(amount_to_send > 0); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** ASYNC_WRITE [ bytes: " << amount_to_send << " ]\n"; + peer_log("==> ASYNC_WRITE [ bytes: %d ]", amount_to_send); #endif std::list const& vec = m_send_buffer.build_iovec(amount_to_send); m_socket->async_write_some( @@ -4537,7 +4501,7 @@ namespace libtorrent #ifdef TORRENT_VERBOSE_LOGGING if (m_read_recurse >= 10) { - (*m_logger) << time_now_string() << " *** reached recursion limit\n"; + peer_log("*** reached recursion limit"); } #endif try_read(read_async, ec); @@ -4612,7 +4576,7 @@ namespace libtorrent { m_channel_state[download_channel] = peer_info::bw_network; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** ASYNC_READ [ max: " << max_receive << " bytes ]\n"; + peer_log("<== ASYNC_READ [ max: %d bytes ]", max_receive); #endif if (num_bufs == 1) @@ -4641,7 +4605,7 @@ namespace libtorrent } #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** SYNC_READ [ max: " << max_receive << " ret: " << ret << " e: " << ec.message() << " ]\n"; + peer_log("<== SYNC_READ [ max: %d ret: %d e: %s ]", max_receive, ret, ec ? ec.message().c_str() : ""); #endif return ret; } @@ -4828,7 +4792,7 @@ namespace libtorrent do { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " <<< read " << bytes_transferred << " bytes\n"; + peer_log("<<< read %d bytes", int(bytes_transferred)); #endif // correct the dl quota usage, if not all of the buffer was actually read TORRENT_ASSERT(int(bytes_transferred) <= m_quota[download_channel]); @@ -5141,13 +5105,13 @@ namespace libtorrent m_statistics.trancieve_ip_packet(bytes_transferred, m_remote.address().is_v6()); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " >>> wrote " << bytes_transferred << " bytes\n"; + peer_log(">>> wrote %d bytes", int(bytes_transferred)); #endif if (error) { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << "**ERROR**: " << error.message() << " [in peer_connection::on_send_data]\n"; + peer_log("**ERROR**: %s [in peer_connection::on_send_data]", error.message().c_str()); #endif disconnect(error); return; diff --git a/src/policy.cpp b/src/policy.cpp index e0845afde..cd5ae71eb 100644 --- a/src/policy.cpp +++ b/src/policy.cpp @@ -145,7 +145,7 @@ namespace libtorrent - (int)c.request_queue().size(); #ifdef TORRENT_VERBOSE_LOGGING - (*c.m_logger) << time_now_string() << " PIECE_PICKER [ req: " << num_requests << " ]\n"; + c.peer_log("*** PIECE_PICKER [ req: %d ]", num_requests); #endif TORRENT_ASSERT(c.desired_queue_size() > 0); // if our request queue is already full, we @@ -224,8 +224,8 @@ namespace libtorrent } #ifdef TORRENT_VERBOSE_LOGGING - (*c.m_logger) << time_now_string() << " PIECE_PICKER [ php: " << prefer_whole_pieces - << " picked: " << interesting_pieces.size() << " ]\n"; + c.peer_log("*** PIECE_PICKER [ prefer_whole: %d picked: %d ]" + , prefer_whole_pieces, int(interesting_pieces.size())); #endif std::vector const& dq = c.download_queue(); std::vector const& rq = c.request_queue(); diff --git a/src/web_peer_connection.cpp b/src/web_peer_connection.cpp index 0e8ea0799..9e2ee31a5 100644 --- a/src/web_peer_connection.cpp +++ b/src/web_peer_connection.cpp @@ -91,7 +91,7 @@ namespace libtorrent request_large_blocks(true); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** web_peer_connection " << url << "\n"; + peer_log("*** web_peer_connection %s", url.c_str()); #endif } @@ -239,7 +239,7 @@ namespace libtorrent } #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " " << request << "\n"; + peer_log("==> %s", request.c_str()); #endif send_buffer(request.c_str(), request.size(), message_type_request); @@ -274,8 +274,7 @@ namespace libtorrent { m_statistics.received_bytes(0, bytes_transferred); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** web_peer_connection error: " - << error.message() << "\n"; + peer_log("*** web_peer_connection error: %s", error.message().c_str()); #endif #ifdef TORRENT_DEBUG TORRENT_ASSERT(m_statistics.last_payload_downloaded() @@ -313,7 +312,7 @@ namespace libtorrent { m_statistics.received_bytes(0, bytes_transferred); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << "*** " << std::string(recv_buffer.begin, recv_buffer.end) << "\n"; + peer_log("*** %s", std::string(recv_buffer.begin, recv_buffer.end).c_str()); #endif disconnect(errors::http_parse_error, 2); #ifdef TORRENT_DEBUG @@ -361,12 +360,11 @@ namespace libtorrent if (!header_finished) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** STATUS: " << m_parser.status_code() - << " " << m_parser.message() << "\n"; + peer_log("*** STATUS: %d %s", m_parser.status_code(), m_parser.message().c_str()); std::map const& headers = m_parser.headers(); for (std::map::const_iterator i = headers.begin() , end(headers.end()); i != end; ++i) - (*m_logger) << " " << i->first << ": " << i->second << "\n"; + peer_log(" %s: %s", i->first.c_str(), i->second.c_str()); #endif // if the status code is not one of the accepted ones, abort if (!is_ok_status(m_parser.status_code())) @@ -558,8 +556,7 @@ namespace libtorrent else { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** parsed chunk: " << chunk_size - << " header_size: " << header_size << "\n"; + peer_log("*** parsed chunk: %d header_size: %d", chunk_size, header_size); #endif TORRENT_ASSERT(bytes_transferred >= header_size - m_partial_chunk_header); bytes_transferred -= header_size - m_partial_chunk_header; @@ -593,9 +590,9 @@ namespace libtorrent TORRENT_ASSERT(m_block_pos >= 0); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << time_now_string() << " *** payload_transferred: " << payload_transferred - << " [" << front_request.piece << ":" << front_request.start - << " = " << front_request.length << "]\n"; + peer_log("*** payload_transferred: %d [ %d:%d = %d ]" + , payload_transferred, front_request.piece + , front_request.start, front_request.length); #endif m_statistics.received_bytes(payload_transferred, 0); TORRENT_ASSERT(bytes_transferred >= payload_transferred); diff --git a/test/test_web_seed.cpp b/test/test_web_seed.cpp index fd853b39b..47e06bcb0 100644 --- a/test/test_web_seed.cpp +++ b/test/test_web_seed.cpp @@ -216,7 +216,7 @@ int run_suite(char const* protocol, bool test_url_seed, bool chunked_encoding) else { piece_size = 64 * 1024; - char random_data[64 * 1024 * 50]; + char random_data[64 * 1024 * 25]; std::generate(random_data, random_data + sizeof(random_data), &std::rand); save_file("./tmp1_web_seed/seed", random_data, sizeof(random_data)); fs.add_file("seed", sizeof(random_data));