E1000E/82567LM-3: link reported up too soon

E1000E/82567LM-3: link reported up too soon

[Arnaud Ebalard]

Hi,

I have a Dell E4300 Laptop running 2.6.35.4. It contains an Intel
82567LM-3 Gigabit chipset. Here is what lspci reports:

00:19.0 Ethernet controller: Intel Corporation 82567LM Gigabit Network Connection (rev 03)
        Subsystem: Dell Device 024d
        Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR+ FastB2B- DisINTx+
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0
        Interrupt: pin A routed to IRQ 44
        Region 0: Memory at f6ae0000 (32-bit, non-prefetchable) [size=128K]
        Region 1: Memory at f6adb000 (32-bit, non-prefetchable) [size=4K]
        Region 2: I/O ports at efe0 [size=32]
        Capabilities: [c8] Power Management version 2
                Flags: PMEClk- DSI+ D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
                Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=1 PME-
        Capabilities: [d0] MSI: Enable+ Count=1/1 Maskable- 64bit+
                Address: 00000000fee0300c  Data: 41b1
        Capabilities: [e0] PCI Advanced Features
                AFCap: TP+ FLR+
                AFCtrl: FLR-
                AFStatus: TP-
        Kernel driver in use: e1000e

When connecting the laptop to an ethernet switch, the driver performs
autoneg and then reports the link up via Netlink. This is monitored by
both netplug and UMIP to emit a DHCP request and an IPv6 Router
Solicitation (respectively) as soon as the link is reported UP and
RUNNING.

Most of the time, those first packets never reach the switch, i.e. the
packets are visible locally via tcpdump but are not seen on the remote
side.

I tested it with 2 different 100M/s switches (Cisco Catalyst 2960 and a
Planex FX08-Mini) so I guess the switch is not the root of the issue. I
came to the conclusion that the link is reported up too soon by the
driver.

Because the first packets are losts, the result is that address
autoconfiguration is delayed by a few seconds as can be seen on
following capture on the laptop:

13.450 IPv6 (0x86dd), length  62: :: > ff02::2: ICMP6, router solicitation, length 8
13.469 IPv4 (0x0800), length 342: 0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request
16.472 IPv4 (0x0800), length 342: 0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request
17.204 IPv4 (0x0800), length 342: 10.1.4.254.67 > 10.1.4.2.68: BOOTP/DHCP, Reply, length 300
17.205 IPv4 (0x0800), length 356: 0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request
17.210 IPv4 (0x0800), length 349: 10.1.4.254.67 > 10.1.4.2.68: BOOTP/DHCP, Reply, length 307
17.237 ARP  (0x0806), length  42: Request who-has 10.1.4.2 tell 0.0.0.0, length 28
17.437 ARP  (0x0806), length  42: Request who-has 10.1.4.2 tell 0.0.0.0, length 28
17.451 IPv6 (0x86dd), length  62: :: > ff02::2: ICMP6, router solicitation, length 8
17.451 IPv6 (0x86dd), length 214: fe80::21e:bff:fe5e:3b2 > ff02::1: ICMP6, router advertisement, length 160
17.461 IPv6 (0x86dd), length  90: :: > ff02::16: HBH ICMP6, multicast listener report v2, 1 group record(s), length 28
17.637 ARP  (0x0806), length  42: Request who-has 10.1.4.2 tell 0.0.0.0, length 28

Don't hesitate to tell if there may be another reason for that behavior
or ask if you need additional info or want me to test some patch.

Cheers,

a+

ps: please, keep me in CC

------------------------------------------------------------------------------
Start uncovering the many advantages of virtual appliances
and start using them to simplify application deployment and
accelerate your shift to cloud computing.
http://p.sf.net/sfu/novell-sfdev2dev
_______________________________________________
E1000-devel mailing list
E1000-devel@lists.sourceforge.net
https://lists.sourceforge.net/lists/listinfo/e1000-devel
To learn more about Intel&#174; Ethernet, visit http://communities.intel.com/community/wired

Re: E1000E/82567LM-3: link reported up too soon

[Brian Haley]

On 09/15/2010 09:48 AM, Arnaud Ebalard wrote:
> Hi,
> 
> I have a Dell E4300 Laptop running 2.6.35.4. It contains an Intel
> 82567LM-3 Gigabit chipset. Here is what lspci reports:
> 
<snip>
> 
> When connecting the laptop to an ethernet switch, the driver performs
> autoneg and then reports the link up via Netlink. This is monitored by
> both netplug and UMIP to emit a DHCP request and an IPv6 Router
> Solicitation (respectively) as soon as the link is reported UP and
> RUNNING.
> 
> Most of the time, those first packets never reach the switch, i.e. the
> packets are visible locally via tcpdump but are not seen on the remote
> side.
> 
> I tested it with 2 different 100M/s switches (Cisco Catalyst 2960 and a
> Planex FX08-Mini) so I guess the switch is not the root of the issue. I
> came to the conclusion that the link is reported up too soon by the
> driver.
> 
> Because the first packets are losts, the result is that address
> autoconfiguration is delayed by a few seconds as can be seen on
> following capture on the laptop:

