2009-06-23 22:25:32

by Sergey Senozhatsky

[permalink] [raw]
Subject: kmemleak: Early log buffer exceeded

Hello.
I can see on my both machines

[ 0.000135] kmemleak: Early log buffer exceeded
[ 0.000140] Pid: 0, comm: swapper Not tainted 2.6.30-dbginfo-nv-git19 #7
[ 0.000144] Call Trace:
[ 0.000153] [<c1418ecc>] ? printk+0x23/0x36
[ 0.000160] [<c10f7c12>] log_early+0xf2/0x110
[ 0.000165] [<c10f8788>] kmemleak_alloc+0x1f8/0x2c0
[ 0.000171] [<c10f28fb>] ? cache_alloc_debugcheck_after+0xeb/0x1e0
[ 0.000176] [<c10f496a>] ? __kmalloc+0xfa/0x240
[ 0.000182] [<c10761fc>] ? trace_hardirqs_on_caller+0x14c/0x1a0
[ 0.000187] [<c10f4a15>] __kmalloc+0x1a5/0x240
[ 0.000192] [<c10f4d8d>] ? alloc_arraycache+0x2d/0x80
[ 0.000198] [<c10f4d8d>] alloc_arraycache+0x2d/0x80
[ 0.000203] [<c10f4e7c>] do_tune_cpucache+0x9c/0x3a0
[ 0.000208] [<c10f5322>] enable_cpucache+0x42/0x110
[ 0.000215] [<c15ff7c4>] kmem_cache_init_late+0x32/0x82
[ 0.000221] [<c15e2995>] start_kernel+0x24c/0x366
[ 0.000226] [<c15e2517>] ? unknown_bootoption+0x0/0x1dd
[ 0.000231] [<c15e2088>] __init_begin+0x88/0xa1

mm/kmemleak.c
static struct early_log early_log[200];

