ftrace/kprobes: Warning when insmod two modules

ftrace/kprobes: Warning when insmod two modules

[Takao Indoh]

Hi all,

I noticed the following ftrace waring message when I insmod module.

[  409.337936] ------------[ cut here ]------------
[  409.337945] WARNING: CPU: 12 PID: 10028 at /mnt/repos/linux/kernel/trace/ftrace.c:1716 ftrace_bug+0x206/0x270()
[  409.337971] Modules linked in: test2(O+) test1(O+) ip6table_filter ip6_tables iptable_filter ip_tables ebtable_nat ebtables coretemp kvm_intel kvm crc32c_intel ghash_clmulni_intel aesni_intel sg aes_x86_64 glue_helper nfsd lrw gf128mul ablk_helper auth_rpcgss oid_registry cryptd exportfs nfs_acl lockd iTCO_wdt iTCO_vendor_support i7core_edac lpc_ich dm_mirror microcode serio_raw pcspkr i2c_i801 ioatdma dm_region_hash mfd_core edac_core ipmi_si dm_log shpchp tpm_infineon acpi_cpufreq dm_mod ipmi_msghandler uinput sunrpc ext4 mbcache jbd2 igb ptp mptsas pps_core lpfc i2c_algo_bit scsi_transport_sas scsi_transport_fc i2c_core mptscsih mptbase scsi_tgt megaraid_sas dca ipv6 autofs4 [last unloaded: test2]
[  409.337974] CPU: 12 PID: 10028 Comm: insmod Tainted: G           O 3.14.0-rc5 #6
[  409.337975] Hardware name: FUJITSU-SV PRIMERGY BX920 S2/D3030, BIOS 080015 Rev.3D81.3030 02/10/2012
[  409.337979]  0000000000000009 ffff88023f7efc50 ffffffff81547bfe 0000000000000000
[  409.337981]  ffff88023f7efc88 ffffffff81049a0d 0000000000000000 ffffffffa0364000
[  409.337983]  ffff88023f6775c0 0000000000000000 ffff880238570000 ffff88023f7efc98
[  409.337983] Call Trace:
[  409.337990]  [<ffffffff81547bfe>] dump_stack+0x45/0x56
[  409.337993]  [<ffffffff81049a0d>] warn_slowpath_common+0x7d/0xa0
[  409.337997]  [<ffffffffa0364000>] ? 0xffffffffa0363fff
[  409.337999]  [<ffffffff81049aea>] warn_slowpath_null+0x1a/0x20
[  409.338001]  [<ffffffff810e79f6>] ftrace_bug+0x206/0x270
[  409.338004]  [<ffffffffa0364000>] ? 0xffffffffa0363fff
[  409.338006]  [<ffffffff810e7d8e>] ftrace_process_locs+0x32e/0x710
[  409.338008]  [<ffffffff810e8206>] ftrace_module_notify_enter+0x96/0xf0
[  409.338012]  [<ffffffff81551dec>] notifier_call_chain+0x4c/0x70
[  409.338018]  [<ffffffff8106fbfd>] __blocking_notifier_call_chain+0x4d/0x70
[  409.338020]  [<ffffffff8106fc36>] blocking_notifier_call_chain+0x16/0x20
[  409.338026]  [<ffffffff810bf3f4>] load_module+0x1f54/0x25d0
[  409.338028]  [<ffffffff810baab0>] ? store_uevent+0x40/0x40
[  409.338031]  [<ffffffff810bfbe6>] SyS_finit_module+0x86/0xb0
[  409.338036]  [<ffffffff81556752>] system_call_fastpath+0x16/0x1b
[  409.338037] ---[ end trace e7e27c36e7a65831 ]---
[  409.338040] ftrace faulted on writing [<ffffffffa0364000>] handler_pre+0x0/0x10 [test2]

To cause this problem,
o Insmod two modules almost at the same time
o At least one of them use kprobe.

Let's say I'm trying to insmod module A and module B at the same time,
and module A calls register_kprobe() in it's module_init funciton.

<insmod module A>
init_module
  load_module
    do_init_module
      do_one_initcall
        kprobe_init
          register_kprobe
            arm_kprobe
              arm_kprobe_ftrace
                register_ftrace_function
                  mutex_lock(&ftrace_lock) ------------------- (1)
                  ftrace_startup
                    ftrace_startup_enable
                      ftrace_run_update_code
                        ftrace_arch_code_modify_post_process
                          set_all_modules_text_ro ------------ (2)
                  mutex_unlock(&ftrace_lock) ----------------- (3)


<insmod module B>
init_module
  load_module
    do_init_module
      blocking_notifier_call_chain
        ftrace_module_notify_enter
          ftrace_init_module
            ftrace_process_locs
             mutex_lock(&ftrace_lock) ------------------------ (4)
             ftrace_update_code
               __ftrace_replace_code
                 ftrace_make_nop
                   ftrace_modify_code_direct
                     do_ftrace_mod_code
                       probe_kernel_write -------------------- (5)


o Frist of all, module A gets ftrace_lock at (1)
o Module B also tries to get ftrace_lock at (4) somewhat late, and wait
  here because modules A got ftrace_lock.
o Module A sets all modules text to ReadOnly at (2), and then release
  ftrace_lock at (3)
o Module B wakes up and tries to rewrite its text at (5), but it fails
  because it is already changed to RO at (2) by modules A. The ftrace
  waring message is outputted.

I'm not familiar with ftrace/kprobe, so any comments/suggestions would
be appreciatd to fix this.

Thanks,
Takao Indoh

Re: ftrace/kprobes: Warning when insmod two modules

[Masami Hiramatsu]

