Bug 445349

Summary:	starting wpa supplicant fails
Product:	[Fedora] Fedora	Reporter:	Karl Lattimer <karl>
Component:	wpa_supplicant	Assignee:	Dan Williams <dcbw>
Status:	CLOSED CURRENTRELEASE	QA Contact:	Fedora Extras Quality Assurance <extras-qa>
Severity:	low	Docs Contact:
Priority:	low
Version:	9	CC:	djuran, henrik.hodne
Target Milestone:	---
Target Release:	---
Hardware:	All
OS:	Linux
Whiteboard:
Fixed In Version:		Doc Type:	Bug Fix
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2008-11-05 13:12:58 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:

Description Karl Lattimer 2008-05-06 12:33:05 UTC

Description of problem:
When issuing a start to wpa_supplicant it fails with
Starting wpa_supplicant: /etc/wpa_supplicant/wpa_supplicant.conf, ,
dbus_bus_request_name[dbus]: Resource temporarily unavailable
Failed to initialize wpa_supplicant
                                                           [FAILED]

Version-Release number of selected component (if applicable):
wpa_supplicant-0.6.3-5.fc9.i386


How reproducible:
Always

Steps to Reproduce:
1./etc/init.d/wpa_supplicant start

I might be missing some configuration in /etc/sysconfig/wpa_supplicant or
/etc/wpa_supplicant/wpa_supplicant.conf

Comment 1 Dan Williams 2008-05-06 13:35:18 UTC

Is the dbus service enabled?  What's the output of 'ps ax | grep dbus-daemon' ?
 If you don't care about the dbus control interface for the supplicant, just
remove the "-u" flag from /etc/sysconfig/wpa_supplicant.

Comment 2 Karl Lattimer 2008-05-06 13:46:55 UTC

yep the service is started... This is why I thought filing a bug would be a good
idea

 1900 ?        Ss     0:03 dbus-daemon --system
 2470 ?        Ss     0:00 /bin/dbus-daemon --fork --print-pid 7 --print-address
9 --session

Comment 3 Bug Zapper 2008-05-14 10:43:06 UTC

Changing version to '9' as part of upcoming Fedora 9 GA.
More information and reason for this action is here:
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Comment 4 Brennan Ashton 2008-06-08 03:12:29 UTC

Could you please reply to the previous question? If you won't reply in one
month, I will have to close this bug as INSUFFICIENT_DATA. Thank you.

Comment 5 David Juran 2008-07-22 08:48:59 UTC

I believe Karl did provide the requested information, or did I miss something?
Anyway, I think the problem comes from dbus changing it's start priority. It
used to be started as number 27(?) which is after wpa_supplicant and at some
point this changed to 22.
Running "chkconfig messagebus resetpriorities" solved the problem for me. Weird
thing though is why this didn't happen on it's own, since that is exactly what
dbus does in it's post-install script

Comment 6 Henrik Hodne 2008-08-05 11:22:35 UTC

I have the same problem

[root@dvyjones /]# wpa_supplicant -v
wpa_supplicant v0.6.3
Copyright (c) 2003-2008, Jouni Malinen <j> and contributors
[root@dvyjones /]# service wpa_supplicant start
Starting wpa-supplicant: /etc/wpa_suplicant/wpa_supplicant.conf, -iwlan0, dbus_bus_request_name[dbus]: Resouce temporarily unavailable
Failed to initialize wpa_supplicant
                                                          [FAILED]
[root@dvyjones /]# cat /etc/sysconfig/wpa_supplicant
# Use the flag "-i" before each of your interfaces, like so:
#  INTERFACES="-ieth1 -iwlan0"
INTERFACES="-iwlan0"

# Use the flag "-D" before each driver, like so:
#  DRIVERS="-Dwext"
DRIVERS=""

# Other arguments
#   -u   Enable the D-Bus interface (required for use with NetworkManager)
#   -f   Log to /var/log/wpa_supplicant.conf
OTHER_ARGS="-u -f /var/log/wpa_supplicant.conf
[root@dvyjones /]# cat /etc/wpa_supplicant/wpa_supplicant.conf
ctrl_interface=/var/run/wpa_supplicant/wpa_supplicant.conf
ctrl_interface_group=wheel
network={
        ssid="MySSID"
        #psk="MyPSK"
        psk=<The PSK-Hash generated by wpa_passphrase>
}

