Leaks in trace reported by kmemleak

Leaks in trace reported by kmemleak

[Zdenek Kabelac]

I've noticed your latest patch for memory leak in filter setting
(8ad807318fcd...) - but even with this patch - kmemleak seems to still
report  lots  (~900) of following leaks - note - they come only from
i915 and kvm module - so I'm not sure if these two modules are doing
something wrong or the problem is in trace code.

It looks like whole directory is somehow forgotten.

nreferenced object 0xffff880134b21268 (size 8):
  comm "modprobe", pid 1099, jiffies 4294881626
  hex dump (first 8 bytes):
    69 6e 74 00 01 88 ff ff                          int.....
  backtrace:
    [<ffffffff8140e986>] kmemleak_alloc+0x26/0x60
    [<ffffffff81127943>] __kmalloc_track_caller+0x143/0x230
    [<ffffffff81104385>] kstrdup+0x45/0x80
    [<ffffffff810dd5c9>] trace_define_field+0x89/0x1b0
    [<ffffffff810dd7bc>] trace_define_common_fields+0xcc/0x110
    [<ffffffffa0370426>]
ftrace_define_fields_i915_ring_wait_end+0x16/0x50 [i915]
    [<ffffffff810dcc53>] event_create_dir+0x93/0x480
    [<ffffffff810dd13f>] trace_module_notify+0xff/0x500
    [<ffffffff814247e8>] notifier_call_chain+0x78/0xb0
    [<ffffffff8107f190>] __blocking_notifier_call_chain+0x60/0x90
    [<ffffffff8107f1d6>] blocking_notifier_call_chain+0x16/0x20
    [<ffffffff810a0bfa>] sys_init_module+0xaa/0x260
    [<ffffffff8100c11b>] system_call_fastpath+0x16/0x1b
    [<ffffffffffffffff>] 0xffffffffffffffff

...

unreferenced object 0xffff880134b21a78 (size 8):
  comm "modprobe", pid 1106, jiffies 4294881716
  hex dump (first 8 bytes):
    5f 5f 75 33 32 00 ff ff                          __u32...
  backtrace:
    [<ffffffff8140e986>] kmemleak_alloc+0x26/0x60
    [<ffffffff81127943>] __kmalloc_track_caller+0x143/0x230
    [<ffffffff81104385>] kstrdup+0x45/0x80
    [<ffffffff810dd5c9>] trace_define_field+0x89/0x1b0
    [<ffffffffa03cf802>]
ftrace_define_fields_kvm_mmu_pagetable_walk+0x82/0x90 [kvm]
    [<ffffffff810dcc53>] event_create_dir+0x93/0x480
    [<ffffffff810dd13f>] trace_module_notify+0xff/0x500
    [<ffffffff814247e8>] notifier_call_chain+0x78/0xb0
    [<ffffffff8107f190>] __blocking_notifier_call_chain+0x60/0x90
    [<ffffffff8107f1d6>] blocking_notifier_call_chain+0x16/0x20
    [<ffffffff810a0bfa>] sys_init_module+0xaa/0x260
    [<ffffffff8100c11b>] system_call_fastpath+0x16/0x1b
    [<ffffffffffffffff>] 0xffffffffffffffff

Re: Leaks in trace reported by kmemleak

[Li Zefan]

CC: ...

Zdenek Kabelac wrote:
> I've noticed your latest patch for memory leak in filter setting
> (8ad807318fcd...) - but even with this patch - kmemleak seems to still
> report  lots  (~900) of following leaks - note - they come only from
> i915 and kvm module - so I'm not sure if these two modules are doing
> something wrong or the problem is in trace code.
> 
> It looks like whole directory is somehow forgotten.
> 

Fortunately those are false-positives:

 # modprobe i915
 # echo scan > /debug/kmemleak
 # cat /debug/kmemleak
 (lots of "leaks")
 # rmmod i915
 # echo scan > /debug/kmemleak
 # cat /debug/kmemleak
 (no leaks)

All the memory allocated when loading the module is
freed in trace_module_remove_events() at module unload.

But I haven't looked into how to suppress those false-postives.
I'd like to, but I'm going to leave my office and won't be
back until 26th..

Re: Leaks in trace reported by kmemleak

[Catalin Marinas]

On Thu, 2009-10-15 at 17:46 +0800, Li Zefan wrote:
> Zdenek Kabelac wrote:
> > I've noticed your latest patch for memory leak in filter setting
> > (8ad807318fcd...) - but even with this patch - kmemleak seems to still
> > report  lots  (~900) of following leaks - note - they come only from
> > i915 and kvm module - so I'm not sure if these two modules are doing
> > something wrong or the problem is in trace code.
> > 
> > It looks like whole directory is somehow forgotten.
> > 
> 
> Fortunately those are false-positives:
> 
>  # modprobe i915
>  # echo scan > /debug/kmemleak
>  # cat /debug/kmemleak
>  (lots of "leaks")
>  # rmmod i915
>  # echo scan > /debug/kmemleak
>  # cat /debug/kmemleak
>  (no leaks)
> 
> All the memory allocated when loading the module is
> freed in trace_module_remove_events() at module unload.
> 
> But I haven't looked into how to suppress those false-postives.
> I'd like to, but I'm going to leave my office and won't be
> back until 26th..

It is probably caused by the fact that kmemleak doesn't scan the
mod->trace_events data in a module (the _ftrace_events section). It only
scans those sections beginning with .data and .bss in a module. Maybe we
should add "_ftrace_events" as well or just prefix it with ".data".

Something like below may fix this (untested):

diff --git a/kernel/module.c b/kernel/module.c
index 8b7d880..1449691 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -2383,6 +2383,9 @@ static noinline struct module *load_module(void __user *umod,
 					 "_ftrace_events",
 					 sizeof(*mod->trace_events),
 					 &mod->num_trace_events);
+	kmemleak_scan_area(mod->module_core, mod->trace_events,
+			   sizeof(*mod->trace_events) * mod->num_trace_events,
+			   GFP_KERNEL);
 #endif
 #ifdef CONFIG_FTRACE_MCOUNT_RECORD
 	/* sechdrs[0].sh_size is always zero */


-- 
Catalin

Re: Leaks in trace reported by kmemleak

[Zdenek Kabelac]

2009/10/15 Catalin Marinas <catalin.marinas@arm.com>:
> On Thu, 2009-10-15 at 17:46 +0800, Li Zefan wrote:
>> Zdenek Kabelac wrote:
>> > I've noticed your latest patch for memory leak in filter setting
>> > (8ad807318fcd...) - but even with this patch - kmemleak seems to still
>> > report  lots  (~900) of following leaks - note - they come only from
>> > i915 and kvm module - so I'm not sure if these two modules are doing
>> > something wrong or the problem is in trace code.
>> >
>> > It looks like whole directory is somehow forgotten.
>> >
>>
>> Fortunately those are false-positives:
>>
>>  # modprobe i915
>>  # echo scan > /debug/kmemleak
>>  # cat /debug/kmemleak
>>  (lots of "leaks")
>>  # rmmod i915
>>  # echo scan > /debug/kmemleak
>>  # cat /debug/kmemleak
>>  (no leaks)
>>
>> All the memory allocated when loading the module is
>> freed in trace_module_remove_events() at module unload.
>>
>> But I haven't looked into how to suppress those false-postives.
>> I'd like to, but I'm going to leave my office and won't be
>> back until 26th..
>
> It is probably caused by the fact that kmemleak doesn't scan the
> mod->trace_events data in a module (the _ftrace_events section). It only
> scans those sections beginning with .data and .bss in a module. Maybe we
> should add "_ftrace_events" as well or just prefix it with ".data".
>
> Something like below may fix this (untested):
>
> diff --git a/kernel/module.c b/kernel/module.c
> index 8b7d880..1449691 100644
> --- a/kernel/module.c
> +++ b/kernel/module.c
> @@ -2383,6 +2383,9 @@ static noinline struct module *load_module(void __user *umod,
>                                         "_ftrace_events",
>                                         sizeof(*mod->trace_events),
>                                         &mod->num_trace_events);
> +       kmemleak_scan_area(mod->module_core, mod->trace_events,
> +                          sizeof(*mod->trace_events) * mod->num_trace_events,
> +                          GFP_KERNEL);
>  #endif
>  #ifdef CONFIG_FTRACE_MCOUNT_RECORD
>        /* sechdrs[0].sh_size is always zero */
>
>

Yep - I've assume it could be also a problem of missing memory segment
in kmemleak scanning routine - but it was weird that just these two
modules (i915 & kvm) are doing such strange thing.

I've tested patch above with added cast  ( (unsigned
long)mod->trace_events) to pacify warning - but it did not helped -
leaks are still printed.

And I add another leak - which might be from the same range of problem :
(it's also present many times - and it even looks like hex dump is
changing so it's probably even frequently used memory region - at
least in few such objects)

