feat(nativemem): emit post-serialization counters so flush cost is visible

ddprof-lib/src/main/cpp/flightRecorder.cpp

@@ -878,7 +878,10 @@ char *Recording::_jvm_flags = NULL;
 char *Recording::_java_command = NULL;
 
 Recording::Recording(int fd, Arguments &args)
-    : _fd(fd), _method_map() {
+    : _fd(fd), _method_map(), _has_post_flush(false) {
+
+  memset(_post_flush_live, 0, sizeof(_post_flush_live));
+  memset(_post_flush_max, 0, sizeof(_post_flush_max));
 
   args.save(_args);
   _chunk_start = lseek(_fd, 0, SEEK_END);
@@ -1056,6 +1059,14 @@ off_t Recording::finishChunk(bool end_recording, bool do_cleanup) {
     cleanupUnreferencedMethods();
   }
 
+  // Serialization (and, on this path, method-map cleanup) is complete: the
+  // dictionary has grown and any memory cleanupUnreferencedMethods() just
+  // freed is already reflected in NativeMem. Capture that state now for the
+  // next chunk to emit, and refresh the JNI-visible counter mirrors so a live
+  // process reading getDebugCounters0() after a dump() sees post-serialization
+  // values rather than pre-.
+  capturePostFlushNativeMem();
+
   if (!err) {
     // delete all local references
     for (int i = 0; i < count; i++) {
@@ -2013,6 +2024,26 @@ void Recording::writeLogLevels(Buffer *buf) {
   }
 }
 
+void Recording::capturePostFlushNativeMem() {
+  for (int c = 0; c < NM_NUM_CATEGORIES; c++) {
+    NativeMemCategory cat = (NativeMemCategory)c;
+    _post_flush_live[c] = NativeMem::live(cat);
+    _post_flush_max[c] = NativeMem::max(cat);
+  }
+  _has_post_flush = true;
+  // Deliberately NOT NativeMem::sample(): that advances a 64-tick moving
+  // average window, so calling it a second time per chunk would silently
+  // redefine avg() as a 32-chunk mean. NATIVE_MEM_AVG_BYTES is refreshed here
+  // too (to the unchanged avgTotal() from the last sample() tick, not
+  // recomputed) purely so the three JNI-visible mirrors stay a coherent
+  // triple -- callers must still be aware avg reflects the last sampled tick,
+  // not this instant, since it cannot be advanced without a second
+  // window-mutating sample().
+  Counters::set(NATIVE_MEM_LIVE_BYTES, NativeMem::liveTotal());
+  Counters::set(NATIVE_MEM_AVG_BYTES, NativeMem::avgTotal());
+  Counters::set(NATIVE_MEM_MAX_BYTES, NativeMem::maxTotal());
+}
+
 void Recording::updateNativeMemStats() {
   // Refresh the moving-window averages and the observed total peak. Per-category
   // peaks are maintained precisely at allocation time, so they are not sampled
@@ -2070,6 +2101,21 @@ void Recording::writeNativeMem(Buffer *buf) {
     }
   }
 
+  // State immediately after the PREVIOUS chunk's writeCpool(), which is the
+  // only way to see what serialization itself costs -- the in-chunk values
+  // above are necessarily sampled before it runs. Absent on the first chunk,
+  // since no flush has happened yet.
+  if (_has_post_flush) {
+    for (int c = 0; c < NM_NUM_CATEGORIES; c++) {
+      const char *name = NativeMem::categoryName((NativeMemCategory)c);
+      char label[64];
+      snprintf(label, sizeof(label), "native_mem_post_flush_live_bytes.%s", name);
+      emit(label, _post_flush_live[c]);
+      snprintf(label, sizeof(label), "native_mem_post_flush_max_bytes.%s", name);
+      emit(label, _post_flush_max[c]);
+    }
+  }
+
   // NATIVE_MEM_MAX_BYTES already carries the upper bound on the total peak (sum
   // of precise per-category peaks); here we also emit the largest observed
   // sampled total (a non-atomic per-category sum; approximate).

ddprof-lib/src/main/cpp/flightRecorder.h

@@ -22,6 +22,7 @@
 #include "common.h"
 #include "countingAllocator.h"
 #include "counters.h"
+#include "nativeMem.h"
 #include "dictionary.h"
 #include "stringDictionary.h"
 #include "event.h"
@@ -246,6 +247,28 @@ class Recording {
   Buffer _cpu_monitor_buf;
   CpuTimes _last_times;
 
+  // Per-category NativeMem state captured immediately AFTER writeCpool(), and
+  // emitted by the following chunk.
+  //
+  // The chunk's own counters are necessarily sampled before serialization: the
+  // chunk header records cpool_offset as the boundary between the event section
+  // and the constant pool, so no event may be appended once writeCpool() has
+  // run. But writeCpool() is where the method map is built and the dictionary
+  // grows -- by two orders of magnitude in a large recording -- so a consumer
+  // reading only the in-chunk values never sees the cost of serialization.
+  //
+  // The post-flush live values are the genuinely new signal here. The
+  // post-flush max is NativeMem::max(cat), a lifetime monotonic high-water
+  // mark that nothing resets in production, so it carries the same
+  // cross-flush attribution ambiguity as native_mem_max_bytes -- a per-flush
+  // peak can only be recovered by a consumer differencing
+  // post_flush_max[N] against the in-chunk native_mem_max_bytes emitted in
+  // chunk N.
+  bool _has_post_flush;
+  long long _post_flush_live[NM_NUM_CATEGORIES];
+  long long _post_flush_max[NM_NUM_CATEGORIES];
+  void capturePostFlushNativeMem();
+
   static float ratio(float value) {
     return value < 0 ? 0 : value > 1 ? 1 : value;
   }

ddprof-test/src/test/java/com/datadoghq/profiler/nativemem/NativeMemAccountingTest.java

@@ -5,8 +5,13 @@
 package com.datadoghq.profiler.nativemem;
 
 import com.datadoghq.profiler.AbstractProfilerTest;
+import com.datadoghq.profiler.JfrEvents;
 import org.junit.jupiter.api.Test;
 
+import java.nio.file.Files;
+import java.nio.file.Path;
+
+import static org.junit.jupiter.api.Assertions.assertEquals;
 import static org.junit.jupiter.api.Assertions.assertTrue;
 
 /**
@@ -33,15 +38,7 @@ public void shouldPublishSaneNativeMemCounters() throws Exception {
         // Keep the sampler busy briefly so the profiler's native buffers
         // (calltrace storage, dictionaries, per-thread data, ...) are populated
         // while the recording captures the counters.
-        long deadline = System.nanoTime() + 100_000_000L; // ~100ms
-        double sink = 0;
-        while (System.nanoTime() < deadline) {
-            for (int i = 0; i < 10_000; i++) {
-                sink += Math.sqrt(i);
-            }
-        }
-        // Guard against dead-code elimination of the busy loop.
-        assertTrue(!Double.isNaN(sink));
+        busyLoop();
 
         stopProfiler();
 
@@ -61,4 +58,83 @@ public void shouldPublishSaneNativeMemCounters() throws Exception {
         assertTrue(max >= live, "max (" + max + ") >= live (" + live + ")");
         assertTrue(max >= avg, "max (" + max + ") >= avg (" + avg + ")");
     }
+
+    /**
+     * Integration test for the cross-chunk post-flush snapshot ({@code
+     * Recording::capturePostFlushNativeMem}, {@code flightRecorder.cpp}): a
+     * dump() mid-recording forces exactly one chunk switch on the continuous
+     * recording, so the resulting file has exactly two chunks. This pins:
+     * <ul>
+     *   <li>the first-chunk-absent invariant ({@code _has_post_flush} starts
+     *       {@code false}): the post-flush labels must not appear in the first
+     *       chunk;</li>
+     *   <li>the later-chunk-present case: they must appear, and be sane, once
+     *       {@code finishChunk()} has run at least once;</li>
+     *   <li>the label spelling ({@code native_mem_post_flush_live_bytes.*} /
+     *       {@code native_mem_post_flush_max_bytes.*}).</li>
+     * </ul>
+     * With exactly one forced chunk switch, a post-flush label can appear at
+     * most once in the whole recording (only in the second chunk) -- so
+     * "exactly one occurrence" is equivalent to "absent in chunk 1, present in
+     * chunk 2", without needing per-chunk parsing.
+     */
+    @Test
+    public void shouldEmitPostFlushCountersOnlyAfterAChunkSwitch() throws Exception {
+        String liveLabel = "native_mem_post_flush_live_bytes.jfr_buffers";
+        String maxLabel = "native_mem_post_flush_max_bytes.jfr_buffers";
+
+        // Nothing has flushed yet: the very first getRecordedCounterValue below
+        // would find these labels nowhere in the recording if this busyLoop()
+        // were the only chunk. Populate some native memory before forcing the
+        // switch so the post-flush snapshot has a non-trivial "jfr_buffers"
+        // value to capture.
+        busyLoop();
+
+        Path dumpTarget = Files.createTempFile("native-mem-post-flush", ".jfr");
+        try {
+            // Forces exactly one finishChunk(end_recording=true, do_cleanup=true)
+            // on the continuous recording (see FlightRecorder::dump ->
+            // Recording::switchChunk), which is where capturePostFlushNativeMem()
+            // runs.
+            dump(dumpTarget);
+
+            // Keep the second chunk non-empty too.
+            busyLoop();
+            stopProfiler();
+
+            long live = getRecordedCounterValue(liveLabel);
+            long max = getRecordedCounterValue(maxLabel);
+            assertTrue(live >= 0, liveLabel + " present, was " + live);
+            assertTrue(max >= 0, maxLabel + " present, was " + max);
+            assertTrue(max >= live, "post-flush max (" + max + ") >= post-flush live (" + live + ")");
+
+            assertEquals(1, countCounterOccurrences(liveLabel),
+                    liveLabel + " must appear exactly once: absent in the first chunk (_has_post_flush"
+                            + " starts false), present from the second chunk onward");
+            assertEquals(1, countCounterOccurrences(maxLabel),
+                    maxLabel + " must appear exactly once: absent in the first chunk, present from the"
+                            + " second chunk onward");
+        } finally {
+            Files.deleteIfExists(dumpTarget);
+        }
+    }
+
+    /** Keeps the sampler busy briefly so native buffers are populated for the counters to report. */
+    private void busyLoop() {
+        long deadline = System.nanoTime() + 100_000_000L; // ~100ms
+        double sink = 0;
+        while (System.nanoTime() < deadline) {
+            for (int i = 0; i < 10_000; i++) {
+                sink += Math.sqrt(i);
+            }
+        }
+        // Guard against dead-code elimination of the busy loop.
+        assertTrue(!Double.isNaN(sink));
+    }
+
+    /** Counts how many {@code datadog.ProfilerCounter} events carry {@code counterName}. */
+    private long countCounterOccurrences(String counterName) throws Exception {
+        JfrEvents events = verifyEvents("datadog.ProfilerCounter", false);
+        return events.filter(item -> counterName.equals(item.getString(NAME))).count();
+    }
 }