[PATCH] drm/xe/pm: Add trace for pm functions
Nirmoy Das
nirmoy.das at linux.intel.com
Wed Jul 17 13:08:02 UTC 2024
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 at intel.com>
>> Cc: Rodrigo Vivi <rodrigo.vivi at intel.com>
>> Signed-off-by: Nirmoy Das <nirmoy.das at 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]
>
>> + ),
>> +
>> + 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
>>
More information about the Intel-xe
mailing list