(2014/03/24 14:10), Takao Indoh wrote:
> Hi all,
> 
> I noticed the following ftrace waring message when I insmod module.
> 
> [  409.337936] ------------[ cut here ]------------
> [  409.337945] WARNING: CPU: 12 PID: 10028 at /mnt/repos/linux/kernel/trace/ftrace.c:1716 ftrace_bug+0x206/0x270()
> [  409.337971] Modules linked in: test2(O+) test1(O+) ip6table_filter ip6_tables iptable_filter ip_tables ebtable_nat ebtables coretemp kvm_intel kvm crc32c_intel ghash_clmulni_intel aesni_intel sg aes_x86_64 glue_helper nfsd lrw gf128mul ablk_helper auth_rpcgss oid_registry cryptd exportfs nfs_acl lockd iTCO_wdt iTCO_vendor_support i7core_edac lpc_ich dm_mirror microcode serio_raw pcspkr i2c_i801 ioatdma dm_region_hash mfd_core edac_core ipmi_si dm_log shpchp tpm_infineon acpi_cpufreq dm_mod ipmi_msghandler uinput sunrpc ext4 mbcache jbd2 igb ptp mptsas pps_core lpfc i2c_algo_bit scsi_transport_sas scsi_transport_fc i2c_core mptscsih mptbase scsi_tgt megaraid_sas dca ipv6 autofs4 [last unloaded: test2]
> [  409.337974] CPU: 12 PID: 10028 Comm: insmod Tainted: G           O 3.14.0-rc5 #6
> [  409.337975] Hardware name: FUJITSU-SV PRIMERGY BX920 S2/D3030, BIOS 080015 Rev.3D81.3030 02/10/2012
> [  409.337979]  0000000000000009 ffff88023f7efc50 ffffffff81547bfe 0000000000000000
> [  409.337981]  ffff88023f7efc88 ffffffff81049a0d 0000000000000000 ffffffffa0364000
> [  409.337983]  ffff88023f6775c0 0000000000000000 ffff880238570000 ffff88023f7efc98
> [  409.337983] Call Trace:
> [  409.337990]  [<ffffffff81547bfe>] dump_stack+0x45/0x56
> [  409.337993]  [<ffffffff81049a0d>] warn_slowpath_common+0x7d/0xa0
> [  409.337997]  [<ffffffffa0364000>] ? 0xffffffffa0363fff
> [  409.337999]  [<ffffffff81049aea>] warn_slowpath_null+0x1a/0x20
> [  409.338001]  [<ffffffff810e79f6>] ftrace_bug+0x206/0x270
> [  409.338004]  [<ffffffffa0364000>] ? 0xffffffffa0363fff
> [  409.338006]  [<ffffffff810e7d8e>] ftrace_process_locs+0x32e/0x710
> [  409.338008]  [<ffffffff810e8206>] ftrace_module_notify_enter+0x96/0xf0
> [  409.338012]  [<ffffffff81551dec>] notifier_call_chain+0x4c/0x70
> [  409.338018]  [<ffffffff8106fbfd>] __blocking_notifier_call_chain+0x4d/0x70
> [  409.338020]  [<ffffffff8106fc36>] blocking_notifier_call_chain+0x16/0x20
> [  409.338026]  [<ffffffff810bf3f4>] load_module+0x1f54/0x25d0
> [  409.338028]  [<ffffffff810baab0>] ? store_uevent+0x40/0x40
> [  409.338031]  [<ffffffff810bfbe6>] SyS_finit_module+0x86/0xb0
> [  409.338036]  [<ffffffff81556752>] system_call_fastpath+0x16/0x1b
> [  409.338037] ---[ end trace e7e27c36e7a65831 ]---
> [  409.338040] ftrace faulted on writing [<ffffffffa0364000>] handler_pre+0x0/0x10 [test2]
> 
> To cause this problem,
> o Insmod two modules almost at the same time
> o At least one of them use kprobe.
> 
> Let's say I'm trying to insmod module A and module B at the same time,
> and module A calls register_kprobe() in it's module_init funciton.
> 
> <insmod module A>
> init_module
>   load_module
>     do_init_module
>       do_one_initcall
>         kprobe_init
>           register_kprobe
>             arm_kprobe
>               arm_kprobe_ftrace
>                 register_ftrace_function
>                   mutex_lock(&ftrace_lock) ------------------- (1)
>                   ftrace_startup
>                     ftrace_startup_enable
>                       ftrace_run_update_code
>                         ftrace_arch_code_modify_post_process
>                           set_all_modules_text_ro ------------ (2)
>                   mutex_unlock(&ftrace_lock) ----------------- (3)
> 
> 
> <insmod module B>
> init_module
>   load_module
>     do_init_module
>       blocking_notifier_call_chain
>         ftrace_module_notify_enter
>           ftrace_init_module
>             ftrace_process_locs
>              mutex_lock(&ftrace_lock) ------------------------ (4)
>              ftrace_update_code
>                __ftrace_replace_code
>                  ftrace_make_nop
>                    ftrace_modify_code_direct
>                      do_ftrace_mod_code
>                        probe_kernel_write -------------------- (5)
> 
> 
> o Frist of all, module A gets ftrace_lock at (1)
> o Module B also tries to get ftrace_lock at (4) somewhat late, and wait
>   here because modules A got ftrace_lock.
> o Module A sets all modules text to ReadOnly at (2), and then release
>   ftrace_lock at (3)
> o Module B wakes up and tries to rewrite its text at (5), but it fails
>   because it is already changed to RO at (2) by modules A. The ftrace
>   waring message is outputted.

Thank you for reporting with this pretty backtrace :)
Steven, I think this is not the kprobe bug but ftrace (and perhaps, module).

If the ftrace can set loading module text read only before the module subsystem
expected, I think it should be protected by the module subsystem itself
(e.g. set_all_modules_text_ro(rw) skips the modules which is MODULE_STATE_COMING)

Thank you,

-- 
Masami HIRAMATSU
IT Management Research Dept. Linux Technology Center
Hitachi, Ltd., Yokohama Research Laboratory
E-mail: masami.hiramatsu.pt@hitachi.com

Re: ftrace/kprobes: Warning when insmod two modules

[Steven Rostedt]

On Mon, 24 Mar 2014 20:26:05 +0900
Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com> wrote:

 
> Thank you for reporting with this pretty backtrace :)
> Steven, I think this is not the kprobe bug but ftrace (and perhaps, module).
> 
> If the ftrace can set loading module text read only before the module subsystem
> expected, I think it should be protected by the module subsystem itself
> (e.g. set_all_modules_text_ro(rw) skips the modules which is MODULE_STATE_COMING)
> 

I have to admit. I never thought about having the module init code
enabling ftrace :-)

Yeah, it looks like we need to handle this case. I'll take a look into
it.

Thanks for the report,

-- Steve

Re: ftrace/kprobes: Warning when insmod two modules

