Re: (radeon?) WARNING: drivers/gpu/drm/drm_irq.c:1195 drm_vblank_put (v4.11-12441-g56868a4)

From: Tommi Rantala
Date: Thu May 18 2017 - 12:44:02 EST


2017-05-11 5:51 GMT+03:00 Michel DÃnzer <michel@xxxxxxxxxxx>:
> On 11/05/17 04:33 AM, Tommi Rantala wrote:
>> Complete kernel log:
>> http://termbin.com/dzy5
>>
>> [ 249.952546] ------------[ cut here ]------------
>> [ 249.952593] WARNING: CPU: 5 PID: 0 at
>> /home/ttrantal/git/linux/drivers/gpu/drm/drm_irq.c:1195
>> drm_vblank_put+0xc4/0x120 [drm]
>> [ 249.952596] Modules linked in: fuse tun bridge stp llc af_packet
>> pl2303 usbserial shpchp acpi_cpufreq binfmt_misc amdgpu hid_generic
>> uhci_hcd radeon 3c59x mii tg3 ehci_pci ehci_hcd i2c_algo_bit
>> drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ttm drm
>> agpgart unix autofs4
>> [ 249.952675] CPU: 5 PID: 0 Comm: swapper/5 Tainted: G W
>> 4.11.0+ #4
>> [ 249.952678] Hardware name: Hewlett-Packard HP xw6600
>> Workstation/0A9Ch, BIOS 786F4 v01.46 09/20/2012
>> [ 249.952681] task: ffff88080aea0000 task.stack: ffffc900031b0000
>> [ 249.952695] RIP: 0010:drm_vblank_put+0xc4/0x120 [drm]
>> [ 249.952698] RSP: 0018:ffff88080f003d70 EFLAGS: 00010046
>> [ 249.952703] RAX: 0000000000000000 RBX: ffff880801d53000 RCX: 0000000000000000
>> [ 249.952706] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff88080a4ac000
>> [ 249.952709] RBP: ffff88080f003d88 R08: 0000000000000001 R09: 0000000000000003
>> [ 249.952711] R10: ffff88080f003d08 R11: 00000000001da540 R12: ffff88080a4ac000
>> [ 249.952714] R13: 0000000000000000 R14: 0000000000000086 R15: ffff8808019a0000
>> [ 249.952717] FS: 0000000000000000(0000) GS:ffff88080f000000(0000)
>> knlGS:0000000000000000
>> [ 249.952720] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
>> [ 249.952723] CR2: 00007f8bcc3a5810 CR3: 0000000808789000 CR4: 00000000000006e0
>> [ 249.952726] Call Trace:
>> [ 249.952731] <IRQ>
>> [ 249.952746] drm_crtc_vblank_put+0x1b/0x30 [drm]
>> [ 249.952813] radeon_crtc_handle_flip+0xdc/0x140 [radeon]
>> [ 249.952843] si_irq_process+0x610/0x1e90 [radeon]
>> [ 249.952872] radeon_driver_irq_handler_kms+0x39/0xc0 [radeon]
>> [ 249.952881] __handle_irq_event_percpu+0x60/0x580
>> [ 249.952887] handle_irq_event_percpu+0x20/0x90
>> [ 249.952892] handle_irq_event+0x46/0xb0
>> [ 249.952897] handle_edge_irq+0x13d/0x370
>> [ 249.952903] handle_irq+0x66/0x210
>> [ 249.952908] ? __local_bh_enable+0x34/0x50
>> [ 249.952914] do_IRQ+0x7e/0x1b0
>> [ 249.952920] common_interrupt+0x95/0x95
>
> Weird, not sure how this could happen. Can you bisect?

Hi,

Bisection points to this (also manually applied commit 9739e74646
while testing, got kernel oops otherwise):

commit 29dc0d1de18239cf3ef8bab578b8321ed340d81c
Author: Daniel Vetter <daniel.vetter@xxxxxxxx>
Date: Wed Mar 22 22:50:49 2017 +0100

drm: Roll out acquire context for the page_flip ioctl

Again just prep work.

