Skip to content

Commit

Permalink
GH-3 More descriptive emit logs
Browse files Browse the repository at this point in the history
  • Loading branch information
@heifner
heifner committed Apr 18, 2024
1 parent 344b778 commit ecc8cd4
Show file tree
Hide file tree
Showing 3 changed files with 24 additions and 24 deletions.
32 changes: 16 additions & 16 deletions libraries/chain/controller.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1417,7 +1417,7 @@ struct controller_impl {
for( auto bitr = branch.rbegin(); bitr != branch.rend() && should_process(*bitr); ++bitr ) {
apply_irreversible_block(forkdb, *bitr);

emit( irreversible_block, std::tie((*bitr)->block, (*bitr)->id()) );
emit( irreversible_block, std::tie((*bitr)->block, (*bitr)->id()), __FILE__, __LINE__ );

// blog.append could fail due to failures like running out of space.
// Do it before commit so that in case it throws, DB can be rolled back.
Expand Down Expand Up @@ -2537,7 +2537,7 @@ struct controller_impl {
pending->_block_report.total_elapsed_time += trace->elapsed;
pending->_block_report.total_time += trace->elapsed;
dmlog_applied_transaction(trace);
emit( applied_transaction, std::tie(trace, trx->packed_trx()) );
emit( applied_transaction, std::tie(trace, trx->packed_trx()), __FILE__, __LINE__ );
undo_session.squash();
return trace;
}
Expand Down Expand Up @@ -2602,7 +2602,7 @@ struct controller_impl {
trace->account_ram_delta = account_delta( gtrx.payer, trx_removal_ram_delta );

dmlog_applied_transaction(trace);
emit( applied_transaction, std::tie(trace, trx->packed_trx()) );
emit( applied_transaction, std::tie(trace, trx->packed_trx()), __FILE__, __LINE__ );

trx_context.squash();
undo_session.squash();
Expand Down Expand Up @@ -2646,7 +2646,7 @@ struct controller_impl {
trace->account_ram_delta = account_delta( gtrx.payer, trx_removal_ram_delta );
trace->elapsed = fc::time_point::now() - start;
dmlog_applied_transaction(trace);
emit( applied_transaction, std::tie(trace, trx->packed_trx()) );
emit( applied_transaction, std::tie(trace, trx->packed_trx()), __FILE__, __LINE__ );
undo_session.squash();
pending->_block_report.total_net_usage += trace->net_usage;
if( trace->receipt ) pending->_block_report.total_cpu_usage_us += trace->receipt->cpu_usage_us;
Expand Down Expand Up @@ -2690,12 +2690,12 @@ struct controller_impl {
trace->account_ram_delta = account_delta( gtrx.payer, trx_removal_ram_delta );

dmlog_applied_transaction(trace);
emit( applied_transaction, std::tie(trace, trx->packed_trx()) );
emit( applied_transaction, std::tie(trace, trx->packed_trx()), __FILE__, __LINE__ );

undo_session.squash();
} else {
dmlog_applied_transaction(trace);
emit( applied_transaction, std::tie(trace, trx->packed_trx()) );
emit( applied_transaction, std::tie(trace, trx->packed_trx()), __FILE__, __LINE__ );
}

pending->_block_report.total_net_usage += trace->net_usage;
Expand Down Expand Up @@ -2834,7 +2834,7 @@ struct controller_impl {
}

dmlog_applied_transaction(trace, &trn);
emit(applied_transaction, std::tie(trace, trx->packed_trx()));
emit( applied_transaction, std::tie(trace, trx->packed_trx()), __FILE__, __LINE__ );
}
}

Expand Down Expand Up @@ -2878,7 +2878,7 @@ struct controller_impl {

if (!trx->is_transient()) {
dmlog_applied_transaction(trace);
emit(applied_transaction, std::tie(trace, trx->packed_trx()));
emit( applied_transaction, std::tie(trace, trx->packed_trx()), __FILE__, __LINE__ );

pending->_block_report.total_net_usage += trace->net_usage;
if( trace->receipt ) pending->_block_report.total_cpu_usage_us += trace->receipt->cpu_usage_us;
Expand All @@ -2899,7 +2899,7 @@ struct controller_impl {
{
EOS_ASSERT( !pending, block_validate_exception, "pending block already exists" );

emit( block_start, chain_head.block_num() + 1 );
emit( block_start, chain_head.block_num() + 1, __FILE__, __LINE__ );

// at block level, no transaction specific logging is possible
if (auto dm_logger = get_deep_mind_logger(false)) {
Expand Down Expand Up @@ -3144,7 +3144,7 @@ struct controller_impl {
const auto& bsp = std::get<std::decay_t<decltype(forkdb.head())>>(cb.bsp.internal());
if( s == controller::block_status::incomplete ) {
forkdb.add( bsp, mark_valid_t::yes, ignore_duplicate_t::no );
emit( accepted_block_header, std::tie(bsp->block, bsp->id()) );
emit( accepted_block_header, std::tie(bsp->block, bsp->id()), __FILE__, __LINE__ );
} else {
assert(s != controller::block_status::irreversible);
forkdb.mark_valid( bsp );
Expand All @@ -3154,7 +3154,7 @@ struct controller_impl {
}

chain_head = block_handle{cb.bsp};
emit( accepted_block, std::tie(chain_head.block(), chain_head.id()) );
emit( accepted_block, std::tie(chain_head.block(), chain_head.id()), __FILE__, __LINE__ );

apply<void>(chain_head, [&](const auto& head) {
#warning todo: support deep_mind_logger even when in IF mode
Expand Down Expand Up @@ -3571,7 +3571,7 @@ struct controller_impl {
my_finalizers.maybe_vote(
*bsp->active_finalizer_policy, bsp, bsp->strong_digest, [&](const vote_message_ptr& vote) {
// net plugin subscribed to this signal. it will broadcast the vote message on receiving the signal
emit(voted_block, std::tuple{uint32_t{0}, vote_status::success, std::cref(vote)});
emit(voted_block, std::tuple{uint32_t{0}, vote_status::success, std::cref(vote)}, __FILE__, __LINE__);

// also aggregate our own vote into the pending_qc for this block, 0 connection_id indicates our own vote
process_vote_message(0, vote);
Expand Down Expand Up @@ -3862,7 +3862,7 @@ struct controller_impl {
if constexpr (std::is_same_v<BSP, typename std::decay_t<decltype(forkdb.head())>>)
forkdb.add( bsp, mark_valid_t::no, ignore_duplicate_t::yes );

emit( accepted_block_header, std::tie(bsp->block, bsp->id()) );
emit( accepted_block_header, std::tie(bsp->block, bsp->id()), __FILE__, __LINE__ );
};

fork_db.apply<void>(do_accept_block);
Expand Down Expand Up @@ -3900,7 +3900,7 @@ struct controller_impl {
trusted_producer_light_validation = true;
};

emit( accepted_block_header, std::tie(bsp->block, bsp->id()) );
emit( accepted_block_header, std::tie(bsp->block, bsp->id()), __FILE__, __LINE__ );

if( read_mode != db_read_mode::IRREVERSIBLE ) {
if constexpr (std::is_same_v<BSP, typename std::decay_t<decltype(forkdb.head())>>)
Expand Down Expand Up @@ -3949,15 +3949,15 @@ struct controller_impl {
});
}

emit(accepted_block_header, std::tie(bsp->block, bsp->id()));
emit( accepted_block_header, std::tie(bsp->block, bsp->id()), __FILE__, __LINE__ );

controller::block_report br;
if (s == controller::block_status::irreversible) {
apply_block(br, bsp, s, trx_meta_cache_lookup{});

// On replay, log_irreversible is not called and so no irreversible_block signal is emitted.
// So emit it explicitly here.
emit(irreversible_block, std::tie(bsp->block, bsp->id()));
emit( irreversible_block, std::tie(bsp->block, bsp->id()), __FILE__, __LINE__ );

if (!skip_db_sessions(s)) {
db.commit(bsp->block_num());
Expand Down
14 changes: 7 additions & 7 deletions libraries/chain/include/eosio/chain/controller.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -421,24 +421,24 @@ namespace eosio::chain {
*
*/
template<typename Signal, typename Arg>
void emit( const Signal& s, Arg&& a, const char* location = "" ) {
void emit( const Signal& s, Arg&& a, const char* file, uint32_t line ) {
try {
s( std::forward<Arg>( a ));
} catch (std::bad_alloc& e) {
wlog( "${l}std::bad_alloc: ${w}", ("l", location)("w", e.what()) );
wlog( "${f}:${l} std::bad_alloc: ${w}", ("f", file)("l", line)("w", e.what()) );
throw e;
} catch (boost::interprocess::bad_alloc& e) {
wlog( "${l}boost::interprocess::bad alloc: ${w}", ("l", location)("w", e.what()) );
wlog( "${f}:${l} boost::interprocess::bad alloc: ${w}", ("f", file)("l", line)("w", e.what()) );
throw e;
} catch ( controller_emit_signal_exception& e ) {
wlog( "${l}controller_emit_signal_exception: ${details}", ("l", location)("details", e.to_detail_string()) );
wlog( "${f}:${l} controller_emit_signal_exception: ${details}", ("f", file)("l", line)("details", e.to_detail_string()) );
throw e;
} catch ( fc::exception& e ) {
wlog( "${l}fc::exception: ${details}", ("l", location)("details", e.to_detail_string()) );
wlog( "${f}:${l} fc::exception: ${details}", ("f", file)("l", line)("details", e.to_detail_string()) );
} catch ( std::exception& e ) {
wlog( "std::exception: ${details}", ("l", location)("details", e.what()) );
wlog( "std::exception: ${details}", ("f", file)("l", line)("details", e.what()) );
} catch ( ... ) {
wlog( "${l}signal handler threw exception", ("l", location) );
wlog( "${f}:${l} signal handler threw exception", ("f", file)("l", line) );
}
}

Expand Down
2 changes: 1 addition & 1 deletion libraries/chain/include/eosio/chain/vote_processor.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -67,7 +67,7 @@ class vote_processor_t {
void emit(uint32_t connection_id, vote_status status, const vote_message_ptr& msg) {
if (connection_id != 0) { // this nodes vote was already signaled
if (status != vote_status::duplicate) { // don't bother emitting duplicates
chain::emit( vote_signal, std::tuple{connection_id, status, std::cref(msg)}, "vote " );
chain::emit( vote_signal, std::tuple{connection_id, status, std::cref(msg)}, __FILE__, __LINE__ );
}
}
}
Expand Down

0 comments on commit ecc8cd4

Please sign in to comment.