unreferenced object 0xffff88013aa4ad80 (size 192):
  comm "swapper", pid 1, jiffies 4294877809
  hex dump (first 32 bytes):
    c0 dc a4 3a 01 88 ff ff 00 0c 79 39 01 88 ff ff  ...:......y9....
    90 00 cf 3a 01 88 ff ff 02 00 00 00 00 00 00 00  ...:............
  backtrace:
    [<ffffffff8140e9a6>] kmemleak_alloc+0x26/0x60
    [<ffffffff81126a01>] kmem_cache_alloc_notrace+0xc1/0x140
    [<ffffffff8127256a>] dma_debug_init+0x23a/0x3a0
    [<ffffffff81864a37>] pci_iommu_init+0xe/0x28
    [<ffffffff8100904c>] do_one_initcall+0x3c/0x1d0
    [<ffffffff8185f4e6>] kernel_init+0x150/0x1a6
    [<ffffffff8100d21a>] child_rip+0xa/0x20
    [<ffffffffffffffff>] 0xffffffffffffffff


Zdenek

Re: Leaks in trace reported by kmemleak

[Catalin Marinas]

On Fri, 2009-10-16 at 09:45 +0200, Zdenek Kabelac wrote:
> 2009/10/15 Catalin Marinas <catalin.marinas@arm.com>:
> >> Zdenek Kabelac wrote:
> >> > I've noticed your latest patch for memory leak in filter setting
> >> > (8ad807318fcd...) - but even with this patch - kmemleak seems to still
> >> > report  lots  (~900) of following leaks - note - they come only from
> >> > i915 and kvm module - so I'm not sure if these two modules are doing
> >> > something wrong or the problem is in trace code.
> > 
> > It is probably caused by the fact that kmemleak doesn't scan the
> > mod->trace_events data in a module (the _ftrace_events section). It only
> > scans those sections beginning with .data and .bss in a module. Maybe we
> > should add "_ftrace_events" as well or just prefix it with ".data".
> >
> > Something like below may fix this (untested):
> >
> > diff --git a/kernel/module.c b/kernel/module.c
> > index 8b7d880..1449691 100644
> > --- a/kernel/module.c
> > +++ b/kernel/module.c
> > @@ -2383,6 +2383,9 @@ static noinline struct module *load_module(void __user *umod,
> >                                         "_ftrace_events",
> >                                         sizeof(*mod->trace_events),
> >                                         &mod->num_trace_events);
> > +       kmemleak_scan_area(mod->module_core, mod->trace_events,
> > +                          sizeof(*mod->trace_events) * mod->num_trace_events,
> > +                          GFP_KERNEL);
> >  #endif
> >  #ifdef CONFIG_FTRACE_MCOUNT_RECORD
> >        /* sechdrs[0].sh_size is always zero */
> 
> Yep - I've assume it could be also a problem of missing memory segment
> in kmemleak scanning routine - but it was weird that just these two
> modules (i915 & kvm) are doing such strange thing.
> 
> I've tested patch above with added cast  ( (unsigned
> long)mod->trace_events) to pacify warning - but it did not helped -
> leaks are still printed.

Same trace-related leaks?

Do any of the leaks disappear with subsequent memory scans (echo scan >
debug/kmemleak)?

Could you try the patch below? It ensures that all the module memory is
scanned:

diff --git a/kernel/module.c b/kernel/module.c
index 8b7d880..fc6ef3a 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -2036,36 +2036,6 @@ static void *module_alloc_update_bounds(unsigned long size)
 	return ret;
 }
 
-#ifdef CONFIG_DEBUG_KMEMLEAK
-static void kmemleak_load_module(struct module *mod, Elf_Ehdr *hdr,
-				 Elf_Shdr *sechdrs, char *secstrings)
-{
-	unsigned int i;
-
-	/* only scan the sections containing data */
-	kmemleak_scan_area(mod->module_core, (unsigned long)mod -
-			   (unsigned long)mod->module_core,
-			   sizeof(struct module), GFP_KERNEL);
-
-	for (i = 1; i < hdr->e_shnum; i++) {
-		if (!(sechdrs[i].sh_flags & SHF_ALLOC))
-			continue;
-		if (strncmp(secstrings + sechdrs[i].sh_name, ".data", 5) != 0
-		    && strncmp(secstrings + sechdrs[i].sh_name, ".bss", 4) != 0)
-			continue;
-
-		kmemleak_scan_area(mod->module_core, sechdrs[i].sh_addr -
-				   (unsigned long)mod->module_core,
-				   sechdrs[i].sh_size, GFP_KERNEL);
-	}
-}
-#else
-static inline void kmemleak_load_module(struct module *mod, Elf_Ehdr *hdr,
-					Elf_Shdr *sechdrs, char *secstrings)
-{
-}
-#endif
-
 /* Allocate and load the module: note that size of section 0 is always
    zero, and we rely on this for optional sections. */
 static noinline struct module *load_module(void __user *umod,
@@ -2293,7 +2263,6 @@ static noinline struct module *load_module(void __user *umod,
 	}
 	/* Module has been moved. */
 	mod = (void *)sechdrs[modindex].sh_addr;
-	kmemleak_load_module(mod, hdr, sechdrs, secstrings);
 
 #if defined(CONFIG_MODULE_UNLOAD) && defined(CONFIG_SMP)
 	mod->refptr = percpu_modalloc(sizeof(local_t), __alignof__(local_t),

> And I add another leak - which might be from the same range of problem :
> (it's also present many times - and it even looks like hex dump is
> changing so it's probably even frequently used memory region - at
> least in few such objects)
> 
> unreferenced object 0xffff88013aa4ad80 (size 192):
>   comm "swapper", pid 1, jiffies 4294877809
>   hex dump (first 32 bytes):
>     c0 dc a4 3a 01 88 ff ff 00 0c 79 39 01 88 ff ff  ...:......y9....
>     90 00 cf 3a 01 88 ff ff 02 00 00 00 00 00 00 00  ...:............
>   backtrace:
>     [<ffffffff8140e9a6>] kmemleak_alloc+0x26/0x60
>     [<ffffffff81126a01>] kmem_cache_alloc_notrace+0xc1/0x140
>     [<ffffffff8127256a>] dma_debug_init+0x23a/0x3a0
>     [<ffffffff81864a37>] pci_iommu_init+0xe/0x28
>     [<ffffffff8100904c>] do_one_initcall+0x3c/0x1d0
>     [<ffffffff8185f4e6>] kernel_init+0x150/0x1a6
>     [<ffffffff8100d21a>] child_rip+0xa/0x20
>     [<ffffffffffffffff>] 0xffffffffffffffff

Same as above, does it disappear with subsequent scans? This doesn't
look immediately like a false positive, it needs a bit more
investigation.

Thanks.

-- 
Catalin

Re: Leaks in trace reported by kmemleak

[Zdenek Kabelac]

2009/10/16 Catalin Marinas <catalin.marinas@arm.com>:
> On Fri, 2009-10-16 at 09:45 +0200, Zdenek Kabelac wrote:
>> 2009/10/15 Catalin Marinas <catalin.marinas@arm.com>:
>> >> Zdenek Kabelac wrote:
>> >> > I've noticed your latest patch for memory leak in filter setting
>> >> > (8ad807318fcd...) - but even with this patch - kmemleak seems to still
>> >> > report  lots  (~900) of following leaks - note - they come only from
>> >> > i915 and kvm module - so I'm not sure if these two modules are doing
>> >> > something wrong or the problem is in trace code.
>> >
>> > It is probably caused by the fact that kmemleak doesn't scan the
>> > mod->trace_events data in a module (the _ftrace_events section). It only
>> > scans those sections beginning with .data and .bss in a module. Maybe we
>> > should add "_ftrace_events" as well or just prefix it with ".data".
>> >
>> > Something like below may fix this (untested):
>> >
>> > diff --git a/kernel/module.c b/kernel/module.c
>> > index 8b7d880..1449691 100644
>> > --- a/kernel/module.c
>> > +++ b/kernel/module.c
>> > @@ -2383,6 +2383,9 @@ static noinline struct module *load_module(void __user *umod,
>> >                                         "_ftrace_events",
>> >                                         sizeof(*mod->trace_events),
>> >                                         &mod->num_trace_events);
>> > +       kmemleak_scan_area(mod->module_core, mod->trace_events,
>> > +                          sizeof(*mod->trace_events) * mod->num_trace_events,
>> > +                          GFP_KERNEL);
>> >  #endif
>> >  #ifdef CONFIG_FTRACE_MCOUNT_RECORD
>> >        /* sechdrs[0].sh_size is always zero */
>>
>> Yep - I've assume it could be also a problem of missing memory segment
>> in kmemleak scanning routine - but it was weird that just these two
>> modules (i915 & kvm) are doing such strange thing.
>>
>> I've tested patch above with added cast  ( (unsigned
>> long)mod->trace_events) to pacify warning - but it did not helped -
>> leaks are still printed.
>
> Same trace-related leaks?
>


