New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 775512 link

Starred by 9 users

Issue metadata

Status: Verified
Owner:
Last visit > 30 days ago
Closed: Jan 2018
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 2
Type: Bug-Regression



Sign in to add a comment

ChromeOS issue: no wifi network avaiable after update to 61 from 58

Project Member Reported by marcore@chromium.org, Oct 17 2017

Issue description

ChromeOS version: 61.0.3163.120/9765.81.0
ChromeOS device model: Samsung xe503c12 PIT
Case#: 13936182

Description: no network avaiable after update to 61 from 58


Steps to reproduce: 
update from 58.0.3029.140/9334.72.0 to latest stable (61.0.3163.120/9765.81.0)
Current Behavior / Reproduction: 
no wifi connection
Expected Behavior: 
wifi connection
Drive link to logs: https://drive.google.com/open?id=0B01ZVp8vDQoccWJLMnVGOUNpcFU
the customer also tryed on beta release:
62.0.3202.55/9901.46.0
Drive link to logs: https://drive.google.com/open?id=0B01ZVp8vDQocMWhUbGx5OHB4QW8

in the log I see:
eventlog.txt
247 | 2017-10-16 10:51:59 | System boot | 0
248 | 2017-10-16 10:58:41 | System boot | 0

net.log:
2017-10-16T10:52:13.607369-06:00 INFO shill[1449]: [INFO:wifi_service.cc(783)] Rep ep updated for 4. [SSID=_SSID4_], bssid: _MAC_ADDRESS_:dc, sig: -57, sec: none, freq: 5785
2017-10-16T10:52:13.611442-06:00 INFO shill[1449]: [INFO:wifi_service.cc(783)] Rep ep updated for 4. [SSID=_SSID4_], bssid: _MAC_ADDRESS_:d8, sig: -45, sec: none, freq: 2427
2017-10-16T10:52:13.635107-06:00 INFO shill[1449]: [INFO:service.cc(305)] Auto-connecting to service 4
2017-10-16T10:52:13.635384-06:00 INFO shill[1449]: [INFO:service.cc(321)] Connect to service 4: AutoConnect
2017-10-16T10:52:13.635589-06:00 INFO shill[1449]: [INFO:wifi.cc(679)] Background scan: simple:30:-50:3601
2017-10-16T10:52:13.639845-06:00 INFO shill[1449]: [INFO:service.cc(400)] Service 4: state Idle -> Associating
2017-10-16T10:52:13.639915-06:00 INFO shill[1449]: [INFO:manager.cc(1452)] Service 4 updated; state: Associating failure Unknown
2017-10-16T10:52:13.640096-06:00 NOTICE wpa_supplicant[652]: mlan0: Trying to associate with _MAC_ADDRESS_:dc (SSID='_SSID4_' freq=5785 MHz)
2017-10-16T10:52:13.646138-06:00 INFO shill[1449]: [INFO:manager.cc(1696)] Default physical service: 4 (not connected)
2017-10-16T10:52:13.646551-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 4 (connecting)
2017-10-16T10:52:13.729268-06:00 NOTICE wpa_supplicant[652]: mlan0: Associated with _MAC_ADDRESS_:dc
2017-10-16T10:52:13.731199-06:00 NOTICE wpa_supplicant[652]: mlan0: CTRL-EVENT-CONNECTED - Connection to _MAC_ADDRESS_:dc completed [id=0 id_str=]
2017-10-16T10:52:13.737230-06:00 ERR wpa_supplicant[652]: WMM AC: Missing IEs
2017-10-16T10:52:13.738529-06:00 INFO shill[1449]: [INFO:wifi_service.cc(783)] Rep ep updated for 4. [SSID=_SSID4_], bssid: _MAC_ADDRESS_:dc, sig: -57, sec: none, freq: 5785
2017-10-16T10:52:13.739546-06:00 NOTICE wpa_supplicant[652]: mlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US
2017-10-16T10:52:13.740196-06:00 INFO shill[1449]: [INFO:wifi.cc(1534)] WiFi mlan0 StateChanged associating -> completed
2017-10-16T10:52:13.755108-06:00 INFO shill[1449]: [INFO:dhcp_config.cc(203)] Spawned /sbin/dhcpcd with pid: 2606
2017-10-16T10:52:13.755260-06:00 INFO shill[1449]: [INFO:wifi.cc(1589)] mlan0 is up; started L3 configuration.
2017-10-16T10:52:13.755440-06:00 INFO shill[1449]: [INFO:service.cc(400)] Service 4: state Associating -> Configuring
2017-10-16T10:52:13.755558-06:00 INFO shill[1449]: [INFO:manager.cc(1452)] Service 4 updated; state: Configuring failure Unknown
2017-10-16T10:52:13.765187-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 4 (connecting)
2017-10-16T10:52:13.766826-06:00 NOTICE dhcpcd[2606]: dhcpcd is running with reduced privileges
2017-10-16T10:52:13.771391-06:00 INFO dhcpcd[2606]: status changed to Init
2017-10-16T10:52:13.772262-06:00 INFO shill[1449]: [INFO:dhcp_config.cc(145)] Init DHCP Proxy: mlan0 at :1.45
2017-10-16T10:52:13.811715-06:00 NOTICE wpa_supplicant[652]: mlan0: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-55 noise=9999 txrate=360000
2017-10-16T10:52:13.919400-06:00 INFO dhcpcd[2606]: status changed to Reboot
2017-10-16T10:52:13.959100-06:00 INFO dhcpcd[2606]: mlan0: ARP probing XX.XX.18.1 (1 of 3), next in 1.2 seconds
2017-10-16T10:52:13.959214-06:00 INFO dhcpcd[2606]: mlan0: rebinding lease of XX.XX.18.99
2017-10-16T10:52:13.959465-06:00 INFO dhcpcd[2606]: mlan0: sending REQUEST (xid 0x8a589897), next in 4.8 seconds
2017-10-16T10:52:13.963307-06:00 INFO dhcpcd[2606]: event GATEWAY-ARP on interface mlan0
2017-10-16T10:52:13.964886-06:00 INFO shill[1449]: [INFO:dhcpv4_config.cc(123)] Event reason: GATEWAY-ARP
2017-10-16T10:52:13.965479-06:00 INFO shill[1449]: [INFO:connection.cc(225)] UpdateFromIPConfig: Installing with parameters: local=XX.XX.18.99 broadcast=XX.XX.19.255 peer=<unknown> gateway=XX.XX.18.1
2017-10-16T10:52:13.966474-06:00 INFO shill[1449]: [INFO:service.cc(400)] Service 4: state Configuring -> Connected
2017-10-16T10:52:13.981984-06:00 INFO shill[1449]: [INFO:manager.cc(1452)] Service 4 updated; state: Connected failure Unknown
2017-10-16T10:52:13.994055-06:00 INFO dhcpcd[2606]: mlan0: received ACK with xid 0x8a589897
2017-10-16T10:52:13.994168-06:00 INFO dhcpcd[2606]: mlan0: acknowledged XX.XX.18.99 from XX.XX.0.5
2017-10-16T10:52:13.994229-06:00 INFO dhcpcd[2606]: mlan0: leased XX.XX.18.99 for 432000 seconds
2017-10-16T10:52:13.994589-06:00 INFO dhcpcd[2606]: event REBOOT on interface mlan0
2017-10-16T10:52:13.996814-06:00 INFO shill[1449]: [INFO:wifi.cc(2348)] Enabling high bitrates.
2017-10-16T10:52:13.997335-06:00 INFO dhcpcd[2606]: status changed to Bound
2017-10-16T10:52:14.036944-06:00 INFO shill[1449]: [INFO:manager.cc(1700)] Default physical service: 4 (connected)
2017-10-16T10:52:14.043334-06:00 INFO shill[1449]: [INFO:dhcpv4_config.cc(123)] Event reason: REBOOT
2017-10-16T10:52:14.043889-06:00 INFO shill[1449]: [INFO:connection.cc(225)] UpdateFromIPConfig: Installing with parameters: local=XX.XX.18.99 broadcast=XX.XX.19.255 peer=<unknown> gateway=XX.XX.18.1
2017-10-16T10:52:14.044726-06:00 INFO shill[1449]: [INFO:wifi.cc(2348)] Enabling high bitrates.
2017-10-16T10:52:14.401824-06:00 INFO shill[1449]: [INFO:portal_detector.cc(125)] Portal detection completed attempt 1 with phase==Content, status==Success, failures in content==0
2017-10-16T10:52:14.402048-06:00 INFO shill[1449]: [INFO:service.cc(400)] Service 4: state Connected -> Online
2017-10-16T10:52:14.402101-06:00 INFO shill[1449]: [INFO:manager.cc(1452)] Service 4 updated; state: Online failure Unknown
2017-10-16T10:52:14.663609-06:00 INFO shill[1449]: [INFO:wifi.cc(319)] Scan on mlan0 from RequestScan
2017-10-16T10:52:16.396124-06:00 NOTICE wpa_supplicant[652]: mlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
2017-10-16T10:52:20.233735-06:00 NOTICE wpa_supplicant[652]: message repeated 3 times: [ mlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN]
2017-10-16T10:52:20.240133-06:00 INFO shill[1449]: [INFO:wifi.cc(386)] ScanDone
2017-10-16T10:52:44.842589-06:00 WARNING shill[1449]: [WARNING:traffic_monitor.cc(221)] Congested tx queues detected, out-of-credits?
2017-10-16T10:52:56.213384-06:00 INFO shill[1449]: [INFO:wifi.cc(386)] ScanDone
2017-10-16T10:53:13.458553-06:00 INFO shill[1449]: [INFO:wifi.cc(319)] Scan on mlan0 from RequestScan
2017-10-16T10:53:14.948806-06:00 INFO shill[1449]: [INFO:manager.cc(1477)] Device mlan0 updated: disabled
2017-10-16T10:53:14.962234-06:00 INFO shill[1449]: [INFO:dhcp_config.cc(210)] Stopping 2606 (ReleaseIP)
2017-10-16T10:53:14.962341-06:00 INFO dhcpcd[2606]: received SIGTERM, stopping
2017-10-16T10:53:14.962361-06:00 INFO dhcpcd[2606]: mlan0: removing interface
2017-10-16T10:53:14.987240-06:00 INFO dhcpcd[2606]: status changed to Release
2017-10-16T10:53:14.987643-06:00 INFO dhcpcd[2606]: dhcpcd exited
2017-10-16T10:53:14.991386-06:00 INFO shill[1449]: [INFO:service.cc(400)] Service 4: state Online -> Idle
2017-10-16T10:53:14.991446-06:00 INFO shill[1449]: [INFO:manager.cc(1452)] Service 4 updated; state: Idle failure Unknown
2017-10-16T10:53:15.170714-06:00 NOTICE wpa_supplicant[652]: mlan0: CTRL-EVENT-DISCONNECTED bssid=_MAC_ADDRESS_:dc reason=0 locally_generated=1
2017-10-16T10:53:18.942844-06:00 INFO shill[1449]: [INFO:manager.cc(1452)] Service 4 updated; state: Idle failure Unknown
2017-10-16T10:53:18.944386-06:00 INFO shill[1449]: message repeated 2 times: [ [INFO:manager.cc(1452)] Service 4 updated; state: Idle failure Unknown]
2017-10-16T10:53:18.944642-06:00 INFO shill[1449]: [INFO:wifi_service.cc(783)] Rep ep updated for 4. [SSID=_SSID4_], bssid: _MAC_ADDRESS_:a8, sig: -66, sec: none, freq: 2412
2017-10-16T10:53:18.945634-06:00 INFO shill[1449]: [INFO:manager.cc(1452)] Service 4 updated; state: Idle failure Unknown
2017-10-16T10:53:18.954111-06:00 INFO shill[1449]: message repeated 10 times: [ [INFO:manager.cc(1452)] Service 4 updated; state: Idle failure Unknown]
2017-10-16T10:53:18.954327-06:00 INFO shill[1449]: [INFO:wifi_service.cc(783)] Rep ep updated for 8. [SSID=_SSID8_], bssid: _MAC_ADDRESS_:a8, sig: -65, sec: rsn, freq: 2412
2017-10-16T10:53:18.955723-06:00 INFO shill[1449]: [INFO:manager.cc(1452)] Service 4 updated; state: Idle failure Unknown
2017-10-16T10:53:18.957025-06:00 INFO shill[1449]: message repeated 2 times: [ [INFO:manager.cc(1452)] Service 4 updated; state: Idle failure Unknown]
2017-10-16T10:53:18.966697-06:00 ERR shill[1449]: [ERROR:object_proxy.cc(582)] Failed to call method: fi.w1.wpa_supplicant1.Interface.Disconnect: object_path= /fi/w1/wpa_supplicant1/Interfaces/1: fi.w1.wpa_supplicant1.NotConnected: This interface is not connected
2017-10-16T10:53:18.966811-06:00 ERR shill[1449]: [ERROR:dbus_method_invoker.h(111)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=fi.w1.wpa_supplicant1.NotConnected, Message=This interface is not connected
2017-10-16T10:53:18.966907-06:00 ERR shill[1449]: [ERROR:chromeos_supplicant_interface_proxy.cc(196)] Failed to disconnect: fi.w1.wpa_supplicant1.NotConnected This interface is not connected
2017-10-16T10:53:18.969186-06:00 INFO shill[1449]: [INFO:manager.cc(1452)] Service 4 updated; state: Idle failure Unknown
2017-10-16T10:53:19.024227-06:00 NOTICE wpa_supplicant[652]: nl80211: deinit ifname=mlan0 disabled_11b_rates=0
2017-10-16T10:53:19.047628-06:00 ERR wpa_supplicant[652]: rmdir[ctrl_interface=/run/wpa_supplicant]: Permission denied
2017-10-16T10:53:19.050730-06:00 INFO shill[1449]: [INFO:wifi.cc(319)] Scan on mlan0 from RequestScan
2017-10-16T10:53:19.050863-06:00 INFO shill[1449]: [INFO:manager.cc(1477)] Device mlan0 updated: enabled
2017-10-16T10:53:19.062655-06:00 INFO shill[1449]: [INFO:wifi.cc(2265)] mlan0: enabled supplicant: present proxy: null
2017-10-16T10:53:19.076312-06:00 NOTICE wpa_supplicant[652]: nl80211: Could not re-add multicast membership for vendor events: -2 (No such file or directory)
2017-10-16T10:53:19.152588-06:00 NOTICE wpa_supplicant[652]: MPM: Debug Dialog Token initialized 2944537697 (0xaf821461)
2017-10-16T10:53:19.168823-06:00 INFO shill[1449]: [INFO:wifi.cc(319)] Scan on mlan0 from ConnectToSupplicant
2017-10-16T10:53:19.170423-06:00 ERR shill[1449]: [ERROR:attribute_list.cc(243)] Trying to re-add attribute: 3
2017-10-16T10:53:19.174604-06:00 ERR shill[1449]: message repeated 29 times: [ [ERROR:attribute_list.cc(243)] Trying to re-add attribute: 3]
2017-10-16T10:53:19.177693-06:00 INFO shill[1449]: [INFO:manager.cc(1696)] Default physical service: 2 (not connected)
2017-10-16T10:53:19.178221-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 2 (no endpoints)
2017-10-16T10:53:19.178403-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 0 (no endpoints)
2017-10-16T10:53:19.178582-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 1 (no endpoints)
2017-10-16T10:53:19.178748-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 3 (no endpoints)
2017-10-16T10:53:19.178898-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 4 (no endpoints)
2017-10-16T10:53:19.179058-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 5 (no endpoints)
2017-10-16T10:53:19.179204-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 6 (no endpoints)
2017-10-16T10:53:19.206859-06:00 NOTICE wpa_supplicant[652]: mlan0: Reject scan trigger since one is already pending
2017-10-16T10:53:19.207368-06:00 ERR shill[1449]: [ERROR:object_proxy.cc(582)] Failed to call method: fi.w1.wpa_supplicant1.Interface.Scan: object_path= /fi/w1/wpa_supplicant1/Interfaces/3: fi.w1.wpa_s
upplicant1.Interface.ScanError: Scan request rejected
2017-10-16T10:53:19.207650-06:00 ERR shill[1449]: [ERROR:dbus_method_invoker.h(111)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=fi.w1.wpa_supplicant1.Interface.ScanError, Message=Scan reques
t rejected
2017-10-16T10:53:19.207894-06:00 ERR shill[1449]: [ERROR:chromeos_supplicant_interface_proxy.cc(305)] Failed to scan: fi.w1.wpa_supplicant1.Interface.ScanError Scan request rejected
2017-10-16T10:53:19.208116-06:00 WARNING shill[1449]: [WARNING:wifi.cc(1500)] Scan failed
2017-10-16T10:53:19.208539-06:00 ERR shill[1449]: [ERROR:chromeos_dhcpcd_listener.cc(184)] Unknown DHCP client PID 2606
2017-10-16T10:53:20.667999-06:00 NOTICE wpa_supplicant[652]: mlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
2017-10-16T10:53:22.995796-06:00 NOTICE wpa_supplicant[652]: message repeated 3 times: [ mlan0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN]
2017-10-16T10:53:23.236305-06:00 INFO shill[1449]: [INFO:service.cc(292)] wifi service 9 constructed.
2017-10-16T10:53:23.237254-06:00 INFO shill[1449]: [INFO:wifi_service.cc(181)] Constructed WiFi service 9 name: [SSID=_SSID9_]
2017-10-16T10:53:23.238021-06:00 INFO shill[1449]: [INFO:wifi_service.cc(783)] Rep ep updated for 9. [SSID=_SSID9_], bssid: _MAC_ADDRESS_:dc, sig: -59, sec: rsn, freq: 5785
2017-10-16T10:53:23.256918-06:00 INFO shill[1449]: [INFO:wifi.cc(386)] ScanDone
2017-10-16T10:53:23.257980-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 2 (no endpoints)
2017-10-16T10:53:23.258186-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 0 (no endpoints)
2017-10-16T10:53:23.258361-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 1 (no endpoints)
2017-10-16T10:53:23.258531-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 3 (no endpoints)
2017-10-16T10:53:23.258697-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 4 (no endpoints)
2017-10-16T10:53:23.258842-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 5 (no endpoints)
2017-10-16T10:53:23.258995-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 6 (no endpoints)
2017-10-16T10:53:23.270640-06:00 INFO shill[1449]: [INFO:wifi_service.cc(783)] Rep ep updated for 4. [SSID=_SSID4_], bssid: _MAC_ADDRESS_:dc, sig: -59, sec: none, freq: 5785
2017-10-16T10:53:23.287405-06:00 INFO shill[1449]: [INFO:wifi.cc(1534)] WiFi mlan0 StateChanged completed -> inactive
2017-10-16T10:53:23.289459-06:00 INFO shill[1449]: [INFO:service.cc(314)] Suppressed autoconnect to service 2 (no endpoints)
2017-10-16T10:53:23.289612-06:00 INFO shill[1449]: [INFO:service.cc(305)] Auto-connecting to service 4
2017-10-16T10:53:23.289938-06:00 INFO shill[1449]: [INFO:service.cc(321)] Connect to service 4: AutoConnect

and then it starts again

 
Cc: marcore@chromium.org
Owner: keta...@chromium.org
Hi, could you please help triage this issue ?
Can we please get any updates on this? Thank you.

Comment 3 by jopina@google.com, Nov 21 2017

Just received a confirmation from the affected user that the issue has been resolved. User was recommended to update the affected devices to the M62 and the issue was not observed anymore. This issue may now be closed.
Status: Fixed (was: Untriaged)
Based on comment#3. Closing this as fixed. 
Status: Verified (was: Fixed)
Closing as verified. 

Sign in to add a comment