I am failing to use a FRITZ!WLAN USB Stick N to connect my Raspberry Pi 1B to my wireless network. I see several problems, but am unable to locate and eliminate the root cause. The problem is reproducible on a Raspberyy Pi 3B.
At the end of the boot process, the wireless network is not available, the network device is shown by ifconfig, but without IP address. iwconfig reports
wlan0 IEEE 802.11abgn ESSID:off/any
Mode:Managed Access Point: Not-Associated Tx-Power=20 dBm
Retry short limit:7 RTS thr:off Fragment thr:off
Power Management:off
Manual Fix (works)
If I bring wlan0 up manually with ifup wlan0, everything works just fine and the machine connects to my network (trying to leave out hopefully irrelevant stuff):
wpa_supplicant[854]: Successfully initialized wpa_supplicant
dhclient: Internet Systems Consortium DHCP Client 4.3.1
dhclient: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 8
wpa_supplicant[855]: wlan0: Associated with xx:xx:xx:xx:xx:xx
wpa_supplicant[855]: wlan0: WPA: Key negotiation completed with xx:xx:xx:xx:xx:xx [PTK=CCMP GTK=CCMP]
[...]
wpa_supplicant[855]: wlan0: CTRL-EVENT-CONNECTED - Connection to xx:xx:xx:xx:xx:xx completed [id=0 id_str=]
dhcpcd[485]: wlan0: carrier acquired
wpa_supplicant[855]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=DE
dhcpcd[485]: wlan0: adding address xxxx::xxxx:xxxx:xxxx:xxxx
dhcpcd[485]: wlan0: IAID 43:0d:1f:fd
dhcpcd[485]: wlan0: rebinding lease of xxx.xxx.x.xx
dhcpcd[485]: wlan0: soliciting an IPv6 router
dhclient: DHCPREQUEST on wlan0 to 255.255.255.255 port 67
dhclient: bound to xxx.xxx.x.xx -- renewal in 335050 seconds.
However, I would like to let the (headless) system boot and connect unsupervised.
Hypothesis
Maybe the problem is that the USB stick changes its USB ID after loading its firmware?
syslog tells me that the stick is recognized early in the boot process (t=4.2s) having idVendor=057c and idProduct=84ff. Right after that (t=5.3s), a SCSI CD-ROM with the label "FRITZ! WLAN selfinstall 1.00 PQ: 0 ANSI: 0 CCS" is detected. I guess that the stick itself provides that drive to let the machine load some USB chip firmware.
At some point between t=12s and t=15.5s, _wpa_supplicant_ tries to bring up the networking device but fails:
wpa_supplicant[264]: Successfully initialized wpa_supplicant
wpa_supplicant[264]: Could not read interface wlan0 flags: No such device
wpa_supplicant[264]: nl80211: Driver does not support authentication/association or connect commands
wpa_supplicant[264]: Could not read interface wlan0 flags: No such device
wpa_supplicant[264]: WEXT: Could not set interface 'wlan0' UP
wpa_supplicant[264]: wlan0: Failed to initialize driver interface networking[198]: Configuring network interfaces...wpa_supplicant: /sbin/wpa_supplicant daemon failed to start
networking[198]: run-parts: /etc/network/if-pre-up.d/wpasupplicant exited with return code 1
networking[198]: Failed to bring up wlan0.
networking[198]: done.
Much later (t=30s) the USB device disconnects and reconnects showing idVendor=057c, idProduct=8401. Soon after (t=34.2s), dhcpcd tries again but fails to connect to the network:
dhcpcd[484]: wlan0: adding address xxxx::xxxx:xxxx:xxxx:xxxx
dhcpcd[484]: wlan0: waiting for carrier
kernel: [ 35.199371] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
khcpcd[484]: wlan0: carrier acquired
dhcpcd[484]: wlan0: IAID 43:0d:1f:fd
dhcpcd[484]: wlan0: carrier lost
dhcpcd[484]: wlan0: deleting address xxxx::xxxx:xxxx:xxxx:xxxx
Why does it fail? I fail to come up with a proper idea.
Sitting it out (does not work)
Tried to set up my fallback solution: let ifup wlan0 being called as systemd service. Created /etc/systemd/system/fritz.wlan.service to start a shell script as late as possible:
[Unit]
Description=Fritz WLAN Stick N
After=ntp.target multi-user.target
[Service]
Type=oneshot
ExecStartPre=/bin/sleep 5
ExecStart=/usr/local/bin/fritz.wlan.sh
[Install]
WantedBy=multi-user.target
and a shell script /usr/local/bin/fritz.wlan.sh:
#!/bin/sh
/bin/sleep 660
iwconfig 2>&1 | grep ESSID:\"xxx > /dev/null || ifup wlan0 2>&1 >> /var/log/fritz.wlan.log
This leads to no success. The script is started right after multi-user.target. syslog tells me that the device was brought up and a DHCP lease was acquired, but soon after, the kernel decides to deauthenticate the device which unwinds the whole connection:
kernel: [ 717.685006] wlan0: deauthenticating from e0:28:6d:37:3e:f5 by local choice (Reason: 3=DEAUTH_LEAVING)
dhcpcd[465]: wlan0: carrier lost
wpa_supplicant[1330]: wlan0: CTRL-EVENT-DISCONNECTED bssid=e0:28:6d:37:3e:f5 reason=3 locally_generated=1
Hrmph. Later, systemd states that the initialization process finished. Not earlier. Well, however.
systemd[1]: Started Fritz WLAN Stick N.
systemd[1]: Startup finished in 3.332s (kernel) + 11min 54.388s (userspace) = 11min 57.720s.
Can it be that the problem comes up when ifup wlan0 is started by systemd and not by an interactive root shell?
Hacky (but working) Fallback
cron creates /var/run/fritz.wlan at reboot time. Another cron job lets a shell script check the existance of this file every minute. To always have a minute delay, this script touches /var/run.fritz.wlan.2 and removes the first file and exits. When being called next minute with the second file existing, the script calls ifup wlan0, removes the second file and exits.
Improvement would be to even remove the cron job which fires the script every minute.
Still, I would like to fully understand the problem and find a proper solution. Any suggestions?
