[Intel-gfx] Kernel 3.19rc6 flooding intel_check_page_flip warnings when using compton

[Dave Gordon]

On 05/02/15 11:01, Chris Wilson wrote:
> On Thu, Feb 05, 2015 at 12:44:21PM +0200, Sakari Kapanen wrote:
>> On 02/04/2015 11:26 AM, Jani Nikula wrote:
>>> On Mon, 02 Feb 2015, Sakari Kapanen <sakari.m.kapanen at student.jyu.fi> wrote:
>>>> Dear maintainers,
>>>>
>>>> On an Asus Zenbook UX32VD laptop with an i5-3317U CPU and Intel HD4000
>>>> graphics, I'm experiencing the following with the latest 3.19rc6
>>>> mainline kernel (built from the Arch Linux AUR package:
>>>> https://aur.archlinux.org/packages/linux-mainline/ ). The problem is
>>>> related to the compton compositor: https://github.com/chjj/compton
>>> Hi, a full dmesg from boot to the problem with drm.debug=14 module
>>> parameter set might be useful. Also, you may get fastest results if you
>>> do a git bisect from a good to bad kernel.
>>>
>>> BR,
>>> Jani.
>>
>> Hi, I did a bisect between 3.18 to 3.19-rc1. I could only narrow it
>> down to ~110
>> commits. They were based on 3.17-rc5 which wouldn't boot on my computer
>> due to an unrelated kernel panic which I couldn't resolve, so I
>> couldn't bisect any
>> further. Sorry about that!
>>
>> I noticed one thing: the warnings I mentioned appear only when threader IRQs
>> are enabled via the `threadirqs` kernel flag. Without that flag, I
>> didn't get any
>> of those warnings on any kernel.
>>
>> I attached the bisect log, in which the commits that were left are
>> shown. Also,
>> there's a dmesg log with drm.debug=14 set. The first warning appears at
>> 4.895940 when X is started (no compton yet). Compton was started at ~14,
>> and the first warning due to it appears at 15.009088.
>>
>> Please let me know if I any other information would be useful.
> 
> The commit you were looking for is:
> 
> commit f326038a29092534b59626f736a3c6e599bda017
> Author: Daniel Vetter <daniel.vetter at ffwll.ch>
> Date:   Mon Sep 15 14:55:23 2014 +0200
> 
>     drm/i915: Clarify event_lock locking, irq&mixed context
>     
>     Now we tackle the functions also called from interrupt handlers.
>     
>     - intel_check_page_flip is exclusively called from irq handlers, so a
>       plain spin_lock is all we need. In i915_irq.c we have the convention
>       to give all such functions an _irq_handler postfix, but that would
>       look strange and als be a bit a misleading name. I've opted for a
>       WARN_ON(!in_irq()) instead.
>     
>     - The other two places left are called both from interrupt handlers
>       and from our reset work, so need the full irqsave dance. Annotate
>       them with a short comment.
>     
>     Reviewed-by: Jesse Barnes <jbarnes at virtuousgeek.org>
>     Signed-off-by: Daniel Vetter <daniel.vetter at ffwll.ch>
> 
> The WARN_ON(!in_irq() fires
> 
>> [    4.889038] [drm:intel_crtc_set_config] [CRTC:8] [FB:33] #connectors=1 (x y) (0 0)
>> [    4.889045] [drm:intel_set_config_compute_mode_changes] computed changes for [CRTC:8], mode_changed=0, fb_changed=1
>> [    4.889050] [drm:intel_modeset_stage_output_state] [CONNECTOR:21:eDP-1] to [CRTC:8]
>> [    4.891027] [drm:ironlake_update_primary_plane] Writing base 0076C000 00000000 0 0 5632
>> [    4.895940] ------------[ cut here ]------------
>> [    4.895980] WARNING: CPU: 1 PID: 248 at drivers/gpu/drm/i915/intel_display.c:9754 intel_check_page_flip+0x99/0xe0 [i915]()
>> [    4.895983] Modules linked in: snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic nls_iso8859_1 nls_cp437 vfat fat joydev mousedev msr coretemp rtsx_usb_ms intel_rapl memstick rtsx_usb_sdmmc uvcvideo x86_pkg_temp_thermal mmc_core videobuf2_vmalloc intel_powerclamp videobuf2_memops videobuf2_core kvm_intel v4l2_common kvm rtsx_usb videodev iTCO_wdt media iTCO_vendor_support arc4 crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel aesni_intel aes_x86_64 glue_helper lrw gf128mul ablk_helper cryptd nouveau
>> [    4.896007] [drm:drm_mode_setcrtc] [CRTC:12]
>> [    4.896009] [drm:intel_crtc_set_config] [CRTC:12] [NOFB]
>> [    4.896011]  snd_hda_intel iwldvm
>> [    4.896013] [drm:intel_set_config_compute_mode_changes] computed changes for [CRTC:12], mode_changed=0, fb_changed=0
>> [    4.896014] [drm:intel_modeset_stage_output_state] [CONNECTOR:21:eDP-1] to [CRTC:8]
>> [    4.896016]  snd_hda_controller
>> [    4.896017]  evdev mac80211
>> [    4.896018] [drm:drm_mode_setcrtc] [CRTC:16]
>> [    4.896018]  psmouse
>> [    4.896019]  serio_raw mac_hid pcspkr snd_hda_codec i2c_i801
>> [    4.896023] [drm:intel_crtc_set_config] [CRTC:16] [NOFB]
>> [    4.896025] [drm:intel_set_config_compute_mode_changes] computed changes for [CRTC:16], mode_changed=0, fb_changed=0
>> [    4.896026] [drm:intel_modeset_stage_output_state] [CONNECTOR:21:eDP-1] to [CRTC:8]
>> [    4.896027]  mxm_wmi i915 ttm snd_hwdep iwlwifi lpc_ich snd_pcm mfd_core snd_timer snd cfg80211 soundcore mei_me mei thermal int3403_thermal fan button i2c_algo_bit drm_kms_helper battery int3400_thermal drm acpi_thermal_rel int3402_thermal i2c_core ac tpm_tis intel_gtt tpm processor shpchp sch_fq_codel ext4 crc16 mbcache jbd2 sd_mod atkbd libps2 xhci_pci ahci xhci_hcd libahci libata ehci_pci ehci_hcd scsi_mod usbcore usb_common i8042 serio asus_nb_wmi asus_wmi hwmon video rfkill sparse_keymap wmi led_class
>> [    4.896064] CPU: 1 PID: 248 Comm: irq/31-i915 Not tainted 3.18.0-rc2-ARCH-00117-gbbf0ef0 #1
>> [    4.896066] Hardware name: ASUSTeK COMPUTER INC. UX32VD/UX32VD, BIOS UX32VD.213 11/16/2012
>> [    4.896068]  0000000000000000 000000000bcd9f26 ffff8800c47cbcd8 ffffffff8152d52f
>> [    4.896071]  0000000000000000 0000000000000000 ffff8800c47cbd18 ffffffff81071bc1
>> [    4.896074]  0000000000000045 ffff8800c4ffb000 ffff8801287ff800 ffff8801287ff800
>> [    4.896077] Call Trace:
>> [    4.896083]  [<ffffffff8152d52f>] dump_stack+0x4e/0x71
>> [    4.896088]  [<ffffffff81071bc1>] warn_slowpath_common+0x81/0xa0
>> [    4.896092]  [<ffffffff81071cda>] warn_slowpath_null+0x1a/0x20
>> [    4.896107]  [<ffffffffa0466019>] intel_check_page_flip+0x99/0xe0 [i915]
>> [    4.896122]  [<ffffffffa04382c0>] ironlake_irq_handler+0x450/0x10b0 [i915]
>> [    4.896127]  [<ffffffff8109d39a>] ? do_set_cpus_allowed+0x4a/0x60
>> [    4.896131]  [<ffffffff8109dfdb>] ? set_cpus_allowed_ptr+0x8b/0x160
>> [    4.896135]  [<ffffffff810caa50>] ? irq_thread_fn+0x50/0x50
>> [    4.896138]  [<ffffffff810caa7e>] irq_forced_thread_fn+0x2e/0x70
>> [    4.896141]  [<ffffffff810cada7>] irq_thread+0x157/0x180
>> [    4.896144]  [<ffffffff810cab90>] ? wake_threads_waitq+0x30/0x30
>> [    4.896147]  [<ffffffff810cac50>] ? irq_thread_dtor+0xc0/0xc0
>> [    4.896150]  [<ffffffff8108fdba>] kthread+0xea/0x100
>> [    4.896154]  [<ffffffff8108fcd0>] ? kthread_create_on_node+0x1c0/0x1c0
>> [    4.896158]  [<ffffffff81532ffc>] ret_from_fork+0x7c/0xb0
>> [    4.896161]  [<ffffffff8108fcd0>] ? kthread_create_on_node+0x1c0/0x1c0
>> [    4.896163] ---[ end trace 517950ad6ce39e66 ]---
> 
> Do we consider !in_irq() unreliable then? Or are we missing some magic
> in our interrupt handler setup?
> -Chris
> 

Looks like in_irq() only tests for being in a real hardware interrupt
and not an interrupt-handler thread, hence the warning when this runs in
such a thread (enabled via 'threadirqs' flag).

.Dave.