Skip to content

Commit

Permalink
fd_pack: add metric for time spent in various states
Browse files Browse the repository at this point in the history
  • Loading branch information
@ptaffet-jump @mmcgee-jump
ptaffet-jump authored and mmcgee-jump committed Mar 20, 2024
1 parent 3a7d3ce commit 3a5f73d
Show file tree
Hide file tree
Showing 5 changed files with 190 additions and 21 deletions.
54 changes: 52 additions & 2 deletions src/app/fdctl/run/tiles/fd_pack.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -110,8 +110,37 @@ typedef struct {
ulong insert_result[ FD_PACK_INSERT_RETVAL_CNT ];
fd_histf_t schedule_duration[ 1 ];
fd_histf_t insert_duration [ 1 ];

struct {
uint metric_state;
long metric_state_begin;
long metric_timing[ 16 ];
};
} fd_pack_ctx_t;


#define FD_PACK_METRIC_STATE_TRANSACTIONS 0
#define FD_PACK_METRIC_STATE_BANKS 1
#define FD_PACK_METRIC_STATE_LEADER 2
#define FD_PACK_METRIC_STATE_MICROBLOCKS 3

/* Updates one component of the metric state. If the state has changed,
records the change. */
static inline void
update_metric_state( fd_pack_ctx_t * ctx,
long effective_as_of,
int type,
int status ) {
uint current_state = fd_uint_insert_bit( ctx->metric_state, type, status );
if( FD_UNLIKELY( current_state!=ctx->metric_state ) ) {
FD_LOG_INFO(( "Transitioning to state %x by setting bit %i to %i", current_state, type, status ));
ctx->metric_timing[ ctx->metric_state ] += effective_as_of - ctx->metric_state_begin;
ctx->metric_state_begin = effective_as_of;
ctx->metric_state = current_state;
}
}


