Gentoo Websites Logo
Go to: Gentoo Home Documentation Forums Lists Bugs Planet Store Wiki Get Gentoo!
Bug 262112 - net-misc/networkmanager-0.7.1-r2 takes too many time for starting because of trying to join to undesired AP
Summary: net-misc/networkmanager-0.7.1-r2 takes too many time for starting because of ...
Status: RESOLVED FIXED
Alias: None
Product: Gentoo Linux
Classification: Unclassified
Component: Current packages (show other bugs)
Hardware: All Linux
: High normal (vote)
Assignee: Steev Klimaszewski (RETIRED)
URL: http://bugzilla.gnome.org/show_bug.cg...
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2009-03-11 11:57 UTC by Pacho Ramos
Modified: 2009-06-11 06:21 UTC (History)
2 users (show)

See Also:
Package list:
Runtime testing required: ---


Attachments
config (config,52.30 KB, text/plain)
2009-04-14 22:03 UTC, Pacho Ramos
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Pacho Ramos gentoo-dev 2009-03-11 11:57:32 UTC
I already reported this to upstream but I didn't get much feedback (maybe I should try with mailing list but, before, I would know your opinion):
I get this problem when switching my RF Kill button in my laptop.

When I switch wireless of I see these messages:
Dec 14 10:34:26 belkin3 atkbd.c: Unknown key pressed (translated set 2, code
0x88 on isa0060/serio0).
Dec 14 10:34:26 belkin3 atkbd.c: Use 'setkeycodes e008 <keycode>' to make it
known.
Dec 14 10:34:26 belkin3 iwl4965: Radio Frequency Kill Switch is On:
Dec 14 10:34:26 belkin3 Kill switch must be turned off for wireless networking
to work.
Dec 14 10:34:27 belkin3 NetworkManager: <info>  Wireless now disabled by radio
killswitch
Dec 14 10:34:27 belkin3 NetworkManager: <info>  (wlan0): device state change: 8
-> 2
Dec 14 10:34:27 belkin3 NetworkManager: <info>  (wlan0): deactivating device
(reason: 0).
Dec 14 10:34:27 belkin3 wlan0: Initial auth_alg=0
Dec 14 10:34:27 belkin3 wlan0: authenticate with AP 00:0c:f6:1d:c9:e8
Dec 14 10:34:27 belkin3 NetworkManager: <info>  (wlan0): deactivating device
(reason: 0).
Dec 14 10:34:27 belkin3 wlan0: Initial auth_alg=0
Dec 14 10:34:27 belkin3 wlan0: authenticate with AP 00:0c:f6:1d:c9:e8
Dec 14 10:34:27 belkin3 wlan0: disassociate(reason=3)
Dec 14 10:34:27 belkin3 NetworkManager: <WARN>  check_one_route(): (wlan0)
error -34 returned from rtnl_route_del(): Missing link name TLV (errno =
Invalid argument)
Dec 14 10:34:27 belkin3 iwl4965: Error sending REPLY_WEPKEY: enqueue_hcmd
failed: -5
Dec 14 10:34:27 belkin3 mac80211-phy0: failed to remove key (0,
ff:ff:ff:ff:ff:ff) from hardware (-5)
Dec 14 10:34:27 belkin3 NetworkManager: <info>  (wlan0): taking down device.
Dec 14 10:34:27 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:27 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:28 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:28 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:28 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:28 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:28 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:28 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:28 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:28 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:29 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:29 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:29 belkin3 usb 3-2: USB disconnect, address 10
Dec 14 10:34:29 belkin3 usb 3-2.1: USB disconnect, address 11
Dec 14 10:34:29 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:29 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:29 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:29 belkin3 hcid[18729]: HCI dev 0 down
Dec 14 10:34:29 belkin3 hcid[18729]: Stopping security manager 0
Dec 14 10:34:29 belkin3 hcid[18729]: Device hci0 has been disabled
Dec 14 10:34:29 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:29 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:29 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:29 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
Dec 14 10:34:29 belkin3 usb 3-2.2: USB disconnect, address 12
Dec 14 10:34:29 belkin3 hcid[18729]: HCI dev 0 unregistered
Dec 14 10:34:29 belkin3 hcid[18729]: HCI dev 0 unregistered
Dec 14 10:34:29 belkin3 hcid[18729]: Unregister path: /org/bluez/hci0
Dec 14 10:34:29 belkin3 hcid[18729]: Device hci0 has been removed
Dec 14 10:34:29 belkin3 usb 3-2.3: USB disconnect, address 13
Dec 14 10:34:29 belkin3 hcid[18729]: Unregistered manager path
Dec 14 10:34:29 belkin3 hcid[18729]: bridge pan0 removed
Dec 14 10:34:29 belkin3 hcid[18729]: Unregistered manager path
Dec 14 10:34:29 belkin3 hcid[18729]: Unregistered manager path
Dec 14 10:34:29 belkin3 hcid[18729]: Stopping SDP server
Dec 14 10:34:29 belkin3 hcid[18729]: Exit

