rust-lang / rust

Empowering everyone to build reliable and efficient software.
https://www.rust-lang.org
Other
97.35k stars 12.58k forks source link

Error when testing with x.py #112273

Closed MoskalykA closed 1 year ago

MoskalykA commented 1 year ago

(Sorry if this isn't the right template, I wasn't sure what to choose)

Hi, when I run tests with x.py from the command python3 x.py test library/std I get this error thread 'main' panicked at 'failed to read output of test runner : stream did not contain valid UTF-8', render_tests.rs:97:29.

jyn514 commented 1 year ago

@MoskalykA can you add some more context? there should be output printed before this panic, what does it say? what commit are you testing?

MoskalykA commented 1 year ago

I'd like to contribute to Rust so I'm first trying to understand and try the tests from x.py, I haven't made any changes, I just cloned the repo then did an x.py setup then this command python3 x.py test library/std. Here is what I get from this command:

E:\rust>python3 x.py test library/std
Building bootstrap
    Finished dev [unoptimized] target(s) in 1.03s
Building stage0 library artifacts (x86_64-pc-windows-msvc)
    Finished release [optimized] target(s) in 0.74s
Testing stage0  {std} (x86_64-pc-windows-msvc)
    Finished release [optimized] target(s) in 0.36s
     Running unittests src\lib.rs (build\x86_64-pc-windows-msvc\stage0-std\x86_64-pc-windows-msvc\release\deps\std-6790327b93c40fba.exe)

running 907 tests
........................................................................................  88/907
........................................................................................ 176/907
............................................................i...............F....i...... 264/907
..............thread '<unnamed>.' panicked at 'explicit panic.', library\std\src\io\buffered\tests.rs.:497:13
............................thread '<unnamed>.' panicked at '.explicit panic', .library\std\src\io\stdio\tests.rs:.37:.9
...................................... 352/907
........................................................................................ 440/907
........................................................................................ 528/907
..............i..i................Microsoft Windows [version 10.0.22621.1778]
thread 'main' panicked at 'failed to read output of test runner: stream did not contain valid UTF-8', render_tests.rs:97:29
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
        finished in 3.492 seconds
error: io error when listing tests: Os { code: 232, kind: BrokenPipe, message: "Le canal de communication est sur le point d’être fermé." }
Build completed unsuccessfully in 0:00:08
error: test failed, to rerun pass `-p std --lib`
jyn514 commented 1 year ago

ok, great! now we need to find which of the tests are causing the "Microsoft Windows [version 10.0.22621.1778]" output - can you run python3 x.py test library/std --stage 0 --no-doc --set rust.verbose-tests=true and print the ~20 or so lines before the panic?

MoskalykA commented 1 year ago

ok, great! now we need to find which of the tests are causing the "Microsoft Windows [version 10.0.22621.1778]" output - can you run python3 x.py test library/std --stage 0 --no-doc --set rust.verbose-tests=true and print the ~20 or so lines before the panic?

test path::tests::test_stem_ext ... ok
test path::tests::test_windows_absolute ... ok
test personality::dwarf::tests::dwarf_reader ... ok
test path::tests::bench_path_cmp_fast_path_short ... ok
test path::tests::bench_path_cmp_fast_path_long ... ok
test net::tcp::tests::set_nonblocking ... ok
test process::tests::env_empty ... ok
test process::tests::set_current_dir_works ... ignored
test net::tcp::tests::ttl ... ok
test net::tcp::tests::timeouts ... ok
test process::tests::stdin_works ... ignored
test process::tests::smoke_failure ... ok
test process::tests::child_stdout_read_buf ... ok
test process::tests::exit_reported_right ... ok
test process::tests::test_command_implements_send_sync ... ok
test process::tests::run_bat_script ... ok
test process::tests::smoke ... ok
test process::tests::run_canonical_bat_script ... ok
test process::tests::test_interior_nul_in_arg_is_error ... ok
test process::tests::test_interior_nul_in_args_is_error ... ok
test process::tests::test_interior_nul_in_current_dir_is_error ... ok
test process::tests::test_interior_nul_in_env_key_is_error ... ok
test process::tests::stdout_works ... ok
test process::tests::test_interior_nul_in_env_value_is_error ... ok
test process::tests::test_interior_nul_in_progname_is_error ... ok
test process::tests::test_add_to_env ... ok
test process::tests::test_capture_env_at_spawn ... ok
jyn514 commented 1 year ago

hmm, that doesn't show the test that panicked. try adding --test-args --nocapture?

MoskalykA commented 1 year ago

hmm, that doesn't show the test that panicked. try adding --test-args --nocapture?

