iwlwifi出错“microcode SW error detected"

yw662 · 2018-11-04 16:58:56

表现：无线网络停止工作，重启wpa_supplicant”和/或"dhcpcd后网络恢复
workaround ：定时监测网络并自动重启wpa_supplicant和dhcpcd......

> sudo journalctl -xe
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: Queue 11 is active on fifo 1 and stuck for 10000 ms. SW [53, 54] HW [53, 54] FH TRB=0x0c010a0b2
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: Microcode SW error detected. Restarting 0x2000000.
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: Start IWL Error Log Dump:
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: Status: 0x00000100, count: 6
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: Loaded firmware version: 29.1044073957.0
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00000084 | NMI_INTERRUPT_UNKNOWN
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00000220 | trm_hw_status0
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00000000 | trm_hw_status1
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00043D54 | branchlink2
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x0004AFDA | interruptlink1
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00015D9E | interruptlink2
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00000000 | data1
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00000080 | data2
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x07030000 | data3
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0xE48193FA | beacon time
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x62504405 | tsf low
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x0000063A | tsf hi
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00000000 | time gp1
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x1FC82D6B | time gp2
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00000001 | uCode revision type
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x0000001D | uCode version major
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x3E3B4DE5 | uCode version minor
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00000210 | hw version
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00C89200 | board version
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x0AA3001C | hcmd
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x24022002 | isr0
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x01800000 | isr1
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00000002 | isr2
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x004170C0 | isr3
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00000000 | isr4
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x05CE001C | last cmd Id
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00000000 | wait_event
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00000080 | l2p_control
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00018030 | l2p_duration
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x0000003F | l2p_mhvalid
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x000000CE | l2p_addr_match
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00000005 | lmpm_pmg_sel
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x14031202 | timestamp
11月 04 03:46:24 yw662 kernel: iwlwifi 0000:03:00.0: 0x00341828 | flow_handler
11月 04 03:46:24 yw662 kernel: ieee80211 phy0: Hardware restart was requested
11月 04 03:46:25 yw662 kernel: pcieport 0000:00:1c.5: AER: Corrected error received: 0000:00:1c.5
11月 04 03:46:25 yw662 kernel: pcieport 0000:00:1c.5: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID)
11月 04 03:46:25 yw662 kernel: pcieport 0000:00:1c.5: device [8086:a115] error status/mask=00000001/00002000
11月 04 03:46:25 yw662 kernel: pcieport 0000:00:1c.5: [ 0] RxErr (First)
11月 04 03:46:25 yw662 kernel: pcieport 0000:00:1c.5: AER: Corrected error received: 0000:00:1c.5
11月 04 03:46:25 yw662 kernel: pcieport 0000:00:1c.5: PCIe Bus Error: severity=Corrected, type=Physical Layer, (Receiver ID)
11月 04 03:46:25 yw662 kernel: pcieport 0000:00:1c.5: device [8086:a115] error status/mask=00000001/00002000
11月 04 03:46:25 yw662 kernel: pcieport 0000:00:1c.5: [ 0] RxErr (First)
11月 04 03:46:26 yw662 sudo[31935]: yw662 : TTY=pts/2 ; PWD=/home/yw662 ; USER=root ; COMMAND=/usr/bin/systemctl restart dhcpcd@wlp3s0.service

> sudo lspci -vv -s 03:00.0
03:00.0 Network controller: Intel Corporation Wireless 3165 (rev 79)
Subsystem: Intel Corporation Wireless 3165
Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx-
Latency: 0, Cache Line Size: 64 bytes
Interrupt: pin A routed to IRQ 139
Region 0: Memory at df200000 (64-bit, non-prefetchable) [size=8K]
Capabilities: [c8] Power Management version 3
Flags: PMEClk- DSI+ D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+)
Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME-
Capabilities: [d0] MSI: Enable+ Count=1/1 Maskable- 64bit+
Address: 00000000fee00458 Data: 0000
Capabilities: [40] Express (v2) Endpoint, MSI 00
DevCap: MaxPayload 128 bytes, PhantFunc 0, Latency L0s <512ns, L1 unlimited
ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset+ SlotPowerLimit 0.000W
DevCtl: CorrErr- NonFatalErr- FatalErr- UnsupReq-
RlxdOrd+ ExtTag- PhantFunc- AuxPwr+ NoSnoop+ FLReset-
MaxPayload 128 bytes, MaxReadReq 128 bytes
DevSta: CorrErr- NonFatalErr- FatalErr- UnsupReq- AuxPwr+ TransPend-
LnkCap: Port #0, Speed 2.5GT/s, Width x1, ASPM L1, Exit Latency L1 <32us
ClockPM+ Surprise- LLActRep- BwNot- ASPMOptComp+
LnkCtl: ASPM L1 Enabled; RCB 64 bytes Disabled- CommClk+
ExtSynch- ClockPM+ AutWidDis- BWInt- AutBWInt-
LnkSta: Speed 2.5GT/s (ok), Width x1 (ok)
TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
DevCap2: Completion Timeout: Range B, TimeoutDis+, LTR+, OBFF Via WAKE#
   AtomicOpsCap: 32bit- 64bit- 128bitCAS-
