Several completion/globbing tests SIGSEGV on i386

[nc7s]

This is the problem reported in #10633 for 4.0b1, that fish segfaults in tests related to globs on i386.

My development/packaging setup:

• host: Debian unstable, current, amd64
• build: chroot, sbuild, unshare mode, i386
• rustc: Debian shipped rustc package
• CPU: Intel i7-9750H, x86_64

Failed tests (see log for output of each test):

The following tests FAILED:
	 27 - complete.fish (Failed)
	 62 - glob.fish (Failed)
	146 - wildcard.fish (Failed)
	185 - wildcard_tab.py (Failed)

With the offending test taken out as a separate .fish script (from tests/checks/complete.fish, CHECK at line 359), running it as build/fish t.fish will always SIGSEGV. The core dump shows:

Core was generated by `./obj-i686-linux-gnu/fish --debug complete --debug-output ../debug-output ddd.f'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x5675a447 in fish::wildcard::expander::WildCardExpander::expand ()
[Current thread is 1 (Thread 0xf7a63980 (LWP 18127))]
(gdb) bt
#0  0x5675a447 in fish::wildcard::expander::WildCardExpander::expand ()
#1  0x567592db in fish::expand::Expander::stage_wildcards ()
#2  0x567570f2 in fish::expand::expand_to_receiver ()
#3  0x567cb43b in fish::complete::Completer::complete_cmd ()
#4  0x567c0f0d in fish::complete::complete ()
#5  0x5671fc65 in fish::builtins::complete::complete ()
#6  0x566f181f in fish::exec::exec_process_in_job ()
#7  0x566d9af7 in fish::exec::exec_job ()
(...)

Then I went the good ol' way: sprinkling eprintln! across the code.

With -DCMAKE_BUILD_TYPE=Debug, the test somehow passed:

::wildcard::expander::WildCardExpander::expand(base_dir = "", wc = "__test6_", effective_prefix = "")
::wildcard::expander::WildCardExpander::expand(base_dir = "", wc = "__test6_", effective_prefix = "")
::wildcard::expander::WildCardExpander::expand(base_dir = "", wc = "__test6_", effective_prefix = "")
::wildcard::expander::WildCardExpander::expand(base_dir = "", wc = "__test6_", effective_prefix = "")
::wildcard::expander::WildCardExpander::expand(base_dir = "", wc = "__test6_", effective_prefix = "")
::wildcard::expander::WildCardExpander::expand(base_dir = "", wc = "__test6_", effective_prefix = "")
::wildcard::expander::WildCardExpander::expand(base_dir = "", wc = "__test6_", effective_prefix = "")
::wildcard::expander::WildCardExpander::expand(base_dir = "", wc = "__test6_", effective_prefix = "")
::wildcard::expander::WildCardExpander::expand(base_dir = "", wc = "__test6_", effective_prefix = "")
::wildcard::expander::WildCardExpander::expand(base_dir = "", wc = "__test6_", effective_prefix = "")
Command completion with parened PATHs test passed

With =RelWithDebInfo, though, it eprinted the same result, but failed with the same output as in Debian builds (or lack of, that is).

This method seems to recurse a lot. On i386 it recursed 10 times. On amd64 it recursed 14 times, though passing the test. In other tests it recurses even more.

This looks like an under-optimized recursion to me, but I don't really know much about this part.

[faho]

::wildcard::expander::WildCardExpander::expand(base_dir = "", wc = "_test6", effective_prefix = "")

Okay, how exactly are you printing that? Where are you putting the printlns, what are you printing?

I don't believe there's a lot of recursion here? I added a FLOGF to WildCardExpander::expand, and I get a bunch of output there, but if I add another FLOGF to expand::stage_wildcards, you can see that they alternate - stage_wildcards runs expand once per directory in $PATH.

With the directory/command created, running

PATH="$path/test6.tmp2.\(paren\).dir:$PATH" target/release/fish --no-config --debug complete -c 'complete -C"test6"'

I get output like:

complete: working_dirs: ':/tmp/tmp.D2aV7vZdaL/test6.tmp2.\(paren\).dir:/home/alfa/.local/bin:/home/alfa/.cargo/bin:/usr/local/sbin:/usr/local/bin:/usr/bin:/usr/bin/site_perl:/usr/bin/vendor_perl:/usr/bin/core_perl:/usr/lib/rustup/bin:'
complete: stage_expand: 'test6', '/tmp/tmp.D2aV7vZdaL/test6.tmp2.\(paren\).dir'
complete: expand: '', 'test6', ''
complete: stage_expand: 'test6', '/home/alfa/.local/bin'
complete: expand: '', 'test6', ''
complete: stage_expand: 'test6', '/home/alfa/.cargo/bin'
complete: expand: '', 'test6', ''
complete: stage_expand: 'test6', '/usr/local/sbin'
complete: expand: '', 'test6', ''
complete: stage_expand: 'test6', '/usr/local/bin'
complete: expand: '', 'test6', ''
complete: stage_expand: 'test6', '/usr/bin'
complete: expand: '', 'test6', ''
complete: stage_expand: 'test6', '/usr/bin/site_perl'
complete: expand: '', 'test6', ''
complete: stage_expand: 'test6', '/usr/bin/vendor_perl'
complete: expand: '', 'test6', ''
complete: stage_expand: 'test6', '/usr/bin/core_perl'
complete: expand: '', 'test6', ''
complete: stage_expand: 'test6', '/usr/lib/rustup/bin'
complete: expand: '', 'test6', ''
complete: stage_expand: 'test6', ''
complete: expand: '', 'test6', ''
complete: working_dirs: ':/home/alfa/dev/fish-shell/'
complete: stage_expand: 'test6', '/home/alfa/dev/fish-shell/'
complete: expand: '', 'test6', ''

Both built as release and as debug.

Here's my patch:

diff --git a/src/expand.rs b/src/expand.rs
index 99b418b97..14d461367 100644
--- a/src/expand.rs
+++ b/src/expand.rs
@@ -15,6 +15,7 @@ use crate::common::{
 use crate::complete::{CompleteFlags, Completion, CompletionList, CompletionReceiver};
 use crate::env::{EnvVar, Environment};
 use crate::exec::exec_subshell_for_expand;
+use crate::FLOGF;
 use crate::future_feature_flags::{feature_test, FeatureFlag};
 use crate::history::{history_session_id, History};
 use crate::operation_context::OperationContext;
@@ -1476,7 +1477,14 @@ impl<'a, 'b, 'c> Expander<'a, 'b, 'c> {
 
             result = ExpandResult::new(ExpandResultCode::wildcard_no_match);
             let mut expanded_recv = out.subreceiver();
+            let mut edstr = WString::new();
+            for ed in &effective_working_dirs {
+                edstr.push_utfstr(L!(":"));
+                edstr.push_utfstr(&ed);
+            }
+            FLOGF!(complete, "working_dirs: '%ls'", edstr);
             for effective_working_dir in effective_working_dirs {
+                FLOGF!(complete, "stage_expand: '%ls', '%ls'", path_to_expand, effective_working_dir);
                 let expand_res = wildcard_expand_string(
                     &path_to_expand,
                     &effective_working_dir,
diff --git a/src/wildcard.rs b/src/wildcard.rs
index a84754ac0..93ce3f96f 100644
--- a/src/wildcard.rs
+++ b/src/wildcard.rs
@@ -10,6 +10,7 @@ use crate::common::{
     UnescapeStringStyle, WILDCARD_RESERVED_BASE, WSL,
 };
 use crate::complete::{CompleteFlags, Completion, CompletionReceiver, PROG_COMPLETE_SEP};
+use crate::FLOGF;
 use crate::expand::ExpandFlags;
 use crate::fallback::wcscasecmp;
 use crate::future_feature_flags::feature_test;
@@ -510,6 +511,7 @@ mod expander {
                 return;
             }
 
+            FLOGF!(complete, "expand: '%ls', '%ls', '%ls'", base_dir, wc, effective_prefix);
             // Get the current segment and compute interesting properties about it.
             let (wc_segment, wc_remainder) = if let Some(next_slash) = wc.find_char('/') {
                 let (seg, rem) = wc.split_at(next_slash);

[krobelus]

would be great if we could find an i386 system where we can reproduce this.
I remember running tests on such a VM but I think I ran into different problems (or maybe everything passed except for some timeout-based tests).

It would be great if we could get a stacktrace with line numbers; since it only happens on a release build maybe add a print statement before every line to narrow it down.

It indeed does not look like infinite recursion (speak up if it is). It also seems unlikely that we're overflowing the stack here.
It could be due improper use of unsafe or a compiler bug.

[nc7s]

@faho:

::wildcard::expander::WildCardExpander::expand(base_dir = "", wc = "_test6", effective_prefix = "")

Okay, how exactly are you printing that? Where are you putting the printlns, what are you printing?

At entrypoint:

diff --git a/src/wildcard.rs b/src/wildcard.rs
index a84754ac..28fa8382 100644
--- a/src/wildcard.rs
+++ b/src/wildcard.rs
@@ -506,6 +506,7 @@ mod expander {
         ///    This is usually the same thing as the original wildcard, but for fuzzy matching, we
         ///    expand intermediate segments. effective_prefix is always either empty, or ends with a slash
         pub fn expand(&mut self, base_dir: &wstr, wc: &wstr, effective_prefix: &wstr) {
+            eprintln!("::wildcard::expander::WildCardExpander::expand(base_dir = {base_dir:?}, wc = {wc:?}, effective_prefix = {effective_prefix:?})");
             if self.interrupted_or_overflowed() {
                 return;
             }

I don't believe there's a lot of recursion here? I added a FLOGF to WildCardExpander::expand, and I get a bunch of output there, but if I add another FLOGF to expand::stage_wildcards, you can see that they alternate - stage_wildcards runs expand once per directory in $PATH.
(...)

Indeed. Then it's not a recursion issue, but something else.

@krobelus:

would be great if we could find an i386 system where we can reproduce this. I remember running tests on such a VM but I think I ran into different problems (or maybe everything passed except for some timeout-based tests).

i386 is mostly "emulated" on amd64 platforms in Debian these days, including on build daemons and porter boxes. You can create an i386 chroot with mmdebstrap ... --architecture=i386. For running it, as a packager I'm most familiar with sbuild, which accepts a similar --arch=i386 argument, but other ways sure exist.

With that, I'm also starting to speculate that the emulation might be at fault.. just a guess.

It would be great if we could get a stacktrace with line numbers; since it only happens on a release build maybe add a print statement before every line to narrow it down.

Doing the experiment ™ right now.

[nc7s]

So uh, the experiment had some interesting results.

Running the tests as scripts (build/fish tests/checks/{glob,wildcard}.fish), fish still SIGSEGV'd, but this time in fish::wildcard::expander::WildCardExpander::expand_intermediate_segment:

Core was generated by `obj-i686-linux-gnu/fish --no-config tests/checks/glob.fish'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x567d85f4 in fish::wildcard::expander::WildCardExpander::expand_intermediate_segment ()
[Current thread is 1 (Thread 0xf7a26980 (LWP 5735))]
(gdb) bt
#0  0x567d85f4 in fish::wildcard::expander::WildCardExpander::expand_intermediate_segment ()
#1  0x567d2986 in fish::wildcard::expander::WildCardExpander::expand ()
#2  0x567d1093 in fish::expand::Expander::stage_wildcards ()
#3  0x567cf0f2 in fish::expand::expand_to_receiver ()
#4  0x568af342 in fish::parse_execution::ExecutionContext::expand_arguments_from_nodes ()
(...)

