Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Index out of bounds when parsing profdata #23

Open
danjujan opened this issue Nov 1, 2022 · 10 comments
Open

Index out of bounds when parsing profdata #23

danjujan opened this issue Nov 1, 2022 · 10 comments

Comments

@danjujan
Copy link

danjujan commented Nov 1, 2022

I tried to use cov show as a replacement for llvm-cov show on the example C++ program from https://clang.llvm.org/docs/SourceBasedCodeCoverage.html but encountered the following panic:

thread 'main' panicked at 'index out of bounds: the len is 3 but the index is 7', src/coverage/coverage_mapping.rs:514:13
stack backtrace:
   0: rust_begin_unwind
             at /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/std/src/panicking.rs:584:5
   1: core::panicking::panic_fmt
             at /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/core/src/panicking.rs:142:14
   2: core::panicking::panic_bounds_check
             at /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/core/src/panicking.rs:84:5
   3: llvm_profparser::coverage::coverage_mapping::parse_counter
             at ./src/coverage/coverage_mapping.rs:514:13
   4: llvm_profparser::coverage::coverage_mapping::parse_mapping_regions
             at ./src/coverage/coverage_mapping.rs:386:31
   5: llvm_profparser::coverage::coverage_mapping::parse_coverage_functions
             at ./src/coverage/coverage_mapping.rs:332:17
   6: llvm_profparser::coverage::coverage_mapping::read_object_file::{{closure}}
             at ./src/coverage/coverage_mapping.rs:70:18
   7: core::option::Option<T>::map
             at /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/core/src/option.rs:929:29
   8: llvm_profparser::coverage::coverage_mapping::read_object_file
             at ./src/coverage/coverage_mapping.rs:67:19
   9: llvm_profparser::coverage::coverage_mapping::CoverageMapping::new
             at ./src/coverage/coverage_mapping.rs:107:31
  10: cov::ShowCommand::run
             at ./src/bin/cov.rs:46:23
  11: cov::main
             at ./src/bin/cov.rs:75:35
  12: core::ops::function::FnOnce::call_once
             at /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/core/src/ops/function.rs:248:5

I know your project is mostly targeted for parsing profiling data from rust programs but since the coverage mapping format is the same it should work universally for other profdata too. Right?

Here are my steps to reproduce:

cd /tmp
git clone https://github.com/xd009642/llvm-profparser.git
cd llvm-profparser

cat <<EOF > foo.cc
#define BAR(x) ((x) || (x))
template <typename T> void foo(T x) {
  for (unsigned I = 0; I < 10; ++I) { BAR(I); }
}
int main() {
  foo<int>(0);
  foo<float>(0);
  return 0;
}
EOF

clang++ -fprofile-instr-generate -fcoverage-mapping foo.cc -o foo
LLVM_PROFILE_FILE="foo.profraw" ./foo
llvm-profdata merge -sparse foo.profraw -o foo.profdata

# Works
llvm-cov show ./foo -instr-profile=foo.profdata

# Works not
RUST_BACKTRACE=1 cargo run --bin cov -- show --instr-profile foo.profdata --object ./foo

OS: Arch Linux
Clang/LLVM version: 14.0.6

Any help to debug this further is highly appreciated!

@xd009642
Copy link
Owner

xd009642 commented Nov 1, 2022

Yeah ideally it should work, it's probably a bug in some assumption I have - I just use the test files from llvm code that are easy to apply and some tests generated from rust code and the format isn't really rigorously defined so it's been a mix of reading the llvm source and reverse engineering solutions to issues from odd output I find in the wild and making sure output is the same.

I'll have a look after work and maybe look at adding some debug logging to aid in debugging 🙏

@xd009642
Copy link
Owner

xd009642 commented Nov 6, 2022

There's now a branch called debug-traces with a --debug flag which will show a bunch of printouts. I don't have the same llvm on my system so I'll have to sort that out and test with the same version as you, but you can always use --debug and see if that provides some more debug info.

Or if you have it handy zip up the executable and profraw + profdata files from your minimal version and attach them to the issue and I'll try them out directly

@danjujan
Copy link
Author

danjujan commented Nov 7, 2022

Thank you. Here is the debug output and the corresponding files. foo-example.zip

