linux-mm.kvack.org archive mirror
 help / color / mirror / Atom feed
* Profiling execution time for __alloc_pages_nodemask
@ 2021-05-10 14:57 Shivank Garg
  2021-05-10 15:01 ` David Hildenbrand
  2021-05-11  0:00 ` Yang Shi
  0 siblings, 2 replies; 6+ messages in thread
From: Shivank Garg @ 2021-05-10 14:57 UTC (permalink / raw)
  To: linux-kernel, linux-mm, akpm, gregkh, sergey.senozhatsky, pmladek, david

Hi Everyone!

I want to profile the time taken to execute the __alloc_pages_nodemask
for different linux configurations/parameters.
To measure the execution time, I use the ktime_get() apis. I get the
ktime_get() on the top, and I want to do ktime_sub(ktime_get(),ktime)
and record it in a tracepoint.
However, the patch on implementation prevents the kernel from booting
up. I debugged the bug to find out that the issue recurs on adding
ktime_get() inside the __alloc_pages_nodemask path. So, that the
kernel fails to boot up ( and show the blank screen without any logs )
I'm using the Linux kernel 5.6.13 (5821a5593fa9f28eb6fcc95c35d00454d9bb8624)

Is it an expected behavior? or a BUG? Has anyone else faced the same issue?

Can you please suggest, what would be a good way to measure execution
time for page allocation (if not ktime_get)

Stay Safe!
Best Regards,
Shivank Garg
Open-Source Enthusiast and Student, IIT Kanpur


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Profiling execution time for __alloc_pages_nodemask
  2021-05-10 14:57 Profiling execution time for __alloc_pages_nodemask Shivank Garg
@ 2021-05-10 15:01 ` David Hildenbrand
  2021-05-11  0:00 ` Yang Shi
  1 sibling, 0 replies; 6+ messages in thread
From: David Hildenbrand @ 2021-05-10 15:01 UTC (permalink / raw)
  To: Shivank Garg, linux-kernel, linux-mm, akpm, gregkh,
	sergey.senozhatsky, pmladek

On 10.05.21 16:57, Shivank Garg wrote:
> Hi Everyone!
> 
> I want to profile the time taken to execute the __alloc_pages_nodemask
> for different linux configurations/parameters.
> To measure the execution time, I use the ktime_get() apis. I get the
> ktime_get() on the top, and I want to do ktime_sub(ktime_get(),ktime)
> and record it in a tracepoint.

Don't tracepoints already record a timestamp? It's bee a while since I 
worked with tracepoints ...

> However, the patch on implementation prevents the kernel from booting
> up. I debugged the bug to find out that the issue recurs on adding
> ktime_get() inside the __alloc_pages_nodemask path. So, that the
> kernel fails to boot up ( and show the blank screen without any logs )
> I'm using the Linux kernel 5.6.13 (5821a5593fa9f28eb6fcc95c35d00454d9bb8624)

Are you maybe calling ktime_get() too early during boot, where some 
subsystems are just about to be brought up?

> 
> Is it an expected behavior? or a BUG? Has anyone else faced the same issue?
> 
> Can you please suggest, what would be a good way to measure execution
> time for page allocation (if not ktime_get)

I could have sworn ordinary tracepoints would already give you a 
timestamp ...

-- 
Thanks,

David / dhildenb