Even with some errors (maybe related to the driver) it is switched off
properly, but now, I get the following when switching on:
Dec 14 10:34:45 belkin3 atkbd.c: Unknown key pressed (translated set 2, code
0x88 on isa0060/serio0).
Dec 14 10:34:45 belkin3 atkbd.c: Use 'setkeycodes e008 <keycode>' to make it
known.
Dec 14 10:34:45 belkin3 usb 3-2: new full speed USB device using uhci_hcd and
address 14
Dec 14 10:34:46 belkin3 usb 3-2: configuration #1 chosen from 1 choice
Dec 14 10:34:46 belkin3 hub 3-2:1.0: USB hub found
Dec 14 10:34:46 belkin3 hub 3-2:1.0: 3 ports detected
Dec 14 10:34:46 belkin3 usb 3-2: New USB device found, idVendor=0a5c,
idProduct=4500
Dec 14 10:34:46 belkin3 usb 3-2: New USB device strings: Mfr=1, Product=2,
SerialNumber=0
Dec 14 10:34:46 belkin3 usb 3-2: Product: BCM2045B2
Dec 14 10:34:46 belkin3 usb 3-2: Manufacturer: Broadcom
Dec 14 10:34:46 belkin3 usb 3-2.1: new full speed USB device using uhci_hcd and
address 15
Dec 14 10:34:46 belkin3 usb 3-2.1: configuration #1 chosen from 1 choice
Dec 14 10:34:46 belkin3 usb 3-2.1: New USB device found, idVendor=413c,
idProduct=8126
Dec 14 10:34:46 belkin3 usb 3-2.1: New USB device strings: Mfr=1, Product=2,
SerialNumber=0
Dec 14 10:34:46 belkin3 usb 3-2.1: Product: BCM2045
Dec 14 10:34:46 belkin3 usb 3-2.1: Manufacturer: Broadcom Corp
Dec 14 10:34:46 belkin3 usb 3-2.2: new full speed USB device using uhci_hcd and
address 16
Dec 14 10:34:46 belkin3 hcid[23972]: Bluetooth HCI daemon
Dec 14 10:34:46 belkin3 hcid[23972]: Parsing /etc/bluetooth/main.conf failed:
No such file or directory
Dec 14 10:34:46 belkin3 hcid[23972]: Starting SDP server
Dec 14 10:34:46 belkin3 usb 3-2.2: configuration #1 chosen from 1 choice
Dec 14 10:34:46 belkin3 hcid[23972]: Unix socket created: 11
Dec 14 10:34:46 belkin3 hcid[23972]: Registered manager path:/org/bluez/audio
Dec 14 10:34:46 belkin3 hcid[23972]: Registered manager path:/org/bluez/serial
Dec 14 10:34:46 belkin3 pan0: Dropping NETIF_F_UFO since no NETIF_F_HW_CSUM
feature.
Dec 14 10:34:46 belkin3 input: Broadcom Corp as
/devices/pci0000:00/0000:00:1a.0/usb3/3-2/3-2.2/3-2.2:1.0/input/input19
Dec 14 10:34:46 belkin3 hcid[23972]: bridge pan0 created
Dec 14 10:34:46 belkin3 hcid[23972]: Registered manager path:/org/bluez/network
Dec 14 10:34:46 belkin3 hcid[23972]: Registered server
path:/org/bluez/network/nap
Dec 14 10:34:46 belkin3 hcid[23972]: Registered server
path:/org/bluez/network/gn
Dec 14 10:34:46 belkin3 hcid[23972]: Registered server
path:/org/bluez/network/panu
Dec 14 10:34:46 belkin3 input,hidraw1: USB HID v1.11 Keyboard [Broadcom Corp]
on usb-0000:00:1a.0-2.2
Dec 14 10:34:46 belkin3 usb 3-2.2: New USB device found, idVendor=0a5c,
idProduct=4502
Dec 14 10:34:46 belkin3 usb 3-2.2: New USB device strings: Mfr=1, Product=0,
SerialNumber=0
Dec 14 10:34:46 belkin3 usb 3-2.2: Manufacturer: Broadcom Corp
Dec 14 10:34:46 belkin3 hcid[23972]: Registered input manager
path:/org/bluez/input
Dec 14 10:34:46 belkin3 hcid[23972]: HCI dev 0 registered
Dec 14 10:34:46 belkin3 hcid[23972]: Default passkey agent (:1.102,
/org/bluez/passkey) registered
Dec 14 10:34:46 belkin3 hcid[23972]: Default authorization agent (:1.102,
/org/bluez/auth) registered
Dec 14 10:34:46 belkin3 hcid[23972]: HCI dev 0 up
Dec 14 10:34:46 belkin3 hcid[23972]: Device hci0 has been added
Dec 14 10:34:46 belkin3 hcid[23972]: Starting security manager 0
Dec 14 10:34:46 belkin3 hcid[23972]: Device hci0 has been activated
Dec 14 10:34:47 belkin3 usb 3-2.3: new full speed USB device using uhci_hcd and
address 17
Dec 14 10:34:47 belkin3 usb 3-2.3: configuration #1 chosen from 1 choice
Dec 14 10:34:47 belkin3 input: Broadcom Corp as
/devices/pci0000:00/0000:00:1a.0/usb3/3-2/3-2.3/3-2.3:1.0/input/input20
Dec 14 10:34:47 belkin3 input,hidraw2: USB HID v1.11 Mouse [Broadcom Corp] on
usb-0000:00:1a.0-2.3
Dec 14 10:34:47 belkin3 usb 3-2.3: New USB device found, idVendor=0a5c,
idProduct=4503
Dec 14 10:34:47 belkin3 usb 3-2.3: New USB device strings: Mfr=1, Product=0,
SerialNumber=0
Dec 14 10:34:47 belkin3 usb 3-2.3: Manufacturer: Broadcom Corp
Dec 14 10:34:47 belkin3 NetworkManager: <info>  Wireless now enabled by radio
killswitch
Dec 14 10:34:47 belkin3 NetworkManager: <WARN>  nm_device_wifi_set_enabled():
not in expected unavailable state!
Dec 14 10:34:47 belkin3 NetworkManager: <info>  (wlan0): bringing up device.
Dec 14 10:34:47 belkin3 ACPI: PCI Interrupt 0000:0c:00.0[A] -> GSI 17 (level,
low) -> IRQ 17
Dec 14 10:34:48 belkin3 Registered led device: iwl-phy0:radio
Dec 14 10:34:48 belkin3 Registered led device: iwl-phy0:assoc
Dec 14 10:34:48 belkin3 Registered led device: iwl-phy0:RX
Dec 14 10:34:48 belkin3 Registered led device: iwl-phy0:TX
Dec 14 10:34:48 belkin3 wlan0: Initial auth_alg=0
Dec 14 10:34:48 belkin3 wlan0: authenticate with AP 00:13:f7:2c:fb:b5
Dec 14 10:34:48 belkin3 NetworkManager: <info>  (wlan0): device state change: 2
-> 3
Dec 14 10:34:48 belkin3 NetworkManager: <info>  (wlan0): supplicant interface
state:  starting -> ready
Dec 14 10:34:48 belkin3 wlan0: authenticate with AP 00:13:f7:2c:fb:b5
Dec 14 10:34:48 belkin3 wlan0: authenticate with AP 00:13:f7:2c:fb:b5
Dec 14 10:34:48 belkin3 wlan0: authentication with AP 00:13:f7:2c:fb:b5 timed
out

