Re: __ftrace_hash_rec_update FTRACE_WARN_ON.

2013-08-01 Thread Steve Hodgson
On Tue, Jul 30, 2013 at 5:51 PM, Steven Rostedt  wrote:
> On Sat, 2013-07-27 at 12:16 -0700, Steve Hodgson wrote:
>
>> This patch fixes ftrace across module removal/reinsertion on our 3.6.11 
>> kernel.
>
> I found a few corner cases that this patch doesn't work with, and the
> solution is just getting uglier and uglier.
>
> I found a new solution that seems to handle all the corner cases
> (including this one). Can you test this as well. I want to add your
> tested-by tag for this too.
>
> Thanks!
>
> -- Steve

This patch also fixes the issue for me: ftrace works fine across module removal.

Sorry for being a little slow in testing this.

- Steve

>
> From 4c647dde26cf8c47ccaaed6f2e2fffee5dab5871 Mon Sep 17 00:00:00 2001
> From: "Steven Rostedt (Red Hat)" 
> Date: Tue, 30 Jul 2013 00:04:32 -0400
> Subject: [PATCH] ftrace: Check module functions being traced on reload
> MIME-Version: 1.0
> Content-Type: text/plain; charset=UTF-8
> Content-Transfer-Encoding: 8bit
>
> There's been a nasty bug that would show up and not give much info.
> The bug displayed the following warning:
>
>  WARNING: at kernel/trace/ftrace.c:1529 __ftrace_hash_rec_update+0x1e3/0x230()
>  Pid: 20903, comm: bash Tainted: G   O 3.6.11+ #38405.trunk
>  Call Trace:
>   [] warn_slowpath_common+0x7f/0xc0
>   [] warn_slowpath_null+0x1a/0x20
>   [] __ftrace_hash_rec_update+0x1e3/0x230
>   [] ftrace_hash_move+0x28/0x1d0
>   [] ? kfree+0x2c/0x110
>   [] ftrace_regex_release+0x8e/0x150
>   [] __fput+0xae/0x220
>   [] fput+0xe/0x10
>   [] task_work_run+0x72/0x90
>   [] do_notify_resume+0x6c/0xc0
>   [] ? trace_hardirqs_on_thunk+0x3a/0x3c
>   [] int_signal+0x12/0x17
>  ---[ end trace 793179526ee09b2c ]---
>
> It was finally narrowed down to unloading a module that was being traced.
>
> It was actually more than that. When functions are being traced, there's
> a table of all functions that have a ref count of the number of active
> tracers attached to that function. When a function trace callback is
> registered to a function, the function's record ref count is incremented.
> When it is unregistered, the function's record ref count is decremented.
> If an inconsistency is detected (ref count goes below zero) the above
> warning is shown and the function tracing is permanently disabled until
> reboot.
>
> The ftrace callback ops holds a hash of functions that it filters on
> (and/or filters off). If the hash is empty, the default means to filter
> all functions (for the filter_hash) or to disable no functions (for the
> notrace_hash).
>
> When a module is unloaded, it frees the function records that represent
> the module functions. These records exist on their own pages, that is
> function records for one module will not exist on the same page as
> function records for other modules or even the core kernel.
>
> Now when a module unloads, the records that represents its functions are
> freed. When the module is loaded again, the records are recreated with
> a default ref count of zero (unless there's a callback that traces all
> functions, then they will also be traced, and the ref count will be
> incremented).
>
> The problem is that if an ftrace callback hash includes functions of the
> module being unloaded, those hash entries will not be removed. If the
> module is reloaded in the same location, the hash entries still point
> to the functions of the module but the module's ref counts do not reflect
> that.
>
> With the help of Steve and Joern, we found a reproducer:
>
>  Using uinput module and uinput_release function.
>
>  cd /sys/kernel/debug/tracing
>  modprobe uinput
>  echo uinput_release > set_ftrace_filter
>  echo function > current_tracer
>  rmmod uinput
>  modprobe uinput
>  # check /proc/modules to see if loaded in same addr, otherwise try again
>  echo nop > current_tracer
>
>  [BOOM]
>
> The above loads the uinput module, which creates a table of functions that
> can be traced within the module.
>
> We add uinput_release to the filter_hash to trace just that function.
>
> Enable function tracincg, which increments the ref count of the record
> associated to uinput_release.
>
> Remove uinput, which frees the records including the one that represents
> uinput_release.
>
> Load the uinput module again (and make sure it's at the same address).
> This recreates the function records all with a ref count of zero,
> including uinput_release.
>
> Disable function tracing, which will decrement the ref count for 
> uinput_release
> which is now zero because of the module removal and reload, and we have
> a mismatch (below zero ref count).
>
> The solution is to check all 

Re: __ftrace_hash_rec_update FTRACE_WARN_ON.

2013-08-01 Thread Steve Hodgson
On Tue, Jul 30, 2013 at 5:51 PM, Steven Rostedt rost...@goodmis.org wrote:
 On Sat, 2013-07-27 at 12:16 -0700, Steve Hodgson wrote:

 This patch fixes ftrace across module removal/reinsertion on our 3.6.11 
 kernel.

 I found a few corner cases that this patch doesn't work with, and the
 solution is just getting uglier and uglier.

 I found a new solution that seems to handle all the corner cases
 (including this one). Can you test this as well. I want to add your
 tested-by tag for this too.

 Thanks!

 -- Steve

This patch also fixes the issue for me: ftrace works fine across module removal.

Sorry for being a little slow in testing this.

- Steve


 From 4c647dde26cf8c47ccaaed6f2e2fffee5dab5871 Mon Sep 17 00:00:00 2001
 From: Steven Rostedt (Red Hat) rost...@goodmis.org
 Date: Tue, 30 Jul 2013 00:04:32 -0400
 Subject: [PATCH] ftrace: Check module functions being traced on reload
 MIME-Version: 1.0
 Content-Type: text/plain; charset=UTF-8
 Content-Transfer-Encoding: 8bit

 There's been a nasty bug that would show up and not give much info.
 The bug displayed the following warning:

  WARNING: at kernel/trace/ftrace.c:1529 __ftrace_hash_rec_update+0x1e3/0x230()
  Pid: 20903, comm: bash Tainted: G   O 3.6.11+ #38405.trunk
  Call Trace:
   [8103e5ff] warn_slowpath_common+0x7f/0xc0
   [8103e65a] warn_slowpath_null+0x1a/0x20
   [810c2ee3] __ftrace_hash_rec_update+0x1e3/0x230
   [810c4f28] ftrace_hash_move+0x28/0x1d0
   [811401cc] ? kfree+0x2c/0x110
   [810c68ee] ftrace_regex_release+0x8e/0x150
   [81149f1e] __fput+0xae/0x220
   [8114a09e] fput+0xe/0x10
   [8105fa22] task_work_run+0x72/0x90
   [810028ec] do_notify_resume+0x6c/0xc0
   [8126596e] ? trace_hardirqs_on_thunk+0x3a/0x3c
   [815c0f88] int_signal+0x12/0x17
  ---[ end trace 793179526ee09b2c ]---

 It was finally narrowed down to unloading a module that was being traced.

 It was actually more than that. When functions are being traced, there's
 a table of all functions that have a ref count of the number of active
 tracers attached to that function. When a function trace callback is
 registered to a function, the function's record ref count is incremented.
 When it is unregistered, the function's record ref count is decremented.
 If an inconsistency is detected (ref count goes below zero) the above
 warning is shown and the function tracing is permanently disabled until
 reboot.

 The ftrace callback ops holds a hash of functions that it filters on
 (and/or filters off). If the hash is empty, the default means to filter
 all functions (for the filter_hash) or to disable no functions (for the
 notrace_hash).

 When a module is unloaded, it frees the function records that represent
 the module functions. These records exist on their own pages, that is
 function records for one module will not exist on the same page as
 function records for other modules or even the core kernel.

 Now when a module unloads, the records that represents its functions are
 freed. When the module is loaded again, the records are recreated with
 a default ref count of zero (unless there's a callback that traces all
 functions, then they will also be traced, and the ref count will be
 incremented).

 The problem is that if an ftrace callback hash includes functions of the
 module being unloaded, those hash entries will not be removed. If the
 module is reloaded in the same location, the hash entries still point
 to the functions of the module but the module's ref counts do not reflect
 that.

 With the help of Steve and Joern, we found a reproducer:

  Using uinput module and uinput_release function.

  cd /sys/kernel/debug/tracing
  modprobe uinput
  echo uinput_release  set_ftrace_filter
  echo function  current_tracer
  rmmod uinput
  modprobe uinput
  # check /proc/modules to see if loaded in same addr, otherwise try again
  echo nop  current_tracer

  [BOOM]

 The above loads the uinput module, which creates a table of functions that
 can be traced within the module.

 We add uinput_release to the filter_hash to trace just that function.

 Enable function tracincg, which increments the ref count of the record
 associated to uinput_release.

 Remove uinput, which frees the records including the one that represents
 uinput_release.

 Load the uinput module again (and make sure it's at the same address).
 This recreates the function records all with a ref count of zero,
 including uinput_release.

 Disable function tracing, which will decrement the ref count for 
 uinput_release
 which is now zero because of the module removal and reload, and we have
 a mismatch (below zero ref count).

 The solution is to check all currently tracing ftrace callbacks to see if any
 are tracing any of the module's functions when a module is loaded (it already 
 does
 that with callbacks that trace all functions). If a callback happens to have
 a module function being traced

Re: __ftrace_hash_rec_update FTRACE_WARN_ON.

2013-07-27 Thread Steve Hodgson
On Thu, Jul 25, 2013 at 8:23 PM, Steven Rostedt  wrote:
> On Thu, 2013-07-25 at 14:59 -0400, Steven Rostedt wrote:
>
>> Now that I know what's the problem, it shouldn't be too hard to fix.
>
> It was a bit more involved to fix than I expected. I don't like the fact
> that if you filter on only module functions and remove that module, you
> now remove the filter and it traces all functions. Oh well, that's the
> side effect of removing modules that you are only tracing. If you trace
> something other than the module you filter on, it will on remove the
> functions that belong to the module but keep the other functions.
>
> So, removing the module, is basically the same as doing:
>
>  echo '!:mod:' > set_ftrace_filter
>
> and acts the same, almost. It only affects the filter if the function
> trace is currently active. Otherwise it doesn't remove the functions
> from the filter, as it only removes functions from active filters. This
> is because ftrace is only aware of filters that are activated. I also
> added code (set for a separate patch, but combined for this email) that
> will add a 64 bit ref counter. Every time a module removes functions
> from ftrace, the counter is incremented. If a filter is activated it has
> its ref number checked with the current number. If it is different, then
> it tests all the functions in its filter to see if any should be removed
> (no longer exists).
>
> The reason for the warning, was that we enable the function and it was
> mapped in the filter. When we removed the module, we removed its
> functions from the table that keeps track of functions being traced (low
> level tracking, below filters). But we never cleared the filter. When
> the module was added again, it was put back into the same location,
> where the filter matched the address, but the low level table had the
> function disabled, and the filter said it was enabled. When an update
> was made, this discrepancy appeared and caused issues.
>
> You can try this patch to see if it fixes your issues. There may be some
> fuzz to apply it because I added it on top of my current queue that
> needs to go out for 3.11.

This patch fixes ftrace across module removal/reinsertion on our 3.6.11 kernel.

-- Steve Hodgson

>
> -- Steve
>
> diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
> index 9f15c00..3e6ed8f 100644
> --- a/include/linux/ftrace.h
> +++ b/include/linux/ftrace.h
> @@ -114,6 +114,7 @@ struct ftrace_ops {
> struct ftrace_hash  *notrace_hash;
> struct ftrace_hash  *filter_hash;
> struct mutexregex_lock;
> +   u64 mod_cnt;
>  #endif
>  };
>
> diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
> index 92d3334..366f524 100644
> --- a/kernel/trace/ftrace.c
> +++ b/kernel/trace/ftrace.c
> @@ -93,6 +93,9 @@ struct ftrace_pid {
> struct pid *pid;
>  };
>
> +/* Keep track of modules unloading and ops updating filters */
> +static u64 mod_ref_cnt;
> +
>  /*
>   * ftrace_disabled is set when an anomaly is discovered.
>   * ftrace_disabled is much stronger than ftrace_enabled.
> @@ -321,6 +324,18 @@ static void add_ftrace_ops(struct ftrace_ops **list, 
> struct ftrace_ops *ops)
> rcu_assign_pointer(*list, ops);
>  }
>
> +#ifdef CONFIG_DYNAMIC_FTRACE
> +static void verify_ops(struct ftrace_ops *ops);
> +#else
> +static inline void verify_ops(struct ftrace_ops *ops) { }
> +#endif
> +
> +static void add_main_ftrace_ops(struct ftrace_ops *ops)
> +{
> +   verify_ops(ops);
> +   add_ftrace_ops(_ops_list, ops);
> +}
> +
>  static int remove_ftrace_ops(struct ftrace_ops **list, struct ftrace_ops 
> *ops)
>  {
> struct ftrace_ops **p;
> @@ -352,7 +367,7 @@ static void add_ftrace_list_ops(struct ftrace_ops **list,
> int first = *list == _list_end;
> add_ftrace_ops(list, ops);
> if (first)
> -   add_ftrace_ops(_ops_list, main_ops);
> +   add_main_ftrace_ops(main_ops);
>  }
>
>  static int remove_ftrace_list_ops(struct ftrace_ops **list,
> @@ -405,7 +420,7 @@ static int __register_ftrace_function(struct ftrace_ops 
> *ops)
> return -ENOMEM;
> add_ftrace_list_ops(_control_list, _ops, ops);
> } else
> -   add_ftrace_ops(_ops_list, ops);
> +   add_main_ftrace_ops(ops);
>
> if (ftrace_enabled)
> update_ftrace_function();
> @@ -1351,6 +1366,38 @@ alloc_and_copy_ftrace_hash(int size_bits, struct 
> ftrace_hash *hash)
> return NULL;
>  }
>
> +static void verify_ops(struct ftrace_ops *ops)
> 

Re: __ftrace_hash_rec_update FTRACE_WARN_ON.

2013-07-27 Thread Steve Hodgson
On Thu, Jul 25, 2013 at 8:23 PM, Steven Rostedt rost...@goodmis.org wrote:
 On Thu, 2013-07-25 at 14:59 -0400, Steven Rostedt wrote:

 Now that I know what's the problem, it shouldn't be too hard to fix.

 It was a bit more involved to fix than I expected. I don't like the fact
 that if you filter on only module functions and remove that module, you
 now remove the filter and it traces all functions. Oh well, that's the
 side effect of removing modules that you are only tracing. If you trace
 something other than the module you filter on, it will on remove the
 functions that belong to the module but keep the other functions.

 So, removing the module, is basically the same as doing:

  echo '!:mod:module'  set_ftrace_filter

 and acts the same, almost. It only affects the filter if the function
 trace is currently active. Otherwise it doesn't remove the functions
 from the filter, as it only removes functions from active filters. This
 is because ftrace is only aware of filters that are activated. I also
 added code (set for a separate patch, but combined for this email) that
 will add a 64 bit ref counter. Every time a module removes functions
 from ftrace, the counter is incremented. If a filter is activated it has
 its ref number checked with the current number. If it is different, then
 it tests all the functions in its filter to see if any should be removed
 (no longer exists).

 The reason for the warning, was that we enable the function and it was
 mapped in the filter. When we removed the module, we removed its
 functions from the table that keeps track of functions being traced (low
 level tracking, below filters). But we never cleared the filter. When
 the module was added again, it was put back into the same location,
 where the filter matched the address, but the low level table had the
 function disabled, and the filter said it was enabled. When an update
 was made, this discrepancy appeared and caused issues.

 You can try this patch to see if it fixes your issues. There may be some
 fuzz to apply it because I added it on top of my current queue that
 needs to go out for 3.11.

This patch fixes ftrace across module removal/reinsertion on our 3.6.11 kernel.

-- Steve Hodgson


 -- Steve

 diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
 index 9f15c00..3e6ed8f 100644
 --- a/include/linux/ftrace.h
 +++ b/include/linux/ftrace.h
 @@ -114,6 +114,7 @@ struct ftrace_ops {
 struct ftrace_hash  *notrace_hash;
 struct ftrace_hash  *filter_hash;
 struct mutexregex_lock;
 +   u64 mod_cnt;
  #endif
  };

 diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
 index 92d3334..366f524 100644
 --- a/kernel/trace/ftrace.c
 +++ b/kernel/trace/ftrace.c
 @@ -93,6 +93,9 @@ struct ftrace_pid {
 struct pid *pid;
  };

 +/* Keep track of modules unloading and ops updating filters */
 +static u64 mod_ref_cnt;
 +
  /*
   * ftrace_disabled is set when an anomaly is discovered.
   * ftrace_disabled is much stronger than ftrace_enabled.
 @@ -321,6 +324,18 @@ static void add_ftrace_ops(struct ftrace_ops **list, 
 struct ftrace_ops *ops)
 rcu_assign_pointer(*list, ops);
  }

 +#ifdef CONFIG_DYNAMIC_FTRACE
 +static void verify_ops(struct ftrace_ops *ops);
 +#else
 +static inline void verify_ops(struct ftrace_ops *ops) { }
 +#endif
 +
 +static void add_main_ftrace_ops(struct ftrace_ops *ops)
 +{
 +   verify_ops(ops);
 +   add_ftrace_ops(ftrace_ops_list, ops);
 +}
 +
  static int remove_ftrace_ops(struct ftrace_ops **list, struct ftrace_ops 
 *ops)
  {
 struct ftrace_ops **p;
 @@ -352,7 +367,7 @@ static void add_ftrace_list_ops(struct ftrace_ops **list,
 int first = *list == ftrace_list_end;
 add_ftrace_ops(list, ops);
 if (first)
 -   add_ftrace_ops(ftrace_ops_list, main_ops);
 +   add_main_ftrace_ops(main_ops);
  }

  static int remove_ftrace_list_ops(struct ftrace_ops **list,
 @@ -405,7 +420,7 @@ static int __register_ftrace_function(struct ftrace_ops 
 *ops)
 return -ENOMEM;
 add_ftrace_list_ops(ftrace_control_list, control_ops, ops);
 } else
 -   add_ftrace_ops(ftrace_ops_list, ops);
 +   add_main_ftrace_ops(ops);

 if (ftrace_enabled)
 update_ftrace_function();
 @@ -1351,6 +1366,38 @@ alloc_and_copy_ftrace_hash(int size_bits, struct 
 ftrace_hash *hash)
 return NULL;
  }

 +static void verify_ops(struct ftrace_ops *ops)
 +{
 +   struct ftrace_hash *hash;
 +   struct hlist_node *tn;
 +   struct ftrace_func_entry *entry;
 +   int size;
 +   int i;
 +
 +   /*
 +* If a module was removed, we may need to verify
 +* the filters of this ops.
 +*/
 +   if (ops-mod_cnt == mod_ref_cnt)
 +   return;
 +
 +   /* We only need to verify the filter that may enable ops

Re: __ftrace_hash_rec_update FTRACE_WARN_ON.

2013-07-24 Thread Steve Hodgson
On Wed, Jul 24, 2013 at 6:24 PM, Steven Rostedt  wrote:
>
> On Wed, 2013-07-24 at 12:04 -0400, Jörn Engel wrote:
> > On Fri, 5 July 2013 10:53:54 -0400, Steven Rostedt wrote:
> > >
> > > Can you find an easy reproducer for this?
> >
> > We might have found something:
> >
> > Jul 23 19:00:59 [28253.487058,08] WARNING: at kernel/trace/ftrace.c:1529 
> > __ftrace_hash_rec_update+0x1e3/0x230()
> > Jul 23 19:00:59 [28253.487203,08] Pid: 20903, comm: bash Tainted: G 
> >   O 3.6.11+ #38405.trunk
> > Jul 23 19:00:59 [28253.487206,08] Call Trace:
> > Jul 23 19:00:59 [28253.487213,08]  [] 
> > warn_slowpath_common+0x7f/0xc0
> > Jul 23 19:00:59 [28253.487218,08]  [] 
> > warn_slowpath_null+0x1a/0x20
> > Jul 23 19:00:59 [28253.487222,08]  [] 
> > __ftrace_hash_rec_update+0x1e3/0x230
> > Jul 23 19:00:59 [28253.487227,08]  [] 
> > ftrace_hash_move+0x28/0x1d0
> > Jul 23 19:00:59 [28253.487232,08]  [] ? kfree+0x2c/0x110
> > Jul 23 19:00:59 [28253.487237,08]  [] 
> > ftrace_regex_release+0x8e/0x150
> > Jul 23 19:00:59 [28253.487242,08]  [] __fput+0xae/0x220
> > Jul 23 19:00:59 [28253.487247,08]  [] fput+0xe/0x10
> > Jul 23 19:00:59 [28253.487252,08]  [] 
> > task_work_run+0x72/0x90
> > Jul 23 19:00:59 [28253.487257,08]  [] 
> > do_notify_resume+0x6c/0xc0
> > Jul 23 19:00:59 [28253.487262,08]  [] ? 
> > trace_hardirqs_on_thunk+0x3a/0x3c
> > Jul 23 19:00:59 [28253.487267,08]  [] int_signal+0x12/0x17
> > Jul 23 19:00:59 [28253.487271,08] ---[ end trace 793179526ee09b2c ]---
> >
> > Jul 23 19:21:02 [  775.393547,08] WARNING: at kernel/trace/ftrace.c:1529 
> > __ftrace_hash_rec_update+0x1e3/0x230()
> > Jul 23 19:21:02 [  775.393715,08] Pid: 6376, comm: bash Tainted: G  
> >  O 3.6.11+ #38405.trunk
> > Jul 23 19:21:02 [  775.393718,08] Call Trace:
> > Jul 23 19:21:02 [  775.393727,08]  [] 
> > warn_slowpath_common+0x7f/0xc0
> > Jul 23 19:21:02 [  775.393732,08]  [] 
> > warn_slowpath_null+0x1a/0x20
> > Jul 23 19:21:02 [  775.393737,08]  [] 
> > __ftrace_hash_rec_update+0x1e3/0x230
> > Jul 23 19:21:02 [  775.393741,08]  [] 
> > ftrace_hash_move+0x28/0x1d0
> > Jul 23 19:21:02 [  775.393748,08]  [] ? kfree+0x2c/0x110
> > Jul 23 19:21:02 [  775.393754,08]  [] 
> > ftrace_regex_release+0x8e/0x150
> > Jul 23 19:21:02 [  775.393771,08]  [] __fput+0xae/0x220
> > Jul 23 19:21:02 [  775.393784,08]  [] fput+0xe/0x10
> > Jul 23 19:21:02 [  775.393792,08]  [] 
> > task_work_run+0x72/0x90
> > Jul 23 19:21:02 [  775.393798,08]  [] 
> > do_notify_resume+0x6c/0xc0
> > Jul 23 19:21:02 [  775.393804,08]  [] ? 
> > trace_hardirqs_on_thunk+0x3a/0x3c
> > Jul 23 19:21:02 [  775.393810,08]  [] int_signal+0x12/0x17
> > Jul 23 19:21:02 [  775.393814,08] ---[ end trace 3b86cc549cc5483e ]---
> >
> > If I understand Steve correctly, you have to enable a trace somewhere
> > in a module, them rmmod that module without disabling the trace.  Easy
> > enough to avoid, but maybe you are interested.
>
> I'm a bit confused by this. What do you mean exactly by enable a trace
> somewhere in a module? The module enables the trace? Does it have its
> own ftrace_ops? Or the module just starts tracing?

No, nothing so complicated.

I added symbols from a kernel module into
/sys/kernel/debug/tracing/set_ftrace_filter, enabled tracing, then
unloaded the kernel module.

Which I'll admit is a stupid thing to do. I was then punished for my
stupidity by being unable to use ftrace until the next reboot.

- Steve
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/


Re: __ftrace_hash_rec_update FTRACE_WARN_ON.

2013-07-24 Thread Steve Hodgson
On Wed, Jul 24, 2013 at 6:24 PM, Steven Rostedt rost...@goodmis.org wrote:

 On Wed, 2013-07-24 at 12:04 -0400, Jörn Engel wrote:
  On Fri, 5 July 2013 10:53:54 -0400, Steven Rostedt wrote:
  
   Can you find an easy reproducer for this?
 
  We might have found something:
 
  Jul 23 19:00:59 [28253.487058,08] WARNING: at kernel/trace/ftrace.c:1529 
  __ftrace_hash_rec_update+0x1e3/0x230()
  Jul 23 19:00:59 [28253.487203,08] Pid: 20903, comm: bash Tainted: G 
O 3.6.11+ #38405.trunk
  Jul 23 19:00:59 [28253.487206,08] Call Trace:
  Jul 23 19:00:59 [28253.487213,08]  [8103e5ff] 
  warn_slowpath_common+0x7f/0xc0
  Jul 23 19:00:59 [28253.487218,08]  [8103e65a] 
  warn_slowpath_null+0x1a/0x20
  Jul 23 19:00:59 [28253.487222,08]  [810c2ee3] 
  __ftrace_hash_rec_update+0x1e3/0x230
  Jul 23 19:00:59 [28253.487227,08]  [810c4f28] 
  ftrace_hash_move+0x28/0x1d0
  Jul 23 19:00:59 [28253.487232,08]  [811401cc] ? kfree+0x2c/0x110
  Jul 23 19:00:59 [28253.487237,08]  [810c68ee] 
  ftrace_regex_release+0x8e/0x150
  Jul 23 19:00:59 [28253.487242,08]  [81149f1e] __fput+0xae/0x220
  Jul 23 19:00:59 [28253.487247,08]  [8114a09e] fput+0xe/0x10
  Jul 23 19:00:59 [28253.487252,08]  [8105fa22] 
  task_work_run+0x72/0x90
  Jul 23 19:00:59 [28253.487257,08]  [810028ec] 
  do_notify_resume+0x6c/0xc0
  Jul 23 19:00:59 [28253.487262,08]  [8126596e] ? 
  trace_hardirqs_on_thunk+0x3a/0x3c
  Jul 23 19:00:59 [28253.487267,08]  [815c0f88] int_signal+0x12/0x17
  Jul 23 19:00:59 [28253.487271,08] ---[ end trace 793179526ee09b2c ]---
 
  Jul 23 19:21:02 [  775.393547,08] WARNING: at kernel/trace/ftrace.c:1529 
  __ftrace_hash_rec_update+0x1e3/0x230()
  Jul 23 19:21:02 [  775.393715,08] Pid: 6376, comm: bash Tainted: G  
   O 3.6.11+ #38405.trunk
  Jul 23 19:21:02 [  775.393718,08] Call Trace:
  Jul 23 19:21:02 [  775.393727,08]  [8103e5ff] 
  warn_slowpath_common+0x7f/0xc0
  Jul 23 19:21:02 [  775.393732,08]  [8103e65a] 
  warn_slowpath_null+0x1a/0x20
  Jul 23 19:21:02 [  775.393737,08]  [810c2ee3] 
  __ftrace_hash_rec_update+0x1e3/0x230
  Jul 23 19:21:02 [  775.393741,08]  [810c4f28] 
  ftrace_hash_move+0x28/0x1d0
  Jul 23 19:21:02 [  775.393748,08]  [811401cc] ? kfree+0x2c/0x110
  Jul 23 19:21:02 [  775.393754,08]  [810c68ee] 
  ftrace_regex_release+0x8e/0x150
  Jul 23 19:21:02 [  775.393771,08]  [81149f1e] __fput+0xae/0x220
  Jul 23 19:21:02 [  775.393784,08]  [8114a09e] fput+0xe/0x10
  Jul 23 19:21:02 [  775.393792,08]  [8105fa22] 
  task_work_run+0x72/0x90
  Jul 23 19:21:02 [  775.393798,08]  [810028ec] 
  do_notify_resume+0x6c/0xc0
  Jul 23 19:21:02 [  775.393804,08]  [8126596e] ? 
  trace_hardirqs_on_thunk+0x3a/0x3c
  Jul 23 19:21:02 [  775.393810,08]  [815c0f88] int_signal+0x12/0x17
  Jul 23 19:21:02 [  775.393814,08] ---[ end trace 3b86cc549cc5483e ]---
 
  If I understand Steve correctly, you have to enable a trace somewhere
  in a module, them rmmod that module without disabling the trace.  Easy
  enough to avoid, but maybe you are interested.

 I'm a bit confused by this. What do you mean exactly by enable a trace
 somewhere in a module? The module enables the trace? Does it have its
 own ftrace_ops? Or the module just starts tracing?

No, nothing so complicated.

I added symbols from a kernel module into
/sys/kernel/debug/tracing/set_ftrace_filter, enabled tracing, then
unloaded the kernel module.

Which I'll admit is a stupid thing to do. I was then punished for my
stupidity by being unable to use ftrace until the next reboot.

- Steve
--
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/