I've seen similar things on various NICs, posted a patch last week that
unfortunately had other bad side-effects.  When I have time I'll work on
it again, but I'd also be curious if there's something that can be done
at the driver level to help out, since it seemed like part of the problem
is that the link-UP came before the device was actually able to transmit
packets, so the DAD was lost.

-Brian

Re: E1000E/82567LM-3: link reported up too soon

[Arnaud Ebalard]

Hi Brian,

Brian Haley <brian.haley@hp.com> writes:

>> <snip>
>> 
>> I tested it with 2 different 100M/s switches (Cisco Catalyst 2960 and a
>> Planex FX08-Mini) so I guess the switch is not the root of the issue. I
>> came to the conclusion that the link is reported up too soon by the
>> driver.
>> 
>> Because the first packets are losts, the result is that address
>> autoconfiguration is delayed by a few seconds as can be seen on
>> following capture on the laptop:
>
> I've seen similar things on various NICs,

I remember I add the same kind of issue on a broadcom chip on a dell
D600 but had no time to investigate at that time. Did you notice the
problem for different brands? Do you think those are driver-related
issues or something in common code?
 
> posted a patch last week that unfortunately had other bad
> side-effects.  When I have time I'll work on it again, but I'd also be
> curious if there's something that can be done at the driver level to
> help out, since it seemed like part of the problem is that the link-UP
> came before the device was actually able to transmit packets, so the
> DAD was lost.

I am not familiar with e1000e code but as I said previously I'd be happy
to test patches to help determine precisely where the packet gets lost
and why.

Cheers,

a+

Re: E1000E/82567LM-3: link reported up too soon

[Brian Haley]

Hi Arnaud,

On 09/15/2010 11:34 AM, Arnaud Ebalard wrote:
> Hi Brian,
> 
> Brian Haley <brian.haley@hp.com> writes:
> 
>>> <snip>
>>>
>>> I tested it with 2 different 100M/s switches (Cisco Catalyst 2960 and a
>>> Planex FX08-Mini) so I guess the switch is not the root of the issue. I
>>> came to the conclusion that the link is reported up too soon by the
>>> driver.
>>>
>>> Because the first packets are losts, the result is that address
>>> autoconfiguration is delayed by a few seconds as can be seen on
>>> following capture on the laptop:
>>
>> I've seen similar things on various NICs,
> 
> I remember I add the same kind of issue on a broadcom chip on a dell
> D600 but had no time to investigate at that time. Did you notice the
> problem for different brands? Do you think those are driver-related
> issues or something in common code?

I know I've seen this on an 82571EB (HP NC364T), but I also *thought* I
saw it with bnx2 as well (5708), but I'm not at the moment.  So maybe
this is just hardware or driver-related?  This is what I see:

 [87878.453422] ADDRCONF(NETDEV_UP): eth6: link is not ready
 [87880.298458] e1000e: eth6 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
 [87880.299296] ADDRCONF(NETDEV_CHANGE): eth6: link becomes ready
 [87881.369642] e1000e: eth6 NIC Link is Down
 [87883.418475] e1000e: eth6 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None

Procurve 5400zl switch, standard settings on the port and NIC.

>> posted a patch last week that unfortunately had other bad
>> side-effects.  When I have time I'll work on it again, but I'd also be
>> curious if there's something that can be done at the driver level to
>> help out, since it seemed like part of the problem is that the link-UP
>> came before the device was actually able to transmit packets, so the
>> DAD was lost.
> 
> I am not familiar with e1000e code but as I said previously I'd be happy
> to test patches to help determine precisely where the packet gets lost
> and why.

I'm not either, the patches I've tried are all for IPv6.

-Brian

Re: E1000E/82567LM-3: link reported up too soon

[Arnaud Ebalard]

Hi Brian and David,                         [removed Intel people from CC]

Brian Haley <brian.haley@hp.com> writes:

>> I am not familiar with e1000e code but as I said previously I'd be happy
>> to test patches to help determine precisely where the packet gets lost
>> and why.
>
> I'm not either, the patches I've tried are all for IPv6.

I definitely think the issue is not chipset-specific (keep reading) and
that it is not just a matter of few milliseconds. It also not
IPv6-specific. 

I spent some additional time on it in userspace. I implemented a
*workaround* in UMIP to allow configuration of a per-interface
additional delay before sending RS after a link up event. I initially
thought few milliseconds would be sufficient. It is not. Obviously, this
gets better when delay is increased but still.

