LinuxLists.cc - V3.10-rc1 memory leak

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

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.

2013-05-14 20:35:47

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

Hi Steve,

On Tue, May 14, 2013 at 08:09:46PM +0100, Steven Rostedt wrote:
> # 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?

I just got a patch today:

https://lkml.org/lkml/2013/5/10/607

which could be related. If Rusty doesn't push it I'll do. But please let
me know if it does not solve the problem.

Thanks.

--
Catalin

2013-05-14 20:36:33

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

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

2013-05-14 21:10:35

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

On 05/14/2013 03:30 PM, Catalin Marinas wrote:
>
> I just got a patch today:
>
> https://lkml.org/lkml/2013/5/10/607
>
> which could be related. If Rusty doesn't push it I'll do. But please let
> me know if it does not solve the problem.

This patch fixes my problem. Now I can see the next new problem reported by
kmemleak. :)

Thanks to you and Jianpeng Ma,

Larry

2013-05-14 21:20:31

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

On Tue, 2013-05-14 at 16:10 -0500, Larry Finger wrote:
> On 05/14/2013 03:30 PM, Catalin Marinas wrote:
> >
> > I just got a patch today:
> >
> > https://lkml.org/lkml/2013/5/10/607
> >
> > which could be related. If Rusty doesn't push it I'll do. But please let
> > me know if it does not solve the problem.
>
> This patch fixes my problem. Now I can see the next new problem reported by
> kmemleak. :)
>
> Thanks to you and Jianpeng Ma,
>
> Larry
>

It goes away on my testing too. So you can add:

Tested-by: Steven Rostedt <[email protected]>

-- Steve

2013-05-15 00:57:09

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

On Tue, 2013-05-14 at 17:20 -0400, Steven Rostedt wrote:
> On Tue, 2013-05-14 at 16:10 -0500, Larry Finger wrote:
> > On 05/14/2013 03:30 PM, Catalin Marinas wrote:
> > >
> > > I just got a patch today:
> > >
> > > https://lkml.org/lkml/2013/5/10/607
> > >
> > > which could be related. If Rusty doesn't push it I'll do. But please let
> > > me know if it does not solve the problem.
> >
> > This patch fixes my problem. Now I can see the next new problem reported by
> > kmemleak. :)
> >
> > Thanks to you and Jianpeng Ma,
> >
> > Larry
> >
>
> It goes away on my testing too. So you can add:
>
> Tested-by: Steven Rostedt <[email protected]>
>

But we are not out of the woods yet. I'm also getting these:

unreferenced object 0xffff88007800efc0 (size 32):
comm "modprobe", pid 1309, jiffies 4294697214 (age 188.356s)
hex dump (first 32 bytes):
00 00 00 00 00 00 00 00 a8 d0 3e a0 ff ff ff ff ..........>.....
30 d1 3e a0 ff ff ff ff 00 00 00 00 00 00 00 00 0.>.............
backtrace:
[<ffffffff814b535f>] kmemleak_alloc+0x73/0x98
[<ffffffff8112003c>] kmemleak_alloc_recursive.constprop.42+0x16/0x18
[<ffffffff81120dfe>] kmem_cache_alloc_trace+0xc0/0x10b
[<ffffffff810e5478>] jump_label_module_notify+0xce/0x1d5
[<ffffffff814d221d>] notifier_call_chain+0x37/0x63
[<ffffffff8105c29c>] __blocking_notifier_call_chain+0x4b/0x60
[<ffffffff8105c2c5>] blocking_notifier_call_chain+0x14/0x16
[<ffffffff8108fe83>] load_module+0x1d7f/0x20d3
[<ffffffff810902b0>] SyS_init_module+0xd9/0xdb
[<ffffffff814d5754>] tracesys+0xdd/0xe2
[<ffffffffffffffff>] 0xffffffffffffffff

Where it points to the allocation in jump_label_add_module() where it
allocates the jlm. And this does get freed in jump_label_del_module(). I
put in printks in add_module():

printk("alloc %p (%s)\n", jlm, mod->name);

and in del_module:

printk("free %p (%s)\n", jlm, mod->name);

And got this:

[ 29.917577] alloc ffff88007800efc0 (kvm_intel)

And removing kvm_intel, I got:

[ 364.965916] free ffff88007800efc0 (kvm_intel)

