On Sat, Sep 11, 2021 at 04:29:58PM +0200, Stefan Hagen wrote: > Sep 11 15:52:39 x13 /bsd: iwx0: associated with e6:63:da:7e:f8:24 ssid > "DiscMate" channel 36 start MCS 0 long preamble short slot time HT enabled > Sep 11 15:52:39 x13 /bsd: iwx0: missed beacon threshold set to 30 beacons, > beacon interval is 100 TU > Sep 11 15:52:39 x13 /bsd: iwx0: received msg 3/4 of the 4-way handshake from > e6:63:da:7e:f8:24 > Sep 11 15:52:39 x13 /bsd: iwx0: sending msg 4/4 of the 4-way handshake to > e6:63:da:7e:f8:24 > Sep 11 15:52:39 x13 /bsd: iwx0: RUN -> ASSOC
Looks like the AP sent a dis-assoc frame here. I wonder why. Are your access points configured for band steering, perhaps? Or are there any other similar fancy "non-standard" enhancements enabled on the AP side? > Sep 11 15:52:39 x13 /bsd: iwx0: sending assoc_req to e6:63:da:7e:f8:24 on > channel 36 mode 11n > Sep 11 15:52:39 x13 /bsd: iwx0: ASSOC -> RUN > Sep 11 15:52:39 x13 /bsd: iwx0: associated with e6:63:da:7e:f8:24 ssid > "DiscMate" channel 36 start MCS 0 long preamble short slot time HT enabled > Sep 11 15:52:39 x13 /bsd: iwx0: missed beacon threshold set to 30 beacons, > beacon interval is 100 TU I suspect we don't handle RUN -> ASSOC -> RUN transitions correctly. This somehow results in the following fw error and the already known: "iwx0: could not remove MAC context (error 35) This error has been reported before (e.g. by jmc). So it's not a regression. This is an interesting trace. Thanks! > Sep 11 15:52:41 x13 /bsd: iwx0: dumping device error log > Sep 11 15:52:41 x13 /bsd: iwx0: Start Error Log Dump: > Sep 11 15:52:41 x13 /bsd: iwx0: Status: 0x9, count: 6 > Sep 11 15:52:41 x13 /bsd: iwx0: 0x00000071 | NMI_INTERRUPT_UMAC_FATAL > Sep 11 15:52:41 x13 /bsd: iwx0: 0080A210 | trm_hw_status0 > Sep 11 15:52:41 x13 /bsd: iwx0: 00000000 | trm_hw_status1 > Sep 11 15:52:41 x13 /bsd: iwx0: 004FAA7E | branchlink2 > Sep 11 15:52:41 x13 /bsd: iwx0: 00018D1C | interruptlink1 > Sep 11 15:52:41 x13 /bsd: iwx0: 00018D1C | interruptlink2 > Sep 11 15:52:41 x13 /bsd: iwx0: 0000AE56 | data1 > Sep 11 15:52:41 x13 /bsd: iwx0: 00001000 | data2 > Sep 11 15:52:41 x13 /bsd: iwx0: 00000000 | data3 > Sep 11 15:52:41 x13 /bsd: iwx0: 05415C5B | beacon time > Sep 11 15:52:41 x13 /bsd: iwx0: E50603B1 | tsf low > Sep 11 15:52:41 x13 /bsd: iwx0: 000000AD | tsf hi > Sep 11 15:52:41 x13 /bsd: iwx0: 00000000 | time gp1 > Sep 11 15:52:41 x13 /bsd: iwx0: 00631658 | time gp2 > Sep 11 15:52:41 x13 /bsd: iwx0: 00000001 | uCode revision type > Sep 11 15:52:41 x13 /bsd: iwx0: 0000003F | uCode version major > Sep 11 15:52:41 x13 /bsd: iwx0: C04F3485 | uCode version minor > Sep 11 15:52:41 x13 /bsd: iwx0: 00000340 | hw version > Sep 11 15:52:41 x13 /bsd: iwx0: 18089000 | board version > Sep 11 15:52:41 x13 /bsd: iwx0: 8018F400 | hcmd > Sep 11 15:52:41 x13 /bsd: iwx0: 24020000 | isr0 > Sep 11 15:52:41 x13 /bsd: iwx0: 00000000 | isr1 > Sep 11 15:52:41 x13 /bsd: iwx0: 08F04002 | isr2 > Sep 11 15:52:41 x13 /bsd: iwx0: 00C37FCC | isr3 > Sep 11 15:52:41 x13 /bsd: iwx0: 00000000 | isr4 > Sep 11 15:52:41 x13 /bsd: iwx0: 8064009D | last cmd Id > Sep 11 15:52:41 x13 /bsd: iwx0: 0000AE56 | wait_event > Sep 11 15:52:41 x13 /bsd: iwx0: 00000094 | l2p_control > Sep 11 15:52:41 x13 /bsd: iwx0: 00010014 | l2p_duration > Sep 11 15:52:41 x13 /bsd: iwx0: 0000000F | l2p_mhvalid > Sep 11 15:52:41 x13 /bsd: iwx0: 00000000 | l2p_addr_match > Sep 11 15:52:41 x13 /bsd: iwx0: 00000008 | lmpm_pmg_sel > Sep 11 15:52:41 x13 /bsd: iwx0: 00000000 | timestamp > Sep 11 15:52:41 x13 /bsd: iwx0: 000088AC | flow_handler > Sep 11 15:52:41 x13 /bsd: iwx0: Start UMAC Error Log Dump: > Sep 11 15:52:41 x13 /bsd: iwx0: Status: 0x9, count: 7 > Sep 11 15:52:41 x13 /bsd: iwx0: 0x20003421 | ADVANCED_SYSASSERT > Sep 11 15:52:41 x13 /bsd: iwx0: 0x00000000 | umac branchlink1 > Sep 11 15:52:41 x13 /bsd: iwx0: 0x8045541A | umac branchlink2 > Sep 11 15:52:41 x13 /bsd: iwx0: 0x01075170 | umac interruptlink1 > Sep 11 15:52:41 x13 /bsd: iwx0: 0x00000000 | umac interruptlink2 > Sep 11 15:52:41 x13 /bsd: iwx0: 0x00000000 | umac data1 > Sep 11 15:52:41 x13 /bsd: iwx0: 0x00000001 | umac data2 > Sep 11 15:52:41 x13 /bsd: iwx0: 0xDEADBEEF | umac data3 > Sep 11 15:52:41 x13 /bsd: iwx0: 0x0000003F | umac major > Sep 11 15:52:41 x13 /bsd: iwx0: 0xC04F3485 | umac minor > Sep 11 15:52:41 x13 /bsd: iwx0: 0x00631653 | frame pointer > Sep 11 15:52:41 x13 /bsd: iwx0: 0xC0885E58 | stack pointer > Sep 11 15:52:41 x13 /bsd: iwx0: 0x003B0128 | last host cmd > Sep 11 15:52:41 x13 /bsd: iwx0: 0x00000000 | isr status reg > Sep 11 15:52:41 x13 /bsd: driver status: > Sep 11 15:52:41 x13 /bsd: tx ring 0: qid=0 cur=60 queued=1 > Sep 11 15:52:41 x13 /bsd: tx ring 1: qid=1 cur=1 queued=0 > Sep 11 15:52:41 x13 /bsd: tx ring 2: qid=2 cur=0 queued=0 > Sep 11 15:52:41 x13 /bsd: tx ring 3: qid=3 cur=0 queued=0 > Sep 11 15:52:41 x13 /bsd: tx ring 4: qid=4 cur=0 queued=0 > Sep 11 15:52:41 x13 /bsd: tx ring 5: qid=5 cur=0 queued=0 > Sep 11 15:52:41 x13 /bsd: tx ring 6: qid=6 cur=0 queued=0 > Sep 11 15:52:41 x13 /bsd: tx ring 7: qid=7 cur=0 queued=0 > Sep 11 15:52:41 x13 /bsd: tx ring 8: qid=8 cur=0 queued=0 > Sep 11 15:52:41 x13 /bsd: rx ring: cur=141 > Sep 11 15:52:41 x13 /bsd: 802.11 state RUN > Sep 11 15:52:41 x13 /bsd: iwx0: fatal firmware error > Sep 11 15:52:42 x13 /bsd: iwx0: could not remove MAC context (error 35) > Sep 11 15:52:42 x13 /bsd: iwx0: RUN -> INIT > Sep 11 15:52:42 x13 /bsd: iwx0: begin active scan > Sep 11 15:52:42 x13 /bsd: iwx0: INIT -> SCAN > Sep 11 15:52:44 x13 ntpd[83393]: recvmsg 2606:4700:f1::1: Host is down > Sep 11 15:52:46 x13 /bsd: iwx0: end active scan > Sep 11 15:52:46 x13 /bsd: iwx0: AP e0:63:da:b7:24:c2 "DiscMate" score 73 > Sep 11 15:52:46 x13 /bsd: iwx0: AP e6:63:da:b8:24:c2 "DiscMate" score 75 > Sep 11 15:52:46 x13 /bsd: iwx0: - 0c:8e:29:42:fb:f0 1 +11 54M ess > privacy rsn "Champ Zone"! > Sep 11 15:52:46 x13 /bsd: iwx0: + 18:e8:29:57:3d:06 1 +24 54M ess > privacy rsn "DiscMate" > Sep 11 15:52:46 x13 /bsd: iwx0: + 18:e8:29:58:3d:06 36 +25 54M ess > privacy rsn "DiscMate" > Sep 11 15:52:46 x13 /bsd: iwx0: - 1c:3a:de:74:c2:50 13 +10 54M ess > privacy rsn "HZN242371510"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 1e:e8:29:58:3d:06 36 +25 54M ess > privacy rsn ""! > Sep 11 15:52:46 x13 /bsd: iwx0: - 2c:91:ab:82:87:44 11 +20 54M ess > privacy rsn "FRITZ!Box 6591 Cable AQ"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 38:43:7d:a5:ea:43 44 +16 54M ess > privacy rsn "UPC5673586"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 38:43:7d:a5:ea:69 1 +17 54M ess > privacy rsn "UPC5673586"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 4c:1b:86:17:91:62 11 +18 54M ess > privacy rsn "WLAN-791054"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 4c:1b:86:17:91:64 11 +20 54M ess > no! rsn! "Telekom_FON"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 64:cc:22:a0:fc:84 1 +20 54M ess > privacy rsn "Champ Zone"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 70:54:25:5d:db:d6 6 +16 54M ess > privacy rsn "Vodafone-87B0"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 70:54:25:5e:70:d5 1 +31 54M ess > privacy rsn "Vodafone-51D6"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 70:54:25:5e:70:d6 64 +23 54M ess > privacy rsn "Vodafone-51D6_5G"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 70:54:25:6f:05:f6 6 +22 54M ess > privacy rsn "Vodafone-B9B8"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 90:5c:44:71:67:f6 6 +19 54M ess > privacy rsn "UPCAC8BF62"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 90:5c:44:98:a8:07 11 +20 54M ess > privacy rsn "UPC852F365"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 92:5c:14:26:33:d5 11 +11 54M ess > no! rsn! "Vodafone Hotspot"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 92:5c:14:71:67:f6 6 +18 54M ess > no! rsn! "Vodafone Hotspot"! > Sep 11 15:52:46 x13 /bsd: iwx0: - 92:5c:14:98:a8:07 11 +20 54M ess > no! rsn! "Vodafone Hotspot"! > Sep 11 15:52:46 x13 /bsd: iwx0: - a2:9d:7e:92:cc:6c 6 +11 54M ess > no! rsn! ""! > Sep 11 15:52:46 x13 /bsd: iwx0: - cc:ce:1e:2d:8a:61 1 +14 54M ess > privacy rsn "FRITZ!Box 7412"! > Sep 11 15:52:46 x13 /bsd: iwx0: - cc:ce:1e:bd:2a:34 1 +20 54M ess > privacy rsn "FRITZ!Box 6490 Cable"! > Sep 11 15:52:46 x13 /bsd: iwx0: - cc:ce:1e:bd:2a:35 60 +13 54M ess > privacy rsn "FRITZ!Box 6490 Cable"! > Sep 11 15:52:46 x13 /bsd: iwx0: - ce:ce:1e:bd:2a:35 60 +14 54M ess > privacy rsn "FRITZ!Box Gastzugang"! > Sep 11 15:52:46 x13 /bsd: iwx0: + e0:63:da:7d:f8:24 1 +41 54M ess > privacy rsn "DiscMate" > Sep 11 15:52:46 x13 /bsd: iwx0: + e0:63:da:b7:24:c2 1 +36 54M ess > privacy rsn "DiscMate" > Sep 11 15:52:46 x13 /bsd: iwx0: + e6:63:da:7e:f8:24 36 +54 54M ess > privacy rsn "DiscMate" > Sep 11 15:52:46 x13 /bsd: iwx0: - e6:63:da:b7:24:c2 1 +36 54M ess > privacy rsn ""! > Sep 11 15:52:46 x13 /bsd: iwx0: + e6:63:da:b8:24:c2 36 +52 54M ess > privacy rsn "DiscMate" > Sep 11 15:52:46 x13 /bsd: iwx0: - ea:63:da:7e:f8:24 36 +54 54M ess > privacy rsn ""! > Sep 11 15:52:46 x13 /bsd: iwx0: - fa:b4:6a:06:50:aa 11 +15 54M ess > privacy rsn "DIRECT-AA-HP ENVY 5000 series"! > Sep 11 15:52:46 x13 /bsd: iwx0: firmware has detected regulatory domain 'EU' > (0x4555) > Sep 11 15:52:46 x13 /bsd: iwx0: SCAN -> AUTH > Sep 11 15:52:46 x13 /bsd: iwx0: sending auth to e6:63:da:7e:f8:24 on channel > 36 mode 11a > Sep 11 15:52:46 x13 /bsd: iwx0: AUTH -> ASSOC > Sep 11 15:52:46 x13 /bsd: iwx0: sending assoc_req to e6:63:da:7e:f8:24 on > channel 36 mode 11a > Sep 11 15:52:46 x13 /bsd: iwx0: received msg 1/4 of the 4-way handshake from > e6:63:da:7e:f8:24 > Sep 11 15:52:46 x13 /bsd: iwx0: sending msg 2/4 of the 4-way handshake to > e6:63:da:7e:f8:24 > Sep 11 15:52:46 x13 /bsd: iwx0: ASSOC -> RUN > Sep 11 15:52:46 x13 /bsd: iwx0: associated with e6:63:da:7e:f8:24 ssid > "DiscMate" channel 36 start MCS 0 long preamble short slot time HT enabled > Sep 11 15:52:46 x13 /bsd: iwx0: missed beacon threshold set to 30 beacons, > beacon interval is 100 TU > Sep 11 15:52:46 x13 /bsd: iwx0: received msg 3/4 of the 4-way handshake from > e6:63:da:7e:f8:24 > Sep 11 15:52:46 x13 /bsd: iwx0: sending msg 4/4 of the 4-way handshake to > e6:63:da:7e:f8:24 > Sep 11 15:52:46 x13 /bsd: iwx0: sending addba_resp to e6:63:da:7e:f8:24 on > channel 36 mode 11n > Sep 11 15:52:46 x13 dhcpleased[35111]: failed to send route message: File > exists > Sep 11 15:52:46 x13 /bsd: iwx0: sending addba_resp to e6:63:da:7e:f8:24 on > channel 36 mode 11n > >
