Bug 100113 - [BSW][BAT] kms_pipe_crc_basic/suspend-read-crc-pipe-c causes dmesg warning
Summary: [BSW][BAT] kms_pipe_crc_basic/suspend-read-crc-pipe-c causes dmesg warning
Status: CLOSED WORKSFORME
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: DRI git
Hardware: Other All
: medium normal
Assignee: Intel GFX Bugs mailing list
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2017-03-08 12:40 UTC by Jani Saarinen
Modified: 2017-06-28 20:34 UTC (History)
1 user (show)

See Also:
i915 platform: BSW/CHT
i915 features:


Attachments

Description Jani Saarinen 2017-03-08 12:40:59 UTC
On CI https://intel-gfx-ci.01.org/CI/CI_DRM_2302/fi-bsw-n3050/igt@kms_pipe_crc_basic@suspend-read-crc-pipe-c.html

Not sure what is real component having issue as log indicates issue in swapper

BUG: scheduling while atomic: swapper/1/0/0x00000002
[  537.337380] no locks held by swapper/1/0.
[  537.337385] Modules linked in: vgem intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel lpc_ich snd_hda_codec snd_hwdep snd_hda_core snd_pcm i2c_designware_platform i2c_designware_core i915 r8169 mii prime_numbers sdhci_acpi i2c_hid sdhci mmc_core
[  537.337507] Preemption disabled at:
[  537.337521] [<ffffffff8103d14d>] start_secondary+0x1d/0x120
[  537.337534] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G     U          4.11.0-rc1-CI-CI_DRM_2302+ #1
[  537.337540] Hardware name:                  /NUC5CPYB, BIOS PYBSWCEL.86A.0055.2016.0812.1130 08/12/2016
[  537.337545] Call Trace:
[  537.337559]  dump_stack+0x67/0x92
[  537.337566]  ? start_secondary+0x1d/0x120
[  537.337573]  __schedule_bug+0x7e/0xe0
[  537.337584]  __schedule+0x88c/0xbd0
[  537.337596]  schedule+0x3b/0x90
[  537.337604]  schedule_hrtimeout_range_clock+0xd1/0x150
[  537.337615]  ? __hrtimer_run_queues+0x530/0x530
[  537.337624]  schedule_hrtimeout+0x12/0x20
[  537.337632]  wait_task_inactive+0x288/0x290
[  537.337647]  __kthread_bind_mask+0x19/0x70
[  537.337655]  kthread_unpark+0x62/0x90
[  537.337665]  cpuhp_online_idle+0x50/0x90
[  537.337674]  cpu_startup_entry+0x13/0x20
[  537.337680]  start_secondary+0x102/0x120
[  537.337689]  start_cpu+0x14/0x14
[  537.337713] ------------[ cut here ]------------
[  537.337719] WARNING: CPU: 1 PID: 0 at kernel/locking/lockdep.c:3541 lock_release+0x4e1/0x4f0
[  537.337722] releasing a pinned lock
[  537.337723] Modules linked in: vgem intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel lpc_ich snd_hda_codec snd_hwdep snd_hda_core snd_pcm i2c_designware_platform i2c_designware_core i915 r8169 mii prime_numbers sdhci_acpi i2c_hid sdhci mmc_core
[  537.337754] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G     U  W       4.11.0-rc1-CI-CI_DRM_2302+ #1
[  537.337756] Hardware name:                  /NUC5CPYB, BIOS PYBSWCEL.86A.0055.2016.0812.1130 08/12/2016
[  537.337757] Call Trace:
[  537.337761]  dump_stack+0x67/0x92
[  537.337766]  __warn+0xc6/0xe0
[  537.337771]  ? dequeue_task_idle+0xd/0x30
[  537.337774]  warn_slowpath_fmt+0x4a/0x50
[  537.337779]  lock_release+0x4e1/0x4f0
[  537.337784]  _raw_spin_unlock_irq+0x1a/0x50
[  537.337786]  dequeue_task_idle+0xd/0x30
[  537.337790]  deactivate_task+0x94/0x120
[  537.337794]  __schedule+0x474/0xbd0
[  537.337798]  schedule+0x3b/0x90
[  537.337801]  schedule_hrtimeout_range_clock+0xd1/0x150
[  537.337804]  ? __hrtimer_run_queues+0x530/0x530
[  537.337808]  schedule_hrtimeout+0x12/0x20
[  537.337811]  wait_task_inactive+0x288/0x290
[  537.337816]  __kthread_bind_mask+0x19/0x70
[  537.337819]  kthread_unpark+0x62/0x90
[  537.337823]  cpuhp_online_idle+0x50/0x90
[  537.337826]  cpu_startup_entry+0x13/0x20
[  537.337829]  start_secondary+0x102/0x120
[  537.337832]  start_cpu+0x14/0x14
[  537.337837] ---[ end trace 963bcdb3fd781f1d ]---
[  537.337839] bad: scheduling from the idle thread!
[  537.337845] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G     U  W       4.11.0-rc1-CI-CI_DRM_2302+ #1
[  537.337850] Hardware name:                  /NUC5CPYB, BIOS PYBSWCEL.86A.0055.2016.0812.1130 08/12/2016
[  537.337853] Call Trace:
[  537.337860]  dump_stack+0x67/0x92
[  537.337868]  dequeue_task_idle+0x1e/0x30
[  537.337875]  deactivate_task+0x94/0x120
[  537.337883]  __schedule+0x474/0xbd0
[  537.337895]  schedule+0x3b/0x90
[  537.337902]  schedule_hrtimeout_range_clock+0xd1/0x150
[  537.337910]  ? __hrtimer_run_queues+0x530/0x530
[  537.337920]  schedule_hrtimeout+0x12/0x20
[  537.337926]  wait_task_inactive+0x288/0x290
[  537.337939]  __kthread_bind_mask+0x19/0x70
[  537.337947]  kthread_unpark+0x62/0x90
[  537.337954]  cpuhp_online_idle+0x50/0x90
[  537.337962]  cpu_startup_entry+0x13/0x20
[  537.337968]  start_secondary+0x102/0x120
[  537.337975]  start_cpu+0x14/0x14
[  537.337994] ------------[ cut here ]------------
[  537.337999] WARNING: CPU: 1 PID: 0 at kernel/locking/lockdep.c:3663 lock_unpin_lock+0x15b/0x160
[  537.338000] unpinning an unpinned lock
[  537.338001] Modules linked in: vgem intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel lpc_ich snd_hda_codec snd_hwdep snd_hda_core snd_pcm i2c_designware_platform i2c_designware_core i915 r8169 mii prime_numbers sdhci_acpi i2c_hid sdhci mmc_core
[  537.338031] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G     U  W       4.11.0-rc1-CI-CI_DRM_2302+ #1
[  537.338033] Hardware name:                  /NUC5CPYB, BIOS PYBSWCEL.86A.0055.2016.0812.1130 08/12/2016
[  537.338034] Call Trace:
[  537.338038]  dump_stack+0x67/0x92
[  537.338042]  __warn+0xc6/0xe0
[  537.338046]  warn_slowpath_fmt+0x4a/0x50
[  537.338050]  lock_unpin_lock+0x15b/0x160
[  537.338054]  __schedule+0x2e5/0xbd0
[  537.338059]  schedule+0x3b/0x90
[  537.338062]  schedule_hrtimeout_range_clock+0xd1/0x150
[  537.338065]  ? __hrtimer_run_queues+0x530/0x530
[  537.338069]  schedule_hrtimeout+0x12/0x20
[  537.338074]  wait_task_inactive+0x288/0x290
[  537.338078]  __kthread_bind_mask+0x19/0x70
[  537.338081]  kthread_unpark+0x62/0x90
[  537.338085]  cpuhp_online_idle+0x50/0x90
[  537.338088]  cpu_startup_entry+0x13/0x20
[  537.338091]  start_secondary+0x102/0x120
[  537.338095]  start_cpu+0x14/0x14
[  537.338099] ---[ end trace 963bcdb3fd781f1e ]---
[  537.338905] ------------[ cut here ]------------
[  537.339215] WARNING: CPU: 1 PID: 0 at kernel/sched/sched.h:833 set_next_entity+0xb22/0xfe0
[  537.339217] rq->clock_update_flags < RQCF_ACT_SKIP
[  537.339219] Modules linked in: vgem intel_powerclamp coretemp crct10dif_pclmul crc32_pclmul ghash_clmulni_intel snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic snd_hda_intel lpc_ich snd_hda_codec snd_hwdep snd_hda_core snd_pcm i2c_designware_platform i2c_designware_core i915 r8169 mii prime_numbers sdhci_acpi i2c_hid sdhci mmc_core
[  537.339282] CPU: 1 PID: 0 Comm: swapper/1 Tainted: G     U  W       4.11.0-rc1-CI-CI_DRM_2302+ #1
[  537.339284] Hardware name:                  /NUC5CPYB, BIOS PYBSWCEL.86A.0055.2016.0812.1130 08/12/2016
[  537.339286] Call Trace:
[  537.339291]  dump_stack+0x67/0x92
[  537.339296]  __warn+0xc6/0xe0
[  537.339302]  warn_slowpath_fmt+0x4a/0x50
[  537.339308]  set_next_entity+0xb22/0xfe0
[  537.339316]  pick_next_task_fair+0x76/0x840
[  537.339320]  ? debug_smp_processor_id+0x17/0x20
[  537.339324]  ? prandom_u32+0x39/0x60
[  537.339331]  __schedule+0x10b/0xbd0
[  537.339337]  ? preempt_schedule+0x1f/0x30
[  537.339342]  preempt_schedule_common+0x37/0x90
[  537.339347]  preempt_schedule+0x1f/0x30
[  537.339351]  ___preempt_schedule+0x16/0x18
[  537.339358]  _raw_spin_unlock_irqrestore+0x5b/0x60
[  537.339363]  try_to_wake_up+0x25a/0x650
[  537.339367]  ? _raw_spin_unlock_irqrestore+0x3d/0x60
[  537.339373]  wake_up_state+0xb/0x10
[  537.339377]  kthread_unpark+0x6f/0x90
[  537.339381]  cpuhp_online_idle+0x50/0x90
[  537.339386]  cpu_startup_entry+0x13/0x20
[  537.339390]  start_secondary+0x102/0x120
[  537.339395]  start_cpu+0x14/0x14
[  537.339403] ---[ end trace 963bcdb3fd781f1f ]---
Comment 1 Chris Wilson 2017-03-08 12:54:35 UTC
cpu-hotplug vs kthread
Comment 2 Jani Saarinen 2017-04-05 06:56:59 UTC
Statistics: Failure rate 2/210 run(s) (0%)
Resolving / Whitelisting
Comment 3 Ricardo 2017-06-27 15:19:16 UTC
issue is solved and now closing - Cleaning our bug BD from resolved
Comment 4 Vikram Mulukutla 2017-06-27 17:56:01 UTC
Hi Ricardo,

May I please know how this bug was resolved? I would like to know if my patch [1] helps avoid this race on your platform.

Thanks,
Vikram

[1] https://patchwork.kernel.org/patch/9810479/
Comment 5 Ricardo 2017-06-28 16:21:58 UTC
Hi Vikram, the bug was marked as resolved by our CI engineers as this failure only happend on 2 out of 210 times.. I was only closing the bug to follow the entire bug cycle
Comment 6 Vikram Mulukutla 2017-06-28 20:34:16 UTC
I see. Thank you.. I'm going to use this report as evidence of the BUG on x86. It seems to be identical to what I'm encountering on my ARM platform. It is quite timing sensitive so no surprise that it happens so infrequently!


Use of freedesktop.org services, including Bugzilla, is subject to our Code of Conduct. How we collect and use information is described in our Privacy Policy.