Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1477706 > unrolled thread

[PATCH 0/3] kobject tracepoints

Back to article view | Back to linux.kernel

Contents

  [PATCH 0/3] kobject tracepoints Shuah Khan <shuahkh@osg.samsung.com> - 2016-09-06 20:00 +0200
    [PATCH 3/3] kobject: Add calls to kobject trace points Shuah Khan <shuahkh@osg.samsung.com> - 2016-09-06 20:00 +0200
    Re: [PATCH 0/3] kobject tracepoints Greg KH <gregkh@linuxfoundation.org> - 2016-09-06 21:40 +0200
      Re: [PATCH 0/3] kobject tracepoints Shuah Khan <shuahkh@osg.samsung.com> - 2016-09-06 22:20 +0200
        Re: [PATCH 0/3] kobject tracepoints Greg KH <gregkh@linuxfoundation.org> - 2016-09-07 07:50 +0200

#1477706 — [PATCH 0/3] kobject tracepoints

Add kobject trace points to track kobject operations: init, add, set_name,
init_and_add, create_and_add, move, rename, get, put, cleanup, and del.

Kobject trace points can aid in debugging, generating status and graphs
on kobjects in the kernel and their hierarchy.

This patch series adds kobject tracepoints and adds calls to tracepoints
from kobject init, add, set_name, init_and_add, create_and_add, move,
rename, get, put, cleanup, and del operations.

A suggestion to provide more visibility into kboject lifetimes came out of
a discussion at my Embedded data structure lifetime talk at LinuxCon NA in
Toronto. As I thought about on how to provide visibility, I decided adding
traces provides a boot and run-time facility to trace kobject operations
without needing compile special kernels and also without impacting run-time
unless trace is enabled. Hence, this resulting patch series.

Example traces:

<...>-13632 [003] d... 11296.965114: kobject_get: KOBJECT: 1:0:0:0 (f
fff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 19
           <...>-13632 [003] d... 11296.965167: kobject_get: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 20
           <...>-13632 [003] d... 11296.965218: kobject_get: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 21
           <...>-13632 [003] d... 11296.965269: kobject_get: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 22
          <idle>-0     [006] ..s. 11296.965378: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 21
          <idle>-0     [006] .Ns. 11296.965542: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 20
     ksoftirqd/6-46    [006] ..s. 11296.965633: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 19
     ksoftirqd/6-46    [006] ..s. 11296.965703: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 18

Shuah Khan (3):
  kobject: add kobject trace points
  kobject: add kobject trace prototypes
  kobject: Add calls to kobject trace points

 include/trace/events/kobject.h | 259 +++++++++++++++++++++++++++++++++++++++++
 lib/Makefile                   |   2 +-
 lib/kobject.c                  |  22 ++++
 lib/kobject_traces.c           |  32 +++++
 4 files changed, 314 insertions(+), 1 deletion(-)
 create mode 100644 include/trace/events/kobject.h
 create mode 100644 lib/kobject_traces.c

-- 
2.7.4

[toc] | [next] | [standalone]

#1477708 — [PATCH 3/3] kobject: Add calls to kobject trace points

Add calls to kobject trace points to kobject init, add, init_and_add,
create_and_add, move, set_name, rename, get, put, cleanup, and del.

Signed-off-by: Shuah Khan <shuahkh@osg.samsung.com>
---
 lib/kobject.c | 22 ++++++++++++++++++++++
 1 file changed, 22 insertions(+)

diff --git a/lib/kobject.c b/lib/kobject.c
index 445dcae..97ab522 100644
--- a/lib/kobject.c
+++ b/lib/kobject.c
@@ -18,6 +18,7 @@
 #include <linux/stat.h>
 #include <linux/slab.h>
 #include <linux/random.h>
+#include <trace/events/kobject.h>
 
 /**
  * kobject_namespace - return @kobj's namespace tag
@@ -306,6 +307,9 @@ int kobject_set_name(struct kobject *kobj, const char *fmt, ...)
 	retval = kobject_set_name_vargs(kobj, fmt, vargs);
 	va_end(vargs);
 
+	if (!retval)
+		trace_kobject_set_name(kobj);
+
 	return retval;
 }
 EXPORT_SYMBOL(kobject_set_name);
@@ -343,6 +347,7 @@ void kobject_init(struct kobject *kobj, struct kobj_type *ktype)
 
 	kobject_init_internal(kobj);
 	kobj->ktype = ktype;
+	trace_kobject_init(kobj);
 	return;
 
 error:
@@ -411,6 +416,9 @@ int kobject_add(struct kobject *kobj, struct kobject *parent,
 	retval = kobject_add_varg(kobj, parent, fmt, args);
 	va_end(args);
 
+	if (!retval)
+		trace_kobject_add(kobj);
+
 	return retval;
 }
 EXPORT_SYMBOL(kobject_add);
@@ -438,6 +446,9 @@ int kobject_init_and_add(struct kobject *kobj, struct kobj_type *ktype,
 	retval = kobject_add_varg(kobj, parent, fmt, args);
 	va_end(args);
 
+	if (!retval)
+		trace_kobject_init_and_add(kobj);
+
 	return retval;
 }
 EXPORT_SYMBOL_GPL(kobject_init_and_add);
@@ -494,11 +505,14 @@ int kobject_rename(struct kobject *kobj, const char *new_name)
 	dup_name = kobj->name;
 	kobj->name = name;
 
+	trace_kobject_rename(kobj, devpath);
+
 	/* This function is mostly/only used for network interface.
 	 * Some hotplug package track interfaces by their name and
 	 * therefore want to know when the name is changed by the user. */
 	kobject_uevent_env(kobj, KOBJ_MOVE, envp);
 
+
 out:
 	kfree_const(dup_name);
 	kfree(devpath_string);
@@ -553,6 +567,7 @@ int kobject_move(struct kobject *kobj, struct kobject *new_parent)
 	new_parent = NULL;
 	kobject_put(old_parent);
 	kobject_uevent_env(kobj, KOBJ_MOVE, envp);
+	trace_kobject_move(kobj, old_parent);
 out:
 	kobject_put(new_parent);
 	kobject_put(kobj);
@@ -581,6 +596,7 @@ void kobject_del(struct kobject *kobj)
 	kobj_kset_leave(kobj);
 	kobject_put(kobj->parent);
 	kobj->parent = NULL;
+	trace_kobject_del(kobj);
 }
 EXPORT_SYMBOL(kobject_del);
 
