Return-Path: <linux-kernel-owner@vger.kernel.org>
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
	id S1758468Ab3ENUgd (ORCPT <rfc822;w@1wt.eu>);
	Tue, 14 May 2013 16:36:33 -0400
Received: from mail-ob0-f175.google.com ([209.85.214.175]:50517 "EHLO
	mail-ob0-f175.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
	with ESMTP id S1757884Ab3ENUgc (ORCPT
	<rfc822;linux-kernel@vger.kernel.org>);
	Tue, 14 May 2013 16:36:32 -0400
Message-ID: <5192A04D.8070701@lwfinger.net>
Date: Tue, 14 May 2013 15:36:29 -0500
From: Larry Finger <Larry.Finger@lwfinger.net>
User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:17.0) Gecko/20130329 Thunderbird/17.0.5
MIME-Version: 1.0
To: Steven Rostedt <rostedt@goodmis.org>
CC: "zhangwei(Jovi)" <jovi.zhangwei@huawei.com>,
        Steven Rostedt <srostedt@redhat.com>,
        Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>,
        LKML <linux-kernel@vger.kernel.org>,
        Catalin Marinas <catalin.marinas@arm.com>
Subject: Re: V3.10-rc1 memory leak
References: <51912567.6090507@lwfinger.net> <1368558586.6828.53.camel@gandalf.local.home>
In-Reply-To: <1368558586.6828.53.camel@gandalf.local.home>
Content-Type: text/plain; charset=UTF-8; format=flowed
Content-Transfer-Encoding: 7bit
Sender: linux-kernel-owner@vger.kernel.org
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org
Content-Length: 6500
Lines: 144