Thus it seems to be yet another false positive :-(

-- Steve

2013-05-15 03:15:50

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

On 05/14/2013 07:57 PM, Steven Rostedt wrote:
> On Tue, 2013-05-14 at 17:20 -0400, Steven Rostedt wrote:
>> On Tue, 2013-05-14 at 16:10 -0500, Larry Finger wrote:
>>> On 05/14/2013 03:30 PM, Catalin Marinas wrote:
>>>>
>>>> I just got a patch today:
>>>>
>>>> https://lkml.org/lkml/2013/5/10/607
>>>>
>>>> which could be related. If Rusty doesn't push it I'll do. But please let
>>>> me know if it does not solve the problem.
>>>
>>> This patch fixes my problem. Now I can see the next new problem reported by
>>> kmemleak. :)
>>>
>>> Thanks to you and Jianpeng Ma,
>>>
>>> Larry
>>>
>>
>> It goes away on my testing too. So you can add:
>>
>> Tested-by: Steven Rostedt <[email protected]>
>>
>
> But we are not out of the woods yet. I'm also getting these:
>
> unreferenced object 0xffff88007800efc0 (size 32):
> comm "modprobe", pid 1309, jiffies 4294697214 (age 188.356s)
> hex dump (first 32 bytes):
> 00 00 00 00 00 00 00 00 a8 d0 3e a0 ff ff ff ff ..........>.....
> 30 d1 3e a0 ff ff ff ff 00 00 00 00 00 00 00 00 0.>.............
> backtrace:
> [<ffffffff814b535f>] kmemleak_alloc+0x73/0x98
> [<ffffffff8112003c>] kmemleak_alloc_recursive.constprop.42+0x16/0x18
> [<ffffffff81120dfe>] kmem_cache_alloc_trace+0xc0/0x10b
> [<ffffffff810e5478>] jump_label_module_notify+0xce/0x1d5
> [<ffffffff814d221d>] notifier_call_chain+0x37/0x63
> [<ffffffff8105c29c>] __blocking_notifier_call_chain+0x4b/0x60
> [<ffffffff8105c2c5>] blocking_notifier_call_chain+0x14/0x16
> [<ffffffff8108fe83>] load_module+0x1d7f/0x20d3
> [<ffffffff810902b0>] SyS_init_module+0xd9/0xdb
> [<ffffffff814d5754>] tracesys+0xdd/0xe2
> [<ffffffffffffffff>] 0xffffffffffffffff
>
> Where it points to the allocation in jump_label_add_module() where it
> allocates the jlm. And this does get freed in jump_label_del_module(). I
> put in printks in add_module():
>
> printk("alloc %p (%s)\n", jlm, mod->name);
>
> and in del_module:
>
> printk("free %p (%s)\n", jlm, mod->name);
>
> And got this:
>
> [ 29.917577] alloc ffff88007800efc0 (kvm_intel)
>
>
> And removing kvm_intel, I got:
>
> [ 364.965916] free ffff88007800efc0 (kvm_intel)
>
>
> Thus it seems to be yet another false positive :-(

I do not see that particular one; however, I see 4 instances of

unreferenced object 0xffff8800b7979750 (size 8):
comm "swapper/0", pid 1, jiffies 4294892402 (age 21888.316s)
hex dump (first 8 bytes):
31 38 00 b7 00 88 ff ff 18......
backtrace:
[<ffffffff81432ea1>] kmemleak_alloc+0x21/0x50
[<ffffffff81145d50>] __kmalloc_track_caller+0x140/0x2b0
[<ffffffff81119fb5>] kstrdup+0x35/0x70
[<ffffffff8125febc>] acpi_set_pnp_ids+0xd0/0x304
[<ffffffff81260c47>] acpi_scan_init_hotplug+0x47/0xa1
[<ffffffff81261223>] acpi_bus_check_add+0x66/0xd7
[<ffffffff8127877a>] acpi_ns_walk_namespace+0xb9/0x173
[<ffffffff81278bf3>] acpi_walk_namespace+0x93/0xc6
[<ffffffff812612dc>] acpi_bus_scan+0x48/0x9a
[<ffffffff818c983d>] acpi_scan_init+0x57/0x14b
[<ffffffff818c966a>] acpi_init+0x244/0x286
[<ffffffff810002fa>] do_one_initcall+0x10a/0x160
[<ffffffff8189cef0>] kernel_init_freeable+0x103/0x192
[<ffffffff814313a9>] kernel_init+0x9/0xf0
[<ffffffff8144992c>] ret_from_fork+0x7c/0xb0
[<ffffffffffffffff>] 0xffffffffffffffff

All four were allocated early in the bootup, and are the only leaks reported in
my system. I have not yet tested to see if they are false.

Larry

2013-05-15 14:42:29

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

On Wed, May 15, 2013 at 01:57:03AM +0100, Steven Rostedt wrote:
> On Tue, 2013-05-14 at 17:20 -0400, Steven Rostedt wrote:
> > On Tue, 2013-05-14 at 16:10 -0500, Larry Finger wrote:
> > > On 05/14/2013 03:30 PM, Catalin Marinas wrote:
> > > >
> > > > I just got a patch today:
> > > >
> > > > https://lkml.org/lkml/2013/5/10/607
> > > >
> > > > which could be related. If Rusty doesn't push it I'll do. But please let
> > > > me know if it does not solve the problem.
> > >
> > > This patch fixes my problem. Now I can see the next new problem reported by
> > > kmemleak. :)
> > >
> > > Thanks to you and Jianpeng Ma,
> > >
> > > Larry
> > >
> >
> > It goes away on my testing too. So you can add:
> >
> > Tested-by: Steven Rostedt <[email protected]>
> >
>
> But we are not out of the woods yet. I'm also getting these:
>
> unreferenced object 0xffff88007800efc0 (size 32):
> comm "modprobe", pid 1309, jiffies 4294697214 (age 188.356s)
> hex dump (first 32 bytes):
> 00 00 00 00 00 00 00 00 a8 d0 3e a0 ff ff ff ff ..........>.....
> 30 d1 3e a0 ff ff ff ff 00 00 00 00 00 00 00 00 0.>.............
> backtrace:
> [<ffffffff814b535f>] kmemleak_alloc+0x73/0x98
> [<ffffffff8112003c>] kmemleak_alloc_recursive.constprop.42+0x16/0x18
> [<ffffffff81120dfe>] kmem_cache_alloc_trace+0xc0/0x10b
> [<ffffffff810e5478>] jump_label_module_notify+0xce/0x1d5
> [<ffffffff814d221d>] notifier_call_chain+0x37/0x63
> [<ffffffff8105c29c>] __blocking_notifier_call_chain+0x4b/0x60
> [<ffffffff8105c2c5>] blocking_notifier_call_chain+0x14/0x16
> [<ffffffff8108fe83>] load_module+0x1d7f/0x20d3
> [<ffffffff810902b0>] SyS_init_module+0xd9/0xdb
> [<ffffffff814d5754>] tracesys+0xdd/0xe2
> [<ffffffffffffffff>] 0xffffffffffffffff
>
> Where it points to the allocation in jump_label_add_module() where it
> allocates the jlm. And this does get freed in jump_label_del_module().

