Re: Suspend/resume - slow resume

Re: Suspend/resume - slow resume

[Linus Torvalds]

On Fri, Apr 15, 2011 at 8:33 AM, Ciprian Docan <docan@eden.rutgers.edu> wrote:
>
> I enabled CONFIG_PRINTK_TIME in the config file and rebuild the kernel; and
> after a fresh reboot I saved the dmesg output before and after
> suspend/resume. Attached is the diff file containing the resume sequence. At
> linew 133 - 134 there is a longer gap, which I think is related to the r8169
> driver.
>
> I have unloaded the module and did a new suspend/resume sequence, but this
> time with the r8169 module removed it went much faster (3-4s to resume
> completely). Can you please help here ?

Ok, this seems to be yet another case of the ridiculously common error
of "let's load the firmware early, before the machine is even up". It
sometimes happens at boot-time (driver writers only test the module
case, not the built-in case), but it happens very often at
suspend/resume time (which driver writers seem to not test at all).

It is not valid to try to load the firmware at resume time. User space
isn't running, so all the firmware loading helpers are frozen.
Firmware that needs to be reloaded after a suspend needs to be saved
to memory!

I added netdev to the recipient list, because this is definitely not
just a r8169 issue - we've had this bug happen over and over again.

Looking at the code, it looks like r8169 _tries_ to save the firmware
(it has had this SAME bug before), but in case no firmware was ever
loaded successfully at all (either because there was no firmware to
begin with, or because the device had never been opened, so it had
never tried to load it before), it _still_ tries to load the firmware.

WTF? At resume time, you should _resume_, not "load firmware even if
it wasn't loaded before".

I also wonder if the generic power management layer code could do
something smarter about this. Print a big warning when somebody wants
to load firmware when the machine isn't fully operational, instead of
the "wait 60 seconds in the totally futile hope that things will
change". Adding greg to the cc for that case, he's marked as firmware
loader maintainer.

So Francois, can we please not load the firmware at resume time when
it wasn't loaded when suspended!

Greg/Rafael/whoever - could we please replace the "sleep for a minute
if you can't load the firmware" with a big immediate WARN_ON() if
somebody tries to load it at early boot time or at resume time? That
way we don't have the machine dead for sixty seconds (most people just
assume it's dead and will just reboot - I've done that myself when
I've been hit by this), and we'd get a nice "here's the offender"
printout.

And netdev/lkml just cc'd for information, just in case some driver
writer is lurking and suddenly realizes that their driver is broken
too.

                             Linus

Re: Suspend/resume - slow resume

[Francois Romieu]

Linus Torvalds <torvalds@linux-foundation.org> :
[...]
> So Francois, can we please not load the firmware at resume time when
> it wasn't loaded when suspended!

One can try the patch below. It is completely untested yet.

Subject: [PATCH] r8169: don't request firmware when there's no userspace.

The firmware is cached during open() and released during close().
The driver uses the cached firmware between open() and close().

Don't bother with rtl8169_pcierr_interrupt. It is special anyway.

Signed-off-by: Francois Romieu <romieu@fr.zoreil.com>
---
 drivers/net/r8169.c |   76 +++++++++++++++++++++++++++++++++++----------------
 1 files changed, 52 insertions(+), 24 deletions(-)

diff --git a/drivers/net/r8169.c b/drivers/net/r8169.c
index 493b0de..ccc25cd 100644
--- a/drivers/net/r8169.c
+++ b/drivers/net/r8169.c
@@ -170,6 +170,16 @@ static const struct {
 };
 #undef _R
 
+static const struct rtl_firmware_info {
+	int mac_version;
+	const char *fw_name;
+} rtl_firmware_infos[] = {
+	{ .mac_version = RTL_GIGA_MAC_VER_25, .fw_name = FIRMWARE_8168D_1 },
+	{ .mac_version = RTL_GIGA_MAC_VER_26, .fw_name = FIRMWARE_8168D_2 },
+	{ .mac_version = RTL_GIGA_MAC_VER_29, .fw_name = FIRMWARE_8105E_1 },
+	{ .mac_version = RTL_GIGA_MAC_VER_30, .fw_name = FIRMWARE_8105E_1 }
+};
+
 enum cfg_version {
 	RTL_CFG_0 = 0x00,
 	RTL_CFG_1,
@@ -1793,21 +1803,21 @@ static void rtl_release_firmware(struct rtl8169_private *tp)
 	tp->fw = NULL;
 }
 
-static int rtl_apply_firmware(struct rtl8169_private *tp, const char *fw_name)
+static void rtl_apply_firmware(struct rtl8169_private *tp)
 {
-	const struct firmware **fw = &tp->fw;
-	int rc = !*fw;
-
-	if (rc) {
-		rc = request_firmware(fw, fw_name, &tp->pci_dev->dev);
-		if (rc < 0)
-			goto out;
-	}
+	const struct firmware *fw = tp->fw;
 
 	/* TODO: release firmware once rtl_phy_write_fw signals failures. */
-	rtl_phy_write_fw(tp, *fw);
-out:
-	return rc;
+	if (fw)
+		rtl_phy_write_fw(tp, fw);
+}
+
+static void rtl_apply_firmware_cond(struct rtl8169_private *tp, u8 reg, u16 val)
+{
+	if (rtl_readphy(tp, reg) != val)
+		netif_warn(tp, hw, tp->dev, "chipset not ready for firmware\n");
+	else
+		rtl_apply_firmware(tp);
 }
 
 static void rtl8169s_hw_phy_config(struct rtl8169_private *tp)
@@ -2246,10 +2256,8 @@ static void rtl8168d_1_hw_phy_config(struct rtl8169_private *tp)
 
 	rtl_writephy(tp, 0x1f, 0x0005);
 	rtl_writephy(tp, 0x05, 0x001b);
-	if ((rtl_readphy(tp, 0x06) != 0xbf00) ||
-	    (rtl_apply_firmware(tp, FIRMWARE_8168D_1) < 0)) {
-		netif_warn(tp, probe, tp->dev, "unable to apply firmware patch\n");
-	}
+
+	rtl_apply_firmware_cond(tp, MII_EXPANSION, 0xbf00);
 
 	rtl_writephy(tp, 0x1f, 0x0000);
 }
@@ -2351,10 +2359,8 @@ static void rtl8168d_2_hw_phy_config(struct rtl8169_private *tp)
 
 	rtl_writephy(tp, 0x1f, 0x0005);
 	rtl_writephy(tp, 0x05, 0x001b);
-	if ((rtl_readphy(tp, 0x06) != 0xb300) ||
-	    (rtl_apply_firmware(tp, FIRMWARE_8168D_2) < 0)) {
-		netif_warn(tp, probe, tp->dev, "unable to apply firmware patch\n");
-	}
+
+	rtl_apply_firmware_cond(tp, MII_EXPANSION, 0xb300);
 
 	rtl_writephy(tp, 0x1f, 0x0000);
 }
@@ -2474,8 +2480,7 @@ static void rtl8105e_hw_phy_config(struct rtl8169_private *tp)
 	rtl_writephy(tp, 0x18, 0x0310);
 	msleep(100);
 
-	if (rtl_apply_firmware(tp, FIRMWARE_8105E_1) < 0)
-		netif_warn(tp, probe, tp->dev, "unable to apply firmware patch\n");
+	rtl_apply_firmware(tp);
 
 	rtl_writephy_batch(tp, phy_reg_init, ARRAY_SIZE(phy_reg_init));
 }
@@ -3288,8 +3293,6 @@ static void __devexit rtl8169_remove_one(struct pci_dev *pdev)
 
 	cancel_delayed_work_sync(&tp->task);
 
-	rtl_release_firmware(tp);
-
 	unregister_netdev(dev);
 
 	if (pci_dev_run_wake(pdev))
@@ -3303,6 +3306,27 @@ static void __devexit rtl8169_remove_one(struct pci_dev *pdev)
 	pci_set_drvdata(pdev, NULL);
 }
 
+static void rtl_request_firmware(struct rtl8169_private *tp)
+{
+	int i;
+
+	for (i = 0; i < ARRAY_SIZE(rtl_firmware_infos); i++) {
+		const struct rtl_firmware_info *info = rtl_firmware_infos + i;
+
+		if (info->mac_version == tp->mac_version) {
+			const char *name = info->fw_name;
+			int rc;
+
+			rc = request_firmware(&tp->fw, name, &tp->pci_dev->dev);
+			if (rc < 0) {
+				netif_warn(tp, ifup, tp->dev, "unable to load "
+					"firmware patch %s (%d)\n", name, rc);
+			}
+			break;
+		}
+	}
+}
+
 static int rtl8169_open(struct net_device *dev)
 {
 	struct rtl8169_private *tp = netdev_priv(dev);
@@ -3334,6 +3358,8 @@ static int rtl8169_open(struct net_device *dev)
 
 	smp_mb();
 
+	rtl_request_firmware(tp);
+
 	retval = request_irq(dev->irq, rtl8169_interrupt,
 			     (tp->features & RTL_FEATURE_MSI) ? 0 : IRQF_SHARED,
 			     dev->name, dev);
@@ -4891,6 +4917,8 @@ static int rtl8169_close(struct net_device *dev)
 
 	free_irq(dev->irq, dev);
 
+	rtl_release_firmware(tp);
+
 	dma_free_coherent(&pdev->dev, R8169_RX_RING_BYTES, tp->RxDescArray,
 			  tp->RxPhyAddr);
 	dma_free_coherent(&pdev->dev, R8169_TX_RING_BYTES, tp->TxDescArray,
-- 
1.7.4

Re: Suspend/resume - slow resume

[Linus Torvalds]

On Sun, Apr 17, 2011 at 3:17 AM, Francois Romieu <romieu@fr.zoreil.com> wrote:
>
> One can try the patch below. It is completely untested yet.

Looks _fairly_ sane to me.  The "request firmware in open, release
firmware in close" approach would seem to be a fairly obvious one.

HOWEVER.

I think it's broken in two ways:

 - it causes too much re-loading for no good reason. I'm looking at
rtl8169_reinit_task() in particular, and if I read that correctly,
then if there are any problems, that crazy function will end up
loading and unloading the firmware EVERY FOUR TIMER TICKS!

   That's just totally broken.

   But I'd also worry about some init scripts in particular, maybe
that whole "open to test something, close immediately" is common. I
don't know.

 - it seems to leak the open function fails after requesting the
firmware - nothing will ever close it, and if you unload the module
the firmware will never be released as far as I can tell.

I might be missing some failure path (maybe the network device open
will call close even if the open failed), but it looks real.

So I think your patch _approaches_ being sane, but no, it's not working as-is.

I really think that this kind of "ad-hoc random firmware loading"
stuff should go away. The device layer (or maybe the network layer)
should have some clear and unambiguous rules. Exactly so that drivers
don't make these kinds of mistakes.

My gut feel for what the rules should be is roughly (but please take
this as a starting point for discussion rather than some final thing):

 - try to load the firmware at each time the user tries to activate
the device. IOW, not like this, where the rtl8169_open() function is
called from many different contexts, only one of them being the
"network layer tried to open the device".

   I do think we need to do it potentially multiple times: the main
issue being something like this:

      ifconfig eth0 up
      ** oops, that failed because we didn't have the firmware files
installed **
      ... install firmware files, the 'dmesg' gave good error messages
that the user could use to know what was going on ..
      ifconfig eth0 up
      ** this needs to trigger another firmware load attempt **

   In other words, doing firmware load at module load time - or at
device scan time - is fundamentally broken for a network driver.

 - unload not on close, but on device unregister (iow not when you do
"ifconfig eth0 down", but when the "eth0" device really goes away)

But as mentioned, the above is (a) just my gut feel - please discuss -
and (b) I really think that leaving this to the network driver has
been shown to continually result in the drivers doing the firmware
load/unload in all the wrong places.

So I do wonder whether we could add a "ndo_firmware_load()" and
"ndo_firmware_unload()" callback to the network device operations, and
have the network layer make the above rules. A network driver
obviously _could_ do its firmware load from other places instead, but
such a network driver would basically be "obviously broken".

Comments?

(That said, I think that Francois' patch could be made acceptable
fairly trivially:

 - avoiding the load/unload from rtl8169_reinit_task() and that
horrible "every four timer ticks" issue. That just seems crazy. Maybe
by just having an internal open helper function that does everything
but the firmware load)

 - adding a rtl_release_firmware on open failure so that you don't leak stuff

but I do think that this whole "firmware load in random places" has
been such a common bug that I think we should have some real rules
about it)

Hmm?

                                Linus

Re: Suspend/resume - slow resume

[Francois Romieu]

Linus Torvalds <torvalds@linux-foundation.org> :
[lots of silly bugs]

Ok. it should be fixed for wednesday.

[...]
>  - unload not on close, but on device unregister (iow not when you do
> "ifconfig eth0 down", but when the "eth0" device really goes away)

Without further action, the firmware(s) will thus be locked in until the
driver is removed. 

> But as mentioned, the above is (a) just my gut feel - please discuss -
> and (b) I really think that leaving this to the network driver has
> been shown to continually result in the drivers doing the firmware
> load/unload in all the wrong places.

As long as it can be fixed... If the 60s delay is removed and the firmware
loading emits some messages for programmer barbie, I am more than happy.

If someone can tell me where Realtek's firmware should be sent to as David
W. seems to be busy, it will be perfect.

-- 
"Lack of vision" Ueimor

Re: Suspend/resume - slow resume

[Linus Torvalds]

[-- Attachment #1: Type: text/plain, Size: 3010 bytes --]

On Mon, Apr 18, 2011 at 11:08 AM, Francois Romieu <romieu@fr.zoreil.com> wrote:
> [...]
>>  - unload not on close, but on device unregister (iow not when you do
>> "ifconfig eth0 down", but when the "eth0" device really goes away)
>
> Without further action, the firmware(s) will thus be locked in until the
> driver is removed.

I do agree. It's a downside. Maybe doing it in "close()" is the right
thing, as long as we don't have that crazy "every four timer ticks"
situation with rtl8169_reinit_task.

As mentioned, the only real reason for me to be worried about the
close thing is that I don't have a good feel for what happens at boot
time. Are the setup scripts going to look at the interface lots of
times? On my desktop, I couldn't care less, but I try to keep boot
time in mind.

Maybe in practice there's just a single open at boot-time (for dhcp or
whatever), and I'm just worried for no good reason.

Without having looked at that whole rtl8169_reinit_task thing, I
probably wouldn't even worry about anything else doing something
similar ;)

> As long as it can be fixed... If the 60s delay is removed and the firmware
> loading emits some messages for programmer barbie, I am more than happy.

So the firmware loading timeout used to be ten seconds (which I
already think is excessive), but then commit
2f65168de7d68a5795e945e781d85b313bdc97b9 increased it to 60s because

    https://bugzilla.redhat.com/bugzilla/show_bug.cgi?id=174589

    The ipw driver sometimes takes a long time to load its firmware.
    Whilst the ipw driver should be using the async interface of
    the firmware loader to make this a non-issue, this is a minimal fix.

although when I actually look at that bugzilla entry, the _timestamps_
for the failed case do not seem to support this being a timeout.

Very odd.

But the real problem is that we do that timeout even in cases where it
cannot help, ie when people load firmware during early boot or during
suspend. So I think drivers/base/firmware_class.c should be made a bit
smarter.

We have a few cases where call_usermodehelper() fails immediately:

 - khelper_wq hasn't been set up yet
 - usermodehelper_disabled is set.

and in particular, during suspend/resume, that
"usermodehelper_disabled" flag will be set.

I don't think it is sensible to do a user request for firmware during
that time either, and that 60-second timeout is just silly. It's not
going to help.

Why doesn't the firmware loader class check the error return from the
kobject_uevent()? I'd expect that if that fails, we should just warn
and abort, rather than wait 60 seconds to time out. Greg?

TOTALLY UNTESTED PATCH ATTACHED!

Ciprian - does this get rid of the 60-second wait? Do you get a nice
kernel traceback in your dmesg instead?

> If someone can tell me where Realtek's firmware should be sent to as David
> W. seems to be busy, it will be perfect.

Hmm. Dunno about that.

                       Linus

[-- Attachment #2: patch.diff --]
[-- Type: text/x-patch, Size: 625 bytes --]

 drivers/base/firmware_class.c |    3 ++-
 1 files changed, 2 insertions(+), 1 deletions(-)

diff --git a/drivers/base/firmware_class.c b/drivers/base/firmware_class.c
index 8c798ef7f13f..956dd34e59da 100644
--- a/drivers/base/firmware_class.c
+++ b/drivers/base/firmware_class.c
@@ -549,7 +549,8 @@ static int _request_firmware(const struct firmware **firmware_p,
 				  round_jiffies_up(jiffies +
 						   loading_timeout * HZ));
 
-		kobject_uevent(&fw_priv->dev.kobj, KOBJ_ADD);
+		if (WARN_ON(kobject_uevent(&fw_priv->dev.kobj, KOBJ_ADD)))
+			fw_load_abort(fw_priv);
 	}
 
 	wait_for_completion(&fw_priv->completion);

Re: Suspend/resume - slow resume

[Ben Hutchings]

On Mon, 2011-04-18 at 11:49 -0700, Linus Torvalds wrote:
> On Mon, Apr 18, 2011 at 11:08 AM, Francois Romieu <romieu@fr.zoreil.com> wrote:
> > [...]
> >>  - unload not on close, but on device unregister (iow not when you do
> >> "ifconfig eth0 down", but when the "eth0" device really goes away)
> >
> > Without further action, the firmware(s) will thus be locked in until the
> > driver is removed.
> 
> I do agree. It's a downside. Maybe doing it in "close()" is the right
> thing, as long as we don't have that crazy "every four timer ticks"
> situation with rtl8169_reinit_task.
> 
> As mentioned, the only real reason for me to be worried about the
> close thing is that I don't have a good feel for what happens at boot
> time. Are the setup scripts going to look at the interface lots of
> times? On my desktop, I couldn't care less, but I try to keep boot
> time in mind.
>
> Maybe in practice there's just a single open at boot-time (for dhcp or
> whatever), and I'm just worried for no good reason.
[...]

Well, net devices are weird - they don't have file descriptors, they
just have names and indices which you can specify in an ioctl on any
socket (or netlink message on an appropriate netlink socket).  Opening
means starting the device, and I can't think of a configuration tool
that implicitly opens a net device.  Normally they get opened by ifup or
network-manager or the local equivalent, and then they stay open until
an explicit action by the administrator.

Ben.

-- 
Ben Hutchings, Senior Software Engineer, Solarflare
Not speaking for my employer; that's the marketing department's job.
They asked us to note that Solarflare product names are trademarked.

Re: Suspend/resume - slow resume

[Ciprian Docan]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 650 bytes --]



> TOTALLY UNTESTED PATCH ATTACHED!
>
> Ciprian - does this get rid of the 60-second wait? Do you get a nice
> kernel traceback in your dmesg instead?

Linus - I applied your patch and attached the diff between output of dmesg 
before and after the patch as resume_timing.diff. This patch alone does 
not seem to fix the issue; however, applying Francois's patch in addition 
to yours make the resume smooth. I have also attached the diff output of 
dmesg before and after, with both patched applied as resume2_timing.diff. 
Both cases were tested after a fresh reboot. Please let me know if you 
need any other information.

Thank you,
--
 	Ciprian

