Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
13 changes: 13 additions & 0 deletions src/main/java/pascal/taie/util/RuntimeInfoLogger.java
Original file line number Diff line number Diff line change
Expand Up @@ -64,6 +64,7 @@ public class RuntimeInfoLogger {
*/
public static void logRuntimeInfo() {
logEnvInfo();
logSystemInfo();
logTaieInfo();
}

Expand All @@ -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.
Expand Down
89 changes: 82 additions & 7 deletions src/main/java/pascal/taie/util/Timer.java
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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();
}
}
}

Expand All @@ -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);
}

/**
Expand All @@ -87,13 +163,12 @@ public String toString() {
* @param taskName name of the task
*/
public static <T> T runAndCount(Supplier<T> 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;
}

Expand Down
Loading