On Fri, Jan 22, 2021 at 01:51:28AM +0000, James Cook wrote:
> On Thu, Jan 21, 2021 at 02:22:40PM +0100, Stefan Sperling wrote:
> > On Thu, Jan 21, 2021 at 12:47:25AM +0000, James Cook wrote:
> > > >Synopsis:        iwx0 repeatedly goes offline with "unhandled firmware 
> > > >response 0x3fd"
> > > >Category:        kernel
> > > >Environment:
> > >   System      : OpenBSD 6.8
> > >   Details     : OpenBSD 6.8-current (GENERIC.MP) #284: Wed Jan 20 
> > > 02:40:03 MST 2021
> > >                    
> > > dera...@amd64.openbsd.org:/usr/src/sys/arch/amd64/compile/GENERIC.MP
> > > 
> > >   Architecture: OpenBSD.amd64
> > >   Machine     : amd64
> > > >Description:
> > >   My wireless connection keeps dropping and then coming back up several
> > >   seconds or a few minutes later. Here is a typical example from 
> > > /var/log/messages:
> > > 
> > >   Jan 21 00:34:27 moth /bsd: iwx0: dumping device error log
> > >   Jan 21 00:34:27 moth /bsd: iwx0: Start Error Log Dump:
> > >   Jan 21 00:34:27 moth /bsd: iwx0: Status: 0x39, count: 6
> > >   Jan 21 00:34:27 moth /bsd: iwx0: 0x00004424 | ADVANCED_SYSASSERT        
> > >   
> > 
> > >   Jan 21 00:34:27 moth /bsd: iwx0: fatal firmware error
> > 
> > This first firmware error is most likely a symptom of a driver bug.
> > 
> > To figure out what's causing this it would help to see exactly which
> > frames were exchanged with the AP at the time (00:34:27).
> > 
> > The best way to observe this is to capture raw frames from another machine
> > listening in monitor mode on the same channel (iwn/iwm/iwx would do).
> > Alternatively, you could capture frames on the iwx(4) client itself, but
> > in this case some information could be missing because the firmware will
> > not expose all received frames to the driver.
> > 
> > In either case, the command to capture raw wifi frames is:
> > tcpdump -n -i iwx0 -s 4096 -y IEEE802_11_RADIO -w /tmp/iwx.pcap
> > Replace iwx0 with the correct interface if you're using monitor mode.
> > 
> > wireshark from ports is the most useful tool for viewing the resulting
> > pcap file.
> 
> I used a different laptop running Linux to monitor the interface. Your
> command seemsed work with Debian's tcpdump except I had to add
> --monitor-mode and change the interface name.
> 
> I captured three events where iwx0 failed. I don't know much about
> analyzing network dumps, but here's what I observed. Let me know if
> there's anything specific I should be looking for.
> 
> In all three cases, moth (the OpenBSD laptop I'm debugging) sent a
> Request-to-Send frame to my AP, and then moth got spammed with hundreds
> of Clear-to-send frames with about a millisecond in between (at a
> glance, gap vary between <0.5ms and a bit over 2ms).
> 
> Here's a censored excerpt from output of tshark -r (the output of
> tcpdump). IntelCor_AA:AA:AA is moth and HitronTe_BB:BB:BB is my router
> and AP.

Thanks. Could you please mail me a full pcap file (zipped)?

There's information I need which isn't visible in this excerpt,
such as dynamic run-time configuration information sent to clients
by the AP in its beacons. Without that I cannot tell how the firmware
and driver are expected to behave compared to the observed behaviour.

