From 5833d66f6540e7b34e10ddef37c2b67bd501994b Mon Sep 17 00:00:00 2001 From: moneromooo-monero Date: Sun, 1 Jan 2017 16:34:23 +0000 Subject: Change logging to easylogging++ This replaces the epee and data_loggers logging systems with a single one, and also adds filename:line and explicit severity levels. Categories may be defined, and logging severity set by category (or set of categories). epee style 0-4 log level maps to a sensible severity configuration. Log files now also rotate when reaching 100 MB. To select which logs to output, use the MONERO_LOGS environment variable, with a comma separated list of categories (globs are supported), with their requested severity level after a colon. If a log matches more than one such setting, the last one in the configuration string applies. A few examples: This one is (mostly) silent, only outputting fatal errors: MONERO_LOGS=*:FATAL This one is very verbose: MONERO_LOGS=*:TRACE This one is totally silent (logwise): MONERO_LOGS="" This one outputs all errors and warnings, except for the "verify" category, which prints just fatal errors (the verify category is used for logs about incoming transactions and blocks, and it is expected that some/many will fail to verify, hence we don't want the spam): MONERO_LOGS=*:WARNING,verify:FATAL Log levels are, in decreasing order of priority: FATAL, ERROR, WARNING, INFO, DEBUG, TRACE Subcategories may be added using prefixes and globs. This example will output net.p2p logs at the TRACE level, but all other net* logs only at INFO: MONERO_LOGS=*:ERROR,net*:INFO,net.p2p:TRACE Logs which are intended for the user (which Monero was using a lot through epee, but really isn't a nice way to go things) should use the "global" category. There are a few helper macros for using this category, eg: MGINFO("this shows up by default") or MGINFO_RED("this is red"), to try to keep a similar look and feel for now. Existing epee log macros still exist, and map to the new log levels, but since they're used as a "user facing" UI element as much as a logging system, they often don't map well to log severities (ie, a log level 0 log may be an error, or may be something we want the user to see, such as an important info). In those cases, I tried to use the new macros. In other cases, I left the existing macros in. When modifying logs, it is probably best to switch to the new macros with explicit levels. The --log-level options and set_log commands now also accept category settings, in addition to the epee style log levels. --- contrib/epee/include/net/abstract_tcp_server2.inl | 85 +++++++++++------------ 1 file changed, 39 insertions(+), 46 deletions(-) (limited to 'contrib/epee/include/net/abstract_tcp_server2.inl') diff --git a/contrib/epee/include/net/abstract_tcp_server2.inl b/contrib/epee/include/net/abstract_tcp_server2.inl index 834b5a7a6..75a9c5be9 100644 --- a/contrib/epee/include/net/abstract_tcp_server2.inl +++ b/contrib/epee/include/net/abstract_tcp_server2.inl @@ -51,9 +51,8 @@ #include "../../../../src/cryptonote_core/cryptonote_core.h" // e.g. for the send_stop_signal() -#include "../../../../contrib/otshell_utils/utils.hpp" -#include "../../../../src/p2p/data_logger.hpp" -using namespace nOT::nUtils; // TODO +#undef MONERO_DEFAULT_LOG_CATEGORY +#define MONERO_DEFAULT_LOG_CATEGORY "net" #define CONNECTION_CLEANUP_TIME 30 // seconds @@ -83,7 +82,7 @@ PRAGMA_WARNING_DISABLE_VS(4355) m_throttle_speed_in("speed_in", "throttle_speed_in"), m_throttle_speed_out("speed_out", "throttle_speed_out") { - _info_c("net/sleepRPC", "test, connection constructor set m_connection_type="<::release() call"); //erasing from container without additional copy can cause start deleting object, including m_self_refs @@ -266,8 +265,7 @@ PRAGMA_WARNING_DISABLE_VS(4355) address = endpoint.address().to_string(); port = boost::lexical_cast(endpoint.port()); } - _mark_c("net/kind" , - " connection type " << to_string( m_connection_type ) << " " + MINFO(" connection type " << to_string( m_connection_type ) << " " << socket_.local_endpoint().address().to_string() << ":" << socket_.local_endpoint().port() << " <--> " << address << ":" << port); } @@ -306,7 +304,6 @@ PRAGMA_WARNING_DISABLE_VS(4355) delay *= 0.5; if (delay > 0) { long int ms = (long int)(delay * 100); - epee::net_utils::data_logger::get_instance().add_data("sleep_down", ms); boost::this_thread::sleep_for(boost::chrono::milliseconds(ms)); } } while(delay > 0); @@ -397,14 +394,14 @@ PRAGMA_WARNING_DISABLE_VS(4355) const t_safe chunksize_max = chunksize_good * 2 ; const bool allow_split = (m_connection_type == e_connection_type_RPC) ? false : true; // do not split RPC data - ASRT(! (chunksize_max<0) ); // make sure it is unsigned before removin sign with cast: + CHECK_AND_ASSERT_MES(! (chunksize_max<0), false, "Negative chunksize_max" ); // make sure it is unsigned before removin sign with cast: long long unsigned int chunksize_max_unsigned = static_cast( chunksize_max ) ; if (allow_split && (cb > chunksize_max_unsigned)) { { // LOCK: chunking epee::critical_region_t send_guard(m_chunking_lock); // *** critical *** - _dbg3_c("net/out/size", "do_send() will SPLIT into small chunks, from packet="<( len ); - ASRT(len>0); // (redundand) - ASRT(len_unsigned < std::numeric_limits::max()); // yeap we want strong < then max size, to be sure + CHECK_AND_ASSERT_MES(len>0, false, "len not strictly positive"); // (redundant) + CHECK_AND_ASSERT_MES(len_unsigned < std::numeric_limits::max(), false, "Invalid len_unsigned"); // yeap we want strong < then max size, to be sure void *chunk_start = ((char*)ptr) + pos; - _fact_c("net/out/size","chunk_start="<0); + pos = pos+len; + CHECK_AND_ASSERT_MES(pos >0, false, "pos <= 0"); // (in catch block, or uniq pointer) delete buf; } // each chunk - _dbg3_c("net/out/size", "do_send() DONE SPLIT from packet="< retry_limit) { - _erro("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"); + MWARNING("send que size is more than ABSTRACT_SERVER_SEND_QUE_MAX_COUNT(" << ABSTRACT_SERVER_SEND_QUE_MAX_COUNT << "), shutting down connection"); shutdown(); return false; } @@ -525,10 +521,10 @@ PRAGMA_WARNING_DISABLE_VS(4355) if(m_send_que.size() > 1) { // active operation should be in progress, nothing to do, just wait last operation callback auto size_now = cb; - _info_c("net/out/size", "do_send() NOW just queues: packet="<::handle_write, self, _1, _2) @@ -602,7 +598,7 @@ PRAGMA_WARNING_DISABLE_VS(4355) void connection::handle_write(const boost::system::error_code& e, size_t cb) { TRY_ENTRY(); - LOG_PRINT_L4("[sock " << socket_.native_handle() << "] Async send calledback " << cb); + LOG_TRACE_CC(context, "[sock " << socket_.native_handle() << "] Async send calledback " << cb); if (e) { @@ -635,10 +631,10 @@ PRAGMA_WARNING_DISABLE_VS(4355) { //have more data to send auto size_now = m_send_que.front().size(); - _dbg1_c("net/out/size", "handle_write() NOW SENDS: packet="<::handle_write, connection::shared_from_this(), _1, _2) @@ -660,8 +656,7 @@ PRAGMA_WARNING_DISABLE_VS(4355) void connection::setRpcStation() { m_connection_type = e_connection_type_RPC; - _fact_c("net/sleepRPC", "set m_connection_type = RPC "); - _info_c("net/kind", "set m_connection_type = RPC "); + MDEBUG("set m_connection_type = RPC "); } @@ -735,7 +730,7 @@ PRAGMA_WARNING_DISABLE_VS(4355) acceptor_.listen(); boost::asio::ip::tcp::endpoint binded_endpoint = acceptor_.local_endpoint(); m_port = binded_endpoint.port(); - _fact_c("net/RPClog", "start accept"); + MDEBUG("start accept"); new_connection_.reset(new connection(io_service_, m_config, m_sock_count, m_sock_number, m_pfilter, m_connection_type)); acceptor_.async_accept(new_connection_->socket(), boost::bind(&boosted_tcp_server::handle_accept, this, @@ -753,7 +748,7 @@ DISABLE_GCC_WARNING(maybe-uninitialized) uint32_t p = 0; if (port.size() && !string_tools::get_xtype_from_string(p, port)) { - LOG_ERROR("Failed to convert port no = " << port); + MERROR("Failed to convert port no = " << port); return false; } return this->init_server(p, address); @@ -767,7 +762,7 @@ POP_WARNINGS uint32_t local_thr_index = boost::interprocess::ipcdetail::atomic_inc32(&m_thread_index); std::string thread_name = std::string("[") + m_thread_name_prefix; thread_name += boost::to_string(local_thr_index) + "]"; - log_space::log_singletone::set_thread_log_prefix(thread_name); + MLOG_SET_THREAD_NAME(thread_name); // _fact("Thread name: " << m_thread_name_prefix); while(!m_stop_signal_sent) { @@ -796,8 +791,7 @@ POP_WARNINGS auto it = server_type_map.find(m_thread_name_prefix); if (it==server_type_map.end()) throw std::runtime_error("Unknown prefix/server type:" + std::string(prefix_name)); auto connection_type = it->second; // the value of type - _info_c("net/RPClog", "Set server type to: " << connection_type << " from name: " << m_thread_name_prefix); - _info_c("net/RPClog", "prefix_name = " << prefix_name); + MINFO("Set server type to: " << connection_type << " from name: " << m_thread_name_prefix << ", prefix_name = " << prefix_name); } //--------------------------------------------------------------------------------- template @@ -812,7 +806,7 @@ POP_WARNINGS TRY_ENTRY(); m_threads_count = threads_count; m_main_thread_id = boost::this_thread::get_id(); - log_space::log_singletone::set_thread_log_prefix("[SRV_MAIN]"); + MLOG_SET_THREAD_NAME("[SRV_MAIN]"); add_idle_handler(boost::bind(&boosted_tcp_server::cleanup_connections, this), 5000); while(!m_stop_signal_sent) { @@ -933,13 +927,12 @@ POP_WARNINGS template void boosted_tcp_server::handle_accept(const boost::system::error_code& e) { - _fact_c("net/RPClog", "handle_accept"); + MDEBUG("handle_accept"); TRY_ENTRY(); if (!e) { if (m_connection_type == e_connection_type_RPC) { - _note_c("net/rpc", "New server for RPC connections"); - _fact_c("net/RPClog", "New server for RPC connections"); + MDEBUG("New server for RPC connections"); new_connection_->setRpcStation(); // hopefully this is not needed actually } connection_ptr conn(std::move(new_connection_)); @@ -965,7 +958,7 @@ POP_WARNINGS connection_ptr new_connection_l(new connection(io_service_, m_config, m_sock_count, m_sock_number, m_pfilter, m_connection_type) ); connections_mutex.lock(); connections_.push_back(std::make_pair(boost::get_system_time(), new_connection_l)); - LOG_PRINT_L2("connections_ size now " << connections_.size()); + MDEBUG("connections_ size now " << connections_.size()); connections_mutex.unlock(); boost::asio::ip::tcp::socket& sock_ = new_connection_l->socket(); @@ -1069,7 +1062,7 @@ POP_WARNINGS connection_ptr new_connection_l(new connection(io_service_, m_config, m_sock_count, m_sock_number, m_pfilter, m_connection_type) ); connections_mutex.lock(); connections_.push_back(std::make_pair(boost::get_system_time(), new_connection_l)); - LOG_PRINT_L2("connections_ size now " << connections_.size()); + MDEBUG("connections_ size now " << connections_.size()); connections_mutex.unlock(); boost::asio::ip::tcp::socket& sock_ = new_connection_l->socket(); -- cgit v1.2.3