DevCtl2: Completion Timeout: 16ms to 55ms, TimeoutDis-, LTR+, OBFF Disabled
   AtomicOpsCtl: ReqEn-
LnkCtl2: Target Link Speed: 2.5GT/s, EnterCompliance- SpeedDis-
   Transmit Margin: Normal Operating Range, EnterModifiedCompliance- ComplianceSOS-
   Compliance De-emphasis: -6dB
LnkSta2: Current De-emphasis Level: -3.5dB, EqualizationComplete-, EqualizationPhase1-
   EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest-
Capabilities: [100 v1] Advanced Error Reporting
UESta: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UEMsk: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UESvrt: DLP+ SDES+ TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt- RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
CESta: RxErr- BadTLP- BadDLLP- Rollover- Timeout- AdvNonFatalErr-
CEMsk: RxErr- BadTLP- BadDLLP- Rollover- Timeout- AdvNonFatalErr+
AERCap: First Error Pointer: 00, ECRCGenCap- ECRCGenEn- ECRCChkCap- ECRCChkEn-
MultHdrRecCap- MultHdrRecEn- TLPPfxPres- HdrLogCap-
HeaderLog: 00000000 00000000 00000000 00000000
Capabilities: [140 v1] Device Serial Number 3c-f8-62-ff-ff-d9-c9-a7
Capabilities: [14c v1] Latency Tolerance Reporting
Max snoop latency: 3145728ns
Max no snoop latency: 3145728ns
Capabilities: [154 v1] L1 PM Substates
L1SubCap: PCI-PM_L1.2+ PCI-PM_L1.1+ ASPM_L1.2+ ASPM_L1.1+ L1_PM_Substates+
   PortCommonModeRestoreTime=30us PortTPowerOnTime=60us
L1SubCtl1: PCI-PM_L1.2+ PCI-PM_L1.1+ ASPM_L1.2+ ASPM_L1.1+
   T_CommonMode=0us LTR1.2_Threshold=163840ns
L1SubCtl2: T_PwrOn=60us
Kernel driver in use: iwlwifi
Kernel modules: iwlwifi

> uname -a
Linux yw662 4.19.0-arch1-1-custom

依云 · 2018-11-04 22:15:09

我有时候也遇到这个。

yw662 · 2018-11-05 03:08:52

这么说，是iwlwifi的bug？

yw662 · 2018-11-06 08:37:27

依云说：

我有时候也遇到这个。

查了一下这个确实是iwlwifi的bug，还没有看到靠谱的解决方法。目前就只能先这样了么

驿窗 · 2018-11-06 09:07:53

这个问题，出现的频率大概有多高？

yw662 · 2018-11-06 10:49:50

piter 说：

这个问题，出现的频率大概有多高？

有时候还挺高的，我有一次10分钟之内触发了3次，而且好像负载越高越容易断

yw662 · 2018-11-06 16:47:41

好像断网的频率相当的高。。。。这是我的监控脚本的日志，后面是时间戳
network failure at 1541493547129
network failure at 1541493557149
network failure at 1541493578586
network failure at 1541493588597
network failure at 1541493598711
network failure at 1541493657936
network failure at 1541493667948
network failure at 1541493683369
network failure at 1541493693376
network failure at 1541493703489
network failure at 1541493765033
network failure at 1541493775042
重启wpa_supplicant后网络恢复很快，5秒左右就都恢复了，但是一般一次断网后会反复断好几次然后才会恢复正常

最近编辑记录 yw662 (2018-11-06 16:49:58)

驿窗 · 2018-11-06 18:33:46

这个我从来没碰到过，因为我一直是用的有线；
明天开始我切换到无线，然后看一下故障频率大概是什么情况；

最近编辑记录驿窗 (2018-11-06 18:37:29)

驿窗 · 2018-11-07 10:02:32

你提到的负载高，主要是指什么？
是数据传输速度么？
如果是的话，你的实际数据传输速度大概是多少？
或者，是连接数？
我开kvm虚拟机用qbittorrent下载linuxDVD，大概两个小时15分钟，没出现过断网(或者断网后自动恢复我没注意到)；
下载速度基本稳定在6MB/S，会在5.5-6.1之间波动；

最近编辑记录驿窗 (2018-11-07 10:08:11)

yw662 · 2018-11-07 15:58:04

piter 说：

你提到的负载高，主要是指什么？
是数据传输速度么？
如果是的话，你的实际数据传输速度大概是多少？
或者，是连接数？
我开kvm虚拟机用qbittorrent下载linuxDVD，大概两个小时15分钟，没出现过断网(或者断网后自动恢复我没注意到)；
下载速度基本稳定在6MB/S，会在5.5-6.1之间波动；

你是iwlwifi的网卡么。。。
对于网卡来说负载高当然指的是传输量了。。。数字我没看
这玩意好像没负载的时候都会发生。。。感觉和负载应该没什么关系

