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

Issue 604769 link

Starred by 2 users

Issue metadata

Status: WontFix
Owner:
Last visit 15 days ago
Closed: Apr 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug

Blocking:
issue 594336
issue 604759



Sign in to add a comment

Crashes in chromeos_supplicant_process_proxy.cc: "Failed to get interface wlan0"

Project Member Reported by steve...@chromium.org, Apr 19 2016

Issue description

The following Shill crash is causing failures in Chrome OS builders, notably the PFQ:

FATAL:chromeos_supplicant_process_proxy.cc(168)] Failed to get interface wlan0: fi.w1.wpa_supplicant1.InterfaceUnknown wpa_supplicant knows nothing about this interface.#012/usr/lib64/libbase-core-369476.so(base::debug::StackTrace::StackTrace()+0x14) [0x7fdb745a9a54]#012

A recent failure along with a bunch of shill crash dumps can be found here:

http://cautotest.corp.google.com/tko/retrieve_logs.cgi?job=/results/59502258-chromeos-test/chromeos4-row2-rack3-host19/debug/


 
Crash snippet:

 3  libbase-core-381699.so!logging::LogMessage::~LogMessage [logging.cc : 751 + 0x5]
    rbx = 0x00007fff4a328ab0   rbp = 0x00007fff4a328810
    rsp = 0x00007fff4a328170   r12 = 0x00007f2f3e053220
    r13 = 0x00007fff4a328ab8   r14 = 0x00007fff4a3281b0
    r15 = 0x00007f2f3f3a7610   rip = 0x00007f2f3e4b63ae
    Found by: call frame info
 4  shill!shill::ChromeosSupplicantProcessProxy::GetInterface [chromeos_supplicant_process_proxy.cc : 168 + 0x8]
    rbx = 0x00007f2f3e053220   rbp = 0x00007fff4a328c70
    rsp = 0x00007fff4a328820   r12 = 0x00007f2f3f3ac7a0
    r13 = 0x00007fff4a328a50   r14 = 0x00007fff4a328ab8
    r15 = 0x00007fff4a328ab0   rip = 0x00007f2f3ea1207c
    Found by: call frame info
 5  shill!shill::WiFi::ConnectToSupplicant [wifi.cc : 2323 + 0xe]
    rbx = 0x00007f2f3f3a81c0   rbp = 0x00007fff4a3294f0
    rsp = 0x00007fff4a328c80   r12 = 0x00007f2f3e053220
    r13 = 0x00007fff4a328d00   r14 = 0x00007fff4a328ce0
    r15 = 0x00007f2f3f3a8708   rip = 0x00007f2f3ea911dd
    Found by: call frame info
 6  shill!shill::WiFi::OnSupplicantAppear [wifi.cc : 2226 + 0x8]
    rbx = 0x00007f2f3f3a81c0   rbp = 0x00007fff4a3296a0
    rsp = 0x00007fff4a329500   r12 = 0x00007fff4a329500
    r13 = 0x00007f2f3f355c80   r14 = 0x00007fff4a329710
    r15 = 0x00007fff4a329a50   rip = 0x00007f2f3ea91d1f
    Found by: call frame info
 7  libbase-core-381699.so!base::debug::TaskAnnotator::RunTask [callback.h : 397 + 0x8]
    rbx = 0x00007fff4a329740   rbp = 0x00007fff4a3297b0
    rsp = 0x00007fff4a3296b0   r12 = 0x00007f2f3e573404
    r13 = 0x00007f2f3f355c80   r14 = 0x00007fff4a329710
    r15 = 0x00007fff4a329a50   rip = 0x00007f2f3e497cda
    Found by: call frame info