Here, I have to wait, Why is NetworkManager wanting to use this AP when I have
a different one configured in /etc/NetworkManager/system-connections/conexion ?

After waiting, NetworkManager connects to proper one finally:
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Activation (wlan0) starting
connection 'conexion'
Dec 14 10:35:12 belkin3 NetworkManager: <info>  (wlan0): device state change: 3
-> 4
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Activation (wlan0) Stage 1 of 5
(Device Prepare) scheduled...
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Activation (wlan0) Stage 1 of 5
(Device Prepare) started...
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Activation (wlan0) Stage 2 of 5
(Device Configure) scheduled...
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Activation (wlan0) Stage 1 of 5
(Device Prepare) complete.
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Activation (wlan0) Stage 2 of 5
(Device Configure) starting...
Dec 14 10:35:12 belkin3 NetworkManager: <info>  (wlan0): device state change: 4
-> 5
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Activation (wlan0/wireless):
connection 'conexion' has security, and secrets exist.  No new secrets needed.
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Config: added 'ssid' value
'OOurnet'
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Config: added 'scan_ssid' value
'1'
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Config: added 'bssid' value
'00:0c:f6:1d:c9:e8'
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Config: added 'key_mgmt' value
'NONE'
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Config: added 'auth_alg' value
'OPEN'
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Config: added 'wep_key0' value
'<omitted>'
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Config: added 'wep_tx_keyidx'
value '0'
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Activation (wlan0) Stage 2 of 5
(Device Configure) complete.
Dec 14 10:35:12 belkin3 NetworkManager: <info>  Config: set interface ap_scan
to 1
Dec 14 10:35:12 belkin3 NetworkManager: <info>  (wlan0): supplicant connection
state:  scanning -> disconnected
Dec 14 10:35:13 belkin3 NetworkManager: <info>  (wlan0): supplicant connection
state:  disconnected -> scanning
Dec 14 10:35:14 belkin3 NetworkManager: <info>  (wlan0): supplicant connection
state:  scanning -> associating
Dec 14 10:35:14 belkin3 wlan0: Initial auth_alg=0
Dec 14 10:35:14 belkin3 wlan0: authenticate with AP 00:0c:f6:1d:c9:e8
Dec 14 10:35:14 belkin3 wlan0: RX authentication from 00:0c:f6:1d:c9:e8 (alg=0
transaction=2 status=0)
Dec 14 10:35:14 belkin3 wlan0: authenticated
Dec 14 10:35:14 belkin3 wlan0: associate with AP 00:0c:f6:1d:c9:e8
Dec 14 10:35:14 belkin3 wlan0: RX AssocResp from 00:0c:f6:1d:c9:e8 (capab=0x431
status=0 aid=1)
Dec 14 10:35:14 belkin3 wlan0: associated
Dec 14 10:35:14 belkin3 wlan0: switched to short barker preamble
(BSSID=00:0c:f6:1d:c9:e8)
Dec 14 10:35:14 belkin3 NetworkManager: <info>  (wlan0): supplicant connection
state:  associating -> associated
Dec 14 10:35:14 belkin3 NetworkManager: <info>  (wlan0): supplicant connection
state:  associated -> completed
Dec 14 10:35:14 belkin3 NetworkManager: <info>  Activation (wlan0/wireless)
Stage 2 of 5 (Device Configure) successful.  Connected to wireless network
'OOurnet'.
Dec 14 10:35:14 belkin3 NetworkManager: <info>  Activation (wlan0) Stage 3 of 5
(IP Configure Start) scheduled.
Dec 14 10:35:14 belkin3 NetworkManager: <info>  Activation (wlan0) Stage 3 of 5
(IP Configure Start) started...
Dec 14 10:35:14 belkin3 NetworkManager: <info>  (wlan0): device state change: 5
-> 7
Dec 14 10:35:14 belkin3 NetworkManager: <info>  Activation (wlan0) Stage 4 of 5
(IP Configure Get) scheduled...
Dec 14 10:35:14 belkin3 NetworkManager: <info>  Activation (wlan0) Stage 3 of 5
(IP Configure Start) complete.
Dec 14 10:35:14 belkin3 NetworkManager: <info>  Activation (wlan0) Stage 4 of 5
(IP Configure Get) started...
Dec 14 10:35:14 belkin3 NetworkManager: <info>  Activation (wlan0) Stage 5 of 5
(IP Configure Commit) scheduled...
Dec 14 10:35:14 belkin3 NetworkManager: <info>  Activation (wlan0) Stage 4 of 5
(IP Configure Get) complete.
Dec 14 10:35:14 belkin3 NetworkManager: <info>  Activation (wlan0) Stage 5 of 5
(IP Configure Commit) started...
Dec 14 10:35:15 belkin3 NetworkManager: <info>  (wlan0): device state change: 7
-> 8
Dec 14 10:35:15 belkin3 NetworkManager: <info>  Policy set 'conexion' (wlan0)
as default for routing and DNS.

