Skip to contentSkip to conversation

V3.10-rc1 memory leak

DISCUSSION Larry Finger 5 participants 18 messages May 13, 2013 – May 17, 2013 ACPI

lore
Share & tools
lore
#0 lore raw

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.

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.

Thanks,

Larry

#1 lore raw
Quoted 26 lines · Larry Finger

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
Quoted 2 lines

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

Quoted 3 lines

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.

#2 lore raw

Hi Steve,

Quoted 25 lines · Steven Rostedt
# 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 *);
};
Quoted 6 lines

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.

Signature · 1 line
Catalin
#3 lore raw
Quoted 7 lines · Catalin Marinas

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

Tested-by
#4 lore raw
Quoted 9 lines · Larry Finger
Quoted 7 lines · Catalin Marinas

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.

Quoted 7 lines

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:

-- Steve

#5 lore raw
Quoted 13 lines · Steven Rostedt
Quoted 12 lines · Larry Finger
Quoted 7 lines · Catalin Marinas

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. :)

Quoted 9 lines
Quoted 4 lines

Thanks to you and Jianpeng Ma,

Larry

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

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

#6 lore raw
Quoted 59 lines · Steven Rostedt
Quoted 13 lines · Steven Rostedt
Quoted 12 lines · Larry Finger
Quoted 7 lines · Catalin Marinas

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. :)

Quoted 9 lines
Quoted 4 lines

Thanks to you and Jianpeng Ma,

Larry

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

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)
Quoted 6 lines

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

#7 lore raw
Quoted 24 lines · Larry Finger

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
Quoted 2 lines

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:

drivers/acpi/scan.c +2 -1
index fe158fd..c1bc608 100644
@@ -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);
 }
 
#8 lore raw
Quoted 28 lines · Catalin Marinas
Quoted 24 lines · Larry Finger

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
Quoted 2 lines

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.

Quoted 6 lines

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.

Quoted 2 lines

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

Quoted 21 lines
drivers/acpi/scan.c +2 -1
index fe158fd..c1bc608 100644
@@ -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);
 }
 
#9 lore raw
Quoted 41 lines · Toshi Kani
Quoted 28 lines · Catalin Marinas
Quoted 24 lines · Larry Finger

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
Quoted 2 lines

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.

Quoted 6 lines

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.

Quoted 6 lines
Quoted 2 lines

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.

Signature · 1 line
Catalin
#10 lore raw
Quoted 45 lines · Catalin Marinas
Quoted 44 lines · Toshi Kani
Quoted 28 lines · Catalin Marinas
Quoted 24 lines · Larry Finger

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
Quoted 2 lines

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.

Quoted 6 lines

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.

Quoted 2 lines

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

Quoted 6 lines
Quoted 3 lines

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

#11 lore raw
In reply to Catalin Marinas
Quoted 51 lines · Catalin Marinas
Quoted 24 lines · Larry Finger

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
Quoted 2 lines

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:

drivers/acpi/scan.c +1 -1
index fe158fd..c1bc608 100644
@@ -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

drivers/acpi/scan.c static void acpi_scan_init_hotplug(acpi_handle handle, int type) · line 1805

Quoted 6 lines
drivers/acpi/scan.c +1 -0
@@ -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

#12 lore raw
In reply to Steven Rostedt
Quoted 44 lines · Steven Rostedt
Quoted 13 lines · Steven Rostedt
Quoted 12 lines · Larry Finger
Quoted 7 lines · Catalin Marinas

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. :)

Quoted 9 lines
Quoted 4 lines

Thanks to you and Jianpeng Ma,

Larry

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

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
Quoted 2 lines

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<----------------------------------

Quoted 1 line

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.

---
 kernel/module.c | 7 +++++++
 1 file changed, 7 insertions(+)
kernel/module.c +7 -0
index b049939..ff83711 100644
@@ -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",
#13 lore raw
Quoted 11 lines · Catalin Marinas
Quoted 1 line

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.

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.

kernel/module.c +5 -3
Index: 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,
#14 lore raw
Quoted 4 lines · Steven Rostedt

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.

kernel/module.c +0 -13
Index: 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 */
#15 lore raw
In reply to Steven Rostedt
Quoted 14 lines · Steven Rostedt
Quoted 11 lines · Catalin Marinas
Quoted 1 line

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.

Quoted 8 lines

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.

That's even better. I tested the two patches as well, added a subject and a bit of clean-up and pushed them to this branch:

git://git.kernel.org/pub/scm/linux/kernel/git/cmarinas/linux-aarch64.git kmemleak

Rusty, are you ok to take these or just ack and I'll push them to Linus.

Thanks.

Signature · 1 line
Catalin
Acked-by
#16 lore raw
Quoted 22 lines · Catalin Marinas
Quoted 21 lines · Steven Rostedt
Quoted 11 lines · Catalin Marinas
Quoted 1 line

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.

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.

Quoted 8 lines
Quoted 1 line

That's even better. I tested the two patches as well, added a subject and a bit of clean-up and pushed them to this branch:

git://git.kernel.org/pub/scm/linux/kernel/git/cmarinas/linux-aarch64.git kmemleak

Rusty, are you ok to take these or just ack and I'll push them to Linus.

Thanks. I've dropped the original "add .ref.data" patch.

For both patches:

Cheers,
Rusty.

#17 lore raw
In reply to Steven Rostedt
Quoted 115 lines · Steven Rostedt
Quoted 26 lines · Larry Finger

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
Quoted 2 lines

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

(quoted diff) +4 -4
@@ -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.

Quoted 13 lines

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

Quoted 3 lines

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