Add very basic logging to the debug info transform

[SingleAccretion]

The DI transform is a kind of compiler and logging is a very good way to gain insight into compilers - hence this change.

For example, this has already helped me narrow down the cause of #9512:

2024-10-30T23:26:56.408332Z TRACE debug-info-transform: === Begin DIE at 0x0000007a (depth = 2):
DW_TAG_subprogram
  DW_AT_linkage_name ("_ZN9SomeClass16SeparateFunctionEv")
  DW_AT_name ("SeparateFunction")
  DW_AT_decl_file (0x00000002)
  DW_AT_decl_line (20)
  DW_AT_type (0x0000008b)
  DW_AT_declaration (true)
  DW_AT_external (true)
  DW_AT_accessibility (DW_ACCESS_public)
    
2024-10-30T23:26:56.408361Z TRACE debug-info-transform: === End DIE at 0x0000007a (depth = 2):
  Skipped as unreachable

I also took the liberty of renaming a few variables for clarity.

Sample output

2024-10-30T23:26:56.398154Z TRACE debug-info-transform: Commencing DWARF transform for [#0: main.wasm, #1: wit-component:adapter:wasi_snapshot_preview1, #2: wit-component:shim, #3: wit-component:fixups]    
2024-10-30T23:26:56.405243Z TRACE debug-info-transform: [== Transforming CUs for module #0 ==]    
2024-10-30T23:26:56.405357Z TRACE debug-info-transform: Cloning CU 0x00000000 ["C:\wasi-sdk\sysroot\wasi-libc-wasm32-wasip2", "libc-bottom-half/crt\crt1-command.c"]    
2024-10-30T23:26:56.405562Z TRACE debug-info-transform: === Begin DIE at 0x0000000b (depth = 0):
DW_TAG_compile_unit
  DW_AT_producer ("clang version 18.1.2 (https://github.com/llvm/llvm-project 26a1d6601d727a96f4301d0d8647b5a42760ae0c)")
  DW_AT_language (DW_LANG_C11)
  DW_AT_name ("libc-bottom-half/crt\crt1-command.c")
  DW_AT_stmt_list (0x00000000)
  DW_AT_comp_dir ("C:\wasi-sdk\sysroot\wasi-libc-wasm32-wasip2")
  DW_AT_low_pc (00000005)
  DW_AT_high_pc (82)
    
2024-10-30T23:26:56.405789Z TRACE debug-info-transform: === End DIE at 0x0000000b (depth = 0):
DW_TAG_compile_unit
  DW_AT_ranges (<TODO: out rnglist dump>)
  DW_AT_producer ("clang version 18.1.2 (https://github.com/llvm/llvm-project 26a1d6601d727a96f4301d0d8647b5a42760ae0c)")
  DW_AT_language (DW_LANG_C11)
  DW_AT_name ("libc-bottom-half/crt\crt1-command.c")
  DW_AT_stmt_list (LineProgramRef)
  DW_AT_comp_dir ("C:\wasi-sdk\sysroot\wasi-libc-wasm32-wasip2")
    
2024-10-30T23:26:56.405832Z TRACE debug-info-transform: === Begin DIE at 0x00000026 (depth = 1):
DW_TAG_subprogram
  DW_AT_low_pc (00000005)
  DW_AT_high_pc (82)
  DW_AT_frame_base (<TODO: exprloc dump>)
  DW_AT_GNU_all_call_sites (true)
  DW_AT_name ("_start")
  DW_AT_decl_file (0x00000001)
  DW_AT_decl_line (11)
  DW_AT_prototyped (true)
  DW_AT_external (true)
    
2024-10-30T23:26:56.406070Z TRACE debug-info-transform: === End DIE at 0x00000026 (depth = 1):
DW_TAG_subprogram
  DW_AT_low_pc (symbol #1+0)
  DW_AT_high_pc (182)
  DW_AT_frame_base (<TODO: out exprloc dump>)
  DW_AT_GNU_all_call_sites (true)
  DW_AT_name ("_start")
  DW_AT_decl_file (FileId(1)>)
  DW_AT_decl_line (11)
  DW_AT_prototyped (true)
  DW_AT_external (true)
    
2024-10-30T23:26:56.406119Z TRACE debug-info-transform: === Begin DIE at 0x0000003d (depth = 2):
DW_TAG_variable
  DW_AT_name ("started")
  DW_AT_type (0x00000089)
  DW_AT_decl_file (0x00000001)
  DW_AT_decl_line (26)
  DW_AT_location (<TODO: exprloc dump>)
    
2024-10-30T23:26:56.406174Z TRACE debug-info-transform: === End DIE at 0x0000003d (depth = 2):
DW_TAG_variable
  DW_AT_name ("started")
  DW_AT_decl_file (FileId(1)>)
  DW_AT_decl_line (26)
    
2024-10-30T23:26:56.406204Z TRACE debug-info-transform: === Begin DIE at 0x00000055 (depth = 2):
DW_TAG_variable
  DW_AT_location (<TODO: loclist dump>)
  DW_AT_name ("r")
  DW_AT_decl_file (0x00000001)
  DW_AT_decl_line (43)
  DW_AT_type (0x0000008e)
    
2024-10-30T23:26:56.406359Z TRACE debug-info-transform: === End DIE at 0x00000055 (depth = 2):
DW_TAG_variable
  DW_AT_location (<TODO: out loclist dump>)
  DW_AT_name ("r")
  DW_AT_decl_file (FileId(1)>)
  DW_AT_decl_line (43)
    
2024-10-30T23:26:56.406392Z TRACE debug-info-transform: === Begin DIE at 0x00000064 (depth = 2):
DW_TAG_GNU_call_site
  DW_AT_abstract_origin (0x00000095)
  DW_AT_low_pc (00000036)
    
2024-10-30T23:26:56.406428Z TRACE debug-info-transform: === End DIE at 0x00000064 (depth = 2):
  Skipped as unreachable
    
2024-10-30T23:26:56.406456Z TRACE debug-info-transform: === Begin DIE at 0x0000006d (depth = 2):
DW_TAG_GNU_call_site
  DW_AT_abstract_origin (0x0000009c)
  DW_AT_low_pc (0000003c)
    
2024-10-30T23:26:56.406505Z TRACE debug-info-transform: === End DIE at 0x0000006d (depth = 2):
  Skipped as unreachable
    
2024-10-30T23:26:56.406541Z TRACE debug-info-transform: === Begin DIE at 0x00000076 (depth = 2):
DW_TAG_GNU_call_site
  DW_AT_abstract_origin (0x000000a7)
  DW_AT_low_pc (00000044)
    
2024-10-30T23:26:56.406588Z TRACE debug-info-transform: === End DIE at 0x00000076 (depth = 2):
  Skipped as unreachable
    
2024-10-30T23:26:56.406610Z TRACE debug-info-transform: === Begin DIE at 0x0000007f (depth = 2):
DW_TAG_GNU_call_site
  DW_AT_abstract_origin (0x000000ae)
  DW_AT_low_pc (00000055)
    
2024-10-30T23:26:56.406633Z TRACE debug-info-transform: === End DIE at 0x0000007f (depth = 2):
  Skipped as unreachable
    
2024-10-30T23:26:56.406650Z TRACE debug-info-transform: === Begin DIE at 0x00000089 (depth = 1):
DW_TAG_volatile_type
  DW_AT_type (0x0000008e)
    
2024-10-30T23:26:56.406696Z TRACE debug-info-transform: === End DIE at 0x00000089 (depth = 1):
DW_TAG_volatile_type
    
2024-10-30T23:26:56.406740Z TRACE debug-info-transform: === Begin DIE at 0x0000008e (depth = 1):
DW_TAG_base_type
  DW_AT_name ("int")
  DW_AT_encoding (DW_ATE_signed)
  DW_AT_byte_size (4)
    
2024-10-30T23:26:56.406805Z TRACE debug-info-transform: === End DIE at 0x0000008e (depth = 1):
DW_TAG_base_type
  DW_AT_name ("int")
  DW_AT_encoding (DW_ATE_signed)
  DW_AT_byte_size (4)
    
2024-10-30T23:26:56.406835Z TRACE debug-info-transform: === Begin DIE at 0x00000095 (depth = 1):
DW_TAG_subprogram
  DW_AT_name ("__wasm_call_ctors")
  DW_AT_decl_file (0x00000001)
  DW_AT_decl_line (6)
  DW_AT_prototyped (true)
  DW_AT_declaration (true)
  DW_AT_external (true)
    
2024-10-30T23:26:56.406865Z TRACE debug-info-transform: === End DIE at 0x00000095 (depth = 1):
  Skipped as unreachable

[cfallin]

Looks generally fine, thanks! I personally agree that this sort of tracing, included in checked-in source rather than ad-hoc as one debugs, is really useful when working out issues. So thanks for building this out.

A few thoughts below but nothing major!

[cfallin]

Looks good, thanks for the patience here!

[SingleAccretion]

removed this pull request from the merge queue due to failed status checks

Hmm, some quite odd breakage.

error: unused import: `EntityRef`
  --> cranelift/codegen/src/alias_analysis.rs:73:53
   |
73 | use cranelift_entity::{packed_option::PackedOption, EntityRef};
   |                                                     ^^^^^^^^^
   |
   = note: `-D unused-imports` implied by `-D warnings`
   = help: to override `-D warnings` add `#[allow(unused_imports)]`

error: unused variable: `data`
   --> cranelift/codegen/src/machinst/lower.rs:640:17
    |
640 |             let data = &self.f.dfg.insts[inst];
    |                 ^^^^ help: if this is intentional, prefix it with an underscore: `_data`
    |
    = note: `-D unused-variables` implied by `-D warnings`
    = help: to override `-D warnings` add `#[allow(unused_variables)]`

error: unused variable: `block`
   --> cranelift/codegen/src/machinst/lower.rs:877:9
    |
877 |         block: Block,
    |         ^^^^^ help: if this is intentional, prefix it with an underscore: `_block`

error: unused variable: `align`
   --> cranelift/codegen/src/machinst/buffer.rs:635:13
    |
635 |             align,
    |             ^^^^^ help: try ignoring the field: `align: _`

error: unused variable: `disasm`
  --> cranelift/codegen/src/isa/x64/mod.rs:82:21
   |
82 |         if let Some(disasm) = emit_result.disasm.as_ref() {
   |                     ^^^^^^ help: if this is intentional, prefix it with an underscore: `_disasm`

error: unused variable: `old`
  --> cranelift/codegen/src/isa/pulley_shared/inst/emit.rs:56:13
   |
56 |         let old = self.virtual_sp_offset;
   |             ^^^ help: if this is intentional, prefix it with an underscore: `_old`

error: unused variable: `value`
   --> cranelift/codegen/src/egraph.rs:535:18
    |
535 |             for (value, def) in self.func.dfg.values_and_defs() {
    |                  ^^^^^ help: if this is intentional, prefix it with an underscore: `_value`

error: unused variable: `i`
   --> cranelift/codegen/src/egraph.rs:538:38
    |
538 |                     ValueDef::Result(i, 0) => {
    |                                      ^ help: if this is intentional, prefix it with an underscore: `_i`

The following warnings were emitted during compilation:

warning: [email protected]: Failed to run `rustfmt` on ISLE-generated code: Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }
warning: [email protected]: Failed to run `rustfmt` on ISLE-generated code: Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }
warning: [email protected]: Failed to run `rustfmt` on ISLE-generated code: Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }
warning: [email protected]: Failed to run `rustfmt` on ISLE-generated code: Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }
warning: [email protected]: Failed to run `rustfmt` on ISLE-generated code: Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }
warning: [email protected]: Failed to run `rustfmt` on ISLE-generated code: Os { code: 32, kind: BrokenPipe, message: "Broken pipe" }

error: could not compile `cranelift-codegen` (lib) due to 8 previous errors