Bug 94721 - [APL] Init time is high
Summary: [APL] Init time is high
Status: CLOSED NOTABUG
Alias: None
Product: DRI
Classification: Unclassified
Component: DRM/Intel (show other bugs)
Version: unspecified
Hardware: x86-64 (AMD64) Linux (All)
: high critical
Assignee: Intel GFX Bugs mailing list
QA Contact: Intel GFX Bugs mailing list
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2016-03-27 10:08 UTC by cprigent
Modified: 2017-07-07 23:02 UTC (History)
1 user (show)

See Also:
i915 platform: BXT
i915 features: power/suspend-resume


Attachments
kern.log (338.98 KB, text/plain)
2016-03-27 10:08 UTC, cprigent
no flags Details

Description cprigent 2016-03-27 10:08:33 UTC
Created attachment 122584 [details]
kern.log

Platform: Broxton P A0 Platform 
CPU Name : Intel(R) @ 1.2 GHz (family: 6, model: 92, stepping: 8) – 4 cores
SoC : BROXTON-P A0
QDF : QYE2
CRB : Apollo Lake RVPC1 Fab1
Mandatory Reworks : R14 , R06C and R16
Software 
APLKRVPA.X64.0116.R20.1512211905
KSC: 1.05
Linux distribution: Ubuntu 15.10 64 bits
Kernel: drm-intel-nightly 4.5.0 e7a7673 from http://cgit.freedesktop.org/drm-intel/
  commit e7a7673e9840fe8b50a5a2894c75565ec7858a00
  Author: Daniel Vetter <daniel.vetter@ffwll.ch>
  Date:   Sat Mar 19 11:10:45 2016 +0100
  drm-intel-nightly: 2016y-03m-19d-10h-09m-53s UTC integration manifest
libdrm-2.4.67-7 49041c3 from git://anongit.freedesktop.org/mesa/drm
mesa: mesa-11.1.2 7bcd827 from git://anongit.freedesktop.org/mesa/mesa
git://anongit.freedesktop.org/cairo 
cairo: 1.15.2 db8a7f1 from git://anongit.freedesktop.org/cairo
waffle: bb29b2a from git://github.com/waffle-gl/waffle
util-macros-1.19.0-2 d7acec2 from git://git.freedesktop.org/git/xorg/util/macros
xorg-server-1.18.1 23e60f9 from git://git.freedesktop.org/git/xorg/xserver
xf86-video-intel 2.99.917-560 d167280 from git://anongit.freedesktop.org/xorg/driver/xf86-video-intel
libva-1.7.0.pre1 35f1447 from git://git.freedesktop.org/git/vaapi/libva
vaapi-intel-driver 1.7.0.pre1 ab8e4e3 from git://anongit.freedesktop.org/vaapi/intel-driver
DMC 1.4 from: https://01.org/linuxgraphics/intel-linux-graphics-firmwares
intel-gpu-tools-1.14 c19b049 from http://anongit.freedesktop.org/git/xorg/app/intel-gpu-tools.git

Steps:
-------
1. Boot
2. Execute command:
dmesg |grep i915_init
3. Suspend to RAM with:
sudo -s
echo mem > /sys/power/state
Wait 30 seconds
Resume with keyboard
4. Execute command:
dmesg |grep "call 0000:00:02.0+ returned 0 after"

Actual result:
-------------
2. Init: 1.101 secs
4. Suspend: 56.725 msecs
   Resume: 332.499 msecs

Expected result:
----------------
2. Init: 62.5 ms
4. Suspend and resume: 187.5 ms


Logs:
-----
Init:
[    1.648257] initcall i915_init+0x0/0x9b [i915] returned 0 after 1101243 usecs

Suspend:
[   74.847170] call 0000:00:02.0+ returned 0 after 56725 usecs
[   74.860581] PM: freeze of devices complete after 71.944 msecs

Resume:
[   74.884550] call 0000:00:02.0+ returned 0 after 23263 usecs
[   74.884954] call 0000:00:02.0+ returned 0 after 0 usecs
[   74.916955] call 0000:00:02.0+ returned 0 after 15447 usecs
[   74.933005] call 0000:00:02.0+ returned 0 after 15590 usecs
[   75.300938] call 0000:00:02.0+ returned 0 after 332499 usecs
[   76.009172] PM: restore of devices complete after 1048.769 msecs
Comment 1 Jani Nikula 2016-03-30 10:09:12 UTC
What are the results with i915.fastboot=1 module parameter?
Comment 2 cprigent 2016-03-31 09:33:10 UTC
It is reproduced with kernel boot command line i915.fastboot=1:
init: 1093444 usecs
Suspend: 60299 usecs
Resume: 330746 usecs
Comment 3 cprigent 2016-03-31 09:42:49 UTC
And also with processor.max_cstate=2
Comment 4 Elio 2016-04-15 16:04:58 UTC
Sharing actual results and configuration:

Init: 2042.896 ms
Suspend : 49.291 ms
Resume: 692.497 ms 

Configuration:

++ Platform                            : BXT-P
 ++ Motherboard model                   : Broxton P
 ++ Motherboard type                    : NOTEBOOK Hand Held
 ++ Motherboard manufacturer            : Intel Corp.
 ++ CPU family                          : Other
 ++ CPU information                     : 06/5c
 ++ GPU Card                            : Intel Corporation Device 5a84 (rev 03) (prog-if 00 [VGA controller])
 ++ Memory ram                          : 8 GB
 ++ Maximum memory ram allowed          : 16 GB
 ++ Display resolution                  :
 ++ CPU's number                        : 4
 ++ Hard drive capacity                 : 120 GB

 ++ Kernel version                      : 4.6.0-rc3-nightly+
 ++ Linux distribution                  : Ubuntu 15.10
 ++ Architecture                        : 64-bit
 
 ++ xf86-video-intel version            : 2.99.917
 ++ Xorg-Xserver version                : 1.17.2
 ++ DRM version                         : 2.4.64
 
 ++ Cairo version                       : 1.14.2
 ++ Intel GPU Tools version             : Tag [intel-gpu-tools-1.14-133-gc89e8db] / Commit [c89e8db]
 ++ Kernel driver in use                : i915
 ++ Hardware acceleration               :
 ++ Bios revision                       : 131.10
 ++ KSC revision                        : 1.12
Comment 5 Imre Deak 2016-04-19 21:38:13 UTC
Could you try
https://github.com/ideak/linux/commits/bxt-tsc ?

It has the following patchset from Gao Bin/Len Brown fixing the system clock rate:
https://lkml.org/lkml/2016/3/31/6
Comment 6 cprigent 2016-04-28 15:21:31 UTC
Tested on RVP1C A0 stepping with kernel 4.6.0-rc4 d998658 from https://github.com/ideak/linux/commits/bxt-tsc
  commit d998658f9e8595eb6a530adaf8f306d0aac7a362
  Author: Bin Gao <bin.gao@intel.com>
  Date:   Mon Apr 18 02:37:45 2016 +0300
  x86 tsc: enumerate BXT tsc_khz via CPUID

Tried 3 times:
Init time is about 1 second
Suspend to RAM does not work. DUT reboots instead of resuming, with nothing restored.
Comment 7 yann 2016-04-29 10:52:50 UTC
Milestone blocker so increasing priority
Comment 8 yann 2016-05-11 12:28:09 UTC
Christophe, please check latest comment in bug 94722 and then re-test
Comment 9 yann 2016-05-17 09:59:08 UTC
No milestone blocker, reducing priority
Comment 10 Jari Tahvanainen 2017-03-13 11:32:02 UTC
Ricardo (or Christophe) - please re-check if this is still valid.
Comment 11 cprigent 2017-03-16 12:31:47 UTC
Hi Ricardo,
Please reassign as soon as it can be tested on a production device.
Comment 12 Ricardo 2017-04-10 13:46:00 UTC
Luis could you please retest to see if the problem continues to exist
Comment 13 Luis Botello 2017-06-08 16:33:26 UTC
We are still out of the criteria range, I tested with latest drm-tip kernel on APL NUC, I found the following results for init time:

Boot:
[    3.176236] calling  i915_init+0x0/0x6e [i915] @ 177
[    3.448193] initcall i915_init+0x0/0x6e [i915] returned 0 after 265513 usecs

Resume:
[  433.010636] call 0000:00:02.0+ returned 0 after 163014 usecs
[  433.091960] call 0000:00:02.0+ returned 0 after 13809 usecs
[  433.096424] call 0000:00:02.0+ returned 0 after 1 usecs
[  433.251991] call 0000:00:02.0+ returned 0 after 11063 usecs
[  433.273124] call 0000:00:02.0+ returned 0 after 7389 usecs
[  434.019411] call 0000:00:02.0+ returned 0 after 722061 usecs

This is my config:

             Software
======================================
kernel version              : 4.12.0-rc4-drm-tip-ww23-commit-17f9a91+
architecture                : x86_64
os version                  : Ubuntu 17.04
kernel driver               : i915
bios revision               : 5.6
bios release date           : 03/10/2017
ksc                         : 16.0
modesetting               : modesetting_drv.so
xorg-xserver              : 1.19.3
libdrm                    : 2.4.76
libva                     : 1.7.3-2
vaapi (intel-driver)      : 1.7.3
cairo                     : 1.14.8-1
dmc version               : 1.7

             Hardware
======================================
motherboard model          : NUC6CAYS
motherboard id             : NUC6CAYB
form factor                : Desktop
manufacturer               : Intelcorporation
cpu family                 : Celeron
cpu family id              : 6
cpu information            : Intel(R) Celeron(R) CPU J3455 @ 1.50GHz
gpu card                   : Intel Corporation Device 5a85 (rev 0b) (prog-if 00 [VGA controller])
memory ram                 : 15.54 GB
cpu thread                 : 4
cpu core                   : 4
cpu model                  : 92
cpu stepping               : 9
signature                  : Type 0, Family 6, Model 92, Stepping 9

             kernel parameters
======================================
quiet splash drm.debug=0xe i915.fastboot=1 initcall_debug no_console_suspend
Comment 14 Jari Tahvanainen 2017-07-05 08:38:18 UTC
Closing this due to "Test method of using Kernel logs has the problem of not pointing these times to i915 only. That is case even for the init time where i915 init is interrupted several times and cannot be assigned to be entirely spend in graphics init."
Please open a new bug with another measurement scenario, if there is something that one should fix.


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.