[Steven Rostedt]

On Mon, 24 Mar 2014 20:26:05 +0900
Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com> wrote:


> Thank you for reporting with this pretty backtrace :)
> Steven, I think this is not the kprobe bug but ftrace (and perhaps, module).

Looks to be more of a module issue than a ftrace issue.

> 
> If the ftrace can set loading module text read only before the module subsystem
> expected, I think it should be protected by the module subsystem itself
> (e.g. set_all_modules_text_ro(rw) skips the modules which is MODULE_STATE_COMING)
> 

Does this patch fix it?

In-review-off-by: Steven Rostedt <rostedt@goodmis.org>

diff --git a/include/linux/module.h b/include/linux/module.h
index 5a50539..a1acabf 100644
--- a/include/linux/module.h
+++ b/include/linux/module.h
@@ -207,10 +207,11 @@ struct module_use {
 };
 
 enum module_state {
-	MODULE_STATE_LIVE,	/* Normal state. */
-	MODULE_STATE_COMING,	/* Full formed, running module_init. */
-	MODULE_STATE_GOING,	/* Going away. */
-	MODULE_STATE_UNFORMED,	/* Still setting it up. */
+	MODULE_STATE_LIVE,		/* Normal state. */
+	MODULE_STATE_COMING,		/* Full formed, running module_init. */
+	MODULE_STATE_COMING_FINAL,	/* Ready to be changed to read only. */
+	MODULE_STATE_GOING,		/* Going away. */
+	MODULE_STATE_UNFORMED,		/* Still setting it up. */
 };
 
 /**
diff --git a/kernel/module.c b/kernel/module.c
index d24fcf2..0905bed 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -1805,7 +1805,8 @@ void set_all_modules_text_ro(void)
 
 	mutex_lock(&module_mutex);
 	list_for_each_entry_rcu(mod, &modules, list) {
-		if (mod->state == MODULE_STATE_UNFORMED)
+		if (mod->state == MODULE_STATE_UNFORMED ||
+		    mod->state == MODULE_STATE_COMING)
 			continue;
 		if ((mod->module_core) && (mod->core_text_size)) {
 			set_page_attributes(mod->module_core,
@@ -3020,6 +3021,13 @@ static int do_init_module(struct module *mod)
 	blocking_notifier_call_chain(&module_notify_list,
 			MODULE_STATE_COMING, mod);
 
+	/*
+	 * This module must not be changed by set_all_modules_text_ro()
+	 * until we get here. Otherwise notifiers that change text
+	 * (like ftrace does) will break.
+	 */
+	mod->state = MODULE_STATE_COMING_FINAL;
+
 	/* Set RO and NX regions for core */
 	set_section_ro_nx(mod->module_core,
 				mod->core_text_size,

Re: ftrace/kprobes: Warning when insmod two modules

[Takao Indoh]

(2014/03/24 23:59), Steven Rostedt wrote:
> On Mon, 24 Mar 2014 20:26:05 +0900
> Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com> wrote:
> 
> 
>> Thank you for reporting with this pretty backtrace :)
>> Steven, I think this is not the kprobe bug but ftrace (and perhaps, module).
> 
> Looks to be more of a module issue than a ftrace issue.
> 
>>
>> If the ftrace can set loading module text read only before the module subsystem
>> expected, I think it should be protected by the module subsystem itself
>> (e.g. set_all_modules_text_ro(rw) skips the modules which is MODULE_STATE_COMING)
>>
> 
> Does this patch fix it?

Yep, I tested using my reproducer and confirmed that this patch fixed
this issue, thanks!

Thanks,
Takao Indoh

> 
> In-review-off-by: Steven Rostedt <rostedt@goodmis.org>
> 
> diff --git a/include/linux/module.h b/include/linux/module.h
> index 5a50539..a1acabf 100644
> --- a/include/linux/module.h
> +++ b/include/linux/module.h
> @@ -207,10 +207,11 @@ struct module_use {
>   };
>   
>   enum module_state {
> -	MODULE_STATE_LIVE,	/* Normal state. */
> -	MODULE_STATE_COMING,	/* Full formed, running module_init. */
> -	MODULE_STATE_GOING,	/* Going away. */
> -	MODULE_STATE_UNFORMED,	/* Still setting it up. */
> +	MODULE_STATE_LIVE,		/* Normal state. */
> +	MODULE_STATE_COMING,		/* Full formed, running module_init. */
> +	MODULE_STATE_COMING_FINAL,	/* Ready to be changed to read only. */
> +	MODULE_STATE_GOING,		/* Going away. */
> +	MODULE_STATE_UNFORMED,		/* Still setting it up. */
>   };
>   
>   /**
> diff --git a/kernel/module.c b/kernel/module.c
> index d24fcf2..0905bed 100644
> --- a/kernel/module.c
> +++ b/kernel/module.c
> @@ -1805,7 +1805,8 @@ void set_all_modules_text_ro(void)
>   
>   	mutex_lock(&module_mutex);
>   	list_for_each_entry_rcu(mod, &modules, list) {
> -		if (mod->state == MODULE_STATE_UNFORMED)
> +		if (mod->state == MODULE_STATE_UNFORMED ||
> +		    mod->state == MODULE_STATE_COMING)
>   			continue;
>   		if ((mod->module_core) && (mod->core_text_size)) {
>   			set_page_attributes(mod->module_core,
> @@ -3020,6 +3021,13 @@ static int do_init_module(struct module *mod)
>   	blocking_notifier_call_chain(&module_notify_list,
>   			MODULE_STATE_COMING, mod);
>   
> +	/*
> +	 * This module must not be changed by set_all_modules_text_ro()
> +	 * until we get here. Otherwise notifiers that change text
> +	 * (like ftrace does) will break.
> +	 */
> +	mod->state = MODULE_STATE_COMING_FINAL;
> +
>   	/* Set RO and NX regions for core */
>   	set_section_ro_nx(mod->module_core,
>   				mod->core_text_size,
> 
> 
> 


-- 
印藤隆夫(INDOH Takao)
 E-Mail : indou.takao@jp.fujitsu.com
 TEL    : 7551-4832(055-924-7241)
富士通(株) PFソ事本)Linux開発統括部 開発部

Re: ftrace/kprobes: Warning when insmod two modules

