Skip to content

Commit

Permalink
Merge pull request #298 from eosnetworkfoundation/3-strike-full-block…
Browse files Browse the repository at this point in the history
…-2.0

Apply 3-strike rule for complete block production - 2.0
  • Loading branch information
heifner authored May 23, 2022
2 parents 3e7cbe1 + 9400c1b commit e9026d2
Showing 1 changed file with 117 additions and 93 deletions.
210 changes: 117 additions & 93 deletions plugins/producer_plugin/producer_plugin.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -175,6 +175,95 @@ enum class pending_block_mode {
speculating
};

namespace {
// track multiple failures on unapplied transactions
class account_failures {
public:
constexpr static uint32_t max_failures_per_account = 3;

void add( const account_name& n, int64_t exception_code ) {
auto& fa = failed_accounts[n];
++fa.num_failures;
fa.add( n, exception_code );
}

// return true if exceeds max_failures_per_account and should be dropped
bool failure_limit( const account_name& n ) {
auto fitr = failed_accounts.find( n );
if( fitr != failed_accounts.end() && fitr->second.num_failures >= max_failures_per_account ) {
++fitr->second.num_failures;
return true;
}
return false;
}

void report() const {
if( _log.is_enabled( fc::log_level::debug ) ) {
for( const auto& e : failed_accounts ) {
std::string reason;
if( e.second.num_failures > max_failures_per_account ) {
reason.clear();
if( e.second.is_deadline() ) reason += "deadline";
if( e.second.is_tx_cpu_usage() ) {
if( !reason.empty() ) reason += ", ";
reason += "tx_cpu_usage";
}
if( e.second.is_eosio_assert() ) {
if( !reason.empty() ) reason += ", ";
reason += "assert";
}
if( e.second.is_other() ) {
if( !reason.empty() ) reason += ", ";
reason += "other";
}
fc_dlog( _log, "Dropped ${n} trxs, account: ${a}, reason: ${r} exceeded",
("n", e.second.num_failures - max_failures_per_account)("a", e.first)("r", reason) );
}
}
}
}

void clear() {
failed_accounts.clear();
}

private:
struct account_failure {
enum class ex_fields : uint8_t {
ex_deadline_exception = 1,
ex_tx_cpu_usage_exceeded = 2,
ex_eosio_assert_exception = 4,
ex_other_exception = 8
};

void add( const account_name& n, int64_t exception_code ) {
if( exception_code == tx_cpu_usage_exceeded::code_value ) {
ex_flags = set_field( ex_flags, ex_fields::ex_tx_cpu_usage_exceeded );
} else if( exception_code == deadline_exception::code_value ) {
ex_flags = set_field( ex_flags, ex_fields::ex_deadline_exception );
} else if( exception_code == eosio_assert_message_exception::code_value ||
exception_code == eosio_assert_code_exception::code_value ) {
ex_flags = set_field( ex_flags, ex_fields::ex_eosio_assert_exception );
} else {
ex_flags = set_field( ex_flags, ex_fields::ex_other_exception );
fc_dlog( _log, "Failed trx, account: ${a}, reason: ${r}",
("a", n)("r", exception_code) );
}
}

bool is_deadline() const { return has_field( ex_flags, ex_fields::ex_deadline_exception ); }
bool is_tx_cpu_usage() const { return has_field( ex_flags, ex_fields::ex_tx_cpu_usage_exceeded ); }
bool is_eosio_assert() const { return has_field( ex_flags, ex_fields::ex_eosio_assert_exception ); }
bool is_other() const { return has_field( ex_flags, ex_fields::ex_other_exception ); }

uint32_t num_failures = 0;
uint8_t ex_flags = 0;
};

std::map<account_name, account_failure> failed_accounts;
};

} // anonymous namespace

class producer_plugin_impl : public std::enable_shared_from_this<producer_plugin_impl> {
public:
Expand Down Expand Up @@ -239,6 +328,7 @@ class producer_plugin_impl : public std::enable_shared_from_this<producer_plugin
transaction_id_with_expiry_index _blacklisted_transactions;
pending_snapshot_index _pending_snapshot_index;
subjective_billing _subjective_billing;
account_failures _account_fails;

fc::optional<scoped_connection> _accepted_block_connection;
fc::optional<scoped_connection> _accepted_block_header_connection;
Expand Down Expand Up @@ -536,7 +626,15 @@ class producer_plugin_impl : public std::enable_shared_from_this<producer_plugin
return true;
}

