wlan not activated

[didomax]

Good morning all!

I am impressed by moodeaudio and I am almost there to get it working

I have a wifi dongle attached to my Rpi3 - it is well recognized and I am able to scan and select my network. However, after restart it is not activated, i.e. it is not used, even if I pull off the LAN cable and I set "wait for eth0" off.

Login onto the system, and I can see

pi@moode:~ $ iwconfig wlan0  
wlan0     unassociated  ESSID:""  Nickname:"<WIFI@REALTEK>"
          Mode:Auto  Frequency=2.412 GHz  Access Point: Not-Associated    
          Sensitivity:0/0   
          Retry:off   RTS thr:off   Fragment thr:off
          Power Management:off
          Link Quality:0  Signal level:0  Noise level:0
          Rx invalid nwid:0  Rx invalid crypt:0  Rx invalid frag:0
          Tx excessive retries:0  Invalid misc:0   Missed beacon:0

wpa_supi@moode:~ $ systemctl status wpa_supplicant
● wpa_supplicant.service - WPA supplicant
   Loaded: loaded (/lib/systemd/system/wpa_supplicant.service; enabled; vendor p
   Active: active (running) since Sat 2021-02-06 09:42:40 CET; 13min ago
 Main PID: 400 (wpa_supplicant)
    Tasks: 1 (limit: 2063)
   CGroup: /system.slice/wpa_supplicant.service
           └─400 /sbin/wpa_supplicant -u -s -O /run/wpa_supplicant
 
Feb 06 09:42:40 moode systemd[1]: Starting WPA supplicant...
Feb 06 09:42:40 moode wpa_supplicant[400]: Successfully initialized wpa_supplica
Feb 06 09:42:40 moode systemd[1]: Started WPA supplicant.
pi@moode:~ $ systemctl status dhcpcd
● dhcpcd.service - dhcpcd on all interfaces
   Loaded: loaded (/lib/systemd/system/dhcpcd.service; enabled; vendor preset: enabled)
  Drop-In: /etc/systemd/system/dhcpcd.service.d
           └─wait.conf
   Active: active (running) since Sat 2021-02-06 09:42:51 CET; 14min ago
 Main PID: 522 (dhcpcd)
    Tasks: 1 (limit: 2063)
   CGroup: /system.slice/dhcpcd.service
           └─522 /sbin/dhcpcd -q -w
 
Feb 06 09:42:51 moode dhcpcd[377]: eth0: leased 192.168.178.56 for 864000 seconds
Feb 06 09:42:51 moode dhcpcd[377]: eth0: adding route to 192.168.178.0/24
Feb 06 09:42:51 moode dhcpcd[377]: eth0: adding default route via 192.168.178.1
Feb 06 09:42:51 moode dhcpcd[377]: Too few arguments.
Feb 06 09:42:51 moode dhcpcd[377]: Too few arguments.
Feb 06 09:42:51 moode dhcpcd[377]: Failed to get unit file state for ntp.service: No such file or directory
Feb 06 09:42:51 moode dhcpcd[377]: forked to background, child pid 522
Feb 06 09:42:51 moode systemd[1]: Started dhcpcd on all interfaces.
Feb 06 09:43:25 moode dhcpcd[522]: eth0: fe80::5e49:79ff:fe37:47bc is reachable again
Feb 06 09:43:25 moode dhcpcd[522]: eth0: fe80::5e49:79ff:fe37:47bc is reachable again

So, apart from the "Too few arguments" error/warning, I cannot see anything wrong.

If I manually execute

pi@moode:~ $ sudo iwconfig wlan0 essid MyNet
pi@moode:~ $ sudo ifconfig wlan0
wlan0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
        inet 169.254.238.30  netmask 255.255.0.0  broadcast 169.254.255.255
        inet6 fe80::a41f:e666:fe48:3cc7  prefixlen 64  scopeid 0x20<link>
        ether 3c:7c:3f:3c:64:1a  txqueuelen 1000  (Ethernet)
        RX packets 122  bytes 14743 (14.3 KiB)
        RX errors 0  dropped 317  overruns 0  frame 0
        TX packets 48  bytes 13069 (12.7 KiB)
        TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0

Any idea why my wifi does not get automatically activated?

Thanks!
Max

[Tim Curtis]

You have "Access Point: Not-Associated" error. Check your Router WiFi log for errors.

The 169.254.x.x address thats assigned after manually bringing up wlan0 is an Automatic Private IP address (APIPA). This address is only assigned when the client is unable to receive an address from your Router DHCP service.

[TheOldPresbyope]

Also, comparing with one of my players I note the following anomaly in your systemctl status dhcpcd output

From your output

Code:

pi@moode:~ $ systemctl status dhcpcd
● dhcpcd.service - dhcpcd on all interfaces
  Loaded: loaded (/lib/systemd/system/dhcpcd.service; enabled; vendor preset: enabled)
 Drop-In: /etc/systemd/system/dhcpcd.service.d
          └─wait.conf
  Active: active (running) since Sat 2021-02-06 09:42:51 CET; 14min ago
Main PID: 522 (dhcpcd)
   Tasks: 1 (limit: 2063)
  CGroup: /system.slice/dhcpcd.service
          └─522 /sbin/dhcpcd -q -w

while from my output

Code:

pi@moode:~ $ systemctl status dhcpcd
● dhcpcd.service - dhcpcd on all interfaces
  Loaded: loaded (/lib/systemd/system/dhcpcd.service; enabled; vendor preset: enabled)
 Drop-In: /etc/systemd/system/dhcpcd.service.d
          └─wait.conf
  Active: active (running) since Sat 2021-02-06 09:22:49 EST; 6min ago
Main PID: 465 (dhcpcd)
   Tasks: 2 (limit: 1894)
  CGroup: /system.slice/dhcpcd.service
          ├─435 wpa_supplicant -B -c/etc/wpa_supplicant/wpa_supplicant.conf -iwlan0 -Dnl80211,wext
          └─465 /sbin/dhcpcd -q -w

What happened to your wpa_supplicant process???

Regards,
Kent

[Tim Curtis]

It prolly won't start or was killed cos the AP association failed. When an AP association fails its typically due to bad user credentials i.e. user name or password. This usually shows up in Router WiFi log messages.

Other causes for AP rejecting an association are usually related to network config, timeouts, etc.

[TheOldPresbyope]

I guess I was being too subtle. It was meant to suggest checking syslog for messages concerning wpa_supplicant.

[didomax]

All,

thanks a lot for all your replies!

A couple of comments

• ESSID/PSK are ok, otherwise it would not connect from command line
  

• wpa_supplicant starts with a different commandline compared to what @TheOldPresbyope  mentioned, see my systemctl output below
  

Code:

  CGroup: /system.slice/wpa_supplicant.service
          └─400 /sbin/wpa_supplicant -u -s -O /run/wpa_supplicant

 
So, no options -iwlan0, -B, -D... why? @TheOldPresbyope , which version are you using? I am on the 7.0.1.

Btw, before reading your posts I already modified the systemd script

Code:

[Service]
Type=dbus
BusName=fi.w1.wpa_supplicant1
ExecStart=/sbin/wpa_supplicant -Dwext -u -s -O /run/wpa_supplicant -c /etc/wpa_supplicant/wpa_supplicant.conf -iwlan0

adding the driver wext, at the nl80211 showed errors in the syslog. Now it works, although not as nice as yours (7€ dongle, not the highest quality)

Code:

pi@moode:~ $ systemctl status wpa_supplicant
● wpa_supplicant.service - WPA supplicant
  Loaded: loaded (/lib/systemd/system/wpa_supplicant.service; enabled; vendor preset: enabled)
  Active: active (running) since Sat 2021-02-06 19:18:39 CET; 3s ago
Main PID: 2847 (wpa_supplicant)
   Tasks: 1 (limit: 2063)
  CGroup: /system.slice/wpa_supplicant.service
          └─2847 /sbin/wpa_supplicant -Dnl80211,wext -u -s -O /run/wpa_supplicant -c /etc/wpa_supplicant/wpa_supplicant.conf -iwlan0

Feb 06 19:18:39 moode wpa_supplicant[2847]: rfkill: Cannot get wiphy information
Feb 06 19:18:39 moode wpa_supplicant[2847]: ioctl[SIOCSIWAP]: Operation not permitted
Feb 06 19:18:39 moode wpa_supplicant[2847]: ioctl[SIOCSIWENCODEEXT]: Invalid argument
Feb 06 19:18:39 moode wpa_supplicant[2847]: ioctl[SIOCSIWENCODEEXT]: Invalid argument
Feb 06 19:18:40 moode wpa_supplicant[2847]: wlan0: Trying to associate with 5c:49:79:37:47:be (SSID='MyNet' freq=2462 MHz)
Feb 06 19:18:40 moode wpa_supplicant[2847]: Failed to add supported operating classes IE
Feb 06 19:18:40 moode wpa_supplicant[2847]: wlan0: Association request to the driver failed
Feb 06 19:18:41 moode wpa_supplicant[2847]: wlan0: Associated with 5c:49:79:37:47:be
Feb 06 19:18:42 moode wpa_supplicant[2847]: wlan0: WPA: Key negotiation completed with 5c:49:79:37:47:be [PTK=CCMP GTK=CCMP]
Feb 06 19:18:42 moode wpa_supplicant[2847]: wlan0: CTRL-EVENT-CONNECTED - Connection to 5c:49:79:37:47:be completed [id=0 id_str=]

Is this a bug in the systemd script I can report? I did not mess around with that file before  

Thanks
Max

[TheOldPresbyope]

@didomax

I quoted from a moOde 7.0.1 installation on an RPi4B using the internal WiFi transceiver. As an aside, I just got the same systemctl output from a moOde 6.5.2 player I spun up for a different test on an RPi3B+ also using the internal WiFi transceiver.

Note that looking at the statuses of dhcpcd and wpa_supplicant gives you information about two different instances of wpa_supplicant. In fact, once invoked, both instances are running on my player

Code:

pi@moode: $ ps aux|grep wpa_sup
root       345  0.0  0.4  10740  3932 ?        Ss   09:22   0:00 /sbin/wpa_supplicant -u -s -O /run/wpa_supplicant
root       435  0.0  0.3  11352  3456 ?        Ss   09:22   0:00 wpa_supplicant -B -c/etc/wpa_supplicant/wpa_supplicant.conf -iwlan0 -Dnl80211,wext

It's been a while and I've forgotten why two instances. The arguments in the second invocation come from /lib/systemd/system/wpa_supplicant@.service (I think this is the only place but I've been known to be wrong before) which includes the line

Code:

ExecStart=/sbin/wpa_supplicant -c/etc/wpa_supplicant/wpa_supplicant-%I.conf -Dnl80211,wext -i%I

There have been occasional posts from users running into problems with WiFi dongles based on certain chipsets. The dongles were often but not always old and/or cheap. IIRC the usual cause of their problems was the transceiver chipset not working in AP mode. I have no insight into what's happening with yours.

Regards,
Kent

[didomax]

@TheOldPresbyope 

you must be right - it could be due to my cheap dongle. Unfortunately my internal WiFi does not work, I have a version of the Rpi3 affected by a known firmware error (as far as I can understand), hence my move to an external device.

I will work with workaround, not a big issue. I am going to post other challenges soon


Max

[Tim Curtis]

All,

thanks a lot for all your replies!

A couple of comments

• ESSID/PSK are ok, otherwise it would not connect from command line
  

• wpa_supplicant starts with a different commandline compared to what @TheOldPresbyope  mentioned, see my systemctl output below
  

Code:

  CGroup: /system.slice/wpa_supplicant.service
          └─400 /sbin/wpa_supplicant -u -s -O /run/wpa_supplicant

 
So, no options -iwlan0, -B, -D... why? @TheOldPresbyope , which version are you using? I am on the 7.0.1.

Btw, before reading your posts I already modified the systemd script

Code:

[Service]
Type=dbus
BusName=fi.w1.wpa_supplicant1
ExecStart=/sbin/wpa_supplicant -Dwext -u -s -O /run/wpa_supplicant -c /etc/wpa_supplicant/wpa_supplicant.conf -iwlan0

adding the driver wext, at the nl80211 showed errors in the syslog. Now it works, although not as nice as yours (7€ dongle, not the highest quality)

Code:

pi@moode:~ $ systemctl status wpa_supplicant
● wpa_supplicant.service - WPA supplicant
  Loaded: loaded (/lib/systemd/system/wpa_supplicant.service; enabled; vendor preset: enabled)
  Active: active (running) since Sat 2021-02-06 19:18:39 CET; 3s ago
Main PID: 2847 (wpa_supplicant)
   Tasks: 1 (limit: 2063)
  CGroup: /system.slice/wpa_supplicant.service
          └─2847 /sbin/wpa_supplicant -Dnl80211,wext -u -s -O /run/wpa_supplicant -c /etc/wpa_supplicant/wpa_supplicant.conf -iwlan0

Feb 06 19:18:39 moode wpa_supplicant[2847]: rfkill: Cannot get wiphy information
Feb 06 19:18:39 moode wpa_supplicant[2847]: ioctl[SIOCSIWAP]: Operation not permitted
Feb 06 19:18:39 moode wpa_supplicant[2847]: ioctl[SIOCSIWENCODEEXT]: Invalid argument
Feb 06 19:18:39 moode wpa_supplicant[2847]: ioctl[SIOCSIWENCODEEXT]: Invalid argument
Feb 06 19:18:40 moode wpa_supplicant[2847]: wlan0: Trying to associate with 5c:49:79:37:47:be (SSID='MyNet' freq=2462 MHz)
Feb 06 19:18:40 moode wpa_supplicant[2847]: Failed to add supported operating classes IE
Feb 06 19:18:40 moode wpa_supplicant[2847]: wlan0: Association request to the driver failed
Feb 06 19:18:41 moode wpa_supplicant[2847]: wlan0: Associated with 5c:49:79:37:47:be
Feb 06 19:18:42 moode wpa_supplicant[2847]: wlan0: WPA: Key negotiation completed with 5c:49:79:37:47:be [PTK=CCMP GTK=CCMP]
Feb 06 19:18:42 moode wpa_supplicant[2847]: wlan0: CTRL-EVENT-CONNECTED - Connection to 5c:49:79:37:47:be completed [id=0 id_str=]

Is this a bug in the systemd script  I can report? I did not mess around with that file before  

Thanks
Max

In your earlier post your cmd line try resulted in an APIPA 169.254.x.x address and not a legit DHCP issued address from your Router. This is not a successful connection and suggests a network issue.