Steve Williams (Oct 10 2021 at 18:23): Steve Williams (Oct 10 2021 at 18:23):g:\dev\test>lldb.exe -- z:\dev\wasm\wasmtime\target\release\wasmtime.exe -g .\test.wasm
(lldb) target create "z:\\dev\\wasm\\wasmtime\\target\\release\\wasmtime.exe"
Current executable set to 'z:\dev\wasm\wasmtime\target\release\wasmtime.exe' (x86_64).
(lldb) settings set -- target.run-args "-g" ".\\test.wasm"
(lldb) b test.cpp:7
Breakpoint 1: no locations (pending).
WARNING: Unable to resolve breakpoint to any actual locations.
(lldb) r
Process 13668 launched: 'z:\dev\wasm\wasmtime\target\release\wasmtime.exe' (x86_64)
1 location added to breakpoint 1
Process 13668 stopped
Steve Williams (Oct 10 2021 at 18:26):when I query globals from the lldb API it seems I'm getting another copy of the locals. something's not quite right.
Steve Williams (Oct 10 2021 at 18:27):also tried
fr v -g
same result.
Steve Williams (Oct 10 2021 at 18:47):Tried native equivalent as sanity check.
correct lldb command : fr v -g
(lldb) b test.cpp:7
Breakpoint 1: where = test`Thing::Thing(int) + 15 at test.cpp:8:13, address = 0x00000000004011ef
(lldb) r
Process 10008 launched: '/home/x/dev/test/test' (x86_64)
Process 10008 stopped
Steve Williams (Oct 11 2021 at 08:20):Into the code :
utils.rs : append_vmctx_info generates DWARF DW_TAG_variable which should expose globals, if any.
That calls build_with_locals in expression.rs to form a list of things to add to the dwarf data.
An inspect of build_with_locals in expression.rs seems to show locals only are built - no mention of globals.
... which is what we're seeing in the debugger.
Hence initial conclusion is : wasmtime debug mode emits only locals. Global variable export implementation needs to be added.
Disclaimer: rust noob, dwarf noob :)
If I've missed anything, misunderstood, etc. correction welcome. First reading of the code.
Steve Williams (Oct 11 2021 at 08:39):Severity: High. Standard debugging pipeline not complete until this has been resolved.
Steve Williams (Oct 11 2021 at 08:49):we've got parse_global_section in wasmtime\cranelift\wasm\src\sections_translator.rs
perhaps can work from that.
Steve Williams (Oct 11 2021 at 09:34):https://github.com/bytecodealliance/wasmtime/issues/3439
Steve Williams (Oct 11 2021 at 10:43):(lldb) fr v -g -l
to print globals only, apparently. (globals, no locals).
Steve Williams (Oct 11 2021 at 20:25):pushing my luck, but if I could get a little assistance from a senior dev on this, it'd be appreciated. I'll stumble through it eventually but someone already familiar with rust/dwarf/jit interface could likely close it faster with less chance of errors. not really a noob task. maybe that's a cop out.
then we have a solid debug pipeline afaik. needs more testing but that's the last issue I'm aware of.
Steve Williams (Oct 11 2021 at 20:58):lldb issue - teemperor is reviewer. we get on ok, so maybe I have to throw my lldb is the test argument over there :)
Steve Williams (Oct 11 2021 at 21:05):lldb aside, continued. I guess they want something like this to test it.
https://llvm.org/docs/DebuggingJITedCode.html
then its all within their tech tree. on it when globals issue resolved. essentials first.
Steve Williams (Oct 12 2021 at 11:46):k, we get the rust noob version :) failing at first fence :) can't inspect with debugger coz stuff that's being injected is 2 debuggers deep (maybe lldb intercept can be disabled), so its logging. have log on screen with RUST_LOG=trace
far too much I don't want to see & doesn't seem to be a filter other than knowing specific module you want to monitor which I don't yet.
put following in wasmtime\crates\cranelift\src\debug\transform\utils.rs
warn!("TODO: inject_globals_here.");
// Build vmctx_die's DW_TAG_subprogram for set method
Won't even compile :( How do I place logging there plz. Can implement custom file logger if I need to, but first step is to ask if there's a standard way I can log from there. Input welcome :)
Steve Williams (Oct 12 2021 at 11:58):seems a simple println works from there :) progress. if at glacial pace.
Steve Williams (Oct 12 2021 at 12:32):shouldn't be there. learning my way around.
Steve Williams (Oct 12 2021 at 13:02):generate_simulated_dwarf is entrypoint.
Steve Williams (Oct 12 2021 at 13:12):DebugInfoData doesn't seem to contain globals. only locals.
Steve Williams (Oct 12 2021 at 15:00):DebugPubNames/Types is globals ?
Steve Williams (Oct 12 2021 at 16:01):to answer my own q previously, dwarf 4 is generated. says so in transform_dwarf - irrelevant aside.
Steve Williams (Oct 12 2021 at 16:33):only a slight oversight :)
Steve Williams (Oct 12 2021 at 16:50):there's a GlobalVariable thing I've just come across in cranelift.
is that set incorrectly somehow & hence responsible for behaviour we're observing ?
Steve Williams (Oct 12 2021 at 17:17):.
Steve Williams (Oct 12 2021 at 18:24):make_global in func_environ.rs is called a few times with apparently zero index each time.
Steve Williams (Oct 12 2021 at 18:25):but as that's passed a function, I don't see how it's globals. so confused.com
Steve Williams (Oct 12 2021 at 18:28):to cover statics maybe.
Steve Williams (Oct 12 2021 at 18:30):whatever it is, same index each time seems odd. disclaimer: don't understand the code yet, might be fine.
Steve Williams (Oct 12 2021 at 18:42):that's driven by Operator::GlobalSet which apparently is called thru set_global which doesn't show up in a source tree search so still confused.
Steve Williams (Oct 12 2021 at 18:44):seems right place as there's Operator::LocalSet there too. zero index every time sounding fishy, but I don't know how that code is driven.
Steve Williams (Oct 12 2021 at 18:46):Dropped in
println!("Operator::GlobalSet {} ", global_index);
0 each time.
Steve Williams (Oct 12 2021 at 18:48):not called thru set_global, misread. that's some kind of built in I dont understand as rust noob.
Steve Williams (Oct 12 2021 at 18:49):don't know what calls that stuff.
Steve Williams (Oct 12 2021 at 18:50):does rust have an diagnostics magic I can drop in to say who called me, plz ? can't run debugger there without modding lldb for passthrough. will skip that if possible.
Steve Williams (Oct 12 2021 at 18:50):actually, lldb might get me that on linux. native debug broken on windows bcoz pe/pdb code incomplete.
Steve Williams (Oct 12 2021 at 18:59):from my simple test.cpp program, I get : https://pastebin.com/rNE64Xa9
GlobalSet index always 0
Q1: What's calling that ?
Q2: Should it always be 0 ? Does that sound right ?
Steve Williams (Oct 12 2021 at 19:35):Operator::LocalSet 0
Operator::LocalSet 2
Operator::LocalSet 1
Operator::LocalSet 0
Operator::LocalSet 0
Operator::LocalSet 1
Operator::LocalSet 2
Operator::GlobalSet 0
Operator::GlobalSet 0
Operator::LocalSet 2
Process 16832 stopped
cranelift_wasm::code_translator::translate_operator::h8f0891072d4134db + 68245
wasmtimecranelift_wasm::code_translator::translate_operator::h8f0891072d4134db:cranelift_wasm::code_translator::translate_operator::h8f0891072d4134db + 68245
wasmtimecranelift_wasm::code_translator::translate_operator::h8f0891072d4134db:with :
Operator::GlobalSet { global_index } => {
println!("Operator::GlobalSet {} ", global_index);
unsafe { std::intrinsics::breakpoint(); }
index always 0 sounds wrong to me, but still getting head around what's going on.
Steve Williams (Oct 12 2021 at 19:56):added second global to test program to cover case where that index should always be zero. with 2 globals it can't be. I think.
but still always zero. so perhaps root cause.
Steve Williams (Oct 12 2021 at 19:57):& even if we only get 1, we're not seeing it at the other end, so still confused.
Steve Williams (Oct 12 2021 at 20:05):behaviour explained by incomplete code. so maybe that's just how it is. global index bug, not noticed bcoz globals not translated.
Steve Williams (Oct 12 2021 at 20:29):Added some more debug.
In GlobalSet
+ println!(" builder.ins().store flags:{} val:{} addr:{} offset:{}", flags, val, addr, offset);
builder.ins().store(flags, val, addr, offset);
dunno if you can do that, but anyway. seems a little more variety so perhaps ok. unsure where that ends up yet.
Operator::GlobalSet 0
Operator::GlobalSet 0
Operator::GlobalSet 0
builder.ins().store flags: notrap aligned val:v10 addr:v11 offset:+176
builder.ins().store flags: notrap aligned val:v10 addr:v11 offset:+176
Operator::GlobalSet 0
builder.ins().store flags: notrap aligned val:v10 addr:v11 offset:+176
builder.ins().store flags: notrap aligned val:v7 addr:v8 offset:+176
Operator::GlobalSet 0
builder.ins().store flags: notrap aligned val:v34 addr:v35 offset:+176
Operator::GlobalSet 0
Operator::GlobalSet 0
builder.ins().store flags: notrap aligned val:v26 addr:v27 offset:+176
builder.ins().store flags: notrap aligned val:v34 addr:v35 offset:+176
Operator::GlobalSet 0
builder.ins().store flags: notrap aligned val:v93 addr:v94 offset:+176
Operator::GlobalSet 0
builder.ins().store flags: notrap aligned val:v8 addr:v9 offset:+176
Operator::GlobalSet 0
builder.ins().store flags: notrap aligned val:v8 addr:v9 offset:+176
Operator::GlobalSet 0
builder.ins().store flags: notrap aligned val:v53 addr:v54 offset:+176
Operator::GlobalSet 0
builder.ins().store flags: notrap aligned val:v2316 addr:v2317 offset:+176
Steve Williams (Oct 12 2021 at 20:36):made one a float, everything still comes thru as i32. so not a clue what's going on yet.
Steve Williams (Oct 12 2021 at 20:36):silence is weird. don't some folks know how this stuff works ?
Steve Williams (Oct 13 2021 at 06:42):switched from cpp test to absolute basic c test.
test.c
float my_global_float = 2.5f;
int main() {
return (int)(my_global_float);
}
nothing coming thru, so the globals I was seeing were probably runtime built-in stuff.
Steve Williams (Oct 13 2021 at 06:44):& dwarf-dump:
.\test.wasm: file format WASM
.debug_info contents:
0x00000000: Compile Unit: length = 0x0000005a, format = DWARF32, version = 0x0004, abbr_offset = 0x0000, addr_size = 0x04 (next unit at 0x0000005e)
0x0000000b: DW_TAG_compile_unit
DW_AT_producer ("clang version 11.0.0 (https://github.com/llvm/llvm-project 176249bd6732a8044d457092ed932768724a6f06)")
DW_AT_language (DW_LANG_C99)
DW_AT_name ("test.c")
DW_AT_stmt_list (0x00000000)
DW_AT_comp_dir ("g:\\dev\\test")
DW_AT_low_pc (0x0000002f)
DW_AT_high_pc (0x000000a4)
0x00000026: DW_TAG_variable
DW_AT_name ("my_global_float")
DW_AT_type (0x00000037 "float")
DW_AT_external (true)
DW_AT_decl_file ("g:\dev\test\.\test.c")
DW_AT_decl_line (1)
DW_AT_location (DW_OP_addr 0x400)
0x00000037: DW_TAG_base_type
DW_AT_name ("float")
DW_AT_encoding (DW_ATE_float)
DW_AT_byte_size (0x04)
0x0000003e: DW_TAG_base_type
DW_AT_name ("int")
DW_AT_encoding (DW_ATE_signed)
DW_AT_byte_size (0x04)
0x00000045: DW_TAG_subprogram
DW_AT_low_pc (0x0000002f)
DW_AT_high_pc (0x000000a4)
DW_AT_frame_base (DW_OP_WASM_location 0x0 0x2, DW_OP_stack_value)
DW_AT_name ("main")
DW_AT_decl_file ("g:\dev\test\.\test.c")
DW_AT_decl_line (3)
DW_AT_type (0x0000003e "int")
DW_AT_external (true)
0x0000005d: NULL
Steve Williams (Oct 13 2021 at 07:10):that test too simple apparently, even with opts off its eliminated global somehow.
so went with test.c :
float my_global_float = 2.5f;
float my_func()
{
return my_global_float;
}
int main()
{
return (int) my_func();
}
which generates this :
GlobalVariable::Memory gv:gv3 ty:i32
builder.ins().store flags: notrap aligned val:v9 addr:v10 offset:+96
Operator::GlobalSet 0
GlobalVariable::Memory gv:gv3 ty:i32
builder.ins().store flags: notrap aligned val:v25 addr:v26 offset:+96
Steve Williams (Oct 13 2021 at 07:11):2 global references, both i32. can't see how that's right.
Steve Williams (Oct 13 2021 at 08:01):workaround: to inspect globals in debugger, load a reference into a local & inspect that. compile works, debug currently has a gap.
Steve Williams (Oct 13 2021 at 12:09):yury - you're quiet :) any advice ?
Steve Williams (Oct 13 2021 at 12:13):@mozilla - can we get a tiny bit of yury time on this, please (if he's willing) ? its quite hard.
Steve Williams (Oct 13 2021 at 12:14):fixing this effectively unlocks wasmtime as far as I can see. aside from exceptions, which can wait (our use case anyway), we can go into production with this once debugging is solid. arguably now, though prefer it not to be wonky.
Steve Williams (Oct 13 2021 at 12:15):we run with wasmtime in production, hopefully prove it solid, then it drops into firefox later. everyone wins.
Steve Williams (Oct 13 2021 at 12:21):last thing stopping this being wasmtime 1.0 unless there are any other mvp gaps I'm unaware of.
Steve Williams (Oct 13 2021 at 12:26):& if I'm understanding correctly, appears gap is all the way into cranelift which isn't parsing debug globals correctly. perhaps requires multiple seniors to resolve.
Steve Williams (Oct 13 2021 at 12:34):even further into basics. can we run a standalone cranelift test to determine what its doing with debug parsing of globals. surprised this hasn't been tested, but its like that with all bugs - the thing you didn't think about.
Steve Williams (Oct 13 2021 at 12:58):to get a sane debug/devel environment for this, seems we need a test program that loads a wasm then calls build_artifacts on it.
that should detect & reference globals.
Steve Williams (Oct 13 2021 at 15:59):all this : https://docs.wasmtime.dev/api/wasmtime/struct.Global.html
so perhaps gap is smaller than feared. we'll see :)
can step thru a rust test app now have decoupled from lldb so can see what's going on.
Steve Williams (Oct 13 2021 at 16:09):A little progress.
Put following wasmtime/rust API test program together, based on introductory sample.
test.c
float my_global=5;
void mytest()
{
my_global = 3;
}
int main() {
int i = my_global;
return i;
}
The global is located :)
Steve Williams (Oct 13 2021 at 17:46):so ... ummm ... cranelift exposes, so dwarf conversion issue. if only we had an expert on that we could borrow for an hour or two with many beers owed :)
Steve Williams (Oct 13 2021 at 17:51):could be an export issue. had to export-all for this test app, haven't done so previously so will check if the issue.
Steve Williams (Oct 13 2021 at 17:56):is that the issue ? is cranelift only passing on exported globals ?
that's valid for standard runtime but not for debug mode. debug mode should get everything.
Steve Williams (Oct 13 2021 at 17:59):my test app has debug mode set.
Steve Williams (Oct 13 2021 at 18:15):early in testing but cranelift seems to propagate all with clang -Wl,--export-all
without it, not getting even the function.
so export-all appears to be cranelift workaround. whether it goes anywhere from there, don't yet know.
Steve Williams (Oct 13 2021 at 18:16):this needs verifying. to avoid us going off on wrong tangents.
Steve Williams (Oct 13 2021 at 18:26):bit early as still not 100% sure but anyhow, here's test files : http://advance-software.com/misc/wasmtime_test.zip
wasm shell scipts a bit off as resolving on windows, but is simple stuff. a hardwired path to fix up.
Steve Williams (Oct 13 2021 at 18:26):extract same level as wasmtime, not inside that tree.
Steve Williams (Oct 13 2021 at 18:30):path is Module::from_file in main.rs to where your test wasm is.
Steve Williams (Oct 14 2021 at 11:05):weird. if I export anything, can't get lldb to hit a breakpoint. so workaround won't work, so gotta figure out why its doing that.
Steve Williams (Oct 14 2021 at 14:04):looking at wasmtime\crates\environ\src\module_environ.rs
Payload::ExportSection(exports) - noticing my global ends up in there.
next up, see if I can follow it into Payload::GlobalSection(globals)
& then figure out how we hook into that so we don't have export constraint.
Steve Williams (Oct 14 2021 at 14:10):still no fan of rust. looking forwards to getting back to c++ :)
Steve Williams (Oct 14 2021 at 15:00):any fixes for variable is optimized away (visual studio, rust debugging), following "cargo build" which is debug config, plz.
the friction to new amazing system is bits are still wonky.
Steve Williams (Oct 14 2021 at 15:09):https://www.reddit.com/r/rust/comments/fr7s7f/whats_the_latest_on_overoptimization_in_debug/
seems a known issue. an aside. can work around it. will use my own debugger gui soon :)
Steve Williams (Oct 14 2021 at 16:00):in build_artifacts , engine.config().tunables
parse_wasm_debuginfo is false. that seems wrong.
Steve Williams (Oct 14 2021 at 16:07):experimental - might not be this, we'll see.
pub fn debug_info(&mut self, enable: bool) -> &mut Self {
self.tunables.generate_native_debuginfo = enable;
// ADV_SW_PATCH[experimental]:
// Required so we are able to emit globals - have to parse them so we know what to emit :)
self.tunables.parse_wasm_debuginfo = enable;
self
}
not seeing test app global float getting parsed even with that. think there's implementation missing but don't fully comprehend the parser yet.
Steve Williams (Oct 14 2021 at 16:38):we've got this thing :
use wasmparser::{
self, Data, DataKind, DataSectionReader, Element, ElementItem, ElementItems, ElementKind,
ElementSectionReader, Export, ExportSectionReader, ExternalKind, FunctionSectionReader,
GlobalSectionReader, GlobalType, ImportSectionEntryType, ImportSectionReader,
MemorySectionReader, MemoryType, NameSectionReader, Naming, Operator, TableSectionReader,
TableType, TagSectionReader, TagType, TypeDef, TypeSectionReader,
};
Steve Williams (Oct 14 2021 at 16:40):& this which we want registering in .debug_info section.
0x00000026: DW_TAG_variable [2]
DW_AT_name [DW_FORM_strp] ( .debug_str[0x00000078] = "my_global")
DW_AT_type [DW_FORM_ref4] (cu + 0x0037 => {0x00000037} "float")
DW_AT_external [DW_FORM_flag_present] (true)
DW_AT_decl_file [DW_FORM_data1] ("g:\dev\test\.\test.c")
DW_AT_decl_line [DW_FORM_data1] (1)
DW_AT_location [DW_FORM_exprloc] (DW_OP_addr 0x400)
Steve Williams (Oct 14 2021 at 16:40):I'm not clear if that should run through GlobalSectionReader or TagSectionReader.
Steve Williams (Oct 14 2021 at 16:41):or some other.
Steve Williams (Oct 14 2021 at 16:46):slow, but I think we're making progress. not so scary now, just working thru it.
Steve Williams (Oct 14 2021 at 17:59):debug_info section containing the variable we want is handled via register_dwarf_section, via Payload::CustomSection.
Steve Williams (Oct 14 2021 at 18:09):that ends up in ModuleEnvironment : self.results[0].debuginfo.dwarf.debug_info.debug_info_section
& isn't parsed - just reference to the section location & length - at that point anyway.
I guess we follow that up to the emit. unsure how we morph from wasm dwarf to target dwarf but it must be in there somewhere as the rest does it.
Steve Williams (Oct 14 2021 at 18:13):has_unparsed_debuginfo flag is badly named. the debuginfo section isn't parsed, its just registered.
Steve Williams (Oct 14 2021 at 18:28):so ... we can parse the debug info section, even if it means writing that code from scratch, we can somehow map from wasm addresses to target addresses & we can emit dwarf. so we can do this :)
Steve Williams (Oct 14 2021 at 18:39):& we've got this thing in use already : https://github.com/gimli-rs/gimli
Loc is terrible abbreviation in that as initially thought it meant local when it in fact means location. code doesn't run faster with shorter variable names :) just write out the whole word.
Steve Williams (Oct 14 2021 at 19:17):can gimli decode debuginfo section to extract global DW_TAG_variable entities ?
if not, we can implement as necessary.
Steve Williams (Oct 14 2021 at 19:17):https://github.com/gimli-rs/gimli
Steve Williams (Oct 14 2021 at 19:19)::)
https://github.com/gimli-rs/gimli/blob/master/examples/simple_line.rs
Steve Williams (Oct 14 2021 at 19:20):that's me on hold until next week with this as real life calls, but feel free to carry on if the mood takes anyone :)
Steve Williams (Oct 14 2021 at 19:30):looks like you need to load & parse each top level DW_TAG_variable yourself, but that's not so hard.
Steve Williams (Oct 14 2021 at 19:32):function statics are also technically globals but assuming function locals deliver those. should verify.
Steve Williams (Oct 14 2021 at 19:34):& that load/parse should probably end up in gimli so its there for the next guy.
Steve Williams (Oct 15 2021 at 11:10):back to it, weekend off cancelled. this needs nailing anyway.
Steve Williams (Oct 15 2021 at 12:02):if a global is at some memory location in input wasm, is it at same location in emitted wasm ? that'd make it easy & can't think why it'd need to be different unless there are different alignment constraints.
Steve Williams (Oct 15 2021 at 12:18):emit_dwarf takes a debug_info so if I can figure out where the globals section is going, it feeds into that & almost done.
Steve Williams (Oct 15 2021 at 12:35):have no idea what GlobalSection stuff is all about. our global doesn't end up there. seems to be used for some kind of built ins only.
Steve Williams (Oct 15 2021 at 12:36):this code is really light on comments. too much so imo.
Last updated: Oct 23 2024 at 20:03 UTC