feat(tracegrind): add ENTER_INLINED/EXIT_INLINED events for inline function tracking

Track inlined function transitions at the BB level using Valgrind's
debug info API. This bumps the trace format to v3 with two new event
types (4=ENTER_INLINED, 5=EXIT_INLINED), updates the analyzer script
to handle them, and adds regression tests for enter and nested inlined
scenarios.

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>

Author: art049

tracegrind/bb.c

@@ -143,6 +143,7 @@ static BB* new_bb(obj_node* obj, PtrdiffT offset,
    bb->fn          = 0;
    bb->line        = 0;
    bb->is_entry    = 0;
+   bb->inl_fn      = NULL;
    bb->bbcc_list   = 0;
    bb->last_bbcc   = 0;
 

tracegrind/bbcc.c

@@ -830,6 +830,21 @@ void TG_(setup_bbcc)(BB* bb)
   }
 
   TG_(current_state).bbcc = bbcc;
+
+  /* Check for inline function transition */
+  if (TG_(current_state).collect) {
+      thread_info* ti = TG_(get_current_thread)();
+      if (ti && bb->inl_fn != ti->cur_inl_fn) {
+          if (ti->cur_inl_fn != NULL) {
+              TG_(trace_emit_exit_inlined)(TG_(current_tid), bb, ti->cur_inl_fn);
+          }
+          if (bb->inl_fn != NULL) {
+              TG_(trace_emit_enter_inlined)(TG_(current_tid), bb);
+          }
+          ti->cur_inl_fn = bb->inl_fn;
+      }
+  }
+
   /* Even though this will be set in instrumented code directly before
    * side exits, it needs to be set to 0 here in case an exception
    * happens in first instructions of the BB */

tracegrind/callstack.c

@@ -234,6 +234,14 @@ void TG_(push_call_stack)(BBCC* from, UInt jmp, BBCC* to, Addr sp, Bool skip)
 
     /* Emit trace sample on function entry */
     if (!skip && TG_(current_state).collect) {
+	/* Emit EXIT_INLINED if we're entering a new function while inside inlined code */
+	thread_info* ti = TG_(get_current_thread)();
+	if (ti && ti->cur_inl_fn != NULL && TG_(current_state).bbcc) {
+	    TG_(trace_emit_exit_inlined)(TG_(current_tid),
+					 TG_(current_state).bbcc->bb,
+					 ti->cur_inl_fn);
+	    ti->cur_inl_fn = NULL;
+	}
 	fn_node* to_fn = to->cxt->fn[0];
 	TG_(trace_emit_sample)(TG_(current_tid), True, to_fn);
     }
@@ -335,6 +343,14 @@ void TG_(pop_call_stack)(void)
 
 	/* Emit trace sample on function exit */
 	if (TG_(current_state).collect) {
+	    /* Emit EXIT_INLINED if we're leaving while inside inlined code */
+	    thread_info* ti = TG_(get_current_thread)();
+	    if (ti && ti->cur_inl_fn != NULL && TG_(current_state).bbcc) {
+		TG_(trace_emit_exit_inlined)(TG_(current_tid),
+					     TG_(current_state).bbcc->bb,
+					     ti->cur_inl_fn);
+		ti->cur_inl_fn = NULL;
+	    }
 	    TG_(trace_emit_sample)(TG_(current_tid), False, to_fn);
 	}
 

tracegrind/dump.c

@@ -116,15 +116,15 @@ static void msgpack_write_header(void)
 
     /* version */
     msgpack_write_key(&hdr, "version");
-    msgpack_write_uint(&hdr, 2);
+    msgpack_write_uint(&hdr, 3);
 
     /* format */
     msgpack_write_key(&hdr, "format");
     msgpack_write_str(&hdr, "tracegrind-msgpack", -1);
 
     /* event_schemas - discriminated union: each event type has its own schema */
     msgpack_write_key(&hdr, "event_schemas");
-    msgpack_write_map_header(&hdr, 4);  /* 4 event types: MARKER, ENTER, EXIT, FORK */
+    msgpack_write_map_header(&hdr, 6);  /* 6 event types: MARKER, ENTER, EXIT, FORK, ENTER_INLINED, EXIT_INLINED */
 
     /* Event type 0 (MARKER) schema */
     msgpack_write_key(&hdr, "0");
