diff --git a/cr-core/src/main/java/org/terasology/crashreporter/pages/CrashSummary.java b/cr-core/src/main/java/org/terasology/crashreporter/pages/CrashSummary.java index 2799a83..efbf76d 100644 --- a/cr-core/src/main/java/org/terasology/crashreporter/pages/CrashSummary.java +++ b/cr-core/src/main/java/org/terasology/crashreporter/pages/CrashSummary.java @@ -12,13 +12,21 @@ import java.util.regex.Pattern; /** - * Builds a pre-filled GitHub issue title/body from a crash: the exception itself (available - * directly, no parsing needed), plus the engine version and active module list, which only exist - * in the crashed process' own log output - the reporter runs in its own JVM (see #52, subprocess - * isolation) and has no other way to reach them. + * Builds a pre-filled GitHub issue title/body from a crash: the exception itself, plus every other + * exception found across the crashed process' own log tabs, and the engine version/active module + * list - the reporter runs in its own JVM (see #52, subprocess isolation) and has no other way to + * reach any of the log-only information. *

- * The regexes here mirror two fixed, narrow log lines the engine emits at startup - see - * {@code TerasologyEngine#logEnvironmentInfo} ({@code TerasologyVersion#toString}'s + * On macOS, that subprocess isolation means the in-process {@code Throwable} passed to + * {@link #extract} is a best-effort reconstruction from just its class name and message (see + * {@code CrashReporter#reconstructThrowable}) - its own stack trace points into the reporter's own + * relaunch machinery, not the real crash site. Whenever the crash was also logged in one of the log + * tabs (the normal case for an engine-level crash handler), the trace captured from that log text is + * the real one and is used instead; the reconstructed exception's own trace is only a fallback for + * when nothing better is available. + *

+ * The version/module regexes here mirror two fixed, narrow log lines the engine emits at startup - + * see {@code TerasologyEngine#logEnvironmentInfo} ({@code TerasologyVersion#toString}'s * {@code [buildNumber=..., ..., engineVersion=X, displayVersion=Y]} format) and * {@code RegisterMods} ({@code "Activating module: :"}, once per active module). * Log formatting is not a published API and can drift; a change there degrades this to a blank @@ -29,21 +37,33 @@ public final class CrashSummary { private static final int MAX_STACK_LINES = 15; private static final int MAX_MODULES_LISTED = 30; private static final int MAX_TITLE_MESSAGE_LENGTH = 80; + private static final int MAX_EXCEPTIONS_LISTED = 10; + private static final int CONTEXT_LINES_BEFORE = 5; + private static final String NO_TAB_LABEL = "this crash"; private static final Pattern ENGINE_VERSION_PATTERN = Pattern.compile("engineVersion=([^,\\]]*)"); private static final Pattern DISPLAY_VERSION_PATTERN = Pattern.compile("displayVersion=([^,\\]]*)"); private static final Pattern ACTIVE_MODULE_PATTERN = Pattern.compile("Activating module: (\\S+:\\S+)"); + private static final Pattern LOG_TAB_PATTERN = Pattern.compile("(?m)^=== (.*) ===$"); + // A log-formatted stack trace: a "some.FullyQualified.NameException[: message]" header line + // immediately followed by one or more "at ..."/"Caused by: ..." frame lines - the shape every + // JVM logging framework prints a Throwable in (Logback's %ex, java.util.logging, a raw + // printStackTrace()), regardless of which class emits it. + private static final Pattern STACK_TRACE_HEADER_PATTERN = Pattern.compile( + "(?m)^([\\w$]+(?:\\.[\\w$]+)+(?:Exception|Error))(:[^\\n]*)?\\n((?:[ \\t]*(?:at |Caused by:)[^\\n]*\\n?)+)"); private final Throwable exception; - private final String stackTraceExtract; + private final List exceptionBlocks; + private final int moreExceptionsCount; private final String engineVersion; private final String displayVersion; private final List activeModules; - private CrashSummary(Throwable exception, String stackTraceExtract, String engineVersion, - String displayVersion, List activeModules) { + private CrashSummary(Throwable exception, List exceptionBlocks, int moreExceptionsCount, + String engineVersion, String displayVersion, List activeModules) { this.exception = exception; - this.stackTraceExtract = stackTraceExtract; + this.exceptionBlocks = exceptionBlocks; + this.moreExceptionsCount = moreExceptionsCount; this.engineVersion = engineVersion; this.displayVersion = displayVersion; this.activeModules = activeModules; @@ -51,15 +71,70 @@ private CrashSummary(Throwable exception, String stackTraceExtract, String engin public static CrashSummary extract(Throwable exception, String combinedLogText) { String text = combinedLogText != null ? combinedLogText : ""; - return new CrashSummary(exception, extractStackTrace(exception), + + List blocks = buildExceptionBlocks(exception, text); + int moreCount = 0; + if (blocks.size() > MAX_EXCEPTIONS_LISTED) { + moreCount = blocks.size() - MAX_EXCEPTIONS_LISTED; + blocks = new ArrayList<>(blocks.subList(0, MAX_EXCEPTIONS_LISTED)); + } + + return new CrashSummary(exception, blocks, moreCount, firstGroup(ENGINE_VERSION_PATTERN, text), firstGroup(DISPLAY_VERSION_PATTERN, text), extractActiveModules(text)); } - private static String extractStackTrace(Throwable exception) { - StringWriter sink = new StringWriter(); - exception.printStackTrace(new PrintWriter(sink)); - String[] lines = sink.toString().split("\r?\n"); + /** + * Builds one Markdown block per distinct exception found - the one that triggered this report + * first, then every other exception found across the log tabs - so a crash whose real cause is + * an earlier exception logged in a different tab (e.g. during init) isn't left out of the + * pre-filled issue just because it wasn't the in-process {@code exception} the reporter happened + * to be invoked with. + */ + private static List buildExceptionBlocks(Throwable exception, String combinedLogText) { + String primaryHeader = exception.toString().trim(); + List found = findAllExceptions(combinedLogText); + + ExceptionEntry primary = null; + for (ExceptionEntry entry : found) { + if (entry.header.equals(primaryHeader)) { + primary = entry; + break; + } + } + // Not logged anywhere - fall back to the exception object's own trace. On macOS that trace + // is a best-effort reconstruction (see the class javadoc) rather than the real crash site, + // but it's all that's available. There's no log text to pull leading context from either. + if (primary == null) { + primary = new ExceptionEntry(null, primaryHeader, framesFromThrowable(exception), ""); + } + + List blocks = new ArrayList<>(); + blocks.add(formatBlock(primary)); + for (ExceptionEntry entry : found) { + if (entry.header.equals(primaryHeader)) { + continue; + } + String block = formatBlock(entry); + if (!blocks.contains(block)) { + blocks.add(block); + } + } + return blocks; + } + + private static String formatBlock(ExceptionEntry entry) { + String label = entry.tabName != null ? entry.tabName : NO_TAB_LABEL; + String combined = entry.frames.isEmpty() ? entry.header : entry.header + "\n" + entry.frames; + String trace = truncateTrace(combined); + // Context isn't part of the trace itself, so it's not subject to truncateTrace()'s + // MAX_STACK_LINES cap - a few lines of what led up to the crash shouldn't cost trace detail. + String content = entry.context.isEmpty() ? trace : entry.context + "\n" + trace; + return "**" + label + "**\n\n```\n" + content + "\n```"; + } + + private static String truncateTrace(String combined) { + String[] lines = combined.split("\r?\n"); StringBuilder builder = new StringBuilder(); int limit = Math.min(lines.length, MAX_STACK_LINES); for (int i = 0; i < limit; i++) { @@ -71,6 +146,110 @@ private static String extractStackTrace(Throwable exception) { return builder.toString().trim(); } + private static String framesFromThrowable(Throwable exception) { + StringWriter sink = new StringWriter(); + exception.printStackTrace(new PrintWriter(sink)); + String full = sink.toString(); + // printStackTrace()'s first line is exception.toString() - already the header - so only the + // "at ..."/"Caused by: ..." frames after it are needed here. + int newlineIndex = full.indexOf('\n'); + return newlineIndex >= 0 ? stripTrailingWhitespace(full.substring(newlineIndex + 1)) : ""; + } + + /** + * Like {@link String#trim()} but only at the end - frame lines are indented with a leading tab + * ({@code "\tat ..."}), which a plain {@code trim()} would strip from the first line along with + * the trailing newline it's actually meant to remove. + */ + private static String stripTrailingWhitespace(String s) { + int end = s.length(); + while (end > 0 && Character.isWhitespace(s.charAt(end - 1))) { + end--; + } + return s.substring(0, end); + } + + private static final class ExceptionEntry { + private final String tabName; + private final String header; + private final String frames; + private final String context; + + private ExceptionEntry(String tabName, String header, String frames, String context) { + this.tabName = tabName; + this.header = header; + this.frames = frames; + this.context = context; + } + } + + private static List findAllExceptions(String combinedLogText) { + List found = new ArrayList<>(); + + Matcher tabMatcher = LOG_TAB_PATTERN.matcher(combinedLogText); + int tabStart = -1; + String tabName = null; + while (true) { + boolean hasNext = tabMatcher.find(); + int nextStart = hasNext ? tabMatcher.start() : combinedLogText.length(); + if (tabName != null) { + collectExceptionHeaders(combinedLogText.substring(tabStart, nextStart), tabName, found); + } + if (!hasNext) { + break; + } + tabName = tabMatcher.group(1); + // tabMatcher.end() lands right after "===", before that line's own terminator - skip it + // too, so each tab's text starts at its real first content line instead of with a blank + // artifact line (which precedingLines() would otherwise count as logged context). + tabStart = tabMatcher.end(); + if (tabStart < combinedLogText.length() && combinedLogText.charAt(tabStart) == '\r') { + tabStart++; + } + if (tabStart < combinedLogText.length() && combinedLogText.charAt(tabStart) == '\n') { + tabStart++; + } + } + // No "=== tab ===" headers at all - a single combined-log caller (e.g. a direct test) rather + // than ErrorMessagePanel#getLog(); scan the whole text with no tab attribution. + if (tabName == null) { + collectExceptionHeaders(combinedLogText, null, found); + } + return found; + } + + private static void collectExceptionHeaders(String tabText, String tabName, List found) { + Matcher matcher = STACK_TRACE_HEADER_PATTERN.matcher(tabText); + while (matcher.find()) { + String header = (matcher.group(1) + (matcher.group(2) != null ? matcher.group(2) : "")).trim(); + String frames = stripTrailingWhitespace(matcher.group(3)); + String context = precedingLines(tabText, matcher.start(), CONTEXT_LINES_BEFORE); + found.add(new ExceptionEntry(tabName, header, frames, context)); + } + } + + /** + * @return up to {@code maxLines} lines of whatever was logged right before {@code beforeIndex} in + * {@code text} - what led up to a crash is often as useful for diagnosing it as the trace + * itself, and it's only available here (the reporter's own {@link #exception} carries no + * log context of its own). + */ + private static String precedingLines(String text, int beforeIndex, int maxLines) { + String[] lines = text.substring(0, beforeIndex).split("\r?\n", -1); + int end = lines.length; + // A trailing empty element only ever means the substring ended in a newline - i.e. the line + // right before the match, not a real blank log line - so it isn't context to show. + if (end > 0 && lines[end - 1].isEmpty()) { + end--; + } + int start = Math.max(0, end - maxLines); + StringBuilder builder = new StringBuilder(); + for (int i = start; i < end; i++) { + builder.append(lines[i]).append('\n'); + } + return stripTrailingWhitespace(builder.toString()); + } + private static String firstGroup(Pattern pattern, String text) { Matcher matcher = pattern.matcher(text); return matcher.find() ? matcher.group(1).trim() : ""; @@ -106,12 +285,19 @@ public String buildTitle() { /** * @param pastebinLink the uploaded log link, or {@code null} if the user skipped upload - * @return a Markdown issue body with the exception extract, environment info, and a link to - * the full logs + * @return a Markdown issue body: every exception found, one labeled code block each (naming the + * log tab it was found in), then environment info, then a link to the full logs */ public String buildBody(URL pastebinLink) { StringBuilder body = new StringBuilder(); - body.append("### Exception\n\n```\n").append(stackTraceExtract).append("\n```\n\n"); + + body.append("### Exceptions\n\n"); + for (String block : exceptionBlocks) { + body.append(block).append("\n\n"); + } + if (moreExceptionsCount > 0) { + body.append("... ").append(moreExceptionsCount).append(" more - see the full log\n\n"); + } body.append("### Environment\n\n"); body.append("- Terasology version: ").append(engineVersion.isEmpty() ? "unknown" : engineVersion); diff --git a/cr-core/src/test/java/org/terasology/crashreporter/pages/CrashSummaryTest.java b/cr-core/src/test/java/org/terasology/crashreporter/pages/CrashSummaryTest.java index 6065361..730f09f 100644 --- a/cr-core/src/test/java/org/terasology/crashreporter/pages/CrashSummaryTest.java +++ b/cr-core/src/test/java/org/terasology/crashreporter/pages/CrashSummaryTest.java @@ -91,4 +91,89 @@ void bodyNotesWhenUploadWasSkipped() { assertFalse(body.contains("null"), "A skipped upload must not leak the literal string \"null\" into the body: " + body); assertTrue(body.contains("not uploaded"), "Expected a note that upload was skipped, got: " + body); } + + // Regression: ErrorMessagePanel#getLog() combines every log tab, not just the one that + // triggered the report, but only the in-process exception ever made it into the pre-filled + // issue - an exception logged in a different tab (e.g. an earlier init-time failure) was + // silently left out even though it was right there in the combined text. All exceptions - the + // primary one and every other one found - are listed together, one labeled code block each + // (full trace, not just a one-line header - a real fix needs the actual trace), before + // "### Environment", not split across two separate sections. + @Test + void bodyListsExceptionsFoundInOtherLogTabsWithTheirFullTraceNamingTheTab() { + String combinedLog = "=== Terasology-init.log ===\n" + LOG_TEXT + + "\n=== Terasology-game.log ===\n" + + "10:10:05.123 [main] ERROR o.t.e.core.TerasologyEngine - Uncaught exception in main loop\n" + + "java.lang.NullPointerException: world was null\n" + + "\tat org.terasology.engine.core.TerasologyEngine.run(TerasologyEngine.java:200)\n"; + + CrashSummary summary = CrashSummary.extract(new RuntimeException("boom"), combinedLog); + String body = summary.buildBody(null); + + assertTrue(body.contains("### Exceptions"), "Expected a single unified exceptions section, got: " + body); + assertTrue(body.contains("**Terasology-game.log**\n\n```\n" + + "10:10:05.123 [main] ERROR o.t.e.core.TerasologyEngine - Uncaught exception in main loop\n" + + "java.lang.NullPointerException: world was null\n" + + "\tat org.terasology.engine.core.TerasologyEngine.run(TerasologyEngine.java:200)\n```"), + "Expected the other tab's exception as its own labeled block, with the line logged right before it and the full " + + "trace, got: " + body); + int exceptionsIndex = body.indexOf("### Exceptions"); + int environmentIndex = body.indexOf("### Environment"); + assertTrue(exceptionsIndex >= 0 && environmentIndex > exceptionsIndex, + "Expected \"### Exceptions\" before \"### Environment\", got: " + body); + } + + @Test + void bodyAttributesThePrimaryExceptionToItsOwnTabInsteadOfListingItTwice() { + RuntimeException primary = new RuntimeException("boom"); + // The crash is very often also logged (by the crashed process itself) in one of its own + // log tabs - that's the same exception, not another one, and must not be listed twice. It's + // also the *real* trace (see the class javadoc on macOS reconstruction), so it must be used + // in preference to the exception object's own (possibly fake) trace. + String combinedLog = "=== Terasology-game.log ===\n" + + primary + "\n" + + "\tat org.terasology.engine.core.TerasologyEngine.run(TerasologyEngine.java:200)\n"; + + CrashSummary summary = CrashSummary.extract(primary, combinedLog); + String body = summary.buildBody(null); + + assertTrue(body.contains("**Terasology-game.log**\n\n```\njava.lang.RuntimeException: boom\n" + + "\tat org.terasology.engine.core.TerasologyEngine.run(TerasologyEngine.java:200)\n```"), + "Expected the primary exception's block attributed to the tab it was found in, using that tab's real trace, got: " + + body); + int blocks = body.split("\\*\\*Terasology-game\\.log\\*\\*", -1).length - 1; + assertEquals(1, blocks, "Expected exactly one block - the primary exception must not also be listed as an \"other\" one: " + + body); + } + + @Test + void bodyIncludesOnlyTheLastFiveLinesLoggedBeforeTheException() { + StringBuilder combinedLog = new StringBuilder("=== Terasology-game.log ===\n"); + for (int i = 1; i <= 8; i++) { + combinedLog.append("log line ").append(i).append('\n'); + } + combinedLog.append("java.lang.NullPointerException: world was null\n") + .append("\tat org.terasology.engine.core.TerasologyEngine.run(TerasologyEngine.java:200)\n"); + + CrashSummary summary = CrashSummary.extract(new RuntimeException("boom"), combinedLog.toString()); + String body = summary.buildBody(null); + + assertFalse(body.contains("log line 1\n") || body.contains("log line 2\n") || body.contains("log line 3\n"), + "Expected only the last 5 lines of context, not all 8, got: " + body); + assertTrue(body.contains("log line 4\nlog line 5\nlog line 6\nlog line 7\nlog line 8\n" + + "java.lang.NullPointerException: world was null"), + "Expected the last 5 lines directly before the exception's header, got: " + body); + } + + @Test + void bodyFallsBackToTheExceptionsOwnTraceWhenNotFoundInAnyTab() { + RuntimeException primary = new RuntimeException("boom"); + CrashSummary summary = CrashSummary.extract(primary, LOG_TEXT); + String body = summary.buildBody(null); + + assertTrue(body.contains("**this crash**\n\n```\njava.lang.RuntimeException: boom\n"), + "Expected a fallback label and the exception's own trace when it isn't found in any log tab, got: " + body); + assertTrue(body.contains(CrashSummaryTest.class.getName()), + "Expected this test's own stack frame in the fallback trace, got: " + body); + } }