Re: WARNING: CPU: 0 PID: 3634 at drivers/gpu/drm/drm_irq.c:1141 drm_wait_one_vblank

Re: WARNING: CPU: 0 PID: 3634 at drivers/gpu/drm/drm_irq.c:1141 drm_wait_one_vblank

[Jani Nikula]

+intel-gfx and Matt

On Wed, 01 Jul 2015, Michal Hocko <mhocko@suse.cz> wrote:
> On Wed 01-07-15 10:26:39, Daniel Vetter wrote:
>> On Tue, Jun 30, 2015 at 10:13:35PM +0200, Michal Hocko wrote:
>> > On Tue 30-06-15 18:59:29, Daniel Vetter wrote:
> [...]
>> > > Also it might be time to start bisecting this if you can readily reproduce it.
>> > 
>> > Yes, I can reproduce it just by switching to the text console. Sometimes
>> > it is the first attempt already but sometimes it takes several attempts.
>> > I will try to go back to 4.0 and bisect it then.
>> 
>> Yes please do, since this is a confusing regression I think the bisect
>> result will be the fastest way forward.
>
> OK, managed to bisect to cf4c7c12258e ("drm/i915: Make all plane
> disables use 'update_plane' (v5)") (CC people involved - the thread
> starts here: http://marc.info/?l=dri-devel&m=143566543432613&w=2 for
> your reference).
>
> I do not see the warning when I revert the commit directly on top of
> cf4c7c12258e but I cannot cleanly revert it on top of the current Linus'
> tree. Anything more I can give you to help to further debug the issue?
>
> Bisect log is:
> git bisect start
> # bad: [c517d838eb7d07bbe9507871fab3931deccff539] Linux 4.0-rc1
> git bisect bad c517d838eb7d07bbe9507871fab3931deccff539
> # good: [bfa76d49576599a4b9f9b7a71f23d73d6dcff735] Linux 3.19
> git bisect good bfa76d49576599a4b9f9b7a71f23d73d6dcff735
> # good: [02f1f2170d2831b3233e91091c60a66622f29e82] kernel.h: remove ancient __FUNCTION__ hack
> git bisect good 02f1f2170d2831b3233e91091c60a66622f29e82
> # bad: [796e1c55717e9a6ff5c81b12289ffa1ffd919b6f] Merge branch 'drm-next' of git://people.freedesktop.org/~airlied/linux
> git bisect bad 796e1c55717e9a6ff5c81b12289ffa1ffd919b6f
> # good: [9682ec9692e5ac11c6caebd079324e727b19e7ce] Merge tag 'driver-core-3.20-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/driver-core
> git bisect good 9682ec9692e5ac11c6caebd079324e727b19e7ce
> # good: [a9724125ad014decf008d782e60447c811391326] Merge tag 'tty-3.20-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/tty
> git bisect good a9724125ad014decf008d782e60447c811391326
> # bad: [f43dff0ee00a259f524ce17ba4f8030553c66590] Merge tag 'drm-amdkfd-next-fixes-2015-01-25' of git://people.freedesktop.org/~gabbayo/linux into drm-next
> git bisect bad f43dff0ee00a259f524ce17ba4f8030553c66590
> # good: [b942c653ae265abbd31032f3b4f5f857e5c7c723] Merge tag 'trace-sh-3.19' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace
> git bisect good b942c653ae265abbd31032f3b4f5f857e5c7c723
> # good: [fcf3aac5fc307f0cae429f5844ddc25761662858] drm/i915: remove unused power_well/get_cdclk_freq api
> git bisect good fcf3aac5fc307f0cae429f5844ddc25761662858
> # bad: [4f4d89af78682f2ed1cf6745794804817f867bba] Merge tag 'drm-amdkfd-next-2015-01-09' of git://people.freedesktop.org/~gabbayo/linux into drm-next
> git bisect bad 4f4d89af78682f2ed1cf6745794804817f867bba
> # bad: [64387b613a43713d0e03d9d43bfbb1727e8475e1] drm/i915: Protect against leaks in pipe_crc_set_source
> git bisect bad 64387b613a43713d0e03d9d43bfbb1727e8475e1
> # good: [bfc882b4e30fbc169ecfe3508378623743806f56] drm/i915: Flatten engine init control flow
> git bisect good bfc882b4e30fbc169ecfe3508378623743806f56
> # good: [2b875c22fa77dfc895d3cf8287a553813d3e64c8] drm/i915: Make intel_plane_state subclass drm_plane_state
> git bisect good 2b875c22fa77dfc895d3cf8287a553813d3e64c8
> # bad: [15a17aae5f803551981a7acc6a4058b247a7452c] drm/i915: Check mask/bit helper functions
> git bisect bad 15a17aae5f803551981a7acc6a4058b247a7452c
> # bad: [146d84f0f2707bfe2c67114eeefac30da8584b3b] drm/i915: Fix up seqno -> request merge issues
> git bisect bad 146d84f0f2707bfe2c67114eeefac30da8584b3b
> # good: [c59cb179aaf444931cf9c547a514e383da3d2526] drm/i915: Consolidate top-level .update_plane() handlers
> git bisect good c59cb179aaf444931cf9c547a514e383da3d2526
> # bad: [cf4c7c12258ed9367f4fc45238f5f50d2db892c1] drm/i915: Make all plane disables use 'update_plane' (v5)
> git bisect bad cf4c7c12258ed9367f4fc45238f5f50d2db892c1
> # good: [e614c3c946ae5b50a679d65d2c981615d8ceccab] drm/i915: Ensure state->crtc is non-NULL for plane updates
> git bisect good e614c3c946ae5b50a679d65d2c981615d8ceccab
> # first bad commit: [cf4c7c12258ed9367f4fc45238f5f50d2db892c1] drm/i915: Make all plane disables use 'update_plane' (v5)
> -- 
> Michal Hocko
> SUSE Labs
> _______________________________________________
> dri-devel mailing list
> dri-devel@lists.freedesktop.org
> http://lists.freedesktop.org/mailman/listinfo/dri-devel