[-- Attachment #2: Type: TEXT/PLAIN, Size: 12194 bytes --]

1003a1004,1167
> [   65.618866] wl_ops_bss_info_changed: qos enabled: false (implement)
> [   65.618883] brcmsmac: wl_ops_bss_info_changed: disassociated
> [   65.618888] wl_ops_bss_info_changed: use_cts_prot: false (implement)
> [   65.618892] wl_ops_bss_info_changed: short preamble: false (implement)
> [   65.618903] wl_ops_bss_info_changed: arp filtering: enabled false, count 1 (implement)
> [   65.618911] wlan0: deauthenticating from 00:1c:10:9c:3c:98 by local choice (reason=3)
> [   65.642295] wl_ops_bss_info_changed: BSS idle: true (implement)
> [   65.642338] cfg80211: All devices are disconnected, going to restore regulatory settings
> [   65.642346] cfg80211: Restoring regulatory settings
> [   65.642356] cfg80211: Calling CRDA to update world regulatory domain
> [   65.642419] wl_ops_bss_info_changed: BSS idle: false (implement)
> [   65.647025] cfg80211: Updating information on frequency 2412 MHz for a 20 MHz width channel with regulatory rule:
> [   65.647033] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   65.647038] cfg80211: Updating information on frequency 2417 MHz for a 20 MHz width channel with regulatory rule:
> [   65.647043] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   65.647047] cfg80211: Updating information on frequency 2422 MHz for a 20 MHz width channel with regulatory rule:
> [   65.647052] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   65.647056] cfg80211: Updating information on frequency 2427 MHz for a 20 MHz width channel with regulatory rule:
> [   65.647061] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   65.647065] cfg80211: Updating information on frequency 2432 MHz for a 20 MHz width channel with regulatory rule:
> [   65.647070] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   65.647075] cfg80211: Updating information on frequency 2437 MHz for a 20 MHz width channel with regulatory rule:
> [   65.647079] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   65.647084] cfg80211: Updating information on frequency 2442 MHz for a 20 MHz width channel with regulatory rule:
> [   65.647089] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   65.647093] cfg80211: Updating information on frequency 2447 MHz for a 20 MHz width channel with regulatory rule:
> [   65.647098] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   65.647102] cfg80211: Updating information on frequency 2452 MHz for a 20 MHz width channel with regulatory rule:
> [   65.647107] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   65.647111] cfg80211: Updating information on frequency 2457 MHz for a 20 MHz width channel with regulatory rule:
> [   65.647116] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   65.647120] cfg80211: Updating information on frequency 2462 MHz for a 20 MHz width channel with regulatory rule:
> [   65.647125] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   65.647129] cfg80211: Disabling freq 2467 MHz
> [   65.647132] cfg80211: Disabling freq 2472 MHz
> [   65.647135] cfg80211: Disabling freq 2484 MHz
> [   65.647139] cfg80211: World regulatory domain updated:
> [   65.647141] cfg80211:     (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
> [   65.647146] cfg80211:     (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
> [   65.647151] cfg80211:     (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
> [   65.647156] cfg80211:     (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
> [   65.647160] cfg80211:     (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
> [   65.647182] cfg80211:     (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
> [   65.661205] wl_ops_bss_info_changed: BSS idle: true (implement)
> [   67.149409] PM: Syncing filesystems ... done.
> [   67.150612] PM: Preparing system for mem sleep
> [   67.294102] Freezing user space processes ... (elapsed 0.01 seconds) done.
> [   67.304765] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
> [   67.315716] PM: Entering mem sleep
> [   67.315872] Suspending console(s) (use no_console_suspend to debug)
> [   67.316505] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> [   67.319105] sd 0:0:0:0: [sda] Stopping disk
> [   67.355568] brcmsmac 0000:03:00.0: PCI INT A disabled
> [   67.366638] ehci_hcd 0000:00:1d.0: PCI INT A disabled
> [   67.366650] ehci_hcd 0000:00:1a.0: PCI INT A disabled
> [   67.455454] HDA Intel 0000:01:00.1: PCI INT B disabled
> [   67.455488] ACPI handle has no context!
> [   67.457872] HDA Intel 0000:00:1b.0: PCI INT A disabled
> [   69.824037] PM: suspend of devices complete after 2514.601 msecs
> [   69.824247] r8169 0000:02:00.0: PME# enabled
> [   69.832945] r8169 0000:02:00.0: wake-up capability enabled by ACPI
> [   69.865924] PM: late suspend of devices complete after 42.000 msecs
> [   69.866079] ACPI: Preparing to enter system sleep state S3
> [   69.911889] PM: Saving platform NVS memory
> [   69.915560] Disabling non-boot CPUs ...
> [   69.917358] CPU 1 is now offline
> [   69.929978] CPU 2 is now offline
> [   69.931819] Broke affinity for irq 9
> [   69.932857] CPU 3 is now offline
> [   69.933182] Extended CMOS year: 2000
> [   69.933377] ACPI: Low-level resume complete
> [   69.933432] PM: Restoring platform NVS memory
> [   69.933979] Extended CMOS year: 2000
> [   69.934000] Enabling non-boot CPUs ...
> [   69.934120] Booting Node 0 Processor 1 APIC 0x1
> [   69.934121] smpboot cpu 1: start_ip = 98000
> [   70.025135] Switched to NOHz mode on CPU #1
> [   70.026670] CPU1 is up
> [   70.026831] Booting Node 0 Processor 2 APIC 0x4
> [   70.026834] smpboot cpu 2: start_ip = 98000
> [   70.117565] CPU2 is up
> [   70.117646] Booting Node 0 Processor 3 APIC 0x5
> [   70.117648] smpboot cpu 3: start_ip = 98000
> [   70.117845] Switched to NOHz mode on CPU #2
> [   70.208157] CPU3 is up
> [   70.209353] Switched to NOHz mode on CPU #3
> [   70.209710] ACPI: Waking up from system sleep state S3
> [   70.277137] pcieport 0000:00:01.0: restoring config space at offset 0x7 (was 0x20003030, writing 0x3030)
> [   70.277142] pcieport 0000:00:01.0: restoring config space at offset 0x1 (was 0x100007, writing 0x100407)
> [   70.277162] i915 0000:00:02.0: restoring config space at offset 0x1 (was 0x900007, writing 0x900407)
> [   70.277190] pci 0000:00:16.0: restoring config space at offset 0x1 (was 0x180006, writing 0x100006)
> [   70.277222] ehci_hcd 0000:00:1a.0: restoring config space at offset 0x1 (was 0x2900006, writing 0x2900002)
> [   70.277257] HDA Intel 0000:00:1b.0: restoring config space at offset 0x1 (was 0x100006, writing 0x100002)
> [   70.277286] pcieport 0000:00:1c.0: restoring config space at offset 0x7 (was 0x20002020, writing 0x2020)
> [   70.277362] ehci_hcd 0000:00:1d.0: restoring config space at offset 0x1 (was 0x2900006, writing 0x2900002)
> [   70.277384] pci 0000:00:1e.0: restoring config space at offset 0xa (was 0xffffffff, writing 0x0)
> [   70.277465] ahci 0000:00:1f.2: restoring config space at offset 0x1 (was 0x2b00007, writing 0x2b00407)
> [   70.277588] HDA Intel 0000:01:00.1: restoring config space at offset 0x1 (was 0x100007, writing 0x100003)
> [   70.277642] r8169 0000:02:00.0: restoring config space at offset 0x1 (was 0x100007, writing 0x100407)
> [   70.277728] brcmsmac 0000:03:00.0: restoring config space at offset 0xf (was 0x100, writing 0x10a)
> [   70.277748] brcmsmac 0000:03:00.0: restoring config space at offset 0x4 (was 0x4, writing 0xc2400004)
> [   70.277753] brcmsmac 0000:03:00.0: restoring config space at offset 0x3 (was 0x0, writing 0x10)
> [   70.277759] brcmsmac 0000:03:00.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100006)
> [   70.277907] PM: early resume of devices complete after 0.832 msecs
> [   70.278058] i915 0000:00:02.0: setting latency timer to 64
> [   70.278063] ehci_hcd 0000:00:1a.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
> [   70.278069] ehci_hcd 0000:00:1a.0: setting latency timer to 64
> [   70.278084] HDA Intel 0000:00:1b.0: PCI INT A -> GSI 22 (level, low) -> IRQ 22
> [   70.278091] ehci_hcd 0000:00:1d.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
> [   70.278093] HDA Intel 0000:00:1b.0: setting latency timer to 64
> [   70.278100] ehci_hcd 0000:00:1d.0: setting latency timer to 64
> [   70.278110] pci 0000:00:1e.0: setting latency timer to 64
> [   70.278132] ahci 0000:00:1f.2: setting latency timer to 64
> [   70.278140] HDA Intel 0000:01:00.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
> [   70.278145] HDA Intel 0000:01:00.1: setting latency timer to 64
> [   70.278160] HDA Intel 0000:00:1b.0: irq 46 for MSI/MSI-X
> [   70.278194] HDA Intel 0000:01:00.1: irq 47 for MSI/MSI-X
> [   70.278338] sd 0:0:0:0: [sda] Starting disk
> [   70.278461] brcmsmac 0000:03:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
> [   70.278467] brcmsmac 0000:03:00.0: setting latency timer to 64
> [   70.286439] r8169 0000:02:00.0: wake-up capability disabled by ACPI
> [   70.286445] r8169 0000:02:00.0: PME# disabled
> [   70.508985] usb 1-1.4: reset full speed USB device number 3 using ehci_hcd
> [   70.583638] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> [   70.585644] ata5: SATA link down (SStatus 0 SControl 300)
> [   70.617518] ata2.00: configured for UDMA/100
> [   70.666598] usb 2-1.3: reset full speed USB device number 3 using ehci_hcd
> [   70.753366] btusb 2-1.3:1.0: no reset_resume for driver btusb?
> [   70.753372] btusb 2-1.3:1.1: no reset_resume for driver btusb?
> [   70.824183] usb 2-1.6: reset high speed USB device number 5 using ehci_hcd
> [   71.753512] hci_cmd_timer: hci0 command tx timeout
> [   73.023083] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
> [   73.035133] ata1.00: configured for UDMA/133
> [   73.642069] PM: resume of devices complete after 3373.220 msecs
> [   73.642418] PM: Finishing wakeup.
> [   73.642420] Restarting tasks ... done.
> [   73.648564] video LNXVIDEO:00: Restoring backlight state
> [   73.648712] video LNXVIDEO:01: Restoring backlight state
> [   74.082737] wl_ops_bss_info_changed: use_cts_prot: false (implement)
> [   74.082742] wl_ops_bss_info_changed: short preamble: false (implement)
> [   74.082760] wl_ops_config: change monitor mode: false (implement)
> [   74.082763] wl_ops_config: change power-save mode: false (implement)
> [   74.084986] wl_ops_bss_info_changed: qos enabled: false (implement)
> [   74.085682] wl_ops_bss_info_changed: BSS idle: false (implement)
> [   74.085702] ADDRCONF(NETDEV_UP): wlan0: link is not ready
> [   74.174940] wl_ops_bss_info_changed: BSS idle: true (implement)
> [   74.174977] wl_ops_bss_info_changed: BSS idle: false (implement)
> [   74.264656] wl_ops_bss_info_changed: BSS idle: true (implement)
> [   74.293752] wl_ops_bss_info_changed: BSS idle: false (implement)
> [   74.293812] wlan0: deauthenticating from 00:1c:10:9c:3c:98 by local choice (reason=3)
> [   74.383350] wlan0: authenticate with 00:1c:10:9c:3c:98 (try 1)
> [   74.398331] wlan0: authenticated
> [   74.398347] wl_ops_bss_info_changed: BSS idle: true (implement)
> [   74.398374] wl_ops_bss_info_changed: BSS idle: false (implement)
> [   74.398381] wlan0: associate with 00:1c:10:9c:3c:98 (try 1)
> [   74.402842] wlan0: RX AssocResp from 00:1c:10:9c:3c:98 (capab=0x411 status=0 aid=11)
> [   74.402846] wlan0: associated
> [   74.403886] wl_ops_bss_info_changed: qos enabled: false (implement)
> [   74.403891] brcmsmac: wl_ops_bss_info_changed: associated
> [   74.403898] wl_ops_bss_info_changed: Need to change Basic Rates: 0xf (implement)
> [   74.403904] wl_ops_bss_info_changed: arp filtering: enabled true, count 0 (implement)
> [   74.405021] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
> [   74.647583] hci_cmd_timer: hci0 command tx timeout
> [   74.776522] wl_ops_bss_info_changed: arp filtering: enabled true, count 1 (implement)

[-- Attachment #3: Type: TEXT/PLAIN, Size: 12320 bytes --]

1031a1032,1197
> [   75.923864] wl_ops_bss_info_changed: qos enabled: false (implement)
> [   75.923874] brcmsmac: wl_ops_bss_info_changed: disassociated
> [   75.923877] wl_ops_bss_info_changed: use_cts_prot: false (implement)
> [   75.923880] wl_ops_bss_info_changed: short preamble: false (implement)
> [   75.923889] wl_ops_bss_info_changed: arp filtering: enabled false, count 1 (implement)
> [   75.923895] wlan0: deauthenticating from 00:1c:10:9c:3c:98 by local choice (reason=3)
> [   75.943322] wl_ops_bss_info_changed: BSS idle: true (implement)
> [   75.943339] cfg80211: All devices are disconnected, going to restore regulatory settings
> [   75.943348] cfg80211: Restoring regulatory settings
> [   75.943357] cfg80211: Calling CRDA to update world regulatory domain
> [   75.943362] wl_ops_bss_info_changed: BSS idle: false (implement)
> [   75.948033] cfg80211: Updating information on frequency 2412 MHz for a 20 MHz width channel with regulatory rule:
> [   75.948041] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   75.948046] cfg80211: Updating information on frequency 2417 MHz for a 20 MHz width channel with regulatory rule:
> [   75.948051] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   75.948055] cfg80211: Updating information on frequency 2422 MHz for a 20 MHz width channel with regulatory rule:
> [   75.948060] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   75.948065] cfg80211: Updating information on frequency 2427 MHz for a 20 MHz width channel with regulatory rule:
> [   75.948069] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   75.948074] cfg80211: Updating information on frequency 2432 MHz for a 20 MHz width channel with regulatory rule:
> [   75.948079] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   75.948083] cfg80211: Updating information on frequency 2437 MHz for a 20 MHz width channel with regulatory rule:
> [   75.948088] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   75.948092] cfg80211: Updating information on frequency 2442 MHz for a 20 MHz width channel with regulatory rule:
> [   75.948097] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   75.948101] cfg80211: Updating information on frequency 2447 MHz for a 20 MHz width channel with regulatory rule:
> [   75.948106] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   75.948110] cfg80211: Updating information on frequency 2452 MHz for a 20 MHz width channel with regulatory rule:
> [   75.948115] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   75.948119] cfg80211: Updating information on frequency 2457 MHz for a 20 MHz width channel with regulatory rule:
> [   75.948124] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   75.948149] cfg80211: Updating information on frequency 2462 MHz for a 20 MHz width channel with regulatory rule:
> [   75.948154] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
> [   75.948157] cfg80211: Disabling freq 2467 MHz
> [   75.948160] cfg80211: Disabling freq 2472 MHz
> [   75.948163] cfg80211: Disabling freq 2484 MHz
> [   75.948167] cfg80211: World regulatory domain updated:
> [   75.948170] cfg80211:     (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
> [   75.948175] cfg80211:     (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
> [   75.948180] cfg80211:     (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
> [   75.948185] cfg80211:     (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
> [   75.948189] cfg80211:     (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
> [   75.948194] cfg80211:     (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
> [   75.957206] wl_ops_bss_info_changed: BSS idle: true (implement)
> [   77.705556] PM: Syncing filesystems ... done.
> [   77.706722] PM: Preparing system for mem sleep
> [   77.850189] Freezing user space processes ... (elapsed 0.01 seconds) done.
> [   77.861052] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
> [   77.872039] PM: Entering mem sleep
> [   77.872191] Suspending console(s) (use no_console_suspend to debug)
> [   77.872837] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> [   77.888620] sd 0:0:0:0: [sda] Stopping disk
> [   77.912060] brcmsmac 0000:03:00.0: PCI INT A disabled
> [   77.923064] ehci_hcd 0000:00:1d.0: PCI INT A disabled
> [   77.923076] ehci_hcd 0000:00:1a.0: PCI INT A disabled
> [   78.013092] HDA Intel 0000:01:00.1: PCI INT B disabled
> [   78.013126] ACPI handle has no context!
> [   78.014369] HDA Intel 0000:00:1b.0: PCI INT A disabled
> [   80.399749] PM: suspend of devices complete after 2527.459 msecs
> [   80.399924] r8169 0000:02:00.0: PME# enabled
> [   80.408697] r8169 0000:02:00.0: wake-up capability enabled by ACPI
> [   80.441740] PM: late suspend of devices complete after 41.997 msecs
> [   80.441884] ACPI: Preparing to enter system sleep state S3
> [   80.487834] PM: Saving platform NVS memory
> [   80.493177] Disabling non-boot CPUs ...
> [   80.494806] CPU 1 is now offline
> [   80.496529] CPU 2 is now offline
> [   80.504829] Broke affinity for irq 20
> [   80.505876] CPU 3 is now offline
> [   80.506220] Extended CMOS year: 2000
> [   80.506416] ACPI: Low-level resume complete
> [   80.506471] PM: Restoring platform NVS memory
> [   80.507040] Extended CMOS year: 2000
> [   80.507079] Enabling non-boot CPUs ...
> [   80.507182] Booting Node 0 Processor 1 APIC 0x1
> [   80.507183] smpboot cpu 1: start_ip = 98000
> [   80.598507] Switched to NOHz mode on CPU #1
> [   80.599960] CPU1 is up
> [   80.600052] Booting Node 0 Processor 2 APIC 0x4
> [   80.600053] smpboot cpu 2: start_ip = 98000
> [   80.691078] CPU2 is up
> [   80.691178] Booting Node 0 Processor 3 APIC 0x5
> [   80.691180] smpboot cpu 3: start_ip = 98000
> [   80.691471] Switched to NOHz mode on CPU #2
> [   80.782157] CPU3 is up
> [   80.783357] Switched to NOHz mode on CPU #3
> [   80.783681] ACPI: Waking up from system sleep state S3
> [   80.851177] pcieport 0000:00:01.0: restoring config space at offset 0x7 (was 0x20003030, writing 0x3030)
> [   80.851181] pcieport 0000:00:01.0: restoring config space at offset 0x1 (was 0x100007, writing 0x100407)
> [   80.851201] i915 0000:00:02.0: restoring config space at offset 0x1 (was 0x900007, writing 0x900407)
> [   80.851229] pci 0000:00:16.0: restoring config space at offset 0x1 (was 0x180006, writing 0x100006)
> [   80.851262] ehci_hcd 0000:00:1a.0: restoring config space at offset 0x1 (was 0x2900006, writing 0x2900002)
> [   80.851297] HDA Intel 0000:00:1b.0: restoring config space at offset 0x1 (was 0x100006, writing 0x100002)
> [   80.851327] pcieport 0000:00:1c.0: restoring config space at offset 0x7 (was 0x20002020, writing 0x2020)
> [   80.851402] ehci_hcd 0000:00:1d.0: restoring config space at offset 0x1 (was 0x2900006, writing 0x2900002)
> [   80.851424] pci 0000:00:1e.0: restoring config space at offset 0xa (was 0xffffffff, writing 0x0)
> [   80.851504] ahci 0000:00:1f.2: restoring config space at offset 0x1 (was 0x2b00007, writing 0x2b00407)
> [   80.851627] HDA Intel 0000:01:00.1: restoring config space at offset 0x1 (was 0x100007, writing 0x100003)
> [   80.851680] r8169 0000:02:00.0: restoring config space at offset 0x1 (was 0x100007, writing 0x100407)
> [   80.851768] brcmsmac 0000:03:00.0: restoring config space at offset 0xf (was 0x100, writing 0x10a)
> [   80.851787] brcmsmac 0000:03:00.0: restoring config space at offset 0x4 (was 0x4, writing 0xc2400004)
> [   80.851792] brcmsmac 0000:03:00.0: restoring config space at offset 0x3 (was 0x0, writing 0x10)
> [   80.851798] brcmsmac 0000:03:00.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100006)
> [   80.851949] PM: early resume of devices complete after 0.833 msecs
> [   80.852100] i915 0000:00:02.0: setting latency timer to 64
> [   80.852107] ehci_hcd 0000:00:1a.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
> [   80.852113] ehci_hcd 0000:00:1a.0: setting latency timer to 64
> [   80.852148] HDA Intel 0000:00:1b.0: PCI INT A -> GSI 22 (level, low) -> IRQ 22
> [   80.852152] HDA Intel 0000:00:1b.0: setting latency timer to 64
> [   80.852191] HDA Intel 0000:00:1b.0: irq 46 for MSI/MSI-X
> [   80.852231] ehci_hcd 0000:00:1d.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
> [   80.852236] ehci_hcd 0000:00:1d.0: setting latency timer to 64
> [   80.852265] pci 0000:00:1e.0: setting latency timer to 64
> [   80.852277] ahci 0000:00:1f.2: setting latency timer to 64
> [   80.852326] HDA Intel 0000:01:00.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
> [   80.852330] HDA Intel 0000:01:00.1: setting latency timer to 64
> [   80.852363] HDA Intel 0000:01:00.1: irq 47 for MSI/MSI-X
> [   80.852480] brcmsmac 0000:03:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
> [   80.852485] brcmsmac 0000:03:00.0: setting latency timer to 64
> [   80.852598] sd 0:0:0:0: [sda] Starting disk
> [   80.865473] r8169 0000:02:00.0: wake-up capability disabled by ACPI
> [   80.865479] r8169 0000:02:00.0: PME# disabled
> [   81.083607] usb 1-1.4: reset full speed USB device number 3 using ehci_hcd
> [   81.158479] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
> [   81.160479] ata5: SATA link down (SStatus 0 SControl 300)
> [   81.192446] ata2.00: configured for UDMA/100
> [   81.241617] usb 2-1.3: reset full speed USB device number 3 using ehci_hcd
> [   81.328714] btusb 2-1.3:1.0: no reset_resume for driver btusb?
> [   81.328719] btusb 2-1.3:1.1: no reset_resume for driver btusb?
> [   81.399752] usb 2-1.6: reset high speed USB device number 5 using ehci_hcd
> [   82.329405] hci_cmd_timer: hci0 command tx timeout
> [   83.604299] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
> [   83.616192] ata1.00: configured for UDMA/133
> [  141.955556] r8169 0000:02:00.0: eth0: unable to apply firmware patch
> [  142.557969] PM: resume of devices complete after 61712.246 msecs
> [  142.558474] PM: Finishing wakeup.
> [  142.558475] Restarting tasks ... done.
> [  142.563742] video LNXVIDEO:00: Restoring backlight state
> [  142.563923] video LNXVIDEO:01: Restoring backlight state
> [  143.565055] hci_cmd_timer: hci0 command tx timeout
> [  143.591177] wl_ops_bss_info_changed: use_cts_prot: false (implement)
> [  143.591183] wl_ops_bss_info_changed: short preamble: false (implement)
> [  143.591202] wl_ops_config: change monitor mode: false (implement)
> [  143.591205] wl_ops_config: change power-save mode: false (implement)
> [  143.593448] wl_ops_bss_info_changed: qos enabled: false (implement)
> [  143.594031] wl_ops_bss_info_changed: BSS idle: false (implement)
> [  143.594061] ADDRCONF(NETDEV_UP): wlan0: link is not ready
> [  143.684097] wl_ops_bss_info_changed: BSS idle: true (implement)
> [  143.684157] wl_ops_bss_info_changed: BSS idle: false (implement)
> [  143.774118] wl_ops_bss_info_changed: BSS idle: true (implement)
> [  143.798174] wl_ops_bss_info_changed: BSS idle: false (implement)
> [  143.798222] wlan0: deauthenticating from 00:1c:10:9c:3c:98 by local choice (reason=3)
> [  143.888109] wlan0: authenticate with 00:1c:10:9c:3c:98 (try 1)
> [  143.911758] wlan0: authenticated
> [  143.911781] wl_ops_bss_info_changed: BSS idle: true (implement)
> [  143.911815] wl_ops_bss_info_changed: BSS idle: false (implement)
> [  143.911821] wlan0: associate with 00:1c:10:9c:3c:98 (try 1)
> [  143.914372] wlan0: RX AssocResp from 00:1c:10:9c:3c:98 (capab=0x411 status=0 aid=11)
> [  143.914377] wlan0: associated
> [  143.915137] wl_ops_bss_info_changed: qos enabled: false (implement)
> [  143.915141] brcmsmac: wl_ops_bss_info_changed: associated
> [  143.915147] wl_ops_bss_info_changed: Need to change Basic Rates: 0xf (implement)
> [  143.915153] wl_ops_bss_info_changed: arp filtering: enabled true, count 0 (implement)
> [  143.915987] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
> [  143.974405] wl_ops_bss_info_changed: arp filtering: enabled true, count 1 (implement)
> [  154.004056] wlan0: no IPv6 routers present

Re: Suspend/resume - slow resume

[Linus Torvalds]

On Mon, Apr 18, 2011 at 12:27 PM, Ciprian Docan <docan@eden.rutgers.edu> wrote:
>
> Linus - I applied your patch and attached the diff between output of dmesg
> before and after the patch as resume_timing.diff. This patch alone does not
> seem to fix the issue;

Ok, that just means that the error return from call_usermodehelper()
gets lost somewhere along the way to kobject_uevent(). Or that I
misread the whole thing.

>  however, applying Francois's patch in addition to
> yours make the resume smooth.

Well, Francois' patch on its own should already have fixed it for you,
and made the whole issue moot.

Francois' patch is fine and improves on things, I only had a few
arguments with it. The problems I think it had were really about some
rather special cases.

                      Linus

Re: Suspend/resume - slow resume

[Francois Romieu]

Linus Torvalds <torvalds@linux-foundation.org> :
[...]
> Francois' patch is fine and improves on things, I only had a few
> arguments with it. The problems I think it had were really about some
> rather special cases.

They may be addressed by the patch below.

I'll test it as soon as my 2.6.39-rc stops softlocking and I have a
working suspend / resume. No joke.

Subject: [PATCH] r8169: don't request firmware when there's no userspace.

The firmware is cached during the first successfull call to open() and
released once the network device is unregistered. The driver uses the
cached firmware between open() and unregister_netdev().

So far the firmware is optional : a failure to load the firmware does
not prevent open() to success. It is thus necessary to 1) unregister
all 816x / 810[23] devices and 2) force a driver probe to issue a new
firmware load.

Signed-off-by: Francois Romieu <romieu@fr.zoreil.com>
---
 drivers/net/r8169.c |   92 ++++++++++++++++++++++++++++++++++++---------------
 1 files changed, 65 insertions(+), 27 deletions(-)

diff --git a/drivers/net/r8169.c b/drivers/net/r8169.c
index 493b0de..fceb954 100644
--- a/drivers/net/r8169.c
+++ b/drivers/net/r8169.c
@@ -170,6 +170,16 @@ static const struct {
 };
 #undef _R
 
+static const struct rtl_firmware_info {
+	int mac_version;
+	const char *fw_name;
+} rtl_firmware_infos[] = {
+	{ .mac_version = RTL_GIGA_MAC_VER_25, .fw_name = FIRMWARE_8168D_1 },
+	{ .mac_version = RTL_GIGA_MAC_VER_26, .fw_name = FIRMWARE_8168D_2 },
+	{ .mac_version = RTL_GIGA_MAC_VER_29, .fw_name = FIRMWARE_8105E_1 },
+	{ .mac_version = RTL_GIGA_MAC_VER_30, .fw_name = FIRMWARE_8105E_1 }
+};
+
 enum cfg_version {
 	RTL_CFG_0 = 0x00,
 	RTL_CFG_1,
@@ -565,6 +575,7 @@ struct rtl8169_private {
 	u32 saved_wolopts;
 
 	const struct firmware *fw;
+#define RTL_FIRMWARE_UNKNOWN	ERR_PTR(-EAGAIN);
 };
 
 MODULE_AUTHOR("Realtek and the Linux r8169 crew <netdev@vger.kernel.org>");
@@ -1790,24 +1801,24 @@ rtl_phy_write_fw(struct rtl8169_private *tp, const struct firmware *fw)
 static void rtl_release_firmware(struct rtl8169_private *tp)
 {
 	release_firmware(tp->fw);
-	tp->fw = NULL;
+	tp->fw = RTL_FIRMWARE_UNKNOWN;
 }
 
-static int rtl_apply_firmware(struct rtl8169_private *tp, const char *fw_name)
+static void rtl_apply_firmware(struct rtl8169_private *tp)
 {
-	const struct firmware **fw = &tp->fw;
-	int rc = !*fw;
-
-	if (rc) {
-		rc = request_firmware(fw, fw_name, &tp->pci_dev->dev);
-		if (rc < 0)
-			goto out;
-	}
+	const struct firmware *fw = tp->fw;
 
 	/* TODO: release firmware once rtl_phy_write_fw signals failures. */
-	rtl_phy_write_fw(tp, *fw);
-out:
-	return rc;
+	if (!IS_ERR_OR_NULL(fw))
+		rtl_phy_write_fw(tp, fw);
+}
+
+static void rtl_apply_firmware_cond(struct rtl8169_private *tp, u8 reg, u16 val)
+{
+	if (rtl_readphy(tp, reg) != val)
+		netif_warn(tp, hw, tp->dev, "chipset not ready for firmware\n");
+	else
+		rtl_apply_firmware(tp);
 }
 
 static void rtl8169s_hw_phy_config(struct rtl8169_private *tp)
@@ -2246,10 +2257,8 @@ static void rtl8168d_1_hw_phy_config(struct rtl8169_private *tp)
 
 	rtl_writephy(tp, 0x1f, 0x0005);
 	rtl_writephy(tp, 0x05, 0x001b);
-	if ((rtl_readphy(tp, 0x06) != 0xbf00) ||
-	    (rtl_apply_firmware(tp, FIRMWARE_8168D_1) < 0)) {
-		netif_warn(tp, probe, tp->dev, "unable to apply firmware patch\n");
-	}
+
+	rtl_apply_firmware_cond(tp, MII_EXPANSION, 0xbf00);
 
 	rtl_writephy(tp, 0x1f, 0x0000);
 }
@@ -2351,10 +2360,8 @@ static void rtl8168d_2_hw_phy_config(struct rtl8169_private *tp)
 
 	rtl_writephy(tp, 0x1f, 0x0005);
 	rtl_writephy(tp, 0x05, 0x001b);
-	if ((rtl_readphy(tp, 0x06) != 0xb300) ||
-	    (rtl_apply_firmware(tp, FIRMWARE_8168D_2) < 0)) {
-		netif_warn(tp, probe, tp->dev, "unable to apply firmware patch\n");
-	}
+
+	rtl_apply_firmware_cond(tp, MII_EXPANSION, 0xb300);
 
 	rtl_writephy(tp, 0x1f, 0x0000);
 }
@@ -2474,8 +2481,7 @@ static void rtl8105e_hw_phy_config(struct rtl8169_private *tp)
 	rtl_writephy(tp, 0x18, 0x0310);
 	msleep(100);
 
-	if (rtl_apply_firmware(tp, FIRMWARE_8105E_1) < 0)
-		netif_warn(tp, probe, tp->dev, "unable to apply firmware patch\n");
+	rtl_apply_firmware(tp);
 
 	rtl_writephy_batch(tp, phy_reg_init, ARRAY_SIZE(phy_reg_init));
 }
@@ -3237,6 +3243,8 @@ rtl8169_init_one(struct pci_dev *pdev, const struct pci_device_id *ent)
 	tp->timer.data = (unsigned long) dev;
 	tp->timer.function = rtl8169_phy_timer;
 
+	tp->fw = RTL_FIRMWARE_UNKNOWN;
+
 	rc = register_netdev(dev);
 	if (rc < 0)
 		goto err_out_msi_4;
@@ -3288,10 +3296,10 @@ static void __devexit rtl8169_remove_one(struct pci_dev *pdev)
 
 	cancel_delayed_work_sync(&tp->task);
 
-	rtl_release_firmware(tp);
-
 	unregister_netdev(dev);
 
+	rtl_release_firmware(tp);
+
 	if (pci_dev_run_wake(pdev))
 		pm_runtime_get_noresume(&pdev->dev);
 
@@ -3303,6 +3311,33 @@ static void __devexit rtl8169_remove_one(struct pci_dev *pdev)
 	pci_set_drvdata(pdev, NULL);
 }
 
