Parsing logs (for an AOT Cache analyzer tool)

Fri Sep 19 08:14:16 UTC 2025

Hi!

As I mentioned yesterday, I am working on a tool (interactive console) to
analyze what is inside the AOT cache, why and when the elements were added
(or not), and if there's anything that can be done to improve it.

It can be found here: https://github.com/Delawen/leyden-analyzer
Warning: very much work in progress, I am changing the way the commands
work almost everyday as I add more commands and more data and I don't like
how it is shown :)

But when analysing logs I found out there are several cases in which it is
difficult to parse it automatically. I am using a consumer that goes line
by line, and sometimes you need some context to know what is happening. A
very clear example:

[info][aot       ] Allocating RW objects ...
[info][aot       ] done (218321 objects)
[info][aot       ] Allocating RO objects ...
[info][aot       ] done (432657 objects)

I guess there are not many parallel things happening at this time on the
JVM, but if any other log message gets in between, that would be chaotic. A
human may get it, a machine will find it confusing.

Also, there are some lines that can be parsed, but need "special treatment"
like for example this line that has a comma inside the content of a
comma-separated list of values:

[info][aot       ] Class  CP entries = 127257, archived =  20941 ( 16,5%),
reverted =      0

Then there are other inconsistencies that are not that problematic but
fixing them could make parsing the log easier. For example, see the
following lines, which have similar information but displayed on very
different ways:

[info][aot       ] Reserved output buffer space at 0x00007f5702e00000
[1084227584 bytes]
[info][aot] Reserved archive_space_rs [0x0000000057000000 -
0x000000005c000000] (83886080) bytes (includes protection zone)
[info][aot] Reserved class_space_rs   [0x000000005c000000 -
0x000000009c000000] (1073741824) bytes
[info][aot] Mapped static  region #0 at base 0x0000000057001000 top
0x0000000058fbe000 (ReadWrite)
[info][aot       ] Heap range = [0x00000000e0000000 - 0x0000000100000000]
[info][aot       ] Shared file region (rw) 0: 31818032 bytes, addr
0x0000000800001000 file offset 0x00001000 crc 0xc67c8575

In my opinion, it would make sense to have a common way of writing region
addresses so the parser only needs to implement one way of parsing it. And
this was a very obvious case, but I'm sure there are others out there that
would benefit from some guidelines on how to output data.

I intend to improve the log messages to make it easier to parse (while not
breaking the human-readable side) following suggestions from
https://cr.openjdk.org/~jrose/jvm/parsing-logs.html which I found very
complete.

Do we have a "good-practices guideline for OpenJDK developers" on how to
write log messages? If not, do I start one? Where?

Should I add new log messages instead of modifying the existing ones in
case someone is already parsing them? As an intermediate step before
"deprecating" the current messages.

Some of the things I already have in mind:
 - Better "CSV-style" lists of data
 - Try to keep context in the same line (if you read a line alone, you
should understand it)
 - Be more consistent in using "=" or ":" when specifying values (like
"[info][aot] Core region alignment: 4096" versus "Selected AOTMode=record
because AOTCacheOutput is specified")
 - Be more consistent in general with similar type of data and similar
messages

What do you think?

Cheers!
María Arias de Reyna Domínguez
Senior Software Engineer
She / Her / Hers
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://mail.openjdk.org/pipermail/leyden-dev/attachments/20250919/fbb00d14/attachment.htm>