[Rusty Russell]

Steven Rostedt <rostedt@goodmis.org> writes:
> On Mon, 24 Mar 2014 20:26:05 +0900
> Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com> wrote:
>
>
>> Thank you for reporting with this pretty backtrace :)
>> Steven, I think this is not the kprobe bug but ftrace (and perhaps, module).
>
> Looks to be more of a module issue than a ftrace issue.
>
>> 
>> If the ftrace can set loading module text read only before the module subsystem
>> expected, I think it should be protected by the module subsystem itself
>> (e.g. set_all_modules_text_ro(rw) skips the modules which is MODULE_STATE_COMING)
>> 
>
> Does this patch fix it?
>
> In-review-off-by: Steven Rostedt <rostedt@goodmis.org>

Sorry, was on paternity leave.

I'm always nervous about adding more states, since every place which
examines the state has to be audited.

We set the mod->state to MOD_STATE_COMING in complete_formation;
why don't we set NX there instead?  It also makes more sense to
set NX before we hit parse_args() which can execute code in the module.

In fact, we should probably call the notifier there too, so people
can breakpoint/tracepoint/etc parameter calls.

Of course, this means that we set NX before the notifier; does anything
break?

Subject: module: set nx before marking module MODULE_STATE_COMING.

This prevents a WARN_ON() where ftrace calls set_all_modules_text_ro()
which races with the module setting its own set_section_ro_nx().

It also means we're NX protected before we call parse_args(), which
can execute module code.

This means that the notifiers will be called on a module which
is already NX, so that may cause problems.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

diff --git a/kernel/module.c b/kernel/module.c
index 11869408f79b..83a437e5d429 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -3023,21 +3023,6 @@ static int do_init_module(struct module *mod)
 	 */
 	current->flags &= ~PF_USED_ASYNC;
 
-	blocking_notifier_call_chain(&module_notify_list,
-			MODULE_STATE_COMING, mod);
-
-	/* Set RO and NX regions for core */
-	set_section_ro_nx(mod->module_core,
-				mod->core_text_size,
-				mod->core_ro_size,
-				mod->core_size);
-
-	/* Set RO and NX regions for init */
-	set_section_ro_nx(mod->module_init,
-				mod->init_text_size,
-				mod->init_ro_size,
-				mod->init_size);
-
 	do_mod_ctors(mod);
 	/* Start the module */
 	if (mod->init != NULL)
@@ -3168,9 +3153,26 @@ static int complete_formation(struct module *mod, struct load_info *info)
 	/* This relies on module_mutex for list integrity. */
 	module_bug_finalize(info->hdr, info->sechdrs, mod);
 
+	/* Set RO and NX regions for core */
+	set_section_ro_nx(mod->module_core,
+				mod->core_text_size,
+				mod->core_ro_size,
+				mod->core_size);
+
+	/* Set RO and NX regions for init */
+	set_section_ro_nx(mod->module_init,
+				mod->init_text_size,
+				mod->init_ro_size,
+				mod->init_size);
+
 	/* Mark state as coming so strong_try_module_get() ignores us,
 	 * but kallsyms etc. can see us. */
 	mod->state = MODULE_STATE_COMING;
+	mutex_unlock(&module_mutex);
+
+	blocking_notifier_call_chain(&module_notify_list,
+				     MODULE_STATE_COMING, mod);
+	return 0;
 
 out:
 	mutex_unlock(&module_mutex);

Re: ftrace/kprobes: Warning when insmod two modules

[Takao Indoh]

(2014/04/22 12:51), Rusty Russell wrote:
> Steven Rostedt <rostedt@goodmis.org> writes:
>> On Mon, 24 Mar 2014 20:26:05 +0900
>> Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com> wrote:
>>
>>
>>> Thank you for reporting with this pretty backtrace :)
>>> Steven, I think this is not the kprobe bug but ftrace (and perhaps, module).
>>
>> Looks to be more of a module issue than a ftrace issue.
>>
>>>
>>> If the ftrace can set loading module text read only before the module subsystem
>>> expected, I think it should be protected by the module subsystem itself
>>> (e.g. set_all_modules_text_ro(rw) skips the modules which is MODULE_STATE_COMING)
>>>
>>
>> Does this patch fix it?
>>
>> In-review-off-by: Steven Rostedt <rostedt@goodmis.org>
> 
> Sorry, was on paternity leave.
> 
> I'm always nervous about adding more states, since every place which
> examines the state has to be audited.
> 
> We set the mod->state to MOD_STATE_COMING in complete_formation;
> why don't we set NX there instead?  It also makes more sense to
> set NX before we hit parse_args() which can execute code in the module.
> 
> In fact, we should probably call the notifier there too, so people
> can breakpoint/tracepoint/etc parameter calls.
> 
> Of course, this means that we set NX before the notifier; does anything
> break?

This does not work. ftrace_process_locs() is called from the notifier,
and it tries to change its text like this.

load_module
  blocking_notifier_call_chain
    ftrace_module_notify_enter
      ftrace_init_module
        ftrace_process_locs
          sort
            ftrace_swap_ips

But the text is already RO, so it causes panic. We need to call notifier
before setting it RO. Or should we unset RO temporarily in
ftrace_process_locs()?

Thanks,
Takao Indoh