FD_FN_CONST static inline ulong
scratch_align( void ) {
return 4096UL;
Expand All @@ -138,7 +167,8 @@ static inline void
metrics_write( void * _ctx ) {
fd_pack_ctx_t * ctx = (fd_pack_ctx_t *)_ctx;

FD_MCNT_ENUM_COPY( PACK, TRANSACTION_INSERTED, ctx->insert_result );
FD_MCNT_ENUM_COPY( PACK, TRANSACTION_INSERTED, ctx->insert_result );
FD_MCNT_ENUM_COPY( PACK, METRIC_TIMING, ((ulong*)ctx->metric_timing) );
FD_MHIST_COPY( PACK, SCHEDULE_MICROBLOCK_DURATION_SECONDS, ctx->schedule_duration );
FD_MHIST_COPY( PACK, INSERT_TRANSACTION_DURATION_SECONDS, ctx->insert_duration );
}
Expand Down Expand Up @@ -183,6 +213,9 @@ after_credit( void * _ctx,
ctx->leader_slot = ULONG_MAX;
fd_pack_end_block( ctx->pack );
ctx->slot_microblock_cnt = 0UL;
update_metric_state( ctx, now, FD_PACK_METRIC_STATE_LEADER, 0 );
update_metric_state( ctx, now, FD_PACK_METRIC_STATE_BANKS, 0 );
update_metric_state( ctx, now, FD_PACK_METRIC_STATE_MICROBLOCKS, 0 );
return;
}

Expand All @@ -198,13 +231,16 @@ after_credit( void * _ctx,
doesn't always get the best transactions. */
ulong offset = fd_rng_ulong_roll( ctx->rng, bank_cnt );

int any_ready = 0;
int any_scheduled = 0;
/* Is it time to schedule the next microblock? For each banking
thread, if it's not busy... */
for( ulong _i=0UL; _i<bank_cnt; _i++ ) {
ulong i = (_i + offset)%bank_cnt;

/* optimize for the case we send a microblock */
if( FD_LIKELY( (fd_fseq_query( ctx->bank_current[i] )==ctx->bank_expect[i]) & (ctx->bank_ready_at[i]<now) ) ) {
any_ready = 1;

fd_pack_microblock_complete( ctx->pack, i );
/* TODO: record metrics for expire */
Expand All @@ -217,6 +253,7 @@ after_credit( void * _ctx,
fd_histf_sample( ctx->schedule_duration, (ulong)schedule_duration );

if( FD_LIKELY( schedule_cnt ) ) {
any_scheduled = 1;
ulong tspub = (ulong)fd_frag_meta_ts_comp( fd_tickcount() );
ulong chunk = ctx->out_chunk;
ulong msg_sz = schedule_cnt*sizeof(fd_txn_p_t);
Expand All @@ -237,9 +274,16 @@ after_credit( void * _ctx,
}
}
}
update_metric_state( ctx, now, FD_PACK_METRIC_STATE_BANKS, any_ready );
update_metric_state( ctx, now, FD_PACK_METRIC_STATE_MICROBLOCKS, any_scheduled );
now = fd_log_wallclock();
update_metric_state( ctx, now, FD_PACK_METRIC_STATE_TRANSACTIONS, fd_pack_avail_txn_cnt( ctx->pack )>0 );

/* Did we send the maximum allowed microblocks? Then end the slot. */
if( FD_UNLIKELY( ctx->slot_microblock_cnt==ctx->slot_max_microblocks )) {
update_metric_state( ctx, now, FD_PACK_METRIC_STATE_LEADER, 0 );
update_metric_state( ctx, now, FD_PACK_METRIC_STATE_BANKS, 0 );
update_metric_state( ctx, now, FD_PACK_METRIC_STATE_MICROBLOCKS, 0 );
ctx->leader_slot = ULONG_MAX;
ctx->slot_microblock_cnt = 0UL;
fd_pack_end_block( ctx->pack );
Expand Down Expand Up @@ -288,6 +332,7 @@ during_frag( void * _ctx,
ctx->slot_end_ns = 0L;
ctx->_slot_end_ns = became_leader->slot_end_ns;

update_metric_state( ctx, fd_log_wallclock(), FD_PACK_METRIC_STATE_LEADER, 1 );
return;
}

Expand Down Expand Up @@ -363,20 +408,22 @@ after_frag( void * _ctx,
(void)mux;

fd_pack_ctx_t * ctx = (fd_pack_ctx_t *)_ctx;
long now = fd_log_wallclock();

if( FD_UNLIKELY( in_idx==POH_IN_IDX ) ) {
ctx->slot_end_ns = ctx->_slot_end_ns;
fd_pack_set_block_limits( ctx->pack, ctx->slot_max_microblocks, ctx->slot_max_data );
} else {
/* Normal transaction case */
long insert_duration = -fd_tickcount();
int result = fd_pack_insert_txn_fini( ctx->pack, ctx->cur_spot, (ulong)(fd_log_wallclock()-LONG_MIN) );
int result = fd_pack_insert_txn_fini( ctx->pack, ctx->cur_spot, (ulong)(now-LONG_MIN) );
insert_duration += fd_tickcount();
ctx->insert_result[ result + FD_PACK_INSERT_RETVAL_OFF ]++;
fd_histf_sample( ctx->insert_duration, (ulong)insert_duration );

ctx->cur_spot = NULL;
}
update_metric_state( ctx, now, FD_PACK_METRIC_STATE_TRANSACTIONS, fd_pack_avail_txn_cnt( ctx->pack )>0 );
}

static void
Expand Down Expand Up @@ -437,6 +484,9 @@ unprivileged_init( fd_topo_t * topo,
FD_MHIST_SECONDS_MAX( PACK, SCHEDULE_MICROBLOCK_DURATION_SECONDS ) ) );
fd_histf_join( fd_histf_new( ctx->insert_duration, FD_MHIST_SECONDS_MIN( PACK, INSERT_TRANSACTION_DURATION_SECONDS ),
FD_MHIST_SECONDS_MAX( PACK, INSERT_TRANSACTION_DURATION_SECONDS ) ) );
ctx->metric_state = 0;
ctx->metric_state_begin = fd_log_wallclock();
memset( ctx->metric_timing, '\0', 16*sizeof(long) );

FD_LOG_INFO(( "packing microblocks of at most %lu transactions to %lu bank tiles", MAX_TXN_PER_MICROBLOCK, tile->pack.bank_tile_count ));

Expand Down
8 changes: 4 additions & 4 deletions src/ballet/pack/fd_pack.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1100,10 +1100,10 @@ fd_pack_schedule_next_microblock( fd_pack_t * pack,
pack->cumulative_block_cost += status.cus_scheduled;
pack->data_bytes_consumed += status.bytes_scheduled;

pack->microblock_cnt += (ulong)(scheduled>0UL);
pack->outstanding_microblock_mask |= 1UL << bank_tile;

if( FD_LIKELY( scheduled ) ) pack->data_bytes_consumed += MICROBLOCK_DATA_OVERHEAD;
ulong nonempty = (ulong)(scheduled>0UL);
pack->microblock_cnt += nonempty;
pack->outstanding_microblock_mask |= nonempty << bank_tile;
pack->data_bytes_consumed += nonempty * MICROBLOCK_DATA_OVERHEAD;

/* Update metrics counters */
FD_MGAUGE_SET( PACK, AVAILABLE_TRANSACTIONS, pack->pending_txn_cnt );
Expand Down
16 changes: 16 additions & 0 deletions src/disco/metrics/generated/fd_metrics_pack.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,22 @@ const fd_metrics_meta_t FD_METRICS_PACK[FD_METRICS_PACK_TOTAL] = {
DECLARE_METRIC_COUNTER( PACK, TRANSACTION_INSERTED_VOTE_ADD ),
DECLARE_METRIC_COUNTER( PACK, TRANSACTION_INSERTED_NONVOTE_REPLACE ),
DECLARE_METRIC_COUNTER( PACK, TRANSACTION_INSERTED_VOTE_REPLACE ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_NO_TXN_NO_BANK_NO_LEADER_NO_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_TXN_NO_BANK_NO_LEADER_NO_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_NO_TXN_BANK_NO_LEADER_NO_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_TXN_BANK_NO_LEADER_NO_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_NO_TXN_NO_BANK_LEADER_NO_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_TXN_NO_BANK_LEADER_NO_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_NO_TXN_BANK_LEADER_NO_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_TXN_BANK_LEADER_NO_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_NO_TXN_NO_BANK_NO_LEADER_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_TXN_NO_BANK_NO_LEADER_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_NO_TXN_BANK_NO_LEADER_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_TXN_BANK_NO_LEADER_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_NO_TXN_NO_BANK_LEADER_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_TXN_NO_BANK_LEADER_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_NO_TXN_BANK_LEADER_MICROBLOCK ),
DECLARE_METRIC_COUNTER( PACK, METRIC_TIMING_TXN_BANK_LEADER_MICROBLOCK ),
DECLARE_METRIC_GAUGE( PACK, AVAILABLE_TRANSACTIONS ),
DECLARE_METRIC_GAUGE( PACK, AVAILABLE_VOTE_TRANSACTIONS ),
DECLARE_METRIC_GAUGE( PACK, PENDING_TRANSACTIONS_HEAP_SIZE ),
Expand Down
Loading

0 comments on commit 3a5f73d

Please sign in to comment.