From: Paul Menzel <hidden> Date: 2012-02-04 19:26:08
found 656331 3.2.2-1
quit
Dear Linux folks,
Am Mittwoch, den 18.01.2012, 15:50 +0000 schrieb Ben Hutchings:
On Wed, 2012-01-18 at 16:32 +0100, Paul Menzel wrote:
quoted
Am Mittwoch, den 18.01.2012, 15:03 +0000 schrieb Ben Hutchings:
quoted
On Wed, 2012-01-18 at 15:15 +0100, Paul Menzel wrote:
quoted
Package: linux-2.6
Version: 3.1.8-2
Severity: normal
quoted
quoted
suspending and resuming a lot, it happens once to me, that the network
device did not come back correctly.
I experienced this problem (only) three times until now. If I remember
correctly the last time with 3.2.1. I still do not know how to reproduce
this.
The work around is to unplug and replug the network cable or to unload
the module and load it again.
quoted
quoted
[...]
Some of the RTL81xx gigabit Ethernet controllers need a firmware patch
to be reliable. I can't tell whether you have one of these. Are there
any kernel log messages about requesting a firmware file for the NIC?
If so, does installing firmware-realtek fix the problem?
There are no Linux messages requesting the firmware.
OK.
quoted
And not being able
to trigger I probably just have to wait that it happens again. Can I
increase some log level to capture more information next time? Or since
this could be a firmware bug Linux cannot do anything about this?
No, it's probably something that can be fixed in the driver.
That sounds promising. It would be great if this could be fixed. Please
tell me how I can get you better debugging information next time this
happens.
I experienced this problem (only) three times until now. If I remember
correctly the last time with 3.2.1. I still do not know how to reproduce
this.
(good PR, nice)
An 'ethtool -d' and a 'mii-tool -v' of the device after a successful resume
and a failed one could help if it's a driver thing.
You may check if runtime power management is enabled or not, especially
after a failed resume. See the /sys/devices/pci....:../....:..:..../power
directory and its control, runtime_enabled and runtime_status files
(control = on -> runtime PM disabled, see Documentation/power/runtime_pm.txt)
If it is enabled and the link does not come up fast enough (5 s), runtime
PM will suspend the device. It should not matter as long as the link is
still present because the device should (TM) soon generate a power management
event. The latter not happening or the PME being ignored could explain
the bug. If so, temporarily disabling runtime PM for your device after a
failed resume instead of removing the module or the cable may be enough
to recover the link. It's just a guess though.
Please stay with v3.2 or above in the meantime.
--
Ueimor
I experienced this problem (only) three times until now. If I remember
correctly the last time with 3.2.1. I still do not know how to reproduce
this.
(good PR, nice)
An 'ethtool -d' and a 'mii-tool -v' of the device after a successful resume
and a failed one could help if it's a driver thing.
The problem has not shown up again until now so I only send the output
from the successful resume. Currently Linux version 3.2.4 is installed.
The following outputs are identical after startup and (a successful)
resume.
$ sudo ethtool --version
ethtool version 3.1
$ sudo ethtool eth0 # The option `-d` does not exist.
Settings for eth0:
Supported ports: [ TP MII ]
Supported link modes: 10baseT/Half 10baseT/Full
100baseT/Half 100baseT/Full
1000baseT/Half 1000baseT/Full
Supported pause frame use: No
Supports auto-negotiation: Yes
Advertised link modes: 10baseT/Half 10baseT/Full
100baseT/Half 100baseT/Full
1000baseT/Half 1000baseT/Full
Advertised pause frame use: Symmetric Receive-only
Advertised auto-negotiation: Yes
Link partner advertised link modes: 10baseT/Half 10baseT/Full
100baseT/Half 100baseT/Full
Link partner advertised pause frame use: Symmetric
Link partner advertised auto-negotiation: Yes
Speed: 100Mb/s
Duplex: Full
Port: MII
PHYAD: 0
Transceiver: internal
Auto-negotiation: on
Supports Wake-on: pumbg
Wake-on: g
Current message level: 0x00000033 (51)
drv probe ifdown ifup
Link detected: yes
$ sudo mii-tool --version
$Id: mii-tool.c,v 1.9 2006/09/27 20:59:18 ecki Exp $
(Author: David Hinds based on Donald Becker's mii-diag)
net-tools 1.60
$ sudo mii-tool -v
eth0: negotiated 100baseTx-FD flow-control, link ok
product info: vendor 00:07:32, model 17 rev 2
basic mode: autonegotiation enabled
basic status: autonegotiation complete, link ok
capabilities: 1000baseT-HD 1000baseT-FD 100baseTx-FD 100baseTx-HD 10baseT-FD 10baseT-HD
advertising: 100baseTx-FD 100baseTx-HD 10baseT-FD 10baseT-HD flow-control
link partner: 1000baseT-HD 1000baseT-FD 100baseTx-FD 100baseTx-HD 10baseT-FD 10baseT-HD flow-control
You may check if runtime power management is enabled or not, especially
after a failed resume. See the /sys/devices/pci....:../....:..:..../power
directory and its control, runtime_enabled and runtime_status files
(control = on -> runtime PM disabled, see Documentation/power/runtime_pm.txt)
The document is online at [1].
For some reason the ethernet controller is not listed under
`/sys/devices`.
$ lspci | grep RTL
02:00.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL8111/8168B PCI Express Gigabit Ethernet controller (rev 01)
$ lspci -n -s 02:00.0
02:00.0 0200: 10ec:8168 (rev 01)
$ ls /sys/devices/
breakpoint i2c-2 LNXSYSTM:00 pnp0 tracepoint
cpu i2c-3 pci0000:00 software virtual
i2c-1 i2c-4 platform system
I use `/sys/bus/pci/devices` instead.
$ more /sys/bus/pci/devices/0000\:02\:00.0/power/{control,runtime_enabled,runtime_status}
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/control
::::::::::::::
on
--More--(Next file: /sys/bus/pci/devices/0000:02:00.0/power/runtime_::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_enabled
::::::::::::::
forbidden
--More--(Next file: /sys/bus/pci/devices/0000:02:00.0/power/runtime_::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status
::::::::::::::
active
If it is enabled and the link does not come up fast enough (5 s), runtime
PM will suspend the device. It should not matter as long as the link is
still present because the device should (TM) soon generate a power management
event. The latter not happening or the PME being ignored could explain
the bug. If so, temporarily disabling runtime PM for your device after a
failed resume instead of removing the module or the cable may be enough
to recover the link. It's just a guess though.
So judging from the output above runtime power management is disabled
after a fresh boot and (a successful) resume and something else went
wrong.
I will report back as soon as I get a failed resume.
I experienced this problem (only) three times until now. If I remember
correctly the last time with 3.2.1. I still do not know how to reproduce
this.
(good PR, nice)
An 'ethtool -d' and a 'mii-tool -v' of the device after a successful resume
and a failed one could help if it's a driver thing.
The problem has not shown up again until now so I only send the output
from the successful resume. Currently Linux version 3.2.4 is installed.
Right on time a suspend cycle later the problem turned up again.
The following outputs are identical after startup and (a successful)
resume.
$ sudo ethtool --version
ethtool version 3.1
$ sudo ethtool eth0 # The option `-d` does not exist.
Settings for eth0:
Supported ports: [ TP MII ]
Supported link modes: 10baseT/Half 10baseT/Full
100baseT/Half 100baseT/Full
1000baseT/Half 1000baseT/Full
Supported pause frame use: No
Supports auto-negotiation: Yes
Advertised link modes: 10baseT/Half 10baseT/Full
100baseT/Half 100baseT/Full
1000baseT/Half 1000baseT/Full
Advertised pause frame use: Symmetric Receive-only
Advertised auto-negotiation: Yes
Link partner advertised link modes: 10baseT/Half 10baseT/Full
100baseT/Half 100baseT/Full
Link partner advertised pause frame use: Symmetric
Link partner advertised auto-negotiation: Yes
Speed: 100Mb/s
Duplex: Full
Port: MII
PHYAD: 0
Transceiver: internal
Auto-negotiation: on
Supports Wake-on: pumbg
Wake-on: g
Current message level: 0x00000033 (51)
drv probe ifdown ifup
Link detected: yes
Now from a failed resume.
$ sudo ethtool eth0
Settings for eth0:
Supported ports: [ TP MII ]
Supported link modes: 10baseT/Half 10baseT/Full
100baseT/Half 100baseT/Full
1000baseT/Half 1000baseT/Full
Supported pause frame use: No
Supports auto-negotiation: Yes
Advertised link modes: 10baseT/Half 10baseT/Full
100baseT/Half 100baseT/Full
1000baseT/Half 1000baseT/Full
Advertised pause frame use: Symmetric Receive-only
Advertised auto-negotiation: Yes
Link partner advertised link modes: 10baseT/Half 10baseT/Full
100baseT/Half 100baseT/Full
Link partner advertised pause frame use: Symmetric
Link partner advertised auto-negotiation: Yes
Speed: 100Mb/s
Duplex: Full
Port: MII
PHYAD: 0
Transceiver: internal
Auto-negotiation: on
Supports Wake-on: pumbg
Wake-on: g
Current message level: 0x00000033 (51)
drv probe ifdown ifup
I could not spot a difference.
$ sudo mii-tool --version
$Id: mii-tool.c,v 1.9 2006/09/27 20:59:18 ecki Exp $
(Author: David Hinds based on Donald Becker's mii-diag)
net-tools 1.60
$ sudo mii-tool -v
eth0: negotiated 100baseTx-FD flow-control, link ok
product info: vendor 00:07:32, model 17 rev 2
basic mode: autonegotiation enabled
basic status: autonegotiation complete, link ok
capabilities: 1000baseT-HD 1000baseT-FD 100baseTx-FD 100baseTx-HD 10baseT-FD 10baseT-HD
advertising: 100baseTx-FD 100baseTx-HD 10baseT-FD 10baseT-HD flow-control
link partner: 1000baseT-HD 1000baseT-FD 100baseTx-FD 100baseTx-HD 10baseT-FD 10baseT-HD flow-control
From a failed resume it looks like the following.
$ sudo mii-tool -v
eth0: negotiated 100baseTx-FD flow-control, link ok
product info: vendor 00:07:32, model 17 rev 2
basic mode: autonegotiation enabled
basic status: autonegotiation complete, link ok
capabilities: 1000baseT-HD 1000baseT-FD 100baseTx-FD 100baseTx-HD 10baseT-FD 10baseT-HD
advertising: 100baseTx-FD 100baseTx-HD 10baseT-FD 10baseT-HD flow-control
link partner: 1000baseT-HD 1000baseT-FD 100baseTx-FD 100baseTx-HD 10baseT-FD 10baseT-HD flow-control
This seems to be identical too.
quoted
You may check if runtime power management is enabled or not, especially
after a failed resume. See the /sys/devices/pci....:../....:..:..../power
directory and its control, runtime_enabled and runtime_status files
(control = on -> runtime PM disabled, see Documentation/power/runtime_pm.txt)
The document is online at [1].
For some reason the Ethernet controller is not listed under
`/sys/devices`.
$ lspci | grep RTL
02:00.0 Ethernet controller: Realtek Semiconductor Co., Ltd. RTL8111/8168B PCI Express Gigabit Ethernet controller (rev 01)
$ lspci -n -s 02:00.0
02:00.0 0200: 10ec:8168 (rev 01)
$ ls /sys/devices/
breakpoint i2c-2 LNXSYSTM:00 pnp0 tracepoint
cpu i2c-3 pci0000:00 software virtual
i2c-1 i2c-4 platform system
I use `/sys/bus/pci/devices` instead.
$ more /sys/bus/pci/devices/0000\:02\:00.0/power/{control,runtime_enabled,runtime_status}
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/control
::::::::::::::
on
--More--(Next file: /sys/bus/pci/devices/0000:02:00.0/power/runtime_::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_enabled
::::::::::::::
forbidden
--More--(Next file: /sys/bus/pci/devices/0000:02:00.0/power/runtime_::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status
::::::::::::::
active
From a failed resume the output is like the following.
$ more /sys/bus/pci/devices/0000\:02\:00.0/power/{control,runtime_enabled,runtime_status}
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/control
::::::::::::::
on
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_enabled
::::::::::::::
forbidden
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status
::::::::::::::
active
This also seems identical.
quoted
If it is enabled and the link does not come up fast enough (5 s), runtime
PM will suspend the device. It should not matter as long as the link is
still present because the device should (TM) soon generate a power management
event. The latter not happening or the PME being ignored could explain
the bug. If so, temporarily disabling runtime PM for your device after a
failed resume instead of removing the module or the cable may be enough
to recover the link. It's just a guess though.
So judging from the output above runtime power management is disabled
after a fresh boot and (a successful) resume and something else went
wrong.
I will report back as soon as I get a failed resume.
Unfortunately I was not able to change the control parameter and always
got »The argument is invalid.« as an response.
# echo off > /sys/bus/pci/devices/0000:02:00.0/power/control
bash: echo: Schreibfehler: Das Argument ist ungültig.
# echo 1 > /sys/bus/pci/devices/0000:02:00.0/power/control
bash: echo: Schreibfehler: Das Argument ist ungültig.
# echo 0 > /sys/bus/pci/devices/0000:02:00.0/power/control
bash: echo: Schreibfehler: Das Argument ist ungültig.
Here are now some more values and outputs from a failed resume. Maybe
they are useful.
$ more /sys/bus/pci/devices/0000:02:00.0/power/runtime_*
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_active_kids
::::::::::::::
0
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_active_time
::::::::::::::
19474892
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_enabled
::::::::::::::
forbidden
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status
::::::::::::::
active
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_suspended_time
::::::::::::::
0
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_usage
::::::::::::::
1
Now when the module was reloaded.
$ more /sys/bus/pci/devices/0000:02:00.0/power/runtime_*
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_active_kids
::::::::::::::
0
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_active_time
::::::::::::::
20478940
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_enabled
::::::::::::::
forbidden
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status
::::::::::::::
active
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_suspended_time
::::::::::::::
0
::::::::::::::
/sys/bus/pci/devices/0000:02:00.0/power/runtime_usage
::::::::::::::
1
Here is the output from `dmesg`.
$ dmesg | grep 8169
[ 1.208236] r8169 Gigabit Ethernet driver 2.3LK-NAPI loaded
[ 1.208291] r8169 0000:02:00.0: PCI INT A -> GSI 19 (level, low) -> IRQ 19
[ 1.208328] r8169 0000:02:00.0: setting latency timer to 64
[ 1.208388] r8169 0000:02:00.0: irq 41 for MSI/MSI-X
[ 1.208944] r8169 0000:02:00.0: eth0: RTL8168b/8111b at 0xffffc90000324000, 00:1e:8c:aa:1d:b5, XID 18000000 IRQ 41
[ 1.208949] r8169 0000:02:00.0: eth0: jumbo features [frames: 4080 bytes, tx checksumming: ko]
[ 102.065361] r8169 0000:02:00.0: eth0: link down
[ 102.065378] r8169 0000:02:00.0: eth0: link down
[ 104.172037] r8169 0000:02:00.0: eth0: link up
I am not sure why the above is there. Maybe due to some package upgrades.
# Successful resume.
[10395.370894] r8169 0000:02:00.0: eth0: link down
[10395.761847] r8169 0000:02:00.0: PME# enabled
[10395.909944] r8169 0000:02:00.0: restoring config space at offset 0xf (was 0x100, writing 0x10a)
[10395.909960] r8169 0000:02:00.0: restoring config space at offset 0x6 (was 0x4, writing 0xfdaff004)
[10395.909967] r8169 0000:02:00.0: restoring config space at offset 0x4 (was 0x1, writing 0xdc01)
[10395.909972] r8169 0000:02:00.0: restoring config space at offset 0x3 (was 0x0, writing 0x8)
[10395.909979] r8169 0000:02:00.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100407)
[10395.910580] r8169 0000:02:00.0: PME# disabled
[10395.928147] r8169 0000:02:00.0: eth0: link down
[10397.978212] r8169 0000:02:00.0: eth0: link up
# Failed resume.
[18764.809975] r8169 0000:02:00.0: PME# enabled
[18764.957890] r8169 0000:02:00.0: restoring config space at offset 0xf (was 0x100, writing 0x10a)
[18764.957906] r8169 0000:02:00.0: restoring config space at offset 0x6 (was 0x4, writing 0xfdaff004)
[18764.957913] r8169 0000:02:00.0: restoring config space at offset 0x4 (was 0x1, writing 0xdc01)
[18764.957918] r8169 0000:02:00.0: restoring config space at offset 0x3 (was 0x0, writing 0x8)
[18764.957925] r8169 0000:02:00.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100407)
[18764.958557] r8169 0000:02:00.0: PME# disabled
[18781.998004] r8169 0000:02:00.0: eth0: link down
[18781.998024] r8169 0000:02:00.0: eth0: link down
# Reloading the module.
[19589.784094] r8169 0000:02:00.0: PCI INT A disabled
[19592.483547] r8169 Gigabit Ethernet driver 2.3LK-NAPI loaded
[19592.483618] r8169 0000:02:00.0: PCI INT A -> GSI 19 (level, low) -> IRQ 19
[19592.483689] r8169 0000:02:00.0: setting latency timer to 64
[19592.483783] r8169 0000:02:00.0: irq 41 for MSI/MSI-X
[19592.485394] r8169 0000:02:00.0: eth0: RTL8168b/8111b at 0xffffc90000324000, 00:1e:8c:aa:1d:b5, XID 18000000 IRQ 41
[19592.485404] r8169 0000:02:00.0: eth0: jumbo features [frames: 4080 bytes, tx checksumming: ko]
[19592.913672] r8169 0000:02:00.0: eth0: link down
[19594.947829] r8169 0000:02:00.0: eth0: link up
[18764.958557] r8169 0000:02:00.0: PME# disabled
[18781.998004] r8169 0000:02:00.0: eth0: link down
^^
[18781.998024] r8169 0000:02:00.0: eth0: link down
^^
Two link events within 20 us. /me wonders...
The datasheet states "[the PHYStatus] register is updated continuously at
maximum periods of 300us." but it is far from clear that the coherency
with the interrupt status register can be taken for granted. Hayes ?
Paul, can you try the hack below ?
From: Paul Menzel <hidden> Date: 2012-02-12 23:12:53
Am Mittwoch, den 08.02.2012, 23:16 +0100 schrieb Francois Romieu:
Paul Menzel [off-list ref] :
[…]
quoted
[18764.958557] r8169 0000:02:00.0: PME# disabled
[18781.998004] r8169 0000:02:00.0: eth0: link down
^^
quoted
[18781.998024] r8169 0000:02:00.0: eth0: link down
^^
Two link events within 20 us. /me wonders...
[20195.408746] r8169 0000:02:00.0: PME# enabled
[20195.466159] r8169 0000:02:00.0: restoring config space at offset 0xf (was 0x100, writing 0x10a)
[20195.466175] r8169 0000:02:00.0: restoring config space at offset 0x6 (was 0x4, writing 0xfdaff004)
[20195.466182] r8169 0000:02:00.0: restoring config space at offset 0x4 (was 0x1, writing 0xdc01)
[20195.466187] r8169 0000:02:00.0: restoring config space at offset 0x3 (was 0x0, writing 0x8)
[20195.466194] r8169 0000:02:00.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100407)
[20195.466826] r8169 0000:02:00.0: PME# disabled
[20211.376483] r8169 0000:02:00.0: eth0: link down
[20211.376507] r8169 0000:02:00.0: eth0: link down
Only ten 24 us difference. But during this resume process the network
came back up fine. Also in my prior pasted output this is also shown at
the beginning but the network worked fine.
[20213.000840] r8169 0000:02:00.0: eth0: link up
[32598.618289] r8169 0000:02:00.0: eth0: link down
This event during resume sometimes shows up and sometimes it does not. I
could not find a correlation between successful and failed resumes.
[32599.249802] r8169 0000:02:00.0: PME# enabled
[32599.397941] r8169 0000:02:00.0: restoring config space at offset 0xf (was 0x100, writing 0x10a)
[32599.397956] r8169 0000:02:00.0: restoring config space at offset 0x6 (was 0x4, writing 0xfdaff004)
[32599.397963] r8169 0000:02:00.0: restoring config space at offset 0x4 (was 0x1, writing 0xdc01)
[32599.397968] r8169 0000:02:00.0: restoring config space at offset 0x3 (was 0x0, writing 0x8)
[32599.397975] r8169 0000:02:00.0: restoring config space at offset 0x1 (was 0x100000, writing 0x100407)
[32599.398766] r8169 0000:02:00.0: PME# disabled
[32599.416148] r8169 0000:02:00.0: eth0: link down
Here it did not work and the link did not come back up. There is over half a second time bet
[32673.504101] r8169 0000:02:00.0: PCI INT A disabled
The module is removed and loaded below.
[32676.218019] r8169 Gigabit Ethernet driver 2.3LK-NAPI loaded
[32676.218078] r8169 0000:02:00.0: PCI INT A -> GSI 19 (level, low) -> IRQ 19
[32676.218152] r8169 0000:02:00.0: setting latency timer to 64
[32676.218246] r8169 0000:02:00.0: irq 41 for MSI/MSI-X
[32676.219792] r8169 0000:02:00.0: eth0: RTL8168b/8111b at 0xffffc90000368000, 00:1e:8c:aa:1d:b5, XID 18000000 IRQ 41
[32676.219803] r8169 0000:02:00.0: eth0: jumbo features [frames: 4080 bytes, tx checksumming: ko]
[32676.563203] r8169 0000:02:00.0: eth0: link down
[32678.356237] r8169 0000:02:00.0: eth0: link up
quoted hunk
The datasheet states "[the PHYStatus] register is updated continuously at
maximum periods of 300us." but it is far from clear that the coherency
with the interrupt status register can be taken for granted. Hayes ?
Paul, can you try the hack below ?
I will try this hack next week. Thank you!
Could it be that there is something wrong with the locking though or
parallel execution? Sometimes
[32598.618289] r8169 0000:02:00.0: eth0: link down
is shown before
[32599.249802] r8169 0000:02:00.0: PME# enabled
and sometimes it is not or only afterward.
Thanks,
Paul