[Intel-gfx] [PATCH 1/2] drm/i915/gt: Add GT oriented dmesg output

[Tvrtko Ursulin]

On 07/11/2022 09:33, Tvrtko Ursulin wrote:
> 
> On 05/11/2022 01:03, Ceraolo Spurio, Daniele wrote:
>>
>>
>> On 11/4/2022 10:25 AM, John.C.Harrison at Intel.com wrote:
>>> From: John Harrison <John.C.Harrison at Intel.com>
>>>
>>> When trying to analyse bug reports from CI, customers, etc. it can be
>>> difficult to work out exactly what is happening on which GT in a
>>> multi-GT system. So add GT oriented debug/error message wrappers. If
>>> used instead of the drm_ equivalents, you get the same output but with
>>> a GT# prefix on it.
>>>
>>> Signed-off-by: John Harrison <John.C.Harrison at Intel.com>
>>
>> The only downside to this is that we'll print "GT0: " even on 
>> single-GT devices. We could introduce a gt->info.name and print that, 
>> so we could have it different per-platform, but IMO it's not worth the 
>> effort.
>>
>> Reviewed-by: Daniele Ceraolo Spurio <daniele.ceraolospurio at intel.com>
>>
>> I think it might be worth getting an ack from one of the maintainers 
>> to make sure we're all aligned on transitioning to these new logging 
>> macro for gt code.
> 
> Idea is I think a very good one. First I would suggest standardising to 
> lowercase GT in logs because:
> 
> $ grep "GT%" i915/ -r
> $ grep "gt%" i915/ -r
> i915/gt/intel_gt_sysfs.c:                                
> gt->i915->sysfs_gt, "gt%d", gt->info.id))
> i915/gt/intel_gt_sysfs.c:                "failed to initialize gt%d 
> sysfs root\n", gt->info.id);
> i915/gt/intel_gt_sysfs_pm.c:                     "failed to create gt%u 
> RC6 sysfs files (%pe)\n",
> i915/gt/intel_gt_sysfs_pm.c:                             "failed to 
> create gt%u RC6p sysfs files (%pe)\n",
> i915/gt/intel_gt_sysfs_pm.c:                     "failed to create gt%u 
> RPS sysfs files (%pe)",
> i915/gt/intel_gt_sysfs_pm.c:                     "failed to create gt%u 
> punit_req_freq_mhz sysfs (%pe)",
> i915/gt/intel_gt_sysfs_pm.c:                             "failed to 
> create gt%u throttle sysfs files (%pe)",
> i915/gt/intel_gt_sysfs_pm.c:                             "failed to 
> create gt%u media_perf_power_attrs sysfs (%pe)\n",
> i915/gt/intel_gt_sysfs_pm.c:                     "failed to add gt%u rps 
> defaults (%pe)\n",
> i915/i915_driver.c:                     drm_err(&gt->i915->drm, "gt%d: 
> intel_pcode_init failed %d\n", id, ret);
> i915/i915_hwmon.c:              snprintf(ddat_gt->name, 
> sizeof(ddat_gt->name), "i915_gt%u", i);
> 
> Then there is a question of naming. Are we okay with GT_XXX or, do we 
> want intel_gt_, or something completely different. I don't have a strong 
> opinion at the moment so I'll add some more folks to Cc.

There was a maintainer level mini-discussion on this topic which I will 
try to summarise.

Main contention point was the maintenance cost and generally an 
undesirable pattern of needing to add many subsystem/component/directory 
specific macros. Which then typically need extra flavours and so on. But 
over verbosity of the code is obviously also bad, so one compromise idea 
was to add a macro which builds the GT string and use drm logging 
helpers directly. This would be something like:

  drm_err(GT_LOG("something went wrong ret=%d\n", gt), ret);
  drm_info(GT_LOG(...same...));

Whether or not to put the gt as parameter to the helper macro or outside 
wasn't really decided upon. Anyway the macro would be adding the magic 
"gt%u: " prefix, drm device and all.

Also the name GT_LOG (or case) is just for illustration, that part 
wasn't really discussed.

If agreeable this pattern could then be used to consolidate some other 
macros that we have. Although apart from CT_DEBUG/ERROR I don't know if 
we have any others.

I hope I have transferred the idea correctly. Please shout if I have not.

Regards,

Tvrtko


> What I'd would like to see tried is to converting all of i915/gt within 
> one kernel release so we don't have a mish-mash of log formats.
> 
> Regards,
> 
> Tvrtko
> 
>>> ---
>>>   drivers/gpu/drm/i915/gt/intel_gt.h | 15 +++++++++++++++
>>>   1 file changed, 15 insertions(+)
>>>
>>> diff --git a/drivers/gpu/drm/i915/gt/intel_gt.h 
>>> b/drivers/gpu/drm/i915/gt/intel_gt.h
>>> index e0365d5562484..1e016fb0117a4 100644
>>> --- a/drivers/gpu/drm/i915/gt/intel_gt.h
>>> +++ b/drivers/gpu/drm/i915/gt/intel_gt.h
>>> @@ -13,6 +13,21 @@
>>>   struct drm_i915_private;
>>>   struct drm_printer;
>>> +#define GT_ERR(_gt, _fmt, ...) \
>>> +    drm_err(&(_gt)->i915->drm, "GT%u: " _fmt, (_gt)->info.id, 
>>> ##__VA_ARGS__)
>>> +
>>> +#define GT_WARN(_gt, _fmt, ...) \
>>> +    drm_warn(&(_gt)->i915->drm, "GT%u: " _fmt, (_gt)->info.id, 
>>> ##__VA_ARGS__)
>>> +
>>> +#define GT_NOTICE(_gt, _fmt, ...) \
>>> +    drm_notice(&(_gt)->i915->drm, "GT%u: " _fmt, (_gt)->info.id, 
>>> ##__VA_ARGS__)
>>> +
>>> +#define GT_INFO(_gt, _fmt, ...) \
>>> +    drm_info(&(_gt)->i915->drm, "GT%u: " _fmt, (_gt)->info.id, 
>>> ##__VA_ARGS__)
>>> +
>>> +#define GT_DBG(_gt, _fmt, ...) \
>>> +    drm_dbg(&(_gt)->i915->drm, "GT%u: " _fmt, (_gt)->info.id, 
>>> ##__VA_ARGS__)
>>> +
>>>   #define GT_TRACE(gt, fmt, ...) do {                    \
>>>       const struct intel_gt *gt__ __maybe_unused = (gt);        \
>>>       GEM_TRACE("%s " fmt, dev_name(gt__->i915->drm.dev),        \
>>