static void log_early(int op_type, const void *ptr, size_t size,
int min_count, unsigned long offset, size_t length)
{
...
if (crt_early_log >= ARRAY_SIZE(early_log)) {
print Early log buffer exceeded;
call dump_stack, etc.

So, my questions are:
1. Is 200 really enough? Why 200 not 512, 1024 (for example)?
//If this has been already discussed - please point me.

2. When (crt_early_log >= ARRAY_SIZE(early_log)) == 1 we just can see stack.
Since we have "full" early_log maybe it'll be helpfull to see it?
//For example like at void __init kmemleak_init(void)

Sergey


2009-06-24 09:36:16

by Catalin Marinas

[permalink] [raw]
Subject: Re: kmemleak: Early log buffer exceeded

On Tue, 2009-06-23 at 22:26 +0100, Sergey Senozhatsky wrote:
> I can see on my both machines
>
> [ 0.000135] kmemleak: Early log buffer exceeded
[...]
> mm/kmemleak.c
> static struct early_log early_log[200];
>
> static void log_early(int op_type, const void *ptr, size_t size,
> int min_count, unsigned long offset, size_t length)
> {
> ...
> if (crt_early_log >= ARRAY_SIZE(early_log)) {
> print Early log buffer exceeded;
> call dump_stack, etc.
>
> So, my questions are:
> 1. Is 200 really enough? Why 200 not 512, 1024 (for example)?

It seems that in your case it isn't. It is fine on the machines I tested
it on but choosing this figure wasn't too scientific.

I initially had it bigger and marked with the __init attribute to free
it after initialisation but this was causing (harmless) section mismatch
warnings.

What kind of hardware do you have?

> 2. When (crt_early_log >= ARRAY_SIZE(early_log)) == 1 we just can see stack.
> Since we have "full" early_log maybe it'll be helpfull to see it?

I recall allocating this dynamically didn't work properly but I'll give
it another try. Otherwise, I can make it configurable and print a better
message (probably without the stack dump).

--
Catalin

2009-06-24 10:06:49

by Sergey Senozhatsky

[permalink] [raw]
Subject: Re: kmemleak: Early log buffer exceeded

On (06/24/09 10:35), Catalin Marinas wrote:
> > So, my questions are:
> > 1. Is 200 really enough? Why 200 not 512, 1024 (for example)?
>
> It seems that in your case it isn't. It is fine on the machines I tested
> it on but choosing this figure wasn't too scientific.
>
> I initially had it bigger and marked with the __init attribute to free
> it after initialisation but this was causing (harmless) section mismatch
> warnings.
>
Hello.

Why not configure it?

//EXAMPLE
config DEBUG_KMEMLEAK_EARLY_LOG_SIZE
int "Maximum early log entries"
range 200 2000
default "300"
depends on DEBUG_KMEMLEAK
help
Specify early_log size (200,400,etc.).

kmemleak.c
static struct early_log early_log[CONFIG_DEBUG_KMEMLEAK_EARLY_LOG_SIZE];

(Well, CONFIG_DEBUG_KMEMLEAK_EARLY_LOG_SIZE is a bit ugly.)


> What kind of hardware do you have?
>
Most of time - ASUS F3Jc laptop.


> > 2. When (crt_early_log >= ARRAY_SIZE(early_log)) == 1 we just can see stack.
> > Since we have "full" early_log maybe it'll be helpfull to see it?
>
> I recall allocating this dynamically didn't work properly but I'll give
> it another try. Otherwise, I can make it configurable and print a better
> message (probably without the stack dump).
>
> --
> Catalin
>

Sergey

2009-06-24 13:18:50

by Catalin Marinas

[permalink] [raw]
Subject: Re: kmemleak: Early log buffer exceeded

On Wed, 2009-06-24 at 13:08 +0300, Sergey Senozhatsky wrote:
> On (06/24/09 10:35), Catalin Marinas wrote:
> > > So, my questions are:
> > > 1. Is 200 really enough? Why 200 not 512, 1024 (for example)?
> >
> > It seems that in your case it isn't. It is fine on the machines I tested
> > it on but choosing this figure wasn't too scientific.
> >
> > I initially had it bigger and marked with the __init attribute to free
> > it after initialisation but this was causing (harmless) section mismatch
> > warnings.
>
> Why not configure it?

Yes, that's the best approach for now. As for dynamic allocation,
alloc_bootmem is the only option but it needs more testing to make sure
it doesn't fail in certain circumstances.

> (Well, CONFIG_DEBUG_KMEMLEAK_EARLY_LOG_SIZE is a bit ugly.)

I couldn't come up with a better one either. Here's the patch:


kmemleak: Allow the early log buffer to be configurable.

From: Catalin Marinas <[email protected]>

Kmemleak needs to track all the memory allocations but some of these
happen before kmemleak is initialised. These are stored in an internal
buffer which may be exceeded in some kernel configurations. This patch
adds a configuration option with a default value of 300 and removes the
stack dump when the kmemleak early log buffer is exceeded.

Signed-off-by: Catalin Marinas <[email protected]>
---
lib/Kconfig.debug | 12 ++++++++++++
mm/kmemleak.c | 5 +++--
2 files changed, 15 insertions(+), 2 deletions(-)

diff --git a/lib/Kconfig.debug b/lib/Kconfig.debug
index 4c32b1a..5cba26f 100644
--- a/lib/Kconfig.debug
+++ b/lib/Kconfig.debug
@@ -359,6 +359,18 @@ config DEBUG_KMEMLEAK
In order to access the kmemleak file, debugfs needs to be
mounted (usually at /sys/kernel/debug).

+config DEBUG_KMEMLEAK_EARLY_LOG_SIZE
+ int "Maximum kmemleak early log entries"
+ depends on DEBUG_KMEMLEAK
+ range 200 2000
+ default 300
+ help
+ Kmemleak must track all the memory allocations to avoid
+ reporting false positives. Since memory may be allocated or
+ freed before kmemleak is initialised, an early log buffer is
+ used to store these actions. If kmemleak reports "early log
+ buffer exceeded", please increase this value.
+
config DEBUG_KMEMLEAK_TEST
tristate "Simple test for the kernel memory leak detector"
depends on DEBUG_KMEMLEAK
diff --git a/mm/kmemleak.c b/mm/kmemleak.c
index c96f2c8..17096d1 100644
--- a/mm/kmemleak.c
+++ b/mm/kmemleak.c
@@ -235,7 +235,7 @@ struct early_log {
};

/* early logging buffer and current position */
-static struct early_log early_log[200];
+static struct early_log early_log[CONFIG_DEBUG_KMEMLEAK_EARLY_LOG_SIZE];
static int crt_early_log;

static void kmemleak_disable(void);
@@ -696,7 +696,8 @@ static void log_early(int op_type, const void *ptr, size_t size,
struct early_log *log;

if (crt_early_log >= ARRAY_SIZE(early_log)) {
- kmemleak_stop("Early log buffer exceeded\n");
+ pr_warning("Early log buffer exceeded\n");
+ kmemleak_disable();
return;
}


Thanks.

--
Catalin