How to get correct filename in probe.execve

How to get correct filename in probe.execve

[Arkady]

Hello,

I am doing the following

stap -e 'probe syscall.execve { { printf("exec %s\n", filename) } }'

My platform is

Linux ubuntu 4.4.0-59-generic #80-Ubuntu SMP Fri Jan 6 17:47:47 UTC
2017 x86_64 x86_64 x86_64 GNU/Linux

I am running a Python script called echo.py which contains two lines:

import os
os.system("ls /tmp")

I am doing something like python ./echo.py

In the exec probe output I am getting

exec "/usr/bin/python"
exec 00007fce05d05177

Where does 00007fce05d05177 come from?

Thanks

Re: How to get correct filename in probe.execve

[David Smith]

On 01/19/2017 08:08 AM, Arkady wrote:
> Hello,
> 
> I am doing the following
> 
> stap -e 'probe syscall.execve { { printf("exec %s\n", filename) } }'
> 
> My platform is
> 
> Linux ubuntu 4.4.0-59-generic #80-Ubuntu SMP Fri Jan 6 17:47:47 UTC
> 2017 x86_64 x86_64 x86_64 GNU/Linux
> 
> I am running a Python script called echo.py which contains two lines:
> 
> import os
> os.system("ls /tmp")
> 
> I am doing something like python ./echo.py
> 
> In the exec probe output I am getting
> 
> exec "/usr/bin/python"
> exec 00007fce05d05177
> 
> Where does 00007fce05d05177 come from?

When the execve syscall gets called, systemtap gets an address for the
filename. It then tries to read that userspace address in the kernel to
find the string stored there. If it can't read that userspace address,
it instead will just report the address it tried to read. I'd bet that's
what happened here.

Why couldn't the address be read? The most likely answer (assuming the
address is valid) is that the memory the address points to hasn't been
paged in yet.

When I run your example, I see the following:

====
exec "/usr/bin/python"
exec 0x7fd57a129032
exec "/usr/bin/ls"
====

So, I'm also seeing the address. Why are there 3 execs in my output?
When you run 'os.system("ls /tmp")', python will run the equivalent of
'sh -c "ls /tmp"'. So, the 2nd exec is for 'sh' and the 3rd is for 'ls'
itself.

So, that's where the address is coming from. I'm not sure how to more
reliably get the string. Perhaps someone else will have an idea.

(I tried the following, but actually got worse results:

  stap -ve 'probe syscall.execve.return { printf("exec %s\n",
user_string_quoted(@entry($filename))) }' -c "python test.py"

)

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

Re: How to get correct filename in probe.execve

[Frank Ch. Eigler]

Arkady <larytet@gmail.com> writes:

> [...]
> stap -e 'probe syscall.execve { { printf("exec %s\n", filename) } }'

Looks good.

> import os
> os.system("ls /tmp")
> I am doing something like python ./echo.py
> In the exec probe output I am getting
> exec "/usr/bin/python"
> exec 00007fce05d05177
> Where does 00007fce05d05177 come from?

That could be the address, in user-space, of the "ls ..." string that
has not been paged into the process' address space yet.  (systemtap
probes never cause page faults, so can't wait to "fault in" such
strings.)  That sometimes happens with C programs, but I wouldn't have
expected it in python, where these are heap-resident, freshly copied
objects.  I wonder it's not the "ls ..." one but some other brief child
process of the python interpreter.

Ah wait, strace suggests an answer.  The filename for a python-initiated
os.system() is "/bin/sh", which is a C-side string constant.  So it
could still be paged out at this early time in the program's life.  I
bet that if you change your python program to have two os.system()
calls, you'd get the "/bin/sh" string printed by the second stap probe
hit.

- FChE

Re: How to get correct filename in probe.execve

[Arkady]

I appreciate the valuable responses.

I have modified the scripts a little bit

stap -e 'probe kprocess.exec { { printf("exec pid=%u ts=%u filename=%s
args=%s\n", pid(), gettimeofday_ns(), filename, argstr) } }'