Reviewed-by: Harry Wentland <harry.wentland@xxxxxxx>
Signed-off-by: Daniel Vetter <daniel.vetter@xxxxxxxxx>
Link: http://patchwork.freedesktop.org/patch/msgid/20170322215058.8671-11-daniel.vetter@xxxxxxxx


I'm also seeing some more warnings in this version:


May 18 19:21:55 xw6600 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): enp14s0:
link becomes ready
May 18 19:21:57 xw6600 kernel: ------------[ cut here ]------------
May 18 19:21:57 xw6600 kernel: WARNING: CPU: 5 PID: 4607 at
/home/ttrantal/git/linux/drivers/gpu/drm/drm_modeset_lock.c:193
drm_modeset_lock_crtc+0xe5/0x100 [drm]
May 18 19:21:57 xw6600 kernel: Modules linked in: tun bridge stp llc
af_packet pl2303 usbserial shpchp acpi_cpufreq binfmt_misc amdgpu
hid_generic uhci_hcd radeon 3c59x mii i2c_algo_bit drm_kms_helper tg3
syscopyarea sysfillrect sysimgblt
May 18 19:21:57 xw6600 kernel: CPU: 5 PID: 4607 Comm: gnome-shell Not
tainted 4.11.0-rc3-00944-g29dc0d1-dirty #30
May 18 19:21:57 xw6600 kernel: Hardware name: Hewlett-Packard HP
xw6600 Workstation/0A9Ch, BIOS 786F4 v01.46 09/20/2012
May 18 19:21:57 xw6600 kernel: Call Trace:
May 18 19:21:57 xw6600 kernel: dump_stack+0x69/0x9b
May 18 19:21:57 xw6600 kernel: __warn+0xff/0x140
May 18 19:21:57 xw6600 kernel: warn_slowpath_null+0x18/0x20
May 18 19:21:57 xw6600 kernel: drm_modeset_lock_crtc+0xe5/0x100 [drm]
May 18 19:21:57 xw6600 kernel: drm_mode_cursor_common+0xbd/0x200 [drm]
May 18 19:21:57 xw6600 kernel: drm_mode_cursor_ioctl+0x3c/0x40 [drm]
May 18 19:21:57 xw6600 kernel: drm_ioctl+0x3ea/0x870 [drm]
May 18 19:21:57 xw6600 kernel: ? drm_mode_setplane+0x1a0/0x1a0 [drm]
May 18 19:21:57 xw6600 kernel: ? trace_hardirqs_on_caller+0x1ad/0x2c0
May 18 19:21:57 xw6600 kernel: ? trace_hardirqs_on+0xd/0x10
May 18 19:21:57 xw6600 kernel: radeon_drm_ioctl+0x6e/0x110 [radeon]
May 18 19:21:57 xw6600 kernel: do_vfs_ioctl+0xac/0x9d0
May 18 19:21:57 xw6600 kernel: ? security_file_ioctl+0x4c/0x80
May 18 19:21:57 xw6600 kernel: SyS_ioctl+0x74/0x80
May 18 19:21:57 xw6600 kernel: entry_SYSCALL_64_fastpath+0x18/0xad
May 18 19:21:57 xw6600 kernel: RIP: 0033:0x7f98d9e52787
May 18 19:21:57 xw6600 kernel: RSP: 002b:00007ffe12ca5938 EFLAGS:
00000246 ORIG_RAX: 0000000000000010
May 18 19:21:57 xw6600 kernel: RAX: ffffffffffffffda RBX:
0000000000000046 RCX: 00007f98d9e52787
May 18 19:21:57 xw6600 kernel: RDX: 00007ffe12ca5970 RSI:
00000000c01c64a3 RDI: 0000000000000008
May 18 19:21:57 xw6600 kernel: RBP: 000000000000000b R08:
0000000000000000 R09: 0000560c5a5c9ac0
May 18 19:21:57 xw6600 kernel: R10: 0000560c5a2988d8 R11:
0000000000000246 R12: 0000000000000008
May 18 19:21:57 xw6600 kernel: R13: 0000000000000001 R14:
0000560c5c121d20 R15: 0000560c5a30ded0
May 18 19:21:57 xw6600 kernel: ---[ end trace bbca894b04cf0b16 ]---
May 18 19:21:57 xw6600 kernel: ------------[ cut here ]------------
May 18 19:21:57 xw6600 kernel: WARNING: CPU: 5 PID: 4607 at
/home/ttrantal/git/linux/drivers/gpu/drm/drm_modeset_lock.c:193
drm_modeset_lock_crtc+0xe5/0x100 [drm]
May 18 19:21:57 xw6600 kernel: Modules linked in: tun bridge stp llc
af_packet pl2303 usbserial shpchp acpi_cpufreq binfmt_misc amdgpu
hid_generic uhci_hcd radeon 3c59x mii i2c_algo_bit drm_kms_helper tg3
syscopyarea sysfillrect sysimgblt
May 18 19:21:57 xw6600 kernel: CPU: 5 PID: 4607 Comm: gnome-shell
Tainted: G W 4.11.0-rc3-00944-g29dc0d1-dirty #30
May 18 19:21:57 xw6600 kernel: Hardware name: Hewlett-Packard HP
xw6600 Workstation/0A9Ch, BIOS 786F4 v01.46 09/20/2012
May 18 19:21:57 xw6600 kernel: Call Trace:
May 18 19:21:57 xw6600 kernel: dump_stack+0x69/0x9b
May 18 19:21:57 xw6600 kernel: __warn+0xff/0x140
May 18 19:21:57 xw6600 kernel: warn_slowpath_null+0x18/0x20
May 18 19:21:57 xw6600 kernel: drm_modeset_lock_crtc+0xe5/0x100 [drm]
May 18 19:21:57 xw6600 kernel: drm_mode_getcrtc+0x82/0x2c0 [drm]
May 18 19:21:57 xw6600 kernel: drm_ioctl+0x3ea/0x870 [drm]
May 18 19:21:57 xw6600 kernel: ? drm_crtc_create_fence+0x80/0x80 [drm]
May 18 19:21:57 xw6600 kernel: radeon_drm_ioctl+0x6e/0x110 [radeon]
May 18 19:21:57 xw6600 kernel: do_vfs_ioctl+0xac/0x9d0
May 18 19:21:57 xw6600 kernel: ? security_file_ioctl+0x4c/0x80
May 18 19:21:57 xw6600 kernel: SyS_ioctl+0x74/0x80
May 18 19:21:57 xw6600 kernel: entry_SYSCALL_64_fastpath+0x18/0xad
May 18 19:21:57 xw6600 kernel: RIP: 0033:0x7f98d9e52787
May 18 19:21:57 xw6600 kernel: RSP: 002b:00007ffe12ca53f8 EFLAGS:
00000246 ORIG_RAX: 0000000000000010
May 18 19:21:57 xw6600 kernel: RAX: ffffffffffffffda RBX:
0000000000000046 RCX: 00007f98d9e52787
May 18 19:21:57 xw6600 kernel: RDX: 00007ffe12ca5430 RSI:
00000000c06864a1 RDI: 0000000000000008
May 18 19:21:57 xw6600 kernel: RBP: 0000560c5a2bbdb0 R08:
0000000000000008 R09: 0000560c5a48bf20
May 18 19:21:57 xw6600 kernel: R10: 0000560c5a485330 R11:
0000000000000246 R12: 0000560c5b66a540
May 18 19:21:57 xw6600 kernel: R13: 0000560c5bddaf90 R14:
0000560c5a88e5e0 R15: 00007ffe12c95c40
May 18 19:21:57 xw6600 kernel: ---[ end trace bbca894b04cf0b17 ]---
May 18 19:21:57 xw6600 kernel: ------------[ cut here ]------------
May 18 19:21:57 xw6600 kernel: WARNING: CPU: 1 PID: 0 at
/home/ttrantal/git/linux/drivers/gpu/drm/drm_irq.c:1186
drm_vblank_put+0xec/0x150 [drm]
May 18 19:21:57 xw6600 kernel: Modules linked in: tun bridge stp llc
af_packet pl2303 usbserial shpchp acpi_cpufreq binfmt_misc amdgpu
hid_generic uhci_hcd radeon 3c59x mii i2c_algo_bit drm_kms_helper tg3
syscopyarea sysfillrect sysimgblt
May 18 19:21:57 xw6600 kernel: CPU: 1 PID: 0 Comm: swapper/1 Tainted:
G W 4.11.0-rc3-00944-g29dc0d1-dirty #30
May 18 19:21:57 xw6600 kernel: Hardware name: Hewlett-Packard HP
xw6600 Workstation/0A9Ch, BIOS 786F4 v01.46 09/20/2012
May 18 19:21:57 xw6600 kernel: Call Trace:
May 18 19:21:57 xw6600 kernel: <IRQ>
May 18 19:21:57 xw6600 kernel: dump_stack+0x69/0x9b
May 18 19:21:57 xw6600 kernel: __warn+0xff/0x140
May 18 19:21:57 xw6600 kernel: ? drm_vblank_count_and_time+0x9e/0x1b0 [drm]
May 18 19:21:57 xw6600 kernel: warn_slowpath_null+0x18/0x20
May 18 19:21:57 xw6600 kernel: drm_vblank_put+0xec/0x150 [drm]
May 18 19:21:57 xw6600 kernel: drm_crtc_vblank_put+0x1b/0x30 [drm]
May 18 19:21:57 xw6600 kernel: radeon_crtc_handle_flip+0xdc/0x140 [radeon]
May 18 19:21:57 xw6600 kernel: si_irq_process+0x611/0x1e90 [radeon]
May 18 19:21:57 xw6600 kernel: ? sched_clock_cpu+0x1c/0x160
May 18 19:21:57 xw6600 kernel: radeon_driver_irq_handler_kms+0x39/0xc0 [radeon]
May 18 19:21:57 xw6600 kernel: __handle_irq_event_percpu+0x60/0x590
May 18 19:21:57 xw6600 kernel: handle_irq_event_percpu+0x20/0x90
May 18 19:21:57 xw6600 kernel: handle_irq_event+0x46/0xb0
May 18 19:21:57 xw6600 kernel: handle_edge_irq+0x13d/0x370
May 18 19:21:57 xw6600 kernel: handle_irq+0x66/0x230
May 18 19:21:57 xw6600 kernel: ? __local_bh_enable+0x38/0x90
May 18 19:21:57 xw6600 kernel: ? _local_bh_enable+0x1d/0x60
May 18 19:21:57 xw6600 kernel: do_IRQ+0x7e/0x1b0
May 18 19:21:57 xw6600 kernel: common_interrupt+0x95/0x95
May 18 19:21:57 xw6600 kernel: RIP: 0010:mwait_idle+0x9c/0x3a0
May 18 19:21:57 xw6600 kernel: RSP: 0018:ffffc90003193e68 EFLAGS:
00000246 ORIG_RAX: ffffffffffffff4d
May 18 19:21:57 xw6600 kernel: RAX: 0000000000000000 RBX:
ffff88080ae71900 RCX: 0000000000000000
May 18 19:21:57 xw6600 kernel: RDX: 0000000000000001 RSI:
0000000000000001 RDI: ffff88080ae71900
May 18 19:21:57 xw6600 kernel: RBP: ffffc90003193e98 R08:
0000000000000006 R09: 0000000000000000
May 18 19:21:57 xw6600 kernel: R10: 0000000000000000 R11:
0000000000000000 R12: ffff88080ae71900
May 18 19:21:57 xw6600 kernel: R13: 0000000000000001 R14:
ffffffff839cbd28 R15: 0000000000000000
May 18 19:21:57 xw6600 kernel: </IRQ>
May 18 19:21:57 xw6600 kernel: ? mwait_idle+0x93/0x3a0
May 18 19:21:57 xw6600 kernel: arch_cpu_idle+0xa/0x10
May 18 19:21:57 xw6600 kernel: default_idle_call+0x24/0x40
May 18 19:21:57 xw6600 kernel: do_idle+0x154/0x230
May 18 19:21:57 xw6600 kernel: cpu_startup_entry+0x18/0x20
May 18 19:21:57 xw6600 kernel: start_secondary+0x159/0x1f0
May 18 19:21:57 xw6600 kernel: start_cpu+0x14/0x14
May 18 19:21:57 xw6600 kernel: ---[ end trace bbca894b04cf0b18 ]---
May 18 19:21:57 xw6600 kernel: ------------[ cut here ]------------


-Tommi