utrace syscall arguments

utrace syscall arguments

[David Smith]

After reorganizing the utrace system call argument handling, I decided
that I really needed to write a testsuite test for them.  After doing
so, I ran the test, utrace_syscall_args.exp, on several systems.

In case anyone is interested, here's what I found:

arch    distro   kernel                          64-bit   32-bit
======  =======  ==============================  =======  =======
x86_64  f10      2.6.27.21-170.2.56.fc10.x86_64  pass     pass
x86_64  rawhide  2.6.29.1-70.fc11.x86_64         pass     pass
i686    RHEL5.3  2.6.18-128.1.6.el5              ----     pass
x86_64  RHEL5.3  2.6.18-128.1.6.el5              pass     fail[1]
ppc64   RHEL5.3  2.6.18-138.el5                  pass     pass
s390x   RHEL5.3  2.6.18-138.el5                  pass     fail[2]
ia64    RHEL5.3  2.6.18-138.el5                  fail[3]  ----

[1] This is a kernel problem.  The 6th syscall argument on 32-bit exes
on a 64-bit kernel is wrong.  RHBZ 495125 filed against this problem
(<https://bugzilla.redhat.com/show_bug.cgi?id=495125>)

[2] This might just be an system call that needs some extra processing
or a kernel problem.  RHBZ 495935 filed against this problem
(<https://bugzilla.redhat.com/show_bug.cgi?id=495935>)

[3] This appears to be an ia64 specific systemtap problem that someone
with actual ia64 knowledge will need to look at.  For system calls that
fail, all arguments come back as zeros.

-- 
David Smith
dsmith@redhat.com
Red Hat
http://www.redhat.com
256.217.0141 (direct)
256.837.0057 (fax)

Re: utrace syscall arguments

[Roland McGrath]

> [2] This might just be an system call that needs some extra processing
> or a kernel problem.  RHBZ 495935 filed against this problem
> (<https://bugzilla.redhat.com/show_bug.cgi?id=495935>)

That just looks like an strace bug for s390x biarch.
I'm a little confused as to how your stap test suite cares what strace thinks.

> [3] This appears to be an ia64 specific systemtap problem that someone
> with actual ia64 knowledge will need to look at.  For system calls that
> fail, all arguments come back as zeros.

I'm confused.  You can only get the syscall arguments at entry time, before
it is decided whether it succeeds or fails.  Or do you mean using a bogus
system call number?


Thanks,
Roland

Re: utrace syscall arguments

[David Smith]

Roland McGrath wrote:
>> [2] This might just be an system call that needs some extra processing
>> or a kernel problem.  RHBZ 495935 filed against this problem
>> (<https://bugzilla.redhat.com/show_bug.cgi?id=495935>)
> 
> That just looks like an strace bug for s390x biarch.
> I'm a little confused as to how your stap test suite cares what strace thinks.

The stap test doesn't really care what strace thinks.  But, when I get
odd results I always check them against what strace sees.  If strace and
stap see the same thing, it might be a kernel bug.  If only stap sees a
problem, I check further with strace.

For instance, on s390x, strace could decode the mmap call correctly for
64-bit executables but stap couldn't.  After running strace on strace, I
saw that strace did additional memory reads for mmap which the test now
does.

RHBZ 495935 shows that strace (and also stap, but I didn't mention that
in the bug) can't decode mmap calls correctly for 32-bit executables.

>> [3] This appears to be an ia64 specific systemtap problem that someone
>> with actual ia64 knowledge will need to look at.  For system calls that
>> fail, all arguments come back as zeros.
> 
> I'm confused.  You can only get the syscall arguments at entry time, before
> it is decided whether it succeeds or fails.  Or do you mean using a bogus
> system call number?

Actually, I meant both.  If the syscall fails or if I use a bogus
syscall number, the args all came back as 0.  Unfortunately, I can't
quite remember what strace did here.  I think it saw the arguments
correctly (but I'm not 100% sure).

-- 
David Smith
dsmith@redhat.com
Red Hat
http://www.redhat.com
256.217.0141 (direct)
256.837.0057 (fax)

Re: utrace syscall arguments

[Roland McGrath]

> Actually, I meant both.  If the syscall fails or if I use a bogus
> syscall number, the args all came back as 0.  

You mean "had come back", right?  That is, arguments as seen at the entry
tracing stop before success or failure has even come into being.  This is
very hard to grok.  If you trace open("/",O_WRONLY), entry tracing does not
see the right arguments because the kernel has looked into the future and
divined that you won't have permission on the filesystem when the call is
tried?  But what could possibly be different at entry from when you trace
open("/",O_RDONLY) and the call will then have been going to succeed?  If
you see the arguments at entry tracing and use syscall_set_arguments() to
change the second argument to O_WRONLY and then resume, does the kernel go
back in time to have failed to give you those arguments in the first place?
(And if so, does that make you your own grandpa?)

I feel positive I am missing something completely here!


Thanks,
Roland

Re: utrace syscall arguments

[Roland McGrath]

> I feel positive I am missing something completely here!

Oh, wait.  We are talking about ia64.  So it probably actually can go
forward and backward in time.  We need to get the ia64 kernel people on
this, for sure.  I can see the potential rip in the fabric of spacetime,
but I don't really understand all the physics involved much at all.  The
corners of this might well differ in RHEL5 vs the vanilla ia64 kernel.

I'm looking at arch/ia64/kernel/ptrace.c:ia64_syscall_get_set_arguments in
the vanilla kernel.  This gets the arguments off the kernel stack RBS.  It
does not take into account TIF_RESTORE_RSE.  If someone has done "writeback",
i.e. called user_regset.writeback in the kernel, or stopped for ptrace
(which does that or equivalent), then these words have all been copied to
the user stack RBS (plain normal user memory).  This user memory is where
strace knows to look.  When strace wants to change a syscall argument (-f
does this for clone2 syscalls), it pokes this memory.  The "writeback"
machinery has set TIF_RESTORE_RSE (at ptrace stop time, before the poke
could happen).  That makes the kernel copy this user stack data back to the
kernel stack RBS area before looking at those syscall arguments.

The kernel checks TIF_RESTORE_RSE after entry tracing and after exit
tracing.  That means if anything in the tracing callback caused "writeback"
(kernel RBS -> user memory), resumption after tracing will reload (user
memory -> kernel RBS).  In the vanilla kernel, "tracing" is ptrace stop,
which does the writeback.  

RHEL5 ptrace is a utrace engine whose callbacks call regset->writeback.
So if you are another utrace engine called before ptrace's (or you are
the only engine), writeback has not happened.  If you are called after
ptrace's engine, then the writeback has happened.  When ptrace is there,
the user memory words, as possibly modified between now and when you
resume after QUIESCE, are what will actually be the syscall's arguments.
But ia64_syscall_get_set_arguments will look at the kernel RBS words
instead.  (There is also the issue of these user memory words you want
to look at being modified after your callback, during quiescence, so you
are not there to see the eventual values.  That is in fact the subject
of Renzo Davoli's concern over on utrace-devel, so look there for that.)

If writeback has happened, then syscall_{get,set}_arguments() really
ought to be working with the new data.  It could do user memory access
if TIF_RESTORE_RSE.  Or it could synchronize back (i.e. so as to reset
TIF_RESTORE_RSE) before looking.  However, the latter is possibly
questionable since someone who called regset->writeback has the
expectation that the user memory is the authoritative state that will be
used by the process on resume, and might be examining it asynchronously.

In fact, I can't see how any angle of this could explain your failure
mode.  In your case, nobody is changing any values and AFAIK the copy
from kernel RBS doesn't molest the old data there, so the answers
ia64_syscall_get_set_arguments gives you ought to be right regardless.
But it is a real cloudy pile of issues that is real near what you are doing.


Thanks,
Roland

Re: utrace syscall arguments

[David Smith]

Roland McGrath wrote:
>> I feel positive I am missing something completely here!
> 
> Oh, wait.  We are talking about ia64.  So it probably actually can go
> forward and backward in time.  We need to get the ia64 kernel people on
> this, for sure.  I can see the potential rip in the fabric of spacetime,
> but I don't really understand all the physics involved much at all.  The
> corners of this might well differ in RHEL5 vs the vanilla ia64 kernel.

... interesting technical discussion deleted ...

OK, you've convinced me.  I'll try to get access to an ia64 machine
again and investigate further.

-- 
David Smith
dsmith@redhat.com
Red Hat
http://www.redhat.com
256.217.0141 (direct)
256.837.0057 (fax)

Re: utrace syscall arguments

[David Smith]

David Smith wrote:
> Roland McGrath wrote:
>>> I feel positive I am missing something completely here!
>> Oh, wait.  We are talking about ia64.  So it probably actually can go
>> forward and backward in time.  We need to get the ia64 kernel people on
>> this, for sure.  I can see the potential rip in the fabric of spacetime,
>> but I don't really understand all the physics involved much at all.  The
>> corners of this might well differ in RHEL5 vs the vanilla ia64 kernel.
> 
> ... interesting technical discussion deleted ...
> 
> OK, you've convinced me.  I'll try to get access to an ia64 machine
> again and investigate further.

Here's an update.  After looking at this more, I decided the systemtap
internal code to get syscall arguments was too far off the upstream
code.  So, I copied the upstream code into systemtap (and have checked
this in).

The good news is that syscall arguments look much better in general now
and I don't see the all args as 0 problem.  The bad news is that the
utrace_syscall_args test still doesn't pass.

The new symptom is that whenever I use "syscall(number, args...)",
systemtap sees the syscall number as the 1st argument.  Here's an
example from a small test program I wrote:

  fd = dup(2);
  close(fd);
  fd = syscall (__NR_dup, 2);
  close(fd);

Logically, these calls should appear to systemtap as identical (as they
do to strace).  Here's what I get:

---------
# stap -ve 'probe process("duptest").syscall {printf("%d(0x%x, 0x%x,
0x%x)\n", $syscall, $arg1, $arg2, $arg3)}' -c ./duptest
...
1057(0x2, 0xff2cd8fe79459316, 0x60000fffff923750)
1029(0x3, 0xff2cd8fe79459316, 0x60000fffff923750)
1057(0x421, 0x2, 0x60000fffff923750)
1029(0x3, 0x2, 0x60000fffff923750)
1236(0x0, 0x3, 0x0)
Pass 5: run completed in 21usr/97sys/204real ms.
---------

On ia64, dup is 1057.  The first dup call above works correctly and sees
the 1st argument as 2.  The second dup call sees 0x421 as the 1st
argument (0x421 is 1057) and 2 as the 2nd argument.

The utrace_syscall_args test sees the same problem.  When syscall() is
used, the arguments are shifted over by 1.

-- 
David Smith
dsmith@redhat.com
Red Hat
http://www.redhat.com
256.217.0141 (direct)
256.837.0057 (fax)

Re: utrace syscall arguments

[Masami Hiramatsu]

David Smith wrote:
> David Smith wrote:
>> Roland McGrath wrote:
>>>> I feel positive I am missing something completely here!
>>> Oh, wait.  We are talking about ia64.  So it probably actually can go
>>> forward and backward in time.  We need to get the ia64 kernel people on
>>> this, for sure.  I can see the potential rip in the fabric of spacetime,
>>> but I don't really understand all the physics involved much at all.  The
>>> corners of this might well differ in RHEL5 vs the vanilla ia64 kernel.
>> ... interesting technical discussion deleted ...
>>
>> OK, you've convinced me.  I'll try to get access to an ia64 machine
>> again and investigate further.
> 
> Here's an update.  After looking at this more, I decided the systemtap
> internal code to get syscall arguments was too far off the upstream
> code.  So, I copied the upstream code into systemtap (and have checked
> this in).
> 
> The good news is that syscall arguments look much better in general now
> and I don't see the all args as 0 problem.  The bad news is that the
> utrace_syscall_args test still doesn't pass.
> 
> The new symptom is that whenever I use "syscall(number, args...)",
> systemtap sees the syscall number as the 1st argument.  Here's an
> example from a small test program I wrote:
> 
>   fd = dup(2);
>   close(fd);
>   fd = syscall (__NR_dup, 2);
>   close(fd);
> 
> Logically, these calls should appear to systemtap as identical (as they
> do to strace).  Here's what I get:
> 
> ---------
> # stap -ve 'probe process("duptest").syscall {printf("%d(0x%x, 0x%x,
> 0x%x)\n", $syscall, $arg1, $arg2, $arg3)}' -c ./duptest
> ...
> 1057(0x2, 0xff2cd8fe79459316, 0x60000fffff923750)
> 1029(0x3, 0xff2cd8fe79459316, 0x60000fffff923750)
> 1057(0x421, 0x2, 0x60000fffff923750)
> 1029(0x3, 0x2, 0x60000fffff923750)
> 1236(0x0, 0x3, 0x0)
> Pass 5: run completed in 21usr/97sys/204real ms.
> ---------
> 
> On ia64, dup is 1057.  The first dup call above works correctly and sees
> the 1st argument as 2.  The second dup call sees 0x421 as the 1st
> argument (0x421 is 1057) and 2 as the 2nd argument.
> 
> The utrace_syscall_args test sees the same problem.  When syscall() is
> used, the arguments are shifted over by 1.

AFAICS in glibc, sysdeps/unix/sysv/linux/ia64/syscall.S
uses alloc to shift arguments (skips 1st argument) as below.
---
ENTRY(syscall)
	alloc r2=ar.pfs,1,0,8,0
	mov r15=r32		/* syscall number */
	break __BREAK_SYSCALL
	;;
---
This frame will be used when calling syscall handlers,
and it will be saved in cr_ifs.
So, I guess it is possible that we can check the system
call is syscall or not by checking cr_ifs.

Thanks,

-- 
Masami Hiramatsu

Software Engineer
Hitachi Computer Products (America) Inc.
Software Solutions Division

e-mail: mhiramat@redhat.com

Re: utrace syscall arguments

[Roland McGrath]

> This frame will be used when calling syscall handlers,
> and it will be saved in cr_ifs.
> So, I guess it is possible that we can check the system
> call is syscall or not by checking cr_ifs.

Now you are speaking ia64 and I am lost!  Ok, I guess I understand it a
little better than if you'd answered in Japanese, but not that much
better. ;-)

It sounds like you might have a fix to suggest to the upstream ia64
maintainers to use in arch/ia64/kernel/ptrace.c:syscall_get_set_args_cb.

The mandate for asm/syscall.h is to report/modify what system call number
and arguments the kernel would actually act on, whatever the details of the
user state and style of kernel entry.  Whatever ia64 magic is required to
make that true is what this arch code should be doing.


Thanks,
Roland

Re: utrace syscall arguments

[Masami Hiramatsu]

Roland McGrath wrote:
>> This frame will be used when calling syscall handlers,
>> and it will be saved in cr_ifs.
>> So, I guess it is possible that we can check the system
>> call is syscall or not by checking cr_ifs.
> 
> Now you are speaking ia64 and I am lost!  Ok, I guess I understand it a
> little better than if you'd answered in Japanese, but not that much
> better. ;-)

Sure, that's ia64 local language:-)

> It sounds like you might have a fix to suggest to the upstream ia64
> maintainers to use in arch/ia64/kernel/ptrace.c:syscall_get_set_args_cb.

I think we need to fix syscall_get_set_args_cb too.
I'll check that we can fix this issue by using cr_ifs.

> The mandate for asm/syscall.h is to report/modify what system call number
> and arguments the kernel would actually act on, whatever the details of the
> user state and style of kernel entry.  Whatever ia64 magic is required to
> make that true is what this arch code should be doing.

Agreed.

Thanks,

-- 
Masami Hiramatsu

Software Engineer
Hitachi Computer Products (America) Inc.
Software Solutions Division

e-mail: mhiramat@redhat.com

Re: utrace syscall arguments

[David Smith]

Masami Hiramatsu wrote:
> Roland McGrath wrote:
>>> This frame will be used when calling syscall handlers,
>>> and it will be saved in cr_ifs.
>>> So, I guess it is possible that we can check the system
>>> call is syscall or not by checking cr_ifs.
>> Now you are speaking ia64 and I am lost!  Ok, I guess I understand it a
>> little better than if you'd answered in Japanese, but not that much
>> better. ;-)
> 
> Sure, that's ia64 local language:-)
> 
>> It sounds like you might have a fix to suggest to the upstream ia64
>> maintainers to use in arch/ia64/kernel/ptrace.c:syscall_get_set_args_cb.
> 
> I think we need to fix syscall_get_set_args_cb too.
> I'll check that we can fix this issue by using cr_ifs.