-- 
Jani Nikula, Intel Open Source Technology Center
_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: WARNING: CPU: 0 PID: 3634 at drivers/gpu/drm/drm_irq.c:1141 drm_wait_one_vblank

[Daniel Vetter]

On Wed, Jul 01, 2015 at 03:23:39PM +0300, Jani Nikula wrote:
> 
> +intel-gfx and Matt
> 
> On Wed, 01 Jul 2015, Michal Hocko <mhocko@suse.cz> wrote:
> > On Wed 01-07-15 10:26:39, Daniel Vetter wrote:
> >> On Tue, Jun 30, 2015 at 10:13:35PM +0200, Michal Hocko wrote:
> >> > On Tue 30-06-15 18:59:29, Daniel Vetter wrote:
> > [...]
> >> > > Also it might be time to start bisecting this if you can readily reproduce it.
> >> > 
> >> > Yes, I can reproduce it just by switching to the text console. Sometimes
> >> > it is the first attempt already but sometimes it takes several attempts.
> >> > I will try to go back to 4.0 and bisect it then.
> >> 
> >> Yes please do, since this is a confusing regression I think the bisect
> >> result will be the fastest way forward.
> >
> > OK, managed to bisect to cf4c7c12258e ("drm/i915: Make all plane
> > disables use 'update_plane' (v5)") (CC people involved - the thread
> > starts here: http://marc.info/?l=dri-devel&m=143566543432613&w=2 for
> > your reference).
> >
> > I do not see the warning when I revert the commit directly on top of
> > cf4c7c12258e but I cannot cleanly revert it on top of the current Linus'
> > tree. Anything more I can give you to help to further debug the issue?

Ok still haven't grown much clue unfortunately. The bisect just points at
where we started to do that vblank_wait in the codepath that somehow
breaks for you. But we should check whether vblank will work beforehand or
not. It's also strange that it only fails sporadically. Can you please
boot with drm.debug=0xf (lots more nois in dmesg with this) and reproduce?
I only need the last few pages before the WARNING backtrace, just to
understand a bit better what's going on there.