@@ -596,6 +612,7 @@ struct kobject *kobject_get(struct kobject *kobj)
 			       "initialized, yet kobject_get() is being "
 			       "called.\n", kobject_name(kobj), kobj);
 		kref_get(&kobj->kref);
+		trace_kobject_get(kobj);
 	}
 	return kobj;
 }
@@ -620,6 +637,8 @@ static void kobject_cleanup(struct kobject *kobj)
 	pr_debug("kobject: '%s' (%p): %s, parent %p\n",
 		 kobject_name(kobj), kobj, __func__, kobj->parent);
 
+	trace_kobject_cleanup(kobj);
+
 	if (t && !t->release)
 		pr_debug("kobject: '%s' (%p): does not have a release() "
 			 "function, it is broken and must be fixed.\n",
@@ -688,6 +707,8 @@ void kobject_put(struct kobject *kobj)
 			WARN(1, KERN_WARNING "kobject: '%s' (%p): is not "
 			       "initialized, yet kobject_put() is being "
 			       "called.\n", kobject_name(kobj), kobj);
+		/* call it now - kobj could get released during kref_put() */
+		trace_kobject_put(kobj);
 		kref_put(&kobj->kref, kobject_release);
 	}
 }
@@ -756,6 +777,7 @@ struct kobject *kobject_create_and_add(const char *name, struct kobject *parent)
 		kobject_put(kobj);
 		kobj = NULL;
 	}
+	trace_kobject_create_and_add(kobj);
 	return kobj;
 }
 EXPORT_SYMBOL_GPL(kobject_create_and_add);
-- 
2.7.4

[toc] | [prev] | [next] | [standalone]

#1477786

