[REGRESSION 5.8] x86/entry: DR0 break-on-write not working

[REGRESSION 5.8] x86/entry: DR0 break-on-write not working

[Kyle Huey]

rr, a userspace record and replay debugger[0], has a test suite that
attempts to exercise strange corners of the Linux API. One such
test[1] began failing after 2bbc68f8373c0631ebf137f376fbea00e8086be7.
I have not tried to understand what has changed in the kernel here but
since the commit message says "No functional change" I assume
something has gone wrong.

The test expects to get a SIGTRAP when watchvar is written to in the
forked child, but instead the program just exits normally and we get a
status value corresponding to that (exit code 77 = wait status
0x4d00). This test program should be usable outside of rr's test suite
if you replace the test_assert/atomic_puts functions with
assert/printf and replace the util.h include with appropriate standard
includes.

This regression is present in 5.8.

- Kyle

[0] https://rr-project.org/
[1] https://github.com/mozilla/rr/blob/master/src/test/x86/ptrace_debug_regs.c#L55

Re: [REGRESSION 5.8] x86/entry: DR0 break-on-write not working

[peterz]

On Wed, Aug 19, 2020 at 10:53:58AM -0700, Kyle Huey wrote:
> rr, a userspace record and replay debugger[0], has a test suite that
> attempts to exercise strange corners of the Linux API. One such
> test[1] began failing after 2bbc68f8373c0631ebf137f376fbea00e8086be7.
> I have not tried to understand what has changed in the kernel here but
> since the commit message says "No functional change" I assume
> something has gone wrong.
> 
> The test expects to get a SIGTRAP when watchvar is written to in the
> forked child, but instead the program just exits normally and we get a
> status value corresponding to that (exit code 77 = wait status
> 0x4d00). This test program should be usable outside of rr's test suite
> if you replace the test_assert/atomic_puts functions with
> assert/printf and replace the util.h include with appropriate standard
> includes.
> 
> This regression is present in 5.8.

$ uname -a
Linux ivb-ep 5.9.0-rc1-dirty #343 SMP PREEMPT Wed Aug 19 15:04:35 CEST 2020 x86_64 GNU/Linux

