On 05/12/2022 18:44, Michal Wajdeczko wrote:
On 05.12.2022 14:16, Tvrtko Ursulin wrote:
On 02/12/2022 20:14, John Harrison wrote:
and while for dbg level messages it doesn't matter, I assume we should
be consistent for err/warn/info messages (as those will eventually show
up to the end user) so let maintainers decide here what is
expectation here
Could we have some examples pasted here, of the end result of this
series, for all message "categories" (origins, macros, whatever)?
GT initialisation:
gt_err(gt, "Failed to allocate scratch page\n");
i915 0000:00:02.0: [drm] GT0: Failed to allocate scratch page
G2H notification handler:
guc_err(guc, "notification: Invalid length %u for deregister done\n",
len);
i915 0000:00:02.0: [drm] GT0: GuC notification: Invalid length 0 for
deregister done
please note that today this message is coded as:
drm_err(&guc_to_gt(guc)->i915->drm, "Invalid length %u\n", len);
-> i915 0000:00:02.0: [drm] Invalid length %u
which makes this rather an example of meaningless log
Okay, so log text needs improving anyway which is orthogonal.
I'm not liking the inconsistency between gt_err and guc_err where with
latter callers either need to start the message with lower case because
of the unstructured "GuC " prefix added. Which then reads bad if callers
do guc_err(guc, "Error X happend").
Looks like Michal was pointing out the same thing, AFAIU at least when
re-reading the thread now.
Why wouldn't this work:
guc_err(guc, "Invalid length %u for deregister done notification\n", len);
i915 0000:00:02.0: [drm] GT0: GuC: Invalid length 0 for deregister done
notification
+1
Or if the use case for adding custom prefixes is strong then maybe
consider:
guc_err(guc, "notification", "Invalid length 0 for deregister done");
i915 0000:00:02.0: [drm] GT0: GuC notification: Invalid length 0 for
deregister done
guc_err(guc, "", "Error X");
i915 0000:00:02.0: [drm] GT0: GuC: Error X
-1
this will make logging macros too different from others (unless we
hide/use prefixes inside macros only, but I'm not sure there is any ROI)
Yeah I said if the use case is strong, no strong opinion either way.
CTB initialisation:
ct_probe_error(ct, "Failed to control/%s CTB (%pe)\n",
str_enable_disable(enable), ERR_PTR(err));
i915 0000:00:02.0: [drm] GT0: GuC CT Failed to control/enable CTB
(EINVAL)
Okay same as above.
Random meaningless (to me) message that is apparently a display thing:
drm_dbg_kms(&dev_priv->drm, "disabling %s\n", pll->info->name);
i915 0000:00:02.0: [drm:intel_disable_shared_dpll [i915]] disabling
PORT PLL B
Plan is to not touch outside gt/.
I'm sure you can extrapolate to all other forms of dbg, notice, info,
etc. without me having to manually type each one out, given that they
are all identical.
Personally, I think the above should be just:
gt_err(gt, "Failed to allocate scratch page\n");
i915 0000:00:02.0: [drm] GT0: Failed to allocate scratch page
gt_err(guc_to_gt(guc), "G2H: Invalid length for deregister done:
%u\n", len);
i915 0000:00:02.0: [drm] GT0: G2H: Invalid length for deregister done: 0
that's probably should be:
"Invalid length for G2H deregister done: %u\n
and it will still just look fine if we auto append the 'GuC' prefix:
i915 0000:00:02.0: [drm] GT0: GuC: Invalid length for G2H deregister
gt_probe_error(ct_to_gt(ct), "Failed to %s CT %d buffer (%pe)\n",
str_enable_disable(enable), send ? "SEND" : "RECV", ERR_PTR(err));
i915 0000:00:02.0: [drm] GT0: Failed to enable CT SEND buffer (EINVAL)
having "GuC/CT" prefix here will also look fine:
i915 0000:00:02.0: [drm] GT0: GuC: Failed to enable CT SEND buffer
i915 0000:00:02.0: [drm] GT0: GuC: CT: Failed to enable SEND buffer
i915 0000:00:02.0: [drm] GT0: CT: Failed to enable SEND buffer
Works for me.
We could but it seems we agreed some weeks ago to consolidate the
existing CT_ERROR macros and such in this exercise. At least no
objections were raised to that plan.
If now we want to go back on that, and if you want to have
guc_to_gt(guc) in all gt/uc/ call sites that's fine by me, but please
get some acks and consensus from people who work in that area. And under
that option someone would also need to convert the CT code to new macros.
while the main goal of this series was to have GT# appended to the log
messages but we also wanted to simplify the use of the logging macros by
passing the component pointer directly (with extra *bonus* that allows
to auto append component specific prefix, if any, like CT macros do)
IMHO adding guc_xxx() macros with "GuC:" prefix will do the trick and
since many of the existing GuC related logs are already broken or
incomplete, we might fix them accordingly.
In other words in addition to gt_xxx() I still want additional guc_xxx()
macros (as it will allow us to fix related messages) and ct_xxx() macros
(as we already have CT_xxx so no need to change anything)
Both approaches are fine by me as long as it's logical and consistent
and we manage not to leave the conversion half-done for too long.
Maybe as a way forward work could be split? If John wants to deal with
gt_xxx macros, avoid touching GuC (putting his original motivation
aside) and you want to convert the gt/uc folder? Assuming John you are
okay with "GuC:" and "CT:" prefixes.
Regards,
Tvrtko
