Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add additional subjective cpu logging #52

Merged
merged 1 commit into from
Mar 12, 2022
+27 −27
Merged

Add additional subjective cpu logging #52

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 @@ -171,10 +171,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;
swatanabe marked this conversation as resolved.
Show resolved Hide resolved
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 @@ -282,7 +282,7 @@ class producer_plugin_impl : public std::enable_shared_from_this<producer_plugin

void on_block( const block_state_ptr& bsp ) {
_unapplied_transactions.clear_applied( bsp );
_subjective_billing.on_block( bsp, fc::time_point::now() );
_subjective_billing.on_block( _log, bsp, fc::time_point::now() );
}

void on_block_header( const block_state_ptr& bsp ) {
Expand Down Expand Up @@ -1824,28 +1824,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 @@ -1974,7 +1972,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