Re: Failure in syscall.open probe

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

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.