Skip to content

Commit e655dbf

Browse files
committed
Force usage of System.out and System.err to go through the calling class's logger.
Combined with better-log4j-config, this will properly blame the class that logged to the wrong thing. Note: if it is somewhere in Minecraft, this may fail to give enough information and need to be made more thorough. We don't really consider raw System.out/System.err to be performance critical so a marginal hit can be taken if necessary.
1 parent b4932c0 commit e655dbf

4 files changed

Lines changed: 66 additions & 7 deletions

File tree

Lines changed: 20 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,20 @@
1+
package net.modfest.fireblanket.mixin.annoyances.stdio;
2+
3+
import net.minecraft.server.LoggedPrintStream;
4+
import net.modfest.fireblanket.stacksmash.StackUtil;
5+
import org.slf4j.Logger;
6+
import org.slf4j.LoggerFactory;
7+
import org.spongepowered.asm.mixin.Mixin;
8+
import org.spongepowered.asm.mixin.injection.At;
9+
import org.spongepowered.asm.mixin.injection.Redirect;
10+
11+
/**
12+
* @author Ampflower
13+
**/
14+
@Mixin(LoggedPrintStream.class)
15+
public class MixinLoggedPrintStream {
16+
@Redirect(method = "logLine", at = @At(value = "INVOKE", target = "Lorg/slf4j/Logger;info(Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;)V"))
17+
private static void onLog(final Logger instance, final String format, final Object name, final Object value) {
18+
LoggerFactory.getLogger(StackUtil.getCallerAsProxy(1).getDeclaringClass()).info(format, name, value);
19+
}
20+
}

src/main/java/net/modfest/fireblanket/stacksmash/StackTracer.java

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -34,7 +34,7 @@ public final class StackTracer implements Guard, Stack, Tracer {
3434
return;
3535
}
3636

37-
final StackFrame current = StackUtil.getCaller(stackDepth);
37+
final StackFrame current = StackUtil.getCallerAsProxy(stackDepth);
3838
this.frames.push(current);
3939
}
4040

@@ -43,15 +43,15 @@ public final class StackTracer implements Guard, Stack, Tracer {
4343
public boolean fireblanket$pop(int stackDepth) {
4444
if (this.fireblanket$guardCheck()) {
4545
final StackFrame peek = this.frames.peek();
46-
throw new StackSmashException(peek, StackUtil.getCaller(stackDepth));
46+
throw new StackSmashException(peek, StackUtil.getCallerAsProxy(stackDepth));
4747
//logger.warn("Guard check: attempted to pop {}", peek, );
4848
//return false;
4949
}
5050

5151
final StackFrame trace = this.frames.pop();
5252

5353
if (this.level != TraceLevel.NONE) {
54-
final StackFrame current = StackUtil.getCaller(stackDepth);
54+
final StackFrame current = StackUtil.getCallerAsProxy(stackDepth);
5555

5656
this.level.logIfMismatched(trace, current);
5757
}
@@ -63,15 +63,15 @@ public final class StackTracer implements Guard, Stack, Tracer {
6363
public void fireblanket$startTrace(final @NotNull TraceLevel level, final int depth) {
6464
if (this.frames.size() != 0) {
6565
this.frames.poll();
66-
this.frames.push(StackUtil.getCaller(3));
66+
this.frames.push(StackUtil.getCallerAsProxy(3));
6767
}
6868
this.level = level;
6969
this.startingTraceDepth = this.frames.size();
7070
}
7171

7272
@Override
7373
public void fireblanket$stopTrace(final int depth) {
74-
final StackFrame frame = StackUtil.getCaller(3);
74+
final StackFrame frame = StackUtil.getCallerAsProxy(3);
7575
final StackFrame trace = this.frames.peek();
7676

7777
this.level.logIfMismatched(trace, frame);

src/main/java/net/modfest/fireblanket/stacksmash/StackUtil.java

Lines changed: 40 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@
99
import org.slf4j.Logger;
1010

1111
import java.util.HashSet;
12+
import java.util.Iterator;
1213
import java.util.Objects;
1314
import java.util.Set;
1415

@@ -70,6 +71,8 @@ public final class StackUtil {
7071
}
7172
}
7273

74+
// TODO: admittedly, this isn't exactly intuitive, as I had to make a mini-diagnostic to
75+
// figure out the depth I actually needed.
7376
/**
7477
* Fetches the stack frame of the caller, skipping over
7578
* {@link #knownSkippableClasses known skippable classes}.
@@ -82,8 +85,8 @@ public final class StackUtil {
8285
* due to an optimization to avoid an expensive {@link String#startsWith(String)} call.
8386
*/
8487
@CheckReturnValue
85-
static StackWalker.StackFrame getCaller(final int depth) {
86-
// walker + self + caller to be skipped
88+
public static StackWalker.StackFrame getCallerAsProxy(final int depth) {
89+
// self + caller as proxy + caller to be skipped
8790
final int lambdaDepth = depth + 3;
8891
return walker.walk(stream -> stream
8992
.skip(lambdaDepth)
@@ -92,6 +95,41 @@ static StackWalker.StackFrame getCaller(final int depth) {
9295
).orElseThrow();
9396
}
9497

98+
/**
99+
* Mini-diagnostic for aiding in what depth should be added to {@link #getCallerAsProxy(int)}
100+
* to get the desired result.
101+
*
102+
* @param depth The amount that you think you need to skip.
103+
* @return The caller, either yours or your proxy's.
104+
* @implSpec This function shall operate the same as {@link #getCallerAsProxy(int)} to allow drop-in debugging,
105+
* with the sole exception of returning {@link TraceElement#nullFrame an empty frame} when it would otherwise fail.
106+
*
107+
*/
108+
public static StackWalker.StackFrame printCallStackAsProxy(final int depth) {
109+
final int lambdaDepth = depth + 3;
110+
return walker.walk(stream -> {
111+
StackWalker.StackFrame returnedFrame = null;
112+
int i = 0;
113+
final Iterator<StackWalker.StackFrame> itr = stream.iterator();
114+
while (itr.hasNext()) {
115+
final StackWalker.StackFrame frame = itr.next();
116+
final int relativeDepth = i - lambdaDepth;
117+
final boolean skipped = isSkippableClass(frame.getDeclaringClass());
118+
119+
logger.info("{} => {} ({})", relativeDepth, frame, skipped ? "skippable" : "retained");
120+
121+
if (relativeDepth >= 0 && !skipped && returnedFrame == null) {
122+
logger.info("^-^ returned");
123+
returnedFrame = frame;
124+
}
125+
126+
i++;
127+
}
128+
129+
return Objects.requireNonNullElse(returnedFrame, TraceElement.nullFrame);
130+
});
131+
}
132+
95133
static boolean isSkippableClass(final Class<?> clazz) {
96134
// If it came from Java, we don't care about it.
97135
// Usually, this means it was a reflection frame.

src/main/resources/fireblanket.mixins.json

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -31,6 +31,7 @@
3131
"annoyances.MixinServerPlayNetworkHandler",
3232
"annoyances.MixinUtil",
3333
"annoyances.lightning.MixinServerChunkLoadingManager",
34+
"annoyances.stdio.MixinLoggedPrintStream",
3435
"be_sync.MixinBlockEntity",
3536
"be_sync.MixinChunkHolder",
3637
"block.AccessorUpdateCommandBlockMinecartC2SPacket",

0 commit comments

Comments
 (0)