Since strace handles syscall() correctly, you might be able to steal
some logic from it.

-- 
David Smith
dsmith@redhat.com
Red Hat
http://www.redhat.com
256.217.0141 (direct)
256.837.0057 (fax)

[PATCH][BUGFIX] ia64: fix syscall_get_set_args_cb() to handle arguments correctly

[Masami Hiramatsu]

Hi,

Here is the patch which fixes utrace on ia64 issue.
I'll post same fix on the upstream kernel later.

Fix syscall_get_set_args_cb() to decode user-stack correctly in case of
syscall() which allocates locals in user-stack. If locals (cfm.sol) exist
on the stack, we have to skip it for getting systemcall arguments.

And also, fix the number of getting arguments which must be less than
(nr outputs - args->i) instead of nr outputs, because args->i is the
indent number (this means, syscall_get_set_args_cb() get/set arguments
from (i)th to (i+n)th.)

---
 runtime/syscall.h |   13 ++++++++++---
 1 file changed, 10 insertions(+), 3 deletions(-)

Index: systemtap/runtime/syscall.h
===================================================================
--- systemtap.orig/runtime/syscall.h
+++ systemtap/runtime/syscall.h
@@ -345,6 +345,10 @@ struct syscall_get_set_args {
 	int rw;
 };

+#define CFM_SOF(cfm) ((cfm) & 0x7f)			/* Size of frame */
+#define CFM_SOL(cfm) (((cfm) >> 7) & 0x7f)		/* Size of locals */
+#define CFM_OUT(cfm) (CFM_SOF(cfm) - CFM_SOL(cfm))	/* Size of outputs */
+
 static void syscall_get_set_args_cb(struct unw_frame_info *info, void *data)
 {
 	struct syscall_get_set_args *args = data;
@@ -361,15 +365,18 @@ static void syscall_get_set_args_cb(stru

 	count = 0;
 	if (in_syscall(pt))
-		count = min_t(int, args->n, cfm & 0x7f);
+		/* args->i + args->n must be less equal than nr outputs */
+		count = min_t(int, args->n, CFM_OUT(cfm) - args->i);

 	for (i = 0; i < count; i++) {
+		/* Skips dirties and locals */
 		if (args->rw)
-			*ia64_rse_skip_regs(krbs, ndirty + i + args->i) =
+			*ia64_rse_skip_regs(krbs,
+				ndirty + CFM_SOL(cfm) + args->i + i) =
 				args->args[i];
 		else
 			args->args[i] = *ia64_rse_skip_regs(krbs,
-				ndirty + i + args->i);
+				ndirty + CFM_SOL(cfm) + args->i + i);
 	}

 	if (!args->rw) {

-- 
Masami Hiramatsu

Software Engineer
Hitachi Computer Products (America) Inc.
Software Solutions Division

e-mail: mhiramat@redhat.com

Re: [PATCH][BUGFIX] ia64: fix syscall_get_set_args_cb() to handle arguments correctly

[David Smith]

Masami Hiramatsu wrote:
> Hi,
> 
> Here is the patch which fixes utrace on ia64 issue.
> I'll post same fix on the upstream kernel later.

I've tested this patch and it seems to work correctly.  I'm able to
correctly access syscall arguments when "syscall()" is used (and when it
isn't) on ia64.

-- 
David Smith
dsmith@redhat.com
Red Hat
http://www.redhat.com
256.217.0141 (direct)
256.837.0057 (fax)

Re: [PATCH][BUGFIX] ia64: fix syscall_get_set_args_cb() to handle arguments correctly

[Masami Hiramatsu]

David Smith wrote:
> Masami Hiramatsu wrote:
>> Hi,
>>
>> Here is the patch which fixes utrace on ia64 issue.
>> I'll post same fix on the upstream kernel later.
> 
> I've tested this patch and it seems to work correctly.  I'm able to
> correctly access syscall arguments when "syscall()" is used (and when it
> isn't) on ia64.

Thanks! I've committed this patch.

-- 
Masami Hiramatsu

Software Engineer
Hitachi Computer Products (America) Inc.
Software Solutions Division

e-mail: mhiramat@redhat.com

Re: utrace syscall arguments

[Roland McGrath]

> On ia64, dup is 1057.  The first dup call above works correctly and sees
> the 1st argument as 2.  The second dup call sees 0x421 as the 1st
> argument (0x421 is 1057) and 2 as the 2nd argument.
> 
> The utrace_syscall_args test sees the same problem.  When syscall() is
> used, the arguments are shifted over by 1.

Ok, that is a problem with the upstream ia64_syscall_get_set_arguments
implementation.  We should punt it to the ia64 kernel folks and then
propagate whatever their fixes are.

In the upstream kernel, a test using e.g. read() vs syscall(__NR_read,)
to sample /proc/self/syscall ought to demonstrate the problem.  That's
a simple test and in pure upstream ia64 terms.


Thanks,
Roland