$ ./ptrace_debug_regs
FAILED: errno=0 (Success)
ptrace_debug_regs: ptrace_debug_regs.c:104: main: Assertion `"FAILED: !" && check_cond(status == ((5 << 8) | 0x7f))' failed.
Aborted

I'm guess that is not the expected outcome, is that the same failure you
saw?

---
/* -*- Mode: C; tab-width: 8; c-basic-offset: 2; indent-tabs-mode: nil; -*- */

#include <stdio.h>
#include <unistd.h>
#include <sys/types.h>
#include <sys/ptrace.h>
#include <stdarg.h>
#include <assert.h>
#include <sys/wait.h>
#include <errno.h>
#include <string.h>
#include <stddef.h>
#include <sys/user.h>

/**
 * Print the printf-like arguments to stdout as atomic-ly as we can
 * manage.  Async-signal-safe.  Does not flush stdio buffers (doing so
 * isn't signal safe).
 */
__attribute__((format(printf, 1, 2))) inline static int atomic_printf(
    const char* fmt, ...) {
  va_list args;
  char buf[1024];
  int len;

  va_start(args, fmt);
  len = vsnprintf(buf, sizeof(buf) - 1, fmt, args);
  va_end(args);
  return write(STDOUT_FILENO, buf, len);
}

/**
 * Write |str| on its own line to stdout as atomic-ly as we can
 * manage.  Async-signal-safe.  Does not flush stdio buffers (doing so
 * isn't signal safe).
 */
inline static int atomic_puts(const char* str) {
  return atomic_printf("%s\n", str);
}

inline static int check_cond(int cond) {
  if (!cond) {
    atomic_printf("FAILED: errno=%d (%s)\n", errno, strerror(errno));
  }
  return cond;
}

#define test_assert(cond) assert("FAILED: !" && check_cond(cond))

#define NEW_VALUE 0xabcdef

static void breakpoint(void) {}

static char watch_var;

int main(void) {
  pid_t child;
  int status;
  int pipe_fds[2];

  test_assert(0 == pipe(pipe_fds));

  if (0 == (child = fork())) {
    char ch;
    read(pipe_fds[0], &ch, 1);
    breakpoint();
    watch_var = 1;
    return 77;
  }

  test_assert(0 == ptrace(PTRACE_ATTACH, child, NULL, NULL));
  test_assert(child == waitpid(child, &status, 0));
  test_assert(status == ((SIGSTOP << 8) | 0x7f));
  test_assert(1 == write(pipe_fds[1], "x", 1));

  test_assert(0 == ptrace(PTRACE_POKEUSER, child,
                          (void*)offsetof(struct user, u_debugreg[0]),
                          (void*)breakpoint));
  /* Enable DR0 break-on-exec */
  test_assert(0 == ptrace(PTRACE_POKEUSER, child,
                          (void*)offsetof(struct user, u_debugreg[7]),
                          (void*)0x1));

  test_assert(0 == ptrace(PTRACE_CONT, child, NULL, NULL));
  test_assert(child == waitpid(child, &status, 0));
  test_assert(status == ((SIGTRAP << 8) | 0x7f));
  test_assert(0x1 == ptrace(PTRACE_PEEKUSER, child,
                            (void*)offsetof(struct user, u_debugreg[6])));

  test_assert(0 == ptrace(PTRACE_POKEUSER, child,
                          (void*)offsetof(struct user, u_debugreg[0]),
                          &watch_var));
  /* Enable DR0 break-on-write */
  test_assert(0 == ptrace(PTRACE_POKEUSER, child,
                          (void*)offsetof(struct user, u_debugreg[7]),
                          (void*)0x10001));

  test_assert(0 == ptrace(PTRACE_CONT, child, NULL, NULL));
  test_assert(child == waitpid(child, &status, 0));
  test_assert(status == ((SIGTRAP << 8) | 0x7f));
  test_assert(0x1 == ptrace(PTRACE_PEEKUSER, child,
                            (void*)offsetof(struct user, u_debugreg[6])));

  test_assert(0 == ptrace(PTRACE_DETACH, child, NULL, NULL));

  test_assert(child == waitpid(child, &status, 0));
  test_assert(WIFEXITED(status));
  test_assert(WEXITSTATUS(status) == 77);

  atomic_puts("EXIT-SUCCESS");
  return 0;
}

Re: [REGRESSION 5.8] x86/entry: DR0 break-on-write not working

[Kyle Huey]

On Wed, Aug 19, 2020 at 11:42 AM <peterz@infradead.org> wrote:
>
> On Wed, Aug 19, 2020 at 10:53:58AM -0700, Kyle Huey wrote:
> > rr, a userspace record and replay debugger[0], has a test suite that
> > attempts to exercise strange corners of the Linux API. One such
> > test[1] began failing after 2bbc68f8373c0631ebf137f376fbea00e8086be7.
> > I have not tried to understand what has changed in the kernel here but
> > since the commit message says "No functional change" I assume
> > something has gone wrong.
> >
> > The test expects to get a SIGTRAP when watchvar is written to in the
> > forked child, but instead the program just exits normally and we get a
> > status value corresponding to that (exit code 77 = wait status
> > 0x4d00). This test program should be usable outside of rr's test suite
> > if you replace the test_assert/atomic_puts functions with
> > assert/printf and replace the util.h include with appropriate standard
> > includes.
> >
> > This regression is present in 5.8.
>
> $ uname -a
> Linux ivb-ep 5.9.0-rc1-dirty #343 SMP PREEMPT Wed Aug 19 15:04:35 CEST 2020 x86_64 GNU/Linux
>
> $ ./ptrace_debug_regs
> FAILED: errno=0 (Success)
> ptrace_debug_regs: ptrace_debug_regs.c:104: main: Assertion `"FAILED: !" && check_cond(status == ((5 << 8) | 0x7f))' failed.
> Aborted
>
> I'm guess that is not the expected outcome, is that the same failure you
> saw?

Yes. Is status also 0x4d00 for you?

The program is expected to complete with no assertions firing.

- Kyle

