From 0000000000000000000000000000000000000000 Mon Sep 17 00:00:00 2001 From: underscore11code Date: Fri, 23 Jul 2021 23:01:42 -0700 Subject: [PATCH] Add System.out/err catcher diff --git a/src/main/java/io/papermc/paper/logging/SysoutCatcher.java b/src/main/java/io/papermc/paper/logging/SysoutCatcher.java new file mode 100644 index 0000000000000000000000000000000000000000..64b8bf47162811334a934136d6aaa6c71a0f47ee --- /dev/null +++ b/src/main/java/io/papermc/paper/logging/SysoutCatcher.java @@ -0,0 +1,229 @@ +package io.papermc.paper.logging; + +import java.io.FilterOutputStream; +import java.io.OutputStream; +import java.io.PrintStream; +import java.nio.charset.StandardCharsets; +import java.util.Formatter; +import java.util.Locale; +import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.ConcurrentMap; +import java.util.concurrent.TimeUnit; +import java.util.logging.Level; +import org.bukkit.Bukkit; +import org.bukkit.plugin.java.JavaPlugin; +import org.jetbrains.annotations.NotNull; +import org.jetbrains.annotations.Nullable; + +public final class SysoutCatcher { + private static final boolean SUPPRESS_NAGS = Boolean.getBoolean("io.papermc.paper.suppress.sout.nags"); + // Nanoseconds between nag at most; if interval is caught first, this is reset. + // <= 0 for disabling. + private static final long NAG_TIMEOUT = TimeUnit.MILLISECONDS.toNanos( + Long.getLong("io.papermc.paper.sout.nags.timeout", TimeUnit.MINUTES.toMillis(5L))); + // Count since last nag; if timeout is first, this is reset. + // <= 0 for disabling. + private static final long NAG_INTERVAL = Long.getLong("io.papermc.paper.sout.nags.interval", 200L); + + // We don't particularly care about how correct this is at any given moment; let's do it on a best attempt basis. + // The records are also pretty small, so let's just go for a size of 64 to start... + // + // Content: Plugin name => nag object + // Why plugin name?: This doesn't store a reference to the plugin; keeps the reload ability. + // Why not clean on reload?: Effort. + private final ConcurrentMap nagRecords = new ConcurrentHashMap<>(64); + + public SysoutCatcher() { + System.setOut(new WrappedOutStream(System.out, Level.INFO, "[STDOUT] ")); + System.setErr(new WrappedOutStream(System.err, Level.SEVERE, "[STDERR] ")); + } + + private final class WrappedOutStream extends PrintStream { + private static final StackWalker STACK_WALKER = StackWalker.getInstance(StackWalker.Option.RETAIN_CLASS_REFERENCE); + private final Level level; + private final String prefix; + + public WrappedOutStream(@NotNull final OutputStream out, final Level level, final String prefix) { + super(out); + this.level = level; + this.prefix = prefix; + } + + @Override + public void println(@Nullable final String line) { + final Class clazz = STACK_WALKER.walk(stream -> { + return stream.filter(it -> { + final Class declr = it.getDeclaringClass(); + return !declr.equals(WrappedOutStream.class) && !declr.equals(PrintStream.class) + && !declr.equals(FilterOutputStream.class) && !declr.getName().equals("java.lang.Throwable$WrappedPrintStream") + && !declr.equals(Throwable.class); + }).findFirst() + .map(StackWalker.StackFrame::getDeclaringClass) + .orElseThrow(); + }); + try { + final JavaPlugin plugin = JavaPlugin.getProvidingPlugin(clazz); + + // Instead of just printing the message, send it to the plugin's logger + plugin.getLogger().log(this.level, this.prefix + line); + + if (SysoutCatcher.SUPPRESS_NAGS) { + return; + } + if (SysoutCatcher.NAG_INTERVAL > 0 || SysoutCatcher.NAG_TIMEOUT > 0) { + final PluginNag nagRecord = SysoutCatcher.this.nagRecords.computeIfAbsent(plugin.getName(), k -> new PluginNag()); + final boolean hasTimePassed = SysoutCatcher.NAG_TIMEOUT > 0 + && (nagRecord.lastNagTimestamp == Long.MIN_VALUE + || nagRecord.lastNagTimestamp + SysoutCatcher.NAG_TIMEOUT <= System.nanoTime()); + final boolean hasMessagesPassed = SysoutCatcher.NAG_INTERVAL > 0 + && (nagRecord.messagesSinceNag == Long.MIN_VALUE + || ++nagRecord.messagesSinceNag >= SysoutCatcher.NAG_INTERVAL); + if (!hasMessagesPassed && !hasTimePassed) { + return; + } + nagRecord.lastNagTimestamp = System.nanoTime(); + nagRecord.messagesSinceNag = 0; + } + Bukkit.getLogger().warning( + String.format("Nag author(s): '%s' of '%s' about their usage of System.out/err.print. " + + "Please use your plugin's logger instead (JavaPlugin#getLogger).", + plugin.getPluginMeta().getAuthors(), + plugin.getPluginMeta().getDisplayName()) + ); + } catch (final IllegalArgumentException | IllegalStateException e) { + // If anything happens, the calling class doesn't exist, there is no JavaPlugin that "owns" the calling class, etc + // Just print out normally, with some added information + Bukkit.getLogger().log(this.level, String.format("%s[%s] %s", this.prefix, clazz.getName(), line)); + } + } + + @Override + public void write(final int b) { + this.println(b); + } + + @Override + public void write(@NotNull final byte[] buf, final int off, final int len) { + final byte[] bytes = new byte[len]; + System.arraycopy(buf, off, bytes, 0, len); + this.write(bytes); + } + + @Override + public void write(final byte[] buf) { + this.println(new String(buf, StandardCharsets.UTF_8)); + } + + @Override + public void writeBytes(final byte[] buf) { + this.write(buf); + } + + @Override + public void print(final boolean b) { + this.println(b); + } + + @Override + public void print(final char c) { + this.println(c); + } + + @Override + public void print(final int i) { + this.println(i); + } + + @Override + public void print(final long l) { + this.println(l); + } + + @Override + public void print(final float f) { + this.println(f); + } + + @Override + public void print(final double d) { + this.println(d); + } + + @Override + public void print(@NotNull final char[] s) { + this.println(s); + } + + @Override + public void print(@Nullable final String s) { + this.println(s); + } + + @Override + public void print(@Nullable final Object obj) { + this.println(obj); + } + + @Override + public PrintStream format(@NotNull final String format, final Object... args) { + this.println(format.formatted(args)); + return this; + } + + @Override + public PrintStream format(final Locale l, @NotNull final String format, final Object... args) { + this.println(new Formatter(l).format(format, args).toString()); + return this; + } + + @Override + public void println() { + this.println(""); + } + + @Override + public void println(final boolean x) { + this.println(String.valueOf(x)); + } + + @Override + public void println(final char x) { + this.println(String.valueOf(x)); + } + + @Override + public void println(final int x) { + this.println(String.valueOf(x)); + } + + @Override + public void println(final long x) { + this.println(String.valueOf(x)); + } + + @Override + public void println(final float x) { + this.println(String.valueOf(x)); + } + + @Override + public void println(final double x) { + this.println(String.valueOf(x)); + } + + @Override + public void println(@NotNull final char[] x) { + this.println(new String(x)); + } + + @Override + public void println(@Nullable final Object x) { + this.println(String.valueOf(String.valueOf(x))); + } + } + + private static class PluginNag { + private long lastNagTimestamp = Long.MIN_VALUE; + private long messagesSinceNag = Long.MIN_VALUE; + } +} diff --git a/src/main/java/org/bukkit/craftbukkit/CraftServer.java b/src/main/java/org/bukkit/craftbukkit/CraftServer.java index 6a860029247e1575329975060fb9c2d7e8c9f033..675788beea6c9559d5764501e76d671abcba3f17 100644 --- a/src/main/java/org/bukkit/craftbukkit/CraftServer.java +++ b/src/main/java/org/bukkit/craftbukkit/CraftServer.java @@ -305,6 +305,7 @@ public final class CraftServer implements Server { public int reloadCount; private final io.papermc.paper.datapack.PaperDatapackManager datapackManager; // Paper public static Exception excessiveVelEx; // Paper - Velocity warnings + private final io.papermc.paper.logging.SysoutCatcher sysoutCatcher = new io.papermc.paper.logging.SysoutCatcher(); // Paper static { ConfigurationSerialization.registerClass(CraftOfflinePlayer.class);