Running `target/debug/cov show --debug --instr-profile foo.profdata --object ./foo`
2022-11-07T12:35:34.163904Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Parsed header: Header { version: 7, hash_type: Md5, hash_offset: 744 }
2022-11-07T12:35:34.163970Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Summary: Some(ProfileSummary { kind: Instr, total_count: 27, max_count: 10, max_internal_count: 10, max_function_count: 1, num_counts: 9, num_fns: 3, partial: false, partial_profile_ratio: 0.0, detailed_summary: [ProfileSummaryEntry { cutoff: 10000, min_count: 0, num_counts: 0 }, ProfileSummaryEntry { cutoff: 100000, min_count: 10, num_counts: 2 }, ProfileSummaryEntry { cutoff: 200000, min_count: 10, num_counts: 2 }, ProfileSummaryEntry { cutoff: 300000, min_count: 10, num_counts: 2 }, ProfileSummaryEntry { cutoff: 400000, min_count: 10, num_counts: 2 }, ProfileSummaryEntry { cutoff: 500000, min_count: 10, num_counts: 2 }, ProfileSummaryEntry { cutoff: 600000, min_count: 10, num_counts: 2 }, ProfileSummaryEntry { cutoff: 700000, min_count: 10, num_counts: 2 }, ProfileSummaryEntry { cutoff: 800000, min_count: 1, num_counts: 9 }, ProfileSummaryEntry { cutoff: 900000, min_count: 1, num_counts: 9 }, ProfileSummaryEntry { cutoff: 950000, min_count: 1, num_counts: 9 }, ProfileSummaryEntry { cutoff: 990000, min_count: 1, num_counts: 9 }, ProfileSummaryEntry { cutoff: 999000, min_count: 1, num_counts: 9 }, ProfileSummaryEntry { cutoff: 999900, min_count: 1, num_counts: 9 }, ProfileSummaryEntry { cutoff: 999990, min_count: 1, num_counts: 9 }, ProfileSummaryEntry { cutoff: 999999, min_count: 1, num_counts: 9 }] })
2022-11-07T12:35:34.164000Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: cs_summary: None
2022-11-07T12:35:34.164008Z DEBUG llvm_profparser::hash_table: Number of hashtable buckets: 8
2022-11-07T12:35:34.164016Z DEBUG llvm_profparser::hash_table: Number of entries: 3
2022-11-07T12:35:34.164023Z DEBUG llvm_profparser::hash_table: Number of items in bucket: 1
2022-11-07T12:35:34.164031Z DEBUG llvm_profparser::hash_table: Hash(?): 13700173462938669976
2022-11-07T12:35:34.164039Z DEBUG llvm_profparser::hash_table: lengths: KeyDataLen { key_len: 12, data_len: 56 } and key: _Z3fooIiEvT_
2022-11-07T12:35:34.164053Z DEBUG llvm_profparser::hash_table: hash: 1160145, value: InstrProfRecord { counts: [1, 10, 1, 1], data: None }
2022-11-07T12:35:34.164071Z DEBUG llvm_profparser::hash_table: Number of items in bucket: 1
2022-11-07T12:35:34.164077Z DEBUG llvm_profparser::hash_table: Hash(?): 15822663052811949562
2022-11-07T12:35:34.164083Z DEBUG llvm_profparser::hash_table: lengths: KeyDataLen { key_len: 4, data_len: 32 } and key: main
2022-11-07T12:35:34.164092Z DEBUG llvm_profparser::hash_table: hash: 24, value: InstrProfRecord { counts: [1], data: None }
2022-11-07T12:35:34.164100Z DEBUG llvm_profparser::hash_table: Number of items in bucket: 1
2022-11-07T12:35:34.164106Z DEBUG llvm_profparser::hash_table: Hash(?): 10591215365152355902
2022-11-07T12:35:34.164112Z DEBUG llvm_profparser::hash_table: lengths: KeyDataLen { key_len: 12, data_len: 56 } and key: _Z3fooIfEvT_
2022-11-07T12:35:34.164121Z DEBUG llvm_profparser::hash_table: hash: 1160145, value: InstrProfRecord { counts: [1, 10, 1, 1], data: None }
2022-11-07T12:35:34.164131Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Function hash table: HashTable({(1160145, "_Z3fooIiEvT_"): InstrProfRecord { counts: [1, 10, 1, 1], data: None }, (24, "main"): InstrProfRecord { counts: [1], data: None }, (1160145, "_Z3fooIfEvT_"): InstrProfRecord { counts: [1, 10, 1, 1], data: None }})
2022-11-07T12:35:34.164158Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Parsed record NamedInstrProfRecord { name: Some("_Z3fooIiEvT_"), hash: Some(1160145), record: InstrProfRecord { counts: [1, 10, 1, 1], data: None } }
2022-11-07T12:35:34.164175Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Parsed record NamedInstrProfRecord { name: Some("main"), hash: Some(24), record: InstrProfRecord { counts: [1], data: None } }
2022-11-07T12:35:34.164186Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Parsed record NamedInstrProfRecord { name: Some("_Z3fooIfEvT_"), hash: Some(1160145), record: InstrProfRecord { counts: [1, 10, 1, 1], data: None } }
thread 'main' panicked at 'index out of bounds: the len is 3 but the index is 7', src/coverage/coverage_mapping.rs:523:13
stack backtrace:
   0: rust_begin_unwind
             at /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/std/src/panicking.rs:584:5
   1: core::panicking::panic_fmt
             at /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/core/src/panicking.rs:142:14
   2: core::panicking::panic_bounds_check
             at /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/core/src/panicking.rs:84:5
   3: llvm_profparser::coverage::coverage_mapping::parse_counter
             at ./src/coverage/coverage_mapping.rs:523:13
   4: llvm_profparser::coverage::coverage_mapping::parse_mapping_regions
             at ./src/coverage/coverage_mapping.rs:395:31
   5: llvm_profparser::coverage::coverage_mapping::parse_coverage_functions
             at ./src/coverage/coverage_mapping.rs:341:17
   6: llvm_profparser::coverage::coverage_mapping::read_object_file::{{closure}}
             at ./src/coverage/coverage_mapping.rs:71:18
   7: core::option::Option<T>::map
             at /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/core/src/option.rs:929:29
   8: llvm_profparser::coverage::coverage_mapping::read_object_file
             at ./src/coverage/coverage_mapping.rs:68:19
   9: llvm_profparser::coverage::coverage_mapping::CoverageMapping::new
             at ./src/coverage/coverage_mapping.rs:116:31
  10: cov::ShowCommand::run
             at ./src/bin/cov.rs:54:23
  11: cov::main
             at ./src/bin/cov.rs:94:35
  12: core::ops::function::FnOnce::call_once
             at /rustc/a55dd71d5fb0ec5a6a3a9e8c27b2127ba491ce52/library/core/src/ops/function.rs:248:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.

