Network not working when TWT is activated on nrf7002DK

[Seb-labs]

I have an nrf7002DK

using sdk-nrf v2.4.1.

I compiled wifi shell sample

The used ap is netgear WAX214 AX1800.

After connecting to it, I check the wifi status:

> wifi status
Status: successful
==================
State: COMPLETED
Interface Mode: STATION
Link Mode: WIFI 6 (802.11ax/HE)
SSID: MyWifi6                    
BSSID: **:**:**:**:**:**
Band: 5GHz
Channel: 44
Security: WPA3-SAE
MFP: Optional
RSSI: -38
Beacon Interval: 100
DTIM: 2
TWT: Supported

All communications are working correctly (ping from 7002DK, ping to 7002DK, tcp from 7002DK).

I activate twt:

>wifi twt setup 0 0 1 1 0 1 1 1 65000 524000
TWT operation TWT setup with dg: 1, flow_id: 1 requested
TWT response: TWT accept
TWT Dialog token: 1
TWT flow ID: 1
TWT negotiation type: TWT individual negotiation
TWT responder: true
TWT implicit: true
TWT announce: true
TWT trigger: true
TWT wake interval: 65024 us
TWT interval: 524000 us
========================
>wifi ps
PS status: Power save enabled
PS mode: Legacy power save
PS listen_interval: 10
PS wake up mode: DTIM
PS timeout: -1 ms
TWT Dialog token: 1
TWT flow ID: 1
TWT negotiation type: TWT individual negotiation
TWT responder: false
TWT implicit: true
TWT announce: true
TWT trigger: true
TWT wake interval: 65024 us
TWT interval: 524000 us
========================

And then no communication are working:

>net ping 192.168.0.1
PING 192.168.0.1
Ping timeout

>net tcp connect 192.168.0.1 80
Connecting from 192.168.1.39:0 to 192.168.0.1:80
TCP connection failed (-116)
[00:08:47.829,925] <err> os: ***** USAGE FAULT *****
[00:08:47.829,956] <err> os:   Illegal use of the EPSR
[00:08:47.829,956] <err> os: r0/a1:  0x20000e18  r1/a2:  0x0008ea08  r2/a3:  0x20007e40
[00:08:47.829,956] <err> os: r3/a4:  0x0008ecf8 r12/ip:  0x20038c20 r14/lr:  0x0000c60f
[00:08:47.829,956] <err> os:  xpsr:  0x60000000
[00:08:47.829,986] <err> os: Faulting instruction address (r15/pc): 0x0008ecf8
[00:08:47.829,986] <err> os: >>> ZEPHYR FATAL ERROR 35: Unknown error on CPU 0
[00:08:47.830,017] <err> os: Current thread: 0x20002868 (tcp_work)
[00:08:47.887,664] <err> coredump: #CD:BEGIN#
[00:08:47.893,432] <err> coredump: #CD:5a4501000300050023000000
[00:08:47.900,726] <err> coredump: #CD:4102004400
[00:08:47.906,829] <err> coredump: #CD:180e002008ea0800407e0020f8ec0800208c03200fc60000f8ec080000000060
[00:08:47.917,633] <err> coredump: #CD:28d0002000000000000000000000000000000000000000000000000000000000
[00:08:47.928,405] <err> coredump: #CD:00000000
[00:08:47.934,326] <err> coredump: #CD:4d01006828002030290020
[00:08:47.941,467] <err> coredump: #CD:e0200020607e0020000000000080f00000000000000000000000000000000000
[00:08:47.952,270] <err> coredump: #CD:000000000000000000000000000000000000000000000000ffffffffffffffff
[00:08:47.963,073] <err> coredump: #CD:00000000000000000000000000000000f0cf002000000000c0280020c0280020
[00:08:47.973,876] <err> coredump: #CD:0001000009910500682800200000000000000000d03200207463705f776f726b
[00:08:47.984,649] <err> coredump: #CD:00000000000000000000000000000000000000000000000000000000a0cc0020
[00:08:47.995,452] <err> coredump: #CD:0004000000000000ec1300200000000000000000000000000000000000000000
[00:08:48.006,256] <err> coredump: #CD:0000000000000000
[00:08:48.012,878] <err> coredump: #CD:4d0100a0cc0020a0d00020
[00:08:48.020,019] <err> coredump: #CD:f0f0f0f0aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.030,822] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.041,595] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.052,398] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.063,201] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.074,005] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.084,808] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.095,581] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.106,384] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.117,187] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.127,990] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.138,793] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.149,597] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.160,400] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.171,203] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa
[00:08:48.182,006] <err> coredump: #CD:aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaab032002020310020
[00:08:48.192,779] <err> coredump: #CD:00000000d99305002031002001000000607e0020f19405006828002068280020
[00:08:48.203,582] <err> coredump: #CD:44100020d79605006828002017a208000000000000ed00e0407e002000000000
[00:08:48.214,385] <err> coredump: #CD:c1000000640c09000200000000000000ffffffff208c0320640c090044cf0020
[00:08:48.225,189] <err> coredump: #CD:02000000e0350020640c0900e1fc060044cf0020020000001c00000025fd0600
[00:08:48.235,992] <err> coredump: #CD:44cf0020020000001c00000080ef080003fd0600c43500200f4809008f0a0700
[00:08:48.246,795] <err> coredump: #CD:0200000002000000140c09000a0000001d05070000000000ffffffffb50a0700
[00:08:48.257,598] <err> coredump: #CD:af0a070015050700140c09005b050700becf00201c000000140c090047590000
[00:08:48.268,402] <err> coredump: #CD:becf0020c0cf00200d48090048d0002074000000000000008000016400000000
[00:08:48.279,174] <err> coredump: #CD:000000000000000000000000010000009294070119950700b032002020310020
[00:08:48.289,978] <err> coredump: #CD:00000000d99305002031002001000000607e0020f19405006828002068280020
[00:08:48.300,781] <err> coredump: #CD:68440020d79605006828002017a208000000000000ed00e0407e002000000000
[00:08:48.311,584] <err> coredump: #CD:208c032023970500e4c400000000006168440020c38d05006844002000000000
[00:08:48.322,357] <err> coredump: #CD:68440020878e0500180e002008ea0800407e0020f8ec0800208c03200fc60000
[00:08:48.333,160] <err> coredump: #CD:f8ec08000000006000000000197007008cffffff0000000064ae032001000000
[00:08:48.343,963] <err> coredump: #CD:3cae032095700700ccae0320682800200000000093910500ffffffffffffffff
[00:08:48.354,736] <err> coredump: #CD:0000000068280020099105000000000000000000f7bc060000000000aaaaaaaa
[00:08:48.365,539] <err> coredump: #CD:END#
[00:08:48.371,093] <err> fatal_error: Resetting system

