Re: [Intel-gfx] [PATCH v7 0/9] dyndbg: drm.debug adaptation

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 





On 10/31/22 6:11 PM, jim.cromie@xxxxxxxxx wrote:
On Mon, Oct 31, 2022 at 7:07 AM Ville Syrjälä
<ville.syrjala@xxxxxxxxxxxxxxx> wrote:
On Sun, Oct 30, 2022 at 08:42:52AM -0600, jim.cromie@xxxxxxxxx wrote:
On Thu, Oct 27, 2022 at 2:10 PM Ville Syrjälä
<ville.syrjala@xxxxxxxxxxxxxxx> wrote:
On Thu, Oct 27, 2022 at 01:55:39PM -0600, jim.cromie@xxxxxxxxx wrote:
On Thu, Oct 27, 2022 at 9:59 AM Ville Syrjälä
<ville.syrjala@xxxxxxxxxxxxxxx> wrote:
On Thu, Oct 27, 2022 at 09:37:52AM -0600, jim.cromie@xxxxxxxxx wrote:
On Thu, Oct 27, 2022 at 9:08 AM Jason Baron <jbaron@xxxxxxxxxx> wrote:


On 10/21/22 05:18, Jani Nikula wrote:
On Thu, 20 Oct 2022, Ville Syrjälä <ville.syrjala@xxxxxxxxxxxxxxx> wrote:
On Sat, Sep 24, 2022 at 03:02:34PM +0200, Greg KH wrote:
On Sun, Sep 11, 2022 at 11:28:43PM -0600, Jim Cromie wrote:
hi Greg, Dan, Jason, DRM-folk,

heres follow-up to V6:
   rebased on driver-core/driver-core-next for -v6 applied bits (thanks)
   rework drm_debug_enabled{_raw,_instrumented,} per Dan.

It excludes:
   nouveau parts (immature)
   tracefs parts (I missed --to=Steve on v6)
   split _ddebug_site and de-duplicate experiment (way unready)

IOW, its the remaining commits of V6 on which Dan gave his Reviewed-by.

If these are good to apply, I'll rebase and repost the rest separately.
All now queued up, thanks.
This stuff broke i915 debugs. When I first load i915 no debug prints are
produced. If I then go fiddle around in /sys/module/drm/parameters/debug
the debug prints start to suddenly work.
Wait what? I always assumed the default behaviour would stay the same,
which is usually how we roll. It's a regression in my books. We've got a
CI farm that's not very helpful in terms of dmesg logging right now
because of this.

BR,
Jani.


That doesn't sound good - so you are saying that prior to this change some
of the drm debugs were default enabled. But now you have to manually enable
them?

Thanks,

-Jason

Im just seeing this now.
Any new details ?
No. We just disabled it as BROKEN for now. I was just today thinking
about sending that patch out if no solutin is forthcoming soon since
we need this working before 6.1 is released.

Pretty sure you should see the problem immediately with any driver
(at least if it's built as a module, didn't try builtin). Or at least
can't think what would make i915 any more special.

So, I should note -
99% of my time & energy on this dyndbg + drm patchset
has been done using virtme,
so my world-view (and dev-hack-test env) has been smaller, simpler
maybe its been fatally simplistic.

ive just rebuilt v6.0  (before the trouble)
and run it thru my virtual home box,
I didnt see any unfamiliar drm-debug output
that I might have inadvertently altered somehow

I have some real HW I can put a reference kernel on,0
to look for the missing output, but its all gonna take some time,
esp to tighten up my dev-test-env

in the meantime, there is:

config DRM_USE_DYNAMIC_DEBUG
bool "use dynamic debug to implement drm.debug"
default y
depends on DRM
depends on DYNAMIC_DEBUG || DYNAMIC_DEBUG_CORE
depends on JUMP_LABEL
help
   Use dynamic-debug to avoid drm_debug_enabled() runtime overheads.
   Due to callsite counts in DRM drivers (~4k in amdgpu) and 56
   bytes per callsite, the .data costs can be substantial, and
   are therefore configurable.

Does changing the default fix things for i915 dmesg ?
I think we want to mark it BROKEN in addition to make sure no one
Ok, I get the distinction now.
youre spelling that
   depends on BROKEN

I have a notional explanation, and a conflating commit:

can you eliminate
git log -p ccc2b496324c13e917ef05f563626f4e7826bef1

as the cause ?
Reverting that doesn't help.

thanks for eliminating it.

I do need to clarify, I dont know exactly what debug/logging output
is missing such that CI is failing
CI isn't failing. But any logs it produces are 100% useless,
as are any user reported logs.

The debugs that are missing are anything not coming directly
from drm.ko.

The stuff that I see being printed by i915.ko are drm_info()
and the drm_printer stuff from i915_welcome_messages(). That
also implies that drm_debug_enabled(DRM_UT_DRIVER) does at
least still work correctly.

I suspect that the problem is just that the debug calls
aren't getting patched in when a module loads. And fiddling
with the modparam after the fact does trigger that somehow.

ok, heres the 'tape' of a virtme boot,
then modprobe going wrong.

[    1.785873] dyndbg:   2 debug prints in module intel_rapl_msr
[    2.040598] virtme-init: udev is done
virtme-init: console is ttyS0

load drm driver
bash-5.2# modprobe i915