auto deadline = fc::time_point::now() + fc::milliseconds( _max_transaction_time_ms );
auto first_auth = trx->packed_trx()->get_transaction().first_authorizer();
if( _account_fails.failure_limit( first_auth ) ) {
send_response( std::static_pointer_cast<fc::exception>( std::make_shared<tx_resource_exhaustion>(
FC_LOG_MESSAGE( error, "transaction dropped too many failures per block ${id}", ("id", id)))) );
return true;
}

auto start = fc::time_point::now();
auto deadline = start + fc::milliseconds( _max_transaction_time_ms );
bool deadline_is_subjective = false;
const auto block_deadline = calculate_block_deadline( chain.pending_block_time() );
if( _max_transaction_time_ms < 0 ||
Expand All @@ -549,12 +647,12 @@ class producer_plugin_impl : public std::enable_shared_from_this<producer_plugin
|| ( persist_until_expired && _disable_subjective_api_billing )
|| ( !persist_until_expired && _disable_subjective_p2p_billing );

auto first_auth = trx->packed_trx()->get_transaction().first_authorizer();
uint32_t sub_bill = 0;
if( !disable_subjective_billing )
sub_bill = _subjective_billing.get_subjective_bill( first_auth, fc::time_point::now() );

auto trace = chain.push_transaction( trx, deadline, trx->billed_cpu_time_us, false, sub_bill );
auto prev_billed_cpu_time_us = trx->billed_cpu_time_us;
auto trace = chain.push_transaction( trx, deadline, prev_billed_cpu_time_us, false, sub_bill );
fc_dlog( _trx_failed_trace_log, "Subjective bill for ${a}: ${b} elapsed ${t}us", ("a",first_auth)("b",sub_bill)("t",trace->elapsed));
if( trace->except ) {
if( exception_is_exhausted( *trace->except, deadline_is_subjective )) {
Expand All @@ -571,6 +669,16 @@ class producer_plugin_impl : public std::enable_shared_from_this<producer_plugin
exhausted = block_is_exhausted();
} else {
_subjective_billing.subjective_bill_failure( first_auth, trace->elapsed, fc::time_point::now() );
if( _pending_block_mode == pending_block_mode::producing ) {
auto failure_code = trace->except->code();
if( failure_code != tx_duplicate::code_value ) {
// this failed our configured maximum transaction time, we don't want to replay it
fc_dlog( _log, "Failed ${c} trx, prev billed: ${p}us, ran: ${r}us, id: ${id}",
("c", trace->except->code())( "p", prev_billed_cpu_time_us )
( "r", fc::time_point::now() - start )( "id", trx->id() ) );
_account_fails.add( first_auth, failure_code );
}
}
auto e_ptr = trace->except->dynamic_copy_exception();
send_response( e_ptr );
}
Expand Down Expand Up @@ -1666,6 +1774,7 @@ producer_plugin_impl::start_block_result producer_plugin_impl::start_block() {

// limit execution of pending incoming to once per block
size_t pending_incoming_process_limit = _pending_incoming_transactions.size();
_account_fails.clear();

if( !process_unapplied_trxs( preprocess_deadline ) )
return start_block_result::exhausted;
Expand Down Expand Up @@ -1786,97 +1895,10 @@ bool producer_plugin_impl::remove_expired_blacklisted_trxs( const fc::time_point
return !exhausted;
}

namespace {
// track multiple failures on unapplied transactions
class account_failures {
public:
constexpr static uint32_t max_failures_per_account = 3;

void add( const account_name& n, int64_t exception_code ) {
auto& fa = failed_accounts[n];
++fa.num_failures;
fa.add( n, exception_code );
}

// return true if exceeds max_failures_per_account and should be dropped
bool failure_limit( const account_name& n ) {
auto fitr = failed_accounts.find( n );
if( fitr != failed_accounts.end() && fitr->second.num_failures >= max_failures_per_account ) {
++fitr->second.num_failures;
return true;
}
return false;
}

void report() const {
if( _log.is_enabled( fc::log_level::debug ) ) {
for( const auto& e : failed_accounts ) {
std::string reason;
if( e.second.num_failures > max_failures_per_account ) {
reason.clear();
if( e.second.is_deadline() ) reason += "deadline";
if( e.second.is_tx_cpu_usage() ) {
if( !reason.empty() ) reason += ", ";
reason += "tx_cpu_usage";
}
if( e.second.is_eosio_assert() ) {
if( !reason.empty() ) reason += ", ";
reason += "assert";
}
if( e.second.is_other() ) {
if( !reason.empty() ) reason += ", ";
reason += "other";
}
fc_dlog( _log, "Dropped ${n} trxs, account: ${a}, reason: ${r} exceeded",
("n", e.second.num_failures - max_failures_per_account)("a", e.first)("r", reason) );
}
}
}
}

private:
struct account_failure {
enum class ex_fields : uint8_t {
ex_deadline_exception = 1,
ex_tx_cpu_usage_exceeded = 2,
ex_eosio_assert_exception = 4,
ex_other_exception = 8
};

void add( const account_name& n, int64_t exception_code ) {
if( exception_code == tx_cpu_usage_exceeded::code_value ) {
ex_flags = set_field( ex_flags, ex_fields::ex_tx_cpu_usage_exceeded );
} else if( exception_code == deadline_exception::code_value ) {
ex_flags = set_field( ex_flags, ex_fields::ex_deadline_exception );
} else if( exception_code == eosio_assert_message_exception::code_value ||
exception_code == eosio_assert_code_exception::code_value ) {
ex_flags = set_field( ex_flags, ex_fields::ex_eosio_assert_exception );
} else {
ex_flags = set_field( ex_flags, ex_fields::ex_other_exception );
fc_dlog( _log, "Failed trx, account: ${a}, reason: ${r}",
("a", n)("r", exception_code) );
}
}

bool is_deadline() const { return has_field( ex_flags, ex_fields::ex_deadline_exception ); }
bool is_tx_cpu_usage() const { return has_field( ex_flags, ex_fields::ex_tx_cpu_usage_exceeded ); }
bool is_eosio_assert() const { return has_field( ex_flags, ex_fields::ex_eosio_assert_exception ); }
bool is_other() const { return has_field( ex_flags, ex_fields::ex_other_exception ); }

uint32_t num_failures = 0;
uint8_t ex_flags = 0;
};

std::map<account_name, account_failure> failed_accounts;
};

} // anonymous namespace

bool producer_plugin_impl::process_unapplied_trxs( const fc::time_point& deadline )
{
bool exhausted = false;
if( !_unapplied_transactions.empty() ) {
account_failures account_fails;
chain::controller& chain = chain_plug->chain();
const auto& rl = chain.get_resource_limits_manager();
int num_applied = 0, num_failed = 0, num_processed = 0;
Expand All @@ -1898,7 +1920,7 @@ bool producer_plugin_impl::process_unapplied_trxs( const fc::time_point& deadlin
auto trx_deadline = start + fc::milliseconds( _max_transaction_time_ms );

auto first_auth = trx->packed_trx()->get_transaction().first_authorizer();
if( account_fails.failure_limit( first_auth ) ) {
if( _account_fails.failure_limit( first_auth ) ) {
++num_failed;
itr = _unapplied_transactions.erase( itr );
continue;
Expand Down Expand Up @@ -1936,7 +1958,7 @@ bool producer_plugin_impl::process_unapplied_trxs( const fc::time_point& deadlin
fc_dlog( _log, "Failed ${c} trx, prev billed: ${p}us, ran: ${r}us, id: ${id}",
("c", trace->except->code())("p", prev_billed_cpu_time_us)
("r", fc::time_point::now() - start)("id", trx->id()) );
account_fails.add( first_auth, failure_code );
_account_fails.add( first_auth, failure_code );
_subjective_billing.subjective_bill_failure( first_auth, trace->elapsed, fc::time_point::now() );
}
++num_failed;
Expand All @@ -1958,7 +1980,6 @@ bool producer_plugin_impl::process_unapplied_trxs( const fc::time_point& deadlin

fc_dlog( _log, "Processed ${m} of ${n} previously applied transactions, Applied ${applied}, Failed/Dropped ${failed}",
("m", num_processed)( "n", unapplied_trxs_size )("applied", num_applied)("failed", num_failed) );
account_fails.report();
}
return !exhausted;
}
Expand Down Expand Up @@ -2294,6 +2315,9 @@ void producer_plugin_impl::produce_block() {

block_state_ptr new_bs = chain.head_block_state();

_account_fails.report();
_account_fails.clear();

ilog("Produced block ${id}... #${n} @ ${t} signed by ${p} [trxs: ${count}, lib: ${lib}, confirmed: ${confs}]",
("p",new_bs->header.producer)("id",new_bs->id.str().substr(8,16))
("n",new_bs->block_num)("t",new_bs->header.timestamp)
Expand Down

0 comments on commit e9026d2

Please sign in to comment.