Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
Date:   Tue, 24 Jul 2018 10:21:45 -0400 (EDT)
From:   Alan Stern <stern@rowland.harvard.edu>
To:     Paul Menzel <pmenzel+linux-usb@molgen.mpg.de>
cc:     linux-usb@vger.kernel.org, <linux-kernel@vger.kernel.org>
Subject: Re: `ohci_rh_resume()` called during `usb_dev_suspend()`
In-Reply-To: <4d24d2f7-6123-ae18-7055-b5d2f50bb964@molgen.mpg.de>
Message-ID: <Pine.LNX.4.44L0.1807241015250.1594-100000@iolanthe.rowland.org>
MIME-Version: 1.0
Content-Type: TEXT/PLAIN; charset=US-ASCII
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

On Tue, 24 Jul 2018, Paul Menzel wrote:

> Dear Linux folks,
> 
> 
> Profiling the suspend to and resume/wake-up from ACPI S3 with 
> `sleepgraph.py` on an ASRock E350M1, I noticed that resume methods are 
> called during suspend.
> 
> Here is an excerpt from the callgraph.
> 
> >   600.376906 |   0)   kworker-81   |               |  /* device_pm_callback_start: usb usb5, parent: 0000:00:14.5, type [suspend] */
> >   600.376909 |   0)   kworker-81   |               |    usb_dev_suspend() {
> >   600.376911 |   0)   kworker-81   |               |      usb_suspend() {
> >   600.376913 |   0)   kworker-81   |               |        __pm_runtime_resume() {
> >   600.376915 |   0)   kworker-81   |               |          _cond_resched() {
> >   600.376917 |   0)   kworker-81   |   0.565 us    |            rcu_all_qs();
> >   600.376921 |   0)   kworker-81   |   4.034 us    |          } /* _cond_resched */
> >   600.376922 |   0)   kworker-81   |   0.505 us    |          _raw_spin_lock_irqsave();
> >   600.376926 |   0)   kworker-81   |               |          rpm_resume() {
> >   600.376928 |   0)   kworker-81   |   0.573 us    |            _raw_spin_lock();
> >   600.376934 |   0)   kworker-81   |   0.706 us    |            rpm_resume();
> >   600.376937 |   0)   kworker-81   |   0.556 us    |            _raw_spin_lock();
> >   600.376942 |   0)   kworker-81   |   0.721 us    |            __rpm_get_callback();
> >   600.376946 |   0)   kworker-81   |   0.564 us    |            dev_pm_disable_wake_irq_check();
> >   600.376949 |   0)   kworker-81   |               |            rpm_callback() {
> >   600.376952 |   0)   kworker-81   |               |              __rpm_callback() {
> >   600.376954 |   0)   kworker-81   |               |                usb_runtime_resume() {
> >   600.376956 |   0)   kworker-81   |               |                  usb_resume_both() {
> >   600.376959 |   0)   kworker-81   |               |                    generic_resume() {
> >   600.376960 |   0)   kworker-81   |               |                      hcd_bus_resume() {
> >   600.376963 |   0)   kworker-81   |               |                        ohci_bus_resume [ohci_hcd]() {
> >   600.376964 |   0)   kworker-81   |   0.588 us    |                          _raw_spin_lock_irq();
> >   600.376968 |   0)   kworker-81   |               |                          ohci_rh_resume [ohci_hcd]() {
> >   600.377043 |   0)   kworker-81   |               |                            msleep() {
> 
> Please find the full callgraph and the HTML output attached.
> 
> Is that expected?

I can't tell exactly what's happening from your callgraph and HTML, but
yes, in general it is expected.

The reason is because some devices have different wakeup settings for
runtime suspend and system suspend: A device that is enabled for wakeup
signalling during runtime suspend often is not enabled for wakeup
during system suspend.

As a result, the device's wakeup setting has to be changed when the 
system goes to sleep, and to do that, we have to wake the device up 
temporarily if it is already in runtime suspend.

Alan Stern