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.
This commit is contained in:
moneromooo-monero 2017-01-01 16:34:23 +00:00
parent dc98019b59
commit 5833d66f65
No known key found for this signature in database
GPG key ID: 686F07454D6CEFC3
125 changed files with 1461 additions and 4409 deletions

View file

@ -38,6 +38,9 @@
#pragma comment(lib, "Ws2_32.lib")
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net"
namespace epee
{
namespace net_utils

View file

@ -55,9 +55,11 @@
#include "net_utils_base.h"
#include "syncobj.h"
#include "../../../../src/p2p/connection_basic.hpp"
#include "../../../../contrib/otshell_utils/utils.hpp"
#include "../../../../src/p2p/network_throttle-detail.hpp"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net"
#define ABSTRACT_SERVER_SEND_QUE_MAX_COUNT 1000
namespace epee

View file

@ -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="<<m_connection_type);
MINFO("test, connection constructor set m_connection_type="<<m_connection_type);
}
PRAGMA_WARNING_DISABLE_VS(4355)
//---------------------------------------------------------------------------------
@ -229,7 +228,7 @@ PRAGMA_WARNING_DISABLE_VS(4355)
{
TRY_ENTRY();
boost::shared_ptr<connection<t_protocol_handler> > back_connection_copy;
LOG_PRINT_L4("[sock " << socket_.native_handle() << "] release");
LOG_TRACE_CC(context, "[sock " << socket_.native_handle() << "] release");
CRITICAL_REGION_BEGIN(m_self_refs_lock);
CHECK_AND_ASSERT_MES(m_self_refs.size(), false, "[sock " << socket_.native_handle() << "] m_self_refs empty at connection<t_protocol_handler>::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<std::string>(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<long long unsigned int>( chunksize_max ) ;
if (allow_split && (cb > chunksize_max_unsigned)) {
{ // LOCK: chunking
epee::critical_region_t<decltype(m_chunking_lock)> send_guard(m_chunking_lock); // *** critical ***
_dbg3_c("net/out/size", "do_send() will SPLIT into small chunks, from packet="<<cb<<" B for ptr="<<ptr);
MDEBUG("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
@ -419,39 +416,39 @@ PRAGMA_WARNING_DISABLE_VS(4355)
while (pos < all) {
t_safe lenall = all-pos; // length from here to end
t_safe len = std::min( chunksize_good , lenall); // take a smaller part
ASRT(len<=chunksize_good);
CHECK_AND_ASSERT_MES(len<=chunksize_good, false, "len too large");
// pos=8; len=4; all=10; len=3;
ASRT(! (len<0) ); // check before we cast away sign:
CHECK_AND_ASSERT_MES(! (len<0), false, "negative len"); // check before we cast away sign:
unsigned long long int len_unsigned = static_cast<long long int>( len );
ASRT(len>0); // (redundand)
ASRT(len_unsigned < std::numeric_limits<size_t>::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<size_t>::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="<<chunk_start<<" ptr="<<ptr<<" pos="<<pos);
ASRT(chunk_start >= ptr); // not wrapped around address?
MDEBUG("chunk_start="<<chunk_start<<" ptr="<<ptr<<" pos="<<pos);
CHECK_AND_ASSERT_MES(chunk_start >= ptr, false, "Pointer wraparound"); // not wrapped around address?
//std::memcpy( (void*)buf, chunk_start, len);
_dbg3_c("net/out/size", "part of " << lenall << ": pos="<<pos << " len="<<len);
MDEBUG("part of " << lenall << ": pos="<<pos << " len="<<len);
bool ok = do_send_chunk(chunk_start, len); // <====== ***
all_ok = all_ok && ok;
if (!all_ok) {
_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 "
MDEBUG("do_send() DONE ***FAILED*** from packet="<<cb<<" B for ptr="<<ptr);
MDEBUG("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
}
pos = pos+len; ASRT(pos >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="<<cb<<" B for ptr="<<ptr);
_dbg3 ( "do_send() DONE SPLIT from packet="<<cb<<" B for ptr="<<ptr);
MDEBUG("do_send() DONE SPLIT from packet="<<cb<<" B for ptr="<<ptr);
_info_c("net/sleepRPC", "do_send() m_connection_type = " << m_connection_type);
MDEBUG("do_send() m_connection_type = " << m_connection_type);
return all_ok; // done - e.g. queued - all the chunks of current do_send call
} // LOCK: chunking
@ -505,15 +502,14 @@ PRAGMA_WARNING_DISABLE_VS(4355)
}*/
long int ms = 250 + (rand()%50);
_info_c("net/sleep", "Sleeping because QUEUE is FULL, in " << __FUNCTION__ << " for " << ms << " ms before packet_size="<<cb); // XXX debug sleep
MDEBUG("Sleeping because QUEUE is FULL, in " << __FUNCTION__ << " for " << ms << " ms before packet_size="<<cb); // XXX debug sleep
m_send_que_lock.unlock();
boost::this_thread::sleep(boost::posix_time::milliseconds( ms ) );
m_send_que_lock.lock();
_dbg1("sleep for queue: " << ms);
if (retry > 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="<<size_now<<" B, is added to queue-size="<<m_send_que.size());
MDEBUG("do_send() NOW just queues: packet="<<size_now<<" B, is added to queue-size="<<m_send_que.size());
//do_send_handler_delayed( ptr , size_now ); // (((H))) // empty function
LOG_PRINT_L4("[sock " << socket_.native_handle() << "] Async send requested " << m_send_que.front().size());
LOG_TRACE_CC(context, "[sock " << socket_.native_handle() << "] Async send requested " << m_send_que.front().size());
}
else
{ // no active operation
@ -540,11 +536,11 @@ PRAGMA_WARNING_DISABLE_VS(4355)
}
auto size_now = m_send_que.front().size();
_dbg1_c("net/out/size", "do_send() NOW SENSD: packet="<<size_now<<" B");
MDEBUG("do_send() NOW SENSD: packet="<<size_now<<" B");
if (speed_limit_is_enabled())
do_send_handler_write( ptr , size_now ); // (((H)))
ASRT( size_now == m_send_que.front().size() );
CHECK_AND_ASSERT_MES( size_now == m_send_que.front().size(), false, "Unexpected queue size");
boost::asio::async_write(socket_, boost::asio::buffer(m_send_que.front().data(), size_now ) ,
//strand_.wrap(
boost::bind(&connection<t_protocol_handler>::handle_write, self, _1, _2)
@ -602,7 +598,7 @@ PRAGMA_WARNING_DISABLE_VS(4355)
void connection<t_protocol_handler>::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="<<size_now<<" B" <<", from queue size="<<m_send_que.size());
MDEBUG("handle_write() NOW SENDS: packet="<<size_now<<" B" <<", from queue size="<<m_send_que.size());
if (speed_limit_is_enabled())
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() );
CHECK_AND_ASSERT_MES( size_now == m_send_que.front().size(), void(), "Unexpected queue size");
boost::asio::async_write(socket_, boost::asio::buffer(m_send_que.front().data(), size_now) ,
// strand_.wrap(
boost::bind(&connection<t_protocol_handler>::handle_write, connection<t_protocol_handler>::shared_from_this(), _1, _2)
@ -660,8 +656,7 @@ PRAGMA_WARNING_DISABLE_VS(4355)
void connection<t_protocol_handler>::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<t_protocol_handler>(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<t_protocol_handler>::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<class t_protocol_handler>
@ -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<class t_protocol_handler>
void boosted_tcp_server<t_protocol_handler>::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<t_protocol_handler>(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<t_protocol_handler>(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();

View file

@ -42,6 +42,9 @@
#include "net_utils_base.h"
#include "pragma_comp_defs.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net"
#define LEVIN_DEFAULT_DATA_BUFF_SIZE 2000
namespace epee

View file

@ -27,6 +27,9 @@
#pragma comment(lib, "Ws2_32.lib")
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net"
namespace epee
{
namespace net_utils

View file

@ -36,6 +36,9 @@
#include "http_base.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net.http"
namespace epee
{
namespace net_utils

View file

@ -31,6 +31,10 @@
#include <boost/regex.hpp>
#include "string_tools.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net.http"
namespace epee
{
namespace net_utils

View file

@ -52,6 +52,9 @@
//#pragma comment(lib, "shlwapi.lib")
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net.http"
extern epee::critical_section gregexp_lock;
@ -325,10 +328,10 @@ using namespace std;
CRITICAL_REGION_LOCAL(m_lock);
if(!is_connected())
{
LOG_PRINT("Reconnecting...", LOG_LEVEL_3);
MDEBUG("Reconnecting...");
if(!connect(m_host_buff, m_port, m_timeout))
{
LOG_PRINT("Failed to connect to " << m_host_buff << ":" << m_port, LOG_LEVEL_3);
MDEBUG("Failed to connect to " << m_host_buff << ":" << m_port);
return false;
}
}
@ -376,7 +379,7 @@ using namespace std;
{
if(!m_net_client.recv(recv_buffer))
{
LOG_PRINT("Unexpected reciec fail", LOG_LEVEL_3);
MERROR("Unexpected recv fail");
m_state = reciev_machine_state_error;
}
if(!recv_buffer.size())
@ -464,7 +467,7 @@ using namespace std;
CRITICAL_REGION_LOCAL(m_lock);
if(!recv_buff.size())
{
LOG_PRINT("Warning: Content-Len mode, but connection unexpectedly closed", LOG_LEVEL_3);
MERROR("Warning: Content-Len mode, but connection unexpectedly closed");
m_state = reciev_machine_state_done;
return true;
}
@ -578,7 +581,7 @@ using namespace std;
CRITICAL_REGION_LOCAL(m_lock);
if(!recv_buff.size())
{
LOG_PRINT("Warning: CHUNKED mode, but connection unexpectedly closed", LOG_LEVEL_3);
MERROR("Warning: CHUNKED mode, but connection unexpectedly closed");
m_state = reciev_machine_state_done;
return true;
}
@ -665,7 +668,7 @@ using namespace std;
inline
bool parse_header(http_header_info& body_info, const std::string& m_cache_to_process)
{
LOG_FRAME("http_stream_filter::parse_cached_header(*)", LOG_LEVEL_4);
MTRACE("http_stream_filter::parse_cached_header(*)");
STATIC_REGEXP_EXPR_1(rexp_mach_field,
"\n?((Connection)|(Referer)|(Content-Length)|(Content-Type)|(Transfer-Encoding)|(Content-Encoding)|(Host)|(Cookie)|(User-Agent)"
@ -833,7 +836,7 @@ using namespace std;
}else
{ //Apparently there are no signs of the form of transfer, will receive data until the connection is closed
m_state = reciev_machine_state_error;
LOG_PRINT("Undefinded transfer type, consider http_body_transfer_connection_close method. header: " << m_header_cache, LOG_LEVEL_2);
MERROR("Undefinded transfer type, consider http_body_transfer_connection_close method. header: " << m_header_cache);
return false;
}
return false;

View file

@ -28,6 +28,9 @@
#pragma once
#include "storages/serializeble_struct_helper.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net.http"
namespace epee
{
namespace net_utils

View file

@ -26,6 +26,9 @@
#pragma once
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net.http"
namespace epee
{
namespace net_utils

View file

@ -32,6 +32,9 @@
#include <atlutil.h>
#pragma comment(lib, "Wininet.lib")
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net.http"
namespace epee
{
namespace net_utils

View file

@ -37,6 +37,9 @@
#include "http_auth.h"
#include "http_base.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net.http"
namespace epee
{
namespace net_utils

View file

@ -33,6 +33,9 @@
#include "file_io_utils.h"
#include "net_parse_helpers.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net.http"
#define HTTP_MAX_URI_LEN 9000
#define HTTP_MAX_HEADER_LEN 100000
@ -133,7 +136,7 @@ namespace net_utils
std::string boundary;
if(!match_boundary(content_type, boundary))
{
LOG_PRINT("Failed to match boundary in content type: " << content_type, LOG_LEVEL_0);
MERROR("Failed to match boundary in content type: " << content_type);
return false;
}
@ -155,7 +158,7 @@ namespace net_utils
pos = body.find(boundary, std::distance(body.begin(), it_begin));
if(std::string::npos == pos)
{
LOG_PRINT("Error: Filed to match closing multipart tag", LOG_LEVEL_0);
MERROR("Error: Filed to match closing multipart tag");
it_end = body.end();
}else
{
@ -177,7 +180,7 @@ namespace net_utils
out_values.push_back(multipart_entry());
if(!handle_part_of_multipart(it_begin, it_end, out_values.back()))
{
LOG_PRINT("Failed to handle_part_of_multipart", LOG_LEVEL_0);
MERROR("Failed to handle_part_of_multipart");
return false;
}
@ -331,8 +334,6 @@ namespace net_utils
template<class t_connection_context>
bool simple_http_connection_handler<t_connection_context>::handle_invoke_query_line()
{
LOG_FRAME("simple_http_connection_handler<t_connection_context>::handle_recognize_protocol_out(*)", LOG_LEVEL_3);
STATIC_REGEXP_EXPR_1(rexp_match_command_line, "^(((OPTIONS)|(GET)|(HEAD)|(POST)|(PUT)|(DELETE)|(TRACE)) (\\S+) HTTP/(\\d+).(\\d+))\r?\n", boost::regex::icase | boost::regex::normal);
// 123 4 5 6 7 8 9 10 11 12
//size_t match_len = 0;
@ -379,8 +380,6 @@ namespace net_utils
{
//LOG_PRINT_L4("HTTP HEAD:\r\n" << m_cache.substr(0, pos));
LOG_FRAME("simple_http_connection_handler<t_connection_context>::analize_cached_request_header_and_invoke_state(*)", LOG_LEVEL_3);
m_query_info.m_full_request_buf_size = pos;
m_query_info.m_request_head.assign(m_cache.begin(), m_cache.begin()+pos);
@ -479,8 +478,6 @@ namespace net_utils
template<class t_connection_context>
bool simple_http_connection_handler<t_connection_context>::parse_cached_header(http_header_info& body_info, const std::string& m_cache_to_process, size_t pos)
{
LOG_FRAME("http_stream_filter::parse_cached_header(*)", LOG_LEVEL_3);
STATIC_REGEXP_EXPR_1(rexp_mach_field,
"\n?((Connection)|(Referer)|(Content-Length)|(Content-Type)|(Transfer-Encoding)|(Content-Encoding)|(Host)|(Cookie)|(User-Agent)"
// 12 3 4 5 6 7 8 9 10
@ -576,7 +573,7 @@ namespace net_utils
m_config.m_lock.unlock();
if(!file_io_utils::load_file_to_string(destination_file_path.c_str(), response.m_body))
{
LOG_PRINT("URI \""<< query_info.m_full_request_str.substr(0, query_info.m_full_request_str.size()-2) << "\" [" << destination_file_path << "] Not Found (404 )" , LOG_LEVEL_1);
MWARNING("URI \""<< query_info.m_full_request_str.substr(0, query_info.m_full_request_str.size()-2) << "\" [" << destination_file_path << "] Not Found (404 )");
response.m_body = get_not_found_response_body(query_info.m_URI);
response.m_response_code = 404;
response.m_response_comment = "Not found";
@ -584,7 +581,7 @@ namespace net_utils
return true;
}
LOG_PRINT(" -->> " << query_info.m_full_request_str << "\r\n<<--OK" , LOG_LEVEL_3);
MDEBUG(" -->> " << query_info.m_full_request_str << "\r\n<<--OK");
response.m_response_code = 200;
response.m_response_comment = "OK";
response.m_mime_tipe = get_file_mime_tipe(uri_to_path);

View file

@ -32,6 +32,10 @@
#include "abstract_tcp_server_cp.h"
#include "http_server.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net.http"
namespace epee
{
namespace net_utils

View file

@ -32,6 +32,10 @@
#include "abstract_tcp_server2.h"
#include "http_protocol_handler.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net.http"
namespace epee
{
namespace net_utils

View file

@ -31,6 +31,9 @@
#include "storages/portable_storage.h"
#include "storages/portable_storage_template_helper.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net.http"
#define CHAIN_HTTP_TO_MAP2(context_type) bool handle_http_request(const epee::net_utils::http::http_request_info& query_info, \
epee::net_utils::http::http_response_info& response, \
@ -77,7 +80,7 @@
uint64_t ticks3 = epee::misc_utils::get_tick_count(); \
response_info.m_mime_tipe = "application/json"; \
response_info.m_header_info.m_content_type = " application/json"; \
LOG_PRINT( s_pattern << " processed with " << ticks1-ticks << "/"<< ticks2-ticks1 << "/" << ticks3-ticks2 << "ms", LOG_LEVEL_2); \
MDEBUG( s_pattern << " processed with " << ticks1-ticks << "/"<< ticks2-ticks1 << "/" << ticks3-ticks2 << "ms"); \
}
#define MAP_URI_AUTO_JON2(s_pattern, callback_f, command_type) MAP_URI_AUTO_JON2_IF(s_pattern, callback_f, command_type, true)
@ -104,7 +107,7 @@
uint64_t ticks3 = epee::misc_utils::get_tick_count(); \
response_info.m_mime_tipe = " application/octet-stream"; \
response_info.m_header_info.m_content_type = " application/octet-stream"; \
LOG_PRINT( s_pattern << "() processed with " << ticks1-ticks << "/"<< ticks2-ticks1 << "/" << ticks3-ticks2 << "ms", LOG_LEVEL_2); \
MDEBUG( s_pattern << "() processed with " << ticks1-ticks << "/"<< ticks2-ticks1 << "/" << ticks3-ticks2 << "ms"); \
}
#define CHAIN_URI_MAP2(callback) else {callback(query_info, response_info, m_conn_context);handled = true;}
@ -166,7 +169,7 @@
uint64_t ticks3 = epee::misc_utils::get_tick_count(); \
response_info.m_mime_tipe = "application/json"; \
response_info.m_header_info.m_content_type = " application/json"; \
LOG_PRINT( query_info.m_URI << "[" << method_name << "] processed with " << ticks1-ticks << "/"<< ticks2-ticks1 << "/" << ticks3-ticks2 << "ms", LOG_LEVEL_2);
MDEBUG( query_info.m_URI << "[" << method_name << "] processed with " << ticks1-ticks << "/"<< ticks2-ticks1 << "/" << ticks3-ticks2 << "ms");
#define MAP_JON_RPC_WE_IF(method_name, callback_f, command_type, cond) \
else if((callback_name == method_name) && (cond)) \

View file

@ -36,6 +36,9 @@
#include "net/http_server_cp2.h"
#include "net/http_server_handlers_map2.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net.http"
namespace epee
{
@ -79,15 +82,14 @@ namespace epee
bool run(size_t threads_count, bool wait = true)
{
//go to loop
LOG_PRINT("Run net_service loop( " << threads_count << " threads)...", LOG_LEVEL_0);
_fact_c("net/RPClog", "Run net_service loop( " << threads_count << " threads)...");
MINFO("Run net_service loop( " << threads_count << " threads)...");
if(!m_net_server.run_server(threads_count, wait))
{
LOG_ERROR("Failed to run net tcp server!");
}
if(wait)
LOG_PRINT("net_service loop stopped.", LOG_LEVEL_0);
MINFO("net_service loop stopped.");
return true;
}

View file

@ -30,6 +30,10 @@
//------------------------------------------------------------------------------
//------------------------------------------------------------------------------
#include "string_tools.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net"
namespace epee
{
namespace levin

View file

@ -31,6 +31,9 @@
#include "net_helper.h"
#include "levin_base.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net"
namespace epee
{

View file

@ -31,6 +31,9 @@
#include "levin_base.h"
#include "serializeble_struct_helper.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net"
namespace epee
{
namespace levin

View file

@ -32,6 +32,9 @@
#include <boost/uuid/uuid_generators.hpp>
#include "levin_base.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net"
namespace epee
{
namespace levin
@ -85,7 +88,7 @@ namespace levin
{
if(!m_config.m_pcommands_handler)
{
LOG_ERROR("Command handler not set!");
LOG_ERROR_CC(m_conn_context, "Command handler not set!");
return false;
}
m_cach_in_buffer.append((const char*)ptr, cb);
@ -100,7 +103,7 @@ namespace levin
{
if(m_cach_in_buffer.size() >= sizeof(uint64_t) && *((uint64_t*)m_cach_in_buffer.data()) != LEVIN_SIGNATURE)
{
LOG_ERROR("Signature missmatch on accepted connection");
LOG_ERROR_CC(m_conn_context, "Signature missmatch on accepted connection");
return false;
}
is_continue = false;
@ -110,7 +113,7 @@ namespace levin
bucket_head* phead = (bucket_head*)m_cach_in_buffer.data();
if(LEVIN_SIGNATURE != phead->m_signature)
{
LOG_ERROR("Signature missmatch on accepted connection");
LOG_ERROR_CC(m_conn_context, "Signature missmatch on accepted connection");
return false;
}
m_current_head = *phead;
@ -154,7 +157,7 @@ namespace levin
m_state = conn_state_reading_head;
break;
default:
LOG_ERROR("Undefined state in levin_server_impl::connection_handler, m_state=" << m_state);
LOG_ERROR_CC(m_conn_context, "Undefined state in levin_server_impl::connection_handler, m_state=" << m_state);
return false;
}
}

View file

@ -38,6 +38,8 @@
#include <random>
#include <chrono>
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net"
namespace epee
{
@ -151,7 +153,7 @@ public:
{
if(ec == boost::asio::error::operation_aborted)
return;
LOG_PRINT_CC(con.get_context_ref(), "Timeout on invoke operation happened, command: " << command, LOG_LEVEL_2);
MINFO(con.get_context_ref() << "Timeout on invoke operation happened, command: " << command);
std::string fake;
cb(LEVIN_ERROR_CONNECTION_TIMEDOUT, fake, con.get_context_ref());
con.close();
@ -244,15 +246,15 @@ public:
}
CHECK_AND_ASSERT_MES_NO_RET(0 == boost::interprocess::ipcdetail::atomic_read32(&m_wait_count), "Failed to wait for operation completion. m_wait_count = " << m_wait_count);
LOG_PRINT_CC(m_connection_context, "~async_protocol_handler()", LOG_LEVEL_4);
MTRACE(m_connection_context << "~async_protocol_handler()");
}
bool start_outer_call()
{
LOG_PRINT_CC_L4(m_connection_context, "[levin_protocol] -->> start_outer_call");
MTRACE(m_connection_context << "[levin_protocol] -->> start_outer_call");
if(!m_pservice_endpoint->add_ref())
{
LOG_PRINT_CC_RED(m_connection_context, "[levin_protocol] -->> start_outer_call failed", LOG_LEVEL_4);
MERROR(m_connection_context << "[levin_protocol] -->> start_outer_call failed");
return false;
}
boost::interprocess::ipcdetail::atomic_inc32(&m_wait_count);
@ -260,7 +262,7 @@ public:
}
bool finish_outer_call()
{
LOG_PRINT_CC_L4(m_connection_context, "[levin_protocol] <<-- finish_outer_call");
MTRACE(m_connection_context << "[levin_protocol] <<-- finish_outer_call");
boost::interprocess::ipcdetail::atomic_dec32(&m_wait_count);
m_pservice_endpoint->release();
return true;
@ -316,13 +318,13 @@ public:
if(!m_config.m_pcommands_handler)
{
LOG_ERROR_CC(m_connection_context, "Commands handler not set!");
MERROR(m_connection_context << "Commands handler not set!");
return false;
}
if(m_cache_in_buffer.size() + cb > m_config.m_max_packet_size)
{
LOG_ERROR_CC(m_connection_context, "Maximum packet size exceed!, m_max_packet_size = " << m_config.m_max_packet_size
MWARNING(m_connection_context << "Maximum packet size exceed!, m_max_packet_size = " << m_config.m_max_packet_size
<< ", packet received " << m_cache_in_buffer.size() + cb
<< ", connection will be closed.");
return false;
@ -353,7 +355,7 @@ public:
bool is_response = (m_oponent_protocol_ver == LEVIN_PROTOCOL_VER_1 && m_current_head.m_flags&LEVIN_PACKET_RESPONSE);
LOG_PRINT_CC_L4(m_connection_context, "LEVIN_PACKET_RECIEVED. [len=" << m_current_head.m_cb
MDEBUG(m_connection_context << "LEVIN_PACKET_RECIEVED. [len=" << m_current_head.m_cb
<< ", flags" << m_current_head.m_flags
<< ", r?=" << m_current_head.m_have_to_return_data
<<", cmd = " << m_current_head.m_command
@ -381,7 +383,7 @@ public:
//use sync call scenario
if(!boost::interprocess::ipcdetail::atomic_read32(&m_wait_count) && !boost::interprocess::ipcdetail::atomic_read32(&m_close_called))
{
LOG_ERROR_CC(m_connection_context, "no active invoke when response came, wtf?");
MERROR(m_connection_context << "no active invoke when response came, wtf?");
return false;
}else
{
@ -413,7 +415,7 @@ public:
if(!m_pservice_endpoint->do_send(send_buff.data(), send_buff.size()))
return false;
CRITICAL_REGION_END();
LOG_PRINT_CC_L4(m_connection_context, "LEVIN_PACKET_SENT. [len=" << m_current_head.m_cb
MDEBUG(m_connection_context << "LEVIN_PACKET_SENT. [len=" << m_current_head.m_cb
<< ", flags" << m_current_head.m_flags
<< ", r?=" << m_current_head.m_have_to_return_data
<<", cmd = " << m_current_head.m_command
@ -431,7 +433,7 @@ public:
{
if(m_cache_in_buffer.size() >= sizeof(uint64_t) && *((uint64_t*)m_cache_in_buffer.data()) != LEVIN_SIGNATURE)
{
LOG_ERROR_CC(m_connection_context, "Signature mismatch, connection will be closed");
MWARNING(m_connection_context << "Signature mismatch, connection will be closed");
return false;
}
is_continue = false;
@ -585,7 +587,7 @@ public:
}
CRITICAL_REGION_END();
LOG_PRINT_CC_L4(m_connection_context, "LEVIN_PACKET_SENT. [len=" << head.m_cb
MDEBUG(m_connection_context << "LEVIN_PACKET_SENT. [len=" << head.m_cb
<< ", f=" << head.m_flags
<< ", r?=" << head.m_have_to_return_data
<< ", cmd = " << head.m_command
@ -597,7 +599,7 @@ public:
{
if(misc_utils::get_tick_count() - ticks_start > m_config.m_invoke_timeout)
{
LOG_PRINT_CC_L2(m_connection_context, "invoke timeout (" << m_config.m_invoke_timeout << "), closing connection ");
MWARNING(m_connection_context << "invoke timeout (" << m_config.m_invoke_timeout << "), closing connection ");
close();
return LEVIN_ERROR_CONNECTION_TIMEDOUT;
}
@ -650,7 +652,7 @@ public:
return -1;
}
CRITICAL_REGION_END();
LOG_PRINT_CC_L4(m_connection_context, "LEVIN_PACKET_SENT. [len=" << head.m_cb <<
LOG_DEBUG_CC(m_connection_context, "LEVIN_PACKET_SENT. [len=" << head.m_cb <<
", f=" << head.m_flags <<
", r?=" << head.m_have_to_return_data <<
", cmd = " << head.m_command <<

View file

@ -46,6 +46,9 @@
//#include "profile_tools.h"
#include "../string_tools.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net"
#ifndef MAKE_IP
#define MAKE_IP( a1, a2, a3, a4 ) (a1|(a2<<8)|(a3<<16)|(a4<<24))
#endif
@ -180,19 +183,19 @@ namespace net_utils
return true;
}else
{
LOG_PRINT("Some problems at connect, message: " << ec.message(), LOG_LEVEL_3);
MWARNING("Some problems at connect, message: " << ec.message());
return false;
}
}
catch(const boost::system::system_error& er)
{
LOG_PRINT("Some problems at connect, message: " << er.what(), LOG_LEVEL_4);
MDEBUG("Some problems at connect, message: " << er.what());
return false;
}
catch(...)
{
LOG_PRINT("Some fatal problems.", LOG_LEVEL_4);
MDEBUG("Some fatal problems.");
return false;
}
@ -387,20 +390,20 @@ namespace net_utils
if (ec)
{
LOG_PRINT_L4("READ ENDS: Connection err_code " << ec.value());
MTRACE("READ ENDS: Connection err_code " << ec.value());
if(ec == boost::asio::error::eof)
{
LOG_PRINT_L4("Connection err_code eof.");
MTRACE("Connection err_code eof.");
//connection closed there, empty
return true;
}
LOG_PRINT_L3("Problems at read: " << ec.message());
MDEBUG("Problems at read: " << ec.message());
m_connected = false;
return false;
}else
{
LOG_PRINT_L4("READ ENDS: Success. bytes_tr: " << bytes_transfered);
MTRACE("READ ENDS: Success. bytes_tr: " << bytes_transfered);
m_deadline.expires_at(boost::posix_time::pos_infin);
}

View file

@ -31,6 +31,8 @@
#include "http_base.h"
#include "reg_exp_definer.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net"
namespace epee
{

View file

@ -31,6 +31,10 @@
#include <boost/uuid/uuid.hpp>
#include "string_tools.h"
#include "misc_log_ex.h"
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net"
#ifndef MAKE_IP
#define MAKE_IP( a1, a2, a3, a4 ) (a1|(a2<<8)|(a3<<16)|(a4<<24))
@ -142,20 +146,24 @@ namespace net_utils
return ss.str();
}
#define LOG_PRINT_CC(ct, message, log_level) LOG_PRINT("[" << epee::net_utils::print_connection_context_short(ct) << "]" << message, log_level)
#define LOG_PRINT_CC_GREEN(ct, message, log_level) LOG_PRINT_GREEN("[" << epee::net_utils::print_connection_context_short(ct) << "]" << message, log_level)
#define LOG_PRINT_CC_RED(ct, message, log_level) LOG_PRINT_RED("[" << epee::net_utils::print_connection_context_short(ct) << "]" << message, log_level)
#define LOG_PRINT_CC_BLUE(ct, message, log_level) LOG_PRINT_BLUE("[" << epee::net_utils::print_connection_context_short(ct) << "]" << message, log_level)
#define LOG_PRINT_CC_YELLOW(ct, message, log_level) LOG_PRINT_YELLOW("[" << epee::net_utils::print_connection_context_short(ct) << "]" << message, log_level)
#define LOG_PRINT_CC_CYAN(ct, message, log_level) LOG_PRINT_CYAN("[" << epee::net_utils::print_connection_context_short(ct) << "]" << message, log_level)
#define LOG_PRINT_CC_MAGENTA(ct, message, log_level) LOG_PRINT_MAGENTA("[" << epee::net_utils::print_connection_context_short(ct) << "]" << message, log_level)
#define LOG_ERROR_CC(ct, message) LOG_PRINT_RED("[" << epee::net_utils::print_connection_context_short(ct) << "]" << message, LOG_LEVEL_2)
inline MAKE_LOGGABLE(connection_context_base, ct, os)
{
os << "[" << epee::net_utils::print_connection_context_short(ct) << "] ";
return os;
}
#define LOG_PRINT_CC_L0(ct, message) LOG_PRINT_L0("[" << epee::net_utils::print_connection_context_short(ct) << "]" << message)
#define LOG_PRINT_CC_L1(ct, message) LOG_PRINT_L1("[" << epee::net_utils::print_connection_context_short(ct) << "]" << message)
#define LOG_PRINT_CC_L2(ct, message) LOG_PRINT_L2("[" << epee::net_utils::print_connection_context_short(ct) << "]" << message)
#define LOG_PRINT_CC_L3(ct, message) LOG_PRINT_L3("[" << epee::net_utils::print_connection_context_short(ct) << "]" << message)
#define LOG_PRINT_CC_L4(ct, message) LOG_PRINT_L4("[" << epee::net_utils::print_connection_context_short(ct) << "]" << message)
#define LOG_ERROR_CC(ct, message) MERROR(ct << message)
#define LOG_WARNING_CC(ct, message) MWARNING(ct << message)
#define LOG_INFO_CC(ct, message) MINFO(ct << message)
#define LOG_DEBUG_CC(ct, message) MDEBUG(ct << message)
#define LOG_TRACE_CC(ct, message) MTRACE(ct << message)
#define LOG_CC(level, ct, message) MLOG(level, ct << message)
#define LOG_PRINT_CC_L0(ct, message) LOG_PRINT_L0(epee::net_utils::print_connection_context_short(ct) << message)
#define LOG_PRINT_CC_L1(ct, message) LOG_PRINT_L1(epee::net_utils::print_connection_context_short(ct) << message)
#define LOG_PRINT_CC_L2(ct, message) LOG_PRINT_L2(epee::net_utils::print_connection_context_short(ct) << message)
#define LOG_PRINT_CC_L3(ct, message) LOG_PRINT_L3(epee::net_utils::print_connection_context_short(ct) << message)
#define LOG_PRINT_CC_L4(ct, message) LOG_PRINT_L4(epee::net_utils::print_connection_context_short(ct) << message)
#define LOG_PRINT_CCONTEXT_L0(message) LOG_PRINT_CC_L0(context, message)
#define LOG_PRINT_CCONTEXT_L1(message) LOG_PRINT_CC_L1(context, message)
@ -163,13 +171,6 @@ namespace net_utils
#define LOG_PRINT_CCONTEXT_L3(message) LOG_PRINT_CC_L3(context, message)
#define LOG_ERROR_CCONTEXT(message) LOG_ERROR_CC(context, message)
#define LOG_PRINT_CCONTEXT_GREEN(message, log_level) LOG_PRINT_CC_GREEN(context, message, log_level)
#define LOG_PRINT_CCONTEXT_RED(message, log_level) LOG_PRINT_CC_RED(context, message, log_level)
#define LOG_PRINT_CCONTEXT_BLUE(message, log_level) LOG_PRINT_CC_BLUE(context, message, log_level)
#define LOG_PRINT_CCONTEXT_YELLOW(message, log_level) LOG_PRINT_CC_YELLOW(context, message, log_level)
#define LOG_PRINT_CCONTEXT_CYAN(message, log_level) LOG_PRINT_CC_CYAN(context, message, log_level)
#define LOG_PRINT_CCONTEXT_MAGENTA(message, log_level) LOG_PRINT_CC_MAGENTA(context, message, log_level)
#define CHECK_AND_ASSERT_MES_CC(condition, return_val, err_message) CHECK_AND_ASSERT_MES(condition, return_val, "[" << epee::net_utils::print_connection_context_short(context) << "]" << err_message)
}