Wifi Client Fails to get IP address

[notlistening]

Hi, been trying out your project as a test and I've got stuck.

I can run it up on my device and can take away the Ethernet connectivity, the AP appears as documented, but then when trying to connect my phone onto the AP it stalls saying Obtaining IP Address and never completes.

The setup I have is Alpine Linux latest, with network manager and iwd. I am running as root with all default settings. The wifi interface has been set with the default gateway IP. After that I am a bit stuck.

[2023-05-18T23:49:11Z INFO ] Wireless device on 'wlan0'
[2023-05-18T23:49:11Z INFO ] Starting up. Network manager reports state Connected
[2023-05-18T23:49:11Z INFO ] Current connectivity: Ok(Connected)
[2023-05-18T23:49:11Z DEBUG] Create stream 1 - type='signal',path='/org/freedesktop/NetworkManager',interface='org.freedesktop.NetworkManager',member='StateChanged' ...
[2023-05-18T23:49:11Z DEBUG] Wake up stream 1, queue: 0
[2023-05-18T23:49:28Z DEBUG] Add to stream 1, queue: 1
[2023-05-18T23:49:28Z DEBUG] Wake up stream 1, queue: 1
[2023-05-18T23:49:28Z DEBUG] Drop stream 1...
[2023-05-18T23:49:28Z INFO ] No connection found. Trying to reestablish
[2023-05-18T23:49:28Z DEBUG] Trying to connect to one of 5 known connections ...
[2023-05-18T23:49:28Z DEBUG] Create stream 2 - type='signal',path='/org/freedesktop/NetworkManager',interface='org.freedesktop.NetworkManager',member='StateChanged' ...
[2023-05-18T23:49:28Z DEBUG] Wake up stream 2, queue: 0
[2023-05-18T23:49:38Z DEBUG] Wake up stream 2, queue: 0
[2023-05-18T23:49:38Z DEBUG] Drop stream 2...
[2023-05-18T23:49:38Z WARN ] Portal SSID/Password file given, but file is not readable!
[2023-05-18T23:49:38Z INFO ] Acquire wifi access point list. This may take a minute ...
[2023-05-18T23:49:38Z INFO ] Found AP "VM8547037"
[2023-05-18T23:49:38Z INFO ] Found AP "HAL9001"
[2023-05-18T23:49:38Z INFO ] Found AP "VMESH-0515-wifi"
[2023-05-18T23:49:38Z INFO ] Found AP "VMESH-1528-wifi"
[2023-05-18T23:49:38Z INFO ] Found AP "VMESH-1528"
[2023-05-18T23:49:38Z INFO ] Found AP "HAL9000"
[2023-05-18T23:49:38Z INFO ] Found AP "Virgin Media"
[2023-05-18T23:49:38Z INFO ] Found AP "VM7239289"
[2023-05-18T23:49:38Z INFO ] Found AP "2.4G"
[2023-05-18T23:49:38Z DEBUG] Configuring hotspot ...
[2023-05-18T23:49:38Z INFO ] Starting hotspot ...
[2023-05-18T23:49:38Z DEBUG] Wait for hotspot to settle ... Activating
[2023-05-18T23:49:38Z DEBUG] Create stream 3 - type='signal',interface='org.freedesktop.NetworkManager.Connection.Active',member='StateChanged' ...
[2023-05-18T23:49:38Z DEBUG] Wake up stream 3, queue: 0
[2023-05-18T23:49:38Z DEBUG] Add to stream 3, queue: 1
[2023-05-18T23:49:38Z DEBUG] Wake up stream 3, queue: 1
[2023-05-18T23:49:38Z DEBUG] Drop stream 3...
[2023-05-18T23:49:38Z INFO ] Activating portal services
[2023-05-18T23:49:38Z INFO ] Started dns server on 192.168.4.1:53
[2023-05-18T23:49:38Z INFO ] Started dhcp server on 192.168.4.1:67
[2023-05-18T23:49:38Z INFO ] Started http server on 192.168.4.1:80
[2023-05-18T23:49:38Z DEBUG] Create stream 4 - type='signal',path='/org/freedesktop/NetworkManager/ActiveConnection/26',interface='org.freedesktop.NetworkManager.Connection.Active',member='StateChanged' ...
[2023-05-18T23:49:38Z DEBUG] Wake up stream 4, queue: 0
[2023-05-18T23:49:38Z DEBUG] Create stream 5 - type='signal',sender='org.freedesktop.NetworkManager',path='/org/freedesktop/NetworkManager/Devices/5',interface='org.freedesktop.NetworkManager.Device.Wireless',member='AccessPointAdded' ...
[2023-05-18T23:49:38Z DEBUG] Create stream 6 - type='signal',sender='org.freedesktop.NetworkManager',path='/org/freedesktop/NetworkManager/Devices/5',interface='org.freedesktop.NetworkManager.Device.Wireless',member='AccessPointRemoved' ...
[2023-05-18T23:49:38Z DEBUG] Wake up stream 5, queue: 0
[2023-05-18T23:49:38Z DEBUG] Wake up stream 6, queue: 0
[2023-05-18T23:49:38Z DEBUG] Wake up stream 4, queue: 0
[2023-05-18T23:49:38Z DEBUG] Wake up stream 4, queue: 0
[2023-05-18T23:49:38Z DEBUG] Create stream 7 - type='signal',path='/org/freedesktop/NetworkManager',interface='org.freedesktop.NetworkManager',member='StateChanged' ...
[2023-05-18T23:49:38Z DEBUG] Wake up stream 7, queue: 0
[2023-05-18T23:54:44Z DEBUG] Add to stream 7, queue: 1
[2023-05-18T23:54:44Z DEBUG] Wake up stream 4, queue: 0
[2023-05-18T23:54:44Z DEBUG] Wake up stream 7, queue: 1
[2023-05-18T23:54:44Z DEBUG] Wake up stream 7, queue: 0
[2023-05-18T23:54:46Z DEBUG] Add to stream 7, queue: 1
[2023-05-18T23:54:46Z DEBUG] Wake up stream 4, queue: 0
[2023-05-18T23:54:46Z DEBUG] Wake up stream 7, queue: 1
[2023-05-18T23:54:46Z DEBUG] Drop stream 7...
[2023-05-18T23:54:46Z DEBUG] signal received, starting graceful shutdown
[2023-05-18T23:54:46Z INFO ] Stopped http server on 192.168.4.1:80
[2023-05-18T23:54:46Z DEBUG] Drop stream 4...
[2023-05-18T23:54:46Z INFO ] Portal closed
[2023-05-18T23:54:46Z INFO ] Stopped dns server on 192.168.4.1:53
[2023-05-18T23:54:46Z INFO ] Stopped dhcp server on 192.168.4.1:67
[2023-05-18T23:54:46Z INFO ] No connection found. Trying to reestablish
[2023-05-18T23:54:46Z DEBUG] Trying to connect to one of 6 known connections ...
[2023-05-18T23:54:46Z INFO ] Deleting old hotspot configuration /org/freedesktop/NetworkManager/Settings/19
[2023-05-18T23:54:46Z WARN ] Dbus Error: org.freedesktop.DBus.Error.UnknownMethod - Object does not exist at path “/”
[2023-05-18T23:54:46Z INFO ] Current connectivity: Ok(Connected)
[2023-05-18T23:54:46Z DEBUG] Create stream 8 - type='signal',path='/org/freedesktop/NetworkManager',interface='org.freedesktop.NetworkManager',member='StateChanged' ...
[2023-05-18T23:54:46Z DEBUG] Wake up stream 8, queue: 0
[2023-05-18T23:54:48Z DEBUG] Wake up stream 8, queue: 0
[2023-05-18T23:54:48Z DEBUG] Drop stream 8...
[2023-05-18T23:54:48Z INFO ] Exiting
[2023-05-18T23:54:48Z INFO ] State machine left
[2023-05-18T23:54:48Z DEBUG] Drop stream 5...
[2023-05-18T23:54:48Z DEBUG] Drop stream 6...

[notlistening]

Further to this I have done a tcpdump and can see the client sending dhcp requests onto wlan0 without any responses.
I then proceeded to statically set the IP on the my phone, connected to the AP and manually visited the portal to configure wifi. So looks like the DHCP server component is not receiving/responding to DHCP lease requests.

[pumicestone]

@notlistening, any update? I am facing the same issue on various architectures. DHCP is in fact not responding in my case as well. Did you build the app, or used precompiled bin?

[notlistening]

I've used the downloadable binary directly and made a few attempts at getting it to compile, however this really is my first adventure into rust. I've found using docker + a rust release with the source code shared in to get the furthest with various changes to the build script as they failed along the way. I'm sure that's my bad due to lack of experience with building and writing rust though. It needs some work to get it working with the latest rust and as noted by the author the packages for dbus might be available now. There are also dbus failures listed when running it, on the switch over between portal back to WiFi client so that will need looking into as well. Overall without the few updates and teething problems it's exactly what I need. Also not sure if the NetworkManager config needs to be tweaked in a certain way, would be nice to get the Author's original setup.

[pumicestone]

Thanks for the description of your situation. cargo build should do the trick!

Doing some monkey-println! debugging I found out that the program does not receive the broadcasted dhcp requests. So I changed the bind function (src/dhcp_server/mod.rs:105) to bind to 0.0.0.0:67 and with that the program receives the packet but finally it throws 101 network error. I think the problem here would be more to local network configuration. I dont know why the local address is 192.168.42.1:67 while other services have it 0.0.0.0:...
What's you netstat -tplanu output?