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

Michal Hocko mhocko at suse.cz
Tue Jun 30 04:57:07 PDT 2015


Hi,
I am getting the following warning when I switch to the text console
from X. I do not know when this has started because I have noticed
that only now (in 4.1 kernel). I can try some older kernels if this is
useful.

I have tried to instrument drm_wait_one_vblank and dump drm_vblank_count
before the wait_event and the value when it returns (see the diff below)
and it seems to be increasing with new switching to the text console:
$ dmesg | grep XXX
[    6.531908] XXX: last:36
[    6.545852] XXX: drm_vblank_count:37
[    9.038658] XXX: last:186
[    9.051332] XXX: drm_vblank_count:187
[    9.051424] XXX: last:187
[    9.068036] XXX: drm_vblank_count:188
[   16.962193] XXX: last:660
[   16.968683] XXX: drm_vblank_count:661
[   30.592874] XXX: last:1476
[   30.598656] XXX: drm_vblank_count:1477
[   30.598768] XXX: last:1477
[   30.615339] XXX: drm_vblank_count:1478
[   37.313338] XXX: last:1879
[   37.330102] XXX: drm_vblank_count:1880
[   39.726809] XXX: last:2023
[   39.735265] XXX: drm_vblank_count:2024
[   39.735375] XXX: last:2024
[   39.752094] XXX: drm_vblank_count:2025
[   60.842401] XXX: last:3287
[   60.848437] XXX: drm_vblank_count:3288
[   62.149546] XXX: last:3365
[   62.151277] XXX: drm_vblank_count:3366
[   62.151411] XXX: last:3366
[   62.249376] XXX: drm_vblank_count:3366
[   92.198305] XXX: last:5160
[   92.297091] XXX: drm_vblank_count:5160
[   93.822331] XXX: last:5253
[   93.922153] XXX: drm_vblank_count:5253
[   93.922424] XXX: last:5254
[   94.022213] XXX: drm_vblank_count:5254
[  100.877802] XXX: last:5665
[  100.974740] XXX: drm_vblank_count:5665

I am sorry about the lack of information in this report but I am really
not sure what might be helpful. I can only tell that I haven't observed
anything wrong going on after the warning so it might be harmless.

Let me know what kind of information might be helpful.