@@ -156,6 +156,20 @@ static void msgpack_write_header(void)
     msgpack_write_str(&hdr, "event", -1);
     msgpack_write_str(&hdr, "child_pid", -1);
 
+    /* Event type 4 (ENTER_INLINED) schema - same columns as ENTER/EXIT */
+    msgpack_write_key(&hdr, "4");
+    msgpack_write_array_header(&hdr, mp_state.ncols);
+    for (Int i = 0; i < mp_state.ncols; i++) {
+        msgpack_write_str(&hdr, mp_state.col_names[i], -1);
+    }
+
+    /* Event type 5 (EXIT_INLINED) schema - same columns as ENTER/EXIT */
+    msgpack_write_key(&hdr, "5");
+    msgpack_write_array_header(&hdr, mp_state.ncols);
+    for (Int i = 0; i < mp_state.ncols; i++) {
+        msgpack_write_str(&hdr, mp_state.col_names[i], -1);
+    }
+
     /* Compress and write header chunk */
     SizeT src_size = hdr.size;
     SizeT dst_capacity = tg_lz4_compress_bound(src_size);
@@ -164,8 +178,8 @@ static void msgpack_write_header(void)
     SizeT compressed_size = tg_lz4_compress(
         compressed, dst_capacity, hdr.data, src_size);
 
-    /* Magic + version (8 bytes): "TGMP" + version(4) - version 2 */
-    UChar magic[8] = {'T', 'G', 'M', 'P', 0x02, 0x00, 0x00, 0x00};
+    /* Magic + version (8 bytes): "TGMP" + version(4) - version 3 */
+    UChar magic[8] = {'T', 'G', 'M', 'P', 0x03, 0x00, 0x00, 0x00};
     VG_(write)(TG_(trace_out).fd, magic, 8);
 
     /* Header chunk size (4 bytes uncompressed, 4 bytes compressed) */
@@ -439,6 +453,92 @@ void TG_(trace_emit_sample)(ThreadId tid, Bool is_enter,
                     deltas, es->size);
 }
 