最近编辑记录 yw662 (2018-11-07 16:01:42)

yw662 · 2018-11-07 16:07:32

11月 07 02:43:37 yw662 network_watchdog[595]: signal received at Wed Nov 07 2018 02:43:37 GMT-0500 (北美东部标准时间)
11月 07 02:53:37 yw662 network_watchdog[595]: network failure at Wed Nov 07 2018 02:53:37 GMT-0500 (北美东部标准时间)
11月 07 02:53:53 yw662 network_watchdog[595]: network failure at Wed Nov 07 2018 02:53:53 GMT-0500 (北美东部标准时间)
11月 07 02:54:08 yw662 network_watchdog[595]: signal received at Wed Nov 07 2018 02:54:08 GMT-0500 (北美东部标准时间)
11月 07 02:54:28 yw662 network_watchdog[595]: network failure at Wed Nov 07 2018 02:54:28 GMT-0500 (北美东部标准时间)
11月 07 02:54:43 yw662 network_watchdog[595]: network failure at Wed Nov 07 2018 02:54:43 GMT-0500 (北美东部标准时间)
11月 07 02:54:58 yw662 network_watchdog[595]: signal received at Wed Nov 07 2018 02:54:58 GMT-0500 (北美东部标准时间)
11月 07 02:56:50 yw662 network_watchdog[595]: network failure at Wed Nov 07 2018 02:56:50 GMT-0500 (北美东部标准时间)
11月 07 02:57:05 yw662 network_watchdog[595]: network failure at Wed Nov 07 2018 02:57:05 GMT-0500 (北美东部标准时间)
11月 07 02:57:20 yw662 network_watchdog[595]: signal received at Wed Nov 07 2018 02:57:20 GMT-0500 (北美东部标准时间)

感觉这个workaround还不错，只是看网页的话完全感觉不到发生了什么。。。

emmm献上脚本

cat ~/net-watchdog/watchdog.js

#! /usr/bin/env node

const http = require("http");
const {exec, execSync} = require("child_process");

if(process.getuid() != 0) {
    console.log("require run as root");
    process.exit(1);
}

const ping = require("net-ping").createSession();

const timeout = 1000;
const inform_counter = 10;
const wait_restart = 20000;
const restart_cmd = "systemctl restart wpa_supplicant@wlp3s0.service";
const watch_host = 
execSync("ip route").toString().match(/(?<=default via )[0-9.]+/)[0];

console.log(watch_host)

let received = true;
let c = inform_counter;
function main() {
    if(!received) {
        c = inform_counter;
        console.log("network failure at " + new Date());
        exec(restart_cmd);
        received = true;
        return setTimeout(main, wait_restart);
    }
    // c += 1;
    if(c >= inform_counter) {
        c = 0;
        console.log("signal received at " + new Date());
    }
    received = false;
    ping.pingHost(watch_host, err => received = err ? received : true);
    setTimeout(main, timeout);
}

main();

cat ~/net-watchdog/package.json

{
  "name": "net-watchdog",
  "version": "1.0.0",
  "description": "",
  "main": "watchdog.js",
  "scripts": {
    "test": "echo \"Error: no test specified\" && exit 1"
  },
  "author": "",
  "license": "CC0-1.0",
  "dependencies": {
    "net-ping": "^1.2.3"
  }
}

cat /usr/lib/systemd/system/network_watchdog.service

[Unit]
Description=network watchdog
After=dhcpcd@wlp3s0.service

[Service]
Type=simple
ExecStart=/usr/bin/network_watchdog

[Install]
WantedBy=multi-user.target

最近编辑记录 yw662 (2018-11-17 15:55:45)

驿窗 · 2018-11-07 16:58:49

我的硬件是intel 7260N；
驱动是iwlwifi；
就是以前很少用无线，都是用的有线；

---
脚本看不懂

最近编辑记录驿窗 (2018-11-07 17:04:04)

Arch Linux

#1 2018-11-04 16:58:56

iwlwifi出错“microcode SW error detected"

#2 2018-11-04 22:15:09

Re: iwlwifi出错“microcode SW error detected"

#3 2018-11-05 03:08:52

Re: iwlwifi出错“microcode SW error detected"

#4 2018-11-06 08:37:27

Re: iwlwifi出错“microcode SW error detected"

#5 2018-11-06 09:07:53

Re: iwlwifi出错“microcode SW error detected"

#6 2018-11-06 10:49:50

Re: iwlwifi出错“microcode SW error detected"

#7 2018-11-06 16:47:41

Re: iwlwifi出错“microcode SW error detected"

#8 2018-11-06 18:33:46

Re: iwlwifi出错“microcode SW error detected"

#9 2018-11-07 10:02:32

Re: iwlwifi出错“microcode SW error detected"

#10 2018-11-07 15:58:04

Re: iwlwifi出错“microcode SW error detected"

#11 2018-11-07 16:07:32

Re: iwlwifi出错“microcode SW error detected"

#12 2018-11-07 16:58:49

Re: iwlwifi出错“microcode SW error detected"

页脚