[Enhancement]: make `trace_fmt!()` emit full file and line/column information
- Dominant language
- C++
- Stars
- 1.9k
- Forks
- 283
- Avg merge
- 2d 10h
- Merged PRs (30d)
- 135
Description
The `trace_fmt!()` output recently improved by actually printing the file name and line number the trace is happening.
## What is
But the output is still not as useful as it could
* it contains all kinds of timestamp information due to the inheritance from absl `LOG(INFO)`, but that is not super-helpful: we're running a test and not a long-running server, so the exact microsecond something happened is just noise.
* The filename is not complete: only the basename is shown, not the full filename. This makes it hard for an IDE to map a test output back to the actual file it happened.
* Other internal log message by XLS are also emitted.
This is how things look now:
bazel build -c opt xls/dslx:interpreter_main && bazel-bin/xls/dslx/interpreter_main xls/examples/protobuf/varint_streaming_decode.x --alsologtostderr
```
I0611 19:46:37.793671 16 varint_streaming_decode.x:118] input_data=[0, 0, 0, 0, 0, 0, 0] input_len=0, do_input=0
I0611 19:46:37.793847 16 varint_streaming_decode.x:127] trace of last_terminator_idx: 2
I0611 19:46:37.793851 16 varint_streaming_decode.x:128] trace of num_terminators: 7
I0611 19:46:37.793875 16 varint_streaming_decode.x:176] next_old_bytes calc: do_input=0 do_big_shift=1 num_terminators=7
I0611 19:46:37.794084 16 varint_streaming_decode.x:199] encoded=[0, 1, 0, 1, 0], decoded=0, this_bytes_taken=1, total_bytes_taken=5, bytes_len=11
I0611 19:46:37.794281 16 varint_streaming_decode.x:199] encoded=[1, 0, 1, 0, 1], decoded=1, this_bytes_taken=1, total_bytes_taken=6, bytes_len=11
I0611 19:46:37.794494 16 varint_streaming_decode.x:199] encoded=[0, 1, 0, 1, 0], decoded=0, this_bytes_taken=1, total_bytes_taken=7, bytes_len=11
I0611 19:46:37.794508 16 varint_streaming_decode.x:213] ouput_words=[0, 1, 0], num_output_words=3
I0611 19:46:37.794538 16 varint_streaming_decode.x:85] state=State {
I0611 19:46:37.794541 16 varint_streaming_decode.x:85] work_chunk: [1, 0, 1, 0, 0, 0, 0],
I0611 19:46:37.794542 16 varint_streaming_decode.x:85] len: 4,
I0611 19:46:37.794544 16 varint_streaming_decode.x:85] old_bytes: [0, 0, 0, 0],
I0611 19:46:37.794546 16 varint_streaming_decode.x:85] old_bytes_len: 0,
I0611 19:46:37.794548 16 varint_streaming_decode.x:85] drop_count: 0
I0611 19:46:37.794550 16 varint_streaming_decode.x:85] }
I0611 19:46:37.795046 16 varint_streaming_decode.x:118] input_data=[0, 0, 0, 0, 0, 0, 0] input_len=0, do_input=0
```
## What should
Instead of re-using the internal absl logging with different goals, make `trace_fmt!()` useful, possibly with a flag e.g. `--trace_out`, that then formats with with full relevant information for an IDE to jump to an step to each message, in the standard `:::` format, but no unnecessary fluff:
```
xls/examples/protobuf/varint_streaming_decode.x:119:5-91: input_data=[0, 0, 0, 0, 0, 0, 0] input_len=0, do_input=0
```
Nice-to-have, but not needed in first implementation:
* make --trace_out get an optional parameter with the filename to emit the traces to; not sure if absl flags can take optional parameters though.
* if `isatty(output_fd)`, color the filename.
## Why is this important ?
Well, the example above shows that it is already much more relevant for a human when debugging xls code. But it is also easier for an IDE to pick up information.
I am working towards a feature where you have a 'play' button next to the test in xls (like in emacs in rust files). That will help to have a much more interactive way to interact with the code.
Contributor guide
Assessment
This issue has not been assessed yet.