Doing as krobelus suggested, sprinkling line number eprintln!s over the code, this piece came suspicious:

fish-shell/src/wildcard.rs

Lines 729 to 736 in 94dfe1b

	let Some(dev_inode) = entry.dev_inode() else {
	continue;
	};
	if !self.visited_files.insert(dev_inode) {
	// Symlink loop! This directory was already visited, so skip it.
	continue;
	}

With eprintln!s:

let Some(dev_inode) = entry.dev_inode() else { 
    eprintln!("INT11");
    continue; 
}; 
eprintln!("INT12");

if !self.visited_files.insert(dev_inode) { 
    eprintln!("INT13");
    // Symlink loop! This directory was already visited, so skip it. 
    continue; 
}
eprintln!("INT14");

It SIGSEGV'd right after printing "INT12". That is, self.visited_files.insert(dev_inode) SIGSEGV'd.

Now here's the interesting part: with eprintln!("{dev_inode:?}"); right before it, it works. eprintln!("{:?}", self.visited_files); doesn't. Basically the DevInode must be "used" once. I can remotely relate to fds since they are only valid while open, but don't know enough about inodes.

Now I do want to get my hands on a real i386 machine like krobelus suggested. Again, this might be emulation or otherwise downstream shenanigans, so I don't want to divert too much of your time before really needed.