+static void rtl_request_firmware(struct rtl8169_private *tp)
+{
+	int i;
+
+	/* Return early if the firmware is already loaded / cached. */
+	if (!IS_ERR(tp->fw))
+		return;
+
+	for (i = 0; i < ARRAY_SIZE(rtl_firmware_infos); i++) {
+		const struct rtl_firmware_info *info = rtl_firmware_infos + i;
+
+		if (info->mac_version == tp->mac_version) {
+			const char *name = info->fw_name;
+			int rc;
+
+			rc = request_firmware(&tp->fw, name, &tp->pci_dev->dev);
+			if (rc < 0) {
+				netif_warn(tp, ifup, tp->dev, "unable to load "
+					"firmware patch %s (%d)\n", name, rc);
+			}
+			return;
+		}
+	}
+
+	tp->fw = NULL;
+}
+
 static int rtl8169_open(struct net_device *dev)
 {
 	struct rtl8169_private *tp = netdev_priv(dev);
@@ -3334,11 +3369,13 @@ static int rtl8169_open(struct net_device *dev)
 
 	smp_mb();
 
+	rtl_request_firmware(tp);
+
 	retval = request_irq(dev->irq, rtl8169_interrupt,
 			     (tp->features & RTL_FEATURE_MSI) ? 0 : IRQF_SHARED,
 			     dev->name, dev);
 	if (retval < 0)
-		goto err_release_ring_2;
+		goto err_release_fw_2;
 
 	napi_enable(&tp->napi);
 
@@ -3359,7 +3396,8 @@ static int rtl8169_open(struct net_device *dev)
 out:
 	return retval;
 
-err_release_ring_2:
+err_release_fw_2:
+	rtl_release_firmware(tp);
 	rtl8169_rx_clear(tp);
 err_free_rx_1:
 	dma_free_coherent(&pdev->dev, R8169_RX_RING_BYTES, tp->RxDescArray,
-- 
1.7.4.2

Re: Suspend/resume - slow resume

[Ciprian Docan]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 518 bytes --]


Hello Francois,

I tried your patch and my machine resumes properly.

> The firmware is cached during the first successfull call to open() and
> released once the network device is unregistered. The driver uses the
> cached firmware between open() and unregister_netdev().

Here is what I did to test it: I compiled the patched module, unloaded the 
previous module, loaded the new one, and then suspend & resume. Output of 
dmesg attached. Please let me know if you need any other information.

Regards,
--
 	Ciprian

[-- Attachment #2: Type: TEXT/PLAIN, Size: 12206 bytes --]

[74001.664088] r8169 0000:02:00.0: PCI INT A disabled
[74033.821473] r8169 Gigabit Ethernet driver 2.3LK-NAPI loaded
[74033.821497] r8169 0000:02:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[74033.822310] r8169 0000:02:00.0: setting latency timer to 64
[74033.822364] r8169 0000:02:00.0: irq 45 for MSI/MSI-X
[74033.822572] r8169 0000:02:00.0: eth0: RTL8168d/8111d at 0xffffc90027e2e000, 64:31:50:69:2c:61, XID 083000c0 IRQ 45
[74058.429717] wl_ops_bss_info_changed: qos enabled: false (implement)
[74058.429729] brcmsmac: wl_ops_bss_info_changed: disassociated
[74058.429735] wl_ops_bss_info_changed: use_cts_prot: false (implement)
[74058.429741] wl_ops_bss_info_changed: short preamble: false (implement)
[74058.429754] wl_ops_bss_info_changed: arp filtering: enabled false, count 1 (implement)
[74058.429764] wlan0: deauthenticating from 00:1e:2a:01:3e:bb by local choice (reason=3)
[74058.455026] wl_ops_bss_info_changed: BSS idle: true (implement)
[74058.455046] cfg80211: All devices are disconnected, going to restore regulatory settings
[74058.455055] cfg80211: Restoring regulatory settings
[74058.455064] cfg80211: Calling CRDA to update world regulatory domain
[74058.455069] wl_ops_bss_info_changed: BSS idle: false (implement)
[74058.460281] cfg80211: Updating information on frequency 2412 MHz for a 20 MHz width channel with regulatory rule:
[74058.460291] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
[74058.460297] cfg80211: Updating information on frequency 2417 MHz for a 20 MHz width channel with regulatory rule:
[74058.460305] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
[74058.460311] cfg80211: Updating information on frequency 2422 MHz for a 20 MHz width channel with regulatory rule:
[74058.460319] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
[74058.460325] cfg80211: Updating information on frequency 2427 MHz for a 20 MHz width channel with regulatory rule:
[74058.460330] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
[74058.460334] cfg80211: Updating information on frequency 2432 MHz for a 20 MHz width channel with regulatory rule:
[74058.460339] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
[74058.460344] cfg80211: Updating information on frequency 2437 MHz for a 20 MHz width channel with regulatory rule:
[74058.460349] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
[74058.460353] cfg80211: Updating information on frequency 2442 MHz for a 20 MHz width channel with regulatory rule:
[74058.460358] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
[74058.460363] cfg80211: Updating information on frequency 2447 MHz for a 20 MHz width channel with regulatory rule:
[74058.460368] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
[74058.460372] cfg80211: Updating information on frequency 2452 MHz for a 20 MHz width channel with regulatory rule:
[74058.460377] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
[74058.460382] cfg80211: Updating information on frequency 2457 MHz for a 20 MHz width channel with regulatory rule:
[74058.460387] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
[74058.460391] cfg80211: Updating information on frequency 2462 MHz for a 20 MHz width channel with regulatory rule:
[74058.460396] cfg80211: 2402000 KHz - 2472000 KHz @  KHz), (300 mBi, 2700 mBm)
[74058.460400] cfg80211: Disabling freq 2467 MHz
[74058.460403] cfg80211: Disabling freq 2472 MHz
[74058.460405] cfg80211: Disabling freq 2484 MHz
[74058.460410] cfg80211: World regulatory domain updated:
[74058.460413] cfg80211:     (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[74058.460418] cfg80211:     (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[74058.460423] cfg80211:     (2457000 KHz - 2482000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[74058.460427] cfg80211:     (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[74058.460432] cfg80211:     (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[74058.460437] cfg80211:     (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[74058.464926] wl_ops_bss_info_changed: BSS idle: true (implement)
[74059.892010] PM: Syncing filesystems ... done.
[74059.909543] PM: Preparing system for mem sleep
[74060.072757] Freezing user space processes ... (elapsed 0.01 seconds) done.
[74060.084607] Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done.
[74060.095548] PM: Entering mem sleep
[74060.095712] Suspending console(s) (use no_console_suspend to debug)
[74060.107943] sd 0:0:0:0: [sda] Synchronizing SCSI cache
[74060.108024] sd 0:0:0:0: [sda] Stopping disk
[74060.147028] HDA Intel 0000:01:00.1: PCI INT B disabled
[74060.147031] brcmsmac 0000:03:00.0: PCI INT A disabled
[74060.147064] ACPI handle has no context!
[74060.157421] ehci_hcd 0000:00:1d.0: PCI INT A disabled
[74060.157444] ehci_hcd 0000:00:1a.0: PCI INT A disabled
[74060.248878] HDA Intel 0000:00:1b.0: PCI INT A disabled
[74062.612741] PM: suspend of devices complete after 2512.037 msecs
[74062.612949] r8169 0000:02:00.0: PME# enabled
[74062.621666] r8169 0000:02:00.0: wake-up capability enabled by ACPI
[74062.654658] PM: late suspend of devices complete after 42.007 msecs
[74062.654817] ACPI: Preparing to enter system sleep state S3
[74062.700627] PM: Saving platform NVS memory
[74062.704367] Disabling non-boot CPUs ...
[74062.706846] CPU 1 is now offline
[74062.724771] CPU 2 is now offline
[74062.734603] CPU 3 is now offline
[74062.734969] Extended CMOS year: 2000
[74062.735165] ACPI: Low-level resume complete
[74062.735220] PM: Restoring platform NVS memory
[74062.735780] Extended CMOS year: 2000
[74062.735802] Enabling non-boot CPUs ...
[74062.735923] Booting Node 0 Processor 1 APIC 0x1
[74062.735924] smpboot cpu 1: start_ip = 98000
[74062.826473] CPU1 is up
[74062.826637] Booting Node 0 Processor 2 APIC 0x4
[74062.826641] smpboot cpu 2: start_ip = 98000
[74062.826826] Switched to NOHz mode on CPU #1
[74062.917217] CPU2 is up
[74062.917382] Booting Node 0 Processor 3 APIC 0x5
[74062.917386] smpboot cpu 3: start_ip = 98000
[74062.917580] Switched to NOHz mode on CPU #2
[74063.008091] CPU3 is up
[74063.009302] Switched to NOHz mode on CPU #3
[74063.009672] ACPI: Waking up from system sleep state S3
[74063.090894] pcieport 0000:00:01.0: restoring config space at offset 0x1 (was 0x100007, writing 0x100407)
[74063.090915] i915 0000:00:02.0: restoring config space at offset 0x1 (was 0x900007, writing 0x900407)
[74063.090974] ehci_hcd 0000:00:1a.0: restoring config space at offset 0x1 (was 0x2900006, writing 0x2900002)
[74063.091009] HDA Intel 0000:00:1b.0: restoring config space at offset 0x1 (was 0x100006, writing 0x100002)
[74063.091117] ehci_hcd 0000:00:1d.0: restoring config space at offset 0x1 (was 0x2900006, writing 0x2900002)
[74063.091140] pci 0000:00:1e.0: restoring config space at offset 0xa (was 0xffffffff, writing 0x0)
[74063.091213] ahci 0000:00:1f.2: restoring config space at offset 0x1 (was 0x2b00007, writing 0x2b00407)
[74063.091336] HDA Intel 0000:01:00.1: restoring config space at offset 0x1 (was 0x100007, writing 0x100003)
[74063.091389] r8169 0000:02:00.0: restoring config space at offset 0x1 (was 0x100007, writing 0x100407)
[74063.091477] brcmsmac 0000:03:00.0: restoring config space at offset 0xf (was 0x100, writing 0x10a)
[74063.091496] brcmsmac 0000:03:00.0: restoring config space at offset 0x4 (was 0x4, writing 0xc2400004)
[74063.091502] brcmsmac 0000:03:00.0: restoring config space at offset 0x3 (was 0x0, writing 0x10)
[74063.091508] brcmsmac 0000:03:00.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100006)
[74063.091655] PM: early resume of devices complete after 0.826 msecs
[74063.091803] i915 0000:00:02.0: setting latency timer to 64
[74063.091883] HDA Intel 0000:01:00.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
[74063.091888] ehci_hcd 0000:00:1a.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[74063.091890] HDA Intel 0000:01:00.1: setting latency timer to 64
[74063.091895] ehci_hcd 0000:00:1a.0: setting latency timer to 64
[74063.091938] HDA Intel 0000:01:00.1: irq 46 for MSI/MSI-X
[74063.091945] HDA Intel 0000:00:1b.0: PCI INT A -> GSI 22 (level, low) -> IRQ 22
[74063.091953] HDA Intel 0000:00:1b.0: setting latency timer to 64
[74063.091987] HDA Intel 0000:00:1b.0: irq 47 for MSI/MSI-X
[74063.091990] ehci_hcd 0000:00:1d.0: PCI INT A -> GSI 20 (level, low) -> IRQ 20
[74063.091996] ehci_hcd 0000:00:1d.0: setting latency timer to 64
[74063.092023] pci 0000:00:1e.0: setting latency timer to 64
[74063.092088] ahci 0000:00:1f.2: setting latency timer to 64
[74063.092096] brcmsmac 0000:03:00.0: PCI INT A -> GSI 17 (level, low) -> IRQ 17
[74063.092107] brcmsmac 0000:03:00.0: setting latency timer to 64
[74063.102150] sd 0:0:0:0: [sda] Starting disk
[74063.105668] r8169 0000:02:00.0: wake-up capability disabled by ACPI
[74063.105674] r8169 0000:02:00.0: PME# disabled
[74063.322691] usb 1-1.4: reset full speed USB device number 3 using ehci_hcd
[74063.406321] ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[74063.410296] ata5: SATA link down (SStatus 0 SControl 300)
[74063.440225] ata2.00: configured for UDMA/100
[74063.480281] usb 2-1.3: reset full speed USB device number 3 using ehci_hcd
[74063.566915] btusb 2-1.3:1.0: no reset_resume for driver btusb?
[74063.566921] btusb 2-1.3:1.1: no reset_resume for driver btusb?
[74063.637853] usb 2-1.6: reset high speed USB device number 5 using ehci_hcd
[74064.566218] hci_cmd_timer: hci0 command tx timeout
[74065.849747] ata1: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[74065.861688] ata1.00: configured for UDMA/133
[74066.466771] PM: resume of devices complete after 3384.208 msecs
[74066.467065] PM: Finishing wakeup.
[74066.467067] Restarting tasks ... done.
[74066.475211] video LNXVIDEO:00: Restoring backlight state
[74066.475339] video LNXVIDEO:01: Restoring backlight state
[74066.740330] wl_ops_bss_info_changed: use_cts_prot: false (implement)
[74066.740334] wl_ops_bss_info_changed: short preamble: false (implement)
[74066.740349] wl_ops_config: change monitor mode: false (implement)
[74066.740350] wl_ops_config: change power-save mode: false (implement)
[74066.742592] wl_ops_bss_info_changed: qos enabled: false (implement)
[74066.743416] wl_ops_bss_info_changed: BSS idle: false (implement)
[74066.743435] ADDRCONF(NETDEV_UP): wlan0: link is not ready
[74066.833025] wl_ops_bss_info_changed: BSS idle: true (implement)
[74066.833049] wl_ops_bss_info_changed: BSS idle: false (implement)
[74066.922738] wl_ops_bss_info_changed: BSS idle: true (implement)
[74067.470305] hci_cmd_timer: hci0 command tx timeout
[74071.913773] wl_ops_bss_info_changed: BSS idle: false (implement)
[74072.813906] wl_ops_bss_info_changed: BSS idle: true (implement)
[74072.813930] wl_ops_bss_info_changed: BSS idle: false (implement)
[74072.813990] wlan0: deauthenticating from 00:1e:2a:00:2d:fe by local choice (reason=3)
[74072.903591] wlan0: authenticate with 00:1e:2a:00:2d:fe (try 1)
[74072.913250] wlan0: authenticated
[74072.913271] wl_ops_bss_info_changed: BSS idle: true (implement)
[74072.913304] wl_ops_bss_info_changed: BSS idle: false (implement)
[74072.913312] wlan0: associate with 00:1e:2a:00:2d:fe (try 1)
[74072.916142] wlan0: RX AssocResp from 00:1e:2a:00:2d:fe (capab=0x411 status=0 aid=1)
[74072.916147] wlan0: associated
[74072.917091] wl_ops_bss_info_changed: qos enabled: true (implement)
[74072.917096] brcmsmac: wl_ops_bss_info_changed: associated
[74072.917100] wl_ops_bss_info_changed: use_cts_prot: true (implement)
[74072.917103] wl_ops_bss_info_changed: short preamble: true (implement)
[74072.917111] wl_ops_bss_info_changed: Need to change Basic Rates: 0xf (implement)
[74072.917118] wl_ops_bss_info_changed: arp filtering: enabled true, count 0 (implement)
[74072.918403] ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[74073.806196] wl_ops_bss_info_changed: arp filtering: enabled true, count 1 (implement)

Re: Suspend/resume - slow resume

[Ciprian Docan]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 201 bytes --]


Hello Francois,

I tried to unload the module, but it crashed. I re-booted the machine and 
tried to unload the module again. I got the output from dmesg; please see 
attached.

Regards,
--
 	Ciprian

[-- Attachment #2: Type: TEXT/PLAIN, Size: 7026 bytes --]

[    7.007361] r8169 Gigabit Ethernet driver 2.3LK-NAPI loaded
[    7.007383] r8169 0000:02:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[    7.007454] r8169 0000:02:00.0: setting latency timer to 64
[    7.007506] r8169 0000:02:00.0: irq 45 for MSI/MSI-X
[    7.007628] r8169 0000:02:00.0: eth0: RTL8168d/8111d at 0xffffc90011810000, 64:31:50:69:2c:61, XID 083000c0 IRQ 45

...

[  109.216074] r8169 0000:02:00.0: PCI INT A disabled
[  116.748813] EXT4-fs (dm-1): mounted filesystem with ordered data mode. Opts: (null)
[  166.963998] r8169 Gigabit Ethernet driver 2.3LK-NAPI loaded
[  166.964100] r8169 0000:02:00.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[  166.964319] r8169 0000:02:00.0: setting latency timer to 64
[  166.964379] r8169 0000:02:00.0: irq 45 for MSI/MSI-X
[  166.964593] r8169 0000:02:00.0: eth0: RTL8168d/8111d at 0xffffc90022fc4000, 64:31:50:69:2c:61, XID 083000c0 IRQ 45
[  174.917306] BUG: unable to handle kernel paging request at fffffffffffffffd
[  174.919573] IP: [<ffffffff8127b267>] firmware_free_data+0xf/0x55
[  174.921828] PGD 1605067 PUD 1606067 PMD 0 
[  174.924088] Oops: 0000 [#1] SMP 
[  174.926323] last sysfs file: /sys/devices/pci0000:00/0000:00:1c.1/0000:03:00.0/ieee80211/phy0/rfkill0/uevent
[  174.928649] CPU 2 
[  174.928670] Modules linked in: r8169(-) aes_x86_64 aes_generic fuse hidp fbcon tileblit font bitblit softcursor rfcomm bnep acpi_cpufreq mperf ip6t_REJECT nf_conntrack_ipv6 nf_defrag_ipv6 ip6table_filter ip6_tables ipv6 snd_hda_codec_hdmi snd_hda_codec_idt snd_hda_intel snd_hda_codec snd_hwdep snd_seq snd_seq_device snd_pcm arc4 snd_timer snd soundcore ecb btusb processor thermal uvcvideo hp_wmi psmouse fan videodev i2c_i801 sparse_keymap snd_page_alloc pcspkr brcmsmac(C) hp_accel iTCO_wdt mac80211 iTCO_vendor_support bluetooth lis3lv02d mii input_polldev serio_raw wmi v4l2_compat_ioctl32 cfg80211 rfkill microcode i915 drm_kms_helper drm fb fbdev intel_agp i2c_algo_bit cfbcopyarea intel_gtt agpgart i2c_core video cfbimgblt cfbfillrect [last unloaded: r8169]
[  174.944284] 
[  174.946871] Pid: 2003, comm: rmmod Tainted: G         C  2.6.39-rc3+ #13 Hewlett-Packard HP Pavilion dm4 Notebook PC     /1603
[  174.949618] RIP: 0010:[<ffffffff8127b267>]  [<ffffffff8127b267>] firmware_free_data+0xf/0x55
[  174.952348] RSP: 0018:ffff88023ad45d48  EFLAGS: 00010246
[  174.954988] RAX: ffffffff815be000 RBX: fffffffffffffff5 RCX: ffff88024b1c0398
[  174.957707] RDX: 0000000000000000 RSI: 0000000000000037 RDI: fffffffffffffff5
[  174.960417] RBP: ffff88023ad45d58 R08: 0000000000000100 R09: ffffffff8172f690
[  174.963039] R10: 000000000000000f R11: ffff88024b1c0000 R12: ffff88024f790000
[  174.965662] R13: ffff88024b1c0000 R14: ffff88024f790090 R15: 0000000000000001
[  174.968194] FS:  00007faaa8774720(0000) GS:ffff88025bc80000(0000) knlGS:0000000000000000
[  174.970806] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[  174.973388] CR2: fffffffffffffffd CR3: 000000024b828000 CR4: 00000000000006e0
[  174.973392] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  174.973396] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[  174.973400] Process rmmod (pid: 2003, threadinfo ffff88023ad44000, task ffff88023adb8000)
[  174.973403] Stack:
[  174.973405]  fffffffffffffff5 ffff88024f790000 ffff88023ad45d78 ffffffff8127b2f6
[  174.973410]  ffff88023ad45d78 ffff88024b1c0740 ffff88023ad45db8 ffffffffa046e21e
[  174.973415]  ffff88024f7900f0 ffff88024f790090 ffffffffa0470030 ffff88024f790000
[  174.973420] Call Trace:
[  174.973427]  [<ffffffff8127b2f6>] release_firmware+0x49/0x4f
[  174.973437]  [<ffffffffa046e21e>] rtl8169_remove_one+0x8f/0x118 [r8169]
[  174.973446]  [<ffffffff8120435c>] pci_device_remove+0x3f/0x91
[  174.973453]  [<ffffffff8127209c>] __device_release_driver+0x83/0xd9
[  174.973458]  [<ffffffff8127278c>] driver_detach+0x86/0xae
[  174.973464]  [<ffffffff81271f4e>] bus_remove_driver+0xb9/0xdf
[  174.973469]  [<ffffffff81272af7>] driver_unregister+0x6c/0x74
[  174.973474]  [<ffffffff8120463a>] pci_unregister_driver+0x44/0x89
[  174.973482]  [<ffffffffa046e2bc>] rtl8169_cleanup_module+0x15/0x17 [r8169]
[  174.973491]  [<ffffffff8106e474>] sys_delete_module+0x1ca/0x23b
[  174.973498]  [<ffffffff81109445>] ? path_put+0x22/0x27
[  174.973505]  [<ffffffff813d43eb>] system_call_fastpath+0x16/0x1b
[  174.973508] Code: c4 18 5b 41 5c 41 5d 41 5e 41 5f c9 c3 4c 89 e7 e8 4d 8d e7 ff b8 f2 ff ff ff eb e2 55 48 89 e5 41 54 53 0f 1f 44 00 00 48 89 fb 
[  174.973529]  8b 7f 08 e8 e5 79 e6 ff 48 83 7b 10 00 74 31 45 31 e4 eb 0e 
[  174.973539] RIP  [<ffffffff8127b267>] firmware_free_data+0xf/0x55
[  174.973545]  RSP <ffff88023ad45d48>
[  174.973547] CR2: fffffffffffffffd
[  174.973551] ---[ end trace 4aa4e169865c5c0c ]---
[  174.973557] BUG: sleeping function called from invalid context at kernel/rwsem.c:21
[  174.973561] in_atomic(): 0, irqs_disabled(): 1, pid: 2003, name: rmmod
[  174.973565] Pid: 2003, comm: rmmod Tainted: G      D  C  2.6.39-rc3+ #13
[  174.973569] Call Trace:
[  174.973576]  [<ffffffff8102dd7b>] __might_sleep+0xeb/0xf0
[  174.973583]  [<ffffffff813cd632>] down_read+0x24/0x3b
[  174.973589]  [<ffffffff810768f9>] acct_collect+0x4d/0x181
[  174.973595]  [<ffffffff81041ccd>] do_exit+0x22d/0x70a
[  174.973600]  [<ffffffff813cde9a>] ? _raw_spin_lock_irqsave+0x12/0x2f
[  174.973605]  [<ffffffff8103fc36>] ? kmsg_dump+0x49/0xdb
[  174.973610]  [<ffffffff813ceeea>] oops_end+0xb7/0xbf
[  174.973616]  [<ffffffff81022b3b>] no_context+0x1f9/0x208
[  174.973620]  [<ffffffff813cc815>] ? schedule+0x664/0x67e
[  174.973626]  [<ffffffff81022cd2>] __bad_area_nosemaphore+0x188/0x1ab
[  174.973631]  [<ffffffff81022d08>] bad_area_nosemaphore+0x13/0x15
[  174.973636]  [<ffffffff813d0d9d>] do_page_fault+0x16f/0x342
[  174.973643]  [<ffffffff8101c67b>] ? flat_send_IPI_allbutself+0x73/0x7e
[  174.973649]  [<ffffffff81018300>] ? native_send_call_func_ipi+0x76/0x96
[  174.973655]  [<ffffffff8106b119>] ? smp_call_function_many+0x1de/0x1ed
[  174.973661]  [<ffffffff813ce49f>] page_fault+0x1f/0x30
[  174.973667]  [<ffffffff8127b267>] ? firmware_free_data+0xf/0x55
[  174.973672]  [<ffffffff8127b2f6>] release_firmware+0x49/0x4f
[  174.973679]  [<ffffffffa046e21e>] rtl8169_remove_one+0x8f/0x118 [r8169]
[  174.973685]  [<ffffffff8120435c>] pci_device_remove+0x3f/0x91
[  174.973691]  [<ffffffff8127209c>] __device_release_driver+0x83/0xd9
[  174.973696]  [<ffffffff8127278c>] driver_detach+0x86/0xae
[  174.973701]  [<ffffffff81271f4e>] bus_remove_driver+0xb9/0xdf
[  174.973706]  [<ffffffff81272af7>] driver_unregister+0x6c/0x74
[  174.973711]  [<ffffffff8120463a>] pci_unregister_driver+0x44/0x89
[  174.973719]  [<ffffffffa046e2bc>] rtl8169_cleanup_module+0x15/0x17 [r8169]
[  174.973724]  [<ffffffff8106e474>] sys_delete_module+0x1ca/0x23b
[  174.973729]  [<ffffffff81109445>] ? path_put+0x22/0x27
[  174.973735]  [<ffffffff813d43eb>] system_call_fastpath+0x16/0x1b

Re: Suspend/resume - slow resume

[Francois Romieu]

Ciprian Docan <docan@eden.rutgers.edu> :
[...]
> Here is what I did to test it: I compiled the patched module,
> unloaded the previous module, loaded the new one, and then suspend &
> resume. Output of dmesg attached. Please let me know if you need any
> other information.

Thanks.

You can remove the firmware and try the same test.

Then you try again with a non-modular r8169 driver, with and without
firmware.

You should see a few extra messages but suffer no extra delay during
resume.

-- 
Ueimor

Re: Suspend/resume - slow resume

[Francois Romieu]

Ciprian Docan <docan@eden.rutgers.edu> :
[...]
> I tried to unload the module, but it crashed. I re-booted the
> machine and tried to unload the module again. I got the output from
> dmesg; please see attached.

Hmmm...

Subject: [PATCH] r8169: don't request firmware when there's no userspace.

The firmware is cached during the first successfull call to open() and
released once the network device is unregistered. The driver uses the
cached firmware between open() and unregister_netdev().

So far the firmware is optional : a failure to load the firmware does
not prevent open() to success. It is thus necessary to 1) unregister
all 816x / 810[23] devices and 2) force a driver probe to issue a new
firmware load.

Signed-off-by: Francois Romieu <romieu@fr.zoreil.com>
---
 drivers/net/r8169.c |   96 ++++++++++++++++++++++++++++++++++++--------------
 1 files changed, 69 insertions(+), 27 deletions(-)

diff --git a/drivers/net/r8169.c b/drivers/net/r8169.c
index 493b0de..4b41b80 100644
--- a/drivers/net/r8169.c
+++ b/drivers/net/r8169.c
@@ -170,6 +170,16 @@ static const struct {
 };
 #undef _R
 
+static const struct rtl_firmware_info {
+	int mac_version;
+	const char *fw_name;
+} rtl_firmware_infos[] = {
+	{ .mac_version = RTL_GIGA_MAC_VER_25, .fw_name = FIRMWARE_8168D_1 },
+	{ .mac_version = RTL_GIGA_MAC_VER_26, .fw_name = FIRMWARE_8168D_2 },
+	{ .mac_version = RTL_GIGA_MAC_VER_29, .fw_name = FIRMWARE_8105E_1 },
+	{ .mac_version = RTL_GIGA_MAC_VER_30, .fw_name = FIRMWARE_8105E_1 }
+};
+
 enum cfg_version {
 	RTL_CFG_0 = 0x00,
 	RTL_CFG_1,
@@ -565,6 +575,7 @@ struct rtl8169_private {
 	u32 saved_wolopts;
 
 	const struct firmware *fw;
+#define RTL_FIRMWARE_UNKNOWN	ERR_PTR(-EAGAIN);
 };
 
 MODULE_AUTHOR("Realtek and the Linux r8169 crew <netdev@vger.kernel.org>");
@@ -1790,24 +1801,24 @@ rtl_phy_write_fw(struct rtl8169_private *tp, const struct firmware *fw)
 static void rtl_release_firmware(struct rtl8169_private *tp)
 {
 	release_firmware(tp->fw);
-	tp->fw = NULL;
+	tp->fw = RTL_FIRMWARE_UNKNOWN;
 }
 
-static int rtl_apply_firmware(struct rtl8169_private *tp, const char *fw_name)
+static void rtl_apply_firmware(struct rtl8169_private *tp)
 {
-	const struct firmware **fw = &tp->fw;
-	int rc = !*fw;
-
-	if (rc) {
-		rc = request_firmware(fw, fw_name, &tp->pci_dev->dev);
-		if (rc < 0)
-			goto out;
-	}
+	const struct firmware *fw = tp->fw;
 
 	/* TODO: release firmware once rtl_phy_write_fw signals failures. */
-	rtl_phy_write_fw(tp, *fw);
-out:
-	return rc;
+	if (!IS_ERR_OR_NULL(fw))
+		rtl_phy_write_fw(tp, fw);
+}
+
+static void rtl_apply_firmware_cond(struct rtl8169_private *tp, u8 reg, u16 val)
+{
+	if (rtl_readphy(tp, reg) != val)
+		netif_warn(tp, hw, tp->dev, "chipset not ready for firmware\n");
+	else
+		rtl_apply_firmware(tp);
 }
 
 static void rtl8169s_hw_phy_config(struct rtl8169_private *tp)
@@ -2246,10 +2257,8 @@ static void rtl8168d_1_hw_phy_config(struct rtl8169_private *tp)
 
 	rtl_writephy(tp, 0x1f, 0x0005);
 	rtl_writephy(tp, 0x05, 0x001b);
-	if ((rtl_readphy(tp, 0x06) != 0xbf00) ||
-	    (rtl_apply_firmware(tp, FIRMWARE_8168D_1) < 0)) {
-		netif_warn(tp, probe, tp->dev, "unable to apply firmware patch\n");
-	}
+
+	rtl_apply_firmware_cond(tp, MII_EXPANSION, 0xbf00);
 
 	rtl_writephy(tp, 0x1f, 0x0000);
 }
@@ -2351,10 +2360,8 @@ static void rtl8168d_2_hw_phy_config(struct rtl8169_private *tp)
 
 	rtl_writephy(tp, 0x1f, 0x0005);
 	rtl_writephy(tp, 0x05, 0x001b);
-	if ((rtl_readphy(tp, 0x06) != 0xb300) ||
-	    (rtl_apply_firmware(tp, FIRMWARE_8168D_2) < 0)) {
-		netif_warn(tp, probe, tp->dev, "unable to apply firmware patch\n");
-	}
+
+	rtl_apply_firmware_cond(tp, MII_EXPANSION, 0xb300);
 
 	rtl_writephy(tp, 0x1f, 0x0000);
 }
@@ -2474,8 +2481,7 @@ static void rtl8105e_hw_phy_config(struct rtl8169_private *tp)
 	rtl_writephy(tp, 0x18, 0x0310);
 	msleep(100);
 
-	if (rtl_apply_firmware(tp, FIRMWARE_8105E_1) < 0)
-		netif_warn(tp, probe, tp->dev, "unable to apply firmware patch\n");
+	rtl_apply_firmware(tp);
 
 	rtl_writephy_batch(tp, phy_reg_init, ARRAY_SIZE(phy_reg_init));
 }
@@ -3237,6 +3243,8 @@ rtl8169_init_one(struct pci_dev *pdev, const struct pci_device_id *ent)
 	tp->timer.data = (unsigned long) dev;
 	tp->timer.function = rtl8169_phy_timer;
 
+	tp->fw = RTL_FIRMWARE_UNKNOWN;
+
 	rc = register_netdev(dev);
 	if (rc < 0)
 		goto err_out_msi_4;
@@ -3288,10 +3296,10 @@ static void __devexit rtl8169_remove_one(struct pci_dev *pdev)
 
 	cancel_delayed_work_sync(&tp->task);
 
-	rtl_release_firmware(tp);
-
 	unregister_netdev(dev);
 
+	rtl_release_firmware(tp);
+
 	if (pci_dev_run_wake(pdev))
 		pm_runtime_get_noresume(&pdev->dev);
 
@@ -3303,6 +3311,37 @@ static void __devexit rtl8169_remove_one(struct pci_dev *pdev)
 	pci_set_drvdata(pdev, NULL);
 }
 
+static void rtl_request_firmware(struct rtl8169_private *tp)
+{
+	int i;
+
+	/* Return early if the firmware is already loaded / cached. */
+	if (!IS_ERR(tp->fw))
+		goto out;
+
+	for (i = 0; i < ARRAY_SIZE(rtl_firmware_infos); i++) {
+		const struct rtl_firmware_info *info = rtl_firmware_infos + i;
+
+		if (info->mac_version == tp->mac_version) {
+			const char *name = info->fw_name;
+			int rc;
+
+			rc = request_firmware(&tp->fw, name, &tp->pci_dev->dev);
+			if (rc < 0) {
+				netif_warn(tp, ifup, tp->dev, "unable to load "
+					"firmware patch %s (%d)\n", name, rc);
+				goto out_disable_request_firmware;
+			}
+			goto out;
+		}
+	}
+
+out_disable_request_firmware:
+	tp->fw = NULL;
+out:
+	return;
+}
+
 static int rtl8169_open(struct net_device *dev)
 {
 	struct rtl8169_private *tp = netdev_priv(dev);
@@ -3334,11 +3373,13 @@ static int rtl8169_open(struct net_device *dev)
 
 	smp_mb();
 
+	rtl_request_firmware(tp);
+
 	retval = request_irq(dev->irq, rtl8169_interrupt,
 			     (tp->features & RTL_FEATURE_MSI) ? 0 : IRQF_SHARED,
 			     dev->name, dev);
 	if (retval < 0)
-		goto err_release_ring_2;
+		goto err_release_fw_2;
 
 	napi_enable(&tp->napi);
 
@@ -3359,7 +3400,8 @@ static int rtl8169_open(struct net_device *dev)
 out:
 	return retval;
 
-err_release_ring_2:
+err_release_fw_2:
+	rtl_release_firmware(tp);
 	rtl8169_rx_clear(tp);
 err_free_rx_1:
 	dma_free_coherent(&pdev->dev, R8169_RX_RING_BYTES, tp->RxDescArray,
-- 
1.7.4.2

Re: Suspend/resume - slow resume

[Ciprian Docan]

[-- Attachment #1: Type: TEXT/PLAIN, Size: 316 bytes --]


Hello Francois,

>> I tried to unload the module, but it crashed. I re-booted the
>> machine and tried to unload the module again. I got the output from
>> dmesg; please see attached.
>
> Hmmm...

I adapted your patch and fixed the module unload problem; please let me 
know what you think. Thank you.

--
 	Ciprian

[-- Attachment #2: Type: TEXT/PLAIN, Size: 5545 bytes --]

diff --git a/drivers/net/r8169.c b/drivers/net/r8169.c
index 493b0de..397c368 100644
--- a/drivers/net/r8169.c
+++ b/drivers/net/r8169.c
@@ -170,6 +170,16 @@ static const struct {
 };
 #undef _R
 
+static const struct rtl_firmware_info {
+	int mac_version;
+	const char *fw_name;
+} rtl_firmware_infos[] = {
+	{ .mac_version = RTL_GIGA_MAC_VER_25, .fw_name = FIRMWARE_8168D_1 },
+	{ .mac_version = RTL_GIGA_MAC_VER_26, .fw_name = FIRMWARE_8168D_2 },
+	{ .mac_version = RTL_GIGA_MAC_VER_29, .fw_name = FIRMWARE_8105E_1 },
+	{ .mac_version = RTL_GIGA_MAC_VER_30, .fw_name = FIRMWARE_8105E_1 }
+};
+
 enum cfg_version {
 	RTL_CFG_0 = 0x00,
 	RTL_CFG_1,
@@ -565,6 +575,7 @@ struct rtl8169_private {
 	u32 saved_wolopts;
 
 	const struct firmware *fw;
+#define RTL_FIRMWARE_UNKNOWN	ERR_PTR(-EAGAIN);
 };
 
 MODULE_AUTHOR("Realtek and the Linux r8169 crew <netdev@vger.kernel.org>");
@@ -1789,25 +1800,26 @@ rtl_phy_write_fw(struct rtl8169_private *tp, const struct firmware *fw)
 
 static void rtl_release_firmware(struct rtl8169_private *tp)
 {
-	release_firmware(tp->fw);
-	tp->fw = NULL;
+	if (!IS_ERR_OR_NULL(tp->fw))
+		release_firmware(tp->fw);
+	tp->fw = RTL_FIRMWARE_UNKNOWN;
 }
 
-static int rtl_apply_firmware(struct rtl8169_private *tp, const char *fw_name)
+static void rtl_apply_firmware(struct rtl8169_private *tp)
 {
-	const struct firmware **fw = &tp->fw;
-	int rc = !*fw;
-
-	if (rc) {
-		rc = request_firmware(fw, fw_name, &tp->pci_dev->dev);
-		if (rc < 0)
-			goto out;
-	}
+	const struct firmware *fw = tp->fw;
 
 	/* TODO: release firmware once rtl_phy_write_fw signals failures. */
-	rtl_phy_write_fw(tp, *fw);
-out:
-	return rc;
+	if (!IS_ERR_OR_NULL(fw))
+		rtl_phy_write_fw(tp, fw);
+}
+
+static void rtl_apply_firmware_cond(struct rtl8169_private *tp, u8 reg, u16 val)
+{
+	if (rtl_readphy(tp, reg) != val)
+		netif_warn(tp, hw, tp->dev, "chipset not ready for firmware\n");
+	else
+		rtl_apply_firmware(tp);
 }
 
 static void rtl8169s_hw_phy_config(struct rtl8169_private *tp)
@@ -2246,10 +2258,8 @@ static void rtl8168d_1_hw_phy_config(struct rtl8169_private *tp)
 
 	rtl_writephy(tp, 0x1f, 0x0005);
 	rtl_writephy(tp, 0x05, 0x001b);
-	if ((rtl_readphy(tp, 0x06) != 0xbf00) ||
-	    (rtl_apply_firmware(tp, FIRMWARE_8168D_1) < 0)) {
-		netif_warn(tp, probe, tp->dev, "unable to apply firmware patch\n");
-	}
+
+	rtl_apply_firmware_cond(tp, MII_EXPANSION, 0xbf00);
 
 	rtl_writephy(tp, 0x1f, 0x0000);
 }
@@ -2351,10 +2361,8 @@ static void rtl8168d_2_hw_phy_config(struct rtl8169_private *tp)
 
 	rtl_writephy(tp, 0x1f, 0x0005);
 	rtl_writephy(tp, 0x05, 0x001b);
-	if ((rtl_readphy(tp, 0x06) != 0xb300) ||
-	    (rtl_apply_firmware(tp, FIRMWARE_8168D_2) < 0)) {
-		netif_warn(tp, probe, tp->dev, "unable to apply firmware patch\n");
-	}
+
+	rtl_apply_firmware_cond(tp, MII_EXPANSION, 0xb300);
 
 	rtl_writephy(tp, 0x1f, 0x0000);
 }
@@ -2474,8 +2482,7 @@ static void rtl8105e_hw_phy_config(struct rtl8169_private *tp)
 	rtl_writephy(tp, 0x18, 0x0310);
 	msleep(100);
 
-	if (rtl_apply_firmware(tp, FIRMWARE_8105E_1) < 0)
-		netif_warn(tp, probe, tp->dev, "unable to apply firmware patch\n");
+	rtl_apply_firmware(tp);
 
 	rtl_writephy_batch(tp, phy_reg_init, ARRAY_SIZE(phy_reg_init));
 }
@@ -3237,6 +3244,8 @@ rtl8169_init_one(struct pci_dev *pdev, const struct pci_device_id *ent)
 	tp->timer.data = (unsigned long) dev;
 	tp->timer.function = rtl8169_phy_timer;
 
+	tp->fw = RTL_FIRMWARE_UNKNOWN;
+
 	rc = register_netdev(dev);
 	if (rc < 0)
 		goto err_out_msi_4;
@@ -3288,10 +3297,10 @@ static void __devexit rtl8169_remove_one(struct pci_dev *pdev)
 
 	cancel_delayed_work_sync(&tp->task);
 
-	rtl_release_firmware(tp);
-
 	unregister_netdev(dev);
 
+	rtl_release_firmware(tp);
+
 	if (pci_dev_run_wake(pdev))
 		pm_runtime_get_noresume(&pdev->dev);
 
@@ -3303,6 +3312,37 @@ static void __devexit rtl8169_remove_one(struct pci_dev *pdev)
 	pci_set_drvdata(pdev, NULL);
 }
 
+static void rtl_request_firmware(struct rtl8169_private *tp)
+{
+	int i;
+
+	/* Return early if the firmware is already loaded / cached. */
+	if (!IS_ERR(tp->fw))
+		goto out;
+
+	for (i = 0; i < ARRAY_SIZE(rtl_firmware_infos); i++) {
+		const struct rtl_firmware_info *info = rtl_firmware_infos + i;
+
+		if (info->mac_version == tp->mac_version) {
+			const char *name = info->fw_name;
+			int rc;
+
+			rc = request_firmware(&tp->fw, name, &tp->pci_dev->dev);
+			if (rc < 0) {
+				netif_warn(tp, ifup, tp->dev, "unable to load "
+					"firmware patch %s (%d)\n", name, rc);
+				goto out_disable_request_firmware;
+			}
+			goto out;
+		}
+	}
+
+out_disable_request_firmware:
+	tp->fw = NULL;
+out:
+	return;
+}
+
 static int rtl8169_open(struct net_device *dev)
 {
 	struct rtl8169_private *tp = netdev_priv(dev);
@@ -3334,11 +3374,13 @@ static int rtl8169_open(struct net_device *dev)
 
 	smp_mb();
 
+	rtl_request_firmware(tp);
+
 	retval = request_irq(dev->irq, rtl8169_interrupt,
 			     (tp->features & RTL_FEATURE_MSI) ? 0 : IRQF_SHARED,
 			     dev->name, dev);
 	if (retval < 0)
-		goto err_release_ring_2;
+		goto err_release_fw_2;
 
 	napi_enable(&tp->napi);
 
@@ -3359,7 +3401,8 @@ static int rtl8169_open(struct net_device *dev)
 out:
 	return retval;
 
-err_release_ring_2:
+err_release_fw_2:
+	rtl_release_firmware(tp);
 	rtl8169_rx_clear(tp);
 err_free_rx_1:
 	dma_free_coherent(&pdev->dev, R8169_RX_RING_BYTES, tp->RxDescArray,

Re: Suspend/resume - slow resume

[Francois Romieu]

Ciprian Docan <docan@eden.rutgers.edu> :
[...]
> @@ -1789,25 +1800,26 @@ rtl_phy_write_fw(struct rtl8169_private *tp, const struct firmware *fw)
>  
>  static void rtl_release_firmware(struct rtl8169_private *tp)
>  {
> -	release_firmware(tp->fw);
> -	tp->fw = NULL;
> +	if (!IS_ERR_OR_NULL(tp->fw))
> +		release_firmware(tp->fw);

Ok.

Nit: the test against NULL is not needed here.

-- 
Ueimor