double initialisation of wireless network interface on startup?

From: Szilveszter Adam <sziszi_at_bsd.hu>
Date: Sat, 3 May 2008 07:20:40 +0200
Hello everybody,

I have recently noticed an oddity in connection with the initialisation
of the wireless network interface upon startup: it seems to be initialised
twice. I do not claim that this only started now, but this behaviour
started to cause problems now, with the introduction of the updated
multi-bss code. 

Here is the version of -CURRENT I am running on this i386 UP machine:

Copyright (c) 1992-2008 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
	The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 8.0-CURRENT #0: Fri May  2 08:06:39 CEST 2008
    sziszi_at_baranyfelhocske.buza.adamsfamily.xx:/usr/obj/usr/home/sziszi/freebsd/build/src/sys/BARANYFELHOCSKE-DEBUG

I have the following physical network interfaces in the machine (all of them
built-in, none removable):

iwi0: <Intel(R) PRO/Wireless 2200BG> mem 0xd0200000-0xd0200fff irq 11 at device 2.0 on pci2
iwi0: [ITHREAD]
fxp0: <Intel 82801DB (ICH4) Pro/100 VE Ethernet> port 0x7000-0x703f mem 0xd0201000-0xd0201fff irq 11 at device 8.0 on pci2
miibus0: <MII bus> on fxp0
inphy0: <i82562ET 10/100 media interface> PHY 1 on miibus0
inphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
fxp0: Ethernet address: 00:0a:e4:34:80:30
fxp0: [ITHREAD]

I configure them with static IPs, using the following lines in rc.conf:

wlans_iwi0=wlan0
ifconfig_fxp0="inet 192.168.3.4  netmask 255.255.255.0"
ifconfig_wlan0="WPA inet 192.168.2.4 netmask 255.255.255.0 indoor
wlanmode sta country HU"
defaultrouter="192.168.2.1"
network_interfaces="AUTO"

Now, here is what gets logged on the console during startup (The fxp0
interface is not plugged in, so it correctly notes no carrier):

lo0: flags=8049<UP,LOOPBACK,RUNNING,MULTICAST> metric 0 mtu 16384
     inet6 fe80::1%lo0 prefixlen 64 scopeid 0x3
     inet6 ::1 prefixlen 128
     inet 127.0.0.1 netmask 0xff000000
wlan0: Ethernet address: 00:16:6f:05:c7:d3
iwi0: need multicast update callback
Starting wpa_supplicant.
wlan0: flags=8802<BROADCAST,SIMPLEX,MULTICAST> metric 0 mtu 1500
       ether 00:16:6f:05:c7:d3
       inet 192.168.2.4 netmask 0xffffff00 broadcast 192.168.2.255
       media: IEEE 802.11 Wireless Ethernet autoselect (autoselect)
       status: no carrier
       ssid "" channel 6 (2437 Mhz 11g)
       regdomain ETSI country HU indoor authmode WPA1+WPA2/802.11i
       privacy ON deftxkey UNDEF txpower 30 bmiss 24 scanvalid 60
       protmode CTS wme roaming MANUAL
iwi0: flags=8802<BROADCAST,SIMPLEX,MULTICAST> metric 0 mtu 2290
      ether 00:16:6f:05:c7:d3
      media: IEEE 802.11 Wireless Ethernet autoselect (autoselect)
      status: no carrier
fxp0: link state changed to DOWN
fxp0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu
1500
        options=8<VLAN_MTU>
        ether 00:0a:e4:34:80:30
        inet 192.168.3.4 netmask 0xffffff00 broadcast 192.168.3.255
        media: Ethernet autoselect (none)
        status: no carrier
add net default: gateway 192.168.2.1
Additional routing options:.
Starting devd.
ifconfig: SIOCIFCREATE2: File exists
iwi0: need multicast update callback
iwi0: need multicast update callback
wpa_supplicant already running? (pid=356).
wlan0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu
1500
        ether 00:16:6f:05:c7:d3
        inet 192.168.2.4 netmask 0xffffff00 broadcast 192.168.2.255
        media: IEEE 802.11 Wireless Ethernet autoselect (autoselect)
        status: no carrier
        ssid "" channel 1 (2412 Mhz 11b)
        regdomain ETSI country HU indoor authmode WPA1+WPA2/802.11i 
        privacy ON deftxkey UNDEF txpower 30 bmiss 24 scanvalid 60 wme
        roaming MANUAL
iwi0: flags=8803<UP,BROADCAST,SIMPLEX,MULTICAST> metric 0 mtu 2290
        ether 00:16:6f:05:c7:d3
        media: IEEE 802.11 Wireless Ethernet autoselect mode 11b
        status: associated

What I have been able to decipher from this is that first the
/etc/rc.d/netif script gets run, it starts all network interfaces it
finds. This is what we see at the top. It causes wlan0 to be created and
starts wpa_supplicant on it. Of course, association takes a while, and
is not yet finished at the time these console lines are printed. After
this, the /etc/rc.d/routing script gets run, and adds the default route.

However, after this soon devd gets started. And for some reason it
restarts the wireless network interface as can be seen below the 
"starting devd" line.

Devd runs /etc/pccard_ether on iwi0. Of course, wlan0 already exists, so
the cloning operation fails (ifconfig: SIOCIFCREATE2: File exists) and
wpa_supplicant is also running already, so it also complains and exits.
(wpa_supplicant already running? (pid=356))

After this, the wlan0 interface gets associated eventually, but due to
the devd intervention, the routing table got blown away, yet the
pccard_ether script could not run to its end, and so we are stuck with
no default route. This necessitates the manual rerunning of the
"routing" rc.d script.

This is of course not very convenient, and I wonder what it may be
caused by, since I have not seen anything like it before 21st April. I
have re-checked the configuration and believe it is correct according to
the "new world order" with regard to wireless. (But of course I am
grateful for any hints also in that direction.) I have also tested the
"netif" and the "pccard_ether" scripts on their own, they work as they
should. I also checked execution order of the rc.d scripts using
rcorder, nothing suspicous there either.

Any ideas?

-- 
Regards:

Szilveszter ADAM
Budapest
Hungary
Received on Sat May 03 2008 - 03:52:35 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:39:30 UTC