Bug 111883

Summary: [CI][SHARDS] igt@kms_pipe_crc_basic@suspend-read-crc-pipe-b - dmesg-warn - Delta way too big!
Product: DRI Reporter: Lakshmi <lakshminarayana.vudum>
Component: DRM/IntelAssignee: Intel GFX Bugs mailing list <intel-gfx-bugs>
Status: RESOLVED MOVED QA Contact: Intel GFX Bugs mailing list <intel-gfx-bugs>
Severity: minor    
Priority: low CC: intel-gfx-bugs, matthew.d.roper, tomi.p.sarvela
Version: DRI git   
Hardware: Other   
OS: All   
Whiteboard:
i915 platform: SNB i915 features: display/Other

Description Lakshmi 2019-10-02 13:27:03 UTC
https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6984/shard-snb7/igt@kms_pipe_crc_basic@suspend-read-crc-pipe-b.html

<4> [1612.748804] Delta way too big! 18446742442521894858 ts=18446744054079126193 write stamp = 1611557231335
If you just came from a suspend/resume,
please switch to the trace global clock:
  echo global > /sys/kernel/debug/tracing/trace_clock
or add trace_clock=global to the kernel command line
<4> [1612.748813] WARNING: CPU: 0 PID: 6867 at kernel/trace/ring_buffer.c:2810 rb_handle_timestamp.isra.44+0x6c/0x70
<4> [1612.748815] Modules linked in: vgem snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_codec_generic mei_hdcp i915 x86_pkg_temp_thermal coretemp crct10dif_pclmul crc32_pclmul snd_hda_intel snd_intel_nhlt snd_hda_codec ghash_clmulni_intel broadcom bcm_phy_lib snd_hwdep tg3 snd_hda_core snd_pcm ptp pps_core mei_me mei lpc_ich prime_numbers
<4> [1612.748833] CPU: 0 PID: 6867 Comm: kworker/u16:57 Tainted: G     U            5.4.0-rc1-CI-CI_DRM_6984+ #1
<4> [1612.748835] Hardware name: Dell Inc. XPS 8300  /0Y2MRG, BIOS A06 10/17/2011
<4> [1612.748839] Workqueue: events_unbound async_run_entry_fn
<4> [1612.748842] RIP: 0010:rb_handle_timestamp.isra.44+0x6c/0x70
<4> [1612.748845] Code: 48 8b 73 08 85 c0 48 8b 13 48 c7 c0 c0 60 0a 82 49 c7 c0 bc 5c 0d 82 4c 0f 44 c0 48 8b 0f 48 c7 c7 80 61 0a 82 e8 a4 3f f2 ff <0f> 0b eb a8 41 54 89 f0 55 53 48 0f a3 47 10 bb 01 00 00 00 72 07
<4> [1612.748847] RSP: 0018:ffffc90000b37cd0 EFLAGS: 00010282
<4> [1612.748849] RAX: 0000000000000000 RBX: ffffc90000b37ce8 RCX: 0000000000000002
<4> [1612.748850] RDX: 0000000080000002 RSI: 0000000000000000 RDI: 00000000ffffffff
<4> [1612.748852] RBP: ffff88822689fb18 R08: 0000000000000000 R09: 0000000000000001
<4> [1612.748854] R10: ffffc90000b37ce0 R11: 000000000006a520 R12: ffff888226890358
<4> [1612.748855] R13: ffff88822689fb58 R14: 00000000000003e8 R15: ffffffff82115793
<4> [1612.748857] FS:  0000000000000000(0000) GS:ffff888227800000(0000) knlGS:0000000000000000
<4> [1612.748859] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
<4> [1612.748861] CR2: 00005590644ca668 CR3: 000000021a254001 CR4: 00000000000606f0
<4> [1612.748862] Call Trace:
<4> [1612.748866]  ring_buffer_lock_reserve+0x210/0x3f0
<4> [1612.748908]  ? intel_gt_pm_init+0x10/0x10 [i915]
<4> [1612.748910]  __trace_bputs+0x5b/0x120
<4> [1612.748956]  intel_gt_sanitize+0x1c/0x90 [i915]
<4> [1612.749001]  i915_pm_resume_early+0xc1/0xf0 [i915]
<4> [1612.749045]  ? vlv_resume_prepare+0x690/0x690 [i915]
<4> [1612.749050]  dpm_run_callback+0x64/0x280
<4> [1612.749054]  device_resume_early+0xa7/0xe0
<4> [1612.749057]  async_resume_early+0x14/0x40
<4> [1612.749059]  async_run_entry_fn+0x34/0x160
<4> [1612.749062]  process_one_work+0x26a/0x620
<4> [1612.749067]  worker_thread+0x37/0x380
<4> [1612.749070]  ? process_one_work+0x620/0x620
<4> [1612.749073]  kthread+0x119/0x130
<4> [1612.749076]  ? kthread_park+0x80/0x80
<4> [1612.749081]  ret_from_fork+0x3a/0x50
<4> [1612.749087] irq event stamp: 0
<4> [1612.749089] hardirqs last  enabled at (0): [<0000000000000000>] 0x0
<4> [1612.749093] hardirqs last disabled at (0): [<ffffffff810acb28>] copy_process+0x538/0x1d80
<4> [1612.749095] softirqs last  enabled at (0): [<ffffffff810acb28>] copy_process+0x538/0x1d80
<4> [1612.749097] softirqs last disabled at (0): [<0000000000000000>] 0x0
<4> [1612.749098] ---[ end trace da8a570f190afe73 ]---
Comment 1 CI Bug Log 2019-10-02 13:27:58 UTC
The CI Bug Log issue associated to this bug has been updated.

