Re: [PATCH 0/3] kobject tracepoints

[Shuah Khan]

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