Bug 495125 - ptrace: wrong value for bp register at syscall entry tracing
ptrace: wrong value for bp register at syscall entry tracing
Status: CLOSED ERRATA
Product: Red Hat Enterprise Linux 5
Classification: Red Hat
Component: kernel (Show other bugs)
5.3
x86_64 Linux
low Severity medium
: rc
: ---
Assigned To: Jiri Olsa
Red Hat Kernel QE team
:
Depends On:
Blocks: 329781
  Show dependency treegraph
 
Reported: 2009-04-09 16:18 EDT by David Smith
Modified: 2009-09-02 04:59 EDT (History)
5 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2009-09-02 04:59:02 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
test program source (540 bytes, text/x-csrc)
2009-04-09 16:19 EDT, David Smith
no flags Details
another reproducer (1017 bytes, application/x-bzip2)
2009-05-06 09:09 EDT, Jiri Olsa
no flags Details


External Trackers
Tracker ID Priority Status Summary Last Updated
Red Hat Product Errata RHSA-2009:1243 normal SHIPPED_LIVE Important: Red Hat Enterprise Linux 5.4 kernel security and bug fix update 2009-09-01 04:53:34 EDT

  None (edit)
Description David Smith 2009-04-09 16:18:56 EDT
Description of problem:

On x86_64, strace is reporting invalid values of the 6th syscall argument when run on 32-bit executables.

Version-Release number of selected component (if applicable):

kernel: 2.6.18-128.1.6.el5
strace: 4.5.18-2.el5_3.3

How reproducible:

Every time.

Steps to Reproduce:
1. compile the attached test program as a 32-bit executable:

# gcc -m32 -o syscall_args syscall_args.c

2. run the 32-bit executable on the 64-bit machine under strace

# strace syscall_args
  
Actual results:

  ...
  open("foobar", O_RDONLY)                = 3
  fstat64(3, {st_mode=S_IFREG|0600, st_size=1030, ...}) = 0
  mmap2(NULL, 1030, PROT_READ, MAP_SHARED, 3, 0x406) = 0xfffffffff7f67000
  munmap(0xf7f67000, 1030)                = 0
  close(3)                                = 0

Expected results:

The mmap2 line should have read:

  mmap2(NULL, 1030, PROT_READ, MAP_SHARED, 3, 0x0) = 0xfffffffff7f67000

The last argument should have been 0.

Additional info:

The above was run on a kvm instance.  Debugging the executable with gdb shows that the "syscall" instruction is being used in __kernel_vsyscall().

Running the same executable on actual hardware (no kvm), I get the following output from strace:

  open("foobar", O_RDONLY)                = 3
  fstat64(3, {st_mode=S_IFREG|0600, st_size=1030, ...}) = 0
  mmap2(NULL, 1030, PROT_READ, MAP_SHARED, 3, 0xffcf733c) = 0xfffffffff7ff9000
  munmap(0xf7ff9000, 1030)                = 0
  close(3)                                = 0

The last mmap2 argument is still invalid, but it is different than what I get on the kvm instance.  On this machine, debugging the executable with gdb shows that the "sysenter" instruction is being used in __kernel_vsyscall().

32-bit versions of strace on the 64-bit machines report the same invalid values.
Comment 1 David Smith 2009-04-09 16:19:35 EDT
Created attachment 338990 [details]
test program source
Comment 2 Denys Vlasenko 2009-04-14 10:22:09 EDT
It happens even with latest upstream of strace, but doesn't happen on F9.

I added this "offset:xxxx" printout to strace source:

int
sys_mmap(tcp)
struct tcb *tcp;
{
        long long offset = tcp->u_arg[5];

#if defined(LINUX) && defined(SH64)
        /*
         * Old mmap differs from new mmap in specifying the
         * offset in units of bytes rather than pages.  We
         * pretend it's in byte units so the user only ever
         * sees bytes in the printout.
         */
        offset <<= PAGE_SHIFT;
#endif
#if defined(LINUX_MIPSN32)
        offset = tcp->ext_arg[5];
#endif
tprintf("\noffset:%llx (%lx,%lx,%lx,%lx,%lx,%lx)\n", offset, tcp->u_arg[0], tcp->u_arg[1], tcp->u_arg[2], tcp->u_arg[3], tcp->u_arg[4], tcp->u_arg[5]);
        return print_mmap(tcp, tcp->u_arg, offset);
}

and I see this:

mmap2(
offset:ffa8ac4c (0,406,1,1,3,ffa8ac4c)
       ^^^^^^^^              ^^^^^^^^
NULL, 1030, PROT_READ, MAP_SHARED, 3, 0xffa8ac4c
offset:ffa8ac4c (0,406,1,1,3,ffa8ac4c)
) = 0xfffffffff7f6f000

Clearly, tcp->u_arg[5] is wrong. And this wrong value seems to be coming from kernel, it is not "invented" by strace. I straced strace itself and I see:

wait4(4294967295, 0x7ffff3e6954c, WNOHANG|__WALL, NULL) = 0
rt_sigprocmask(SIG_BLOCK, [HUP INT QUIT PIPE TERM], NULL, 8) = 0
ptrace(PTRACE_PEEKUSER, 25646, 8*ORIG_RAX, [0xc0]) = 0
ptrace(PTRACE_PEEKUSER, 25646, 8*CS, [0x23]) = 0
ptrace(PTRACE_PEEKUSER, 25646, 8*RAX, [0xffffffda]) = 0
ptrace(PTRACE_PEEKUSER, 25646, 8*RBX, [0]) = 0
ptrace(PTRACE_PEEKUSER, 25646, 8*RCX, [0x406]) = 0
ptrace(PTRACE_PEEKUSER, 25646, 8*RDX, [0x1]) = 0
ptrace(PTRACE_PEEKUSER, 25646, 8*RSI, [0x1]) = 0
ptrace(PTRACE_PEEKUSER, 25646, 8*RDI, [0x3]) = 0
ptrace(PTRACE_PEEKUSER, 25646, 8*RBP, [0xffa8ac4c]) = 0
                                      ^^^^^^^^^^^^
write(2, "mmap2(\n", 7)                 = 7
write(2, "offset:ffa8ac4c (0,406,1,1,3,ffa"..., 39) = 39
write(2, "NULL, 1030, PROT_READ, MAP_SHARE"..., 48) = 48
....

The bad value came from kernel via ptrace(PTRACE_PEEKUSER, 25646, 8*RBP).

On F9:

wait4(4294967295, 0x7fff24eaff4c, WNOHANG|__WALL, NULL) = 0
rt_sigprocmask(SIG_BLOCK, [HUP INT QUIT PIPE TERM], NULL, 8) = 0
ptrace(PTRACE_PEEKUSER, 19710, 8*ORIG_RAX, [0xc0]) = 0
ptrace(PTRACE_PEEKUSER, 19710, 8*CS, [0x23]) = 0
ptrace(PTRACE_PEEKUSER, 19710, 8*RAX, [0xffffffffffffffda]) = 0
ptrace(PTRACE_PEEKUSER, 19710, 8*RBX, [0]) = 0
ptrace(PTRACE_PEEKUSER, 19710, 8*RCX, [0x406]) = 0
ptrace(PTRACE_PEEKUSER, 19710, 8*RDX, [0x1]) = 0
ptrace(PTRACE_PEEKUSER, 19710, 8*RSI, [0x1]) = 0
ptrace(PTRACE_PEEKUSER, 19710, 8*RDI, [0x3]) = 0
ptrace(PTRACE_PEEKUSER, 19710, 8*RBP, [0]) = 0
write(2, "mmap2(\n", 7)                 = 7
write(2, "offset:0 (0,406,1,1,3,0)\n", 25) = 25
write(2, "NULL, 1030, PROT_READ, MAP_SHARE"..., 39) = 39

Looks like this kernel reports RBP correctly.

RHEL tested:

# uname -a
Linux hp-xw8400-01.rhts.bos.redhat.com 2.6.18-138.el5 #1 SMP Fri Apr 3 18:07:22 EDT 2009 x86_64 x86_64 x86_64 GNU/Linux

F9 tested:

# uname -a
Linux localhost.localdomain 2.6.29-0.28.rc1.fc11.x86_64 #1 SMP Sun Jan 11 20:52:37 EST 2009 x86_64 x86_64 x86_64 GNU/Linux
Comment 3 Roland McGrath 2009-04-14 16:17:58 EDT
Yes, we had already verified that this is a kernel bug and specific to RHEL5 kernels.
Comment 6 RHEL Product and Program Management 2009-05-04 11:28:58 EDT
This request was evaluated by Red Hat Product Management for inclusion in a Red
Hat Enterprise Linux maintenance release.  Product Management has requested
further review of this request by Red Hat Engineering, for potential
inclusion in a Red Hat Enterprise Linux Update release for currently deployed
products.  This request is not yet committed for inclusion in an Update
release.
Comment 7 Roland McGrath 2009-05-04 16:03:05 EDT
Note there were some later upstream patches after that one in this area.
I don't really recall the details, but I think the commit mentioned in comment#4 may have had some other regression.  Check all the upstream commits touching that code since.
Comment 8 Jiri Olsa 2009-05-06 09:09:13 EDT
Created attachment 342637 [details]
another reproducer

unpack and run make
for the test itself run: strace ./ex
for last 2 calls to mmap2:
- 1st one is done via int 0x80
- 2nd one is done via vdso (sysenter instr. on Intel, syscall instr. on AMD)
Comment 10 Don Zickus 2009-05-14 15:35:27 EDT
in kernel-2.6.18-148.el5
You can download this test kernel from http://people.redhat.com/dzickus/el5

Please do NOT transition this bugzilla state to VERIFIED until our QE team
has sent specific instructions indicating when to do so.  However feel free
to provide a comment indicating that this fix has been verified.
Comment 13 errata-xmlrpc 2009-09-02 04:59:02 EDT
An advisory has been issued which should help the problem
described in this bug report. This report is therefore being
closed with a resolution of ERRATA. For more information
on therefore solution and/or where to find the updated files,
please follow the link below. You may reopen this bug report
if the solution does not work for you.

http://rhn.redhat.com/errata/RHSA-2009-1243.html

Note You need to log in before you can comment on or make changes to this bug.