FreeBSD 10.0-R: wpa_supplicant doesn't work when starts from ifconfig_wlan0-"WPA DHCP mode 11g"

[Lev Serebryakov]

Hello, Freebsd-wireless.

  I'm trying to use FreeBSD 10.-RELEASE (installed from installation media,
 which is unusual for me) as desktop system on old Sony Vaio laptop.

  This laptop is equipped with:

wpi0: <Intel(R) PRO/Wireless 3945ABG> mem 0xde100000-0xde100fff irq 17 at device 0.0 on pci6

  I have these lines in /etc/rc.conf:

====
wlans_wpi0="wlan0"
create_args_wlan0="wlanmode sta"
ifconfig_wlan0="WPA DHCP mode 11g"
ifconfig_wlan0_ipv6="inet6 accept_rtadv"
====

 Of course, I have entry for my home network in /etc/wpa_supplicant.conf:

====
ctrl_interface=/var/run/wpa_supplicant
eapol_version=2
ap_scan=1
fast_reauth=1

network={
        ssid="home.serebryakov.spb.ru"
        proto=WPA2
        key_mgmt=WPA-PSK
        psk="XXXXX"
}
====

  When system boots, it try to start wpa_supplicant, but it shows only:

====
wlan0: Ethernet address: 00:18:de:08:e8:1d
wpi0: need multicast update callback
Starting wpa_supplicant
wpi0: need multicast update callback
msk0: link state changed to DOWN
Starting Networl: lo0 wpi0 msk0
lo0: ...
wpi0: ...
msk0: ...
====

 Please, note: no wlan0 here!

 Also, wpa_supplicant shows a TONS of this:

Feb  7 01:10:36 labrat wpa_supplicant[476]: ioctl[SIOCS80211, op=103, val=0, arg_len=128]: Operation now in progress
Feb  7 01:10:36 labrat wpa_supplicant[476]: wlan0: Failed to initiate AP scan

 And works forever! No association, only channel is switched in rounds and
rounds and all these messages!

 If I login as root to consoleand stop/start wpa_supplicant by hands, it
 associate and works perfectly!

root at labrat:~ # /etc/rc.d/wpa_supplicant stop wlan0 && /etc/rc.d/wpa_supplicant start wlan0

 And after that I have access to my network:

Feb  7 01:11:24 labrat wpa_supplicant[476]: ioctl[SIOCS80211, op=26, val=0, arg_len=0]: Operation not supported
Feb  7 01:11:24 labrat wpa_supplicant[476]: ioctl[SIOCS80211, op=26, val=0, arg_len=0]: Operation not supported
Feb  7 01:11:24 labrat wpa_supplicant[476]: wlan0: CTRL-EVENT-TERMINATING 
Feb  7 01:11:29 labrat wpa_supplicant[1316]: Successfully initialized wpa_supplicant
Feb  7 01:11:29 labrat wpa_supplicant[1317]: wlan0: Trying to associate with 00:15:6d:85:5f:fc (SSID='home.serebryakov.spb.ru' freq=2422 MHz)
Feb  7 01:11:29 labrat wpa_supplicant[1317]: wlan0: Associated with 00:15:6d:85:5f:fc
Feb  7 01:11:29 labrat kernel: wlan0: link state changed to UP
Feb  7 01:11:29 labrat devd: Executing '/etc/rc.d/dhclient quietstart wlan0'
Feb  7 01:11:29 labrat wpa_supplicant[1317]: wlan0: WPA: Key negotiation completed with 00:15:6d:85:5f:fc [PTK=CCMP GTK=CCMP]
Feb  7 01:11:29 labrat wpa_supplicant[1317]: wlan0: CTRL-EVENT-CONNECTED - Connection to 00:15:6d:85:5f:fc completed [id=0 id_str=]
Feb  7 01:11:30 labrat kernel: wpi0: need multicast update callback
Feb  7 01:11:30 labrat dhclient: New IP Address (wlan0): 192.168.135.65
Feb  7 01:11:30 labrat kernel: wpi0: need multicast update callback
Feb  7 01:11:30 labrat kernel: wpi0: need multicast update callback
Feb  7 01:11:30 labrat dhclient: New Subnet Mask (wlan0): 255.255.255.0
Feb  7 01:11:30 labrat dhclient: New Broadcast Address (wlan0): 192.168.135.255
Feb  7 01:11:30 labrat dhclient: New Routers (wlan0): 192.168.135.1

  What does go wrong with wpa_supplicant started by /etc/rc?

-- 
// Black Lion AKA Lev Serebryakov <lev at FreeBSD.org>