Re: Failure in syscall.open probe

[Arkady <arkady dot miasnikov at gmail dot com>]

Update 3

This code fails as well


global ARRAY_FILENAME%

probe syscall.open
{
  tid = tid()
  ARRAY_FILENAME[tid] = filename
}

probe syscall.open.return
{
  tid = tid();
  delete ARRAY_FILENAME[tid]
}

Load thescript
stap -g -p 4 -m test_open  -v -k test_open.stp
staprun test_open -L

Run a tight loop which opens a file
touch test.txt;while [ 1 ];do cat test.txt;done;

Wait a couple of minutes.

The problem appears to be specific for the kernel
2.6.32-696.3.2.el6.x86_64 #1 CentOS 6.9

On Thu, Aug 24, 2017 at 7:28 PM, Arkady <arkady.miasnikov@gmail.com> wrote:
> Update 2
>
> I made the script shorter - failed after 400 driver restarts
>
> global ARRAY_FILENAME_PID%
> global ARRAY_TIMESTAMP_OPEN%
>
> function current_time:long()
> %{  /* pure */
>    struct timespec now = current_kernel_time();
>    STAP_RETURN(timespec_to_ns(&now));
> %}
>
> probe syscall.open
> {
>    tid = tid()
>    ARRAY_FILENAME_PID[tid] = filename
>    ARRAY_TIMESTAMP_OPEN[tid] = current_time()
> }
>
> probe syscall.open.return
> {
>    tid = tid();
>    delete ARRAY_FILENAME_PID[tid]
>    delete ARRAY_TIMESTAMP_OPEN[tid]
> }
>
> On Thu, Aug 24, 2017 at 5:35 PM, Arkady <arkady.miasnikov@gmail.com> wrote:
>> Update
>> The build line can be as short as
>>
>> stap -g -p4 -m test_open  -v -k test_open.stp
>>
>>
>> On Thu, Aug 24, 2017 at 5:26 PM, Arkady <arkady.miasnikov@gmail.com> wrote:
>>> Hi,
>>>
>>> I am trying the following code
>>> https://gist.github.com/larytet/5c361b1a4ee967655f500909026978f9
>>> - the script is mostly syscall.open and syscall.open.return
>>>
>>> on CentOS release 6.9 (Final)
>>> kernel 2.6.32-696.3.2.el6.x86_64 #1 SMP Tue Jun 20 01:26:55 UTC 2017
>>> x86_64 x86_64 x86_64 GNU/Linux
>>>
>>> g++ (GCC) 5.3.1 20160406 (Red Hat 5.3.1-6)
>>>
>>> I use a custom build of 3.1 release of Systemtap
>>> Systemtap translator/driver (version 3.1/0.164, commit
>>> release-2.9-1416-gb8ea350dc13a)
>>> Copyright (C) 2005-2017 Red Hat, Inc. and others
>>> This is free software; see the source for copying conditions.
>>> tested kernel versions: 2.6.18 ... 4.10-rc8
>>> enabled features: PYTHON2 NLS
>>>
>>> Build command stap -g -p4 -m test_open -g --suppress-time-limits -v -k
>>> -D MAXSKIPPED=0 -D MAXTRYLOCK=100000 -D TRYLOCKDELAY=1 test_open.stp
>>>
>>> I restart the script using the following bash one liner
>>> count=0;while [ 1 ];do echo $count;count=$(($count+1));sudo rmmod
>>> test_open;sudo staprun test_open.ko -L  ;done;
>>>
>>> 30-50 restarts later I get an exception:
>>>
>>> Aug 24 10:13:52 localhost kernel: <#DB>  [<ffffffff81068244>] ?
>>> __schedule_bug+0x44/0x50
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff8154af4c>] ? schedule+0xa4c/0xb70
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff812a6356>] ? vsnprintf+0x336/0x5e0
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff810740aa>] ?
>>> __cond_resched+0x2a/0x40
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff8154b340>] ? _cond_resched+0x30/0x40
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff812a8cda>] ?
>>> strncpy_from_user+0x4a/0x90
>>> Aug 24 10:13:52 localhost kernel: [<ffffffffa0703fb0>] ?
>>> function___global_user_string_quoted__overload_0+0x460/0x890
>>> [test_open]
>>> Aug 24 10:13:52 localhost kernel: [<ffffffffa070281e>] ?
>>> _new_map_create+0x3e/0xa0 [test_open]
>>> Aug 24 10:13:52 localhost kernel: [<ffffffffa07047f1>] ?
>>> probe_3606+0x101/0x400 [test_open]
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff81196da1>] ? sys_open+0x1/0x30
>>> Aug 24 10:13:52 localhost kernel: [<ffffffffa0707ce0>] ?
>>> enter_kprobe_probe+0x1c0/0x2d0 [test_open]
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff815513fb>] ?
>>> aggr_pre_handler+0x5b/0xb0
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff81196da0>] ? sys_open+0x0/0x30
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff81196da1>] ? sys_open+0x1/0x30
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff81550e15>] ?
>>> kprobe_exceptions_notify+0x3d5/0x430
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff81551085>] ?
>>> notifier_call_chain+0x55/0x80
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff815510ea>] ?
>>> atomic_notifier_call_chain+0x1a/0x20
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff810acd0e>] ? notify_die+0x2e/0x30
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff8154e955>] ? do_int3+0x35/0xb0
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff8154e1c3>] ? int3+0x33/0x40
>>> Aug 24 10:13:52 localhost kernel: [<ffffffff81196da0>] ? sys_open+0x0/0x30
>>>
>>> Thank you, Arkady.