diff --git a/CHANGELOG.md b/CHANGELOG.md index 471be016d55..5325ecc93b8 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,19 @@ ## Unreleased +### Enhancements + +* Add continuous profiling (`enableContinuousProfiling`, `continuousProfilingMaxAgeSeconds`) which + keeps a single JFR recording running in a circular buffer so profile requests dump the most recent + window of data immediately + ([#4807](https://github.com/microsoft/ApplicationInsights-Java/pull/4807)) + +### Breaking changes + +* Rename the `MachineStats` JFR diagnostic event to `MachineInfo`. Custom `.jfc` files that enable + `com.microsoft.applicationinsights.diagnostics.jfr.MachineStats` must be updated to the new event + name ([#4807](https://github.com/microsoft/ApplicationInsights-Java/pull/4807)) + ## Version 3.7.9 GA (06/18/2026) ### Enhancements diff --git a/agent/agent-profiler/agent-diagnostics-api/src/main/java/com/microsoft/applicationinsights/diagnostics/DiagnosticEngine.java b/agent/agent-profiler/agent-diagnostics-api/src/main/java/com/microsoft/applicationinsights/diagnostics/DiagnosticEngine.java index f47a8f4659b..fca33239223 100644 --- a/agent/agent-profiler/agent-diagnostics-api/src/main/java/com/microsoft/applicationinsights/diagnostics/DiagnosticEngine.java +++ b/agent/agent-profiler/agent-diagnostics-api/src/main/java/com/microsoft/applicationinsights/diagnostics/DiagnosticEngine.java @@ -17,4 +17,17 @@ public interface DiagnosticEngine { * alertBreach.alertConfiguration.profileDuration */ Future> performDiagnosis(AlertBreach alertBreach); + + /** + * Start collecting diagnostics continuously. + * + *

