Add simulation profiler
This commit is contained in:
@@ -76,9 +76,14 @@ public final class SimulationManager {
|
|||||||
|
|
||||||
List<RegionUpdateJob> jobs = this.scheduler.pollJobsForCycle();
|
List<RegionUpdateJob> jobs = this.scheduler.pollJobsForCycle();
|
||||||
int nextJobIndex = 0;
|
int nextJobIndex = 0;
|
||||||
|
boolean budgetOverrunRecorded = false;
|
||||||
try {
|
try {
|
||||||
for (; nextJobIndex < jobs.size(); nextJobIndex++) {
|
for (; nextJobIndex < jobs.size(); nextJobIndex++) {
|
||||||
if (nextJobIndex > 0 && hasExceededTimeBudget(startTimeNanos)) {
|
if (nextJobIndex > 0 && hasExceededTimeBudget(startTimeNanos)) {
|
||||||
|
if (this.profiler != null) {
|
||||||
|
this.profiler.recordBudgetOverrun();
|
||||||
|
budgetOverrunRecorded = true;
|
||||||
|
}
|
||||||
requeueJobs(jobs, nextJobIndex);
|
requeueJobs(jobs, nextJobIndex);
|
||||||
break;
|
break;
|
||||||
}
|
}
|
||||||
@@ -97,6 +102,10 @@ public final class SimulationManager {
|
|||||||
long durationMs = elapsedMilliseconds(startTimeNanos);
|
long durationMs = elapsedMilliseconds(startTimeNanos);
|
||||||
this.scheduler.endCycle(durationMs);
|
this.scheduler.endCycle(durationMs);
|
||||||
if (this.profiler != null) {
|
if (this.profiler != null) {
|
||||||
|
if (!budgetOverrunRecorded
|
||||||
|
&& durationMs > this.scheduler.getMaxMillisecondsPerCycle()) {
|
||||||
|
this.profiler.recordBudgetOverrun();
|
||||||
|
}
|
||||||
this.profiler.endCycle(durationMs);
|
this.profiler.endCycle(durationMs);
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
@@ -126,6 +135,9 @@ public final class SimulationManager {
|
|||||||
}
|
}
|
||||||
|
|
||||||
try {
|
try {
|
||||||
|
if (this.profiler != null) {
|
||||||
|
this.profiler.beginModule(module.getModuleId());
|
||||||
|
}
|
||||||
ModuleUpdateResult result = module.updateRegion(new RegionUpdateContext(region));
|
ModuleUpdateResult result = module.updateRegion(new RegionUpdateContext(region));
|
||||||
if (result == null) {
|
if (result == null) {
|
||||||
throw new IllegalStateException(
|
throw new IllegalStateException(
|
||||||
@@ -133,7 +145,12 @@ public final class SimulationManager {
|
|||||||
}
|
}
|
||||||
|
|
||||||
changed |= result.changedRegion();
|
changed |= result.changedRegion();
|
||||||
result.generatedEvents().forEach(this.eventBus::publish);
|
result.generatedEvents().forEach(event -> {
|
||||||
|
this.eventBus.publish(event);
|
||||||
|
if (this.profiler != null) {
|
||||||
|
this.profiler.recordEvent();
|
||||||
|
}
|
||||||
|
});
|
||||||
result.warnings().forEach(warning -> LivingWorldLogger.warn(
|
result.warnings().forEach(warning -> LivingWorldLogger.warn(
|
||||||
DiagnosticCategory.SIMULATION,
|
DiagnosticCategory.SIMULATION,
|
||||||
"[" + module.getModuleId() + "] " + warning));
|
"[" + module.getModuleId() + "] " + warning));
|
||||||
@@ -141,10 +158,17 @@ public final class SimulationManager {
|
|||||||
LivingWorldLogger.error(DiagnosticCategory.SIMULATION,
|
LivingWorldLogger.error(DiagnosticCategory.SIMULATION,
|
||||||
"Module update failed for " + module.getModuleId()
|
"Module update failed for " + module.getModuleId()
|
||||||
+ " in region " + region.getCoordinate(), e);
|
+ " in region " + region.getCoordinate(), e);
|
||||||
|
} finally {
|
||||||
|
if (this.profiler != null) {
|
||||||
|
this.profiler.endModule(module.getModuleId());
|
||||||
|
}
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
region.updateLastSimulatedTick(simulationTick);
|
region.updateLastSimulatedTick(simulationTick);
|
||||||
|
if (this.profiler != null) {
|
||||||
|
this.profiler.recordRegionUpdated();
|
||||||
|
}
|
||||||
if (changed) {
|
if (changed) {
|
||||||
this.regionManager.markDirty(region);
|
this.regionManager.markDirty(region);
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -20,4 +20,22 @@ public interface SimulationProfiler {
|
|||||||
* @param durationMs the wall-clock duration in milliseconds
|
* @param durationMs the wall-clock duration in milliseconds
|
||||||
*/
|
*/
|
||||||
void endCycle(long durationMs);
|
void endCycle(long durationMs);
|
||||||
|
|
||||||
|
default void beginModule(String moduleId) {
|
||||||
|
}
|
||||||
|
|
||||||
|
default void endModule(String moduleId) {
|
||||||
|
}
|
||||||
|
|
||||||
|
default void recordEvent() {
|
||||||
|
}
|
||||||
|
|
||||||
|
default void recordRegionUpdated() {
|
||||||
|
}
|
||||||
|
|
||||||
|
default void recordSave() {
|
||||||
|
}
|
||||||
|
|
||||||
|
default void recordBudgetOverrun() {
|
||||||
|
}
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -0,0 +1,38 @@
|
|||||||
|
package com.livingworld.debug;
|
||||||
|
|
||||||
|
import java.util.LinkedHashMap;
|
||||||
|
import java.util.Map;
|
||||||
|
|
||||||
|
/**
|
||||||
|
* Immutable snapshot of one simulation profiling cycle.
|
||||||
|
*/
|
||||||
|
public record SimulationProfileSnapshot(
|
||||||
|
long totalCycleNanos,
|
||||||
|
Map<String, Long> moduleTimings,
|
||||||
|
int eventsPublished,
|
||||||
|
int regionsUpdated,
|
||||||
|
int savesPerformed,
|
||||||
|
boolean budgetExceeded) {
|
||||||
|
|
||||||
|
public SimulationProfileSnapshot {
|
||||||
|
if (totalCycleNanos < 0) {
|
||||||
|
throw new IllegalArgumentException("totalCycleNanos must not be negative");
|
||||||
|
}
|
||||||
|
if (moduleTimings == null) {
|
||||||
|
throw new IllegalArgumentException("moduleTimings must not be null");
|
||||||
|
}
|
||||||
|
if (eventsPublished < 0 || regionsUpdated < 0 || savesPerformed < 0) {
|
||||||
|
throw new IllegalArgumentException("profile counts must not be negative");
|
||||||
|
}
|
||||||
|
moduleTimings = Map.copyOf(new LinkedHashMap<>(moduleTimings));
|
||||||
|
}
|
||||||
|
|
||||||
|
public String toHumanReadableString() {
|
||||||
|
return "cycle=" + (totalCycleNanos / 1_000_000.0) + "ms"
|
||||||
|
+ ", modules=" + moduleTimings
|
||||||
|
+ ", events=" + eventsPublished
|
||||||
|
+ ", regions=" + regionsUpdated
|
||||||
|
+ ", saves=" + savesPerformed
|
||||||
|
+ ", budgetExceeded=" + budgetExceeded;
|
||||||
|
}
|
||||||
|
}
|
||||||
@@ -0,0 +1,128 @@
|
|||||||
|
package com.livingworld.debug;
|
||||||
|
|
||||||
|
import java.util.LinkedHashMap;
|
||||||
|
import java.util.Map;
|
||||||
|
|
||||||
|
/**
|
||||||
|
* Measures simulation cycle and module cost using a monotonic clock.
|
||||||
|
*/
|
||||||
|
public final class SimulationProfiler
|
||||||
|
implements com.livingworld.core.simulation.SimulationProfiler {
|
||||||
|
|
||||||
|
private long cycleStartNanos = -1L;
|
||||||
|
private long totalCycleNanos;
|
||||||
|
private final Map<String, Long> moduleStartNanos = new LinkedHashMap<>();
|
||||||
|
private final Map<String, Long> moduleTimings = new LinkedHashMap<>();
|
||||||
|
private int eventsPublished;
|
||||||
|
private int regionsUpdated;
|
||||||
|
private int savesPerformed;
|
||||||
|
private int budgetOverruns;
|
||||||
|
|
||||||
|
public synchronized void beginCycle() {
|
||||||
|
if (cycleStartNanos >= 0L) {
|
||||||
|
throw new IllegalStateException("a profiling cycle is already active");
|
||||||
|
}
|
||||||
|
totalCycleNanos = 0L;
|
||||||
|
moduleStartNanos.clear();
|
||||||
|
moduleTimings.clear();
|
||||||
|
eventsPublished = 0;
|
||||||
|
regionsUpdated = 0;
|
||||||
|
savesPerformed = 0;
|
||||||
|
budgetOverruns = 0;
|
||||||
|
cycleStartNanos = System.nanoTime();
|
||||||
|
}
|
||||||
|
|
||||||
|
public synchronized void endCycle() {
|
||||||
|
ensureCycleActive();
|
||||||
|
if (!moduleStartNanos.isEmpty()) {
|
||||||
|
throw new IllegalStateException(
|
||||||
|
"cannot end cycle while modules are still active: " + moduleStartNanos.keySet());
|
||||||
|
}
|
||||||
|
totalCycleNanos = System.nanoTime() - cycleStartNanos;
|
||||||
|
cycleStartNanos = -1L;
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public synchronized void startCycle(long simulationTick) {
|
||||||
|
beginCycle();
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public synchronized void endCycle(long durationMs) {
|
||||||
|
endCycle();
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public synchronized void beginModule(String moduleId) {
|
||||||
|
ensureCycleActive();
|
||||||
|
validateModuleId(moduleId);
|
||||||
|
if (moduleStartNanos.putIfAbsent(moduleId, System.nanoTime()) != null) {
|
||||||
|
throw new IllegalStateException("module is already being profiled: " + moduleId);
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public synchronized void endModule(String moduleId) {
|
||||||
|
ensureCycleActive();
|
||||||
|
validateModuleId(moduleId);
|
||||||
|
Long startedAt = moduleStartNanos.remove(moduleId);
|
||||||
|
if (startedAt == null) {
|
||||||
|
throw new IllegalStateException("module profiling was not started: " + moduleId);
|
||||||
|
}
|
||||||
|
long elapsed = System.nanoTime() - startedAt;
|
||||||
|
moduleTimings.merge(moduleId, elapsed, Long::sum);
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public synchronized void recordEvent() {
|
||||||
|
ensureCycleActive();
|
||||||
|
eventsPublished++;
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public synchronized void recordRegionUpdated() {
|
||||||
|
ensureCycleActive();
|
||||||
|
regionsUpdated++;
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public synchronized void recordSave() {
|
||||||
|
ensureCycleActive();
|
||||||
|
savesPerformed++;
|
||||||
|
}
|
||||||
|
|
||||||
|
@Override
|
||||||
|
public synchronized void recordBudgetOverrun() {
|
||||||
|
ensureCycleActive();
|
||||||
|
budgetOverruns++;
|
||||||
|
}
|
||||||
|
|
||||||
|
public synchronized SimulationProfileSnapshot createSnapshot() {
|
||||||
|
long cycleNanos = cycleStartNanos >= 0L
|
||||||
|
? System.nanoTime() - cycleStartNanos
|
||||||
|
: totalCycleNanos;
|
||||||
|
return new SimulationProfileSnapshot(
|
||||||
|
cycleNanos,
|
||||||
|
moduleTimings,
|
||||||
|
eventsPublished,
|
||||||
|
regionsUpdated,
|
||||||
|
savesPerformed,
|
||||||
|
budgetOverruns > 0);
|
||||||
|
}
|
||||||
|
|
||||||
|
public synchronized int getBudgetOverrunCount() {
|
||||||
|
return budgetOverruns;
|
||||||
|
}
|
||||||
|
|
||||||
|
private void ensureCycleActive() {
|
||||||
|
if (cycleStartNanos < 0L) {
|
||||||
|
throw new IllegalStateException("no profiling cycle is active");
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
private static void validateModuleId(String moduleId) {
|
||||||
|
if (moduleId == null || moduleId.isBlank()) {
|
||||||
|
throw new IllegalArgumentException("moduleId must not be null or blank");
|
||||||
|
}
|
||||||
|
}
|
||||||
|
}
|
||||||
@@ -0,0 +1,55 @@
|
|||||||
|
package com.livingworld.debug;
|
||||||
|
|
||||||
|
import static org.junit.jupiter.api.Assertions.assertEquals;
|
||||||
|
import static org.junit.jupiter.api.Assertions.assertThrows;
|
||||||
|
import static org.junit.jupiter.api.Assertions.assertTrue;
|
||||||
|
|
||||||
|
import org.junit.jupiter.api.Test;
|
||||||
|
|
||||||
|
class SimulationProfilerTest {
|
||||||
|
|
||||||
|
@Test
|
||||||
|
void recordsCycleModulesEventsRegionsSavesAndBudgetOverruns() {
|
||||||
|
SimulationProfiler profiler = new SimulationProfiler();
|
||||||
|
|
||||||
|
profiler.beginCycle();
|
||||||
|
profiler.beginModule("soil");
|
||||||
|
profiler.endModule("soil");
|
||||||
|
profiler.recordEvent();
|
||||||
|
profiler.recordRegionUpdated();
|
||||||
|
profiler.recordSave();
|
||||||
|
profiler.recordBudgetOverrun();
|
||||||
|
profiler.endCycle();
|
||||||
|
|
||||||
|
SimulationProfileSnapshot snapshot = profiler.createSnapshot();
|
||||||
|
assertTrue(snapshot.totalCycleNanos() >= 0);
|
||||||
|
assertTrue(snapshot.moduleTimings().get("soil") >= 0);
|
||||||
|
assertEquals(1, snapshot.eventsPublished());
|
||||||
|
assertEquals(1, snapshot.regionsUpdated());
|
||||||
|
assertEquals(1, snapshot.savesPerformed());
|
||||||
|
assertTrue(snapshot.budgetExceeded());
|
||||||
|
assertTrue(snapshot.toHumanReadableString().contains("soil"));
|
||||||
|
}
|
||||||
|
|
||||||
|
@Test
|
||||||
|
void supportsExistingSimulationProfilerAdapterMethods() {
|
||||||
|
com.livingworld.core.simulation.SimulationProfiler profiler =
|
||||||
|
new SimulationProfiler();
|
||||||
|
|
||||||
|
profiler.startCycle(12);
|
||||||
|
profiler.beginModule("water");
|
||||||
|
profiler.endModule("water");
|
||||||
|
profiler.endCycle(1);
|
||||||
|
}
|
||||||
|
|
||||||
|
@Test
|
||||||
|
void validatesProfilingLifecycle() {
|
||||||
|
SimulationProfiler profiler = new SimulationProfiler();
|
||||||
|
|
||||||
|
assertThrows(IllegalStateException.class, profiler::endCycle);
|
||||||
|
profiler.beginCycle();
|
||||||
|
assertThrows(IllegalStateException.class, profiler::beginCycle);
|
||||||
|
assertThrows(IllegalArgumentException.class, () -> profiler.beginModule(" "));
|
||||||
|
assertThrows(IllegalStateException.class, () -> profiler.endModule("soil"));
|
||||||
|
}
|
||||||
|
}
|
||||||
Reference in New Issue
Block a user