igt@perf* - abort/incomplete - WARNING: at kernel/events/core.c __do_sys_perf_event_open
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_14006/shard-dg1-13/igt@perf_pmu@busy@rcs0.html
<7> [44.529406] [drm:eb_lookup_vmas [i915]] EINVAL at eb_validate_vma:511
<7> [44.549516] i915 0000:03:00.0: [drm:i915_drop_caches_set [i915]] Dropping caches: 0x0000005c [0x0000005c]
<4> [44.580332] ------------[ cut here ]------------
<4> [44.580343] WARNING: CPU: 0 PID: 923 at kernel/events/core.c:1950 __do_sys_perf_event_open+0xef0/0x1060
<4> [44.580349] Modules linked in: fuse mei_gsc mei_me mei i915 btusb btrtl btintel btbcm bluetooth x86_pkg_temp_thermal coretemp snd_hda_codec_realtek kvm_intel ecdh_generic snd_hda_codec_generic ecc ledtrig_audio wmi_bmof kvm prime_numbers i2c_algo_bit snd_hda_intel irqbypass ttm crct10dif_pclmul snd_intel_dspcfg crc32_pclmul ghash_clmulni_intel snd_hda_codec video snd_hwdep drm_display_helper snd_hda_core atlantic i2c_i801 drm_buddy i2c_smbus snd_pcm e1000e ptp pps_core wmi
<4> [44.580410] CPU: 0 PID: 923 Comm: perf_pmu Tainted: G U 6.7.0-rc5-CI_DRM_14006-ge3fd8d148b98+ #1 (moved)
Activity
Since it's also reproducible on RKL, I tried it on an available machine. The test consistently passes for me:
$ sudo ./build/tests/perf_pmu --r busy IGT-Version: 1.28-gc33e2e14b (x86_64) (Linux: 6.7.0-rc5-CI_DRM_14008-gd630426f84b0+ x86_64) Using IGT_SRANDOM=1702362660 for randomisation Opened device: /dev/dri/card0 Starting subtest: busy Starting dynamic subtest: rcs0 Dynamic subtest rcs0: SUCCESS (0.557s) Starting dynamic subtest: bcs0 Dynamic subtest bcs0: SUCCESS (0.534s) Starting dynamic subtest: vcs0 Dynamic subtest vcs0: SUCCESS (0.533s) Starting dynamic subtest: vecs0 Dynamic subtest vecs0: SUCCESS (0.526s) Subtest busy: SUCCESS (2.152s) Opened device: /dev/dri/renderD128No warnings in kernel log neither:
[ 7144.481909] [IGT] perf_pmu: starting dynamic subtest rcs0 [ 7144.482013] [drm:eb_lookup_vmas [i915]] EINVAL at eb_validate_vma:511 [ 7144.483047] i915 0000:00:02.0: [drm:i915_drop_caches_set [i915]] Dropping caches: 0x0000005c [0x0000005c] [ 7144.509709] i915 0000:00:02.0: [drm:i915_gem_open [i915]] [ 7145.014431] i915 0000:00:02.0: [drm:i915_drop_caches_set [i915]] Dropping caches: 0x0000005c [0x0000005c] [ 7145.024649] [IGT] perf_pmu: finished subtest rcs0, SUCCESS [ 7145.024845] [IGT] perf_pmu: finished subtest busy, SUCCESSI will have to try on a few other machines.
Edited by Lucas De Marchi@demarchi : please see CI Buglog for the failures. There are both perf and perf_pmu failures, e.g. RKL has a perf failure not a perf_pmu failure. Perf failures (as opposed to perf_pmu) are interesting because i915 perf does not actually use the kernel perf event framework, so we should not expect to see the __do_sys_perf_event_open call in the perf failures (we should see that call only in the perf_pmu failures which uses the kernel perf framework). Kernel perf is what we call perf_pmu (it's confusing). So something weird is going on. I'm wondering if this is some sort of kernel perf_pmu stack trace, not an i915 stack trace.
mentioned in issue #9855 (closed)
See #9855 (closed), issue is happening in tests totally unrelated to perf or perf_pmu.
The CI Bug Log issue associated to this bug has been updated by tillipix.
New filters associated
- GLK TGL: Few pm tests - incomplete - No warnings/errors
-
A CI Bug Log filter associated to this bug has been updated by tillipix.
Description: SNB GLK TGL: Few pm tests - incomplete - No warnings/errors
Equivalent query: runconfig_tag IS IN ["DRM-TIP"] AND machine_name IS IN ["shard-snb2", "shard-glk7", "shard-tglu-9"] AND ((testsuite_name = "IGT" AND test_name IS IN ["igt@perf_pmu@busy-check-all@rcs0", "igt@perf_pmu@busy-idle-check-all", "igt@i915_pm_rc6_residency@rc6-fence@gt0"])) AND ((testsuite_name = "IGT" AND status_name IS IN ["incomplete"]))
New failures caught by the filter:
-
A CI Bug Log filter associated to this bug has been updated by tillipix.
Description: DG1 DG2 GKL MTL_P RKL: igt@perf* - abort/incomplete - WARNING: at kernel/events/core.c __do_sys_perf_event_open
Equivalent query: runconfig_tag IS IN ["DRM-TIP"] AND machine_tag IS IN ["DG2", "MTL-P", "GEN9", "GLK", "DG1", "RKL", "GEN12"] AND ((testsuite_name = "IGT" AND test_name IS IN ["igt@perf@rc6-disable", "igt@perf_pmu@busy@rcs0", "igt@perf@global-sseu-config-invalid", "igt@perf@global-sseu-config", "igt@perf_pmu@faulting-read@gtt", "igt@perf_pmu@gt-awake", "igt@perf@unprivileged-single-ctx-counters", "igt@perf@invalid-oa-format-id", "igt@perf_pmu@most-busy-check-all@rcs0", "igt@perf@gen12-mi-rpc@rcs0", "igt@perf_pmu@rc6-suspend", "igt@perf_pmu@faulting-read@fixed", "igt@perf@buffer-fill@0-rcs0", "igt@perf@polling@0-rcs0", "igt@perf@stress-open-close@0-rcs0", "igt@perf@gen12-invalid-class-instance", "igt@perf_pmu@all-busy-idle-check-all", "igt@perf@global-sseu-config@0-rcs0", "igt@perf_pmu@semaphore-wait-idle@rcs0", "igt@perf@blocking@0-rcs0", "igt@perf@global-sseu-config-invalid@0-rcs0", "igt@perf_pmu@frequency@gt0", "igt@perf_pmu@rc6@gt0", "igt@perf@invalid-open-flags", "igt@perf_pmu@busy-accuracy-98@rcs0", "igt@perf_pmu@init-sema@rcs0", "igt@perf_pmu@busy-no-semaphores@rcs0", "igt@perf@invalid-oa-exponent", "igt@perf@invalid-remove-userspace-config", "igt@perf@invalid-oa-exponent", "igt@perf@gen12-group-exclusive-stream-sample-oa", "igt@perf@gen12-group-concurrent-oa-buffer-read", "igt@perf@non-sampling-read-error", "igt@perf_pmu@busy-no-semaphores@rcs0", "igt@perf_pmu@render-node-busy@rcs0", "igt@perf@non-system-wide-paranoid", "igt@perf@whitelisted-registers-userspace-config", "igt@perf_pmu@render-node-busy-idle@rcs0", "igt@perf@blocking-parameterized", "igt@perf@polling-parameterized", "igt@perf_pmu@idle-no-semaphores@rcs0"])) AND ((testsuite_name = "IGT" AND status_name IS IN ["incomplete", "abort"])) AND dmesg ~= 'WARNING: .* at kernel/events/core.c.* __do_sys_perf_event_open'
New failures caught by the filter:
- https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_14009/shard-mtlp-2/igt@perf@invalid-open-flags.html
- https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_14009/shard-mtlp-8/igt@perf@blocking@0-rcs0.html
- https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_14010/shard-dg2-3/igt@perf@blocking@0-rcs0.html
- https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_14010/shard-glk1/igt@perf@blocking@0-rcs0.html
- https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_14010/shard-mtlp-6/igt@perf@blocking@0-rcs0.html
- https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_14010/shard-mtlp-7/igt@perf@invalid-open-flags.html
- https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_14010/shard-rkl-5/igt@perf@invalid-open-flags.html
-
A CI Bug Log filter associated to this bug has been updated by tillipix.
Description: RKL SNB GLK TGL: Few pm tests - incomplete - No warnings/errors
Equivalent query: runconfig_tag IS IN ["DRM-TIP"] AND machine_name IS IN ["shard-glk8", "shard-snb27", "shard-glk7", "shard-tglu-9", "shard-tglu-5", "shard-snb2", "shard-rkl-7"] AND ((testsuite_name = "IGT" AND test_name IS IN ["igt@perf_pmu@busy-check-all@rcs0", "igt@perfi915_pmu@busy-_rps@engidlne-chordeck-allr", "igt@i915_pm_rc6_residency@rc6-fence@gt0", "igt@perf_pmu@busy-idle-check-all"])) AND ((testsuite_name = "IGT" AND status_name IS IN ["incomplete"]))
New failures caught by the filter:
-
A CI Bug Log filter associated to this bug has been updated by tillipix.
Description: RKL SNB GLK TGL: Few pm tests - incomplete - No warnings/errors
Equivalent query: runconfig_tag IS IN ["DRM-TIP"] AND machine_name IS IN ["shard-glk8", "shard-snb7", "shard-glk7", "shard-tglu-9", "shard-tglu-5", "shard-snb2", "shard-snb5", "shard-rkl-7"] AND ((testsuite_name = "IGT" AND test_name IS IN ["igt@i915_pm_rps@fence-order", "igt@perf_pmu@busy-idle-check-all", "igt@perf_pmu@busy-check-all@rcs0", "igt@i915_pm_rps@engine-order", "igt@i915_pm_rc6_residency@rc6-fence@gt0", "igt@perf_pmu@busy-idle-check-all"])) AND ((testsuite_name = "IGT" AND status_name IS IN ["incomplete"]))
New failures caught by the filter:
-
A CI Bug Log filter associated to this bug has been updated by tillipix.
Description: RKL SNB GLK TGL: Few pm tests - incomplete - No warnings/errors
Equivalent query: runconfig_tag IS IN ["DRM-TIP"] AND machine_name IS IN ["shard-glk8", "shard-snb7", "shard-glk7", "shard-tglu-9", "shard-tglu-5", "shard-snb2", "shard-snb5", "shard-rkl-7"] AND ((testsuite_name = "IGT" AND test_name IS IN ["igt@i915_pm_rps@fence-order", "igt@perf_pmu@busy-idle-check-all", "igt@perf_pmu@busy-check-all@rcs0", "igt@i915_pm_rps@engine-order", "igt@i915_pm_rc6_residency@rc6-fence@gt0", "igt@perf_pmu@busy-idle-check-all"])) AND ((testsuite_name = "IGT" AND status_name IS IN ["incomplete"]))
New failures caught by the filter:
-
A CI Bug Log filter associated to this bug has been updated by tillipix.
Description: RKL SNB GLK TGL: Few pm tests - incomplete - No warnings/errors
Equivalent query: runconfig_tag IS IN ["DRM-TIP"] AND machine_name IS IN ["shard-glk8", "shard-snb7", "shard-glk7", "shard-tglu-9", "shard-tglu-5", "shard-snb2", "shard-snb5", "shard-rkl-7"] AND ((testsuite_name = "IGT" AND test_name IS IN ["igt@i915_pm_rps@fence-order", "igt@perf_pmu@busy-idle-check-all", "igt@perf_pmu@busy-check-all@rcs0", "igt@i915_pm_rps@engine-order", "igt@i915_pm_rc6_residency@rc6-fence@gt0", "igt@perf_pmu@busy-idle-check-all"])) AND ((testsuite_name = "IGT" AND status_name IS IN ["incomplete"]))
New failures caught by the filter:
-
A CI Bug Log filter associated to this bug has been updated by tillipix.
Description: RKL SNB GLK TGL: Few pm tests - incomplete - No warnings/errors
Equivalent query: runconfig_tag IS IN ["DRM-TIP"] AND machine_name IS IN ["shard-glk8", "shard-snb7", "shard-glk7", "shard-tglu-9", "shard-tglu-5", "shard-snb2", "shard-snb5", "shard-rkl-7"] AND ((testsuite_name = "IGT" AND test_name IS IN ["igt@i915_pm_rps@fence-order", "igt@perf_pmu@busy-idle-check-all", "igt@perf_pmu@busy-check-all@rcs0", "igt@i915_pm_rps@engine-order", "igt@i915_pm_rc6_residency@rc6-fence@gt0", "igt@perf_pmu@busy-idle-check-all"])) AND ((testsuite_name = "IGT" AND status_name IS IN ["incomplete"]))
New failures caught by the filter:
-
A CI Bug Log filter associated to this bug has been updated by tillipix.
Description: RKL SNB GLK TGL: Few pm tests - incomplete - No warnings/errors
Equivalent query: runconfig_tag IS IN ["DRM-TIP"] AND machine_name IS IN ["shard-glk8", "shard-snb7", "shard-glk7", "shard-tglu-9", "shard-tglu-5", "shard-snb2", "shard-snb5", "shard-rkl-7"] AND ((testsuite_name = "IGT" AND test_name IS IN ["igt@i915_pm_rps@fence-order", "igt@perf_pmu@busy-idle-check-all", "igt@perf_pmu@busy-check-all@rcs0", "igt@i915_pm_rps@engine-order", "igt@i915_pm_rc6_residency@rc6-fence@gt0", "igt@perf_pmu@busy-idle-check-all"])) AND ((testsuite_name = "IGT" AND status_name IS IN ["incomplete"]))
New failures caught by the filter:
-
A CI Bug Log filter associated to this bug has been updated by tillipix.
Description: RKL SNB GLK TGL: Few pm tests - incomplete - No warnings/errors
Equivalent query: runconfig_tag IS IN ["DRM-TIP"] AND machine_name IS IN ["shard-glk8", "shard-snb7", "shard-glk7", "shard-tglu-9", "shard-tglu-5", "shard-snb2", "shard-snb5", "shard-rkl-7"] AND ((testsuite_name = "IGT" AND test_name IS IN ["igt@i915_pm_rps@fence-order", "igt@perf_pmu@busy-idle-check-all", "igt@perf_pmu@busy-check-all@rcs0", "igt@i915_pm_rps@engine-order", "igt@i915_pm_rc6_residency@rc6-fence@gt0", "igt@perf_pmu@busy-idle-check-all"])) AND ((testsuite_name = "IGT" AND status_name IS IN ["incomplete"]))
New failures caught by the filter:
I'm wondering if this is some sort of kernel perf_pmu stack trace, not an i915 stack trace.
not sure I understand this part... it is a kernel perf stack trace, but it's coming from a syscall. The kernel itself shouldn't be calling it. Something in igt (or another tool in userspace) must be calling perf_event_open(). I will try to reproduce again today.
The warning we are hitting is:
#define lockdep_assert_event_ctx(event) \ WARN_ON_ONCE(__lockdep_enabled && \ (this_cpu_read(hardirqs_enabled) && \ lockdep_is_held(&(event)->ctx->mutex) != LOCK_STATE_HELD))Since it's a _ONCE variant, whatever test executes first is the once that triggers the warning, which explains why it's a different test on each platform. strace on igt@i915_pm_rps@fence-order for example confirms the perf_even_open() call is coming from the test being executed:
perf_event_open({type=0x16 /* PERF_TYPE_??? */, size=PERF_ATTR_SIZE_VER7, config=0x100000, sample_period=0, sample_type=0, read_format=PERF_FORMAT_TOTAL_TIME_ENABLED, precise_ip=0 /* arbitrary skid */, use_clockid=1, ...}, -1, 0, -1, 0) = 14 perf_event_open({type=0x16 /* PERF_TYPE_??? */, size=PERF_ATTR_SIZE_VER7, config=0x100000, sample_period=0, sample_type=0, read_format=PERF_FORMAT_TOTAL_TIME_ENABLED, precise_ip=0 /* arbitrary skid */, use_clockid=1, ...}, -1, 0, -1, 0) = 14 perf_event_open({type=0x16 /* PERF_TYPE_??? */, size=PERF_ATTR_SIZE_VER7, config=0x100000, sample_period=0, sample_type=0, read_format=PERF_FORMAT_TOTAL_TIME_ENABLED, precise_ip=0 /* arbitrary skid */, use_clockid=1, ...}, -1, 0, -1, 0) = 14@demarchi: Thanks for digging into this.
I was trying to see if IGT lib calls perf_event_open(), so that any test will cause it when IGT lib loads. But it doesn't look like IGT lib is calling perf_event_open(), only particular tests are calling perf_event_open().
I think, at this point, since it's not our issue, I would just send a mail on LKML about the lockdep warning and expect somebody from the 'PERFORMANCE EVENTS SUBSYSTEM' to fix it.
@adixit already did earlier today: https://lore.kernel.org/all/20231214000620.3081018-1-lucas.demarchi@intel.com/.
Checking on lore.kernel.org now I also see another similar report.