^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Profiling execution time for __alloc_pages_nodemask
  2021-05-10 14:57 Profiling execution time for __alloc_pages_nodemask Shivank Garg
  2021-05-10 15:01 ` David Hildenbrand
@ 2021-05-11  0:00 ` Yang Shi
  2021-05-11  5:31   ` Shivank Garg
  1 sibling, 1 reply; 6+ messages in thread
From: Yang Shi @ 2021-05-11  0:00 UTC (permalink / raw)
  To: Shivank Garg
  Cc: Linux Kernel Mailing List, Linux MM, Andrew Morton, gregkh,
	sergey.senozhatsky, pmladek, David Hildenbrand

On Mon, May 10, 2021 at 7:57 AM Shivank Garg <shivankgarg98@gmail.com> wrote:
>
> Hi Everyone!
>
> I want to profile the time taken to execute the __alloc_pages_nodemask
> for different linux configurations/parameters.
> To measure the execution time, I use the ktime_get() apis. I get the
> ktime_get() on the top, and I want to do ktime_sub(ktime_get(),ktime)
> and record it in a tracepoint.
> However, the patch on implementation prevents the kernel from booting
> up. I debugged the bug to find out that the issue recurs on adding
> ktime_get() inside the __alloc_pages_nodemask path. So, that the
> kernel fails to boot up ( and show the blank screen without any logs )
> I'm using the Linux kernel 5.6.13 (5821a5593fa9f28eb6fcc95c35d00454d9bb8624)

Is there any reason that prevents you from using some advanced tools,
i.e. perf, bcc/bpftrace, etc? They are much simpler than adding
instrumentation in kernel.

>
> Is it an expected behavior? or a BUG? Has anyone else faced the same issue?
>
> Can you please suggest, what would be a good way to measure execution
> time for page allocation (if not ktime_get)
>
> Stay Safe!
> Best Regards,
> Shivank Garg
> Open-Source Enthusiast and Student, IIT Kanpur
>


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Profiling execution time for __alloc_pages_nodemask
  2021-05-11  0:00 ` Yang Shi
@ 2021-05-11  5:31   ` Shivank Garg
  2021-05-12  3:56     ` Yang Shi
  0 siblings, 1 reply; 6+ messages in thread
From: Shivank Garg @ 2021-05-11  5:31 UTC (permalink / raw)
  To: Yang Shi, David Hildenbrand
  Cc: Linux MM, Andrew Morton, Linux Kernel Mailing List, gregkh,
	sergey.senozhatsky, pmladek

>Are you maybe calling ktime_get() too early during boot, where some
>subsystems are just about to be brought up?

Thanks David, I guess this is the issue.

>Is there any reason that prevents you from using some advanced tools,
>i.e. perf, bcc/bpftrace, etc? They are much simpler than adding
>instrumentation in kernel.

Actually, I want to record the arguments for the memory allocator and
filter out the calls I don't need (which are creating noise).
For instance, I'm only interested in particular order and flags.

This is the reason I added my custom tracepoint, which theoretically
looked easy to implement without adding much overhead.

Thanks,
Shivank