> 
> Subject: module: set nx before marking module MODULE_STATE_COMING.
> 
> This prevents a WARN_ON() where ftrace calls set_all_modules_text_ro()
> which races with the module setting its own set_section_ro_nx().
> 
> It also means we're NX protected before we call parse_args(), which
> can execute module code.
> 
> This means that the notifiers will be called on a module which
> is already NX, so that may cause problems.
> 
> Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
> 
> diff --git a/kernel/module.c b/kernel/module.c
> index 11869408f79b..83a437e5d429 100644
> --- a/kernel/module.c
> +++ b/kernel/module.c
> @@ -3023,21 +3023,6 @@ static int do_init_module(struct module *mod)
>   	 */
>   	current->flags &= ~PF_USED_ASYNC;
>   
> -	blocking_notifier_call_chain(&module_notify_list,
> -			MODULE_STATE_COMING, mod);
> -
> -	/* Set RO and NX regions for core */
> -	set_section_ro_nx(mod->module_core,
> -				mod->core_text_size,
> -				mod->core_ro_size,
> -				mod->core_size);
> -
> -	/* Set RO and NX regions for init */
> -	set_section_ro_nx(mod->module_init,
> -				mod->init_text_size,
> -				mod->init_ro_size,
> -				mod->init_size);
> -
>   	do_mod_ctors(mod);
>   	/* Start the module */
>   	if (mod->init != NULL)
> @@ -3168,9 +3153,26 @@ static int complete_formation(struct module *mod, struct load_info *info)
>   	/* This relies on module_mutex for list integrity. */
>   	module_bug_finalize(info->hdr, info->sechdrs, mod);
>   
> +	/* Set RO and NX regions for core */
> +	set_section_ro_nx(mod->module_core,
> +				mod->core_text_size,
> +				mod->core_ro_size,
> +				mod->core_size);
> +
> +	/* Set RO and NX regions for init */
> +	set_section_ro_nx(mod->module_init,
> +				mod->init_text_size,
> +				mod->init_ro_size,
> +				mod->init_size);
> +
>   	/* Mark state as coming so strong_try_module_get() ignores us,
>   	 * but kallsyms etc. can see us. */
>   	mod->state = MODULE_STATE_COMING;
> +	mutex_unlock(&module_mutex);
> +
> +	blocking_notifier_call_chain(&module_notify_list,
> +				     MODULE_STATE_COMING, mod);
> +	return 0;
>   
>   out:
>   	mutex_unlock(&module_mutex);
> 
> 

Re: Re: ftrace/kprobes: Warning when insmod two modules

[Masami Hiramatsu]

(2014/04/22 14:29), Takao Indoh wrote:
> (2014/04/22 12:51), Rusty Russell wrote:
>> Steven Rostedt <rostedt@goodmis.org> writes:
>>> On Mon, 24 Mar 2014 20:26:05 +0900
>>> Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com> wrote:
>>>
>>>
>>>> Thank you for reporting with this pretty backtrace :)
>>>> Steven, I think this is not the kprobe bug but ftrace (and perhaps, module).
>>>
>>> Looks to be more of a module issue than a ftrace issue.
>>>
>>>>
>>>> If the ftrace can set loading module text read only before the module subsystem
>>>> expected, I think it should be protected by the module subsystem itself
>>>> (e.g. set_all_modules_text_ro(rw) skips the modules which is MODULE_STATE_COMING)
>>>>
>>>
>>> Does this patch fix it?
>>>
>>> In-review-off-by: Steven Rostedt <rostedt@goodmis.org>
>>
>> Sorry, was on paternity leave.
>>
>> I'm always nervous about adding more states, since every place which
>> examines the state has to be audited.
>>
>> We set the mod->state to MOD_STATE_COMING in complete_formation;
>> why don't we set NX there instead?  It also makes more sense to
>> set NX before we hit parse_args() which can execute code in the module.
>>
>> In fact, we should probably call the notifier there too, so people
>> can breakpoint/tracepoint/etc parameter calls.
>>
>> Of course, this means that we set NX before the notifier; does anything
>> break?
> 
> This does not work. ftrace_process_locs() is called from the notifier,
> and it tries to change its text like this.
> 
> load_module
>   blocking_notifier_call_chain
>     ftrace_module_notify_enter
>       ftrace_init_module
>         ftrace_process_locs
>           sort
>             ftrace_swap_ips
> 
> But the text is already RO, so it causes panic. We need to call notifier
> before setting it RO. Or should we unset RO temporarily in
> ftrace_process_locs()?

Perhaps, IMHO, ftrace needs to change the module RW in ftrace_init_module and
makes it RO after modifying the module text.

Thank you,


-- 
Masami HIRAMATSU
Software Platform Research Dept. Linux Technology Research Center
Hitachi, Ltd., Yokohama Research Laboratory
E-mail: masami.hiramatsu.pt@hitachi.com

Re: ftrace/kprobes: Warning when insmod two modules

[Takao Indoh]

(2014/04/22 16:28), Masami Hiramatsu wrote:
> (2014/04/22 14:29), Takao Indoh wrote:
>> (2014/04/22 12:51), Rusty Russell wrote:
>>> Steven Rostedt <rostedt@goodmis.org> writes:
>>>> On Mon, 24 Mar 2014 20:26:05 +0900
>>>> Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com> wrote:
>>>>
>>>>
>>>>> Thank you for reporting with this pretty backtrace :)
>>>>> Steven, I think this is not the kprobe bug but ftrace (and perhaps, module).
>>>>
>>>> Looks to be more of a module issue than a ftrace issue.
>>>>
>>>>>
>>>>> If the ftrace can set loading module text read only before the module subsystem
>>>>> expected, I think it should be protected by the module subsystem itself
>>>>> (e.g. set_all_modules_text_ro(rw) skips the modules which is MODULE_STATE_COMING)
>>>>>
>>>>
>>>> Does this patch fix it?
>>>>
>>>> In-review-off-by: Steven Rostedt <rostedt@goodmis.org>
>>>
>>> Sorry, was on paternity leave.
>>>
>>> I'm always nervous about adding more states, since every place which
>>> examines the state has to be audited.
>>>
>>> We set the mod->state to MOD_STATE_COMING in complete_formation;
>>> why don't we set NX there instead?  It also makes more sense to
>>> set NX before we hit parse_args() which can execute code in the module.
>>>
>>> In fact, we should probably call the notifier there too, so people
>>> can breakpoint/tracepoint/etc parameter calls.
>>>
>>> Of course, this means that we set NX before the notifier; does anything
>>> break?
>>
>> This does not work. ftrace_process_locs() is called from the notifier,
>> and it tries to change its text like this.
>>
>> load_module
>>    blocking_notifier_call_chain
>>      ftrace_module_notify_enter
>>        ftrace_init_module
>>          ftrace_process_locs
>>            sort
>>              ftrace_swap_ips
>>
>> But the text is already RO, so it causes panic. We need to call notifier
>> before setting it RO. Or should we unset RO temporarily in
>> ftrace_process_locs()?
> 
> Perhaps, IMHO, ftrace needs to change the module RW in ftrace_init_module and
> makes it RO after modifying the module text.

Hmm..., I think the same problem occurs if we set module RW in
ftrace_init_module().

<insmod module B>
init_module
  load_module
    complete_formation
      set_section_ro_nx -------------------------------------- (1)
      set_section_ro_nx -------------------------------------- (2)
      blocking_notifier_call_chain
        ftrace_module_notify_enter
          ftrace_init_module --------------------------------- (3)
            ftrace_process_locs
             mutex_lock(&ftrace_lock) ------------------------ (4)
             ftrace_update_code
               __ftrace_replace_code
                 ftrace_make_nop
                   ftrace_modify_code_direct
                     do_ftrace_mod_code
                       probe_kernel_write -------------------- (5)


The text of module B is set to RO at (1) and (2) by Rusty's patch. And
even if we change it to RW at (3), it set to RO again by another module
while module B is waiting at (4).

So, we need to set module to RW somewhere after get ftrace_lock, maybe
in ftrace_update_code()?

Thanks,
Takao Indoh

Re: ftrace/kprobes: Warning when insmod two modules

[Masami Hiramatsu]

(2014/04/22 17:35), Takao Indoh wrote:
>>> >> But the text is already RO, so it causes panic. We need to call notifier
>>> >> before setting it RO. Or should we unset RO temporarily in
>>> >> ftrace_process_locs()?
>> > 
>> > Perhaps, IMHO, ftrace needs to change the module RW in ftrace_init_module and
>> > makes it RO after modifying the module text.
> Hmm..., I think the same problem occurs if we set module RW in
> ftrace_init_module().
> 
> <insmod module B>
> init_module
>   load_module
>     complete_formation
>       set_section_ro_nx -------------------------------------- (1)
>       set_section_ro_nx -------------------------------------- (2)
>       blocking_notifier_call_chain
>         ftrace_module_notify_enter
>           ftrace_init_module --------------------------------- (3)
>             ftrace_process_locs
>              mutex_lock(&ftrace_lock) ------------------------ (4)
>              ftrace_update_code
>                __ftrace_replace_code
>                  ftrace_make_nop
>                    ftrace_modify_code_direct
>                      do_ftrace_mod_code
>                        probe_kernel_write -------------------- (5)
> 
> 
> The text of module B is set to RO at (1) and (2) by Rusty's patch. And
> even if we change it to RW at (3), it set to RO again by another module
> while module B is waiting at (4).
> 
> So, we need to set module to RW somewhere after get ftrace_lock, maybe
> in ftrace_update_code()?

Agreed. That should be done in a protected (critical) region,
and the region must be protected by correct lock. It seems that
the ftrace_lock is not a correct one.

Thank you,


-- 
Masami HIRAMATSU
Software Platform Research Dept. Linux Technology Research Center
Hitachi, Ltd., Yokohama Research Laboratory
E-mail: masami.hiramatsu.pt@hitachi.com

Re: ftrace/kprobes: Warning when insmod two modules

[Steven Rostedt]

On Wed, 23 Apr 2014 10:26:00 +0900
Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com> wrote:


> Agreed. That should be done in a protected (critical) region,
> and the region must be protected by correct lock. It seems that
> the ftrace_lock is not a correct one.

The setting of RO to RW done by ftrace before doing the normal
modification is under the ftrace_lock mutex. Why wouldn't that be the
correct lock?

