Skip to content
This repository has been archived by the owner on Aug 2, 2022. It is now read-only.

Additional subjective CPU logging - 2.1.x #11074

Open
wants to merge 1 commit into
base: release/2.1.x
Choose a base branch
from
Open

Additional subjective CPU logging - 2.1.x #11074

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
6 changes: 4 additions & 2 deletions plugins/producer_plugin/include/eosio/producer_plugin/subjective_billing.hpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -174,10 +174,12 @@ class subjective_billing {
_block_subjective_bill_cache.clear();
}

void on_block( const block_state_ptr& bsp, const fc::time_point& now ) {
if( bsp == nullptr ) return;
void on_block( fc::logger& log, const block_state_ptr& bsp, const fc::time_point& now ) {
if( bsp == nullptr || _disabled ) return;
const auto time_ordinal = time_ordinal_for(now);
const auto orig_count = _account_subjective_bill_cache.size();
remove_subjective_billing( bsp, time_ordinal );
fc_dlog( log, "Subjective billed accounts ${n} removed ${r}", ("n", orig_count)("r", orig_count - _account_subjective_bill_cache.size()) );
}

bool remove_expired( fc::logger& log, const fc::time_point& pending_block_time, const fc::time_point& now, const fc::time_point& deadline ) {
Expand Down
38 changes: 18 additions & 20 deletions plugins/producer_plugin/producer_plugin.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -249,7 +249,7 @@ class producer_plugin_impl : public std::enable_shared_from_this<producer_plugin
void on_block( const block_state_ptr& bsp ) {
auto before = _unapplied_transactions.size();
_unapplied_transactions.clear_applied( bsp );
_subjective_billing.on_block( bsp, fc::time_point::now() );
_subjective_billing.on_block( _log, bsp, fc::time_point::now() );
fc_dlog( _log, "Removed applied transactions before: ${before}, after: ${after}",
("before", before)("after", _unapplied_transactions.size()) );
}
Expand Down Expand Up @@ -1769,28 +1769,26 @@ class account_failures {
return false;
}

void report() const {
void report(const subjective_billing& sub_bill) const {
if( _log.is_enabled( fc::log_level::debug ) ) {
auto now = fc::time_point::now();
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) );
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, "Failed ${n} trxs, account: ${a}, sub bill: ${b}us, reason: ${r}",
("n", e.second.num_failures)("b", sub_bill.get_subjective_bill(e.first, now))("a", e.first)("r", reason) );
}
}
}
Expand Down Expand Up @@ -1932,7 +1930,7 @@ 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();
account_fails.report(_subjective_billing);
}
return !exhausted;
}
Expand Down
10 changes: 5 additions & 5 deletions plugins/producer_plugin/test/test_subjective_billing.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -41,7 +41,7 @@ BOOST_AUTO_TEST_CASE( subjective_bill_test ) {
BOOST_CHECK_EQUAL( 13+11, sub_bill.get_subjective_bill(a, now) );
BOOST_CHECK_EQUAL( 9, sub_bill.get_subjective_bill(b, now) );

sub_bill.on_block({}, now);
sub_bill.on_block(log, {}, now);
sub_bill.abort_block(); // they all failed so nothing in aborted block

BOOST_CHECK_EQUAL( 13+11, sub_bill.get_subjective_bill(a, now) );
Expand Down Expand Up @@ -69,13 +69,13 @@ BOOST_AUTO_TEST_CASE( subjective_bill_test ) {
BOOST_CHECK_EQUAL( 23+19, sub_bill.get_subjective_bill(a, now) );
BOOST_CHECK_EQUAL( 7, sub_bill.get_subjective_bill(b, now) );

sub_bill.on_block({}, now); // have not seen any of the transactions come back yet
sub_bill.on_block(log, {}, now); // have not seen any of the transactions come back yet
sub_bill.abort_block();

BOOST_CHECK_EQUAL( 23+19, sub_bill.get_subjective_bill(a, now) );
BOOST_CHECK_EQUAL( 7, sub_bill.get_subjective_bill(b, now) );

sub_bill.on_block({}, now);
sub_bill.on_block(log, {}, now);
sub_bill.remove_subjective_billing( id1, 0 ); // simulate seeing id1 come back in block (this is what on_block would do)
sub_bill.abort_block();

Expand All @@ -96,13 +96,13 @@ BOOST_AUTO_TEST_CASE( subjective_bill_test ) {
BOOST_CHECK_EQUAL( 0, sub_bill.get_subjective_bill(b, now) ); // should not include what is in the pending block
BOOST_CHECK_EQUAL( 0, sub_bill.get_subjective_bill(c, now) );

sub_bill.on_block({}, now); // have not seen any of the transactions come back yet
sub_bill.on_block(log, {}, now); // have not seen any of the transactions come back yet
sub_bill.abort_block(); // aborts the pending block, so subjective billing needs to include the reverted trxs

BOOST_CHECK_EQUAL( 23+19+55+11, sub_bill.get_subjective_bill(a, now) );
BOOST_CHECK_EQUAL( 3+7, sub_bill.get_subjective_bill(b, now) );

sub_bill.on_block({}, now);
sub_bill.on_block(log, {}, now);
sub_bill.remove_subjective_billing( id3, 0 ); // simulate seeing id3 come back in block (this is what on_block would do)
sub_bill.remove_subjective_billing( id4, 0 ); // simulate seeing id4 come back in block (this is what on_block would do)
sub_bill.abort_block();
Expand Down