On 05/14/2013 02:09 PM, Steven Rostedt wrote:
> On Mon, 2013-05-13 at 15:06 -0400, Larry Finger wrote:
>> Using v3.10-rc1-68-g2d3ec09, I am getting many instances of the following from
>> kmemleak:
>>
>> unreferenced object 0xffff8800b546dc30 (size 48):
>>     comm "systemd-udevd", pid 2181, jiffies 4294899141 (age 274.096s)
>>     hex dump (first 32 bytes):
>>       00 dc 46 b5 00 88 ff ff d0 ff 5b a0 ff ff ff ff  ..F.......[.....
>>       1c 3b 5b a0 ff ff ff ff 12 3a 5b a0 ff ff ff ff  .;[......:[.....
>>     backtrace:
>>       [<ffffffff81432e81>] kmemleak_alloc+0x21/0x50
>>       [<ffffffff81143c2b>] kmem_cache_alloc+0x11b/0x270
>>       [<ffffffff810e9ee0>] __trace_define_field+0x40/0xd0
>>       [<ffffffff810e9fc5>] trace_define_field+0x55/0x70
>>       [<ffffffffa05e6ba0>] 0xffffffffa05e6ba0
>>       [<ffffffff810ea735>] event_create_dir+0x2e5/0x480
>>       [<ffffffff810ea920>] __trace_add_new_event+0x50/0x80
>>       [<ffffffff810eacf9>] __add_event_to_tracers+0x69/0xc0
>>       [<ffffffff810eb4e1>] trace_module_notify+0x1e1/0x2f0
>>       [<ffffffff8106e8f5>] notifier_call_chain+0x55/0x110
>>       [<ffffffff8106eb27>] __blocking_notifier_call_chain+0x67/0xc0
>>       [<ffffffff8106eb91>] blocking_notifier_call_chain+0x11/0x20
>>       [<ffffffff810af792>] load_module+0x19e2/0x24b0
>>       [<ffffffff810b0317>] SyS_init_module+0xb7/0xe0
>>       [<ffffffff814499d2>] system_call_fastpath+0x16/0x1b
>>       [<ffffffffffffffff>] 0xffffffffffffffff
>>
>> These appear to be real leaks, but I am not familiar with this section of the
>> code, and they could be false indications.
>
> They are false positives. Yesterday and today I've been looking at these
> trying to find where the leak is. I actually discovered a leak elsewhere
> that's been there for a while (and fixed it), but it had nothing to do
> with these.
>
> Finally, as I was suspecting that these were false positives, I broke
> down and added the following code:
>
> +++ b/kernel/trace/trace_events.c
> @@ -863,15 +863,15 @@ static int f_show(struct seq_file *m, void *v)
>                  array_descriptor = NULL;
>
>          if (!array_descriptor)
> -               seq_printf(m, "\tfield:%s %s;\toffset:%u;\tsize:%u;\tsigned:%d;
> +               seq_printf(m, "\tfield:%s %s;\toffset:%u;\tsize:%u;\tsigned:%d;
>                             field->type, field->name, field->offset,
> -                          field->size, !!field->is_signed);
> +                          field->size, !!field->is_signed, field);
>          else
> -               seq_printf(m, "\tfield:%.*s %s%s;\toffset:%u;\tsize:%u;\tsigned
> +               seq_printf(m, "\tfield:%.*s %s%s;\toffset:%u;\tsize:%u;\tsigned
>                             (int)(array_descriptor - field->type),
>                             field->type, field->name,
>                             array_descriptor, field->offset,
> -                          field->size, !!field->is_signed);
> +                          field->size, !!field->is_signed, field);
>
>
> Which adds the field pointer to the output of the fields in the format
> files. And sure enough, it proved to be a false positive:
>
> # cat /debug/kmemleak
> unreferenced object 0xffff8800769f7438 (size 48):
>    comm "modprobe", pid 881, jiffies 4294691017 (age 716.781s)
>    hex dump (first 32 bytes):
>      90 98 04 a0 ff ff ff ff 08 74 9f 76 00 88 ff ff  .........t.v....
>      b6 52 04 a0 ff ff ff ff ba 52 04 a0 ff ff ff ff  .R.......R......
>    backtrace:
>      [<ffffffff814b52ef>] kmemleak_alloc+0x73/0x98
>      [<ffffffff8111ffcc>] kmemleak_alloc_recursive.constprop.42+0x16/0x18
>      [<ffffffff8112092f>] kmem_cache_alloc+0xb9/0x142
>      [<ffffffff810d0e2e>] __trace_define_field+0x3c/0xbd
>      [<ffffffff810d0f0c>] trace_define_field+0x5d/0x5f
>      [<ffffffffa005a166>] 0xffffffffa005a166
>      [<ffffffff810d19dc>] event_create_dir+0x31c/0x381
>      [<ffffffff810d1ae3>] __add_event_to_tracers+0xa2/0xbd
>      [<ffffffff810d1cc6>] trace_module_notify+0x1c8/0x26f
>      [<ffffffff814d219d>] notifier_call_chain+0x37/0x63
>      [<ffffffff8105c29c>] __blocking_notifier_call_chain+0x4b/0x60
>      [<ffffffff8105c2c5>] blocking_notifier_call_chain+0x14/0x16
>      [<ffffffff8108fe59>] load_module+0x1d55/0x20a9
>      [<ffffffff81090286>] SyS_init_module+0xd9/0xdb
>      [<ffffffff814d5694>] tracesys+0xdd/0xe2
>      [<ffffffffffffffff>] 0xffffffffffffffff
> [...]
>
> # find /debug/tracing/events/ -name format |xargs grep ffff8800769f7438
> /debug/tracing/events/drm/drm_vblank_event_delivered/format:	field:pid_t pid;	offset:8;	size:4;	signed:1;ffff8800769f7438
>
> Thus, what it is complaining about being leaked, is currently being
> used.
>
> I guess it's because the fields are stored on the "event class"
> structure of the module. That is, the struct ftrace_event_class, which
> is part of the module data section:
>
> struct ftrace_event_class {
>          char                    *system;
>          void                    *probe;
> #ifdef CONFIG_PERF_EVENTS
>          void                    *perf_probe;
> #endif
>          int                     (*reg)(struct ftrace_event_call *event,
>                                         enum trace_reg type, void *data);
>          int                     (*define_fields)(struct ftrace_event_call *);
>          struct list_head        *(*get_fields)(struct ftrace_event_call *);
>          struct list_head        fields;
>          int                     (*raw_init)(struct ftrace_event_call *);
> };
>
>
> The list_head fields holds the fields and these are used to print out
> the formats. For some reason, kmemleak is missing that the fields are
> being assigned to this list on module load.
>
> Catalin, have any idea why kmemleak is not detecting that the field is
> being referenced?
>
> kernel/trace/trace_events.c: __trace_define_field()
>
>          list_add(&field->link, head);
>
> -- Steve
>
>
>>
>> This mail is sent to all authors of patches incorporated in
>> kernel/trace/trace_events.c in 2013. Kernel 3.9 did not show this problem.

Steve,

Thanks for checking on this. While you and Catalin work this out, I can always 
drop back to 3.9 to cut out the noise if I need to check one of my drivers for 
leaks,

Larry


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