On Tue, Dec 13, 2022 at 04:51:11PM +0000, Mark Brown wrote:
> On Tue, Dec 13, 2022 at 05:56:30AM -0800, KernelCI bot wrote:
>
> The KernelCI bisection bot found regressions in at least two KMS tests
> in the Renesas tree on rk3399-gru-kevin just after the Renesas tree
> merged up mainline:
>
> igt-kms-rockchip.kms_vblank.pipe-A-wait-forked
> igt-kms-rockchip.kms_vblank.pipe-A-query-busy
>
> which it bisected to ca871659ec16 ("drm/bridge: analogix_dp: Support
> PSR-exit to disable transition"). I'm not *100%* sure I trust the
> bisection but it sure is suspicous that two separate bisects for related
> issues landed on the same commit.
>
> Below is the full report for the bisect for the first test, the bisect
> for the latter looks identical. It's got links to full logs for the
> test run and a Reported-by for the bot - I do see some backtraces from
> userspace in the output, the first is:
I think the backtraces are just because IGT calls assert().
> | IGT-Version: 1.26-gf8a4a0b (aarch64) (Linux: 6.1.0 aarch64)
> | <14>[ 35.444448] [IGT] drm_read: starting subtest short-buffer-wakeup
> | Starting subtest: short-buffer-wakeup
> |
> | (| drm_read:350) CRITICAL: Test assertion failure function generate_event, file ../tests/drm_read.c:65:
> | (drm_read:350) CRITICAL: <14>[ 36.155642] [IGT] drm_read: exiting, ret=98
> | Failed assertion: kmstest_get_vblank(fd, pipe, DRM_VBLANK_EVENT)
> |
> | (drm_read:350) CRITICAL: Last errno: 22, Invalid argument
> | Stack trace:
> |
> | #0 ../lib/igt_core.c:1933 __igt_fail_assert()
> | #1 [<unknown>+0xd5362770]
> | #2 [<unknown>+0xd536193c]
> | #3 [__libc_start_main+0xe8]
> | #4 [<unknown>+0xd5361974]
> | #5 [<unknown<6>[ 36.162851] Console: switching to colour frame buffer device 300x100>+0xd5361974]
> | Subtest short-buffer-wakeup failed.
>
> Unfortunately we don't have current results from mainline or -next.
Thanks for the notification. I'm running:
6e516faf0431 drm/panfrost: Job should reference MMU not file_priv
which is allegedly a "good" kernel. And running this:
### First kill my display manager, etc.
## Then:
IGT_FORCE_DRIVER=rockchip /usr/libexec/igt-gpu-tools/kms_vblank --run-subtest pipe-A-wait-forked
Gives the appended log [1]. If I'm looking right, it seems like it's
failing the same way as the "regression."
I also tested this:
# the 5.10.x backport, and its parent:
dbe04e874d4fbd56be64fdfcb29410241b6ad08a^ -- i.e.:
61297ee0c329 Input: bcm5974 - set missing URB_NO_TRANSFER_DMA_MAP urb flag
and saw the same failures, and I also see the failures I was trying to
avoid in this series (see e54a4424925a ("drm/atomic: Force bridge
self-refresh-exit on CRTC switch")). Perhaps that's because of the
"First kill my display manager, etc." -- because that step means we
might end up switching CRTCs (VOPs) when the test starts, and triggering
the bug.
I'll look some more, but this might be a difference of test setup, such
that my setup has the issue before and after that commit, but your setup
sees a regression.
Small tangent: It's possible this is similar to stuff I had to debug a
while back in this space:
atomictest: Disable CRTCs before test
https://chromium-review.googlesource.com/c/chromiumos/platform/drm-tests/+/3309960
null_platform_test: Disable CRTCs first
https://chromium-review.googlesource.com/c/chromiumos/platform/drm-tests/+/3315478
In that case, there was actually an underlying kernel regression due to:
846c7dfc1193 drm/atomic: Try to preserve the crtc enabled state in drm_atomic_remove_fb, v2.
But our tests were broken too (assuming an initial state that wasn't
guaranteed), so we just fixed the tests.
Anyway, I'll confirm when I get some fresh eyes and can try a few more
things (like neutering the ChromeOS display framework for my tests).
Brian
[1]
IGT-Version: 1.26-gf8a4a0b5 (arm) (Linux: 5.18.0-rc6+ aarch64)
Starting subtest: pipe-A-wait-forked
Beginning pipe-A-wait-forked on pipe A, connector eDP-1
(kms_vblank:2532) CRITICAL: Test assertion failure function vblank_wait, file ../igt-gpu-tools-1.25/tests/kms_vblank.c:319:
(kms_vblank:2535) CRITICAL: Test assertion failure function vblank_wait, file ../igt-gpu-tools-1.25/tests/kms_vblank.c:319:
(kms_vblank:2531) CRITICAL: Test assertion failure function vblank_wait, file ../igt-gpu-tools-1.25/tests/kms_vblank.c:319:
(kms_vblank:2532) CRITICAL: Failed assertion: wait_vblank(fd, &vbl) == 0
(kms_vblank:2534) CRITICAL: Test assertion failure function vblank_wait, file ../igt-gpu-tools-1.25/tests/kms_vblank.c:319:
(kms_vblank:2535) CRITICAL: Failed assertion: wait_vblank(fd, &vbl) == 0
(kms_vblank:2531) CRITICAL: Failed assertion: wait_vblank(fd, &vbl) == 0
(kms_vblank:2536) CRITICAL: Test assertion failure function vblank_wait, file ../igt-gpu-tools-1.25/tests/kms_vblank.c:319:
(kms_vblank:2532) CRITICAL: Last errno: 22, Invalid argument
(kms_vblank:2534) CRITICAL: Failed assertion: wait_vblank(fd, &vbl) == 0
(kms_vblank:2536) CRITICAL: Failed assertion: wait_vblank(fd, &vbl) == 0
(kms_vblank:2532) CRITICAL: error: -22 != 0
(kms_vblank:2531) CRITICAL: Last errno: 22, Invalid argument
(kms_vblank:2535) CRITICAL: Last errno: 22, Invalid argument
(kms_vblank:2531) CRITICAL: error: -22 != 0
(kms_vblank:2534) CRITICAL: Last errno: 22, Invalid argument
(kms_vblank:2536) CRITICAL: Last errno: 22, Invalid argument
(kms_vblank:2535) CRITICAL: error: -22 != 0
(kms_vblank:2534) CRITICAL: error: -22 != 0
(kms_vblank:2536) CRITICAL: error: -22 != 0
(kms_vblank:2533) CRITICAL: Test assertion failure function vblank_wait, file ../igt-gpu-tools-1.25/tests/kms_vblank.c:319:
(kms_vblank:2533) CRITICAL: Failed assertion: wait_vblank(fd, &vbl) == 0
(kms_vblank:2533) CRITICAL: Last errno: 22, Invalid argument
Stack trace:
Stack trace:
(kms_vblank:2533) CRITICAL: error: -22 != 0
Stack trace:
Stack trace:
Stack trace:
Stack trace:
child 1 failed with exit status 98
Subtest pipe-A-wait-forked failed.
**** DEBUG ****
(kms_vblank:2526) igt_kms-DEBUG: display: eDP-1: set_pipe(A)
(kms_vblank:2526) igt_kms-DEBUG: display: eDP-1: Selecting pipe A
(kms_vblank:2526) igt_fb-DEBUG: igt_create_fb_with_bo_size(width=2400, height=1600, format=XR24(0x34325258), modifier=0x0, size=0)
(kms_vblank:2526) igt_fb-DEBUG: igt_create_fb_with_bo_size(handle=1, pitch=9600)
(kms_vblank:2526) ioctl_wrappers-DEBUG: Test requirement passed: igt_has_fb_modifiers(fd)
(kms_vblank:2526) igt_fb-DEBUG: Test requirement passed: cairo_surface_status(fb->cairo_surface) == CAIRO_STATUS_SUCCESS
(kms_vblank:2526) igt_kms-DEBUG: Test requirement passed: plane_idx >= 0 && plane_idx < pipe->n_planes
(kms_vblank:2526) igt_kms-DEBUG: display: A.0: plane_set_fb(56)
(kms_vblank:2526) igt_kms-DEBUG: display: A.0: plane_set_size (2400x1600)
(kms_vblank:2526) igt_kms-DEBUG: display: A.0: fb_set_position(0,0)
(kms_vblank:2526) igt_kms-DEBUG: display: A.0: fb_set_size(2400x1600)
(kms_vblank:2526) igt_kms-DEBUG: display: commit {
(kms_vblank:2526) igt_kms-DEBUG: Test requirement passed: plane_idx >= 0 && plane_idx < pipe->n_planes
(kms_vblank:2526) igt_kms-DEBUG: display: Fixing up initial rotation pipe A, plane 0
(kms_vblank:2526) igt_kms-DEBUG: display: eDP-1: SetCrtc pipe A, fb 56, src (0, 0), mode 2400x1600
(kms_vblank:2526) igt_kms-DEBUG: Test requirement passed: plane_idx >= 0 && plane_idx < pipe->n_planes
(kms_vblank:2526) igt_kms-DEBUG: display: Fixing up initial rotation pipe A, plane 1
(kms_vblank:2526) igt_kms-DEBUG: display: SetCursor pipe A, disabling
(kms_vblank:2526) igt_kms-DEBUG: display: MoveCursor pipe A, (0, 0)
(kms_vblank:2526) igt_kms-DEBUG: Test requirement passed: plane_idx >= 0 && plane_idx < pipe->n_planes
(kms_vblank:2526) igt_kms-DEBUG: display: Fixing up initial rotation pipe B, plane 0
(kms_vblank:2526) igt_kms-DEBUG: display: SetCrtc pipe B, disabling
(kms_vblank:2526) igt_kms-DEBUG: Test requirement passed: plane_idx >= 0 && plane_idx < pipe->n_planes
(kms_vblank:2526) igt_kms-DEBUG: display: Fixing up initial rotation pipe B, plane 1
(kms_vblank:2526) igt_kms-DEBUG: display: SetPlane pipe B, plane 1, disabling
(kms_vblank:2526) igt_kms-DEBUG: display: SetProp plane B.1 "rotation" to 0x1/1
(kms_vblank:2526) igt_kms-DEBUG: Test requirement passed: plane_idx >= 0 && plane_idx < pipe->n_planes
(kms_vblank:2526) igt_kms-DEBUG: display: Fixing up initial rotation pipe B, plane 2
(kms_vblank:2526) igt_kms-DEBUG: display: SetPlane pipe B, plane 2, disabling
(kms_vblank:2526) igt_kms-DEBUG: display: SetProp plane B.2 "rotation" to 0x1/1
(kms_vblank:2526) igt_kms-DEBUG: Test requirement passed: plane_idx >= 0 && plane_idx < pipe->n_planes
(kms_vblank:2526) igt_kms-DEBUG: display: Fixing up initial rotation pipe B, plane 3
(kms_vblank:2526) igt_kms-DEBUG: display: SetCursor pipe B, disabling
(kms_vblank:2526) igt_kms-DEBUG: display: MoveCursor pipe B, (0, 0)
(kms_vblank:2526) igt_kms-DEBUG: display: }
(kms_vblank:2526) igt_debugfs-DEBUG: Opening debugfs directory '/sys/kernel/debug/dri/1'
(kms_vblank:2526) INFO: Beginning pipe-A-wait-forked on pipe A, connector eDP-1
(kms_vblank:2526) DEBUG: Spawning 6 threads
**** END ****
Subtest pipe-A-wait-forked: FAIL (0.938s)
Test requirement not met in function igt_require_pipe, file ../igt-gpu-tools-1.25/lib/igt_kms.c:2360:
Test requirement: !(pipe >= display->n_pipes || !display->pipes[pipe].enabled)
Pipe C does not exist or not enabled
Test requirement not met in function igt_require_pipe, file ../igt-gpu-tools-1.25/lib/igt_kms.c:2360:
Test requirement: !(pipe >= display->n_pipes || !display->pipes[pipe].enabled)
Pipe D does not exist or not enabled
Test requirement not met in function igt_require_pipe, file ../igt-gpu-tools-1.25/lib/igt_kms.c:2360:
Test requirement: !(pipe >= display->n_pipes || !display->pipes[pipe].enabled)
Pipe E does not exist or not enabled
Test requirement not met in function igt_require_pipe, file ../igt-gpu-tools-1.25/lib/igt_kms.c:2360:
Test requirement: !(pipe >= display->n_pipes || !display->pipes[pipe].enabled)
Pipe F does not exist or not enabled