On Tue, Sep 06, 2016 at 11:49:22AM -0600, Shuah Khan wrote:
> Add kobject trace points to track kobject operations: init, add, set_name,
> init_and_add, create_and_add, move, rename, get, put, cleanup, and del.
> 
> Kobject trace points can aid in debugging, generating status and graphs
> on kobjects in the kernel and their hierarchy.

What type of "graphs"?  Isn't this just too noisy to ever find anything
"real"?

> This patch series adds kobject tracepoints and adds calls to tracepoints
> from kobject init, add, set_name, init_and_add, create_and_add, move,
> rename, get, put, cleanup, and del operations.
> 
> A suggestion to provide more visibility into kboject lifetimes came out of
> a discussion at my Embedded data structure lifetime talk at LinuxCon NA in
> Toronto. As I thought about on how to provide visibility, I decided adding
> traces provides a boot and run-time facility to trace kobject operations
> without needing compile special kernels and also without impacting run-time
> unless trace is enabled. Hence, this resulting patch series.
> 
> Example traces:
> 
> <...>-13632 [003] d... 11296.965114: kobject_get: KOBJECT: 1:0:0:0 (f
> fff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 19
>            <...>-13632 [003] d... 11296.965167: kobject_get: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 20
>            <...>-13632 [003] d... 11296.965218: kobject_get: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 21
>            <...>-13632 [003] d... 11296.965269: kobject_get: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 22
>           <idle>-0     [006] ..s. 11296.965378: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 21
>           <idle>-0     [006] .Ns. 11296.965542: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 20
>      ksoftirqd/6-46    [006] ..s. 11296.965633: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 19
>      ksoftirqd/6-46    [006] ..s. 11296.965703: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 18
> 
> Shuah Khan (3):
>   kobject: add kobject trace points
>   kobject: add kobject trace prototypes
>   kobject: Add calls to kobject trace points
> 
>  include/trace/events/kobject.h | 259 +++++++++++++++++++++++++++++++++++++++++
>  lib/Makefile                   |   2 +-
>  lib/kobject.c                  |  22 ++++
>  lib/kobject_traces.c           |  32 +++++
>  4 files changed, 314 insertions(+), 1 deletion(-)
>  create mode 100644 include/trace/events/kobject.h
>  create mode 100644 lib/kobject_traces.c

I've strongly resisted tracepoints in the driver core, and kobjects,
because of the implicit "userspace API" guarantees that some people see
these as.  I notice that Al Viro just posted a proposal to the ksummit
mailing list to potentially talk about this very issue.

I'm really curious as to exactly what these tracepoints can buy us,
other than drowning in them as devices are added and removed from the
system?  Isn't this just too noisy for any real use?

And again, I worry about people relying on them, as we have changed the
internals of kobjects at times over the years, I don't want to have to
worry about somehow keeping these tracepoints "identical" for the next
40+ years.

thanks,

greg k-h

[toc] | [prev] | [next] | [standalone]

#1477801

On 09/06/2016 01:30 PM, Greg KH wrote:
> On Tue, Sep 06, 2016 at 11:49:22AM -0600, Shuah Khan wrote:
>> Add kobject trace points to track kobject operations: init, add, set_name,
>> init_and_add, create_and_add, move, rename, get, put, cleanup, and del.
>>
>> Kobject trace points can aid in debugging, generating status and graphs
>> on kobjects in the kernel and their hierarchy.
> 
> What type of "graphs"?  Isn't this just too noisy to ever find anything
> "real"?

Parent and child relationship between kobjects can be useful information
for debugging.

> 
>> This patch series adds kobject tracepoints and adds calls to tracepoints
>> from kobject init, add, set_name, init_and_add, create_and_add, move,
>> rename, get, put, cleanup, and del operations.
>>
>> A suggestion to provide more visibility into kboject lifetimes came out of
>> a discussion at my Embedded data structure lifetime talk at LinuxCon NA in
>> Toronto. As I thought about on how to provide visibility, I decided adding
>> traces provides a boot and run-time facility to trace kobject operations
>> without needing compile special kernels and also without impacting run-time
>> unless trace is enabled. Hence, this resulting patch series.
>>
>> Example traces:
>>
>> <...>-13632 [003] d... 11296.965114: kobject_get: KOBJECT: 1:0:0:0 (f
>> fff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 19
>>            <...>-13632 [003] d... 11296.965167: kobject_get: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 20
>>            <...>-13632 [003] d... 11296.965218: kobject_get: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 21
>>            <...>-13632 [003] d... 11296.965269: kobject_get: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 22
>>           <idle>-0     [006] ..s. 11296.965378: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 21
>>           <idle>-0     [006] .Ns. 11296.965542: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 20
>>      ksoftirqd/6-46    [006] ..s. 11296.965633: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 19
>>      ksoftirqd/6-46    [006] ..s. 11296.965703: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 18
>>
>> Shuah Khan (3):
>>   kobject: add kobject trace points
>>   kobject: add kobject trace prototypes
>>   kobject: Add calls to kobject trace points
>>
>>  include/trace/events/kobject.h | 259 +++++++++++++++++++++++++++++++++++++++++
>>  lib/Makefile                   |   2 +-
>>  lib/kobject.c                  |  22 ++++
>>  lib/kobject_traces.c           |  32 +++++
>>  4 files changed, 314 insertions(+), 1 deletion(-)
>>  create mode 100644 include/trace/events/kobject.h
>>  create mode 100644 lib/kobject_traces.c
> 
> I've strongly resisted tracepoints in the driver core, and kobjects,
> because of the implicit "userspace API" guarantees that some people see
> these as.  I notice that Al Viro just posted a proposal to the ksummit
> mailing list to potentially talk about this very issue.

Yes. I saw that discussion topic coming in. I honestly didn't think that
my patch series will result in a special KS topic :) However, I think it
is a good idea to discuss it as general topic for what kind of kernel
information should/should not be made visible via tracepoints.

We do support a wide range of tracepoints and events in various sub-systems
skb.h, pagemap.h, and pagemap.h so on. Maybe it would be helpful to agree
on some sort of guidelines for exposure.

> 
> I'm really curious as to exactly what these tracepoints can buy us,
> other than drowning in them as devices are added and removed from the
> system?  Isn't this just too noisy for any real use?

My main objective is for debugging lifetime related problems without
adding debug overhead. Being able to debug unbalanced gets and puts
for example. Yes this can get noisy for certain objects. 

> 
> And again, I worry about people relying on them, as we have changed the
> internals of kobjects at times over the years, I don't want to have to
> worry about somehow keeping these tracepoints "identical" for the next
> 40+ years.

Guess I never considered tracepoints as userspace API, anymore than debug
messages. It is part of debug and only visible to root.

In my mind it is mainly a debug information that would only make sense to
kernel developers. That is why I didn't think about needing to keep the
tracepoints identical. That said, if it is generally agreed that we shouldn't
expose this kind of information to userspace, I will look into doing this
in a different way.

thanks,
-- Shuah

[toc] | [prev] | [next] | [standalone]

#1477970

On Tue, Sep 06, 2016 at 02:19:17PM -0600, Shuah Khan wrote:
> On 09/06/2016 01:30 PM, Greg KH wrote:
> > On Tue, Sep 06, 2016 at 11:49:22AM -0600, Shuah Khan wrote:
> >> Add kobject trace points to track kobject operations: init, add, set_name,
> >> init_and_add, create_and_add, move, rename, get, put, cleanup, and del.
> >>
> >> Kobject trace points can aid in debugging, generating status and graphs
> >> on kobjects in the kernel and their hierarchy.
> > 
> > What type of "graphs"?  Isn't this just too noisy to ever find anything
> > "real"?
> 
> Parent and child relationship between kobjects can be useful information
> for debugging.

Sure, but those show up in sysfs already :)