### New filters associated

* SNB: igt@kms_pipe_crc_basic@suspend-read-crc-pipe-b - dmesg-warn - Delta way too big!
  - https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_6984/shard-snb7/igt@kms_pipe_crc_basic@suspend-read-crc-pipe-b.html
Comment 2 Matt Roper 2019-10-05 00:59:59 UTC
This is probably the same issue as bug 111772, just on a different machine; the warning happens following a suspend/resume cycle.  If this machine doesn't have "trace_clock=global" on the kernel command line (I can't verify since the CI boot.txt link is giving me an 'access denied' error), we should add it for the same reasons described in bug 111772.
Comment 3 Lakshmi 2019-10-10 07:28:12 UTC
(In reply to Matt Roper from comment #2)
> This is probably the same issue as bug 111772, just on a different machine;
> the warning happens following a suspend/resume cycle.  If this machine
> doesn't have "trace_clock=global" on the kernel command line (I can't verify
> since the CI boot.txt link is giving me an 'access denied' error), we should
> add it for the same reasons described in bug 111772.

Tomi, your help needed.
Comment 4 Tomi Sarvela 2019-10-21 10:01:08 UTC
Is this option something that can be enabled on all hosts? I don't really like adding host-specific options when kernel should recognize and autoconfigure them.
Comment 5 Matt Roper 2019-10-22 14:42:31 UTC
I believe using global clock has a performance impact (although only for specific operations so I'm not sure how visible it is to an end user), but should be safe in general.  Unfortunately I don't believe the kernel can detect that a platform is going to have an unstable clock through suspend/resume and will need to fall back to the global clock until it's too late (i.e., once it's already actually gone through a suspend cycle).
Comment 6 CI Bug Log 2019-10-31 10:54:14 UTC
A CI Bug Log filter associated to this bug has been updated:

{- SNB: igt@kms_pipe_crc_basic@suspend-read-crc-pipe-b - dmesg-warn - Delta way too big! -}
{+ SNB: igt@kms_pipe_crc_basic@suspend-read-crc-pipe-b |igt@i915_suspend@forcewake- dmesg-warn - Delta way too big! +}

New failures caught by the filter:

  * https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_7219/shard-snb7/igt@i915_suspend@forcewake.html
Comment 7 CI Bug Log 2019-10-31 10:55:27 UTC
The CI Bug Log issue associated to this bug has been updated.

### New filters associated

* SNB: igt@runner@aborted - fail - Previous test: i915_suspend (forcewake)
  - http://gfx-ci.fi.intel.com/tree/drm-tip/CUSTOM_mupuf-1568726118/shard-snb5/igt@runner@aborted.html
  - http://gfx-ci.fi.intel.com/tree/drm-tip/CUSTOM_mupuf-1568726983/shard-snb6/igt@runner@aborted.html
  - https://intel-gfx-ci.01.org/tree/drm-tip/CI_DRM_7219/shard-snb7/igt@runner@aborted.html
Comment 8 Martin Peres 2019-11-29 19:36:53 UTC
-- GitLab Migration Automatic Message --

This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity.

You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/drm/intel/issues/473.

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.