network_DefaultProfileServices/sysinfo/messages snippet (In https://pantheon.corp.google.com/storage/browser/chromeos-autotest-results/59502258-chromeos-test/chromeos4-row2-rack3-host19/network_DefaultProfileServices/sysinfo/)

2016-04-09T19:08:54.796966+00:00 ERR wpa_supplicant[545]: Could not set interface wlan0 flags (UP): Input/output error
2016-04-09T19:08:54.796992+00:00 ERR wpa_supplicant[545]: nl80211: Could not set interface 'wlan0' UP
2016-04-09T19:08:54.797015+00:00 ERR wpa_supplicant[545]: wlan0: Failed to initialize driver interface
2016-04-09T19:08:54.797655+00:00 ERR shill[21243]: [ERROR:object_proxy.cc(580)] Failed to call method: fi.w1.wpa_supplicant1.CreateInterface: object_path= /fi/w1/wpa_supplicant1: fi.w1.wpa_supplicant1.UnknownError: wpa_supplicant couldn't grab this interface.
2016-04-09T19:08:54.797682+00:00 ERR shill[21243]: [ERROR:dbus_method_invoker.h(111)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=fi.w1.wpa_supplicant1.UnknownError, Message=wpa_supplicant couldn't grab this interface.
2016-04-09T19:08:54.797695+00:00 ERR shill[21243]: [ERROR:chromeos_supplicant_process_proxy.cc(130)] Failed to create interface: fi.w1.wpa_supplicant1.UnknownError wpa_supplicant couldn't grab this interface.
2016-04-09T19:08:54.799735+00:00 ERR shill[21243]: [ERROR:object_proxy.cc(580)] Failed to call method: fi.w1.wpa_supplicant1.GetInterface: object_path= /fi/w1/wpa_supplicant1: fi.w1.wpa_supplicant1.InterfaceUnknown: wpa_supplicant knows nothing about this interface.
2016-04-09T19:08:54.799761+00:00 ERR shill[21243]: [ERROR:dbus_method_invoker.h(111)] CallMethodAndBlockWithTimeout(...): Domain=dbus, Code=fi.w1.wpa_supplicant1.InterfaceUnknown, Message=wpa_supplicant knows nothing about this interface.
2016-04-09T19:08:54.799774+00:00 CRIT shill[21243]: [FATAL:chromeos_supplicant_process_proxy.cc(168)] Failed to get interface wlan0: fi.w1.wpa_supplicant1.InterfaceUnknown wpa_supplicant knows nothing about this interface.#012/usr/lib64/libbase-core-381699.so(base::debug::StackTrace::StackTrace()+0x14) [0x7f2f3e496d14]#012
2016-04-09T19:08:54.799791+00:00 ERR shill[21244]: [FATAL:chromeos_supplicant_process_proxy.cc(168)] Failed to get interface wlan0: fi.w1.wpa_supplicant1.InterfaceUnknown wpa_supplicant knows nothing about this interface.
2016-04-09T19:08:54.799803+00:00 ERR shill[21244]: /usr/lib64/libbase-core-381699.so(base::debug::StackTrace::StackTrace()+0x14) [0x7f2f3e496d14]

Note: there are a bunch of kernel errors preceding that.


Comment 3 by z...@chromium.org, Apr 19 2016

Owner: ejcaruso@chromium.org
I think shill crashes are just side effect of the wifi driver failing to bring up the interface, there is nothing shill can do without the WiFi interface.

2016-04-09T19:08:54.794586+00:00 ERR kernel: [  296.827088] iwlwifi 0000:02:00.0: Microcode SW error detected.  Restarting 0x2000000.
2016-04-09T19:08:54.794616+00:00 ERR kernel: [  296.827116] iwlwifi 0000:02:00.0: CSR values:
2016-04-09T19:08:54.794624+00:00 ERR kernel: [  296.827131] iwlwifi 0000:02:00.0: (2nd byte of CSR_INT_COALESCING is CSR_INT_PERIODIC_REG)
2016-04-09T19:08:54.794628+00:00 ERR kernel: [  296.827164] iwlwifi 0000:02:00.0:        CSR_HW_IF_CONFIG_REG: 0X40489204
2016-04-09T19:08:54.794633+00:00 ERR kernel: [  296.827194] iwlwifi 0000:02:00.0:          CSR_INT_COALESCING: 0X80000040
2016-04-09T19:08:54.794640+00:00 ERR kernel: [  296.827224] iwlwifi 0000:02:00.0:                     CSR_INT: 0X00000000
2016-04-09T19:08:54.794643+00:00 ERR kernel: [  296.827253] iwlwifi 0000:02:00.0:                CSR_INT_MASK: 0X00000000
2016-04-09T19:08:54.794647+00:00 ERR kernel: [  296.827282] iwlwifi 0000:02:00.0:           CSR_FH_INT_STATUS: 0X00000000
2016-04-09T19:08:54.794651+00:00 ERR kernel: [  296.827311] iwlwifi 0000:02:00.0:                 CSR_GPIO_IN: 0X00000000
2016-04-09T19:08:54.794664+00:00 ERR kernel: [  296.827340] iwlwifi 0000:02:00.0:                   CSR_RESET: 0X00000000
2016-04-09T19:08:54.794667+00:00 ERR kernel: [  296.827370] iwlwifi 0000:02:00.0:                CSR_GP_CNTRL: 0X080403c5
2016-04-09T19:08:54.794671+00:00 ERR kernel: [  296.827399] iwlwifi 0000:02:00.0:                  CSR_HW_REV: 0X00000144
2016-04-09T19:08:54.794677+00:00 ERR kernel: [  296.827428] iwlwifi 0000:02:00.0:              CSR_EEPROM_REG: 0X00000000
2016-04-09T19:08:54.794684+00:00 ERR kernel: [  296.827458] iwlwifi 0000:02:00.0:               CSR_EEPROM_GP: 0X80000000
2016-04-09T19:08:54.794687+00:00 ERR kernel: [  296.827487] iwlwifi 0000:02:00.0:              CSR_OTP_GP_REG: 0X803a0000
2016-04-09T19:08:54.794691+00:00 ERR kernel: [  296.827516] iwlwifi 0000:02:00.0:                 CSR_GIO_REG: 0X00080042
2016-04-09T19:08:54.794695+00:00 ERR kernel: [  296.827545] iwlwifi 0000:02:00.0:            CSR_GP_UCODE_REG: 0X00000000
2016-04-09T19:08:54.794707+00:00 ERR kernel: [  296.827575] iwlwifi 0000:02:00.0:           CSR_GP_DRIVER_REG: 0X00000000
2016-04-09T19:08:54.794710+00:00 ERR kernel: [  296.827604] iwlwifi 0000:02:00.0:           CSR_UCODE_DRV_GP1: 0X00000000
2016-04-09T19:08:54.794714+00:00 ERR kernel: [  296.827633] iwlwifi 0000:02:00.0:           CSR_UCODE_DRV_GP2: 0X00000000
2016-04-09T19:08:54.794720+00:00 ERR kernel: [  296.827663] iwlwifi 0000:02:00.0:                 CSR_LED_REG: 0X00000018
2016-04-09T19:08:54.794726+00:00 ERR kernel: [  296.827692] iwlwifi 0000:02:00.0:        CSR_DRAM_INT_TBL_REG: 0X881528d9
2016-04-09T19:08:54.794732+00:00 ERR kernel: [  296.827721] iwlwifi 0000:02:00.0:        CSR_GIO_CHICKEN_BITS: 0X27800200
2016-04-09T19:08:54.794736+00:00 ERR kernel: [  296.827750] iwlwifi 0000:02:00.0:             CSR_ANA_PLL_CFG: 0Xd55555d5
2016-04-09T19:08:54.794740+00:00 ERR kernel: [  296.827821] iwlwifi 0000:02:00.0:      CSR_MONITOR_STATUS_REG: 0X3d0801bc
2016-04-09T19:08:54.794777+00:00 ERR kernel: [  296.827895] iwlwifi 0000:02:00.0:           CSR_HW_REV_WA_REG: 0X0001001a
2016-04-09T19:08:54.794784+00:00 ERR kernel: [  296.827930] iwlwifi 0000:02:00.0:        CSR_DBG_HPET_MEM_REG: 0Xffff0000
2016-04-09T19:08:54.794788+00:00 ERR kernel: [  296.827955] iwlwifi 0000:02:00.0: FH register values:
2016-04-09T19:08:54.794801+00:00 ERR kernel: [  296.827998] iwlwifi 0000:02:00.0:         FH_RSCSR_CHNL0_STTS_WPTR_REG: 0X14ff2400
2016-04-09T19:08:54.794805+00:00 ERR kernel: [  296.828043] iwlwifi 0000:02:00.0:        FH_RSCSR_CHNL0_RBDCB_BASE_REG: 0X014ff230
2016-04-09T19:08:54.794809+00:00 ERR kernel: [  296.828089] iwlwifi 0000:02:00.0:                  FH_RSCSR_CHNL0_WPTR: 0X00000000
2016-04-09T19:08:54.795771+00:00 ERR kernel: [  296.828136] iwlwifi 0000:02:00.0:         FH_MEM_RCSR_CHNL0_CONFIG_REG: 0X00801114
2016-04-09T19:08:54.795786+00:00 ERR kernel: [  296.828181] iwlwifi 0000:02:00.0:          FH_MEM_RSSR_SHARED_CTRL_REG: 0X000000fc
2016-04-09T19:08:54.795791+00:00 ERR kernel: [  296.828226] iwlwifi 0000:02:00.0:            FH_MEM_RSSR_RX_STATUS_REG: 0X03030000
2016-04-09T19:08:54.795797+00:00 ERR kernel: [  296.828271] iwlwifi 0000:02:00.0:    FH_MEM_RSSR_RX_ENABLE_ERR_IRQ2DRV: 0X00000000
2016-04-09T19:08:54.795803+00:00 ERR kernel: [  296.828316] iwlwifi 0000:02:00.0:                FH_TSSR_TX_STATUS_REG: 0X07ff0001
2016-04-09T19:08:54.795808+00:00 ERR kernel: [  296.828363] iwlwifi 0000:02:00.0:                 FH_TSSR_TX_ERROR_REG: 0X00000000
2016-04-09T19:08:54.795813+00:00 ERR kernel: [  296.828509] iwlwifi 0000:02:00.0: Start IWL Error Log Dump:
2016-04-09T19:08:54.795818+00:00 ERR kernel: [  296.828532] iwlwifi 0000:02:00.0: Status: 0x00000000, count: 6
2016-04-09T19:08:54.795823+00:00 ERR kernel: [  296.828554] iwlwifi 0000:02:00.0: Loaded firmware version: 16.229726.0
2016-04-09T19:08:54.795829+00:00 ERR kernel: [  296.828579] iwlwifi 0000:02:00.0: 0x00000034 | NMI_INTERRUPT_WDG           
2016-04-09T19:08:54.795835+00:00 ERR kernel: [  296.828602] iwlwifi 0000:02:00.0: 0x000002F0 | uPc
2016-04-09T19:08:54.795839+00:00 ERR kernel: [  296.828622] iwlwifi 0000:02:00.0: 0x00000000 | branchlink1
2016-04-09T19:08:54.795845+00:00 ERR kernel: [  296.828643] iwlwifi 0000:02:00.0: 0x0000099A | branchlink2
2016-04-09T19:08:54.795850+00:00 ERR kernel: [  296.828664] iwlwifi 0000:02:00.0: 0x0000D21C | interruptlink1
2016-04-09T19:08:54.795855+00:00 ERR kernel: [  296.828689] iwlwifi 0000:02:00.0: 0x0000D928 | interruptlink2
2016-04-09T19:08:54.795860+00:00 ERR kernel: [  296.828710] iwlwifi 0000:02:00.0: 0x00000000 | data1
2016-04-09T19:08:54.795864+00:00 ERR kernel: [  296.828730] iwlwifi 0000:02:00.0: 0x00000002 | data2
2016-04-09T19:08:54.795870+00:00 ERR kernel: [  296.828751] iwlwifi 0000:02:00.0: 0x07030000 | data3
2016-04-09T19:08:54.795875+00:00 ERR kernel: [  296.828785] iwlwifi 0000:02:00.0: 0x003C7B1B | beacon time
2016-04-09T19:08:54.795880+00:00 ERR kernel: [  296.828806] iwlwifi 0000:02:00.0: 0x000384E3 | tsf low
2016-04-09T19:08:54.795885+00:00 ERR kernel: [  296.828827] iwlwifi 0000:02:00.0: 0x00000000 | tsf hi
2016-04-09T19:08:54.795890+00:00 ERR kernel: [  296.828847] iwlwifi 0000:02:00.0: 0x00000000 | time gp1
2016-04-09T19:08:54.795896+00:00 ERR kernel: [  296.828868] iwlwifi 0000:02:00.0: 0x000384E4 | time gp2
2016-04-09T19:08:54.795900+00:00 ERR kernel: [  296.828889] iwlwifi 0000:02:00.0: 0x00000000 | time gp3
2016-04-09T19:08:54.795905+00:00 ERR kernel: [  296.828911] iwlwifi 0000:02:00.0: 0x00000010 | uCode version major
2016-04-09T19:08:54.795911+00:00 ERR kernel: [  296.828933] iwlwifi 0000:02:00.0: 0x0003815E | uCode version minor
2016-04-09T19:08:54.795916+00:00 ERR kernel: [  296.828955] iwlwifi 0000:02:00.0: 0x00000144 | hw version
2016-04-09T19:08:54.795921+00:00 ERR kernel: [  296.828977] iwlwifi 0000:02:00.0: 0x40489204 | board version
2016-04-09T19:08:54.795961+00:00 ERR kernel: [  296.829085] iwlwifi 0000:02:00.0: 0x0902006A | hcmd
2016-04-09T19:08:54.795966+00:00 ERR kernel: [  296.829105] iwlwifi 0000:02:00.0: 0x00022080 | isr0
2016-04-09T19:08:54.795971+00:00 ERR kernel: [  296.829125] iwlwifi 0000:02:00.0: 0x00000000 | isr1
2016-04-09T19:08:54.795976+00:00 ERR kernel: [  296.829145] iwlwifi 0000:02:00.0: 0x00000002 | isr2
2016-04-09T19:08:54.795980+00:00 ERR kernel: [  296.829165] iwlwifi 0000:02:00.0: 0x404000C0 | isr3
2016-04-09T19:08:54.795985+00:00 ERR kernel: [  296.829185] iwlwifi 0000:02:00.0: 0x00000080 | isr4
2016-04-09T19:08:54.795990+00:00 ERR kernel: [  296.829205] iwlwifi 0000:02:00.0: 0x01800112 | isr_pref
2016-04-09T19:08:54.795995+00:00 ERR kernel: [  296.829226] iwlwifi 0000:02:00.0: 0x00000000 | wait_event
2016-04-09T19:08:54.796000+00:00 ERR kernel: [  296.829247] iwlwifi 0000:02:00.0: 0x00000040 | l2p_control
2016-04-09T19:08:54.796023+00:00 ERR kernel: [  296.829285] iwlwifi 0000:02:00.0: 0x00000000 | l2p_duration
2016-04-09T19:08:54.796028+00:00 ERR kernel: [  296.829307] iwlwifi 0000:02:00.0: 0x00000000 | l2p_mhvalid
2016-04-09T19:08:54.796034+00:00 ERR kernel: [  296.829328] iwlwifi 0000:02:00.0: 0x00000000 | l2p_addr_match
2016-04-09T19:08:54.796044+00:00 ERR kernel: [  296.829350] iwlwifi 0000:02:00.0: 0x00000007 | lmpm_pmg_sel
2016-04-09T19:08:54.796481+00:00 ERR kernel: [  296.829372] iwlwifi 0000:02:00.0: 0x12101904 | timestamp
2016-04-09T19:08:54.796490+00:00 ERR kernel: [  296.829393] iwlwifi 0000:02:00.0: 0x00340010 | flow_handler
2016-04-09T19:08:54.796495+00:00 ERR kernel: [  296.829441] iwlwifi 0000:02:00.0: Failed to run INIT ucode: -5
2016-04-09T19:08:54.796966+00:00 ERR wpa_supplicant[545]: Could not set interface wlan0 flags (UP): Input/output error
2016-04-09T19:08:54.796992+00:00 ERR wpa_supplicant[545]: nl80211: Could not set interface 'wlan0' UP
2016-04-09T19:08:54.797015+00:00 ERR wpa_supplicant[545]: wlan0: Failed to initialize driver interface

@ejcaruso, feel free to reassign someone in Chrome OS WiFi team to investigate further.
Cc: snanda@chromium.org
Do we know why the interface isn't coming up? Are we seeing this on all trickies/haswell/7260s or just specific DUTs?
Good question. Scanning the failures blocked on  issue 604759 , I see a range of DUTs affected, but several times where the same DUT will fail several times in a row.

It is limited to tricky and cyan DUTs.

Comment 7 by pstew@chromium.org, Apr 19 2016

Thanks for the quick response Peter!  BTW, Steven, Peter's not on the WiFi team anymore (not even mine) so please don't assign directly to him anymore.  You should find someone on the Chrome OS WiFi team to triage.
He was on the blame list which was all I had to go on, but I'll try to remember :) I appreciate the quick responses all around, and thanks Eric for investigating.


Comment 9 by snanda@chromium.org, Apr 27 2016

Status: WontFix (was: Assigned)
Creating partner tracker issue crosbug.com/p/52804 to help track this.  Closing here.
Naive comment - would it be preferable to have shill fail gracefully? if the wifi interface isn't being brought up for some reason, pretend that wifi is turned off instead of crashing? 

Fair question.

My take on this is: as long as the shill crash isn't taking down the system, the current behavior is actually a good thing.

Most Chromebooks are Wifi-only. On such systems, a shill crash (should) only affect Wifi. The user should still be able to access local/cached content, as normal.

Since the crash doesn't affect the user, it's better to fail loudly. That way, we find out about lower-layer problems more quickly (as this bug demonstrates).

Note that there's also some chance that a crash will fix the problem. When shill crashes, the init daemon will restart shill. If the root cause was that shill had corrupted its memory (and hence, was asking supplicant for wlan123, instead of wlan0), then the crash-and-restart would have recovered Wifi.

Sign in to add a comment