> >> This patch series adds kobject tracepoints and adds calls to tracepoints
> >> from kobject init, add, set_name, init_and_add, create_and_add, move,
> >> rename, get, put, cleanup, and del operations.
> >>
> >> A suggestion to provide more visibility into kboject lifetimes came out of
> >> a discussion at my Embedded data structure lifetime talk at LinuxCon NA in
> >> Toronto. As I thought about on how to provide visibility, I decided adding
> >> traces provides a boot and run-time facility to trace kobject operations
> >> without needing compile special kernels and also without impacting run-time
> >> unless trace is enabled. Hence, this resulting patch series.
> >>
> >> Example traces:
> >>
> >> <...>-13632 [003] d... 11296.965114: kobject_get: KOBJECT: 1:0:0:0 (f
> >> fff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 19
> >>            <...>-13632 [003] d... 11296.965167: kobject_get: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 20
> >>            <...>-13632 [003] d... 11296.965218: kobject_get: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 21
> >>            <...>-13632 [003] d... 11296.965269: kobject_get: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 22
> >>           <idle>-0     [006] ..s. 11296.965378: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 21
> >>           <idle>-0     [006] .Ns. 11296.965542: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 20
> >>      ksoftirqd/6-46    [006] ..s. 11296.965633: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 19
> >>      ksoftirqd/6-46    [006] ..s. 11296.965703: kobject_put: KOBJECT: 1:0:0:0 (ffff88034aeb1348) state=1 parent= target1:0:0 (ffff88038c875db8) counter= 18
> >>
> >> Shuah Khan (3):
> >>   kobject: add kobject trace points
> >>   kobject: add kobject trace prototypes
> >>   kobject: Add calls to kobject trace points
> >>
> >>  include/trace/events/kobject.h | 259 +++++++++++++++++++++++++++++++++++++++++
> >>  lib/Makefile                   |   2 +-
> >>  lib/kobject.c                  |  22 ++++
> >>  lib/kobject_traces.c           |  32 +++++
> >>  4 files changed, 314 insertions(+), 1 deletion(-)
> >>  create mode 100644 include/trace/events/kobject.h
> >>  create mode 100644 lib/kobject_traces.c
> > 
> > I've strongly resisted tracepoints in the driver core, and kobjects,
> > because of the implicit "userspace API" guarantees that some people see
> > these as.  I notice that Al Viro just posted a proposal to the ksummit
> > mailing list to potentially talk about this very issue.
> 
> Yes. I saw that discussion topic coming in. I honestly didn't think that
> my patch series will result in a special KS topic :) However, I think it
> is a good idea to discuss it as general topic for what kind of kernel
> information should/should not be made visible via tracepoints.

