On 3/7/2018 11:52 PM, Matthew Wilcox wrote:
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.
This is exactly what I was thinking. But looking up 'age' is easy
compared to 'when' and this seems required as from Christopher's
reply. So, will raise new patch cleaning commit message a bit.
Chintan
--
Qualcomm India Private Limited, on behalf of Qualcomm Innovation Center,
Inc. is a member of the Code Aurora Forum, a Linux Foundation
Collaborative Project
