dbg_inline_begin triggering UB in the LLVM backend

andrewrk commented 2 years ago

$ valgrind --track-origins=yes ./stage2/bin/zig test ../lib/std/multi_array_list.zig -fLLVM
==352736== Conditional jump or move depends on uninitialised value(s)
==352736==    at 0x30BE750: std.array_hash_map.ArrayHashMapUnmanaged(type.Type,codegen.llvm.AnnotatedDITypePtr,type.HashContext32,true).getOrPutInternal (array_hash_map.zig:1479)
==352736==    by 0x30BCEDC: std.array_hash_map.ArrayHashMapUnmanaged(type.Type,codegen.llvm.AnnotatedDITypePtr,type.HashContext32,true).getOrPutAssumeCapacityAdapted (array_hash_map.zig:736)
==352736==    by 0x30BC385: std.array_hash_map.ArrayHashMapUnmanaged(type.Type,codegen.llvm.AnnotatedDITypePtr,type.HashContext32,true).getOrPutContextAdapted (array_hash_map.zig:674)
==352736==    by 0x30BC161: std.array_hash_map.ArrayHashMapUnmanaged(type.Type,codegen.llvm.AnnotatedDITypePtr,type.HashContext32,true).getOrPutContext (array_hash_map.zig:650)
==352736==    by 0x307DB53: std.array_hash_map.ArrayHashMapUnmanaged(type.Type,codegen.llvm.AnnotatedDITypePtr,type.HashContext32,true).getOrPut (array_hash_map.zig:647)
==352736==    by 0x2E3DFD9: codegen.llvm.Object.lowerDebugType (llvm.zig:815)
==352736==    by 0x33A99CE: codegen.llvm.FuncGen.airDbgInlineBegin (llvm.zig:4235)
==352736==    by 0x33834B8: codegen.llvm.FuncGen.genBody (llvm.zig:3475)
==352736==    by 0x33956A0: codegen.llvm.FuncGen.airBlock (llvm.zig:3757)
==352736==    by 0x3380B7D: codegen.llvm.FuncGen.genBody (llvm.zig:3378)
==352736==    by 0x33973F5: codegen.llvm.FuncGen.airCondBr (llvm.zig:3819)
==352736==    by 0x3380E44: codegen.llvm.FuncGen.genBody (llvm.zig:3384)
==352736==  Uninitialised value was created by a client request
==352736==    at 0x31F5038: std.mem.Allocator.allocAdvancedWithRetAddr.6900 (Allocator.zig:323)
==352736==    by 0x304E779: std.mem.Allocator.create.4283 (Allocator.zig:184)
==352736==    by 0x34F1AA7: Module.makeIntType (Module.zig:5023)
==352736==    by 0x3328D46: Sema.zirIntType (Sema.zig:5221)
==352736==    by 0x31DD0CF: Sema.analyzeBodyInner (Sema.zig:699)
==352736==    by 0x31D610C: Sema.analyzeBodyBreak (Sema.zig:558)
==352736==    by 0x34D9C20: Sema.resolveBody (Sema.zig:523)
==352736==    by 0x34E1DB7: Sema.analyzeCall (Sema.zig:4663)
==352736==    by 0x331F23E: Sema.zirCall (Sema.zig:4392)
==352736==    by 0x31DAE6B: Sema.analyzeBodyInner (Sema.zig:654)
==352736==    by 0x35008A2: Sema.resolveBlockBody (Sema.zig:3850)
==352736==    by 0x33739E2: Sema.zirBlock (Sema.zig:3833)

The stack trace for where the unitialized value does not make sense to me but I do think that the fn_ty in the handling of dbg_inline_begin is pointing to undefined memory.

Something is wrong with the:

            try self.dg.object.lowerDebugType(fn_ty, .full),

I wasn't able to figure out why, but I also noticed that dbg_inline_begin creates a debug info function which it stores into di_map with the key of decl. That's not correct because the decl/function here is generic function, but the debug info created is for an instantiation.

I wasn't able to fully figure out what is going wrong here but I have a mitigation commit upcoming.

andrewrk commented 2 years ago

cc @Vexu

Vexu commented 2 years ago

I don't think this is relevant anymore.

andrewrk commented 2 years ago

I ran valgrind --track-origins=yes stage3/bin/zig test ../lib/std/std.zig with 0.10.0-dev.4644+e036cc48d all the way to completion, and observed the following output:

