diff --git a/src/app/firedancer-dev/commands/backtest.c b/src/app/firedancer-dev/commands/backtest.c index 1980a4fa277..e2f325d5821 100644 --- a/src/app/firedancer-dev/commands/backtest.c +++ b/src/app/firedancer-dev/commands/backtest.c @@ -342,15 +342,16 @@ backtest_topo( config_t * config ) { fd_topo_obj_t * accdb_data = setup_topo_accdb_cache( topo, &config->firedancer ); - fd_topob_wksp( topo, "accdb_execrp" ); - fd_topo_tile_t * accdb_tile = fd_topob_tile( topo, "accdb", "accdb_execrp", "metric_in", cpu_idx++, 0, 0 ); + fd_topob_wksp( topo, "accdb" ); + fd_topo_tile_t * accdb_tile = fd_topob_tile( topo, "accdb", "accdb", "metric_in", cpu_idx++, 0, 0 ); fd_topob_tile_uses( topo, accdb_tile, accdb_data, FD_SHMEM_JOIN_MODE_READ_WRITE ); fd_topob_tile_uses( topo, replay_tile, accdb_data, FD_SHMEM_JOIN_MODE_READ_WRITE ); for( ulong i=0UL; itiles[ fd_topo_find_tile( topo, "execrp", i ) ], accdb_data, FD_SHMEM_JOIN_MODE_READ_WRITE ); } - fd_topob_wksp( topo, "accdb_replay" ); + fd_topob_link( topo, "accdb_trace", "accdb", 256UL, 64UL, 1UL )->permit_no_consumers = 1; + fd_topob_tile_out( topo, "accdb", 0UL, "accdb_trace", 0UL ); } /**********************************************************************/ diff --git a/src/app/firedancer-dev/main.c b/src/app/firedancer-dev/main.c index 1f0bf661869..bde5746ea6a 100644 --- a/src/app/firedancer-dev/main.c +++ b/src/app/firedancer-dev/main.c @@ -230,6 +230,7 @@ extern action_t fd_action_ipecho_server; extern action_t fd_action_send_test; extern action_t fd_action_gossip_dump; extern action_t fd_action_watch; +extern action_t fd_action_trace; action_t * ACTIONS[] = { &fd_action_run, @@ -267,6 +268,7 @@ action_t * ACTIONS[] = { &fd_action_send_test, &fd_action_gossip_dump, &fd_action_watch, + &fd_action_trace, NULL, }; diff --git a/src/app/firedancer/topology.c b/src/app/firedancer/topology.c index 69a9cfcda72..e7260b9bd28 100644 --- a/src/app/firedancer/topology.c +++ b/src/app/firedancer/topology.c @@ -724,6 +724,8 @@ fd_topo_initialize( config_t * config ) { fd_topob_tile_uses( topo, accdb_tile, accdb_data, FD_SHMEM_JOIN_MODE_READ_WRITE ); fd_topob_tile_uses( topo, accdb_tile, accdb_map_obj, FD_SHMEM_JOIN_MODE_READ_WRITE ); fd_topob_tile_uses( topo, accdb_tile, accdb_pool_obj, FD_SHMEM_JOIN_MODE_READ_WRITE ); + fd_topob_link( topo, "accdb_trace", "accdb", 256UL, 64UL, 1UL )->permit_no_consumers = 1; + fd_topob_tile_out( topo, "accdb", 0UL, "accdb_trace", 0UL ); fd_topob_tile_uses( topo, &topo->tiles[ fd_topo_find_tile( topo, "replay", 0UL ) ], accdb_data, FD_SHMEM_JOIN_MODE_READ_WRITE ); for( ulong i=0UL; i +#include +#include +#include +#include +#include + +/* Tile that busy polls metric links */ + +#define FXT_COLLECT_MAX 256 /* fxt source limit */ + +struct fxt_in { + fd_frag_meta_t const * mcache; + void const * base; + ulong seq; + ulong depth; +}; + +typedef struct fxt_in fxt_in_t; + +struct fxt_collect { + fd_trace_fxt_o_t * fxt; + + uint rng_seed; + + fxt_in_t in[ FXT_COLLECT_MAX ]; + ulong in_cnt; + + ulong drop_cnt; +}; + +typedef struct fxt_collect fxt_collect_t; + +static void +fxt_collect_run( fxt_collect_t * collect, + char const * out_path ) { + + fd_rng_t _rng[1]; fd_rng_t * rng = fd_rng_join( fd_rng_new( _rng, collect->rng_seed, 0UL ) ); + + fxt_in_t * in = collect->in; + ulong in_seq = 0UL; + ulong in_cnt = collect->in_cnt; + if( FD_UNLIKELY( !in_cnt ) ) FD_LOG_ERR(( "no links to poll" )); + + long lazy = (long)10e6; /* flush every 10ms */ + ulong async_min = fd_tempo_async_min( lazy, 1UL, (float)fd_tempo_tick_per_ns( NULL ) ); + + FILE * out = collect->fxt->file; + + FD_LOG_NOTICE(( "Exporting events to %s", out_path )); + long then = fd_tickcount(); + long now = then; + for(;;) { + + /* Do housekeeping at a low rate in the background */ + + if( FD_UNLIKELY( (now-then)>=0L ) ) { + if( FD_UNLIKELY( 0!=fflush( out ) ) ) FD_LOG_ERR(( "fflush(%s) failed: %i-%s", out_path, errno, fd_io_strerror( errno ) )); + if( FD_UNLIKELY( collect->drop_cnt ) ) { + FD_LOG_NOTICE(( "Detected %lu drop events", collect->drop_cnt )); + collect->drop_cnt = 0UL; + } + + /* Reload housekeeping timer */ + then = now + (long)fd_tempo_async_reload( rng, async_min ); + } + + /* Select which in to poll next (randomized round robin) */ + + if( FD_UNLIKELY( !in_cnt ) ) { now = fd_tickcount(); continue; } + fxt_in_t * this_in = &in[ in_seq ]; + in_seq++; + if( in_seq>=in_cnt ) in_seq = 0UL; /* cmov */ + + /* Check if this in has any new fragments to consume */ + + ulong this_in_seq = this_in->seq; + fd_frag_meta_t const * this_in_mline = this_in->mcache + fd_mcache_line_idx( this_in_seq, this_in->depth ); + + ulong seq_found = fd_frag_meta_seq_query( this_in_mline ); + + long diff = fd_seq_diff( this_in_seq, seq_found ); + if( FD_UNLIKELY( diff ) ) { /* Caught up or overrun, optimize for new frag case */ + if( FD_UNLIKELY( diff<0L ) ) { /* Overrun (impossible if in is honoring our flow control) */ + collect->drop_cnt++; + this_in->seq = seq_found; /* Resume from here (probably reasonably current, could query in mcache sync directly instead) */ + } + /* Don't bother with spin as polling multiple locations */ + now = fd_tickcount(); + continue; + } + + /* We have a new fragment to consume */ + + FD_COMPILER_MFENCE(); + ulong word0 = this_in_mline->sig; + ulong chunk = (ulong)this_in_mline->chunk; + ulong sz = (ulong)this_in_mline->sz; + ulong ctl = (ulong)this_in_mline->ctl; + ulong word1lo = (ulong)this_in_mline->tsorig; + ulong word2hi = (ulong)this_in_mline->tspub; + + if( FD_UNLIKELY( !sz || !fd_ulong_is_aligned( sz, 8UL ) ) ) { + FD_LOG_CRIT(( "Invalid FTF record size %#lx", sz )); + } + + if( ctl ) { + + /* external record */ + void const * buf = fd_chunk_to_laddr_const( this_in->base, chunk ); + /* FIXME missing bounds check */ + ulong written = fwrite( buf, sz, 1UL, out ); + if( FD_UNLIKELY( written!=1UL ) ) FD_LOG_ERR(( "fwrite(%s,%lu bytes) failed: %i-%s", out_path, sz, errno, fd_io_strerror( errno ) )); + + } else { + + /* inline record */ + if( FD_UNLIKELY( sz>16UL ) ) FD_LOG_CRIT(( "Invalid internal FTF record size %#lx", sz )); + ulong words[ 2 ] = { word0, word1lo+(word2hi<<32) }; + ulong written = fwrite( words, sz, 1UL, out ); + if( FD_UNLIKELY( written!=1UL ) ) FD_LOG_ERR(( "fwrite(%s,%lu bytes) failed: %i-%s", out_path, sz, errno, fd_io_strerror( errno ) )); + + } + + ulong seq_test = fd_frag_meta_seq_query( this_in_mline ); + + if( FD_UNLIKELY( fd_seq_ne( seq_test, seq_found ) ) ) { /* Overrun while reading (impossible if this_in honoring our fctl) */ + this_in->seq = seq_test; /* Resume from here (probably reasonably current, could query in mcache sync instead) */ + /* FIXME recover from overrun */ + collect->drop_cnt++; + /* Don't bother with spin as polling multiple locations */ + now = fd_tickcount(); + continue; + } + + /* Windup for the next in poll */ + + this_in_seq = fd_seq_inc( this_in_seq, 1UL ); + this_in->seq = this_in_seq; + } + + /* Technically unreachable ... */ + + fd_rng_delete( fd_rng_leave( rng ) ); + +} + +/* Command-line plumbing */ + +extern action_t * ACTIONS[]; + +static void +trace_args( int * pargc, + char *** pargv, + args_t * args ) { + char const * out_file = fd_env_strip_cmdline_cstr( pargc, pargv, "--out-file", NULL, NULL ); + char const * topo_name = fd_env_strip_cmdline_cstr( pargc, pargv, "--topo", NULL, "" ); + if( !out_file ) FD_LOG_ERR(( "Usage: firedancer trace --out-file " )); + fd_cstr_fini( fd_cstr_append_cstr_safe( fd_cstr_init( args->trace.fxt_path ), out_file, sizeof(args->trace.fxt_path)-1UL ) ); + fd_cstr_fini( fd_cstr_append_cstr_safe( fd_cstr_init( args->trace.topo ), topo_name, sizeof(args->trace.topo )-1UL ) ); +} + +static void +reconstruct_topo( config_t * config, + char const * topo_name ) { + if( !topo_name[0] ) return; /* keep default action topo */ + + action_t const * selected = NULL; + for( action_t ** a=ACTIONS; a; a++ ) { + action_t const * action = *a; + if( 0==strcmp( action->name, topo_name ) ) { + selected = action; + break; + } + } + + if( !selected ) FD_LOG_ERR(( "Unknown --topo %s", topo_name )); + if( !selected->topo ) FD_LOG_ERR(( "Cannot recover topology for --topo %s", topo_name )); + + selected->topo( config ); +} + +static void +trace_fn( args_t * args, + config_t * config ) { + reconstruct_topo( config, args->trace.topo ); + fd_topo_t * topo = &config->topo; + + /* Join FXT tracing shared memory rings */ + + static fxt_collect_t collect[1]; + collect->rng_seed = (uint)fd_tickcount(); + for( ulong i=0UL; i<(topo->link_cnt); i++ ) { + fd_topo_link_t const * link = &topo->links[ i ]; + ulong link_name_strlen = strlen( link->name ); + if( link_name_strlen<=6 || 0!=memcmp( link->name+link_name_strlen-6, "_trace", 7UL ) ) continue; + + fd_topo_wksp_t * link_wksp = &topo->workspaces[ topo->objs[ link->mcache_obj_id ].wksp_id ]; + fd_topo_join_workspace( topo, link_wksp, FD_SHMEM_JOIN_MODE_READ_ONLY, FD_TOPO_CORE_DUMP_LEVEL_REGULAR ); + fd_topo_workspace_fill( topo, link_wksp ); + if( FD_UNLIKELY( !link->mcache || !link->dcache ) ) continue; + + /* Found a new tile-metric region, join it */ + if( FD_UNLIKELY( collect->in_cnt>=FXT_COLLECT_MAX ) ) { + FD_LOG_WARNING(( "Too many fxt sources, too many tiles? Only exporting the first %u", (uint)FXT_COLLECT_MAX )); + } + FD_LOG_NOTICE(( "monitoring %s:%lu", link->name, link->kind_id )); + fxt_in_t * in = &collect->in[ collect->in_cnt++ ]; + in->mcache = link->mcache; + in->base = link->dcache; + in->seq = 0UL; + in->depth = fd_mcache_depth( in->mcache ); + } + + /* Set up a new FXT file */ + + int trace_fd = open( args->trace.fxt_path, O_WRONLY|O_CREAT|O_TRUNC, 0664 ); + if( FD_UNLIKELY( trace_fd<0 ) ) FD_LOG_ERR(( "open(%s) failed (%i-%s)", args->trace.fxt_path, errno, fd_io_strerror( errno ) )); + + fd_trace_fxt_o_t writer[1]; + if( FD_UNLIKELY( !fd_trace_fxt_o_new( writer, trace_fd ) ) ) { + FD_LOG_ERR(( "fd_trace_fxt_o_new failed" )); + } + int err = fd_trace_fxt_o_start( writer, &config->topo ); + if( FD_UNLIKELY( err ) ) FD_LOG_ERR(( "Failed to write .fxt header: %i-%s", err, fd_io_strerror( err ) )); + collect->fxt = writer; + + /* Busy poll events and export */ + + fxt_collect_run( collect, args->trace.fxt_path ); + + /* Done */ + + fd_trace_fxt_o_delete( writer ); +} + +void +trace_perm( args_t * args FD_PARAM_UNUSED, + fd_cap_chk_t * chk, + config_t const * config ) { + ulong mlock_limit = fd_topo_mlock( &config->topo ); + + fd_cap_chk_raise_rlimit( chk, "trace", RLIMIT_MEMLOCK, mlock_limit, "call `rlimit(2)` to increase `RLIMIT_MEMLOCK` so all memory can be locked with `mlock(2)`" ); + + if( fd_sandbox_requires_cap_sys_admin( config->uid, config->gid ) ) + fd_cap_chk_cap( chk, "trace", CAP_SYS_ADMIN, "call `unshare(2)` with `CLONE_NEWUSER` to sandbox the process in a user namespace" ); + if( FD_LIKELY( getuid() != config->uid ) ) + fd_cap_chk_cap( chk, "trace", CAP_SETUID, "call `setresuid(2)` to switch uid to the sandbox user" ); + if( FD_LIKELY( getgid() != config->gid ) ) + fd_cap_chk_cap( chk, "trace", CAP_SETGID, "call `setresgid(2)` to switch gid to the sandbox user" ); +} + +action_t fd_action_trace = { + .name = "trace", + .args = trace_args, + .fn = trace_fn, + .perm = trace_perm, + .description = "Export .fxt trace" +}; diff --git a/src/app/shared/fd_action.h b/src/app/shared/fd_action.h index 8e708c13c5c..e3a67e6001b 100644 --- a/src/app/shared/fd_action.h +++ b/src/app/shared/fd_action.h @@ -171,6 +171,12 @@ union fdctl_args { char const * pos_arg; int help; } tower; + + struct { + char fxt_path[ PATH_MAX ]; + char topo[ 64 ]; + } trace; + }; typedef union fdctl_args args_t; diff --git a/src/disco/trace/Local.mk b/src/disco/trace/Local.mk new file mode 100644 index 00000000000..47c8a489da8 --- /dev/null +++ b/src/disco/trace/Local.mk @@ -0,0 +1,7 @@ +$(call add-hdrs,fd_trace_target.h) +$(call add-objs,fd_trace_target,fd_disco) + +$(call add-hdrs,fd_trace_export.h) +$(call add-objs,fd_trace_export,fd_disco) + +$(call add-objs,generated/fd_trace_strings,fd_disco) diff --git a/src/disco/trace/fd_trace_target.c b/src/disco/trace/fd_trace_target.c new file mode 100644 index 00000000000..71de8769fea --- /dev/null +++ b/src/disco/trace/fd_trace_target.c @@ -0,0 +1,3 @@ +#include "fd_trace_target.h" + +FD_TL fd_fxt_pub_t * fd_fxt_pub_cur; diff --git a/src/disco/trace/fd_trace_target.h b/src/disco/trace/fd_trace_target.h new file mode 100644 index 00000000000..7642d735039 --- /dev/null +++ b/src/disco/trace/fd_trace_target.h @@ -0,0 +1,4 @@ +#include "../../tango/fxt/fd_fxt_pub.h" + +/* The current thread's trace target */ +extern FD_TL fd_fxt_pub_t * fd_fxt_pub_cur; diff --git a/src/disco/trace/generated/fd_trace_accdb.h b/src/disco/trace/generated/fd_trace_accdb.h new file mode 100644 index 00000000000..f2ab0f2a9e3 --- /dev/null +++ b/src/disco/trace/generated/fd_trace_accdb.h @@ -0,0 +1,125 @@ +/* THIS FILE IS GENERATED BY gen_tracing.py. DO NOT HAND EDIT. */ + +#include "../../../tango/fxt/fd_fxt_proto.h" +#include "../fd_trace_target.h" + +static inline void +fd_trace_vinyl_request_batch_enter( void ) { + ulong const words[] = { + fd_fxt_rec_event_hdr( + /* rec_sz */ 16UL, + /* event_type */ FD_FXT_EVENT_DURATION_BEGIN, + /* arg_cnt */ 0UL, + /* thread_ref */ fd_fxt_pub_cur->thread_id, + /* cat_ref */ 0UL, + /* name_ref */ 1UL ), + (ulong)fd_tickcount(), + }; + fd_fxt_pub_rec2( fd_fxt_pub_cur, words[0], words[1] ); +} + +static inline void +fd_trace_vinyl_request_batch_exit( void ) { + ulong const words[] = { + fd_fxt_rec_event_hdr( + /* rec_sz */ 16UL, + /* event_type */ FD_FXT_EVENT_DURATION_END, + /* arg_cnt */ 0UL, + /* thread_ref */ fd_fxt_pub_cur->thread_id, + /* cat_ref */ 0UL, + /* name_ref */ 1UL ), + (ulong)fd_tickcount(), + }; + fd_fxt_pub_rec2( fd_fxt_pub_cur, words[0], words[1] ); +} + +static inline void +fd_trace_vinyl_io_poll_enter( void ) { + ulong const words[] = { + fd_fxt_rec_event_hdr( + /* rec_sz */ 16UL, + /* event_type */ FD_FXT_EVENT_DURATION_BEGIN, + /* arg_cnt */ 0UL, + /* thread_ref */ fd_fxt_pub_cur->thread_id, + /* cat_ref */ 0UL, + /* name_ref */ 2UL ), + (ulong)fd_tickcount(), + }; + fd_fxt_pub_rec2( fd_fxt_pub_cur, words[0], words[1] ); +} + +static inline void +fd_trace_vinyl_io_poll_exit( void ) { + ulong const words[] = { + fd_fxt_rec_event_hdr( + /* rec_sz */ 16UL, + /* event_type */ FD_FXT_EVENT_DURATION_END, + /* arg_cnt */ 0UL, + /* thread_ref */ fd_fxt_pub_cur->thread_id, + /* cat_ref */ 0UL, + /* name_ref */ 2UL ), + (ulong)fd_tickcount(), + }; + fd_fxt_pub_rec2( fd_fxt_pub_cur, words[0], words[1] ); +} + +static inline void +fd_trace_vinyl_io_append_enter( void ) { + ulong const words[] = { + fd_fxt_rec_event_hdr( + /* rec_sz */ 16UL, + /* event_type */ FD_FXT_EVENT_DURATION_BEGIN, + /* arg_cnt */ 0UL, + /* thread_ref */ fd_fxt_pub_cur->thread_id, + /* cat_ref */ 0UL, + /* name_ref */ 3UL ), + (ulong)fd_tickcount(), + }; + fd_fxt_pub_rec2( fd_fxt_pub_cur, words[0], words[1] ); +} + +static inline void +fd_trace_vinyl_io_append_exit( void ) { + ulong const words[] = { + fd_fxt_rec_event_hdr( + /* rec_sz */ 16UL, + /* event_type */ FD_FXT_EVENT_DURATION_END, + /* arg_cnt */ 0UL, + /* thread_ref */ fd_fxt_pub_cur->thread_id, + /* cat_ref */ 0UL, + /* name_ref */ 3UL ), + (ulong)fd_tickcount(), + }; + fd_fxt_pub_rec2( fd_fxt_pub_cur, words[0], words[1] ); +} + +static inline void +fd_trace_vinyl_compact_enter( void ) { + ulong const words[] = { + fd_fxt_rec_event_hdr( + /* rec_sz */ 16UL, + /* event_type */ FD_FXT_EVENT_DURATION_BEGIN, + /* arg_cnt */ 0UL, + /* thread_ref */ fd_fxt_pub_cur->thread_id, + /* cat_ref */ 0UL, + /* name_ref */ 4UL ), + (ulong)fd_tickcount(), + }; + fd_fxt_pub_rec2( fd_fxt_pub_cur, words[0], words[1] ); +} + +static inline void +fd_trace_vinyl_compact_exit( void ) { + ulong const words[] = { + fd_fxt_rec_event_hdr( + /* rec_sz */ 16UL, + /* event_type */ FD_FXT_EVENT_DURATION_END, + /* arg_cnt */ 0UL, + /* thread_ref */ fd_fxt_pub_cur->thread_id, + /* cat_ref */ 0UL, + /* name_ref */ 4UL ), + (ulong)fd_tickcount(), + }; + fd_fxt_pub_rec2( fd_fxt_pub_cur, words[0], words[1] ); +} + diff --git a/src/disco/trace/generated/fd_trace_strings.c b/src/disco/trace/generated/fd_trace_strings.c new file mode 100644 index 00000000000..2f80aa893c3 --- /dev/null +++ b/src/disco/trace/generated/fd_trace_strings.c @@ -0,0 +1,12 @@ +/* THIS FILE IS GENERATED BY gen_tracing.py. DO NOT HAND EDIT. */ + +#include + +char const * fd_trace_strtab[] = { + "accdb", + "vinyl_request_batch", + "vinyl_io_poll", + "vinyl_io_append", + "vinyl_compact", + NULL +}; diff --git a/src/disco/trace/tracing.xml b/src/disco/trace/tracing.xml new file mode 100644 index 00000000000..3b635d35959 --- /dev/null +++ b/src/disco/trace/tracing.xml @@ -0,0 +1,15 @@ + + + + + + + + + + + + + + + diff --git a/src/discof/accdb/fd_accdb_tile.c b/src/discof/accdb/fd_accdb_tile.c index d16ad57f0cf..8bbda463f55 100644 --- a/src/discof/accdb/fd_accdb_tile.c +++ b/src/discof/accdb/fd_accdb_tile.c @@ -9,6 +9,7 @@ #define _GNU_SOURCE #include "../../disco/topo/fd_topo.h" +#include "../../disco/trace/generated/fd_trace_accdb.h" #include "../../disco/metrics/fd_metrics.h" #include "../../vinyl/fd_vinyl.h" #include "../../vinyl/fd_vinyl_base.h" @@ -85,6 +86,7 @@ struct fd_vinyl_tile { uint shutdown : 1; ulong volatile const * snapct_state; ulong volatile const * snapwm_pair_cnt; + fd_fxt_pub_t tracer[1]; /* I/O */ @@ -479,6 +481,10 @@ unprivileged_init( fd_topo_t * topo, } /* client join loop */ + ulong trace_out_idx = fd_topo_find_tile_out_link( topo, tile, "accdb_trace", 0UL ); + if( FD_UNLIKELY( trace_out_idx==ULONG_MAX ) ) FD_LOG_ERR(( "accdb_trace link not found" )); + fd_topo_link_t const * trace_out_link = &topo->links[ tile->out_link_id[ trace_out_idx ] ]; + fd_fxt_pub_cur = fd_fxt_pub_init( ctx->tracer, trace_out_link->mcache, trace_out_link->dcache, trace_out_link->mtu, tile->id+1UL ); } /* during_housekeeping is called periodically (approx every STEM_LAZY ns) */ @@ -570,7 +576,11 @@ during_housekeeping( fd_vinyl_tile_t * ctx ) { vinyl->garbage_sz += ctx->accum_garbage_sz; ctx->accum_garbage_sz = 0UL; ulong garbage_pre = vinyl->garbage_sz; - fd_vinyl_compact( vinyl, compact_max ); + if( compact_max ) { + fd_trace_vinyl_compact_enter(); + fd_vinyl_compact( vinyl, compact_max ); + fd_trace_vinyl_compact_exit(); + } FD_MCNT_INC( ACCDB, CUM_GC_BYTES, garbage_pre - vinyl->garbage_sz ); } @@ -772,6 +782,7 @@ before_credit( fd_vinyl_tile_t * ctx, /* Execute received requests */ for( ulong exec_rem=fd_ulong_min( ctx->req_tail-ctx->req_head, ctx->exec_max ); exec_rem; exec_rem-- ) { + fd_trace_vinyl_request_batch_enter(); fd_vinyl_req_t * req = ctx->_req + ((ctx->req_head++) & (FD_VINYL_REQ_MAX-1UL)); /* Determine the client that sent this request and unpack the @@ -812,6 +823,8 @@ before_credit( fd_vinyl_tile_t * ctx, ulong append_cnt = 0UL; ulong accum_cache_hit = 0UL; +# define TRACE_IO_APPEND_ENTER fd_trace_vinyl_io_append_enter() +# define TRACE_IO_APPEND_EXIT fd_trace_vinyl_io_append_exit() switch( req->type ) { # include "../../vinyl/fd_vinyl_case_acquire.c" @@ -845,7 +858,9 @@ before_credit( fd_vinyl_tile_t * ctx, for( ; read_cnt; read_cnt-- ) { fd_vinyl_io_rd_t * _rd; /* avoid pointer escape */ + fd_trace_vinyl_io_poll_enter(); fd_vinyl_io_poll( io, &_rd, FD_VINYL_IO_FLAG_BLOCKING ); + fd_trace_vinyl_io_poll_exit(); fd_vinyl_io_rd_t * rd = _rd; fd_vinyl_data_obj_t * obj = (fd_vinyl_data_obj_t *) rd->ctx; @@ -952,7 +967,7 @@ before_credit( fd_vinyl_tile_t * ctx, ulong const dead_cnt = accum_dead_cnt - ctx->accum_dead_cnt; FD_MCNT_INC( ACCDB, BLOCKS_PAIR, append_cnt - dead_cnt ); FD_MCNT_INC( ACCDB, BLOCKS_DEAD, dead_cnt ); - + fd_trace_vinyl_request_batch_exit(); } ctx->accum_dead_cnt = accum_dead_cnt;