2024-11-01T16:11:51.916773Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:12:01.951866Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:15:03.880418Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:15:04.092797Z INFO shill[1231]: message repeated 7 times: [ INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online] 2024-11-01T16:15:04.105213Z INFO shill[1231]: INFO shill: [wifi_provider.cc(544)] Removed endpoint (MAC OUI=fe:9e:38 IFACE=5) from service wifi_psk_1 2024-11-01T16:15:04.105531Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:15:04.126114Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:15:04.151342Z INFO shill[1231]: INFO shill: [wifi.cc(1048)] Updated bgscan parameters: simple:360:-70:86400 2024-11-01T16:15:04.201775Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-61 noise=-99 txrate=173000 2024-11-01T16:15:04.201901Z ERR wpa_supplicant[802]: dbus: wpa_dbus_property_changed: no property SignalChange in object /fi/w1/wpa_supplicant1/Interfaces/0 2024-11-01T16:15:04.215243Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:16:41.403311Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:16:41.441313Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:22:01.686075Z INFO shill[1231]: INFO shill: [wifi.cc(963)] Significant movement away from AP, RSSI dropped from -53 to -63. Attempting to trigger scan. 2024-11-01T16:22:08.298580Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_23. sig: -59, sec: wpa2+wpa3, freq: 5765 2024-11-01T16:22:08.305175Z INFO shill[1231]: INFO shill: [wifi_provider.cc(511)] Assigning endpoint (MAC OUI=fe:9e:38 IFACE=6) to service wifi_psk_1 2024-11-01T16:22:08.305557Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_1. sig: -59, sec: wpa2+wpa3, freq: 5765 2024-11-01T16:22:08.313718Z NOTICE wpa_supplicant[802]: wlan0: Considering within-ESS reassociation 2024-11-01T16:22:08.313901Z NOTICE wpa_supplicant[802]: wlan0: Current BSS: (MAC OUI=ea:9e:38 IFACE=1) freq=5240 level=-64 snr=35 est_throughput=78001 2024-11-01T16:22:08.313964Z NOTICE wpa_supplicant[802]: wlan0: Selected BSS: (MAC OUI=ea:9e:38 IFACE=2) freq=5765 level=-60 snr=39 est_throughput=78001 2024-11-01T16:22:08.315824Z NOTICE wpa_supplicant[802]: wlan0: Using signal poll values for the current BSS: level=-63 snr=36 est_throughput=78001 2024-11-01T16:22:08.315926Z NOTICE wpa_supplicant[802]: wlan0: Skip roam - too small difference in signal level (3 < 9) 2024-11-01T16:22:08.338991Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:22:08.361295Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_24. sig: -60, sec: wpa2, freq: 5765 2024-11-01T16:22:08.363011Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:22:08.398282Z INFO shill[1231]: INFO shill: [wifi.cc(1048)] Updated bgscan parameters: simple:64:-70:360 2024-11-01T16:22:08.400034Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_25. sig: -60, sec: wpa2, freq: 5765 2024-11-01T16:22:08.402221Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_26. sig: -60, sec: wpa2, freq: 5765 2024-11-01T16:22:08.404348Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_27. sig: -60, sec: wpa2, freq: 5765 2024-11-01T16:22:08.408892Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:22:08.431032Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:22:08.446660Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-63 noise=-99 txrate=173300 2024-11-01T16:22:08.446818Z ERR wpa_supplicant[802]: dbus: wpa_dbus_property_changed: no property SignalChange in object /fi/w1/wpa_supplicant1/Interfaces/0 2024-11-01T16:22:08.447361Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:22:08.495123Z INFO shill[1231]: message repeated 2 times: [ INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online] 2024-11-01T16:22:08.512822Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_28. sig: -56, sec: wpa2, freq: 2437 2024-11-01T16:22:08.516534Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_29. sig: -69, sec: wpa2, freq: 2437 2024-11-01T16:22:08.521951Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_30. sig: -76, sec: wpa2+wpa3, freq: 5745 2024-11-01T16:22:08.527433Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:22:08.569013Z INFO shill[1231]: message repeated 2 times: [ INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online] 2024-11-01T16:22:08.587769Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_31. sig: -80, sec: wpa+wpa2, freq: 2462 2024-11-01T16:22:08.622691Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:22:35.688794Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:22:35.691786Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-57 noise=-99 txrate=173000 2024-11-01T16:22:35.691912Z ERR wpa_supplicant[802]: dbus: wpa_dbus_property_changed: no property SignalChange in object /fi/w1/wpa_supplicant1/Interfaces/0 2024-11-01T16:25:14.261026Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:25:14.366175Z INFO shill[1231]: message repeated 5 times: [ INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online] 2024-11-01T16:25:14.383304Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_24. sig: -72, sec: wpa2, freq: 2462 2024-11-01T16:25:14.387227Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:25:14.415003Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:25:14.435618Z INFO shill[1231]: INFO shill: [wifi_provider.cc(544)] Removed endpoint (MAC OUI=fe:9e:38 IFACE=5) from service wifi_psk_1 2024-11-01T16:25:14.436708Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:25:14.466970Z INFO shill[1231]: INFO shill: [wifi.cc(1048)] Updated bgscan parameters: simple:360:-70:86400 2024-11-01T16:25:14.510351Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-61 noise=-99 txrate=173000 2024-11-01T16:25:14.510442Z ERR wpa_supplicant[802]: dbus: wpa_dbus_property_changed: no property SignalChange in object /fi/w1/wpa_supplicant1/Interfaces/0 2024-11-01T16:25:14.513841Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:26:41.882029Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:26:41.892680Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:26:47.133241Z INFO shill[1231]: INFO shill: [manager.cc(2289)] Creating Connectivity Report 2024-11-01T16:26:47.133373Z INFO shill[1231]: INFO shill: [network.cc(977)] wlan0 wifi_psk_0: Starting Internet connectivity test 2024-11-01T16:26:47.135238Z INFO shill[1231]: INFO shill: [portal_detector.cc(158)] wifi_psk_0 IPFamily=IPv4 attempt=1: Starting HTTP probe: connectivitycheck.gstatic.com 2024-11-01T16:26:47.137198Z INFO shill[1231]: INFO shill: [portal_detector.cc(176)] wifi_psk_0 IPFamily=IPv4 attempt=1: Starting HTTPS probe: www.google.com 2024-11-01T16:26:47.157069Z INFO shill[1231]: INFO shill: [http_request.cc(240)] wifi_psk_0 IPFamily=IPv4 attempt=1 HTTP probe: Resolved connectivitycheck.gstatic.com to (IPv4: 5) in 0.01971 s 2024-11-01T16:26:47.158195Z INFO shill[1231]: INFO shill: [http_request.cc(240)] wifi_psk_0 IPFamily=IPv4 attempt=1 HTTPS probe: Resolved www.google.com to (IPv4: 6) in 0.018989 s 2024-11-01T16:26:47.189512Z INFO shill[1231]: INFO shill: [http_transport_curl.cc(587)] Response: 204 (No Content) 2024-11-01T16:26:47.189735Z INFO shill[1231]: INFO shill: [portal_detector.cc(184)] wifi_psk_0 IPFamily=IPv4 attempt=1: { num_attempts=1, HTTP probe result=Success code=204 content-length=0 duration=0.055473 s, HTTPS probe in-flight, is_complete=false} 2024-11-01T16:26:47.225564Z INFO shill[1231]: INFO shill: [http_transport_curl.cc(587)] Response: 204 () 2024-11-01T16:26:47.225736Z INFO shill[1231]: INFO shill: [portal_detector.cc(184)] wifi_psk_0 IPFamily=IPv4 attempt=1: { num_attempts=1, HTTP probe result=Success code=204 content-length=0 duration=0.055473 s, HTTPS probe result=Success duration=0.091473 s, is_complete=true} 2024-11-01T16:26:47.226388Z INFO shill[1231]: INFO shill: [network.cc(989)] wifi_psk_0: Completed connectivity test: { num_attempts=1, HTTP probe result=Success code=204 content-length=0 duration=0.055473 s, HTTPS probe result=Success duration=0.091473 s, is_complete=true} 2024-11-01T16:27:01.538619Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(357)] {default:wlan0} Do53 query to (IPv4: 1) failed after 1 attempt: Timeout while contacting DNS servers. 1/2 validated name servers 2024-11-01T16:27:01.539767Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(357)] {default:wlan0} Do53 query to (IPv4: 2) failed after 1 attempt: Timeout while contacting DNS servers. 0/2 validated name servers 2024-11-01T16:27:06.540214Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 1 to (IPv4: 1) failed: Timeout while contacting DNS servers (5.00291 s) 2024-11-01T16:27:06.541870Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 1 to (IPv4: 2) failed: Timeout while contacting DNS servers (5.00267 s) 2024-11-01T16:27:06.542862Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:06.544700Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:07.387003Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 2 to (IPv4: 2) failed: Timeout while contacting DNS servers (5.00226 s) 2024-11-01T16:27:07.519949Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 2 to (IPv4: 1) failed: Timeout while contacting DNS servers (5.00304 s) 2024-11-01T16:27:07.549784Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:08.667116Z ERR dnsproxyd[2715]: message repeated 5 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:27:08.821336Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 3 to (IPv4: 2) failed: Timeout while contacting DNS servers (5.00322 s) 2024-11-01T16:27:08.888231Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 3 to (IPv4: 1) failed: Timeout while contacting DNS servers (5.00346 s) 2024-11-01T16:27:09.041651Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:09.793386Z ERR dnsproxyd[2715]: message repeated 5 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:27:10.877716Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 4 to (IPv4: 1) failed: Timeout while contacting DNS servers (5.0033 s) 2024-11-01T16:27:10.909070Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 4 to (IPv4: 2) failed: Timeout while contacting DNS servers (5.00231 s) 2024-11-01T16:27:11.289318Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:12.115212Z ERR dnsproxyd[2715]: message repeated 3 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:27:12.161756Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(568)] {default:wlan0} Do53 probe attempt 5 to (IPv4: 1) succeeded (3.21968 s). 1/2 validated name servers 2024-11-01T16:27:12.179700Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(568)] {default:wlan0} Do53 probe attempt 5 to (IPv4: 2) succeeded (3.43006 s). 2/2 validated name servers 2024-11-01T16:27:23.510338Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(357)] {default:wlan0} Do53 query to (IPv4: 1) failed after 1 attempt: Timeout while contacting DNS servers. 1/2 validated name servers 2024-11-01T16:27:23.511160Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(357)] {default:wlan0} Do53 query to (IPv4: 2) failed after 1 attempt: Timeout while contacting DNS servers. 0/2 validated name servers 2024-11-01T16:27:28.510856Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 1 to (IPv4: 1) failed: Timeout while contacting DNS servers (5.0011 s) 2024-11-01T16:27:28.511710Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 1 to (IPv4: 2) failed: Timeout while contacting DNS servers (5.00093 s) 2024-11-01T16:27:28.512711Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:29.152570Z ERR dnsproxyd[2715]: message repeated 5 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:27:29.449800Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 2 to (IPv4: 1) failed: Timeout while contacting DNS servers (5.0016 s) 2024-11-01T16:27:29.484922Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 2 to (IPv4: 2) failed: Timeout while contacting DNS servers (5.00206 s) 2024-11-01T16:27:30.000285Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:30.001382Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:30.662229Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 3 to (IPv4: 1) failed: Timeout while contacting DNS servers (5.00263 s) 2024-11-01T16:27:30.956846Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 3 to (IPv4: 2) failed: Timeout while contacting DNS servers (5.00203 s) 2024-11-01T16:27:31.698617Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:31.699761Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:32.808078Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 4 to (IPv4: 1) failed: Timeout while contacting DNS servers (5.00227 s) 2024-11-01T16:27:32.894817Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 4 to (IPv4: 2) failed: Timeout while contacting DNS servers (5.0021 s) 2024-11-01T16:27:33.204499Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:35.092970Z ERR dnsproxyd[2715]: message repeated 8 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:27:35.764159Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 5 to (IPv4: 2) failed: Timeout while contacting DNS servers (5.00234 s) 2024-11-01T16:27:36.096013Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:36.142476Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 5 to (IPv4: 1) failed: Timeout while contacting DNS servers (5.00148 s) 2024-11-01T16:27:36.392496Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:39.908436Z ERR dnsproxyd[2715]: message repeated 23 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:27:40.302546Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 6 to (IPv4: 1) failed: Timeout while contacting DNS servers (5.00152 s) 2024-11-01T16:27:40.607496Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 6 to (IPv4: 2) failed: Timeout while contacting DNS servers (5.00234 s) 2024-11-01T16:27:40.791369Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:41.008962Z ERR dnsproxyd[2715]: message repeated 2 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:27:41.369502Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:42.009269Z ERR dnsproxyd[2715]: message repeated 6 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:27:42.794100Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:43.795199Z ERR dnsproxyd[2715]: message repeated 4 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:27:44.012184Z INFO patchpaneld[2025]: INFO patchpaneld: [network_monitor_service.cc(322)] NUD state changed on wlan0 for { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED }, old_state=NUD_PROBE 2024-11-01T16:27:44.012325Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_PROBE on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:27:44.017396Z INFO shill[1231]: INFO shill: [wifi.cc(3510)] WiFi Device wlan0: StartReconnectTimer 2024-11-01T16:27:44.017493Z INFO shill[1231]: INFO shill: [wifi.cc(2954)] In OnLinkMonitorFailure(): Called Reattach(). 2024-11-01T16:27:44.285529Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_32. sig: -60, sec: wpa2+wpa3, freq: 5240 2024-11-01T16:27:44.292001Z INFO shill[1231]: INFO shill: [wifi_provider.cc(511)] Assigning endpoint (MAC OUI=fe:9e:38 IFACE=7) to service wifi_psk_1 2024-11-01T16:27:44.292238Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_1. sig: -60, sec: wpa2+wpa3, freq: 5240 2024-11-01T16:27:44.295400Z NOTICE wpa_supplicant[802]: SME: Trying to authenticate with (MAC OUI=ea:9e:38 IFACE=1) (SSID='(SSID: 1)' freq=5240 MHz) 2024-11-01T16:27:44.297994Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_33. sig: -60, sec: wpa2, freq: 5240 2024-11-01T16:27:44.303870Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:44.308085Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:27:44.313710Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_34. sig: -60, sec: wpa2, freq: 5240 2024-11-01T16:27:44.324443Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_35. sig: -61, sec: wpa2, freq: 5240 2024-11-01T16:27:44.326774Z NOTICE wpa_supplicant[802]: nl80211: send_event_marker failed: Source based routing not supported 2024-11-01T16:27:44.338471Z INFO shill[1231]: INFO shill: [wifi_provider.cc(1540)] RegionChanged: Country notification: 00 2024-11-01T16:27:44.390191Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD 2024-11-01T16:27:44.391215Z INFO shill[1231]: INFO shill: [wifi_provider.cc(1540)] RegionChanged: Country notification: US 2024-11-01T16:27:44.392869Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD 2024-11-01T16:27:44.395114Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US 2024-11-01T16:27:44.396969Z NOTICE wpa_supplicant[802]: Trying to associate with (MAC OUI=ea:9e:38 IFACE=1) (SSID='(SSID: 1)' freq=5240 MHz) 2024-11-01T16:27:44.402639Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:44.406172Z INFO shill[1231]: INFO shill: [wifi.cc(1178)] WiFi wlan0 CurrentBSS /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/26 -> /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/26 2024-11-01T16:27:44.408662Z INFO shill[1231]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged completed -> authenticating 2024-11-01T16:27:44.414856Z NOTICE wpa_supplicant[802]: wlan0: Associated with (MAC OUI=ea:9e:38 IFACE=1) 2024-11-01T16:27:44.416626Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 2024-11-01T16:27:44.416809Z INFO shill[1231]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged authenticating -> associating 2024-11-01T16:27:44.417150Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US 2024-11-01T16:27:44.418512Z INFO shill[1231]: INFO shill: [wifi_provider.cc(1540)] RegionChanged: Country notification: US 2024-11-01T16:27:44.418936Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US 2024-11-01T16:27:44.427021Z NOTICE wpa_supplicant[802]: wlan0: WPA: Key negotiation completed with (MAC OUI=ea:9e:38 IFACE=1) [PTK=CCMP GTK=CCMP] 2024-11-01T16:27:44.427177Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-CONNECTED - Connection to (MAC OUI=ea:9e:38 IFACE=1) completed [id=0 id_str=] 2024-11-01T16:27:44.428017Z INFO shill[1231]: INFO shill: [wifi.cc(1178)] WiFi wlan0 CurrentBSS /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/26 -> /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/26 2024-11-01T16:27:44.429023Z INFO shill[1231]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged associating -> 4way_handshake 2024-11-01T16:27:44.438472Z INFO shill[1231]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged 4way_handshake -> completed 2024-11-01T16:27:44.440853Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:27:44.441658Z INFO shill[1231]: INFO shill: [wifi.cc(2711)] wlan0 renewing L3 configuration after roam. 2024-11-01T16:27:44.442339Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:27:44.453781Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:27:44.457820Z INFO dhcpcd7[3686]: status changed to Reboot 2024-11-01T16:27:44.457981Z INFO dhcpcd7[3686]: wlan0: rebinding lease of (10.0.0.0/8: 3) 2024-11-01T16:27:44.463097Z INFO dhcpcd7[3686]: wlan0: sending REQUEST (xid 0x3c40bb82), next in 4.3 seconds 2024-11-01T16:27:44.478968Z INFO dhcpcd7[3686]: wlan0: received ACK with xid 0x3c40bb82 2024-11-01T16:27:44.479007Z INFO dhcpcd7[3686]: wlan0: acknowledged (10.0.0.0/8: 3) from (10.0.0.0/8: 7) 2024-11-01T16:27:44.479485Z INFO dhcpcd7[3686]: event RENEW on interface wlan0 2024-11-01T16:27:44.479930Z INFO dhcpcd7[3686]: status changed to Bound 2024-11-01T16:27:44.480403Z INFO dhcpcd7[3686]: wlan0: adding route to (10.0.0.0/8: 8)/21 2024-11-01T16:27:44.495292Z INFO shill[1231]: INFO shill: [network.cc(465)] wlan0 wifi_psk_0: DHCP lease acquired {IPv4 address: (10.0.0.0/8: 3)/21, IPv4 broadcast: (10.0.0.0/8: 9), IPv4 gateway: (10.0.0.0/8: 7), IPv6 addresses: [], DNS: [(IPv4: 1),(IPv4: 2)]} 2024-11-01T16:27:44.496227Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:27:44.507787Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:27:44.508532Z INFO shill[1231]: INFO shill: [network.cc(247)] wlan0 wifi_psk_0: Setting IPv4 connection 2024-11-01T16:27:44.528386Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: (10.0.0.0/8: 3)/21, IPv4 broadcast: (10.0.0.0/8: 9), IPv4 gateway: (10.0.0.0/8: 7), IPv6 addresses: [], DNS: [(IPv4: 1),(IPv4: 2)]}, priority {0, primary_logical, primary_physical, primary_for_dns}, area 0x70007 2024-11-01T16:27:44.534837Z INFO shill[1231]: INFO shill: [network.cc(291)] wlan0 wifi_psk_0: OnSetupConnectionFinished(success: true) 2024-11-01T16:27:44.535094Z INFO shill[1231]: INFO shill: [network.cc(881)] wlan0 wifi_psk_0: RequestNetworkValidation(NetworkConnectionUpdate): Network validation is disabled 2024-11-01T16:27:44.536723Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:27:44.549028Z INFO shill[1231]: message repeated 2 times: [ INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11)] 2024-11-01T16:27:44.554503Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:44.555692Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:44.579296Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:27:44.581706Z INFO shill[1231]: INFO shill: [device.cc(429)] wlan0 wifi_psk_0: Portal detection is disabled for this service 2024-11-01T16:27:44.732447Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:27:44.737073Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-61 noise=-99 txrate=6000 2024-11-01T16:27:44.737334Z ERR wpa_supplicant[802]: dbus: wpa_dbus_property_changed: no property SignalChange in object /fi/w1/wpa_supplicant1/Interfaces/0 2024-11-01T16:27:45.304952Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:45.404117Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:45.431228Z INFO patchpaneld[2025]: INFO patchpaneld: [network_monitor_service.cc(322)] NUD state changed on wlan0 for { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_REACHABLE }, old_state=NUD_NONE 2024-11-01T16:27:46.306115Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:46.405071Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:47.125604Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 7 to (IPv4: 2) failed: Timeout while contacting DNS servers (5.00184 s) 2024-11-01T16:27:47.137867Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 7 to (IPv4: 1) failed: Timeout while contacting DNS servers (5.00208 s) 2024-11-01T16:27:47.307364Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:48.441923Z ERR dnsproxyd[2715]: message repeated 5 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:27:48.487324Z INFO patchpaneld[2025]: INFO patchpaneld: [network_monitor_service.cc(322)] NUD state changed on wlan0 for { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED }, old_state=NUD_PROBE 2024-11-01T16:27:48.487415Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_PROBE on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:27:48.490162Z INFO shill[1231]: INFO shill: [wifi.cc(2939)] Current service is unreliable, skipping reassociate attempt. 2024-11-01T16:27:48.953429Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:49.954716Z ERR dnsproxyd[2715]: message repeated 7 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:27:50.348581Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:50.349297Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:50.471609Z INFO patchpaneld[2025]: INFO patchpaneld: [network_monitor_service.cc(322)] NUD state changed on wlan0 for { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_DELAY }, old_state=NUD_FAILED 2024-11-01T16:27:50.954831Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:51.198727Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:56.512074Z ERR dnsproxyd[2715]: message repeated 19 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:27:57.209523Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 8 to (IPv4: 1) failed: Timeout while contacting DNS servers (5.0023 s) 2024-11-01T16:27:57.298018Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:57.817338Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 8 to (IPv4: 2) failed: Timeout while contacting DNS servers (5.00191 s) 2024-11-01T16:27:58.129640Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:27:58.771719Z ERR dnsproxyd[2715]: message repeated 6 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:27:58.855353Z INFO patchpaneld[2025]: INFO patchpaneld: [network_monitor_service.cc(322)] NUD state changed on wlan0 for { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED }, old_state=NUD_PROBE 2024-11-01T16:27:58.855442Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_PROBE on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:27:59.301713Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:00.907635Z ERR dnsproxyd[2715]: message repeated 7 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:01.318618Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:01.908643Z ERR dnsproxyd[2715]: message repeated 6 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:01.992593Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:02.255143Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:04.808333Z ERR dnsproxyd[2715]: message repeated 16 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:05.064528Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:05.525121Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:10.901055Z ERR dnsproxyd[2715]: message repeated 41 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:11.197812Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:11.203396Z ERR dnsproxyd[2715]: message repeated 3 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:11.207703Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_INCOMPLETE on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:11.208752Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:13.117979Z ERR dnsproxyd[2715]: message repeated 17 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:13.693711Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 9 to (IPv4: 2) failed: Timeout while contacting DNS servers (5.00044 s) 2024-11-01T16:28:13.742120Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:13.749944Z ERR dnsproxyd[2715]: message repeated 3 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:13.850194Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 9 to (IPv4: 1) failed: Timeout while contacting DNS servers (5.00139 s) 2024-11-01T16:28:13.863750Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:13.904966Z ERR dnsproxyd[2715]: message repeated 2 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:14.282311Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:15.016352Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:17.255327Z ERR dnsproxyd[2715]: message repeated 10 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:17.352814Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:17.512422Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:20.259444Z ERR dnsproxyd[2715]: message repeated 19 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:20.490528Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:20.515221Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:21.139677Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:23.499034Z ERR dnsproxyd[2715]: message repeated 39 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:23.561499Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:23.662846Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:26.535891Z ERR dnsproxyd[2715]: message repeated 68 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:26.698323Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:26.746891Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:29.761546Z ERR dnsproxyd[2715]: message repeated 63 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:29.769284Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:29.777402Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:30.963963Z ERR dnsproxyd[2715]: message repeated 17 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:31.168785Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:32.783151Z ERR dnsproxyd[2715]: message repeated 26 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:32.840610Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:32.874207Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:35.892062Z ERR dnsproxyd[2715]: message repeated 62 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:35.978834Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:36.102632Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:37.380929Z ERR dnsproxyd[2715]: message repeated 21 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:37.435719Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 10 to (IPv4: 2) failed: Timeout while contacting DNS servers (5.00343 s) 2024-11-01T16:28:37.802956Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:37.957701Z ERR dnsproxyd[2715]: message repeated 4 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:37.960305Z INFO shill[1231]: INFO shill: [device.cc(655)] SetEnabledChecked: wlan0 wifi_psk_0 starting 2024-11-01T16:28:37.960369Z INFO shill[1231]: INFO shill: [device.cc(676)] Already in desired enable state. 2024-11-01T16:28:37.960407Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:28:37.960440Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:28:37.961647Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:38.126743Z ERR dnsproxyd[2715]: message repeated 5 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:38.153215Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(560)] {default:wlan0} Do53 probe attempt 10 to (IPv4: 1) failed: Timeout while contacting DNS servers (5.00212 s) 2024-11-01T16:28:38.319815Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:39.117210Z ERR dnsproxyd[2715]: message repeated 11 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:39.177151Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:39.538891Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:40.882587Z ERR dnsproxyd[2715]: message repeated 12 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:41.121663Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:42.127463Z ERR dnsproxyd[2715]: message repeated 16 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:42.249072Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:42.338617Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:42.478396Z ERR dnsproxyd[2715]: message repeated 4 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:42.543269Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:44.634124Z ERR dnsproxyd[2715]: message repeated 37 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:44.671163Z NOTICE wpa_supplicant[802]: wlan0: Considering within-ESS reassociation 2024-11-01T16:28:44.671216Z NOTICE wpa_supplicant[802]: wlan0: Current BSS: (MAC OUI=ea:9e:38 IFACE=1) freq=5240 level=-61 snr=38 est_throughput=78001 2024-11-01T16:28:44.671257Z NOTICE wpa_supplicant[802]: wlan0: Selected BSS: (MAC OUI=ea:9e:38 IFACE=3) freq=5280 level=-59 snr=40 est_throughput=78001 2024-11-01T16:28:44.679231Z NOTICE wpa_supplicant[802]: wlan0: Using signal poll values for the current BSS: level=-61 snr=38 est_throughput=78001 2024-11-01T16:28:44.679624Z NOTICE wpa_supplicant[802]: wlan0: Skip roam - too small difference in signal level (2 < 9) 2024-11-01T16:28:44.689934Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:28:44.705861Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:44.714992Z INFO shill[1231]: INFO shill: [wifi.cc(1048)] Updated bgscan parameters: simple:64:-70:360 2024-11-01T16:28:44.732572Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:28:44.741474Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_36. sig: -59, sec: wpa2, freq: 5765 2024-11-01T16:28:44.741477Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-61 noise=-99 txrate=78000 2024-11-01T16:28:44.741577Z ERR wpa_supplicant[802]: dbus: wpa_dbus_property_changed: no property SignalChange in object /fi/w1/wpa_supplicant1/Interfaces/0 2024-11-01T16:28:44.765309Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:28:44.785116Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:28:44.786950Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:28:44.853052Z INFO shill[1231]: message repeated 3 times: [ INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online] 2024-11-01T16:28:44.867611Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_37. sig: -59, sec: wpa2, freq: 2437 2024-11-01T16:28:44.877063Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_38. sig: -72, sec: wpa2, freq: 2437 2024-11-01T16:28:44.885591Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:28:44.918885Z INFO shill[1231]: message repeated 2 times: [ INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online] 2024-11-01T16:28:44.933030Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_39. sig: -88, sec: wpa+wpa2, freq: 2462 2024-11-01T16:28:44.936326Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_40. sig: -85, sec: wpa2+wpa3, freq: 5745 2024-11-01T16:28:45.311102Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:45.357098Z ERR dnsproxyd[2715]: message repeated 2 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:45.387413Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:45.474174Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:48.323100Z ERR dnsproxyd[2715]: message repeated 41 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:48.522469Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:48.704831Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:50.825011Z ERR dnsproxyd[2715]: message repeated 33 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:51.328645Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:51.706930Z ERR dnsproxyd[2715]: message repeated 4 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:51.720683Z WARNING patchpaneld[2025]: WARNING patchpaneld: [network_monitor_service.cc(328)] Neighbor becomes NUD_FAILED from NUD_FAILED on wlan0 { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_FAILED } 2024-11-01T16:28:51.728183Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:51.831515Z ERR dnsproxyd[2715]: message repeated 3 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:51.886749Z INFO patchpaneld[2025]: INFO patchpaneld: [network_monitor_service.cc(322)] NUD state changed on wlan0 for { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_REACHABLE }, old_state=NUD_FAILED 2024-11-01T16:28:52.044650Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:54.034413Z ERR dnsproxyd[2715]: message repeated 41 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:28:54.648906Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_41. sig: -77, sec: wpa2+wpa3, freq: 5745 2024-11-01T16:28:54.651313Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:54.654054Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:54.660872Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:28:54.691403Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:54.692722Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:54.717222Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:28:54.742704Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers 2024-11-01T16:28:56.693009Z ERR dnsproxyd[2715]: message repeated 38 times: [ ERROR dnsproxyd: [resolver.cc(385)] {default:wlan0} Failed to do ares lookup: Timeout while contacting DNS servers] 2024-11-01T16:29:04.937742Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(568)] {default:wlan0} Do53 probe attempt 11 to (IPv4: 2) succeeded (0.017061 s). 1/2 validated name servers 2024-11-01T16:29:08.812299Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(568)] {default:wlan0} Do53 probe attempt 11 to (IPv4: 1) succeeded (0.021186 s). 2/2 validated name servers 2024-11-01T16:30:37.072218Z INFO shill[1231]: INFO shill: [device.cc(655)] SetEnabledChecked: wlan0 wifi_psk_0 starting 2024-11-01T16:30:37.072361Z INFO shill[1231]: INFO shill: [device.cc(676)] Already in desired enable state. 2024-11-01T16:30:37.072434Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:30:37.072497Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:30:43.760949Z NOTICE wpa_supplicant[802]: wlan0: Considering within-ESS reassociation 2024-11-01T16:30:43.760977Z NOTICE wpa_supplicant[802]: wlan0: Current BSS: (MAC OUI=ea:9e:38 IFACE=1) freq=5240 level=-62 snr=37 est_throughput=78001 2024-11-01T16:30:43.760991Z NOTICE wpa_supplicant[802]: wlan0: Selected BSS: (MAC OUI=ea:9e:38 IFACE=2) freq=5765 level=-59 snr=40 est_throughput=78001 2024-11-01T16:30:43.770541Z NOTICE wpa_supplicant[802]: wlan0: Using signal poll values for the current BSS: level=-61 snr=38 est_throughput=78001 2024-11-01T16:30:43.770593Z NOTICE wpa_supplicant[802]: wlan0: Skip roam - too small difference in signal level (2 < 9) 2024-11-01T16:30:43.781987Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:31:54.512570Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:32:31.024089Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(357)] {default:wlan0} Do53 query to (IPv4: 2) failed after 1 attempt: Timeout while contacting DNS servers. 1/2 validated name servers 2024-11-01T16:32:31.024864Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [resolver.cc(357)] {default:wlan0} Do53 query to (IPv4: 1) failed after 1 attempt: Timeout while contacting DNS servers. 0/2 validated name servers 2024-11-01T16:32:35.828368Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(568)] {default:wlan0} Do53 probe attempt 1 to (IPv4: 2) succeeded (4.80518 s). 1/2 validated name servers 2024-11-01T16:32:35.835995Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(568)] {default:wlan0} Do53 probe attempt 2 to (IPv4: 1) succeeded (3.94971 s). 2/2 validated name servers 2024-11-01T16:33:44.644966Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:33:44.773830Z INFO shill[1231]: message repeated 5 times: [ INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online] 2024-11-01T16:33:44.791418Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_34. sig: -70, sec: wpa2, freq: 2437 2024-11-01T16:33:44.795937Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:33:44.808470Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:33:44.822652Z INFO shill[1231]: INFO shill: [wifi_provider.cc(544)] Removed endpoint (MAC OUI=fe:9e:38 IFACE=8) from service wifi_psk_1 2024-11-01T16:33:44.822907Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:33:44.849954Z INFO shill[1231]: INFO shill: [wifi.cc(1048)] Updated bgscan parameters: simple:360:-70:86400 2024-11-01T16:33:44.874606Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-59 noise=-99 txrate=173000 2024-11-01T16:33:44.874762Z ERR wpa_supplicant[802]: dbus: wpa_dbus_property_changed: no property SignalChange in object /fi/w1/wpa_supplicant1/Interfaces/0 2024-11-01T16:33:44.926118Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:37:45.045878Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:37:45.108758Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:47:45.489718Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:47:45.516675Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:48:27.751565Z INFO shill[1231]: INFO shill: [device.cc(655)] SetEnabledChecked: wlan0 wifi_psk_0 starting 2024-11-01T16:48:27.751635Z INFO shill[1231]: INFO shill: [device.cc(676)] Already in desired enable state. 2024-11-01T16:48:27.751674Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:48:27.751708Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:48:34.369396Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_42. sig: -59, sec: wpa2+wpa3, freq: 5765 2024-11-01T16:48:34.405760Z INFO shill[1231]: INFO shill: [wifi_provider.cc(511)] Assigning endpoint (MAC OUI=fe:9e:38 IFACE=7) to service wifi_psk_1 2024-11-01T16:48:34.405828Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_1. sig: -60, sec: wpa2+wpa3, freq: 5240 2024-11-01T16:48:34.465644Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:48:34.478741Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_43. sig: -59, sec: wpa2, freq: 5765 2024-11-01T16:48:34.481337Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:48:34.506068Z INFO shill[1231]: INFO shill: [wifi.cc(1048)] Updated bgscan parameters: simple:64:-70:360 2024-11-01T16:48:34.513734Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_44. sig: -59, sec: wpa2, freq: 5765 2024-11-01T16:48:34.520961Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_45. sig: -59, sec: wpa2, freq: 5765 2024-11-01T16:48:34.526174Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_46. sig: -60, sec: wpa2, freq: 5240 2024-11-01T16:48:34.531339Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:48:34.535237Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-59 noise=-99 txrate=173000 2024-11-01T16:48:34.535331Z ERR wpa_supplicant[802]: dbus: wpa_dbus_property_changed: no property SignalChange in object /fi/w1/wpa_supplicant1/Interfaces/0 2024-11-01T16:48:34.549121Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:48:34.584486Z INFO shill[1231]: message repeated 2 times: [ INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online] 2024-11-01T16:48:34.609389Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_47. sig: -60, sec: wpa2, freq: 2437 2024-11-01T16:48:34.621747Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_48. sig: -72, sec: wpa2, freq: 2437 2024-11-01T16:48:34.626681Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:48:34.641991Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_49. sig: -76, sec: wpa2+wpa3, freq: 5745 2024-11-01T16:48:34.650964Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:48:34.684736Z INFO shill[1231]: message repeated 2 times: [ INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online] 2024-11-01T16:48:34.699441Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_50. sig: -86, sec: wpa+wpa2, freq: 2462 2024-11-01T16:48:34.735538Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:48:44.405322Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:48:44.411175Z NOTICE wpa_supplicant[802]: wlan0: Considering within-ESS reassociation 2024-11-01T16:48:44.411399Z NOTICE wpa_supplicant[802]: wlan0: Current BSS: (MAC OUI=ea:9e:38 IFACE=1) freq=5240 level=-59 snr=40 est_throughput=78001 2024-11-01T16:48:44.411486Z NOTICE wpa_supplicant[802]: wlan0: Selected BSS: (MAC OUI=ea:9e:38 IFACE=2) freq=5765 level=-58 snr=41 est_throughput=78001 2024-11-01T16:48:44.420115Z NOTICE wpa_supplicant[802]: wlan0: Using signal poll values for the current BSS: level=-58 snr=41 est_throughput=78001 2024-11-01T16:48:44.420406Z NOTICE wpa_supplicant[802]: wlan0: Skip roam - too small difference in signal level (0 < 10) 2024-11-01T16:48:44.431937Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:48:54.438990Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:48:54.448956Z NOTICE wpa_supplicant[802]: wlan0: Considering within-ESS reassociation 2024-11-01T16:48:54.449018Z NOTICE wpa_supplicant[802]: wlan0: Current BSS: (MAC OUI=ea:9e:38 IFACE=1) freq=5240 level=-60 snr=39 est_throughput=78001 2024-11-01T16:48:54.449057Z NOTICE wpa_supplicant[802]: wlan0: Selected BSS: (MAC OUI=ea:9e:38 IFACE=2) freq=5765 level=-58 snr=41 est_throughput=78001 2024-11-01T16:48:54.458994Z NOTICE wpa_supplicant[802]: wlan0: Using signal poll values for the current BSS: level=-59 snr=40 est_throughput=78001 2024-11-01T16:48:54.459091Z NOTICE wpa_supplicant[802]: wlan0: Skip roam - too small difference in signal level (1 < 10) 2024-11-01T16:49:04.363598Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:49:14.408405Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:49:24.431167Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:49:34.372389Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:49:34.374550Z NOTICE wpa_supplicant[802]: wlan0: Considering within-ESS reassociation 2024-11-01T16:49:34.374611Z NOTICE wpa_supplicant[802]: wlan0: Current BSS: (MAC OUI=ea:9e:38 IFACE=1) freq=5240 level=-59 snr=40 est_throughput=78001 2024-11-01T16:49:34.374666Z NOTICE wpa_supplicant[802]: wlan0: Selected BSS: (MAC OUI=ea:9e:38 IFACE=2) freq=5765 level=-58 snr=41 est_throughput=78001 2024-11-01T16:49:34.379781Z NOTICE wpa_supplicant[802]: wlan0: Using signal poll values for the current BSS: level=-58 snr=41 est_throughput=78001 2024-11-01T16:49:34.379995Z NOTICE wpa_supplicant[802]: wlan0: Skip roam - too small difference in signal level (0 < 10) 2024-11-01T16:51:15.890556Z INFO shill[1231]: INFO shill: [power_manager_proxy.cc(323)] SuspendImminent 2024-11-01T16:51:15.934517Z NOTICE ModemManager[1919]: [sleep-monitor-powerd] system suspend signal from powerd 2024-11-01T16:51:15.942672Z INFO shill[1231]: INFO shill: [power_manager.cc(159)] OnSuspendImminent(87490561) 2024-11-01T16:51:15.942753Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.942777Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.942801Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.942822Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.942844Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.942865Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.942887Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.942908Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.942929Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.942950Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.942971Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.942992Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943014Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943035Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943057Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943077Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943100Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943121Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943144Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943165Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943187Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943208Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943229Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943259Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943282Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943304Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943328Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943350Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943372Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943393Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943414Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943435Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.943460Z INFO shill[1231]: INFO shill: [wifi.cc(3076)] OnBeforeSuspend: connected 2024-11-01T16:51:15.946495Z INFO shill[1231]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.946535Z WARNING shill[1231]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.946565Z INFO shill[1231]: INFO shill: [manager.cc(1732)] Finished suspend actions. Result: org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:51:15.946596Z INFO shill[1231]: INFO shill: [power_manager_proxy.cc(281)] ReportSuspendReadinessInternal(87490563, 87490561, dark=false) 2024-11-01T16:51:15.972020Z INFO shill[1231]: INFO shill: [manager.cc(1734)] Successfully reported suspend readiness to powerd 2024-11-01T16:53:49.931479Z INFO patchpaneld[2025]: INFO patchpaneld: [network_monitor_service.cc(322)] NUD state changed on wlan0 for { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_NONE }, old_state=NUD_REACHABLE 2024-11-01T16:53:49.933689Z INFO shill[1231]: INFO shill: [wifi_provider.cc(1540)] RegionChanged: Country notification: 00 2024-11-01T16:53:49.938157Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-DISCONNECTED bssid=(MAC OUI=ea:9e:38 IFACE=1) reason=3 locally_generated=1 2024-11-01T16:53:49.997669Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD 2024-11-01T16:53:49.998861Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD 2024-11-01T16:53:49.999664Z INFO shill[1231]: INFO shill: [wifi_provider.cc(1540)] RegionChanged: Country notification: US 2024-11-01T16:53:49.999878Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US 2024-11-01T16:53:50.021002Z INFO shill[1231]: INFO shill: [manager.cc(2103)] Auto-connect suppressed -- system is suspending. 2024-11-01T16:53:50.043626Z NOTICE ModemManager[1919]: [sleep-monitor-powerd] system resume signal from powerd 2024-11-01T16:53:50.057568Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:53:50.102396Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:53:50.148947Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_45. sig: -72, sec: wpa2, freq: 5220 2024-11-01T16:53:50.150430Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:53:50.224970Z INFO shill[1231]: INFO shill: [power_manager_proxy.cc(334)] SuspendDone 2024-11-01T16:53:50.225414Z INFO shill[1231]: INFO shill: [power_manager_proxy.cc(341)] Suspend: ID 87490561 duration 154148105 2024-11-01T16:53:50.226314Z INFO shill[1231]: INFO shill: [power_manager.cc(181)] OnSuspendDone(87490561) 2024-11-01T16:53:50.226827Z INFO shill[1231]: INFO shill: [wifi.cc(3130)] OnAfterResume: connected, enabled 2024-11-01T16:53:50.227026Z INFO shill[1231]: INFO shill: [device.cc(342)] wlan0 wifi_psk_0: forced IP config update 2024-11-01T16:53:50.231762Z INFO dhcpcd7[3686]: status changed to Reboot 2024-11-01T16:53:50.231956Z INFO dhcpcd7[3686]: wlan0: rebinding lease of (10.0.0.0/8: 3) 2024-11-01T16:53:50.260632Z INFO dhcpcd7[3686]: wlan0: sending REQUEST (xid 0x54e9defa), next in 4.6 seconds 2024-11-01T16:53:50.311506Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:53:50.437285Z INFO shill[1231]: message repeated 5 times: [ INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online] 2024-11-01T16:53:50.461625Z INFO shill[1231]: INFO shill: [wifi_provider.cc(544)] Removed endpoint (MAC OUI=fe:9e:38 IFACE=5) from service wifi_psk_1 2024-11-01T16:53:50.462256Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:53:50.488462Z INFO shill[1231]: INFO shill: [wifi.cc(1048)] Updated bgscan parameters: simple:360:-70:86400 2024-11-01T16:53:50.497230Z INFO shill[1231]: INFO shill: [wifi.cc(1304)] WiFi wlan0 supplicant updated DisconnectReason to 3 (Deauthenticated because sending STA is leaving (or has left) IBSS or ESS) 2024-11-01T16:53:50.532800Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:53:50.534414Z INFO shill[1231]: INFO shill: [wifi.cc(1178)] WiFi wlan0 CurrentBSS /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/26 -> / 2024-11-01T16:53:50.534463Z INFO shill[1231]: INFO shill: [wifi.cc(1193)] Current BSS signal strength at disconnect: -60 2024-11-01T16:53:50.534515Z INFO shill[1231]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Online -> Idle 2024-11-01T16:53:50.543041Z INFO dnsproxyd[2703]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [online] to [idle] 2024-11-01T16:53:50.543043Z INFO dnsproxyd[5365]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [online] to [idle] 2024-11-01T16:53:50.543589Z INFO dnsproxyd[1896]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [online] to [idle] 2024-11-01T16:53:50.543709Z INFO dnsproxyd[2715]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [online] to [idle] 2024-11-01T16:53:50.544331Z INFO shill[1231]: INFO shill: [network.cc(331)] wlan0 wifi_psk_0: Stopping normally, network config: {IPv4 address: (10.0.0.0/8: 3)/21, IPv4 broadcast: (10.0.0.0/8: 9), IPv4 gateway: (10.0.0.0/8: 7), IPv6 addresses: [], DNS: [(IPv4: 1),(IPv4: 2)]} 2024-11-01T16:53:50.545737Z INFO dhcpcd7[3686]: received SIGTERM, stopping 2024-11-01T16:53:50.545773Z INFO dhcpcd7[3686]: wlan0: removing interface 2024-11-01T16:53:50.551326Z INFO dhcpcd7[3686]: status changed to Release 2024-11-01T16:53:50.551520Z INFO dhcpcd7[3686]: wlan0: deleting route to (10.0.0.0/8: 8)/21 2024-11-01T16:53:50.551534Z INFO dhcpcd7[3686]: wlan0: deleting default route via (10.0.0.0/8: 7) 2024-11-01T16:53:50.555648Z INFO dhcpcd7[3686]: dhcpcd exited 2024-11-01T16:53:50.581967Z INFO shill[1231]: INFO shill: [wifi.cc(3182)] InitiateScan 2024-11-01T16:53:50.582079Z INFO shill[1231]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged completed -> disconnected 2024-11-01T16:53:50.582248Z INFO shill[1231]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged disconnected -> scanning 2024-11-01T16:53:50.582332Z WARNING shill[1231]: WARNING shill: [legacy_dhcpcd_proxy.cc(316)] Received signal from the untracked dhcpcd with pid: 3686 2024-11-01T16:53:50.600247Z INFO shill[1231]: INFO shill: [manager.cc(1657)] Default physical service: NONE 2024-11-01T16:53:50.600720Z INFO shill[1231]: INFO shill: [service.cc(403)] Auto-connecting to wifi_psk_0 2024-11-01T16:53:50.600757Z INFO shill[1231]: INFO shill: [service.cc(462)] Connecting to wifi Service wifi_psk_0: AutoConnect 2024-11-01T16:53:50.601061Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:53:50.644480Z WARNING dnsproxyd[2715]: WARNING dnsproxyd: [proxy.cc(512)] {default:wlan0} is stopping because the default device [wlan0] is offline 2024-11-01T16:53:50.644755Z WARNING dnsproxyd[2703]: WARNING dnsproxyd: [proxy.cc(512)] {system:wlan0} is stopping because the default device [wlan0] is offline 2024-11-01T16:53:50.644867Z WARNING dnsproxyd[5365]: WARNING dnsproxyd: [proxy.cc(602)] {arc:wlan0} is stopping because the device [wlan0] is offline 2024-11-01T16:53:50.646177Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:53:50.648358Z INFO shill[1231]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Idle -> Associating 2024-11-01T16:53:50.648398Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Associating 2024-11-01T16:53:50.649749Z INFO shill[1231]: INFO shill: [network.cc(331)] wlan0 : Stopping normally, network config: {IPv4 address: nullopt, IPv6 addresses: [], DNS: []} 2024-11-01T16:53:50.653463Z INFO dnsproxyd[1896]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [100.115.92.134] 2024-11-01T16:53:50.654767Z INFO dnsproxyd[1896]: message repeated 2 times: [ INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [100.115.92.134]] 2024-11-01T16:53:50.655047Z INFO dnsproxyd[1896]: INFO dnsproxyd: [client.cc(391)] Default service changed from [/service/0] to [/] 2024-11-01T16:53:50.660652Z INFO dnsproxyd[5365]: INFO dnsproxyd: [client.cc(391)] Default service changed from [/service/0] to [/] 2024-11-01T16:53:50.664531Z INFO dnsproxyd[2715]: INFO dnsproxyd: [client.cc(391)] Default service changed from [/service/0] to [/] 2024-11-01T16:53:50.691410Z WARNING shill[1231]: WARNING shill: [legacy_dhcpcd_proxy.cc(316)] Received signal from the untracked dhcpcd with pid: 3686 2024-11-01T16:53:50.696122Z INFO patchpaneld[2025]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:53:50.696196Z INFO patchpaneld[2025]: INFO patchpaneld: [shill_client.cc(334)] Default logical device changed from {shill_device: wlan0, type: wifi, ifname: wlan0, ifindex: 2, service: /service/0} to none 2024-11-01T16:53:50.697051Z INFO patchpaneld[2025]: INFO patchpaneld: [shill_client.cc(350)] Default physical device changed from {shill_device: wlan0, type: wifi, ifname: wlan0, ifindex: 2, service: /service/0} to none 2024-11-01T16:53:50.698017Z INFO dnsproxyd[2703]: INFO dnsproxyd: [proxy.cc(787)] {system:_} Successfully cleared dns-proxy address property 2024-11-01T16:53:50.702126Z INFO dnsproxyd[2703]: INFO dnsproxyd: [client.cc(391)] Default service changed from [/service/0] to [/] 2024-11-01T16:53:50.710490Z WARNING dnsproxyd[1896]: WARNING dnsproxyd: [resolv_conf.cc(59)] Setting resolv.conf to [] 2024-11-01T16:53:50.796433Z INFO patchpaneld[2025]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:53:50.817134Z INFO patchpaneld[2025]: message repeated 3 times: [ INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected] 2024-11-01T16:53:50.817770Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: nullopt, IPv6 addresses: [], DNS: []}, priority {31}, area 0x80000000 2024-11-01T16:53:50.818704Z WARNING patchpaneld[2025]: WARNING patchpaneld: [routing_table.cc(110)] Successfully removed routing entry but could not find the corresponding entry in patchpanel's representation of the routing table. 2024-11-01T16:53:50.822994Z INFO patchpaneld[2025]: INFO patchpaneld: [shill_client.cc(727)] [/device/wlan0]: IPConfig changed: { ipv4_cidr: (0.0.0.0/8: 10)/0, ipv4_gateway: (0.0.0.0/8: 10), ipv4_dns: [], ipv6_cidr: ::/0, ipv6_gateway: ::, ipv6_dns: []} 2024-11-01T16:53:50.909807Z INFO patchpaneld[2025]: INFO patchpaneld: [conntrack_monitor.cc(194)] ConntrackMonitor added listener 2024-11-01T16:53:50.909841Z INFO patchpaneld[2025]: INFO patchpaneld: [network_monitor_service.cc(171)] ipconfigs changed on wlan0, update watching entries 2024-11-01T16:53:50.909855Z INFO patchpaneld[2025]: INFO patchpaneld: [network_monitor_service.cc(188)] Stop due to empty watching list on wlan0 2024-11-01T16:53:51.024419Z INFO patchpaneld[2025]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:53:51.024932Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: nullopt, IPv6 addresses: [], DNS: []}, priority {31}, area 0x80000000 2024-11-01T16:53:51.058287Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: EXCLUDE_DESTINATION, proxy_address: (IPv6: 1) } 2024-11-01T16:53:51.072187Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: EXCLUDE_DESTINATION, proxy_address: 100.115.92.134 } 2024-11-01T16:53:51.081226Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: ARC, input_ifname: arc_wlan0, proxy_address: (IPv6: 2) } 2024-11-01T16:53:51.081678Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: ARC, input_ifname: arc_wlan0, proxy_address: 100.115.92.138 } 2024-11-01T16:53:51.082546Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: USER, proxy_address: (IPv6: 3) } 2024-11-01T16:53:51.104940Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: USER, proxy_address: 100.115.92.130, nameserver(s): (IPv4: 1),(IPv4: 2), } 2024-11-01T16:53:51.267616Z INFO shill[1231]: INFO shill: [wake_on_wifi.cc(1088)] NotifySuspendDurationAfterWake: is_connected: 0 is_dark_connect_enabled: 0 seconds_in_suspend: 154 2024-11-01T16:53:53.685871Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_51. sig: -72, sec: wpa2+wpa3, freq: 5745 2024-11-01T16:53:53.689185Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_52. sig: -56, sec: wpa2+wpa3, freq: 5280 2024-11-01T16:53:53.691862Z INFO shill[1231]: INFO shill: [wifi_provider.cc(511)] Assigning endpoint (MAC OUI=fe:9e:38 IFACE=9) to service wifi_psk_1 2024-11-01T16:53:53.691913Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_1. sig: -56, sec: wpa2+wpa3, freq: 5280 2024-11-01T16:53:53.723864Z NOTICE wpa_supplicant[802]: SME: Trying to authenticate with (MAC OUI=ea:9e:38 IFACE=1) (SSID='(SSID: 1)' freq=5240 MHz) 2024-11-01T16:53:53.733448Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_53. sig: -56, sec: wpa2, freq: 5280 2024-11-01T16:53:53.734334Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Associating 2024-11-01T16:53:53.791977Z INFO shill[1231]: INFO shill: [wifi.cc(1048)] Updated bgscan parameters: simple:64:-70:360 2024-11-01T16:53:53.793130Z NOTICE wpa_supplicant[802]: Trying to associate with (MAC OUI=ea:9e:38 IFACE=1) (SSID='(SSID: 1)' freq=5240 MHz) 2024-11-01T16:53:53.793848Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_54. sig: -56, sec: wpa2, freq: 5280 2024-11-01T16:53:53.795530Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_55. sig: -56, sec: wpa2, freq: 5280 2024-11-01T16:53:53.796666Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Associating 2024-11-01T16:53:53.802318Z INFO shill[1231]: message repeated 2 times: [ INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Associating] 2024-11-01T16:53:53.804602Z NOTICE wpa_supplicant[802]: wlan0: Associated with (MAC OUI=ea:9e:38 IFACE=1) 2024-11-01T16:53:53.804754Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 2024-11-01T16:53:53.805230Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US 2024-11-01T16:53:53.805869Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Associating 2024-11-01T16:53:53.806389Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US 2024-11-01T16:53:53.809205Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Associating 2024-11-01T16:53:53.812348Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Associating 2024-11-01T16:53:53.815047Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_56. sig: -53, sec: wpa2, freq: 2437 2024-11-01T16:53:53.816639Z NOTICE wpa_supplicant[802]: wlan0: WPA: Key negotiation completed with (MAC OUI=ea:9e:38 IFACE=1) [PTK=CCMP GTK=CCMP] 2024-11-01T16:53:53.816697Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-CONNECTED - Connection to (MAC OUI=ea:9e:38 IFACE=1) completed [id=0 id_str=] 2024-11-01T16:53:53.824195Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_57. sig: -70, sec: wpa2, freq: 2437 2024-11-01T16:53:53.828037Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Associating 2024-11-01T16:53:53.847787Z INFO shill[1231]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:53:53.872468Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Associating 2024-11-01T16:53:53.878873Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_58. sig: -81, sec: wpa+wpa2, freq: 2462 2024-11-01T16:53:53.881656Z INFO shill[1231]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged scanning -> authenticating 2024-11-01T16:53:53.881724Z INFO shill[1231]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged authenticating -> associating 2024-11-01T16:53:53.881768Z INFO shill[1231]: INFO shill: [wifi.cc(1178)] WiFi wlan0 CurrentBSS / -> /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/26 2024-11-01T16:53:53.882471Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_0. sig: -58, sec: wpa2, freq: 5240 2024-11-01T16:53:53.882889Z INFO shill[1231]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged associating -> 4way_handshake 2024-11-01T16:53:53.883035Z INFO shill[1231]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged 4way_handshake -> completed 2024-11-01T16:53:53.892102Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:53:53.899431Z INFO shill[1231]: INFO shill: [legacy_dhcpcd_proxy.cc(216)] Created dhcpcd with pid 19615 and args: -B -f /etc/dhcpcd7.conf -i chromeos -q -4 -o captive_portal_uri --nodelay -h wlan0 2024-11-01T16:53:53.899701Z INFO shill[1231]: INFO shill: [network.cc(234)] wlan0 wifi_psk_0: Started IP provisioning, dhcp: started, accept_ra: true 2024-11-01T16:53:53.899747Z INFO shill[1231]: INFO shill: [network.cc(237)] wlan0 wifi_psk_0 initial config: wlan0: combined config {IPv4 address: nullopt, IPv6 addresses: [], DNS: []} 2024-11-01T16:53:53.899786Z INFO shill[1231]: INFO shill: [wifi.cc(2739)] wlan0 is up; started L3 configuration. 2024-11-01T16:53:53.900858Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:53:53.908992Z INFO dhcpcd7[19615]: status changed to Init 2024-11-01T16:53:53.910842Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:53:53.911371Z INFO shill[1231]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Associating -> Configuring 2024-11-01T16:53:53.911408Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Configuring 2024-11-01T16:53:53.912767Z INFO dhcpcd7[19615]: status changed to Discover 2024-11-01T16:53:53.912972Z INFO dhcpcd7[19615]: wlan0: soliciting a DHCP lease 2024-11-01T16:53:53.913002Z INFO dhcpcd7[19615]: wlan0: sending DISCOVER (xid 0x220d0e6f), next in 4.9 seconds 2024-11-01T16:53:53.930395Z INFO shill[1231]: INFO shill: [legacy_dhcpcd_proxy.cc(307)] SetDBusProxyIfPending: Set the D-Bus proxy to LegacyDHCPCDProxy for pid: 19615 2024-11-01T16:53:53.937787Z INFO patchpaneld[2025]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:53:53.938981Z INFO shill[1231]: INFO shill: [wifi_provider.cc(1540)] RegionChanged: Country notification: US 2024-11-01T16:53:53.943730Z INFO patchpaneld[2025]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:53:53.994157Z INFO patchpaneld[2025]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:53:54.126321Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-58 noise=-99 txrate=78000 2024-11-01T16:53:54.126365Z ERR wpa_supplicant[802]: dbus: wpa_dbus_property_changed: no property SignalChange in object /fi/w1/wpa_supplicant1/Interfaces/0 2024-11-01T16:53:54.127339Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:53:54.920964Z INFO dhcpcd7[19615]: wlan0: received OFFER with xid 0x220d0e6f 2024-11-01T16:53:54.920989Z INFO dhcpcd7[19615]: wlan0: offered (10.0.0.0/8: 3) from (10.0.0.0/8: 7) 2024-11-01T16:53:54.921001Z INFO dhcpcd7[19615]: status changed to Request 2024-11-01T16:53:54.921105Z INFO dhcpcd7[19615]: wlan0: requesting lease of (10.0.0.0/8: 3) 2024-11-01T16:53:54.921122Z INFO dhcpcd7[19615]: wlan0: sending REQUEST (xid 0x220d0e6f), next in 4.6 seconds 2024-11-01T16:53:54.932471Z INFO dhcpcd7[19615]: wlan0: received ACK with xid 0x220d0e6f 2024-11-01T16:53:54.932498Z INFO dhcpcd7[19615]: wlan0: acknowledged (10.0.0.0/8: 3) from (10.0.0.0/8: 7) 2024-11-01T16:53:54.932516Z INFO dhcpcd7[19615]: wlan0: leased (10.0.0.0/8: 3) for 86400 seconds 2024-11-01T16:53:54.933760Z INFO dhcpcd7[19615]: event BOUND on interface wlan0 2024-11-01T16:53:54.934180Z INFO dhcpcd7[19615]: status changed to Bound 2024-11-01T16:53:54.934442Z INFO dhcpcd7[19615]: wlan0: adding route to (10.0.0.0/8: 8)/21 2024-11-01T16:53:54.934467Z INFO dhcpcd7[19615]: wlan0: adding default route via (10.0.0.0/8: 7) 2024-11-01T16:53:54.935377Z INFO shill[1231]: INFO shill: [network.cc(465)] wlan0 wifi_psk_0: DHCP lease acquired {IPv4 address: (10.0.0.0/8: 3)/21, IPv4 broadcast: (10.0.0.0/8: 9), IPv4 gateway: (10.0.0.0/8: 7), IPv6 addresses: [], DNS: [(IPv4: 1),(IPv4: 2)]} 2024-11-01T16:53:54.936216Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:53:54.947767Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:53:54.949629Z INFO shill[1231]: INFO shill: [network.cc(247)] wlan0 wifi_psk_0: Setting IPv4 connection 2024-11-01T16:53:54.956103Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: (10.0.0.0/8: 3)/21, IPv4 broadcast: (10.0.0.0/8: 9), IPv4 gateway: (10.0.0.0/8: 7), IPv6 addresses: [], DNS: [(IPv4: 1),(IPv4: 2)]}, priority {31}, area 0x70007 2024-11-01T16:53:54.956620Z INFO patchpaneld[2025]: INFO patchpaneld: [address_service.cc(83)] SetIPv4Address: adding new address (10.0.0.0/8: 3)/21 2024-11-01T16:53:54.956834Z WARNING patchpaneld[2025]: WARNING patchpaneld: [routing_table.cc(110)] Successfully removed routing entry but could not find the corresponding entry in patchpanel's representation of the routing table. 2024-11-01T16:53:54.956869Z INFO dhcpcd7[19615]: wlan0: pid -705774929 deleted route to (10.0.0.0/8: 8)/21 2024-11-01T16:53:54.959707Z INFO patchpaneld[2025]: INFO patchpaneld: [shill_client.cc(727)] [/device/wlan0]: IPConfig changed: { ipv4_cidr: (10.0.0.0/8: 3)/21, ipv4_gateway: (10.0.0.0/8: 7), ipv4_dns: [(IPv4: 1),(IPv4: 2)], ipv6_cidr: ::/0, ipv6_gateway: ::, ipv6_dns: []} 2024-11-01T16:53:55.029947Z INFO patchpaneld[2025]: INFO patchpaneld: [network_monitor_service.cc(171)] ipconfigs changed on wlan0, update watching entries 2024-11-01T16:53:55.030021Z INFO patchpaneld[2025]: INFO patchpaneld: [network_monitor_service.cc(135)] IPv4 watching entries added on wlan0: skipped_dns_num=2 ,watching_dns_num=0 2024-11-01T16:53:55.031272Z INFO shill[1231]: INFO shill: [network.cc(291)] wlan0 wifi_psk_0: OnSetupConnectionFinished(success: true) 2024-11-01T16:53:55.031327Z INFO shill[1231]: INFO shill: [network.cc(881)] wlan0 wifi_psk_0: RequestNetworkValidation(NetworkConnectionUpdate): Network validation is disabled 2024-11-01T16:53:55.031362Z INFO shill[1231]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Configuring -> Connected 2024-11-01T16:53:55.056472Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Connected 2024-11-01T16:53:55.067002Z INFO patchpaneld[2025]: INFO patchpaneld: [network_monitor_service.cc(322)] NUD state changed on wlan0 for { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_REACHABLE }, old_state=NUD_NONE 2024-11-01T16:53:55.075338Z INFO shill[1231]: INFO shill: [wifi_service.cc(854)] SendPostReadyStateMetrics wifi_psk_0: time_resume_to_ready=4.84857 s 2024-11-01T16:53:55.077368Z INFO dnsproxyd[2703]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [configuration] to [ready] 2024-11-01T16:53:55.077370Z INFO dnsproxyd[5365]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [configuration] to [ready] 2024-11-01T16:53:55.077371Z INFO dnsproxyd[2715]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [configuration] to [ready] 2024-11-01T16:53:55.077645Z INFO dnsproxyd[1896]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [configuration] to [ready] 2024-11-01T16:53:55.078502Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:53:55.087108Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:53:55.097118Z INFO shill[1231]: message repeated 2 times: [ INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11)] 2024-11-01T16:53:55.097693Z INFO shill[1231]: INFO shill: [device.cc(429)] wlan0 wifi_psk_0: Portal detection is disabled for this service 2024-11-01T16:53:55.097743Z INFO shill[1231]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Connected -> Online 2024-11-01T16:53:55.098010Z INFO shill[1231]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:53:55.112024Z INFO shill[1231]: INFO shill: [manager.cc(1654)] Default physical service: wifi_psk_0 (online) 2024-11-01T16:53:55.112271Z INFO dnsproxyd[2703]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [ready] to [online] 2024-11-01T16:53:55.112365Z INFO dnsproxyd[2715]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [ready] to [online] 2024-11-01T16:53:55.112613Z INFO dnsproxyd[1896]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [ready] to [online] 2024-11-01T16:53:55.115060Z INFO dnsproxyd[5365]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [ready] to [online] 2024-11-01T16:53:55.116851Z INFO dnsproxyd[5365]: INFO dnsproxyd: [resolver.cc(676)] {arc:wlan0} Name servers are updated, 0/2 validated name servers 2024-11-01T16:53:55.117151Z INFO dnsproxyd[5365]: INFO dnsproxyd: [resolver.cc(294)] {arc:wlan0} Accepting UDP queries on {family: AF_INET6, port: 53, addr: ::} 2024-11-01T16:53:55.117327Z INFO dnsproxyd[5365]: INFO dnsproxyd: [resolver.cc(269)] {arc:wlan0} Accepting TCP connections on {family: AF_INET6, port: 53, addr: ::} 2024-11-01T16:53:55.118109Z INFO dnsproxyd[2715]: INFO dnsproxyd: [client.cc(391)] Default service changed from [/] to [/service/0] 2024-11-01T16:53:55.118373Z INFO dnsproxyd[2703]: INFO dnsproxyd: [client.cc(391)] Default service changed from [/] to [/service/0] 2024-11-01T16:53:55.119164Z INFO dnsproxyd[1896]: INFO dnsproxyd: [client.cc(391)] Default service changed from [/] to [/service/0] 2024-11-01T16:53:55.130230Z INFO dnsproxyd[2715]: INFO dnsproxyd: [proxy.cc(524)] {default:_} is now tracking [wlan0] 2024-11-01T16:53:55.130560Z INFO dnsproxyd[5365]: INFO dnsproxyd: [proxy.cc(888)] {arc:wlan0} DoH: off 2024-11-01T16:53:55.132033Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(676)] {default:wlan0} Name servers are updated, 0/2 validated name servers 2024-11-01T16:53:55.132132Z INFO dnsproxyd[5365]: INFO dnsproxyd: [proxy.cc(725)] {arc:wlan0} applied device DNS configuration 2024-11-01T16:53:55.132236Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(294)] {default:wlan0} Accepting UDP queries on {family: AF_INET6, port: 53, addr: ::} 2024-11-01T16:53:55.132343Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(269)] {default:wlan0} Accepting TCP connections on {family: AF_INET6, port: 53, addr: ::} 2024-11-01T16:53:55.133638Z INFO dnsproxyd[2703]: INFO dnsproxyd: [proxy.cc(524)] {system:_} is now tracking [wlan0] 2024-11-01T16:53:55.134495Z INFO dnsproxyd[1896]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [(IPv4: 1),(IPv4: 2)] 2024-11-01T16:53:55.135462Z INFO dnsproxyd[2703]: INFO dnsproxyd: [resolver.cc(676)] {system:wlan0} Name servers are updated, 0/2 validated name servers 2024-11-01T16:53:55.135639Z INFO dnsproxyd[2703]: INFO dnsproxyd: [resolver.cc(294)] {system:wlan0} Accepting UDP queries on {family: AF_INET6, port: 53, addr: ::} 2024-11-01T16:53:55.135737Z INFO dnsproxyd[2703]: INFO dnsproxyd: [resolver.cc(269)] {system:wlan0} Accepting TCP connections on {family: AF_INET6, port: 53, addr: ::} 2024-11-01T16:53:55.139519Z INFO dnsproxyd[2715]: INFO dnsproxyd: [proxy.cc(888)] {default:wlan0} DoH: off 2024-11-01T16:53:55.139525Z INFO dnsproxyd[2703]: INFO dnsproxyd: [proxy.cc(888)] {system:wlan0} DoH: off 2024-11-01T16:53:55.139864Z INFO dnsproxyd[2715]: INFO dnsproxyd: [proxy.cc(725)] {default:wlan0} applied device DNS configuration 2024-11-01T16:53:55.140355Z INFO patchpaneld[2025]: INFO patchpaneld: [shill_client.cc(334)] Default logical device changed from none to {shill_device: wlan0, type: wifi, ifname: wlan0, ifindex: 2, service: /service/0} 2024-11-01T16:53:55.140404Z INFO patchpaneld[2025]: INFO patchpaneld: [shill_client.cc(350)] Default physical device changed from none to {shill_device: wlan0, type: wifi, ifname: wlan0, ifindex: 2, service: /service/0} 2024-11-01T16:53:55.142777Z INFO dnsproxyd[2703]: INFO dnsproxyd: [proxy.cc(793)] {system:wlan0} Successfully set dns-proxy address property [100.115.92.134] 2024-11-01T16:53:55.142934Z INFO dnsproxyd[2703]: INFO dnsproxyd: [proxy.cc(725)] {system:wlan0} applied device DNS configuration 2024-11-01T16:53:55.143136Z INFO dnsproxyd[1896]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [100.115.92.134] 2024-11-01T16:53:55.196660Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: (10.0.0.0/8: 3)/21, IPv4 broadcast: (10.0.0.0/8: 9), IPv4 gateway: (10.0.0.0/8: 7), IPv6 addresses: [], DNS: [(IPv4: 1),(IPv4: 2)]}, priority {0, primary_logical, primary_physical, primary_for_dns}, area 0x30000 2024-11-01T16:53:55.260131Z INFO dnsproxyd[5365]: INFO dnsproxyd: [client.cc(391)] Default service changed from [/] to [/service/0] 2024-11-01T16:53:55.262617Z INFO dnsproxyd[5365]: INFO dnsproxyd: [resolver.cc(568)] {arc:wlan0} Do53 probe attempt 1 to (IPv4: 1) succeeded (0.146031 s). 1/2 validated name servers 2024-11-01T16:53:55.262946Z INFO dnsproxyd[5365]: INFO dnsproxyd: [resolver.cc(568)] {arc:wlan0} Do53 probe attempt 1 to (IPv4: 2) succeeded (0.146851 s). 2/2 validated name servers 2024-11-01T16:53:56.022392Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(568)] {default:wlan0} Do53 probe attempt 2 to (IPv4: 2) succeeded (0.016014 s). 1/2 validated name servers 2024-11-01T16:53:56.044067Z INFO dnsproxyd[2715]: INFO dnsproxyd: [resolver.cc(568)] {default:wlan0} Do53 probe attempt 2 to (IPv4: 1) succeeded (0.017183 s). 2/2 validated name servers 2024-11-01T16:53:56.044702Z INFO dnsproxyd[2703]: INFO dnsproxyd: [resolver.cc(568)] {system:wlan0} Do53 probe attempt 2 to (IPv4: 1) succeeded (0.017242 s). 1/2 validated name servers 2024-11-01T16:53:56.129298Z INFO dnsproxyd[2703]: INFO dnsproxyd: [resolver.cc(568)] {system:wlan0} Do53 probe attempt 2 to (IPv4: 2) succeeded (0.01583 s). 2/2 validated name servers 2024-11-01T16:54:36.697731Z INFO dhcpcd7[19615]: received SIGTERM, stopping 2024-11-01T16:54:36.697753Z INFO dhcpcd7[19615]: wlan0: removing interface 2024-11-01T16:54:36.697770Z INFO dhcpcd7[19615]: status changed to Release 2024-11-01T16:54:36.697849Z INFO dhcpcd7[19615]: wlan0: deleting default route via (10.0.0.0/8: 7) 2024-11-01T16:54:36.698005Z INFO shill[1231]: INFO shill: [shill_daemon.cc(32)] ShillDaemon received shutdown. 2024-11-01T16:54:36.698009Z INFO dhcpcd7[19615]: dhcpcd exited 2024-11-01T16:54:36.699717Z INFO shill[1231]: INFO shill: [manager.cc(1565)] Device wlan0 updated: enabled 2024-11-01T16:54:36.795575Z INFO shill[1231]: INFO shill: [service.cc(482)] Disconnecting from wifi_psk_0: Stop 2024-11-01T16:54:36.795614Z INFO shill[1231]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Online -> Disconnecting 2024-11-01T16:54:36.799258Z INFO dnsproxyd[1896]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [online] to [disconnecting] 2024-11-01T16:54:36.799259Z INFO dnsproxyd[2715]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [online] to [disconnecting] 2024-11-01T16:54:36.799260Z INFO dnsproxyd[5365]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [online] to [disconnecting] 2024-11-01T16:54:36.799295Z WARNING dnsproxyd[2715]: WARNING dnsproxyd: [proxy.cc(512)] {default:wlan0} is stopping because the default device [wlan0] is offline 2024-11-01T16:54:36.799296Z WARNING dnsproxyd[5365]: WARNING dnsproxyd: [proxy.cc(602)] {arc:wlan0} is stopping because the device [wlan0] is offline 2024-11-01T16:54:36.799306Z INFO dnsproxyd[1896]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [100.115.92.134] 2024-11-01T16:54:36.799322Z INFO dnsproxyd[2703]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [online] to [disconnecting] 2024-11-01T16:54:36.799371Z WARNING dnsproxyd[2703]: WARNING dnsproxyd: [proxy.cc(512)] {system:wlan0} is stopping because the default device [wlan0] is offline 2024-11-01T16:54:36.800037Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: USER, proxy_address: (IPv6: 3) } 2024-11-01T16:54:36.813249Z NOTICE wpa_supplicant[802]: nl80211: send_event_marker failed: Source based routing not supported 2024-11-01T16:54:36.813309Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-DISCONNECTED bssid=(MAC OUI=ea:9e:38 IFACE=1) reason=3 locally_generated=1 2024-11-01T16:54:36.814606Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all 2024-11-01T16:54:36.815209Z INFO shill[1231]: INFO shill: [device.cc(636)] SetEnabled(0) 2024-11-01T16:54:36.815236Z INFO shill[1231]: INFO shill: [device.cc(655)] SetEnabledChecked: wlan0 wifi_psk_0 stopping 2024-11-01T16:54:36.815252Z INFO shill[1231]: INFO shill: [device.cc(708)] wlan0 wifi_psk_0 SetEnabledUnchecked(false) 2024-11-01T16:54:36.815300Z INFO shill[1231]: INFO shill: [network.cc(331)] wlan0 wifi_psk_0: Stopping normally, network config: {IPv4 address: (10.0.0.0/8: 3)/21, IPv4 broadcast: (10.0.0.0/8: 9), IPv4 gateway: (10.0.0.0/8: 7), IPv6 addresses: [], DNS: [(IPv4: 1),(IPv4: 2)]} 2024-11-01T16:54:36.817436Z INFO shill[1231]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Disconnecting -> Idle 2024-11-01T16:54:36.818176Z INFO dnsproxyd[1896]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [100.115.92.134] 2024-11-01T16:54:36.820408Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD 2024-11-01T16:54:36.820589Z INFO dnsproxyd[1896]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [100.115.92.134] 2024-11-01T16:54:36.821324Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD 2024-11-01T16:54:36.822192Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US 2024-11-01T16:54:36.825092Z INFO dnsproxyd[1896]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [100.115.92.134] 2024-11-01T16:54:36.831670Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:54:36.833455Z INFO shill[1231]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:54:36.833954Z INFO shill[1231]: INFO shill: [network.cc(331)] wlan0 : Stopping normally, network config: {IPv4 address: nullopt, IPv6 addresses: [], DNS: []} 2024-11-01T16:54:36.834968Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_52. sig: -67, sec: wpa2+wpa3, freq: 5680 2024-11-01T16:54:36.837732Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_54. sig: -67, sec: wpa2, freq: 5805 2024-11-01T16:54:36.838125Z INFO shill[1231]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_0. sig: -67, sec: wpa2, freq: 5680 2024-11-01T16:54:36.847203Z INFO shill[1231]: INFO shill: [wifi_provider.cc(544)] Removed endpoint (MAC OUI=fe:9e:38 IFACE=5) from service wifi_psk_1 2024-11-01T16:54:36.859761Z ERR shill[1231]: ERROR shill: [object_proxy.cc(576)] Failed to call method: fi.w1.wpa_supplicant1.Interface.Disconnect: object_path= /fi/w1/wpa_supplicant1/Interfaces/0: fi.w1.wpa_supplicant1.NotConnected: This interface is not connected 2024-11-01T16:54:36.859809Z ERR shill[1231]: ERROR shill: [dbus_method_invoker.h(114)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=fi.w1.wpa_supplicant1.NotConnected, Message=Error calling D-Bus method: fi.w1.wpa_supplicant1.Interface.Disconnect: This interface is not connected 2024-11-01T16:54:36.859834Z INFO shill[1231]: INFO shill: [supplicant_interface_proxy.cc(197)] Failed to disconnect: fi.w1.wpa_supplicant1.NotConnected Error calling D-Bus method: fi.w1.wpa_supplicant1.Interface.Disconnect: This interface is not connected 2024-11-01T16:54:36.870568Z INFO shill[1231]: INFO shill: [wifi_provider.cc(544)] Removed endpoint (MAC OUI=ea:9e:38 IFACE=10) from service wifi_psk_0 2024-11-01T16:54:36.875242Z INFO shill[1231]: INFO shill: [device.cc(608)] OnEnabledStateChanged: wlan0 no_service (target: 0, success: 1) 2024-11-01T16:54:36.879071Z INFO shill[1231]: INFO shill: [p2p_manager.cc(140)] Stop 2024-11-01T16:54:36.879108Z INFO shill[1231]: INFO shill: [modem_info.cc(51)] Stop 2024-11-01T16:54:36.925223Z INFO shill[1231]: INFO shill: [modem_info.cc(97)] Disconnect 2024-11-01T16:54:36.925291Z INFO shill[1231]: INFO shill: [device.cc(123)] ~Device(): arc_ns0 no_service 2024-11-01T16:54:36.925501Z INFO shill[1231]: INFO shill: [device.cc(123)] ~Device(): arc_ns2 no_service 2024-11-01T16:54:36.925598Z INFO shill[1231]: INFO shill: [device.cc(123)] ~Device(): arc_wlan0 no_service 2024-11-01T16:54:36.925691Z INFO shill[1231]: INFO shill: [device.cc(123)] ~Device(): arc_ns1 no_service 2024-11-01T16:54:36.925796Z INFO shill[1231]: INFO shill: [power_manager.cc(59)] Stop 2024-11-01T16:54:36.925827Z INFO shill[1231]: INFO shill: [power_manager_proxy.cc(254)] UnregisterSuspendDelayInternal(87490563, dark=false) 2024-11-01T16:54:36.927451Z INFO shill[1231]: INFO shill: [power_manager_proxy.cc(254)] UnregisterSuspendDelayInternal(87523329, dark=true) 2024-11-01T16:54:36.930322Z NOTICE wpa_supplicant[802]: p2p-dev-wlan0: CTRL-EVENT-DSCP-POLICY clear_all 2024-11-01T16:54:36.971412Z NOTICE wpa_supplicant[802]: p2p-dev-wlan0: CTRL-EVENT-DSCP-POLICY clear_all 2024-11-01T16:54:36.971529Z NOTICE wpa_supplicant[802]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0 2024-11-01T16:54:37.069411Z ERR wpa_supplicant[802]: rmdir[ctrl_interface=/run/wpa_supplicant]: Permission denied 2024-11-01T16:54:37.069752Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all 2024-11-01T16:54:37.073887Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: ARC, input_ifname: arc_wlan0, proxy_address: (IPv6: 2) } 2024-11-01T16:54:37.074622Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: ARC, input_ifname: arc_wlan0, proxy_address: 100.115.92.138 } 2024-11-01T16:54:37.075196Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: USER, proxy_address: 100.115.92.130, nameserver(s): (IPv4: 1),(IPv4: 2), } 2024-11-01T16:54:37.091213Z NOTICE wpa_supplicant[802]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all 2024-11-01T16:54:37.091534Z NOTICE wpa_supplicant[802]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 2024-11-01T16:54:37.092349Z ERR wpa_supplicant[802]: rmdir[ctrl_interface=/run/wpa_supplicant]: Permission denied 2024-11-01T16:54:37.093856Z INFO shill[1231]: INFO shill: [device.cc(123)] ~Device(): wlan0 no_service 2024-11-01T16:54:37.295738Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: EXCLUDE_DESTINATION, proxy_address: (IPv6: 1) } 2024-11-01T16:54:37.308199Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: EXCLUDE_DESTINATION, proxy_address: 100.115.92.134 } 2024-11-01T16:54:37.316619Z INFO patchpaneld[2025]: INFO patchpaneld: [network_monitor_service.cc(322)] NUD state changed on wlan0 for { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_NONE }, old_state=NUD_REACHABLE 2024-11-01T16:54:37.317154Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: nullopt, IPv6 addresses: [], DNS: []}, priority {31}, area 0x80000000 2024-11-01T16:54:37.317646Z WARNING patchpaneld[2025]: WARNING patchpaneld: [routing_table.cc(110)] Successfully removed routing entry but could not find the corresponding entry in patchpanel's representation of the routing table. 2024-11-01T16:54:37.342261Z ERR dnsproxyd[2703]: ERROR dnsproxyd: [object_proxy.cc(576)] Failed to call method: org.chromium.flimflam.Manager.ClearDNSProxyAddresses: object_path= /: org.freedesktop.DBus.Error.UnknownMethod: Method "ClearDNSProxyAddresses" with signature "" on interface "org.chromium.flimflam.Manager" doesn't exist#012 2024-11-01T16:54:37.342319Z ERR dnsproxyd[2703]: ERROR dnsproxyd: [dbus_method_invoker.h(114)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=org.freedesktop.DBus.Error.UnknownMethod, Message=Error calling D-Bus method: org.chromium.flimflam.Manager.ClearDNSProxyAddresses: Method "ClearDNSProxyAddresses" with signature "" on interface "org.chromium.flimflam.Manager" doesn't exist#012 2024-11-01T16:54:37.342363Z INFO dnsproxyd[2703]: INFO dnsproxyd: [proxy.cc(787)] {system:_} Successfully cleared dns-proxy address property 2024-11-01T16:54:37.342432Z WARNING patchpaneld[2025]: WARNING patchpaneld: [object_proxy.cc(574)] Failed to call method: org.chromium.flimflam.Device.GetProperties: object_path= /device/wlan0: org.freedesktop.DBus.Error.UnknownObject: Method "GetProperties" with signature "" on interface "org.chromium.flimflam.Device" doesn't exist#012 2024-11-01T16:54:37.342461Z ERR patchpaneld[2025]: ERROR patchpaneld: [dbus_method_invoker.h(114)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=org.freedesktop.DBus.Error.UnknownObject, Message=Error calling D-Bus method: org.chromium.flimflam.Device.GetProperties: Method "GetProperties" with signature "" on interface "org.chromium.flimflam.Device" doesn't exist#012 2024-11-01T16:54:37.342480Z ERR patchpaneld[2025]: ERROR patchpaneld: [shill_client.cc(472)] Unable to get shill Device properties for /device/wlan0 2024-11-01T16:54:37.342495Z ERR patchpaneld[2025]: ERROR patchpaneld: [shill_client.cc(700)] Failed to update properties of Device /device/wlan0 2024-11-01T16:54:37.344547Z INFO shill[1231]: INFO shill: [shill_main.cc(120)] Process exiting. 2024-11-01T16:54:37.344631Z WARNING dnsproxyd[1896]: WARNING dnsproxyd: [resolv_conf.cc(59)] Setting resolv.conf to [] 2024-11-01T16:54:37.346005Z WARNING dnsproxyd[2715]: WARNING dnsproxyd: [proxy.cc(394)] {default:_} Shill has been shutdown 2024-11-01T16:54:37.346245Z WARNING dnsproxyd[5365]: WARNING dnsproxyd: [proxy.cc(394)] {arc:wlan0} Shill has been shutdown 2024-11-01T16:54:37.346617Z WARNING dnsproxyd[1896]: WARNING dnsproxyd: [controller.cc(233)] Shill has been shutdown 2024-11-01T16:54:37.348180Z WARNING dnsproxyd[2703]: WARNING dnsproxyd: [proxy.cc(394)] {system:_} Shill has been shutdown 2024-11-01T16:54:37.349517Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [object_proxy.cc(576)] Failed to call method: org.chromium.flimflam.Manager.GetProperties: object_path= /: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.flimflam was not provided by any .service files 2024-11-01T16:54:37.349555Z ERR dnsproxyd[2715]: ERROR dnsproxyd: [dbus_method_invoker.h(114)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=org.freedesktop.DBus.Error.ServiceUnknown, Message=Error calling D-Bus method: org.chromium.flimflam.Manager.GetProperties: The name org.chromium.flimflam was not provided by any .service files 2024-11-01T16:54:37.349576Z WARNING dnsproxyd[2715]: WARNING dnsproxyd: [client.cc(357)] Unable to get shill Manager properties, likely because shill is unavailable 2024-11-01T16:54:37.349890Z ERR dnsproxyd[5365]: ERROR dnsproxyd: [object_proxy.cc(576)] Failed to call method: org.chromium.flimflam.Manager.GetProperties: object_path= /: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.flimflam was not provided by any .service files 2024-11-01T16:54:37.349949Z ERR dnsproxyd[5365]: ERROR dnsproxyd: [dbus_method_invoker.h(114)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=org.freedesktop.DBus.Error.ServiceUnknown, Message=Error calling D-Bus method: org.chromium.flimflam.Manager.GetProperties: The name org.chromium.flimflam was not provided by any .service files 2024-11-01T16:54:37.349969Z WARNING dnsproxyd[5365]: WARNING dnsproxyd: [client.cc(357)] Unable to get shill Manager properties, likely because shill is unavailable 2024-11-01T16:54:37.353413Z ERR dnsproxyd[2703]: ERROR dnsproxyd: [object_proxy.cc(576)] Failed to call method: org.chromium.flimflam.Manager.GetProperties: object_path= /: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.flimflam was not provided by any .service files 2024-11-01T16:54:37.353452Z ERR dnsproxyd[2703]: ERROR dnsproxyd: [dbus_method_invoker.h(114)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=org.freedesktop.DBus.Error.ServiceUnknown, Message=Error calling D-Bus method: org.chromium.flimflam.Manager.GetProperties: The name org.chromium.flimflam was not provided by any .service files 2024-11-01T16:54:37.353474Z WARNING dnsproxyd[2703]: WARNING dnsproxyd: [client.cc(357)] Unable to get shill Manager properties, likely because shill is unavailable 2024-11-01T16:54:37.377445Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: nullopt, IPv6 addresses: [], DNS: []}, priority {31}, area 0x80000000 2024-11-01T16:54:39.584290Z INFO patchpaneld[2025]: INFO patchpaneld: [patchpanel_adaptor.cc(90)] ARCVM shutting down 2024-11-01T16:54:39.586143Z INFO patchpaneld[2025]: INFO patchpaneld: [arc_service.cc(651)] Removing ARC Device { type: ARCVM, arc_device_ifname: vmtap5, arc_ipv4_addr: 100.115.92.22/30, arc_device_mac_addr: (MAC OUI=42:37:05 IFACE=11), bridge_ifname: arc_wlan0, bridge_ipv4_addr: 100.115.92.21/30, guest_device_ifname: eth5, shill_ifname: wlan0} 2024-11-01T16:54:39.586456Z INFO patchpaneld[2025]: INFO patchpaneld: [guest_ipv6_service.cc(223)] StopForwarding: uplink: wlan0, downlink: arc_wlan0 2024-11-01T16:54:39.586571Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(1069)] Stopping multicast forwarding from {shill_device: wlan0, type: wifi, ifname: wlan0, ifindex: 2, service: /service/0} to arc_wlan0 2024-11-01T16:54:39.586656Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(1025)] Stopping broadcast forwarding from {shill_device: wlan0, type: wifi, ifname: wlan0, ifindex: 2, service: /service/0} to arc_wlan0 2024-11-01T16:54:39.587757Z INFO patchpaneld[2271]: INFO patchpaneld: [multicast_proxy.cc(146)] Disabling forwarding outbound mDNS traffic between wlan0 and arc_wlan0 2024-11-01T16:54:39.588132Z INFO patchpaneld[2271]: INFO patchpaneld: [multicast_proxy.cc(150)] Disabling forwarding inbound mDNS traffic between wlan0 and arc_wlan0 2024-11-01T16:54:39.588343Z INFO patchpaneld[2271]: INFO patchpaneld: [multicast_proxy.cc(157)] Disabling forwarding outbound SSDP traffic between wlan0 and arc_wlan0 2024-11-01T16:54:39.588367Z INFO patchpaneld[2271]: INFO patchpaneld: [multicast_proxy.cc(161)] Disabling forwarding inbound SSDP traffic between wlan0 and arc_wlan0 2024-11-01T16:54:39.588537Z INFO patchpaneld[2271]: INFO patchpaneld: [multicast_proxy.cc(211)] Disabling broadcast forwarding between wlan0 and arc_wlan0 2024-11-01T16:54:39.589058Z INFO dnsproxyd[5365]: INFO dnsproxyd: [proxy.cc(177)] {arc:wlan0} Stopping DNS proxy (0) 2024-11-01T16:54:39.605145Z INFO dnsproxyd[1896]: INFO dnsproxyd: [process_reaper.cc(78)] Untracked process 5365 terminated with status 0 (code = 1) 2024-11-01T16:54:39.703262Z INFO patchpaneld[2025]: INFO patchpaneld: [arc_service.cc(523)] Stopped ARC management Device { type: ARCVM, arc_device_ifname: vmtap0, arc_ipv4_addr: 100.115.92.2/30, arc_device_mac_addr: (MAC OUI=42:37:05 IFACE=12), bridge_ifname: arcbr0, bridge_ipv4_addr: 100.115.92.1/30, guest_device_ifname: arc0} 2024-11-01T16:54:39.879662Z INFO patchpaneld[2025]: INFO patchpaneld: [manager.cc(858)] OnConnectedNamespaceAutoclose: { pid: 5365, source: ARC, outbound_ifname: wlan0, route_on_vpn: 0, host_ifname: arc_ns2, peer_ifname: veth2, peer_ipv4_subnet: 100.115.92.136/30, static_ipv6_subnet: (IPv6: 4)/64} 2024-11-01T16:54:39.879717Z INFO patchpaneld[2025]: INFO patchpaneld: [guest_ipv6_service.cc(223)] StopForwarding: uplink: wlan0, downlink: arc_ns2 2024-11-01T16:54:39.982539Z INFO dnsproxyd[2703]: INFO dnsproxyd: [proxy.cc(408)] {system:_} Service disabled by user logout 2024-11-01T16:54:39.982558Z INFO dnsproxyd[2715]: INFO dnsproxyd: [proxy.cc(408)] {default:_} Service disabled by user logout 2024-11-01T16:54:39.982628Z WARNING dnsproxyd[2703]: WARNING dnsproxyd: [proxy.cc(770)] {system:_} No connection to shill - cannot set dns-proxy address property IPv4 [], IPv6 [] 2024-11-01T16:54:39.983018Z WARNING dnsproxyd[1896]: WARNING dnsproxyd: [resolv_conf.cc(59)] Setting resolv.conf to [] 2024-11-01T16:55:08.657878Z NOTICE wpa_supplicant[792]: Successfully initialized wpa_supplicant 2024-11-01T16:55:09.209623Z INFO shill[1195]: INFO shill: [manager.cc(347)] Manager started. 2024-11-01T16:55:09.215556Z INFO shill[1195]: INFO shill: [power_manager_proxy.cc(413)] OnSignalConnected interface: org.chromium.PowerManager signal: SuspendImminentsuccess: 1 2024-11-01T16:55:09.216418Z INFO shill[1195]: INFO shill: [power_manager_proxy.cc(413)] OnSignalConnected interface: org.chromium.PowerManager signal: SuspendDonesuccess: 1 2024-11-01T16:55:09.217071Z INFO shill[1195]: INFO shill: [power_manager_proxy.cc(413)] OnSignalConnected interface: org.chromium.PowerManager signal: DarkSuspendImminentsuccess: 1 2024-11-01T16:55:09.415283Z INFO shill[1195]: INFO shill: [manager.cc(555)] Push default profile. 2024-11-01T16:55:09.418276Z INFO shill[1195]: INFO shill: [manager.cc(1990)] Setting always-on VPN to mode=off service=nullptr 2024-11-01T16:55:09.418834Z INFO shill[1195]: INFO shill: [manager.cc(602)] PushProfileInternal finished; 1 profile(s) now present. 2024-11-01T16:55:09.419170Z INFO shill[1195]: INFO shill: [modem_info.cc(41)] Start 2024-11-01T16:55:09.422802Z INFO shill[1195]: INFO shill: [service.cc(1404)] Service ethernet_2: SetAutoConnect: 1 2024-11-01T16:55:09.424203Z INFO shill[1195]: INFO shill: [p2p_manager.cc(136)] Start 2024-11-01T16:55:09.445164Z ERR shill[1195]: ERROR shill: [utils.cc(84)] AddDBusError(...): Domain=dbus, Code=org.freedesktop.DBus.Error.ServiceUnknown, Message=The name org.chromium.PatchPanel was not provided by any .service files 2024-11-01T16:55:09.445442Z ERR shill[1195]: ERROR shill: [client.cc(662)] OnGetTrafficCountersError(): The name org.chromium.PatchPanel was not provided by any .service files 2024-11-01T16:55:09.530975Z INFO shill[1195]: INFO shill: [power_manager.cc(225)] OnPowerManagerAppeared 2024-11-01T16:55:09.531044Z INFO shill[1195]: INFO shill: [power_manager_proxy.cc(196)] RegisterSuspendDelayInternal(19500, dark=false) 2024-11-01T16:55:09.531184Z INFO shill[1195]: INFO shill: [power_manager_proxy.cc(196)] RegisterSuspendDelayInternal(19500, dark=true) 2024-11-01T16:55:09.847989Z INFO shill[1195]: INFO shill: [device_info.cc(1378)] Creating WiFi device for station mode interface wlan0 at interface index 2 2024-11-01T16:55:09.852924Z INFO shill[1195]: INFO shill: [manager.cc(1195)] Device wlan0 registered. 2024-11-01T16:55:09.853024Z INFO shill[1195]: INFO shill: [manager.cc(1565)] Device wlan0 updated: enabled 2024-11-01T16:55:09.864697Z INFO shill[1195]: INFO shill: [device.cc(655)] SetEnabledChecked: wlan0 no_service starting 2024-11-01T16:55:09.865313Z INFO shill[1195]: INFO shill: [device.cc(708)] wlan0 no_service SetEnabledUnchecked(true) 2024-11-01T16:55:09.878615Z INFO shill[1195]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:55:09.895549Z INFO shill[1195]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: No such file or directory (2) 2024-11-01T16:55:09.897014Z INFO shill[1195]: INFO shill: [wifi.cc(3612)] wlan0: disabled supplicant: absent proxy: null 2024-11-01T16:55:09.897196Z INFO shill[1195]: INFO shill: [device.cc(608)] OnEnabledStateChanged: wlan0 no_service (target: 1, success: 1) 2024-11-01T16:55:09.897597Z INFO shill[1195]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:55:09.897729Z WARNING shill[1195]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:55:09.898342Z INFO shill[1195]: INFO shill: [wifi.cc(3532)] WPA supplicant presence changed: 1 2024-11-01T16:55:09.898476Z INFO shill[1195]: INFO shill: [wifi.cc(3612)] wlan0: enabled supplicant: present proxy: null 2024-11-01T16:55:09.898605Z INFO shill[1195]: INFO shill: [wifi.cc(3562)] WiFi debug scope changed; enable is now 0 2024-11-01T16:55:10.374761Z NOTICE wpa_supplicant[792]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US 2024-11-01T16:55:10.374763Z INFO shill[1195]: INFO shill: [wifi.cc(3666)] connected to supplicant on attempt 1 2024-11-01T16:55:10.419012Z INFO shill[1195]: INFO shill: [wifi_provider.cc(1540)] RegionChanged: Country notification: US 2024-11-01T16:55:10.448003Z INFO shill[1195]: INFO shill: [bluetooth_manager.cc(97)] OnBTManagerAvailable: BT manager is available 2024-11-01T16:55:10.448060Z INFO shill[1195]: INFO shill: [bluetooth_manager.cc(69)] Completing initialization of BT manager 2024-11-01T16:55:10.449642Z INFO shill[1195]: INFO shill: [bluetooth_manager.cc(83)] BT manager found 0 adapters 2024-11-01T16:55:10.449707Z INFO shill[1195]: INFO shill: [bluetooth_manager.cc(93)] Completed initialization of BT manager 2024-11-01T16:55:10.458792Z INFO shill[1195]: INFO shill: [power_manager_proxy.cc(172)] ChangeRegDomain 2024-11-01T16:55:10.575567Z INFO shill[1195]: INFO shill: [p2p_manager.cc(472)] SetAllowed Allowed set to true 2024-11-01T16:55:10.575621Z INFO shill[1195]: INFO shill: [p2p_manager.cc(140)] Stop 2024-11-01T16:55:11.413393Z INFO shill[1195]: INFO shill: [manager.cc(2766)] The WiFi AP list is empty 2024-11-01T16:55:11.500157Z INFO shill[1195]: INFO shill: [manager.cc(3259)] Received command for network throttling disabling 2024-11-01T16:55:11.523680Z ERR shill[1195]: ERROR shill: [throttler.cc(226)] Throttler failed with status: 1 2024-11-01T16:55:12.048376Z INFO dnsproxyd[1895]: INFO dnsproxyd: [controller.cc(93)] Starting DNS Proxy service 2024-11-01T16:55:12.068803Z INFO dnsproxyd[1895]: INFO dnsproxyd: [client.cc(391)] Default service changed from [] to [/] 2024-11-01T16:55:12.081916Z NOTICE ModemManager[1904]: ModemManager (version 1.23.9) starting in system bus... 2024-11-01T16:55:12.091075Z INFO patchpanel_bpf_loader[1884]: Pinned bpf program match_dtls_srtp at /sys/fs/bpf/patchpanel/match_dtls_srtp 2024-11-01T16:55:12.160720Z INFO shill[1195]: INFO shill: [dbus_objectmanager_proxy.cc(100)] OnServiceOwnerChanged old: new: :1.69 2024-11-01T16:55:12.160794Z INFO shill[1195]: INFO shill: [dbus_objectmanager_proxy.cc(86)] OnServiceAvailable: 1 2024-11-01T16:55:12.160864Z INFO shill[1195]: INFO shill: [dbus_objectmanager_proxy.cc(86)] OnServiceAvailable: 1 2024-11-01T16:55:12.160925Z INFO shill[1195]: INFO shill: [modem_info.cc(122)] OnAppeared 2024-11-01T16:55:12.160944Z INFO shill[1195]: INFO shill: [modem_info.cc(89)] Connect 2024-11-01T16:55:12.161059Z INFO shill[1195]: INFO shill: [modem_info.cc(122)] OnAppeared 2024-11-01T16:55:12.161079Z INFO shill[1195]: INFO shill: [modem_info.cc(89)] Connect 2024-11-01T16:55:12.189204Z INFO patchpaneld[2007]: INFO patchpaneld: [main.cc(74)] Starting patchpanel D-Bus daemon 2024-11-01T16:55:12.197117Z INFO shill[1195]: INFO shill: [modem_info.cc(165)] OnGetManagedObjectsReply: 1 2024-11-01T16:55:12.197188Z INFO shill[1195]: INFO shill: [modem_info.cc(165)] OnGetManagedObjectsReply: 1 2024-11-01T16:55:12.377125Z INFO patchpaneld[2036]: INFO patchpaneld: [main.cc(68)] Spawning socket D-Bus daemon 2024-11-01T16:55:12.391467Z INFO patchpaneld[2029]: INFO patchpaneld: [main.cc(47)] Spawning adb proxy 2024-11-01T16:55:12.420634Z INFO patchpaneld[2034]: INFO patchpaneld: [main.cc(54)] Spawning nd proxy 2024-11-01T16:55:12.423050Z INFO patchpaneld[2034]: INFO patchpaneld: [ndproxy.cc(830)] Started watching on packet fd... 2024-11-01T16:55:12.424318Z INFO patchpaneld[2033]: INFO patchpaneld: [main.cc(61)] Spawning multicast proxy 2024-11-01T16:55:12.453275Z INFO patchpaneld[2029]: INFO patchpaneld: [adb_proxy.cc(326)] Chrome OS is not in developer mode and ADB sideloading is not enabled. ADB proxy is not listening 2024-11-01T16:55:12.759856Z INFO dnsproxyd[1895]: INFO dnsproxyd: [controller.cc(178)] Service enabled by feature flag 2024-11-01T16:55:12.762814Z INFO dnsproxyd[1895]: INFO dnsproxyd: [controller.cc(316)] Launched process for proxy {system:}(pid: 2348) 2024-11-01T16:55:12.765571Z INFO dnsproxyd[1895]: INFO dnsproxyd: [controller.cc(316)] Launched process for proxy {default:}(pid: 2350) 2024-11-01T16:55:12.771576Z WARNING dnsproxyd[2350]: libminijail[2350]: ioctl(SIOCSIFFLAGS) failed: Operation not permitted 2024-11-01T16:55:12.776824Z WARNING dnsproxyd[2348]: libminijail[2348]: ioctl(SIOCSIFFLAGS) failed: Operation not permitted 2024-11-01T16:55:12.816999Z WARNING dnsproxyd[2348]: WARNING dnsproxyd: [socket.cc(257)] Failed to increase receive buffer size to 3145728b: Operation not permitted (1) 2024-11-01T16:55:12.817158Z INFO dnsproxyd[2348]: INFO dnsproxyd: [proxy.cc(168)] {system:_} Starting DNS proxy 2024-11-01T16:55:12.819919Z WARNING dnsproxyd[2350]: WARNING dnsproxyd: [socket.cc(257)] Failed to increase receive buffer size to 3145728b: Operation not permitted (1) 2024-11-01T16:55:12.820064Z INFO dnsproxyd[2350]: INFO dnsproxyd: [proxy.cc(168)] {default:_} Starting DNS proxy 2024-11-01T16:55:12.824143Z INFO patchpaneld[2007]: INFO patchpaneld: [conntrack_monitor.cc(70)] ConntrackMonitor started 2024-11-01T16:55:12.824215Z INFO patchpaneld[2007]: INFO patchpaneld: [conntrack_monitor.cc(194)] ConntrackMonitor added listener 2024-11-01T16:55:12.962597Z INFO shill[1195]: INFO shill: [manager.cc(2917)] OnPatchpanelClientReady 2024-11-01T16:55:12.964400Z INFO shill[1195]: INFO shill: [manager.cc(1990)] Setting always-on VPN to mode=off service=nullptr 2024-11-01T16:55:13.338457Z WARNING ModemManager[1904]: [plugin-manager] task 0: port context already scheduled 2024-11-01T16:55:13.353045Z INFO patchpaneld[2007]: INFO patchpaneld: [manager.cc(830)] Connected network namespace { pid: 2350, source: USER, route_on_vpn: 1, host_ifname: arc_ns0, peer_ifname: veth0, peer_ipv4_subnet: 100.115.92.128/30, static_ipv6_subnet: (IPv6: 5)/64} 2024-11-01T16:55:13.354770Z INFO dnsproxyd[2350]: INFO dnsproxyd: [client.cc(1373)] ConnectNamespace for netns pid 2350 succeeded: peer_ifname=veth0 peer_ipv4_address=100.115.92.130 host_ifname=arc_ns0 host_ipv4_address=100.115.92.129 subnet=100.115.92.128/30 2024-11-01T16:55:13.354833Z INFO dnsproxyd[2350]: INFO dnsproxyd: [proxy.cc(257)] {default:_} Successfully connected private network namespace: arc_ns0 <--> veth0 2024-11-01T16:55:13.363867Z INFO dnsproxyd[2350]: INFO dnsproxyd: [client.cc(391)] Default service changed from [] to [/] 2024-11-01T16:55:13.365575Z INFO dnsproxyd[2350]: INFO dnsproxyd: [client.cc(1022)] Patchpanel reset 2024-11-01T16:55:13.365948Z WARNING dnsproxyd[2350]: WARNING dnsproxyd: [proxy.cc(329)] {default:_} Patchpanel has been reset 2024-11-01T16:55:13.373327Z INFO dnsproxyd[2350]: INFO dnsproxyd: [proxy.cc(1014)] {default:_} Peer IPv6 addr updated to (IPv6: 6) 2024-11-01T16:55:13.833341Z INFO patchpaneld[2007]: INFO patchpaneld: [manager.cc(830)] Connected network namespace { pid: 2348, source: SYSTEM, route_on_vpn: 0, host_ifname: arc_ns1, peer_ifname: veth1, peer_ipv4_subnet: 100.115.92.132/30, static_ipv6_subnet: (IPv6: 7)/64} 2024-11-01T16:55:13.835311Z INFO patchpaneld[2007]: INFO patchpaneld: [manager.cc(1171)] SetFeatureFlag: set WiFi QoS to 0 from 0 2024-11-01T16:55:13.838826Z INFO dnsproxyd[2348]: INFO dnsproxyd: [client.cc(1373)] ConnectNamespace for netns pid 2348 succeeded: peer_ifname=veth1 peer_ipv4_address=100.115.92.134 host_ifname=arc_ns1 host_ipv4_address=100.115.92.133 subnet=100.115.92.132/30 2024-11-01T16:55:13.838911Z INFO dnsproxyd[2348]: INFO dnsproxyd: [proxy.cc(257)] {system:_} Successfully connected private network namespace: arc_ns1 <--> veth1 2024-11-01T16:55:13.839709Z INFO dnsproxyd[1895]: INFO dnsproxyd: [client.cc(1022)] Patchpanel reset 2024-11-01T16:55:13.839771Z WARNING dnsproxyd[1895]: WARNING dnsproxyd: [controller.cc(203)] Patchpanel has been reset 2024-11-01T16:55:13.854481Z INFO dnsproxyd[2348]: INFO dnsproxyd: [client.cc(391)] Default service changed from [] to [/] 2024-11-01T16:55:13.854856Z INFO dnsproxyd[2348]: INFO dnsproxyd: [client.cc(1022)] Patchpanel reset 2024-11-01T16:55:13.855233Z WARNING dnsproxyd[2348]: WARNING dnsproxyd: [proxy.cc(329)] {system:_} Patchpanel has been reset 2024-11-01T16:55:13.864445Z INFO dnsproxyd[2348]: INFO dnsproxyd: [proxy.cc(1014)] {system:_} Peer IPv6 addr updated to (IPv6: 8) 2024-11-01T16:55:13.960537Z INFO patchpaneld[2007]: INFO patchpaneld: [manager.cc(173)] RunDelayedInitialization: start 2024-11-01T16:55:13.960621Z INFO patchpaneld[2007]: INFO patchpaneld: [qos_service.cc(81)] DoHUpdater called with 0 valid hostnames 2024-11-01T16:55:13.960690Z INFO patchpaneld[2007]: INFO patchpaneld: [qos_service.cc(157)] Updating iptables rules for QoS with 0 IPv4 addrs and 0 IPv6 addrs 2024-11-01T16:55:13.999485Z INFO patchpaneld[2007]: INFO patchpaneld: [shill_client.cc(430)] New shill Device {shill_device: wlan0, type: wifi, ifname: wlan0, ifindex: 2, service: /} 2024-11-01T16:55:14.060483Z INFO shill[1195]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_4. sig: -50, sec: wpa2+wpa3, freq: 5765 2024-11-01T16:55:14.069966Z INFO shill[1195]: INFO shill: [wifi_provider.cc(511)] Assigning endpoint (MAC OUI=fe:9e:38 IFACE=6) to service wifi_psk_1 2024-11-01T16:55:14.070049Z INFO shill[1195]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_1. sig: -50, sec: wpa2+wpa3, freq: 5765 2024-11-01T16:55:14.121391Z INFO patchpaneld[2007]: INFO patchpaneld: [datapath.cc(1438)] Start connection pinning on wlan0 fwmark=0x03ea0000 2024-11-01T16:55:14.153477Z INFO shill[1195]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:55:14.167206Z INFO patchpaneld[2007]: INFO patchpaneld: [network_monitor_service.cc(171)] ipconfigs changed on wlan0, update watching entries 2024-11-01T16:55:14.167260Z INFO patchpaneld[2007]: INFO patchpaneld: [network_monitor_service.cc(188)] Stop due to empty watching list on wlan0 2024-11-01T16:55:14.167421Z INFO patchpaneld[2007]: INFO patchpaneld: [manager.cc(196)] RunDelayedInitialization: finished 2024-11-01T16:55:14.178083Z INFO shill[1195]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_5. sig: -50, sec: wpa2, freq: 5765 2024-11-01T16:55:14.181900Z INFO shill[1195]: INFO shill: [wifi_provider.cc(511)] Assigning endpoint (MAC OUI=ea:9e:38 IFACE=2) to service wifi_psk_0 2024-11-01T16:55:14.181979Z INFO shill[1195]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_0. sig: -50, sec: wpa2, freq: 5765 2024-11-01T16:55:14.187426Z INFO shill[1195]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_6. sig: -50, sec: wpa2, freq: 5765 2024-11-01T16:55:14.193005Z INFO shill[1195]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_7. sig: -50, sec: wpa2, freq: 5765 2024-11-01T16:55:14.197430Z INFO shill[1195]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_8. sig: -50, sec: wpa2, freq: 5765 2024-11-01T16:55:14.243129Z INFO shill[1195]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_9. sig: -53, sec: wpa2, freq: 2437 2024-11-01T16:55:14.253511Z INFO shill[1195]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_10. sig: -68, sec: wpa2, freq: 2437 2024-11-01T16:55:14.262603Z INFO shill[1195]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_11. sig: -79, sec: wpa+wpa2, freq: 2462 2024-11-01T16:55:14.266522Z INFO shill[1195]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged shill-unknown -> inactive 2024-11-01T16:55:14.266849Z INFO shill[1195]: INFO shill: [service.cc(2341)] Service wifi_psk_0: AutoConnect=1->1 2024-11-01T16:55:14.364291Z INFO shill[1195]: INFO shill: [service.cc(2341)] Service wifi_psk_1: AutoConnect=0->0 2024-11-01T16:55:14.448480Z INFO shill[1195]: INFO shill: [service.cc(403)] Auto-connecting to wifi_psk_0 2024-11-01T16:55:14.448521Z INFO shill[1195]: INFO shill: [service.cc(462)] Connecting to wifi Service wifi_psk_0: AutoConnect 2024-11-01T16:55:14.469028Z INFO shill[1195]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:55:14.469831Z INFO shill[1195]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:55:14.498314Z NOTICE wpa_supplicant[792]: SME: Trying to authenticate with (MAC OUI=ea:9e:38 IFACE=2) (SSID='(SSID: 2)' freq=5765 MHz) 2024-11-01T16:55:14.525448Z INFO shill[1195]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Idle -> Associating 2024-11-01T16:55:14.525488Z INFO shill[1195]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Associating 2024-11-01T16:55:14.527027Z INFO shill[1195]: INFO shill: [network.cc(331)] wlan0 wlan0: Stopping normally, network config: {IPv4 address: nullopt, IPv6 addresses: [], DNS: []} 2024-11-01T16:55:14.571650Z NOTICE wpa_supplicant[792]: Trying to associate with (MAC OUI=ea:9e:38 IFACE=2) (SSID='(SSID: 2)' freq=5765 MHz) 2024-11-01T16:55:14.585851Z INFO shill[1195]: INFO shill: [wifi_provider.cc(1540)] RegionChanged: Country notification: US 2024-11-01T16:55:14.586297Z NOTICE wpa_supplicant[792]: wlan0: Associated with (MAC OUI=ea:9e:38 IFACE=2) 2024-11-01T16:55:14.586427Z NOTICE wpa_supplicant[792]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 2024-11-01T16:55:14.586811Z NOTICE wpa_supplicant[792]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US 2024-11-01T16:55:14.587574Z NOTICE wpa_supplicant[792]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US 2024-11-01T16:55:14.592867Z INFO shill[1195]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged inactive -> authenticating 2024-11-01T16:55:14.602489Z INFO shill[1195]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged authenticating -> associating 2024-11-01T16:55:14.602570Z INFO shill[1195]: INFO shill: [wifi.cc(1178)] WiFi wlan0 CurrentBSS (unknown) -> /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/25 2024-11-01T16:55:14.603395Z INFO shill[1195]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged associating -> associated 2024-11-01T16:55:14.614908Z INFO patchpaneld[2007]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:55:14.647548Z INFO shill[1195]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged associated -> 4way_handshake 2024-11-01T16:55:14.651946Z NOTICE wpa_supplicant[792]: wlan0: WPA: Key negotiation completed with (MAC OUI=ea:9e:38 IFACE=2) [PTK=CCMP GTK=CCMP] 2024-11-01T16:55:14.652052Z NOTICE wpa_supplicant[792]: wlan0: CTRL-EVENT-CONNECTED - Connection to (MAC OUI=ea:9e:38 IFACE=2) completed [id=0 id_str=] 2024-11-01T16:55:14.673036Z INFO shill[1195]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged 4way_handshake -> completed 2024-11-01T16:55:14.673869Z INFO shill[1195]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:55:14.678873Z INFO shill[1195]: INFO shill: [legacy_dhcpcd_proxy.cc(216)] Created dhcpcd with pid 3512 and args: -B -f /etc/dhcpcd7.conf -i chromeos -q -4 -o captive_portal_uri --nodelay -h wlan0 2024-11-01T16:55:14.679214Z INFO shill[1195]: INFO shill: [network.cc(234)] wlan0 wifi_psk_0: Started IP provisioning, dhcp: started, accept_ra: true 2024-11-01T16:55:14.679268Z INFO shill[1195]: INFO shill: [network.cc(237)] wlan0 wifi_psk_0 initial config: wlan0: combined config {IPv4 address: nullopt, IPv6 addresses: [], DNS: []} 2024-11-01T16:55:14.679310Z INFO shill[1195]: INFO shill: [wifi.cc(2739)] wlan0 is up; started L3 configuration. 2024-11-01T16:55:14.680613Z INFO shill[1195]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:55:14.726574Z INFO shill[1195]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:55:14.727065Z INFO shill[1195]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Associating -> Configuring 2024-11-01T16:55:14.727102Z INFO shill[1195]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Configuring 2024-11-01T16:55:14.778484Z INFO dhcpcd7[3512]: status changed to Init 2024-11-01T16:55:14.794419Z INFO shill[1195]: INFO shill: [legacy_dhcpcd_proxy.cc(307)] SetDBusProxyIfPending: Set the D-Bus proxy to LegacyDHCPCDProxy for pid: 3512 2024-11-01T16:55:14.806927Z INFO patchpaneld[2007]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:55:14.819294Z INFO patchpaneld[2007]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:55:14.819990Z INFO patchpaneld[2007]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: nullopt, IPv6 addresses: [], DNS: []}, priority {31}, area 0x80000000 2024-11-01T16:55:14.833012Z INFO dhcpcd7[3512]: status changed to Discover 2024-11-01T16:55:14.833283Z INFO dhcpcd7[3512]: wlan0: soliciting a DHCP lease 2024-11-01T16:55:14.833313Z INFO dhcpcd7[3512]: wlan0: sending DISCOVER (xid 0x628efcfb), next in 3.3 seconds 2024-11-01T16:55:14.874956Z INFO patchpaneld[2007]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:55:14.909125Z INFO shill[1195]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:55:14.912616Z INFO patchpaneld[2007]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:55:14.916804Z NOTICE wpa_supplicant[792]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-56 noise=-98 txrate=78000 2024-11-01T16:55:14.916857Z ERR wpa_supplicant[792]: dbus: wpa_dbus_property_changed: no property SignalChange in object /fi/w1/wpa_supplicant1/Interfaces/0 2024-11-01T16:55:14.954456Z INFO shill[1195]: INFO shill: [manager.cc(2169)] ScanAndConnectToBestServices: ensure scan 2024-11-01T16:55:15.386841Z INFO dhcpcd7[3512]: wlan0: received OFFER with xid 0x628efcfb 2024-11-01T16:55:15.386883Z INFO dhcpcd7[3512]: wlan0: offered (10.0.0.0/8: 3) from (10.0.0.0/8: 7) 2024-11-01T16:55:15.386904Z INFO dhcpcd7[3512]: status changed to Request 2024-11-01T16:55:15.387080Z INFO dhcpcd7[3512]: wlan0: requesting lease of (10.0.0.0/8: 3) 2024-11-01T16:55:15.387117Z INFO dhcpcd7[3512]: wlan0: sending REQUEST (xid 0x628efcfb), next in 4.5 seconds 2024-11-01T16:55:15.397580Z INFO dhcpcd7[3512]: wlan0: received ACK with xid 0x628efcfb 2024-11-01T16:55:15.397825Z INFO dhcpcd7[3512]: wlan0: acknowledged (10.0.0.0/8: 3) from (10.0.0.0/8: 7) 2024-11-01T16:55:15.397863Z INFO dhcpcd7[3512]: wlan0: leased (10.0.0.0/8: 3) for 86400 seconds 2024-11-01T16:55:15.398432Z INFO dhcpcd7[3512]: event BOUND on interface wlan0 2024-11-01T16:55:15.398880Z INFO dhcpcd7[3512]: status changed to Bound 2024-11-01T16:55:15.399160Z INFO dhcpcd7[3512]: wlan0: adding route to (10.0.0.0/8: 8)/21 2024-11-01T16:55:15.399186Z INFO dhcpcd7[3512]: wlan0: adding default route via (10.0.0.0/8: 7) 2024-11-01T16:55:15.399896Z INFO shill[1195]: INFO shill: [network.cc(465)] wlan0 wifi_psk_0: DHCP lease acquired {IPv4 address: (10.0.0.0/8: 3)/21, IPv4 broadcast: (10.0.0.0/8: 9), IPv4 gateway: (10.0.0.0/8: 7), IPv6 addresses: [], DNS: [(IPv4: 1),(IPv4: 2)]} 2024-11-01T16:55:15.401911Z INFO shill[1195]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:55:15.603425Z ERR shill[1195]: ERROR shill: [object_proxy.cc(576)] Failed to call method: org.chromium.bluetooth.Bluetooth.GetProfileConnectionState: object_path= /org/chromium/bluetooth/hci0/adapter: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.bluetooth was not provided by any .service files 2024-11-01T16:55:15.603465Z ERR shill[1195]: ERROR shill: [dbus_method_invoker.h(114)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=org.freedesktop.DBus.Error.ServiceUnknown, Message=Error calling D-Bus method: org.chromium.bluetooth.Bluetooth.GetProfileConnectionState: The name org.chromium.bluetooth was not provided by any .service files 2024-11-01T16:55:15.603490Z ERR shill[1195]: ERROR shill: [bluetooth_adapter_proxy.cc(104)] Failed to query BT profile connection state: org.freedesktop.DBus.Error.ServiceUnknown Error calling D-Bus method: org.chromium.bluetooth.Bluetooth.GetProfileConnectionState: The name org.chromium.bluetooth was not provided by any .service files 2024-11-01T16:55:15.603505Z ERR shill[1195]: ERROR shill: [bluetooth_manager.cc(186)] Failed to query profile connection state 2024-11-01T16:55:15.604315Z ERR shill[1195]: ERROR shill: [object_proxy.cc(576)] Failed to call method: org.chromium.bluetooth.Bluetooth.GetProfileConnectionState: object_path= /org/chromium/bluetooth/hci0/adapter: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.bluetooth was not provided by any .service files 2024-11-01T16:55:15.604344Z ERR shill[1195]: ERROR shill: [dbus_method_invoker.h(114)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=org.freedesktop.DBus.Error.ServiceUnknown, Message=Error calling D-Bus method: org.chromium.bluetooth.Bluetooth.GetProfileConnectionState: The name org.chromium.bluetooth was not provided by any .service files 2024-11-01T16:55:15.604364Z ERR shill[1195]: ERROR shill: [bluetooth_adapter_proxy.cc(104)] Failed to query BT profile connection state: org.freedesktop.DBus.Error.ServiceUnknown Error calling D-Bus method: org.chromium.bluetooth.Bluetooth.GetProfileConnectionState: The name org.chromium.bluetooth was not provided by any .service files 2024-11-01T16:55:15.604375Z ERR shill[1195]: ERROR shill: [bluetooth_manager.cc(186)] Failed to query profile connection state 2024-11-01T16:55:15.605092Z ERR shill[1195]: ERROR shill: [object_proxy.cc(576)] Failed to call method: org.chromium.bluetooth.Bluetooth.IsDiscovering: object_path= /org/chromium/bluetooth/hci0/adapter: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.bluetooth was not provided by any .service files 2024-11-01T16:55:15.605121Z ERR shill[1195]: ERROR shill: [dbus_method_invoker.h(114)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=org.freedesktop.DBus.Error.ServiceUnknown, Message=Error calling D-Bus method: org.chromium.bluetooth.Bluetooth.IsDiscovering: The name org.chromium.bluetooth was not provided by any .service files 2024-11-01T16:55:15.605140Z ERR shill[1195]: ERROR shill: [bluetooth_adapter_proxy.cc(118)] Failed to query BT discovering state: org.freedesktop.DBus.Error.ServiceUnknown Error calling D-Bus method: org.chromium.bluetooth.Bluetooth.IsDiscovering: The name org.chromium.bluetooth was not provided by any .service files 2024-11-01T16:55:15.605152Z ERR shill[1195]: ERROR shill: [bluetooth_manager.cc(203)] Failed to query discovering state 2024-11-01T16:55:15.605557Z INFO shill[1195]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:55:15.606270Z INFO shill[1195]: INFO shill: [network.cc(247)] wlan0 wifi_psk_0: Setting IPv4 connection 2024-11-01T16:55:15.617475Z INFO patchpaneld[2007]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: (10.0.0.0/8: 3)/21, IPv4 broadcast: (10.0.0.0/8: 9), IPv4 gateway: (10.0.0.0/8: 7), IPv6 addresses: [], DNS: [(IPv4: 1),(IPv4: 2)]}, priority {31}, area 0x70007 2024-11-01T16:55:15.617910Z INFO patchpaneld[2007]: INFO patchpaneld: [address_service.cc(83)] SetIPv4Address: adding new address (10.0.0.0/8: 3)/21 2024-11-01T16:55:15.618099Z INFO dhcpcd7[3512]: wlan0: pid -852920976 deleted route to (10.0.0.0/8: 8)/21 2024-11-01T16:55:15.618102Z WARNING patchpaneld[2007]: WARNING patchpaneld: [routing_table.cc(110)] Successfully removed routing entry but could not find the corresponding entry in patchpanel's representation of the routing table. 2024-11-01T16:55:15.620695Z INFO patchpaneld[2007]: INFO patchpaneld: [shill_client.cc(727)] [/device/wlan0]: IPConfig changed: { ipv4_cidr: (10.0.0.0/8: 3)/21, ipv4_gateway: (10.0.0.0/8: 7), ipv4_dns: [(IPv4: 1),(IPv4: 2)], ipv6_cidr: ::/0, ipv6_gateway: ::, ipv6_dns: []} 2024-11-01T16:55:15.675272Z INFO patchpaneld[2007]: INFO patchpaneld: [network_monitor_service.cc(171)] ipconfigs changed on wlan0, update watching entries 2024-11-01T16:55:15.675344Z INFO patchpaneld[2007]: INFO patchpaneld: [network_monitor_service.cc(135)] IPv4 watching entries added on wlan0: skipped_dns_num=2 ,watching_dns_num=0 2024-11-01T16:55:15.676383Z INFO shill[1195]: INFO shill: [network.cc(291)] wlan0 wifi_psk_0: OnSetupConnectionFinished(success: true) 2024-11-01T16:55:15.676425Z INFO shill[1195]: INFO shill: [network.cc(881)] wlan0 wifi_psk_0: RequestNetworkValidation(NetworkConnectionUpdate): Network validation is disabled 2024-11-01T16:55:15.676453Z INFO shill[1195]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Configuring -> Connected 2024-11-01T16:55:15.690278Z INFO shill[1195]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Connected 2024-11-01T16:55:15.698457Z INFO shill[1195]: INFO shill: [wifi_service.cc(854)] SendPostReadyStateMetrics wifi_psk_0: time_resume_to_ready=0 s 2024-11-01T16:55:15.699470Z INFO shill[1195]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Invalid argument (22) 2024-11-01T16:55:15.700181Z INFO dnsproxyd[2348]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [configuration] to [ready] 2024-11-01T16:55:15.700182Z INFO dnsproxyd[2350]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [configuration] to [ready] 2024-11-01T16:55:15.700184Z INFO dnsproxyd[1895]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [configuration] to [ready] 2024-11-01T16:55:15.706545Z INFO shill[1195]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:55:15.713468Z INFO shill[1195]: message repeated 2 times: [ INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11)] 2024-11-01T16:55:15.714186Z INFO shill[1195]: INFO shill: [device.cc(429)] wlan0 wifi_psk_0: Portal detection is disabled for this service 2024-11-01T16:55:15.714219Z INFO shill[1195]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Connected -> Online 2024-11-01T16:55:15.714459Z INFO shill[1195]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:55:15.727981Z INFO dnsproxyd[1895]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [ready] to [online] 2024-11-01T16:55:15.727982Z INFO dnsproxyd[2350]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [ready] to [online] 2024-11-01T16:55:15.727995Z INFO dnsproxyd[2348]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [ready] to [online] 2024-11-01T16:55:15.728251Z INFO shill[1195]: INFO shill: [manager.cc(1654)] Default physical service: wifi_psk_0 (online) 2024-11-01T16:55:15.731010Z INFO dnsproxyd[2350]: INFO dnsproxyd: [client.cc(391)] Default service changed from [/] to [/service/0] 2024-11-01T16:55:15.731011Z INFO dnsproxyd[2348]: INFO dnsproxyd: [client.cc(391)] Default service changed from [/] to [/service/0] 2024-11-01T16:55:15.731045Z INFO dnsproxyd[1895]: INFO dnsproxyd: [client.cc(391)] Default service changed from [/] to [/service/0] 2024-11-01T16:55:15.737838Z INFO dnsproxyd[2350]: INFO dnsproxyd: [proxy.cc(524)] {default:_} is now tracking [wlan0] 2024-11-01T16:55:15.738823Z INFO dnsproxyd[1895]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [(IPv4: 1),(IPv4: 2)] 2024-11-01T16:55:15.739872Z INFO dnsproxyd[2350]: INFO dnsproxyd: [resolver.cc(294)] {default:wlan0} Accepting UDP queries on {family: AF_INET6, port: 53, addr: ::} 2024-11-01T16:55:15.740032Z INFO dnsproxyd[2350]: INFO dnsproxyd: [resolver.cc(269)] {default:wlan0} Accepting TCP connections on {family: AF_INET6, port: 53, addr: ::} 2024-11-01T16:55:15.740375Z INFO dnsproxyd[2348]: INFO dnsproxyd: [proxy.cc(524)] {system:_} is now tracking [wlan0] 2024-11-01T16:55:15.742366Z INFO dnsproxyd[2350]: INFO dnsproxyd: [proxy.cc(888)] {default:wlan0} DoH: off 2024-11-01T16:55:15.743302Z INFO dnsproxyd[2348]: INFO dnsproxyd: [resolver.cc(294)] {system:wlan0} Accepting UDP queries on {family: AF_INET6, port: 53, addr: ::} 2024-11-01T16:55:15.743324Z INFO dnsproxyd[2350]: INFO dnsproxyd: [resolver.cc(676)] {default:wlan0} Name servers are updated, 0/2 validated name servers 2024-11-01T16:55:15.743428Z INFO dnsproxyd[2348]: INFO dnsproxyd: [resolver.cc(269)] {system:wlan0} Accepting TCP connections on {family: AF_INET6, port: 53, addr: ::} 2024-11-01T16:55:15.743660Z INFO dnsproxyd[2350]: INFO dnsproxyd: [proxy.cc(725)] {default:wlan0} applied device DNS configuration 2024-11-01T16:55:15.743848Z INFO patchpaneld[2007]: INFO patchpaneld: [shill_client.cc(334)] Default logical device changed from none to {shill_device: wlan0, type: wifi, ifname: wlan0, ifindex: 2, service: /service/0} 2024-11-01T16:55:15.743888Z INFO patchpaneld[2007]: INFO patchpaneld: [shill_client.cc(350)] Default physical device changed from none to {shill_device: wlan0, type: wifi, ifname: wlan0, ifindex: 2, service: /service/0} 2024-11-01T16:55:15.746383Z INFO dnsproxyd[2348]: INFO dnsproxyd: [proxy.cc(888)] {system:wlan0} DoH: off 2024-11-01T16:55:15.747658Z INFO dnsproxyd[2348]: INFO dnsproxyd: [resolver.cc(676)] {system:wlan0} Name servers are updated, 0/2 validated name servers 2024-11-01T16:55:15.748905Z INFO dnsproxyd[2348]: INFO dnsproxyd: [proxy.cc(793)] {system:wlan0} Successfully set dns-proxy address property [100.115.92.134] 2024-11-01T16:55:15.748980Z INFO dnsproxyd[2348]: INFO dnsproxyd: [proxy.cc(725)] {system:wlan0} applied device DNS configuration 2024-11-01T16:55:15.749126Z INFO dnsproxyd[1895]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [100.115.92.134] 2024-11-01T16:55:15.751408Z NOTICE ModemManager[1904]: [base-manager] couldn't check support for device '/sys/devices/platform/soc/11240000.mmc/mmc_host/mmc1/mmc1:0001/mmc1:0001:1': not supported by any plugin 2024-11-01T16:55:15.782087Z INFO patchpaneld[2007]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: (10.0.0.0/8: 3)/21, IPv4 broadcast: (10.0.0.0/8: 9), IPv4 gateway: (10.0.0.0/8: 7), IPv6 addresses: [], DNS: [(IPv4: 1),(IPv4: 2)]}, priority {0, primary_logical, primary_physical, primary_for_dns}, area 0x30000 2024-11-01T16:55:15.812449Z INFO patchpaneld[2007]: INFO patchpaneld: [guest_ipv6_service.cc(653)] RegisterDownstreamNeighborIP: downlink: arc_ns0, neighbor IP {(IPv6: 6)}, no corresponding uplink IP yet, postponing /128 route 2024-11-01T16:55:15.820142Z INFO patchpaneld[2007]: INFO patchpaneld: [guest_ipv6_service.cc(653)] RegisterDownstreamNeighborIP: downlink: arc_ns1, neighbor IP {(IPv6: 8)}, no corresponding uplink IP yet, postponing /128 route 2024-11-01T16:55:16.047751Z INFO patchpaneld[2007]: INFO patchpaneld: [network_monitor_service.cc(322)] NUD state changed on wlan0 for { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_REACHABLE }, old_state=NUD_NONE 2024-11-01T16:55:16.486173Z INFO dnsproxyd[2350]: INFO dnsproxyd: [resolver.cc(568)] {default:wlan0} Do53 probe attempt 2 to (IPv4: 2) succeeded (0.014987 s). 1/2 validated name servers 2024-11-01T16:55:16.502434Z INFO dnsproxyd[2350]: INFO dnsproxyd: [resolver.cc(568)] {default:wlan0} Do53 probe attempt 2 to (IPv4: 1) succeeded (0.01593 s). 2/2 validated name servers 2024-11-01T16:55:16.553168Z INFO dnsproxyd[2348]: INFO dnsproxyd: [resolver.cc(568)] {system:wlan0} Do53 probe attempt 2 to (IPv4: 1) succeeded (0.016051 s). 1/2 validated name servers 2024-11-01T16:55:16.604195Z INFO dnsproxyd[2348]: INFO dnsproxyd: [resolver.cc(568)] {system:wlan0} Do53 probe attempt 2 to (IPv4: 2) succeeded (0.017414 s). 2/2 validated name servers 2024-11-01T16:55:32.707019Z INFO dhcpcd7[3512]: received SIGTERM, stopping 2024-11-01T16:55:32.707054Z INFO dhcpcd7[3512]: wlan0: removing interface 2024-11-01T16:55:32.707078Z INFO dhcpcd7[3512]: status changed to Release 2024-11-01T16:55:32.707108Z INFO shill[1195]: INFO shill: [shill_daemon.cc(32)] ShillDaemon received shutdown. 2024-11-01T16:55:32.707188Z INFO dhcpcd7[3512]: wlan0: deleting default route via (10.0.0.0/8: 7) 2024-11-01T16:55:32.707403Z INFO dhcpcd7[3512]: dhcpcd exited 2024-11-01T16:55:32.708296Z INFO shill[1195]: INFO shill: [manager.cc(1565)] Device wlan0 updated: enabled 2024-11-01T16:55:32.743033Z INFO shill[1195]: INFO shill: [service.cc(482)] Disconnecting from wifi_psk_0: Stop 2024-11-01T16:55:32.743083Z INFO shill[1195]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Online -> Disconnecting 2024-11-01T16:55:32.746940Z INFO dnsproxyd[2348]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [online] to [disconnecting] 2024-11-01T16:55:32.747004Z WARNING dnsproxyd[2348]: WARNING dnsproxyd: [proxy.cc(512)] {system:wlan0} is stopping because the default device [wlan0] is offline 2024-11-01T16:55:32.747249Z INFO dnsproxyd[1895]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [online] to [disconnecting] 2024-11-01T16:55:32.747305Z INFO dnsproxyd[1895]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [100.115.92.134] 2024-11-01T16:55:32.748053Z INFO patchpaneld[2007]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: EXCLUDE_DESTINATION, proxy_address: (IPv6: 8) } 2024-11-01T16:55:32.749524Z INFO dnsproxyd[2350]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [online] to [disconnecting] 2024-11-01T16:55:32.749584Z WARNING dnsproxyd[2350]: WARNING dnsproxyd: [proxy.cc(512)] {default:wlan0} is stopping because the default device [wlan0] is offline 2024-11-01T16:55:32.761648Z NOTICE wpa_supplicant[792]: nl80211: send_event_marker failed: Source based routing not supported 2024-11-01T16:55:32.761726Z NOTICE wpa_supplicant[792]: wlan0: CTRL-EVENT-DISCONNECTED bssid=(MAC OUI=ea:9e:38 IFACE=2) reason=3 locally_generated=1 2024-11-01T16:55:32.763791Z INFO patchpaneld[2007]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: EXCLUDE_DESTINATION, proxy_address: 100.115.92.134 } 2024-11-01T16:55:32.765391Z NOTICE wpa_supplicant[792]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all 2024-11-01T16:55:32.766752Z INFO shill[1195]: INFO shill: [device.cc(636)] SetEnabled(0) 2024-11-01T16:55:32.766805Z INFO shill[1195]: INFO shill: [device.cc(655)] SetEnabledChecked: wlan0 wifi_psk_0 stopping 2024-11-01T16:55:32.766855Z INFO shill[1195]: INFO shill: [device.cc(708)] wlan0 wifi_psk_0 SetEnabledUnchecked(false) 2024-11-01T16:55:32.766875Z NOTICE wpa_supplicant[792]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD 2024-11-01T16:55:32.766923Z INFO shill[1195]: INFO shill: [network.cc(331)] wlan0 wifi_psk_0: Stopping normally, network config: {IPv4 address: (10.0.0.0/8: 3)/21, IPv4 broadcast: (10.0.0.0/8: 9), IPv4 gateway: (10.0.0.0/8: 7), IPv6 addresses: [], DNS: [(IPv4: 1),(IPv4: 2)]} 2024-11-01T16:55:32.768098Z NOTICE wpa_supplicant[792]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD 2024-11-01T16:55:32.768939Z INFO shill[1195]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Disconnecting -> Idle 2024-11-01T16:55:32.769588Z NOTICE wpa_supplicant[792]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US 2024-11-01T16:55:32.769870Z INFO dnsproxyd[1895]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [100.115.92.134] 2024-11-01T16:55:32.771391Z INFO patchpaneld[2007]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: USER, proxy_address: (IPv6: 6) } 2024-11-01T16:55:32.771512Z INFO dnsproxyd[1895]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [100.115.92.134] 2024-11-01T16:55:32.774019Z INFO dnsproxyd[1895]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [100.115.92.134] 2024-11-01T16:55:32.775323Z INFO shill[1195]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:55:32.776488Z INFO shill[1195]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:55:32.777380Z INFO shill[1195]: INFO shill: [network.cc(331)] wlan0 : Stopping normally, network config: {IPv4 address: nullopt, IPv6 addresses: [], DNS: []} 2024-11-01T16:55:32.782144Z INFO patchpaneld[2007]: INFO patchpaneld: [manager.cc(882)] OnDnsRedirectionRulesAutoclose: { type: USER, proxy_address: 100.115.92.130, nameserver(s): (IPv4: 1),(IPv4: 2), } 2024-11-01T16:55:32.792572Z INFO patchpaneld[2007]: INFO patchpaneld: [network_monitor_service.cc(322)] NUD state changed on wlan0 for { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_NONE }, old_state=NUD_REACHABLE 2024-11-01T16:55:32.827003Z ERR shill[1195]: ERROR shill: [object_proxy.cc(576)] Failed to call method: fi.w1.wpa_supplicant1.Interface.Disconnect: object_path= /fi/w1/wpa_supplicant1/Interfaces/0: fi.w1.wpa_supplicant1.NotConnected: This interface is not connected 2024-11-01T16:55:32.827062Z ERR shill[1195]: ERROR shill: [dbus_method_invoker.h(114)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=fi.w1.wpa_supplicant1.NotConnected, Message=Error calling D-Bus method: fi.w1.wpa_supplicant1.Interface.Disconnect: This interface is not connected 2024-11-01T16:55:32.827099Z INFO shill[1195]: INFO shill: [supplicant_interface_proxy.cc(197)] Failed to disconnect: fi.w1.wpa_supplicant1.NotConnected Error calling D-Bus method: fi.w1.wpa_supplicant1.Interface.Disconnect: This interface is not connected 2024-11-01T16:55:32.834307Z INFO shill[1195]: INFO shill: [wifi_provider.cc(544)] Removed endpoint (MAC OUI=ea:9e:38 IFACE=13) from service wifi_psk_0 2024-11-01T16:55:32.834760Z INFO shill[1195]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_8. sig: -66, sec: wpa2, freq: 2412 2024-11-01T16:55:32.840220Z INFO shill[1195]: INFO shill: [wifi_provider.cc(544)] Removed endpoint (MAC OUI=fe:9e:38 IFACE=14) from service wifi_psk_1 2024-11-01T16:55:32.840278Z INFO shill[1195]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_7. sig: -87, sec: wpa2, freq: 5180 2024-11-01T16:55:32.845634Z INFO shill[1195]: INFO shill: [wifi.cc(3896)] Stop - wlan0: Scan state: IDLE -> IDLE ensured scan: Scanning 2024-11-01T16:55:32.846172Z INFO shill[1195]: INFO shill: [device.cc(608)] OnEnabledStateChanged: wlan0 no_service (target: 0, success: 1) 2024-11-01T16:55:32.850162Z INFO shill[1195]: INFO shill: [p2p_manager.cc(140)] Stop 2024-11-01T16:55:32.850364Z INFO shill[1195]: INFO shill: [modem_info.cc(51)] Stop 2024-11-01T16:55:32.861558Z INFO shill[1195]: INFO shill: [modem_info.cc(97)] Disconnect 2024-11-01T16:55:32.861628Z INFO shill[1195]: INFO shill: [device.cc(123)] ~Device(): arc_ns1 no_service 2024-11-01T16:55:32.861821Z INFO shill[1195]: INFO shill: [device.cc(123)] ~Device(): arc_ns0 no_service 2024-11-01T16:55:32.862001Z INFO shill[1195]: INFO shill: [power_manager.cc(59)] Stop 2024-11-01T16:55:32.862030Z INFO shill[1195]: INFO shill: [power_manager_proxy.cc(254)] UnregisterSuspendDelayInternal(82378755, dark=false) 2024-11-01T16:55:32.863706Z INFO shill[1195]: INFO shill: [power_manager_proxy.cc(254)] UnregisterSuspendDelayInternal(82411521, dark=true) 2024-11-01T16:55:32.866281Z NOTICE wpa_supplicant[792]: p2p-dev-wlan0: CTRL-EVENT-DSCP-POLICY clear_all 2024-11-01T16:55:32.868125Z NOTICE wpa_supplicant[792]: p2p-dev-wlan0: CTRL-EVENT-DSCP-POLICY clear_all 2024-11-01T16:55:32.868237Z NOTICE wpa_supplicant[792]: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0 2024-11-01T16:55:32.957445Z ERR wpa_supplicant[792]: rmdir[ctrl_interface=/run/wpa_supplicant]: Permission denied 2024-11-01T16:55:32.957723Z NOTICE wpa_supplicant[792]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all 2024-11-01T16:55:32.968418Z NOTICE wpa_supplicant[792]: wlan0: CTRL-EVENT-DSCP-POLICY clear_all 2024-11-01T16:55:32.968455Z NOTICE wpa_supplicant[792]: nl80211: deinit ifname=wlan0 disabled_11b_rates=0 2024-11-01T16:55:32.968786Z ERR wpa_supplicant[792]: rmdir[ctrl_interface=/run/wpa_supplicant]: Permission denied 2024-11-01T16:55:32.969706Z INFO shill[1195]: INFO shill: [device.cc(123)] ~Device(): wlan0 no_service 2024-11-01T16:55:32.996042Z INFO patchpaneld[2007]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: nullopt, IPv6 addresses: [], DNS: []}, priority {31}, area 0x80000000 2024-11-01T16:55:32.997211Z WARNING patchpaneld[2007]: WARNING patchpaneld: [routing_table.cc(110)] Successfully removed routing entry but could not find the corresponding entry in patchpanel's representation of the routing table. 2024-11-01T16:55:33.022791Z ERR dnsproxyd[2348]: ERROR dnsproxyd: [object_proxy.cc(576)] Failed to call method: org.chromium.flimflam.Manager.ClearDNSProxyAddresses: object_path= /: org.freedesktop.DBus.Error.UnknownMethod: Method "ClearDNSProxyAddresses" with signature "" on interface "org.chromium.flimflam.Manager" doesn't exist#012 2024-11-01T16:55:33.022838Z ERR dnsproxyd[2348]: ERROR dnsproxyd: [dbus_method_invoker.h(114)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=org.freedesktop.DBus.Error.UnknownMethod, Message=Error calling D-Bus method: org.chromium.flimflam.Manager.ClearDNSProxyAddresses: Method "ClearDNSProxyAddresses" with signature "" on interface "org.chromium.flimflam.Manager" doesn't exist#012 2024-11-01T16:55:33.022866Z INFO dnsproxyd[2348]: INFO dnsproxyd: [proxy.cc(787)] {system:_} Successfully cleared dns-proxy address property 2024-11-01T16:55:33.023013Z WARNING dnsproxyd[1895]: WARNING dnsproxyd: [resolv_conf.cc(59)] Setting resolv.conf to [] 2024-11-01T16:55:33.023025Z WARNING patchpaneld[2007]: WARNING patchpaneld: [object_proxy.cc(574)] Failed to call method: org.chromium.flimflam.Device.GetProperties: object_path= /device/wlan0: org.freedesktop.DBus.Error.UnknownObject: Method "GetProperties" with signature "" on interface "org.chromium.flimflam.Device" doesn't exist#012 2024-11-01T16:55:33.023046Z INFO shill[1195]: INFO shill: [shill_main.cc(120)] Process exiting. 2024-11-01T16:55:33.023075Z ERR patchpaneld[2007]: ERROR patchpaneld: [dbus_method_invoker.h(114)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=org.freedesktop.DBus.Error.UnknownObject, Message=Error calling D-Bus method: org.chromium.flimflam.Device.GetProperties: Method "GetProperties" with signature "" on interface "org.chromium.flimflam.Device" doesn't exist#012 2024-11-01T16:55:33.023119Z ERR patchpaneld[2007]: ERROR patchpaneld: [shill_client.cc(472)] Unable to get shill Device properties for /device/wlan0 2024-11-01T16:55:33.023152Z ERR patchpaneld[2007]: ERROR patchpaneld: [shill_client.cc(700)] Failed to update properties of Device /device/wlan0 2024-11-01T16:55:33.024014Z WARNING dnsproxyd[1895]: WARNING dnsproxyd: [controller.cc(233)] Shill has been shutdown 2024-11-01T16:55:33.024075Z WARNING dnsproxyd[2348]: WARNING dnsproxyd: [proxy.cc(394)] {system:_} Shill has been shutdown 2024-11-01T16:55:33.024388Z WARNING dnsproxyd[2350]: WARNING dnsproxyd: [proxy.cc(394)] {default:_} Shill has been shutdown 2024-11-01T16:55:33.025801Z ERR dnsproxyd[2350]: ERROR dnsproxyd: [object_proxy.cc(576)] Failed to call method: org.chromium.flimflam.Manager.GetProperties: object_path= /: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.flimflam was not provided by any .service files 2024-11-01T16:55:33.025855Z ERR dnsproxyd[2350]: ERROR dnsproxyd: [dbus_method_invoker.h(114)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=org.freedesktop.DBus.Error.ServiceUnknown, Message=Error calling D-Bus method: org.chromium.flimflam.Manager.GetProperties: The name org.chromium.flimflam was not provided by any .service files 2024-11-01T16:55:33.025876Z WARNING dnsproxyd[2350]: WARNING dnsproxyd: [client.cc(357)] Unable to get shill Manager properties, likely because shill is unavailable 2024-11-01T16:55:33.026935Z ERR dnsproxyd[2348]: ERROR dnsproxyd: [object_proxy.cc(576)] Failed to call method: org.chromium.flimflam.Manager.GetProperties: object_path= /: org.freedesktop.DBus.Error.ServiceUnknown: The name org.chromium.flimflam was not provided by any .service files 2024-11-01T16:55:33.026998Z ERR dnsproxyd[2348]: ERROR dnsproxyd: [dbus_method_invoker.h(114)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=org.freedesktop.DBus.Error.ServiceUnknown, Message=Error calling D-Bus method: org.chromium.flimflam.Manager.GetProperties: The name org.chromium.flimflam was not provided by any .service files 2024-11-01T16:55:33.027041Z WARNING dnsproxyd[2348]: WARNING dnsproxyd: [client.cc(357)] Unable to get shill Manager properties, likely because shill is unavailable 2024-11-01T16:55:33.052551Z INFO patchpaneld[2007]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: nullopt, IPv6 addresses: [], DNS: []}, priority {31}, area 0x80000000 2024-11-01T16:56:00.618655Z NOTICE wpa_supplicant[796]: Successfully initialized wpa_supplicant 2024-11-01T16:56:01.229305Z INFO shill[1226]: INFO shill: [manager.cc(347)] Manager started. 2024-11-01T16:56:01.236062Z INFO shill[1226]: INFO shill: [power_manager_proxy.cc(413)] OnSignalConnected interface: org.chromium.PowerManager signal: SuspendImminentsuccess: 1 2024-11-01T16:56:01.236780Z INFO shill[1226]: INFO shill: [power_manager_proxy.cc(413)] OnSignalConnected interface: org.chromium.PowerManager signal: SuspendDonesuccess: 1 2024-11-01T16:56:01.237411Z INFO shill[1226]: INFO shill: [power_manager_proxy.cc(413)] OnSignalConnected interface: org.chromium.PowerManager signal: DarkSuspendImminentsuccess: 1 2024-11-01T16:56:01.358623Z INFO shill[1226]: INFO shill: [manager.cc(555)] Push default profile. 2024-11-01T16:56:01.360295Z INFO shill[1226]: INFO shill: [manager.cc(1990)] Setting always-on VPN to mode=off service=nullptr 2024-11-01T16:56:01.360508Z INFO shill[1226]: INFO shill: [manager.cc(602)] PushProfileInternal finished; 1 profile(s) now present. 2024-11-01T16:56:01.360680Z INFO shill[1226]: INFO shill: [modem_info.cc(41)] Start 2024-11-01T16:56:01.363276Z INFO shill[1226]: INFO shill: [service.cc(1404)] Service ethernet_2: SetAutoConnect: 1 2024-11-01T16:56:01.364111Z INFO shill[1226]: INFO shill: [p2p_manager.cc(136)] Start 2024-11-01T16:56:01.378747Z ERR shill[1226]: ERROR shill: [utils.cc(84)] AddDBusError(...): Domain=dbus, Code=org.freedesktop.DBus.Error.ServiceUnknown, Message=The name org.chromium.PatchPanel was not provided by any .service files 2024-11-01T16:56:01.379003Z ERR shill[1226]: ERROR shill: [client.cc(662)] OnGetTrafficCountersError(): The name org.chromium.PatchPanel was not provided by any .service files 2024-11-01T16:56:01.410340Z INFO shill[1226]: INFO shill: [power_manager.cc(225)] OnPowerManagerAppeared 2024-11-01T16:56:01.410415Z INFO shill[1226]: INFO shill: [power_manager_proxy.cc(196)] RegisterSuspendDelayInternal(19500, dark=false) 2024-11-01T16:56:01.410661Z INFO shill[1226]: INFO shill: [power_manager_proxy.cc(196)] RegisterSuspendDelayInternal(19500, dark=true) 2024-11-01T16:56:01.643912Z INFO shill[1226]: INFO shill: [device_info.cc(1378)] Creating WiFi device for station mode interface wlan0 at interface index 2 2024-11-01T16:56:01.646808Z INFO shill[1226]: INFO shill: [manager.cc(1195)] Device wlan0 registered. 2024-11-01T16:56:01.646974Z INFO shill[1226]: INFO shill: [manager.cc(1565)] Device wlan0 updated: enabled 2024-11-01T16:56:01.664077Z INFO shill[1226]: INFO shill: [device.cc(655)] SetEnabledChecked: wlan0 no_service starting 2024-11-01T16:56:01.664164Z INFO shill[1226]: INFO shill: [device.cc(708)] wlan0 no_service SetEnabledUnchecked(true) 2024-11-01T16:56:01.676257Z INFO shill[1226]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:56:01.688531Z INFO shill[1226]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: No such file or directory (2) 2024-11-01T16:56:01.690669Z INFO shill[1226]: INFO shill: [wifi.cc(3612)] wlan0: disabled supplicant: absent proxy: null 2024-11-01T16:56:01.690738Z INFO shill[1226]: INFO shill: [device.cc(608)] OnEnabledStateChanged: wlan0 no_service (target: 1, success: 1) 2024-11-01T16:56:01.691104Z INFO shill[1226]: INFO shill: [result_aggregator.cc(56)] org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:56:01.691152Z WARNING shill[1226]: WARNING shill: [result_aggregator.cc(61)] Dropping error type org.chromium.flimflam.Error.Success: Success (no error) 2024-11-01T16:56:01.691664Z INFO shill[1226]: INFO shill: [wifi.cc(3532)] WPA supplicant presence changed: 1 2024-11-01T16:56:01.691709Z INFO shill[1226]: INFO shill: [wifi.cc(3612)] wlan0: enabled supplicant: present proxy: null 2024-11-01T16:56:01.691745Z INFO shill[1226]: INFO shill: [wifi.cc(3562)] WiFi debug scope changed; enable is now 0 2024-11-01T16:56:02.158535Z INFO shill[1226]: INFO shill: [wifi.cc(3666)] connected to supplicant on attempt 1 2024-11-01T16:56:02.172005Z NOTICE wpa_supplicant[796]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=USER type=COUNTRY alpha2=US 2024-11-01T16:56:02.191435Z INFO shill[1226]: INFO shill: [wifi_provider.cc(1540)] RegionChanged: Country notification: US 2024-11-01T16:56:02.227686Z INFO shill[1226]: INFO shill: [power_manager_proxy.cc(172)] ChangeRegDomain 2024-11-01T16:56:02.306916Z INFO shill[1226]: INFO shill: [p2p_manager.cc(472)] SetAllowed Allowed set to true 2024-11-01T16:56:02.306955Z INFO shill[1226]: INFO shill: [p2p_manager.cc(140)] Stop 2024-11-01T16:56:02.377878Z INFO shill[1226]: INFO shill: [bluetooth_manager.cc(97)] OnBTManagerAvailable: BT manager is available 2024-11-01T16:56:02.377958Z INFO shill[1226]: INFO shill: [bluetooth_manager.cc(69)] Completing initialization of BT manager 2024-11-01T16:56:02.380802Z INFO shill[1226]: INFO shill: [bluetooth_manager.cc(83)] BT manager found 0 adapters 2024-11-01T16:56:02.380876Z INFO shill[1226]: INFO shill: [bluetooth_manager.cc(93)] Completed initialization of BT manager 2024-11-01T16:56:03.148380Z INFO shill[1226]: INFO shill: [manager.cc(2766)] The WiFi AP list is empty 2024-11-01T16:56:03.223815Z INFO shill[1226]: INFO shill: [manager.cc(3259)] Received command for network throttling disabling 2024-11-01T16:56:03.242648Z ERR shill[1226]: ERROR shill: [throttler.cc(226)] Throttler failed with status: 1 2024-11-01T16:56:03.785301Z INFO dnsproxyd[1927]: INFO dnsproxyd: [controller.cc(93)] Starting DNS Proxy service 2024-11-01T16:56:03.810301Z INFO dnsproxyd[1927]: INFO dnsproxyd: [client.cc(391)] Default service changed from [] to [/] 2024-11-01T16:56:03.901080Z INFO patchpanel_bpf_loader[1897]: Pinned bpf program match_dtls_srtp at /sys/fs/bpf/patchpanel/match_dtls_srtp 2024-11-01T16:56:04.003614Z NOTICE ModemManager[1941]: ModemManager (version 1.23.9) starting in system bus... 2024-11-01T16:56:04.030829Z INFO patchpaneld[2009]: INFO patchpaneld: [main.cc(74)] Starting patchpanel D-Bus daemon 2024-11-01T16:56:04.070436Z INFO shill[1226]: INFO shill: [dbus_objectmanager_proxy.cc(100)] OnServiceOwnerChanged old: new: :1.75 2024-11-01T16:56:04.070488Z INFO shill[1226]: INFO shill: [dbus_objectmanager_proxy.cc(86)] OnServiceAvailable: 1 2024-11-01T16:56:04.070558Z INFO shill[1226]: INFO shill: [dbus_objectmanager_proxy.cc(86)] OnServiceAvailable: 1 2024-11-01T16:56:04.070643Z INFO shill[1226]: INFO shill: [modem_info.cc(122)] OnAppeared 2024-11-01T16:56:04.070677Z INFO shill[1226]: INFO shill: [modem_info.cc(89)] Connect 2024-11-01T16:56:04.070818Z INFO shill[1226]: INFO shill: [modem_info.cc(122)] OnAppeared 2024-11-01T16:56:04.070891Z INFO shill[1226]: INFO shill: [modem_info.cc(89)] Connect 2024-11-01T16:56:04.102810Z INFO patchpaneld[2042]: INFO patchpaneld: [main.cc(47)] Spawning adb proxy 2024-11-01T16:56:04.108758Z INFO patchpaneld[2042]: INFO patchpaneld: [adb_proxy.cc(326)] Chrome OS is not in developer mode and ADB sideloading is not enabled. ADB proxy is not listening 2024-11-01T16:56:04.113370Z INFO patchpaneld[2044]: INFO patchpaneld: [main.cc(61)] Spawning multicast proxy 2024-11-01T16:56:04.123600Z INFO patchpaneld[2045]: INFO patchpaneld: [main.cc(54)] Spawning nd proxy 2024-11-01T16:56:04.123908Z INFO patchpaneld[2046]: INFO patchpaneld: [main.cc(68)] Spawning socket D-Bus daemon 2024-11-01T16:56:04.126230Z INFO patchpaneld[2045]: INFO patchpaneld: [ndproxy.cc(830)] Started watching on packet fd... 2024-11-01T16:56:04.190670Z INFO shill[1226]: INFO shill: [modem_info.cc(165)] OnGetManagedObjectsReply: 1 2024-11-01T16:56:04.190784Z INFO shill[1226]: INFO shill: [modem_info.cc(165)] OnGetManagedObjectsReply: 1 2024-11-01T16:56:04.406831Z INFO dnsproxyd[1927]: INFO dnsproxyd: [controller.cc(178)] Service enabled by feature flag 2024-11-01T16:56:04.411874Z INFO dnsproxyd[1927]: INFO dnsproxyd: [controller.cc(316)] Launched process for proxy {system:}(pid: 2147) 2024-11-01T16:56:04.429229Z INFO dnsproxyd[1927]: INFO dnsproxyd: [controller.cc(316)] Launched process for proxy {default:}(pid: 2161) 2024-11-01T16:56:04.438206Z WARNING dnsproxyd[2161]: libminijail[2161]: ioctl(SIOCSIFFLAGS) failed: Operation not permitted 2024-11-01T16:56:04.471123Z WARNING dnsproxyd[2147]: libminijail[2147]: ioctl(SIOCSIFFLAGS) failed: Operation not permitted 2024-11-01T16:56:04.530924Z WARNING dnsproxyd[2147]: WARNING dnsproxyd: [socket.cc(257)] Failed to increase receive buffer size to 3145728b: Operation not permitted (1) 2024-11-01T16:56:04.531070Z INFO dnsproxyd[2147]: INFO dnsproxyd: [proxy.cc(168)] {system:_} Starting DNS proxy 2024-11-01T16:56:04.534899Z WARNING dnsproxyd[2161]: WARNING dnsproxyd: [socket.cc(257)] Failed to increase receive buffer size to 3145728b: Operation not permitted (1) 2024-11-01T16:56:04.535549Z INFO dnsproxyd[2161]: INFO dnsproxyd: [proxy.cc(168)] {default:_} Starting DNS proxy 2024-11-01T16:56:04.595827Z INFO patchpaneld[2009]: INFO patchpaneld: [conntrack_monitor.cc(70)] ConntrackMonitor started 2024-11-01T16:56:04.595930Z INFO patchpaneld[2009]: INFO patchpaneld: [conntrack_monitor.cc(194)] ConntrackMonitor added listener 2024-11-01T16:56:04.660148Z INFO shill[1226]: INFO shill: [service.cc(2341)] Service wifi_psk_0: AutoConnect=1->1 2024-11-01T16:56:04.769484Z INFO shill[1226]: INFO shill: [service.cc(2341)] Service wifi_psk_1: AutoConnect=0->0 2024-11-01T16:56:04.874779Z INFO shill[1226]: INFO shill: [manager.cc(2917)] OnPatchpanelClientReady 2024-11-01T16:56:04.885205Z INFO shill[1226]: INFO shill: [manager.cc(1990)] Setting always-on VPN to mode=off service=nullptr 2024-11-01T16:56:05.258958Z WARNING ModemManager[1941]: [plugin-manager] task 0: port context already scheduled 2024-11-01T16:56:05.321740Z INFO patchpaneld[2009]: INFO patchpaneld: [manager.cc(830)] Connected network namespace { pid: 2147, source: SYSTEM, route_on_vpn: 0, host_ifname: arc_ns0, peer_ifname: veth0, peer_ipv4_subnet: 100.115.92.128/30, static_ipv6_subnet: (IPv6: 9)/64} 2024-11-01T16:56:05.339186Z INFO dnsproxyd[2147]: INFO dnsproxyd: [client.cc(1373)] ConnectNamespace for netns pid 2147 succeeded: peer_ifname=veth0 peer_ipv4_address=100.115.92.130 host_ifname=arc_ns0 host_ipv4_address=100.115.92.129 subnet=100.115.92.128/30 2024-11-01T16:56:05.339265Z INFO dnsproxyd[2147]: INFO dnsproxyd: [proxy.cc(257)] {system:_} Successfully connected private network namespace: arc_ns0 <--> veth0 2024-11-01T16:56:05.413890Z INFO dnsproxyd[2147]: INFO dnsproxyd: [client.cc(391)] Default service changed from [] to [/] 2024-11-01T16:56:05.414230Z INFO dnsproxyd[2147]: INFO dnsproxyd: [client.cc(1022)] Patchpanel reset 2024-11-01T16:56:05.414658Z WARNING dnsproxyd[2147]: WARNING dnsproxyd: [proxy.cc(329)] {system:_} Patchpanel has been reset 2024-11-01T16:56:05.422707Z INFO dnsproxyd[2147]: INFO dnsproxyd: [proxy.cc(1014)] {system:_} Peer IPv6 addr updated to (IPv6: 10) 2024-11-01T16:56:05.558430Z INFO shill[1226]: INFO shill: [manager.cc(2169)] ScanAndConnectToBestServices: ensure scan 2024-11-01T16:56:05.682068Z INFO patchpaneld[2009]: INFO patchpaneld: [manager.cc(830)] Connected network namespace { pid: 2161, source: USER, route_on_vpn: 1, host_ifname: arc_ns1, peer_ifname: veth1, peer_ipv4_subnet: 100.115.92.132/30, static_ipv6_subnet: (IPv6: 11)/64} 2024-11-01T16:56:05.682633Z INFO patchpaneld[2009]: INFO patchpaneld: [manager.cc(1171)] SetFeatureFlag: set WiFi QoS to 0 from 0 2024-11-01T16:56:05.685934Z INFO dnsproxyd[1927]: INFO dnsproxyd: [client.cc(1022)] Patchpanel reset 2024-11-01T16:56:05.685997Z WARNING dnsproxyd[1927]: WARNING dnsproxyd: [controller.cc(203)] Patchpanel has been reset 2024-11-01T16:56:05.686634Z INFO dnsproxyd[2161]: INFO dnsproxyd: [client.cc(1373)] ConnectNamespace for netns pid 2161 succeeded: peer_ifname=veth1 peer_ipv4_address=100.115.92.134 host_ifname=arc_ns1 host_ipv4_address=100.115.92.133 subnet=100.115.92.132/30 2024-11-01T16:56:05.686681Z INFO dnsproxyd[2161]: INFO dnsproxyd: [proxy.cc(257)] {default:_} Successfully connected private network namespace: arc_ns1 <--> veth1 2024-11-01T16:56:05.703307Z INFO dnsproxyd[2161]: INFO dnsproxyd: [client.cc(391)] Default service changed from [] to [/] 2024-11-01T16:56:05.710011Z INFO dnsproxyd[2161]: INFO dnsproxyd: [client.cc(1022)] Patchpanel reset 2024-11-01T16:56:05.710289Z WARNING dnsproxyd[2161]: WARNING dnsproxyd: [proxy.cc(329)] {default:_} Patchpanel has been reset 2024-11-01T16:56:05.711758Z INFO dnsproxyd[2161]: INFO dnsproxyd: [proxy.cc(1014)] {default:_} Peer IPv6 addr updated to (IPv6: 12) 2024-11-01T16:56:05.750137Z INFO patchpaneld[2009]: INFO patchpaneld: [manager.cc(173)] RunDelayedInitialization: start 2024-11-01T16:56:05.750195Z INFO patchpaneld[2009]: INFO patchpaneld: [qos_service.cc(81)] DoHUpdater called with 0 valid hostnames 2024-11-01T16:56:05.750218Z INFO patchpaneld[2009]: INFO patchpaneld: [qos_service.cc(157)] Updating iptables rules for QoS with 0 IPv4 addrs and 0 IPv6 addrs 2024-11-01T16:56:05.802173Z INFO patchpaneld[2009]: INFO patchpaneld: [shill_client.cc(430)] New shill Device {shill_device: wlan0, type: wifi, ifname: wlan0, ifindex: 2, service: /} 2024-11-01T16:56:05.846420Z INFO shill[1226]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_4. sig: -55, sec: wpa2+wpa3, freq: 5280 2024-11-01T16:56:05.852708Z INFO shill[1226]: INFO shill: [wifi_provider.cc(511)] Assigning endpoint (MAC OUI=fe:9e:38 IFACE=9) to service wifi_psk_1 2024-11-01T16:56:05.852770Z INFO shill[1226]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_1. sig: -55, sec: wpa2+wpa3, freq: 5280 2024-11-01T16:56:05.968333Z INFO shill[1226]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_5. sig: -55, sec: wpa2, freq: 5280 2024-11-01T16:56:05.974896Z INFO shill[1226]: INFO shill: [wifi_provider.cc(511)] Assigning endpoint (MAC OUI=ea:9e:38 IFACE=3) to service wifi_psk_0 2024-11-01T16:56:05.974947Z INFO shill[1226]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_0. sig: -55, sec: wpa2, freq: 5280 2024-11-01T16:56:05.986331Z INFO shill[1226]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_6. sig: -55, sec: wpa2, freq: 5280 2024-11-01T16:56:05.989884Z INFO shill[1226]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_7. sig: -55, sec: wpa2, freq: 5280 2024-11-01T16:56:06.010155Z INFO shill[1226]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_8. sig: -56, sec: wpa2, freq: 5765 2024-11-01T16:56:06.074991Z INFO patchpaneld[2009]: INFO patchpaneld: [datapath.cc(1438)] Start connection pinning on wlan0 fwmark=0x03ea0000 2024-11-01T16:56:06.094587Z INFO shill[1226]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_9. sig: -51, sec: wpa2, freq: 2437 2024-11-01T16:56:06.129748Z INFO patchpaneld[2009]: INFO patchpaneld: [network_monitor_service.cc(171)] ipconfigs changed on wlan0, update watching entries 2024-11-01T16:56:06.129787Z INFO patchpaneld[2009]: INFO patchpaneld: [network_monitor_service.cc(188)] Stop due to empty watching list on wlan0 2024-11-01T16:56:06.129926Z INFO patchpaneld[2009]: INFO patchpaneld: [manager.cc(196)] RunDelayedInitialization: finished 2024-11-01T16:56:06.135376Z INFO shill[1226]: INFO shill: [wifi.cc(536)] ScanDone 2024-11-01T16:56:06.137542Z INFO shill[1226]: INFO shill: [service.cc(403)] Auto-connecting to wifi_psk_0 2024-11-01T16:56:06.137602Z INFO shill[1226]: INFO shill: [service.cc(462)] Connecting to wifi Service wifi_psk_0: AutoConnect 2024-11-01T16:56:06.160523Z INFO shill[1226]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:56:06.162038Z INFO shill[1226]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Permission denied (13) 2024-11-01T16:56:06.178371Z NOTICE wpa_supplicant[796]: SME: Trying to authenticate with (MAC OUI=ea:9e:38 IFACE=3) (SSID='(SSID: 3)' freq=5280 MHz) 2024-11-01T16:56:06.179672Z INFO shill[1226]: INFO shill: [wifi.cc(3896)] SetPendingService - wlan0: Scan state: FULL_START -> FULL_CONNECTING ensured scan: Waiting 2024-11-01T16:56:06.180039Z INFO shill[1226]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Idle -> Associating 2024-11-01T16:56:06.180075Z INFO shill[1226]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Associating 2024-11-01T16:56:06.182009Z INFO shill[1226]: INFO shill: [network.cc(331)] wlan0 wlan0: Stopping normally, network config: {IPv4 address: nullopt, IPv6 addresses: [], DNS: []} 2024-11-01T16:56:06.193251Z INFO shill[1226]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_10. sig: -68, sec: wpa2, freq: 2437 2024-11-01T16:56:06.225171Z INFO shill[1226]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Associating 2024-11-01T16:56:06.232644Z INFO shill[1226]: INFO shill: [wifi_service.cc(1483)] Rep endpoint updated for wifi_psk_11. sig: -85, sec: wpa+wpa2, freq: 2462 2024-11-01T16:56:06.238049Z INFO shill[1226]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Associating 2024-11-01T16:56:06.241314Z INFO shill[1226]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged shill-unknown -> inactive 2024-11-01T16:56:06.246091Z NOTICE wpa_supplicant[796]: Trying to associate with (MAC OUI=ea:9e:38 IFACE=3) (SSID='(SSID: 3)' freq=5280 MHz) 2024-11-01T16:56:06.254307Z INFO shill[1226]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged inactive -> authenticating 2024-11-01T16:56:06.254671Z INFO shill[1226]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged authenticating -> associating 2024-11-01T16:56:06.261556Z INFO patchpaneld[2009]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:56:06.263906Z INFO shill[1226]: INFO shill: [wifi_provider.cc(1540)] RegionChanged: Country notification: US 2024-11-01T16:56:06.266807Z NOTICE wpa_supplicant[796]: wlan0: Associated with (MAC OUI=ea:9e:38 IFACE=3) 2024-11-01T16:56:06.267002Z NOTICE wpa_supplicant[796]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 2024-11-01T16:56:06.267690Z NOTICE wpa_supplicant[796]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US 2024-11-01T16:56:06.268513Z NOTICE wpa_supplicant[796]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US 2024-11-01T16:56:06.278363Z NOTICE wpa_supplicant[796]: wlan0: WPA: Key negotiation completed with (MAC OUI=ea:9e:38 IFACE=3) [PTK=CCMP GTK=CCMP] 2024-11-01T16:56:06.278444Z NOTICE wpa_supplicant[796]: wlan0: CTRL-EVENT-CONNECTED - Connection to (MAC OUI=ea:9e:38 IFACE=3) completed [id=0 id_str=] 2024-11-01T16:56:06.287151Z INFO shill[1226]: INFO shill: [wifi.cc(1178)] WiFi wlan0 CurrentBSS (unknown) -> /fi/w1/wpa_supplicant1/Interfaces/0/BSSs/20 2024-11-01T16:56:06.289024Z INFO shill[1226]: INFO shill: [wifi.cc(3896)] HandleRoam - wlan0: Scan state: FULL_CONNECTING -> FULL_CONNECTED ensured scan: Waiting 2024-11-01T16:56:06.289556Z INFO shill[1226]: INFO shill: [wifi.cc(3896)] HandleRoam - wlan0: Scan state: FULL_CONNECTED -> IDLE ensured scan: Waiting 2024-11-01T16:56:06.289980Z INFO shill[1226]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged associating -> 4way_handshake 2024-11-01T16:56:06.298555Z INFO shill[1226]: INFO shill: [wifi.cc(2659)] WiFi wlan0 StateChanged 4way_handshake -> completed 2024-11-01T16:56:06.305594Z INFO shill[1226]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:56:06.310093Z INFO shill[1226]: INFO shill: [legacy_dhcpcd_proxy.cc(216)] Created dhcpcd with pid 3288 and args: -B -f /etc/dhcpcd7.conf -i chromeos -q -4 -o captive_portal_uri --nodelay -h wlan0 2024-11-01T16:56:06.310259Z INFO shill[1226]: INFO shill: [network.cc(234)] wlan0 wifi_psk_0: Started IP provisioning, dhcp: started, accept_ra: true 2024-11-01T16:56:06.310301Z INFO shill[1226]: INFO shill: [network.cc(237)] wlan0 wifi_psk_0 initial config: wlan0: combined config {IPv4 address: nullopt, IPv6 addresses: [], DNS: []} 2024-11-01T16:56:06.310320Z INFO shill[1226]: INFO shill: [wifi.cc(2739)] wlan0 is up; started L3 configuration. 2024-11-01T16:56:06.311922Z INFO shill[1226]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:56:06.339220Z INFO shill[1226]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:56:06.339910Z INFO shill[1226]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Associating -> Configuring 2024-11-01T16:56:06.339957Z INFO shill[1226]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Configuring 2024-11-01T16:56:06.352731Z INFO dhcpcd7[3288]: status changed to Init 2024-11-01T16:56:06.364360Z INFO shill[1226]: INFO shill: [legacy_dhcpcd_proxy.cc(307)] SetDBusProxyIfPending: Set the D-Bus proxy to LegacyDHCPCDProxy for pid: 3288 2024-11-01T16:56:06.404337Z INFO dhcpcd7[3288]: status changed to Discover 2024-11-01T16:56:06.404508Z INFO dhcpcd7[3288]: wlan0: soliciting a DHCP lease 2024-11-01T16:56:06.404528Z INFO dhcpcd7[3288]: wlan0: sending DISCOVER (xid 0xfcea1eac), next in 3.7 seconds 2024-11-01T16:56:06.416163Z INFO dhcpcd7[3288]: wlan0: received OFFER with xid 0xfcea1eac 2024-11-01T16:56:06.416195Z INFO dhcpcd7[3288]: wlan0: offered (10.0.0.0/8: 3) from (10.0.0.0/8: 7) 2024-11-01T16:56:06.416214Z INFO dhcpcd7[3288]: status changed to Request 2024-11-01T16:56:06.416276Z INFO dhcpcd7[3288]: wlan0: requesting lease of (10.0.0.0/8: 3) 2024-11-01T16:56:06.416293Z INFO dhcpcd7[3288]: wlan0: sending REQUEST (xid 0xfcea1eac), next in 4.7 seconds 2024-11-01T16:56:06.426335Z INFO dhcpcd7[3288]: wlan0: received ACK with xid 0xfcea1eac 2024-11-01T16:56:06.426364Z INFO dhcpcd7[3288]: wlan0: acknowledged (10.0.0.0/8: 3) from (10.0.0.0/8: 7) 2024-11-01T16:56:06.426384Z INFO dhcpcd7[3288]: wlan0: leased (10.0.0.0/8: 3) for 86400 seconds 2024-11-01T16:56:06.426884Z INFO dhcpcd7[3288]: event BOUND on interface wlan0 2024-11-01T16:56:06.427308Z INFO dhcpcd7[3288]: status changed to Bound 2024-11-01T16:56:06.427505Z INFO dhcpcd7[3288]: wlan0: adding route to (10.0.0.0/8: 8)/21 2024-11-01T16:56:06.427517Z INFO dhcpcd7[3288]: wlan0: adding default route via (10.0.0.0/8: 7) 2024-11-01T16:56:06.448493Z INFO patchpaneld[2009]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:56:06.448524Z INFO shill[1226]: INFO shill: [network.cc(465)] wlan0 wifi_psk_0: DHCP lease acquired {IPv4 address: (10.0.0.0/8: 3)/21, IPv4 broadcast: (10.0.0.0/8: 9), IPv4 gateway: (10.0.0.0/8: 7), IPv6 addresses: [], DNS: [(IPv4: 1),(IPv4: 2)]} 2024-11-01T16:56:06.449440Z INFO shill[1226]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:56:06.474394Z INFO shill[1226]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:56:06.475162Z INFO shill[1226]: INFO shill: [network.cc(247)] wlan0 wifi_psk_0: Setting IPv4 connection 2024-11-01T16:56:06.484997Z INFO patchpaneld[2009]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:56:06.485547Z INFO patchpaneld[2009]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: nullopt, IPv6 addresses: [], DNS: []}, priority {31}, area 0x80000000 2024-11-01T16:56:06.547708Z INFO patchpaneld[2009]: INFO patchpaneld: [shill_client.cc(285)] Service /service/0 was not connected 2024-11-01T16:56:06.548240Z INFO patchpaneld[2009]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: (10.0.0.0/8: 3)/21, IPv4 broadcast: (10.0.0.0/8: 9), IPv4 gateway: (10.0.0.0/8: 7), IPv6 addresses: [], DNS: [(IPv4: 1),(IPv4: 2)]}, priority {31}, area 0x70007 2024-11-01T16:56:06.548682Z INFO patchpaneld[2009]: INFO patchpaneld: [address_service.cc(83)] SetIPv4Address: adding new address (10.0.0.0/8: 3)/21 2024-11-01T16:56:06.548819Z WARNING patchpaneld[2009]: WARNING patchpaneld: [routing_table.cc(110)] Successfully removed routing entry but could not find the corresponding entry in patchpanel's representation of the routing table. 2024-11-01T16:56:06.549889Z INFO dhcpcd7[3288]: wlan0: pid -1996889191 deleted route to (10.0.0.0/8: 8)/21 2024-11-01T16:56:06.551856Z INFO patchpaneld[2009]: INFO patchpaneld: [shill_client.cc(727)] [/device/wlan0]: IPConfig changed: { ipv4_cidr: (10.0.0.0/8: 3)/21, ipv4_gateway: (10.0.0.0/8: 7), ipv4_dns: [(IPv4: 1),(IPv4: 2)], ipv6_cidr: ::/0, ipv6_gateway: ::, ipv6_dns: []} 2024-11-01T16:56:06.568677Z INFO shill[1226]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:56:06.571882Z NOTICE wpa_supplicant[796]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-60 noise=-99 txrate=78000 2024-11-01T16:56:06.571958Z ERR wpa_supplicant[796]: dbus: wpa_dbus_property_changed: no property SignalChange in object /fi/w1/wpa_supplicant1/Interfaces/0 2024-11-01T16:56:06.663391Z INFO patchpaneld[2009]: INFO patchpaneld: [network_monitor_service.cc(171)] ipconfigs changed on wlan0, update watching entries 2024-11-01T16:56:06.663451Z INFO patchpaneld[2009]: INFO patchpaneld: [network_monitor_service.cc(135)] IPv4 watching entries added on wlan0: skipped_dns_num=2 ,watching_dns_num=0 2024-11-01T16:56:06.665444Z INFO shill[1226]: INFO shill: [network.cc(291)] wlan0 wifi_psk_0: OnSetupConnectionFinished(success: true) 2024-11-01T16:56:06.665497Z INFO shill[1226]: INFO shill: [network.cc(881)] wlan0 wifi_psk_0: RequestNetworkValidation(NetworkConnectionUpdate): Network validation is disabled 2024-11-01T16:56:06.665522Z INFO shill[1226]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Configuring -> Connected 2024-11-01T16:56:06.696005Z INFO shill[1226]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Connected 2024-11-01T16:56:06.798400Z INFO shill[1226]: INFO shill: [wifi_service.cc(854)] SendPostReadyStateMetrics wifi_psk_0: time_resume_to_ready=0 s 2024-11-01T16:56:06.799587Z INFO dnsproxyd[1927]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [configuration] to [ready] 2024-11-01T16:56:06.799589Z INFO dnsproxyd[2147]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [configuration] to [ready] 2024-11-01T16:56:06.799618Z INFO dnsproxyd[2161]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [configuration] to [ready] 2024-11-01T16:56:06.800583Z INFO shill[1226]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Invalid argument (22) 2024-11-01T16:56:06.818231Z INFO shill[1226]: INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11) 2024-11-01T16:56:06.828348Z INFO shill[1226]: message repeated 2 times: [ INFO shill: [batch_event_storage.cc(134)] Events at exceeded timer. Triggering a flush.: Resource temporarily unavailable (11)] 2024-11-01T16:56:06.828862Z INFO shill[1226]: INFO shill: [device.cc(429)] wlan0 wifi_psk_0: Portal detection is disabled for this service 2024-11-01T16:56:06.828889Z INFO shill[1226]: INFO shill: [service.cc(618)] Service wifi_psk_0: state Connected -> Online 2024-11-01T16:56:06.829063Z INFO shill[1226]: INFO shill: [manager.cc(1490)] Service wifi_psk_0 updated; state: Online 2024-11-01T16:56:06.885867Z INFO shill[1226]: INFO shill: [manager.cc(1654)] Default physical service: wifi_psk_0 (online) 2024-11-01T16:56:06.886029Z INFO dnsproxyd[2161]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [ready] to [online] 2024-11-01T16:56:06.886030Z INFO dnsproxyd[1927]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [ready] to [online] 2024-11-01T16:56:06.886037Z INFO dnsproxyd[2147]: INFO dnsproxyd: [client.cc(686)] Device [/device/wlan0] connection state changed from [ready] to [online] 2024-11-01T16:56:06.889217Z INFO dnsproxyd[2161]: INFO dnsproxyd: [client.cc(391)] Default service changed from [/] to [/service/0] 2024-11-01T16:56:06.889218Z INFO dnsproxyd[1927]: INFO dnsproxyd: [client.cc(391)] Default service changed from [/] to [/service/0] 2024-11-01T16:56:06.889261Z INFO dnsproxyd[2147]: INFO dnsproxyd: [client.cc(391)] Default service changed from [/] to [/service/0] 2024-11-01T16:56:06.900632Z INFO dnsproxyd[2161]: INFO dnsproxyd: [proxy.cc(524)] {default:_} is now tracking [wlan0] 2024-11-01T16:56:06.901624Z INFO dnsproxyd[1927]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [(IPv4: 1),(IPv4: 2)] 2024-11-01T16:56:06.901701Z INFO dnsproxyd[2147]: INFO dnsproxyd: [proxy.cc(524)] {system:_} is now tracking [wlan0] 2024-11-01T16:56:06.902879Z INFO dnsproxyd[2161]: INFO dnsproxyd: [resolver.cc(294)] {default:wlan0} Accepting UDP queries on {family: AF_INET6, port: 53, addr: ::} 2024-11-01T16:56:06.903139Z INFO dnsproxyd[2161]: INFO dnsproxyd: [resolver.cc(269)] {default:wlan0} Accepting TCP connections on {family: AF_INET6, port: 53, addr: ::} 2024-11-01T16:56:06.905090Z INFO dnsproxyd[2147]: INFO dnsproxyd: [resolver.cc(294)] {system:wlan0} Accepting UDP queries on {family: AF_INET6, port: 53, addr: ::} 2024-11-01T16:56:06.905292Z INFO dnsproxyd[2147]: INFO dnsproxyd: [resolver.cc(269)] {system:wlan0} Accepting TCP connections on {family: AF_INET6, port: 53, addr: ::} 2024-11-01T16:56:06.907372Z INFO dnsproxyd[2161]: INFO dnsproxyd: [proxy.cc(888)] {default:wlan0} DoH: off 2024-11-01T16:56:06.908380Z INFO dnsproxyd[2161]: INFO dnsproxyd: [resolver.cc(676)] {default:wlan0} Name servers are updated, 0/2 validated name servers 2024-11-01T16:56:06.908754Z INFO dnsproxyd[2161]: INFO dnsproxyd: [proxy.cc(725)] {default:wlan0} applied device DNS configuration 2024-11-01T16:56:06.912364Z INFO patchpaneld[2009]: INFO patchpaneld: [shill_client.cc(334)] Default logical device changed from none to {shill_device: wlan0, type: wifi, ifname: wlan0, ifindex: 2, service: /service/0} 2024-11-01T16:56:06.912407Z INFO patchpaneld[2009]: INFO patchpaneld: [shill_client.cc(350)] Default physical device changed from none to {shill_device: wlan0, type: wifi, ifname: wlan0, ifindex: 2, service: /service/0} 2024-11-01T16:56:06.912528Z INFO dnsproxyd[2147]: INFO dnsproxyd: [proxy.cc(888)] {system:wlan0} DoH: off 2024-11-01T16:56:06.914400Z INFO dnsproxyd[2147]: INFO dnsproxyd: [resolver.cc(676)] {system:wlan0} Name servers are updated, 0/2 validated name servers 2024-11-01T16:56:06.917804Z INFO dnsproxyd[2147]: INFO dnsproxyd: [proxy.cc(793)] {system:wlan0} Successfully set dns-proxy address property [100.115.92.130] 2024-11-01T16:56:06.918004Z INFO dnsproxyd[2147]: INFO dnsproxyd: [proxy.cc(725)] {system:wlan0} applied device DNS configuration 2024-11-01T16:56:06.918907Z INFO dnsproxyd[1927]: INFO dnsproxyd: [resolv_conf.cc(63)] Setting resolv.conf to [100.115.92.130] 2024-11-01T16:56:06.976480Z INFO patchpaneld[2009]: INFO patchpaneld: [manager.cc(1090)] ConfigureNetwork on wlan0(2): {IPv4 address: (10.0.0.0/8: 3)/21, IPv4 broadcast: (10.0.0.0/8: 9), IPv4 gateway: (10.0.0.0/8: 7), IPv6 addresses: [], DNS: [(IPv4: 1),(IPv4: 2)]}, priority {0, primary_logical, primary_physical, primary_for_dns}, area 0x30000 2024-11-01T16:56:07.043083Z INFO patchpaneld[2009]: INFO patchpaneld: [guest_ipv6_service.cc(653)] RegisterDownstreamNeighborIP: downlink: arc_ns1, neighbor IP {(IPv6: 12)}, no corresponding uplink IP yet, postponing /128 route 2024-11-01T16:56:07.057054Z INFO patchpaneld[2009]: INFO patchpaneld: [guest_ipv6_service.cc(653)] RegisterDownstreamNeighborIP: downlink: arc_ns0, neighbor IP {(IPv6: 10)}, no corresponding uplink IP yet, postponing /128 route 2024-11-01T16:56:07.081589Z INFO patchpaneld[2009]: INFO patchpaneld: [network_monitor_service.cc(322)] NUD state changed on wlan0 for { addr: (10.0.0.0/8: 7), role: gateway, state: NUD_REACHABLE }, old_state=NUD_NONE 2024-11-01T16:56:07.567965Z INFO dnsproxyd[2147]: INFO dnsproxyd: [resolver.cc(568)] {system:wlan0} Do53 probe attempt 2 to (IPv4: 1) succeeded (0.01515 s). 1/2 validated name servers 2024-11-01T16:56:07.587380Z INFO dnsproxyd[2147]: INFO dnsproxyd: [resolver.cc(568)] {system:wlan0} Do53 probe attempt 2 to (IPv4: 2) succeeded (0.015076 s). 2/2 validated name servers 2024-11-01T16:56:07.620276Z INFO dnsproxyd[2161]: INFO dnsproxyd: [resolver.cc(568)] {default:wlan0} Do53 probe attempt 2 to (IPv4: 1) succeeded (0.014588 s). 1/2 validated name servers 2024-11-01T16:56:07.638930Z INFO dnsproxyd[2161]: INFO dnsproxyd: [resolver.cc(568)] {default:wlan0} Do53 probe attempt 2 to (IPv4: 2) succeeded (0.015035 s). 2/2 validated name servers 2024-11-01T16:56:08.013842Z NOTICE ModemManager[1941]: [base-manager] couldn't check support for device '/sys/devices/platform/soc/11240000.mmc/mmc_host/mmc1/mmc1:0001/mmc1:0001:1': not supported by any plugin