Collect and log exceptions occurring in DeferredWorkQueue tasks (#9449)

This commit is contained in:
Dennis C authored and GitHub committed 2023-05-04 16:43:34 -07:00
1 parent e1bf07dece
commit 3de22ffba3
3 files changed
+103 -6

No files matched your search

@@ -11,9 +11,11 @@ import java.util.HashMap;
import java.util.Map;
import java.util.Optional;
import java.util.concurrent.CompletableFuture;
import java.util.concurrent.CompletionException;
import java.util.concurrent.ConcurrentLinkedDeque;
import java.util.concurrent.Executor;
import java.util.concurrent.TimeUnit;
import java.util.function.Function;
import java.util.function.Supplier;
import com.google.common.base.Stopwatch;
@@ -53,17 +55,29 @@ public class DeferredWorkQueue
public void runTasks() {
if (tasks.isEmpty()) return;
LOGGER.debug(LOADING, "Dispatching synchronous work for work queue {}: {} jobs", modLoadingStage, tasks.size());
RuntimeException aggregate = new RuntimeException();
Stopwatch timer = Stopwatch.createStarted();
tasks.forEach(t->makeRunnable(t, Runnable::run));
tasks.forEach(t -> makeRunnable(t, Runnable::run, aggregate));
timer.stop();
LOGGER.debug(LOADING, "Synchronous work queue completed in {}", timer);
if (aggregate.getSuppressed().length > 0) {
LOGGER.fatal(
LOADING,
"Synchronous work queue completed exceptionally in {}, see suppressed exceptions for details:",
timer,
aggregate
);
//TODO 1.20: throw aggregate exception
} else {
LOGGER.debug(LOADING, "Synchronous work queue completed in {}", timer);
}
}
private static void makeRunnable(TaskInfo ti, Executor executor) {
private static void makeRunnable(TaskInfo ti, Executor executor, RuntimeException aggregate) {
executor.execute(() -> {
Stopwatch timer = Stopwatch.createStarted();
ModLoadingContext.get().setActiveContainer(ti.owner);
try {
ti.future.exceptionally(t -> captureException(ti.owner.getModId(), aggregate, t));
ti.task.run();
} finally {
ModLoadingContext.get().setActiveContainer(null);
@@ -75,13 +89,38 @@ public class DeferredWorkQueue
});
}
private static <T> T captureException(String modId, RuntimeException aggregate, Throwable throwable) {
if (throwable instanceof CompletionException ce) {
throwable = ce.getCause();
}
aggregate.addSuppressed(throwable);
LOGGER.error("Mod '{}' encountered an error in a deferred task:", modId, throwable);
return null;
}
public CompletableFuture<Void> enqueueWork(final ModContainer modInfo, final Runnable work) {
return CompletableFuture.runAsync(work, r->tasks.add(new TaskInfo(modInfo, r)));
return enqueueWork(modInfo, taskInfo -> CompletableFuture.runAsync(work, r -> taskInfo.task = r));
}
public <T> CompletableFuture<T> enqueueWork(final ModContainer modInfo, final Supplier<T> work) {
return CompletableFuture.supplyAsync(work, r->tasks.add(new TaskInfo(modInfo, r)));
return enqueueWork(modInfo, taskInfo -> CompletableFuture.supplyAsync(work, r -> taskInfo.task = r));
}
record TaskInfo(ModContainer owner, Runnable task) {}
private <T> CompletableFuture<T> enqueueWork(final ModContainer modInfo, Function<TaskInfo, CompletableFuture<T>> futureGen) {
TaskInfo taskInfo = new TaskInfo(modInfo);
CompletableFuture<T> future = futureGen.apply(taskInfo);
taskInfo.future = future;
tasks.add(taskInfo);
return future;
}
private static class TaskInfo {
private final ModContainer owner;
private Runnable task;
private CompletableFuture<?> future;
private TaskInfo(ModContainer owner) {
this.owner = owner;
}
}
}
@@ -0,0 +1,56 @@
/*
* Copyright (c) Forge Development LLC and contributors
* SPDX-License-Identifier: LGPL-2.1-only
*/
package net.minecraftforge.debug;
import com.mojang.logging.LogUtils;
import net.minecraftforge.eventbus.api.SubscribeEvent;
import net.minecraftforge.fml.common.Mod;
import net.minecraftforge.fml.event.lifecycle.FMLCommonSetupEvent;
import org.slf4j.Logger;
/**
* Tests that the {@link net.minecraftforge.fml.DeferredWorkQueue} properly executes enqueued tasks and
* forwards any exceptions thrown by those tasks
*/
@Mod(DeferredWorkQueueTest.MOD_ID)
@Mod.EventBusSubscriber(modid = DeferredWorkQueueTest.MOD_ID, bus = Mod.EventBusSubscriber.Bus.MOD)
public class DeferredWorkQueueTest
{
public static final String MOD_ID = "deferred_work_queue_test";
private static final boolean ENABLE = false;
private static final Logger LOGGER = LogUtils.getLogger();
public DeferredWorkQueueTest() { }
@SubscribeEvent
public static void onCommonSetup(final FMLCommonSetupEvent event)
{
if (!ENABLE)
{
return;
}
event.enqueueWork(() -> LOGGER.info("Enqueued runnable ran"));
event.enqueueWork(() -> "Enqueued supplier ran").thenAccept(LOGGER::info);
event.enqueueWork(DeferredWorkQueueTest::executeThrowingRunnable);
event.enqueueWork(DeferredWorkQueueTest::executeThrowingSupplier).thenAccept(s ->
LOGGER.error("This must not be printed")
);
}
private static void executeThrowingRunnable()
{
LOGGER.info("Enqueued throwing runnable ran");
throw new IllegalStateException("Throwing runnable ran");
}
private static String executeThrowingSupplier()
{
LOGGER.info("Enqueued throwing supplier ran");
throw new IllegalStateException("Throwing supplier ran");
}
}
+2
View File
@@ -26,6 +26,8 @@ modId="mdk_datagen"
modId="shader_resources_test"
[[mods]]
modId="crash_callable_test"
[[mods]]
modId="deferred_work_queue_test"
# LEGACY TEST CASES
###### The mods below are from the old test framework and need to be yeeted later again.