Used with continuous profiling, where a circular buffer is dumped on demand rather than a + * forward-looking recording being created per breach. Registering the periodic diagnostic + * emitters up front ensures diagnostic events populate the continuous recording buffer, so they + * are present in any snapshot that is dumped. Defaults to a no-op. + */ + default void startContinuousDiagnostics() {} + + /** Stop collecting diagnostics continuously. Defaults to a no-op. */ + default void stopContinuousDiagnostics() {} } diff --git a/agent/agent-profiler/agent-diagnostics-jfr/src/main/java/com/microsoft/applicationinsights/diagnostics/jfr/MachineStats.java b/agent/agent-profiler/agent-diagnostics-jfr/src/main/java/com/microsoft/applicationinsights/diagnostics/jfr/MachineInfo.java similarity index 50% rename from agent/agent-profiler/agent-diagnostics-jfr/src/main/java/com/microsoft/applicationinsights/diagnostics/jfr/MachineStats.java rename to agent/agent-profiler/agent-diagnostics-jfr/src/main/java/com/microsoft/applicationinsights/diagnostics/jfr/MachineInfo.java index 438a98ed9e3..a9944c77830 100644 --- a/agent/agent-profiler/agent-diagnostics-jfr/src/main/java/com/microsoft/applicationinsights/diagnostics/jfr/MachineStats.java +++ b/agent/agent-profiler/agent-diagnostics-jfr/src/main/java/com/microsoft/applicationinsights/diagnostics/jfr/MachineInfo.java @@ -17,58 +17,73 @@ import jdk.jfr.StackTrace; @SuppressWarnings("Java8ApiChecker") // JFR APIs require Java 11+, but agent targets Java 8 bytecode -@Name("com.microsoft.applicationinsights.diagnostics.jfr.MachineStats") -@Label("MachineStats") +@Name("com.microsoft.applicationinsights.diagnostics.jfr.MachineInfo") +@Label("MachineInfo") @Category("Diagnostic") -@Description("MachineStats") +@Description("MachineInfo") @StackTrace(false) @Period("beginChunk") -public class MachineStats extends Event implements JsonSerializable { - public static final String NAME = +public class MachineInfo extends Event implements JsonSerializable { + public static final String NAME = "com.microsoft.applicationinsights.diagnostics.jfr.MachineInfo"; + + /** + * Event name emitted by agents prior to the MachineStats->MachineInfo rename. Readers fall + * back to this so previously-recorded recordings (which carry a "MachineStats" event) can still + * be located and scored. + */ + public static final String LEGACY_NAME = "com.microsoft.applicationinsights.diagnostics.jfr.MachineStats"; - private double contextSwitchesPerMs; + + /** + * Current schema version. Version 2 drops the legacy {@code contextSwitchesPerMs} field; + * recordings produced before the schemaVersion field was added carry schemaVersion 1 (the + * implicit legacy version) and still serialize {@code contextSwitchesPerMs}. + */ + public static final int SCHEMA_VERSION = 2; private int coreCount; - public double getContextSwitchesPerMs() { - return contextSwitchesPerMs; + private int schemaVersion; + + public int getCoreCount() { + return coreCount; } - public MachineStats setContextSwitchesPerMs(double contextSwitchesPerMs) { - this.contextSwitchesPerMs = contextSwitchesPerMs; + public MachineInfo setCoreCount(int coreCount) { + this.coreCount = coreCount; return this; } - public int getCoreCount() { - return coreCount; + public int getSchemaVersion() { + return schemaVersion; } - public MachineStats setCoreCount(int coreCount) { - this.coreCount = coreCount; + public MachineInfo setSchemaVersion(int schemaVersion) { + this.schemaVersion = schemaVersion; return this; } @Override public JsonWriter toJson(JsonWriter jsonWriter) throws IOException { + jsonWriter.writeStartObject(); return jsonWriter - .writeStartObject() - .writeDoubleField("contextSwitchesPerMs", contextSwitchesPerMs) .writeIntField("coreCount", coreCount) + .writeIntField("schemaVersion", schemaVersion) .writeEndObject(); } - public static MachineStats fromJson(JsonReader jsonReader) throws IOException { + public static MachineInfo fromJson(JsonReader jsonReader) throws IOException { return jsonReader.readObject( reader -> { - MachineStats deserializedValue = new MachineStats(); + MachineInfo deserializedValue = new MachineInfo(); while (reader.nextToken() != JsonToken.END_OBJECT) { String fieldName = reader.getFieldName(); reader.nextToken(); - if ("contextSwitchesPerMs".equals(fieldName)) { - deserializedValue.setContextSwitchesPerMs(reader.getDouble()); - } else if ("coreCount".equals(fieldName)) { + if ("coreCount".equals(fieldName)) { deserializedValue.setCoreCount(reader.getInt()); + } else if ("schemaVersion".equals(fieldName)) { + deserializedValue.setSchemaVersion(reader.getInt()); } else { reader.skipChildren(); } diff --git a/agent/agent-profiler/agent-diagnostics/build.gradle.kts b/agent/agent-profiler/agent-diagnostics/build.gradle.kts index 8aedc1966c9..3e7350428a3 100644 --- a/agent/agent-profiler/agent-diagnostics/build.gradle.kts +++ b/agent/agent-profiler/agent-diagnostics/build.gradle.kts @@ -18,4 +18,9 @@ dependencies { compileOnly("com.google.auto.service:auto-service") annotationProcessor("com.google.auto.service:auto-service") + + testImplementation("org.assertj:assertj-core") + testImplementation("org.mockito:mockito-core") + testImplementation("org.gradle.jfr.polyfill:jfr-polyfill:1.0.2") + testImplementation("com.azure:azure-json") } diff --git a/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/appinsights/CodeOptimizerDiagnosticEngineJfr.java b/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/appinsights/CodeOptimizerDiagnosticEngineJfr.java index de01d5d6901..540f71c5372 100644 --- a/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/appinsights/CodeOptimizerDiagnosticEngineJfr.java +++ b/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/appinsights/CodeOptimizerDiagnosticEngineJfr.java @@ -10,7 +10,7 @@ import com.microsoft.applicationinsights.diagnostics.DiagnosticEngine; import com.microsoft.applicationinsights.diagnostics.jfr.AlertBreachJfrEvent; import com.microsoft.applicationinsights.diagnostics.jfr.CodeOptimizerDiagnosticsJfrInit; -import com.microsoft.applicationinsights.diagnostics.jfr.MachineStats; +import com.microsoft.applicationinsights.diagnostics.jfr.MachineInfo; import com.microsoft.applicationinsights.diagnostics.jfr.SystemStatsProvider; import java.io.IOException; import java.io.StringWriter; @@ -20,6 +20,8 @@ import java.util.concurrent.ScheduledExecutorService; import java.util.concurrent.Semaphore; import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.concurrent.atomic.AtomicInteger; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -35,7 +37,16 @@ public class CodeOptimizerDiagnosticEngineJfr implements DiagnosticEngine { private final ScheduledExecutorService executorService; private final Semaphore semaphore = new Semaphore(1, false); private final Path cgroupBasePath; - private int thisPid; + private final AtomicInteger thisPid = new AtomicInteger(); + + // When true, periodic diagnostic emitters are registered continuously (for continuous profiling) + // and must not be torn down by an individual performDiagnosis cycle. + private final AtomicBoolean continuous = new AtomicBoolean(false); + + // Guards transitions of the continuous flag against the teardown performed at the end of a + // (non-continuous) diagnostic cycle, so that a breach processed during startup cannot tear down + // the continuously-registered emitters once continuous profiling has been enabled. + private final Object continuousLifecycleLock = new Object(); public CodeOptimizerDiagnosticEngineJfr( ScheduledExecutorService executorService, Path cgroupBasePath) { @@ -45,42 +56,97 @@ public CodeOptimizerDiagnosticEngineJfr( @Override public void init(int thisPid) { - if (!CodeOptimizerDiagnosticsJfrInit.isOsSupported()) { + if (!isOsSupported()) { logger.warn("Code Optimizer diagnostics is not supported on this operating system"); return; } - this.thisPid = thisPid; + this.thisPid.set(thisPid); logger.debug("Initialising Code Optimizer Diagnostic Engine"); CodeOptimizerDiagnosticsJfrInit.initFeature(thisPid, cgroupBasePath); logger.debug("Code Optimizer Diagnostic Engine Initialised"); } - private static void startDiagnosticCycle(int thisPid, Path cgroupBasePath) { + // visible for testing + protected boolean isOsSupported() { + return CodeOptimizerDiagnosticsJfrInit.isOsSupported(); + } + + // visible for testing + protected void startDiagnosticCycle() { logger.debug("Starting Code Optimizer Diagnostic Cycle"); - CodeOptimizerDiagnosticsJfrInit.initFeature(thisPid, cgroupBasePath); - CodeOptimizerDiagnosticsJfrInit.start(thisPid, cgroupBasePath); + int pid = thisPid.get(); + CodeOptimizerDiagnosticsJfrInit.initFeature(pid, cgroupBasePath); + CodeOptimizerDiagnosticsJfrInit.start(pid, cgroupBasePath); } - private static void endDiagnosticCycle() { + // visible for testing + protected void endDiagnosticCycle() { logger.debug("Ending Code Optimizer Diagnostic Cycle"); CodeOptimizerDiagnosticsJfrInit.stop(); } + @Override + public void startContinuousDiagnostics() { + if (!isOsSupported()) { + logger.warn("Code Optimizer diagnostics is not supported on this operating system"); + return; + } + + synchronized (continuousLifecycleLock) { + continuous.set(true); + logger.debug("Starting continuous Code Optimizer diagnostics"); + // Registers the periodic diagnostic emitters (Telemetry, CGroupData) so they continuously + // populate the continuous profiling circular buffer. + startDiagnosticCycle(); + } + } + + @Override + public void stopContinuousDiagnostics() { + if (!isOsSupported()) { + return; + } + + synchronized (continuousLifecycleLock) { + continuous.set(false); + logger.debug("Stopping continuous Code Optimizer diagnostics"); + endDiagnosticCycle(); + } + } + @Override public Future> performDiagnosis(AlertBreach alert) { + if (continuous.get()) { + // Periodic diagnostics are already running continuously, so we must not start or stop the + // diagnostic cycle here (doing so would remove the continuously-registered emitters). Just + // emit the point-in-time breach information. + CompletableFuture> diagnosisResultCompletableFuture = + new CompletableFuture<>(); + try { + emitInfo(alert); + diagnosisResultCompletableFuture.complete(null); + } catch (RuntimeException e) { + // The caller discards the returned future, so log here to avoid silently swallowing the + // failure to emit breach diagnostics. + logger.error("Failed to emit continuous diagnostic breach information", e); + diagnosisResultCompletableFuture.completeExceptionally(e); + } + return diagnosisResultCompletableFuture; + } + CompletableFuture> diagnosisResultCompletableFuture = new CompletableFuture<>(); try { if (semaphore.tryAcquire(SEMAPHORE_TIMEOUT_IN_SEC, TimeUnit.SECONDS)) { - emitInfo(alert, cgroupBasePath); + emitInfo(alert); long profileDurationInSec = alert.getAlertConfiguration().getProfileDurationSeconds(); long end = profileDurationInSec - TIME_BEFORE_END_OF_PROFILE_TO_EMIT_EVENT; - startDiagnosticCycle(thisPid, cgroupBasePath); + startDiagnosticCycle(); scheduleEmittingAlertBreachEvent(alert, end); @@ -105,13 +171,25 @@ private void scheduleShutdown( executorService.schedule( () -> { try { - emitInfo(alert, cgroupBasePath); + emitInfo(alert); // We do not return a result atm diagnosisResultCompletableFuture.complete(null); - logger.debug("Shutting down diagnostic cycle"); - endDiagnosticCycle(); + // Only tear down the diagnostic cycle if continuous diagnostics has not been enabled in + // the meantime. If a breach is processed during startup, before + // startContinuousDiagnostics + // has run, this shutdown would otherwise permanently stop the continuously-registered + // emitters once continuous profiling starts. The lock ensures the check-and-stop cannot + // interleave with a concurrent startContinuousDiagnostics. + synchronized (continuousLifecycleLock) { + if (continuous.get()) { + logger.debug("Continuous diagnostics is active; leaving diagnostic cycle running"); + } else { + logger.debug("Shutting down diagnostic cycle"); + endDiagnosticCycle(); + } + } } catch (RuntimeException e) { logger.error("Failed to shutdown cleanly", e); } finally { @@ -127,7 +205,7 @@ private void scheduleEmittingAlertBreachEvent(AlertBreach alert, long end) { executorService.schedule( () -> { try { - emitInfo(alert, cgroupBasePath); + emitInfo(alert); } catch (RuntimeException e) { logger.error("Failed to emit breach", e); } @@ -136,16 +214,17 @@ private void scheduleEmittingAlertBreachEvent(AlertBreach alert, long end) { TimeUnit.SECONDS); } - private static void emitInfo(AlertBreach alert, Path cgroupBasePath) { + // visible for testing + protected void emitInfo(AlertBreach alert) { logger.debug("Emitting Code Optimizer Diagnostic Event"); emitAlertBreachJfrEvent(alert); CodeOptimizerDiagnosticsJfrInit.emitCGroupData(cgroupBasePath); - emitMachineStats(); + emitMachineInfo(); } - private static void emitMachineStats() { - MachineStats machineStats = SystemStatsProvider.getMachineStats(); - machineStats.commit(); + private static void emitMachineInfo() { + MachineInfo machineInfo = SystemStatsProvider.getMachineInfo(); + machineInfo.commit(); } private static void emitAlertBreachJfrEvent(AlertBreach alert) { diff --git a/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/collection/calibration/Calibration.java b/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/collection/calibration/Calibration.java deleted file mode 100644 index 8fef10c3e30..00000000000 --- a/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/collection/calibration/Calibration.java +++ /dev/null @@ -1,17 +0,0 @@ -// Copyright (c) Microsoft Corporation. All rights reserved. -// Licensed under the MIT License. - -package com.microsoft.applicationinsights.diagnostics.collection.calibration; - -public class Calibration { - public static final double UNKNOWN = -1; - private final double contextSwitchingRate; - - public Calibration(double contextSwitchingRate) { - this.contextSwitchingRate = contextSwitchingRate; - } - - public double getContextSwitchingRate() { - return contextSwitchingRate; - } -} diff --git a/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/collection/calibration/Calibrator.java b/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/collection/calibration/Calibrator.java deleted file mode 100644 index c2950e8ddd8..00000000000 --- a/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/collection/calibration/Calibrator.java +++ /dev/null @@ -1,9 +0,0 @@ -// Copyright (c) Microsoft Corporation. All rights reserved. -// Licensed under the MIT License. - -package com.microsoft.applicationinsights.diagnostics.collection.calibration; - -public interface Calibrator { - - Calibration calibrate(); -} diff --git a/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/collection/calibration/CalibratorDefault.java b/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/collection/calibration/CalibratorDefault.java deleted file mode 100644 index 7045adb6edc..00000000000 --- a/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/collection/calibration/CalibratorDefault.java +++ /dev/null @@ -1,100 +0,0 @@ -// Copyright (c) Microsoft Corporation. All rights reserved. -// Licensed under the MIT License. - -package com.microsoft.applicationinsights.diagnostics.collection.calibration; - -import com.microsoft.applicationinsights.diagnostics.collection.libos.OperatingSystemInteractionException; -import com.microsoft.applicationinsights.diagnostics.collection.libos.kernel.KernelMonitorDeviceDriver; -import com.microsoft.applicationinsights.diagnostics.collection.libos.process.Process; -import java.util.ArrayList; -import java.util.Collections; -import java.util.Iterator; -import java.util.List; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; - -public class CalibratorDefault implements Calibrator { - - private static final Logger logger = LoggerFactory.getLogger(ContextSwitchingRunner.class); - - private final ContextSwitchingRunner contextSwitching; - private final KernelMonitorDeviceDriver kernel; - private final Process thisProcess; - - public CalibratorDefault( - ContextSwitchingRunner contextSwitching, - KernelMonitorDeviceDriver kernel, - Process thisProcess) { - this.contextSwitching = contextSwitching; - this.kernel = kernel; - this.thisProcess = thisProcess; - } - - @Override - public Calibration calibrate() { - try { - List contextSwitchesPerRun = new ArrayList<>(); - Iterator iterator = contextSwitching.iterator(); - - int runCount = contextSwitching.getRunCount(); - double[] diagnosticsTimes = new double[runCount]; - double[] cpuTimes = new double[runCount]; - - for (int i = 0; iterator.hasNext(); i++) { - long time = System.currentTimeMillis(); - - update(thisProcess); - - iterator.next(); - - update(thisProcess); - - time = System.currentTimeMillis() - time; - - // MIN_VALUE to Make sure its not 0 - diagnosticsTimes[i] = safeDiv(getProcessCpuTime(thisProcess), (double) time); - cpuTimes[i] = safeDiv(getCpuTime(), (double) time); - - double contextSwitches = getContextSwitches(); - - contextSwitchesPerRun.add(safeDiv(contextSwitches, (double) time)); - } - - double maxContextSwitches = Collections.max(contextSwitchesPerRun); - int index = contextSwitchesPerRun.indexOf(maxContextSwitches); - - double diagnosticsTime = diagnosticsTimes[index]; - double cpuTime = diagnosticsTimes[index]; - double timeDiagnosticsHadAvailable = safeDiv(diagnosticsTime, cpuTime); - double contextSwitchingRate = safeDiv(maxContextSwitches, timeDiagnosticsHadAvailable); - return new Calibration(contextSwitchingRate); - } catch (Throwable e) { - logger.debug("Completing exceptionally", e); - } - return new Calibration(Calibration.UNKNOWN); - } - - private static double safeDiv(double numerator, double denominator) { - return numerator / (denominator + Double.MIN_VALUE); - } - - private void update(Process process) throws OperatingSystemInteractionException { - process.poll(); - kernel.poll(); - - process.update(); - kernel.update(); - } - - private static double getProcessCpuTime(Process process) { - return process.getCpuStats().getTotalTime().doubleValue(); - } - - private long getContextSwitches() throws OperatingSystemInteractionException { - return kernel.getCounters().getContextSwitches(); - } - - private double getCpuTime() throws OperatingSystemInteractionException { - return 100D - kernel.getCounters().getIdleTime(); - } -} diff --git a/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/collection/calibration/ContextSwitchingRunner.java b/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/collection/calibration/ContextSwitchingRunner.java deleted file mode 100644 index 90ff94f45c5..00000000000 --- a/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/collection/calibration/ContextSwitchingRunner.java +++ /dev/null @@ -1,97 +0,0 @@ -// Copyright (c) Microsoft Corporation. All rights reserved. -// Licensed under the MIT License. - -package com.microsoft.applicationinsights.diagnostics.collection.calibration; - -import java.util.Arrays; -import java.util.Iterator; -import java.util.List; - -public class ContextSwitchingRunner implements Iterable { - - private static final int NUMBER_OF_CALLS = 40000; - - private static final Object lock = new Object(); - - private final List threadCounts; - - public ContextSwitchingRunner() { - threadCounts = Arrays.asList(100, 1000, 10, 100); - } - - public int getRunCount() { - return threadCounts.size(); - } - - public static void main(String[] args) { - new ContextSwitchingRunner().runThreads(1000); - } - - @SuppressWarnings( - "ThreadJoinLoop") // thread join in loop is safe and necessary for proper synchronization - private void runThreads(int threadCount) { - Thread[] threads = new Thread[threadCount]; - - for (int i = 0; i < threads.length; i++) { - threads[i] = - new Thread() { - @SuppressWarnings("unused") // value not used but required by API signature or framework - private int value = 0; - - @Override - public void run() { - for (int i = 0; i < NUMBER_OF_CALLS; i++) { - synchronized (lock) { - value++; - } - } - } - }; - } - - int numThreads = 0; - // fork - for (; numThreads < threads.length; numThreads++) { - try { - threads[numThreads].start(); - } catch (Error error) { - // OS will not allow us to spawn enough threads, just use however many we have - break; - } - } - - // join - try { - for (int i = 0; i < numThreads; i++) { - if (threads[i] != null) { - threads[i].join(); - } - } - } catch (InterruptedException e) { - // Ignore - } - } - - @Override - public Iterator iterator() { - Iterator countIterator = threadCounts.iterator(); - return new Iterator() { - @Override - public boolean hasNext() { - return countIterator.hasNext(); - } - - @Override - public Void next() { - Integer threadCount = countIterator.next(); - runThreads(threadCount); - return null; - } - - @Override - public void remove() { - throw new UnsupportedOperationException("Doesn't make sense to remove from this iterable"); - } - }; - } -} diff --git a/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/jfr/SystemStatsProvider.java b/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/jfr/SystemStatsProvider.java index 953ffd970f8..ef6757e0dbb 100644 --- a/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/jfr/SystemStatsProvider.java +++ b/agent/agent-profiler/agent-diagnostics/src/main/java/com/microsoft/applicationinsights/diagnostics/jfr/SystemStatsProvider.java @@ -4,10 +4,6 @@ package com.microsoft.applicationinsights.diagnostics.jfr; import com.microsoft.applicationinsights.diagnostics.collection.SystemStatsReader; -import com.microsoft.applicationinsights.diagnostics.collection.calibration.Calibration; -import com.microsoft.applicationinsights.diagnostics.collection.calibration.Calibrator; -import com.microsoft.applicationinsights.diagnostics.collection.calibration.CalibratorDefault; -import com.microsoft.applicationinsights.diagnostics.collection.calibration.ContextSwitchingRunner; import com.microsoft.applicationinsights.diagnostics.collection.cores.RuntimeCoreCounter; import com.microsoft.applicationinsights.diagnostics.collection.libos.OperatingSystemInteractionException; import com.microsoft.applicationinsights.diagnostics.collection.libos.hardware.MemoryInfoReader; @@ -61,17 +57,15 @@ public static void init(int thisPid, Path cgroupBasePath) { if (initialised.compareAndSet(false, true)) { singletons.put(ThisPidSupplier.class, new AtomicReference<>((ThisPidSupplier) () -> thisPid)); - if (singletons.get(Calibrator.class) == null) { - try { - getCalibration(); - getMachineStats(); - getCGroupData(cgroupBasePath); + try { + // Eagerly warm up the machine and cgroup singletons, then release resources until needed. + getMachineInfo(); + getCGroupData(cgroupBasePath); - // Close until needed - close(); - } catch (RuntimeException e) { - logger.error("Failed to initialise Code Optimizer", e); - } + // Close until needed + close(); + } catch (RuntimeException e) { + logger.error("Failed to initialise Code Optimizer", e); } } } @@ -132,25 +126,13 @@ public static CGroupData getCGroupData(Path cgroupBasePath) { }); } - public static MachineStats getMachineStats() { + public static MachineInfo getMachineInfo() { return getSingleton( - MachineStats.class, + MachineInfo.class, () -> - new MachineStats() - .setContextSwitchesPerMs(getCalibration().getContextSwitchingRate()) - .setCoreCount(new RuntimeCoreCounter().getCoreCount())); - } - - private static Calibration getCalibration() { - return getSingleton( - Calibration.class, - () -> { - Calibrator calibrator = - new CalibratorDefault( - new ContextSwitchingRunner(), getKernelMonitor(), getThisProcess()); - - return calibrator.calibrate(); - }); + new MachineInfo() + .setCoreCount(new RuntimeCoreCounter().getCoreCount()) + .setSchemaVersion(MachineInfo.SCHEMA_VERSION)); } private static Process getThisProcess() { @@ -158,12 +140,17 @@ private static Process getThisProcess() { Process.class, () -> { ProcessDumper processDumper = getProcessDumper(); - if (processDumper == null) { - return null; - } processDumper.poll(); Process thisProcess = processDumper.thisProcess(); + if (thisProcess == null) { + // e.g. NoOpProcessDumper on unsupported operating systems returns no process. The only + // caller (buildSystemStatsReader) dereferences the result, so fail fast with a clear + // message rather than returning null and triggering an opaque NPE later. + throw new IllegalStateException( + "Current process information is unavailable on this operating system; " + + "system stats cannot be collected"); + } processDumper.closeProcesses(Collections.singletonList(thisProcess.getPid())); return thisProcess; }); diff --git a/agent/agent-profiler/agent-diagnostics/src/test/java/com/microsoft/applicationinsights/diagnostics/appinsights/CodeOptimizerDiagnosticEngineJfrTest.java b/agent/agent-profiler/agent-diagnostics/src/test/java/com/microsoft/applicationinsights/diagnostics/appinsights/CodeOptimizerDiagnosticEngineJfrTest.java new file mode 100644 index 00000000000..1f13cf42895 --- /dev/null +++ b/agent/agent-profiler/agent-diagnostics/src/test/java/com/microsoft/applicationinsights/diagnostics/appinsights/CodeOptimizerDiagnosticEngineJfrTest.java @@ -0,0 +1,141 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +package com.microsoft.applicationinsights.diagnostics.appinsights; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.mockito.ArgumentMatchers.any; +import static org.mockito.ArgumentMatchers.anyLong; +import static org.mockito.ArgumentMatchers.eq; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.times; +import static org.mockito.Mockito.verify; +import static org.mockito.Mockito.when; + +import com.microsoft.applicationinsights.alerting.alert.AlertBreach; +import com.microsoft.applicationinsights.alerting.config.AlertConfiguration; +import com.microsoft.applicationinsights.alerting.config.AlertMetricType; +import java.nio.file.Paths; +import java.util.List; +import java.util.UUID; +import java.util.concurrent.ScheduledExecutorService; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicInteger; +import org.junit.jupiter.api.Test; +import org.mockito.ArgumentCaptor; + +class CodeOptimizerDiagnosticEngineJfrTest { + + /** + * Engine subclass that avoids the real JFR subsystem and simply records how many times the + * diagnostic cycle is started/ended so tests can assert on lifecycle behavior. + */ + private static class RecordingEngine extends CodeOptimizerDiagnosticEngineJfr { + final AtomicInteger startCycleCount = new AtomicInteger(); + final AtomicInteger endCycleCount = new AtomicInteger(); + final AtomicInteger emitInfoCount = new AtomicInteger(); + + RecordingEngine(ScheduledExecutorService executorService) { + super(executorService, Paths.get("/")); + } + + @Override + protected boolean isOsSupported() { + return true; + } + + @Override + protected void startDiagnosticCycle() { + startCycleCount.incrementAndGet(); + } + + @Override + protected void endDiagnosticCycle() { + endCycleCount.incrementAndGet(); + } + + @Override + protected void emitInfo(AlertBreach alert) { + emitInfoCount.incrementAndGet(); + } + } + + private static AlertBreach manualBreach(int profileDurationSeconds) { + return AlertBreach.builder() + .setType(AlertMetricType.MANUAL) + .setAlertValue(0.0) + .setAlertConfiguration( + AlertConfiguration.builder() + .setType(AlertMetricType.MANUAL) + .setEnabled(true) + .setProfileDurationSeconds(profileDurationSeconds) + .build()) + .setProfileId(UUID.randomUUID().toString()) + .setCpuMetric(0) + .setMemoryUsage(0) + .build(); + } + + private static Runnable captureScheduledShutdown( + ScheduledExecutorService executor, long expectedDelaySeconds) { + ArgumentCaptor runnableCaptor = ArgumentCaptor.forClass(Runnable.class); + ArgumentCaptor delayCaptor = ArgumentCaptor.forClass(Long.class); + verify(executor, times(2)) + .schedule(runnableCaptor.capture(), delayCaptor.capture(), eq(TimeUnit.SECONDS)); + List runnables = runnableCaptor.getAllValues(); + List delays = delayCaptor.getAllValues(); + for (int i = 0; i < delays.size(); i++) { + if (delays.get(i) == expectedDelaySeconds) { + return runnables.get(i); + } + } + throw new AssertionError("No task scheduled with delay " + expectedDelaySeconds); + } + + @Test + void breachDuringStartupDoesNotTearDownContinuousEmitters() { + ScheduledExecutorService executor = mock(ScheduledExecutorService.class); + when(executor.schedule(any(Runnable.class), anyLong(), any(TimeUnit.class))).thenReturn(null); + + RecordingEngine engine = new RecordingEngine(executor); + + // A breach is processed during startup, before continuous diagnostics has been enabled. + int profileDurationSeconds = 60; + long end = + profileDurationSeconds + - CodeOptimizerDiagnosticEngineJfr.TIME_BEFORE_END_OF_PROFILE_TO_EMIT_EVENT; + engine.performDiagnosis(manualBreach(profileDurationSeconds)); + + Runnable shutdown = captureScheduledShutdown(executor, end); + + // Continuous diagnostics is enabled after the breach was scheduled but before the stale + // shutdown fires. + engine.startContinuousDiagnostics(); + + // The stale shutdown from the initial breach now fires. + shutdown.run(); + + // It must NOT tear down the continuously-registered emitters. + assertThat(engine.endCycleCount.get()).isZero(); + } + + @Test + void breachWithoutContinuousDiagnosticsTearsDownCycle() { + ScheduledExecutorService executor = mock(ScheduledExecutorService.class); + when(executor.schedule(any(Runnable.class), anyLong(), any(TimeUnit.class))).thenReturn(null); + + RecordingEngine engine = new RecordingEngine(executor); + + int profileDurationSeconds = 60; + long end = + profileDurationSeconds + - CodeOptimizerDiagnosticEngineJfr.TIME_BEFORE_END_OF_PROFILE_TO_EMIT_EVENT; + engine.performDiagnosis(manualBreach(profileDurationSeconds)); + + Runnable shutdown = captureScheduledShutdown(executor, end); + shutdown.run(); + + // With no continuous diagnostics, the cycle is torn down as before. + assertThat(engine.endCycleCount.get()).isEqualTo(1); + } +} diff --git a/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/configuration/Configuration.java b/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/configuration/Configuration.java index 57861e0a0d0..77517f7bb22 100644 --- a/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/configuration/Configuration.java +++ b/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/configuration/Configuration.java @@ -1543,6 +1543,18 @@ public static class ProfilerConfiguration { // Whether to register a JMX MBean that allows triggering profiles via JMX tools. public boolean enableProfilerControlMBean = false; + + // When enabled, the profiler keeps a single JFR recording running continuously using a + // circular buffer (bounded by continuousProfilingMaxAgeSeconds) instead of starting a new + // timed recording for each trigger. When a profile is requested, the current contents of the + // circular buffer are dumped and uploaded immediately, capturing the most recent + // continuousProfilingMaxAgeSeconds of data. This lets profile requests be serviced without + // waiting for a recording duration to elapse. + public boolean enableContinuousProfiling = false; + + // The maximum age (in seconds) of data retained in the continuous profiling circular buffer. + // Only used when enableContinuousProfiling is true. + public int continuousProfilingMaxAgeSeconds = 120; } /** diff --git a/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/profiler/PerformanceMonitoringService.java b/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/profiler/PerformanceMonitoringService.java index d8af15d22db..5f00a46fdd4 100644 --- a/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/profiler/PerformanceMonitoringService.java +++ b/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/profiler/PerformanceMonitoringService.java @@ -135,6 +135,13 @@ synchronized void enableProfiler( // Daemon remains alive permanently due to scheduling an update profiler.initialize(uploadService, serviceProfilerExecutorService); + // When continuous profiling is enabled the profiler dumps a backward-looking circular buffer + // on demand, so diagnostics must run continuously to populate that buffer with diagnostic + // events (rather than being started per-breach for a forward-looking recording). + if (configuration.enableContinuousProfiling && diagnosticEngine != null) { + diagnosticEngine.startContinuousDiagnostics(); + } + } catch (Throwable t) { logger.error( "Failed to initialise profiler service", diff --git a/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/profiler/Profiler.java b/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/profiler/Profiler.java index 6ad09d39bbb..531f836eabe 100644 --- a/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/profiler/Profiler.java +++ b/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/profiler/Profiler.java @@ -48,6 +48,8 @@ public class Profiler { private static final Logger logger = LoggerFactory.getLogger(Profiler.class); + private static final Duration DEFAULT_CONTINUOUS_PROFILING_MAX_AGE = Duration.ofMinutes(2); + // service execution context private ScheduledExecutorService scheduledExecutorService; @@ -77,6 +79,14 @@ public class Profiler { private final RecordingConfiguration spanRecordingConfiguration; private final RecordingConfiguration manualRecordingConfiguration; + private final boolean continuousProfilingEnabled; + private final Duration continuousProfilingMaxAge; + private final RecordingConfiguration continuousRecordingConfiguration; + + // Long-running recording backed by a circular buffer (maxAge, no duration) used when + // continuous profiling is enabled. Guarded by activeRecordingLock. + @Nullable private Recording continuousRecording = null; + private final File temporaryDirectory; private final TimeSource timeSource; @@ -104,9 +114,26 @@ public Profiler(Configuration.ProfilerConfiguration config, File tempDir, TimeSo cpuRecordingConfiguration = AlternativeJfrConfigurations.getCpuProfileConfig(config); spanRecordingConfiguration = AlternativeJfrConfigurations.getSpanProfileConfig(config); manualRecordingConfiguration = AlternativeJfrConfigurations.getManualProfileConfig(config); + continuousProfilingEnabled = config.enableContinuousProfiling; + continuousProfilingMaxAge = + resolveContinuousProfilingMaxAge(config.continuousProfilingMaxAgeSeconds); + // Continuous profiling uses a single always-on recording, so it can only carry one JFC. Reuse + // the CPU configuration rather than opening a second stream on the same resource. + continuousRecordingConfiguration = cpuRecordingConfiguration; temporaryDirectory = tempDir; } + private static Duration resolveContinuousProfilingMaxAge(int continuousProfilingMaxAgeSeconds) { + if (continuousProfilingMaxAgeSeconds <= 0) { + logger.warn( + "continuousProfilingMaxAgeSeconds must be positive but was {}; falling back to {}s", + continuousProfilingMaxAgeSeconds, + DEFAULT_CONTINUOUS_PROFILING_MAX_AGE.getSeconds()); + return DEFAULT_CONTINUOUS_PROFILING_MAX_AGE; + } + return Duration.ofSeconds(continuousProfilingMaxAgeSeconds); + } + /** * Call init before run. * @@ -129,6 +156,8 @@ public void initialize( // Possibly an older JVM, try using Diagnostic command flightRecorderConnection = FlightRecorderConnection.diagnosticCommandConnection(mbeanServer); } + + startContinuousRecordingIfEnabled(); } // visible for testing @@ -140,6 +169,8 @@ void initialize( this.scheduledExecutorService = scheduledExecutorService; this.recordingOptionsBuilder = new RecordingOptions.Builder(); this.flightRecorderConnection = flightRecorderConnection; + + startContinuousRecordingIfEnabled(); } /** Apply new configuration settings obtained from Service Profiler. */ @@ -152,12 +183,115 @@ public void updateConfiguration(ProfilerConfiguration newConfig) { // visible for tests void profileAndUpload(AlertBreach alertBreach, Duration duration, UploadListener uploadListener) { Instant recordingStart = timeSource.getNow(); + if (continuousProfilingEnabled) { + captureContinuousRecording(alertBreach, recordingStart, uploadListener); + return; + } executeProfile( alertBreach.getType(), duration, uploadNewRecording(alertBreach, recordingStart, uploadListener)); } + private void startContinuousRecordingIfEnabled() { + if (!continuousProfilingEnabled) { + return; + } + synchronized (activeRecordingLock) { + if (continuousRecording != null) { + return; + } + try { + // A continuous recording uses a circular buffer bounded by maxAge and no duration, so it + // runs indefinitely while only retaining the most recent window of data on disk. + // Use a dedicated builder so the maxAge/disk options for the continuous circular buffer do + // not mutate the shared recordingOptionsBuilder used by on-demand recordings. + RecordingOptions recordingOptions = + new RecordingOptions.Builder() + .maxAge(continuousProfilingMaxAge.toMillis() + " ms") + .disk("true") + .build(); + continuousRecording = createRecording(recordingOptions, continuousRecordingConfiguration); + continuousRecording.start(); + logger.info( + "Started continuous JFR recording with circular buffer maxAge of {} seconds", + continuousProfilingMaxAge.getSeconds()); + } catch (IOException | JfrConnectionException e) { + logger.error("Failed to start continuous JFR recording", e); + continuousRecording = null; + } + } + } + + @SuppressWarnings( + "CatchingUnchecked") // catching unchecked exception is necessary for proper error handling + private void captureContinuousRecording( + AlertBreach alertBreach, Instant recordingEnd, UploadListener uploadListener) { + File dumpFile; + Instant bufferStart; + synchronized (activeRecordingLock) { + if (continuousRecording == null) { + logger.warn("Profile requested but continuous recording is not running, ignoring request."); + return; + } + + // Enforce global cooldown across all trigger sources + if (globalCooldownSeconds > 0 && timeSource.getNow().isBefore(globalCooldownUntil)) { + logger.info( + "Profile requested (type={}), but global cooldown is active until {}. Ignoring request.", + alertBreach.getType(), + globalCooldownUntil); + return; + } + + // A live circular buffer can only be dumped in its entirety; the JFR connection only supports + // streaming a sub-window from a stopped recording, so a shorter portal-/JMX-configured + // profile + // duration cannot be honored without tearing down continuous profiling. The dump therefore + // always covers the full retained window, [recordingEnd - maxAge, recordingEnd]. Index the + // profile at the start of that window rather than at dump time. + bufferStart = recordingEnd.minus(continuousProfilingMaxAge); + + try { + dumpFile = createJfrFile(bufferStart, recordingEnd); + } catch (IOException e) { + logger.error("Failed to create jfr file", e); + return; + } + + try { + // Dump the current state of the circular buffer, capturing up to maxAge of data. The + // continuous recording keeps running so future requests can be serviced immediately. + continuousRecording.dump(dumpFile.getAbsolutePath()); + } catch (IOException | JfrConnectionException e) { + logger.error("Failed to dump continuous recording", e); + if (dumpFile.exists() && !dumpFile.delete()) { + logger.error("Failed to remove file " + dumpFile.getAbsolutePath()); + } + return; + } + + // Start the global cooldown while still holding the lock so concurrent triggers are rejected + // before they can dump another snapshot. + startGlobalCooldown(); + } + + try { + logger.info("Uploading continuous recording snapshot"); + uploadService.upload(alertBreach, bufferStart.toEpochMilli(), dumpFile, uploadListener); + } catch (Exception e) { + logger.error("Failed to upload recording", e); + } catch (Error e) { + // rethrow errors + logger.error("Failed to upload recording", e); + throw e; + } finally { + if (dumpFile.exists() && !dumpFile.delete()) { + logger.error("Failed to remove file " + dumpFile.getAbsolutePath()); + } + } + } + @Nullable private Recording startRecording(AlertMetricType alertType, Duration duration) { synchronized (activeRecordingLock) { @@ -326,10 +460,7 @@ void clearActiveRecording() { activeRecording = null; // Start global cooldown now that the recording is complete - if (globalCooldownSeconds > 0) { - globalCooldownUntil = timeSource.getNow().plusSeconds(globalCooldownSeconds); - logger.debug("Global profile cooldown active until {}", globalCooldownUntil); - } + startGlobalCooldown(); // delete uploaded profile if (activeRecordingFile != null && activeRecordingFile.exists()) { @@ -341,6 +472,14 @@ void clearActiveRecording() { } } + // Advances the global cooldown window. Callers must hold activeRecordingLock. + private void startGlobalCooldown() { + if (globalCooldownSeconds > 0) { + globalCooldownUntil = timeSource.getNow().plusSeconds(globalCooldownSeconds); + logger.debug("Global profile cooldown active until {}", globalCooldownUntil); + } + } + // visible for testing Instant getGlobalCooldownUntil() { return globalCooldownUntil; @@ -356,6 +495,13 @@ boolean isRecordingActive() { /** Dump JFR profile to file. */ // visible for testing protected File createJfrFile(Duration duration) throws IOException { + Instant recordingStart = timeSource.getNow(); + return createJfrFile(recordingStart, recordingStart.plus(duration)); + } + + /** Create a JFR file whose name encodes the window of data it contains. */ + // visible for testing + protected File createJfrFile(Instant recordingStart, Instant recordingEnd) throws IOException { if (!temporaryDirectory.exists()) { if (!temporaryDirectory.mkdirs()) { throw new IOException( @@ -363,9 +509,6 @@ protected File createJfrFile(Duration duration) throws IOException { } } - Instant recordingStart = timeSource.getNow(); - Instant recordingEnd = recordingStart.plus(duration); - return new File( temporaryDirectory, "recording_" + recordingStart.toEpochMilli() + "-" + recordingEnd.toEpochMilli() + ".jfr"); diff --git a/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/profiler/triggers/AlertingSubsystemInit.java b/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/profiler/triggers/AlertingSubsystemInit.java index b7c5b3a5b85..3e20ea64dbd 100644 --- a/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/profiler/triggers/AlertingSubsystemInit.java +++ b/agent/agent-tooling/src/main/java/com/microsoft/applicationinsights/agent/internal/profiler/triggers/AlertingSubsystemInit.java @@ -55,7 +55,13 @@ public static AlertingSubsystem create( // TODO (trask) delay creation of AlertingSubsystem until after Profiler is created and // initialized? Consumer alertAction = - alert -> alertAction(alert, profiler, diagnosticEngine, telemetryClient); + alert -> + alertAction( + alert, + profiler, + diagnosticEngine, + telemetryClient, + configuration.enableContinuousProfiling); alertingSubsystem = AlertingSubsystem.create( @@ -126,18 +132,28 @@ private static void alertAction( AlertBreach alert, Profiler profiler, DiagnosticEngine diagnosticEngine, - TelemetryClient telemetryClient) { + TelemetryClient telemetryClient, + boolean continuousProfilingEnabled) { if (profiler != null) { // This is an event that the backend specifically looks for to track when a profile is // started sendMessageTelemetry(telemetryClient, "StartProfiler triggered."); + // With continuous profiling the profiler immediately dumps a backward-looking snapshot of the + // circular buffer, so the breach diagnostics (AlertBreach, CGroupData, MachineInfo) must be + // emitted before the dump in order to be captured in the recording. + if (continuousProfilingEnabled && diagnosticEngine != null) { + diagnosticEngine.performDiagnosis(alert); + } + profiler.accept( alert, serviceProfilerIndex -> sendServiceProfilerIndex(serviceProfilerIndex, telemetryClient)); - if (diagnosticEngine != null) { + // With traditional profiling a new forward-looking recording is created, so diagnostics are + // emitted after the recording has started. + if (!continuousProfilingEnabled && diagnosticEngine != null) { diagnosticEngine.performDiagnosis(alert); } } diff --git a/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/diagnostic-cpu-profile.jfc b/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/diagnostic-cpu-profile.jfc index c63ef693d1f..25b792bd7a9 100644 --- a/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/diagnostic-cpu-profile.jfc +++ b/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/diagnostic-cpu-profile.jfc @@ -699,7 +699,7 @@ beginChunk - + true beginChunk diff --git a/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/diagnostic-memory-profile.jfc b/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/diagnostic-memory-profile.jfc index 3a3b373ac6d..1786375188b 100644 --- a/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/diagnostic-memory-profile.jfc +++ b/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/diagnostic-memory-profile.jfc @@ -698,7 +698,7 @@ beginChunk - + true beginChunk diff --git a/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/reduced-cpu-profile.jfc b/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/reduced-cpu-profile.jfc index 472f1b8d78d..4642c09351e 100644 --- a/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/reduced-cpu-profile.jfc +++ b/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/reduced-cpu-profile.jfc @@ -698,7 +698,7 @@ beginChunk - + true beginChunk diff --git a/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/reduced-memory-profile.jfc b/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/reduced-memory-profile.jfc index 3ac17539e95..aedeecc63e7 100644 --- a/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/reduced-memory-profile.jfc +++ b/agent/agent-tooling/src/main/resources/com/microsoft/applicationinsights/agent/internal/profiler/reduced-memory-profile.jfc @@ -698,7 +698,7 @@ beginChunk - + true beginChunk diff --git a/agent/agent-tooling/src/test/java/com/microsoft/applicationinsights/agent/internal/profiler/ProfilerContinuousProfilingTest.java b/agent/agent-tooling/src/test/java/com/microsoft/applicationinsights/agent/internal/profiler/ProfilerContinuousProfilingTest.java new file mode 100644 index 00000000000..26be48ab0fd --- /dev/null +++ b/agent/agent-tooling/src/test/java/com/microsoft/applicationinsights/agent/internal/profiler/ProfilerContinuousProfilingTest.java @@ -0,0 +1,146 @@ +// Copyright (c) Microsoft Corporation. All rights reserved. +// Licensed under the MIT License. + +package com.microsoft.applicationinsights.agent.internal.profiler; + +import static org.assertj.core.api.Assertions.assertThat; +import static org.mockito.ArgumentMatchers.any; +import static org.mockito.ArgumentMatchers.anyString; +import static org.mockito.ArgumentMatchers.eq; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.never; +import static org.mockito.Mockito.verify; + +import com.microsoft.applicationinsights.agent.internal.configuration.Configuration; +import com.microsoft.applicationinsights.agent.internal.profiler.testutil.TestTimeSource; +import com.microsoft.applicationinsights.agent.internal.profiler.upload.UploadListener; +import com.microsoft.applicationinsights.agent.internal.profiler.upload.UploadService; +import com.microsoft.applicationinsights.alerting.alert.AlertBreach; +import com.microsoft.applicationinsights.alerting.config.AlertConfiguration; +import com.microsoft.applicationinsights.alerting.config.AlertMetricType; +import io.opentelemetry.contrib.jfr.connection.FlightRecorderConnection; +import io.opentelemetry.contrib.jfr.connection.Recording; +import io.opentelemetry.contrib.jfr.connection.RecordingConfiguration; +import io.opentelemetry.contrib.jfr.connection.RecordingOptions; +import java.io.File; +import java.time.Duration; +import java.time.Instant; +import java.util.UUID; +import java.util.concurrent.Executors; +import java.util.concurrent.ScheduledExecutorService; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.Test; +import org.junit.jupiter.api.io.TempDir; + +class ProfilerContinuousProfilingTest { + @TempDir File tempDir; + + private final TestTimeSource timeSource = new TestTimeSource(); + private ScheduledExecutorService executor; + + @AfterEach + void tearDown() { + if (executor != null) { + executor.shutdownNow(); + } + } + + private static AlertBreach manualBreach(int profileDurationSeconds) { + return AlertBreach.builder() + .setType(AlertMetricType.MANUAL) + .setAlertValue(0.0) + .setAlertConfiguration( + AlertConfiguration.builder() + .setType(AlertMetricType.MANUAL) + .setEnabled(true) + .setProfileDurationSeconds(profileDurationSeconds) + .build()) + .setProfileId(UUID.randomUUID().toString()) + .setCpuMetric(0) + .setMemoryUsage(0) + .build(); + } + + @Test + void profileRequestAlwaysDumpsWholeBufferEvenForShorterRequestedDuration() throws Exception { + Configuration.ProfilerConfiguration config = new Configuration.ProfilerConfiguration(); + config.enableContinuousProfiling = true; + config.continuousProfilingMaxAgeSeconds = 60; + config.globalCooldownSeconds = 0; + + Recording continuousRecording = mock(Recording.class); + + Profiler profiler = + new Profiler(config, tempDir, timeSource) { + @Override + protected Recording createRecording(RecordingOptions o, RecordingConfiguration c) { + return continuousRecording; + } + }; + + UploadService uploadService = mock(UploadService.class); + FlightRecorderConnection frc = mock(FlightRecorderConnection.class); + executor = Executors.newScheduledThreadPool(1); + profiler.initialize(uploadService, executor, frc); + + // Continuous recording is started up-front and kept running. + verify(continuousRecording).start(); + + Instant now = Instant.parse("2025-01-01T00:00:00Z"); + timeSource.setNow(now); + UploadListener noOp = index -> {}; + + // A live circular buffer can only be dumped in its entirety; a shorter portal-/JMX-configured + // duration (10s) cannot be honored by streaming a sub-window from the still-running recording, + // so the whole 60s buffer is dumped via the robust dump() path. + profiler.profileAndUpload(manualBreach(10), Duration.ofSeconds(10), noOp); + + verify(continuousRecording).dump(anyString()); + verify(continuousRecording, never()).getStream(any(), any()); + verify(continuousRecording, never()).stop(); + // The captured window is the whole 60s buffer, so the profile is timestamped at now - 60s. + verify(uploadService) + .upload(any(), eq(now.minusSeconds(60).toEpochMilli()), any(File.class), any()); + assertThat(profiler.isRecordingActive()).isFalse(); + } + + @Test + void profileRequestDumpsWholeBufferWhenRequestedDurationExceedsMaxAge() throws Exception { + Configuration.ProfilerConfiguration config = new Configuration.ProfilerConfiguration(); + config.enableContinuousProfiling = true; + config.continuousProfilingMaxAgeSeconds = 60; + config.globalCooldownSeconds = 0; + + Recording continuousRecording = mock(Recording.class); + Profiler profiler = + new Profiler(config, tempDir, timeSource) { + @Override + protected Recording createRecording(RecordingOptions o, RecordingConfiguration c) { + return continuousRecording; + } + }; + + UploadService uploadService = mock(UploadService.class); + FlightRecorderConnection frc = mock(FlightRecorderConnection.class); + executor = Executors.newScheduledThreadPool(1); + profiler.initialize(uploadService, executor, frc); + + verify(continuousRecording).start(); + + timeSource.setNow(Instant.parse("2025-01-01T00:00:00Z")); + Instant now = Instant.parse("2025-01-01T00:00:00Z"); + UploadListener noOp = index -> {}; + + // The requested duration (90s) exceeds the 60s buffer, so the whole circular buffer is dumped + // via the more robust dump() path. + profiler.profileAndUpload(manualBreach(90), Duration.ofSeconds(90), noOp); + + verify(continuousRecording).dump(anyString()); + verify(continuousRecording, never()).getStream(any(), any()); + verify(continuousRecording, never()).stop(); + // The captured window is the whole 60s buffer, so the profile is timestamped at now - 60s. + verify(uploadService) + .upload(any(), eq(now.minusSeconds(60).toEpochMilli()), any(File.class), any()); + assertThat(profiler.isRecordingActive()).isFalse(); + } +} diff --git a/docs/README.md b/docs/README.md index 0574b30ca65..56615a8d9af 100644 --- a/docs/README.md +++ b/docs/README.md @@ -96,6 +96,8 @@ Additionally, a number of parameters can be configured using environment variabl "manualTriggeredSettings": "profile-without-env-data", "globalCooldownSeconds": 120, "enableProfilerControlMBean": false, + "enableContinuousProfiling": false, + "continuousProfilingMaxAgeSeconds": 120, "manualTrigger": { "enabled": false, "filePath": "applicationinsights-agent-profile-trigger", @@ -135,6 +137,27 @@ cooldowns still apply). (`com.microsoft:type=AI-alert,name=ProfilerControl`) that allows triggering profiles via JMX tools. See [Manual Profile Triggering](#manual-profile-triggering) for usage. +`enableContinuousProfiling` - (default: false) When enabled, the profiler keeps a single JFR +recording running continuously using a circular buffer (bounded by `continuousProfilingMaxAgeSeconds`) +instead of starting a new timed recording for each trigger. When a profile is requested, the current +contents of the circular buffer are dumped and uploaded immediately, so requests are serviced without +waiting for a recording duration to elapse. The uploaded profile is timestamped at the start of the +captured window. Note the following limitations while this feature is in preview: + +- The continuous recording uses the `cpuTriggeredSettings` JFC for all trigger types, so + `memoryTriggeredSettings` and `manualTriggeredSettings` are not applied to continuous captures. +- A requested profile duration (from the portal, JMX, or a file trigger) is ignored: each request + dumps the whole retained circular buffer (up to `continuousProfilingMaxAgeSeconds`), because a + live JFR recording can only be dumped in its entirety and cannot be streamed for a sub-window + without being stopped. +- Because JFR runs for the lifetime of the JVM rather than in short bursts, expect a steady-state + increase in CPU, memory and disk I/O compared to on-demand profiling. + +`continuousProfilingMaxAgeSeconds` - (default: 120) The maximum age, in seconds, of data retained in +the continuous profiling circular buffer. Only used when `enableContinuousProfiling` is `true`. +Non-positive values fall back to the default. Larger values increase both the on-disk retention and +the size of each uploaded profile. + `manualTrigger` - Configuration for the file-based manual profile trigger: - `enabled` - (default: false) Whether the file-based manual trigger is enabled. diff --git a/smoke-tests/apps/Diagnostics/JfrFileReader/src/main/java/com/microsoft/applicationinsights/jfrfile/JfrFileReader.java b/smoke-tests/apps/Diagnostics/JfrFileReader/src/main/java/com/microsoft/applicationinsights/jfrfile/JfrFileReader.java index 6af5701aad2..6df6ac368ac 100644 --- a/smoke-tests/apps/Diagnostics/JfrFileReader/src/main/java/com/microsoft/applicationinsights/jfrfile/JfrFileReader.java +++ b/smoke-tests/apps/Diagnostics/JfrFileReader/src/main/java/com/microsoft/applicationinsights/jfrfile/JfrFileReader.java @@ -7,6 +7,7 @@ import java.io.IOException; import java.nio.file.Path; import jdk.jfr.EventType; +import jdk.jfr.consumer.RecordedEvent; import jdk.jfr.consumer.RecordingFile; public class JfrFileReader { @@ -17,4 +18,23 @@ public static boolean hasEventOfType(Path jfrFile, String event) throws IOExcept .stream().map(EventType::getName) .anyMatch(event::equals); } + + /** + * Returns true if the recording contains at least one actual event instance of the given type. + * + *