>  2909  45.410650              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Clear-to-send, Flags=........C
>  2910  45.410743 IntelCor_AA:AA:AA → 00:00:00_00:00:02 802.11 157 Data, 
> SN=51, FN=0, Flags=.p.....TC
>  2911  45.410751              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Acknowledgement, Flags=........C
>  2912  45.427510 ASUSTekC_DD:DD:DD → Broadcast    802.11 369 Beacon frame, 
> SN=2168, FN=0, Flags=........C, BI=100, SSID=XXX
>  2913  45.430718              → HitronTe_BB:BB:BB (f8:1d:0f:BB:BB:BB) (RA) 
> 802.11 32 Clear-to-send, Flags=........C
>  2914  45.430868 00:00:00_00:00:02 → IntelCor_AA:AA:AA 802.11 159 QoS Data, 
> SN=20, FN=0, Flags=.p....F.C
>  2915  45.430876              → HitronTe_BB:BB:BB (f8:1d:0f:BB:BB:BB) (RA) 
> 802.11 32 Acknowledgement, Flags=........C
>  2916  45.466591 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2976, FN=0, Flags=........C, BI=100, SSID=XXX
>  2917  45.532568 HitronTe_BB:BB:BB → Broadcast    802.11 327 Beacon frame, 
> SN=3495, FN=0, Flags=........C, BI=400, SSID=OnOffStar
>  2918  45.569113 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2977, FN=0, Flags=........C, BI=100, SSID=XXX
>  2919  45.632294 ASUSTekC_DD:DD:DD → Broadcast    802.11 369 Beacon frame, 
> SN=2171, FN=0, Flags=........C, BI=100, SSID=YYY
>  2920  45.669184 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2978, FN=0, Flags=........C, BI=100, SSID=XXX
>  2921  45.686800 HitronTe_EE:EE:EE → Broadcast    802.11 322 Beacon frame, 
> SN=2938, FN=0, Flags=........C, BI=400, SSID=ZZZ
>  2922  45.734689 ASUSTekC_DD:DD:DD → Broadcast    802.11 369 Beacon frame, 
> SN=2172, FN=0, Flags=........C, BI=100, SSID=YYY
>  2923  45.773799 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2979, FN=0, Flags=........C, BI=100, SSID=XXX
>  2924  45.837091 ASUSTekC_DD:DD:DD → Broadcast    802.11 369 Beacon frame, 
> SN=2173, FN=0, Flags=........C, BI=100, SSID=YYY
>  2925  45.839804 HitronTe_BB:BB:BB → Broadcast    802.11 327 Beacon frame, 
> SN=3496, FN=0, Flags=........C, BI=400, SSID=OnOffStar
>  2926  45.874071 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2980, FN=0, Flags=........C, BI=100, SSID=XXX
>  2927  45.941138 Sagemcom_CC:CC:CC → Spanning-tree-(for-bridges)_00 802.11 
> 108 Data, SN=2981, FN=0, Flags=.p....F.C
>  2928  45.976276 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2982, FN=0, Flags=........C, BI=100, SSID=XXX
>  2929  45.994053 HitronTe_EE:EE:EE → Broadcast    802.11 322 Beacon frame, 
> SN=2939, FN=0, Flags=........C, BI=400, SSID=ZZZ
>  2930  46.041894 ASUSTekC_DD:DD:DD → Broadcast    802.11 369 Beacon frame, 
> SN=2175, FN=0, Flags=........C, BI=100, SSID=YYY
>  2931  46.083023 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2983, FN=0, Flags=........C, BI=100, SSID=XXX
>  2932  46.144311 ASUSTekC_DD:DD:DD → Broadcast    802.11 369 Beacon frame, 
> SN=2176, FN=0, Flags=........C, BI=100, SSID=YYY
>  2933  46.146986 HitronTe_BB:BB:BB → Broadcast    802.11 327 Beacon frame, 
> SN=3497, FN=0, Flags=........C, BI=400, SSID=OnOffStar
>  2934  46.181192 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2984, FN=0, Flags=........C, BI=100, SSID=XXX
>  2935  46.283566 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2985, FN=0, Flags=........C, BI=100, SSID=XXX
>  2936  46.301313 HitronTe_EE:EE:EE → Broadcast    802.11 322 Beacon frame, 
> SN=2940, FN=0, Flags=........C, BI=400, SSID=ZZZ
>  2937  46.388245 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2986, FN=0, Flags=........C, BI=100, SSID=XXX
>  2938  46.440201 IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (TA) → 
> HitronTe_BB:BB:BB (f8:1d:0f:BB:BB:BB) (RA) 802.11 38 Request-to-send, 
> Flags=........C
>  2939  46.440410              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Clear-to-send, Flags=........C
>  2940  46.440495 IntelCor_AA:AA:AA → 00:00:00_00:00:02 802.11 157 Data, 
> SN=52, FN=0, Flags=.p.....TC
>  2941  46.440504              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Acknowledgement, Flags=........C
>  2942  46.451511 ASUSTekC_DD:DD:DD → Broadcast    802.11 369 Beacon frame, 
> SN=2179, FN=0, Flags=........C, BI=100, SSID=YYY
>  2943  46.454193 HitronTe_BB:BB:BB → Broadcast    802.11 327 Beacon frame, 
> SN=3498, FN=0, Flags=........C, BI=400, SSID=OnOffStar
>  2944  46.461564              → HitronTe_BB:BB:BB (f8:1d:0f:BB:BB:BB) (RA) 
> 802.11 32 Clear-to-send, Flags=........C
>  2945  46.461574 00:00:00_00:00:02 → IntelCor_AA:AA:AA 802.11 159 QoS Data, 
> SN=21, FN=0, Flags=.p....F.C
>  2946  46.461578              → HitronTe_BB:BB:BB (f8:1d:0f:BB:BB:BB) (RA) 
> 802.11 32 Acknowledgement, Flags=........C
>  2947  46.488492 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2987, FN=0, Flags=........C, BI=100, SSID=XXX
>  2948  46.543795 ASUSTekC_GG:GG:GG → Spanning-tree-(for-bridges)_00 802.11 
> 108 Data, SN=3499, FN=0, Flags=.p....F.C
>  2949  46.590969 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2988, FN=0, Flags=........C, BI=100, SSID=XXX
>  2950  46.608444 HitronTe_EE:EE:EE → Broadcast    802.11 322 Beacon frame, 
> SN=2941, FN=0, Flags=........C, BI=400, SSID=ZZZ
>  2951  46.656303 ASUSTekC_DD:DD:DD → Broadcast    802.11 369 Beacon frame, 
> SN=2181, FN=0, Flags=........C, BI=100, SSID=YYY
>  2952  46.658743 SamsungE_FF:FF:FF → IPv4mcast_07 802.11 298 Data, SN=2182, 
> FN=0, Flags=.p....F.C
>  2953  46.695414 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2989, FN=0, Flags=........C, BI=100, SSID=XXX
>  2954  46.758702 ASUSTekC_DD:DD:DD → Broadcast    802.11 369 Beacon frame, 
> SN=2183, FN=0, Flags=........C, BI=100, SSID=YYY
>  2955  46.761375 HitronTe_BB:BB:BB → Broadcast    802.11 327 Beacon frame, 
> SN=3500, FN=0, Flags=........C, BI=400, SSID=OnOffStar
>  2956  46.797203 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2990, FN=0, Flags=........C, BI=100, SSID=XXX
>  2957  46.815911 ASUSTekC_DD:DD:DD → Dyson_HH:HH:HH 802.11 48 QoS Null 
> function (No data), SN=2184, FN=0, Flags=......F.C
>  2958  46.861125 ASUSTekC_DD:DD:DD → Broadcast    802.11 369 Beacon frame, 
> SN=2185, FN=0, Flags=........C, BI=100, SSID=YYY
>  2959  46.898000 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2991, FN=0, Flags=........C, BI=100, SSID=XXX
>  2960  46.915644 HitronTe_EE:EE:EE → Broadcast    802.11 322 Beacon frame, 
> SN=2942, FN=0, Flags=........C, BI=400, SSID=ZZZ
>  2961  46.936028 00:00:00_00:00:02 → IPv6mcast_01 802.11 246 Data, SN=3501, 
> FN=0, Flags=.p....F.C
>  2962  46.966084 SamsungE_FF:FF:FF → IPv4mcast_7f:ff:fa 802.11 133 Data, 
> SN=2187, FN=0, Flags=.pm...F.C
>  2963  47.009253 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2992, FN=0, Flags=........C, BI=100, SSID=XXX
>  2964  47.065916 ASUSTekC_DD:DD:DD → Broadcast    802.11 369 Beacon frame, 
> SN=2189, FN=0, Flags=........C, BI=100, SSID=YYY
>  2965  47.068509 HitronTe_BB:BB:BB → Broadcast    802.11 327 Beacon frame, 
> SN=3502, FN=0, Flags=........C, BI=400, SSID=OnOffStar
>  2966  47.102843 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2993, FN=0, Flags=........C, BI=100, SSID=XXX
>  2967  47.207497 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2994, FN=0, Flags=........C, BI=100, SSID=XXX
>  2968  47.222844 HitronTe_EE:EE:EE → Broadcast    802.11 322 Beacon frame, 
> SN=2943, FN=0, Flags=........C, BI=400, SSID=ZZZ
>  2969  47.310532 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2995, FN=0, Flags=........C, BI=100, SSID=XXX
>  2970  47.376140 HitronTe_BB:BB:BB → Broadcast    802.11 327 Beacon frame, 
> SN=3503, FN=0, Flags=........C, BI=400, SSID=OnOffStar
>  2971  47.410839 Sagemcom_CC:CC:CC → Broadcast    802.11 286 Beacon frame, 
> SN=2996, FN=0, Flags=........C, BI=100, SSID=XXX
>  2972  47.472950 IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (TA) → 
> HitronTe_BB:BB:BB (f8:1d:0f:BB:BB:BB) (RA) 802.11 38 Request-to-send, 
> Flags=........C
>  2973  47.473461 IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (TA) → 
> HitronTe_BB:BB:BB (f8:1d:0f:BB:BB:BB) (RA) 802.11 38 Request-to-send, 
> Flags=........C
>  2974  47.473649              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Clear-to-send, Flags=........C
>  2975  47.474702 IntelCor_AA:AA:AA → 00:00:00_00:00:02 802.11 157 Data, 
> SN=53, FN=0, Flags=.p.....TC
>  2976  47.474715 IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (TA) → 
> HitronTe_BB:BB:BB (f8:1d:0f:BB:BB:BB) (RA) 802.11 38 Request-to-send, 
> Flags=........C
>  2977  47.474721              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Clear-to-send, Flags=........C
>  2978  47.475137 IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (TA) → 
> HitronTe_BB:BB:BB (f8:1d:0f:BB:BB:BB) (RA) 802.11 38 Request-to-send, 
> Flags=........C
>  2979  47.475149              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Clear-to-send, Flags=........C
>  2980  47.477456              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Clear-to-send, Flags=........C
>  2981  47.479468              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Clear-to-send, Flags=........C
>  2982  47.483590              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Clear-to-send, Flags=........C
>  2983  47.485564              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Clear-to-send, Flags=........C
>  2984  47.487995              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Clear-to-send, Flags=........C
>  2985  47.488685              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Clear-to-send, Flags=........C
>  2986  47.489048              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Clear-to-send, Flags=........C
>  2987  47.493778              → IntelCor_AA:AA:AA (4c:1d:96:AA:AA:AA) (RA) 
> 802.11 32 Clear-to-send, Flags=........C

Reply via email to