Message-ID: <CA+ydwtqxj5rT73dCB-g0=PaTq3UWyvPiLDzSZ5Cu-1wuynpKBA@mail.gmail.com>
Date:   Thu, 18 May 2017 19:43:51 +0300
From:   Tommi Rantala <tt.rantala@...il.com>
To:     Michel Dänzer <michel@...nzer.net>,
        Daniel Vetter <daniel.vetter@...el.com>
Cc:     DRI Development <dri-devel@...ts.freedesktop.org>,
        LKML <linux-kernel@...r.kernel.org>,
        amd-gfx@...ts.freedesktop.org, David Airlie <airlied@...ux.ie>,
        Jani Nikula <jani.nikula@...ux.intel.com>,
        Sean Paul <seanpaul@...omium.org>,
        Alex Deucher <alexander.deucher@....com>,
        Christian König <christian.koenig@....com>
Subject: Re: (radeon?) WARNING: drivers/gpu/drm/drm_irq.c:1195 drm_vblank_put (v4.11-12441-g56868a4)

2017-05-11 5:51 GMT+03:00 Michel Dänzer <michel@...nzer.net>:
> 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@...ll.ch>
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@....com>
    Signed-off-by: Daniel Vetter <daniel.vetter@...el.com>
    Link: http://patchwork.freedesktop.org/patch/msgid/20170322215058.8671-11-daniel.vetter@ffwll.ch


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

Powered by blists - more mailing lists