I progressively increased the value until RS is no more dropped. Below,
UMIP is configured to send RS only *550ms* after the RTM_NEWLINK event
(indicating link is up and running event) is received and the packet is
still dropped locally. Note that the IPv4 DHCP Request below is sent as
soon as link gets up to show the time difference (RS is indeed sent
550ms later):

15:12:32.728429 ethertype IPv4 (0x0800), length 342: 0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request
15:12:33.256201 ethertype IPv6 (0x86dd), length 62: :: > ff02::2: ICMP6, router solicitation, length 8
15:12:35.729668 ethertype IPv4 (0x0800), length 342: 0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request
15:12:35.741238 ethertype IPv4 (0x0800), length 590: 192.168.0.254.67 > 192.168.0.16.68: BOOTP/DHCP, Reply

The switch is a 5 ports Planex gigabit switch connected to the 82567LM-3
on my Dell E4300 (negotiated 1000baseT-FD flow-control, link ok). Still
on a 2.6.35.4 kernel.

Then, I decided to test with a totally different kind of ethernet
interface. An USB2 Ethernet 10/100 dongle. Here is what lsusb reports
about it:

Bus 002 Device 003: ID 0411:003d MelCo., Inc. LUA-U2-KTX Ethernet

Below, UMIP is configured w/o any additional delay before RS emission on
that interface. No DHCP running either:

15:40:22.984311 ethertype IPv6 (0x86dd), length 62: :: > ff02::2: ICMP6, router solicitation, length 8
15:40:26.984845 ethertype IPv6 (0x86dd), length 62: :: > ff02::2: ICMP6, router solicitation, length 8
15:40:26.989264 ethertype IPv6 (0x86dd), length 158: fe80::224:d5ff:fed4:476c > ff02::1: ICMP6, router advertisement

David, any idea on where this may come from and how to track the cause?

Cheers,

a+

Re: E1000E/82567LM-3: link reported up too soon

[David Miller]

From: arno@natisbad.org (Arnaud Ebalard)
Date: Sat, 18 Sep 2010 16:14:16 +0200

> Below, UMIP is configured w/o any additional delay before RS emission on
> that interface. No DHCP running either:
> 
> 15:40:22.984311 ethertype IPv6 (0x86dd), length 62: :: > ff02::2: ICMP6, router solicitation, length 8
> 15:40:26.984845 ethertype IPv6 (0x86dd), length 62: :: > ff02::2: ICMP6, router solicitation, length 8
> 15:40:26.989264 ethertype IPv6 (0x86dd), length 158: fe80::224:d5ff:fed4:476c > ff02::1: ICMP6, router advertisement
> 
> David, any idea on where this may come from and how to track the cause?

I have no context, what's the exact problem?

Re: E1000E/82567LM-3: link reported up too soon

[Arnaud Ebalard]

Hi,

David Miller <davem@davemloft.net> writes:

> From: arno@natisbad.org (Arnaud Ebalard)
> Date: Sat, 18 Sep 2010 16:14:16 +0200
>
>> Below, UMIP is configured w/o any additional delay before RS emission on
>> that interface. No DHCP running either:
>> 
>> 15:40:22.984311 ethertype IPv6 (0x86dd), length 62: :: > ff02::2: ICMP6, router solicitation, length 8
>> 15:40:26.984845 ethertype IPv6 (0x86dd), length 62: :: > ff02::2: ICMP6, router solicitation, length 8
>> 15:40:26.989264 ethertype IPv6 (0x86dd), length 158: fe80::224:d5ff:fed4:476c > ff02::1: ICMP6, router advertisement
>> 
>> David, any idea on where this may come from and how to track the cause?
>
> I have no context, what's the exact problem?

On some ethernet devices (at least), link may be reported up (NEWLINK
received by userspace with flags indicating UP and RUNNING) before the
interface is really usable. When sending packets as soon as the link is
available, the first one may be dropped. That's what you see on the
capture above.

I think all the details are in the first message of the thread:

  http://www.spinics.net/lists/netdev/msg140916.html

I started adding printk in net/core/dev.c and net/sched/sch_generic.c
and I am now in e1000e code ... I will report what I found if it's
interesting.

Cheers,

a+

Re: E1000E/82567LM-3: link reported up too soon

[David Miller]

From: arno@natisbad.org (Arnaud Ebalard)
Date: Mon, 20 Sep 2010 20:57:46 +0200

> On some ethernet devices (at least), link may be reported up (NEWLINK
> received by userspace with flags indicating UP and RUNNING) before the
> interface is really usable. When sending packets as soon as the link is
> available, the first one may be dropped. That's what you see on the
> capture above.

The link being up doesn't mean an address has been assigned to the
interface for the protocol you are using yet.

I think you have to schedule whatever it is you need to make sure it
runs after dhcp successfully complete.

