<html>
    <head>
      <base href="https://bugs.freedesktop.org/" />
    </head>
    <body>
      <p>
        <div>
            <b><a class="bz_bug_link 
          bz_status_NEW "
   title="NEW --- - [HSW bisected] i915 module resume time regression"
   href="https://bugs.freedesktop.org/show_bug.cgi?id=65922#c8">Comment # 8</a>
              on <a class="bz_bug_link 
          bz_status_NEW "
   title="NEW --- - [HSW bisected] i915 module resume time regression"
   href="https://bugs.freedesktop.org/show_bug.cgi?id=65922">bug 65922</a>
              from <span class="vcard"><a class="email" href="mailto:cancan.feng@intel.com" title="cancan,feng <cancan.feng@intel.com>"> <span class="fn">cancan,feng</span></a>
</span></b>
        <pre>(In reply to <a href="show_bug.cgi?id=65922#c4">comment #4</a>)
<span class="quote">> During resume:

> good -> [   24.789721] call 0000:00:02.0+ returned 0 after 253503 usecs
> bad  -> [   31.337787] call 0000:00:02.0+ returned 0 after 38479 usecs

> So switchless is indeed doing its job in speeding up resume. So I guess we
> need to look at what happens after the kernel finishes its resume. How are
> you measuring the resume time?</span >

1. After booting a machine, I will first do a S3 suspend-resume cycle, then 
dmesg | grep -i -e "i915_init\|PM:.*complete\|00:02.0+" 
We will get some message as following(Here I used attachment good_commit.dmesg,
dmesg of good commit):
[    1.381662] calling  i915_init+0x0/0x68 [i915] @ 1249
[    1.826391] initcall i915_init+0x0/0x68 [i915] returned 0 after 434521 usecs
[   30.819536] calling  0000:00:02.0+ @ 3917, parent: pci0000:00
[   30.860073] call 0000:00:02.0+ returned 0 after 39605 usecs
[   30.936632] PM: suspend of devices complete after 124.805 msecs
[   30.936957] PM: late suspend of devices complete after 0.322 msecs
[   30.981010] calling  0000:00:02.0+ @ 3841, parent: pci0000:00
[   30.981011] call 0000:00:02.0+ returned 0 after 0 usecs
[   30.981071] PM: noirq suspend of devices complete after 44.137 msecs
[   31.199416] calling  0000:00:02.0+ @ 3841, parent: pci0000:00
[   31.210059] call 0000:00:02.0+ returned 0 after 10398 usecs
[   31.298228] PM: noirq resume of devices complete after 98.936 msecs
[   31.298385] PM: early resume of devices complete after 0.129 msecs
[   31.298404] calling  0000:00:02.0+ @ 3914, parent: pci0000:00
[   31.337787] call 0000:00:02.0+ returned 0 after 38479 usecs
[   36.313220] PM: resume of devices complete after 5017.604 msecs

So, we will get resume time: 10398 usecs + 38479 usecs = 48877 usecs = 48.877
msecs

2. For the bad_commit.dmesg,
[    1.871578] initcall i915_init+0x0/0x68 [i915] returned 0 after 478124 usecs
[   24.050262] calling  0000:00:02.0+ @ 3861, parent: pci0000:00
[   24.080930] call 0000:00:02.0+ returned 0 after 29964 usecs
[   24.167496] PM: suspend of devices complete after 123.843 msecs
[   24.167819] PM: late suspend of devices complete after 0.321 msecs
[   24.211848] calling  0000:00:02.0+ @ 3753, parent: pci0000:00
[   24.211849] call 0000:00:02.0+ returned 0 after 0 usecs
[   24.211909] PM: noirq suspend of devices complete after 44.112 msecs
[   24.431277] calling  0000:00:02.0+ @ 3753, parent: pci0000:00
[   24.441924] call 0000:00:02.0+ returned 0 after 10402 usecs
[   24.530095] PM: noirq resume of devices complete after 98.940 msecs
[   24.530252] PM: early resume of devices complete after 0.129 msecs
[   24.530276] calling  0000:00:02.0+ @ 25, parent: pci0000:00
[   24.789721] call 0000:00:02.0+ returned 0 after 253503 usecs
[   29.546061] PM: resume of devices complete after 5018.598 msecs

resume time is: 10402 usecs + 253503 usecs = 263905 usecs = 263.905 msecs</pre>
        </div>
      </p>
      <hr>
      <span>You are receiving this mail because:</span>
      
      <ul>
          <li>You are the QA Contact for the bug.</li>
          <li>You are the assignee for the bug.</li>
      </ul>
    </body>
</html>