Bug 455095 - event trace syscall on i386 has bogus parameters
event trace syscall on i386 has bogus parameters
Status: CLOSED ERRATA
Product: Red Hat Enterprise MRG
Classification: Red Hat
Component: realtime-kernel (Show other bugs)
1.1
i386 Linux
low Severity low
: 1.1
: ---
Assigned To: Steven Rostedt
:
Depends On:
Blocks: 474683
  Show dependency treegraph
 
Reported: 2008-07-11 17:56 EDT by Steven Rostedt
Modified: 2009-01-22 05:45 EST (History)
4 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2009-01-22 05:45:08 EST
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
fix event tracer function annotations (1.31 KB, patch)
2008-07-11 18:54 EDT, Steven Rostedt
no flags Details | Diff
use passed in edx register on i386 (2.35 KB, patch)
2008-07-11 18:56 EDT, Steven Rostedt
no flags Details | Diff
fix parameter passing for i386 event system call tracer (1.08 KB, patch)
2008-12-04 11:51 EST, Steven Rostedt
no flags Details | Diff

  None (edit)
Description Steven Rostedt 2008-07-11 17:56:58 EDT
Description of problem:

The events_trace tracer on i386 gives bad parameters to syscalls.

This is due to a couple of things. One is that the sys_call interface needs
to use the assmebly linked annotation, and the other is that the
edx register is used before it is stored on the stack.

Expect two patches to follow.
Comment 1 Steven Rostedt 2008-07-11 18:54:26 EDT
Created attachment 311623 [details]
fix event tracer function annotations

This patch fixes the function annotations of the event trace. The main fix is
adding asmlinkage annotation to the sys_call function to give the syscalls in
the event trace correct parameter recording on i386.
Comment 2 Steven Rostedt 2008-07-11 18:56:06 EDT
Created attachment 311624 [details]
use passed in edx register on i386

The edx register on i386 was being used after SAVE_ALL, so the wrong data was
being passed as the third parameter to the event tracer.
Comment 3 Luis Claudio R. Goncalves 2008-10-23 06:52:22 EDT
Added to -88
Comment 5 David Sommerseth 2008-11-26 15:29:59 EST
Difficult to say if this one is really fixed or not.  Tested on RHEL/32 with 2.6.24.7-81.el5rt and 2.6.24.7-81.el5rt

The following test program was used:
----------------------------------------------------
int main() {
  int fd;
  char *data = "0123456789";
  char buf[20];

  fd = open("test.file", O_CREAT | O_RDWR, 0660);
  write(fd, data, 10);
  lseek(fd, 0, SEEK_SET);
  read(fd, &buf, 10);
  close(fd);
  fprintf(stderr, "data = %lx\n", s);
  fprintf(stderr, "buf = %lx\n", &buf);
  return 0;
}
----------------------------------------------------

The test was executed with:
   # trace-cmd -e -l -f ./tracetest > test.log


For the -81 kernel, it was not possible to find much information about the different calls, as they were missing reference points to the code.

# grep tracetes test-81.log  | grep "sys_read ("
tracetes-4278  7.... 36775us : sys_read (syscall_call)
tracetes-4278  7.... 38010us : sys_read (syscall_call)

# grep tracetes test2-81.log  | grep "sys_write ("
tracetes-4278  7.... 37918us : sys_write (syscall_call)
tracetes-4278  7.... 38348us : sys_write (syscall_call)
tracetes-4278  7.... 38395us : sys_write (syscall_call)

For the -93 kernel, more information was found ... but seems to be some wrong formatting.

The output of the test program running on -93 kernel was:
-----------------------
data = 8048640
buf = bf855298
-----------------------

Trace logs shows ...

# grep tracetes test-93.log  | grep "sys_read ("
tracetes-4055  4.... 46586us : system_call sys_read (3 bf854ae8 bf854ae8)
tracetes-4055  4.... 46588us : sys_read (syscall_call)
tracetes-4055  4.... 56132us : sysenter_enter sys_read (3 bf855298 bf855298)
tracetes-4055  4.... 56134us : sys_read (syscall_call)

# grep tracetes test2-93_2.log  | grep "sysenter_enter"
tracetes-4055  5.... 36831us : sysenter_enter sys_execve (bf9cbbf6 bf9c9cb4 bf9c9cb4)
tracetes-4055  4.... 47643us : sysenter_enter sys_open (804864b 42 42)
tracetes-4055  4.... 47797us : sysenter_enter sys_write (3 8048640 8048640)
tracetes-4055  4.... 56125us : sysenter_enter sys_lseek (3 0 0)
tracetes-4055  4.... 56132us : sysenter_enter sys_read (3 bf855298 bf855298)
tracetes-4055  4.... 56165us : sysenter_enter sys_close (3 bf855298 bf855298)
tracetes-4055  4.... 56350us : sysenter_enter sys_write (2 bf852b78 bf852b78)
tracetes-4055  4.... 56416us : sysenter_enter sys_write (2 bf852b78 bf852b78)
tracetes-4055  4.... 56624us : sysenter_enter sys_exit_group (0 4 4)

Here the 2nd and 3rd parameter logged is identical, which I believe is wrong.  But the first sys_write matches the address to *data.  While the first sys_read matches the address to &buf.
Comment 6 Steven Rostedt 2008-12-04 11:51:56 EST
Created attachment 325706 [details]
fix parameter passing for i386 event system call tracer

The parameter index of the stack to retrieve the third parameter was wrong.

The SAVE_ALL code pushes the parameters in as:

  push edx
  push ecx
  push ebx

But it modifies edx before we get to the sys_call call. So we need to retrieve edx. But we also need to save it to its original value and we push it too.

  push edx
  move 8(esp), edx

The problem here is that, after the push edx, the index went from 8 to 12.
Comment 7 Beth Uptagrafft 2008-12-04 15:56:58 EST
The problem davids found in testing is i386 only.  BZ474683 was created to track the new i386 problem and the fix in Comment #6 (on 2008-12-04) will be targeted for the 1.1.1 release.

The fix in BZ455095 will remain in the 1.1 release.
Comment 8 David Sommerseth 2008-12-10 04:39:13 EST
Moved to verified, as the extra patch needed will be implemented in a later release.  This patch is found in bug #474683.

Even though, this bug is not completely fixed, it is after all an improvement from the MRG-1.0.3 release (-81 kernel).  And it is definitely not a regression.
Comment 10 errata-xmlrpc 2009-01-22 05:45:08 EST
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-0009.html

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