Unlike {@link #hasEventOfType(Path, String)}, which only checks whether the event type is + * registered in the recording metadata, this reads the recorded events and confirms one was + * actually captured. + */ + public static boolean hasEventInstanceOfType(Path jfrFile, String event) throws IOException { + try (RecordingFile recordingFile = new RecordingFile(jfrFile)) { + while (recordingFile.hasMoreEvents()) { + RecordedEvent recordedEvent = recordingFile.readEvent(); + if (recordedEvent.getEventType().getName().equals(event)) { + return true; + } + } + } + return false; + } } diff --git a/smoke-tests/apps/Diagnostics/src/main/java/com/microsoft/applicationinsights/smoketestapp/TestController.java b/smoke-tests/apps/Diagnostics/src/main/java/com/microsoft/applicationinsights/smoketestapp/TestController.java index 4ff77440f75..2867736cf44 100644 --- a/smoke-tests/apps/Diagnostics/src/main/java/com/microsoft/applicationinsights/smoketestapp/TestController.java +++ b/smoke-tests/apps/Diagnostics/src/main/java/com/microsoft/applicationinsights/smoketestapp/TestController.java @@ -5,9 +5,14 @@ import java.io.File; import java.io.OutputStream; +import java.io.UncheckedIOException; import java.nio.file.Files; import java.nio.file.Path; -import java.util.Optional; +import java.util.Collections; +import java.util.Comparator; +import java.util.List; +import java.util.stream.Collectors; +import java.util.stream.Stream; import java.util.zip.GZIPInputStream; import java.util.zip.ZipException; import org.springframework.web.bind.annotation.GetMapping; @@ -22,41 +27,99 @@ public String root() { @GetMapping("/jfrFileHasDiagnostics") public String jfrFileHasDiagnostics() throws Exception { - Optional jfrFile; - for (int i = 0; i < 60; i++) { - try { - jfrFile = - Files.walk(new File("/tmp/root/applicationinsights").toPath()) - .filter(Files::isRegularFile) - .filter(it -> it.toFile().getName().contains(".jfr")) - .findFirst(); - - if (!jfrFile.isPresent()) { - Thread.sleep(1000, 0); - continue; - } + return String.valueOf( + pollForJfrFileMatching( + decompressedFile -> + com.microsoft.applicationinsights.jfrfile.JfrFileReader.hasEventOfType( + decompressedFile, + "com.microsoft.applicationinsights.diagnostics.jfr.Telemetry"))); + } - Path decompressedFile = decompressFile(jfrFile.get()); + /** + * Verifies that a continuous-profiling recording captured the breach diagnostic events. When a + * profile is requested the profiler immediately dumps the backward-looking circular buffer, so + * {@code AlertBreach}, {@code MachineInfo} and {@code CGroupData} must be emitted before the dump + * in order to be captured in the recording. + */ + @GetMapping("/continuousJfrFileHasDiagnostics") + public String continuousJfrFileHasDiagnostics() throws Exception { + String[] requiredEvents = { + "com.microsoft.applicationinsights.diagnostics.jfr.AlertBreach", + "com.microsoft.applicationinsights.diagnostics.jfr.MachineInfo", + "com.microsoft.applicationinsights.diagnostics.jfr.CGroupData", + }; - boolean hasTelemetry = - com.microsoft.applicationinsights.jfrfile.JfrFileReader.hasEventOfType( - decompressedFile, "com.microsoft.applicationinsights.diagnostics.jfr.Telemetry"); + return String.valueOf( + pollForJfrFileMatching( + decompressedFile -> { + for (String event : requiredEvents) { + if (!com.microsoft.applicationinsights.jfrfile.JfrFileReader.hasEventInstanceOfType( + decompressedFile, event)) { + return false; + } + } + return true; + })); + } - if (hasTelemetry) { - return String.valueOf(true); - } - } catch (Exception e) { - // Ignore early exceptions, as to be expected, throw them if they are still happening - // towards the end - if (i > 55) { - throw e; - } else { - Thread.sleep(1000, 0); + /** + * Polls for up to 60 seconds for a {@code .jfr} file produced by the agent that satisfies {@code + * predicate}. Continuous profiling can produce several dumps and a dump may be observed + * mid-write, so every candidate file is examined (newest first) and any file that cannot be read + * yet is skipped rather than failing the whole request. + */ + private boolean pollForJfrFileMatching(JfrFilePredicate predicate) throws Exception { + for (int i = 0; i < 60; i++) { + for (Path jfrFile : findJfrFilesNewestFirst()) { + Path decompressedFile = null; + try { + decompressedFile = decompressFile(jfrFile); + if (predicate.test(decompressedFile)) { + return true; + } + } catch (Exception e) { + // A dump may still be being written, or otherwise unreadable; skip it and try the next + // candidate / next poll iteration. + if (i > 55) { + e.printStackTrace(); + } + } finally { + // decompressFile returns the original file (not a temp copy) when decompression fails, so + // only delete files we actually created to avoid removing the agent's dump. + if (decompressedFile != null && !decompressedFile.equals(jfrFile)) { + try { + Files.deleteIfExists(decompressedFile); + } catch (java.io.IOException ignored) { + // best effort cleanup + } + } } } + Thread.sleep(1000, 0); } - return String.valueOf(false); + return false; + } + + @FunctionalInterface + private interface JfrFilePredicate { + boolean test(Path decompressedFile) throws Exception; + } + + private static List findJfrFilesNewestFirst() { + Path root = new File("/tmp/root/applicationinsights").toPath(); + if (!Files.isDirectory(root)) { + return Collections.emptyList(); + } + try (Stream files = Files.walk(root)) { + return files + .filter(Files::isRegularFile) + .filter(it -> it.toFile().getName().contains(".jfr")) + .sorted(Comparator.comparingLong((Path it) -> it.toFile().lastModified()).reversed()) + .collect(Collectors.toList()); + } catch (java.io.IOException e) { + throw new UncheckedIOException(e); + } } private Path decompressFile(Path jfrFile) { diff --git a/smoke-tests/apps/Diagnostics/src/smokeTest/java/com/microsoft/applicationinsights/smoketest/DiagnosticsTest.java b/smoke-tests/apps/Diagnostics/src/smokeTest/java/com/microsoft/applicationinsights/smoketest/DiagnosticsTest.java index d43ab793d0c..e6641d1e625 100644 --- a/smoke-tests/apps/Diagnostics/src/smokeTest/java/com/microsoft/applicationinsights/smoketest/DiagnosticsTest.java +++ b/smoke-tests/apps/Diagnostics/src/smokeTest/java/com/microsoft/applicationinsights/smoketest/DiagnosticsTest.java @@ -41,4 +41,25 @@ static class Java11Test extends DiagnosticsTest { super(testing); } } + + @UseAgent("applicationinsights-continuous.json") + @Environment(JAVA_11) + static class ContinuousProfilingJava11Test extends DiagnosticsTest { + + @RegisterExtension + static final SmokeTestExtension testing = + BASE_BUILDER.setProfilerEndpoint(ProfilerState.manualprofile).build(); + + ContinuousProfilingJava11Test() { + super(testing); + } + + @Test + @TargetUri("/") + void continuousRecordingHasBreachDiagnostics() throws Exception { + String url = testing.getBaseUrl() + "/continuousJfrFileHasDiagnostics"; + String response = HttpHelper.get(url, "", emptyMap()); + Assertions.assertTrue(Boolean.parseBoolean(response)); + } + } } diff --git a/smoke-tests/apps/Diagnostics/src/smokeTest/resources/applicationinsights-continuous.json b/smoke-tests/apps/Diagnostics/src/smokeTest/resources/applicationinsights-continuous.json new file mode 100644 index 00000000000..7ae10f1226c --- /dev/null +++ b/smoke-tests/apps/Diagnostics/src/smokeTest/resources/applicationinsights-continuous.json @@ -0,0 +1,17 @@ +{ + "role" : { + "name" : "testrolename", + "instance" : "testroleinstance" + }, + "sampling" : { + "percentage" : 100 + }, + "preview" : { + "profiler" : { + "enabled" : true, + "enableContinuousProfiling" : true, + "continuousProfilingMaxAgeSeconds" : 120, + "enableDiagnostics" : true + } + } +}