[ 7322.444556] ------------[ cut here ]------------
[ 7322.444569] WARNING: CPU: 0 PID: 3634 at drivers/gpu/drm/drm_irq.c:1141 drm_wait_one_vblank+0x144/0x16f [drm]()
[ 7322.444570] vblank wait timed out on crtc 0
[ 7322.444586] Modules linked in: i915 fbcon cfbfillrect bitblit softcursor cfbimgblt font i2c_algo_bit cfbcopyarea drm_kms_helper drm fb fbdev binfmt_misc snd_hda_codec_hdmi uvcvideo videobuf2_vmalloc videobuf2_memops snd_hda_codec_idt i2c_i801 snd_hda_codec_generic snd_hda_intel snd_hda_controller videobuf2_core arc4 snd_hda_codec snd_hda_core snd_pcm_oss v4l2_common snd_mixer_oss videodev iwldvm media i2c_core mac80211 video iwlwifi backlight snd_pcm sdhci_pci sdhci mmc_core cfg80211 snd_timer snd
[ 7322.444588] CPU: 0 PID: 3634 Comm: Xorg Not tainted 4.1.0 #587
[ 7322.444589] Hardware name: Dell Inc. Latitude E6320/09PHH9, BIOS A08 10/18/2011
[ 7322.444591]  0000000000000009 ffff8800c5bb7888 ffffffff8151b709 0000000080000000
[ 7322.444592]  ffff8800c5bb78d8 ffff8800c5bb78c8 ffffffff8104550a ffff8800c5bb7958
[ 7322.444593]  ffffffffa02d414e 0000000000000000 0000000000000000 ffff8800c58d7000
[ 7322.444594] Call Trace:
[ 7322.444599]  [<ffffffff8151b709>] dump_stack+0x4f/0x7b
[ 7322.444601]  [<ffffffff8104550a>] warn_slowpath_common+0xa1/0xbb
[ 7322.444608]  [<ffffffffa02d414e>] ? drm_wait_one_vblank+0x144/0x16f [drm]
[ 7322.444609]  [<ffffffff8104556a>] warn_slowpath_fmt+0x46/0x48
[ 7322.444611]  [<ffffffff81075b7d>] ? finish_wait+0x59/0x62
[ 7322.444617]  [<ffffffffa02d414e>] drm_wait_one_vblank+0x144/0x16f [drm]
[ 7322.444618]  [<ffffffff81075c9d>] ? wait_woken+0x76/0x76
[ 7322.444624]  [<ffffffffa02d4196>] drm_crtc_wait_one_vblank+0x1d/0x21 [drm]
[ 7322.444628]  [<ffffffffa0331baa>] drm_plane_helper_commit+0x1b3/0x240 [drm_kms_helper]
[ 7322.444631]  [<ffffffffa0331cfe>] drm_plane_helper_update+0xc7/0xd6 [drm_kms_helper]
[ 7322.444652]  [<ffffffffa03cd9a5>] intel_crtc_set_config+0x95e/0xc4f [i915]
[ 7322.444661]  [<ffffffffa02db020>] drm_mode_set_config_internal+0x5c/0xe8 [drm]
[ 7322.444666]  [<ffffffffa0338ae3>] drm_fb_helper_pan_display+0xa2/0xd8 [drm_kms_helper]
[ 7322.444668]  [<ffffffffa02be312>] fb_pan_display+0xee/0x131 [fb]
[ 7322.444670]  [<ffffffffa0353254>] bit_update_start+0x20/0x43 [bitblit]
[ 7322.444672]  [<ffffffffa035fa24>] fbcon_switch+0x3b7/0x438 [fbcon]
[ 7322.444674]  [<ffffffff812f7f0d>] redraw_screen+0x112/0x1e3
[ 7322.444676]  [<ffffffff812f0711>] complete_change_console+0x3e/0xc7
[ 7322.444678]  [<ffffffff812f1684>] vt_ioctl+0xeea/0x117f
[ 7322.444680]  [<ffffffff812e7538>] tty_ioctl+0xa01/0xa74
[ 7322.444682]  [<ffffffff81065154>] ? preempt_count_sub+0xc6/0xd3
[ 7322.444684]  [<ffffffff81156204>] do_vfs_ioctl+0x377/0x425
[ 7322.444685]  [<ffffffff8115e2a9>] ? __fget+0x70/0x7b
[ 7322.444686]  [<ffffffff811562f6>] SyS_ioctl+0x44/0x63
[ 7322.444688]  [<ffffffff81520197>] system_call_fastpath+0x12/0x6a
[ 7322.444689] ---[ end trace 9d3b554e7f553db3 ]---
[ 7326.066994] ------------[ cut here ]------------

Debugging patch
--
diff --git a/drivers/gpu/drm/drm_irq.c b/drivers/gpu/drm/drm_irq.c
index af9662e58272..446f4ce02a9d 100644
--- a/drivers/gpu/drm/drm_irq.c
+++ b/drivers/gpu/drm/drm_irq.c
@@ -1126,17 +1126,19 @@ EXPORT_SYMBOL(drm_crtc_vblank_put);
 void drm_wait_one_vblank(struct drm_device *dev, int crtc)
 {
 	int ret;
-	u32 last;
+	u32 last, l;
 
 	ret = drm_vblank_get(dev, crtc);
 	if (WARN(ret, "vblank not available on crtc %i, ret=%i\n", crtc, ret))
 		return;
 
 	last = drm_vblank_count(dev, crtc);
+	pr_info("XXX: last:%u\n", last);
 
 	ret = wait_event_timeout(dev->vblank[crtc].queue,
-				 last != drm_vblank_count(dev, crtc),
+				 last != (l = drm_vblank_count(dev, crtc)),
 				 msecs_to_jiffies(100));
+	pr_info("XXX: drm_vblank_count:%u\n", l);
 
 	WARN(ret == 0, "vblank wait timed out on crtc %i\n", crtc);
 
-- 
Michal Hocko
SUSE Labs


More information about the dri-devel mailing list