From 0917f694c96036b93cb86c51b20c0459857ce319 Mon Sep 17 00:00:00 2001 From: DaneBettis Date: Mon, 29 Nov 2021 20:52:06 +0000 Subject: [PATCH] vere: add %near and %hela tracing hints --- pkg/urbit/include/all.h | 2 +- pkg/urbit/include/c/motes.h | 2 + pkg/urbit/include/noun/trace.h | 23 +++++++++ pkg/urbit/noun/manage.c | 3 +- pkg/urbit/noun/nock.c | 81 +++++++++++++++++++++++------ pkg/urbit/noun/trace.c | 94 ++++++++++++++++++++++++++++++++++ 6 files changed, 186 insertions(+), 19 deletions(-) diff --git a/pkg/urbit/include/all.h b/pkg/urbit/include/all.h index b138c6d408..c1b7663be1 100644 --- a/pkg/urbit/include/all.h +++ b/pkg/urbit/include/all.h @@ -21,11 +21,11 @@ # include "noun/jets.h" // u3j: jet control # include "noun/log.h" // u3l: logging # include "noun/manage.h" // u3m: master state +# include "noun/trace.h" // u3t: profiling / tracing # include "noun/nock.h" // u3n: nock execution # include "noun/options.h" // u3o: config options # include "noun/retrieve.h" // u3r: noun access (error returns) # include "noun/serial.h" // u3s: serialization -# include "noun/trace.h" // u3t: profiling / tracing # include "noun/xtract.h" // u3x: noun access (error crashes) # include "noun/urth.h" // u3u: off-loom integration # include "noun/vortex.h" // u3v: arvo kernel diff --git a/pkg/urbit/include/c/motes.h b/pkg/urbit/include/c/motes.h index 789fd209f8..8dad329ac2 100644 --- a/pkg/urbit/include/c/motes.h +++ b/pkg/urbit/include/c/motes.h @@ -525,6 +525,7 @@ # define c3__head c3_s4('h','e','a','d') # define c3__heal c3_s4('h','e','a','l') # define c3__hear c3_s4('h','e','a','r') +# define c3__hela c3_s4('h','e','l','a') # define c3__helm c3_s4('h','e','l','m') # define c3__helo c3_s4('h','e','l','o') # define c3__help c3_s4('h','e','l','p') @@ -770,6 +771,7 @@ # define c3__nap c3_s3('n','a','p') # define c3__narv c3_s4('n','a','r','v') # define c3__ne c3_s2('n','e') +# define c3__near c3_s4('n','e', 'a', 'r') # define c3__need c3_s4('n','e','e','d') # define c3__neft c3_s4('n','e','f','t') # define c3__nest c3_s4('n','e','s','t') diff --git a/pkg/urbit/include/noun/trace.h b/pkg/urbit/include/noun/trace.h index 28b42151d7..349276c17e 100644 --- a/pkg/urbit/include/noun/trace.h +++ b/pkg/urbit/include/noun/trace.h @@ -130,6 +130,29 @@ void u3t_boot(void); + /* dynamic_header: slog a vere headline, and hoon hint with + * a given indent-style c3_l int (assumed 0-3). + */ + void + dynamic_header(c3_l pri_l, u3_noun headline, u3_noun message); + + /* slog_trace: given an indent-style c3_l int and a raw stack tax + * flop the order into start-to-end, render, and slog each item + * until done. + */ + void + slog_trace(c3_l pri_l, u3_noun tax); + + /* near_trace: slog only the deepest road's trace + */ + void + near_trace(c3_l pri_l); + + /* full_trace: join all roads' traces together into one tax + * and pass it to slog_trace allong with the given pri_l + */ + void + full_trace(c3_l pri_l); /** Globals. **/ diff --git a/pkg/urbit/noun/manage.c b/pkg/urbit/noun/manage.c index f6e6928246..f69ec08062 100644 --- a/pkg/urbit/noun/manage.c +++ b/pkg/urbit/noun/manage.c @@ -1796,7 +1796,8 @@ u3m_boot(c3_c* dir_c) if ( c3n == nuu_o ) { u3j_ream(); u3n_ream(); - + // TODO: remove me before PR + u3m_reclaim(); return u3A->eve_d; } else { diff --git a/pkg/urbit/noun/nock.c b/pkg/urbit/noun/nock.c index f2ec04e644..343dee47cb 100644 --- a/pkg/urbit/noun/nock.c +++ b/pkg/urbit/noun/nock.c @@ -1020,7 +1020,8 @@ _n_bint(u3_noun* ops, u3_noun hif, u3_noun nef, c3_o los_o, c3_o tel_o) default: { return _n_comp(ops, nef, los_o, tel_o); } - + case c3__near: + case c3__hela: case c3__bout: { u3_noun fen = u3_nul; c3_w nef_w = _n_comp(&fen, nef, los_o, tel_o); @@ -1055,7 +1056,8 @@ _n_bint(u3_noun* ops, u3_noun hif, u3_noun nef, c3_o los_o, c3_o tel_o) ++tot_w; _n_emit(ops, TOSS); tot_w += _n_comp(ops, nef, los_o, tel_o); } break; - + case c3__near: + case c3__hela: case c3__bout: { u3_noun fen = u3_nul; c3_w nef_w = _n_comp(&fen, nef, los_o, tel_o); @@ -1685,6 +1687,20 @@ u3n_find(u3_noun key, u3_noun fol) return pog_p; } +/* TODO: + * - DONE: move slog tracing functions to trace.h/trace.c + * - DONE: implement hints for near and full trace + * - clean up style of docs etc + * - add a test for each hint to the hoon test suite + * - make it a test series of its own + * - is there a hoon test set for jets/hints/vere? + * - maybe in dir run or dir bug ... + * - submit a PR + * - ask world about pretty after pr merge + * - BONUS: setup home-manager with my new nix files + */ + + /* _n_hilt_fore(): literal (atomic) dynamic hint, before formula evaluation. ** hin: [hint-atom, formula]. TRANSFER ** bus: subject. RETAIN @@ -1700,6 +1716,18 @@ _n_hilt_fore(u3_noun hin, u3_noun bus, u3_noun* out) u3_atom now = u3i_chub(u3t_trace_time()); *out = u3i_cell(u3h(hin), now); } + else if ( c3__near == u3h(hin) ) { + // this will run BEFORE calling the wrapped code + // thus it prints a trace UPTO the call site + near_trace(0); + *out = u3_nul; + } + else if ( c3__hela == u3h(hin) ) { + // this will run BEFORE calling the wrapped code + // thus it prints a trace UPTO the call site + full_trace(0); + *out = u3_nul; + } else { *out = u3_nul; } @@ -1723,6 +1751,11 @@ _n_hilt_hind(u3_noun tok, u3_noun pro) u3t_slog(u3nc(0, u3i_string(str_c))); u3z(delta); } + else if ( (c3y == u3r_cell(tok, &p_tok, &q_tok)) && + ((c3__near == p_tok) || (c3__hela == p_tok)) + ) { + // DO NOTHING + } else { c3_assert( u3_nul == tok ); } @@ -1742,7 +1775,7 @@ _n_hilt_hind(u3_noun tok, u3_noun pro) static c3_o _n_hint_fore(u3_cell hin, u3_noun bus, u3_noun* clu) { - if ( c3__bout == u3h(hin) ) { + if ( c3__bout == u3h(hin) || c3__near == u3h(hin) || c3__hela == u3h(hin) ) { u3_atom now = u3i_chub(u3t_trace_time()); *clu = u3i_trel(u3h(hin), *clu, now); } @@ -1763,9 +1796,7 @@ static void _n_hint_hind(u3_noun tok, u3_noun pro) { u3_noun p_tok, q_tok, r_tok; - if ( (c3y == u3r_trel(tok, &p_tok, &q_tok, &r_tok)) - && (c3__bout == p_tok) ) - { + if ( (c3y == u3r_trel(tok, &p_tok, &q_tok, &r_tok)) && (c3__bout == p_tok) ) { // get the microseconds elapsed u3_atom delta = u3ka_sub(u3i_chub(u3t_trace_time()), u3k(r_tok)); @@ -1782,19 +1813,35 @@ _n_hint_hind(u3_noun tok, u3_noun pro) // "q_q_tok: report" // prepend the priority to form a cell of the same shape q_tok // send this to ut3_slog so that it can be logged out - u3t_slog( - u3nc( - u3k(p_q_tok), - u3nt( - c3__rose, - u3nt(u3nt(':', ' ', u3_nul), u3_nul, u3_nul), - u3nt(u3k(q_q_tok), u3i_string(str_c), u3_nul) - ) - ) - ); - + c3_l pri_l = c3y == u3a_is_cat(p_q_tok) ? p_q_tok : 0; + dynamic_header(pri_l, u3k(q_q_tok), u3i_string(str_c)); u3z(delta); } + else if ( (c3y == u3r_trel(tok, &p_tok, &q_tok, &r_tok)) && + ((c3__near == p_tok) || (c3__hela == p_tok)) + ) { + // unpack q_tok to get the priority integer and the tank + // p_q_tok is the priority, q_q_tok is the tank we will work with + u3_noun p_q_tok, q_q_tok; + c3_assert(c3y == u3r_cell(q_tok, &p_q_tok, &q_q_tok)); + + // format the timing report + c3_c str_c[64]; + snprintf(str_c, 63, "trace of"); + + // join the timing report with the original tank from q_q_tok like so: + // "q_q_tok: report" + // prepend the priority to form a cell of the same shape q_tok + // send this to ut3_slog so that it can be logged out + c3_l pri_l = c3y == u3a_is_cat(p_q_tok) ? p_q_tok : 0; + dynamic_header(pri_l, u3i_string(str_c), u3k(q_q_tok)); + if (c3__near == p_tok) { + near_trace(pri_l); + } + else { + full_trace(pri_l); + } + } else { c3_assert( u3_nul == tok ); } diff --git a/pkg/urbit/noun/trace.c b/pkg/urbit/noun/trace.c index 1ee8168c70..78918829c6 100644 --- a/pkg/urbit/noun/trace.c +++ b/pkg/urbit/noun/trace.c @@ -589,3 +589,97 @@ u3t_boff(void) #endif } } + +/* where pir_l is the priority, headline is provided by the c-caller + * and message is provided by the hint-caller + */ +void +dynamic_header(c3_l pri_l, u3_noun headline, u3_noun message) +{ + u3t_slog( + u3nc( + pri_l, + u3nt( + c3__rose, + u3nt(u3nt(':', ' ', u3_nul), u3_nul, u3_nul), + u3nt(headline, message, u3_nul) + ) + ) + ); +} + +/* This flops the given tax and slogs it entry by entry. + */ +void +slog_trace +(c3_l pri_l, u3_noun tax) +{ + // render the stack + // Note: ton is a reference to a data struct + // we have just allocated + // lit is a used as a moving cursor pointer through + // that allocated struct + // once we finish lit will be null, but ton will still + // point to the whole valid allocated data structure + // and thus we can free it safely at the end of the func + // to clean up after ourselves. + // Note: flop reverses the stack trace list 'tax' + u3_noun ton = u3dc("mook", 2, u3kb_flop(tax)); + u3_noun lit = u3t(ton); + + // TODO: we need to clean the means in the stack where we add + // "call: failed", and "[ %gall-call-failed" + + // print the stack one stack item at a time + while ( u3_nul != lit ) { + u3t_slog(u3nc(pri_l, u3k(u3h(lit)) )); + lit = u3t(lit); + } + + u3z(ton); +} + +/* this function calls slog_trace on the same road + * as the wrapped hoon function was called in effectively + * showing only the short trace from just after the most + * recent virtualization, down into the wrap site + * it takes a c3_l pri_l + */ +void +near_trace(c3_l pri_l) +{ + u3_noun tax = u3k(u3R->bug.tax); + slog_trace(pri_l, tax); +} + +/* this function joins all the road traces together + * into a sinlge trace, which it sends to slog_trace + */ +void +full_trace(c3_l pri_l) +{ + /* Goals: + * 01. DONE: print lines in the correct order + * 02. print only what we must per line, since we can see the whole stack + * 03. emphasize which clause in the last block led to the call of the next block? + * 04. emphasize virtualization changes + * 05. make the visual xp pretty, clear, and informative + */ + + // rod_u protects us from mutating the global state + u3_road* rod_u = u3R; + + // inits to the the current road's trace + u3_noun tax = u3k(rod_u->bug.tax); + + // while there is a parent road ref ... + while ( &(u3H->rod_u) != rod_u ) { + // ... point at the next road and append its stack to tax + rod_u = u3tn(u3_road, rod_u->par_p); + // TODO: we can insert another mean or spot between tax, u3k(.. + tax = u3kb_weld(tax, u3k(rod_u->bug.tax)); + } + + slog_trace(pri_l, tax); +} +