From 2a55fe8c70488b73abd103173e0078f77ea68f30 Mon Sep 17 00:00:00 2001 From: Arvid Norberg Date: Wed, 14 Apr 2010 18:52:13 +0000 Subject: [PATCH] debug logging fixes --- include/libtorrent/debug.hpp | 20 +++++++++------- src/bt_peer_connection.cpp | 46 ++++++++++++++++++------------------ src/peer_connection.cpp | 25 ++++++++++---------- src/session_impl.cpp | 34 ++++++++++++++++---------- 4 files changed, 70 insertions(+), 55 deletions(-) diff --git a/include/libtorrent/debug.hpp b/include/libtorrent/debug.hpp index 567802a7b..d240f2095 100644 --- a/include/libtorrent/debug.hpp +++ b/include/libtorrent/debug.hpp @@ -33,6 +33,8 @@ POSSIBILITY OF SUCH DAMAGE. #ifndef TORRENT_DEBUG_HPP_INCLUDED #define TORRENT_DEBUG_HPP_INCLUDED +#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING + #include #include "libtorrent/config.hpp" #include "libtorrent/file.hpp" @@ -47,16 +49,17 @@ namespace libtorrent { // DEBUG API -#if TORRENT_USE_IOSTREAM - // all log streams share a single file descriptor - // and re-opens the file for each log line - static std::ofstream log_file; - static std::string open_filename; - static mutex file_mutex; -#endif - struct logger { +#if TORRENT_USE_IOSTREAM + // all log streams share a single file descriptor + // and re-opens the file for each log line + // these members are defined in session_impl.cpp + static std::ofstream log_file; + static std::string open_filename; + static mutex file_mutex; +#endif + logger(std::string const& logpath, std::string const& filename , int instance, bool append) { @@ -102,5 +105,6 @@ namespace libtorrent } +#endif // TORRENT_VERBOSE_LOGGING || TORRENT_LOGGING || TORRENT_ERROR_LOGGING #endif // TORRENT_DEBUG_HPP_INCLUDED diff --git a/src/bt_peer_connection.cpp b/src/bt_peer_connection.cpp index 2d128874a..fb3d21dee 100644 --- a/src/bt_peer_connection.cpp +++ b/src/bt_peer_connection.cpp @@ -116,7 +116,7 @@ namespace libtorrent #endif { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << "*** bt_peer_connection\n"; + (*m_logger) << time_now_string() << "*** bt_peer_connection\n"; #endif #ifdef TORRENT_DEBUG @@ -1499,13 +1499,13 @@ namespace libtorrent if (root.type() != lazy_entry::dict_t) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << "invalid extended handshake\n"; + (*m_logger) << time_now_string() << " invalid extended handshake\n"; #endif return; } #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << "<== EXTENDED HANDSHAKE: \n" << root; + (*m_logger) << time_now_string() << " <== EXTENDED HANDSHAKE: \n" << root; #endif #ifndef TORRENT_DISABLE_EXTENSIONS @@ -1937,7 +1937,7 @@ namespace libtorrent #if defined TORRENT_VERBOSE_LOGGING && TORRENT_USE_IOSTREAM std::stringstream ext; handshake.print(ext); - (*m_logger) << "==> EXTENDED HANDSHAKE: \n" << ext.str(); + (*m_logger) << time_now_string() << " ==> EXTENDED HANDSHAKE: \n" << ext.str(); #endif setup_send(); @@ -2144,7 +2144,7 @@ namespace libtorrent } #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " received DH key\n"; + (*m_logger) << time_now_string() << " received DH key\n"; #endif // PadA/B can be a max of 512 bytes, and 20 bytes more for @@ -2245,7 +2245,7 @@ namespace libtorrent { std::size_t bytes_processed = syncoffset + 20; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " sync point (hash) found at offset " + (*m_logger) << time_now_string << " sync point (hash) found at offset " << m_sync_bytes_read + bytes_processed - 20 << "\n"; #endif m_state = read_pe_skey_vc; @@ -2296,7 +2296,7 @@ namespace libtorrent init_pe_RC4_handler(m_dh_key_exchange->get_secret(), ti.info_hash()); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " stream key found, torrent located.\n"; + (*m_logger) << time_now_string() << " stream key found, torrent located.\n"; #endif break; } @@ -2321,7 +2321,7 @@ namespace libtorrent } #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " verification constant found\n"; + (*m_logger) << time_now_string() << " verification constant found\n"; #endif m_state = read_pe_cryptofield; reset_recv_buffer(4 + 2); @@ -2385,7 +2385,7 @@ namespace libtorrent { std::size_t bytes_processed = syncoffset + 8; #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " sync point (verification constant) found at offset " + (*m_logger) << time_now_string() << " sync point (verification constant) found at offset " << m_sync_bytes_read + bytes_processed - 8 << "\n"; #endif int transferred_used = bytes_processed - recv_buffer.left() + bytes_transferred; @@ -2421,9 +2421,9 @@ namespace libtorrent #ifdef TORRENT_VERBOSE_LOGGING if (!is_local()) - (*m_logger) << " crypto provide : [ "; + (*m_logger) << time_now_string() << " crypto provide : [ "; else - (*m_logger) << " crypto select : [ "; + (*m_logger) << time_now_string() << " crypto select : [ "; if (crypto_field & 0x01) (*m_logger) << "plaintext "; @@ -2558,7 +2558,7 @@ namespace libtorrent } #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " len(IA) : " << len_ia << "\n"; + (*m_logger) << time_now_string() << " len(IA) : " << len_ia << "\n"; #endif if (len_ia == 0) { @@ -2594,14 +2594,14 @@ namespace libtorrent m_RC4_handler->decrypt(wr_buf.begin, packet_size()); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " decrypted ia : " << packet_size() << " bytes\n"; + (*m_logger) << time_now_string() << " decrypted ia : " << packet_size() << " bytes\n"; #endif if (!m_rc4_encrypted) { m_RC4_handler.reset(); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " destroyed rc4 keys\n"; + (*m_logger) << time_now_string() << " destroyed rc4 keys\n"; #endif } @@ -2625,14 +2625,14 @@ namespace libtorrent wr_buf.begin += packet_size(); m_RC4_handler->decrypt(wr_buf.begin, wr_buf.left()); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " decrypted remaining " << wr_buf.left() << " bytes\n"; + (*m_logger) << time_now_string() << " decrypted remaining " << wr_buf.left() << " bytes\n"; #endif } else // !m_rc4_encrypted { m_RC4_handler.reset(); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " destroyed rc4 keys\n"; + (*m_logger) << time_now_string() << " destroyed rc4 keys\n"; #endif } @@ -2681,7 +2681,7 @@ namespace libtorrent if (!m_encrypted && !is_local()) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " attempting encrypted connection\n"; + (*m_logger) << time_now_string() << " attempting encrypted connection\n"; #endif m_state = read_pe_dhkey; cut_receive_buffer(0, dh_key_len); @@ -2708,7 +2708,7 @@ namespace libtorrent #endif #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " BitTorrent protocol\n"; + (*m_logger) << time_now_string() << " BitTorrent protocol\n"; #endif m_state = read_info_hash; @@ -2737,11 +2737,11 @@ namespace libtorrent } (*m_logger) << "\n"; if (recv_buffer[7] & 0x01) - (*m_logger) << "supports DHT port message\n"; + (*m_logger) << " supports DHT port message\n"; if (recv_buffer[7] & 0x04) - (*m_logger) << "supports FAST extensions\n"; + (*m_logger) << " supports FAST extensions\n"; if (recv_buffer[5] & 0x10) - (*m_logger) << "supports extensions protocol\n"; + (*m_logger) << " supports extensions protocol\n"; #endif #ifndef DISABLE_EXTENSIONS @@ -2775,14 +2775,14 @@ namespace libtorrent , (const char*)t->torrent_file().info_hash().begin())) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " received invalid info_hash\n"; + (*m_logger) << time_now_string() << " received invalid info_hash\n"; #endif disconnect(errors::invalid_info_hash, 2); return; } #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " info_hash received\n"; + (*m_logger) << time_now_string() << " info_hash received\n"; #endif } diff --git a/src/peer_connection.cpp b/src/peer_connection.cpp index 1951e2bc4..52592df15 100644 --- a/src/peer_connection.cpp +++ b/src/peer_connection.cpp @@ -191,7 +191,7 @@ namespace libtorrent error_code ec; m_logger = m_ses.create_log(m_remote.address().to_string(ec) + "_" + to_string(m_remote.port()).elems, m_ses.listen_port()); - (*m_logger) << "*** OUTGOING CONNECTION\n"; + (*m_logger) << time_now_string() << " *** OUTGOING CONNECTION\n"; #endif #ifdef TORRENT_DEBUG piece_failed = false; @@ -327,7 +327,7 @@ namespace libtorrent TORRENT_ASSERT(m_socket->remote_endpoint(ec) == m_remote || ec); m_logger = m_ses.create_log(remote().address().to_string(ec) + "_" + to_string(remote().port()).elems, m_ses.listen_port()); - (*m_logger) << "*** INCOMING CONNECTION\n"; + (*m_logger) << time_now_string() << " *** INCOMING CONNECTION\n"; #endif #ifndef TORRENT_DISABLE_GEO_IP @@ -744,7 +744,7 @@ namespace libtorrent if (m_num_pieces == int(m_have_piece.size())) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " *** THIS IS A SEED ***\n"; + (*m_logger) << time_now_string() << " *** THIS IS A SEED ***\n"; #endif // if this is a web seed. we don't have a peer_info struct t->get_policy().set_seed(m_peer_info, true); @@ -1057,7 +1057,7 @@ namespace libtorrent if (t && t->is_aborted()) { #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << " *** the torrent has been aborted\n"; + (*m_logger) << time_now_string() << " *** the torrent has been aborted\n"; #endif t.reset(); } @@ -1066,7 +1066,8 @@ namespace libtorrent { // we couldn't find the torrent! #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << " *** couldn't find a torrent with the given info_hash: " << ih << "\n"; + (*m_logger) << time_now_string() + << " *** couldn't find a torrent with the given info_hash: " << ih << "\n"; (*m_logger) << " torrents:\n"; session_impl::torrent_map const& torrents = m_ses.m_torrents; for (session_impl::torrent_map::const_iterator i = torrents.begin() @@ -1089,7 +1090,7 @@ namespace libtorrent // torrents that have errors should always reject // incoming peers #if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_ERROR_LOGGING - (*m_logger) << " rejected connection to paused torrent\n"; + (*m_logger) << time_now_string() << " rejected connection to paused torrent\n"; #endif disconnect(errors::torrent_paused, 2); return; @@ -1102,7 +1103,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) << " rejected regular connection to i2p torrent\n"; + (*m_logger) << time_now_string() << " rejected regular connection to i2p torrent\n"; #endif disconnect(errors::peer_banned, 2); return; @@ -1726,7 +1727,7 @@ namespace libtorrent if (num_pieces == int(m_have_piece.size())) { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << " *** THIS IS A SEED ***\n"; + (*m_logger) << time_now_string() << " *** THIS IS A SEED ***\n"; #endif // if this is a web seed. we don't have a peer_info struct t->get_policy().set_seed(m_peer_info, true); @@ -2059,7 +2060,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 " + (*m_logger) << " *** The block we just got was not in the " "request queue ***\n"; #endif } @@ -2226,7 +2227,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 " + (*m_logger) << " *** The block we just got was not in the " "request queue ***\n"; #endif #ifdef TORRENT_DEBUG @@ -4571,7 +4572,7 @@ namespace libtorrent do { #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << "read " << bytes_transferred << " bytes\n"; + (*m_logger) << time_now_string() << " <<< read " << bytes_transferred << " bytes\n"; #endif // correct the dl quota usage, if not all of the buffer was actually read TORRENT_ASSERT(int(bytes_transferred) <= m_quota[download_channel]); @@ -4900,7 +4901,7 @@ namespace libtorrent m_statistics.trancieve_ip_packet(bytes_transferred, m_remote.address().is_v6()); #ifdef TORRENT_VERBOSE_LOGGING - (*m_logger) << "wrote " << bytes_transferred << " bytes\n"; + (*m_logger) << time_now_string() << " >>> wrote " << bytes_transferred << " bytes\n"; #endif if (error) diff --git a/src/session_impl.cpp b/src/session_impl.cpp index cc9230382..e7919b0ab 100644 --- a/src/session_impl.cpp +++ b/src/session_impl.cpp @@ -50,18 +50,6 @@ POSSIBILITY OF SUCH DAMAGE. #pragma warning(pop) #endif -// for logging the size of DHT structures -#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING -#ifndef TORRENT_DISABLE_DHT - -#include -#include -#include -#include - -#endif -#endif - #include "libtorrent/peer_id.hpp" #include "libtorrent/torrent_info.hpp" #include "libtorrent/tracker_manager.hpp" @@ -92,6 +80,28 @@ POSSIBILITY OF SUCH DAMAGE. #include #endif +#if defined TORRENT_VERBOSE_LOGGING || defined TORRENT_LOGGING || defined TORRENT_ERROR_LOGGING + +// for logging the size of DHT structures +#ifndef TORRENT_DISABLE_DHT +#include +#include +#include +#include +#endif // TORRENT_DISABLE_DHT + +#include "libtorrent/debug.hpp" + +#if TORRENT_USE_IOSTREAM +namespace libtorrent { +std::ofstream logger::log_file; +std::string logger::open_filename; +mutex logger::file_mutex; +} +#endif // TORRENT_USE_IOSTREAM + +#endif + #ifdef TORRENT_USE_GCRYPT extern "C" {