NetworkManager not reliably starting ethernet interface directly wired between two computers



I have two computers that have a direct ethernet wire between them. The
interface is set to a static ip address on each side, and under control
of the NetworkManager.  The computers are on the same power supply and
power up at the same time.

About 1/10 the time, the interface does not start. The messages log file
will show:

Jun 22 13:01:22 owl10 NetworkManager[601]: <info> (p6p1): carrier is OFF
Jun 22 13:01:22 owl10 NetworkManager[601]: <info> (p6p1): new Ethernet
device (driver: 'r8169' ifindex: 2)
Jun 22 13:01:22 owl10 NetworkManager[601]: <info> (p6p1): exported
as /org/freedesktop/NetworkManager/Devices/0
Jun 22 13:01:22 owl10 NetworkManager[601]: <info> (p6p1): now managed
Jun 22 13:01:22 owl10 NetworkManager[601]: <info> (p6p1): device state
change: unmanaged -> unavailable (reason 'managed') [10 20 2]
Jun 22 13:01:22 owl10 NetworkManager[601]: <info> (p6p1): bringing up
device.
Jun 22 13:01:22 owl10 NetworkManager[601]: <info> (p6p1): preparing
device.
Jun 22 13:01:22 owl10 NetworkManager[601]: <info> (p6p1): deactivating
device (reason: 2).
Jun 22 13:01:22 owl10 kernel: [ 4.932240] r8169 0000:05:00.0: p6p1: link
down
Jun 22 13:01:22 owl10 kernel: [ 4.932248] r8169 0000:05:00.0: p6p1: link
down
Jun 22 13:01:22 owl10 kernel: [ 4.932634] ADDRCONF(NETDEV_UP): p6p1:
link is not ready


And, if I just physically unplug the cable and plug it back in
NetworkManager starts the interface:

Jun 22 13:08:40 owl10 kernel: [ 442.658355] r8169 0000:05:00.0: p6p1:
link up
Jun 22 13:08:40 owl10 kernel: [ 442.658875] ADDRCONF(NETDEV_CHANGE):
p6p1: link becomes ready
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> (p6p1): carrier now ON
(device state 20)
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> (p6p1): device state
change: unavailable -> disconnected (reason 'carrier-changed') [20 30
40]
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
starting connection 'Middle Port'
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> (p6p1): device state
change: disconnected -> prepare (reason 'none') [30 40 0]
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 1 of 5 (Device Prepare) scheduled...
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 1 of 5 (Device Prepare) started...
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 2 of 5 (Device Configure) scheduled...
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 1 of 5 (Device Prepare) complete.
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 2 of 5 (Device Configure) starting...
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> (p6p1): device state
change: prepare -> config (reason 'none') [40 50 0]
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 2 of 5 (Device Configure) successful.
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 3 of 5 (IP Configure Start) scheduled.
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 2 of 5 (Device Configure) complete.
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 3 of 5 (IP Configure Start) started...
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> (p6p1): device state
change: config -> ip-config (reason 'none') [50 70 0]
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 4 of 5 (IP4 Configure Get) scheduled...
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 3 of 5 (IP Configure Start) complete.
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 4 of 5 (IP4 Configure Get) started...
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 5 of 5 (IP Configure Commit) scheduled...
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 4 of 5 (IP4 Configure Get) complete.
Jun 22 13:08:40 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 5 of 5 (IP Configure Commit) started...
Jun 22 13:08:40 owl10 avahi-daemon[614]: Joining mDNS multicast group on
interface p6p1.IPv4 with address 192.168.3.10.
Jun 22 13:08:40 owl10 avahi-daemon[614]: New relevant interface
p6p1.IPv4 for mDNS.
Jun 22 13:08:40 owl10 avahi-daemon[614]: Registering new address record
for 192.168.3.10 on p6p1.IPv4.
Jun 22 13:08:41 owl10 NetworkManager[601]: <info> Policy set 'Side
Port' (p7p1) as default for IPv4 routing and DNS.
Jun 22 13:08:41 owl10 NetworkManager[601]: <info> (p6p1): device state
change: ip-config -> activated (reason 'none') [70 100 0]
Jun 22 13:08:41 owl10 NetworkManager[601]: <info> Activation (p6p1)
successful, device activated.
Jun 22 13:08:41 owl10 NetworkManager[601]: <info> Activation (p6p1)
Stage 5 of 5 (IP Configure Commit) complete.


So, I imagine there is a race condition where both boxes wait for the
other to start the interface and provide a carrier.  Is that likely the
problem?

If so, is there a way to force NetworkManager to bring up an interface
even if there is no Carrier?  Or, is it a kernel issue.

BTW, this problem started recently on Fedora 13 after some upgrades. We
upgraded to the latest Fedora 15 to try and solve it, and it now appears
more often than it did on Fedora 13.  It is happening on two different
pairs of computers, with different cables, so I doubt it is a hardware
problem.

Doug




[Date Prev][Date Next]   [Thread Prev][Thread Next]   [Thread Index] [Date Index] [Author Index]