still the same thing, earlier today I had a theory, I thought it had nothing to do with tests but more a story of utf-8 and console

jyn514 commented 1 year ago

right, I understand it's still panicking, but I'm trying to find what's causing it to panic.

alternatively, you could try making this change to bootstrap to have it print the thing it couldn't parse:

diff --git a/src/bootstrap/render_tests.rs b/src/bootstrap/render_tests.rs
index 872b75f6c15..932fa7d93d7 100644
--- a/src/bootstrap/render_tests.rs
+++ b/src/bootstrap/render_tests.rs
@@ -88,10 +88,10 @@ fn new(stdout: ChildStdout, builder: &'a Builder<'a>) -> Self {
     }

     fn render_all(mut self) {
-        let mut line = String::new();
+        let mut line = Vec::new();
         loop {
             line.clear();
-            match self.stdout.read_line(&mut line) {
+            match self.stdout.read_until(b'\n', &mut line) {
                 Ok(_) => {}
                 Err(err) if err.kind() == std::io::ErrorKind::UnexpectedEof => break,
                 Err(err) => panic!("failed to read output of test runner: {err}"),
@@ -100,11 +100,11 @@ fn render_all(mut self) {
                 break;
             }

-            match serde_json::from_str(&line) {
+            match serde_json::from_slice(&line) {
                 Ok(parsed) => self.render_message(parsed),
                 Err(_err) => {
                     // Handle non-JSON output, for example when --nocapture is passed.
-                    print!("{line}");
+                    print!("{}", String::from_utf8_lossy(&line));
                     let _ = std::io::stdout().flush();
                 }
             }

you can paste that into git apply and it should make the change for you.

MoskalykA commented 1 year ago

I'm not sure what to copy, is that enough?

Microsoft Windows [version 10.0.22621.1778]
(c) Microsoft Corporation. Tous droits r serv s.

E:\rust\library\std>exit
jyn514 commented 1 year ago

is that with --nocapture? I'm trying to find which of the tests are emitting this output, not just the output itself. If you could paste the 20 or so lines before in addition to this version output it would be very helpful.

MoskalykA commented 1 year ago

is that with --nocapture? I'm trying to find which of the tests are emitting this output, not just the output itself. If you could paste the 20 or so lines before in addition to this version output it would be very helpful.

It's with this line, but I don't know where to start copying the 20 lines, I don't have any more crashes?

MoskalykA commented 1 year ago

I started from the last line where I was

test process::tests::test_capture_env_at_spawn ... ok
Microsoft Windows [version 10.0.22621.1778]
(c) Microsoft Corporation. Tous droits r serv s.

E:\rust\library\std>exit
test process::tests::test_creation_flags ... ok
test process::tests::test_finish_once ... ok
test process::tests::test_finish_twice ... ok
test std_float::tests::everything_works ... ok
test sync::barrier::tests::test_barrier ... ok
test sync::condvar::tests::notify_all ... ok
test sync::condvar::tests::notify_one ... ok
test sync::condvar::tests::smoke ... ok
test process::tests::test_override_env ... ok
test process::tests::test_process_output_fail_to_start ... ok
test sync::condvar::tests::wait_timeout_while_instant_satisfy ... ok
test sync::condvar::tests::wait_timeout_wait ... ok
test sync::condvar::tests::wait_timeout_wake ... ok
test sync::condvar::tests::wait_timeout_while_wait ... ok
test sync::lazy_lock::tests::is_sync_send ... ok
test sync::condvar::tests::wait_while ... ok
thread 'sync::lazy_lock::tests::lazy_poisoning' panicked at 'test sync::lazy_lock::tests::lazy_default ... ok
kaboom', test sync::lazy_lock::tests::lazy_type_inference ... ok
library\std\src\sync\lazy_lock\tests.rs:test process::tests::test_process_output_error ... ok
43:48test sync::lazy_lock::tests::static_sync_lazy ... ok

thread 'thread 'test sync::lazy_lock::tests::static_sync_lazy_via_fn ... ok
sync::lazy_lock::tests::sync_lazy_poisoning' panicked at 'sync::lazy_lock::tests::lazy_poisoningkaboom' panicked at 'test sync::lazy_lock::tests::sync_lazy_default ... ok
LazyCell has previously been poisoned', ', E:\rust\library\core\src\cell\lazy.rstest sync::lazy_lock::tests::sync_lazy_new ... ok
library\std\src\sync\lazy_lock\tests.rs::124test sync::mpsc::sync_tests::chan_gone_concurrent ... ok
:13232:
48
thread 'sync::lazy_lock::tests::sync_lazy_poisoningtest sync::lazy_lock::tests::lazy_poisoning ... ok
' panicked at 'Once instance has previously been poisoned', library\std\src\sync\lazy_lock.rs:127:19
test sync::mpsc::sync_tests::drop_full ... ok
test sync::lazy_lock::tests::sync_lazy_poisoning ... ok
thread '<unnamed>' panicked at 'called `Result::unwrap()` on an `Err` value: RecvErrortest sync::mpsc::sync_tests::drop_unreceived ... ok
', library\std\src\sync\mpsc\sync_tests.rs:357test sync::mpsc::sync_tests::destroy_upgraded_shared_port_when_sender_still_active ... ok
:28
test sync::mpsc::sync_tests::oneshot_multi_task_recv_then_send ... ok
test sync::mpsc::sync_tests::oneshot_multi_task_recv_then_close ... ok
test sync::mpsc::sync_tests::oneshot_multi_thread_close_stress ... ok
test sync::mpsc::sync_tests::oneshot_multi_thread_recv_close_stress ... ok
thread '<unnamed>' panicked at 'thread 'called `Result::unwrap()` on an `Err` value: RecvError<unnamed>', ' panicked at 'library\std\src\sync\mpsc\sync_tests.rscalled `Result::unwrap()` on an `Err` value: SendError { .. }:test sync::mpsc::sync_tests::oneshot_multi_thread_send_recv_stress ... ok
', 394library\std\src\sync\mpsc\sync_tests.rs::27382
:24test sync::mpsc::sync_tests::oneshot_single_thread_close_chan_first ... ok

test sync::mpsc::sync_tests::oneshot_single_thread_close_port_first ... ok
test sync::mpsc::sync_tests::oneshot_multi_thread_send_close_stress ... ok
test sync::mpsc::sync_tests::oneshot_single_thread_peek_close ... ok
test sync::mpsc::sync_tests::oneshot_single_thread_peek_data ... ok
thread 'test process::tests::test_process_output_output ... ok
<unnamed>' panicked at 'test sync::mpsc::sync_tests::oneshot_single_thread_peek_open ... ok
called `Result::unwrap()` on an `Err` value: RecvError', library\std\src\sync\mpsc\sync_tests.rstest sync::mpsc::sync_tests::oneshot_single_thread_send_port_close ... ok
:261:test sync::mpsc::sync_tests::oneshot_single_thread_send_then_recv ... ok
19
test sync::mpsc::sync_tests::oneshot_single_thread_try_recv_closed ... ok
test sync::mpsc::sync_tests::oneshot_single_thread_try_recv_closed_with_data ... ok
jyn514 commented 1 year ago

test_capture_env_at_spawn

hmm, this runs cmd /c set on windows, maybe that's printing the version notice?

jyn514 commented 1 year ago

can you post the output of cmd /c set?

MoskalykA commented 1 year ago

can you post the output of cmd /c set?

ALLUSERSPROFILE=C:\ProgramData
APPDATA=C:\Users\Arthur\AppData\Roaming
ChocolateyInstall=C:\ProgramData\chocolatey
ChocolateyLastPathUpdate=133226107574816313
CommonProgramFiles=C:\Program Files\Common Files
CommonProgramFiles(x86)=C:\Program Files (x86)\Common Files
CommonProgramW6432=C:\Program Files\Common Files
COMPUTERNAME=DESKTOP-IJL5688
ComSpec=C:\Windows\system32\cmd.exe
DriverData=C:\Windows\System32\Drivers\DriverData
GARRYSMOD_COMMON=E:\Gmod\garrysmod\gamemodes\garrysmod_common
HOMEDRIVE=C:
HOMEPATH=\Users\Arthur
LIBCLANG_PATH=E:\LLVM\lib
LOCALAPPDATA=C:\Users\Arthur\AppData\Local
LOGONSERVER=\\DESKTOP-IJL5688
NUMBER_OF_PROCESSORS=12
OneDrive=C:\Users\Arthur\OneDrive
OS=Windows_NT
Path=C:\Program Files\Common Files\Oracle\Java\javapath;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Windows\System32\OpenSSH\;C:\Program Files\Git\cmd;C:\ProgramData\chocolatey\bin;E:\LLVM\bin;C:\Program Files\NVIDIA Corporation\NVIDIA NvDLISR;C:\Program Files\nodejs\;C:\Program Files\CMake\bin;C:\Program Files (x86)\NVIDIA Corporation\PhysX\Common;C:\Program Files (x86)\Microsoft SDKs\TypeScript\1.0\;E:\PHP;C:\Program Files\PuTTY\;C:\Program Files\dotnet\;C:\Program Files\Docker\Docker\resources\bin;C:\Program Files (x86)\Windows Kits\10\Windows Performance Toolkit\;C:\Users\Arthur\AppData\Local\Programs\Python\Python310\Scripts\;C:\Users\Arthur\AppData\Local\Programs\Python\Python310\;C:\Users\Arthur\scoop\shims;C:\Users\Arthur\AppData\Local\pnpm;C:\Users\Arthur\.console-ninja\.bin;C:\Users\Arthur\AppData\Local\pnpm;C:\Users\Arthur\.cargo\bin;C:\Users\Arthur\AppData\Local\Microsoft\WindowsApps;C:\Users\Arthur\AppData\Local\GitHubDesktop\bin;C:\Users\Arthur\AppData\Local\Programs\Microsoft VS Code\bin;C:\Program Files\Git\usr\bin;C:\Users\Arthur\.deno\bin;C:\Users\Arthur\AppData\Local\Programs\Hyper\resources\bin;C:\Users\Arthur\AppData\Roaming\npm;C:\Users\Arthur\AppData\Local\JetBrains\Toolbox\scripts;C:\Users\Arthur\.dotnet\tools;E:\premake;C:\Users\Arthur\.dotnet\tools;C:\Program Files\Microsoft Visual Studio\2022\Community\Msbuild\Current\Bin;E:\protoc\bin;C:\cygwin64\bin;C:\Program Files\Autodesk\FBX\FBX SDK\2020.0.1\include;C:\msys64\mingw64\bin;C:\Users\Arthur\AppData\Local\Programs\Python\Python310;
PATHEXT=.COM;.EXE;.BAT;.CMD;.VBS;.VBE;.JS;.JSE;.WSF;.WSH;.MSC
PNPM_HOME=C:\Users\Arthur\AppData\Local\pnpm
PROCESSOR_ARCHITECTURE=AMD64
PROCESSOR_IDENTIFIER=Intel64 Family 6 Model 165 Stepping 3, GenuineIntel
PROCESSOR_LEVEL=6
PROCESSOR_REVISION=a503
ProgramData=C:\ProgramData
ProgramFiles=C:\Program Files
ProgramFiles(x86)=C:\Program Files (x86)
ProgramW6432=C:\Program Files
PROMPT=$P$G
PSModulePath=C:\Program Files\WindowsPowerShell\Modules;C:\Windows\system32\WindowsPowerShell\v1.0\Modules
PUBLIC=C:\Users\Public
SESSIONNAME=Console
SystemDrive=C:
SystemRoot=C:\Windows
TEMP=C:\Users\Arthur\AppData\Local\Temp
TMP=C:\Users\Arthur\AppData\Local\Temp
USERDOMAIN=DESKTOP-IJL5688
USERDOMAIN_ROAMINGPROFILE=DESKTOP-IJL5688
USERNAME=Arthur
USERPROFILE=C:\Users\Arthur
VTFLIB_STATIC=D:\import\vtflib-sys\vendor
windir=C:\Windows
_NT_SYMBOL_PATH=srv*C:\symbols*https://msdl.microsoft.com/download/symbols
jyn514 commented 1 year ago

hmm ok, but you don't see the "Microsoft Windows [version 10.0.22621.1778]" from cmd /c set? it might be a different test that's making bootstrap panic then.

cc @ChrisDenton, do you have ideas what could be going wrong here? @MoskalykA is using a french locale and that's making one of the tests emit non-utf8 on Windows for some reason.

MoskalykA commented 1 year ago

hmm ok, but you don't see the "Microsoft Windows [version 10.0.22621.1778]" from cmd /c set? it might be a different test that's making bootstrap panic then.

When I launch a terminal, I get "Microsoft Windows...", but with the command I don't get "Microsoft Windows..."

MoskalykA commented 1 year ago

I set my computer to English, I deleted the changes from earlier and I no longer have the problem.

ChrisDenton commented 1 year ago

Setting the VSLANG environment variable to 1033 should work if the Visual Studio English language pack is installed. I believe rustc itself sets this.

I did recently add some code to rustc to attempt to re-encode as UTF-8 if the output is not UTF-8 but this only triggers for linker output. Perhaps other tools may also want the same treatment but I've not investigated.

ChrisDenton commented 1 year ago

Oh sorry, just read that again. This is caused by cmd when used with /c? Hm, strange. I'm not sure off-hand. Using chcp 65001 should switch to the UTF-8 code page. But I'm unsure of the cause so I don't know if that would help in this case.