Yes -same - though I forget to mention that log contained these two
extra messages:
(got lost in other debug stuff :( )...

So it could be the parameters in your first patch were not correct ?

[drm] Initialized drm 1.1.0 20060810
kmemleak: Scan area larger than object 0xffffffffa033b000
Pid: 1083, comm: modprobe Not tainted 2.6.32-rc5-00002-ga8ed0d4 #25
Call Trace:
 [<ffffffff8140ee5f>] kmemleak_scan_area+0x15f/0x1a0
 [<ffffffff810a0086>] load_module+0xff6/0x1ae0
 [<ffffffff8109ca70>] ? setup_modinfo_srcversion+0x0/0x30
 [<ffffffff810a0beb>] sys_init_module+0x7b/0x260
 [<ffffffff8100c11b>] system_call_fastpath+0x16/0x1b
kmemleak: Object 0xffffffffa033b000 (size 307200):
kmemleak:   comm "modprobe", pid 1083, jiffies 4294881856
kmemleak:   min_count = 0
kmemleak:   count = -1
kmemleak:   flags = 0x9
kmemleak:   backtrace:
     [<ffffffff8140eae6>] kmemleak_alloc+0x26/0x60
     [<ffffffff8111992a>] __vmalloc_area+0x4a/0x60
     [<ffffffff8102b6ee>] module_alloc+0x5e/0x60
     [<ffffffff8109c626>] module_alloc_update_bounds+0x16/0x50
     [<ffffffff8109f8d3>] load_module+0x843/0x1ae0
     [<ffffffff810a0beb>] sys_init_module+0x7b/0x260
     [<ffffffff8100c11b>] system_call_fastpath+0x16/0x1b
     [<ffffffffffffffff>] 0xffffffffffffffff
pci 0000:00:02.0: power state changed by ACPI to D0
pci 0000:00:02.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
acpi device:01: registered as cooling_device2
input: Video Bus as
/devices/LNXSYSTM:00/LNXSYBUS:00/PNP0A08:00/LNXVIDEO:00/input/input8
ACPI: Video Device [VID] (multi-head: yes  rom: no  post: no)
[drm] Initialized i915 1.6.0 20080730 for 0000:00:02.0 on minor 0
kmemleak: Scan area larger than object 0xffffffffa0399000
Pid: 1090, comm: modprobe Not tainted 2.6.32-rc5-00002-ga8ed0d4 #25
Call Trace:
 [<ffffffff8140ee5f>] kmemleak_scan_area+0x15f/0x1a0
 [<ffffffff810a0086>] load_module+0xff6/0x1ae0
 [<ffffffff8109ca70>] ? setup_modinfo_srcversion+0x0/0x30
 [<ffffffff810a0beb>] sys_init_module+0x7b/0x260
 [<ffffffff8100c11b>] system_call_fastpath+0x16/0x1b
kmemleak: Object 0xffffffffa0399000 (size 278528):
kmemleak:   comm "modprobe", pid 1090, jiffies 4294881947
kmemleak:   min_count = 0
kmemleak:   count = -1
kmemleak:   flags = 0x9
kmemleak:   backtrace:
     [<ffffffff8140eae6>] kmemleak_alloc+0x26/0x60
     [<ffffffff8111992a>] __vmalloc_area+0x4a/0x60
     [<ffffffff8102b6ee>] module_alloc+0x5e/0x60
     [<ffffffff8109c626>] module_alloc_update_bounds+0x16/0x50
     [<ffffffff8109f8d3>] load_module+0x843/0x1ae0
     [<ffffffff810a0beb>] sys_init_module+0x7b/0x260
     [<ffffffff8100c11b>] system_call_fastpath+0x16/0x1b
     [<ffffffffffffffff>] 0xffffffffffffffff




> Do any of the leaks disappear with subsequent memory scans (echo scan >
> debug/kmemleak)?
>

Yep - they are persistent until module unload - for i915 though there
are some left.

BTW - it's kind of ugly - that module removal destroys stack trace -
it would be nice to see some hook for module unload - to eventually
create a permanent stack trace for this occasion??
Otherwise when i915 is unloaded - I get leaks with unresolved addresses.
(as a workaround I store leaks before unload and do a manual compare)

> Could you try the patch below? It ensures that all the module memory is
> scanned:
>
> diff --git a/kernel/module.c b/kernel/module.c
> index 8b7d880..fc6ef3a 100644
> --- a/kernel/module.c
> +++ b/kernel/module.c
> @@ -2036,36 +2036,6 @@ static void *module_alloc_update_bounds(unsigned long size)
>        return ret;
>  }
>
> -#ifdef CONFIG_DEBUG_KMEMLEAK
> -static void kmemleak_load_module(struct module *mod, Elf_Ehdr *hdr,
> -                                Elf_Shdr *sechdrs, char *secstrings)
> -{

I'll check with next reboot.

>> And I add another leak - which might be from the same range of problem :
>> (it's also present many times - and it even looks like hex dump is
>> changing so it's probably even frequently used memory region - at
>> least in few such objects)
>>
>> unreferenced object 0xffff88013aa4ad80 (size 192):
>>   comm "swapper", pid 1, jiffies 4294877809
>>   hex dump (first 32 bytes):
>>     c0 dc a4 3a 01 88 ff ff 00 0c 79 39 01 88 ff ff  ...:......y9....
>>     90 00 cf 3a 01 88 ff ff 02 00 00 00 00 00 00 00  ...:............
>>   backtrace:
>>     [<ffffffff8140e9a6>] kmemleak_alloc+0x26/0x60
>>     [<ffffffff81126a01>] kmem_cache_alloc_notrace+0xc1/0x140
>>     [<ffffffff8127256a>] dma_debug_init+0x23a/0x3a0
>>     [<ffffffff81864a37>] pci_iommu_init+0xe/0x28
>>     [<ffffffff8100904c>] do_one_initcall+0x3c/0x1d0
>>     [<ffffffff8185f4e6>] kernel_init+0x150/0x1a6
>>     [<ffffffff8100d21a>] child_rip+0xa/0x20
>>     [<ffffffffffffffff>] 0xffffffffffffffff
>
> Same as above, does it disappear with subsequent scans? This doesn't
> look immediately like a false positive, it needs a bit more
> investigation.
>

No they seem to be permanent - but the hex dump area is changing for
some of those objects.
That's why I assume they are false positives.

Zdenek

Re: Leaks in trace reported by kmemleak

[Catalin Marinas]

Zdenek Kabelac <zdenek.kabelac@gmail.com> wrote:
> Yes -same - though I forget to mention that log contained these two
> extra messages:
> (got lost in other debug stuff :( )...
>
> So it could be the parameters in your first patch were not correct ?
>
> [drm] Initialized drm 1.1.0 20060810
> kmemleak: Scan area larger than object 0xffffffffa033b000

Ah, I forgot that kmemleak_scan_area takes an offset inside an object
rather than an absolute address. Something like below (I should
actually change this prototype of this function, it doesn't need to be
so complex):

diff --git a/kernel/module.c b/kernel/module.c
index 8b7d880..8cc4406 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -2383,6 +2383,10 @@ static noinline struct module *load_module(void __user *umod,
 					 "_ftrace_events",
 					 sizeof(*mod->trace_events),
 					 &mod->num_trace_events);
+	kmemleak_scan_area(mod->module_core, (unsigned long)mod->trace_events -
+			   (unsigned long)mod->module_core,
+			   sizeof(*mod->trace_events) * mod->num_trace_events,
+			   GFP_KERNEL);
 #endif
 #ifdef CONFIG_FTRACE_MCOUNT_RECORD
 	/* sechdrs[0].sh_size is always zero */

> BTW - it's kind of ugly - that module removal destroys stack trace -
> it would be nice to see some hook for module unload - to eventually
> create a permanent stack trace for this occasion??

Kmemleak only uses whatever stacktrace mechanism is available in the
kernel. Resolving the symbol names when objects are allocated would
slow it down and it takes up more space in the traces. I don't have a
proper solution.

-- 
Catalin

Re: Leaks in trace reported by kmemleak

[Zdenek Kabelac]

2009/10/16 Catalin Marinas <catalin.marinas@arm.com>:
> Zdenek Kabelac <zdenek.kabelac@gmail.com> wrote:
>> Yes -same - though I forget to mention that log contained these two
>> extra messages:
>> (got lost in other debug stuff :( )...
>>
>> So it could be the parameters in your first patch were not correct ?
>>
>> [drm] Initialized drm 1.1.0 20060810
>> kmemleak: Scan area larger than object 0xffffffffa033b000
>
> Ah, I forgot that kmemleak_scan_area takes an offset inside an object
> rather than an absolute address. Something like below (I should
> actually change this prototype of this function, it doesn't need to be
> so complex):
>
> diff --git a/kernel/module.c b/kernel/module.c
> index 8b7d880..8cc4406 100644
> --- a/kernel/module.c
> +++ b/kernel/module.c
> @@ -2383,6 +2383,10 @@ static noinline struct module *load_module(void __user *umod,
>                                         "_ftrace_events",
>                                         sizeof(*mod->trace_events),
>                                         &mod->num_trace_events);
> +       kmemleak_scan_area(mod->module_core, (unsigned long)mod->trace_events -
> +                          (unsigned long)mod->module_core,
> +                          sizeof(*mod->trace_events) * mod->num_trace_events,
> +                          GFP_KERNEL);
>  #endif
>  #ifdef CONFIG_FTRACE_MCOUNT_RECORD
>        /* sechdrs[0].sh_size is always zero */

Hmm - ok I'll retest this one - meanwhile here is my observation from
your previous post

It looks like this remove leaks from  i915 & kvm
But on the other hand there are ~4 other leaks now reported from
various kernel parts.


>
>> BTW - it's kind of ugly - that module removal destroys stack trace -
>> it would be nice to see some hook for module unload - to eventually
>> create a permanent stack trace for this occasion??
>
> Kmemleak only uses whatever stacktrace mechanism is available in the
> kernel. Resolving the symbol names when objects are allocated would
> slow it down and it takes up more space in the traces. I don't have a
> proper solution.
>

I think that no drastic solutions would need to be deployed in my case.
I would propose something like this:

When you display/resolve  stacktrace  with  cat
/sys/kernel/debug/kmemleak - you could remember decoded stacktraces in
some given buffer - and so next time - you would not need to decode
this stacktrace - and when the module is removed the stacktrace could
be displayed properly.

It's already time costly to keep stacktrace (very noticeable in drm -
where there is permanently something being allocated and deallocated)

IMHO it wouldn't be too time consuming to resolve traces even right
after scan command - as only new objects would need to be decoded.

Obviously it would cost slightly more memory to keep this string
output somewhere - but I think my machine will not miss that much 0.5M
for this purpose.

Zdenek

Re: Leaks in trace reported by kmemleak

[Zdenek Kabelac]

2009/10/16 Zdenek Kabelac <zdenek.kabelac@gmail.com>:
> 2009/10/16 Catalin Marinas <catalin.marinas@arm.com>:
>> Zdenek Kabelac <zdenek.kabelac@gmail.com> wrote:
>>> Yes -same - though I forget to mention that log contained these two
>>> extra messages:
>>> (got lost in other debug stuff :( )...
>>>
>>> So it could be the parameters in your first patch were not correct ?
>>>
>>> [drm] Initialized drm 1.1.0 20060810
>>> kmemleak: Scan area larger than object 0xffffffffa033b000
>>
>> Ah, I forgot that kmemleak_scan_area takes an offset inside an object
>> rather than an absolute address. Something like below (I should
>> actually change this prototype of this function, it doesn't need to be
>> so complex):
>>
>> diff --git a/kernel/module.c b/kernel/module.c
>> index 8b7d880..8cc4406 100644
>> --- a/kernel/module.c
>> +++ b/kernel/module.c
>> @@ -2383,6 +2383,10 @@ static noinline struct module *load_module(void __user *umod,
>>                                         "_ftrace_events",
>>                                         sizeof(*mod->trace_events),
>>                                         &mod->num_trace_events);
>> +       kmemleak_scan_area(mod->module_core, (unsigned long)mod->trace_events -
>> +                          (unsigned long)mod->module_core,
>> +                          sizeof(*mod->trace_events) * mod->num_trace_events,
>> +                          GFP_KERNEL);
>>  #endif
>>  #ifdef CONFIG_FTRACE_MCOUNT_RECORD
>>        /* sechdrs[0].sh_size is always zero */
>


So I've tested this modified version and it gives much better result
with respect to amount of leaked objects
It gets even to 0 - so even dma is not usually printed now - thus I
think the dma_debug_init is not a real issue.
As on some scan they are present and on some they are not there.

And also traces' strdup leaks are now gone for i915 and kvm.

But it's still not perfect - as my machine now has a lot of these
entries in the boot log:
(I'm using only this patch - and not the next one where you removed
call to kmemleak_load_module)

kmemleak: Scan area larger than object 0xffffffffa04f0000
Pid: 1752, comm: modprobe Not tainted 2.6.32-rc5-00002-gdab7e9a #27
Call Trace:
 [<ffffffff8140ee6f>] kmemleak_scan_area+0x15f/0x1a0
 [<ffffffff810a0089>] load_module+0xff9/0x1af0
 [<ffffffff8109ca70>] ? setup_modinfo_srcversion+0x0/0x30
 [<ffffffff810a0bfb>] sys_init_module+0x7b/0x260
 [<ffffffff8100c11b>] system_call_fastpath+0x16/0x1b
kmemleak: Object 0xffffffffa04f0000 (size 8192):
kmemleak:   comm "modprobe", pid 1752, jiffies 4294886643
kmemleak:   min_count = 0
kmemleak:   count = -1
kmemleak:   flags = 0x9
kmemleak:   backtrace:
     [<ffffffff8140eaf6>] kmemleak_alloc+0x26/0x60
     [<ffffffff8111993a>] __vmalloc_area+0x4a/0x60
     [<ffffffff8102b6ee>] module_alloc+0x5e/0x60
     [<ffffffff8109c626>] module_alloc_update_bounds+0x16/0x50
     [<ffffffff8109f8d3>] load_module+0x843/0x1af0
     [<ffffffff810a0bfb>] sys_init_module+0x7b/0x260
     [<ffffffff8100c11b>] system_call_fastpath+0x16/0x1b
     [<ffffffffffffffff>] 0xffffffffffffffff

Zdenek

Re: Leaks in trace reported by kmemleak

[Catalin Marinas]

On Fri, 2009-10-16 at 17:07 +0200, Zdenek Kabelac wrote:
> 2009/10/16 Zdenek Kabelac <zdenek.kabelac@gmail.com>:
> > 2009/10/16 Catalin Marinas <catalin.marinas@arm.com>:
> >> diff --git a/kernel/module.c b/kernel/module.c
> >> index 8b7d880..8cc4406 100644
> >> --- a/kernel/module.c
> >> +++ b/kernel/module.c
> >> @@ -2383,6 +2383,10 @@ static noinline struct module *load_module(void __user *umod,
> >>                                         "_ftrace_events",
> >>                                         sizeof(*mod->trace_events),
> >>                                         &mod->num_trace_events);
> >> +       kmemleak_scan_area(mod->module_core, (unsigned long)mod->trace_events -
> >> +                          (unsigned long)mod->module_core,
> >> +                          sizeof(*mod->trace_events) * mod->num_trace_events,
> >> +                          GFP_KERNEL);
> >>  #endif
> >>  #ifdef CONFIG_FTRACE_MCOUNT_RECORD
> >>        /* sechdrs[0].sh_size is always zero */
> 
> But it's still not perfect - as my machine now has a lot of these
> entries in the boot log:
> (I'm using only this patch - and not the next one where you removed
> call to kmemleak_load_module)
> 
> kmemleak: Scan area larger than object 0xffffffffa04f0000
> Pid: 1752, comm: modprobe Not tainted 2.6.32-rc5-00002-gdab7e9a #27
> Call Trace:
>  [<ffffffff8140ee6f>] kmemleak_scan_area+0x15f/0x1a0
>  [<ffffffff810a0089>] load_module+0xff9/0x1af0
>  [<ffffffff8109ca70>] ? setup_modinfo_srcversion+0x0/0x30
>  [<ffffffff810a0bfb>] sys_init_module+0x7b/0x260
>  [<ffffffff8100c11b>] system_call_fastpath+0x16/0x1b
> kmemleak: Object 0xffffffffa04f0000 (size 8192):

I think that's caused by modules not having an _ftrace_events section.
The patch below (applied after the one above, though there may be a
conflict with some comments I added) changes the interface of
kmemleak_scan_area and now handles NULL pointers passed to it (not fully
tested as I just created it):


kmemleak: Simplify the kmemleak_scan_area() function prototype

From: Catalin Marinas <catalin.marinas@arm.com>

This function was taking non-necessary arguments which can be determined
by kmemleak. The patch also modifies the calling sites.

Signed-off-by: Catalin Marinas <catalin.marinas@arm.com>
---
 include/linux/kmemleak.h |    8 ++++----
 kernel/module.c          |   13 ++++--------
 mm/kmemleak.c            |   49 ++++++++++++++++++++--------------------------
 mm/slab.c                |    4 ++--
 4 files changed, 31 insertions(+), 43 deletions(-)

diff --git a/include/linux/kmemleak.h b/include/linux/kmemleak.h
index 3c7497d..00888b9 100644
--- a/include/linux/kmemleak.h
+++ b/include/linux/kmemleak.h
@@ -32,8 +32,8 @@ extern void kmemleak_padding(const void *ptr, unsigned long offset,
 			     size_t size) __ref;
 extern void kmemleak_not_leak(const void *ptr) __ref;
 extern void kmemleak_ignore(const void *ptr) __ref;
-extern void kmemleak_scan_area(const void *ptr, unsigned long offset,
-			       size_t length, gfp_t gfp) __ref;
+extern void kmemleak_scan_area(const void *ptr, size_t length,
+			       gfp_t gfp) __ref;
 extern void kmemleak_no_scan(const void *ptr) __ref;
 
 static inline void kmemleak_alloc_recursive(const void *ptr, size_t size,
@@ -84,8 +84,8 @@ static inline void kmemleak_not_leak(const void *ptr)
 static inline void kmemleak_ignore(const void *ptr)
 {
 }
-static inline void kmemleak_scan_area(const void *ptr, unsigned long offset,
-				      size_t length, gfp_t gfp)
+static inline void kmemleak_scan_area(const void *ptr, size_t length,
+				      gfp_t gfp)
 {
 }
 static inline void kmemleak_erase(void **ptr)
diff --git a/kernel/module.c b/kernel/module.c
index dd22f4e..dd29ba4 100644
--- a/kernel/module.c
+++ b/kernel/module.c
@@ -2043,9 +2043,7 @@ static void kmemleak_load_module(struct module *mod, Elf_Ehdr *hdr,
 	unsigned int i;
 
 	/* only scan the sections containing data */
-	kmemleak_scan_area(mod->module_core, (unsigned long)mod -
-			   (unsigned long)mod->module_core,
-			   sizeof(struct module), GFP_KERNEL);
+	kmemleak_scan_area(mod, sizeof(struct module), GFP_KERNEL);
 
 	for (i = 1; i < hdr->e_shnum; i++) {
 		if (!(sechdrs[i].sh_flags & SHF_ALLOC))
@@ -2054,8 +2052,7 @@ static void kmemleak_load_module(struct module *mod, Elf_Ehdr *hdr,
 		    && strncmp(secstrings + sechdrs[i].sh_name, ".bss", 4) != 0)
 			continue;
 
-		kmemleak_scan_area(mod->module_core, sechdrs[i].sh_addr -
-				   (unsigned long)mod->module_core,
+		kmemleak_scan_area((void *)sechdrs[i].sh_addr,
 				   sechdrs[i].sh_size, GFP_KERNEL);
 	}
 }
@@ -2387,10 +2384,8 @@ static noinline struct module *load_module(void __user *umod,
 	 * This section contains pointers to allocated objects in the trace
 	 * code and not scanning it leads to false positives.
 	 */
-	kmemleak_scan_area(mod->module_core, (unsigned long)mod->trace_events -
-			   (unsigned long)mod->module_core,
-			   sizeof(*mod->trace_events) * mod->num_trace_events,
-			   GFP_KERNEL);
+	kmemleak_scan_area(mod->trace_events, sizeof(*mod->trace_events) *
+			   mod->num_trace_events, GFP_KERNEL);
 #endif
 #ifdef CONFIG_FTRACE_MCOUNT_RECORD
 	/* sechdrs[0].sh_size is always zero */
diff --git a/mm/kmemleak.c b/mm/kmemleak.c
index 8bf765c..9610635 100644
--- a/mm/kmemleak.c
+++ b/mm/kmemleak.c
@@ -119,8 +119,8 @@
 /* scanning area inside a memory block */
 struct kmemleak_scan_area {
 	struct hlist_node node;
-	unsigned long offset;
-	size_t length;
+	unsigned long start;
+	size_t size;
 };
 
 #define KMEMLEAK_GREY	0
@@ -241,8 +241,6 @@ struct early_log {
 	const void *ptr;		/* allocated/freed memory block */
 	size_t size;			/* memory block size */
 	int min_count;			/* minimum reference count */
-	unsigned long offset;		/* scan area offset */
-	size_t length;			/* scan area length */
 	unsigned long trace[MAX_TRACE];	/* stack trace */
 	unsigned int trace_len;		/* stack trace length */
 };
@@ -720,14 +718,13 @@ static void make_black_object(unsigned long ptr)
  * Add a scanning area to the object. If at least one such area is added,
  * kmemleak will only scan these ranges rather than the whole memory block.
  */
-static void add_scan_area(unsigned long ptr, unsigned long offset,
-			  size_t length, gfp_t gfp)
+static void add_scan_area(unsigned long ptr, size_t size, gfp_t gfp)
 {
 	unsigned long flags;
 	struct kmemleak_object *object;
 	struct kmemleak_scan_area *area;
 
-	object = find_and_get_object(ptr, 0);
+	object = find_and_get_object(ptr, 1);
 	if (!object) {
 		kmemleak_warn("Adding scan area to unknown object at 0x%08lx\n",
 			      ptr);
@@ -741,7 +738,7 @@ static void add_scan_area(unsigned long ptr, unsigned long offset,
 	}
 
 	spin_lock_irqsave(&object->lock, flags);
-	if (offset + length > object->size) {
+	if (ptr + size > object->pointer + object->size) {
 		kmemleak_warn("Scan area larger than object 0x%08lx\n", ptr);
 		dump_object_info(object);
 		kmem_cache_free(scan_area_cache, area);
@@ -749,8 +746,8 @@ static void add_scan_area(unsigned long ptr, unsigned long offset,
 	}
 
 	INIT_HLIST_NODE(&area->node);
-	area->offset = offset;
-	area->length = length;
+	area->start = ptr;
+	area->size = size;
 
 	hlist_add_head(&area->node, &object->area_list);
 out_unlock:
@@ -786,7 +783,7 @@ static void object_no_scan(unsigned long ptr)
  * processed later once kmemleak is fully initialized.
  */
 static void __init log_early(int op_type, const void *ptr, size_t size,
-			     int min_count, unsigned long offset, size_t length)
+			     int min_count)
 {
 	unsigned long flags;
 	struct early_log *log;
@@ -808,8 +805,6 @@ static void __init log_early(int op_type, const void *ptr, size_t size,
 	log->ptr = ptr;
 	log->size = size;
 	log->min_count = min_count;
-	log->offset = offset;
-	log->length = length;
 	if (op_type == KMEMLEAK_ALLOC)
 		log->trace_len = __save_stack_trace(log->trace);
 	crt_early_log++;
@@ -858,7 +853,7 @@ void __ref kmemleak_alloc(const void *ptr, size_t size, int min_count,
 	if (atomic_read(&kmemleak_enabled) && ptr && !IS_ERR(ptr))
 		create_object((unsigned long)ptr, size, min_count, gfp);
 	else if (atomic_read(&kmemleak_early_log))
-		log_early(KMEMLEAK_ALLOC, ptr, size, min_count, 0, 0);
+		log_early(KMEMLEAK_ALLOC, ptr, size, min_count);
 }
 EXPORT_SYMBOL_GPL(kmemleak_alloc);
 
@@ -873,7 +868,7 @@ void __ref kmemleak_free(const void *ptr)
 	if (atomic_read(&kmemleak_enabled) && ptr && !IS_ERR(ptr))
 		delete_object_full((unsigned long)ptr);
 	else if (atomic_read(&kmemleak_early_log))
-		log_early(KMEMLEAK_FREE, ptr, 0, 0, 0, 0);
+		log_early(KMEMLEAK_FREE, ptr, 0, 0);
 }
 EXPORT_SYMBOL_GPL(kmemleak_free);
 
@@ -888,7 +883,7 @@ void __ref kmemleak_free_part(const void *ptr, size_t size)
 	if (atomic_read(&kmemleak_enabled) && ptr && !IS_ERR(ptr))
 		delete_object_part((unsigned long)ptr, size);
 	else if (atomic_read(&kmemleak_early_log))
-		log_early(KMEMLEAK_FREE_PART, ptr, size, 0, 0, 0);
+		log_early(KMEMLEAK_FREE_PART, ptr, size, 0);
 }
 EXPORT_SYMBOL_GPL(kmemleak_free_part);
 
@@ -903,7 +898,7 @@ void __ref kmemleak_not_leak(const void *ptr)
 	if (atomic_read(&kmemleak_enabled) && ptr && !IS_ERR(ptr))
 		make_gray_object((unsigned long)ptr);
 	else if (atomic_read(&kmemleak_early_log))
-		log_early(KMEMLEAK_NOT_LEAK, ptr, 0, 0, 0, 0);
+		log_early(KMEMLEAK_NOT_LEAK, ptr, 0, 0);
 }
 EXPORT_SYMBOL(kmemleak_not_leak);
 
@@ -919,22 +914,21 @@ void __ref kmemleak_ignore(const void *ptr)
 	if (atomic_read(&kmemleak_enabled) && ptr && !IS_ERR(ptr))
 		make_black_object((unsigned long)ptr);
 	else if (atomic_read(&kmemleak_early_log))
-		log_early(KMEMLEAK_IGNORE, ptr, 0, 0, 0, 0);
+		log_early(KMEMLEAK_IGNORE, ptr, 0, 0);
 }
 EXPORT_SYMBOL(kmemleak_ignore);
 
 /*
  * Limit the range to be scanned in an allocated memory block.
  */
-void __ref kmemleak_scan_area(const void *ptr, unsigned long offset,
-			      size_t length, gfp_t gfp)
+void __ref kmemleak_scan_area(const void *ptr, size_t size, gfp_t gfp)
 {
 	pr_debug("%s(0x%p)\n", __func__, ptr);
 
 	if (atomic_read(&kmemleak_enabled) && ptr && !IS_ERR(ptr))
-		add_scan_area((unsigned long)ptr, offset, length, gfp);
+		add_scan_area((unsigned long)ptr, size, gfp);
 	else if (atomic_read(&kmemleak_early_log))
-		log_early(KMEMLEAK_SCAN_AREA, ptr, 0, 0, offset, length);
+		log_early(KMEMLEAK_SCAN_AREA, ptr, size, 0);
 }
 EXPORT_SYMBOL(kmemleak_scan_area);
 
@@ -948,7 +942,7 @@ void __ref kmemleak_no_scan(const void *ptr)
 	if (atomic_read(&kmemleak_enabled) && ptr && !IS_ERR(ptr))
 		object_no_scan((unsigned long)ptr);
 	else if (atomic_read(&kmemleak_early_log))
-		log_early(KMEMLEAK_NO_SCAN, ptr, 0, 0, 0, 0);
+		log_early(KMEMLEAK_NO_SCAN, ptr, 0, 0);
 }
 EXPORT_SYMBOL(kmemleak_no_scan);
 
@@ -1075,9 +1069,9 @@ static void scan_object(struct kmemleak_object *object)
 		}
 	} else
 		hlist_for_each_entry(area, elem, &object->area_list, node)
-			scan_block((void *)(object->pointer + area->offset),
-				   (void *)(object->pointer + area->offset
-					    + area->length), object, 0);
+			scan_block((void *)area->start,
+				   (void *)(area->start + area->size),
+				   object, 0);
 out:
 	spin_unlock_irqrestore(&object->lock, flags);
 }
@@ -1642,8 +1636,7 @@ void __init kmemleak_init(void)
 			kmemleak_ignore(log->ptr);
 			break;
 		case KMEMLEAK_SCAN_AREA:
-			kmemleak_scan_area(log->ptr, log->offset, log->length,
-					   GFP_KERNEL);
+			kmemleak_scan_area(log->ptr, log->size, GFP_KERNEL);
 			break;
 		case KMEMLEAK_NO_SCAN:
 			kmemleak_no_scan(log->ptr);
diff --git a/mm/slab.c b/mm/slab.c
index 646db30..d2713a9 100644
--- a/mm/slab.c
+++ b/mm/slab.c
@@ -2584,8 +2584,8 @@ static struct slab *alloc_slabmgmt(struct kmem_cache *cachep, void *objp,
 		 * kmemleak does not treat the ->s_mem pointer as a reference
 		 * to the object. Otherwise we will not report the leak.
 		 */
-		kmemleak_scan_area(slabp, offsetof(struct slab, list),
-				   sizeof(struct list_head), local_flags);
+		kmemleak_scan_area(&slabp->list, sizeof(struct list_head),
+				   local_flags);
 		if (!slabp)
 			return NULL;
 	} else {

-- 
Catalin

Re: Leaks in trace reported by kmemleak

[Catalin Marinas]

On Fri, 2009-10-16 at 17:07 +0200, Zdenek Kabelac wrote:
> So I've tested this modified version and it gives much better result
> with respect to amount of leaked objects

BTW, I created this tree with kmemleak patches to be pushed upstream:

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

It would be easier to test.

-- 
Catalin

Re: Leaks in trace reported by kmemleak

[Zdenek Kabelac]

2009/10/16 Catalin Marinas <catalin.marinas@arm.com>:
> On Fri, 2009-10-16 at 17:07 +0200, Zdenek Kabelac wrote:
>> So I've tested this modified version and it gives much better result
>> with respect to amount of leaked objects
>
> BTW, I created this tree with kmemleak patches to be pushed upstream:
>
> git://git.kernel.org/pub/scm/linux/kernel/git/cmarinas/kmemleak.git
>
> It would be easier to test.

Yes this branch worked well - and there were no leaks  from i915 or
kvm modules for trace.

What is however interesting is the false positive leak for
dma_debug_init(). Which is sometimes listed and sometimes not - the
memory is allocated just once in the code during boot, so it's strange
that pointers to that area are sometimes out of kmemleak scan.

Zdenek

Re: Leaks in trace reported by kmemleak

[Catalin Marinas]

On Mon, 2009-10-19 at 11:15 +0200, Zdenek Kabelac wrote:
> 2009/10/16 Catalin Marinas <catalin.marinas@arm.com>:
> > On Fri, 2009-10-16 at 17:07 +0200, Zdenek Kabelac wrote:
> >> So I've tested this modified version and it gives much better result
> >> with respect to amount of leaked objects
> >
> > BTW, I created this tree with kmemleak patches to be pushed upstream:
> >
> > git://git.kernel.org/pub/scm/linux/kernel/git/cmarinas/kmemleak.git
> >
> > It would be easier to test.
> 
> Yes this branch worked well - and there were no leaks  from i915 or
> kvm modules for trace.
> 
> What is however interesting is the false positive leak for
> dma_debug_init(). Which is sometimes listed and sometimes not - the
> memory is allocated just once in the code during boot, so it's strange
> that pointers to that area are sometimes out of kmemleak scan.

I updated the tree above with another patch which lists where an object
is referred from. So when you get a leak reported and it later
disappears, you can use:

echo dump=0x... > /sys/kernel/debug/kmemleak

and in syslog you can find information about the previously reported
object and where it is referred from (if it is no longer reported as a
leak). I'm not sure whether this option would be useful for anything
other than debugging kmemleak. I still aim on getting to near 0 false
positives.

Anyway, trying this new patch on the debug_objects, when no longer
reported they are referred from obj_hash. My opinion is that they were
moved to obj_hash during the kmemleak scanning but after kmemleak
finished scanning the data section, hence they couldn't be found.

I hoped that not reporting object allocated within the last 5s would
avoid such problems but there are places like debug_objects for which it
doesn't work as the objects were reported earlier.

A workaround I had in the past was to not report an object unless it was
found as a leak in two consecutive scans. I should probably reinstate
this feature (could be optimised to use a second prio_tree containing
only objects found as leaks).

-- 
Catalin

Re: Leaks in trace reported by kmemleak

[Catalin Marinas]

On Mon, 2009-10-19 at 13:00 +0100, Catalin Marinas wrote:
> On Mon, 2009-10-19 at 11:15 +0200, Zdenek Kabelac wrote:
> > What is however interesting is the false positive leak for
> > dma_debug_init(). Which is sometimes listed and sometimes not - the
> > memory is allocated just once in the code during boot, so it's strange
> > that pointers to that area are sometimes out of kmemleak scan.
> 
> A workaround I had in the past was to not report an object unless it was
> found as a leak in two consecutive scans. I should probably reinstate
> this feature (could be optimised to use a second prio_tree containing
> only objects found as leaks).

OK, I re-added a form of this to the kmemleak.git tree and simplified
the scanning logic (meant initially to reduce the false positives). Now,
for an object to be reported, it needs to be found as leak during two
consecutive scans (this works around pointer moving from a structure to
a different one which was already scanned).

If you have time, could you please give it a try and see whether you
still get transient false positives?

As for the patch showing where an object is referred from, I think it's
still useful for debugging possible false negatives, so I'll leave it
in.

Thanks.

-- 
Catalin

Re: Leaks in trace reported by kmemleak

[Zdenek Kabelac]

2009/10/19 Catalin Marinas <catalin.marinas@arm.com>:
> On Mon, 2009-10-19 at 13:00 +0100, Catalin Marinas wrote:
>> On Mon, 2009-10-19 at 11:15 +0200, Zdenek Kabelac wrote:
>> > What is however interesting is the false positive leak for
>> > dma_debug_init(). Which is sometimes listed and sometimes not - the
>> > memory is allocated just once in the code during boot, so it's strange
>> > that pointers to that area are sometimes out of kmemleak scan.
>>
>> A workaround I had in the past was to not report an object unless it was
>> found as a leak in two consecutive scans. I should probably reinstate
>> this feature (could be optimised to use a second prio_tree containing
>> only objects found as leaks).
>
> OK, I re-added a form of this to the kmemleak.git tree and simplified
> the scanning logic (meant initially to reduce the false positives). Now,
> for an object to be reported, it needs to be found as leak during two
> consecutive scans (this works around pointer moving from a structure to
> a different one which was already scanned).
>
> If you have time, could you please give it a try and see whether you
> still get transient false positives?
>
> As for the patch showing where an object is referred from, I think it's
> still useful for debugging possible false negatives, so I'll leave it
> in.
>
> Thanks.

I've tested your git with updates - and here is my experience:

I'm still able to get FP leaks printed even with the print of
more-then-once appearanc.

i.e. here is output of dump=

kmemleak: Object 0xffff8801390fd300 (size 192):
kmemleak:   comm "swapper", pid 1, jiffies 4294877823
kmemleak:   min_count = 1
kmemleak:   count = 0
kmemleak:   flags = 0xb
kmemleak:   backtrace:
     [<ffffffff8140e986>] kmemleak_alloc+0x26/0x50
     [<ffffffff811269f1>] kmem_cache_alloc_notrace+0xc1/0x140
     [<ffffffff8127243a>] dma_debug_init+0x23a/0x3a0
     [<ffffffff81864a37>] pci_iommu_init+0xe/0x28
     [<ffffffff8100904c>] do_one_initcall+0x3c/0x1d0
     [<ffffffff8185f4e6>] kernel_init+0x150/0x1a6
     [<ffffffff8100d21a>] child_rip+0xa/0x20
     [<ffffffffffffffff>] 0xffffffffffffffff


i think it would be useful to print count of leak appearance - i.e.
leak was seen during XX scans.
Also jiffies might be eventually more readable via data/time - but
this can be preprocessed via script.
So it still looks like some memory areas are missing in scan.

I think new interesting 'probably real leak is being printed from
cpufreq during pm-suspend - it seems to be repeatable.

unreferenced object 0xffff880139bdfc10 (size 8):
  comm "swapper", pid 1, jiffies 4294878042
  hex dump (first 8 bytes):
    63 70 75 66 72 65 71 00                          cpufreq.
  backtrace:
    [<ffffffff8140e986>] kmemleak_alloc+0x26/0x50
    [<ffffffff81127953>] __kmalloc_track_caller+0x143/0x230
    [<ffffffff81104395>] kstrdup+0x45/0x80
    [<ffffffff8119e2cc>] sysfs_new_dirent+0x10c/0x120
    [<ffffffff8119f132>] create_dir+0x42/0xb0
    [<ffffffff8119f1d9>] sysfs_create_dir+0x39/0x50
    [<ffffffff8126048b>] kobject_add_internal+0x11b/0x210
    [<ffffffff812606a8>] kobject_add_varg+0x38/0x60
    [<ffffffff81260723>] kobject_init_and_add+0x53/0x70
    [<ffffffff81373552>] cpufreq_add_dev_interface+0x42/0x220
    [<ffffffff81373cee>] cpufreq_add_dev+0x27e/0x410
    [<ffffffff8130e636>] sysdev_driver_register+0xa6/0x130
    [<ffffffff81371d38>] cpufreq_register_driver+0x88/0x160
    [<ffffffff81867c8c>] acpi_cpufreq_init+0x91/0xc7
    [<ffffffff8100904c>] do_one_initcall+0x3c/0x1d0
    [<ffffffff8185f4e6>] kernel_init+0x150/0x1a6

unreferenced object 0xffff8801350a5410 (size 80):
  comm "pm-suspend", pid 2841, jiffies 4296695092
  hex dump (first 32 bytes):
    04 00 00 00 00 00 00 00 00 50 0a 35 01 88 ff ff  .........P.5....
    00 00 00 00 00 00 00 00 28 58 20 3a 01 88 ff ff  ........(X :....
  backtrace:
    [<ffffffff8140e986>] kmemleak_alloc+0x26/0x50
    [<ffffffff81126c73>] kmem_cache_alloc+0x133/0x1c0
    [<ffffffff8119e201>] sysfs_new_dirent+0x41/0x120
    [<ffffffff8119f132>] create_dir+0x42/0xb0
    [<ffffffff8119f20b>] sysfs_create_subdir+0x1b/0x20
    [<ffffffff811a0508>] internal_create_group+0x58/0x1a0
    [<ffffffff811a0683>] sysfs_create_group+0x13/0x20
    [<ffffffff8137477a>] cpufreq_stat_notifier_policy+0xda/0x2b0
    [<ffffffff81424788>] notifier_call_chain+0x78/0xb0
    [<ffffffff8107f190>] __blocking_notifier_call_chain+0x60/0x90
    [<ffffffff8107f1d6>] blocking_notifier_call_chain+0x16/0x20
    [<ffffffff81373329>] __cpufreq_set_policy+0xc9/0x190
    [<ffffffff813736e3>] cpufreq_add_dev_interface+0x1d3/0x220
    [<ffffffff81373cee>] cpufreq_add_dev+0x27e/0x410
    [<ffffffff8141d244>] cpufreq_cpu_callback+0x71/0x7e
    [<ffffffff81424788>] notifier_call_chain+0x78/0xb0
.....


I've made also test with removal of as much modules as possible
(though for some reason some of them were kept in memory, because I
couldn't decrease module count to 0 - while nearly every userland task
was killed except for bash and mingetty


ipt_MASQUERADE          1823  1
iptable_nat             4228  1
nf_nat                 18462  2 ipt_MASQUERADE,iptable_nat
nf_conntrack_ipv4      12687  3 iptable_nat,nf_nat
nf_defrag_ipv4          1353  1 nf_conntrack_ipv4
nf_conntrack           72037  4
ipt_MASQUERADE,iptable_nat,nf_nat,nf_conntrack_ipv4
ip_tables              16520  1 iptable_nat
x_tables               20541  3 ipt_MASQUERADE,iptable_nat,ip_tables
sunrpc                221415  1
ipv6                  292258  10
binfmt_misc             7686  1
usbcore               168536  1


This left few other leaks - however because trace after module removal
is meaningless it's hard to say from where the leak comes from. Well -
how about adding new command    "echo resolve >debug/kmemleak". This
would resolve all backtraces - it would surely eat 'some' memory - but
it would give the usable trace for removed modules. I think lots' of
stack traces could eventually use some sort of heap - to avoid
duplicate resolving of same stack and keeping same strings in memory.


Anyway here are few leaks from i915 -

unreferenced object 0xffff8800bf15fba0 (size 544):
  comm "X", pid 2014, jiffies 4299475327
  hex dump (first 32 bytes):
    ff ff ff ff ff ff ff ff 40 db aa ba 00 88 ff ff  ........@.......
    00 df aa ba 00 88 ff ff c0 d0 aa ba 00 88 ff ff  ................
  backtrace:
    [<ffffffff8140e986>] kmemleak_alloc+0x26/0x50
    [<ffffffff81126c73>] kmem_cache_alloc+0x133/0x1c0
    [<ffffffff8125f43f>] idr_pre_get+0x5f/0x90
    [<ffffffffa03374cd>] drm_gem_handle_create+0x3d/0xb0 [drm]
    [<ffffffffa0379815>] i915_gem_create_ioctl+0x65/0xc0 [i915]
    [<ffffffffa0335f76>] drm_ioctl+0x176/0x390 [drm]
    [<ffffffff81143b9c>] vfs_ioctl+0x7c/0xa0
    [<ffffffff81143ce4>] do_vfs_ioctl+0x84/0x590
    [<ffffffff81144271>] sys_ioctl+0x81/0xa0
    [<ffffffff8100c11b>] system_call_fastpath+0x16/0x1b
    [<ffffffffffffffff>] 0xffffffffffffffff

Those are present also after i915 removal:

unreferenced object 0xffff880132f31760 (size 544):
  comm "X", pid 2014, jiffies 4294899254
  hex dump (first 32 bytes):
    ff ff ff df fe dd f5 9a 40 4e 34 30 01 88 ff ff  ........@N40....
    80 41 34 30 01 88 ff ff c0 46 34 30 01 88 ff ff  .A40.....F40....
  backtrace:
    [<ffffffff8140e986>] kmemleak_alloc+0x26/0x50
    [<ffffffff81126c73>] kmem_cache_alloc+0x133/0x1c0
    [<ffffffff8125f43f>] idr_pre_get+0x5f/0x90
    [<ffffffffa03374cd>] 0xffffffffa03374cd
    [<ffffffffa0379815>] 0xffffffffa0379815
    [<ffffffffa0335f76>] 0xffffffffa0335f76
    [<ffffffff81143b9c>] vfs_ioctl+0x7c/0xa0
    [<ffffffff81143ce4>] do_vfs_ioctl+0x84/0x590
    [<ffffffff81144271>] sys_ioctl+0x81/0xa0
    [<ffffffff8100c11b>] system_call_fastpath+0x16/0x1b
    [<ffffffffffffffff>] 0xffffffffffffffff


And one from  iwl3945:

unreferenced object 0xffff8801280f4900 (size 256):
  comm "events/0", pid 9, jiffies 4301085444
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
    00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
  backtrace:
    [<ffffffff8140e986>] kmemleak_alloc+0x26/0x50
    [<ffffffff81126c73>] kmem_cache_alloc+0x133/0x1c0
    [<ffffffff813891ea>] __alloc_skb+0x4a/0x180
    [<ffffffff8140b292>] wireless_send_event+0x1f2/0x410
    [<ffffffffa00fdeec>] ___cfg80211_scan_done+0xcc/0xf0 [cfg80211]
    [<ffffffffa00fdf3b>] __cfg80211_scan_done+0x2b/0x50 [cfg80211]
    [<ffffffff81073ada>] worker_thread+0x21a/0x400
    [<ffffffff810794a6>] kthread+0x96/0xa0
    [<ffffffff8100d21a>] child_rip+0xa/0x20
    [<ffffffffffffffff>] 0xffffffffffffffff

after removal of iwl3945:

unreferenced object 0xffff8801280f4900 (size 256):
  comm "events/0", pid 9, jiffies 4301085444
  hex dump (first 32 bytes):
    00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
    00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00  ................
  backtrace:
    [<ffffffff8140e986>] kmemleak_alloc+0x26/0x50
    [<ffffffff81126c73>] kmem_cache_alloc+0x133/0x1c0
    [<ffffffff813891ea>] __alloc_skb+0x4a/0x180
    [<ffffffff8140b292>] wireless_send_event+0x1f2/0x410
    [<ffffffffa00fdeec>] 0xffffffffa00fdeec
    [<ffffffffa00fdf3b>] 0xffffffffa00fdf3b
    [<ffffffff81073ada>] worker_thread+0x21a/0x400
    [<ffffffff810794a6>] kthread+0x96/0xa0
    [<ffffffff8100d21a>] child_rip+0xa/0x20
    [<ffffffffffffffff>] 0xffffffffffffffff


And could be matched because of   idr_pre_get()    vfs_ioctl()  usage pattern

I'll try to look later in the code myself.

Zdenek

Re: Leaks in trace reported by kmemleak

[Catalin Marinas]

On Tue, 2009-10-20 at 11:58 +0200, Zdenek Kabelac wrote:
> I've tested your git with updates - and here is my experience:
> 
> I'm still able to get FP leaks printed even with the print of
> more-then-once appearanc.
> 
> i.e. here is output of dump=
> 
> kmemleak: Object 0xffff8801390fd300 (size 192):
> kmemleak:   comm "swapper", pid 1, jiffies 4294877823
> kmemleak:   min_count = 1
> kmemleak:   count = 0
> kmemleak:   flags = 0xb
> kmemleak:   backtrace:
>      [<ffffffff8140e986>] kmemleak_alloc+0x26/0x50
>      [<ffffffff811269f1>] kmem_cache_alloc_notrace+0xc1/0x140
>      [<ffffffff8127243a>] dma_debug_init+0x23a/0x3a0
>      [<ffffffff81864a37>] pci_iommu_init+0xe/0x28
>      [<ffffffff8100904c>] do_one_initcall+0x3c/0x1d0
>      [<ffffffff8185f4e6>] kernel_init+0x150/0x1a6
>      [<ffffffff8100d21a>] child_rip+0xa/0x20
>      [<ffffffffffffffff>] 0xffffffffffffffff

I investigated this a bit more (similar to the debug_objects false
positives, they behave similarly). I can reproduce the debug_objects
false positive by running ltp in parallel with "echo scan".

Basically, there is a free list of debug objects with the hlist_head
usually in the data section (obj_pool) and scanned by kmemleak. The
kernel retrieves one element from the top of the list when required to
allocate one. The scenario is something like below:

     1. kmemleak scans the data section and the free_entries variable
        points to an object A (which also points to object B). The
        object A is added to the gray list for scanning (object A not a
        leak)
     2. kernel removes object A from the list also modifying (maybe
        zeroing) the hlist_node structure inside object A. The
        hlist_head now points to object B
     3. kmemleak eventually reaches object A during scanning but it
        doesn't point to object B anymore, hence B becomes a suspected
        leak

The scenario above can happen during more than one consecutive scans for
the same objects at the tail of the list, especially when objects at the
head of the list are removed and added frequently. While it is harder to
show false positive if we require a minimum number of consecutive scans,
it is still possible to show them.

I'll have to think about other ways to avoid this kind of false
positives than requiring a minimum number of scans (and not locking the
system during a scan).

> Also jiffies might be eventually more readable via data/time - but
> this can be preprocessed via script.

I think that would be useful as well. I'll keep it in mind.

> Anyway here are few leaks from i915 -
> 
> unreferenced object 0xffff8800bf15fba0 (size 544):
>   comm "X", pid 2014, jiffies 4299475327
>   hex dump (first 32 bytes):
>     ff ff ff ff ff ff ff ff 40 db aa ba 00 88 ff ff  ........@.......
>     00 df aa ba 00 88 ff ff c0 d0 aa ba 00 88 ff ff  ................
>   backtrace:
>     [<ffffffff8140e986>] kmemleak_alloc+0x26/0x50
>     [<ffffffff81126c73>] kmem_cache_alloc+0x133/0x1c0
>     [<ffffffff8125f43f>] idr_pre_get+0x5f/0x90
>     [<ffffffffa03374cd>] drm_gem_handle_create+0x3d/0xb0 [drm]
>     [<ffffffffa0379815>] i915_gem_create_ioctl+0x65/0xc0 [i915]
>     [<ffffffffa0335f76>] drm_ioctl+0x176/0x390 [drm]
>     [<ffffffff81143b9c>] vfs_ioctl+0x7c/0xa0
>     [<ffffffff81143ce4>] do_vfs_ioctl+0x84/0x590
>     [<ffffffff81144271>] sys_ioctl+0x81/0xa0
>     [<ffffffff8100c11b>] system_call_fastpath+0x16/0x1b
>     [<ffffffffffffffff>] 0xffffffffffffffff
> 
> Those are present also after i915 removal:
> 
> unreferenced object 0xffff880132f31760 (size 544):
>   comm "X", pid 2014, jiffies 4294899254
>   hex dump (first 32 bytes):
>     ff ff ff df fe dd f5 9a 40 4e 34 30 01 88 ff ff  ........@N40....
>     80 41 34 30 01 88 ff ff c0 46 34 30 01 88 ff ff  .A40.....F40....
>   backtrace:
>     [<ffffffff8140e986>] kmemleak_alloc+0x26/0x50
>     [<ffffffff81126c73>] kmem_cache_alloc+0x133/0x1c0
>     [<ffffffff8125f43f>] idr_pre_get+0x5f/0x90
>     [<ffffffffa03374cd>] 0xffffffffa03374cd
>     [<ffffffffa0379815>] 0xffffffffa0379815
>     [<ffffffffa0335f76>] 0xffffffffa0335f76
>     [<ffffffff81143b9c>] vfs_ioctl+0x7c/0xa0
>     [<ffffffff81143ce4>] do_vfs_ioctl+0x84/0x590
>     [<ffffffff81144271>] sys_ioctl+0x81/0xa0
>     [<ffffffff8100c11b>] system_call_fastpath+0x16/0x1b
>     [<ffffffffffffffff>] 0xffffffffffffffff

I got this as well even without removing modules. IIRC, I reported it on
the list some time ago.

-- 
Catalin

Re: Leaks in trace reported by kmemleak

[Catalin Marinas]

Hi Zdenek,

On Tue, 2009-10-20 at 11:58 +0200, Zdenek Kabelac wrote:
> I've tested your git with updates - and here is my experience:
> 
> I'm still able to get FP leaks printed even with the print of
> more-then-once appearanc.

I updated the kmemleak.git tree and in my tests it reduced the false
positives significantly. I dropped the two-pass scanning patch and I
added a new one which checks whether objects were modified since the
previous leak suspicion and only report them if unmodified (using
csum_partial for checksum calculation). This works well with linked
lists since list deletion modifies the prev/next pointers of those left
in the list (like in the debug_objects case).

> Also jiffies might be eventually more readable via data/time - but
> this can be preprocessed via script.

Jiffies is still useful to ensure it's the same object or a new one
allocated in the same function (and possibly false positive). I added
another bit of information - the age of an object in seconds.msecs.

-- 
Catalin