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

[3.2 -> 4.0] Report transaction failed if trx was exhausted in non-producing mode (GH 1247) #1329

Merged
merged 6 commits into from
Jun 22, 2023
Merged

[3.2 -> 4.0] Report transaction failed if trx was exhausted in non-producing mode (GH 1247) #1329

Changes from all commits
Commits
Show all changes
6 commits
Select commit Hold shift + click to select a range
41eaeef
Report transaction failed if trx was exhausted in non-producing mode
greg7mdp Jun 20, 2023
3e11f79
name/terminology update according to PR comments
greg7mdp Jun 20, 2023
2d3e786
Add `in_producing_mode()` and `in_speculating_mode()` members.
greg7mdp Jun 20, 2023
c293d33
Remove comment as per PR review.
greg7mdp Jun 21, 2023
5f763da
Merge pull request #1319 from AntelopeIO/gh-1247-3.2
greg7mdp Jun 21, 2023
76de72a
Merge branch 'release/3.2' of github.com:AntelopeIO/leap into gh-1247…
greg7mdp Jun 21, 2023
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
54 changes: 30 additions & 24 deletions plugins/producer_plugin/producer_plugin.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -568,7 +568,7 @@ class producer_plugin_impl : public std::enable_shared_from_this<producer_plugin

bool on_incoming_block(const signed_block_ptr& block, const std::optional<block_id_type>& block_id, const block_state_ptr& bsp) {
auto& chain = chain_plug->chain();
if ( _pending_block_mode == pending_block_mode::producing ) {
if ( in_producing_mode() ) {
fc_wlog( _log, "dropped incoming block #${num} id: ${id}",
("num", block->block_num())("id", block_id ? (*block_id).str() : "UNKNOWN") );
return false;
Expand Down Expand Up @@ -732,7 +732,7 @@ class producer_plugin_impl : public std::enable_shared_from_this<producer_plugin
try {
auto result = future.get();
if( !self->process_incoming_transaction_async( result, api_trx, return_failure_traces, next) ) {
if( self->_pending_block_mode == pending_block_mode::producing ) {
if( self->in_producing_mode() ) {
self->schedule_maybe_produce_block( true );
} else {
self->restart_speculative_block();
Expand Down Expand Up @@ -781,11 +781,16 @@ class producer_plugin_impl : public std::enable_shared_from_this<producer_plugin
const auto block_deadline = calculate_block_deadline( chain.pending_block_time() );
push_result pr = push_transaction( block_deadline, trx, api_trx, return_failure_trace, next );

exhausted = pr.block_exhausted;
if( pr.trx_exhausted ) {
_unapplied_transactions.add_incoming( trx, api_trx, return_failure_trace, next );
}

exhausted = pr.block_exhausted;

if ( !in_producing_mode() && pr.trx_exhausted )
exhausted = true; // report transaction exhausted if trx was exhausted in non-producing mode (so we will restart
// a speculative block to retry it immediately, instead of waiting to receive a new block)

} catch ( const guard_exception& e ) {
chain_plugin::handle_guard_exception(e);
} catch ( boost::interprocess::bad_alloc& ) {
Expand Down Expand Up @@ -836,6 +841,8 @@ class producer_plugin_impl : public std::enable_shared_from_this<producer_plugin
void schedule_delayed_production_loop(const std::weak_ptr<producer_plugin_impl>& weak_this, std::optional<fc::time_point> wake_up_time);
std::optional<fc::time_point> calculate_producer_wake_up_time( const block_timestamp_type& ref_block_time ) const;

bool in_producing_mode() const { return _pending_block_mode == pending_block_mode::producing; }
bool in_speculating_mode() const { return _pending_block_mode == pending_block_mode::speculating; }
};

void new_chain_banner(const eosio::chain::controller& db)
Expand Down Expand Up @@ -1330,7 +1337,7 @@ void producer_plugin::resume() {
// it is possible that we are only speculating because of this policy which we have now changed
// re-evaluate that now
//
if (my->_pending_block_mode == pending_block_mode::speculating) {
if (my->in_speculating_mode()) {
my->abort_block();
fc_ilog(_log, "Producer resumed. Scheduling production.");
my->schedule_production_loop();
Expand Down Expand Up @@ -1372,7 +1379,7 @@ void producer_plugin::update_runtime_options(const runtime_options& options) {
my->_incoming_defer_ratio = *options.incoming_defer_ratio;
}

if (check_speculating && my->_pending_block_mode == pending_block_mode::speculating) {
if (check_speculating && my->in_speculating_mode()) {
my->abort_block();
my->schedule_production_loop();
}
Expand Down Expand Up @@ -1826,7 +1833,7 @@ fc::time_point producer_plugin_impl::calculate_pending_block_time() const {
}

fc::time_point producer_plugin_impl::calculate_block_deadline( const fc::time_point& block_time ) const {
if( _pending_block_mode == pending_block_mode::producing ) {
if( in_producing_mode() ) {
bool last_block = ((block_timestamp_type( block_time ).slot % config::producer_repetitions) == config::producer_repetitions - 1);
return block_time + fc::microseconds(last_block ? _last_block_time_offset_us : _produce_time_offset_us);
} else {
Expand All @@ -1835,7 +1842,7 @@ fc::time_point producer_plugin_impl::calculate_block_deadline( const fc::time_po
}

bool producer_plugin_impl::should_interrupt_start_block( const fc::time_point& deadline, uint32_t pending_block_num ) const {
if( _pending_block_mode == pending_block_mode::producing ) {
if( in_producing_mode() ) {
return deadline <= fc::time_point::now();
}
// if we can produce then honor deadline so production starts on time
Expand Down Expand Up @@ -1896,7 +1903,7 @@ producer_plugin_impl::start_block_result producer_plugin_impl::start_block() {
_pending_block_mode = pending_block_mode::speculating;
}

if (_pending_block_mode == pending_block_mode::producing) {
if (in_producing_mode()) {
// determine if our watermark excludes us from producing at this point
if (current_watermark) {
const block_timestamp_type block_timestamp{block_time};
Expand All @@ -1916,13 +1923,13 @@ producer_plugin_impl::start_block_result producer_plugin_impl::start_block() {
}
}

if (_pending_block_mode == pending_block_mode::speculating) {
if (in_speculating_mode()) {
auto head_block_age = now - chain.head_block_time();
if (head_block_age > fc::seconds(5))
return start_block_result::waiting_for_block;
}

if (_pending_block_mode == pending_block_mode::producing) {
if (in_producing_mode()) {
const auto start_block_time = block_time - fc::microseconds( config::block_interval_us );
if( now < start_block_time ) {
fc_dlog(_log, "Not producing block waiting for production window ${n} ${bt}", ("n", pending_block_num)("bt", block_time) );
Expand All @@ -1944,7 +1951,7 @@ producer_plugin_impl::start_block_result producer_plugin_impl::start_block() {
try {
uint16_t blocks_to_confirm = 0;

if (_pending_block_mode == pending_block_mode::producing) {
if (in_producing_mode()) {
// determine how many blocks this producer can confirm
// 1) if it is not a producer from this node, assume no confirmations (we will discard this block anyway)
// 2) if it is a producer on this node that has never produced, the conservative approach is to assume no
Expand All @@ -1965,7 +1972,7 @@ producer_plugin_impl::start_block_result producer_plugin_impl::start_block() {
abort_block();

auto features_to_activate = chain.get_preactivated_protocol_features();
if( _pending_block_mode == pending_block_mode::producing && _protocol_features_to_activate.size() > 0 ) {
if( in_producing_mode() && _protocol_features_to_activate.size() > 0 ) {
bool drop_features_to_activate = false;
try {
chain.validate_protocol_features( _protocol_features_to_activate );
Expand Down Expand Up @@ -2007,15 +2014,14 @@ producer_plugin_impl::start_block_result producer_plugin_impl::start_block() {
}
}

controller::block_status bs = _pending_block_mode == pending_block_mode::producing ?
controller::block_status::incomplete : controller::block_status::ephemeral;
controller::block_status bs = in_producing_mode() ? controller::block_status::incomplete : controller::block_status::ephemeral;
chain.start_block( block_time, blocks_to_confirm, features_to_activate, bs, preprocess_deadline );
} LOG_AND_DROP();

if( chain.is_building_block() ) {
const auto& pending_block_signing_authority = chain.pending_block_signing_authority();

if (_pending_block_mode == pending_block_mode::producing && pending_block_signing_authority != scheduled_producer.authority) {
if (in_producing_mode() && pending_block_signing_authority != scheduled_producer.authority) {
elog("Unexpected block signing authority, reverting to speculative mode! [expected: \"${expected}\", actual: \"${actual\"", ("expected", scheduled_producer.authority)("actual", pending_block_signing_authority));
_pending_block_mode = pending_block_mode::speculating;
}
Expand All @@ -2036,7 +2042,7 @@ producer_plugin_impl::start_block_result producer_plugin_impl::start_block() {
// limit execution of pending incoming to once per block
auto incoming_itr = _unapplied_transactions.incoming_begin();

if (_pending_block_mode == pending_block_mode::producing) {
if (in_producing_mode()) {
if( !process_unapplied_trxs( preprocess_deadline ) )
return start_block_result::exhausted;

Expand Down Expand Up @@ -2094,7 +2100,7 @@ bool producer_plugin_impl::remove_expired_trxs( const fc::time_point& deadline )
++num_expired;
});

if( exhausted && _pending_block_mode == pending_block_mode::producing ) {
if( exhausted && in_producing_mode() ) {
fc_wlog( _log, "Unable to process all expired transactions of the ${n} transactions in the unapplied queue before deadline, "
"Expired ${expired}", ("n", orig_count)("expired", num_expired) );
} else {
Expand Down Expand Up @@ -2195,7 +2201,7 @@ void producer_plugin_impl::log_trx_results( const packed_transaction_ptr& trx,

bool except = except_ptr || (trace && trace->except);
if (except) {
if (_pending_block_mode == pending_block_mode::producing) {
if (in_producing_mode()) {
fc_dlog( is_transient ? _transient_trx_failed_trace_log : _trx_failed_trace_log,
"[TRX_TRACE] Block ${block_num} for producer ${prod} is REJECTING ${desc}tx: ${txid}, auth: ${a}, ${details}",
("block_num", chain.head_block_num() + 1)("prod", get_pending_block_producer())
Expand Down Expand Up @@ -2224,7 +2230,7 @@ void producer_plugin_impl::log_trx_results( const packed_transaction_ptr& trx,
}
}
} else {
if (_pending_block_mode == pending_block_mode::producing) {
if (in_producing_mode()) {
fc_dlog( is_transient ? _transient_trx_successful_trace_log : _trx_successful_trace_log, "[TRX_TRACE] Block ${block_num} for producer ${prod} is ACCEPTING ${desc}tx: ${txid}, auth: ${a}, cpu: ${cpu}",
("block_num", chain.head_block_num() + 1)("prod", get_pending_block_producer())("desc", is_transient ? "transient " : "")("txid", trx->id())
("a", trx->get_transaction().first_authorizer())("cpu", billed_cpu_us));
Expand Down Expand Up @@ -2289,7 +2295,7 @@ producer_plugin_impl::push_transaction( const fc::time_point& block_deadline,
sub_bill = _subjective_billing.get_subjective_bill( first_auth, fc::time_point::now() );

auto prev_billed_cpu_time_us = trx->billed_cpu_time_us;
if( _pending_block_mode == pending_block_mode::producing && prev_billed_cpu_time_us > 0 ) {
if( in_producing_mode() && prev_billed_cpu_time_us > 0 ) {
const auto& rl = chain.get_resource_limits_manager();
if ( !_subjective_billing.is_account_disabled( first_auth ) && !rl.is_unlimited_cpu( first_auth ) ) {
int64_t prev_billed_plus100_us = prev_billed_cpu_time_us + EOS_PERCENT( prev_billed_cpu_time_us, 100 * config::percent_1 );
Expand Down Expand Up @@ -2325,7 +2331,7 @@ producer_plugin_impl::handle_push_result( const transaction_metadata_ptr& trx,
_time_tracker.add_fail_time(dur, trx->is_transient());
}
if( exception_is_exhausted( *trace->except ) ) {
if( _pending_block_mode == pending_block_mode::producing ) {
if( in_producing_mode() ) {
fc_dlog(trx->is_transient() ? _transient_trx_failed_trace_log : _trx_failed_trace_log, "[TRX_TRACE] Block ${block_num} for producer ${prod} COULD NOT FIT, tx: ${txid} RETRYING ",
("block_num", chain.head_block_num() + 1)("prod", get_pending_block_producer())("txid", trx->id()));
} else {
Expand Down Expand Up @@ -2644,10 +2650,10 @@ void producer_plugin_impl::schedule_production_loop() {
} else if (result == start_block_result::waiting_for_production) {
// scheduled in start_block()

} else if (_pending_block_mode == pending_block_mode::producing) {
} else if (in_producing_mode()) {
schedule_maybe_produce_block( result == start_block_result::exhausted );

} else if (_pending_block_mode == pending_block_mode::speculating && !_producers.empty() && !production_disabled_by_policy()){
} else if (in_speculating_mode() && !_producers.empty() && !production_disabled_by_policy()){
chain::controller& chain = chain_plug->chain();
fc_dlog(_log, "Speculative Block Created; Scheduling Speculative/Production Change");
EOS_ASSERT( chain.is_building_block(), missing_pending_block_state, "speculating without pending_block_state" );
Expand Down Expand Up @@ -2764,7 +2770,7 @@ static auto maybe_make_debug_time_logger() -> std::optional<decltype(make_debug_
void producer_plugin_impl::produce_block() {
//ilog("produce_block ${t}", ("t", fc::time_point::now())); // for testing _produce_time_offset_us
auto start = fc::time_point::now();
EOS_ASSERT(_pending_block_mode == pending_block_mode::producing, producer_exception, "called produce_block while not actually producing");
EOS_ASSERT(in_producing_mode(), producer_exception, "called produce_block while not actually producing");
chain::controller& chain = chain_plug->chain();
EOS_ASSERT(chain.is_building_block(), missing_pending_block_state, "pending_block_state does not exist but it should, another plugin may have corrupted it");

Expand Down