> ---
> /* -*- Mode: C; tab-width: 8; c-basic-offset: 2; indent-tabs-mode: nil; -*- */
>
> #include <stdio.h>
> #include <unistd.h>
> #include <sys/types.h>
> #include <sys/ptrace.h>
> #include <stdarg.h>
> #include <assert.h>
> #include <sys/wait.h>
> #include <errno.h>
> #include <string.h>
> #include <stddef.h>
> #include <sys/user.h>
>
> /**
>  * Print the printf-like arguments to stdout as atomic-ly as we can
>  * manage.  Async-signal-safe.  Does not flush stdio buffers (doing so
>  * isn't signal safe).
>  */
> __attribute__((format(printf, 1, 2))) inline static int atomic_printf(
>     const char* fmt, ...) {
>   va_list args;
>   char buf[1024];
>   int len;
>
>   va_start(args, fmt);
>   len = vsnprintf(buf, sizeof(buf) - 1, fmt, args);
>   va_end(args);
>   return write(STDOUT_FILENO, buf, len);
> }
>
> /**
>  * Write |str| on its own line to stdout as atomic-ly as we can
>  * manage.  Async-signal-safe.  Does not flush stdio buffers (doing so
>  * isn't signal safe).
>  */
> inline static int atomic_puts(const char* str) {
>   return atomic_printf("%s\n", str);
> }
>
> inline static int check_cond(int cond) {
>   if (!cond) {
>     atomic_printf("FAILED: errno=%d (%s)\n", errno, strerror(errno));
>   }
>   return cond;
> }
>
> #define test_assert(cond) assert("FAILED: !" && check_cond(cond))
>
> #define NEW_VALUE 0xabcdef
>
> static void breakpoint(void) {}
>
> static char watch_var;
>
> int main(void) {
>   pid_t child;
>   int status;
>   int pipe_fds[2];
>
>   test_assert(0 == pipe(pipe_fds));
>
>   if (0 == (child = fork())) {
>     char ch;
>     read(pipe_fds[0], &ch, 1);
>     breakpoint();
>     watch_var = 1;
>     return 77;
>   }
>
>   test_assert(0 == ptrace(PTRACE_ATTACH, child, NULL, NULL));
>   test_assert(child == waitpid(child, &status, 0));
>   test_assert(status == ((SIGSTOP << 8) | 0x7f));
>   test_assert(1 == write(pipe_fds[1], "x", 1));
>
>   test_assert(0 == ptrace(PTRACE_POKEUSER, child,
>                           (void*)offsetof(struct user, u_debugreg[0]),
>                           (void*)breakpoint));
>   /* Enable DR0 break-on-exec */
>   test_assert(0 == ptrace(PTRACE_POKEUSER, child,
>                           (void*)offsetof(struct user, u_debugreg[7]),
>                           (void*)0x1));
>
>   test_assert(0 == ptrace(PTRACE_CONT, child, NULL, NULL));
>   test_assert(child == waitpid(child, &status, 0));
>   test_assert(status == ((SIGTRAP << 8) | 0x7f));
>   test_assert(0x1 == ptrace(PTRACE_PEEKUSER, child,
>                             (void*)offsetof(struct user, u_debugreg[6])));
>
>   test_assert(0 == ptrace(PTRACE_POKEUSER, child,
>                           (void*)offsetof(struct user, u_debugreg[0]),
>                           &watch_var));
>   /* Enable DR0 break-on-write */
>   test_assert(0 == ptrace(PTRACE_POKEUSER, child,
>                           (void*)offsetof(struct user, u_debugreg[7]),
>                           (void*)0x10001));
>
>   test_assert(0 == ptrace(PTRACE_CONT, child, NULL, NULL));
>   test_assert(child == waitpid(child, &status, 0));
>   test_assert(status == ((SIGTRAP << 8) | 0x7f));
>   test_assert(0x1 == ptrace(PTRACE_PEEKUSER, child,
>                             (void*)offsetof(struct user, u_debugreg[6])));
>
>   test_assert(0 == ptrace(PTRACE_DETACH, child, NULL, NULL));
>
>   test_assert(child == waitpid(child, &status, 0));
>   test_assert(WIFEXITED(status));
>   test_assert(WEXITSTATUS(status) == 77);
>
>   atomic_puts("EXIT-SUCCESS");
>   return 0;
> }

Re: [REGRESSION 5.8] x86/entry: DR0 break-on-write not working

[Peter Zijlstra]

On Wed, Aug 19, 2020 at 12:28:16PM -0700, Kyle Huey wrote:

> > I'm guess that is not the expected outcome, is that the same failure you
> > saw?
> 
> Yes. Is status also 0x4d00 for you?

Indeed.

> The program is expected to complete with no assertions firing.

When I comment out the break-on-exec test, the break-on-write test
succeeds.

When I add a few printk()'s to our #DB handler (6) the program will
magically work again.