Thanks, Daniel
> >
> > Bisect log is:
> > git bisect start
> > # bad: [c517d838eb7d07bbe9507871fab3931deccff539] Linux 4.0-rc1
> > git bisect bad c517d838eb7d07bbe9507871fab3931deccff539
> > # good: [bfa76d49576599a4b9f9b7a71f23d73d6dcff735] Linux 3.19
> > git bisect good bfa76d49576599a4b9f9b7a71f23d73d6dcff735
> > # good: [02f1f2170d2831b3233e91091c60a66622f29e82] kernel.h: remove ancient __FUNCTION__ hack
> > git bisect good 02f1f2170d2831b3233e91091c60a66622f29e82
> > # bad: [796e1c55717e9a6ff5c81b12289ffa1ffd919b6f] Merge branch 'drm-next' of git://people.freedesktop.org/~airlied/linux
> > git bisect bad 796e1c55717e9a6ff5c81b12289ffa1ffd919b6f
> > # good: [9682ec9692e5ac11c6caebd079324e727b19e7ce] Merge tag 'driver-core-3.20-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/driver-core
> > git bisect good 9682ec9692e5ac11c6caebd079324e727b19e7ce
> > # good: [a9724125ad014decf008d782e60447c811391326] Merge tag 'tty-3.20-rc1' of git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/tty
> > git bisect good a9724125ad014decf008d782e60447c811391326
> > # bad: [f43dff0ee00a259f524ce17ba4f8030553c66590] Merge tag 'drm-amdkfd-next-fixes-2015-01-25' of git://people.freedesktop.org/~gabbayo/linux into drm-next
> > git bisect bad f43dff0ee00a259f524ce17ba4f8030553c66590
> > # good: [b942c653ae265abbd31032f3b4f5f857e5c7c723] Merge tag 'trace-sh-3.19' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace
> > git bisect good b942c653ae265abbd31032f3b4f5f857e5c7c723
> > # good: [fcf3aac5fc307f0cae429f5844ddc25761662858] drm/i915: remove unused power_well/get_cdclk_freq api
> > git bisect good fcf3aac5fc307f0cae429f5844ddc25761662858
> > # bad: [4f4d89af78682f2ed1cf6745794804817f867bba] Merge tag 'drm-amdkfd-next-2015-01-09' of git://people.freedesktop.org/~gabbayo/linux into drm-next
> > git bisect bad 4f4d89af78682f2ed1cf6745794804817f867bba
> > # bad: [64387b613a43713d0e03d9d43bfbb1727e8475e1] drm/i915: Protect against leaks in pipe_crc_set_source
> > git bisect bad 64387b613a43713d0e03d9d43bfbb1727e8475e1
> > # good: [bfc882b4e30fbc169ecfe3508378623743806f56] drm/i915: Flatten engine init control flow
> > git bisect good bfc882b4e30fbc169ecfe3508378623743806f56
> > # good: [2b875c22fa77dfc895d3cf8287a553813d3e64c8] drm/i915: Make intel_plane_state subclass drm_plane_state
> > git bisect good 2b875c22fa77dfc895d3cf8287a553813d3e64c8
> > # bad: [15a17aae5f803551981a7acc6a4058b247a7452c] drm/i915: Check mask/bit helper functions
> > git bisect bad 15a17aae5f803551981a7acc6a4058b247a7452c
> > # bad: [146d84f0f2707bfe2c67114eeefac30da8584b3b] drm/i915: Fix up seqno -> request merge issues
> > git bisect bad 146d84f0f2707bfe2c67114eeefac30da8584b3b
> > # good: [c59cb179aaf444931cf9c547a514e383da3d2526] drm/i915: Consolidate top-level .update_plane() handlers
> > git bisect good c59cb179aaf444931cf9c547a514e383da3d2526
> > # bad: [cf4c7c12258ed9367f4fc45238f5f50d2db892c1] drm/i915: Make all plane disables use 'update_plane' (v5)
> > git bisect bad cf4c7c12258ed9367f4fc45238f5f50d2db892c1
> > # good: [e614c3c946ae5b50a679d65d2c981615d8ceccab] drm/i915: Ensure state->crtc is non-NULL for plane updates
> > git bisect good e614c3c946ae5b50a679d65d2c981615d8ceccab
> > # first bad commit: [cf4c7c12258ed9367f4fc45238f5f50d2db892c1] drm/i915: Make all plane disables use 'update_plane' (v5)
> > -- 
> > Michal Hocko
> > SUSE Labs
> > _______________________________________________
> > dri-devel mailing list
> > dri-devel@lists.freedesktop.org
> > http://lists.freedesktop.org/mailman/listinfo/dri-devel
> 
> -- 
> Jani Nikula, Intel Open Source Technology Center