+void TG_(trace_emit_enter_inlined)(ThreadId tid, BB* bb)
+{
+    Int i;
+
+    if (!TG_(trace_out).initialized) return;
+    if (TG_(trace_out).fd < 0) return;
+
+    thread_info* ti = TG_(get_current_thread)();
+    if (!ti) return;
+
+    EventSet* es = TG_(sets).full;
+    FullCost current_cost = TG_(current_state).cost;
+
+    if (!ti->last_sample_cost) {
+        ti->last_sample_cost = TG_(get_eventset_cost)(es);
+        TG_(init_cost)(es, ti->last_sample_cost);
+    }
+
+    TG_(trace_out).seq++;
+
+    const HChar* fn_name = bb->inl_fn;
+    const HChar* obj_name = bb->obj ? bb->obj->name : "???";
+    const HChar* file_name = (bb->fn && bb->fn->file) ? bb->fn->file->name : "???";
+    UInt line = bb->line;
+
+    ULong deltas[64];
+    tl_assert(es->size <= 64);
+    if (current_cost && ti->last_sample_cost) {
+        for (i = 0; i < es->size; i++) {
+            deltas[i] = current_cost[i] - ti->last_sample_cost[i];
+        }
+        TG_(copy_cost)(es, ti->last_sample_cost, current_cost);
+    } else {
+        for (i = 0; i < es->size; i++) {
+            deltas[i] = 0;
+        }
+    }
+
+    msgpack_add_row(TG_(trace_out).seq, (Int)tid, TG_EV_ENTER_INLINED,
+                    fn_name, obj_name, file_name, (Int)line,
+                    deltas, es->size);
+}
+
+void TG_(trace_emit_exit_inlined)(ThreadId tid, BB* bb, const HChar* inl_fn)
+{
+    Int i;
+
+    if (!TG_(trace_out).initialized) return;
+    if (TG_(trace_out).fd < 0) return;
+
+    thread_info* ti = TG_(get_current_thread)();
+    if (!ti) return;
+
+    EventSet* es = TG_(sets).full;
+    FullCost current_cost = TG_(current_state).cost;
+
+    if (!ti->last_sample_cost) {
+        ti->last_sample_cost = TG_(get_eventset_cost)(es);
+        TG_(init_cost)(es, ti->last_sample_cost);
+    }
+
+    TG_(trace_out).seq++;
+
+    const HChar* fn_name = inl_fn;
+    const HChar* obj_name = bb->obj ? bb->obj->name : "???";
+    const HChar* file_name = (bb->fn && bb->fn->file) ? bb->fn->file->name : "???";
+    UInt line = bb->line;
+
+    ULong deltas[64];
+    tl_assert(es->size <= 64);
+    if (current_cost && ti->last_sample_cost) {
+        for (i = 0; i < es->size; i++) {
+            deltas[i] = current_cost[i] - ti->last_sample_cost[i];
+        }
+        TG_(copy_cost)(es, ti->last_sample_cost, current_cost);
+    } else {
+        for (i = 0; i < es->size; i++) {
+            deltas[i] = 0;
+        }
+    }
+
+    msgpack_add_row(TG_(trace_out).seq, (Int)tid, TG_EV_EXIT_INLINED,
+                    fn_name, obj_name, file_name, (Int)line,
+                    deltas, es->size);
+}
+
 /*
  * Emit a FORK event when a child process is created.
  * Called from the post-syscall handler when fork/clone returns in parent.

tracegrind/fn.c

@@ -593,6 +593,14 @@ fn_node* TG_(get_fn_node)(BB* bb)
                          &dirname, &filename, &fnname, &line_num, &di);
 
     DiEpoch ep = VG_(current_DiEpoch)();
+
+    /* Check if BB start address is in inlined code */
+    {
+        const HChar* inl_fn_name = NULL;
+        VG_(get_inline_fnname)(ep, bb_addr(bb), &inl_fn_name);
+        bb->inl_fn = inl_fn_name;  /* NULL if not inlined */
+    }
+
     if (0 == VG_(strcmp)(fnname, "???")) {
 	int p;
         static HChar buf[32];  // for sure large enough

tracegrind/global.h

@@ -81,10 +81,12 @@ typedef enum {
 
 /* Trace event types */
 typedef enum {
-   TG_EV_MARKER = 0,
-   TG_EV_ENTER  = 1,
-   TG_EV_EXIT   = 2,
-   TG_EV_FORK   = 3
+   TG_EV_MARKER         = 0,
+   TG_EV_ENTER          = 1,
+   TG_EV_EXIT           = 2,
+   TG_EV_FORK           = 3,
+   TG_EV_ENTER_INLINED  = 4,
+   TG_EV_EXIT_INLINED   = 5
 } TraceEventType;
 
 typedef struct _CommandLineOptions CommandLineOptions;
@@ -142,7 +144,7 @@ struct _Statistics {
   ULong bb_executions;
 
   Int  context_counter;
-  Int  bb_retranslations;  
+  Int  bb_retranslations;
 
   Int  distinct_objs;
   Int  distinct_files;
@@ -238,7 +240,7 @@ struct _jCC {
 };
 
 
-/* 
+/*
  * Info for one instruction of a basic block.
  */
 typedef struct _InstrInfo InstrInfo;
@@ -284,12 +286,12 @@ struct _BB {
 
   VgSectKind sect_kind;  /* section of this BB, e.g. PLT */
   UInt       instr_count;
-  
+
   /* filled by TG_(get_fn_node) if debug info is available */
   fn_node*   fn;          /* debug info for this BB */
   UInt       line;
   Bool       is_entry;    /* True if this BB is a function entry */
-        
+
   BBCC*      bbcc_list;  /* BBCCs for same BB (see next_bbcc in BBCC) */
   BBCC*      last_bbcc;  /* Temporary: Cached for faster access (LRU) */
 
@@ -299,6 +301,8 @@ struct _BB {
 			   * allocated directly after this struct */
   Bool       cjmp_inverted; /* is last side exit actually fall through? */
 
+  const HChar* inl_fn;    /* inlined function name at BB start, or NULL */
+
   UInt       instr_len;
   UInt       cost_count;
   InstrInfo  instr[0];   /* info on instruction sizes and costs */
@@ -365,12 +369,12 @@ struct _BBCC {
 			    * recursion BBCCs. Shared. */
     BBCC*    next_bbcc;    /* Chain of BBCCs for same BB */
     BBCC*    lru_next_bbcc; /* BBCC executed next the last time */
-    
+
     jCC*     lru_from_jcc; /* Temporary: Cached for faster access (LRU) */
     jCC*     lru_to_jcc;   /* Temporary: Cached for faster access (LRU) */
-    FullCost skipped;      /* cost for skipped functions called from 
+    FullCost skipped;      /* cost for skipped functions called from
 			    * jmp_addr. Allocated lazy */
-    
+
     BBCC*    next;         /* entry chain in hash */
     ULong*   cost;         /* start of 64bit costs for this BBCC */
     ULong    ecounter_sum; /* execution counter for first instruction of BB */
@@ -432,7 +436,7 @@ struct _obj_node {
  *
  * <nonskipped> is 0 if the function called is not skipped (usual case).
  * Otherwise, it is the last non-skipped BBCC. This one gets all
- * the calls to non-skipped functions and all costs in skipped 
+ * the calls to non-skipped functions and all costs in skipped
  * instructions.
  */
 struct _call_entry {
@@ -464,14 +468,14 @@ struct _exec_state {
   /* the signum of the handler, 0 for main thread context
    */
   Int sig;
-  
+
   /* the old call stack pointer at entering the signal handler */
   Int orig_sp;
-  
+
   FullCost cost;
   Bool     collect;
   Context* cxt;
-  
+
   /* number of conditional jumps passed in last BB */
   Int   jmps_passed;
   BBCC* bbcc;      /* last BB executed */
@@ -491,7 +495,7 @@ typedef struct _cxt_hash cxt_hash;
 struct _cxt_hash {
   UInt size, entries;
   Context** table;
-};  
+};
 
 /* Thread specific state structures, i.e. parts of a thread state.
  * There are variables for the current state of each part,
@@ -540,7 +544,7 @@ struct _exec_stack {
   exec_state* entry[MAX_SIGHANDLERS];
 };
 
-/* Thread State 
+/* Thread State
  *
  * This structure stores thread specific info while a thread is *not*
  * running. See function switch_thread() for save/restore on thread switch.
@@ -562,6 +566,9 @@ struct _thread_info {
   /* CSV trace: per-thread snapshot of cost at last sample emission */
   FullCost last_sample_cost;
 
+  /* Inline tracking: current inlined function name (NULL if not in inlined code) */
+  const HChar* cur_inl_fn;
+
   /* thread specific data structure containers */
   fn_array fn_active;
   jcc_hash jccs;
@@ -580,7 +587,7 @@ struct cachesim_if
     void (*clear)(void);
     void (*printstat)(Int,Int,Int);
     void (*finish)(void);
-    
+
     void (*log_1I0D)(InstrInfo*) VG_REGPARM(1);
     void (*log_2I0D)(InstrInfo*, InstrInfo*) VG_REGPARM(2);
     void (*log_3I0D)(InstrInfo*, InstrInfo*, InstrInfo*) VG_REGPARM(3);
@@ -731,6 +738,8 @@ void TG_(run_post_signal_on_call_stack_bottom)(void);
 void TG_(trace_open_output)(void);
 void TG_(trace_reopen_child)(void);
 void TG_(trace_emit_sample)(ThreadId tid, Bool is_enter, fn_node* fn);
+void TG_(trace_emit_enter_inlined)(ThreadId tid, BB* bb);
+void TG_(trace_emit_exit_inlined)(ThreadId tid, BB* bb, const HChar* inl_fn);
 void TG_(trace_emit_fork)(ThreadId tid, Int child_pid);
 void TG_(trace_emit_marker)(ThreadId tid, const HChar* marker);
 void TG_(trace_close_output)(void);