Bug 455095

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.

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.

Added to -88

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.

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.

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.

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.

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