-- 
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch
_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/dri-devel

Re: WARNING: CPU: 0 PID: 3634 at drivers/gpu/drm/drm_irq.c:1141 drm_wait_one_vblank

[Michal Hocko]

I have just tried to boot 4.2-rc1 and cannot seem to reproduce the issue
anymore.

On Tue 07-07-15 10:43:58, Daniel Vetter wrote:
[...]
> Can you please
> boot with drm.debug=0xf (lots more nois in dmesg with this) and reproduce?
> I only need the last few pages before the WARNING backtrace, just to
> understand a bit better what's going on there.

And 0xf debug level seem to paper over the problem because I do not see
the warning even with 4.1 where I am able to reproduce this reliably.
This suggests this is a timing sensitive issue.
-- 
Michal Hocko
SUSE Labs
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: WARNING: CPU: 0 PID: 3634 at drivers/gpu/drm/drm_irq.c:1141 drm_wait_one_vblank

[Daniel Vetter]

On Wed, Jul 08, 2015 at 08:40:17AM +0200, Michal Hocko wrote:
> I have just tried to boot 4.2-rc1 and cannot seem to reproduce the issue
> anymore.
> 
> On Tue 07-07-15 10:43:58, Daniel Vetter wrote:
> [...]
> > Can you please
> > boot with drm.debug=0xf (lots more nois in dmesg with this) and reproduce?
> > I only need the last few pages before the WARNING backtrace, just to
> > understand a bit better what's going on there.
> 
> And 0xf debug level seem to paper over the problem because I do not see
> the warning even with 4.1 where I am able to reproduce this reliably.
> This suggests this is a timing sensitive issue.

Ok that's starting to get nasty. Can you please test what happens when you
boot with drm.vblankoffdelay=0 and whether drm.vblankoffdelay=1000 has an
effect on reproduction rate? No debug output needed.
-Daniel
-- 
Daniel Vetter
Software Engineer, Intel Corporation
http://blog.ffwll.ch
_______________________________________________
Intel-gfx mailing list
Intel-gfx@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/intel-gfx

Re: WARNING: CPU: 0 PID: 3634 at drivers/gpu/drm/drm_irq.c:1141 drm_wait_one_vblank

[Michal Hocko]

[-- Attachment #1: Type: text/plain, Size: 348 bytes --]

On Wed 08-07-15 09:32:18, Daniel Vetter wrote:
[...]
> Ok that's starting to get nasty. Can you please test what happens when you
> boot with drm.vblankoffdelay=0 and whether drm.vblankoffdelay=1000 has an
> effect on reproduction rate? No debug output needed.

No difference. See the kernel log from both runs attached.
-- 
Michal Hocko
SUSE Labs

[-- Attachment #2: log.gz --]
[-- Type: application/gzip, Size: 32451 bytes --]

[-- Attachment #3: Type: text/plain, Size: 159 bytes --]

_______________________________________________
dri-devel mailing list
dri-devel@lists.freedesktop.org
http://lists.freedesktop.org/mailman/listinfo/dri-devel