Xray produces an invalid/confusing log file when no data is generated.

[HFTrader]

Xray produces a confusing log file when no data is generated.

For debugging this I wrote a small test

// test.cpp
void doit() {
}

void passthrough() {
    doit();
}

int main() {
    passthrough();
    return 0;
}

Then I compile and run the above example using clang 14.0.6 (taken straight from Github)

$ clang++ -O3 test.cpp -fxray-instrument -fxray-instruction-threshold=1 -o test
$ ls -1
attr.txt
test.cpp
test

According to the documentation, I have to run with environment variables set up

$ XRAY_OPTIONS="patch_premain=true  xray_mode=xray-basic verbosity=1"  ./test
==219673==XRay: Log file in 'xray-log.test.ym8oWP'
==219673==Skipping buffer for TID: 219673; Offset = 0
==219673==Cleaned up log for TID: 219673

The trace file at first seems generated ok

$ ls -1
attr.txt
test
test.cpp
xray-log.test.ym8oWP

Obviously, these above functions get optimized away - an oversight of mine - and understandably there is no data to be generated.

But when I try to look into the trace file, I get the following confusing error instead of a warning "empty file" or similar.

$ llvm-xray account --instr_map=./test xray-log.test.ym8oWP 
llvm-xray: Failed loading input file 'xray-log.test.ym8oWP'
Unsupported version for Basic/Naive Mode logging: 768

When I look into the binary, everything seems fine

$ llvm-xray extract ./test 
---
- { id: 1, address: 0x420EA0, function: 0x420EA0, kind: function-enter, always-instrument: false, function-name: '', version: 2 }
- { id: 1, address: 0x420EAC, function: 0x420EA0, kind: function-exit, always-instrument: false, function-name: '', version: 2 }
- { id: 2, address: 0x420EC0, function: 0x420EC0, kind: function-enter, always-instrument: false, function-name: '', version: 2 }
- { id: 2, address: 0x420ECC, function: 0x420EC0, kind: function-exit, always-instrument: false, function-name: '', version: 2 }
- { id: 3, address: 0x420EE0, function: 0x420EE0, kind: function-enter, always-instrument: false, function-name: '', version: 2 }
- { id: 3, address: 0x420EEE, function: 0x420EE0, kind: function-exit, always-instrument: false, function-name: '', version: 2 }
...

The trace file has 0x0300 as the first 2 bytes while the source code states that the enumeration is either 0x01 (basic) or 0x02 (fdr).

$ hexdump -C ./xray-log.test.d0IxRD 
00000000  03 00 00 00 ff 7f 00 00  68 4e 9d 1e 01 00 00 00  |........hN......|
00000010  00 20 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |. ..............|
00000020

The sources for that compiler version show that the headers should look like one of the following

  //   0x01 0x00 0x00 0x00 - version 1, "naive" format
  //   0x01 0x00 0x01 0x00 - version 1, "flight data recorder" format
  //   0x02 0x00 0x01 0x00 - version 2, "flight data recorder" format

I can see these 4 bytes starting at position 12 but wondering why llvm-xray is looking at byte zero?

I guess the key is the message " Skipping buffer for TID: 219673; Offset = 0"

The generated empty file looks okay also - I can see the same prefix bytes in another populated log file. It is the parsing of the log file that is causing it to display a confusing message.

[stasos24]

i have encountered with the same problem

[alexey-milovidov]

Same problem, see ClickHouse/ClickHouse#34160

[carlcook]

I've hit the same (18.1.8 Fedora Core 40).