Re: E1000E/82567LM-3: link reported up too soon

[Arnaud Ebalard]

Hi David,

David Miller <davem@davemloft.net> writes:

> From: arno@natisbad.org (Arnaud Ebalard)
> Date: Mon, 20 Sep 2010 20:57:46 +0200
>
>> On some ethernet devices (at least), link may be reported up (NEWLINK
>> received by userspace with flags indicating UP and RUNNING) before the
>> interface is really usable. When sending packets as soon as the link is
>> available, the first one may be dropped. That's what you see on the
>> capture above.
>
> The link being up doesn't mean an address has been assigned to the
> interface for the protocol you are using yet.
>
> I think you have to schedule whatever it is you need to make sure it
> runs after dhcp successfully complete.

Maybe I was a bit unclear.

The packets sent are an IPv6 Router Solicitation (to get IPv6 subnet
prefixes from the router) and a DHCP Request (to get an IPv4 address
from the DHCP server). 

The former is sent from the unspecified address (::) and the latter from
0.0.0.0. The former is sent by UMIP Mobile IPv6 daemon. The second by my
DHCP client. They both use netlink to do that as soon as the link is up.
Both are for address configuration ...

Cheers,

a+

Re: E1000E/82567LM-3: link reported up too soon

[David Miller]

From: arno@natisbad.org (Arnaud Ebalard)
Date: Mon, 20 Sep 2010 22:09:16 +0200

> The packets sent are an IPv6 Router Solicitation (to get IPv6 subnet
> prefixes from the router) and a DHCP Request (to get an IPv4 address
> from the DHCP server). 
> 
> The former is sent from the unspecified address (::) and the latter from
> 0.0.0.0. The former is sent by UMIP Mobile IPv6 daemon. The second by my
> DHCP client. They both use netlink to do that as soon as the link is up.
> Both are for address configuration ...

So do both DHCP request and the IPV6 RS get dropped, or just the IPV6 RS?

Re: E1000E/82567LM-3: link reported up too soon

[Arnaud Ebalard]

David Miller <davem@davemloft.net> writes:

> So do both DHCP request and the IPV6 RS get dropped, or just the IPV6 RS?

both.

Re: E1000E/82567LM-3: link reported up too soon

[Arnaud Ebalard]

Hi,

David Miller <davem@davemloft.net> writes:

> From: arno@natisbad.org (Arnaud Ebalard)
> Date: Mon, 20 Sep 2010 22:09:16 +0200
>
>> The packets sent are an IPv6 Router Solicitation (to get IPv6 subnet
>> prefixes from the router) and a DHCP Request (to get an IPv4 address
>> from the DHCP server). 
>> 
>> The former is sent from the unspecified address (::) and the latter from
>> 0.0.0.0. The former is sent by UMIP Mobile IPv6 daemon. The second by my
>> DHCP client. They both use netlink to do that as soon as the link is up.
>> Both are for address configuration ...
>
> So do both DHCP request and the IPV6 RS get dropped, or just the IPV6 RS?

I added printk() to see where/if those first packets get dropped in
e1000e code. I followed those first packets to e1000_xmit_frame() and
don't see anything obvious happening there, i.e. they are passed to the
device as expected.

If I find some time tomorrow, I will try and take a look at
e1000_watchdog_task() and other functions that may perform asynchronous
tasks.

Cheers,

a+

Re: E1000E/82567LM-3: link reported up too soon

[David Miller]

From: arno@natisbad.org (Arnaud Ebalard)
Date: Mon, 20 Sep 2010 23:28:57 +0200

> I added printk() to see where/if those first packets get dropped in
> e1000e code. I followed those first packets to e1000_xmit_frame() and
> don't see anything obvious happening there, i.e. they are passed to the
> device as expected.

I suspect the packet is sucessfully given to the chip and the PHY simply
doesn't put it onto the wire for whatever reason.

Re: E1000E/82567LM-3: link reported up too soon

[Arnaud Ebalard]

Hi,

David Miller <davem@davemloft.net> writes:

> From: arno@natisbad.org (Arnaud Ebalard)
> Date: Mon, 20 Sep 2010 23:28:57 +0200
>
>> I added printk() to see where/if those first packets get dropped in
>> e1000e code. I followed those first packets to e1000_xmit_frame() and
>> don't see anything obvious happening there, i.e. they are passed to the
>> device as expected.
>
> I suspect the packet is sucessfully given to the chip and the PHY simply
> doesn't put it onto the wire for whatever reason.

I spent additional time on it, putting printk() at various locations in
e1000e driver code and also using driver's debug functions to see what
could be different in the internal state when the first packet is
delivered and when it is not. I just found nothing, so AFAICT your guess
above is backed up by those tests. 

I will try and summarize that for Intel ethernet drivers maintainers.

Cheers,

a+