drm module is loaded 1st
[    6.549451] dyndbg: add-module: drm.302 sites
[    6.549991] dyndbg: class[0]: module:drm base:0 len:10 ty:0
[    6.550647] dyndbg:  0: 0 DRM_UT_CORE
[    6.551097] dyndbg:  1: 1 DRM_UT_DRIVER
[    6.551531] dyndbg:  2: 2 DRM_UT_KMS
[    6.551931] dyndbg:  3: 3 DRM_UT_PRIME
[    6.552402] dyndbg:  4: 4 DRM_UT_ATOMIC
[    6.552799] dyndbg:  5: 5 DRM_UT_VBL
[    6.553270] dyndbg:  6: 6 DRM_UT_STATE
[    6.553634] dyndbg:  7: 7 DRM_UT_LEASE
[    6.554043] dyndbg:  8: 8 DRM_UT_DP
[    6.554392] dyndbg:  9: 9 DRM_UT_DRMRES
[    6.554776] dyndbg: module:drm attached 1 classes
[    6.555241] dyndbg: 302 debug prints in module drm

here modprobe reads /etc/modprobe.d/drm-test.conf:
options drm dyndbg="class DRM_UT_CORE +p; class DRM_UT_DRIVER +p"
and dyndbg applies it

Hi,

I'm a bit confused with this. My understanding is that there
is a 'regression' here from how this used to work. But the
'class' keyword is new - are we sure this is the command-line
we are trying to fix?


[    6.564284] dyndbg: module: drm dyndbg="class DRM_UT_CORE +p; class
DRM_UT_DRIVER +p"
[    6.564957] dyndbg: query 0: "class DRM_UT_CORE +p" mod:drm
[    6.565348] dyndbg: split into words: "class" "DRM_UT_CORE" "+p"
[    6.565836] dyndbg: op='+'
[    6.566059] dyndbg: flags=0x1
[    6.566321] dyndbg: *flagsp=0x1 *maskp=0xffffffff
[    6.566875] dyndbg: parsed: func="" file="" module="drm" format=""
lineno=0-0 class=DRM_UT_CORE
[    6.568753] dyndbg: applied: func="" file="" module="drm" format=""
lineno=0-0 class=DRM_UT_CORE
[    6.569473] dyndbg: query 1: "class DRM_UT_DRIVER +p" mod:drm
[    6.570139] dyndbg: split into words: "class" "DRM_UT_DRIVER" "+p"
[    6.570522] dyndbg: op='+'
[    6.570699] dyndbg: flags=0x1
[    6.570893] dyndbg: *flagsp=0x1 *maskp=0xffffffff
[    6.571200] dyndbg: parsed: func="" file="" module="drm" format=""
lineno=0-0 class=DRM_UT_DRIVER
[    6.571778] dyndbg: no matches for query
[    6.572031] dyndbg: no-match: func="" file="" module="drm"
format="" lineno=0-0 class=DRM_UT_DRIVER
[    6.572615] dyndbg: processed 2 queries, with 61 matches, 0 errs
[    6.573286] ACPI: bus type drm_connector registered

next required module is loaded, but drm.debug isnt propagated.

[    6.578645] dyndbg: add-module: drm_kms_helper.94 sites
[    6.579487] dyndbg: class[0]: module:drm_kms_helper base:0 len:10 ty:0
[    6.580639] dyndbg:  0: 0 DRM_UT_CORE
[    6.581135] dyndbg:  1: 1 DRM_UT_DRIVER
[    6.581651] dyndbg:  2: 2 DRM_UT_KMS
[    6.582178] dyndbg:  3: 3 DRM_UT_PRIME
[    6.582927] dyndbg:  4: 4 DRM_UT_ATOMIC
[    6.583627] dyndbg:  5: 5 DRM_UT_VBL
[    6.584350] dyndbg:  6: 6 DRM_UT_STATE
[    6.584999] dyndbg:  7: 7 DRM_UT_LEASE
[    6.585699] dyndbg:  8: 8 DRM_UT_DP
[    6.586354] dyndbg:  9: 9 DRM_UT_DRMRES
[    6.587040] dyndbg: module:drm_kms_helper attached 1 classes
[    6.588103] dyndbg:  94 debug prints in module drm_kms_helper

and so on

[    6.595628] dyndbg: add-module: drm_display_helper.150 sites
[    6.596442] dyndbg: class[0]: module:drm_display_helper base:0 len:10 ty:0
[    6.597453] dyndbg:  0: 0 DRM_UT_CORE
...
[    6.601678] dyndbg: module:drm_display_helper attached 1 classes
[    6.602335] dyndbg: 150 debug prints in module drm_display_helper

[    6.692760] dyndbg: add-module: i915.1657 sites
[    6.693023] dyndbg: class[0]: module:i915 base:0 len:10 ty:0
[    6.693323] dyndbg:  0: 0 DRM_UT_CORE
....
[    6.695220] dyndbg: module:i915 attached 1 classes
[    6.695463] dyndbg: 1657 debug prints in module i915
bash-5.2#
bash-5.2#


So, what I think I need to add:

ddebug_add_module()  scans the module being loaded,
looking for a param thats wired to dyndbg's modparam callback.
Then it calls that callback, with the val of the sysfs-node
(drm.debug in this case), and the module (i915)

Ok, I thought the sysfs callbacks only happen when
the sysfs file is written? And thus this works once
when the sysfs file is explicitly written by the user
after boot but not before then?

Thanks,

-Jason


the callback will then run the query to enable callsites per drm.debug.

I'll guess the kparams I need to find are in a section somewhere
Anyone want to toss a lawn-dart at the code I need to look at, copy ?

--
Ville Syrjälä
Intel
thanks again
Jim




[Index of Archives]     [Linux DRI Users]     [Linux Intel Graphics]     [Linux USB Devel]     [Video for Linux]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [XFree86]     [Linux USB Devel]     [Video for Linux]     [Linux Audio Users]     [Linux Kernel]     [Linux SCSI]     [XFree86]
  Powered by Linux