* 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 19:36 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).