[root@dvyjones /]# cat /var/log/wpa_supplicant.log
CTRL-EVENT-SCAN-RESULTS 
WPA: No SSID info found (msg 1 of 4).
WPA: No SSID info found (msg 1 of 4).
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
CTRL-EVENT-SCAN-RESULTS 
Associated with 00:11:50:39:81:5f
WPA: Invalid EAPOL-Key MIC when using TPTK - ignoring TPTK
WPA: Could not verify EAPOL-Key MIC - dropping packet
WPA: Invalid EAPOL-Key MIC when using TPTK - ignoring TPTK
WPA: Could not verify EAPOL-Key MIC - dropping packet
WPA: Invalid EAPOL-Key MIC when using TPTK - ignoring TPTK
WPA: Could not verify EAPOL-Key MIC - dropping packet
WPA: 4-Way Handshake failed - pre-shared key may be incorrect
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
WPA: Invalid EAPOL-Key MIC when using TPTK - ignoring TPTK
WPA: Could not verify EAPOL-Key MIC - dropping packet
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Associated with 00:11:50:39:81:5f
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
CTRL-EVENT-SCAN-RESULTS 
Authentication with 00:11:50:39:81:5f timed out.
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
CTRL-EVENT-SCAN-RESULTS 
Authentication with 00:00:00:00:00:00 timed out.
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
No network configuration found for the current AP
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
WPA: EAPOL-Key Replay Counter did not increase - dropping packet
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
CTRL-EVENT-SCAN-RESULTS 
Authentication with 00:11:50:39:81:5f timed out.
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
CTRL-EVENT-TERMINATING - signal 15 received
Could not request DBus service name: already registered.
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Associated with 00:11:50:39:81:5f
WPA: 4-Way Handshake failed - pre-shared key may be incorrect
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Associated with 00:11:50:39:81:5f
WPA: 4-Way Handshake failed - pre-shared key may be incorrect
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Authentication with 00:11:50:39:81:5f timed out.
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Authentication with 00:11:50:39:81:5f timed out.
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
CTRL-EVENT-SCAN-RESULTS 
Authentication with 00:00:00:00:00:00 timed out.
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
CTRL-EVENT-SCAN-RESULTS 
Authentication with 00:11:50:39:81:5f timed out.
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Associated with 00:11:50:39:81:5f
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Associated with 00:11:50:39:81:5f
CTRL-EVENT-SCAN-RESULTS 
WPA: 4-Way Handshake failed - pre-shared key may be incorrect
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Authentication with 00:11:50:39:81:5f timed out.
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Authentication with 00:11:50:39:81:5f timed out.
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
CTRL-EVENT-TERMINATING - signal 15 received
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Authentication with 00:11:50:39:81:5f timed out.
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
CTRL-EVENT-SCAN-RESULTS 
Authentication with 00:11:50:39:81:5f timed out.
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Authentication with 00:11:50:39:81:5f timed out.
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Authentication with 00:11:50:39:81:5f timed out.
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Authentication with 00:11:50:39:81:5f timed out.
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Authentication with 00:11:50:39:81:5f timed out.
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Associated with 00:11:50:39:81:5f
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
CTRL-EVENT-DISCONNECTED - Disconnect event - remove keys
Authentication with 00:00:00:00:00:00 timed out.
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Authentication with 00:11:50:39:81:5f timed out.
CTRL-EVENT-SCAN-RESULTS 
Trying to associate with 00:11:50:39:81:5f (SSID='ETNet' freq=2447 MHz)
Authentication with 00:00:00:00:00:00 timed out.
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-TERMINATING - signal 15 received
Could not request DBus service name: already registered.
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
Could not request DBus service name: already registered.
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
CTRL-EVENT-SCAN-RESULTS 
[root@localhost /]# ps ax | grep dbus-daemon
 1946 ?        Ssl    0:01 dbus-daemon --system
 2745 ?        Ssl    0:00 /bin/dbus-daemon --fork --print-pid 7 --print-adress 9 --session
 4657 pts/1    R+     0:00 grep dbus-daemon

Comment 7 Karl Lattimer 2008-11-05 12:54:15 UTC

no longer an issue for me