Re: Failure in syscall.open probe

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

The following comment is probably relevant:
/*
 * On some kernels (e.g. 2.6.39), even with preemption disabled, the
strncpy_from_user,
 * instead of returning -1 after a page fault, schedules the process,
so we drop events
 * because of the preemption. This function reads the user buffer in
atomic chunks, and
 * returns when there's an error or the terminator is found
 */

https://github.com/draios/sysdig/blob/dev/driver/ppm_events.c#L108

> On Fri, Aug 25, 2017 at 10:52 PM, David Smith <dsmith@redhat.com> wrote:
>> Arkady,
>>
>> The "good" news is that I've duplicated your problem. I went ahead and
>> filed PR22012 (<https://sourceware.org/bugzilla/show_bug.cgi?id=22012>)
>> on this issue so I won't forget it.
>>
>> I'm looking into it.
>>
>>
>> On Fri, Aug 25, 2017 at 12:25 PM, Arkady <arkady.miasnikov@gmail.com> wrote:
>>> Reproduce the problem
>>>
>>> Run the following one liner on CentOS 6.9
>>>
>>> stap -e "global AF%;probe syscall.open {tid = tid();AF[tid] =
>>> filename;}probe syscall.open.return{tid = tid();delete AF[tid];}"
>>>
>>> Run a bash loop
>>> touch test.txt;while [ 1 ];do cat test.txt;done;
>>>
>>> Monitor the kernel log
>>> tail -f /var/log/messages
>>>
>>> After a couple of minutes you shall see
>>>
>>> BUG: scheduling while atomic: cat/87764/0x10000001
>>> Modules linked in: test_open(U) fuse rfcomm sco bridge bnep l2cap
>>> autofs4 bnx2fc cnic uio fcoe libfcoe libfc 8021q scsi_transport_fc
>>> garp stp scsi_tgt llc ipt_REJECT nf_conntrack_ipv4 nf_defrag_ipv4
>>> iptable_filter ip_tables ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6
>>> xt_state nf_conntrack ip6table_filter ip6_tables ib_ipoib rdma_ucm
>>> ib_ucm ib_uverbs ib_umad rdma_cm ib_cm iw_cm ib_sa ib_mad ib_core
>>> ib_addr ipv6 uinput microcode vmware_balloon uvcvideo videodev
>>> v4l2_compat_ioctl32 btusb bluetooth rfkill snd_seq_midi e1000
>>> snd_seq_midi_event snd_ens1371 snd_rawmidi snd_ac97_codec ac97_bus
>>> snd_seq snd_seq_device snd_pcm snd_timer snd soundcore snd_page_alloc
>>> sg i2c_piix4 shpchp ext4 jbd2 mbcache sd_mod crc_t10dif sr_mod cdrom
>>> mptspi mptscsih mptbase scsi_transport_spi pata_acpi ata_generic
>>> ata_piix vmwgfx ttm drm_kms_helper drm i2c_core dm_mirror
>>> dm_region_hash dm_log dm_mod [last unloaded: speedstep_lib]
>>> Pid: 87764, comm: cat Not tainted 2.6.32-696.10.1.el6.x86_64 #1
>>> Call Trace:
>>> <#DB>  [<ffffffff81068244>] ? __schedule_bug+0x44/0x50
>>> [<ffffffff8154ae0c>] ? schedule+0xa4c/0xb70
>>> [<ffffffff812a6216>] ? vsnprintf+0x336/0x5e0
>>> [<ffffffff810740aa>] ? __cond_resched+0x2a/0x40
>>> [<ffffffff8154b200>] ? _cond_resched+0x30/0x40
>>> [<ffffffff812a8b9a>] ? strncpy_from_user+0x4a/0x90
>>> [<ffffffffa0705ff9>] ? probe_3602+0x5f9/0x1220 [test_open]
>>> [<ffffffff81196c31>] ? sys_open+0x1/0x30
>>> [<ffffffffa0707fed>] ? enter_kprobe_probe+0x1ed/0x3a0 [test_open]
>>> [<ffffffff815512bb>] ? aggr_pre_handler+0x5b/0xb0
>>> [<ffffffff81196c30>] ? sys_open+0x0/0x30
>>> [<ffffffff81196c31>] ? sys_open+0x1/0x30
>>> [<ffffffff81550cd5>] ? kprobe_exceptions_notify+0x3d5/0x430
>>> [<ffffffff81550f45>] ? notifier_call_chain+0x55/0x80
>>> [<ffffffff81550faa>] ? atomic_notifier_call_chain+0x1a/0x20
>>> [<ffffffff810acd0e>] ? notify_die+0x2e/0x30
>>> [<ffffffff8154e815>] ? do_int3+0x35/0xb0
>>> [<ffffffff8154e083>] ? int3+0x33/0x40
>>> [<ffffffff81196c30>] ? sys_open+0x0/0x30
>>
>>
>>
>> --
>> David Smith
>> Principal Software Engineer
>> Red Hat