Indeed, another false positive (I should use modules more often ;).
Here's a patch:

---------------------8<----------------------------------

>From 0621c7e1909ea86bf8499a0ffe5ea59d1007ee8c Mon Sep 17 00:00:00 2001
From: Catalin Marinas <[email protected]>
Date: Wed, 15 May 2013 15:30:46 +0100
Subject: [PATCH] kmemleak: Scan the jump label module section

Objects allocated in jump_label_add_module() are currently reported as
leaks, though the pointers are stored in the module jump label section.
This patch informs kmemleak that this section needs to be scanned.

Signed-off-by: Catalin Marinas <[email protected]>
Reported-by: Steven Rostedt <[email protected]>
---
kernel/module.c | 7 +++++++
1 file changed, 7 insertions(+)

diff --git a/kernel/module.c b/kernel/module.c
index b049939..ff83711 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -2764,6 +2764,13 @@ static void find_module_sections(struct module *mod, struct load_info *info)
mod->jump_entries = section_objs(info, "__jump_table",
sizeof(*mod->jump_entries),
&mod->num_jump_entries);
+ /*
+ * This section contains pointers to objects allocated in
+ * jump_label_add_module() and not scanning it leads to false
+ * positives.
+ */
+ kmemleak_scan_area(mod->jump_entries, sizeof(*mod->jump_entries) *
+ mod->num_jump_entries, GFP_KERNEL);
#endif
#ifdef CONFIG_EVENT_TRACING
mod->trace_events = section_objs(info, "_ftrace_events",

2013-05-15 15:03:28

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

On Wed, May 15, 2013 at 04:15:46AM +0100, Larry Finger wrote:
> I do not see that particular one; however, I see 4 instances of
>
> unreferenced object 0xffff8800b7979750 (size 8):
> comm "swapper/0", pid 1, jiffies 4294892402 (age 21888.316s)
> hex dump (first 8 bytes):
> 31 38 00 b7 00 88 ff ff 18......
> backtrace:
> [<ffffffff81432ea1>] kmemleak_alloc+0x21/0x50
> [<ffffffff81145d50>] __kmalloc_track_caller+0x140/0x2b0
> [<ffffffff81119fb5>] kstrdup+0x35/0x70
> [<ffffffff8125febc>] acpi_set_pnp_ids+0xd0/0x304
> [<ffffffff81260c47>] acpi_scan_init_hotplug+0x47/0xa1
> [<ffffffff81261223>] acpi_bus_check_add+0x66/0xd7
> [<ffffffff8127877a>] acpi_ns_walk_namespace+0xb9/0x173
> [<ffffffff81278bf3>] acpi_walk_namespace+0x93/0xc6
> [<ffffffff812612dc>] acpi_bus_scan+0x48/0x9a
> [<ffffffff818c983d>] acpi_scan_init+0x57/0x14b
> [<ffffffff818c966a>] acpi_init+0x244/0x286
> [<ffffffff810002fa>] do_one_initcall+0x10a/0x160
> [<ffffffff8189cef0>] kernel_init_freeable+0x103/0x192
> [<ffffffff814313a9>] kernel_init+0x9/0xf0
> [<ffffffff8144992c>] ret_from_fork+0x7c/0xb0
> [<ffffffffffffffff>] 0xffffffffffffffff
>
> All four were allocated early in the bootup, and are the only leaks reported in
> my system. I have not yet tested to see if they are false.

This looks to me like a real leak, possibly introduced by commit
6b772e8f9 (ACPI: Update PNPID match handling for notify). The
acpi_scan_init_hotplug() function calls acpi_set_pnp_ids() which
allocates pnp.unique_id (kstrdup()) but for some reason it fails and
does not set pnp.type.hardware_id. The return does not call
acpi_free_pnp_ids() which would be responsible for such freeing.
Something like below, but not tested and may fail some NULL pointer
checks:

diff --git a/drivers/acpi/scan.c b/drivers/acpi/scan.c
index fe158fd..c1bc608 100644
--- a/drivers/acpi/scan.c
+++ b/drivers/acpi/scan.c
@@ -1785,7 +1785,7 @@ static void acpi_scan_init_hotplug(acpi_handle handle, int type)
acpi_set_pnp_ids(handle, &pnp, type);

if (!pnp.type.hardware_id)
- return;
+ goto out;

/*
* This relies on the fact that acpi_install_notify_handler() will not
@@ -1800,6 +1800,7 @@ static void acpi_scan_init_hotplug(acpi_handle handle, int type)
}
}

+out:
acpi_free_pnp_ids(&pnp);
}

2013-05-15 15:49:57

by Toshi Kani

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

On Wed, 2013-05-15 at 16:02 +0100, Catalin Marinas wrote:
> On Wed, May 15, 2013 at 04:15:46AM +0100, Larry Finger wrote:
> > I do not see that particular one; however, I see 4 instances of
> >
> > unreferenced object 0xffff8800b7979750 (size 8):
> > comm "swapper/0", pid 1, jiffies 4294892402 (age 21888.316s)
> > hex dump (first 8 bytes):
> > 31 38 00 b7 00 88 ff ff 18......
> > backtrace:
> > [<ffffffff81432ea1>] kmemleak_alloc+0x21/0x50
> > [<ffffffff81145d50>] __kmalloc_track_caller+0x140/0x2b0
> > [<ffffffff81119fb5>] kstrdup+0x35/0x70
> > [<ffffffff8125febc>] acpi_set_pnp_ids+0xd0/0x304
> > [<ffffffff81260c47>] acpi_scan_init_hotplug+0x47/0xa1
> > [<ffffffff81261223>] acpi_bus_check_add+0x66/0xd7
> > [<ffffffff8127877a>] acpi_ns_walk_namespace+0xb9/0x173
> > [<ffffffff81278bf3>] acpi_walk_namespace+0x93/0xc6
> > [<ffffffff812612dc>] acpi_bus_scan+0x48/0x9a
> > [<ffffffff818c983d>] acpi_scan_init+0x57/0x14b
> > [<ffffffff818c966a>] acpi_init+0x244/0x286
> > [<ffffffff810002fa>] do_one_initcall+0x10a/0x160
> > [<ffffffff8189cef0>] kernel_init_freeable+0x103/0x192
> > [<ffffffff814313a9>] kernel_init+0x9/0xf0
> > [<ffffffff8144992c>] ret_from_fork+0x7c/0xb0
> > [<ffffffffffffffff>] 0xffffffffffffffff
> >
> > All four were allocated early in the bootup, and are the only leaks reported in
> > my system. I have not yet tested to see if they are false.
>
> This looks to me like a real leak, possibly introduced by commit
> 6b772e8f9 (ACPI: Update PNPID match handling for notify). The
> acpi_scan_init_hotplug() function calls acpi_set_pnp_ids() which
> allocates pnp.unique_id (kstrdup()) but for some reason it fails and
> does not set pnp.type.hardware_id. The return does not call
> acpi_free_pnp_ids() which would be responsible for such freeing.

I agree with your analysis. It appears that this ACPI device object has
_UID but not _HID. ACPI spec defines that _UID is a unique ID among a
same _HID. So, it is odd to have _UID without _HID. But, nonetheless,
this case needs to be handled as such systems exist.

> Something like below, but not tested and may fail some NULL pointer
> checks:

The change looks good. acpi_free_pnp_ids() handles this empty list
pnp->ids properly. Are you going to submit this patch with your
signed-off?

Thanks!
-Toshi

> diff --git a/drivers/acpi/scan.c b/drivers/acpi/scan.c
> index fe158fd..c1bc608 100644
> --- a/drivers/acpi/scan.c
> +++ b/drivers/acpi/scan.c
> @@ -1785,7 +1785,7 @@ static void acpi_scan_init_hotplug(acpi_handle handle, int type)
> acpi_set_pnp_ids(handle, &pnp, type);
>
> if (!pnp.type.hardware_id)
> - return;
> + goto out;
>
> /*
> * This relies on the fact that acpi_install_notify_handler() will not
> @@ -1800,6 +1800,7 @@ static void acpi_scan_init_hotplug(acpi_handle handle, int type)
> }
> }
>
> +out:
> acpi_free_pnp_ids(&pnp);
> }
>

2013-05-15 16:53:20

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

On Wed, May 15, 2013 at 04:49:50PM +0100, Toshi Kani wrote:
> On Wed, 2013-05-15 at 16:02 +0100, Catalin Marinas wrote:
> > On Wed, May 15, 2013 at 04:15:46AM +0100, Larry Finger wrote:
> > > I do not see that particular one; however, I see 4 instances of
> > >
> > > unreferenced object 0xffff8800b7979750 (size 8):
> > > comm "swapper/0", pid 1, jiffies 4294892402 (age 21888.316s)
> > > hex dump (first 8 bytes):
> > > 31 38 00 b7 00 88 ff ff 18......
> > > backtrace:
> > > [<ffffffff81432ea1>] kmemleak_alloc+0x21/0x50
> > > [<ffffffff81145d50>] __kmalloc_track_caller+0x140/0x2b0
> > > [<ffffffff81119fb5>] kstrdup+0x35/0x70
> > > [<ffffffff8125febc>] acpi_set_pnp_ids+0xd0/0x304
> > > [<ffffffff81260c47>] acpi_scan_init_hotplug+0x47/0xa1
> > > [<ffffffff81261223>] acpi_bus_check_add+0x66/0xd7
> > > [<ffffffff8127877a>] acpi_ns_walk_namespace+0xb9/0x173
> > > [<ffffffff81278bf3>] acpi_walk_namespace+0x93/0xc6
> > > [<ffffffff812612dc>] acpi_bus_scan+0x48/0x9a
> > > [<ffffffff818c983d>] acpi_scan_init+0x57/0x14b
> > > [<ffffffff818c966a>] acpi_init+0x244/0x286
> > > [<ffffffff810002fa>] do_one_initcall+0x10a/0x160
> > > [<ffffffff8189cef0>] kernel_init_freeable+0x103/0x192
> > > [<ffffffff814313a9>] kernel_init+0x9/0xf0
> > > [<ffffffff8144992c>] ret_from_fork+0x7c/0xb0
> > > [<ffffffffffffffff>] 0xffffffffffffffff
> > >
> > > All four were allocated early in the bootup, and are the only leaks reported in
> > > my system. I have not yet tested to see if they are false.
> >
> > This looks to me like a real leak, possibly introduced by commit
> > 6b772e8f9 (ACPI: Update PNPID match handling for notify). The
> > acpi_scan_init_hotplug() function calls acpi_set_pnp_ids() which
> > allocates pnp.unique_id (kstrdup()) but for some reason it fails and
> > does not set pnp.type.hardware_id. The return does not call
> > acpi_free_pnp_ids() which would be responsible for such freeing.
>
> I agree with your analysis. It appears that this ACPI device object has
> _UID but not _HID. ACPI spec defines that _UID is a unique ID among a
> same _HID. So, it is odd to have _UID without _HID. But, nonetheless,
> this case needs to be handled as such systems exist.
>
> > Something like below, but not tested and may fail some NULL pointer
> > checks:
>
> The change looks good. acpi_free_pnp_ids() handles this empty list
> pnp->ids properly. Are you going to submit this patch with your
> signed-off?

Yes, I'll post it shortly. But I'd like an acked/tested-by as I don't
have a platform to test it.

Thanks.

--
Catalin

2013-05-15 17:53:23

by Toshi Kani

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

On Wed, 2013-05-15 at 17:47 +0100, Catalin Marinas wrote:
> On Wed, May 15, 2013 at 04:49:50PM +0100, Toshi Kani wrote:
> > On Wed, 2013-05-15 at 16:02 +0100, Catalin Marinas wrote:
> > > On Wed, May 15, 2013 at 04:15:46AM +0100, Larry Finger wrote:
> > > > I do not see that particular one; however, I see 4 instances of
> > > >
> > > > unreferenced object 0xffff8800b7979750 (size 8):
> > > > comm "swapper/0", pid 1, jiffies 4294892402 (age 21888.316s)
> > > > hex dump (first 8 bytes):
> > > > 31 38 00 b7 00 88 ff ff 18......
> > > > backtrace:
> > > > [<ffffffff81432ea1>] kmemleak_alloc+0x21/0x50
> > > > [<ffffffff81145d50>] __kmalloc_track_caller+0x140/0x2b0
> > > > [<ffffffff81119fb5>] kstrdup+0x35/0x70
> > > > [<ffffffff8125febc>] acpi_set_pnp_ids+0xd0/0x304
> > > > [<ffffffff81260c47>] acpi_scan_init_hotplug+0x47/0xa1
> > > > [<ffffffff81261223>] acpi_bus_check_add+0x66/0xd7
> > > > [<ffffffff8127877a>] acpi_ns_walk_namespace+0xb9/0x173
> > > > [<ffffffff81278bf3>] acpi_walk_namespace+0x93/0xc6
> > > > [<ffffffff812612dc>] acpi_bus_scan+0x48/0x9a
> > > > [<ffffffff818c983d>] acpi_scan_init+0x57/0x14b
> > > > [<ffffffff818c966a>] acpi_init+0x244/0x286
> > > > [<ffffffff810002fa>] do_one_initcall+0x10a/0x160
> > > > [<ffffffff8189cef0>] kernel_init_freeable+0x103/0x192
> > > > [<ffffffff814313a9>] kernel_init+0x9/0xf0
> > > > [<ffffffff8144992c>] ret_from_fork+0x7c/0xb0
> > > > [<ffffffffffffffff>] 0xffffffffffffffff
> > > >
> > > > All four were allocated early in the bootup, and are the only leaks reported in
> > > > my system. I have not yet tested to see if they are false.
> > >
> > > This looks to me like a real leak, possibly introduced by commit
> > > 6b772e8f9 (ACPI: Update PNPID match handling for notify). The
> > > acpi_scan_init_hotplug() function calls acpi_set_pnp_ids() which
> > > allocates pnp.unique_id (kstrdup()) but for some reason it fails and
> > > does not set pnp.type.hardware_id. The return does not call
> > > acpi_free_pnp_ids() which would be responsible for such freeing.
> >
> > I agree with your analysis. It appears that this ACPI device object has
> > _UID but not _HID. ACPI spec defines that _UID is a unique ID among a
> > same _HID. So, it is odd to have _UID without _HID. But, nonetheless,
> > this case needs to be handled as such systems exist.
> >
> > > Something like below, but not tested and may fail some NULL pointer
> > > checks:
> >
> > The change looks good. acpi_free_pnp_ids() handles this empty list
> > pnp->ids properly. Are you going to submit this patch with your
> > signed-off?
>
> Yes, I'll post it shortly. But I'd like an acked/tested-by as I don't
> have a platform to test it.

I was able to reproduce this issue by adding a fake ACPI device object
with _UID only. I will test your change as well.

Thanks,
-Toshi

2013-05-15 19:33:06

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

On Wed, 2013-05-15 at 15:37 +0100, Catalin Marinas wrote:

> >From 0621c7e1909ea86bf8499a0ffe5ea59d1007ee8c Mon Sep 17 00:00:00 2001
> From: Catalin Marinas <[email protected]>
> Date: Wed, 15 May 2013 15:30:46 +0100
> Subject: [PATCH] kmemleak: Scan the jump label module section
>
> Objects allocated in jump_label_add_module() are currently reported as
> leaks, though the pointers are stored in the module jump label section.
> This patch informs kmemleak that this section needs to be scanned.
>
> Signed-off-by: Catalin Marinas <[email protected]>
> Reported-by: Steven Rostedt <[email protected]>

This didn't work. I still get the leak messages. But this change did:

Instead of just picking data sections by name (names that start
with .data, .bss or .ref.data), use the section flags and scan all
sections that are allocated, writable and not executable. Which should
cover all sections of a module that might reference data.

Signed-off-by: Steven Rostedt <[email protected]>

Index: linux-trace.git/kernel/module.c
===================================================================
--- linux-trace.git.orig/kernel/module.c
+++ linux-trace.git/kernel/module.c
@@ -2432,10 +2432,12 @@ static void kmemleak_load_module(const s

for (i = 1; i < info->hdr->e_shnum; i++) {
const char *name = info->secstrings + info->sechdrs[i].sh_name;
- if (!(info->sechdrs[i].sh_flags & SHF_ALLOC))
+
+ /* Scan all writable sections that's not executable */
+ if (!(info->sechdrs[i].sh_flags & SHF_ALLOC) ||
+ !(info->sechdrs[i].sh_flags & SHF_WRITE))
continue;
- if (!strstarts(name, ".data") && !strstarts(name, ".bss") &&
- !strstarts(name, ".ref.data"))
+ if (info->sechdrs[i].sh_flags & SHF_EXECINSTR)
continue;

kmemleak_scan_area((void *)info->sechdrs[i].sh_addr,

2013-05-15 19:46:27

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

On Wed, 2013-05-15 at 15:33 -0400, Steven Rostedt wrote:

> Instead of just picking data sections by name (names that start
> with .data, .bss or .ref.data), use the section flags and scan all
> sections that are allocated, writable and not executable. Which should
> cover all sections of a module that might reference data.

After this patch is applied, you can add this one too:

kmemleak: No need for scanning specific module sections

As kmemleak now scans all module sections that are allocated, writable
and non executable, there's no need to scan individual sections that
might reference data.

Signed-off-by: Steven Rostedt <[email protected]>

Index: linux-trace.git/kernel/module.c
===================================================================
--- linux-trace.git.orig/kernel/module.c
+++ linux-trace.git/kernel/module.c
@@ -2772,24 +2772,11 @@ static void find_module_sections(struct
mod->trace_events = section_objs(info, "_ftrace_events",
sizeof(*mod->trace_events),
&mod->num_trace_events);
- /*
- * This section contains pointers to allocated objects in the trace
- * code and not scanning it leads to false positives.
- */
- kmemleak_scan_area(mod->trace_events, sizeof(*mod->trace_events) *
- mod->num_trace_events, GFP_KERNEL);
#endif
#ifdef CONFIG_TRACING
mod->trace_bprintk_fmt_start = section_objs(info, "__trace_printk_fmt",
sizeof(*mod->trace_bprintk_fmt_start),
&mod->num_trace_bprintk_fmt);
- /*
- * This section contains pointers to allocated objects in the trace
- * code and not scanning it leads to false positives.
- */
- kmemleak_scan_area(mod->trace_bprintk_fmt_start,
- sizeof(*mod->trace_bprintk_fmt_start) *
- mod->num_trace_bprintk_fmt, GFP_KERNEL);
#endif
#ifdef CONFIG_FTRACE_MCOUNT_RECORD
/* sechdrs[0].sh_size is always zero */

2013-05-15 20:46:43

[permalink] [raw]

Subject: Re: V3.10-rc1 memory leak

On 05/15/2013 10:02 AM, Catalin Marinas wrote:
> On Wed, May 15, 2013 at 04:15:46AM +0100, Larry Finger wrote:
>> I do not see that particular one; however, I see 4 instances of
>>
>> unreferenced object 0xffff8800b7979750 (size 8):
>> comm "swapper/0", pid 1, jiffies 4294892402 (age 21888.316s)
>> hex dump (first 8 bytes):
>> 31 38 00 b7 00 88 ff ff 18......
>> backtrace:
>> [<ffffffff81432ea1>] kmemleak_alloc+0x21/0x50
>> [<ffffffff81145d50>] __kmalloc_track_caller+0x140/0x2b0
>> [<ffffffff81119fb5>] kstrdup+0x35/0x70
>> [<ffffffff8125febc>] acpi_set_pnp_ids+0xd0/0x304
>> [<ffffffff81260c47>] acpi_scan_init_hotplug+0x47/0xa1
>> [<ffffffff81261223>] acpi_bus_check_add+0x66/0xd7
>> [<ffffffff8127877a>] acpi_ns_walk_namespace+0xb9/0x173
>> [<ffffffff81278bf3>] acpi_walk_namespace+0x93/0xc6
>> [<ffffffff812612dc>] acpi_bus_scan+0x48/0x9a
>> [<ffffffff818c983d>] acpi_scan_init+0x57/0x14b
>> [<ffffffff818c966a>] acpi_init+0x244/0x286
>> [<ffffffff810002fa>] do_one_initcall+0x10a/0x160
>> [<ffffffff8189cef0>] kernel_init_freeable+0x103/0x192
>> [<ffffffff814313a9>] kernel_init+0x9/0xf0
>> [<ffffffff8144992c>] ret_from_fork+0x7c/0xb0
>> [<ffffffffffffffff>] 0xffffffffffffffff
>>
>> All four were allocated early in the bootup, and are the only leaks reported in
>> my system. I have not yet tested to see if they are false.
>
> This looks to me like a real leak, possibly introduced by commit
> 6b772e8f9 (ACPI: Update PNPID match handling for notify). The
> acpi_scan_init_hotplug() function calls acpi_set_pnp_ids() which
> allocates pnp.unique_id (kstrdup()) but for some reason it fails and
> does not set pnp.type.hardware_id. The return does not call
> acpi_free_pnp_ids() which would be responsible for such freeing.
> Something like below, but not tested and may fail some NULL pointer
> checks:
>
> diff --git a/drivers/acpi/scan.c b/drivers/acpi/scan.c
> index fe158fd..c1bc608 100644
> --- a/drivers/acpi/scan.c
> +++ b/drivers/acpi/scan.c
> @@ -1785,7 +1785,7 @@ static void acpi_scan_init_hotplug(acpi_handle handle, int type)
> acpi_set_pnp_ids(handle, &pnp, type);
>
> if (!pnp.type.hardware_id)
> - return;
> + goto out;
>
> /*
> * This relies on the fact that acpi_install_notify_handler() will not
> @@ -1800,6 +1800,7 @@ static void acpi_scan_init_hotplug(acpi_handle handle, int type)
> }
> }
>
> +out:
> acpi_free_pnp_ids(&pnp);
> }

This patch fixes the memory leaks on my system. My kmemleak scans are now clean
again. You may add a "Tested-by: Larry Finger <[email protected]>".

Thanks,

Larry

2013-05-16 10:13:45