Log Buffer Example
If you really want hexdump level of details about a log buffer, this is the page for you. Feel free to skip it otherwise.
After creating a Publication with a term length of 64KB, but before writing any messages to it, the log buffer contains
the following. Note that this output was produced by hd
on Linux, where an asterisk means the contents of the
previous line were repeated one or more times:
00000000 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................| // term 0
*
00010000 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................| // term 1
*
00020000 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................| // term 2
*
00030000 00 00 00 00 e3 50 43 5f 00 00 00 00 e1 50 43 5f |.....PC_.....PC_| // metadata part 1
00030010 00 00 00 00 e2 50 43 5f 00 00 00 00 00 00 00 00 |.....PC_........|
00030020 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
*
00030080 ff ff ff ff ff ff ff 7f 01 00 00 00 00 00 00 00 |................| // metadata part 2
00030090 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
*
00030100 02 00 00 00 00 00 00 00 e3 50 43 5f 20 00 00 00 |.........PC_ ...| // metadata part 3
00030110 80 05 00 00 00 00 01 00 00 10 00 00 00 00 00 00 |................|
00030120 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
*
00030140 00 00 00 00 00 c0 01 00 00 00 00 00 d9 21 1c 18 |.............!..| // metadata part 4
00030150 7b 00 00 00 e3 50 43 5f 00 00 00 00 00 00 00 00 |{....PC_........|
00030160 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
*
00031000
The term length is 0x010000 (64KB), so the above shows 3 terms full of zeros, ending at 0x030000 where the metadata section starts. The metadata is split into 4 parts. Each part contains data followed by some padding to pack it out to a multiple of cache line size. Parts with unrelated data are on different cache lines to help alleviate False Sharing.
Metadata part 1 starts at 0x00030000:
0x5F4350E300000000: Tail Counter 0 (note the term id in the top 32 bits)
0x5F4350E100000000: Tail Counter 1
0x5F4350E200000000: Tail Counter 2
0x00000000: Active Term Count
Metadata part 2 starts at 0x00030080:
0x7FFFFFFFFFFFFFFF: End of Stream Position (Long.MAX_VALUE)
0x00000001: Is Connected (1 == true; 0 == false)
0x00000000: Active Transport Count
Metadata part 3 starts at 0x00030100:
0x0000000000000002: Registration / Correlation ID (this matches the number in the log buffer filename)
0x5F4350E3: Initial Term Id (randomly generated)
0x00000020: Default Frame Header Length (32 bytes)
0x00000580: MTU Length (1408 in decimal)
0x00010000: Term Length (64KB)
0x00001000: Page Size (4KB)
Metadata part 4 starts at 0x00030140. It contains the Default Frame Header, which contains the default values for the Data Frame Header that is written before every data frame in the Terms. The file ends with more zeros, rounding it up to the next page boundary (4KB), which takes it to a length of 0x00031000.
Decoding some of the values in the Default Frame Header gives:
0x181C21D9: Session Id (404496857)
0x0000007B: Stream Id (123)
0x5F4350E3: Term Id (1598247139)
Aeron provides a tool for decoding the contents of log buffer files: LogInspector It outputs information from the metadata before displaying the term buffer contents:
======================================================================
Sun Nov 19 12:29:09 GMT 2023 Inspection dump for /tmp/aeron-logbuffers/2.logbuffer
======================================================================
Is connected: true
Initial term id: 1598247139
Term count: 0
Active index: 0
Term length: 65536
MTU length: 1408
Page size: 4096
EOS position: 9223372036854775807
default DATA Header{frame-length=0 version=0 flags=11000000 type=1 term-offset=0 session-id=404496857 stream-id=123 term-id=1598247139 reserved-value=0}
Index 0 Term Meta Data termOffset=0 termId=1598247139 rawTail=6864419192930566144 position=0
Index 1 Term Meta Data termOffset=0 termId=1598247137 rawTail=6864419184340631552 position=-131072
Index 2 Term Meta Data termOffset=0 termId=1598247138 rawTail=6864419188635598848 position=-65536
... (term buffer contents follows) ...
After writing the first message
After publishing the first message to the Publication, the changes are as below. The message was 1024 bytes in length
minus the length of the header (32 bytes), so the overall length including the header was 1024 bytes. The message
contained text with the same 16-byte pattern <msgXXX-partYYY>
repeated over and over, so you can identify it easily
when looking at the log buffer.
00000000 00 04 00 00 00 c0 01 00 00 00 00 00 d9 21 1c 18 |.............!..|
00000010 7b 00 00 00 e3 50 43 5f 00 00 00 00 00 00 00 00 |{....PC_........|
00000020 3c 6d 73 67 30 30 31 2d 70 61 72 74 30 30 30 3e |<msg001-part000>|
00000030 3c 6d 73 67 30 30 31 2d 70 61 72 74 30 30 31 3e |<msg001-part001>|
-- other parts omitted for clarity --
000003e0 3c 6d 73 67 30 30 31 2d 70 61 72 74 30 36 30 3e |<msg001-part060>|
000003f0 3c 6d 73 67 30 30 31 2d 70 61 72 74 30 36 31 3e |<msg001-part061>|
-- then in the metadata section --
00030000 00 04 00 00 e3 50 43 5f 00 00 00 00 e1 50 43 5f |.....PC_.....PC_|
The 32-byte message header starts at byte 0, followed by the message itself at 0x20. The final byte in the message is at byte 0x03FF (1024 bytes long). The message header contains the SessionId, StreamId and TermId copied from the Default Frame Header. The message header also contains the message length 0x00000400 (at byte 0), which is 1024 and is the length of the message header and message.
Within the metadata section, Tail Counter 0 has increased by 1024 to 0x5F4350E300000400.