(these logs are from upstream bug report, even being a bit old, they haven't changed)

I get the same problem with iwlagn, iwl4965 (no replaced by first one) and iwl3945

Thanks a lot

Reproducible: Always

Steps to Reproduce:
Comment 1 Pacho Ramos gentoo-dev 2009-03-11 12:00:48 UTC
Portage 2.1.6.7 (default/linux/amd64/2008.0/desktop, gcc-4.1.2, glibc-2.8_p20080602-r1, 2.6.28-tuxonice-r4 x86_64)
=================================================================
System uname: Linux-2.6.28-tuxonice-r4-x86_64-Intel-R-_Core-TM-2_Duo_CPU_T9300_@_2.50GHz-with-glibc2.2.5
Timestamp of tree: Sun, 08 Mar 2009 09:35:01 +0000
distcc 3.0 x86_64-pc-linux-gnu [disabled]
ccache version 2.4 [enabled]
app-shells/bash:     3.2_p39
dev-java/java-config: 2.1.6-r1
dev-lang/python:     2.5.2-r7
dev-util/ccache:     2.4-r7
dev-util/cmake:      2.6.2-r1
sys-apps/baselayout: 1.12.11.1
sys-apps/sandbox:    1.2.18.1-r2
sys-devel/autoconf:  2.13, 2.63
sys-devel/automake:  1.5, 1.7.9-r1, 1.8.5-r3, 1.9.6-r2, 1.10.2
sys-devel/binutils:  2.18-r3
sys-devel/gcc-config: 1.4.0-r4
sys-devel/libtool:   1.5.26
virtual/os-headers:  2.6.27-r2
ACCEPT_KEYWORDS="amd64"
CBUILD="x86_64-pc-linux-gnu"
CFLAGS="-O2 -pipe -march=nocona -fomit-frame-pointer"
CHOST="x86_64-pc-linux-gnu"
CONFIG_PROTECT="/etc /usr/kde/3.5/env /usr/kde/3.5/share/config /usr/kde/3.5/shutdown /usr/share/config /var/lib/hsqldb"
CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/env.d /etc/env.d/java/ /etc/fonts/fonts.conf /etc/gconf /etc/revdep-rebuild /etc/splash /etc/terminfo /etc/texmf/web2c /etc/udev/rules.d"
CXXFLAGS="-O2 -pipe -march=nocona -fomit-frame-pointer"
DISTDIR="/usr/distfiles"
FEATURES="autoaddcvs ccache collision-protect cvs distlocks fixpackages multilib-strict parallel-fetch protect-owned sandbox sfperms strict unmerge-orphans userfetch"
GENTOO_MIRRORS="ftp://ftp.free.fr/mirrors/ftp.gentoo.org"
LANG="es_ES.UTF-8"
LC_ALL="es_ES.UTF-8"
LDFLAGS="-Wl,-O1"
LINGUAS="es es_ES en_US"
MAKEOPTS="-j3"
PKGDIR="/usr/portage/packages"
PORTAGE_CONFIGROOT="/"
PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --compress --force --whole-file --delete --stats --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages"
PORTAGE_TMPDIR="/var/tmp"
PORTDIR="/usr/portage"
PORTDIR_OVERLAY="/usr/local/portage/layman/sunrise /usr/local/portage/layman/wschlich-testing /usr/local/portage"
SYNC="rsync://rsync.gentoo.org/gentoo-portage"
USE="X a52 aac acl acpi alsa amd64 amr avahi bash-completion berkdb bluetooth branding bzip2 cairo cdda cddb cdparanoia cdr cli consolekit cracklib crypt css cups daap dbus dell dirac divx djvu dts dvd dvdr dvdread dvi eds emboss emovix encode epiphany evo exif fam fbcondecor fbsplash ffmpeg flac fortran fuse galago gdbm gif glitz gmedia gnome gnome-keyring gpm gsm gstreamer gtk hal iconv ieee1394 ipv6 isdnlog java java6 jpeg jpeg2k kdeenablefinal kdehiddenvisibility kpathsea laptop latex lcms ldap libnotify lzma mad midi mikmod mjpeg mmx mmxext mono moonlight mp3 mpeg mudflap multilib musepack musicbrainz nautilus ncurses network network-cron networkmanager nls nptl nptlonly ntp ogg opengl openmp pam pch pcre pdf perl png ppds pppd python qt3 qt3support qt4 quicktime readline realmedia reflection scanner schroedinger sdl session smp sms speex spell spl sse sse2 sse3 ssl ssse3 startup-notification svg sysfs t1lib tcpd theora threads tiff totem truetype unicode usb v4l2 vcd vorbis wmf wmp x264 xattr xcb xft xinetd xml xorg xulrunner xv xvid zeroconf zlib" ALSA_CARDS="hda-intel" ALSA_PCM_PLUGINS="adpcm alaw asym copy dmix dshare dsnoop empty extplug file hooks iec958 ioplug ladspa lfloat linear meter mmap_emul mulaw multi null plug rate route share shm softvol" APACHE2_MODULES="actions alias auth_basic authn_alias authn_anon authn_dbm authn_default authn_file authz_dbm authz_default authz_groupfile authz_host authz_owner authz_user autoindex cache dav dav_fs dav_lock deflate dir disk_cache env expires ext_filter file_cache filter headers include info log_config logio mem_cache mime mime_magic negotiation rewrite setenvif speling status unique_id userdir usertrack vhost_alias" ELIBC="glibc" INPUT_DEVICES="keyboard mouse synaptics" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" LINGUAS="es es_ES en_US" USERLAND="GNU" VIDEO_CARDS="nvidia nv"
Unset:  CPPFLAGS, CTARGET, EMERGE_DEFAULT_OPTS, FFLAGS, INSTALL_MASK, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS
Comment 2 Pacho Ramos gentoo-dev 2009-04-01 08:38:55 UTC
No idea about what could I try or what more info could I provide? This is causes problems with ntpd and nfsmount started "too soon" and working wrong due unavailable networking

Thanks a lot
Comment 3 Robert Piasek (RETIRED) gentoo-dev 2009-04-01 10:22:53 UTC
Hi Pacho,

The problem you linked in here is a driver problem and not networkmanager.

All errors like this:
Dec 14 10:34:27 belkin3 iwl4965: WARNING: Requesting MAC access during RFKILL
wakes up NIC
are caused with driver incorrectly responding to killswitch.

Once network card is enabled - NM initialise connection without any problems:
Dec 14 10:34:47 belkin3 NetworkManager: <info>  Wireless now enabled by radio
killswitch
Dec 14 10:35:15 belkin3 NetworkManager: <info>  Policy set 'conexion' (wlan0)
as default for routing and DNS.

You can see that enabling killswitch is enabling plenty of devices (USB?, bluetooth) - so it's either wrongly configured or not working as intended (killswitch shouldn't touch USB host/hub - only radio devices).

