[Toybox] weird timeout flake

[Rob Landley]

On 10/3/23 16:07, enh wrote:
>> I don't THINK that's a likely fallback path here? Although /bin/sh not found
>> might explain it. But that would be deterministically reproducible and you're
>> having an intermittent issue, right?
> 
> correct. ccross tells me it's ~2% of all runs in CI.

Ok, that's significant. That's not a "second guy finally saw this happen to him
once", that's "we can hammer and reproduce".

> locally, i commented out all the other tests, and just ran this
> repeatedly on a device, and it did repro after about half an hour.
> i've kicked off a similar test on the host, and i've kicked off the
> device again but with strace in the mix (which hopefully doesn't slow
> things down enough to make the problem disappear!).

$ grep -r 'errno.*=.*ENOENT' -r bionic | grep -v ==

Bionic's exec.cpp can return ENOENT when name or *name is null. Seems unlikely.

And that's not argv[0] being null, that's the "name" argument which we're
passing a constant-ish string to. Failure to marshall the string into that
argument there would have to be in the shell, or the toybox argument parsing
path, or something in then xpopen_setup() plumbing? This isn't timeout -i so
it's not doing the pipe setup and you have CFG_TOYBOX_FORK enabled in your
config so the else case in xpopen_setup() returning 127 can't trigger, and it
also eliminates the less tested vfork() codepath in the kernel (although not by
THAT much, it's just clone() with a bunch of flags...) Similarly xfork() is just
checking pid<0 to perror_exit() which you'd _notice_ and isn't 127 anyway. The
callback() is just setting the child's SIGCHLD signal handler back to default
and you didn't --foreground so it wouldn't setpgid() anyway, and then xexec()
and you have CFG_TOYBOX_NORECURSE so there's our call to execvp(). I don't see
how we'd get derailed before there.

>> $ cat > potato.c << EOF
>> #include <unistd.h>
>> int main(int argc, char *argv[]) { execvp("/", (char *[]){"/", 0}); }
>> EOF
>> $ gcc potato.c
>> $ strace ./a.out
>> execve("/", ["/"], 0x7ffebd0880d8 /* 36 vars */) = -1 EACCES (Permission denied)
>> $ sudo strace ./a.out
>> execve("/", ["/"], 0x7ffc32654e08 /* 16 vars */) = -1 EACCES (Permission denied)
>> $ ls -ld /
>> drwxr-xr-x 24 root root 4096 Feb  9  2023 /
>>
>> In general root doesn't care about permission bits, and there's no /bin/sh
>> follow-up to the syscall failure here. Tried again with bionic and there were a
>> couple extra mprotect() calls on the way out but still no /bin/sh fallback...
>>
>> So the question here is does the kernel have a weird intermittent codepath, or
>> does bionic+selinux have a weird intermittent codepath?
> 
> (yeah, that's why i'm trying on the host now.)
> 
>> Let's see: in the vanilla kernel source fs/exec.c has SYSCALL_DEFINE3(execve)
>> which does return do_execve(getname(filename), argv, envp); which wraps
>> do_execveat_common() on line 1888 of the same file.
>>
>> A quick cheat grepping for EACCES shows two uses in this file, one in
>> SYSCALL_DEFINE1(uselib) which I just BOGGLE at because how are shared libraries
>> THE KERNEL'S PROBLEM... but I really doubt we get there here. No, the NORMAL
>> codepath (which we're apparently not reaching) is do_open_execat(int fd, struct
>> filename *name, int flags) which says no, may_open() already checked and this is
>> just a race condition check, and it's common plumbing in another file that
>> returns this error code. Alright, cheat failed, back to drilling.
>>
>> Back to do_execveat_common(): filename was not a NULL pointer or similar.
>> UCOUNT_RLIMIT_NPROC would return -EAGAIN. What error code might alloc_bprm()
>> return, it's on line 1512 of this same file and it is understandably ENOMEM.
>> count() can return EFAULT, E2BIG, and ERESTARTNOHAND. (Huh, launching a process
>> with an argv of { NULL } has a kernel workaround with shaking finger of shame in
>> the log? Did not know that.)
> 
> (yeah, surprisingly that "broke userspace" in the mild sense of "we
> had tests" that made sure the _dynamic linker_ didn't crash in that
> circumstance. and of course, we only had that test because it'd
> happened in real life. but, yeah, i'm pretty happy with "don't do
> that".)

int main(int argc, char *argv[])
{
  // don't segfault if our environment is crazy
  if (!*argv) return 127;

I can remove that. :)

When did this... commit dcd46d897adb7 last year, responding to CVE-2021-4034.
Ok, explains why I hadn't noticed before. And 7 year horizon for removing the
check. Add a TODO note but my main.c is dirty because of the zhelp stuff...

>> bprm_stack_limits() can set E2BIG.
>> copy_string_kernel() and copy_strings() can both EFAULT or E2BIG.
>>
>> And now we're on to bprm_execve(), which I can drill through after lunch...

Make that after dinner.

> when i wrote the test i was trying to make sure we tested _all_ the
> paths through....
> 
> ...but there's a bug _somewhere_ for this to be non-deterministic.

Eh, "bug"... signal delivery causing a different return path, data in cache vs
data not in cache causing an EAGAIN codepath being handled differently on retry,
some sort of marginal timeout... Slightly different error return code nobody's
CARED about before now.

Still lots of variables: architecture (arm vs x86), kernel version (android vs
vanilla maybe), libc version, compiler version (unlikely), selinux (and/or hwsan
triggering somewhere _in_ the kernel), has it only been seen on specific
hardware or filesystems (driver return code somehow)...

> this was a hwasan build on cheetah. (a) because that's what happens to
> be on my desk, but (b) because ccross' example was arm64 hwasan too.

Googling for "android cheetah" says it got banned from the play store and
accused of insider trading by the SEC, and its founder is the current CEO of
Bilibili.

Rob