import os
os.system("echo Hello")
os.system("echo Hello")
os.system("ls /tmp")
os.system("ls /tmp")

and the output is:

exec pid=2578 ts=1484871567781365344 filename="/usr/bin/python"
args="/usr/bin/python", ["python", "echo.py"], [/* 20 vars */]
exec pid=2579 ts=1484871567790241888 filename=00007fd509724177
args=00007fd509724177, [00007fd50972417c, 00007fd509724174, "echo
Hello"], [/* 20 vars */]
exec pid=2580 ts=1484871567791230838 filename=00007fd509724177
args=00007fd509724177, [00007fd50972417c, 00007fd509724174, "echo
Hello"], [/* 20 vars */]

exec pid=2581 ts=1484871567792359834 filename=00007fd509724177
args=00007fd509724177, [00007fd50972417c, 00007fd509724174, "ls
/tmp"], [/* 20 vars */]
exec pid=2582 ts=1484871567793112384 filename="/bin/ls"
args="/bin/ls", ["ls", "/tmp"], [/* 20 vars */]
exec pid=2583 ts=1484871567794590362 filename=00007fd509724177
args=00007fd509724177, [00007fd50972417c, 00007fd509724174, "ls
/tmp"], [/* 20 vars */]
exec pid=2584 ts=1484871567795367498 filename="/bin/ls"
args="/bin/ls", ["ls", "/tmp"], [/* 20 vars */]

When running under strace I see execve. When I check the generated by
the SystemTap C source code I see a probe in execveat in the file
fs/exec.c. Does the probe kprocess.exec hooks all "exec" syscalls?

In the syscall.accept the sockaddress argument is an address to the
user space buffer. Shall I expect to hit a not loaded page from time
to time?

Thank you.

On Thu, Jan 19, 2017 at 4:55 PM, Frank Ch. Eigler <fche@redhat.com> wrote:
> Arkady <larytet@gmail.com> writes:
>
>> [...]
>> stap -e 'probe syscall.execve { { printf("exec %s\n", filename) } }'
>
> Looks good.
>
>> import os
>> os.system("ls /tmp")
>> I am doing something like python ./echo.py
>> In the exec probe output I am getting
>> exec "/usr/bin/python"
>> exec 00007fce05d05177
>> Where does 00007fce05d05177 come from?
>
> That could be the address, in user-space, of the "ls ..." string that
> has not been paged into the process' address space yet.  (systemtap
> probes never cause page faults, so can't wait to "fault in" such
> strings.)  That sometimes happens with C programs, but I wouldn't have
> expected it in python, where these are heap-resident, freshly copied
> objects.  I wonder it's not the "ls ..." one but some other brief child
> process of the python interpreter.
>
> Ah wait, strace suggests an answer.  The filename for a python-initiated
> os.system() is "/bin/sh", which is a C-side string constant.  So it
> could still be paged out at this early time in the program's life.  I
> bet that if you change your python program to have two os.system()
> calls, you'd get the "/bin/sh" string printed by the second stap probe
> hit.
>
> - FChE

Re: How to get correct filename in probe.execve

[David Smith]

On 01/19/2017 06:34 PM, Arkady wrote:
> I appreciate the valuable responses.
> 
> I have modified the scripts a little bit
> 
> stap -e 'probe kprocess.exec { { printf("exec pid=%u ts=%u filename=%s
> args=%s\n", pid(), gettimeofday_ns(), filename, argstr) } }'
> 
> import os
> os.system("echo Hello")
> os.system("echo Hello")
> os.system("ls /tmp")
> os.system("ls /tmp")
> 
> and the output is:
> 
> exec pid=2578 ts=1484871567781365344 filename="/usr/bin/python"
> args="/usr/bin/python", ["python", "echo.py"], [/* 20 vars */]
> exec pid=2579 ts=1484871567790241888 filename=00007fd509724177
> args=00007fd509724177, [00007fd50972417c, 00007fd509724174, "echo
> Hello"], [/* 20 vars */]
> exec pid=2580 ts=1484871567791230838 filename=00007fd509724177
> args=00007fd509724177, [00007fd50972417c, 00007fd509724174, "echo
> Hello"], [/* 20 vars */]
> 
> exec pid=2581 ts=1484871567792359834 filename=00007fd509724177
> args=00007fd509724177, [00007fd50972417c, 00007fd509724174, "ls
> /tmp"], [/* 20 vars */]
> exec pid=2582 ts=1484871567793112384 filename="/bin/ls"
> args="/bin/ls", ["ls", "/tmp"], [/* 20 vars */]
> exec pid=2583 ts=1484871567794590362 filename=00007fd509724177
> args=00007fd509724177, [00007fd50972417c, 00007fd509724174, "ls
> /tmp"], [/* 20 vars */]
> exec pid=2584 ts=1484871567795367498 filename="/bin/ls"
> args="/bin/ls", ["ls", "/tmp"], [/* 20 vars */]
> 
> When running under strace I see execve. When I check the generated by
> the SystemTap C source code I see a probe in execveat in the file
> fs/exec.c. Does the probe kprocess.exec hooks all "exec" syscalls?

If you are running with systemtap 2.5+, kprocess.exec is an alias for
syscall.execve. If you wanted to be sure to catch all the execve
variants, you should probe on: syscall.execve, syscall.compat_execve,
syscall.execveat, syscall.compat_execveat.

> In the syscall.accept the sockaddress argument is an address to the
> user space buffer. Shall I expect to hit a not loaded page from time
> to time?

It is possible, depending on the how syscall.accept is implemented on
your kernel. On some kernels, accept() is a true function call. On those
kernels, the sockaddress should always be available, since it is one of
the parameters. On other kernels, accept() has been multiplexed into
socketcall(). On those kernels, systemtap does have to read user memory
and you might hit an address that hasn't been paged in yet.

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

Re: How to get correct filename in probe.execve

[Arkady]

I tried the following

global EXEC_FILENAME%

probe kprocess.exec
{
        printf("exec pid=%u ts=%u filename=%s arg1=%s args=%s\n",
pid(), gettimeofday_ns(), filename, user_string_quoted(ulong_arg(1)),
argstr)
        EXEC_FILENAME[pid(),tid()] = ulong_arg(1)
}


probe kprocess.exec_complete
{
        printf("exec_complete pid=%d, u_filename=%s\n", pid(),
user_string_quoted(EXEC_FILENAME[pid(), tid()]))
}

probe kernel.function("do_filp_open").call
{
        if ([pid(), tid()] in EXEC_FILENAME)
        {
                printf("do_filp_open pid=%d %s\n", pid(),
user_string_quoted(EXEC_FILENAME[pid(), tid()]))
        }
}

I am getting this marvel:

exec pid=30825 ts=1484976492960517468 filename=00007f32db232177
arg1=00007f32db232177 args=00007f32db232177, [00007f32db23217c,
00007f32db232174, "echo Hello"], [/* 20 vars */]
do_filp_open pid=30825 "/bin/sh"
do_filp_open pid=30825 "/bin/sh"
exec_complete pid=30825, u_filename=00007f32db232177

Will this approach work across the kernel versions? How reliable it is
going to be?

Thanks.

On Fri, Jan 20, 2017 at 4:28 PM, David Smith <dsmith@redhat.com> wrote:
> On 01/19/2017 06:34 PM, Arkady wrote:
>> I appreciate the valuable responses.
>>
>> I have modified the scripts a little bit
>>
>> stap -e 'probe kprocess.exec { { printf("exec pid=%u ts=%u filename=%s
>> args=%s\n", pid(), gettimeofday_ns(), filename, argstr) } }'
>>
>> import os
>> os.system("echo Hello")
>> os.system("echo Hello")
>> os.system("ls /tmp")
>> os.system("ls /tmp")
>>
>> and the output is:
>>
>> exec pid=2578 ts=1484871567781365344 filename="/usr/bin/python"
>> args="/usr/bin/python", ["python", "echo.py"], [/* 20 vars */]
>> exec pid=2579 ts=1484871567790241888 filename=00007fd509724177
>> args=00007fd509724177, [00007fd50972417c, 00007fd509724174, "echo
>> Hello"], [/* 20 vars */]
>> exec pid=2580 ts=1484871567791230838 filename=00007fd509724177
>> args=00007fd509724177, [00007fd50972417c, 00007fd509724174, "echo
>> Hello"], [/* 20 vars */]
>>
>> exec pid=2581 ts=1484871567792359834 filename=00007fd509724177
>> args=00007fd509724177, [00007fd50972417c, 00007fd509724174, "ls
>> /tmp"], [/* 20 vars */]
>> exec pid=2582 ts=1484871567793112384 filename="/bin/ls"
>> args="/bin/ls", ["ls", "/tmp"], [/* 20 vars */]
>> exec pid=2583 ts=1484871567794590362 filename=00007fd509724177
>> args=00007fd509724177, [00007fd50972417c, 00007fd509724174, "ls
>> /tmp"], [/* 20 vars */]
>> exec pid=2584 ts=1484871567795367498 filename="/bin/ls"
>> args="/bin/ls", ["ls", "/tmp"], [/* 20 vars */]
>>
>> When running under strace I see execve. When I check the generated by
>> the SystemTap C source code I see a probe in execveat in the file
>> fs/exec.c. Does the probe kprocess.exec hooks all "exec" syscalls?
>
> If you are running with systemtap 2.5+, kprocess.exec is an alias for
> syscall.execve. If you wanted to be sure to catch all the execve
> variants, you should probe on: syscall.execve, syscall.compat_execve,
> syscall.execveat, syscall.compat_execveat.
>
>> In the syscall.accept the sockaddress argument is an address to the
>> user space buffer. Shall I expect to hit a not loaded page from time
>> to time?
>
> It is possible, depending on the how syscall.accept is implemented on
> your kernel. On some kernels, accept() is a true function call. On those
> kernels, the sockaddress should always be available, since it is one of
> the parameters. On other kernels, accept() has been multiplexed into
> socketcall(). On those kernels, systemtap does have to read user memory
> and you might hit an address that hasn't been paged in yet.
>
> --
> David Smith
> dsmith@redhat.com
> Red Hat
> http://www.redhat.com
> 256.217.0141 (direct)
> 256.837.0057 (fax)

Re: How to get correct filename in probe.execve

[Frank Ch. Eigler]

Hi -

> probe kprocess.exec
> {
>         printf("exec pid=%u ts=%u filename=%s arg1=%s args=%s\n",
> pid(), gettimeofday_ns(), filename, user_string_quoted(ulong_arg(1)),
> argstr)
>         EXEC_FILENAME[pid(),tid()] = ulong_arg(1)
> }

I'd use the tapset-provided variables or $context variables rather
than ulong_arg*:

% stap -L kprocess.exec

kprocess.exec name:string filename:string __argv:long args:string __envp:long env_str:string argstr:string $filename:long int $argv:long int $envp:long int

Those are likely more stable across versions / architectures.  You can
use the @defined() function to test for availability of $context
variables, so your script can even fall back between one and the other.
 


> [...]
> probe kernel.function("do_filp_open").call
> {
>         if ([pid(), tid()] in EXEC_FILENAME)
> [...]

By the way, there is no need to index -both- by pid() and tid().
Just tid() is enough if you want per-process+per-thread tracking;
just pid() if per-process.


> I am getting this marvel:
> 
> exec pid=30825 ts=1484976492960517468 filename=00007f32db232177
> arg1=00007f32db232177 args=00007f32db232177, [00007f32db23217c,
> 00007f32db232174, "echo Hello"], [/* 20 vars */]
> [...]

Good, enjoy!


- FChE

Re: How to get correct filename in probe.execve

[Arkady]

On Sat, Jan 21, 2017 at 8:52 AM, Frank Ch. Eigler <fche@redhat.com> wrote:
> Hi -
>
>> probe kprocess.exec
>> {
>>         .........
>>         EXEC_FILENAME[pid(),tid()] = ulong_arg(1)
>> }
>
> I'd use the tapset-provided variables or $context variables rather
> than ulong_arg*:
>

I am trying to ensure that I keep an integer in the EXEC_FILENAME.
If I do
EXEC_FILENAME=filename

SystemTap assumes a (zero terminated) string. After that I want to do
something like

user_string_quoted(EXEC_FILENAME[pid(), tid()])


> % stap -L kprocess.exec
>
> kprocess.exec name:string filename:string __argv:long args:string __envp:long env_str:string argstr:string $filename:long int $argv:long int $envp:long int
>
> Those are likely more stable across versions / architectures.  You can
> use the @defined() function to test for availability of $context
> variables, so your script can even fall back between one and the other.
>
>
> By the way, there is no need to index -both- by pid() and tid().
> Just tid() is enough if you want per-process+per-thread tracking;
> just pid() if per-process.
>
Great tip. I did not think about it - the kernel knows only threads, of course.
>
>> I am getting this marvel:
>>
>> [...]
>
> Good, enjoy!

Thank you!
>
>
> - FChE

Re: How to get correct filename in probe.execve

[Frank Ch. Eigler]

Hi -

> I am trying to ensure that I keep an integer in the EXEC_FILENAME.
> If I do EXEC_FILENAME=filename
> 
> SystemTap assumes a (zero terminated) string. After that I want to do
> something like
> 
> user_string_quoted(EXEC_FILENAME[pid(), tid()])

Aha - you want to save the pointer only and dereference it later?  OK,
as long as you do so very soon afterwards (in another probe, hit
before the target task gets a chance to resume or context-switch).

- FChE

Re: How to get correct filename in probe.execve

[Frank Ch. Eigler]

larytet wrote:

> [...]
> I am trying to ensure that I keep an integer in the EXEC_FILENAME.
> If I do
> EXEC_FILENAME=filename
> SystemTap assumes a (zero terminated) string. [...]

BTW, you could still use $filename (the context variable, which is an
integer/char*) instead of filename (the script level variable, which is
a string).


- FChE

Re: How to get correct filename in probe.execve

[Arkady]

This is what I did

global ARRAY_EXEC_DOEXECVE_FILENAME%
global ARRAY_EXEC_DOEXECVE_ARGSTR%

probe kprocess.exec
{
  tid = tid()
  if (stringat(filename,0) == 0x22) // filename starts with a quotation mark
  {
      argstr = sprintf("%s, %s", filename, args)
      pid = pid()
      printf("pid=%d filename='%s', args='%s' kprocess.exec\n", pid,
filename, argstr);
  }
  else  // failed to recog the filename, trigger do_execve
  {
     ARRAY_EXEC_DOEXECVE_FILENAME[tid] = @choose_defined($filename, $name)
     ARRAY_EXEC_DOEXECVE_ARGSTR[tid] = @choose_defined($__argv, $argv)
  }
}

probe kernel.function("do_execve")
{
  tid = tid()
  if (tid in ARRAY_EXEC_DOEXECVE_FILENAME)  // unlikely
  {
     filename = user_string_quoted(ARRAY_EXEC_DOEXECVE_FILENAME[tid])
     args = __get_argv(ARRAY_EXEC_DOEXECVE_ARGSTR[tid], 0)
     argstr = sprintf("%s, %s", filename, args)
     delete ARRAY_EXEC_DOEXECVE_FILENAME[tid]
     delete ARRAY_EXEC_DOEXECVE_ARGSTR[tid]

     pid = pid()
     printf("pid=%d filename='%s', args='%s' do_execve\n", pid,
filename, argstr);
  }
}


Does it make sense?
Is there a better way than "if (stringat(filename,0) == 0x22)" to
figure out that fetching a failename from the user space failed?
I am dropping the env_str by "argstr = sprintf("%s, %s", filename,
args)". Is it the best way to get the string of arguments?

Thanks

On Sat, Jan 21, 2017 at 4:02 PM, Frank Ch. Eigler <fche@redhat.com> wrote:
>
> larytet wrote:
>
>> [...]
>> I am trying to ensure that I keep an integer in the EXEC_FILENAME.
>> If I do
>> EXEC_FILENAME=filename
>> SystemTap assumes a (zero terminated) string. [...]
>
> BTW, you could still use $filename (the context variable, which is an
> integer/char*) instead of filename (the script level variable, which is
> a string).
>
>
> - FChE

Re: How to get correct filename in probe.execve

[Arkady]

... and another question. What are pros and cons of using probe
kprocess.exec vs probe kernel.function("do_execve") ?
Thanks

On Sun, Jan 22, 2017 at 1:11 PM, Arkady <larytet@gmail.com> wrote:
> This is what I did
>
> global ARRAY_EXEC_DOEXECVE_FILENAME%
> global ARRAY_EXEC_DOEXECVE_ARGSTR%
>
> probe kprocess.exec
> {
>   tid = tid()
>   if (stringat(filename,0) == 0x22) // filename starts with a quotation mark
>   {
>       argstr = sprintf("%s, %s", filename, args)
>       pid = pid()
>       printf("pid=%d filename='%s', args='%s' kprocess.exec\n", pid,
> filename, argstr);
>   }
>   else  // failed to recog the filename, trigger do_execve
>   {
>      ARRAY_EXEC_DOEXECVE_FILENAME[tid] = @choose_defined($filename, $name)
>      ARRAY_EXEC_DOEXECVE_ARGSTR[tid] = @choose_defined($__argv, $argv)
>   }
> }
>
> probe kernel.function("do_execve")
> {
>   tid = tid()
>   if (tid in ARRAY_EXEC_DOEXECVE_FILENAME)  // unlikely
>   {
>      filename = user_string_quoted(ARRAY_EXEC_DOEXECVE_FILENAME[tid])
>      args = __get_argv(ARRAY_EXEC_DOEXECVE_ARGSTR[tid], 0)
>      argstr = sprintf("%s, %s", filename, args)
>      delete ARRAY_EXEC_DOEXECVE_FILENAME[tid]
>      delete ARRAY_EXEC_DOEXECVE_ARGSTR[tid]
>
>      pid = pid()
>      printf("pid=%d filename='%s', args='%s' do_execve\n", pid,
> filename, argstr);
>   }
> }
>
>
> Does it make sense?
> Is there a better way than "if (stringat(filename,0) == 0x22)" to
> figure out that fetching a failename from the user space failed?
> I am dropping the env_str by "argstr = sprintf("%s, %s", filename,
> args)". Is it the best way to get the string of arguments?
>
> Thanks
>
> On Sat, Jan 21, 2017 at 4:02 PM, Frank Ch. Eigler <fche@redhat.com> wrote:
>>
>> larytet wrote:
>>
>>> [...]
>>> I am trying to ensure that I keep an integer in the EXEC_FILENAME.
>>> If I do
>>> EXEC_FILENAME=filename
>>> SystemTap assumes a (zero terminated) string. [...]
>>
>> BTW, you could still use $filename (the context variable, which is an
>> integer/char*) instead of filename (the script level variable, which is
>> a string).
>>
>>
>> - FChE

Re: How to get correct filename in probe.execve

[David Smith]

On 01/22/2017 08:50 AM, Arkady wrote:
> ... and another question. What are pros and cons of using probe
> kprocess.exec vs probe kernel.function("do_execve") ?
> Thanks

That's an easy one. When you use the probe alias, you are trusting us to
keep that alias up to date. If you probe kernel.function("do_execve")
directly yourself, you are responsible for keeping your code up to date.

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