Exception when using RotatingGCLogFile

[srilakshmikanthanp]

I would like to extend my sincere thanks for developing and maintaining the GC Toolkit. I am encountering a DateTimeParseException when trying to use the RotatingGCLogFile class to analyze GC log files.

package com.example;

import java.io.IOException;
import java.nio.file.Path;

import com.microsoft.gctoolkit.GCToolKit;
import com.microsoft.gctoolkit.io.RotatingGCLogFile;

public class Main {
    public static void main(String[] args) throws IOException {
        var logFile = new RotatingGCLogFile(Path.of("./logs"));
        var gcToolKit = new GCToolKit();
        var jvm = gcToolKit.analyze(logFile);
    }
}

Above throws exception,

Main 
Exception in thread "main" java.time.format.DateTimeParseException: Text '[2025-05-13T14:47:20.320+0530]' could not be parsed at index 0
        at java.base/java.time.format.DateTimeFormatter.parseResolved0(DateTimeFormatter.java:2052)
        at java.base/java.time.format.DateTimeFormatter.parse(DateTimeFormatter.java:1880)
        at com.microsoft.gctoolkit.time.DateTimeStamp.dateFromString(DateTimeStamp.java:52)
        at com.microsoft.gctoolkit.time.DateTimeStamp.fromGCLogLine(DateTimeStamp.java:92)
        at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
        at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625)
        at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
        at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
        at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921)
        at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
        at java.base/java.util.stream.ReferencePipeline.reduce(ReferencePipeline.java:662)
        at java.base/java.util.stream.ReferencePipeline.max(ReferencePipeline.java:698)
        at com.microsoft.gctoolkit.io.GCLogFileSegment.ageOfJVMAtLogEnd(GCLogFileSegment.java:146)
        at com.microsoft.gctoolkit.io.GCLogFileSegment.getEndTime(GCLogFileSegment.java:93)
        at com.microsoft.gctoolkit.io.RotatingLogFileMetadata.lambda$removeIneligibleSegments$6(RotatingLogFileMetadata.java:166)
        at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:178)
        at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1625)
        at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
        at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
        at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921)
        at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
        at java.base/java.util.stream.ReferencePipeline.collect(ReferencePipeline.java:682)
        at com.microsoft.gctoolkit.io.RotatingLogFileMetadata.removeIneligibleSegments(RotatingLogFileMetadata.java:167)
        at com.microsoft.gctoolkit.io.RotatingLogFileMetadata.orderSegments(RotatingLogFileMetadata.java:153)
        at com.microsoft.gctoolkit.io.RotatingLogFileMetadata.findSegments(RotatingLogFileMetadata.java:135)
        at com.microsoft.gctoolkit.io.RotatingLogFileMetadata.logFiles(RotatingLogFileMetadata.java:36)
        at com.microsoft.gctoolkit.io.RotatingGCLogFile.stream(RotatingGCLogFile.java:52)
        at com.microsoft.gctoolkit.io.GCLogFile.discoverFormat(GCLogFile.java:130)
        at com.microsoft.gctoolkit.io.GCLogFile.isUnified(GCLogFile.java:68)
        at com.microsoft.gctoolkit.io.GCLogFile.diarizer(GCLogFile.java:83)
        at com.microsoft.gctoolkit.io.GCLogFile.diary(GCLogFile.java:98)
        at com.microsoft.gctoolkit.GCToolKit.analyze(GCToolKit.java:308)
        at com.example.Main.main(Main.java:13)

Log file sample

[2025-05-13T14:47:17.266+0530][gc] Using G1
[2025-05-13T14:47:17.278+0530][gc,init] Version: 17.0.14+7-Ubuntu-124.04 (release)
[2025-05-13T14:47:17.278+0530][gc,init] CPUs: 16 total, 16 available
[2025-05-13T14:47:17.278+0530][gc,init] Memory: 15715M
[2025-05-13T14:47:17.278+0530][gc,init] Large Page Support: Disabled
[2025-05-13T14:47:17.278+0530][gc,init] NUMA Support: Disabled
[2025-05-13T14:47:17.278+0530][gc,init] Compressed Oops: Enabled (Zero based)
[2025-05-13T14:47:17.278+0530][gc,init] Heap Region Size: 4M
[2025-05-13T14:47:17.278+0530][gc,init] Heap Min Capacity: 7860M
[2025-05-13T14:47:17.278+0530][gc,init] Heap Initial Capacity: 7860M
[2025-05-13T14:47:17.278+0530][gc,init] Heap Max Capacity: 7860M
[2025-05-13T14:47:17.278+0530][gc,init] Pre-touch: Disabled
[2025-05-13T14:47:17.278+0530][gc,init] Parallel Workers: 13
[2025-05-13T14:47:17.278+0530][gc,init] Concurrent Workers: 3
[2025-05-13T14:47:17.278+0530][gc,init] Concurrent Refinement Workers: 13
[2025-05-13T14:47:17.278+0530][gc,init] Periodic GC: Disabled
[2025-05-13T14:47:17.278+0530][gc,metaspace] CDS archive(s) not mapped
[2025-05-13T14:47:17.278+0530][gc,metaspace] Compressed class space mapped at: 0x00000007c0000000-0x0000000800000000, reserved size: 1073741824
[2025-05-13T14:47:17.278+0530][gc,metaspace] Narrow klass base: 0x0000000000000000, Narrow klass shift: 3, Narrow klass range: 0x800000000
[2025-05-13T14:47:17.849+0530][gc,start    ] GC(0) Pause Young (Concurrent Start) (Metadata GC Threshold)
[2025-05-13T14:47:17.850+0530][gc,task     ] GC(0) Using 13 workers of 13 for evacuation
[2025-05-13T14:47:17.853+0530][gc,phases   ] GC(0)   Pre Evacuate Collection Set: 0.1ms

Below is the state of that string before it throws exception,

is there anything else I might be missing in terms usage when working with RotatingGCLogFile, Thanks

[mpicque]

+1

I just ran into the same bug

It seems the DateTimeStamp parsing of Unified GC Logs is bugged and don't remove the brackets, see DateTimeStamp.fromGCLogLine and the date/timestamp regex for Unified GC logs here

And the method DateTimeStamp.fromGCLogLine is only used by RotationGCLogFile.

[dsgrieve]

There is an inconsistency between DATE_TAG and UPTIME_TAG in that UPTIME_TAG captures the date between the square brackets and DATE_TAG does not. This should be made consistent. IMHO, UPTIME_TAG is correct.