Skip to content

feat: GC log streaming analysis with --follow mode (#116) #121

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
rlaope wants to merge 1 commit into from
Closed

feat: GC log streaming analysis with --follow mode (#116) #121

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
99 changes: 99 additions & 0 deletions argus-cli/src/main/java/io/argus/cli/command/GcLogCommand.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -54,11 +54,18 @@ public void execute(String[] args, CliConfig config, ProviderRegistry registry,
boolean json = "json".equals(config.format());
boolean useColor = config.color();
boolean flagsOnly = false;
boolean follow = false;
String exportHtml = null;
for (int i = 1; i < args.length; i++) {
if (args[i].equals("--format=json")) json = true;
if (args[i].equals("--suggest-flags")) flagsOnly = true;
if (args[i].startsWith("--export=")) exportHtml = args[i].substring(9);
if (args[i].equals("--follow") || args[i].equals("-f")) follow = true;
}

if (follow) {
runFollowMode(logFile, useColor);
return;
}

List<GcEvent> events;
Expand Down Expand Up @@ -275,6 +282,98 @@ private void printRich(GcLogAnalysis a, List<GcEvent> events, Path file, boolean
a.pauseEvents() + " pauses, " + String.format("%.1f%%", a.throughputPercent()) + " throughput", WIDTH));
}

private void runFollowMode(Path logFile, boolean c) {
GcLogFollower follower = new GcLogFollower(logFile);
RollingGcAnalysis rolling = new RollingGcAnalysis();

try {
List<GcEvent> initial = follower.readAll();
rolling.addEvents(initial);
} catch (IOException e) {
System.err.println("Failed to read GC log: " + e.getMessage());
return;
}

System.out.println("Following " + logFile.getFileName() + "... (Ctrl+C to stop)");

// Set terminal to non-canonical mode if possible
try {
new ProcessBuilder("stty", "-icanon", "min", "0", "-echo")
.inheritIO().start().waitFor();
} catch (Exception ignored) {}

try {
long lastUpdate = System.currentTimeMillis();
while (true) {
// Poll for new events
List<GcEvent> newEvents = follower.pollNewEvents();
if (!newEvents.isEmpty()) {
rolling.addEvents(newEvents);
lastUpdate = System.currentTimeMillis();
}

// Refresh display every 2 seconds
long elapsed = System.currentTimeMillis() - lastUpdate;
RollingGcAnalysis.Snapshot snap = rolling.snapshot();

// Clear screen and render
System.out.print("\033[H\033[2J");
System.out.flush();

long uptime = (System.currentTimeMillis() - lastUpdate) / 1000;
String uptimeStr = snap.totalEventsEver() > 0
? String.format("last update %ds ago", elapsed / 1000) : "waiting for events...";

System.out.println(RichRenderer.boxHeader(c, "GC Log Monitor", WIDTH,
logFile.getFileName().toString(), "following", uptimeStr));
System.out.println(RichRenderer.emptyLine(WIDTH));

kv(c, "Events", snap.totalEventsEver() + " total, " + rolling.windowSize() + " in window");
kv(c, "Throughput", String.format("%.1f%%", snap.throughputPercent()));
System.out.println(RichRenderer.emptyLine(WIDTH));

System.out.println(RichRenderer.boxLine(String.format(
" p50: %dms p95: %dms p99: %dms max: %dms avg: %dms",
snap.p50PauseMs(), snap.p95PauseMs(), snap.p99PauseMs(),
snap.maxPauseMs(), snap.avgPauseMs()), WIDTH));

if (snap.fullGcCount() > 0) {
System.out.println(RichRenderer.emptyLine(WIDTH));
kv(c, "Full GC", AnsiStyle.style(c, AnsiStyle.RED) + snap.fullGcCount()
+ AnsiStyle.style(c, AnsiStyle.RESET)
+ (snap.secsSinceLastFullGc() >= 0
? String.format(" (last %.0fs ago)", snap.secsSinceLastFullGc()) : ""));
}

if (snap.peakHeapKB() > 0) {
kv(c, "Peak Heap", RichRenderer.formatKB(snap.peakHeapKB()));
}

System.out.println(RichRenderer.emptyLine(WIDTH));
System.out.println(RichRenderer.boxFooter(c,
"[Ctrl+C] quit", WIDTH));

// Check for key input (non-blocking)
if (System.in.available() > 0) {
int key = System.in.read();
if (key == 'q' || key == 'Q') break;
}

Thread.sleep(2000);
}
} catch (InterruptedException ignored) {
// Normal exit on Ctrl+C
} catch (IOException e) {
System.err.println("Follow error: " + e.getMessage());
} finally {
// Restore terminal
try {
new ProcessBuilder("stty", "icanon", "echo")
.inheritIO().start().waitFor();
} catch (Exception ignored) {}
}
}

private void section(boolean c, String title) {
System.out.println(RichRenderer.emptyLine(WIDTH));
System.out.println(RichRenderer.boxSeparator(WIDTH));
Expand Down
203 changes: 203 additions & 0 deletions argus-cli/src/main/java/io/argus/cli/gclog/GcLogFollower.java
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,203 @@
package io.argus.cli.gclog;

import java.io.IOException;
import java.io.RandomAccessFile;
import java.nio.charset.StandardCharsets;
import java.nio.file.Path;
import java.util.ArrayList;
import java.util.Collections;
import java.util.List;

/**
* Tails a growing GC log file, polling for new lines and parsing them.
* Thread-safe for the poll loop pattern (single consumer).
*/
public final class GcLogFollower {

private final Path logFile;
private final int maxEvents;

private long filePosition = 0;
private boolean formatDetected = false;
private boolean unified = false;
private final StringBuilder lineBuffer = new StringBuilder();

public GcLogFollower(Path logFile, int maxEvents) {
this.logFile = logFile;
this.maxEvents = maxEvents;
}

public GcLogFollower(Path logFile) {
this(logFile, 1000);
}

/**
* Reads the entire file from the beginning, returning all parsed events.
* Resets the follower position to end of file.
*/
public synchronized List<GcEvent> readAll() throws IOException {
filePosition = 0;
lineBuffer.setLength(0);
formatDetected = false;
unified = false;
return pollNewEvents();
}

/**
* Reads new bytes since last position, parses any complete lines,
* and returns newly parsed GcEvents. Returns empty list if no new data.
*/
public synchronized List<GcEvent> pollNewEvents() throws IOException {
try (RandomAccessFile raf = new RandomAccessFile(logFile.toFile(), "r")) {
long fileLength = raf.length();
if (fileLength <= filePosition) {
return Collections.emptyList();
}

raf.seek(filePosition);
long bytesToRead = fileLength - filePosition;
byte[] buf = new byte[(int) Math.min(bytesToRead, 4 * 1024 * 1024)]; // 4MB cap
int bytesRead = raf.read(buf);
if (bytesRead <= 0) {
return Collections.emptyList();
}

filePosition += bytesRead;

String chunk = new String(buf, 0, bytesRead, StandardCharsets.UTF_8);
lineBuffer.append(chunk);

List<GcEvent> events = new ArrayList<>();
int start = 0;
int len = lineBuffer.length();
for (int i = 0; i < len; i++) {
if (lineBuffer.charAt(i) == '\n') {
String line = lineBuffer.substring(start, i).stripTrailing();
start = i + 1;
if (line.isEmpty()) continue;

// Auto-detect format from first non-empty line
if (!formatDetected) {
unified = line.contains("[gc") || line.contains("[info]")
|| (line.startsWith("[") && (line.contains("s]") || line.contains("T")));
formatDetected = true;
}

GcEvent event = parseLine(line, unified);
if (event != null) events.add(event);
}
}
// Keep any incomplete line in buffer
lineBuffer.delete(0, start);

return events;
}
}

/**
* Parses a single GC log line using the detected format.
* Package-private to allow reuse from tests.
*/
static GcEvent parseLine(String line, boolean unified) {
return unified ? parseUnifiedLine(line) : parseLegacyLine(line);
}

// ── Unified (JDK 9+) ────────────────────────────────────────────────────

private static GcEvent parseUnifiedLine(String line) {
double timestamp = extractTimestamp(line);
if (timestamp < 0) return null;

java.util.regex.Matcher m = GcLogPatterns.UNIFIED_PAUSE.matcher(line);
if (m.find()) {
String type = m.group(1).trim();
long heapBefore = toKB(Long.parseLong(m.group(2)), m.group(3));
long heapAfter = toKB(Long.parseLong(m.group(4)), m.group(5));
long heapTotal = toKB(Long.parseLong(m.group(6)), m.group(7));
double pauseMs = Double.parseDouble(m.group(8));

String cause = "";
java.util.regex.Matcher cm = GcLogPatterns.UNIFIED_CAUSE.matcher(line);
if (cm.find()) cause = cm.group(1).trim();

return new GcEvent(timestamp, type, cause, pauseMs, heapBefore, heapAfter, heapTotal);
}

java.util.regex.Matcher zm = GcLogPatterns.ZGC_PAUSE.matcher(line);
if (zm.find() && line.contains("ZGC")) {
return new GcEvent(timestamp, "ZGC Pause " + zm.group(1), "ZGC",
Double.parseDouble(zm.group(2)), 0, 0, 0);
}

java.util.regex.Matcher zcm = GcLogPatterns.ZGC_CYCLE.matcher(line);
if (zcm.find()) {
long heapBefore = toKB(Long.parseLong(zcm.group(2)), zcm.group(3));
long heapAfter = toKB(Long.parseLong(zcm.group(4)), zcm.group(5));
return new GcEvent(timestamp, "ZGC Cycle", zcm.group(1), 0, heapBefore, heapAfter, 0);
}

java.util.regex.Matcher sm = GcLogPatterns.SHENANDOAH_PAUSE.matcher(line);
if (sm.find()) {
return new GcEvent(timestamp, "Shenandoah " + sm.group(1), "Shenandoah",
Double.parseDouble(sm.group(2)), 0, 0, 0);
}

java.util.regex.Matcher cm2 = GcLogPatterns.UNIFIED_CONCURRENT.matcher(line);
if (cm2.find()) {
return new GcEvent(timestamp, "Concurrent " + cm2.group(1), "Concurrent",
Double.parseDouble(cm2.group(2)), 0, 0, 0);
}

return null;
}

private static GcEvent parseLegacyLine(String line) {
java.util.regex.Matcher m = GcLogPatterns.LEGACY_GC.matcher(line);
if (!m.find()) return null;

double timestamp = Double.parseDouble(m.group(1));
boolean full = m.group(2) != null;
String cause = m.group(3).trim();
long heapBefore = Long.parseLong(m.group(4));
long heapAfter = Long.parseLong(m.group(5));
long heapTotal = Long.parseLong(m.group(6));
double pauseMs = Double.parseDouble(m.group(7)) * 1000;

return new GcEvent(timestamp, full ? "Full" : "Young", cause,
pauseMs, heapBefore, heapAfter, heapTotal);
}

private static double extractTimestamp(String line) {
java.util.regex.Matcher m = GcLogPatterns.TIMESTAMP_UPTIME.matcher(line);
if (m.find()) return Double.parseDouble(m.group(1));

java.util.regex.Matcher im = GcLogPatterns.TIMESTAMP_ISO.matcher(line);
if (im.find()) {
try {
String iso = im.group(1);
int tIdx = iso.indexOf('T');
if (tIdx > 0) {
String timePart = iso.substring(tIdx + 1);
String[] parts = timePart.split("[:+]");
if (parts.length >= 3) {
return Double.parseDouble(parts[0]) * 3600
+ Double.parseDouble(parts[1]) * 60
+ Double.parseDouble(parts[2]);
}
}
} catch (Exception ignored) {}
}
return -1;
}

private static long toKB(long value, String unit) {
return switch (unit) {
case "K" -> value;
case "M" -> value * 1024;
case "G" -> value * 1024 * 1024;
default -> value;
};
}

public int maxEvents() { return maxEvents; }
}
34 changes: 34 additions & 0 deletions argus-cli/src/main/java/io/argus/cli/gclog/GcLogPatterns.java
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -0,0 +1,34 @@
package io.argus.cli.gclog;

import java.util.regex.Pattern;

/**
* Shared GC log regex patterns used by GcLogParser and GcLogFollower.
*/
final class GcLogPatterns {

static final Pattern TIMESTAMP_UPTIME = Pattern.compile("\\[(\\d+\\.\\d+)s\\]");
static final Pattern TIMESTAMP_ISO = Pattern.compile("\\[(\\d{4}-\\d{2}-\\d{2}T[\\d:.+]+)\\]");

static final Pattern UNIFIED_PAUSE = Pattern.compile(
"GC\\(\\d+\\)\\s+Pause\\s+(\\S+(?:\\s+\\([^)]*\\))*)\\s+(\\d+)([MKG])->(\\d+)([MKG])\\((\\d+)([MKG])\\)\\s+(\\d+\\.?\\d*)ms");

static final Pattern UNIFIED_CAUSE = Pattern.compile("\\(([^)]+)\\)\\s+\\d+[MKG]->");

static final Pattern ZGC_PAUSE = Pattern.compile(
"GC\\(\\d+\\)\\s+Pause\\s+(\\w+)\\s+(\\d+\\.?\\d*)ms");

static final Pattern ZGC_CYCLE = Pattern.compile(
"GC\\(\\d+\\)\\s+Garbage Collection\\s+\\(([^)]+)\\)\\s+(\\d+)([MKG])\\([^)]*\\)->(\\d+)([MKG])");

static final Pattern SHENANDOAH_PAUSE = Pattern.compile(
"GC\\(\\d+\\)\\s+Pause\\s+(Init Mark|Final Mark|Init Update|Final Update|Full).*?(\\d+\\.?\\d*)ms");

static final Pattern LEGACY_GC = Pattern.compile(
"(\\d+\\.\\d+):\\s+\\[(Full )?GC\\s*\\(([^)]+)\\).*?(\\d+)K->(\\d+)K\\((\\d+)K\\),?\\s+(\\d+\\.\\d+)\\s+secs");

static final Pattern UNIFIED_CONCURRENT = Pattern.compile(
"GC\\(\\d+\\)\\s+Concurrent\\s+(\\S+)\\s+(\\d+\\.?\\d*)ms");

private GcLogPatterns() {}
}
Loading
Loading