The last valid stack trace is https://github.com/nrfconnect/sdk-zephyr/blob/28a3fca7da5cfb3b72f1a874b3b7fa62f713ab3d/subsys/net/ip/tcp.c#L503.

After some minutes of twt activated, the 7002DK disappear from connected device in the AP webui. If I desactivate twt, the 7002DK realise it is disconnected, and reconnect:

>wifi twt teardown_all
TWT operation TWT teardown all flows
Disconnected
[00:18:21.978,485] <inf> wpa_supp: wlan0: CTRL-EVENT-DISCONNECTED bssid=**:**:**:**:**:** reason=2 locally_generated=1
[00:18:22.004,547] <inf> wpa_supp: wlan0: CTRL-EVENT-DSCP-POLICY clear_all
Connected
[00:18:27.160,644] <inf> wpa_supp: wlan0: SME: Trying to authenticate with **:**:**:**:**:** (SSID='MyWifi6' freq=5220 MHz)
[00:18:27.171,997] <inf> wifi_nrf: wifi_nrf_wpa_supp_authenticate:Authentication request sent successfully

[00:18:27.739,959] <inf> wpa_supp: wlan0: SME: Trying to authenticate with **:**:**:**:**:** (SSID='MyWifi6' freq=5220 MHz)
[00:18:27.747,985] <inf> wifi_nrf: wifi_nrf_wpa_supp_authenticate:Authentication request sent successfully

[00:18:27.754,455] <inf> wpa_supp: wlan0: Trying to associate with **:**:**:**:**:** (SSID='MyWifi6' freq=5220 MHz)
[00:18:27.760,681] <inf> wifi_nrf: wifi_nrf_wpa_supp_associate: Association request sent successfully

[00:18:27.773,681] <inf> wpa_supp: wlan0: Associated with **:**:**:**:**:**
[00:18:27.773,773] <inf> wpa_supp: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
[00:18:27.799,011] <inf> wpa_supp: wlan0: WPA: Key negotiation completed with **:**:**:**:**:** [PTK=CCMP GTK=CCMP]
[00:18:27.799,133] <inf> wpa_supp: wlan0: CTRL-EVENT-CONNECTED - Connection to **:**:**:**:**:** completed [id=0 id_str=]
[00:18:27.835,144] <inf> net_dhcpv4: Received: 192.168.1.39

Do you have an idea of what is happening? I have nothing to capture wifi communications.

[Kenneth]

Hi,

In trigger disable and unannounced mode, DK will not send any QoSNull/PS-Polls to inform our awake state. So, AP will deauth since there is no exchange between AP and DK for 15mins (If MAX_BSS_IDLE_PERIOD is less than 15mins in AP). We can do same test with latest NCS main with trigger disable and announced mode(wifi twt setup 0 0 1 1 0 0 1 1 65000 524000), in this case DK will send PS-Polls for every twt interval.

Kenneth

[Seb-labs]

I tried with sdk-nrf commit a96c8d083a8489ce2b3878334afa56d2dc9cb20c (Tue Jul 18 11:33:56 2023 +0200).

I configured twt with:

wifi twt setup 0 0 1 1 0 0 1 1 65000 60030000

After several minutes, I enter:

wifi twt teardown_all

and the answer is:

TWT operation TWT teardown all flows success
Disconnected

[Kenneth]

Ok still getting deauth, can we get sniffer capture if possible? Also can we confirm is it trigger disabled and announced mode. Though above cmd meant to be trigger disabled some times AP may alter the twt params in response to the twt setup.

Kenneth

[Seb-labs]

Here is the wifi_shell output:

>wifi twt setup 0 0 1 1 0 0 1 1 65000 60030000
TWT operation TWT setup with dg: 1, flow_id: 1 requested
TWT response: TWT accept
== TWT negotiated parameters ==
TWT Dialog token: 1
TWT flow ID: 1
TWT negotiation type: TWT individual negotiation
TWT responder: true
TWT implicit: true
TWT announce: true
TWT trigger: false
TWT wake interval: 65024 us
TWT interval: 60030000 us
========================

Here is the capture:

wifi6-twt-disconnected.pcapng

[Kenneth]

Thank you.

Can you try to lower sleep periods. There could be some interop issue. Please try 10 seconds sleep and see if there is any improvement.

Kenneth