2015-01-05 19:30:17 +00:00
/// @file
/// @author rfree (current maintainer/user in monero.cc project - most of code is from CryptoNote)
/// @brief This is the orginal cryptonote protocol network-events handler, modified by us
2017-02-21 17:38:18 +00:00
// Copyright (c) 2014-2017, The Monero Project
2015-12-14 04:54:39 +00:00
//
2014-07-23 13:03:52 +00:00
// All rights reserved.
2015-12-14 04:54:39 +00:00
//
2014-07-23 13:03:52 +00:00
// Redistribution and use in source and binary forms, with or without modification, are
// permitted provided that the following conditions are met:
2015-12-14 04:54:39 +00:00
//
2014-07-23 13:03:52 +00:00
// 1. Redistributions of source code must retain the above copyright notice, this list of
// conditions and the following disclaimer.
2015-12-14 04:54:39 +00:00
//
2014-07-23 13:03:52 +00:00
// 2. Redistributions in binary form must reproduce the above copyright notice, this list
// of conditions and the following disclaimer in the documentation and/or other
// materials provided with the distribution.
2015-12-14 04:54:39 +00:00
//
2014-07-23 13:03:52 +00:00
// 3. Neither the name of the copyright holder nor the names of its contributors may be
// used to endorse or promote products derived from this software without specific
// prior written permission.
2015-12-14 04:54:39 +00:00
//
2014-07-23 13:03:52 +00:00
// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS" AND ANY
// EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES OF
// MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL
// THE COPYRIGHT HOLDER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO,
// PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
// INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT,
// STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF
// THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
2015-12-14 04:54:39 +00:00
//
2014-07-23 13:03:52 +00:00
// Parts of this file are originally copyright (c) 2012-2013 The Cryptonote developers
2014-03-03 22:07:58 +00:00
2015-01-05 19:30:17 +00:00
// (may contain code and/or modifications by other developers)
// developer rfree: this code is caller of our new network code, and is modded; e.g. for rate limiting
2014-03-03 22:07:58 +00:00
#include <boost/interprocess/detail/atomic.hpp>
2014-07-18 23:33:03 +00:00
#include <list>
2016-10-26 19:00:08 +00:00
#include <unordered_map>
2014-07-18 23:33:03 +00:00
2017-01-26 15:07:23 +00:00
#include "cryptonote_basic/cryptonote_format_utils.h"
2014-03-03 22:07:58 +00:00
#include "profile_tools.h"
2015-02-12 19:59:39 +00:00
#include "../../src/p2p/network_throttle-detail.hpp"
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.
2017-01-01 16:34:23 +00:00
#undef MONERO_DEFAULT_LOG_CATEGORY
#define MONERO_DEFAULT_LOG_CATEGORY "net.cn"
2015-01-05 19:30:17 +00:00
2017-01-22 10:14:45 +00:00
#define MLOG_P2P_MESSAGE(x) MCINFO("net.p2p.msg", context << x)
2014-03-03 22:07:58 +00:00
namespace cryptonote
{
2015-01-05 19:30:17 +00:00
2015-12-14 04:54:39 +00:00
//-----------------------------------------------------------------------------------------------------------------------
2014-03-03 22:07:58 +00:00
template<class t_core>
2015-12-14 04:54:39 +00:00
t_cryptonote_protocol_handler<t_core>::t_cryptonote_protocol_handler(t_core& rcore, nodetool::i_p2p_endpoint<connection_context>* p_net_layout):m_core(rcore),
2014-03-03 22:07:58 +00:00
m_p2p(p_net_layout),
m_syncronized_connections_count(0),
2016-12-04 12:27:45 +00:00
m_synchronized(false),
m_stopping(false)
2014-03-03 22:07:58 +00:00
{
if(!m_p2p)
m_p2p = &m_p2p_stub;
}
//-----------------------------------------------------------------------------------------------------------------------
2015-12-14 04:54:39 +00:00
template<class t_core>
2014-03-03 22:07:58 +00:00
bool t_cryptonote_protocol_handler<t_core>::init(const boost::program_options::variables_map& vm)
{
return true;
}
2015-12-14 04:54:39 +00:00
//------------------------------------------------------------------------------------------------------------------------
template<class t_core>
2014-03-03 22:07:58 +00:00
bool t_cryptonote_protocol_handler<t_core>::deinit()
{
return true;
}
2015-12-14 04:54:39 +00:00
//------------------------------------------------------------------------------------------------------------------------
template<class t_core>
2014-03-03 22:07:58 +00:00
void t_cryptonote_protocol_handler<t_core>::set_p2p_endpoint(nodetool::i_p2p_endpoint<connection_context>* p2p)
{
if(p2p)
m_p2p = p2p;
else
m_p2p = &m_p2p_stub;
}
2015-12-14 04:54:39 +00:00
//------------------------------------------------------------------------------------------------------------------------
template<class t_core>
2014-03-03 22:07:58 +00:00
bool t_cryptonote_protocol_handler<t_core>::on_callback(cryptonote_connection_context& context)
{
LOG_PRINT_CCONTEXT_L2("callback fired");
CHECK_AND_ASSERT_MES_CC( context.m_callback_request_count > 0, false, "false callback fired, but context.m_callback_request_count=" << context.m_callback_request_count);
--context.m_callback_request_count;
if(context.m_state == cryptonote_connection_context::state_synchronizing)
{
NOTIFY_REQUEST_CHAIN::request r = boost::value_initialized<NOTIFY_REQUEST_CHAIN::request>();
m_core.get_short_chain_history(r.block_ids);
LOG_PRINT_CCONTEXT_L2("-->>NOTIFY_REQUEST_CHAIN: m_block_ids.size()=" << r.block_ids.size() );
post_notify<NOTIFY_REQUEST_CHAIN>(r, context);
}
return true;
}
//------------------------------------------------------------------------------------------------------------------------
2015-12-14 04:54:39 +00:00
template<class t_core>
2014-03-03 22:07:58 +00:00
bool t_cryptonote_protocol_handler<t_core>::get_stat_info(core_stat_info& stat_inf)
{
return m_core.get_stat_info(stat_inf);
}
2015-12-14 04:54:39 +00:00
//------------------------------------------------------------------------------------------------------------------------
template<class t_core>
2014-03-20 11:46:11 +00:00
void t_cryptonote_protocol_handler<t_core>::log_connections()
{
std::stringstream ss;
2015-02-12 19:59:39 +00:00
ss.precision(1);
2015-12-14 04:54:39 +00:00
double down_sum = 0.0;
double down_curr_sum = 0.0;
double up_sum = 0.0;
double up_curr_sum = 0.0;
2014-03-20 11:46:11 +00:00
2015-01-05 19:30:17 +00:00
ss << std::setw(30) << std::left << "Remote Host"
2014-03-20 11:46:11 +00:00
<< std::setw(20) << "Peer id"
2016-10-26 19:00:08 +00:00
<< std::setw(20) << "Support Flags"
2015-02-12 19:59:39 +00:00
<< std::setw(30) << "Recv/Sent (inactive,sec)"
2014-03-20 11:46:11 +00:00
<< std::setw(25) << "State"
2015-02-12 19:59:39 +00:00
<< std::setw(20) << "Livetime(sec)"
<< std::setw(12) << "Down (kB/s)"
<< std::setw(14) << "Down(now)"
2015-12-14 04:54:39 +00:00
<< std::setw(10) << "Up (kB/s)"
2015-02-12 19:59:39 +00:00
<< std::setw(13) << "Up(now)"
<< ENDL;
2014-03-20 11:46:11 +00:00
2015-12-14 04:54:39 +00:00
uint32_t ip;
2016-10-26 19:00:08 +00:00
m_p2p->for_each_connection([&](const connection_context& cntxt, nodetool::peerid_type peer_id, uint32_t support_flags)
2014-03-20 11:46:11 +00:00
{
2015-12-14 04:54:39 +00:00
bool local_ip = false;
ip = ntohl(cntxt.m_remote_ip);
// TODO: local ip in calss A, B
if (ip > 3232235520 && ip < 3232301055) // 192.168.x.x
local_ip = true;
auto connection_time = time(NULL) - cntxt.m_started;
2015-01-05 19:30:17 +00:00
ss << std::setw(30) << std::left << std::string(cntxt.m_is_income ? " [INC]":"[OUT]") +
epee::string_tools::get_ip_string_from_int32(cntxt.m_remote_ip) + ":" + std::to_string(cntxt.m_remote_port)
2014-03-20 11:46:11 +00:00
<< std::setw(20) << std::hex << peer_id
2016-10-26 19:00:08 +00:00
<< std::setw(20) << std::hex << support_flags
2015-02-12 19:59:39 +00:00
<< std::setw(30) << std::to_string(cntxt.m_recv_cnt)+ "(" + std::to_string(time(NULL) - cntxt.m_last_recv) + ")" + "/" + std::to_string(cntxt.m_send_cnt) + "(" + std::to_string(time(NULL) - cntxt.m_last_send) + ")"
2014-03-20 11:46:11 +00:00
<< std::setw(25) << get_protocol_state_string(cntxt.m_state)
2015-01-05 19:30:17 +00:00
<< std::setw(20) << std::to_string(time(NULL) - cntxt.m_started)
2015-02-12 19:59:39 +00:00
<< std::setw(12) << std::fixed << (connection_time == 0 ? 0.0 : cntxt.m_recv_cnt / connection_time / 1024)
<< std::setw(14) << std::fixed << cntxt.m_current_speed_down / 1024
<< 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]" : "")
2015-02-20 21:28:03 +00:00
<< std::left << (ip == LOCALHOST_INT ? "[LOCALHOST]" : "") // 127.0.0.1
2015-02-12 19:59:39 +00:00
<< ENDL;
2015-12-14 04:54:39 +00:00
if (connection_time > 1)
{
down_sum += (cntxt.m_recv_cnt / connection_time / 1024);
up_sum += (cntxt.m_send_cnt / connection_time / 1024);
}
down_curr_sum += (cntxt.m_current_speed_down / 1024);
up_curr_sum += (cntxt.m_current_speed_up / 1024);
2014-03-20 11:46:11 +00:00
return true;
});
2015-12-14 04:54:39 +00:00
ss << ENDL
<< std::setw(125) << " "
<< std::setw(12) << down_sum
<< std::setw(14) << down_curr_sum
<< std::setw(10) << up_sum
<< std::setw(13) << up_curr_sum
<< ENDL;
LOG_PRINT_L0("Connections: " << ENDL << ss.str());
2014-03-20 11:46:11 +00:00
}
2015-12-14 04:54:39 +00:00
//------------------------------------------------------------------------------------------------------------------------
2014-07-18 23:33:03 +00:00
// Returns a list of connection_info objects describing each open p2p connection
2015-12-14 04:54:39 +00:00
//------------------------------------------------------------------------------------------------------------------------
2014-07-18 23:33:03 +00:00
template<class t_core>
std::list<connection_info> t_cryptonote_protocol_handler<t_core>::get_connections()
{
std::list<connection_info> connections;
2016-10-26 19:00:08 +00:00
m_p2p->for_each_connection([&](const connection_context& cntxt, nodetool::peerid_type peer_id, uint32_t support_flags)
2014-07-18 23:33:03 +00:00
{
connection_info cnx;
auto timestamp = time(NULL);
cnx.incoming = cntxt.m_is_income ? true : false;
cnx.ip = epee::string_tools::get_ip_string_from_int32(cntxt.m_remote_ip);
cnx.port = std::to_string(cntxt.m_remote_port);
std::stringstream peer_id_str;
peer_id_str << std::hex << peer_id;
peer_id_str >> cnx.peer_id;
2016-10-26 19:00:08 +00:00
cnx.support_flags = support_flags;
2014-07-18 23:33:03 +00:00
cnx.recv_count = cntxt.m_recv_cnt;
cnx.recv_idle_time = timestamp - cntxt.m_last_recv;
cnx.send_count = cntxt.m_send_cnt;
cnx.send_idle_time = timestamp;
cnx.state = get_protocol_state_string(cntxt.m_state);
cnx.live_time = timestamp - cntxt.m_started;
2015-12-14 04:54:39 +00:00
2015-04-01 17:00:45 +00:00
uint32_t ip;
2015-12-14 04:54:39 +00:00
ip = ntohl(cntxt.m_remote_ip);
if (ip == LOCALHOST_INT)
{
cnx.localhost = true;
}
else
{
cnx.localhost = false;
}
2015-04-01 17:00:45 +00:00
if (ip > 3232235520 && ip < 3232301055) // 192.168.x.x
{
2015-12-14 04:54:39 +00:00
cnx.local_ip = true;
}
else
{
cnx.local_ip = false;
}
auto connection_time = time(NULL) - cntxt.m_started;
if (connection_time == 0)
{
cnx.avg_download = 0;
cnx.avg_upload = 0;
}
else
{
cnx.avg_download = cntxt.m_recv_cnt / connection_time / 1024;
cnx.avg_upload = cntxt.m_send_cnt / connection_time / 1024;
}
cnx.current_download = cntxt.m_current_speed_down / 1024;
cnx.current_upload = cntxt.m_current_speed_up / 1024;
2014-07-18 23:33:03 +00:00
connections.push_back(cnx);
return true;
});
return connections;
}
2014-03-20 11:46:11 +00:00
//------------------------------------------------------------------------------------------------------------------------
2015-12-14 04:54:39 +00:00
template<class t_core>
2014-03-03 22:07:58 +00:00
bool t_cryptonote_protocol_handler<t_core>::process_payload_sync_data(const CORE_SYNC_DATA& hshd, cryptonote_connection_context& context, bool is_inital)
{
if(context.m_state == cryptonote_connection_context::state_befor_handshake && !is_inital)
return true;
if(context.m_state == cryptonote_connection_context::state_synchronizing)
return true;
2017-02-15 14:38:38 +00:00
uint64_t target = m_core.get_target_blockchain_height();
2017-02-24 00:29:47 +00:00
if (target == 0)
target = m_core.get_current_blockchain_height();
2016-09-25 18:08:31 +00:00
if(m_core.have_block(hshd.top_id))
2014-03-03 22:07:58 +00:00
{
context.m_state = cryptonote_connection_context::state_normal;
2017-02-15 14:38:38 +00:00
if(is_inital && target == m_core.get_current_blockchain_height())
2014-03-03 22:07:58 +00:00
on_connection_synchronized();
return true;
}
2017-02-15 14:38:38 +00:00
if (hshd.current_height > target)
{
2015-12-14 04:54:39 +00:00
/* As I don't know if accessing hshd from core could be a good practice,
2014-06-04 20:50:13 +00:00
I prefer pushing target height to the core at the same time it is pushed to the user.
Nz. */
2014-06-04 21:10:33 +00:00
m_core.set_target_blockchain_height(static_cast<int64_t>(hshd.current_height));
2014-05-25 17:06:40 +00:00
int64_t diff = static_cast<int64_t>(hshd.current_height) - static_cast<int64_t>(m_core.get_current_blockchain_height());
2016-08-29 20:13:27 +00:00
int64_t max_block_height = max(static_cast<int64_t>(hshd.current_height),static_cast<int64_t>(m_core.get_current_blockchain_height()));
int64_t last_block_v1 = 1009826;
int64_t diff_v2 = max_block_height > last_block_v1 ? min(abs(diff), max_block_height - last_block_v1) : 0;
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.
2017-01-01 16:34:23 +00:00
MCLOG(is_inital ? el::Level::Info : el::Level::Debug, "global", context << "Sync data returned a new top block candidate: " << m_core.get_current_blockchain_height() << " -> " << hshd.current_height
2016-12-12 23:24:40 +00:00
<< " [Your node is " << std::abs(diff) << " blocks (" << ((abs(diff) - diff_v2) / (24 * 60 * 60 / DIFFICULTY_TARGET_V1)) + (diff_v2 / (24 * 60 * 60 / DIFFICULTY_TARGET_V2)) << " days) "
2014-05-25 17:06:40 +00:00
<< (0 <= diff ? std::string("behind") : std::string("ahead"))
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.
2017-01-01 16:34:23 +00:00
<< "] " << ENDL << "SYNCHRONIZATION started");
2017-02-15 14:38:38 +00:00
}
2016-03-20 12:35:53 +00:00
LOG_PRINT_L1("Remote blockchain height: " << hshd.current_height << ", id: " << hshd.top_id);
2014-03-03 22:07:58 +00:00
context.m_state = cryptonote_connection_context::state_synchronizing;
context.m_remote_blockchain_height = hshd.current_height;
//let the socket to send response to handshake, but request callback, to let send request data after response
LOG_PRINT_CCONTEXT_L2("requesting callback");
++context.m_callback_request_count;
m_p2p->request_callback(context);
return true;
}
2015-12-14 04:54:39 +00:00
//------------------------------------------------------------------------------------------------------------------------
template<class t_core>
2014-03-03 22:07:58 +00:00
bool t_cryptonote_protocol_handler<t_core>::get_payload_sync_data(CORE_SYNC_DATA& hshd)
{
m_core.get_blockchain_top(hshd.current_height, hshd.top_id);
hshd.current_height +=1;
return true;
}
2015-12-14 04:54:39 +00:00
//------------------------------------------------------------------------------------------------------------------------
template<class t_core>
2014-03-03 22:07:58 +00:00
bool t_cryptonote_protocol_handler<t_core>::get_payload_sync_data(blobdata& data)
{
CORE_SYNC_DATA hsd = boost::value_initialized<CORE_SYNC_DATA>();
get_payload_sync_data(hsd);
epee::serialization::store_t_to_binary(hsd, data);
return true;
}
2015-12-14 04:54:39 +00:00
//------------------------------------------------------------------------------------------------------------------------
template<class t_core>
2014-03-03 22:07:58 +00:00
int t_cryptonote_protocol_handler<t_core>::handle_notify_new_block(int command, NOTIFY_NEW_BLOCK::request& arg, cryptonote_connection_context& context)
{
2017-01-22 10:14:45 +00:00
MLOG_P2P_MESSAGE("Received NOTIFY_NEW_BLOCK (hop " << arg.hop << ", " << arg.b.txs.size() << " txes)");
2014-03-03 22:07:58 +00:00
if(context.m_state != cryptonote_connection_context::state_normal)
return 1;
2015-07-10 21:39:12 +00:00
m_core.pause_mine();
std::list<block_complete_entry> blocks;
blocks.push_back(arg.b);
m_core.prepare_handle_incoming_blocks(blocks);
2014-03-03 22:07:58 +00:00
for(auto tx_blob_it = arg.b.txs.begin(); tx_blob_it!=arg.b.txs.end();tx_blob_it++)
{
cryptonote::tx_verification_context tvc = AUTO_VAL_INIT(tvc);
2017-01-14 13:01:21 +00:00
m_core.handle_incoming_tx(*tx_blob_it, tvc, true, true, false);
2014-03-03 22:07:58 +00:00
if(tvc.m_verifivation_failed)
{
2014-09-09 09:32:00 +00:00
LOG_PRINT_CCONTEXT_L1("Block verification failed: transaction verification failed, dropping connection");
2014-03-03 22:07:58 +00:00
m_p2p->drop_connection(context);
** CHANGES ARE EXPERIMENTAL (FOR TESTING ONLY)
Bockchain:
1. Optim: Multi-thread long-hash computation when encountering groups of blocks.
2. Optim: Cache verified txs and return result from cache instead of re-checking whenever possible.
3. Optim: Preload output-keys when encoutering groups of blocks. Sort by amount and global-index before bulk querying database and multi-thread when possible.
4. Optim: Disable double spend check on block verification, double spend is already detected when trying to add blocks.
5. Optim: Multi-thread signature computation whenever possible.
6. Patch: Disable locking (recursive mutex) on called functions from check_tx_inputs which causes slowdowns (only seems to happen on ubuntu/VMs??? Reason: TBD)
7. Optim: Removed looped full-tx hash computation when retrieving transactions from pool (???).
8. Optim: Cache difficulty/timestamps (735 blocks) for next-difficulty calculations so that only 2 db reads per new block is needed when a new block arrives (instead of 1470 reads).
Berkeley-DB:
1. Fix: 32-bit data errors causing wrong output global indices and failure to send blocks to peers (etc).
2. Fix: Unable to pop blocks on reorganize due to transaction errors.
3. Patch: Large number of transaction aborts when running multi-threaded bulk queries.
4. Patch: Insufficient locks error when running full sync.
5. Patch: Incorrect db stats when returning from an immediate exit from "pop block" operation.
6. Optim: Add bulk queries to get output global indices.
7. Optim: Modified output_keys table to store public_key+unlock_time+height for single transaction lookup (vs 3)
8. Optim: Used output_keys table retrieve public_keys instead of going through output_amounts->output_txs+output_indices->txs->output:public_key
9. Optim: Added thread-safe buffers used when multi-threading bulk queries.
10. Optim: Added support for nosync/write_nosync options for improved performance (*see --db-sync-mode option for details)
11. Mod: Added checkpoint thread and auto-remove-logs option.
12. *Now usable on 32-bit systems like RPI2.
LMDB:
1. Optim: Added custom comparison for 256-bit key tables (minor speed-up, TBD: get actual effect)
2. Optim: Modified output_keys table to store public_key+unlock_time+height for single transaction lookup (vs 3)
3. Optim: Used output_keys table retrieve public_keys instead of going through output_amounts->output_txs+output_indices->txs->output:public_key
4. Optim: Added support for sync/writemap options for improved performance (*see --db-sync-mode option for details)
5. Mod: Auto resize to +1GB instead of multiplier x1.5
ETC:
1. Minor optimizations for slow-hash for ARM (RPI2). Incomplete.
2. Fix: 32-bit saturation bug when computing next difficulty on large blocks.
[PENDING ISSUES]
1. Berkely db has a very slow "pop-block" operation. This is very noticeable on the RPI2 as it sometimes takes > 10 MINUTES to pop a block during reorganization.
This does not happen very often however, most reorgs seem to take a few seconds but it possibly depends on the number of outputs present. TBD.
2. Berkeley db, possible bug "unable to allocate memory". TBD.
[NEW OPTIONS] (*Currently all enabled for testing purposes)
1. --fast-block-sync arg=[0:1] (default: 1)
a. 0 = Compute long hash per block (may take a while depending on CPU)
b. 1 = Skip long-hash and verify blocks based on embedded known good block hashes (faster, minimal CPU dependence)
2. --db-sync-mode arg=[[safe|fast|fastest]:[sync|async]:[nblocks_per_sync]] (default: fastest:async:1000)
a. safe = fdatasync/fsync (or equivalent) per stored block. Very slow, but safest option to protect against power-out/crash conditions.
b. fast/fastest = Enables asynchronous fdatasync/fsync (or equivalent). Useful for battery operated devices or STABLE systems with UPS and/or systems with battery backed write cache/solid state cache.
Fast - Write meta-data but defer data flush.
Fastest - Defer meta-data and data flush.
Sync - Flush data after nblocks_per_sync and wait.
Async - Flush data after nblocks_per_sync but do not wait for the operation to finish.
3. --prep-blocks-threads arg=[n] (default: 4 or system max threads, whichever is lower)
Max number of threads to use when computing long-hash in groups.
4. --show-time-stats arg=[0:1] (default: 1)
Show benchmark related time stats.
5. --db-auto-remove-logs arg=[0:1] (default: 1)
For berkeley-db only. Auto remove logs if enabled.
**Note: lmdb and berkeley-db have changes to the tables and are not compatible with official git head version.
At the moment, you need a full resync to use this optimized version.
[PERFORMANCE COMPARISON]
**Some figures are approximations only.
Using a baseline machine of an i7-2600K+SSD+(with full pow computation):
1. The optimized lmdb/blockhain core can process blocks up to 585K for ~1.25 hours + download time, so it usually takes 2.5 hours to sync the full chain.
2. The current head with memory can process blocks up to 585K for ~4.2 hours + download time, so it usually takes 5.5 hours to sync the full chain.
3. The current head with lmdb can process blocks up to 585K for ~32 hours + download time and usually takes 36 hours to sync the full chain.
Averate procesing times (with full pow computation):
lmdb-optimized:
1. tx_ave = 2.5 ms / tx
2. block_ave = 5.87 ms / block
memory-official-repo:
1. tx_ave = 8.85 ms / tx
2. block_ave = 19.68 ms / block
lmdb-official-repo (0f4a036437fd41a5498ee5e74e2422ea6177aa3e)
1. tx_ave = 47.8 ms / tx
2. block_ave = 64.2 ms / block
**Note: The following data denotes processing times only (does not include p2p download time)
lmdb-optimized processing times (with full pow computation):
1. Desktop, Quad-core / 8-threads 2600k (8Mb) - 1.25 hours processing time (--db-sync-mode=fastest:async:1000).
2. Laptop, Dual-core / 4-threads U4200 (3Mb) - 4.90 hours processing time (--db-sync-mode=fastest:async:1000).
3. Embedded, Quad-core / 4-threads Z3735F (2x1Mb) - 12.0 hours processing time (--db-sync-mode=fastest:async:1000).
lmdb-optimized processing times (with per-block-checkpoint)
1. Desktop, Quad-core / 8-threads 2600k (8Mb) - 10 minutes processing time (--db-sync-mode=fastest:async:1000).
berkeley-db optimized processing times (with full pow computation)
1. Desktop, Quad-core / 8-threads 2600k (8Mb) - 1.8 hours processing time (--db-sync-mode=fastest:async:1000).
2. RPI2. Improved from estimated 3 months(???) into 2.5 days (*Need 2AMP supply + Clock:1Ghz + [usb+ssd] to achieve this speed) (--db-sync-mode=fastest:async:1000).
berkeley-db optimized processing times (with per-block-checkpoint)
1. RPI2. 12-15 hours (*Need 2AMP supply + Clock:1Ghz + [usb+ssd] to achieve this speed) (--db-sync-mode=fastest:async:1000).
2015-07-10 20:09:32 +00:00
m_core.cleanup_handle_incoming_blocks();
2015-07-10 21:39:12 +00:00
m_core.resume_mine();
2014-03-03 22:07:58 +00:00
return 1;
}
}
block_verification_context bvc = boost::value_initialized<block_verification_context>();
2015-12-14 04:54:39 +00:00
m_core.handle_incoming_block(arg.b.block, bvc); // got block from handle_notify_new_block
** CHANGES ARE EXPERIMENTAL (FOR TESTING ONLY)
Bockchain:
1. Optim: Multi-thread long-hash computation when encountering groups of blocks.
2. Optim: Cache verified txs and return result from cache instead of re-checking whenever possible.
3. Optim: Preload output-keys when encoutering groups of blocks. Sort by amount and global-index before bulk querying database and multi-thread when possible.
4. Optim: Disable double spend check on block verification, double spend is already detected when trying to add blocks.
5. Optim: Multi-thread signature computation whenever possible.
6. Patch: Disable locking (recursive mutex) on called functions from check_tx_inputs which causes slowdowns (only seems to happen on ubuntu/VMs??? Reason: TBD)
7. Optim: Removed looped full-tx hash computation when retrieving transactions from pool (???).
8. Optim: Cache difficulty/timestamps (735 blocks) for next-difficulty calculations so that only 2 db reads per new block is needed when a new block arrives (instead of 1470 reads).
Berkeley-DB:
1. Fix: 32-bit data errors causing wrong output global indices and failure to send blocks to peers (etc).
2. Fix: Unable to pop blocks on reorganize due to transaction errors.
3. Patch: Large number of transaction aborts when running multi-threaded bulk queries.
4. Patch: Insufficient locks error when running full sync.
5. Patch: Incorrect db stats when returning from an immediate exit from "pop block" operation.
6. Optim: Add bulk queries to get output global indices.
7. Optim: Modified output_keys table to store public_key+unlock_time+height for single transaction lookup (vs 3)
8. Optim: Used output_keys table retrieve public_keys instead of going through output_amounts->output_txs+output_indices->txs->output:public_key
9. Optim: Added thread-safe buffers used when multi-threading bulk queries.
10. Optim: Added support for nosync/write_nosync options for improved performance (*see --db-sync-mode option for details)
11. Mod: Added checkpoint thread and auto-remove-logs option.
12. *Now usable on 32-bit systems like RPI2.
LMDB:
1. Optim: Added custom comparison for 256-bit key tables (minor speed-up, TBD: get actual effect)
2. Optim: Modified output_keys table to store public_key+unlock_time+height for single transaction lookup (vs 3)
3. Optim: Used output_keys table retrieve public_keys instead of going through output_amounts->output_txs+output_indices->txs->output:public_key
4. Optim: Added support for sync/writemap options for improved performance (*see --db-sync-mode option for details)
5. Mod: Auto resize to +1GB instead of multiplier x1.5
ETC:
1. Minor optimizations for slow-hash for ARM (RPI2). Incomplete.
2. Fix: 32-bit saturation bug when computing next difficulty on large blocks.
[PENDING ISSUES]
1. Berkely db has a very slow "pop-block" operation. This is very noticeable on the RPI2 as it sometimes takes > 10 MINUTES to pop a block during reorganization.
This does not happen very often however, most reorgs seem to take a few seconds but it possibly depends on the number of outputs present. TBD.
2. Berkeley db, possible bug "unable to allocate memory". TBD.
[NEW OPTIONS] (*Currently all enabled for testing purposes)
1. --fast-block-sync arg=[0:1] (default: 1)
a. 0 = Compute long hash per block (may take a while depending on CPU)
b. 1 = Skip long-hash and verify blocks based on embedded known good block hashes (faster, minimal CPU dependence)
2. --db-sync-mode arg=[[safe|fast|fastest]:[sync|async]:[nblocks_per_sync]] (default: fastest:async:1000)
a. safe = fdatasync/fsync (or equivalent) per stored block. Very slow, but safest option to protect against power-out/crash conditions.
b. fast/fastest = Enables asynchronous fdatasync/fsync (or equivalent). Useful for battery operated devices or STABLE systems with UPS and/or systems with battery backed write cache/solid state cache.
Fast - Write meta-data but defer data flush.
Fastest - Defer meta-data and data flush.
Sync - Flush data after nblocks_per_sync and wait.
Async - Flush data after nblocks_per_sync but do not wait for the operation to finish.
3. --prep-blocks-threads arg=[n] (default: 4 or system max threads, whichever is lower)
Max number of threads to use when computing long-hash in groups.
4. --show-time-stats arg=[0:1] (default: 1)
Show benchmark related time stats.
5. --db-auto-remove-logs arg=[0:1] (default: 1)
For berkeley-db only. Auto remove logs if enabled.
**Note: lmdb and berkeley-db have changes to the tables and are not compatible with official git head version.
At the moment, you need a full resync to use this optimized version.
[PERFORMANCE COMPARISON]
**Some figures are approximations only.
Using a baseline machine of an i7-2600K+SSD+(with full pow computation):
1. The optimized lmdb/blockhain core can process blocks up to 585K for ~1.25 hours + download time, so it usually takes 2.5 hours to sync the full chain.
2. The current head with memory can process blocks up to 585K for ~4.2 hours + download time, so it usually takes 5.5 hours to sync the full chain.
3. The current head with lmdb can process blocks up to 585K for ~32 hours + download time and usually takes 36 hours to sync the full chain.
Averate procesing times (with full pow computation):
lmdb-optimized:
1. tx_ave = 2.5 ms / tx
2. block_ave = 5.87 ms / block
memory-official-repo:
1. tx_ave = 8.85 ms / tx
2. block_ave = 19.68 ms / block
lmdb-official-repo (0f4a036437fd41a5498ee5e74e2422ea6177aa3e)
1. tx_ave = 47.8 ms / tx
2. block_ave = 64.2 ms / block
**Note: The following data denotes processing times only (does not include p2p download time)
lmdb-optimized processing times (with full pow computation):
1. Desktop, Quad-core / 8-threads 2600k (8Mb) - 1.25 hours processing time (--db-sync-mode=fastest:async:1000).
2. Laptop, Dual-core / 4-threads U4200 (3Mb) - 4.90 hours processing time (--db-sync-mode=fastest:async:1000).
3. Embedded, Quad-core / 4-threads Z3735F (2x1Mb) - 12.0 hours processing time (--db-sync-mode=fastest:async:1000).
lmdb-optimized processing times (with per-block-checkpoint)
1. Desktop, Quad-core / 8-threads 2600k (8Mb) - 10 minutes processing time (--db-sync-mode=fastest:async:1000).
berkeley-db optimized processing times (with full pow computation)
1. Desktop, Quad-core / 8-threads 2600k (8Mb) - 1.8 hours processing time (--db-sync-mode=fastest:async:1000).
2. RPI2. Improved from estimated 3 months(???) into 2.5 days (*Need 2AMP supply + Clock:1Ghz + [usb+ssd] to achieve this speed) (--db-sync-mode=fastest:async:1000).
berkeley-db optimized processing times (with per-block-checkpoint)
1. RPI2. 12-15 hours (*Need 2AMP supply + Clock:1Ghz + [usb+ssd] to achieve this speed) (--db-sync-mode=fastest:async:1000).
2015-07-10 20:09:32 +00:00
m_core.cleanup_handle_incoming_blocks(true);
2014-03-03 22:07:58 +00:00
m_core.resume_mine();
if(bvc.m_verifivation_failed)
{
2015-01-05 19:30:17 +00:00
LOG_PRINT_CCONTEXT_L0("Block verification failed, dropping connection");
2014-03-03 22:07:58 +00:00
m_p2p->drop_connection(context);
return 1;
}
if(bvc.m_added_to_main_chain)
{
++arg.hop;
//TODO: Add here announce protocol usage
relay_block(arg, context);
}else if(bvc.m_marked_as_orphaned)
{
context.m_state = cryptonote_connection_context::state_synchronizing;
NOTIFY_REQUEST_CHAIN::request r = boost::value_initialized<NOTIFY_REQUEST_CHAIN::request>();
m_core.get_short_chain_history(r.block_ids);
LOG_PRINT_CCONTEXT_L2("-->>NOTIFY_REQUEST_CHAIN: m_block_ids.size()=" << r.block_ids.size() );
post_notify<NOTIFY_REQUEST_CHAIN>(r, context);
}
2015-12-14 04:54:39 +00:00
2014-03-03 22:07:58 +00:00
return 1;
}
//------------------------------------------------------------------------------------------------------------------------
2015-12-14 04:54:39 +00:00
template<class t_core>
2016-10-26 19:00:08 +00:00
int t_cryptonote_protocol_handler<t_core>::handle_notify_new_fluffy_block(int command, NOTIFY_NEW_FLUFFY_BLOCK::request& arg, cryptonote_connection_context& context)
{
2017-02-11 19:38:18 +00:00
MLOG_P2P_MESSAGE("Received NOTIFY_NEW_FLUFFY_BLOCK (height " << arg.current_blockchain_height << ", hop " << arg.hop << ", " << arg.b.txs.size() << " txes)");
2016-10-26 19:00:08 +00:00
if(context.m_state != cryptonote_connection_context::state_normal)
return 1;
m_core.pause_mine();
block new_block;
transaction miner_tx;
if(parse_and_validate_block_from_blob(arg.b.block, new_block))
{
2017-02-11 19:38:18 +00:00
// This is a second notification, we must have asked for some missing tx
2016-10-26 19:00:08 +00:00
if(!context.m_requested_objects.empty())
{
// What we asked for != to what we received ..
if(context.m_requested_objects.size() != arg.b.txs.size())
{
LOG_ERROR_CCONTEXT
(
"NOTIFY_NEW_FLUFFY_BLOCK -> request/response mismatch, "
<< "block = " << epee::string_tools::pod_to_hex(get_blob_hash(arg.b.block))
<< ", requested = " << context.m_requested_objects.size()
<< ", received = " << new_block.tx_hashes.size()
<< ", dropping connection"
);
m_p2p->drop_connection(context);
m_core.resume_mine();
return 1;
}
}
std::list<blobdata> have_tx;
// Instead of requesting missing transactions by hash like BTC,
// we do it by index (thanks to a suggestion from moneromooo) because
// we're way cooler .. and also because they're smaller than hashes.
//
// Also, remember to pepper some whitespace changes around to bother
// moneromooo ... only because I <3 him.
std::vector<size_t> need_tx_indices;
transaction tx;
crypto::hash tx_hash;
2017-01-22 20:38:10 +00:00
for(auto& tx_blob: arg.b.txs)
2016-10-26 19:00:08 +00:00
{
if(parse_and_validate_tx_from_blob(tx_blob, tx))
{
try
{
if(!get_transaction_hash(tx, tx_hash))
{
LOG_PRINT_CCONTEXT_L1
(
"NOTIFY_NEW_FLUFFY_BLOCK: get_transaction_hash failed"
<< ", dropping connection"
);
m_p2p->drop_connection(context);
m_core.resume_mine();
return 1;
}
}
catch(...)
{
LOG_PRINT_CCONTEXT_L1
(
"NOTIFY_NEW_FLUFFY_BLOCK: get_transaction_hash failed"
<< ", exception thrown"
<< ", dropping connection"
);
m_p2p->drop_connection(context);
m_core.resume_mine();
return 1;
}
// hijacking m_requested objects in connection context to patch up
// a possible DOS vector pointed out by @monero-moo where peers keep
// sending (0...n-1) transactions.
// If requested objects is not empty, then we must have asked for
// some missing transacionts, make sure that they're all there.
//
// Can I safely re-use this field? I think so, but someone check me!
if(!context.m_requested_objects.empty())
{
auto req_tx_it = context.m_requested_objects.find(tx_hash);
if(req_tx_it == context.m_requested_objects.end())
{
LOG_ERROR_CCONTEXT
(
"Peer sent wrong transaction (NOTIFY_NEW_FLUFFY_BLOCK): "
<< "transaction with id = " << tx_hash << " wasn't requested, "
<< "dropping connection"
);
m_p2p->drop_connection(context);
m_core.resume_mine();
return 1;
}
context.m_requested_objects.erase(req_tx_it);
}
// we might already have the tx that the peer
// sent in our pool, so don't verify again..
2017-05-14 13:06:55 +00:00
if(!m_core.pool_has_tx(tx_hash))
2016-10-26 19:00:08 +00:00
{
2017-02-11 19:38:18 +00:00
MDEBUG("Incoming tx " << tx_hash << " not in pool, adding");
2016-10-26 19:00:08 +00:00
cryptonote::tx_verification_context tvc = AUTO_VAL_INIT(tvc);
2017-01-14 13:01:21 +00:00
if(!m_core.handle_incoming_tx(tx_blob, tvc, true, true, false) || tvc.m_verifivation_failed)
2016-10-26 19:00:08 +00:00
{
LOG_PRINT_CCONTEXT_L1("Block verification failed: transaction verification failed, dropping connection");
m_p2p->drop_connection(context);
m_core.resume_mine();
return 1;
}
//
// future todo:
// tx should only not be added to pool if verification failed, but
// maybe in the future could not be added for other reasons
// according to monero-moo so keep track of these separately ..
//
}
}
else
{
LOG_ERROR_CCONTEXT
(
2017-02-11 19:38:18 +00:00
"sent wrong tx: failed to parse and validate transaction: "
2016-10-26 19:00:08 +00:00
<< epee::string_tools::buff_to_hex_nodelimer(tx_blob)
2017-02-11 19:38:18 +00:00
<< ", dropping connection"
2016-10-26 19:00:08 +00:00
);
m_p2p->drop_connection(context);
m_core.resume_mine();
return 1;
}
}
// The initial size equality check could have been fooled if the sender
// gave us the number of transactions we asked for, but not the right
// ones. This check make sure the transactions we asked for were the
// ones we received.
if(context.m_requested_objects.size())
{
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.
2017-01-01 16:34:23 +00:00
MERROR
2016-10-26 19:00:08 +00:00
(
"NOTIFY_NEW_FLUFFY_BLOCK: peer sent the number of transaction requested"
<< ", but not the actual transactions requested"
<< ", context.m_requested_objects.size() = " << context.m_requested_objects.size()
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.
2017-01-01 16:34:23 +00:00
<< ", dropping connection"
2016-10-26 19:00:08 +00:00
);
m_p2p->drop_connection(context);
m_core.resume_mine();
return 1;
}
size_t tx_idx = 0;
2017-01-22 20:38:10 +00:00
for(auto& tx_hash: new_block.tx_hashes)
2016-10-26 19:00:08 +00:00
{
2017-05-14 13:06:55 +00:00
cryptonote::blobdata txblob;
if(m_core.get_pool_transaction(tx_hash, txblob))
2016-10-26 19:00:08 +00:00
{
2017-05-14 13:06:55 +00:00
have_tx.push_back(txblob);
2016-10-26 19:00:08 +00:00
}
else
{
2017-02-11 19:38:18 +00:00
std::vector<crypto::hash> tx_ids;
std::list<transaction> txes;
std::list<crypto::hash> missing;
tx_ids.push_back(tx_hash);
if (m_core.get_transactions(tx_ids, txes, missing) && missing.empty())
{
2017-03-13 19:16:25 +00:00
if (txes.size() == 1)
{
have_tx.push_back(tx_to_blob(txes.front()));
}
else
{
MERROR("1 tx requested, none not found, but " << txes.size() << " returned");
m_core.resume_mine();
return 1;
}
2017-02-11 19:38:18 +00:00
}
else
{
MDEBUG("Tx " << tx_hash << " not found in pool");
need_tx_indices.push_back(tx_idx);
}
2016-10-26 19:00:08 +00:00
}
++tx_idx;
}
if(!need_tx_indices.empty()) // drats, we don't have everything..
{
// request non-mempool txs
2017-02-11 19:38:18 +00:00
MDEBUG("We are missing " << need_tx_indices.size() << " txes for this fluffy block");
for (auto txidx: need_tx_indices)
MDEBUG(" tx " << new_block.tx_hashes[txidx]);
2016-10-26 19:00:08 +00:00
NOTIFY_REQUEST_FLUFFY_MISSING_TX::request missing_tx_req;
2017-02-11 19:38:18 +00:00
missing_tx_req.block_hash = get_block_hash(new_block);
2016-10-26 19:00:08 +00:00
missing_tx_req.hop = arg.hop;
missing_tx_req.current_blockchain_height = arg.current_blockchain_height;
missing_tx_req.missing_tx_indices = std::move(need_tx_indices);
m_core.resume_mine();
post_notify<NOTIFY_REQUEST_FLUFFY_MISSING_TX>(missing_tx_req, context);
}
else // whoo-hoo we've got em all ..
{
2017-02-11 19:38:18 +00:00
MDEBUG("We have all needed txes for this fluffy block");
2016-10-26 19:00:08 +00:00
block_complete_entry b;
b.block = arg.b.block;
b.txs = have_tx;
std::list<block_complete_entry> blocks;
blocks.push_back(b);
m_core.prepare_handle_incoming_blocks(blocks);
block_verification_context bvc = boost::value_initialized<block_verification_context>();
m_core.handle_incoming_block(arg.b.block, bvc); // got block from handle_notify_new_block
m_core.cleanup_handle_incoming_blocks(true);
m_core.resume_mine();
if( bvc.m_verifivation_failed )
{
LOG_PRINT_CCONTEXT_L0("Block verification failed, dropping connection");
m_p2p->drop_connection(context);
return 1;
}
if( bvc.m_added_to_main_chain )
{
++arg.hop;
//TODO: Add here announce protocol usage
NOTIFY_NEW_BLOCK::request reg_arg = AUTO_VAL_INIT(reg_arg);
reg_arg.hop = arg.hop;
reg_arg.current_blockchain_height = arg.current_blockchain_height;
2017-03-12 14:14:51 +00:00
reg_arg.b = b;
2016-10-26 19:00:08 +00:00
relay_block(reg_arg, context);
}
else if( bvc.m_marked_as_orphaned )
{
context.m_state = cryptonote_connection_context::state_synchronizing;
NOTIFY_REQUEST_CHAIN::request r = boost::value_initialized<NOTIFY_REQUEST_CHAIN::request>();
m_core.get_short_chain_history(r.block_ids);
LOG_PRINT_CCONTEXT_L2("-->>NOTIFY_REQUEST_CHAIN: m_block_ids.size()=" << r.block_ids.size() );
post_notify<NOTIFY_REQUEST_CHAIN>(r, context);
}
}
}
else
{
LOG_ERROR_CCONTEXT
(
2017-02-11 19:38:18 +00:00
"sent wrong block: failed to parse and validate block: "
2016-10-26 19:00:08 +00:00
<< epee::string_tools::buff_to_hex_nodelimer(arg.b.block)
2017-02-11 19:38:18 +00:00
<< ", dropping connection"
2016-10-26 19:00:08 +00:00
);
m_core.resume_mine();
m_p2p->drop_connection(context);
return 1;
}
return 1;
}
//------------------------------------------------------------------------------------------------------------------------
template<class t_core>
int t_cryptonote_protocol_handler<t_core>::handle_request_fluffy_missing_tx(int command, NOTIFY_REQUEST_FLUFFY_MISSING_TX::request& arg, cryptonote_connection_context& context)
{
2017-02-11 19:38:18 +00:00
MLOG_P2P_MESSAGE("Received NOTIFY_REQUEST_FLUFFY_MISSING_TX (" << arg.missing_tx_indices.size() << " txes), block hash " << arg.block_hash);
2017-01-15 16:05:55 +00:00
std::list<std::pair<cryptonote::blobdata, block>> local_blocks;
std::list<cryptonote::blobdata> local_txs;
2016-10-26 19:00:08 +00:00
2017-02-11 19:38:18 +00:00
block b;
if (!m_core.get_block_by_hash(arg.block_hash, b))
{
LOG_ERROR_CCONTEXT("failed to find block: " << arg.block_hash << ", dropping connection");
2016-10-26 19:00:08 +00:00
m_p2p->drop_connection(context);
2017-02-11 19:38:18 +00:00
return 1;
2016-10-26 19:00:08 +00:00
}
2017-02-11 19:38:18 +00:00
for (auto txidx: arg.missing_tx_indices)
MDEBUG(" tx " << b.tx_hashes[txidx]);
std::vector<crypto::hash> txids;
2016-10-26 19:00:08 +00:00
NOTIFY_NEW_FLUFFY_BLOCK::request fluffy_response;
2017-02-11 19:38:18 +00:00
fluffy_response.b.block = t_serializable_object_to_blob(b);
fluffy_response.current_blockchain_height = arg.current_blockchain_height;
2016-10-26 19:00:08 +00:00
fluffy_response.hop = arg.hop;
2017-01-22 20:38:10 +00:00
for(auto& tx_idx: arg.missing_tx_indices)
2016-10-26 19:00:08 +00:00
{
2017-02-11 19:38:18 +00:00
if(tx_idx < b.tx_hashes.size())
2016-10-26 19:00:08 +00:00
{
2017-02-11 19:38:18 +00:00
txids.push_back(b.tx_hashes[tx_idx]);
2016-10-26 19:00:08 +00:00
}
else
{
LOG_ERROR_CCONTEXT
(
"Failed to handle request NOTIFY_REQUEST_FLUFFY_MISSING_TX"
<< ", request is asking for a tx whose index is out of bounds "
2017-02-11 19:38:18 +00:00
<< ", tx index = " << tx_idx << ", block tx count " << b.tx_hashes.size()
<< ", block_height = " << arg.current_blockchain_height
2016-10-26 19:00:08 +00:00
<< ", dropping connection"
);
m_p2p->drop_connection(context);
return 1;
}
}
2017-02-11 19:38:18 +00:00
std::list<cryptonote::transaction> txs;
std::list<crypto::hash> missed;
if (!m_core.get_transactions(txids, txs, missed))
{
LOG_ERROR_CCONTEXT("Failed to handle request NOTIFY_REQUEST_FLUFFY_MISSING_TX, "
<< "failed to get requested transactions");
m_p2p->drop_connection(context);
return 1;
}
if (!missed.empty() || txs.size() != txids.size())
{
LOG_ERROR_CCONTEXT("Failed to handle request NOTIFY_REQUEST_FLUFFY_MISSING_TX, "
<< missed.size() << " requested transactions not found" << ", dropping connection");
m_p2p->drop_connection(context);
return 1;
}
for(auto& tx: txs)
{
fluffy_response.b.txs.push_back(t_serializable_object_to_blob(tx));
}
2016-10-26 19:00:08 +00:00
LOG_PRINT_CCONTEXT_L2
(
"-->>NOTIFY_RESPONSE_FLUFFY_MISSING_TX: "
<< ", txs.size()=" << fluffy_response.b.txs.size()
<< ", rsp.current_blockchain_height=" << fluffy_response.current_blockchain_height
);
post_notify<NOTIFY_NEW_FLUFFY_BLOCK>(fluffy_response, context);
return 1;
}
//------------------------------------------------------------------------------------------------------------------------
template<class t_core>
2014-03-03 22:07:58 +00:00
int t_cryptonote_protocol_handler<t_core>::handle_notify_new_transactions(int command, NOTIFY_NEW_TRANSACTIONS::request& arg, cryptonote_connection_context& context)
{
2017-01-22 10:14:45 +00:00
MLOG_P2P_MESSAGE("Received NOTIFY_NEW_TRANSACTIONS (" << arg.txs.size() << " txes)");
2014-03-03 22:07:58 +00:00
if(context.m_state != cryptonote_connection_context::state_normal)
return 1;
2017-05-14 13:06:55 +00:00
// while syncing, core will lock for a long time, so we ignore
// those txes as they aren't really needed anyway, and avoid a
// long block before replying
if(!is_synchronized())
{
LOG_DEBUG_CC(context, "Received new tx while syncing, ignored");
return 1;
}
2014-03-03 22:07:58 +00:00
for(auto tx_blob_it = arg.txs.begin(); tx_blob_it!=arg.txs.end();)
{
cryptonote::tx_verification_context tvc = AUTO_VAL_INIT(tvc);
2017-01-14 13:01:21 +00:00
m_core.handle_incoming_tx(*tx_blob_it, tvc, false, true, false);
2014-03-03 22:07:58 +00:00
if(tvc.m_verifivation_failed)
{
2014-09-09 09:32:00 +00:00
LOG_PRINT_CCONTEXT_L1("Tx verification failed, dropping connection");
2014-03-03 22:07:58 +00:00
m_p2p->drop_connection(context);
return 1;
}
if(tvc.m_should_be_relayed)
++tx_blob_it;
else
arg.txs.erase(tx_blob_it++);
}
if(arg.txs.size())
{
//TODO: add announce usage here
relay_transactions(arg, context);
}
return true;
}
//------------------------------------------------------------------------------------------------------------------------
2015-12-14 04:54:39 +00:00
template<class t_core>
2014-03-03 22:07:58 +00:00
int t_cryptonote_protocol_handler<t_core>::handle_request_get_objects(int command, NOTIFY_REQUEST_GET_OBJECTS::request& arg, cryptonote_connection_context& context)
{
2017-01-22 10:14:45 +00:00
MLOG_P2P_MESSAGE("Received NOTIFY_REQUEST_GET_OBJECTS (" << arg.blocks.size() << " blocks, " << arg.txs.size() << " txes)");
2014-03-03 22:07:58 +00:00
NOTIFY_RESPONSE_GET_OBJECTS::request rsp;
if(!m_core.handle_get_objects(arg, rsp, context))
{
LOG_ERROR_CCONTEXT("failed to handle request NOTIFY_REQUEST_GET_OBJECTS, dropping connection");
m_p2p->drop_connection(context);
}
2015-12-14 04:54:39 +00:00
LOG_PRINT_CCONTEXT_L2("-->>NOTIFY_RESPONSE_GET_OBJECTS: blocks.size()=" << rsp.blocks.size() << ", txs.size()=" << rsp.txs.size()
2014-03-03 22:07:58 +00:00
<< ", rsp.m_current_blockchain_height=" << rsp.current_blockchain_height << ", missed_ids.size()=" << rsp.missed_ids.size());
post_notify<NOTIFY_RESPONSE_GET_OBJECTS>(rsp, context);
2015-01-05 19:30:17 +00:00
//handler_response_blocks_now(sizeof(rsp)); // XXX
//handler_response_blocks_now(200);
2014-03-03 22:07:58 +00:00
return 1;
}
//------------------------------------------------------------------------------------------------------------------------
2015-01-05 19:30:17 +00:00
2015-12-14 04:54:39 +00:00
2015-01-05 19:30:17 +00:00
template<class t_core>
2015-02-12 19:59:39 +00:00
double t_cryptonote_protocol_handler<t_core>::get_avg_block_size() {
2015-12-14 04:54:39 +00:00
// return m_core.get_blockchain_storage().get_avg_block_size(count); // this does not count too well the actuall network-size of data we need to download
CRITICAL_REGION_LOCAL(m_buffer_mutex);
double avg = 0;
if (m_avg_buffer.size() == 0) {
_warn("m_avg_buffer.size() == 0");
return 500;
}
const bool dbg_poke_lock = 0; // debug: try to trigger an error by poking around with locks. TODO: configure option
long int dbg_repeat=0;
do {
for (auto element : m_avg_buffer) avg += element;
} while(dbg_poke_lock && (dbg_repeat++)<100000); // in debug/poke mode, repeat this calculation to trigger hidden locking error if there is one
return avg / m_avg_buffer.size();
2015-01-05 19:30:17 +00:00
}
2015-12-14 04:54:39 +00:00
2014-03-03 22:07:58 +00:00
template<class t_core>
int t_cryptonote_protocol_handler<t_core>::handle_response_get_objects(int command, NOTIFY_RESPONSE_GET_OBJECTS::request& arg, cryptonote_connection_context& context)
{
2017-01-22 10:14:45 +00:00
MLOG_P2P_MESSAGE("Received NOTIFY_RESPONSE_GET_OBJECTS (" << arg.blocks.size() << " blocks, " << arg.txs.size() << " txes)");
2015-12-14 04:54:39 +00:00
2015-02-12 19:59:39 +00:00
// calculate size of request - mainly for logging/debug
size_t size = 0;
2015-02-20 21:28:03 +00:00
for (auto element : arg.txs) size += element.size();
2015-12-14 04:54:39 +00:00
for (auto element : arg.blocks) {
size += element.block.size();
for (auto tx : element.txs)
size += tx.size();
}
for (auto element : arg.missed_ids)
size += sizeof(element.data);
size += sizeof(arg.current_blockchain_height);
{
CRITICAL_REGION_LOCAL(m_buffer_mutex);
m_avg_buffer.push_back(size);
const bool dbg_poke_lock = 0; // debug: try to trigger an error by poking around with locks. TODO: configure option
long int dbg_repeat=0;
do {
m_avg_buffer.push_back(666); // a test value
m_avg_buffer.erase_end(1);
} while(dbg_poke_lock && (dbg_repeat++)<100000); // in debug/poke mode, repeat this calculation to trigger hidden locking error if there is one
}
/*using namespace boost::chrono;
auto point = steady_clock::now();
auto time_from_epoh = point.time_since_epoch();
auto sec = duration_cast< seconds >( time_from_epoh ).count();*/
//epee::net_utils::network_throttle_manager::get_global_throttle_inreq().logger_handle_net("log/dr-monero/net/req-all.data", sec, get_avg_block_size());
2014-03-03 22:07:58 +00:00
if(context.m_last_response_height > arg.current_blockchain_height)
{
2015-12-14 04:54:39 +00:00
LOG_ERROR_CCONTEXT("sent wrong NOTIFY_HAVE_OBJECTS: arg.m_current_blockchain_height=" << arg.current_blockchain_height
2014-03-03 22:07:58 +00:00
<< " < m_last_response_height=" << context.m_last_response_height << ", dropping connection");
m_p2p->drop_connection(context);
return 1;
}
context.m_remote_blockchain_height = arg.current_blockchain_height;
2014-03-20 11:46:11 +00:00
size_t count = 0;
2017-02-12 17:17:30 +00:00
std::vector<crypto::hash> block_hashes;
block_hashes.reserve(arg.blocks.size());
2017-01-22 20:38:10 +00:00
for(const block_complete_entry& block_entry: arg.blocks)
2014-03-03 22:07:58 +00:00
{
2016-12-04 12:27:45 +00:00
if (m_stopping)
{
return 1;
}
2014-03-20 11:46:11 +00:00
++count;
2014-03-03 22:07:58 +00:00
block b;
if(!parse_and_validate_block_from_blob(block_entry.block, b))
{
2017-02-11 19:38:18 +00:00
LOG_ERROR_CCONTEXT("sent wrong block: failed to parse and validate block: "
<< epee::string_tools::buff_to_hex_nodelimer(block_entry.block) << ", dropping connection");
2014-03-03 22:07:58 +00:00
m_p2p->drop_connection(context);
return 1;
2015-12-14 04:54:39 +00:00
}
2014-03-20 11:46:11 +00:00
//to avoid concurrency in core between connections, suspend connections which delivered block later then first one
2017-02-12 17:17:30 +00:00
const crypto::hash block_hash = get_block_hash(b);
2014-03-20 11:46:11 +00:00
if(count == 2)
2015-12-14 04:54:39 +00:00
{
2017-02-12 17:17:30 +00:00
if(m_core.have_block(block_hash))
2014-03-20 11:46:11 +00:00
{
context.m_state = cryptonote_connection_context::state_idle;
context.m_needed_objects.clear();
context.m_requested_objects.clear();
LOG_PRINT_CCONTEXT_L1("Connection set to idle state.");
return 1;
}
2014-03-03 22:07:58 +00:00
}
2015-12-14 04:54:39 +00:00
2017-02-12 17:17:30 +00:00
auto req_it = context.m_requested_objects.find(block_hash);
2014-03-03 22:07:58 +00:00
if(req_it == context.m_requested_objects.end())
{
2015-12-14 04:54:39 +00:00
LOG_ERROR_CCONTEXT("sent wrong NOTIFY_RESPONSE_GET_OBJECTS: block with id=" << epee::string_tools::pod_to_hex(get_blob_hash(block_entry.block))
2014-03-03 22:07:58 +00:00
<< " wasn't requested, dropping connection");
m_p2p->drop_connection(context);
return 1;
}
2015-12-14 04:54:39 +00:00
if(b.tx_hashes.size() != block_entry.txs.size())
2014-03-03 22:07:58 +00:00
{
2015-12-14 04:54:39 +00:00
LOG_ERROR_CCONTEXT("sent wrong NOTIFY_RESPONSE_GET_OBJECTS: block with id=" << epee::string_tools::pod_to_hex(get_blob_hash(block_entry.block))
2014-03-03 22:07:58 +00:00
<< ", tx_hashes.size()=" << b.tx_hashes.size() << " mismatch with block_complete_entry.m_txs.size()=" << block_entry.txs.size() << ", dropping connection");
m_p2p->drop_connection(context);
return 1;
}
context.m_requested_objects.erase(req_it);
2017-02-12 17:17:30 +00:00
block_hashes.push_back(block_hash);
2014-03-03 22:07:58 +00:00
}
if(context.m_requested_objects.size())
{
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.
2017-01-01 16:34:23 +00:00
MERROR("returned not all requested objects (context.m_requested_objects.size()="
<< context.m_requested_objects.size() << "), dropping connection");
2014-03-03 22:07:58 +00:00
m_p2p->drop_connection(context);
return 1;
}
2015-02-20 21:28:03 +00:00
2014-03-03 22:07:58 +00:00
{
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.
2017-01-01 16:34:23 +00:00
MLOG_YELLOW(el::Level::Debug, "Got NEW BLOCKS inside of " << __FUNCTION__ << ": size: " << arg.blocks.size());
2015-12-14 04:54:39 +00:00
2015-02-20 21:28:03 +00:00
if (m_core.get_test_drop_download() && m_core.get_test_drop_download_height()) { // DISCARD BLOCKS for testing
2015-12-14 04:54:39 +00:00
2017-02-12 17:17:30 +00:00
// we lock all the rest to avoid having multiple connections redo a lot
// of the same work, and one of them doing it for nothing: subsequent
// connections will wait until the current one's added its blocks, then
// will add any extra it has, if any
CRITICAL_REGION_LOCAL(m_sync_lock);
2017-02-13 19:36:31 +00:00
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));
const uint64_t previous_height = m_core.get_current_blockchain_height();
2017-02-12 17:17:30 +00:00
// dismiss what another connection might already have done (likely everything)
uint64_t top_height;
crypto::hash top_hash;
if (m_core.get_blockchain_top(top_height, top_hash)) {
uint64_t dismiss = 1;
for (const auto &h: block_hashes) {
if (top_hash == h) {
LOG_DEBUG_CC(context, "Found current top block in synced blocks, dismissing "
<< dismiss << "/" << arg.blocks.size() << " blocks");
while (dismiss--)
arg.blocks.pop_front();
break;
}
++dismiss;
}
}
2017-02-13 19:36:31 +00:00
if (arg.blocks.empty())
goto skip;
2015-12-14 04:54:39 +00:00
m_core.prepare_handle_incoming_blocks(arg.blocks);
2017-02-12 17:17:30 +00:00
2017-01-22 20:38:10 +00:00
for(const block_complete_entry& block_entry: arg.blocks)
2015-12-14 04:54:39 +00:00
{
2016-12-04 12:27:45 +00:00
if (m_stopping)
{
m_core.cleanup_handle_incoming_blocks();
return 1;
}
2015-12-14 04:54:39 +00:00
// process transactions
TIME_MEASURE_START(transactions_process_time);
2017-01-22 20:38:10 +00:00
for(auto& tx_blob: block_entry.txs)
2015-12-14 04:54:39 +00:00
{
tx_verification_context tvc = AUTO_VAL_INIT(tvc);
2017-01-14 13:01:21 +00:00
m_core.handle_incoming_tx(tx_blob, tvc, true, true, false);
2015-12-14 04:54:39 +00:00
if(tvc.m_verifivation_failed)
{
2017-02-11 19:38:18 +00:00
LOG_ERROR_CCONTEXT("transaction verification failed on NOTIFY_RESPONSE_GET_OBJECTS, tx_id = "
2015-12-14 04:54:39 +00:00
<< epee::string_tools::pod_to_hex(get_blob_hash(tx_blob)) << ", dropping connection");
m_p2p->drop_connection(context);
m_core.cleanup_handle_incoming_blocks();
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);
m_p2p->add_ip_fail(context.m_remote_ip);
m_core.cleanup_handle_incoming_blocks();
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);
m_p2p->add_ip_fail(context.m_remote_ip);
m_core.cleanup_handle_incoming_blocks();
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");
} // each download block
m_core.cleanup_handle_incoming_blocks();
if (m_core.get_current_blockchain_height() > previous_height)
{
2017-01-16 10:45:59 +00:00
MGINFO_YELLOW(context << " Synced " << m_core.get_current_blockchain_height() << "/" << m_core.get_target_blockchain_height());
2015-12-14 04:54:39 +00:00
}
} // if not DISCARD BLOCK
2014-03-03 22:07:58 +00:00
}
2017-02-13 19:36:31 +00:00
skip:
2014-03-03 22:07:58 +00:00
request_missing_objects(context, true);
return 1;
}
//------------------------------------------------------------------------------------------------------------------------
2015-12-14 04:54:39 +00:00
template<class t_core>
2014-03-03 22:07:58 +00:00
bool t_cryptonote_protocol_handler<t_core>::on_idle()
{
return m_core.on_idle();
}
//------------------------------------------------------------------------------------------------------------------------
template<class t_core>
int t_cryptonote_protocol_handler<t_core>::handle_request_chain(int command, NOTIFY_REQUEST_CHAIN::request& arg, cryptonote_connection_context& context)
{
2017-01-22 10:14:45 +00:00
MLOG_P2P_MESSAGE("Received NOTIFY_REQUEST_CHAIN (" << arg.block_ids.size() << " blocks");
2014-03-03 22:07:58 +00:00
NOTIFY_RESPONSE_CHAIN_ENTRY::request r;
if(!m_core.find_blockchain_supplement(arg.block_ids, r))
{
LOG_ERROR_CCONTEXT("Failed to handle NOTIFY_REQUEST_CHAIN.");
2016-11-09 10:52:29 +00:00
m_p2p->drop_connection(context);
2014-03-03 22:07:58 +00:00
return 1;
}
LOG_PRINT_CCONTEXT_L2("-->>NOTIFY_RESPONSE_CHAIN_ENTRY: m_start_height=" << r.start_height << ", m_total_height=" << r.total_height << ", m_block_ids.size()=" << r.m_block_ids.size());
post_notify<NOTIFY_RESPONSE_CHAIN_ENTRY>(r, context);
return 1;
}
//------------------------------------------------------------------------------------------------------------------------
2015-12-14 04:54:39 +00:00
template<class t_core>
2014-03-03 22:07:58 +00:00
bool t_cryptonote_protocol_handler<t_core>::request_missing_objects(cryptonote_connection_context& context, bool check_having_blocks)
{
2015-12-14 04:54:39 +00:00
//if (!m_one_request == false)
//return true;
m_one_request = false;
// save request size to log (dr monero)
/*using namespace boost::chrono;
auto point = steady_clock::now();
auto time_from_epoh = point.time_since_epoch();
auto sec = duration_cast< seconds >( time_from_epoh ).count();*/
2014-03-03 22:07:58 +00:00
if(context.m_needed_objects.size())
{
//we know objects that we need, request this objects
NOTIFY_REQUEST_GET_OBJECTS::request req;
size_t count = 0;
auto it = context.m_needed_objects.begin();
2016-09-24 16:00:19 +00:00
const size_t count_limit = m_core.get_block_sync_size();
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.
2017-01-01 16:34:23 +00:00
MDEBUG("Setting count_limit: " << count_limit);
2016-09-24 16:00:19 +00:00
while(it != context.m_needed_objects.end() && count < count_limit)
2014-03-03 22:07:58 +00:00
{
if( !(check_having_blocks && m_core.have_block(*it)))
{
req.blocks.push_back(*it);
++count;
context.m_requested_objects.insert(*it);
}
context.m_needed_objects.erase(it++);
}
2015-12-14 00:36:37 +00:00
LOG_PRINT_CCONTEXT_L1("-->>NOTIFY_REQUEST_GET_OBJECTS: blocks.size()=" << req.blocks.size() << ", txs.size()=" << req.txs.size()
2015-12-14 04:54:39 +00:00
<< "requested blocks count=" << count << " / " << count_limit);
//epee::net_utils::network_throttle_manager::get_global_throttle_inreq().logger_handle_net("log/dr-monero/net/req-all.data", sec, get_avg_block_size());
post_notify<NOTIFY_REQUEST_GET_OBJECTS>(req, context);
2014-03-03 22:07:58 +00:00
}else if(context.m_last_response_height < context.m_remote_blockchain_height-1)
{//we have to fetch more objects ids, request blockchain entry
2015-12-14 04:54:39 +00:00
2014-03-03 22:07:58 +00:00
NOTIFY_REQUEST_CHAIN::request r = boost::value_initialized<NOTIFY_REQUEST_CHAIN::request>();
m_core.get_short_chain_history(r.block_ids);
2015-12-14 04:54:39 +00:00
handler_request_blocks_history( r.block_ids ); // change the limit(?), sleep(?)
//std::string blob; // for calculate size of request
//epee::serialization::store_t_to_binary(r, blob);
//epee::net_utils::network_throttle_manager::get_global_throttle_inreq().logger_handle_net("log/dr-monero/net/req-all.data", sec, get_avg_block_size());
LOG_PRINT_CCONTEXT_L1("r = " << 200);
2015-12-14 17:45:32 +00:00
LOG_PRINT_CCONTEXT_L1("-->>NOTIFY_REQUEST_CHAIN: m_block_ids.size()=" << r.block_ids.size() );
2014-03-03 22:07:58 +00:00
post_notify<NOTIFY_REQUEST_CHAIN>(r, context);
}else
2015-12-14 04:54:39 +00:00
{
CHECK_AND_ASSERT_MES(context.m_last_response_height == context.m_remote_blockchain_height-1
&& !context.m_needed_objects.size()
&& !context.m_requested_objects.size(), false, "request_missing_blocks final condition failed!"
2014-03-03 22:07:58 +00:00
<< "\r\nm_last_response_height=" << context.m_last_response_height
<< "\r\nm_remote_blockchain_height=" << context.m_remote_blockchain_height
<< "\r\nm_needed_objects.size()=" << context.m_needed_objects.size()
<< "\r\nm_requested_objects.size()=" << context.m_requested_objects.size()
2014-05-25 17:06:40 +00:00
<< "\r\non connection [" << epee::net_utils::print_connection_context_short(context)<< "]");
2015-12-14 04:54:39 +00:00
2014-03-03 22:07:58 +00:00
context.m_state = cryptonote_connection_context::state_normal;
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.
2017-01-01 16:34:23 +00:00
MGINFO_GREEN("SYNCHRONIZED OK");
2014-03-20 11:46:11 +00:00
on_connection_synchronized();
2014-03-03 22:07:58 +00:00
}
return true;
}
//------------------------------------------------------------------------------------------------------------------------
2015-12-14 04:54:39 +00:00
template<class t_core>
2014-03-03 22:07:58 +00:00
bool t_cryptonote_protocol_handler<t_core>::on_connection_synchronized()
{
bool val_expected = false;
2014-03-20 11:46:11 +00:00
if(m_synchronized.compare_exchange_strong(val_expected, true))
2014-03-03 22:07:58 +00:00
{
2017-01-23 01:03:04 +00:00
MGINFO_YELLOW(ENDL << "**********************************************************************" << ENDL
2016-09-03 20:03:44 +00:00
<< "You are now synchronized with the network. You may now start monero-wallet-cli." << ENDL
2014-03-03 22:07:58 +00:00
<< ENDL
2017-01-23 01:03:04 +00:00
<< "Use the \"help\" command to see the list of available commands." << ENDL
2014-03-03 22:07:58 +00:00
<< "**********************************************************************");
m_core.on_synchronized();
}
return true;
}
//------------------------------------------------------------------------------------------------------------------------
2015-12-14 04:54:39 +00:00
template<class t_core>
2014-03-03 22:07:58 +00:00
size_t t_cryptonote_protocol_handler<t_core>::get_synchronizing_connections_count()
{
size_t count = 0;
2014-03-20 11:46:11 +00:00
m_p2p->for_each_connection([&](cryptonote_connection_context& context, nodetool::peerid_type peer_id)->bool{
2014-03-03 22:07:58 +00:00
if(context.m_state == cryptonote_connection_context::state_synchronizing)
++count;
return true;
});
return count;
}
//------------------------------------------------------------------------------------------------------------------------
2015-12-14 04:54:39 +00:00
template<class t_core>
2014-03-03 22:07:58 +00:00
int t_cryptonote_protocol_handler<t_core>::handle_response_chain_entry(int command, NOTIFY_RESPONSE_CHAIN_ENTRY::request& arg, cryptonote_connection_context& context)
{
2017-01-22 10:14:45 +00:00
MLOG_P2P_MESSAGE("Received NOTIFY_RESPONSE_CHAIN_ENTRY: m_block_ids.size()=" << arg.m_block_ids.size()
2014-03-03 22:07:58 +00:00
<< ", m_start_height=" << arg.start_height << ", m_total_height=" << arg.total_height);
2015-12-14 04:54:39 +00:00
2014-03-03 22:07:58 +00:00
if(!arg.m_block_ids.size())
{
LOG_ERROR_CCONTEXT("sent empty m_block_ids, dropping connection");
m_p2p->drop_connection(context);
2015-11-23 17:34:55 +00:00
m_p2p->add_ip_fail(context.m_remote_ip);
2014-03-03 22:07:58 +00:00
return 1;
}
if(!m_core.have_block(arg.m_block_ids.front()))
{
LOG_ERROR_CCONTEXT("sent m_block_ids starting from unknown id: "
2014-05-25 17:06:40 +00:00
<< epee::string_tools::pod_to_hex(arg.m_block_ids.front()) << " , dropping connection");
2014-03-03 22:07:58 +00:00
m_p2p->drop_connection(context);
2015-11-23 17:34:55 +00:00
m_p2p->add_ip_fail(context.m_remote_ip);
2014-03-03 22:07:58 +00:00
return 1;
}
2015-12-14 04:54:39 +00:00
2014-03-03 22:07:58 +00:00
context.m_remote_blockchain_height = arg.total_height;
context.m_last_response_height = arg.start_height + arg.m_block_ids.size()-1;
if(context.m_last_response_height > context.m_remote_blockchain_height)
{
2017-02-11 19:38:18 +00:00
LOG_ERROR_CCONTEXT("sent wrong NOTIFY_RESPONSE_CHAIN_ENTRY, with m_total_height=" << arg.total_height
<< ", m_start_height=" << arg.start_height
<< ", m_block_ids.size()=" << arg.m_block_ids.size());
2014-03-03 22:07:58 +00:00
m_p2p->drop_connection(context);
}
2017-01-22 20:38:10 +00:00
for(auto& bl_id: arg.m_block_ids)
2014-03-03 22:07:58 +00:00
{
if(!m_core.have_block(bl_id))
context.m_needed_objects.push_back(bl_id);
}
request_missing_objects(context, false);
return 1;
}
//------------------------------------------------------------------------------------------------------------------------
2015-12-14 04:54:39 +00:00
template<class t_core>
2014-03-03 22:07:58 +00:00
bool t_cryptonote_protocol_handler<t_core>::relay_block(NOTIFY_NEW_BLOCK::request& arg, cryptonote_connection_context& exclude_context)
{
2016-10-26 19:00:08 +00:00
NOTIFY_NEW_FLUFFY_BLOCK::request fluffy_arg = AUTO_VAL_INIT(fluffy_arg);
fluffy_arg.hop = arg.hop;
fluffy_arg.current_blockchain_height = arg.current_blockchain_height;
std::list<blobdata> fluffy_txs;
fluffy_arg.b = arg.b;
fluffy_arg.b.txs = fluffy_txs;
2016-11-29 16:21:33 +00:00
// pre-serialize them
std::string fullBlob, fluffyBlob;
epee::serialization::store_t_to_binary(arg, fullBlob);
epee::serialization::store_t_to_binary(fluffy_arg, fluffyBlob);
// sort peers between fluffy ones and others
std::list<boost::uuids::uuid> fullConnections, fluffyConnections;
m_p2p->for_each_connection([this, &arg, &fluffy_arg, &exclude_context, &fullConnections, &fluffyConnections](connection_context& context, nodetool::peerid_type peer_id, uint32_t support_flags)
2016-10-26 19:00:08 +00:00
{
2016-11-29 16:21:33 +00:00
if (peer_id && exclude_context.m_connection_id != context.m_connection_id)
2016-10-26 19:00:08 +00:00
{
2016-11-29 16:21:33 +00:00
if(m_core.get_testnet() && (support_flags & P2P_SUPPORT_FLAG_FLUFFY_BLOCKS))
{
2017-02-11 19:38:18 +00:00
LOG_DEBUG_CC(context, "PEER SUPPORTS FLUFFY BLOCKS - RELAYING THIN/COMPACT WHATEVER BLOCK");
2016-11-29 16:21:33 +00:00
fluffyConnections.push_back(context.m_connection_id);
}
else
{
2017-02-11 19:38:18 +00:00
LOG_DEBUG_CC(context, "PEER DOESN'T SUPPORT FLUFFY BLOCKS - RELAYING FULL BLOCK");
2016-11-29 16:21:33 +00:00
fullConnections.push_back(context.m_connection_id);
}
2016-10-26 19:00:08 +00:00
}
2016-11-29 16:21:33 +00:00
return true;
2016-10-26 19:00:08 +00:00
});
2016-11-29 16:21:33 +00:00
// send fluffy ones first, we want to encourage people to run that
m_p2p->relay_notify_to_list(NOTIFY_NEW_FLUFFY_BLOCK::ID, fluffyBlob, fluffyConnections);
m_p2p->relay_notify_to_list(NOTIFY_NEW_BLOCK::ID, fullBlob, fullConnections);
2016-10-26 19:00:08 +00:00
return 1;
2014-03-03 22:07:58 +00:00
}
//------------------------------------------------------------------------------------------------------------------------
2015-12-14 04:54:39 +00:00
template<class t_core>
2014-03-03 22:07:58 +00:00
bool t_cryptonote_protocol_handler<t_core>::relay_transactions(NOTIFY_NEW_TRANSACTIONS::request& arg, cryptonote_connection_context& exclude_context)
{
2016-10-22 19:46:51 +00:00
// no check for success, so tell core they're relayed unconditionally
for(auto tx_blob_it = arg.txs.begin(); tx_blob_it!=arg.txs.end(); ++tx_blob_it)
m_core.on_transaction_relayed(*tx_blob_it);
2014-03-03 22:07:58 +00:00
return relay_post_notify<NOTIFY_NEW_TRANSACTIONS>(arg, exclude_context);
}
2015-01-05 19:30:17 +00:00
2016-12-04 12:27:45 +00:00
//------------------------------------------------------------------------------------------------------------------------
template<class t_core>
void t_cryptonote_protocol_handler<t_core>::stop()
{
m_stopping = true;
m_core.stop();
}
2015-01-05 19:30:17 +00:00
} // namespace