==1235409== Memcheck, a memory error detector
==1235409== Copyright (C) 2002-2022, and GNU GPL'd, by Julian Seward et al.
==1235409== Using Valgrind-3.19.0 and LibVEX; rerun with -h for copyright info
==1235409== Command: stage3/bin/zig test ../lib/std/std.zig
==1235409== 
==1235409== Thread 13:
==1235409== Syscall param writev(vector[...]) points to uninitialised byte(s)
==1235409==    at 0xE942F47: writev (in /nix/store/lxpdbaazqd2s79jx6lngr8nak2rjdaq1-glibc-2.34-210/lib/libc.so.6)
==1235409==    by 0x9BF6D57: os.writev (os.zig:1152)
==1235409==    by 0x9CD125B: fs.file.File.writev (fs/file.zig:1166)
==1235409==    by 0x9AEB43A: fs.file.File.writevAll (fs/file.zig:1181)
==1235409==    by 0x9AE9A26: Module.astGenFile (Module.zig:3920)
==1235409==    by 0x9AEBCBF: Compilation.workerAstGenFile (Compilation.zig:3371)
==1235409==    by 0x9AEBB4F: ThreadPool.spawn__anon_92830.Closure.runFn (ThreadPool.zig:90)
==1235409==    by 0x9923284: ThreadPool.worker (ThreadPool.zig:129)
==1235409==    by 0x9AB37FB: Thread.callFn__anon_88501 (Thread.zig:393)
==1235409==    by 0x9923BE4: Thread.PosixThreadImpl.spawn__anon_69736.Instance.entryFn (Thread.zig:666)
==1235409==    by 0xE8CAFF1: start_thread (in /nix/store/lxpdbaazqd2s79jx6lngr8nak2rjdaq1-glibc-2.34-210/lib/libc.so.6)
==1235409==    by 0xE94CFAF: clone (in /nix/store/lxpdbaazqd2s79jx6lngr8nak2rjdaq1-glibc-2.34-210/lib/libc.so.6)
==1235409==  Address 0x1f8467bc is 444 bytes inside a block of size 9,328 alloc'd
==1235409==    at 0xE74159B: memalign (in /nix/store/i3kvljpyyyyqvrg3ihf1j3vbvz2f39mv-valgrind-3.19.0/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==1235409==    by 0xE7416AB: posix_memalign (in /nix/store/i3kvljpyyyyqvrg3ihf1j3vbvz2f39mv-valgrind-3.19.0/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==1235409==    by 0x98BD60B: heap.CAllocator.alignedAlloc (heap.zig:62)
==1235409==    by 0x98BD324: heap.CAllocator.alloc (heap.zig:110)
==1235409==    by 0x9CCD97F: rawAlloc (mem/Allocator.zig:154)
==1235409==    by 0x9CCD97F: mem.Allocator.allocAdvancedWithRetAddr__anon_108739 (mem/Allocator.zig:302)
==1235409==    by 0x9AEA423: mem.Allocator.alloc__anon_90832 (mem/Allocator.zig:194)
==1235409==    by 0x9AE92C7: Module.astGenFile (Module.zig:3870)
==1235409==    by 0x9AEBCBF: Compilation.workerAstGenFile (Compilation.zig:3371)
==1235409==    by 0x9AEBB4F: ThreadPool.spawn__anon_92830.Closure.runFn (ThreadPool.zig:90)
==1235409==    by 0x9923284: ThreadPool.worker (ThreadPool.zig:129)
==1235409==    by 0x9AB37FB: Thread.callFn__anon_88501 (Thread.zig:393)
==1235409==    by 0x9923BE4: Thread.PosixThreadImpl.spawn__anon_69736.Instance.entryFn (Thread.zig:666)
==1235409==  Uninitialised value was created by a stack allocation
==1235409==    at 0x9F10510: AstGen.GenZir.addNode (AstGen.zig:11483)
==1235409== 
AST Lowering [449] array_list.zig... AST Lowering [336] os/uefi/protocols/shell_parameters_protocol.zigSemantic Analysis [17861] containsAdapted... AST Lowering [581] crypto/pcurves/secp256k1/secp256k1_scalTest [42/2225] test.sign... SKIP
Test [93/2225] test.zeroes... SKIP
Test [192/2225] test.float.hexadecimal... 
====== expected this output: =========
f80: 0x1.5555555555555556p-2
======== instead found this: =========
f80: 0x1.5555555555555p-2
======================================
Test [192/2225] test.float.hexadecimal... FAIL (TestExpectedFmt)
/home/andy/Downloads/zig/lib/std/testing.zig:210:5: 0x75e13c in expectFmt__anon_16958 (test)
    return error.TestExpectedFmt;
    ^
/home/andy/Downloads/zig/lib/std/fmt.zig:2319:5: 0x763ffa in test.float.hexadecimal (test)
    try expectFmt("f80: 0x1.5555555555555556p-2", "f80: {x}", .{@as(f80, 1.0 / 3.0)});
    ^
Test [328/2225] test.PackedIntArray... SKIP
Test [332/2225] test.PackedIntSlice... SKIP
Test [333/2225] test.PackedIntSlice of PackedInt(Array/Slice)... SKIP
Test [389/2225] test.basic functionality... SKIP
Test [487/2225] test.vector prefix scan... SKIP
Test [553/2225] test.std.event.Loop - basic... SKIP
Test [554/2225] test.std.event.Loop - runDetached... SKIP
Test [555/2225] test.std.event.Loop - sleep... SKIP
Test [596/2225] test.math.isFinite... FAIL (TestUnexpectedResult)
/home/andy/Downloads/zig/lib/std/testing.zig:347:14: 0x63315f in expect (test)
    if (!ok) return error.TestUnexpectedResult;
             ^
/home/andy/Downloads/zig/lib/std/math/isfinite.zig:26:9: 0xb5199f in test.math.isFinite (test)
        try expect(isFinite(math.floatMax(T)));
        ^
Test [600/2225] test.math.isNormal... FAIL (TestUnexpectedResult)
/home/andy/Downloads/zig/lib/std/testing.zig:347:14: 0x63315f in expect (test)
    if (!ok) return error.TestUnexpectedResult;
             ^
/home/andy/Downloads/zig/lib/std/math/isnormal.zig:29:9: 0xb55675 in test.math.isNormal (test)
        try expect(isNormal(math.floatMin(T)));
        ^
Test [603/2225] test.math.ldexp... FAIL (TestUnexpectedResult)
/home/andy/Downloads/zig/lib/std/testing.zig:347:14: 0x63315f in expect (test)
    if (!ok) return error.TestUnexpectedResult;
             ^
/home/andy/Downloads/zig/lib/std/math/ldexp.zig:75:5: 0xb59630 in test.math.ldexp (test)
    try expect(ldexp(@as(f80, 0x1.7FFFFFFFFFFFFFFEp-1), -16382 - 62) == math.floatTrueMin(f80));
    ^
Test [649/2225] test.80... FAIL (TestUnexpectedResult)
/home/andy/Downloads/zig/lib/std/testing.zig:347:14: 0x63315f in expect (test)
    if (!ok) return error.TestUnexpectedResult;
             ^
/home/andy/Downloads/zig/lib/std/math/ilogb.zig:121:5: 0xb71465 in test.80 (test)
    try expect(ilogbX(f80, 0x1p-16383) == -16383);
    ^
Test [895/2225] test.x25519 rfc7748 1,000 iterations... SKIP
Test [896/2225] test.x25519 rfc7748 1,000,000 iterations... SKIP
Test [976/2225] test.kdf... SKIP
Test [977/2225] test.kdf rfc 1... SKIP
Test [978/2225] test.kdf rfc 2... SKIP
Test [979/2225] test.kdf rfc 3... SKIP
Test [980/2225] test.kdf rfc 4... SKIP
Test [981/2225] test.password hashing (crypt format)... SKIP
Test [982/2225] test.strHash and strVerify... SKIP
Test [983/2225] test.unix-scrypt... SKIP
Test [989/2225] test.RFC 6070 16,777,216 iterations... SKIP
Test [992/2225] test.Very large dk_len... SKIP
Test [1010/2225] test.std.event.Channel... SKIP
Test [1011/2225] test.std.event.Channel wraparound... SKIP
Test [1012/2225] test.std.event.Future... SKIP
Test [1013/2225] test.std.event.Group... SKIP
Test [1014/2225] test.std.event.Batch... SKIP
Test [1015/2225] test.std.event.Lock... SKIP
Test [1016/2225] test.std.event.RwLock... SKIP
Test [1017/2225] test.basic WaitGroup usage... SKIP
Test [1066/2225] test.write a file, watch it, write it again, delete it... SKIP
Test [1102/2225] test.C Writer... SKIP
Test [1468/2225] test.invalid but parseable IPv6 scope ids... SKIP
Test [1472/2225] test.listen on a port, send bytes, receive bytes... SKIP
Test [1473/2225] test.listen on ipv4 try connect on ipv6 then ipv4... SKIP
Test [1484/2225] test.readlink on Windows... SKIP
Test [1512/2225] test.POSIX file locking with fcntl... SKIP
2183 passed; 37 skipped; 5 failed.
error: the following test command failed with exit code 1:
/home/andy/Downloads/zig/zig-cache/o/1de29885af15ee94407b07271dc35698/test
==1235409== 
==1235409== HEAP SUMMARY:
==1235409==     in use at exit: 374,163 bytes in 2,426 blocks
==1235409==   total heap usage: 45,605,651 allocs, 45,603,225 frees, 20,572,516,748 bytes allocated
==1235409== 
==1235409== LEAK SUMMARY:
==1235409==    definitely lost: 10,089 bytes in 252 blocks
==1235409==    indirectly lost: 7,512 bytes in 116 blocks
==1235409==      possibly lost: 4,832 bytes in 17 blocks
==1235409==    still reachable: 351,730 bytes in 2,041 blocks
==1235409==         suppressed: 0 bytes in 0 blocks
==1235409== Rerun with --leak-check=full to see details of leaked memory
==1235409== 
==1235409== For lists of detected and suppressed errors, rerun with: -s
==1235409== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 0 from 0)

Syscall param writev(vector[...]) points to uninitialised byte(s)

These two things have to do with AstGen caching. I do think they are worth investigating but they are not undefined behavior. I suspect some harmless padding is making its way in and out of the file system.

std lib float test failures

This indicates that running the compiler in Valgrind had different behavior than running it normally. Perhaps Valgrind is handling floating point instructions differently. Or perhaps there is a bug here. But it's not UB in the LLVM backend.

Conclusion

Confirmed, this issue is resolved. It may be interesting to revisit this Valgrind output in the future, however, it's not enough to say there is any bug here.

ziglang / zig