by 平松雅巳 / HIRAMATU，MASAMI

[permalink] [raw]

Subject: Re: [PATCH -tip v2 0/3] ftrace, kprobes: Introduce IPMODIFY flag for ftrace_ops to detect conflicts

(2014/06/19 23:18), Josh Poimboeuf wrote:
> On Thu, Jun 19, 2014 at 02:03:31PM +0900, Masami Hiramatsu wrote:
>> (2014/06/19 11:08), Josh Poimboeuf wrote:
>>> On Tue, Jun 17, 2014 at 11:04:36AM +0000, Masami Hiramatsu wrote:
>>>> Hi,
>>>>
>>>> Here is the version 2 of the series of patches which introduces
>>>> IPMODIFY flag for ftrace_ops to detect conflicts of ftrace users
>>>> who can modify regs->ip in their handler.
>>>> In this version, I fixed some bugs in previous version and
>>>> added a patch which made kprobe itself free from IPMODIFY
>>>> except for jprobe.
>>>
>>> Hi Masami,
>>>
>>> This seems better, but I still saw a few issues. I'm not sure if the
>>> issues are specific to stap or kprobes. For the following issues I used
>>> this command to set a kprobe:
>>>
>>> stap -v -e 'probe kernel.function("meminfo_proc_show") {printf("meminfo_proc_show called\n");}'
>>>
>>> With patches 1-2, when I used stap to kprobe the function after it was
>>> already kpatched, stap didn't return an error and instead acted like it
>>> succeeded (though the probe didn't work):
>>>
>>> $ sudo stap -v -e 'probe kernel.function("meminfo_proc_show") {printf("meminfo_proc_show called\n");}'
>>> Pass 1: parsed user script and 112 library script(s) using 221516virt/41612res/6028shr/36228data kb, in 130usr/0sys/132real ms.
>>> Pass 2: analyzed script: 1 probe(s), 0 function(s), 0 embed(s), 0 global(s) using 255840virt/77132res/7132shr/70552data kb, in 510usr/20sys/577real ms.
>>> Pass 3: translated to C into "/tmp/stap3Qunba/stap_2690192fea570fb7bba78c7ed7fa1e0d_898_src.c" using 255840virt/77392res/7392shr/70552data kb, in 10usr/0sys/4real ms.
>>> Pass 4: compiled C into "stap_2690192fea570fb7bba78c7ed7fa1e0d_898.ko" in 5020usr/640sys/7105real ms.
>>> Pass 5: starting run.
>>> (no error)
>>
>> Yeah, I guess you can see some warning messages in dmesg (by
>> arm_kprobe) at this point.
>
> Ah, you're right:
>
> Jun 19 08:03:10 treble kernel: ------------[ cut here ]------------
> Jun 19 08:03:10 treble kernel: WARNING: CPU: 1 PID: 17991 at kernel/kprobes.c:953 arm_kprobe+0xa7/0xe0()
> Jun 19 08:03:10 treble kernel: Failed to init kprobe-ftrace (-16)
> Jun 19 08:03:10 treble kernel: Modules linked in: stap_1faf9cc0ccf85c0d203c74ab6f604b_17991(OE) ...defra
> Jun 19 08:03:10 treble kernel: videobuf2_vmalloc serio_raw microcode sdhci_pci bluetooth videobuf2_m...
> Jun 19 08:03:10 treble kernel: CPU: 1 PID: 17991 Comm: stapio Tainted: G U W OE 3.15.0+ #1
> Jun 19 08:03:10 treble kernel: Hardware name: LENOVO 2356BH8/2356BH8, BIOS G7ET63WW (2.05 ) 11/12/2012
> Jun 19 08:03:10 treble kernel: 0000000000000000 000000009023f19e ffff8803dcce7d80 ffffffff816f31fd
> Jun 19 08:03:10 treble kernel: ffff8803dcce7dc8 ffff8803dcce7db8 ffffffff8108914d ffffffffa08248e0
> Jun 19 08:03:10 treble kernel: ffffffffa08248f0 0000000000000000 0000000000000000 0000000000000000
> Jun 19 08:03:10 treble kernel: Call Trace:
> Jun 19 08:03:10 treble kernel: [<ffffffff816f31fd>] dump_stack+0x45/0x56
> Jun 19 08:03:10 treble kernel: [<ffffffff8108914d>] warn_slowpath_common+0x7d/0xa0
> Jun 19 08:03:10 treble kernel: [<ffffffff810891cc>] warn_slowpath_fmt+0x5c/0x80
> Jun 19 08:03:10 treble kernel: [<ffffffff816ff9d7>] arm_kprobe+0xa7/0xe0
> Jun 19 08:03:10 treble kernel: [<ffffffff817007f7>] register_kprobe+0x557/0x5d0
> Jun 19 08:03:10 treble kernel: [<ffffffff81254db0>] ? meminfo_proc_open+0x30/0x30
> Jun 19 08:03:10 treble kernel: [<ffffffffa081fc95>] _stp_ctl_write_cmd+0x8d5/0x930 [stap_1faf9c...7991]
> Jun 19 08:03:10 treble kernel: [<ffffffff811e5dba>] vfs_write+0xba/0x1e0
> Jun 19 08:03:10 treble kernel: [<ffffffff811e6975>] SyS_write+0x55/0xd0
> Jun 19 08:03:10 treble kernel: [<ffffffff81703179>] system_call_fastpath+0x16/0x1b
> Jun 19 08:03:10 treble kernel: ---[ end trace 19615ed55413a30d ]---
>
> Why not change arm_kprobe() to return an error?

Actually, arm_kprobe() is widely used at deeper point.
And the 3rd patch will solve the problem. So I decided just adding
IPMODIFY flag at the 2nd patch.

>>> With all 3 patches, I expected kprobes and kpatch to be able to ftrace
>>> the same function. But when I tried to kpatch the function after it was
>>> kprobed, I got the following oops in stap:
>>>
>>> [ 455.842797] BUG: unable to handle kernel NULL pointer dereference at 0000000000000020
>>> [ 455.843388] IP: [<ffffffffa0833d1e>] _stp_module_notifier+0x1e/0x320 [stap_2690192fea570fb7bba78c7ed7fa1e_20189]
>>
>> Hmm, since this happens in _stp_module_notifier() which is a code in systemtap,
>> I guess it's a systemtap problem.
>>
>> Could you test it with kprobe-tracer as below?
>>
>> # (do something kpatch related activation)
>> # echo p meminfo_proc_show > /sys/kernel/debug/tracing/kprobe_events
>> # echo 1 > /sys/kernel/debug/tracing/events/kprobe/enable
>
> That worked, thanks.

Moreover, I couldn't reproduced the stap case on my fedora20.
Perhaps, Maybe a different version of systemtap I used.

Thank you,

--
Masami HIRAMATSU
Software Platform Research Dept. Linux Technology Research Center
Hitachi, Ltd., Yokohama Research Laboratory
E-mail: [email protected]

2014-06-23 07:57:28

by 平松雅巳 / HIRAMATU，MASAMI

[permalink] [raw]

Subject: Re: [PATCH -tip v2 2/3] ftrace, kprobes: Support IPMODIFY flag to find IP modify conflict

(2014/06/20 11:48), Steven Rostedt wrote:
> On Tue, 17 Jun 2014 11:04:49 +0000
> Masami Hiramatsu <[email protected]> wrote:
>
>> Introduce FTRACE_OPS_FL_IPMODIFY to avoid conflict among
>> ftrace users who may modify regs->ip to change the execution
>> path. This also adds the flag to kprobe_ftrace_ops, since
>> ftrace-based kprobes already modifies regs->ip. Thus, if
>> another user modifies the regs->ip on the same function entry,
>> one of them will be broken. So both should add IPMODIFY flag
>> and make sure that ftrace_set_filter_ip() succeeds.
>>
>> Note that currently conflicts of IPMODIFY are detected on the
>> filter hash. It does NOT care about the notrace hash. This means
>> that if you set filter hash all functions and notrace(mask)
>> some of them, the IPMODIFY flag will be applied to all
>> functions.
>
> Hmm, this worries me. I'm not sure I care about ignoring the notrace
> hash.

Since the notrace hash is not updated atomically (it is disabled ->
updated -> enabled), there could be a small window where only filter
hash is enabled.　I considered that.

[...]
>> @@ -317,13 +322,14 @@ extern int ftrace_nr_registered_ops(void);
>> * from tracing that function.
>> */
>> enum {
>> + FTRACE_FL_IPMODIFY = (1UL << 28),
>> FTRACE_FL_ENABLED = (1UL << 29),
>> FTRACE_FL_REGS = (1UL << 30),
>> FTRACE_FL_REGS_EN = (1UL << 31)
>> };
>>
>> -#define FTRACE_FL_MASK (0x7UL << 29)
>> -#define FTRACE_REF_MAX ((1UL << 29) - 1)
>> +#define FTRACE_FL_MASK (0xfUL << 28)
>> +#define FTRACE_REF_MAX ((1UL << 28) - 1)
>
> Note, this is going to conflict with my queue for 3.17, as I'm starting
> to write individual trampolines.
>
> You can take a look at my ftrace/next branch, but be warned, it will
> rebase.

OK, anyway, at least this flag can easily be changed. :)