I'm not much for ptrace(), but are we sure the test program is well
behaved?

The below also always works..

---
/* -*- Mode: C; tab-width: 8; c-basic-offset: 2; indent-tabs-mode: nil; -*- */

#include <stdio.h>
#include <unistd.h>
#include <sys/types.h>
#include <sys/ptrace.h>
#include <stdarg.h>
#include <assert.h>
#include <sys/wait.h>
#include <errno.h>
#include <string.h>
#include <stddef.h>
#include <sys/user.h>

/**
 * Print the printf-like arguments to stdout as atomic-ly as we can
 * manage.  Async-signal-safe.  Does not flush stdio buffers (doing so
 * isn't signal safe).
 */
__attribute__((format(printf, 1, 2))) inline static int atomic_printf(
    const char* fmt, ...) {
  va_list args;
  char buf[1024];
  int len;

  va_start(args, fmt);
  len = vsnprintf(buf, sizeof(buf) - 1, fmt, args);
  va_end(args);
  return write(STDOUT_FILENO, buf, len);
}

/**
 * Write |str| on its own line to stdout as atomic-ly as we can
 * manage.  Async-signal-safe.  Does not flush stdio buffers (doing so
 * isn't signal safe).
 */
inline static int atomic_puts(const char* str) {
  return atomic_printf("%s\n", str);
}

inline static int check_cond(int cond) {
  if (!cond) {
    atomic_printf("FAILED: errno=%d (%s)\n", errno, strerror(errno));
  }
  return cond;
}

#define test_assert(cond) assert("FAILED: !" && check_cond(cond))

#define NEW_VALUE 0xabcdef

static void breakpoint(void) {}

static char watch_var;

int main(void) {
  pid_t child;
  int status;
  int pipe_fds[2];

  test_assert(0 == pipe(pipe_fds));

  if (0 == (child = fork())) {
    char ch;
    read(pipe_fds[0], &ch, 1);
    breakpoint();
    watch_var = 1;
    return 77;
  }

  test_assert(0 == ptrace(PTRACE_ATTACH, child, NULL, NULL));
  test_assert(child == waitpid(child, &status, 0));
  test_assert(status == ((SIGSTOP << 8) | 0x7f));
  test_assert(1 == write(pipe_fds[1], "x", 1));

  test_assert(0 == ptrace(PTRACE_POKEUSER, child,
                          (void*)offsetof(struct user, u_debugreg[0]),
                          (void*)breakpoint));
  test_assert(0 == ptrace(PTRACE_POKEUSER, child,
                          (void*)offsetof(struct user, u_debugreg[1]),
                          &watch_var));
  test_assert(0 == ptrace(PTRACE_POKEUSER, child,
                          (void*)offsetof(struct user, u_debugreg[7]),
                          (void*)0x100005));

  test_assert(0 == ptrace(PTRACE_CONT, child, NULL, NULL));
  test_assert(child == waitpid(child, &status, 0));
  test_assert(status == ((SIGTRAP << 8) | 0x7f));
  test_assert(0x1 == ptrace(PTRACE_PEEKUSER, child,
                            (void*)offsetof(struct user, u_debugreg[6])));

  test_assert(0 == ptrace(PTRACE_CONT, child, NULL, NULL));
  test_assert(child == waitpid(child, &status, 0));
  test_assert(status == ((SIGTRAP << 8) | 0x7f));
  test_assert(0x2 == ptrace(PTRACE_PEEKUSER, child,
                            (void*)offsetof(struct user, u_debugreg[6])));

  test_assert(0 == ptrace(PTRACE_DETACH, child, NULL, NULL));

  test_assert(child == waitpid(child, &status, 0));
  test_assert(WIFEXITED(status));
  test_assert(WEXITSTATUS(status) == 77);

  atomic_puts("EXIT-SUCCESS");
  return 0;
}

Re: [REGRESSION 5.8] x86/entry: DR0 break-on-write not working

[Josh Poimboeuf]

On Wed, Aug 19, 2020 at 11:35:34PM +0200, Peter Zijlstra wrote:
> On Wed, Aug 19, 2020 at 12:28:16PM -0700, Kyle Huey wrote:
> 
> > > I'm guess that is not the expected outcome, is that the same failure you
> > > saw?
> > 
> > Yes. Is status also 0x4d00 for you?
> 
> Indeed.
> 
> > The program is expected to complete with no assertions firing.
> 
> When I comment out the break-on-exec test, the break-on-write test
> succeeds.
> 
> When I add a few printk()'s to our #DB handler (6) the program will
> magically work again.

