diff options
23 files changed, 257 insertions, 184 deletions
diff --git a/contrib/epee/include/net/abstract_tcp_server2.inl b/contrib/epee/include/net/abstract_tcp_server2.inl index 3dff6da56..31836fe9e 100644 --- a/contrib/epee/include/net/abstract_tcp_server2.inl +++ b/contrib/epee/include/net/abstract_tcp_server2.inl @@ -198,8 +198,9 @@ PRAGMA_WARNING_DISABLE_VS(4355) bool connection<t_protocol_handler>::add_ref() { TRY_ENTRY(); - //_info("[sock " << socket_.native_handle() << "] add_ref"); + //_dbg3("[sock " << socket_.native_handle() << "] add_ref, m_peer_number=" << mI->m_peer_number); CRITICAL_REGION_LOCAL(m_self_refs_lock); + //_dbg3("[sock " << socket_.native_handle() << "] add_ref 2, m_peer_number=" << mI->m_peer_number); // Use safe_shared_from_this, because of this is public method and it can be called on the object being deleted auto self = safe_shared_from_this(); @@ -364,8 +365,7 @@ PRAGMA_WARNING_DISABLE_VS(4355) { // LOCK: chunking epee::critical_region_t<decltype(m_chunking_lock)> send_guard(m_chunking_lock); // *** critical *** - _mark_c("net/out/size", "do_send() will SPLIT into small chunks, from packet="<<cb<<" B for ptr="<<ptr); - _mark("do_send() will SPLIT into small chunks, from packet="<<cb<<" B for ptr="<<ptr); + _dbg3_c("net/out/size", "do_send() will SPLIT into small chunks, from packet="<<cb<<" B for ptr="<<ptr); t_safe all = cb; // all bytes to send t_safe pos = 0; // current sending position // 01234567890 @@ -393,14 +393,13 @@ PRAGMA_WARNING_DISABLE_VS(4355) ASRT(chunk_start >= ptr); // not wrapped around address? //std::memcpy( (void*)buf, chunk_start, len); - _dbg1_c("net/out/size", "part of " << lenall << ": pos="<<pos << " len="<<len); + _dbg3_c("net/out/size", "part of " << lenall << ": pos="<<pos << " len="<<len); bool ok = do_send_chunk(chunk_start, len); // <====== *** all_ok = all_ok && ok; if (!all_ok) { - _mark_c("net/out/size", "do_send() DONE ***FAILED*** from packet="<<cb<<" B for ptr="<<ptr); - _mark ( "do_send() DONE ***FAILED*** from packet="<<cb<<" B for ptr="<<ptr); + _dbg1_c("net/out/size", "do_send() DONE ***FAILED*** from packet="<<cb<<" B for ptr="<<ptr); _dbg1("do_send() SEND was aborted in middle of big package - this is mostly harmless " << " (e.g. peer closed connection) but if it causes trouble tell us at #monero-dev. " << cb); return false; // partial failure in sending @@ -410,8 +409,8 @@ PRAGMA_WARNING_DISABLE_VS(4355) // (in catch block, or uniq pointer) delete buf; } // each chunk - _mark_c("net/out/size", "do_send() DONE SPLIT from packet="<<cb<<" B for ptr="<<ptr); - _mark ( "do_send() DONE SPLIT from packet="<<cb<<" B for ptr="<<ptr); + _dbg3_c("net/out/size", "do_send() DONE SPLIT from packet="<<cb<<" B for ptr="<<ptr); + _dbg3 ( "do_send() DONE SPLIT from packet="<<cb<<" B for ptr="<<ptr); _info_c("net/sleepRPC", "do_send() m_connection_type = " << m_connection_type); @@ -469,7 +468,7 @@ PRAGMA_WARNING_DISABLE_VS(4355) if (retry > retry_limit) { send_guard.unlock(); _erro("send que size is more than ABSTRACT_SERVER_SEND_QUE_MAX_COUNT(" << ABSTRACT_SERVER_SEND_QUE_MAX_COUNT << "), shutting down connection"); - // _mark_c("net/sleep", "send que size is more than ABSTRACT_SERVER_SEND_QUE_MAX_COUNT(" << ABSTRACT_SERVER_SEND_QUE_MAX_COUNT << "), shutting down connection"); + // _dbg1_c("net/sleep", "send que size is more than ABSTRACT_SERVER_SEND_QUE_MAX_COUNT(" << ABSTRACT_SERVER_SEND_QUE_MAX_COUNT << "), shutting down connection"); close(); return false; } @@ -496,7 +495,7 @@ PRAGMA_WARNING_DISABLE_VS(4355) } auto size_now = m_send_que.front().size(); - _mark_c("net/out/size", "do_send() NOW SENSD: packet="<<size_now<<" B"); + _dbg1_c("net/out/size", "do_send() NOW SENSD: packet="<<size_now<<" B"); do_send_handler_write( ptr , size_now ); // (((H))) ASRT( size_now == m_send_que.front().size() ); @@ -580,7 +579,7 @@ PRAGMA_WARNING_DISABLE_VS(4355) { //have more data to send auto size_now = m_send_que.front().size(); - _mark_c("net/out/size", "handle_write() NOW SENDS: packet="<<size_now<<" B" <<", from queue size="<<m_send_que.size()); + _dbg1_c("net/out/size", "handle_write() NOW SENDS: packet="<<size_now<<" B" <<", from queue size="<<m_send_que.size()); do_send_handler_write_from_queue(e, m_send_que.front().size() , m_send_que.size()); // (((H))) ASRT( size_now == m_send_que.front().size() ); boost::asio::async_write(socket_, boost::asio::buffer(m_send_que.front().data(), size_now) , diff --git a/contrib/epee/include/syncobj.h b/contrib/epee/include/syncobj.h index b7273da8e..b81eb43a9 100644 --- a/contrib/epee/include/syncobj.h +++ b/contrib/epee/include/syncobj.h @@ -35,10 +35,14 @@ #include <boost/thread/locks.hpp> #include <boost/thread/mutex.hpp> #include <boost/thread/recursive_mutex.hpp> +#include <thread> +#include <chrono> namespace epee { + extern unsigned int g_test_dbg_lock_sleep; + struct simple_event { simple_event() : m_rised(false) @@ -215,10 +219,10 @@ namespace epee #define SHARED_CRITICAL_REGION_BEGIN(x) { shared_guard critical_region_var(x) #define EXCLUSIVE_CRITICAL_REGION_BEGIN(x) { exclusive_guard critical_region_var(x) -#define CRITICAL_REGION_LOCAL(x) epee::critical_region_t<decltype(x)> critical_region_var(x) -#define CRITICAL_REGION_BEGIN(x) { epee::critical_region_t<decltype(x)> critical_region_var(x) -#define CRITICAL_REGION_LOCAL1(x) epee::critical_region_t<decltype(x)> critical_region_var1(x) -#define CRITICAL_REGION_BEGIN1(x) { epee::critical_region_t<decltype(x)> critical_region_var1(x) +#define CRITICAL_REGION_LOCAL(x) {std::this_thread::sleep_for(std::chrono::milliseconds(epee::g_test_dbg_lock_sleep));} epee::critical_region_t<decltype(x)> critical_region_var(x) +#define CRITICAL_REGION_BEGIN(x) { std::this_thread::sleep_for(std::chrono::milliseconds(epee::g_test_dbg_lock_sleep)); epee::critical_region_t<decltype(x)> critical_region_var(x) +#define CRITICAL_REGION_LOCAL1(x) {std::this_thread::sleep_for(std::chrono::milliseconds(epee::g_test_dbg_lock_sleep));} epee::critical_region_t<decltype(x)> critical_region_var1(x) +#define CRITICAL_REGION_BEGIN1(x) { std::this_thread::sleep_for(std::chrono::milliseconds(epee::g_test_dbg_lock_sleep)); epee::critical_region_t<decltype(x)> critical_region_var1(x) #define CRITICAL_REGION_END() } diff --git a/contrib/otshell_utils/lib_common1.hpp b/contrib/otshell_utils/lib_common1.hpp index 108b1847c..456e63fbb 100644 --- a/contrib/otshell_utils/lib_common1.hpp +++ b/contrib/otshell_utils/lib_common1.hpp @@ -20,6 +20,7 @@ #include <functional> #include <memory> #include <thread> +#include <atomic> #include <mutex> diff --git a/contrib/otshell_utils/utils.cpp b/contrib/otshell_utils/utils.cpp index 1d26075c4..043260807 100644 --- a/contrib/otshell_utils/utils.cpp +++ b/contrib/otshell_utils/utils.cpp @@ -112,7 +112,22 @@ std::string get_current_time() { cNullstream g_nullstream; // extern a stream that does nothing (eats/discards data) -std::mutex gLoggerGuard; // extern +std::recursive_mutex gLoggerGuard; // extern +std::atomic<int> gLoggerGuardDepth; // extern + +std::atomic<int> & gLoggerGuardDepth_Get() { + // TODO std::once would be nicer here + + static bool once=0; + + if (!once) { // initialize it once + once=1; + gLoggerGuardDepth=0; + } + + return gLoggerGuardDepth; // global, atomic counter +} + // ==================================================================== diff --git a/contrib/otshell_utils/utils.hpp b/contrib/otshell_utils/utils.hpp index bb984320b..83e6b822d 100644 --- a/contrib/otshell_utils/utils.hpp +++ b/contrib/otshell_utils/utils.hpp @@ -65,18 +65,55 @@ extern cNullstream g_nullstream; // a stream that does nothing (eats/discards da // TODO make _dbg_ignore thread-safe everywhere -extern std::mutex gLoggerGuard; - - +extern std::recursive_mutex gLoggerGuard; // the mutex guarding logging/debugging code e.g. protecting streams, files, etc + +std::atomic<int> & gLoggerGuardDepth_Get(); // getter for the global singleton of counter (it guarantees initializing it to 0). This counter shows the current recursion (re-entrant) level of debug macros. + +// TODO more debug of the debug system: +// detect lock() error e.g. recursive limit +// detect stream e.g. operator<< error + +#define _debug_level(LEVEL,VAR) do { if (_dbg_ignore< LEVEL) { \ + auto level=LEVEL; short int part=0; \ + try { \ + std::lock_guard<std::recursive_mutex> mutex_guard( nOT::nUtils::gLoggerGuard ); \ + part=1; \ + try { \ + ++nOT::nUtils::gLoggerGuardDepth_Get(); \ +/* int counter = nOT::nUtils::gLoggerGuardDepth_Get(); if (counter!=1) gCurrentLogger.write_stream(100,"")<<"DEBUG-ERROR: recursion, counter="<<counter<<gCurrentLogger.endline(); */ \ + gCurrentLogger.write_stream(LEVEL,"") << nOT::nUtils::get_current_time() << ' ' << OT_CODE_STAMP << ' ' << VAR << gCurrentLogger.endline() << std::flush; \ + part=9; \ + } catch(...) { \ + gCurrentLogger.write_stream(std::max(level,90),"") << nOT::nUtils::get_current_time() << ' ' << OT_CODE_STAMP << ' ' << "(ERROR IN DEBUG)" << gCurrentLogger.endline(); \ + --nOT::nUtils::gLoggerGuardDepth_Get(); throw ; \ + } \ + --nOT::nUtils::gLoggerGuardDepth_Get(); \ + } catch(...) { if (part<8) gCurrentLogger.write_stream(100,"")<<"DEBUG-ERROR: problem in debug mechanism e.g. in locking." <<gCurrentLogger.endline(); throw ; } \ + } } while(0) +// info for code below: oss object is normal stack variable, using it does not need lock protection #define _debug_level_c(CHANNEL,LEVEL,VAR) do { if (_dbg_ignore< LEVEL) { \ - nOT::nUtils::gLoggerGuard.try_lock(); \ - gCurrentLogger.write_stream(LEVEL,CHANNEL) << nOT::nUtils::get_current_time() << ' ' << OT_CODE_STAMP << ' ' << VAR << gCurrentLogger.endline() << std::flush; \ - nOT::nUtils::gLoggerGuard.unlock(); \ + auto level=LEVEL; short int part=0; \ + try { \ + std::lock_guard<std::recursive_mutex> mutex_guard( nOT::nUtils::gLoggerGuard ); \ + part=1; \ + try { \ + ++nOT::nUtils::gLoggerGuardDepth_Get(); \ + std::ostringstream oss; \ + oss << nOT::nUtils::get_current_time() << ' ' << OT_CODE_STAMP << ' ' << VAR << gCurrentLogger.endline() << std::flush; \ + std::string as_string = oss.str(); \ +/* int counter = nOT::nUtils::gLoggerGuardDepth_Get(); if (counter!=1) gCurrentLogger.write_stream(100,"")<<"DEBUG-ERROR: recursion, counter="<<counter<<gCurrentLogger.endline(); */ \ + gCurrentLogger.write_stream(LEVEL,"" ) << as_string << gCurrentLogger.endline() << std::flush; \ + gCurrentLogger.write_stream(LEVEL,CHANNEL) << as_string << gCurrentLogger.endline() << std::flush; \ + part=9; \ + } catch(...) { \ + gCurrentLogger.write_stream(std::max(level,90),CHANNEL) << nOT::nUtils::get_current_time() << ' ' << OT_CODE_STAMP << ' ' << "(ERROR IN DEBUG)" << gCurrentLogger.endline(); \ + --nOT::nUtils::gLoggerGuardDepth_Get(); throw ; \ + } \ + --nOT::nUtils::gLoggerGuardDepth_Get(); \ + } catch(...) { if (part<8) gCurrentLogger.write_stream(100,CHANNEL)<<"DEBUG-ERROR: problem in debug mechanism e.g. in locking." <<gCurrentLogger.endline(); throw ; } \ } } while(0) -#define _debug_level(LEVEL,VAR) _debug_level_c("",LEVEL,VAR) - #define _dbg3(VAR) _debug_level( 20,VAR) #define _dbg2(VAR) _debug_level( 30,VAR) #define _dbg1(VAR) _debug_level( 40,VAR) // details @@ -98,10 +135,10 @@ extern std::mutex gLoggerGuard; #define _warn_c(C,VAR) _debug_level_c(C, 90,VAR) // some problem #define _erro_c(C,VAR) _debug_level_c(C,100,VAR) // error - report -// lock // because od VAR +// lock // because of VAR #define _scope_debug_level_c(CHANNEL,LEVEL,VAR) \ std::ostringstream debug_detail_oss; \ - nOT::nUtils::gLoggerGuard.try_lock(); \ + nOT::nUtils::gLoggerGuard.lock(); \ debug_detail_oss << OT_CODE_STAMP << ' ' << VAR ; \ nOT::nUtils::nDetail::cDebugScopeGuard debugScopeGuard; \ if (_dbg_ignore<LEVEL) debugScopeGuard.Assign(CHANNEL,LEVEL, debug_detail_oss.str()); \ diff --git a/src/connectivity_tool/conn_tool.cpp b/src/connectivity_tool/conn_tool.cpp index e658d2706..7506dba6f 100644 --- a/src/connectivity_tool/conn_tool.cpp +++ b/src/connectivity_tool/conn_tool.cpp @@ -49,6 +49,8 @@ namespace po = boost::program_options; using namespace cryptonote; using namespace nodetool; +unsigned int epee::g_test_dbg_lock_sleep = 0; + namespace { const command_line::arg_descriptor<std::string, true> arg_ip = {"ip", "set ip"}; diff --git a/src/cryptonote_core/blockchain_storage.cpp b/src/cryptonote_core/blockchain_storage.cpp index fe80d75ac..4e669daa5 100644 --- a/src/cryptonote_core/blockchain_storage.cpp +++ b/src/cryptonote_core/blockchain_storage.cpp @@ -50,6 +50,7 @@ #include "cryptonote_core/checkpoints_create.h" //#include "serialization/json_archive.h" #include "../../contrib/otshell_utils/utils.hpp" +#include "../../src/p2p/data_logger.hpp" using namespace cryptonote; @@ -178,22 +179,6 @@ bool blockchain_storage::store_genesis_block(bool testnet) { return true; } //------------------------------------------------------------------ -void blockchain_storage::logger_handle(long int ms) -{ - std::ofstream log_file; - log_file.open("log/dr-monero/blockchain_log.data", std::ofstream::out | std::ofstream::app); - log_file.precision(7); - - using namespace boost::chrono; - auto point = steady_clock::now(); - auto time_from_epoh = point.time_since_epoch(); - auto m_ms = duration_cast< milliseconds >( time_from_epoh ).count(); - double ms_f = m_ms; - ms_f /= 1000.; - - log_file << ms_f << " " << ms << std::endl; -} -//------------------------------------------------------------------ bool blockchain_storage::store_blockchain() { m_is_blockchain_storing = true; @@ -1776,7 +1761,7 @@ bool blockchain_storage::handle_block_to_main_chain(const block& bl, const crypt << "), coinbase_blob_size: " << coinbase_blob_size << ", cumulative size: " << cumulative_block_size << ", " << block_processing_time << "("<< target_calculating_time << "/" << longhash_calculating_time << ")ms"); - logger_handle(block_processing_time); + epee::net_utils::data_logger::get_instance().add_data("blockchain_processing_time", block_processing_time); bvc.m_added_to_main_chain = true; /*if(!m_orphanes_reorganize_in_work) diff --git a/src/cryptonote_core/blockchain_storage.h b/src/cryptonote_core/blockchain_storage.h index 6456689b9..38bdfbce7 100644 --- a/src/cryptonote_core/blockchain_storage.h +++ b/src/cryptonote_core/blockchain_storage.h @@ -249,7 +249,6 @@ namespace cryptonote bool complete_timestamps_vector(uint64_t start_height, std::vector<uint64_t>& timestamps); bool update_next_comulative_size_limit(); bool store_genesis_block(bool testnet); - void logger_handle(long int ms); }; diff --git a/src/cryptonote_core/cryptonote_core.cpp b/src/cryptonote_core/cryptonote_core.cpp index c8daa3510..49ce63065 100644 --- a/src/cryptonote_core/cryptonote_core.cpp +++ b/src/cryptonote_core/cryptonote_core.cpp @@ -206,14 +206,30 @@ namespace cryptonote return m_fast_exit; } //----------------------------------------------------------------------------------------------- - void core::no_check_blocks() + void core::test_drop_download() { - m_check_blocks = false; + m_test_drop_download = false; } //----------------------------------------------------------------------------------------------- - bool core::get_check_blocks() + void core::test_drop_download_height(uint64_t height) { - return m_check_blocks; + m_test_drop_download_height = height; + } + //----------------------------------------------------------------------------------------------- + bool core::get_test_drop_download() + { + return m_test_drop_download; + } + //----------------------------------------------------------------------------------------------- + bool core::get_test_drop_download_height() + { + if (m_test_drop_download_height == 0) + return true; + + if (get_blockchain_storage().get_current_blockchain_height() <= m_test_drop_download_height) + return true; + + return false; } //----------------------------------------------------------------------------------------------- bool core::handle_incoming_tx(const blobdata& tx_blob, tx_verification_context& tvc, bool keeped_by_block) diff --git a/src/cryptonote_core/cryptonote_core.h b/src/cryptonote_core/cryptonote_core.h index 9218aef0f..795a6d214 100644 --- a/src/cryptonote_core/cryptonote_core.h +++ b/src/cryptonote_core/cryptonote_core.h @@ -77,8 +77,10 @@ namespace cryptonote bool deinit(); static void set_fast_exit(); static bool get_fast_exit(); - void no_check_blocks(); - bool get_check_blocks(); + void test_drop_download(); + void test_drop_download_height(uint64_t height); + bool get_test_drop_download(); + bool get_test_drop_download_height(); uint64_t get_current_blockchain_height(); bool get_blockchain_top(uint64_t& heeight, crypto::hash& top_id); bool get_blocks(uint64_t start_offset, size_t count, std::list<block>& blocks, std::list<transaction>& txs); @@ -151,8 +153,8 @@ namespace cryptonote bool check_tx_inputs_keyimages_diff(const transaction& tx); void graceful_exit(); static std::atomic<bool> m_fast_exit; - bool m_check_blocks = true; - + bool m_test_drop_download = true; + uint64_t m_test_drop_download_height = 0; tx_memory_pool m_mempool; blockchain_storage m_blockchain_storage; diff --git a/src/cryptonote_protocol/cryptonote_protocol_handler-base.cpp b/src/cryptonote_protocol/cryptonote_protocol_handler-base.cpp index b5a5ceea9..614ee8fab 100644 --- a/src/cryptonote_protocol/cryptonote_protocol_handler-base.cpp +++ b/src/cryptonote_protocol/cryptonote_protocol_handler-base.cpp @@ -128,7 +128,7 @@ void cryptonote_protocol_handler_base::handler_request_blocks_history(std::list< // TODO } -void cryptonote_protocol_handler_base::handler_response_blocks_now(size_t packet_size) { _scope_mark(""); +void cryptonote_protocol_handler_base::handler_response_blocks_now(size_t packet_size) { _scope_dbg1(""); using namespace epee::net_utils; double delay=0; // will be calculated _dbg1("Packet size: " << packet_size); diff --git a/src/cryptonote_protocol/cryptonote_protocol_handler.h b/src/cryptonote_protocol/cryptonote_protocol_handler.h index ada269678..571c36dc1 100644 --- a/src/cryptonote_protocol/cryptonote_protocol_handler.h +++ b/src/cryptonote_protocol/cryptonote_protocol_handler.h @@ -45,11 +45,14 @@ #include "cryptonote_core/connection_context.h" #include "cryptonote_core/cryptonote_stat_info.h" #include "cryptonote_core/verification_context.h" +// #include <netinet/in.h> #include <boost/circular_buffer.hpp> PUSH_WARNINGS DISABLE_VS_WARNINGS(4355) +#define LOCALHOST_INT 2130706433 + namespace cryptonote { diff --git a/src/cryptonote_protocol/cryptonote_protocol_handler.inl b/src/cryptonote_protocol/cryptonote_protocol_handler.inl index 0130cb384..023dd03a6 100644 --- a/src/cryptonote_protocol/cryptonote_protocol_handler.inl +++ b/src/cryptonote_protocol/cryptonote_protocol_handler.inl @@ -42,6 +42,7 @@ #include "profile_tools.h" #include "../../contrib/otshell_utils/utils.hpp" #include "../../src/p2p/network_throttle-detail.hpp" +#include "../../src/p2p/data_logger.hpp" using namespace nOT::nUtils; namespace cryptonote @@ -154,10 +155,10 @@ namespace cryptonote << std::setw(10) << std::fixed << (connection_time == 0 ? 0.0 : cntxt.m_send_cnt / connection_time / 1024) << std::setw(13) << std::fixed << cntxt.m_current_speed_up / 1024 << (local_ip ? "[LAN]" : "") - << std::left << (ip == 2130706433 ? "[LOCALHOST]" : "") // 127.0.0.1 + << std::left << (ip == LOCALHOST_INT ? "[LOCALHOST]" : "") // 127.0.0.1 << ENDL; - if (connection_time > 0) + if (connection_time > 1) { down_sum += (cntxt.m_recv_cnt / connection_time / 1024); up_sum += (cntxt.m_send_cnt / connection_time / 1024); @@ -397,11 +398,9 @@ namespace cryptonote // calculate size of request - mainly for logging/debug size_t size = 0; - for (auto element : arg.txs) - size += element.size(); + for (auto element : arg.txs) size += element.size(); - for (auto element : arg.blocks) - { + for (auto element : arg.blocks) { size += element.block.size(); for (auto tx : element.txs) size += tx.size(); @@ -491,66 +490,65 @@ namespace cryptonote return 1; } + { m_core.pause_mine(); epee::misc_utils::auto_scope_leave_caller scope_exit_handler = epee::misc_utils::create_scope_leave_handler( boost::bind(&t_core::resume_mine, &m_core)); LOG_PRINT_CCONTEXT_YELLOW( "Got NEW BLOCKS inside of " << __FUNCTION__ << ": size: " << arg.blocks.size() , LOG_LEVEL_0); - BOOST_FOREACH(const block_complete_entry& block_entry, arg.blocks) - { - //process transactions - TIME_MEASURE_START(transactions_process_time); - BOOST_FOREACH(auto& tx_blob, block_entry.txs) - { - tx_verification_context tvc = AUTO_VAL_INIT(tvc); - m_core.handle_incoming_tx(tx_blob, tvc, true); - if(tvc.m_verifivation_failed) - { - LOG_ERROR_CCONTEXT("transaction verification failed on NOTIFY_RESPONSE_GET_OBJECTS, \r\ntx_id = " - << epee::string_tools::pod_to_hex(get_blob_hash(tx_blob)) << ", dropping connection"); - m_p2p->drop_connection(context); - return 1; - } - } - TIME_MEASURE_FINISH(transactions_process_time); - - //process block - TIME_MEASURE_START(block_process_time); - block_verification_context bvc = boost::value_initialized<block_verification_context>(); - - if (m_core.get_check_blocks()) - m_core.handle_incoming_block(block_entry.block, bvc, false); - - if(bvc.m_verifivation_failed) - { - LOG_PRINT_CCONTEXT_L1("Block verification failed, dropping connection"); - m_p2p->drop_connection(context); - return 1; - } - if(bvc.m_marked_as_orphaned) - { - LOG_PRINT_CCONTEXT_L1("Block received at sync phase was marked as orphaned, dropping connection"); - m_p2p->drop_connection(context); - return 1; - } - - TIME_MEASURE_FINISH(block_process_time); - LOG_PRINT_CCONTEXT_L2("Block process time: " << block_process_time + transactions_process_time << "(" << transactions_process_time << "/" << block_process_time << ")ms"); - - std::ofstream log_file; - log_file.open("log/dr-monero/get_objects_calc_time.data", std::ofstream::out | std::ofstream::app); - log_file.precision(7); - - using namespace boost::chrono; - auto point = steady_clock::now(); - auto time_from_epoh = point.time_since_epoch(); - auto m_ms = duration_cast< milliseconds >( time_from_epoh ).count(); - double ms_f = m_ms; - ms_f /= 1000.; - - log_file << static_cast<int>(ms_f) << " " << block_process_time + transactions_process_time << std::endl; - } + + if (m_core.get_test_drop_download() && m_core.get_test_drop_download_height()) { // DISCARD BLOCKS for testing + + + BOOST_FOREACH(const block_complete_entry& block_entry, arg.blocks) + { + // process transactions + TIME_MEASURE_START(transactions_process_time); + BOOST_FOREACH(auto& tx_blob, block_entry.txs) + { + tx_verification_context tvc = AUTO_VAL_INIT(tvc); + m_core.handle_incoming_tx(tx_blob, tvc, true); + if(tvc.m_verifivation_failed) + { + LOG_ERROR_CCONTEXT("transaction verification failed on NOTIFY_RESPONSE_GET_OBJECTS, \r\ntx_id = " + << epee::string_tools::pod_to_hex(get_blob_hash(tx_blob)) << ", dropping connection"); + m_p2p->drop_connection(context); + return 1; + } + } + TIME_MEASURE_FINISH(transactions_process_time); + + // process block + + TIME_MEASURE_START(block_process_time); + block_verification_context bvc = boost::value_initialized<block_verification_context>(); + + m_core.handle_incoming_block(block_entry.block, bvc, false); // <--- process block + + if(bvc.m_verifivation_failed) + { + LOG_PRINT_CCONTEXT_L1("Block verification failed, dropping connection"); + m_p2p->drop_connection(context); + return 1; + } + if(bvc.m_marked_as_orphaned) + { + LOG_PRINT_CCONTEXT_L1("Block received at sync phase was marked as orphaned, dropping connection"); + m_p2p->drop_connection(context); + return 1; + } + + TIME_MEASURE_FINISH(block_process_time); + LOG_PRINT_CCONTEXT_L2("Block process time: " << block_process_time + transactions_process_time << "(" << transactions_process_time << "/" << block_process_time << ")ms"); + + epee::net_utils::data_logger::get_instance().add_data("calc_time", block_process_time + transactions_process_time); + + } // each download block + + } // if not DISCARD BLOCK + + } request_missing_objects(context, true); return 1; diff --git a/src/daemon/daemon.cpp b/src/daemon/daemon.cpp index 27a1129dc..8497efbf2 100644 --- a/src/daemon/daemon.cpp +++ b/src/daemon/daemon.cpp @@ -34,6 +34,7 @@ #include "include_base_utils.h" #include "version.h" +#include "../../contrib/epee/include/syncobj.h" using namespace epee; @@ -57,6 +58,8 @@ using namespace epee; namespace po = boost::program_options; +unsigned int epee::g_test_dbg_lock_sleep = 0; + namespace { const command_line::arg_descriptor<std::string> arg_config_file = {"config-file", "Specify configuration file", std::string(CRYPTONOTE_NAME ".conf")}; @@ -69,9 +72,11 @@ namespace , "Run on testnet. The wallet must be launched with --testnet flag." , false }; - const command_line::arg_descriptor<bool> arg_dns_checkpoints = {"enforce-dns-checkpointing", "checkpoints from DNS server will be enforced", false}; - const command_line::arg_descriptor<bool> arg_test_drop_download = {"test-drop-download", "For network testing, drop downloaded blocks instead checking/adding them to blockchain. Can fake-download blocks very fast."}; - const command_line::arg_descriptor<bool> arg_save_graph = {"save-graph", "Save data for dr monero", false}; + const command_line::arg_descriptor<bool> arg_dns_checkpoints = {"enforce-dns-checkpointing", "checkpoints from DNS server will be enforced", false}; + const command_line::arg_descriptor<bool> arg_test_drop_download = {"test-drop-download", "For net tests: in download, discard ALL blocks instead checking/saving them (very fast)"}; + const command_line::arg_descriptor<uint64_t> arg_test_drop_download_height = {"test-drop-download-height", "Like test-drop-download but disards only after around certain height", 0}; + const command_line::arg_descriptor<bool> arg_save_graph = {"save-graph", "Save data for dr monero", false}; + const command_line::arg_descriptor<int> test_dbg_lock_sleep = {"test-dbg-lock-sleep", "Sleep time in ms, defaults to 0 (off), used to debug before/after locking mutex. Values 100 to 1000 are good for tests.", 0}; } bool command_line_preprocessor(const boost::program_options::variables_map& vm) @@ -111,7 +116,6 @@ bool command_line_preprocessor(const boost::program_options::variables_map& vm) int main(int argc, char* argv[]) { - string_tools::set_module_name_and_folder(argv[0]); #ifdef WIN32 _CrtSetDbgFlag ( _CRTDBG_ALLOC_MEM_DF | _CRTDBG_LEAK_CHECK_DF ); @@ -119,7 +123,10 @@ int main(int argc, char* argv[]) log_space::get_set_log_detalisation_level(true, LOG_LEVEL_0); log_space::log_singletone::add_logger(LOGGER_CONSOLE, NULL, NULL); LOG_PRINT_L0("Starting..."); - + + nOT::nUtils::cFilesystemUtils::CreateDirTree("log/dr-monero/net/"); + // _warn_c("log/test","Starting program"); // TODO + TRY_ENTRY(); boost::filesystem::path default_data_path {tools::get_default_data_dir()}; @@ -142,7 +149,9 @@ int main(int argc, char* argv[]) command_line::add_arg(desc_cmd_sett, arg_testnet_on); command_line::add_arg(desc_cmd_sett, arg_dns_checkpoints); command_line::add_arg(desc_cmd_sett, arg_test_drop_download); + command_line::add_arg(desc_cmd_sett, arg_test_drop_download_height); command_line::add_arg(desc_cmd_sett, arg_save_graph); + command_line::add_arg(desc_cmd_sett, test_dbg_lock_sleep); cryptonote::core::init_options(desc_cmd_sett); cryptonote::core_rpc_server::init_options(desc_cmd_sett); @@ -241,12 +250,16 @@ int main(int argc, char* argv[]) if(command_line::has_arg(vm, arg_save_graph)) p2psrv.set_save_graph(true); + epee::g_test_dbg_lock_sleep = command_line::get_arg(vm, test_dbg_lock_sleep); + //initialize core here LOG_PRINT_L0("Initializing core..."); res = ccore.init(vm, testnet_mode); CHECK_AND_ASSERT_MES(res, 1, "Failed to initialize core"); if (command_line::get_arg(vm, arg_test_drop_download)) - ccore.no_check_blocks(); + ccore.test_drop_download(); + + ccore.test_drop_download_height(command_line::get_arg(vm, arg_test_drop_download_height)); LOG_PRINT_L0("Core initialized OK"); //initialize objects diff --git a/src/daemon/daemon_commands_handler.h b/src/daemon/daemon_commands_handler.h index 6afbbb07f..c23df0443 100644 --- a/src/daemon/daemon_commands_handler.h +++ b/src/daemon/daemon_commands_handler.h @@ -426,27 +426,21 @@ private: return false; } - using namespace boost::chrono; - auto point = steady_clock::now(); - auto time_from_epoh = point.time_since_epoch(); - auto ms = duration_cast< milliseconds >( time_from_epoh ).count(); - double ms_f = ms; - ms_f /= 1000.; - - std::ofstream limitFile("log/dr-monero/peers_limit.info", std::ios::app); - limitFile.precision(7); - limitFile << ms_f << " " << static_cast<int>(limit) << std::endl; if (m_srv.m_config.m_net_config.connections_count > limit) { m_srv.m_config.m_net_config.connections_count = limit; - if (m_srv.m_number_of_out_peers > limit) + epee::net_utils::data_logger::get_instance().add_data("peers_limit", m_srv.m_config.m_net_config.connections_count); + if (m_srv.m_current_number_of_out_peers > limit) { - int count = m_srv.m_number_of_out_peers - limit; + int count = m_srv.m_current_number_of_out_peers - limit; m_srv.delete_connections(count); } } else + { m_srv.m_config.m_net_config.connections_count = limit; + epee::net_utils::data_logger::get_instance().add_data("peers_limit", m_srv.m_config.m_net_config.connections_count); + } return true; } @@ -556,7 +550,7 @@ private: //-------------------------------------------------------------------------------- bool test_drop_download(const std::vector<std::string>& args) { - m_srv.get_payload_object().get_core().no_check_blocks(); + m_srv.get_payload_object().get_core().test_drop_download(); return true; } //-------------------------------------------------------------------------------- diff --git a/src/miner/simpleminer.cpp b/src/miner/simpleminer.cpp index fafe6b3f3..6212f88f5 100644 --- a/src/miner/simpleminer.cpp +++ b/src/miner/simpleminer.cpp @@ -41,6 +41,7 @@ using namespace epee; namespace po = boost::program_options; +unsigned int epee::g_test_dbg_lock_sleep = 0; int main(int argc, char** argv) { diff --git a/src/p2p/connection_basic.cpp b/src/p2p/connection_basic.cpp index 0e2fd5942..4a4a32384 100644 --- a/src/p2p/connection_basic.cpp +++ b/src/p2p/connection_basic.cpp @@ -152,7 +152,7 @@ connection_basic::connection_basic(boost::asio::io_service& io_service, std::ato try { remote_addr_str = socket_.remote_endpoint().address().to_string(); } catch(...){} ; _note("Spawned connection p2p#"<<mI->m_peer_number<<" to " << remote_addr_str << " currently we have sockets count:" << m_ref_sock_count); - boost::filesystem::create_directories("log/dr-monero/net/"); + //boost::filesystem::create_directories("log/dr-monero/net/"); } connection_basic::~connection_basic() { @@ -192,24 +192,15 @@ void connection_basic::save_limit_to_file(int limit) { // saving limit to file if (!epee::net_utils::data_logger::m_save_graph) return; - std::ofstream file_up, file_down; - file_up.open("log/dr-monero/limit_up.info", std::ofstream::out | std::ofstream::app); - file_up.precision(8); - file_down.open("log/dr-monero/limit_down.info", std::ofstream::out | std::ofstream::app); - file_down.precision(8); - using namespace boost::chrono; - auto point = steady_clock::now(); - auto time_from_epoh = point.time_since_epoch(); - auto s = duration_cast< seconds >( time_from_epoh ).count(); { CRITICAL_REGION_LOCAL( network_throttle_manager::m_lock_get_global_throttle_out ); - file_up << s << " " << network_throttle_manager::get_global_throttle_out().get_terget_speed() / 1024 << "\n"; + epee::net_utils::data_logger::get_instance().add_data("upload_limit", network_throttle_manager::get_global_throttle_out().get_terget_speed() / 1024); } { CRITICAL_REGION_LOCAL( network_throttle_manager::m_lock_get_global_throttle_in ); - file_down << s << " " << network_throttle_manager::get_global_throttle_in().get_terget_speed() / 1024 << "\n"; + epee::net_utils::data_logger::get_instance().add_data("download_limit", network_throttle_manager::get_global_throttle_in().get_terget_speed() / 1024); } } diff --git a/src/p2p/data_logger.cpp b/src/p2p/data_logger.cpp index 6a8eb25be..77f647bed 100644 --- a/src/p2p/data_logger.cpp +++ b/src/p2p/data_logger.cpp @@ -1,7 +1,9 @@ #include "data_logger.hpp" #include <boost/chrono.hpp> +#include <boost/filesystem.hpp> #include <chrono> +#include "../../contrib/otshell_utils/utils.hpp" namespace epee { @@ -32,7 +34,16 @@ namespace net_utils mFilesMap["request"] = data_logger::fileData("log/dr-monero/net/req-all.data"); mFilesMap["sleep_down"] = data_logger::fileData("log/dr-monero/down_sleep_log.data"); mFilesMap["sleep_up"] = data_logger::fileData("log/dr-monero/up_sleep_log.data"); + mFilesMap["calc_time"] = data_logger::fileData("log/dr-monero/get_objects_calc_time.data"); + mFilesMap["blockchain_processing_time"] = data_logger::fileData("log/dr-monero/blockchain_log.data"); + mFilesMap["peers_limit"] = data_logger::fileData("log/dr-monero/peers_limit.info"); + mFilesMap["download_limit"] = data_logger::fileData("log/dr-monero/limit_down.info"); + mFilesMap["upload_limit"] = data_logger::fileData("log/dr-monero/limit_up.info"); + + mFilesMap["peers_limit"].mLimitFile = true; + mFilesMap["download_limit"].mLimitFile = true; + mFilesMap["upload_limit"].mLimitFile = true; } void data_logger::add_data(std::string filename, unsigned int data) @@ -40,7 +51,14 @@ namespace net_utils if (mFilesMap.find(filename) == mFilesMap.end()) return; // TODO: exception - mFilesMap[filename].mDataToSave += data; + + nOT::nUtils::cFilesystemUtils::CreateDirTree("log/dr-monero/net/"); + + std::lock_guard<std::mutex> lock(mSaveMutex); + if (mFilesMap[filename].mLimitFile) + mFilesMap[filename].mDataToSave = data; + else + mFilesMap[filename].mDataToSave += data; } double data_logger::fileData::get_current_time() @@ -56,23 +74,27 @@ namespace net_utils data_logger::fileData::fileData(std::string pFile) { mFile = std::make_shared<std::ofstream> (pFile); + mPath = pFile; } void data_logger::fileData::save() { if (!data_logger::m_save_graph) return; + mFile->open(mPath, std::ios::app); *mFile << static_cast<int>(get_current_time()) << " " << mDataToSave << std::endl; + mFile->close(); } void data_logger::saveToFile() { - std::lock_guard<std::mutex> lock(mSaveMutex); - for (auto &element : mFilesMap) - { - element.second.save(); - element.second.mDataToSave = 0; - } + std::lock_guard<std::mutex> lock(mSaveMutex); + for (auto &element : mFilesMap) + { + element.second.save(); + if (!element.second.mLimitFile) + element.second.mDataToSave = 0; + } } std::atomic<bool> data_logger::m_save_graph(false); diff --git a/src/p2p/data_logger.hpp b/src/p2p/data_logger.hpp index 2b8503df3..50beb847a 100644 --- a/src/p2p/data_logger.hpp +++ b/src/p2p/data_logger.hpp @@ -27,12 +27,15 @@ namespace net_utils { public: fileData(){} + fileData(const fileData &ob) = delete; fileData(std::string pFile); std::shared_ptr<std::ofstream> mFile; long int mDataToSave = 0; static double get_current_time(); void save(); + std::string mPath; + bool mLimitFile = false; }; std::map <std::string, fileData> mFilesMap; diff --git a/src/p2p/net_node.h b/src/p2p/net_node.h index ea7d5c383..5417ffa52 100644 --- a/src/p2p/net_node.h +++ b/src/p2p/net_node.h @@ -87,7 +87,7 @@ namespace nodetool m_hide_my_port(false), m_network_id(std::move(network_id)) { - m_number_of_out_peers = 0; + m_current_number_of_out_peers = 0; m_save_graph = false; } @@ -228,7 +228,7 @@ namespace nodetool public: config m_config; // TODO was private, add getters? - std::atomic<unsigned int> m_number_of_out_peers; + std::atomic<unsigned int> m_current_number_of_out_peers; void set_save_graph(bool save_graph) { m_save_graph = save_graph; diff --git a/src/p2p/net_node.inl b/src/p2p/net_node.inl index 60eed1f36..a015763bf 100644 --- a/src/p2p/net_node.inl +++ b/src/p2p/net_node.inl @@ -296,20 +296,18 @@ namespace nodetool unsigned int number_of_peers; while (1) { - if (m_save_graph) + //number_of_peers = m_net_server.get_config_object().get_connections_count(); + number_of_peers = 0; + m_net_server.get_config_object().foreach_connection([&](const p2p_connection_context& cntxt) { - //number_of_peers = m_net_server.get_config_object().get_connections_count(); - number_of_peers = 0; - m_net_server.get_config_object().foreach_connection([&](const p2p_connection_context& cntxt) - { - if(!cntxt.m_is_income) - ++number_of_peers; - return true; - }); // lambda + if(!cntxt.m_is_income) + ++number_of_peers; + return true; + }); // lambda + + m_current_number_of_out_peers = number_of_peers; + epee::net_utils::data_logger::get_instance().add_data("peers", number_of_peers); - m_number_of_out_peers = number_of_peers; - epee::net_utils::data_logger::get_instance().add_data("peers", number_of_peers); - } std::this_thread::sleep_for(std::chrono::seconds(1)); } })); // lambda @@ -724,14 +722,14 @@ namespace nodetool template<class t_payload_net_handler> bool node_server<t_payload_net_handler>::try_to_connect_and_handshake_with_new_peer(const net_address& na, bool just_take_peerlist, uint64_t last_seen_stamp, bool white) { - if (m_number_of_out_peers == m_config.m_net_config.connections_count) // out peers limit + if (m_current_number_of_out_peers == m_config.m_net_config.connections_count) // out peers limit { return false; } - else if (m_number_of_out_peers > m_config.m_net_config.connections_count) + else if (m_current_number_of_out_peers > m_config.m_net_config.connections_count) { m_net_server.get_config_object().del_out_connections(1); - m_number_of_out_peers --; // atomic variable, update time = 1s + m_current_number_of_out_peers --; // atomic variable, update time = 1s return false; } LOG_PRINT_L1("Connecting to " << epee::string_tools::get_ip_string_from_int32(na.ip) << ":" @@ -1378,25 +1376,14 @@ namespace nodetool template<class t_payload_net_handler> bool node_server<t_payload_net_handler>::set_max_out_peers(const boost::program_options::variables_map& vm, int64_t max) - { - using namespace std::chrono; - auto point = steady_clock::now(); - auto time_from_epoh = point.time_since_epoch(); - auto ms = duration_cast< milliseconds >( time_from_epoh ).count(); - double ms_f = ms; - ms_f /= 1000.; - - std::ofstream limitFile("log/dr-monero/peers_limit.info", std::ios::app); - limitFile.precision(7); + { if(max == -1) { m_config.m_net_config.connections_count = P2P_DEFAULT_CONNECTIONS_COUNT; - if (m_save_graph) - limitFile << static_cast<int>(ms_f) << " " << P2P_DEFAULT_CONNECTIONS_COUNT << std::endl; + epee::net_utils::data_logger::get_instance().add_data("peers_limit", m_config.m_net_config.connections_count); return true; } - + epee::net_utils::data_logger::get_instance().add_data("peers_limit", max); m_config.m_net_config.connections_count = max; - limitFile << static_cast<int>(ms_f) << " " << max << std::endl; return true; } diff --git a/src/p2p/network_throttle-detail.cpp b/src/p2p/network_throttle-detail.cpp index 6b2ee698e..7426e6dc7 100644 --- a/src/p2p/network_throttle-detail.cpp +++ b/src/p2p/network_throttle-detail.cpp @@ -220,7 +220,7 @@ void network_throttle::_handle_trafic_exact(size_t packet_size, size_t orginal_s std::ostringstream oss; oss << "["; for (auto sample: m_history) oss << sample.m_size << " "; oss << "]" << std::ends; std::string history_str = oss.str(); - _info_c( "net/" + m_nameshort , "Throttle " << m_name << ": packet of ~"<<packet_size<<"b " << " (from "<<orginal_size<<" b)" + _dbg2_c( "net/" + m_nameshort , "Throttle " << m_name << ": packet of ~"<<packet_size<<"b " << " (from "<<orginal_size<<" b)" << " Speed AVG=" << std::setw(4) << ((long int)(cts .average/1024)) <<"[w="<<cts .window<<"]" << " " << std::setw(4) << ((long int)(cts2.average/1024)) <<"[w="<<cts2.window<<"]" <<" / " << " Limit="<< ((long int)(m_target_speed/1024)) <<" KiB/sec " @@ -312,7 +312,7 @@ void network_throttle::calculate_times(size_t packet_size, calculate_times_struc if (dbg) { std::ostringstream oss; oss << "["; for (auto sample: m_history) oss << sample.m_size << " "; oss << "]" << std::ends; std::string history_str = oss.str(); - _info_c( "net/"+m_nameshort+"_c" , + _dbg1_c( "net/"+m_nameshort+"_c" , (cts.delay > 0 ? "SLEEP" : "") << "dbg " << m_name << ": " << "speed is A=" << std::setw(8) <<cts.average<<" vs " diff --git a/src/simplewallet/simplewallet.cpp b/src/simplewallet/simplewallet.cpp index ae61871dc..2a0e0e2f4 100644 --- a/src/simplewallet/simplewallet.cpp +++ b/src/simplewallet/simplewallet.cpp @@ -67,6 +67,7 @@ namespace po = boost::program_options; #define EXTENDED_LOGS_FILE "wallet_details.log" +unsigned int epee::g_test_dbg_lock_sleep = 0; namespace { |