On Tue, May 11, 2021 at 5:30 AM Yang Shi <shy828301@gmail.com> wrote:
>
> On Mon, May 10, 2021 at 7:57 AM Shivank Garg <shivankgarg98@gmail.com> wrote:
> >
> > Hi Everyone!
> >
> > I want to profile the time taken to execute the __alloc_pages_nodemask
> > for different linux configurations/parameters.
> > To measure the execution time, I use the ktime_get() apis. I get the
> > ktime_get() on the top, and I want to do ktime_sub(ktime_get(),ktime)
> > and record it in a tracepoint.
> > However, the patch on implementation prevents the kernel from booting
> > up. I debugged the bug to find out that the issue recurs on adding
> > ktime_get() inside the __alloc_pages_nodemask path. So, that the
> > kernel fails to boot up ( and show the blank screen without any logs )
> > I'm using the Linux kernel 5.6.13 (5821a5593fa9f28eb6fcc95c35d00454d9bb8624)
>
> Is there any reason that prevents you from using some advanced tools,
> i.e. perf, bcc/bpftrace, etc? They are much simpler than adding
> instrumentation in kernel.
>
> >
> > Is it an expected behavior? or a BUG? Has anyone else faced the same issue?
> >
> > Can you please suggest, what would be a good way to measure execution
> > time for page allocation (if not ktime_get)
> >
> > Stay Safe!
> > Best Regards,
> > Shivank Garg
> > Open-Source Enthusiast and Student, IIT Kanpur
> >


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Profiling execution time for __alloc_pages_nodemask
  2021-05-11  5:31   ` Shivank Garg
@ 2021-05-12  3:56     ` Yang Shi
  2021-05-12 17:39       ` Shivank Garg
  0 siblings, 1 reply; 6+ messages in thread
From: Yang Shi @ 2021-05-12  3:56 UTC (permalink / raw)
  To: Shivank Garg
  Cc: David Hildenbrand, Linux MM, Andrew Morton,
	Linux Kernel Mailing List, gregkh, sergey.senozhatsky, pmladek

On Mon, May 10, 2021 at 10:31 PM Shivank Garg <shivankgarg98@gmail.com> wrote:
>
> >Are you maybe calling ktime_get() too early during boot, where some
> >subsystems are just about to be brought up?
>
> Thanks David, I guess this is the issue.
>
> >Is there any reason that prevents you from using some advanced tools,
> >i.e. perf, bcc/bpftrace, etc? They are much simpler than adding
> >instrumentation in kernel.
>
> Actually, I want to record the arguments for the memory allocator and
> filter out the calls I don't need (which are creating noise).
> For instance, I'm only interested in particular order and flags.

BPF can do so too. You can either attach to kprobe or tracepoint, then
filter out the calls by the function's parameters or tracepoint's
fields.

>
> This is the reason I added my custom tracepoint, which theoretically
> looked easy to implement without adding much overhead.
>
> Thanks,
> Shivank
>
> On Tue, May 11, 2021 at 5:30 AM Yang Shi <shy828301@gmail.com> wrote:
> >
> > On Mon, May 10, 2021 at 7:57 AM Shivank Garg <shivankgarg98@gmail.com> wrote:
> > >
> > > Hi Everyone!
> > >
> > > I want to profile the time taken to execute the __alloc_pages_nodemask
> > > for different linux configurations/parameters.
> > > To measure the execution time, I use the ktime_get() apis. I get the
> > > ktime_get() on the top, and I want to do ktime_sub(ktime_get(),ktime)
> > > and record it in a tracepoint.
> > > However, the patch on implementation prevents the kernel from booting
> > > up. I debugged the bug to find out that the issue recurs on adding
> > > ktime_get() inside the __alloc_pages_nodemask path. So, that the
> > > kernel fails to boot up ( and show the blank screen without any logs )
> > > I'm using the Linux kernel 5.6.13 (5821a5593fa9f28eb6fcc95c35d00454d9bb8624)
> >
> > Is there any reason that prevents you from using some advanced tools,
> > i.e. perf, bcc/bpftrace, etc? They are much simpler than adding
> > instrumentation in kernel.
> >
> > >
> > > Is it an expected behavior? or a BUG? Has anyone else faced the same issue?
> > >
> > > Can you please suggest, what would be a good way to measure execution
> > > time for page allocation (if not ktime_get)
> > >
> > > Stay Safe!
> > > Best Regards,
> > > Shivank Garg
> > > Open-Source Enthusiast and Student, IIT Kanpur
> > >


^ permalink raw reply	[flat|nested] 6+ messages in thread

* Re: Profiling execution time for __alloc_pages_nodemask
  2021-05-12  3:56     ` Yang Shi
@ 2021-05-12 17:39       ` Shivank Garg
  0 siblings, 0 replies; 6+ messages in thread
From: Shivank Garg @ 2021-05-12 17:39 UTC (permalink / raw)
  To: Yang Shi
  Cc: David Hildenbrand, Linux MM, Andrew Morton,
	Linux Kernel Mailing List, gregkh, sergey.senozhatsky, pmladek

>> Actually, I want to record the arguments for the memory allocator and
>> filter out the calls I don't need (which are creating noise).
>> For instance, I'm only interested in particular order and flags.

>BPF can do so too. You can either attach to kprobe or tracepoint, then
>filter out the calls by the function's parameters or tracepoint's
>fields.

Thanks Yang for the suggestion, I'll try the BPF. Anyway my problem
was solved by the filter in custom tracepoints (for instance,
tracing/events/kmem/filter).

Also, I used trace_*_enabled() to first check if tracepoint is enabled
and take ktime_get() only after that. This solved my initial issue.

Thanks David, Yang and the Linux community for helping me identify my
issue and solve it.

Best Regards,
Shivank


^ permalink raw reply	[flat|nested] 6+ messages in thread

end of thread, other threads:[~2021-05-12 17:40 UTC | newest]

Thread overview: 6+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-05-10 14:57 Profiling execution time for __alloc_pages_nodemask Shivank Garg
2021-05-10 15:01 ` David Hildenbrand
2021-05-11  0:00 ` Yang Shi
2021-05-11  5:31   ` Shivank Garg
2021-05-12  3:56     ` Yang Shi
2021-05-12 17:39       ` Shivank Garg

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).