I added some trace_printk()'s and I think the #DB handler is calling
schedule????

exc_debug_user()
  irqentry_exit_to_user_mode()
    exit_to_user_mode_prepare()
      exit_to_user_mode_loop()
        schedule()

So #DB schedules out, then the process scheduls in and tells ptrace to
set the data breakpoint in DR7.  Then the #DB handler schedules back in
and overwrites DR7 with the original value.

What amazes me is that it successfully schedules back to the end of the
#DB handler finish and everything keeps working.

Do we not have assertions in the scheduler to catch this?

-- 
Josh

Re: [REGRESSION 5.8] x86/entry: DR0 break-on-write not working

[Andy Lutomirski]

On Wed, Aug 19, 2020 at 3:47 PM Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>
> On Wed, Aug 19, 2020 at 11:35:34PM +0200, Peter Zijlstra wrote:
> > On Wed, Aug 19, 2020 at 12:28:16PM -0700, Kyle Huey wrote:
> >
> > > > I'm guess that is not the expected outcome, is that the same failure you
> > > > saw?
> > >
> > > Yes. Is status also 0x4d00 for you?
> >
> > Indeed.
> >
> > > The program is expected to complete with no assertions firing.
> >
> > When I comment out the break-on-exec test, the break-on-write test
> > succeeds.
> >
> > When I add a few printk()'s to our #DB handler (6) the program will
> > magically work again.
>
> I added some trace_printk()'s and I think the #DB handler is calling
> schedule????
>
> exc_debug_user()
>   irqentry_exit_to_user_mode()
>     exit_to_user_mode_prepare()
>       exit_to_user_mode_loop()
>         schedule()
>
> So #DB schedules out, then the process scheduls in and tells ptrace to
> set the data breakpoint in DR7.  Then the #DB handler schedules back in
> and overwrites DR7 with the original value.
>
> What amazes me is that it successfully schedules back to the end of the
> #DB handler finish and everything keeps working.
>
> Do we not have assertions in the scheduler to catch this?

You almost nailed it.

I'm pretty sure you have the buggy sequence of events right, but for
the wrong reason.  There's nothing wrong with scheduling when
delivering SIGTRAP, but it's definitely wrong to blindly save and
restore DR7 around scheduling and around ptrace invocations.  Remember
this is an entry from user mode, so it runs on the user stack.

Patch coming.

--Andy

Re: [REGRESSION 5.8] x86/entry: DR0 break-on-write not working

[Josh Poimboeuf]

On Wed, Aug 19, 2020 at 05:14:18PM -0700, Andy Lutomirski wrote:
> On Wed, Aug 19, 2020 at 3:47 PM Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> > What amazes me is that it successfully schedules back to the end of the
> > #DB handler finish and everything keeps working.
> >
> > Do we not have assertions in the scheduler to catch this?
> 
> You almost nailed it.
> 
> I'm pretty sure you have the buggy sequence of events right, but for
> the wrong reason.  There's nothing wrong with scheduling when
> delivering SIGTRAP, but it's definitely wrong to blindly save and
> restore DR7 around scheduling and around ptrace invocations.  Remember
> this is an entry from user mode, so it runs on the user stack.

Wow, I had no idea user #DB's run on the task stack.  The scheduling
from #DB blew my mind :-)  What's the purpose of that?

-- 
Josh

Re: [REGRESSION 5.8] x86/entry: DR0 break-on-write not working

[peterz]

On Wed, Aug 19, 2020 at 10:46:36PM -0500, Josh Poimboeuf wrote:
> On Wed, Aug 19, 2020 at 05:14:18PM -0700, Andy Lutomirski wrote:

> > I'm pretty sure you have the buggy sequence of events right, but for
> > the wrong reason.  There's nothing wrong with scheduling when
> > delivering SIGTRAP, but it's definitely wrong to blindly save and
> > restore DR7 around scheduling and around ptrace invocations.  Remember
> > this is an entry from user mode, so it runs on the user stack.

*groan*, yeah that's broken :/

> Wow, I had no idea user #DB's run on the task stack.  The scheduling
> from #DB blew my mind :-)  What's the purpose of that?

At the very least that vm86 junk needs to I think. Also -RT needs it to
send signals.