Open marler8997 opened 1 year ago
On 0.12.0-dev.5+fc6e57568 (macOS x64_64) I see a out-of-bounds panic instead of an error:
----
info: got 8192 bytes
info: got 8192 bytes
info: got 8192 bytes
thread 4669890 panic: index out of bounds: index 18427, len 16645
/Users/stevie/bin/lib/std/crypto/tls/Client.zig:1251:81: 0x1048d390a in finishRead2 (main)
@memcpy(c.partially_read_buffer[c.partial_ciphertext_idx + first.len ..][0..frag1.len], frag1);
^
/Users/stevie/bin/lib/std/crypto/tls/Client.zig:1071:35: 0x1048cdb92 in readvAdvanced__anon_4373 (main)
return finishRead2(c, first, frag1, vp.total);
^
/Users/stevie/bin/lib/std/crypto/tls/Client.zig:900:38: 0x1048d98b5 in readvAtLeast__anon_4372 (main)
var amt = try c.readvAdvanced(stream, iovecs[vec_i..]);
^
/Users/stevie/bin/lib/std/crypto/tls/Client.zig:861:24: 0x1048d9d70 in readAtLeast__anon_4370 (main)
return readvAtLeast(c, stream, &iovecs, len);
^
/Users/stevie/bin/lib/std/crypto/tls/Client.zig:866:23: 0x1048d9e42 in read__anon_4369 (main)
return readAtLeast(c, stream, buffer, 1);
^
/Users/stevie/tmp/14573/main.zig:46:36: 0x1048da6d0 in main (main)
const len = try client.read(stream, &buf);
^
/Users/stevie/bin/lib/std/start.zig:574:37: 0x104987300 in main (main)
const result = root.main() catch |err| {
The panic is consistent for me, but the number of "info: got XXX bytes" logs that happens before the panic varies wildly between runs. I'm seeing everything between zero and 45 read chunks before the failure.
With double the read buffer size (8192 * 2)
, the request succeeds consistently. With anything smaller I get the above.
I'm also experiencing the issue @hryx mentioned on macOS ARM M2 0.12.0-dev.294+4d1432299
This issue is a bit over my head, but I've narrowed it down a bit.
The repro seems to always fail in this call to finishRead2()
https://github.com/ziglang/zig/blob/d2014fe9713794f6cc0830301a1110d5e92d0ff0/lib/std/crypto/tls/Client.zig#L1066-L1072
frag1
is too large here (line 1251), causing the out-of-bounds error. It seems to grow before every invocation.
https://github.com/ziglang/zig/blob/d2014fe9713794f6cc0830301a1110d5e92d0ff0/lib/std/crypto/tls/Client.zig#L1245-L1251
And it's set here https://github.com/ziglang/zig/blob/d2014fe9713794f6cc0830301a1110d5e92d0ff0/lib/std/crypto/tls/Client.zig#L1001-L1010
Duplicate of #15226, fixed by #20587. Can be closed now.
I just tried this on 0.13.0, set the buffer size to 300 and I got a panic:
info: sending request
----
GET https://ziglang.org/download/0.7.0/zig-linux-x86_64-0.7.0.tar.xz HTTP/1.1
Host: ziglang.org
Connection: close
----
thread 16080 panic: index out of bounds: index 1, len 1
C:\tools\zig\0.13.0\files\lib\std\crypto\tls\Client.zig:931:29: 0xcb55e1 in readvAtLeast__anon_5018 (bug.exe.obj)
while (amt >= iovecs[vec_i].len) {
^
C:\tools\zig\0.13.0\files\lib\std\crypto\tls\Client.zig:889:24: 0xcb5881 in readAtLeast__anon_5016 (bug.exe.obj)
return readvAtLeast(c, stream, &iovecs, len);
^
C:\tools\zig\0.13.0\files\lib\std\crypto\tls\Client.zig:894:23: 0xcb5931 in read__anon_5015 (bug.exe.obj)
return readAtLeast(c, stream, buffer, 1);
^
C:\temp\bug.zig:38:40: 0xcb5da4 in main (bug.exe.obj)
const len = try client.read(stream, buf[total_read..]);
^
C:\tools\zig\0.13.0\files\lib\std\start.zig:363:53: 0xd60d7c in WinStartup (bug.exe.obj)
std.os.windows.ntdll.RtlExitUserProcess(callMain());
^
???:?:?: 0x7ffa234a257c in ??? (KERNEL32.DLL)
???:?:?: 0x7ffa24b0af27 in ??? (ntdll.dll)
The TLS implementation is pretty riddled with bugs atm, I noticed multiple when I was working on fixing this.
In this case, buffer size 300, example from the first post in this thread, in line:
C:\temp\bug.zig:38:40: 0xcb5da4 in main (bug.exe.obj)
const len = try client.read(stream, buf[total_read..]);
read is called with zero size buffer. total_read
is already 300. read
in tls.Client is not guarded against calling with zero size buffer.
If I make buf large enough to get all headers (666 in this case) then zig master succeeds and 0.13 fails with the panic fixed in #20587.
Zig Version
0.11.0-dev.1507+6f13a725a
Steps to Reproduce and Observed Behavior
I found this intermittent issue when trying to use the new std TLS implementation for zigup. I've created a small application that will intermittently reproduce the issue. It's extremely intermittent. Once I had 30 successful runs before I saw it, but usually I see it before 10 runs, sometimes after the first few runs as well. Seems to happen on CI pretty often though (see https://github.com/marler8997/zigup/actions/runs/4095377532/jobs/7066880134), it's odd. It also seems to be sensitive to the "read buffer size".
Here's the program:
This program sends a simple HTTP request to download the zig 0.7.0 linux tarball release. A non-successful run (can take running a bunch of times to see) looks like this:
If I change the buffer size to
8192 * 10
, then I get a different error:Another thing to note is that in a wireshark trace, nothing coming from the server seems "out of the ordinary" as far as I can see. The server isn't trying to close the connection, it seems to just be sending the data and then suddenly the client closes the connection with "RST" packets.
Expected Behavior
The commands above to build and then run
tlsbug.zig
should end with output that looks like this:The program shouldn't intermittently fail.