All of lore.kernel.org
 help / color / mirror / Atom feed
From: Matthew Wilcox <willy@infradead.org>
To: Christopher Lameter <cl@linux.com>
Cc: Chintan Pandya <cpandya@codeaurora.org>,
	penberg@kernel.org, rientjes@google.com, iamjoonsoo.kim@lge.com,
	akpm@linux-foundation.org, linux-mm@kvack.org,
	linux-kernel@vger.kernel.org
Subject: Re: [PATCH] slub: Fix misleading 'age' in verbose slub prints
Date: Wed, 7 Mar 2018 10:22:12 -0800	[thread overview]
Message-ID: <20180307182212.GA23411@bombadil.infradead.org> (raw)
In-Reply-To: <alpine.DEB.2.20.1803071212150.6373@nuc-kabylake>

On Wed, Mar 07, 2018 at 12:13:56PM -0600, Christopher Lameter wrote:
> On Wed, 7 Mar 2018, Chintan Pandya wrote:
> > In this case, object got freed later but 'age' shows
> > otherwise. This could be because, while printing
> > this info, we print allocation traces first and
> > free traces thereafter. In between, if we get schedule
> > out, (jiffies - t->when) could become meaningless.
> 
> Ok then get the jiffies earlier?
> 
> > So, simply print when the object was allocated/freed.
> 
> The tick value may not related to anything in the logs that is why the
> "age" is there. How do I know how long ago the allocation was if I look at
> the log and only see long and large number of ticks since bootup?

I missed that the first read-through too.  The trick is that there are two printks:

[ 6044.170804] INFO: Allocated in binder_transaction+0x4b0/0x2448 age=731 cpu=3 pid=5314
...
[ 6044.216696] INFO: Freed in binder_free_transaction+0x2c/0x58 age=735 cpu=6 pid=2079

If you print the raw value, then you can do the subtraction yourself;
if you've subtracted it from jiffies each time, you've at least introduced
jitter, and possibly enough jitter to confuse and mislead.

WARNING: multiple messages have this Message-ID (diff)
From: Matthew Wilcox <willy@infradead.org>
To: Christopher Lameter <cl@linux.com>
Cc: Chintan Pandya <cpandya@codeaurora.org>,
	penberg@kernel.org, rientjes@google.com, iamjoonsoo.kim@lge.com,
	akpm@linux-foundation.org, linux-mm@kvack.org,
	linux-kernel@vger.kernel.org
Subject: Re: [PATCH] slub: Fix misleading 'age' in verbose slub prints
Date: Wed, 7 Mar 2018 10:22:12 -0800	[thread overview]
Message-ID: <20180307182212.GA23411@bombadil.infradead.org> (raw)
In-Reply-To: <alpine.DEB.2.20.1803071212150.6373@nuc-kabylake>

On Wed, Mar 07, 2018 at 12:13:56PM -0600, Christopher Lameter wrote:
> On Wed, 7 Mar 2018, Chintan Pandya wrote:
> > In this case, object got freed later but 'age' shows
> > otherwise. This could be because, while printing
> > this info, we print allocation traces first and
> > free traces thereafter. In between, if we get schedule
> > out, (jiffies - t->when) could become meaningless.
> 
> Ok then get the jiffies earlier?
> 
> > So, simply print when the object was allocated/freed.
> 
> The tick value may not related to anything in the logs that is why the
> "age" is there. How do I know how long ago the allocation was if I look at
> the log and only see long and large number of ticks since bootup?

I missed that the first read-through too.  The trick is that there are two printks:

[ 6044.170804] INFO: Allocated in binder_transaction+0x4b0/0x2448 age=731 cpu=3 pid=5314
...
[ 6044.216696] INFO: Freed in binder_free_transaction+0x2c/0x58 age=735 cpu=6 pid=2079

If you print the raw value, then you can do the subtraction yourself;
if you've subtracted it from jiffies each time, you've at least introduced
jitter, and possibly enough jitter to confuse and mislead.

--
To unsubscribe, send a message with 'unsubscribe linux-mm' in
the body to majordomo@kvack.org.  For more info on Linux MM,
see: http://www.linux-mm.org/ .
Don't email: <a href=mailto:"dont@kvack.org"> email@kvack.org </a>

  reply	other threads:[~2018-03-07 18:22 UTC|newest]

Thread overview: 8+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2018-03-07 11:47 [PATCH] slub: Fix misleading 'age' in verbose slub prints Chintan Pandya
2018-03-07 11:47 ` Chintan Pandya
2018-03-07 18:13 ` Christopher Lameter
2018-03-07 18:13   ` Christopher Lameter
2018-03-07 18:22   ` Matthew Wilcox [this message]
2018-03-07 18:22     ` Matthew Wilcox
2018-03-08  6:51     ` Chintan Pandya
2018-03-08 18:09       ` Christopher Lameter

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20180307182212.GA23411@bombadil.infradead.org \
    --to=willy@infradead.org \
    --cc=akpm@linux-foundation.org \
    --cc=cl@linux.com \
    --cc=cpandya@codeaurora.org \
    --cc=iamjoonsoo.kim@lge.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=linux-mm@kvack.org \
    --cc=penberg@kernel.org \
    --cc=rientjes@google.com \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body. 
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.