From: Matthew Brost <matthew.brost@intel.com>
To: Nirmoy Das <nirmoy.das@linux.intel.com>
Cc: Nirmoy Das <nirmoy.das@intel.com>,
<intel-xe@lists.freedesktop.org>,
Rodrigo Vivi <rodrigo.vivi@intel.com>
Subject: Re: [PATCH] drm/xe/pm: Add trace for pm functions
Date: Wed, 17 Jul 2024 13:25:07 +0000 [thread overview]
Message-ID: <ZpfGMyHDReGmvwrP@DUT025-TGLU.fm.intel.com> (raw)
In-Reply-To: <3ba40443-12cf-444a-b2b1-1d858f3e8294@linux.intel.com>
On Wed, Jul 17, 2024 at 03:08:02PM +0200, Nirmoy Das wrote:
>
> On 7/17/2024 2:40 PM, Matthew Brost wrote:
> > On Wed, Jul 17, 2024 at 01:29:08PM +0200, Nirmoy Das wrote:
> > > Add trace for xe pm function for better debuggability.
> > >
> > > Cc: Matthew Brost <matthew.brost@intel.com>
> > > Cc: Rodrigo Vivi <rodrigo.vivi@intel.com>
> > > Signed-off-by: Nirmoy Das <nirmoy.das@intel.com>
> > > ---
> > > Example Output:
> > > <idle>-0 [004] d.h2. 3821.138392: xe_pm_runtime_put: dev=0000:00:02.0 caller_function=xe_guc_ct_fast_path+0x2e4/0x430 [xe]
> > > kworker/u32:0-53314 [001] ..... 3821.138411: xe_pm_runtime_put: dev=0000:00:02.0 caller_function=receive_g2h+0x2cc/0x350 [xe]
> > > <idle>-0 [004] d.h2. 3821.138439: xe_pm_runtime_put: dev=0000:00:02.0 caller_function=xe_guc_ct_fast_path+0x2e4/0x430 [xe]
> > > kworker/u32:0-53314 [001] ..... 3821.138443: xe_pm_runtime_put: dev=0000:00:02.0 caller_function=receive_g2h+0x2cc/0x350 [xe]
> > > kworker/0:1-9 [000] ..... 3821.138474: xe_pm_runtime_put: dev=0000:00:02.0 caller_function=xe_ggtt_remove_node+0x1f6/0x280 [xe]
> > > kworker/0:1-9 [000] ..... 3821.138495: xe_pm_runtime_put: dev=0000:00:02.0 caller_function=__guc_exec_queue_fini_async+0x1b3/0x350 [xe]
> > > kworker/0:0-21730 [000] ..... 3821.138503: xe_pm_runtime_put: dev=0000:00:02.0 caller_function=xe_ggtt_remove_node+0x1f6/0x280 [xe]
> > > kworker/0:0-21730 [000] ..... 3821.138540: xe_pm_runtime_put: dev=0000:00:02.0 caller_function=__guc_exec_queue_fini_async+0x1b3/0x350 [xe]
> > Looks very helpful, I didn't know exactly how to get caller function in
> > output like this, cool.
> >
> > > kworker/u33:0-25711 [002] ..... 3821.138601: xe_vm_free: dev=0000:00:02.0, vm=ffff88811185a000, asid=0x00004
> > > kworker/1:6-21907 [001] ..... 3822.308942: xe_pm_runtime_suspend: dev=0000:00:02.0 caller_function=xe_pci_runtime_suspend+0x3f/0x120 [xe]
> > > kworker/1:6-21907 [001] ..... 3822.309550: xe_exec_queue_stop: dev=0000:00:02.0, 3:0x2, gt=0, width=1, guc_id=0, guc_state=0x0, flags=0x13
> > >
> > > drivers/gpu/drm/xe/xe_pm.c | 7 ++++++
> > > drivers/gpu/drm/xe/xe_trace.h | 47 +++++++++++++++++++++++++++++++++++
> > > 2 files changed, 54 insertions(+)
> > >
> > > diff --git a/drivers/gpu/drm/xe/xe_pm.c b/drivers/gpu/drm/xe/xe_pm.c
> > > index de3b5df65e48..a38452ccf033 100644
> > > --- a/drivers/gpu/drm/xe/xe_pm.c
> > > +++ b/drivers/gpu/drm/xe/xe_pm.c
> > > @@ -20,6 +20,7 @@
> > > #include "xe_guc.h"
> > > #include "xe_irq.h"
> > > #include "xe_pcode.h"
> > > +#include "xe_trace.h"
> > > #include "xe_wa.h"
> > > /**
> > > @@ -87,6 +88,7 @@ int xe_pm_suspend(struct xe_device *xe)
> > > int err;
> > > drm_dbg(&xe->drm, "Suspending device\n");
> > > + trace_xe_pm_suspend(xe, __builtin_return_address(0));
> > > for_each_gt(gt, xe, id)
> > > xe_gt_suspend_prepare(gt);
> > > @@ -131,6 +133,7 @@ int xe_pm_resume(struct xe_device *xe)
> > > int err;
> > > drm_dbg(&xe->drm, "Resuming device\n");
> > > + trace_xe_pm_resume(xe, __builtin_return_address(0));
> > > for_each_tile(tile, xe, id)
> > > xe_wa_apply_tile_workarounds(tile);
> > > @@ -326,6 +329,7 @@ int xe_pm_runtime_suspend(struct xe_device *xe)
> > > u8 id;
> > > int err = 0;
> > > + trace_xe_pm_runtime_suspend(xe, __builtin_return_address(0));
> > > /* Disable access_ongoing asserts and prevent recursive pm calls */
> > > xe_pm_write_callback_task(xe, current);
> > > @@ -399,6 +403,7 @@ int xe_pm_runtime_resume(struct xe_device *xe)
> > > u8 id;
> > > int err = 0;
> > > + trace_xe_pm_runtime_resume(xe, __builtin_return_address(0));
> > > /* Disable access_ongoing asserts and prevent recursive pm calls */
> > > xe_pm_write_callback_task(xe, current);
> > > @@ -463,6 +468,7 @@ static void pm_runtime_lockdep_prime(void)
> > > */
> > > void xe_pm_runtime_get(struct xe_device *xe)
> > > {
> > > + trace_xe_pm_runtime_get(xe, __builtin_return_address(0));
> > > pm_runtime_get_noresume(xe->drm.dev);
> > > if (xe_pm_read_callback_task(xe) == current)
> > > @@ -478,6 +484,7 @@ void xe_pm_runtime_get(struct xe_device *xe)
> > > */
> > > void xe_pm_runtime_put(struct xe_device *xe)
> > > {
> > > + trace_xe_pm_runtime_put(xe, __builtin_return_address(0));
> > > if (xe_pm_read_callback_task(xe) == current) {
> > > pm_runtime_put_noidle(xe->drm.dev);
> > > } else {
> > > diff --git a/drivers/gpu/drm/xe/xe_trace.h b/drivers/gpu/drm/xe/xe_trace.h
> > > index baba14fb1e32..73fe28f92d48 100644
> > > --- a/drivers/gpu/drm/xe/xe_trace.h
> > > +++ b/drivers/gpu/drm/xe/xe_trace.h
> > > @@ -369,6 +369,53 @@ TRACE_EVENT(xe_reg_rw,
> > > (u32)(__entry->val >> 32))
> > > );
> > > +DECLARE_EVENT_CLASS(xe_pm_runtime,
> > > + TP_PROTO(struct xe_device *xe, void *caller),
> > > + TP_ARGS(xe, caller),
> > > +
> > > + TP_STRUCT__entry(
> > > + __string(dev, __dev_name_xe(xe))
> > > + __field(void *, caller)
> > > + ),
> > > +
> > > + TP_fast_assign(
> > > + __assign_str(dev);
> > > + __entry->caller = caller;
> > Does it work drop the 'void *caller' argument and do this?
> >
> > __entry->caller = __builtin_return_address(0);
> >
> > Unsure if that will produce the correct output though but worth checking
> > on.
>
> I tried that 1st but it didn't go well:
>
> xe_exec_store-86116 [001] ..... 9013.365684: xe_pm_runtime_put:
> dev=0000:00:02.0 caller_function=xe_pm_runtime_put+0x1b1/0x300 [xe]
> xe_exec_store-86116 [001] ..... 9013.365745: xe_pm_runtime_get_ioctl:
> dev=0000:00:02.0 caller_function=xe_pm_runtime_get_ioctl+0x194/0x240 [xe]
>
Ah, yes. That makes sense. Looks good as is then.
Matt
> >
> > > + ),
> > > +
> > > + TP_printk("dev=%s caller_function=%pS", __get_str(dev), __entry->caller)
> > > +);
> > > +
> > > +DEFINE_EVENT(xe_pm_runtime, xe_pm_runtime_get,
> > > + TP_PROTO(struct xe_device *xe, void *caller),
> > > + TP_ARGS(xe, caller)
> > > +);
> > > +
> > > +DEFINE_EVENT(xe_pm_runtime, xe_pm_runtime_put,
> > > + TP_PROTO(struct xe_device *xe, void *caller),
> > > + TP_ARGS(xe, caller)
> > Nit the alignment looks off here.
> >
> > > +);
> > > +
> > > +DEFINE_EVENT(xe_pm_runtime, xe_pm_resume,
> > > + TP_PROTO(struct xe_device *xe, void *caller),
> > > + TP_ARGS(xe, caller)
> > > +);
> > > +
> > > +DEFINE_EVENT(xe_pm_runtime, xe_pm_suspend,
> > > + TP_PROTO(struct xe_device *xe, void *caller),
> > > + TP_ARGS(xe, caller)
> > > +);
> > > +
> > > +DEFINE_EVENT(xe_pm_runtime, xe_pm_runtime_resume,
> > > + TP_PROTO(struct xe_device *xe, void *caller),
> > > + TP_ARGS(xe, caller)
> > > +);
> > > +
> > > +DEFINE_EVENT(xe_pm_runtime, xe_pm_runtime_suspend,
> > > + TP_PROTO(struct xe_device *xe, void *caller),
> > > + TP_ARGS(xe, caller)
> > Nit the alignment looks off here.
> >
> > Also a few other look off in patchworks too, double check on all of
> > these.
>
>
> I accidentally used vim's auto indent on portion of code and even ignored
> checkpatch's warning thinking
>
> it must be because of existing tracing code. I will resend soon.
>
>
> Regards,
>
> Nirmoy
>
> > Matt
> >
> > > +);
> > > +
> > > #endif
> > > /* This part must be outside protection */
> > > --
> > > 2.42.0
> > >
next prev parent reply other threads:[~2024-07-17 13:26 UTC|newest]
Thread overview: 12+ messages / expand[flat|nested] mbox.gz Atom feed top
2024-07-17 11:29 [PATCH] drm/xe/pm: Add trace for pm functions Nirmoy Das
2024-07-17 11:51 ` ✓ CI.Patch_applied: success for " Patchwork
2024-07-17 11:51 ` ✗ CI.checkpatch: warning " Patchwork
2024-07-17 11:53 ` ✓ CI.KUnit: success " Patchwork
2024-07-17 12:04 ` ✓ CI.Build: " Patchwork
2024-07-17 12:07 ` ✓ CI.Hooks: " Patchwork
2024-07-17 12:08 ` ✓ CI.checksparse: " Patchwork
2024-07-17 12:32 ` ✓ CI.BAT: " Patchwork
2024-07-17 12:40 ` [PATCH] " Matthew Brost
2024-07-17 13:08 ` Nirmoy Das
2024-07-17 13:25 ` Matthew Brost [this message]
2024-07-17 15:42 ` ✗ CI.FULL: failure for " Patchwork
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=ZpfGMyHDReGmvwrP@DUT025-TGLU.fm.intel.com \
--to=matthew.brost@intel.com \
--cc=intel-xe@lists.freedesktop.org \
--cc=nirmoy.das@intel.com \
--cc=nirmoy.das@linux.intel.com \
--cc=rodrigo.vivi@intel.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 a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox