search

balena-os / wifi-connect

Easy WiFi setup for Linux devices from your mobile phone or laptop
Apache License 2.0
1.29k stars 363 forks source link

Unable to connect to internet after successful captive portal entry #307

Open mpoon opened 5 years ago

mpoon commented 5 years ago

I have wifi-connect set up on a RB4 running Raspbian 10 (buster). I'm able to successfully bring up a captive portal on a mobile device, enter in network credentials, and get the following output from wifi-connect:

...
Starting access point...
Access point 'WiFi Connect' created
Starting HTTP server on 192.168.42.1:80
User connected to the captive portal
Deleting existing WiFi connection: "<ssid>"
Stopping access point 'WiFi Connect' ...
Access point 'WiFi Connect' stopped
Access points: [...]
Connecting to access point 'cat dog owl pig cow'...
Internet connectivity established

However there does not seem to be internet connection:

ping -I wlan0 google.com
ping: google.com: Temporary failure in name resolution

Also the following:

Aug 14 18:16:52 raspberrypi NetworkManager[2746]: <info>  [1565831812.3398] audit: op="connection-delete" uuid="01051064-9ba7-4b15-aecb-4eec00803f39" name="cat dog owl pig cow" pid=5650 uid=0 result="success"
Aug 14 18:16:52 raspberrypi NetworkManager[2746]: <info>  [1565831812.3480] device (wlan0): state change: activated -> deactivating (reason 'user-requested', sys-iface-state: 'managed')
Aug 14 18:16:52 raspberrypi NetworkManager[2746]: <info>  [1565831812.3496] manager: NetworkManager state is now DISCONNECTING
Aug 14 18:16:52 raspberrypi NetworkManager[2746]: <info>  [1565831812.3715] audit: op="connection-deactivate" uuid="9fd1e831-1667-47f6-b6fa-ec3c32e24e88" name="WiFi Connect" pid=5650 uid=0 result="success"
Aug 14 18:16:52 raspberrypi NetworkManager[2746]: <info>  [1565831812.3719] device (wlan0): state change: deactivating -> disconnected (reason 'user-requested', sys-iface-state: 'managed')
Aug 14 18:16:53 raspberrypi NetworkManager[2746]: <info>  [1565831813.4081] device (wlan0): set-hw-addr: set MAC address to C2:C0:2F:A2:66:D6 (scanning)
Aug 14 18:16:53 raspberrypi NetworkManager[2746]: <info>  [1565831813.4270] manager: NetworkManager state is now DISCONNECTED
Aug 14 18:16:53 raspberrypi NetworkManager[2746]: <info>  [1565831813.4326] device (wlan0): supplicant interface state: completed -> disconnected
Aug 14 18:16:54 raspberrypi NetworkManager[2746]: <info>  [1565831814.4604] audit: op="connection-delete" uuid="9fd1e831-1667-47f6-b6fa-ec3c32e24e88" name="WiFi Connect" pid=5650 uid=0 result="success"
Aug 14 18:16:56 raspberrypi NetworkManager[2746]: <info>  [1565831816.6801] keyfile: add connection /run/NetworkManager/system-connections/cat dog owl pig cow.nmconnection (a07c91b9-a409-4430-a08a-d75836e9a058,"cat dog owl pig cow")
Aug 14 18:16:56 raspberrypi NetworkManager[2746]: <info>  [1565831816.6860] device (wlan0): Activation: starting connection 'cat dog owl pig cow' (a07c91b9-a409-4430-a08a-d75836e9a058)
Aug 14 18:16:56 raspberrypi NetworkManager[2746]: <info>  [1565831816.6923] settings-connection[0x1cb2658,a07c91b9-a409-4430-a08a-d75836e9a058]: write: successfully commited (keyfile: update /etc/NetworkManager/system-connections/cat dog owl pig cow.nmconnection (a07c91b9-a409-4430-a08a-d75836e9a058,"cat do
Aug 14 18:16:56 raspberrypi NetworkManager[2746]: <info>  [1565831816.6927] audit: op="connection-add-activate" uuid="a07c91b9-a409-4430-a08a-d75836e9a058" name="cat dog owl pig cow" pid=5650 uid=0 result="success"
Aug 14 18:16:56 raspberrypi NetworkManager[2746]: <info>  [1565831816.7004] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Aug 14 18:16:56 raspberrypi NetworkManager[2746]: <info>  [1565831816.7031] manager: NetworkManager state is now CONNECTING
Aug 14 18:16:57 raspberrypi NetworkManager[2746]: <info>  [1565831817.2294] device (wlan0): set-hw-addr: reset MAC address to DC:A6:32:02:B4:4A (preserve)
Aug 14 18:16:57 raspberrypi NetworkManager[2746]: <info>  [1565831817.2879] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Aug 14 18:16:57 raspberrypi NetworkManager[2746]: <info>  [1565831817.2893] device (wlan0): Activation: (wifi) access point 'cat dog owl pig cow' has security, but secrets are required.
Aug 14 18:16:57 raspberrypi NetworkManager[2746]: <info>  [1565831817.2894] device (wlan0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
Aug 14 18:16:57 raspberrypi NetworkManager[2746]: <info>  [1565831817.2973] device (wlan0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Aug 14 18:16:57 raspberrypi NetworkManager[2746]: <info>  [1565831817.2992] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Aug 14 18:16:57 raspberrypi NetworkManager[2746]: <info>  [1565831817.3006] device (wlan0): Activation: (wifi) connection 'cat dog owl pig cow' has security, and secrets exist.  No new secrets needed.
Aug 14 18:16:57 raspberrypi NetworkManager[2746]: <info>  [1565831817.3008] Config: added 'ssid' value 'cat dog owl pig cow'
Aug 14 18:16:57 raspberrypi NetworkManager[2746]: <info>  [1565831817.3008] Config: added 'scan_ssid' value '1'
Aug 14 18:16:57 raspberrypi NetworkManager[2746]: <info>  [1565831817.3008] Config: added 'bgscan' value 'simple:30:-80:86400'
Aug 14 18:16:57 raspberrypi NetworkManager[2746]: <info>  [1565831817.3009] Config: added 'key_mgmt' value 'WPA-PSK WPA-PSK-SHA256'
Aug 14 18:16:57 raspberrypi NetworkManager[2746]: <info>  [1565831817.3009] Config: added 'auth_alg' value 'OPEN'
Aug 14 18:16:57 raspberrypi NetworkManager[2746]: <info>  [1565831817.3009] Config: added 'psk' value '<hidden>'
Aug 14 18:16:57 raspberrypi NetworkManager[2746]: <info>  [1565831817.3436] device (wlan0): supplicant interface state: disconnected -> scanning
Aug 14 18:17:00 raspberrypi NetworkManager[2746]: <info>  [1565831820.1794] device (wlan0): supplicant interface state: scanning -> associating
Aug 14 18:17:03 raspberrypi NetworkManager[2746]: <info>  [1565831823.0395] device (wlan0): supplicant interface state: associating -> completed
Aug 14 18:17:03 raspberrypi NetworkManager[2746]: <info>  [1565831823.0396] device (wlan0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network "cat dog owl pig cow"
Aug 14 18:17:03 raspberrypi NetworkManager[2746]: <info>  [1565831823.0417] device (wlan0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Aug 14 18:17:03 raspberrypi NetworkManager[2746]: <info>  [1565831823.0474] dhcp4 (wlan0): activation: beginning transaction (timeout in 45 seconds)
Aug 14 18:17:03 raspberrypi NetworkManager[2746]: <info>  [1565831823.0525] dhcp4 (wlan0): dhclient started with pid 5871
Aug 14 18:17:03 raspberrypi dhclient[5871]: DHCPDISCOVER on wlan0 to 255.255.255.255 port 67 interval 5
Aug 14 18:17:04 raspberrypi dhclient[5871]: DHCPOFFER of 192.168.1.207 from 192.168.1.1
Aug 14 18:17:04 raspberrypi dhclient[5871]: DHCPREQUEST for 192.168.1.207 on wlan0 to 255.255.255.255 port 67
Aug 14 18:17:04 raspberrypi dhclient[5871]: DHCPACK of 192.168.1.207 from 192.168.1.1
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.2080] dhcp4 (wlan0):   address 192.168.1.207
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.2081] dhcp4 (wlan0):   plen 24 (255.255.255.0)
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.2082] dhcp4 (wlan0):   gateway 192.168.1.1
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.2082] dhcp4 (wlan0):   lease time 86400
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.2083] dhcp4 (wlan0):   nameserver '192.168.1.1'
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.2083] dhcp4 (wlan0): state changed unknown -> bound
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.2169] device (wlan0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.2206] device (wlan0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.2216] device (wlan0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.2236] manager: NetworkManager state is now CONNECTED_LOCAL
Aug 14 18:17:04 raspberrypi dhclient[5871]: bound to 192.168.1.207 -- renewal in 35060 seconds.
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.2557] manager: NetworkManager state is now CONNECTED_SITE
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.2566] policy: set 'cat dog owl pig cow' (wlan0) as default for IPv4 routing and DNS
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.2579] dns-mgr: Writing DNS information to /sbin/resolvconf
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.3607] device (wlan0): Activation: successful, device activated.
Aug 14 18:17:04 raspberrypi NetworkManager[2746]: <info>  [1565831824.3646] manager: NetworkManager state is now CONNECTED_GLOBAL

Everything to me points toward successful network connection, but I'm stuck on how to debug further. Any pointers are appreciated!

majorz commented 5 years ago

@mpoon That is odd indeed. For DNS resolution checks you may use dig and nslookup, e.g. nslookup www.google.com 192.168.1.1.

If you need to do detailed examination then the best way is to make a packet capture of the wlan0 interface with tcpdump or tshark, copy the .pcap file to your laptop/desktop and find out where the issue is with wireshark.