Bug 194124
| Summary: | NM tries to get address on wired connection without link | ||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | [Fedora] Fedora | Reporter: | Jeremy Katz <katzj> | ||||||||||
| Component: | NetworkManager | Assignee: | Christopher Aillon <caillon> | ||||||||||
| Status: | CLOSED ERRATA | QA Contact: | |||||||||||
| Severity: | medium | Docs Contact: | |||||||||||
| Priority: | medium | ||||||||||||
| Version: | rawhide | CC: | bjohnson, casualprogrammer, covex, dcbw, drago01, gauret, louisgtwo, ma, mozbugs, steved, vic | ||||||||||
| Target Milestone: | --- | Keywords: | Reopened | ||||||||||
| Target Release: | --- | ||||||||||||
| Hardware: | All | ||||||||||||
| OS: | Linux | ||||||||||||
| Whiteboard: | |||||||||||||
| Fixed In Version: | 0.6.5-6.fc7 | Doc Type: | Bug Fix | ||||||||||
| Doc Text: | Story Points: | --- | |||||||||||
| Clone Of: | Environment: | ||||||||||||
| Last Closed: | 2007-06-25 23:24:40 UTC | Type: | --- | ||||||||||
| Regression: | --- | Mount Type: | --- | ||||||||||
| Documentation: | --- | CRM: | |||||||||||
| Verified Versions: | Category: | --- | |||||||||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||||||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||||||||
| Embargoed: | |||||||||||||
| Bug Depends On: | |||||||||||||
| Bug Blocks: | 150225 | ||||||||||||
| Attachments: |
|
||||||||||||
|
Description
Jeremy Katz
2006-06-05 21:23:48 UTC
Are you still seeing this? Yep So I'm having difficulty reproducing this. The symptoms are that you log in and see the nm-applet spinning dots? Do any of them turn green? Can you attach relevant bits from your syslog? Jeremy ? I log in, the applet starts spinning dots then I get the notification bubble that it's gotten a connection on the wired connection. Which has no link (and the addr it gets is just the link-local one). And then, after that, the behavior I saw on Friday night when I got home was that it then saw the wireless and tried to use it. There's not anything in the syslog to make it seem like anything should have told NM that the wired connection has a link. What I *think* is happening is that we're init'ing to "there's a link" and that's not getting invalidated until we get the list of valid APs. But that's pure speculation from just reading the current log :) Jul 28 20:46:54 aglarond NetworkManager: <information> starting... Jul 28 20:46:54 aglarond NetworkManager: <information> Adding VPN service 'org. freedesktop.NetworkManager.vpnc' with name 'vpnc' and program '/usr/bin/nm-vpnc- service' Jul 28 20:46:54 aglarond NetworkManager: <information> eth1: Device is fully-su pported using driver 'ipw3945'. Jul 28 20:46:54 aglarond NetworkManager: <information> nm_device_init(): waitin g for device's worker thread to start Jul 28 20:46:54 aglarond NetworkManager: <information> nm_device_init(): device 's worker thread started, continuing. Jul 28 20:46:54 aglarond NetworkManager: <information> Now managing wireless (8 02.11) device 'eth1'. Jul 28 20:46:54 aglarond NetworkManager: <information> Deactivating device eth1 . Jul 28 20:46:57 aglarond NetworkManager: <information> eth0: Device is fully-su pported using driver 'e100'. Jul 28 20:46:57 aglarond NetworkManager: <information> nm_device_init(): waitin g for device's worker thread to start Jul 28 20:46:57 aglarond NetworkManager: <information> nm_device_init(): device 's worker thread started, continuing. net (802.3) device 'eth0'. Jul 28 20:46:57 aglarond NetworkManager: <information> Deactivating device eth0 . Jul 28 20:46:57 aglarond NetworkManager: <information> Found dial up configurat ion for gprsusb via Modem: gprsusb Jul 28 20:46:57 aglarond NetworkManager: <information> SWITCH: no current conne ction, found better connection 'eth0'. Jul 28 20:46:57 aglarond NetworkManager: <information> Will activate wired conn ection 'eth0' because it now has a link. Jul 28 20:46:57 aglarond NetworkManager: <information> Will activate connection 'eth0'. Jul 28 20:46:57 aglarond NetworkManager: <information> Device eth0 activation s cheduled... Jul 28 20:46:57 aglarond NetworkManager: <information> Activation (eth0) starte d... Jul 28 20:46:57 aglarond NetworkManager: <information> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled... Jul 28 20:46:57 aglarond NetworkManager: <information> Activation (eth0) Stage 1 of 5 (Device Prepare) started... Jul 28 20:46:57 aglarond NetworkManager: <information> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled... Jul 28 20:46:57 aglarond NetworkManager: <information> Activation (eth0) Stage 1 of 5 (Device Prepare) complete. Jul 28 20:46:57 aglarond NetworkManager: <information> Activation (eth0) Stage 2 of 5 (Device Configure) starting... Jul 28 20:46:57 aglarond NetworkManager: <information> Activation (eth0) Stage 2 of 5 (Device Configure) successful. Jul 28 20:46:57 aglarond NetworkManager: <information> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled. Jul 28 20:46:57 aglarond NetworkManager: <information> Activation (eth0) Stage 2 of 5 (Device Configure) complete. Jul 28 20:46:57 aglarond NetworkManager: <information> Activation (eth0) Stage 3 of 5 (IP Configure Start) started... Jul 28 20:46:57 aglarond NetworkManager: <information> Old device 'eth0' activa ting, won't change. Jul 28 20:46:58 aglarond NetworkManager: <information> Activation (eth0) Beginn ing DHCP transaction. Jul 28 20:46:58 aglarond NetworkManager: <information> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete. Jul 28 20:46:58 aglarond NetworkManager: <information> DHCP daemon state is now 12 (successfully started) for interface eth0 Jul 28 20:46:58 aglarond NetworkManager: <information> DHCP daemon state is now 1 (starting) for interface eth0 Jul 28 20:47:04 aglarond NetworkManager: <information> Old device 'eth0' activa ting, won't change. Jul 28 20:47:19 aglarond NetworkManager: <information> Updating allowed wireles s network lists. ... Jul 28 20:47:20 aglarond NetworkManager: <information> Old device 'eth0' activa ting, won't change. Jul 28 20:47:34 aglarond NetworkManager: <information> Old device 'eth0' activa ting, won't change. Jul 28 20:47:43 aglarond NetworkManager: <information> Device 'eth0' DHCP trans action took too long (>45s), stopping it. Jul 28 20:47:44 aglarond NetworkManager: <information> Activation (eth0) Stage 4 of 5 (IP Configure Timeout) scheduled... Jul 28 20:47:44 aglarond NetworkManager: <information> DHCP daemon state is now 14 (normal exit) for interface eth0 Jul 28 20:47:44 aglarond NetworkManager: <information> Activation (eth0) Stage 4 of 5 (IP Configure Timeout) started... Jul 28 20:47:44 aglarond NetworkManager: <information> No DHCP reply received. Automatically obtaining IP via Zeroconf. Jul 28 20:47:44 aglarond NetworkManager: <information> DHCP daemon state is now 11 (unknown) for interface eth0 (autoip stuff here) Jul 28 20:48:00 aglarond NetworkManager: <information> Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled... Jul 28 20:48:00 aglarond NetworkManager: <information> Activation (eth0) Stage 4 of 5 (IP Configure Timeout) complete. Jul 28 20:48:00 aglarond NetworkManager: <information> Activation (eth0) Stage 5 of 5 (IP Configure Commit) started... Jul 28 20:48:01 aglarond NetworkManager: <information> Activation (eth0) succes sful, device activated. Jul 28 20:48:01 aglarond NetworkManager: <information> Activation (eth0) Finish handler scheduled. Jul 28 20:48:01 aglarond NetworkManager: <information> Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete. Jul 28 20:48:04 aglarond NetworkManager: <information> SWITCH: found better con nection 'eth1' than current connection 'eth0'. Jul 28 20:48:04 aglarond NetworkManager: <information> Will activate connection 'eth1/e^(i*pi)'. Can you try tomorrow's rawhide and report if the problem goes away for you? Ray, is the fix in NetworkManager-0.7.0-dont-choose-inactive-wired-device.patch? It doesn't seem to apply, because the "if (!link_active)" bit is actually "if (link_active)" in NetworkManagerPolicy.c... What's the fix then? wow, so I: 1) diffed the patch to a modified source tree (so it couldn't actually be applied) 2) didn't notice that it couldn't be applied, because I never tried to apply it in the spec file. Awesome. Building hopefully better packages now. Jeremy can you give them a go? Jeremy ? NetworkManager-0.7.0-0.cvs20060529.5 still exhibits this behavior. bummer. Bernard, do your logs look the same? can you attach them? Jeremy, Does 'cat /sys/class/net/eth0/carrier' give you a 1 or a 0 when you boot up and have _no_ link? Also, is there just no cable plugged in, or is there a cable plugged in an nothing on the other end? Or is there something on the other end that's not powered on, or what? What's the output of '/sbin/mii-tool eth0' when you have a link and also when no link? What's the ouptut of '/sbin/ethtool eth0' for both link and no link? My logs more or less look the same with NM saying "Will activate wired
connection 'eth0' because it now has a link." - when it doesn't have a link (no
cable plugged in).
(with no link - no cable plugged in):
[root@localhost ~]# cat /sys/class/net/eth0/carrier
0
[root@localhost ~]# /sbin/mii-tool eth0
eth0: no link
[root@localhost ~]# /sbin/ethtool eth0
Settings for eth0:
Supported ports: [ TP MII ]
Supported link modes: 10baseT/Half 10baseT/Full
100baseT/Half 100baseT/Full
Supports auto-negotiation: Yes
Advertised link modes: 10baseT/Half 10baseT/Full
100baseT/Half 100baseT/Full
Advertised auto-negotiation: Yes
Speed: 10Mb/s
Duplex: Half
Port: MII
PHYAD: 32
Transceiver: internal
Auto-negotiation: on
Supports Wake-on: pumbg
Wake-on: d
Current message level: 0x00000007 (7)
Link detected: no
(with link):
[root@localhost ~]# cat /sys/class/net/eth0/carrier
1
[root@localhost ~]# /sbin/mii-tool eth0
eth0: negotiated 100baseTx-FD, link ok
[root@localhost ~]# /sbin/ethtool eth0
Settings for eth0:
Supported ports: [ TP MII ]
Supported link modes: 10baseT/Half 10baseT/Full
100baseT/Half 100baseT/Full
Supports auto-negotiation: Yes
Advertised link modes: 10baseT/Half 10baseT/Full
100baseT/Half 100baseT/Full
Advertised auto-negotiation: Yes
Speed: 100Mb/s
Duplex: Full
Port: MII
PHYAD: 32
Transceiver: internal
Auto-negotiation: on
Supports Wake-on: pumbg
Wake-on: d
Current message level: 0x00000007 (7)
Link detected: yes
Ok; NM uses netlink to detect whether the device has a link or not; I've got a tool I can post somewhere that you can run to see whether or not netlink reports the devices as having the link. If that works as expected, then something in NM is actually wrong. At this point I'm blaming the driver and/or netlink reporting the wrong thing, which has bitten us before. Post the tool and I'll produce whatever output you're looking for. Ok, please grab: http://people.redhat.com/dcbw/NetworkManager/nmnetlinktest It's an i386 executable. Turn both NM and the 'network' init script off at boot time, make sure the cable is _unplugged_, and then when the system has booted, run the tool. Plug in the cable, then unplug the cable. Post the output here. Thanks! There is no change when I plug in the cable or unplug the cable. [root@localhost ~]# ./nmnetlinktest interface 'lo' connected interface 'dev1804289383' disconnected interface 'eth0' disconnected interface 'sit0' disconnected It seems that if NetworkManager is not running the state of eth0 doesn't get reported. I don't know if this is a valid test or not, but I ran nmnetlinktest while NM was first attempting to connect: This is the output from where it tries to connect to the (un)wired eth0 network, then switches back to the wireless: [root@localhost ~]# ./nmnetlinktest interface 'lo' connected interface 'eth0' disconnected interface 'eth1' disconnected interface 'sit0' disconnected interface 'eth1' connected interface 'eth1' connected [eth0 plugged in here] interface 'eth0' connected interface 'eth1' disconnected interface 'eth1' disconnected interface 'eth1' disconnected [eth0 unplugged here] interface 'eth0' disconnected interface 'eth1' connected interface 'eth1' connected interface 'eth1' disconnected interface 'eth1' connected interface 'eth1' connected What do you mean in comment #17? Do you mean that plug/unplug of the cable produces _no_ messages from nmnetlinktest when NM isn't running? It produces no messages when the cable is plugged or unplugged, only output when nmnetlinktest is started before I start messing with the cable. Comment #18 is with NM running. Dan, what is the next step here ? comment 17 could be because the network card drivers aren't loaded. If you modprobe the drivers or start NetworkManager and then stop it again, what does nmnetlinktest report? Ok, I let NetworkManager start normally, then I stopped it. I checked for drivers: [root@localhost ~]# lsmod | egrep "bcm|8139" bcm43xx 434145 0 ieee80211softmac 37833 1 bcm43xx ieee80211 35601 2 bcm43xx,ieee80211softmac 8139cp 29257 0 8139too 31953 0 mii 9793 2 8139cp,8139too I then ran nmnetlinktest and plugged in the network cable and then unplugged it: [root@localhost ~]# ./nmnetlinktest interface 'lo' connected interface 'eth0' disconnected interface 'eth1' disconnected interface 'sit0' disconnected interface 'eth0' connected (<-- This is where I plugged it in) interface 'eth0' disconnected (<-- This is where I unplugged it) Dan, any chance the recent reversal to the stable branch changes this ? Possibly; but I looked over the code again and the patch Ray did shouldn't have changed behavior at all. Is this still being seen on specific hardware that you've got? Which driver? If you're still getting it, I'll post a debug binary to try that will print out more information about the device autochoose process. I'm running NetworkManager-0.6.4-4.fc6 now and I don't have this problem anymore. Okay, so it must be a regression in 0.7.0. We aren't going with it anymore. Would you mind filing an upstream bug report? Upstreamed: http://bugzilla.gnome.org/show_bug.cgi?id=354565 This is back in F7 rawhide. $ rpm -q NetworkManager NetworkManager-0.6.5-0.4.svn2474.fc7 just want to add a "me too" here (I have the exact same problem) see: http://bugzilla.gnome.org/show_bug.cgi?id=431680 NetworkManager is not enabled by default; moving to FC7Target I think I experience even more troubles with this bug in latest rawhide live image (20050517). I have two ethernet cards one is connected to network with DHCP the other one is disconnected. After boot the NM incorrectly configures both interfaces. eth0 (disconn) is havind 169.x.x.x IP the eth1 is not configured at all. When I do "service network restart" then ifup configures correctly eth1 and loads IP, DNS, routes from dhcp, however NM tries to configure eth0 even though it failed during "service network restart". After some timeout the NM sets eth0 to 169.x.x.x, empties resolv.conf and sets default route to 169.x.x.x. Then the network is broken again. Fixed in revision 2578 on NETWORKMANAGER_0_6_0_RELEASE branch upstream. *** Bug 230256 has been marked as a duplicate of this bug. *** Should be fixed in NetworkManager-0.6.5-4.f7 NetworkManager-0.6.5-4.fc7 has been pushed to the Fedora 7 testing repository. If problems still persist, please make note of it in this bug report. I still see this problem with NetworkManager-0.6.5-4.f7 from testing. Updated F7 as of Friday June 8: Jun 8 14:51:40 sonlaptop NetworkManager: <info> starting... Jun 8 14:51:40 sonlaptop kernel: ADDRCONF(NETDEV_UP): wlan0: link is not ready Jun 8 14:51:40 sonlaptop NetworkManager: <info> wlan0: Device is fully-supported using driver 'iwl3945'. Jun 8 14:51:41 sonlaptop NetworkManager: <info> nm_device_init(): waiting for device's worker thread to start Jun 8 14:51:41 sonlaptop NetworkManager: <info> nm_device_init(): device's worker thread started, continuing. Jun 8 14:51:41 sonlaptop NetworkManager: <info> Now managing wireless (802.11) device 'wlan0'. Jun 8 14:51:42 sonlaptop NetworkManager: <info> Deactivating device wlan0. Jun 8 14:51:42 sonlaptop kernel: ADDRCONF(NETDEV_UP): eth0: link is not ready Jun 8 14:51:42 sonlaptop NetworkManager: <info> eth0: Device is fully-supported using driver 'e100'. Jun 8 14:51:42 sonlaptop NetworkManager: <info> nm_device_init(): waiting for device's worker thread to start Jun 8 14:51:42 sonlaptop NetworkManager: <info> nm_device_init(): device's worker thread started, continuing. Jun 8 14:51:43 sonlaptop NetworkManager: <info> Now managing wired Ethernet (802.3) device 'eth0'. Jun 8 14:51:43 sonlaptop NetworkManager: <info> Deactivating device eth0. Jun 8 14:51:43 sonlaptop NetworkManager: <info> Will activate wired connection 'eth0' because it now has a link. Jun 8 14:51:43 sonlaptop NetworkManager: <info> SWITCH: no current connection, found better connection 'eth0'. Jun 8 14:51:44 sonlaptop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/eth0 for sub-path eth0.dbus.get.reason Jun 8 14:51:44 sonlaptop NetworkManager: <info> Will activate connection 'eth0'. Jun 8 14:51:44 sonlaptop NetworkManager: <info> Device eth0 activation scheduled... Jun 8 14:51:44 sonlaptop NetworkManager: <info> Activation (eth0) started... Jun 8 14:51:44 sonlaptop NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) scheduled... Jun 8 14:51:44 sonlaptop NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) started... Jun 8 14:51:44 sonlaptop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) scheduled... Jun 8 14:51:44 sonlaptop NetworkManager: <info> Activation (eth0) Stage 1 of 5 (Device Prepare) complete. Jun 8 14:51:44 sonlaptop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) starting... Jun 8 14:51:44 sonlaptop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) successful. Jun 8 14:51:44 sonlaptop NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) scheduled. Jun 8 14:51:44 sonlaptop NetworkManager: <info> Activation (eth0) Stage 2 of 5 (Device Configure) complete. Jun 8 14:51:44 sonlaptop NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) started... Jun 8 14:51:45 sonlaptop NetworkManager: <info> Activation (eth0) Beginning DHCP transaction. Jun 8 14:51:45 sonlaptop NetworkManager: <info> Activation (eth0) Stage 3 of 5 (IP Configure Start) complete. Jun 8 14:51:45 sonlaptop NetworkManager: <info> DHCP daemon state is now 12 (successfully started) for interface eth0 Jun 8 14:51:45 sonlaptop dhclient: wmaster0: unknown hardware address type 801 Jun 8 14:51:45 sonlaptop dhclient: wmaster0: unknown hardware address type 801 Jun 8 14:51:45 sonlaptop NetworkManager: <info> DHCP daemon state is now 1 (starting) for interface eth0 Jun 8 14:51:45 sonlaptop dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 5 Jun 8 14:51:50 sonlaptop dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 6 Jun 8 14:51:50 sonlaptop NetworkManager: <info> Old device 'eth0' activating, won't change. Jun 8 14:51:56 sonlaptop dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 13 Jun 8 14:52:09 sonlaptop dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 15 Jun 8 14:52:20 sonlaptop NetworkManager: <info> Old device 'eth0' activating, won't change. Jun 8 14:52:21 sonlaptop NetworkManager: <info> Updating allowed wireless network lists. Jun 8 14:52:22 sonlaptop NetworkManager: <info> Old device 'eth0' activating, won't change. Jun 8 14:52:24 sonlaptop dhclient: DHCPDISCOVER on eth0 to 255.255.255.255 port 67 interval 8 Jun 8 14:52:30 sonlaptop NetworkManager: <info> Device 'eth0' DHCP transaction took too long (>45s), stopping it. Jun 8 14:52:30 sonlaptop dhclient: wmaster0: unknown hardware address type 801 Jun 8 14:52:30 sonlaptop dhclient: wmaster0: unknown hardware address type 801 Jun 8 14:52:30 sonlaptop dhclient: DHCPRELEASE on eth0 to 10.0.0.1 port 67 Jun 8 14:52:30 sonlaptop dhclient: send_packet: Network is unreachable Jun 8 14:52:30 sonlaptop dhclient: send_packet: please consult README file regarding broadcast address. Jun 8 14:52:31 sonlaptop NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Timeout) scheduled... Jun 8 14:52:31 sonlaptop NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Timeout) started... Jun 8 14:52:31 sonlaptop NetworkManager: <info> No DHCP reply received. Automatically obtaining IP via Zeroconf. Jun 8 14:52:31 sonlaptop NetworkManager: <info> DHCP daemon state is now 14 (normal exit) for interface eth0 Jun 8 14:52:31 sonlaptop NetworkManager: <info> DHCP daemon state is now 11 (unknown) for interface eth0 Jun 8 14:52:31 sonlaptop NetworkManager: <info> DHCP daemon state is now 14 (normal exit) for interface eth0 Jun 8 14:52:31 sonlaptop NetworkManager: <info> autoip: Sending probe #0 for IP address 169.254.143.1. Jun 8 14:52:31 sonlaptop NetworkManager: <info> autoip: Waiting for reply... Jun 8 14:52:33 sonlaptop NetworkManager: <info> autoip: Sending probe #1 for IP address 169.254.143.1. Jun 8 14:52:33 sonlaptop NetworkManager: <info> autoip: Waiting for reply... Jun 8 14:52:35 sonlaptop NetworkManager: <info> autoip: Sending probe #2 for IP address 169.254.143.1. Jun 8 14:52:35 sonlaptop NetworkManager: <info> autoip: Waiting for reply... Jun 8 14:52:38 sonlaptop NetworkManager: <info> autoip: Sending announce #0 for IP address 169.254.143.1. Jun 8 14:52:38 sonlaptop NetworkManager: <info> autoip: Waiting for reply... Jun 8 14:52:41 sonlaptop NetworkManager: <info> autoip: Sending announce #1 for IP address 169.254.143.1. Jun 8 14:52:41 sonlaptop NetworkManager: <info> autoip: Waiting for reply... Jun 8 14:52:44 sonlaptop NetworkManager: <info> autoip: Sending announce #2 for IP address 169.254.143.1. Jun 8 14:52:44 sonlaptop NetworkManager: <info> autoip: Waiting for reply... Jun 8 14:52:47 sonlaptop NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) scheduled... Jun 8 14:52:47 sonlaptop NetworkManager: <info> Activation (eth0) Stage 4 of 5 (IP Configure Timeout) complete. Jun 8 14:52:47 sonlaptop NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) started... Jun 8 14:52:48 sonlaptop NetworkManager: <info> Activation (eth0) Finish handler scheduled. Jun 8 14:52:48 sonlaptop NetworkManager: <info> Activation (eth0) Stage 5 of 5 (IP Configure Commit) complete. Jun 8 14:52:48 sonlaptop NetworkManager: <info> Activation (eth0) successful, device activated. Jun 8 14:52:50 sonlaptop NetworkManager: <info> SWITCH: found better connection 'wlan0' than current connection 'eth0'. Jun 8 14:52:50 sonlaptop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/wlan0 for sub-path wlan0.dbus.get.reason Jun 8 14:52:50 sonlaptop NetworkManager: <info> Will activate connection 'wlan0/sabastion'. Jun 8 14:52:50 sonlaptop NetworkManager: <info> Device wlan0 activation scheduled... Jun 8 14:52:50 sonlaptop NetworkManager: <info> Deactivating device eth0. Jun 8 14:52:50 sonlaptop NetworkManager: <info> Activation (wlan0) started... Jun 8 14:52:50 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... Jun 8 14:52:50 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... Jun 8 14:52:50 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... Jun 8 14:52:50 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. Jun 8 14:52:50 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... Jun 8 14:52:50 sonlaptop NetworkManager: <info> Activation (wlan0/wireless): access point 'sabastion' is encrypted, but NO valid key exists. New key needed. Jun 8 14:52:50 sonlaptop NetworkManager: <info> Activation (wlan0) New wireless user key requested for network 'sabastion'. Jun 8 14:52:50 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. Jun 8 14:52:59 sonlaptop NetworkManager: <info> Activation (wlan0) New wireless user key for network 'sabastion' received. Jun 8 14:52:59 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled... Jun 8 14:52:59 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) started... Jun 8 14:52:59 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled... Jun 8 14:52:59 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 1 of 5 (Device Prepare) complete. Jun 8 14:52:59 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) starting... Jun 8 14:52:59 sonlaptop NetworkManager: <info> Activation (wlan0/wireless): access point 'sabastion' is encrypted, and a key exists. No new key needed. Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: sending command 'INTERFACE_ADD wlan0 wext /var/run/wpa_supplicant ' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: response was 'OK' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: sending command 'AP_SCAN 1' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: response was 'OK' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: sending command 'ADD_NETWORK' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: response was '0' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 ssid 736162617374696f6e' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: response was 'OK' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 proto WPA' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: response was 'OK' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 key_mgmt WPA-PSK' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: response was 'OK' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 psk <key>' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: response was 'OK' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 pairwise TKIP' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: response was 'OK' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: sending command 'SET_NETWORK 0 group TKIP' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: response was 'OK' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: sending command 'ENABLE_NETWORK 0' Jun 8 14:53:00 sonlaptop NetworkManager: <info> SUP: response was 'OK' Jun 8 14:53:00 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 2 of 5 (Device Configure) complete. Jun 8 14:53:02 sonlaptop kernel: iwl3945: REPLY_ADD_STA failed Jun 8 14:53:02 sonlaptop kernel: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready Jun 8 14:53:03 sonlaptop NetworkManager: <info> Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful. Connected to access point 'sabastion'. Jun 8 14:53:03 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled. Jun 8 14:53:03 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) started... Jun 8 14:53:04 sonlaptop NetworkManager: <info> Activation (wlan0) Beginning DHCP transaction. Jun 8 14:53:04 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete. Jun 8 14:53:04 sonlaptop NetworkManager: <info> DHCP daemon state is now 12 (successfully started) for interface wlan0 Jun 8 14:53:04 sonlaptop dhclient: wmaster0: unknown hardware address type 801 Jun 8 14:53:04 sonlaptop dhclient: wmaster0: unknown hardware address type 801 Jun 8 14:53:04 sonlaptop NetworkManager: <info> DHCP daemon state is now 1 (starting) for interface wlan0 Jun 8 14:53:04 sonlaptop dhclient: DHCPREQUEST on wlan0 to 255.255.255.255 port 67 Jun 8 14:53:06 sonlaptop dhclient: DHCPACK from 10.0.0.1 Jun 8 14:53:06 sonlaptop NetworkManager: <info> DHCP daemon state is now 4 (reboot) for interface wlan0 Jun 8 14:53:06 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP Configure Get) scheduled... Jun 8 14:53:06 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP Configure Get) started... Jun 8 14:53:06 sonlaptop dhclient: bound to 10.0.0.10 -- renewal in 33528 seconds. Jun 8 14:53:06 sonlaptop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/wlan0 for sub-path wlan0.dbus.get.host_name Jun 8 14:53:06 sonlaptop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/wlan0 for sub-path wlan0.dbus.get.domain_name Jun 8 14:53:06 sonlaptop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/wlan0 for sub-path wlan0.dbus.get.nis_domain Jun 8 14:53:06 sonlaptop dhcdbd: message_handler: message handler not found under /com/redhat/dhcp/wlan0 for sub-path wlan0.dbus.get.nis_servers Jun 8 14:53:06 sonlaptop NetworkManager: <info> Retrieved the following IP4 configuration from the DHCP daemon: Jun 8 14:53:06 sonlaptop NetworkManager: <info> address 10.0.0.10 Jun 8 14:53:06 sonlaptop NetworkManager: <info> netmask 255.255.0.0 Jun 8 14:53:06 sonlaptop NetworkManager: <info> broadcast 10.0.255.255 Jun 8 14:53:06 sonlaptop NetworkManager: <info> gateway 10.0.0.1 Jun 8 14:53:06 sonlaptop NetworkManager: <info> nameserver 205.152.144.23 Jun 8 14:53:06 sonlaptop NetworkManager: <info> nameserver 205.152.132.23 Jun 8 14:53:06 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) scheduled... Jun 8 14:53:06 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 4 of 5 (IP Configure Get) complete. Jun 8 14:53:06 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started... Jun 8 14:53:07 sonlaptop NetworkManager: <info> Activation (wlan0) Finish handler scheduled. Jun 8 14:53:07 sonlaptop NetworkManager: <info> Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complete. Jun 8 14:53:07 sonlaptop NetworkManager: <info> Activation (wlan0) successful, device activated. Jun 8 14:53:29 sonlaptop kernel: iwl3945: REPLY_ADD_STA failed Jun 8 14:56:10 sonlaptop last message repeated 3 times Jun 8 14:59:08 sonlaptop last message repeated 6 times Jun 8 15:01:19 sonlaptop kernel: iwl3945: REPLY_ADD_STA failed Jun 8 15:03:29 sonlaptop last message repeated 2 times Jun 8 15:05:39 sonlaptop kernel: iwl3945: REPLY_ADD_STA failed Jun 8 15:07:49 sonlaptop kernel: iwl3945: REPLY_ADD_STA failed Jun 8 15:09:59 sonlaptop kernel: iwl3945: REPLY_ADD_STA failed *** Bug 242786 has been marked as a duplicate of this bug. *** I can confirm that this is still not fixed in (fully updated) rawhide with NetworkManager-0.6.5-5.fc8. Reopening. I upgraded to NetworkManager-0.6.5-4.fc7 on my F7 install, and a for at least the couple of reboots I've done since, it no longer picks a nonexistent wired network instead of the wireless. Seems to work for me, in other words. Created attachment 156795 [details]
Syslog (with extra debug code)
I also see this problem.
I've tried with version: NetworkManager-0.6.5-5.fc7 on F7. I hope the extra
debug code gives some insight into what is wrong.
*** Bug 244353 has been marked as a duplicate of this bug. *** this "fix" results into nm does not detect link status @all ->regression ok let me correct my self: it works sometimes and breaks after 2-3 disconnects I have to restart the networkmanager service to get it working again for the next 2-3 dis/connects drago01, can you attach your /var/log/messages so we can see what NM thinks it's doing? Created attachment 157295 [details]
/var/log/messages
here is it...
Created attachment 157301 [details]
better one
ok here is a new log. this time I did this:
reboot with a cabled plugged.
unplugged/plugged the cable until it failed to detect the link state (where I
had to rightclick on the applet to select the wired network to get it working).
I think this are the interessting lines: Jun 18 19:19:27 localhost NetworkManager: nm_device_is_802_3_ethernet: assertion `dev != NULL' failed Jun 18 19:19:27 localhost NetworkManager: nm_device_is_802_11_wireless: assertion `dev != NULL' failed sorry I am still using NetworkManager-0.6.5-5.fc7 will test again with the version from updates-testing... sorry again for the noise. (In reply to comment #49) > sorry I am still using NetworkManager-0.6.5-5.fc7 will test again with the > version from updates-testing... sorry again for the noise. ignore this comment it is the lastest version... so the problem described above is still present *** Bug 224086 has been marked as a duplicate of this bug. *** Additional fixes for this have been committed in revision 2605 on the 0.6.x branch (In reply to comment #52) > Additional fixes for this have been committed in revision 2605 on the 0.6.x branch can you backport them to the fedora package or even better release a 0.6.6 release? Built in F-7 testing, http://koji.fedoraproject.org/koji/buildinfo?buildID=9454 , could you test the packages out and see if they help at all? Also includes the HAL rfkill support. Thanks! thx, will test them when I get home (in one hour ;) ) (In reply to comment #54) > Built in F-7 testing, http://koji.fedoraproject.org/koji/buildinfo?buildID=9454 > , could you test the packages out and see if they help at all? ok here are the test results: 1)login with no link: nothing happens 2)I can plug/unplug the cable as often as I want ... nm always does the correct thing (up/down) => great work :) rawhide NetworkManager-0.6.5-6.fc8 does not fix the problem, or was it supposed to be another release? Should be fixed in these two: NetworkManager-0.6.5-6.fc7 NetworkManager-0.6.5-6.1.fc8 (In reply to comment #58) > NetworkManager-0.6.5-6.1.fc8 This seems to resolve it for me. I am using NetworkManager-0.6.5-5.fc7 and the problem still appears to me (see my duplicate bug 242786) Created attachment 157705 [details]
my /var/log/messages cutting
here's my syslog cutting as i still encounter the problem after booting and
logging in.
(In reply to comment #58) > NetworkManager-0.6.5-6.fc7 This version resolves the problem for me on Fedora 7 NetworkManager-0.6.5-6.fc7 has been pushed to the Fedora 7 stable repository. If problems still persist, please make note of it in this bug report. |