I would check acpi events and make sure you don't have some random actions for killswitch events.
Dec 14 10:34:45 belkin3 atkbd.c: Unknown key pressed (translated set 2, code
0x88 on isa0060/serio0).
Dec 14 10:34:45 belkin3 atkbd.c: Use 'setkeycodes e008 <keycode>' to make it
known.

 As a workaround you could also disable killswitch (it's NOT ideal, but would make the problem go away until you can find the proper solution).

Rob
Comment 4 Pacho Ramos gentoo-dev 2009-04-03 14:47:47 UTC
Seems reasonable, I will also tryto upgrade hal-info packages for seeing it it improves something related with rf-kill behavior

Maybe nfsmount is failing because NetworkManager still doesn't completely replace net init.d script (bug 252137)
Comment 5 Pacho Ramos gentoo-dev 2009-04-03 14:58:25 UTC
Please take care that this not only occur when switching my RF Kill button, also when restarting NetworkManager:
# /etc/init.d/NetworkManager stop
Apr  3 16:54:51 belkin NetworkManager: <WARN>  nm_signal_handler(): Caught signal 15, shutting down normally.
Apr  3 16:54:51 belkin NetworkManager: <info>  (eth1): now unmanaged
Apr  3 16:54:51 belkin NetworkManager: <info>  (eth1): device state change: 2 -> 1
Apr  3 16:54:51 belkin NetworkManager: <info>  (eth1): cleaning up...
Apr  3 16:54:51 belkin NetworkManager: <info>  (eth1): taking down device.
Apr  3 16:54:51 belkin NetworkManager: <info>  (wlan0): now unmanaged
Apr  3 16:54:51 belkin NetworkManager: <info>  (wlan0): device state change: 8 -> 1
Apr  3 16:54:51 belkin NetworkManager: <info>  (wlan0): deactivating device (reason: 36).
Apr  3 16:54:51 belkin wlan0: direct probe to AP 00:0c:f6:1d:c9:e8 try 1
Apr  3 16:54:51 belkin wlan0: disassociating by local choice (reason=3)
Apr  3 16:54:51 belkin wlan0 direct probe responded
Apr  3 16:54:51 belkin wlan0: authenticate with AP 00:0c:f6:1d:c9:e8
Apr  3 16:54:51 belkin wlan0: authenticated
Apr  3 16:54:51 belkin wlan0: associate with AP 00:0c:f6:1d:c9:e8
Apr  3 16:54:51 belkin wlan0: RX AssocResp from 00:0c:f6:1d:c9:e8 (capab=0x431 status=0 aid=1)
Apr  3 16:54:51 belkin wlan0: associated
Apr  3 16:54:51 belkin NetworkManager: <WARN>  check_one_route(): (wlan0) error -34 returned from rtnl_route_del(): Sucess
Apr  3 14:54:51 belkin avahi-daemon[4513]: Withdrawing address record for 192.168.1.202 on wlan0.
Apr  3 14:54:51 belkin avahi-daemon[4513]: Leaving mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.202.
Apr  3 14:54:51 belkin avahi-daemon[4513]: Interface wlan0.IPv4 no longer relevant for mDNS.
Apr  3 16:54:51 belkin NetworkManager: <info>  (wlan0): cleaning up...
Apr  3 16:54:51 belkin NetworkManager: <info>  (wlan0): taking down device.
Apr  3 16:54:51 belkin wlan0: No STA entry for own AP 00:00:00:00:00:00
Apr  3 16:54:52 belkin NetworkManager: <info>  disconnected by the system bus.


# /etc/init.d/NetworkManager start
Apr  3 16:55:37 belkin NetworkManager: <info>  starting...
Apr  3 16:55:37 belkin NetworkManager: <info>  Found radio killswitch /org/freedesktop/Hal/devices/iwl_wlan_switch
Apr  3 16:55:37 belkin NetworkManager: <info>  eth1: driver is 'r8169'.
Apr  3 16:55:37 belkin NetworkManager: <info>  Found new Ethernet device 'eth1'.
Apr  3 16:55:37 belkin NetworkManager: <info>  (eth1): exported as /org/freedesktop/Hal/devices/net_00_17_31_15_5a_78
Apr  3 16:55:37 belkin NetworkManager: <info>  wlan0: driver is 'iwl3945'.
Apr  3 16:55:37 belkin NetworkManager: <info>  wlan0: driver supports SSID scans (scan_capa 0x01).
Apr  3 16:55:37 belkin NetworkManager: <info>  Found new 802.11 WiFi device 'wlan0'.
Apr  3 16:55:37 belkin NetworkManager: <info>  (wlan0): exported as /org/freedesktop/Hal/devices/net_00_13_02_18_aa_26
Apr  3 16:55:37 belkin NetworkManager: <WARN>  killswitch_getpower_reply(): Error getting killswitch power: hal-ipw-killswitch-linux returned 255.
Apr  3 16:55:38 belkin ntpd[4816]: sendto(195.10.6.126) (fd=18): Invalid argument
Apr  3 16:55:39 belkin ntpd[4816]: Deleting interface #2 wlan0, 192.168.1.202#123, interface stats: received=41, sent=41, dropped=16, active_time=900 secs
Apr  3 16:55:41 belkin r8169: eth1: link down
Apr  3 16:55:41 belkin NetworkManager: <info>  (eth1): device state change: 1 -> 2
Apr  3 16:55:41 belkin NetworkManager: <info>  (eth1): bringing up device.
Apr  3 16:55:41 belkin NetworkManager: <info>  (eth1): preparing device.
Apr  3 16:55:41 belkin NetworkManager: <info>  (eth1): deactivating device (reason: 2).
Apr  3 16:55:41 belkin NetworkManager: <info>  (wlan0): device state change: 1 -> 2
Apr  3 16:55:41 belkin iwl3945 0000:03:00.0: PCI INT A -> GSI 19 (level, low) -> IRQ 19
Apr  3 16:55:41 belkin NetworkManager: <info>  (wlan0): bringing up device.
Apr  3 16:55:41 belkin Registered led device: iwl-phy1:radio
Apr  3 16:55:41 belkin Registered led device: iwl-phy1:assoc
Apr  3 16:55:41 belkin Registered led device: iwl-phy1:RX
Apr  3 16:55:41 belkin Registered led device: iwl-phy1:TX
Apr  3 16:55:41 belkin NetworkManager: <info>  (wlan0): preparing device.
Apr  3 16:55:41 belkin NetworkManager: <info>  (wlan0): deactivating device (reason: 2).
Apr  3 16:55:41 belkin NetworkManager: <info>  (wlan0): device state change: 2 -> 3
Apr  3 16:55:41 belkin wlan0: direct probe to AP 00:13:f7:2c:fb:b5 try 1
Apr  3 16:55:41 belkin wlan0: direct probe to AP 00:13:f7:2c:fb:b5 try 1
Apr  3 16:55:41 belkin NetworkManager: <info>  (wlan0): supplicant interface state:  starting -> ready
Apr  3 16:55:41 belkin wlan0: direct probe to AP 00:13:f7:2c:fb:b5 try 2
Apr  3 16:55:41 belkin wlan0: direct probe to AP 00:13:f7:2c:fb:b5 try 3
Apr  3 16:55:41 belkin wlan0: direct probe to AP 00:13:f7:2c:fb:b5 timed out
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0) starting connection 'conexion'
Apr  3 16:56:06 belkin NetworkManager: <info>  (wlan0): device state change: 3 -> 4
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Apr  3 16:56:06 belkin NetworkManager: <info>  (wlan0): device state change: 4 -> 5
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0/wireless): access point 'conexion' has security, but secrets are required.
Apr  3 16:56:06 belkin NetworkManager: <info>  (wlan0): device state change: 5 -> 6
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) scheduled...
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) started...
Apr  3 16:56:06 belkin NetworkManager: <info>  (wlan0): device state change: 6 -> 4
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) scheduled...
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0) Stage 1 of 5 (Device Prepare) complete.
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) starting...
Apr  3 16:56:06 belkin NetworkManager: <info>  (wlan0): device state change: 4 -> 5
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0/wireless): connection 'conexion' has security, and secrets exist.  No new secrets needed.
Apr  3 16:56:06 belkin NetworkManager: <info>  Config: added 'ssid' value 'OOurnet'
Apr  3 16:56:06 belkin NetworkManager: <info>  Config: added 'scan_ssid' value '1'
Apr  3 16:56:06 belkin NetworkManager: <info>  Config: added 'bssid' value '00:0c:f6:1d:c9:e8'
Apr  3 16:56:06 belkin NetworkManager: <info>  Config: added 'key_mgmt' value 'NONE'
Apr  3 16:56:06 belkin NetworkManager: <info>  Config: added 'auth_alg' value 'OPEN'
Apr  3 16:56:06 belkin NetworkManager: <info>  Config: added 'wep_key0' value '<omitted>'
Apr  3 16:56:06 belkin NetworkManager: <info>  Config: added 'wep_tx_keyidx' value '0'
Apr  3 16:56:06 belkin NetworkManager: <info>  Activation (wlan0) Stage 2 of 5 (Device Configure) complete.
Apr  3 16:56:06 belkin NetworkManager: <info>  Config: set interface ap_scan to 1
Apr  3 16:56:06 belkin NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> disconnected
Apr  3 16:56:07 belkin NetworkManager: <info>  (wlan0): supplicant connection state:  disconnected -> scanning
Apr  3 16:56:08 belkin wlan0: direct probe to AP 00:0c:f6:1d:c9:e8 try 1
Apr  3 16:56:08 belkin NetworkManager: <info>  (wlan0): supplicant connection state:  scanning -> associating
Apr  3 16:56:08 belkin wlan0 direct probe responded
Apr  3 16:56:08 belkin wlan0: authenticate with AP 00:0c:f6:1d:c9:e8
Apr  3 16:56:08 belkin wlan0: authenticated
Apr  3 16:56:08 belkin wlan0: associate with AP 00:0c:f6:1d:c9:e8
Apr  3 16:56:08 belkin wlan0: RX AssocResp from 00:0c:f6:1d:c9:e8 (capab=0x431 status=0 aid=1)
Apr  3 16:56:08 belkin wlan0: associated
Apr  3 16:56:08 belkin NetworkManager: <info>  (wlan0): supplicant connection state:  associating -> associated
Apr  3 16:56:08 belkin NetworkManager: <info>  (wlan0): supplicant connection state:  associated -> completed
Apr  3 16:56:08 belkin NetworkManager: <info>  Activation (wlan0/wireless) Stage 2 of 5 (Device Configure) successful.  Connected to wireless network 'OOurnet'.
Apr  3 16:56:08 belkin NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure Start) scheduled.
Apr  3 16:56:08 belkin NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure Start) started...
Apr  3 16:56:08 belkin NetworkManager: <info>  (wlan0): device state change: 5 -> 7
Apr  3 16:56:08 belkin NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP Configure Get) scheduled...
Apr  3 16:56:08 belkin NetworkManager: <info>  Activation (wlan0) Stage 3 of 5 (IP Configure Start) complete.
Apr  3 16:56:08 belkin NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP Configure Get) started...
Apr  3 14:56:08 belkin avahi-daemon[4513]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.1.202.
Apr  3 14:56:08 belkin avahi-daemon[4513]: New relevant interface wlan0.IPv4 for mDNS.
Apr  3 14:56:08 belkin avahi-daemon[4513]: Registering new address record for 192.168.1.202 on wlan0.IPv4.
Apr  3 16:56:08 belkin NetworkManager: <info>  Activation (wlan0) Stage 5 of 5 (IP Configure Commit) scheduled...
Apr  3 16:56:08 belkin NetworkManager: <info>  Activation (wlan0) Stage 4 of 5 (IP Configure Get) complete.
Apr  3 16:56:08 belkin NetworkManager: <info>  Activation (wlan0) Stage 5 of 5 (IP Configure Commit) started...
Apr  3 16:56:09 belkin NetworkManager: <info>  (wlan0): device state change: 7 -> 8
Apr  3 16:56:09 belkin NetworkManager: <info>  Policy set 'conexion' (wlan0) as default for routing and DNS.
Apr  3 16:56:09 belkin NetworkManager: <info>  Activation (wlan0) successful, device activated.
Apr  3 16:56:09 belkin NetworkManager: <info>  Activation (wlan0) Stage 5 of 5 (IP Configure Commit) complete.

