Hi all,
I am running some experiments on my laptop, based on an Intel i5 CPU
("Intel(R) Core(TM) i5-5200U CPU @ 2.20GHz", according to
/proc/cpuinfo), and cyclictest shows high latencies with both
4.14.78-rt47 and 4.19.1-rt3 (of course, I enabled PREEMPT_RT_FULL).
In particular, even if I disable hypertreading (by putting offline
"cpus" 2 and 3), I can easily trigger latencies larger than 200us.
While running some of these experiments with cyclictest, I found the
attached BUG() in dmesg... Since it seems to indicate a problem in the
i915 driver (looks like there is a spinlock - "uncore.lock"? - that is
locked when preemption is disabled, or something similar... Should it
be a raw spinlock?), I recompiled the kernel with the i915 driver
disabled.
Now the graphical interface is very slow (and the window system
consumes a large amount of CPU), but the maximum latency stays easily
below 50us for very large amounts of times...
So, I am wondering if there is some known issue with the i915 driver
and real-time... In case this is not a known issue, I can run
additional tests and provide more data if needed.
Thanks,
Luca
[89839.494438] BUG: scheduling while atomic: kworker/u8:2/15203/0x00000003
[89839.494439] Modules linked in: ccm rfcomm cmac bnep rtsx_usb_ms memstick binfmt_misc uvcvideo videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common videodev media btusb btrtl btbcm btintel bluetooth ecdh_generic wmi_bmof acer_wmi sparse_keymap nls_iso8859_1 intel_rapl intel_powerclamp coretemp kvm_intel kvm joydev irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc aesni_intel aes_x86_64 crypto_simd cryptd glue_helper intel_cstate intel_rapl_perf hid_multitouch input_leds arc4 serio_raw iwlmvm mac80211 intel_pch_thermal iwlwifi cfg80211 lpc_ich snd_hda_codec_realtek snd_hda_codec_generic wmi snd_hda_codec_hdmi snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm snd_seq snd_timer snd_seq_device mac_hid snd mei_me acpi_pad mei soundcore sch_fq_codel parport_pc ppdev
[89839.494472] lp parport ip_tables x_tables autofs4 dm_mirror dm_region_hash dm_log rtsx_usb_sdmmc rtsx_usb i915 hid_generic i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ahci r8169 i2c_i801 libahci drm i2c_hid video hid
[89839.494485] CPU: 1 PID: 15203 Comm: kworker/u8:2 Not tainted 4.19.1-rt3 #10
[89839.494485] Hardware name: Acer TravelMate P236-M/TravelMate P236-M, BIOS V1.22 06/28/2016
[89839.494528] Workqueue: events_unbound intel_atomic_commit_work [i915]
[89839.494529] Call Trace:
[89839.494536] dump_stack+0x63/0x85
[89839.494539] __schedule_bug+0x55/0x70
[89839.494542] __schedule+0x506/0x710
[89839.494545] schedule+0x3a/0xe0
[89839.494547] rt_spin_lock_slowlock_locked+0xf3/0x280
[89839.494549] rt_spin_lock_slowlock+0x57/0x90
[89839.494551] rt_spin_lock+0x3f/0x50
[89839.494578] gen6_read32+0x45/0x1d0 [i915]
[89839.494595] g4x_get_vblank_counter+0x36/0x40 [i915]
[89839.494618] trace_event_raw_event_i915_pipe_update_start+0x7d/0xf0 [i915]
[89839.494643] intel_pipe_update_start+0x39c/0x410 [i915]
[89839.494646] ? wait_woken+0x80/0x80
[89839.494670] intel_begin_crtc_commit+0x62/0x1b0 [i915]
[89839.494672] ? __rt_mutex_unlock+0xe/0x10
[89839.494682] drm_atomic_helper_commit_planes_on_crtc+0x71/0x1f0 [drm_kms_helper]
[89839.494706] intel_update_crtc+0x80/0xa0 [i915]
[89839.494727] intel_update_crtcs+0x54/0x70 [i915]
[89839.494745] intel_atomic_commit_tail+0x1fb/0xd60 [i915]
[89839.494748] ? preempt_schedule_notrace+0x5c/0xb0
[89839.494767] intel_atomic_commit_work+0x12/0x20 [i915]
[89839.494770] process_one_work+0x1dd/0x460
[89839.494772] worker_thread+0x34/0x430
[89839.494774] kthread+0x121/0x140
[89839.494776] ? process_one_work+0x460/0x460
[89839.494778] ? kthread_create_worker_on_cpu+0x70/0x70
[89839.494780] ret_from_fork+0x35/0x40
[89839.494789] WARNING: CPU: 1 PID: 15203 at /home/luca/Src/Kernel/RT/linux-4.19.1/kernel/sched/core.c:7281 migrate_enable+0x283/0x310
[89839.494789] Modules linked in: ccm rfcomm cmac bnep rtsx_usb_ms memstick binfmt_misc uvcvideo videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common videodev media btusb btrtl btbcm btintel bluetooth ecdh_generic wmi_bmof acer_wmi sparse_keymap nls_iso8859_1 intel_rapl intel_powerclamp coretemp kvm_intel kvm joydev irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc aesni_intel aes_x86_64 crypto_simd cryptd glue_helper intel_cstate intel_rapl_perf hid_multitouch input_leds arc4 serio_raw iwlmvm mac80211 intel_pch_thermal iwlwifi cfg80211 lpc_ich snd_hda_codec_realtek snd_hda_codec_generic wmi snd_hda_codec_hdmi snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm snd_seq snd_timer snd_seq_device mac_hid snd mei_me acpi_pad mei soundcore sch_fq_codel parport_pc ppdev
[89839.494812] lp parport ip_tables x_tables autofs4 dm_mirror dm_region_hash dm_log rtsx_usb_sdmmc rtsx_usb i915 hid_generic i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ahci r8169 i2c_i801 libahci drm i2c_hid video hid
[89839.494822] CPU: 1 PID: 15203 Comm: kworker/u8:2 Tainted: G W 4.19.1-rt3 #10
[89839.494823] Hardware name: Acer TravelMate P236-M/TravelMate P236-M, BIOS V1.22 06/28/2016
[89839.494842] Workqueue: events_unbound intel_atomic_commit_work [i915]
[89839.494845] RIP: 0010:migrate_enable+0x283/0x310
[89839.494846] Code: 75 2f e8 e5 ec f4 ff e9 10 fe ff ff 81 e2 ff ff ff 7f 75 e5 8b 48 0c 85 c9 75 de 48 8b 00 f6 c4 02 74 d6 eb cf e8 ad 85 0c 00 <0f> 0b e9 ca fd ff ff 65 48 8b 04 25 c0 5d 01 00 8b 50 0c 85 d2 0f
[89839.494847] RSP: 0018:ffffb4cb81c3bb68 EFLAGS: 00010246
[89839.494848] RAX: 0000000000000000 RBX: ffff9be70835a700 RCX: ffff9be71a40a008
[89839.494849] RDX: 0000000000000000 RSI: 0000000000100000 RDI: ffff9be71a40a000
[89839.494850] RBP: ffffb4cb81c3bba8 R08: ffffb4cb81c3bb28 R09: 0000000000000001
[89839.494850] R10: 0000000000000000 R11: 0000000000000001 R12: 0000000000070040
[89839.494851] R13: ffff9be714a70a30 R14: 0000000000000001 R15: 000000000007e665
[89839.494853] FS: 0000000000000000(0000) GS:ffff9be71aa80000(0000) knlGS:0000000000000000
[89839.494854] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[89839.494855] CR2: 00007f54270c9000 CR3: 0000000006e0e006 CR4: 00000000003606e0
[89839.494856] Call Trace:
[89839.494858] rt_spin_unlock+0x27/0x40
[89839.494881] gen6_read32+0x7b/0x1d0 [i915]
[89839.494897] g4x_get_vblank_counter+0x36/0x40 [i915]
[89839.494918] trace_event_raw_event_i915_pipe_update_start+0x7d/0xf0 [i915]
[89839.494942] intel_pipe_update_start+0x39c/0x410 [i915]
[89839.494945] ? wait_woken+0x80/0x80
[89839.494967] intel_begin_crtc_commit+0x62/0x1b0 [i915]
[89839.494968] ? __rt_mutex_unlock+0xe/0x10
[89839.494976] drm_atomic_helper_commit_planes_on_crtc+0x71/0x1f0 [drm_kms_helper]
[89839.494997] intel_update_crtc+0x80/0xa0 [i915]
[89839.495016] intel_update_crtcs+0x54/0x70 [i915]
[89839.495033] intel_atomic_commit_tail+0x1fb/0xd60 [i915]
[89839.495036] ? preempt_schedule_notrace+0x5c/0xb0
[89839.495054] intel_atomic_commit_work+0x12/0x20 [i915]
[89839.495056] process_one_work+0x1dd/0x460
[89839.495057] worker_thread+0x34/0x430
[89839.495060] kthread+0x121/0x140
[89839.495061] ? process_one_work+0x460/0x460
[89839.495063] ? kthread_create_worker_on_cpu+0x70/0x70
[89839.495065] ret_from_fork+0x35/0x40
[89839.495067] ---[ end trace 0000000000000002 ]---
[89839.495408] WARNING: CPU: 1 PID: 15203 at /home/luca/Src/Kernel/RT/linux-4.19.1/kernel/sched/core.c:7247 migrate_disable+0x16e/0x1e0
[89839.495408] Modules linked in: ccm rfcomm cmac bnep rtsx_usb_ms memstick binfmt_misc uvcvideo videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common videodev media btusb btrtl btbcm btintel bluetooth ecdh_generic wmi_bmof acer_wmi sparse_keymap nls_iso8859_1 intel_rapl intel_powerclamp coretemp kvm_intel kvm joydev irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc aesni_intel aes_x86_64 crypto_simd cryptd glue_helper intel_cstate intel_rapl_perf hid_multitouch input_leds arc4 serio_raw iwlmvm mac80211 intel_pch_thermal iwlwifi cfg80211 lpc_ich snd_hda_codec_realtek snd_hda_codec_generic wmi snd_hda_codec_hdmi snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm snd_seq snd_timer snd_seq_device mac_hid snd mei_me acpi_pad mei soundcore sch_fq_codel parport_pc ppdev
[89839.495433] lp parport ip_tables x_tables autofs4 dm_mirror dm_region_hash dm_log rtsx_usb_sdmmc rtsx_usb i915 hid_generic i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ahci r8169 i2c_i801 libahci drm i2c_hid video hid
[89839.495443] CPU: 1 PID: 15203 Comm: kworker/u8:2 Tainted: G W 4.19.1-rt3 #10
[89839.495443] Hardware name: Acer TravelMate P236-M/TravelMate P236-M, BIOS V1.22 06/28/2016
[89839.495467] Workqueue: events_unbound intel_atomic_commit_work [i915]
[89839.495469] RIP: 0010:migrate_disable+0x16e/0x1e0
[89839.495471] Code: ff ff ff 65 48 8b 04 25 c0 5d 01 00 8b 50 0c 85 d2 0f 85 0f ff ff ff 48 8b 00 f6 c4 02 0f 84 03 ff ff ff eb d4 e8 42 99 0c 00 <0f> 0b e9 d9 fe ff ff 83 bb a0 03 00 00 01 0f 8e 76 ff ff ff 8b 4b
[89839.495471] RSP: 0018:ffffb4cb81c3bba0 EFLAGS: 00010246
[89839.495473] RAX: 0000000000100000 RBX: ffff9be70835a700 RCX: ffff9be71a40a008
[89839.495473] RDX: 0000000000100000 RSI: 0000000000100000 RDI: ffff9be71a40a000
[89839.495474] RBP: ffffb4cb81c3bbc0 R08: 0000000000000246 R09: 0000000000000000
[89839.495475] R10: ffffffffc06a6160 R11: 0000000000000001 R12: ffff9be714a70a30
[89839.495476] R13: ffff9be7157f5800 R14: 0000000000029180 R15: ffff9be715e66000
[89839.495478] FS: 0000000000000000(0000) GS:ffff9be71aa80000(0000) knlGS:0000000000000000
[89839.495478] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[89839.495479] CR2: 00007fefa185d660 CR3: 0000000006e0e006 CR4: 00000000003606e0
[89839.495480] Call Trace:
[89839.495483] rt_spin_lock+0x24/0x50
[89839.495500] intel_get_crtc_scanline+0x21/0x40 [i915]
[89839.495522] trace_event_raw_event_i915_pipe_update_start+0x88/0xf0 [i915]
[89839.495545] intel_pipe_update_start+0x39c/0x410 [i915]
[89839.495548] ? wait_woken+0x80/0x80
[89839.495570] intel_begin_crtc_commit+0x62/0x1b0 [i915]
[89839.495571] ? __rt_mutex_unlock+0xe/0x10
[89839.495581] drm_atomic_helper_commit_planes_on_crtc+0x71/0x1f0 [drm_kms_helper]
[89839.495602] intel_update_crtc+0x80/0xa0 [i915]
[89839.495621] intel_update_crtcs+0x54/0x70 [i915]
[89839.495639] intel_atomic_commit_tail+0x1fb/0xd60 [i915]
[89839.495642] ? preempt_schedule_notrace+0x5c/0xb0
[89839.495659] intel_atomic_commit_work+0x12/0x20 [i915]
[89839.495661] process_one_work+0x1dd/0x460
[89839.495663] worker_thread+0x34/0x430
[89839.495666] kthread+0x121/0x140
[89839.495667] ? process_one_work+0x460/0x460
[89839.495669] ? kthread_create_worker_on_cpu+0x70/0x70
[89839.495671] ret_from_fork+0x35/0x40
[89839.495673] ---[ end trace 0000000000000003 ]---
[89839.495688] BUG: scheduling while atomic: kworker/u8:2/15203/0x7fffffff
[89839.495688] Modules linked in: ccm rfcomm cmac bnep rtsx_usb_ms memstick binfmt_misc uvcvideo videobuf2_vmalloc videobuf2_memops videobuf2_v4l2 videobuf2_common videodev media btusb btrtl btbcm btintel bluetooth ecdh_generic wmi_bmof acer_wmi sparse_keymap nls_iso8859_1 intel_rapl intel_powerclamp coretemp kvm_intel kvm joydev irqbypass crct10dif_pclmul crc32_pclmul ghash_clmulni_intel pcbc aesni_intel aes_x86_64 crypto_simd cryptd glue_helper intel_cstate intel_rapl_perf hid_multitouch input_leds arc4 serio_raw iwlmvm mac80211 intel_pch_thermal iwlwifi cfg80211 lpc_ich snd_hda_codec_realtek snd_hda_codec_generic wmi snd_hda_codec_hdmi snd_hda_intel snd_hda_codec snd_hwdep snd_hda_core snd_pcm snd_seq snd_timer snd_seq_device mac_hid snd mei_me acpi_pad mei soundcore sch_fq_codel parport_pc ppdev
[89839.495887] lp parport ip_tables x_tables autofs4 dm_mirror dm_region_hash dm_log rtsx_usb_sdmmc rtsx_usb i915 hid_generic i2c_algo_bit drm_kms_helper syscopyarea sysfillrect sysimgblt fb_sys_fops ahci r8169 i2c_i801 libahci drm i2c_hid video hid
[89839.495947] CPU: 1 PID: 15203 Comm: kworker/u8:2 Tainted: G W 4.19.1-rt3 #10
[89839.495948] Hardware name: Acer TravelMate P236-M/TravelMate P236-M, BIOS V1.22 06/28/2016
[89839.495968] Workqueue: events_unbound intel_atomic_commit_work [i915]
[89839.495969] Call Trace:
[89839.495972] dump_stack+0x63/0x85
[89839.495975] __schedule_bug+0x55/0x70
[89839.495977] __schedule+0x506/0x710
[89839.495979] ? trace_event_raw_event_timer_start+0x55/0xd0
[89839.495982] schedule+0x3a/0xe0
[89839.495983] schedule_timeout+0x1db/0x3e0
[89839.495985] ? __next_timer_interrupt+0xe0/0xe0
[89839.495988] wait_for_completion_timeout+0xcd/0x110
[89839.495994] drm_atomic_helper_wait_for_flip_done+0x73/0xb0 [drm_kms_helper]
[89839.496014] intel_atomic_commit_tail+0x206/0xd60 [i915]
[89839.496016] ? preempt_schedule_notrace+0x5c/0xb0
[89839.496034] intel_atomic_commit_work+0x12/0x20 [i915]
[89839.496036] process_one_work+0x1dd/0x460
[89839.496038] worker_thread+0x34/0x430
[89839.496040] kthread+0x121/0x140
[89839.496042] ? process_one_work+0x460/0x460
[89839.496044] ? kthread_create_worker_on_cpu+0x70/0x70
[89839.496046] ret_from_fork+0x35/0x40