Yes, your patchset just brought up the old topic again, it isn't
specific to these changes.

> We do support a wide range of tracepoints and events in various sub-systems
> skb.h, pagemap.h, and pagemap.h so on. Maybe it would be helpful to agree
> on some sort of guidelines for exposure.

I agree.  Until then I would like to hold off on these changes to
kobjects, or any other core bits I maintain.

> > I'm really curious as to exactly what these tracepoints can buy us,
> > other than drowning in them as devices are added and removed from the
> > system?  Isn't this just too noisy for any real use?
> 
> My main objective is for debugging lifetime related problems without
> adding debug overhead. Being able to debug unbalanced gets and puts
> for example. Yes this can get noisy for certain objects. 

You can always enable CONFIG_DEBUG_KOBJECT to see much of what you
wanted here, in the kernel log.  Not as "nice" as a tracepoint I know,
but it is there for debugging.

And almost no one should be worrying about the kobject level, that's
usually rare.  'struct device' lifetime rules are more common, but even
then, that's at the bus level so it too can be rare for developers to
care about once the bus code is up and running properly.

> > And again, I worry about people relying on them, as we have changed the
> > internals of kobjects at times over the years, I don't want to have to
> > worry about somehow keeping these tracepoints "identical" for the next
> > 40+ years.
> 
> Guess I never considered tracepoints as userspace API, anymore than debug
> messages. It is part of debug and only visible to root.

See the conversation on ksummit-discuss, they have been used as
userspace APIs in the past, and could not be changed because userspace
tools relied on them, and the field size/structures.  I don't want to
have that happen here as I saw all of the problems that occured then.

> In my mind it is mainly a debug information that would only make sense to
> kernel developers. That is why I didn't think about needing to keep the
> tracepoints identical. That said, if it is generally agreed that we shouldn't
> expose this kind of information to userspace, I will look into doing this
> in a different way.

CONFIG_DEBUG_KOBJECT?  :)

thanks,

greg k-h

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web