Do you still think it's a driver issue? (I want confirm it before)

Thanks a lot for your help :-)
Comment 6 Robert Piasek (RETIRED) gentoo-dev 2009-04-08 08:08:58 UTC
I don't like this line:

Apr  3 16:55:37 belkin NetworkManager: <WARN>  killswitch_getpower_reply():
Error getting killswitch power: hal-ipw-killswitch-linux returned 255.

Could you post your .config? Hal should be able to provide all required information.

R
Comment 7 Pacho Ramos gentoo-dev 2009-04-14 22:03:25 UTC
Created attachment 188364 [details]
config

Here goes

Thanks a lot :-)
Comment 8 Pacho Ramos gentoo-dev 2009-05-05 06:22:02 UTC
I have also sent this to iwlwifi upstream, but they dubt it's a driver fault:
http://www.intellinuxwireless.org/bugzilla/show_bug.cgi?id=1984
Comment 9 Pacho Ramos gentoo-dev 2009-06-05 21:04:49 UTC
Should be fixed already in trunk and 0.7 networkmanager branch per:
http://www.intellinuxwireless.org/bugzilla/show_bug.cgi?id=1984#c36

But patch doesn't apply cleanly to 0.7.1 and I cannot build branch sources as "gudev-1.0" is missing when I run ./autogen.sh:
checking for GUDEV... configure: error: Package requirements (gudev-1.0) were not met:

No package 'gudev-1.0' found

Consider adjusting the PKG_CONFIG_PATH environment variable if you
installed software in a non-standard prefix.

Alternatively, you may set the environment variables GUDEV_CFLAGS
and GUDEV_LIBS to avoid the need to call pkg-config.
See the pkg-config man page for more details.
Comment 10 Robert Piasek (RETIRED) gentoo-dev 2009-06-10 22:05:49 UTC
That should be fixed in 0.7.1-r4

Changelog:
  Backported some importent patches from NM trunk. Fixes gentoo bug #262112
  gnome bug #513820, rh bug #441070 among the others. Thanks to Pacho Ramos
  for investigating the problem (bug #262112).
Comment 11 Pacho Ramos gentoo-dev 2009-06-11 06:21:05 UTC
Thanks a lot for backporting it! :-D, I will test it as soon as I am able to