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

Thu Feb 5 03:01:57 PST 2015

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

-- 
Chris Wilson, Intel Open Source Technology Centre