From 3be2659ef8baf573e34e5875c3e8edc461321915 Mon Sep 17 00:00:00 2001 From: Teng Zhang Date: Thu, 4 Sep 2025 11:53:58 +0800 Subject: [PATCH 1/3] Log cpu cores and memory size --- .../java/pascal/taie/util/RuntimeInfoLogger.java | 13 +++++++++++++ 1 file changed, 13 insertions(+) diff --git a/src/main/java/pascal/taie/util/RuntimeInfoLogger.java b/src/main/java/pascal/taie/util/RuntimeInfoLogger.java index 829cf8a4d..7130a8de8 100644 --- a/src/main/java/pascal/taie/util/RuntimeInfoLogger.java +++ b/src/main/java/pascal/taie/util/RuntimeInfoLogger.java @@ -64,6 +64,7 @@ public class RuntimeInfoLogger { */ public static void logRuntimeInfo() { logEnvInfo(); + logSystemInfo(); logTaieInfo(); } @@ -77,6 +78,18 @@ private static void logEnvInfo() { } } + /** + * Logs system information such as the number of CPU cores and total memory size. + */ + private static void logSystemInfo() { + var osBean = (com.sun.management.OperatingSystemMXBean) + java.lang.management.ManagementFactory.getOperatingSystemMXBean(); + int cpuCores = osBean.getAvailableProcessors(); + long memoryMB = osBean.getTotalMemorySize() / (1024 * 1024); + logger.info("Available CPU cores: {}", cpuCores); + logger.info("Total memory (MB): {}", memoryMB); + } + /** * Logs Tai-e version and commit information by attempting to read from the build properties file * or fallback methods if the build properties are not available. From a00ed9c85c582052870a43d581d61e67b6dc1a4b Mon Sep 17 00:00:00 2001 From: Teng Zhang Date: Thu, 4 Sep 2025 12:04:10 +0800 Subject: [PATCH 2/3] Unify timer logging --- src/main/java/pascal/taie/util/Timer.java | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/src/main/java/pascal/taie/util/Timer.java b/src/main/java/pascal/taie/util/Timer.java index 1b7471788..eb494b005 100644 --- a/src/main/java/pascal/taie/util/Timer.java +++ b/src/main/java/pascal/taie/util/Timer.java @@ -87,13 +87,12 @@ public String toString() { * @param taskName name of the task */ public static T runAndCount(Supplier task, String taskName, Level level) { - logger.info("{} starts ...", taskName); + logger.info("[{}] starts ...", taskName); Timer timer = new Timer(taskName); timer.start(); T result = task.get(); timer.stop(); - logger.log(level, "{} finishes, elapsed time: {}", taskName, - String.format("%.2fs", timer.inSecond())); + logger.log(level, timer); return result; } From d935c5060d9ef48ba5df29d3a2c18d3fa00f81a5 Mon Sep 17 00:00:00 2001 From: Teng Zhang Date: Fri, 5 Sep 2025 12:45:25 +0800 Subject: [PATCH 3/3] Add performance monitor function to Timer --- .../pascal/taie/util/RuntimeInfoLogger.java | 2 +- src/main/java/pascal/taie/util/Timer.java | 84 ++++++++++++++++++- 2 files changed, 81 insertions(+), 5 deletions(-) diff --git a/src/main/java/pascal/taie/util/RuntimeInfoLogger.java b/src/main/java/pascal/taie/util/RuntimeInfoLogger.java index 7130a8de8..525ef6322 100644 --- a/src/main/java/pascal/taie/util/RuntimeInfoLogger.java +++ b/src/main/java/pascal/taie/util/RuntimeInfoLogger.java @@ -87,7 +87,7 @@ private static void logSystemInfo() { int cpuCores = osBean.getAvailableProcessors(); long memoryMB = osBean.getTotalMemorySize() / (1024 * 1024); logger.info("Available CPU cores: {}", cpuCores); - logger.info("Total memory (MB): {}", memoryMB); + logger.info("Total memory: {}MB", memoryMB); } /** diff --git a/src/main/java/pascal/taie/util/Timer.java b/src/main/java/pascal/taie/util/Timer.java index eb494b005..e00fa274b 100644 --- a/src/main/java/pascal/taie/util/Timer.java +++ b/src/main/java/pascal/taie/util/Timer.java @@ -22,15 +22,19 @@ package pascal.taie.util; +import com.sun.management.OperatingSystemMXBean; import org.apache.logging.log4j.Level; import org.apache.logging.log4j.LogManager; import org.apache.logging.log4j.Logger; +import java.lang.management.ManagementFactory; +import java.lang.management.MemoryMXBean; import java.time.Duration; import java.util.concurrent.ExecutionException; import java.util.concurrent.ExecutorService; import java.util.concurrent.Executors; import java.util.concurrent.Future; +import java.util.concurrent.ScheduledExecutorService; import java.util.concurrent.TimeUnit; import java.util.concurrent.TimeoutException; import java.util.function.Supplier; @@ -39,29 +43,71 @@ public class Timer { private static final Logger logger = LogManager.getLogger(Timer.class); + /** + * Monitoring interval in seconds + */ + private static final int INTERVAL = 1; + private final String name; - private long elapsedTime = 0; + private final OperatingSystemMXBean osBean; + private final MemoryMXBean memoryBean; + private final ScheduledExecutorService scheduler; + // Time tracking private long startTime; + private long elapsedTime = 0; + + // CPU and Memory tracking + private double startCpuUsage; + private double peakCpuUsage; + private double endCpuUsage; + private long startMemoryMB; + private long peakMemoryMB; + private long endMemoryMB; private boolean inCounting = false; public Timer(String name) { this.name = name; + this.osBean = (OperatingSystemMXBean) ManagementFactory + .getOperatingSystemMXBean(); + this.memoryBean = ManagementFactory.getMemoryMXBean(); + this.scheduler = Executors.newSingleThreadScheduledExecutor(r -> { + Thread t = new Thread(r, this.getClass().getName() + "[" + name + "]"); + t.setDaemon(true); + return t; + }); } public void start() { if (!inCounting) { inCounting = true; startTime = System.currentTimeMillis(); + startCpuUsage = getCpuUsage(); + startMemoryMB = getMemoryUsedMB(); + // start up the scheduler + scheduler.scheduleAtFixedRate(this::updatePeakValues, + 0, INTERVAL, TimeUnit.SECONDS); } } public void stop() { if (inCounting) { - elapsedTime += System.currentTimeMillis() - startTime; inCounting = false; + elapsedTime += System.currentTimeMillis() - startTime; + endCpuUsage = getCpuUsage(); + endMemoryMB = getMemoryUsedMB(); + // shut down the scheduler + scheduler.shutdown(); + try { + if (!scheduler.awaitTermination(2, TimeUnit.SECONDS)) { + scheduler.shutdownNow(); + } + } catch (InterruptedException e) { + scheduler.shutdownNow(); + Thread.currentThread().interrupt(); + } } } @@ -76,8 +122,38 @@ public void clear() { @Override public String toString() { - return String.format("[%s] elapsed time: %.2fs", - name, inSecond()); + StringBuilder sb = new StringBuilder(); + sb.append(String.format("[%s] elapsed time: %.2fs", name, inSecond())); + sb.append(String.format("; CPU usage: start %.2f%%, peak %.2f%%, end %.2f%%", + startCpuUsage * 100, peakCpuUsage * 100, endCpuUsage * 100)); + sb.append(String.format("; Memory usage: start %dMB, peak %dMB, end %dMB", + startMemoryMB, peakMemoryMB, endMemoryMB)); + return sb.toString(); + } + + private void updatePeakValues() { + double currentCpuUsage = getCpuUsage(); + if (currentCpuUsage > peakCpuUsage) { + peakCpuUsage = currentCpuUsage; + } + long currentMemoryMB = getMemoryUsedMB(); + if (currentMemoryMB > peakMemoryMB) { + peakMemoryMB = currentMemoryMB; + } + } + + private double getCpuUsage() { + double processCpuUsage = osBean.getProcessCpuLoad(); + if (processCpuUsage < 0) { + processCpuUsage = 0.0; + } + return processCpuUsage; + } + + private long getMemoryUsedMB() { + long heapMemoryUsed = memoryBean.getHeapMemoryUsage().getUsed(); + long nonHeapMemoryUsed = memoryBean.getNonHeapMemoryUsage().getUsed(); + return (heapMemoryUsed + nonHeapMemoryUsed) / (1024 * 1024); } /**