diff options
author | rfree2monero <rfreemonero@op.pl> | 2015-02-20 22:28:03 +0100 |
---|---|---|
committer | rfree2monero <rfreemonero@op.pl> | 2015-02-20 22:28:03 +0100 |
commit | ae2a50659f7dc74a5446a0dc3a5f8f78563b9e1f (patch) | |
tree | 0d1e7332174fdad966a3048b6b12daee4d07f367 | |
parent | fixed size_t on windows (diff) | |
download | monero-ae2a50659f7dc74a5446a0dc3a5f8f78563b9e1f.tar.xz |
2014 network limit 1.2 +utils +toc -doc -drmonero
new update of the pr with network limits
more debug options:
discarding downloaded blocks all or after given height.
trying to trigger the locking errors.
debug levels polished/tuned to sane values.
debug/logging improved.
warning: this pr should be correct code, but it could make
an existing (in master version) locking error appear more often.
it's a race on the list (map) of peers, e.g. between closing/deleting
them versus working on them in net-limit sleep in sending chunk.
the bug is not in this code/this pr, but in the master version.
the locking problem of master will be fixed in other pr.
problem is ub, and in practice is seems to usually cause program abort
(tested on debian stable with updated gcc). see --help for option
to add sleep to trigger the error faster.
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 { |