[faho]

i386 is mostly "emulated" on amd64 platforms in Debian these days, including on build daemons and porter boxes. You can create an i386 chroot with mmdebstrap ... --architecture=i386.

Okay, I created a debian chroot - with debootstrap, because that's packaged on archlinux:

debootstrap --arch=i386 stable Machines/debian

installed the required packages and rust via rustup - because this is stable and it would have rust 1.63.

And... other than a few permission tests failing because I've not bothered to set up a non-root user in the chroot everything passes.

I do not get segfaults.

[krobelus]

Maybe tools like valgrind or AddressSanitizer will flag a problem. Chances are they don't but it should be fairly easy to try
According to .github/workflows/main.yml ASan can be enabled like this:

export LSAN_OPTIONS=verbosity=0:log_threads=0:use_tls=1:print_suppressions=0:suppressions=$PWD/build_tools/lsan_suppressions.txt
export ASAN_OPTIONS=check_initialization_order=1:detect_stack_use_after_return=1:detect_leaks=1:fast_unwind_on_malloc=0
mkdir build && cd build
cmake .. -DASAN=1 -DRust_CARGO_TARGET=i386-unknown-linux-gnu -DCMAKE_BUILD_TYPE=Debug
make

If that doesn't work, I'd probably minimize the crashing program. It is highly likely that it's possible to reduce this to a small, single-file program with basically no dependencies. Reducing the input program step-by-step should be a reliable way to narrow down the problem.