@xd009642
Copy link
Owner

So a PR has just been merged which should fix this issue - something in branch regions which rust doesn't currently emit. I'm going to cut a new release later today or tomorrow so hopefully you can confirm this works for you then (if it's not been too long)

@danjujan
Copy link
Author

Current master does not fix it for me. However, the debug output changed and it does not crash anymore. So probably one step in the right direction!

clang++ --version
clang version 15.0.7
Target: x86_64-pc-linux-gnu
Thread model: posix
InstalledDir: /usr/bin
...
     Running `target/debug/cov show --debug --instr-profile foo.profdata --object ./foo`
2023-03-30T10:59:58.995921Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Parsed header: Header { version: 8, hash_type: Md5, hash_offset: 752 }
2023-03-30T10:59:58.995949Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Summary: Some(ProfileSummary { kind: Instr, total_count: 0, max_count: 0, max_internal_count: 0, max_function_count: 0, num_counts: 0, num_fns: 0, partial: false, partial_profile_ratio: 0.0, detailed_summary: [ProfileSummaryEntry { cutoff: 16, min_count: 3, num_counts: 9 }, ProfileSummaryEntry { cutoff: 1, min_count: 10, num_counts: 10 }, ProfileSummaryEntry { cutoff: 27, min_count: 10000, num_counts: 0 }, ProfileSummaryEntry { cutoff: 0, min_count: 100000, num_counts: 10 }, ProfileSummaryEntry { cutoff: 2, min_count: 200000, num_counts: 10 }, ProfileSummaryEntry { cutoff: 2, min_count: 300000, num_counts: 10 }] })
2023-03-30T10:59:58.995962Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: cs_summary: None
2023-03-30T10:59:58.995969Z DEBUG llvm_profparser::hash_table: Number of hashtable buckets: 8
2023-03-30T10:59:58.995974Z DEBUG llvm_profparser::hash_table: Number of entries: 3
2023-03-30T10:59:58.995979Z DEBUG llvm_profparser::hash_table: Number of items in bucket: 2
2023-03-30T10:59:58.995984Z DEBUG llvm_profparser::hash_table: Hash(?): 1909526242005090304
Error: Parsing failed

@xd009642
Copy link
Owner

@Quessou looks like there's a bit more to this one if you want to continue with it 👀

@Quessou
Copy link
Contributor

Quessou commented Mar 30, 2023

I'll take a look at it tomorrow ! :)

@Quessou
Copy link
Contributor

Quessou commented Apr 3, 2023

Sorry for the time to answer ! 😅

Just for traceability : Bug was first observed on Clang/LLVM 14
This second issue on parsing seem to be on Clang/LLVM 15.
I tried to reproduce the issue with the same setup I used to fix the first issue and the parsing does not fail on my end.

2023-04-03T13:41:46.719787Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Parsed header: Header { version: 7, hash_type: Md5, hash_offset: 744 }
2023-04-03T13:41:46.719898Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Summary: Some(ProfileSummary { kind: Instr, total_count: 27, max_count: 10, max_internal_count: 10, max_function_count: 1, num_counts: 9, num_fns: 3, partial: false, partial_profile_ratio: 0.0, detailed_summary: [ProfileSummaryEntry { cutoff: 10000, min_count: 0, num_counts: 0 }, ProfileSummaryEntry { cutoff: 100000, min_count: 10, num_counts: 2 }, ProfileSummaryEntry { cutoff: 200000, min_count: 10, num_counts: 2 }, ProfileSummaryEntry { cutoff: 300000, min_count: 10, num_counts: 2 }, ProfileSummaryEntry { cutoff: 400000, min_count: 10, num_counts: 2 }, ProfileSummaryEntry { cutoff: 500000, min_count: 10, num_counts: 2 }, ProfileSummaryEntry { cutoff: 600000, min_count: 10, num_counts: 2 }, ProfileSummaryEntry { cutoff: 700000, min_count: 10, num_counts: 2 }, ProfileSummaryEntry { cutoff: 800000, min_count: 1, num_counts: 9 }, ProfileSummaryEntry { cutoff: 900000, min_count: 1, num_counts: 9 }, ProfileSummaryEntry { cutoff: 950000, min_count: 1, num_counts: 9 }, ProfileSummaryEntry { cutoff: 990000, min_count: 1, num_counts: 9 }, ProfileSummaryEntry { cutoff: 999000, min_count: 1, num_counts: 9 }, ProfileSummaryEntry { cutoff: 999900, min_count: 1, num_counts: 9 }, ProfileSummaryEntry { cutoff: 999990, min_count: 1, num_counts: 9 }, ProfileSummaryEntry { cutoff: 999999, min_count: 1, num_counts: 9 }] })
2023-04-03T13:41:46.719962Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: cs_summary: None
2023-04-03T13:41:46.719980Z DEBUG llvm_profparser::hash_table: Number of hashtable buckets: 8
2023-04-03T13:41:46.719993Z DEBUG llvm_profparser::hash_table: Number of entries: 3
2023-04-03T13:41:46.720009Z DEBUG llvm_profparser::hash_table: Number of items in bucket: 1
2023-04-03T13:41:46.720024Z DEBUG llvm_profparser::hash_table: Hash(?): 13700173462938669976
2023-04-03T13:41:46.720038Z DEBUG llvm_profparser::hash_table: lengths: KeyDataLen { key_len: 12, data_len: 56 } and key: _Z3fooIiEvT_
2023-04-03T13:41:46.720062Z DEBUG llvm_profparser::hash_table: hash: 1160145, value: InstrProfRecord { counts: [1, 10, 1, 1], data: None }
2023-04-03T13:41:46.720093Z DEBUG llvm_profparser::hash_table: Number of items in bucket: 1
2023-04-03T13:41:46.720108Z DEBUG llvm_profparser::hash_table: Hash(?): 15822663052811949562
2023-04-03T13:41:46.720144Z DEBUG llvm_profparser::hash_table: lengths: KeyDataLen { key_len: 4, data_len: 32 } and key: main
2023-04-03T13:41:46.720181Z DEBUG llvm_profparser::hash_table: hash: 24, value: InstrProfRecord { counts: [1], data: None }
2023-04-03T13:41:46.720214Z DEBUG llvm_profparser::hash_table: Number of items in bucket: 1
2023-04-03T13:41:46.720240Z DEBUG llvm_profparser::hash_table: Hash(?): 10591215365152355902
2023-04-03T13:41:46.720263Z DEBUG llvm_profparser::hash_table: lengths: KeyDataLen { key_len: 12, data_len: 56 } and key: _Z3fooIfEvT_
2023-04-03T13:41:46.720297Z DEBUG llvm_profparser::hash_table: hash: 1160145, value: InstrProfRecord { counts: [1, 10, 1, 1], data: None }
2023-04-03T13:41:46.720332Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Function hash table: HashTable({(1160145, "_Z3fooIiEvT_"): InstrProfRecord { counts: [1, 10, 1, 1], data: None }, (24, "main"): InstrProfRecord { counts: [1], data: None }, (1160145, "_Z3fooIfEvT_"): InstrProfRecord { counts: [1, 10, 1, 1], data: None }})
2023-04-03T13:41:46.720403Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Parsed record NamedInstrProfRecord { name: Some("_Z3fooIiEvT_"), hash: Some(1160145), record: InstrProfRecord { counts: [1, 10, 1, 1], data: None } }
2023-04-03T13:41:46.720456Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Parsed record NamedInstrProfRecord { name: Some("main"), hash: Some(24), record: InstrProfRecord { counts: [1], data: None } }
2023-04-03T13:41:46.720497Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Parsed record NamedInstrProfRecord { name: Some("_Z3fooIfEvT_"), hash: Some(1160145), record: InstrProfRecord { counts: [1, 10, 1, 1], data: None } }
2023-04-03T13:41:46.720950Z DEBUG llvm_profparser::coverage::coverage_mapping: Parsed covfun section: [FunctionRecordV3 { header: FunctionRecordHeader { name_hash: 15822663052811949562, data_len: 9, fn_hash: 24, filenames_ref: 2481258828569542473 }, regions: [CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 0 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 5, column_start: 12, line_end: 9, column_end: 2 } }], expressions: [] }, FunctionRecordV3 { header: FunctionRecordHeader { name_hash: 13700173462938669976, data_len: 82, fn_hash: 1160145, filenames_ref: 2481258828569542473 }, regions: [CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 0 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 2, column_start: 37, line_end: 4, column_end: 2 } }, CounterMappingRegion { kind: Code, count: Counter { kind: Expression(Add), id: 0 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 3, column_start: 24, line_end: 3, column_end: 30 } }, CounterMappingRegion { kind: Branch, count: Counter { kind: ProfileInstrumentation, id: 1 }, false_count: Counter { kind: ProfileInstrumentation, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 3, column_start: 24, line_end: 3, column_end: 30 } }, CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 1 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 3, column_start: 32, line_end: 3, column_end: 35 } }, CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 1 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 3, column_start: 36, line_end: 3, column_end: 2147483685 } }, CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 1 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 3, column_start: 37, line_end: 3, column_end: 48 } }, CounterMappingRegion { kind: Expansion, count: Counter { kind: Zero, id: 3 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 1, loc: SourceLocation { line_start: 3, column_start: 39, line_end: 3, column_end: 42 } }, CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 1 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 1, column_start: 16, line_end: 1, column_end: 28 } }, CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 1 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 1, column_start: 17, line_end: 1, column_end: 20 } }, CounterMappingRegion { kind: Branch, count: Counter { kind: Expression(Subtract), id: 1 }, false_count: Counter { kind: ProfileInstrumentation, id: 2 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 1, column_start: 17, line_end: 1, column_end: 20 } }, CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 2 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 1, column_start: 24, line_end: 1, column_end: 27 } }, CounterMappingRegion { kind: Branch, count: Counter { kind: Expression(Subtract), id: 2 }, false_count: Counter { kind: ProfileInstrumentation, id: 3 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 1, column_start: 24, line_end: 1, column_end: 27 } }], expressions: [Expression { kind: Add, lhs: Counter { kind: ProfileInstrumentation, id: 0 }, rhs: Counter { kind: ProfileInstrumentation, id: 1 } }, Expression { kind: Subtract, lhs: Counter { kind: ProfileInstrumentation, id: 1 }, rhs: Counter { kind: ProfileInstrumentation, id: 2 } }, Expression { kind: Subtract, lhs: Counter { kind: ProfileInstrumentation, id: 2 }, rhs: Counter { kind: ProfileInstrumentation, id: 3 } }] }, FunctionRecordV3 { header: FunctionRecordHeader { name_hash: 10591215365152355902, data_len: 82, fn_hash: 1160145, filenames_ref: 2481258828569542473 }, regions: [CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 0 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 2, column_start: 37, line_end: 4, column_end: 2 } }, CounterMappingRegion { kind: Code, count: Counter { kind: Expression(Add), id: 0 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 3, column_start: 24, line_end: 3, column_end: 30 } }, CounterMappingRegion { kind: Branch, count: Counter { kind: ProfileInstrumentation, id: 1 }, false_count: Counter { kind: ProfileInstrumentation, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 3, column_start: 24, line_end: 3, column_end: 30 } }, CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 1 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 3, column_start: 32, line_end: 3, column_end: 35 } }, CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 1 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 3, column_start: 36, line_end: 3, column_end: 2147483685 } }, CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 1 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 3, column_start: 37, line_end: 3, column_end: 48 } }, CounterMappingRegion { kind: Expansion, count: Counter { kind: Zero, id: 3 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 1, loc: SourceLocation { line_start: 3, column_start: 39, line_end: 3, column_end: 42 } }, CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 1 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 1, column_start: 16, line_end: 1, column_end: 28 } }, CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 1 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 1, column_start: 17, line_end: 1, column_end: 20 } }, CounterMappingRegion { kind: Branch, count: Counter { kind: Expression(Subtract), id: 1 }, false_count: Counter { kind: ProfileInstrumentation, id: 2 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 1, column_start: 17, line_end: 1, column_end: 20 } }, CounterMappingRegion { kind: Code, count: Counter { kind: ProfileInstrumentation, id: 2 }, false_count: Counter { kind: Zero, id: 0 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 1, column_start: 24, line_end: 1, column_end: 27 } }, CounterMappingRegion { kind: Branch, count: Counter { kind: Expression(Subtract), id: 2 }, false_count: Counter { kind: ProfileInstrumentation, id: 3 }, file_id: 1, expanded_file_id: 0, loc: SourceLocation { line_start: 1, column_start: 24, line_end: 1, column_end: 27 } }], expressions: [Expression { kind: Add, lhs: Counter { kind: ProfileInstrumentation, id: 0 }, rhs: Counter { kind: ProfileInstrumentation, id: 1 } }, Expression { kind: Subtract, lhs: Counter { kind: ProfileInstrumentation, id: 1 }, rhs: Counter { kind: ProfileInstrumentation, id: 2 } }, Expression { kind: Subtract, lhs: Counter { kind: ProfileInstrumentation, id: 2 }, rhs: Counter { kind: ProfileInstrumentation, id: 3 } }] }]
2023-04-03T13:41:46.721552Z DEBUG llvm_profparser::coverage::coverage_mapping: Parsed covmap section: {2481258828569542473: ["/home/maxime/05_Rust/22_llvm_profparser/llvm-profparser", "foo.cc"]}
2023-04-03T13:41:46.721615Z DEBUG llvm_profparser::coverage::coverage_mapping: Parsed prf_cnts: Some([0, 0, 0, 0, 0, 0, 0, 0, 0])
2023-04-03T13:41:46.721665Z DEBUG llvm_profparser::coverage::coverage_mapping: Parsed prf_data section: Some([ProfileData { name_md5: 15822663052811949562, structural_hash: 24, counters_len: 1 }, ProfileData { name_md5: 13700173462938669976, structural_hash: 1160145, counters_len: 4 }, ProfileData { name_md5: 10591215365152355902, structural_hash: 1160145, counters_len: 4 }])
    1|     20|#define BAR(x) ((x) || (x))
    2|      2|template <typename T> void foo(T x) {
    3|      2|  for (unsigned I = 0; I < 10; ++I) { BAR(I); }
    4|      2|}
    5|      1|int main() {
    6|      1|  foo<int>(0);
    7|      1|  foo<float>(0);
    8|      1|  return 0;
    9|      1|}

