gctoolkit icon indicating copy to clipboard operation
gctoolkit copied to clipboard

I find gctoolkit can't parse a CMF my gc log

Open karianna opened this issue 3 years ago • 8 comments

I find gctoolkit can't parse my gc log and show that Missed: 2021-12-19T22:31:54.909+0800: 623.525: [Full GC (Allocation Failure) 2021-12-19T22:31:54.909+0800: 623.525: [CMS (concurrent mode failure): 2097152K->2097152K(2097152K), 9.4110998 secs] 3984639K->3984638K(3984640K), [Metaspace: 215219K->215219K(1241088K)], 9.4112098 secs] [Times: user=9.27 sys=0.15, real=9.41 secs] I think gctoolkit should add or modify a rule to match the line of gc log. By the way, I suggest we should build an issue to record the missing rule which used to strengthen gctoolkit.

Originally posted by @ZhangShushu123 in https://github.com/microsoft/gctoolkit/discussions/192

karianna avatar Dec 20 '21 14:12 karianna

@ZhangShushu123 - Would you be willing to try and adjust the pattern? I'd love to see what we're missing in terms of helping contributors make changes like that :-)

karianna avatar Dec 20 '21 14:12 karianna

Ok, I will follow this issue and try my best to contribute it :-)

ZhangShushu123 avatar Dec 23 '21 12:12 ZhangShushu123

I think the solution of this issue is changing the CMS_TENURED_BLOCK from DATE_TIMESTAMP + "\\[CMS: " + BEFORE_AFTER_CONFIGURED_PAUSE + "\\]" to DATE_TIMESTAMP + "\\[CMS(?:| \(concurrent mode failure\)): " + BEFORE_AFTER_CONFIGURED_PAUSE + "\\]"

ZhangShushu123 avatar Dec 27 '21 07:12 ZhangShushu123

@kirk-microsoft - WDYT?

karianna avatar Jan 04 '22 10:01 karianna

Ok, this is weird. I was following this thread and I didn’t see any new comments show up until now. This might work however, and unfortunately, without properly functional named capture groups, the parsers rely capture group indexes which is very fragile. Since this rule fragment is used in many different places, one needs to be careful as to not disturb the indexing. This is also an area that deserves better test coverage. That said, you’ll end up breaking a test some where when this happens. Second issue is in the interpretation of the data. This is a full GC inside a concurrent cycle. Is it in or out of a concurrent phase. It would appear to not be. Anyways, the Point is, we need to present the event so that any interested downstream aggregators will have a chance at understanding what has happened so they can capture and report on this issue.

kcpeppe avatar Jan 04 '22 14:01 kcpeppe

Ok, this is weird. I was following this thread and I didn’t see any new comments show up until now. This might work however, and unfortunately, without properly functional named capture groups, the parsers rely capture group indexes which is very fragile. Since this rule fragment is used in many different places, one needs to be careful as to not disturb the indexing. This is also an area that deserves better test coverage. That said, you’ll end up breaking a test some where when this happens. Second issue is in the interpretation of the data. This is a full GC inside a concurrent cycle. Is it in or out of a concurrent phase. It would appear to not be. Anyways, the Point is, we need to present the event so that any interested downstream aggregators will have a chance at understanding what has happened so they can capture and report on this issue.

What's the proposed next step here do you think? We wait until we have named capture groups before fixing this one?

karianna avatar Jan 04 '22 15:01 karianna

I was trying to clarify the issues without being prescriptive. That said, I’m happy to eval a PR with this solution.

kcpeppe avatar Jan 04 '22 15:01 kcpeppe

I have the same problem and expect it to be solved

messi612 avatar Jul 26 '22 09:07 messi612