[zanchey]

@nc7s can you give more detail about the environment, OS and hardware here? Is this Debian Experimental? Using the system rustc/cargo?

The RelWithDebInfo builds should have line number debug info, but it appears they may not.

[nc7s]

zanchey:

@nc7s can you give more detail about the environment, OS and hardware here? Is this Debian Experimental? Using the system rustc/cargo?

Added in the topic.

With krobelus' suggestion, valgrind shows (after the "INT12" mark):

==10773== Invalid read of size 4
==10773==    at 0x28D608: fish::wildcard::expander::WildCardExpander::expand_intermediate_segment (in /build/reproducible-path/fish-4.0~b1/obj-i686-linux-gnu/fish)
==10773==    by 0x287985: fish::wildcard::expander::WildCardExpander::expand (in /build/reproducible-path/fish-4.0~b1/obj-i686-linux-gnu/fish)
==10773==    by 0x286092: fish::expand::Expander::stage_wildcards (in /build/reproducible-path/fish-4.0~b1/obj-i686-linux-gnu/fish)
(...)
==10773==  Address 0x30 is not stack'd, malloc'd or (recently) free'd
==10773==
==10773==
==10773== Process terminating with default action of signal 11 (SIGSEGV): dumping core
==10773==  Access not within mapped region at address 0x30
==10773==    at 0x28D608: fish::wildcard::expander::WildCardExpander::expand_intermediate_segment (in /build/reproducible-path/fish-4.0~b1/obj-i686-linux-gnu/fish)
==10773==    by 0x287985: fish::wildcard::expander::WildCardExpander::expand (in /build/reproducible-path/fish-4.0~b1/obj-i686-linux-gnu/fish)
==10773==    by 0x286092: fish::expand::Expander::stage_wildcards (in /build/reproducible-path/fish-4.0~b1/obj-i686-linux-gnu/fish)
(...)

I'll be reducing the program as krobelus suggested.

[nc7s]

Thanks faho for taking the time to check on a different distro. I did the similar, but on Fedora. Debian shipped rustc continues to produce failing results, while rustup downloaded does not. (Though only for the one discussed above; other tests fail for different reasons, incl. excessive output and timeout.) I'll redirect this to our rustc maintainers. Thanks for the time and help.

Meanwhile, a fun aside: write!-ing the value of dev_inode into a std::io::Sink effectively works around this particular case. But like above, other things start to fail.

[faho]

Yeah, that smells like a miscompilation.

I'm going to close this, assuming it's in Debian's rustc - there are some patches related to x86 in there.