>> struct dyn_ftrace {
>> unsigned long ip; /* address of mcount call-site */
>> diff --git a/kernel/kprobes.c b/kernel/kprobes.c
>> index 3214289..e52d86f 100644
>> --- a/kernel/kprobes.c
>> +++ b/kernel/kprobes.c
>> @@ -915,7 +915,7 @@ static struct kprobe *alloc_aggr_kprobe(struct kprobe *p)
>> #ifdef CONFIG_KPROBES_ON_FTRACE
>> static struct ftrace_ops kprobe_ftrace_ops __read_mostly = {
>> .func = kprobe_ftrace_handler,
>> - .flags = FTRACE_OPS_FL_SAVE_REGS,
>> + .flags = FTRACE_OPS_FL_SAVE_REGS | FTRACE_OPS_FL_IPMODIFY,
>
> We probably should comment somewhere that once you set the IPMODIFY
> flag (or do not set it), it should never change. An ops either has it
> or it doesn't, it can't change its mind. Otherwise it could play havoc
> with the update code below.

Agreed. Hmm, it seems that we currently have no document about ftrace_ops.
This is a kind of undocumented kmodule API. At least we need to add a comment
on the header.

[...]
>> @@ -1593,6 +1607,109 @@ static void ftrace_hash_rec_enable(struct ftrace_ops *ops,
>> __ftrace_hash_rec_update(ops, filter_hash, 1);
>> }
>>
>> +/*
>> + * Try to update IPMODIFY flag on each ftrace_rec. Return 0 if it is OK
>> + * or no-needed to update, -EBUSY if it detects a conflict of the flag
>> + * on a ftrace_rec.
>> + * Note that old_hash and new_hash has below meanings
>> + * - If the hash is NULL, it hits all recs
>> + * - If the hash is EMPTY_HASH, it hits nothing
>> + * - Others hits the recs which match the hash entries.
>
> - Anything else hits the recs ...

Oh, thanks!

>
>> + */
>> +static int __ftrace_hash_update_ipmodify(struct ftrace_ops *ops,
>> + struct ftrace_hash *old_hash,
>> + struct ftrace_hash *new_hash)
>> +{
>> + struct ftrace_page *pg;
>> + struct dyn_ftrace *rec, *end = NULL;
>> + int in_old, in_new;
>> +
>> + /* Only update if the ops has been registered */
>> + if (!(ops->flags & FTRACE_OPS_FL_ENABLED))
>> + return 0;
>> +
>> + if (!(ops->flags & FTRACE_OPS_FL_SAVE_REGS) ||
>> + !(ops->flags & FTRACE_OPS_FL_IPMODIFY))
>
> Only check the IPMODIFY flag. In the future, I may allow this without
> SAVE_REGS. That is, the function will get a regs pointer that has a
> limited number of regs set. Maybe just ip.

Ah, I see. I'll change that.

>> + return 0;
>> +
>> + /* Update rec->flags */
>> + do_for_each_ftrace_rec(pg, rec) {
>> + /* We need to update only differences of filter_hash */
>> + in_old = !old_hash || ftrace_lookup_ip(old_hash, rec->ip);
>> + in_new = !new_hash || ftrace_lookup_ip(new_hash, rec->ip);
>> + if (in_old == in_new)
>> + continue;
>> +
>> + if (in_new) {
>> + /* New entries must ensure no others are using it */
>> + if (rec->flags & FTRACE_FL_IPMODIFY)
>> + goto rollback;
>> + rec->flags |= FTRACE_FL_IPMODIFY;
>> + } else /* Removed entry */
>> + rec->flags &= ~FTRACE_FL_IPMODIFY;
>
> Like I mentioned before. This code depends on oldhash also having
> IPMODIFY set. I wonder if we can detect if it changed.

Yeah, I guess that SAVE_REGS flag has same issue. And, of course
kprobe->flags has same. I think we just need comments or a document
for the ftrace_ops API.

[...]
>> @@ -2078,6 +2195,15 @@ static int ftrace_startup(struct ftrace_ops *ops, int command)
>>
>> ops->flags |= FTRACE_OPS_FL_ENABLED;
>>
>> + ret = ftrace_hash_ipmodify_enable(ops);
>> + if (ret < 0) {
>> + /* Rollback registration process */
>> + __unregister_ftrace_function(ops);
>> + ftrace_start_up--;
>> + ops->flags &= ~FTRACE_OPS_FL_ENABLED;
>> + return ret;
>> + }
>> +
>> ftrace_hash_rec_enable(ops, 1);
>>
>> ftrace_startup_enable(command);
>> @@ -2104,6 +2230,8 @@ static int ftrace_shutdown(struct ftrace_ops *ops, int command)
>> */
>> WARN_ON_ONCE(ftrace_start_up < 0);
>>
>> + /* Disabling ipmodify never be failed */
>
> "Disabling ipmodify never fails"

OK, I'll fix that.

>
>> + ftrace_hash_ipmodify_disable(ops);
>> ftrace_hash_rec_disable(ops, 1);
>>
>> if (!global_start_up)
>> @@ -2641,9 +2769,10 @@ static int t_show(struct seq_file *m, void *v)
>>
>> seq_printf(m, "%ps", (void *)rec->ip);
>> if (iter->flags & FTRACE_ITER_ENABLED)
>> - seq_printf(m, " (%ld)%s",
>> + seq_printf(m, " (%ld)%s%s",
>> rec->flags & ~FTRACE_FL_MASK,
>> - rec->flags & FTRACE_FL_REGS ? " R" : "");
>> + rec->flags & FTRACE_FL_REGS ? " R" : "",
>> + rec->flags & FTRACE_FL_IPMODIFY ? " I" : "");
>
> Perhaps even add 'I' as we may allow setting it without regs.

Yes, here we do so. :)

Thank you,

--
Masami HIRAMATSU
Software Platform Research Dept. Linux Technology Research Center
Hitachi, Ltd., Yokohama Research Laboratory
E-mail: [email protected]