vere: add %near and %hela tracing hints

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

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')

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.
   **/

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 {

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))
+  if ( (c3y == u3r_trel(tok, &p_tok, &q_tok, &r_tok)) && (c3__bout == p_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(
+    c3_l pri_l = c3y == u3a_is_cat(p_q_tok) ? p_q_tok : 0;
-      u3nc(
+    dynamic_header(pri_l, u3k(q_q_tok), u3i_string(str_c));
-        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)
-        )
-      )
-    );
-
     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 );
   }

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);
+}
+