So maybe it's another issue actually, in this case, maybe creating another ticket would be relevant ? Anyway I'll get LLVM 15, try to reproduce and if I manage to do so, investigate a bit.

@danjujan
Copy link
Author

danjujan commented Apr 3, 2023

I get the same error with clang14 under Arch.

cd /tmp
git clone https://github.com/xd009642/llvm-profparser.git
cd llvm-profparser

cat <<EOF > foo.cc
#define BAR(x) ((x) || (x))
template <typename T> void foo(T x) {
  for (unsigned I = 0; I < 10; ++I) { BAR(I); }
}
int main() {
  foo<int>(0);
  foo<float>(0);
  return 0;
}
EOF

/usr/lib/llvm14/bin/clang++ -fprofile-instr-generate -fcoverage-mapping foo.cc -o foo
LLVM_PROFILE_FILE="foo.profraw" ./foo
llvm-profdata merge -sparse foo.profraw -o foo.profdata

# Works
llvm-cov show ./foo -instr-profile=foo.profdata

# Works not
RUST_BACKTRACE=1 cargo run --bin cov -- show --debug --instr-profile foo.profdata --object ./foo
Klone nach 'llvm-profparser'...
remote: Enumerating objects: 1194, done.
remote: Counting objects: 100% (340/340), done.
remote: Compressing objects: 100% (151/151), done.
remote: Total 1194 (delta 233), reused 222 (delta 180), pack-reused 854
Empfange Objekte: 100% (1194/1194), 4.23 MiB | 675.00 KiB/s, fertig.
Löse Unterschiede auf: 100% (602/602), fertig.
    1|     20|#define BAR(x) ((x) || (x))
    2|      2|template <typename T> void foo(T x) {
    3|     22|  for (unsigned I = 0; I < 10; ++I) { BAR(I); }
    4|      2|}
  ------------------
  | _Z3fooIiEvT_:
  |    2|      1|template <typename T> void foo(T x) {
  |    3|     11|  for (unsigned I = 0; I < 10; ++I) { BAR(I); }
  |    4|      1|}
  ------------------
  | _Z3fooIfEvT_:
  |    2|      1|template <typename T> void foo(T x) {
  |    3|     11|  for (unsigned I = 0; I < 10; ++I) { BAR(I); }
  |    4|      1|}
  ------------------
    5|      1|int main() {
    6|      1|  foo<int>(0);
    7|      1|  foo<float>(0);
    8|      1|  return 0;
    9|      1|}

    Updating crates.io index
   Compiling proc-macro2 v1.0.56
   Compiling quote v1.0.26
   Compiling unicode-ident v1.0.8
   Compiling cfg-if v1.0.0
   Compiling version_check v0.9.4
   Compiling syn v1.0.109
   Compiling libc v0.2.140
   Compiling once_cell v1.17.1
   Compiling lazy_static v1.4.0
   Compiling memchr v2.5.0
   Compiling log v0.4.17
   Compiling crc32fast v1.3.2
   Compiling adler v1.0.2
   Compiling autocfg v1.1.0
   Compiling unicode-width v0.1.10
   Compiling unicode-segmentation v1.10.1
   Compiling bitflags v1.3.2
   Compiling overload v0.1.1
   Compiling thiserror v1.0.40
   Compiling anyhow v1.0.70
   Compiling ansi_term v0.12.1
   Compiling vec_map v0.8.2
   Compiling strsim v0.8.0
   Compiling hashbrown v0.11.2
   Compiling smallvec v1.10.0
   Compiling llvm_profparser v0.3.2 (/tmp/llvm-profparser)
   Compiling sharded-slab v0.1.4
   Compiling nu-ansi-term v0.46.0
   Compiling miniz_oxide v0.6.2
   Compiling textwrap v0.11.0
   Compiling minimal-lexical v0.2.1
   Compiling tracing-core v0.1.30
   Compiling thread_local v1.1.7
   Compiling pin-project-lite v0.2.9
   Compiling heck v0.3.3
   Compiling md5 v0.7.0
   Compiling leb128 v0.2.5
   Compiling proc-macro-error-attr v1.0.4
   Compiling proc-macro-error v1.0.4
   Compiling tracing-log v0.1.3
   Compiling indexmap v1.8.2
   Compiling flate2 v1.0.25
   Compiling nom v7.1.3
   Compiling tracing-subscriber v0.3.16
   Compiling object v0.26.2
   Compiling atty v0.2.14
   Compiling clap v2.34.0
   Compiling syn v2.0.13
   Compiling thiserror-impl v1.0.40
   Compiling tracing-attributes v0.1.23
   Compiling structopt-derive v0.4.18
   Compiling structopt v0.3.26
   Compiling tracing v0.1.37