The issue today is with the loading of a module and ftrace
expecting its code to be RW. Here's the current race:


	CPU 1				CPU 2
	-----				-----
  load_module()
   module->state = MODULE_STATE_COMING

				register_ftrace_function()
				 mutex_lock(&ftrace_lock);
				 ftrace_startup()
				  update_ftrace_function();
				   ftrace_arch_code_modify_prepare()
				    set_all_module_text_rw();
				   <enables-ftrace>
				    ftrace_arch_code_modify_post_process()
				     set_all_module_text_ro();

				[ here all module text is set to RO,
				  including the module that is
				  loading!! ]

   blocking_notifier_call_chain(MODULE_STATE_COMING);
    ftrace_init_module()


     [ tries to modify code, but it's RO, and fails! ]

One solution is to add a way to set a single module text to ro and rw,
and then we can encapsulate ftrace_init_module() under ftrace_lock
mutex and have the ftrace_init_module() set the text to RW and then
back to RO, and this will keep ftrace from having issues with the
loaded module.

Now, if text poke does something similar, we need to make another mutex
that covers modifying text. Don't we have one already?

The worry I have here, and why I still prefer the simple split state of
MODULE_STATE_COMING, is that once you add another mutex, we now have to
fight mutex ordering. Not to mention where else things might do this :-p

-- Steve

Re: ftrace/kprobes: Warning when insmod two modules

[Masami Hiramatsu]

(2014/04/23 10:56), Steven Rostedt wrote:
> On Wed, 23 Apr 2014 10:26:00 +0900
> Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com> wrote:
> 
> 
>> Agreed. That should be done in a protected (critical) region,
>> and the region must be protected by correct lock. It seems that
>> the ftrace_lock is not a correct one.
> 
> The setting of RO to RW done by ftrace before doing the normal
> modification is under the ftrace_lock mutex. Why wouldn't that be the
> correct lock?

Hmm, Ok. I checked that currently ftrace is the only user of
set_all_modules_text_rw(), so until another user appears,
ftrace_lock mutex can work.  (and also, we need a comment
on the top of such functions, about by what it is protected. )

> The issue today is with the loading of a module and ftrace
> expecting its code to be RW. Here's the current race:
> 
> 
> 	CPU 1				CPU 2
> 	-----				-----
>   load_module()
>    module->state = MODULE_STATE_COMING
> 
> 				register_ftrace_function()
> 				 mutex_lock(&ftrace_lock);
> 				 ftrace_startup()
> 				  update_ftrace_function();
> 				   ftrace_arch_code_modify_prepare()
> 				    set_all_module_text_rw();
> 				   <enables-ftrace>
> 				    ftrace_arch_code_modify_post_process()
> 				     set_all_module_text_ro();
> 
> 				[ here all module text is set to RO,
> 				  including the module that is
> 				  loading!! ]
> 
>    blocking_notifier_call_chain(MODULE_STATE_COMING);
>     ftrace_init_module()
> 
> 
>      [ tries to modify code, but it's RO, and fails! ]
> 
> One solution is to add a way to set a single module text to ro and rw,
> and then we can encapsulate ftrace_init_module() under ftrace_lock
> mutex and have the ftrace_init_module() set the text to RW and then
> back to RO, and this will keep ftrace from having issues with the
> loaded module.

It sounds nicer solution, less side-effect.

> Now, if text poke does something similar, we need to make another mutex
> that covers modifying text. Don't we have one already?

We have the text_mutex already :).

> The worry I have here, and why I still prefer the simple split state of
> MODULE_STATE_COMING, is that once you add another mutex, we now have to
> fight mutex ordering. Not to mention where else things might do this :-p

I see, however, we should take care of it, at least comment level.

Thank you,

-- 
Masami HIRAMATSU
Software Platform Research Dept. Linux Technology Research Center
Hitachi, Ltd., Yokohama Research Laboratory
E-mail: masami.hiramatsu.pt@hitachi.com

Re: ftrace/kprobes: Warning when insmod two modules

[Takao Indoh]

(2014/04/23 11:37), Masami Hiramatsu wrote:
> (2014/04/23 10:56), Steven Rostedt wrote:
>> On Wed, 23 Apr 2014 10:26:00 +0900
>> Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com> wrote:
>>
>>
>>> Agreed. That should be done in a protected (critical) region,
>>> and the region must be protected by correct lock. It seems that
>>> the ftrace_lock is not a correct one.
>>
>> The setting of RO to RW done by ftrace before doing the normal
>> modification is under the ftrace_lock mutex. Why wouldn't that be the
>> correct lock?
> 
> Hmm, Ok. I checked that currently ftrace is the only user of
> set_all_modules_text_rw(), so until another user appears,
> ftrace_lock mutex can work.  (and also, we need a comment
> on the top of such functions, about by what it is protected. )
> 
>> The issue today is with the loading of a module and ftrace
>> expecting its code to be RW. Here's the current race:
>>
>>
>> 	CPU 1				CPU 2
>> 	-----				-----
>>    load_module()
>>     module->state = MODULE_STATE_COMING
>>
>> 				register_ftrace_function()
>> 				 mutex_lock(&ftrace_lock);
>> 				 ftrace_startup()
>> 				  update_ftrace_function();
>> 				   ftrace_arch_code_modify_prepare()
>> 				    set_all_module_text_rw();
>> 				   <enables-ftrace>
>> 				    ftrace_arch_code_modify_post_process()
>> 				     set_all_module_text_ro();
>>
>> 				[ here all module text is set to RO,
>> 				  including the module that is
>> 				  loading!! ]
>>
>>     blocking_notifier_call_chain(MODULE_STATE_COMING);
>>      ftrace_init_module()
>>
>>
>>       [ tries to modify code, but it's RO, and fails! ]
>>
>> One solution is to add a way to set a single module text to ro and rw,
>> and then we can encapsulate ftrace_init_module() under ftrace_lock
>> mutex and have the ftrace_init_module() set the text to RW and then
>> back to RO, and this will keep ftrace from having issues with the
>> loaded module.
> 
> It sounds nicer solution, less side-effect.
> 
>> Now, if text poke does something similar, we need to make another mutex
>> that covers modifying text. Don't we have one already?
> 
> We have the text_mutex already :).
> 
>> The worry I have here, and why I still prefer the simple split state of
>> MODULE_STATE_COMING, is that once you add another mutex, we now have to
>> fight mutex ordering. Not to mention where else things might do this :-p
> 
> I see, however, we should take care of it, at least comment level.

Ok, I'll do this. Something like this, right?

static void ftrace_init_module(struct module *mod,
                               unsigned long *start, unsigned long *end)
{
	if (ftrace_disabled || start == end)
		return;

	/*
	 * Need ftrace_lock here to prevent someone from changing the module
	 * text to RO by set_all_modules_text_ro(). Currently ftrace is the
	 * only user of set_all_modules_text_ro(), so until another user
	 * appears, ftrace_lock mutex can work.
	 */
	mutex_lock(&ftrace_lock);

	set_one_module_text_rw(mod);
	ftrace_process_locs(mod, start, end);
	set_one_module_text_ro(mod);

	mutex_unlock(&ftrace_lock);
}

Thanks,
Takao Indoh

Re: ftrace/kprobes: Warning when insmod two modules

[Steven Rostedt]

On Thu, 24 Apr 2014 15:58:53 +0900
Takao Indoh <indou.takao@jp.fujitsu.com> wrote:

> Ok, I'll do this. Something like this, right?
> 
> static void ftrace_init_module(struct module *mod,
>                                unsigned long *start, unsigned long *end)
> {
> 	if (ftrace_disabled || start == end)
> 		return;
> 
> 	/*
> 	 * Need ftrace_lock here to prevent someone from changing the module
> 	 * text to RO by set_all_modules_text_ro(). Currently ftrace is the
> 	 * only user of set_all_modules_text_ro(), so until another user
> 	 * appears, ftrace_lock mutex can work.
> 	 */
> 	mutex_lock(&ftrace_lock);
> 
> 	set_one_module_text_rw(mod);
> 	ftrace_process_locs(mod, start, end);
> 	set_one_module_text_ro(mod);
> 
> 	mutex_unlock(&ftrace_lock);
> }
> 

I like Rusty's solution the best. Just hard code the call to ftrace's
module init code where it is still safe to do so
(MODULE_STATE_UNFORMED). This seems to be an ftrace only issue.

Thanks,

-- Steve

Re: ftrace/kprobes: Warning when insmod two modules

[Steven Rostedt]

On Tue, 22 Apr 2014 13:21:18 +0930
Rusty Russell <rusty@rustcorp.com.au> wrote:


> Sorry, was on paternity leave.

Congratulations! Although having two teenage daughters myself, I'm more
inclined to say "my condolences".

> 
> I'm always nervous about adding more states, since every place which
> examines the state has to be audited.

I didn't really add a state but instead broke an existing state into
two. More importantly, this second part of the state doesn't get
exported to other parts of the kernel. That is, there is no notifier
for it.

This means the only place you need to audit is in module.c itself. Any
other change requires auditing all module notifiers.


> 
> We set the mod->state to MOD_STATE_COMING in complete_formation;
> why don't we set NX there instead?  It also makes more sense to
> set NX before we hit parse_args() which can execute code in the module.

Well, NX is a different issue here all together. Sure if you want to,
but that wont affect this.

> 
> In fact, we should probably call the notifier there too, so people
> can breakpoint/tracepoint/etc parameter calls.
> 
> Of course, this means that we set NX before the notifier; does anything
> break?
> 
> Subject: module: set nx before marking module MODULE_STATE_COMING.
> 
> This prevents a WARN_ON() where ftrace calls set_all_modules_text_ro()
> which races with the module setting its own set_section_ro_nx().
> 
> It also means we're NX protected before we call parse_args(), which
> can execute module code.
> 
> This means that the notifiers will be called on a module which
> is already NX, so that may cause problems.
> 
> Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>
> 
> diff --git a/kernel/module.c b/kernel/module.c
> index 11869408f79b..83a437e5d429 100644
> --- a/kernel/module.c
> +++ b/kernel/module.c
> @@ -3023,21 +3023,6 @@ static int do_init_module(struct module *mod)
>  	 */
>  	current->flags &= ~PF_USED_ASYNC;
>  
> -	blocking_notifier_call_chain(&module_notify_list,
> -			MODULE_STATE_COMING, mod);
> -
> -	/* Set RO and NX regions for core */
> -	set_section_ro_nx(mod->module_core,
> -				mod->core_text_size,
> -				mod->core_ro_size,
> -				mod->core_size);
> -
> -	/* Set RO and NX regions for init */
> -	set_section_ro_nx(mod->module_init,
> -				mod->init_text_size,
> -				mod->init_ro_size,
> -				mod->init_size);
> -
>  	do_mod_ctors(mod);
>  	/* Start the module */
>  	if (mod->init != NULL)
> @@ -3168,9 +3153,26 @@ static int complete_formation(struct module *mod, struct load_info *info)
>  	/* This relies on module_mutex for list integrity. */
>  	module_bug_finalize(info->hdr, info->sechdrs, mod);
>  
> +	/* Set RO and NX regions for core */
> +	set_section_ro_nx(mod->module_core,
> +				mod->core_text_size,
> +				mod->core_ro_size,
> +				mod->core_size);
> +
> +	/* Set RO and NX regions for init */
> +	set_section_ro_nx(mod->module_init,
> +				mod->init_text_size,
> +				mod->init_ro_size,
> +				mod->init_size);
> +
>  	/* Mark state as coming so strong_try_module_get() ignores us,
>  	 * but kallsyms etc. can see us. */
>  	mod->state = MODULE_STATE_COMING;
> +	mutex_unlock(&module_mutex);
> +
> +	blocking_notifier_call_chain(&module_notify_list,
> +				     MODULE_STATE_COMING, mod);

Here we break ftrace. ftrace expects that it can still replaces the
calls to mcount with nops here. If the text is RO, then it will crash.

-- Steve


> +	return 0;
>  
>  out:
>  	mutex_unlock(&module_mutex);

Re: ftrace/kprobes: Warning when insmod two modules

[Rusty Russell]

Steven Rostedt <rostedt@goodmis.org> writes:
> On Tue, 22 Apr 2014 13:21:18 +0930
> Rusty Russell <rusty@rustcorp.com.au> wrote:
>
>
>> Sorry, was on paternity leave.
>
> Congratulations! Although having two teenage daughters myself, I'm more
> inclined to say "my condolences".

Thanks... I think!

>> I'm always nervous about adding more states, since every place which
>> examines the state has to be audited.
>
> I didn't really add a state but instead broke an existing state into
> two. More importantly, this second part of the state doesn't get
> exported to other parts of the kernel. That is, there is no notifier
> for it.
>
> This means the only place you need to audit is in module.c itself. Any
> other change requires auditing all module notifiers.

Yes, we only need to check everywhere which looks at mod->state.

>> We set the mod->state to MOD_STATE_COMING in complete_formation;
>> why don't we set NX there instead?  It also makes more sense to
>> set NX before we hit parse_args() which can execute code in the module.
>
> Well, NX is a different issue here all together. Sure if you want to,
> but that wont affect this.

RO and NX get set together in the module code, but you're right, it's
the RO which affects you.

>> +	/* Set RO and NX regions for core */
>> +	set_section_ro_nx(mod->module_core,
>> +				mod->core_text_size,
>> +				mod->core_ro_size,
>> +				mod->core_size);
>> +
>> +	/* Set RO and NX regions for init */
>> +	set_section_ro_nx(mod->module_init,
>> +				mod->init_text_size,
>> +				mod->init_ro_size,
>> +				mod->init_size);
>> +
>>  	/* Mark state as coming so strong_try_module_get() ignores us,
>>  	 * but kallsyms etc. can see us. */
>>  	mod->state = MODULE_STATE_COMING;
>> +	mutex_unlock(&module_mutex);
>> +
>> +	blocking_notifier_call_chain(&module_notify_list,
>> +				     MODULE_STATE_COMING, mod);
>
> Here we break ftrace. ftrace expects that it can still replaces the
> calls to mcount with nops here. If the text is RO, then it will crash.

I think we should apply a patch like the above for other reasons, so...

What if we call the notifier before setting ro_nx, and then set the
state after the notifier?

OTOH, if it's just ftrace (do tracepoints have an issue?) I'd rather
hardcode a ftrace_init_module() call in exactly the right place.
Notifiers which are sensitive to their exact call location tend give me
the creeps...

Cheers,
Rusty.

Re: ftrace/kprobes: Warning when insmod two modules

[Steven Rostedt]

On Thu, 24 Apr 2014 17:08:56 +0930
Rusty Russell <rusty@rustcorp.com.au> wrote:

> OTOH, if it's just ftrace (do tracepoints have an issue?) I'd rather
> hardcode a ftrace_init_module() call in exactly the right place.
> Notifiers which are sensitive to their exact call location tend give me
> the creeps...

I think I like this solution the best. I believe it was the original
solution for ftrace until we realized that it can be also done by a
notifier.

It also makes it more in line with what the core kernel does, as I
considered notifiers similar to initcalls and the init code for ftrace
is hard coded in init/main.c and not done by initcalls, as it is
important to be done before anything else.

Yeah, a ftrace_init_module() hard coded in where the module state is
still MODULE_STATE_UNFORMED, would work.

-- Steve