nondeterministic dwarf

[fangism]

We've observed some local build nondeterminism in clang outputs.

The following command produces different .o outputs (with some non-zero probability).

$ ../../prebuilt/third_party/clang/linux-x64/bin/clang++ -MD -MF host_x64-asan-ubsan/obj/src/storage/minfs/libminfs.vnode.cc.o.d -DTOOLCHAIN_VERSION=AD59JKqO1TWgxp7uA0Fq99aIrVCXG2i4HShWi6sFFV8C -DFUCHSIA_API_LEVEL=13 -D_LIBCPP_DISABLE_VISIBILITY_ANNOTATIONS -D_LIBCPP_REMOVE_TRANSITIVE_INCLUDES -I../.. -Ihost_x64-asan-ubsan/gen -I../../zircon/system/ulib/zx/include -I../../sdk/lib/fit/include -I../../sdk/lib/stdcompat/include -I../../zircon/system/public -I../../src/zircon/lib/zircon/include -Ifidling/gen/zircon/vdso/zx/zither/legacy_syscall_cdecl -I../../sdk/lib/fit-promise/include -I../../zircon/system/ulib/fbl/include -I../../zircon/system/ulib/storage/buffer/include -Ifidling/gen/sdk/fidl/fuchsia.hardware.block.driver/fuchsia.hardware.block.driver/banjo/cpp -Ibanjoing/gen -Ifidling/gen/sdk/fidl/fuchsia.hardware.block.driver/fuchsia.hardware.block.driver/banjo/c -I../../src/lib/ddk/include -I../../sdk/lib/driver/runtime/include -I../../zircon/system/ulib/async/include -I../../sdk/lib/zbi-format/include -I../../zircon/system/ulib/ddk-platform-defs/include -I../../zircon/system/ulib/syslog/include -Ifidling/gen/sdk/fidl/fuchsia.hardware.block/fuchsia.hardware.block/banjo/c -Ifidling/gen/sdk/fidl/fuchsia.storage.metrics/fuchsia.storage.metrics/banjo/c -Ifidling/gen/sdk/fidl/fuchsia.unknown/fuchsia.unknown/banjo/c -Ifidling/gen/zircon/vdso/zx/zx/banjo/c -I../../src/lib/ddktl/include -I../../sdk/lib/fidl/cpp/wire/include -I../../sdk -Ihost_x64-asan-ubsan/gen/sdk -I../../sdk/lib/fidl_base/include -Ifidling/gen/sdk/fidl/fuchsia.hardware.block/fuchsia.hardware.block/banjo/cpp -Ifidling/gen/sdk/fidl/fuchsia.storage.metrics/fuchsia.storage.metrics/banjo/cpp -Ifidling/gen/sdk/fidl/fuchsia.unknown/fuchsia.unknown/banjo/cpp -Ifidling/gen/zircon/vdso/zx/zx/banjo/cpp -I../../zircon/system/ulib/storage/operation/include -I../../zircon/system/ulib/zircon-internal/include -I../../sdk/lib/fdio/include -I../../src/storage/gpt/include -Ifidling/gen/sdk/fidl/fuchsia.device/fuchsia.device/cpp -Ifidling/gen/sdk/fidl/fuchsia.logger/fuchsia.logger/cpp -Ifidling/gen/sdk/fidl/fuchsia.diagnostics/fuchsia.diagnostics/cpp -Ifidling/gen/sdk/fidl/fuchsia.mem/fuchsia.mem/cpp -Ifidling/gen/sdk/fidl/fuchsia.hardware.block/fuchsia.hardware.block/cpp -Ifidling/gen/sdk/fidl/fuchsia.storage.metrics/fuchsia.storage.metrics/cpp -Ifidling/gen/sdk/fidl/fuchsia.unknown/fuchsia.unknown/cpp -I../../zircon/third_party/ulib/lz4/include -I../../src/storage/lib/disk_inspector/include -I../../zircon/system/ulib/bitmap/include -I../../zircon/system/ulib/range/include -I../../zircon/third_party/ulib/cksum/include -I../../zircon/third_party/ulib/safemath/include -fcolor-diagnostics -fcrash-diagnostics-dir=clang-crashreports -fcrash-diagnostics=all -ffp-contract=off --sysroot=../../prebuilt/third_party/sysroot/linux --target=x86_64-unknown-linux-gnu -ffile-compilation-dir=. -no-canonical-prefixes -fdata-sections -ffunction-sections -O1 -gdwarf-5 -Xclang -debug-info-kind=constructor -g3 -Wall -Wextra -Wconversion -Wextra-semi -Wimplicit-fallthrough -Wnewline-eof -Wstrict-prototypes -Wwrite-strings -Wno-sign-conversion -Wno-unused-parameter -Wnonportable-system-include-path -Wno-type-limits -fvisibility=hidden -Werror -Wno-error=deprecated-declarations -Wa,--fatal-warnings --sysroot=../../prebuilt/third_party/sysroot/linux --target=x86_64-unknown-linux-gnu -fPIE -mllvm -asan-use-private-alias=1 -fno-sanitize-address-use-odr-indicator -fsanitize=address -fno-omit-frame-pointer -fsanitize=undefined -fno-sanitize=vptr -fvisibility-inlines-hidden -stdlib=libc++ -std=c++17 -fno-exceptions -stdlib=libc++ -c ../../src/storage/minfs/vnode.cc -o host_x64-asan-ubsan/obj/src/storage/minfs/libminfs.vnode.cc.o

A recent local experiment took about 40 attempts before a difference was observed.

A dwarfdump diff looks like:

$ diff -u <(../../prebuilt/third_party/clang/linux-x64/bin/llvm-dwarfdump -a host_x64-asan-ubsan/obj/src/storage/minfs/libminfs.vnode.cc.o) <(../../prebuilt/third_party/clang/linux-x64/bin/llvm-dwarfdump -a host_x64-asan-ubsan/obj/src/storage/minfs/tmp-libminfs.vnode.cc.o)

--- /dev/fd/63	2023-07-17 18:55:26.925479892 +0000
+++ /dev/fd/62	2023-07-17 18:55:26.925479892 +0000
@@ -1,4 +1,4 @@
-host_x64-asan-ubsan/obj/src/storage/minfs/libminfs.vnode.cc.o:	file format elf64-x86-64
+host_x64-asan-ubsan/obj/src/storage/minfs/tmp-libminfs.vnode.cc.o:	file format elf64-x86-64
 
 .debug_abbrev contents:
 Abbrev table for offset: 0x00000000
@@ -54937,7 +54937,7 @@
                        [0x000000000000045f, 0x000000000000047b))
 
 0x0000fd7f:         DW_TAG_variable
-                      DW_AT_location	(indexed (0x1c) loclist = 0x00000a67: 
+                      DW_AT_location	(indexed (0x1b) loclist = 0x00000a3d: 
                          [0x00000000000002cc, 0x00000000000002d7): DW_OP_breg14 R14+0, DW_OP_convert (0x00000030) "DW_ATE_unsigned_64", DW_OP_convert (0x00000035) "DW_ATE_unsigned_32", DW_OP_stack_value, DW_OP_piece 0x4, DW_OP_breg14 R14+0, DW_OP_constu 0x20, DW_OP_shr, DW_OP_convert (0x00000030) "DW_ATE_unsigned_64", DW_OP_convert (0x00000035) "DW_ATE_unsigned_32", DW_OP_stack_value, DW_OP_piece 0x4
                          [0x000000000000046d, 0x000000000000047b): DW_OP_breg14 R14+0, DW_OP_convert (0x00000030) "DW_ATE_unsigned_64", DW_OP_convert (0x00000035) "DW_ATE_unsigned_32", DW_OP_stack_value, DW_OP_piece 0x4, DW_OP_breg14 R14+0, DW_OP_constu 0x20, DW_OP_shr, DW_OP_convert (0x00000030) "DW_ATE_unsigned_64", DW_OP_convert (0x00000035) "DW_ATE_unsigned_32", DW_OP_stack_value, DW_OP_piece 0x4)
                       DW_AT_name	("status")
@@ -55077,7 +55077,7 @@
                   DW_AT_high_pc	(0x00000000000004c3)
 
 0x0000fe2a:       DW_TAG_variable
-                    DW_AT_location	(indexed (0x1b) loclist = 0x00000a3d: 
+                    DW_AT_location	(indexed (0x1c) loclist = 0x00000a8e: 
                        [0x00000000000004bd, 0x00000000000004c3): DW_OP_breg14 R14+0, DW_OP_convert (0x00000030) "DW_ATE_unsigned_64", DW_OP_convert (0x00000035) "DW_ATE_unsigned_32", DW_OP_stack_value, DW_OP_piece 0x4, DW_OP_breg14 R14+0, DW_OP_constu 0x20, DW_OP_shr, DW_OP_convert (0x00000030) "DW_ATE_unsigned_64", DW_OP_convert (0x00000035) "DW_ATE_unsigned_32", DW_OP_stack_value, DW_OP_piece 0x4)
                     DW_AT_name	("status")
                     DW_AT_decl_file	("./../../src/storage/minfs/vnode.cc")
@@ -73993,7 +73993,7 @@
 0x000009cf
 0x00000a00
 0x00000a31
-0x00000a5b
+0x00000a82
 0x00000aac
 0x00000ad6
 0x00000b00
@@ -74533,13 +74533,13 @@
 
 0x00000a3d: 
             DW_LLE_base_addressx   (0x0000000000000028)
-            DW_LLE_offset_pair     (0x00000000000004bd, 0x00000000000004c3): DW_OP_breg14 R14+0, DW_OP_convert 0x30, DW_OP_convert 0x35, DW_OP_stack_value, DW_OP_piece 0x4, DW_OP_breg14 R14+0, DW_OP_constu 0x20, DW_OP_shr, DW_OP_convert 0x30, DW_OP_convert 0x35, DW_OP_stack_value, DW_OP_piece 0x4
-
-0x00000a67: 
-            DW_LLE_base_addressx   (0x0000000000000028)
             DW_LLE_offset_pair     (0x00000000000002cc, 0x00000000000002d7): DW_OP_breg14 R14+0, DW_OP_convert 0x30, DW_OP_convert 0x35, DW_OP_stack_value, DW_OP_piece 0x4, DW_OP_breg14 R14+0, DW_OP_constu 0x20, DW_OP_shr, DW_OP_convert 0x30, DW_OP_convert 0x35, DW_OP_stack_value, DW_OP_piece 0x4
             DW_LLE_offset_pair     (0x000000000000046d, 0x000000000000047b): DW_OP_breg14 R14+0, DW_OP_convert 0x30, DW_OP_convert 0x35, DW_OP_stack_value, DW_OP_piece 0x4, DW_OP_breg14 R14+0, DW_OP_constu 0x20, DW_OP_shr, DW_OP_convert 0x30, DW_OP_convert 0x35, DW_OP_stack_value, DW_OP_piece 0x4
 
+0x00000a8e: 
+            DW_LLE_base_addressx   (0x0000000000000028)
+            DW_LLE_offset_pair     (0x00000000000004bd, 0x00000000000004c3): DW_OP_breg14 R14+0, DW_OP_convert 0x30, DW_OP_convert 0x35, DW_OP_stack_value, DW_OP_piece 0x4, DW_OP_breg14 R14+0, DW_OP_constu 0x20, DW_OP_shr, DW_OP_convert 0x30, DW_OP_convert 0x35, DW_OP_stack_value, DW_OP_piece 0x4
+
 0x00000ab8: 
             DW_LLE_base_addressx   (0x0000000000000028)
             DW_LLE_offset_pair     (0x000000000000042f, 0x000000000000043b): DW_OP_breg14 R14+0, DW_OP_convert 0x30, DW_OP_convert 0x35, DW_OP_stack_value, DW_OP_piece 0x4, DW_OP_breg14 R14+0, DW_OP_constu 0x20, DW_OP_shr, DW_OP_convert 0x30, DW_OP_convert 0x35, DW_OP_stack_value, DW_OP_piece 0x4

llvm-nondet.zip

Attachment contains:

• vnode.ii (from --save-temps)
• libminfs.vnode.cc.o
• tmp-libminfs.vnode.cc.o (saved copy of the first run)

[fangism]

It was pointed out to me that SectionRanges uses a MapVector keyed on pointers:

llvm-project/llvm/lib/CodeGen/AsmPrinter/DwarfDebug.cpp

Line 2831 in 92f4bf2

MapVector<const MCSection *, std::vector<decltype(&*R.begin())>> SectionRanges;

So if those are coming from the allocator, that could explain the nondeterministic ordering in the output.

[llvmbot]

@llvm/issue-subscribers-debuginfo

[MaskRay]

https://llvm.org/docs/ProgrammersManual.html#llvm-adt-mapvector-h MapVector guarantees the iteration order.

I have run while fclang -c -g -fsanitize=address -fvisibility-inlines-hidden -O vnode.ii -o 1.o -w && cmp 0.o 1.o; do :; done for half an hour and cannot reproduce the issue.

[pogo59]

-host_x64-asan-ubsan/obj/src/storage/minfs/libminfs.vnode.cc.o:	file format elf64-x86-64
+host_x64-asan-ubsan/obj/src/storage/minfs/tmp-libminfs.vnode.cc.o:	file format elf64-x86-64

This has the feel of a problem renaming the .o file,

[fangism]

-host_x64-asan-ubsan/obj/src/storage/minfs/libminfs.vnode.cc.o:	file format elf64-x86-64
+host_x64-asan-ubsan/obj/src/storage/minfs/tmp-libminfs.vnode.cc.o:	file format elf64-x86-64

This has the feel of a problem renaming the .o file,

Ignore the difference in the file name in the diff, that's just from the dwarfdump tool. The other difference is significant.

[jmorse]

I haven't managed to replicate this after a few hundred runs. Looking at the difference, it looks like the position of two sets of entries in .debug_loclists have swapped, which I suppose is the kind of thing you'd expect to see from a nondeterminism bug. The two variables that these swap between are identically named, in sibling DW_TAG_lexical_block's, which is slightly suspicious. I don't have a smoking gun.

[ilovepi]

I think this may be an issue related to this fixme:

llvm-project/llvm/lib/CodeGen/AsmPrinter/DwarfDebug.cpp

Line 1139 in ca31f82

// FIXME: Come up with a more comprehensive comparator so

. @dwblaikie @chbessonova Do either of you have any thoughts on how to improve the comparison?

As an FYI, I didn't get it to trigger reliably until I added a lot of print statements trying to figure out what was happening. That seems to have perturbed this behavior a bit more reliably for me. I doubt that's much help, but maybe triggering the allocator a bit more will make this easier to reproduce for others.

[dwblaikie]

Looks like this FIXME was added here: 48e7549 / https://reviews.llvm.org/D38830 (@efriedma-quic / @adrian-prantl )

But it'd be good to get a more reduced test case (I know nondeterminism is hard to isolate - could see if LLVM's reverse iteration helps force the failure (eg: does it fail reliably/is there usually a difference between a forward and reverse iteration build of llvm?)) would be good to be more certain of whether we're barking up the wrong tree, etc.

[ilovepi]

I normally build w/ reverse iteration locally after being bit by that before, but it doesn't seem to help so much in this case.
Also, after some more thought/digging I realized that all uses of llvm::sort are randomized under EXPENSIVE_CHECKS, so a bad behavior should show up pretty reliably in CI. That makes me a bit concerned that I've misattributed the issue, but I'm not 100% certain.

Right now, my best guess is that one of the inputs used to generate the location list is somehow coming out in a slightly different order, but I haven't managed to track that to something more helpful. TBH I'm pretty confused. It seems that allocations perturb the behavior, but other than that I can't say much.

As for reducing ... any suggestions on how to do that in the non-determinism case? The trouble I've had so far is that I can't reliably find a reasonable iteration limit to use w/ either creduce, bugpoint, or llvm-reduce. Suggestions would be very welcome.

[dwblaikie]

Also, after some more thought/digging I realized that all uses of llvm::sort are randomized under EXPENSIVE_CHECKS, so a bad behavior should show up pretty reliably in CI. That makes me a bit concerned that I've misattributed the issue, but I'm not 100% certain.

Hmm, that seems unfortunate - got a pointer to that code that causes the randomization? Perhaps we can add something to llvm::sort to more deterministically perturb things - like reversing the equivalent elements, rather than randomizing them.

As for reducing ... any suggestions on how to do that in the non-determinism case? The trouble I've had so far is that I can't reliably find a reasonable iteration limit to use w/ either creduce, bugpoint, or llvm-reduce. Suggestions would be very welcome.

No great advice, unfortunately - if there's no way to make it more deterministic, then it needs really long cutoffs and it's just going to take a long time... but, you know, if you've got a few spare cores you can dedicate it to for a week, maybe it gets somewhere?