warning: associated constant `ENCODING_TAG_BITS` is never used
   --> src/coverage/mod.rs:188:11
    |
188 |     const ENCODING_TAG_BITS: u64 = 2;
    |           ^^^^^^^^^^^^^^^^^
    |
    = note: `#[warn(dead_code)]` on by default

warning: associated function `deserialize_to` is never used
   --> src/instrumentation_profile/types.rs:354:8
    |
354 |     fn deserialize_to(&self, _record: &mut InstrProfRecord, _symtab: Option<&Symtab>) {
    |        ^^^^^^^^^^^^^^

warning: `llvm_profparser` (lib) generated 2 warnings
    Finished dev [unoptimized + debuginfo] target(s) in 55.00s
     Running `target/debug/cov show --debug --instr-profile foo.profdata --object ./foo`
2023-04-03T22:00:40.597346Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Parsed header: Header { version: 8, hash_type: Md5, hash_offset: 752 }
2023-04-03T22:00:40.597377Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: Summary: Some(ProfileSummary { kind: Instr, total_count: 0, max_count: 0, max_internal_count: 0, max_function_count: 0, num_counts: 0, num_fns: 0, partial: false, partial_profile_ratio: 0.0, detailed_summary: [ProfileSummaryEntry { cutoff: 16, min_count: 3, num_counts: 9 }, ProfileSummaryEntry { cutoff: 1, min_count: 10, num_counts: 10 }, ProfileSummaryEntry { cutoff: 27, min_count: 10000, num_counts: 0 }, ProfileSummaryEntry { cutoff: 0, min_count: 100000, num_counts: 10 }, ProfileSummaryEntry { cutoff: 2, min_count: 200000, num_counts: 10 }, ProfileSummaryEntry { cutoff: 2, min_count: 300000, num_counts: 10 }] })
2023-04-03T22:00:40.597391Z DEBUG llvm_profparser::instrumentation_profile::indexed_profile: cs_summary: None
2023-04-03T22:00:40.597398Z DEBUG llvm_profparser::hash_table: Number of hashtable buckets: 8
2023-04-03T22:00:40.597402Z DEBUG llvm_profparser::hash_table: Number of entries: 3
2023-04-03T22:00:40.597408Z DEBUG llvm_profparser::hash_table: Number of items in bucket: 2
2023-04-03T22:00:40.597413Z DEBUG llvm_profparser::hash_table: Hash(?): 1909526242005090304
Error: Parsing failed

@Quessou
Copy link
Contributor

Quessou commented Apr 4, 2023

I couldn't reproduce it on LLVM/Clang14. 😬

However I have your exact same issue on LLVM15, with the following crash stack :

Stack backtrace:
   0: anyhow::error::<impl core::convert::From<E> for anyhow::Error>::from
             at /home/maxime/.cargo/registry/src/github.com-1ecc6299db9ec823/anyhow-1.0.70/src/error.rs:547:25
   1: <core::result::Result<T,F> as core::ops::try_trait::FromResidual<core::result::Result<core::convert::Infallible,E>>>::from_residual
             at /rustc/2585bcea0bc2a9c42a4be2c1eba5c61137f2b167/library/core/src/result.rs:2108:27
   2: cov::ShowCommand::run
             at ./src/bin/cov.rs:48:13
   3: cov::main
             at ./src/bin/cov.rs:94:35
   4: core::ops::function::FnOnce::call_once
             at /rustc/2585bcea0bc2a9c42a4be2c1eba5c61137f2b167/library/core/src/ops/function.rs:507:5
   5: std::sys_common::backtrace::__rust_begin_short_backtrace
             at /rustc/2585bcea0bc2a9c42a4be2c1eba5c61137f2b167/library/std/src/sys_common/backtrace.rs:121:18
   6: std::rt::lang_start::{{closure}}
             at /rustc/2585bcea0bc2a9c42a4be2c1eba5c61137f2b167/library/std/src/rt.rs:166:18
   7: core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once
             at /rustc/2585bcea0bc2a9c42a4be2c1eba5c61137f2b167/library/core/src/ops/function.rs:606:13
   8: std::panicking::try::do_call
             at /rustc/2585bcea0bc2a9c42a4be2c1eba5c61137f2b167/library/std/src/panicking.rs:483:40
   9: std::panicking::try
             at /rustc/2585bcea0bc2a9c42a4be2c1eba5c61137f2b167/library/std/src/panicking.rs:447:19
  10: std::panic::catch_unwind
             at /rustc/2585bcea0bc2a9c42a4be2c1eba5c61137f2b167/library/std/src/panic.rs:137:14
  11: std::rt::lang_start_internal::{{closure}}
             at /rustc/2585bcea0bc2a9c42a4be2c1eba5c61137f2b167/library/std/src/rt.rs:148:48
  12: std::panicking::try::do_call
             at /rustc/2585bcea0bc2a9c42a4be2c1eba5c61137f2b167/library/std/src/panicking.rs:483:40
  13: std::panicking::try
             at /rustc/2585bcea0bc2a9c42a4be2c1eba5c61137f2b167/library/std/src/panicking.rs:447:19
  14: std::panic::catch_unwind
             at /rustc/2585bcea0bc2a9c42a4be2c1eba5c61137f2b167/library/std/src/panic.rs:137:14
  15: std::rt::lang_start_internal
             at /rustc/2585bcea0bc2a9c42a4be2c1eba5c61137f2b167/library/std/src/rt.rs:148:20
  16: std::rt::lang_start
             at /rustc/2585bcea0bc2a9c42a4be2c1eba5c61137f2b167/library/std/src/rt.rs:165:17
  17: main
  18: __libc_start_call_main
             at ./csu/../sysdeps/nptl/libc_start_call_main.h:58:16
  19: __libc_start_main_impl
             at ./csu/../csu/libc-start.c:392:3
  20: _start

I'm kinda busy today but I will investigate this in the upcoming days ! :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants