Giter Club home page Giter Club logo

Comments (8)

olewales avatar olewales commented on July 17, 2024

Sorry, I have just noticed #180 which looks awfully similar
Can you confirm that its the same issue?

from ath10k-ct.

greearb avatar greearb commented on July 17, 2024

Yes, it is same as Stintel's report. Corrupted descriptor, and I have no idea how to fix it. I guess it is possible it is some kernel related issue, like kernel use-after-free or something. And quite strange that usteer would have anything to do with this...maybe strace on usteer to see if it does anything interesting in same period as the crashes?

Here is decode:
[greearb@ben-dt4 qca]$ ./decode_ath10k --no-htonl < /tmp/bug.txt
[ 1457.296045] ath10k_pci 0000:00:00.0: firmware crashed! (guid 01902bd0-b5bb-4bb7-8872-bf791e0b3098)
[ 1457.305198] ath10k_pci 0000:00:00.0: qca988x hw2.0 target 0x4100016c chip_id 0x043202ff sub 0000:0000
[ 1457.305211] ath10k_pci 0000:00:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 0 testmode 0
[ 1457.308833] ath10k_pci 0000:00:00.0: firmware ver 10.1-ct-8x-__fH-022-ecad3248 api 2 features wmi-10.x,mfp,txstatus-noack,wmi-10.x-CT,ratemask-CT,regdump-CT,txrate-CT,flush-all-CT,pingpong-CT,ch-regs-CT,nop-CT,set-special-CT,get-temp-CT,tx-rc-CT,cust-stats-CT,retry-gt2-CT,txrate2-CT,beacon-cb-CT,wmi-block-ack-CT crc32 1b2a161c
[ 1457.308883] ath10k_pci 0000:00:00.0: board_file api 1 bmi_id N/A crc32 bebc7c08
[ 1457.308896] ath10k_pci 0000:00:00.0: htt-ver 2.2 wmi-op 2 htt-op 2 cal file max-sta 128 raw 0 hwcrypto 1
[ 1457.309047] ath10k_pci 0000:00:00.0: firmware register dump:
regs dump, len: 60
Firmware ASSERT Failure
Target: 0x4100016c Assert-Line: ROM/NA PC: 0x009948fa Bad-Virt-Addr: 0x00955b31
XT-PC: 0x009948fa XT-PS: 0x00060330 XT-SAR: 0x00000005 XT-VPRI: 0x00000051
XT-AT2: 0x00000000 XT-AT3: 0x009bab5c XT-AT4: 0x00426474 XT-AT5: 0x00000800
XT-EXCCAUSE: 0x00000009 XT-LCOUNT: 0x00000000 XT-LBEG: 0x0099485c XT-LEND: 0x00994869
EPC1: 0x00958080 EPC2: 0x0094085d XT-EPC3: 0x00000000 XT-EPC4: 0x00000000
Stack:
[0]: PC 0x409948fa SP: 0x0040ac34 (STD) A2: 0x00000000 A3: 0x0047c180
[1]: PC 0x809950af SP: 0x0040ac94 (STD) A2: 0x00000011 A3: 0xc09948fa
[2]: PC 0x809960a0 SP: 0x0040ad14 (STD) A2: 0x0041e524 A3: 0x00426474
[3]: PC 0x80997ec9 SP: 0x0040adb4 (STD) A2: 0x0041e524 A3: 0x00426474
[4]: PC 0x809af249 SP: 0x0040aee4 (STD) A2: 0x00425918 A3: 0x00000002
[5]: PC 0x80940f18 SP: 0x0040af14 (STD) A2: 0x00000004 A3: 0x004039d0
[6]: PC 0x80940eea SP: 0x0040af44 (STD) A2: 0x00400000 A3: 0x00000000
[7]: PC 0x80940f31 SP: 0x0040af64 (STD) A2: 0x00401c10 A3: 0x00400600
[8]: PC 0x40940024 SP: 0x0040af84 (STD) A2: 0x004068e8 A3: 0x004068e8
0x009948fa RAM: _tx_send_handle_completion /home/greearb/git/qca/perf_pwr_offload/drivers/target/src/wlan/wal/AR/tx/wifi_ip01/ar_wal_tx_send.c:3076
0x409948fa RAM: _tx_send_handle_completion /home/greearb/git/qca/perf_pwr_offload/drivers/target/src/wlan/wal/AR/tx/wifi_ip01/ar_wal_tx_send.c:3076
0x809950af RAM: _tx_send_proc_ppdu_done /home/greearb/git/qca/perf_pwr_offload/drivers/target/src/wlan/wal/AR/tx/wifi_ip01/ar_wal_tx_send.c:4089
0x809960a0 RAM: _tx_send_completion_hdlr /home/greearb/git/qca/perf_pwr_offload/drivers/target/src/wlan/wal/AR/tx/wifi_ip01/ar_wal_tx_send.c:5505
0x80997ec9 RAM: _wal_intr_scheduler_intr_handler /home/greearb/git/qca/perf_pwr_offload/drivers/target/src/wlan/wal/AR/coex/wal_coex.c:1475
0x809af249 RAM: patch_cmnos_intr_handle_pending_dsrs /home/greearb/git/qca/perf_pwr_offload/drivers/target/src/wlan/wal/AR/coex/wal_coex.c:1475
0x80940f18 ROM: check_idle /home/scobb/work/scobb-vbox-export2/perf_pwr_offload/drivers/target/src/os/athos/athos_main.c:1597
0x80940eea ROM: athos_main /home/scobb/work/scobb-vbox-export2/perf_pwr_offload/drivers/target/src/os/athos/athos_main.c:1578
0x80940f31 ROM: main /home/scobb/work/scobb-vbox-export2/perf_pwr_offload/drivers/target/src/os/athos/athos_main.c:1631
0x40940024 ROM: _stext /home/scobb/work/scobb-vbox-export2/perf_pwr_offload/drivers/target/src/os/athos/xtos/crt1-tiny.S:90

EPC1 0x00958080 ROM: memcpy /home/customer/tree/RD-2011.2/p4root/Xtensa/Target-libs/newlib/newlib/libc/machine/xtensa/memcpy.S:135
EPC2 0x0094085d ROM: _athos_wait_for_activity /home/scobb/work/scobb-vbox-export2/perf_pwr_offload/drivers/target/src/os/athos/athos_main.c:391

Process State Register (PS):
INT-LEVEL: 0 EXCM: 1 UM: 1 RING: 0 OWB: 3 CALLINC: 2 WOE: 1
Exception cause Register (EXCCAUSE): LoadStoreAlignment

[ 1457.436154] ath10k_pci 0000:00:00.0: Copy Engine register dump:
[ 1457.442276] ath10k_pci 0000:00:00.0: [00]: 0x00057400 7 7 3 3
[ 1457.448831] ath10k_pci 0000:00:00.0: [01]: 0x00057800 20 20 278 279
[ 1457.455391] ath10k_pci 0000:00:00.0: [02]: 0x00057c00 46 46 109 110
[ 1457.461930] ath10k_pci 0000:00:00.0: [03]: 0x00058000 8 8 12 8
[ 1457.468481] ath10k_pci 0000:00:00.0: [04]: 0x00058400 1283 1283 171 131
[ 1457.475202] ath10k_pci 0000:00:00.0: [05]: 0x00058800 2 2 481 482
[ 1457.481738] ath10k_pci 0000:00:00.0: [06]: 0x00058c00 6 6 6 6
[ 1457.488289] ath10k_pci 0000:00:00.0: [07]: 0x00059000 0 0 0 0
[ 1457.495107] ath10k_pci 0000:00:00.0: debug log header, dbuf: 0x411a98 dropped: 0
[ 1457.502799] ath10k_pci 0000:00:00.0: [0] next: 0x411ab0 buf: 0x40f8fc sz: 1500 len: 108 count: 4 free: 0
[ 1457.512498] ath10k_pci 0000:00:00.0: ath10k_pci ATH10K_DBG_BUFFER:
Decoding dbglog buffer, len: 108
ath10k-fw: ts: 1512091 args: 5 WAL(19) vid: 255 INVALID_STATE(81) 0x91108443 0x00490000 0x00429c44 0x01b90000 0x00000000
ath10k-fw: ts: 1512091 args: 5 WAL(19) vid: 255 INVALID_STATE(81) 0x91108441 0x00000800 0x00000800 0x00490000 0x0047c180
ath10k-fw: ts: 1512091 args: 4 WAL(19) vid: 255 INVALID_STATE(81) 0x91108442 0x00000000 0x00000000 0x00000000
ath10k-fw: ts: 1512091 args: 5 INF(00) vid: 255 ASSERT-FAILED(01) 0x000015b3 0x000015b3 0x0040ab24 0x4100016c 0x00000000
[ 1457.556543] ath10k_pci 0000:00:00.0: [1] next: 0x411a98 buf: 0x40feec sz: 1500 len: 0 count: 0 free: 0
[ 1457.572562] ath10k_pci 0000:00:00.0: removing peer, cleanup-all, deleting: peer ffeabf71 vdev: 0 addr: f8:59:71:52:46:3f
[ 1457.583734] ath10k_pci 0000:00:00.0: removing peer, cleanup-all, deleting: peer 22e49f6e vdev: 0 addr: ac:86:74:51:a5:70
[ 1457.725985] ieee80211 phy0: Hardware restart was requested

from ath10k-ct.

olewales avatar olewales commented on July 17, 2024

Ok, more info, as requested:
I wasn't able to crash the driver for a few hours without usteer and it crashed immediately when I started it so if you want to pursue this bug I accidentally created good environment for it. Below is a strace of usteer and my attempt to correlate dmesg timestamps with system time:

dmesg of a crash:

[ 1468.565602] ath10k_pci 0000:00:00.0: firmware crashed! (guid 464e95ca-e126-4c79-9499-2c786e0b0567)
[ 1468.575415] ath10k_pci 0000:00:00.0: qca988x hw2.0 target 0x4100016c chip_id 0x043202ff sub 0000:0000
[ 1468.584813] ath10k_pci 0000:00:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 0 testmode 0
[ 1468.596871] ath10k_pci 0000:00:00.0: firmware ver 10.1-ct-8x-__fH-022-ecad3248 api 2 features wmi-10.x,mfp,txstatus-noack,wmi-10.x-CT,ratemask-CT,regdump-CT,txrate-CT,flush-all-CT,pingpong-CT,ch-regs-CT,nop-CT,set-special-CT,get-temp-CT,tx-rc-CT,cust-stats-CT,retry-gt2-CT,txrate2-CT,beacon-cb-CT,wmi-block-ack-CT crc32 1b2a161c
[ 1468.626399] ath10k_pci 0000:00:00.0: board_file api 1 bmi_id N/A crc32 bebc7c08
[ 1468.633904] ath10k_pci 0000:00:00.0: htt-ver 2.2 wmi-op 2 htt-op 2 cal file max-sta 128 raw 0 hwcrypto 1
[ 1468.643756] ath10k_pci 0000:00:00.0: firmware register dump:
[ 1468.649506] ath10k_pci 0000:00:00.0: [00]: 0x4100016C 0x000015B3 0x009948FA 0x00955B31
[ 1468.657565] ath10k_pci 0000:00:00.0: [04]: 0x009948FA 0x00060330 0x00000005 0x00000051
[ 1468.665666] ath10k_pci 0000:00:00.0: [08]: 0x00000000 0x009BAACC 0x004268C4 0x00000800
[ 1468.673806] ath10k_pci 0000:00:00.0: [12]: 0x00000009 0x00000000 0x0099485C 0x00994869
[ 1468.681870] ath10k_pci 0000:00:00.0: [16]: 0x00958080 0x0094085D 0x00000000 0x00000000
[ 1468.689912] ath10k_pci 0000:00:00.0: [20]: 0x409948FA 0x0040AC34 0x00000000 0x0047C180
[ 1468.698018] ath10k_pci 0000:00:00.0: [24]: 0x809950AF 0x0040AC94 0x00000011 0xC09948FA
[ 1468.706071] ath10k_pci 0000:00:00.0: [28]: 0x809960A0 0x0040AD14 0x0041E524 0x004268C4
[ 1468.714123] ath10k_pci 0000:00:00.0: [32]: 0x80997EC9 0x0040ADB4 0x0041E524 0x004268C4
[ 1468.722231] ath10k_pci 0000:00:00.0: [36]: 0x809AF249 0x0040AEE4 0x00425918 0x00000002
[ 1468.730426] ath10k_pci 0000:00:00.0: [40]: 0x80940F18 0x0040AF14 0x00000004 0x004039D0
[ 1468.738498] ath10k_pci 0000:00:00.0: [44]: 0x80940EEA 0x0040AF44 0x00400000 0x00000000
[ 1468.746616] ath10k_pci 0000:00:00.0: [48]: 0x80940F31 0x0040AF64 0x00401C10 0x00400600
[ 1468.754679] ath10k_pci 0000:00:00.0: [52]: 0x40940024 0x0040AF84 0x004068E8 0x004068E8
[ 1468.762719] ath10k_pci 0000:00:00.0: [56]: 0x00000000 0x0040AFA4 0x009BB001 0x00040020
[ 1468.770761] ath10k_pci 0000:00:00.0: Copy Engine register dump:
[ 1468.776851] ath10k_pci 0000:00:00.0: [00]: 0x00057400   7   7   3   3
[ 1468.783427] ath10k_pci 0000:00:00.0: [01]: 0x00057800  21  21 215 216
[ 1468.789966] ath10k_pci 0000:00:00.0: [02]: 0x00057c00  43  43  42  43
[ 1468.796517] ath10k_pci 0000:00:00.0: [03]: 0x00058000   5   5   9   5
[ 1468.803063] ath10k_pci 0000:00:00.0: [04]: 0x00058400 4005 4005 252 212
[ 1468.809774] ath10k_pci 0000:00:00.0: [05]: 0x00058800   3   3   2   3
[ 1468.816325] ath10k_pci 0000:00:00.0: [06]: 0x00058c00  10  10  10  10
[ 1468.822872] ath10k_pci 0000:00:00.0: [07]: 0x00059000   0   0   0   0
[ 1468.829681] ath10k_pci 0000:00:00.0: debug log header, dbuf: 0x411ab0  dropped: 0
[ 1468.837382] ath10k_pci 0000:00:00.0: [0] next: 0x411a98 buf: 0x40feec sz: 1500 len: 108 count: 4 free: 0
[ 1468.847108] ath10k_pci 0000:00:00.0: ath10k_pci ATH10K_DBG_BUFFER:
[ 1468.853404] ath10k: [0000]: 48401700 514CFC17 43841091 00004E00 2CA84200 00009E01 00000000 48401700
[ 1468.862590] ath10k: [0008]: 514CFC17 41841091 00080000 00080000 00004E00 80C14700 48401700 514CFC13
[ 1468.871812] ath10k: [0016]: 42841091 00000000 00000000 00000000 48401700 0100FC17 B3150000 B3150000
[ 1468.881085] ath10k: [0024]: 24AB4000 6C010041 00000000
[ 1468.886302] ath10k_pci 0000:00:00.0: ATH10K_END
[ 1468.890979] ath10k_pci 0000:00:00.0: [1] next: 0x411ab0 buf: 0x40f8fc sz: 1500 len: 0 count: 0 free: 0
[ 1470.011115] ath10k_pci 0000:00:00.0: removing peer, cleanup-all, deleting: peer 5e8771fc vdev: 0 addr: f8:4d:89:5d:ef:37 
[ 1470.022265] ath10k_pci 0000:00:00.0: removing peer, cleanup-all, deleting: peer 699cb110 vdev: 0 addr: ac:86:74:51:a5:70 
[ 1470.165329] ieee80211 phy0: Hardware restart was requested
[ 1470.171088] ath10k_pci 0000:00:00.0: failed to send pdev bss chan info request: -143
[ 1470.179131] ath10k_pci 0000:00:00.0: failed to send pdev bss chan info request: -143
[ 1471.147464] ath10k_pci 0000:00:00.0: 10.1 wmi init: vdevs: 16  peers: 127  tid: 256
[ 1471.164869] ath10k_pci 0000:00:00.0: wmi print 'P 128 V 8 T 410'
[ 1471.171234] ath10k_pci 0000:00:00.0: wmi print 'msdu-desc: 1424  sw-crypt: 0 ct-sta: 0'
[ 1471.179674] ath10k_pci 0000:00:00.0: wmi print 'alloc rem: 25000 iram: 38944'
[ 1471.251241] ath10k_pci 0000:00:00.0: pdev param 0 not supported by firmware
[ 1471.258646] ath10k_pci 0000:00:00.0: set-coverage-class, phyclk: 88  value: 0
[ 1471.266924] ath10k_pci 0000:00:00.0: rts threshold -1
[ 1471.281007] ath10k_pci 0000:00:00.0: Invalid state: 3 in ath10k_htt_tx_32, warning will not be repeated.
[ 1471.290682] ------------[ cut here ]------------
[ 1471.295445] WARNING: CPU: 0 PID: 8909 at target-mips_74kc_musl/linux-ath79_generic/ath10k-ct-regular/ath10k-ct-2022-05-13-f808496f/ath10k-5.15/htt_tx.c:1495 ieee80211_is_robust_mgmt_frame_tx+0xad0/0xbc4 [ath10k_core]
[ 1471.314925] Modules linked in: ath9k ath9k_common ath9k_hw ath10k_pci ath10k_core ath mac80211 lzo cfg80211 lzo_rle lzo_decompress lzo_compress compat sha256_generic libsha256 seqiv jitterentropy_rng drbg hmac cmac crypto_acompress
[ 1471.335802] CPU: 0 PID: 8909 Comm: kworker/0:2 Not tainted 5.10.120 #0
[ 1471.342567] Workqueue: events_freezable 0x81b00188
[ 1471.347428] Stack : 804f4b30 00000000 81aada30 00000009 40000012 800b5d6c 80570000 00000017
[ 1471.355937]         81d5f83c 8222f9c8 8222f9bc 80128d38 81aada30 00000001 8222f990 00000027
[ 1471.364438]         00000000 00000000 804f4b30 8222f818 ffffefff 00000000 00000000 ffffffea
[ 1471.372942]         00000120 8222f808 00000120 805742c8 00000000 00000009 00000000 81aada30
[ 1471.381439]         00000009 40000012 81c97638 819fb240 00000018 802e3bb8 00000000 80720000
[ 1471.389931]         ...
[ 1471.392422] Call Trace:
[ 1471.394922] [<80066e3c>] show_stack+0x30/0x100
[ 1471.399438] [<800853d0>] __warn+0xc4/0x130
[ 1471.403607] [<80085498>] warn_slowpath_fmt+0x5c/0xac
[ 1471.408703] [<81aada30>] ieee80211_is_robust_mgmt_frame_tx+0xad0/0xbc4 [ath10k_core]
[ 1471.416593] [<81a822d0>] 0x81a822d0
[ 1471.420134] 
[ 1471.421660] ---[ end trace 7400bc48d52425c2 ]---
[ 1471.426351] ath10k_pci 0000:00:00.0: failed to transmit packet, dropping: -19
[ 1471.433600] ath10k_pci 0000:00:00.0: failed to submit frame: -19
[ 1471.439691] ath10k_pci 0000:00:00.0: failed to transmit frame: -19
[ 1471.445977] ath10k_pci 0000:00:00.0: failed to transmit packet, dropping: -19
[ 1471.453220] ath10k_pci 0000:00:00.0: failed to submit frame: -19
[ 1471.459306] ath10k_pci 0000:00:00.0: failed to transmit frame: -19
[ 1471.465585] ath10k_pci 0000:00:00.0: failed to transmit packet, dropping: -19
[ 1471.472834] ath10k_pci 0000:00:00.0: failed to submit frame: -19
[ 1471.478921] ath10k_pci 0000:00:00.0: failed to transmit frame: -19
[ 1471.485755] ath10k_pci 0000:00:00.0: failed to transmit packet, dropping: -19
[ 1471.493046] ath10k_pci 0000:00:00.0: failed to submit frame: -19
[ 1471.499135] ath10k_pci 0000:00:00.0: failed to push frame: -19
[ 1471.505198] ath10k_pci 0000:00:00.0: failed to transmit packet, dropping: -19
[ 1471.512476] ath10k_pci 0000:00:00.0: failed to submit frame: -19
[ 1471.518565] ath10k_pci 0000:00:00.0: failed to push frame: -19
[ 1471.524867] ath10k_pci 0000:00:00.0: failed to transmit packet, dropping: -19
[ 1471.532152] ath10k_pci 0000:00:00.0: failed to submit frame: -19
[ 1471.538242] ath10k_pci 0000:00:00.0: failed to push frame: -19
[ 1471.544360] ath10k_pci 0000:00:00.0: device successfully recovered
[ 1472.820889] mark

strace of a mark (writing to /dev/kmsg)

root@OpenWrt:~# strace -tt echo "mark" > /dev/kmsg 
12:01:18.423460 execve("/bin/echo", ["echo", "mark"], 0x7fa8f018 /* 13 vars */) = 0
12:01:18.426163 set_thread_area(0x77e2ff40) = 0
12:01:18.427205 set_tid_address(0x77e277ec) = 8938
12:01:18.429595 brk(NULL)               = 0x2413000
12:01:18.430946 brk(0x2415000)          = 0x2415000
12:01:18.440251 mmap2(0x2413000, 4096, PROT_NONE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x2413000
12:01:18.441982 open("/etc/ld-musl-mips-sf.path", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = -1 ENOENT (No such file or directory)
12:01:18.443503 open("/lib/libgcc_s.so.1", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3
12:01:18.445385 fcntl64(3, F_SETFD, FD_CLOEXEC) = 0
12:01:18.446516 statx(3, "", AT_STATX_SYNC_AS_STAT|AT_EMPTY_PATH, STATX_BASIC_STATS, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=0, stx_mode=S_IFREG|0644, stx_size=54512, ...}) = 0
12:01:18.449799 read(3, "\177ELF\1\2\1\0\0\0\0\0\0\0\0\0\0\3\0\10\0\0\0\1\0\0\0\0\0\0\0004"..., 936) = 936
12:01:18.451632 mmap2(NULL, 122880, PROT_READ|PROT_EXEC, MAP_PRIVATE, 3, 0) = 0x77d50000
12:01:18.453674 mmap2(0x77d6d000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 3, 0xd000) = 0x77d6d000
12:01:18.455512 close(3)                = 0
12:01:18.457611 prctl(PR_GET_NAME, "echo") = 0
12:01:18.458963 write(1, "mark\n", 5)   = 5
12:01:18.462406 exit_group(0)           = ?
12:01:18.463774 +++ exited with 0 +++

relevant (i think) part of usteer strace

12:01:13.959201 sendmsg(7, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=[{nlmsg_len=28, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK|0x300, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x32\x00\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08"], iov_len=28}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 28
12:01:13.972405 recvmsg(7, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=[[{nlmsg_len=112, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08\x00\x54\x00\x54\x00\x08\x00\x01\x00\x00\x09\x6c\x00\x05\x00\x02\xa1\x00\x00\x00"...], [{nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08\x00\x0c\x00\x54\x00\x08\x00\x01\x00\x00\x09\x71"], [{nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08\x00\x0c\x00\x54\x00\x08\x00\x01\x00\x00\x09\x76"], [{nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08\x00\x0c\x00\x54\x00\x08\x00\x01\x00\x00\x09\x7b"], [{nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08\x00\x0c\x00\x54\x00\x08\x00\x01\x00\x00\x09\x80"], [{nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08\x00\x0c\x00\x54\x00\x08\x00\x01\x00\x00\x09\x85"], [{nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08\x00\x0c\x00\x54\x00\x08\x00\x01\x00\x00\x09\x8a"], [{nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08\x00\x0c\x00\x54\x00\x08\x00\x01\x00\x00\x09\x8f"], [{nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08\x00\x0c\x00\x54\x00\x08\x00\x01\x00\x00\x09\x94"], [{nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08\x00\x0c\x00\x54\x00\x08\x00\x01\x00\x00\x09\x99"], [{nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08\x00\x0c\x00\x54\x00\x08\x00\x01\x00\x00\x09\x9e"], [{nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08\x00\x0c\x00\x54\x00\x08\x00\x01\x00\x00\x09\xa3"], [{nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08\x00\x0c\x00\x54\x00\x08\x00\x01\x00\x00\x09\xa8"], [{nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x08\x00\x0c\x00\x54\x00\x08\x00\x01\x00\x00\x09\xb4"]], iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 632
12:01:13.986470 recvmsg(7, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=[{nlmsg_len=20, nlmsg_type=NLMSG_DONE, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863750, nlmsg_pid=2553}, 0], iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 20
12:01:14.002163 epoll_pwait(3, [], 10, 5, NULL, 16) = 0
12:01:14.008004 socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 9
12:01:14.009939 ioctl(9, SIOCGIFINDEX, {ifr_name="wlan-dc5", ifr_ifindex=9}) = 0
12:01:14.011502 close(9)                = 0
12:01:14.012900 sendmsg(7, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=[{nlmsg_len=28, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK|0x300, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x32\x00\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09"], iov_len=28}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 28
12:01:14.025712 recvmsg(7, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=[[{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x14\x3c\x00\x05\x00\x02\x97\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x14\x50\x00\x05\x00\x02\x98\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x14\x64\x00\x05\x00\x02\x98\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x14\x78\x00\x05\x00\x02\x98\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x14\x8c\x00\x05\x00\x02\x98\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x14\xa0\x00\x05\x00\x02\x99\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x14\xb4\x00\x05\x00\x02\x99\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x14\xc8\x00\x05\x00\x02\x99\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x15\x7c\x00\x05\x00\x02\x9a\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x15\x90\x00\x05\x00\x02\x9a\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x15\xa4\x00\x05\x00\x02\x9a\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x15\xb8\x00\x05\x00\x02\x9a\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x15\xcc\x00\x05\x00\x02\x9a\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x15\xe0\x00\x05\x00\x02\x99\x00\x00\x00"...], [{nlmsg_len=112, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x54\x00\x54\x00\x08\x00\x01\x00\x00\x15\xf4\x00\x05\x00\x02\x99\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x16\x08\x00\x05\x00\x02\x9a\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x16\x1c\x00\x05\x00\x02\x98\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x16\x30\x00\x05\x00\x02\x9a\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x16\x44\x00\x05\x00\x02\x99\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x16\x58\x00\x05\x00\x02\x97\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x16\x71\x00\x05\x00\x02\x96\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x16\x85\x00\x05\x00\x02\x97\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x16\x99\x00\x05\x00\x02\x94\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x16\xad\x00\x05\x00\x02\x96\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x16\xc1\x00\x05\x00\x02\x93\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x16\xd5\x00\x05\x00\x02\x94\x00\x00\x00"...], [{nlmsg_len=80, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, "\x33\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x34\x00\x54\x00\x08\x00\x01\x00\x00\x16\xe9\x00\x05\x00\x02\x93\x00\x00\x00"...]], iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 2192
12:01:14.054831 recvmsg(7, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=[{nlmsg_len=20, nlmsg_type=NLMSG_DONE, nlmsg_flags=NLM_F_MULTI, nlmsg_seq=1654863751, nlmsg_pid=2553}, 0], iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 20
12:01:14.067276 epoll_pwait(3, [{events=EPOLLIN, data={u32=2010672012, u64=8635770534522519552}}], 10, 8, NULL, 16) = 1
12:01:14.068419 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\5\n\"\245-h\240\0\0\2\354", iov_len=12}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 12
12:01:14.071456 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\3\0\0\10u\242\tG\4\0\0\nprobe\0\0\0\f\0\0\troot\0\0\0\0"..., iov_len=744}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 744
12:01:14.073997 sendmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\1\n\"\245-h\240", iov_len=8}, {iov_base="\0\0\0\24\1\0\0\10\0\0\0\0\3\0\0\10u\242\tG", iov_len=20}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, 0) = 28
12:01:14.078825 sendmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\5&\312<\323\260-", iov_len=8}, {iov_base="\0\0\0|\3\0\0\10<\323\260-\4\0\0\31link_measurement"..., iov_len=124}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, 0) = 132
12:01:14.082444 poll([{fd=6, events=POLLIN|POLLERR}], 1, 100) = 1 ([{fd=6, revents=POLLIN}])
12:01:14.084232 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\1&\312<\323\260-\0\0\0\24", iov_len=12}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 12
12:01:14.086758 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\1\0\0\10\0\0\0\0\3\0\0\10<\323\260-", iov_len=16}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 16
12:01:14.089565 sendmsg(8, {msg_name={sa_family=AF_INET, sin_port=htons(16720), sin_addr=inet_addr("255.255.255.255")}, msg_namelen=16, msg_iov=[{iov_base="\0\0\25p\0\0\0\10\252\303\211\7\1\0\0\10\0\0\10\326\2\0\25\\\0\0\r\240\0\0\0\26"..., iov_len=5488}], msg_iovlen=1, msg_control=[{cmsg_len=24, cmsg_level=SOL_IP, cmsg_type=IP_PKTINFO, cmsg_data={ipi_ifindex=if_nametoindex("eth0"), ipi_spec_dst=inet_addr("0.0.0.0"), ipi_addr=inet_addr("0.0.0.0")}}], msg_controllen=24, msg_flags=0}, 0) = 5488
12:01:14.093962 epoll_pwait(3, [{events=EPOLLIN, data={u32=4450296, u64=19113875777519616}}], 10, 0, NULL, 16) = 1
12:01:14.096001 recvmsg(8, {msg_name={sa_family=AF_INET, sin_port=htons(16720), sin_addr=inet_addr("192.168.1.1")}, msg_namelen=16, msg_iov=[{iov_base="\0\0\25p\0\0\0\10\252\303\211\7\1\0\0\10\0\0\10\326\2\0\25\\\0\0\r\240\0\0\0\26"..., iov_len=65536}], msg_iovlen=1, msg_control=[{cmsg_len=24, cmsg_level=SOL_IP, cmsg_type=IP_PKTINFO, cmsg_data={ipi_ifindex=if_nametoindex("eth0"), ipi_spec_dst=inet_addr("192.168.1.1"), ipi_addr=inet_addr("255.255.255.255")}}], msg_controllen=24, msg_flags=0}, 0) = 5488
12:01:14.100991 recvmsg(8, {msg_namelen=16}, 0) = -1 EAGAIN (Resource temporarily unavailable)
12:01:14.103295 sendmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\5&\313nCv4", iov_len=8}, {iov_base="\0\0\0 \3\0\0\10nCv4\4\0\0\20get_clients\0\7\0\0\4", iov_len=32}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, 0) = 40
12:01:14.106594 sendmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\5&\314<\323\260-", iov_len=8}, {iov_base="\0\0\0 \3\0\0\10<\323\260-\4\0\0\20get_clients\0\7\0\0\4", iov_len=32}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, 0) = 40
12:01:14.111531 epoll_pwait(3, [{events=EPOLLIN, data={u32=2010672012, u64=8635770534522519552}}], 10, 843, NULL, 16) = 1
12:01:14.113327 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\2&\313nCv4\0\0\0000", iov_len=12}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 12
12:01:14.115704 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\3\0\0\10nCv4\7\0\0$\205\0\0\20\0\4freq\0\0\0\0\tl\202\0\0\20"..., iov_len=44}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 44
12:01:14.118184 epoll_pwait(3, [{events=EPOLLIN, data={u32=2010672012, u64=8635770534522519552}}], 10, 836, NULL, 16) = 1
12:01:14.120136 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\1&\313nCv4\0\0\0\24", iov_len=12}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 12
12:01:14.122776 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\1\0\0\10\0\0\0\0\3\0\0\10nCv4", iov_len=16}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 16
12:01:14.125479 sendmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\5&\315nCv4", iov_len=8}, {iov_base="\0\0\0 \3\0\0\10nCv4\4\0\0\17get_status\0\0\7\0\0\4", iov_len=32}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, 0) = 40
12:01:14.129077 epoll_pwait(3, [{events=EPOLLIN, data={u32=2010672012, u64=8635770534522519552}}], 10, 825, NULL, 16) = 1
12:01:14.131161 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\2&\314<\323\260-\0\0\4,", iov_len=12}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 12
12:01:14.133512 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\3\0\0\10<\323\260-\7\0\4 \205\0\0\20\0\4freq\0\0\0\0\25\364\202\0\4\f"..., iov_len=1064}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 1064
12:01:14.136209 sendmsg(7, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=[{nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1654863752, nlmsg_pid=2553}, "\x11\x00\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x0a\x00\x06\xf8\x4d\x89\x5d\xef\x37\x00\x00"], iov_len=40}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 40
12:01:14.148652 recvmsg(7, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=[{nlmsg_len=2760, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=0, nlmsg_seq=1654863752, nlmsg_pid=2553}, "\x13\x01\x00\x00\x00\x08\x00\x03\x00\x00\x00\x09\x00\x0a\x00\x06\xf8\x4d\x89\x5d\xef\x37\x00\x00\x00\x08\x00\x2e\x00\x00\x00\x01"...], iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 2760
12:01:14.160678 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x77cdc000
12:01:14.161867 recvmsg(7, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=[{nlmsg_len=36, nlmsg_type=NLMSG_ERROR, nlmsg_flags=NLM_F_CAPPED, nlmsg_seq=1654863752, nlmsg_pid=2553}, {error=0, msg={nlmsg_len=40, nlmsg_type=0x16 /* NLMSG_??? */, nlmsg_flags=NLM_F_REQUEST|NLM_F_ACK, nlmsg_seq=1654863752, nlmsg_pid=2553}}], iov_len=16384}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 36
12:01:14.174804 munmap(0x77e31000, 20480) = 0
12:01:14.175917 munmap(0x77cdc000, 4096) = 0
12:01:14.177751 epoll_pwait(3, [{events=EPOLLIN, data={u32=2010672012, u64=8635770534522519552}}], 10, 777, NULL, 16) = 1
12:01:14.179463 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\1&\314<\323\260-\0\0\0\24", iov_len=12}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 12
12:01:14.181714 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\1\0\0\10\0\0\0\0\3\0\0\10<\323\260-", iov_len=16}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 16
12:01:14.184158 sendmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\5&\316<\323\260-", iov_len=8}, {iov_base="\0\0\0 \3\0\0\10<\323\260-\4\0\0\17get_status\0\0\7\0\0\4", iov_len=32}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, 0) = 40
12:01:14.187205 epoll_pwait(3, [{events=EPOLLIN, data={u32=2010672012, u64=8635770534522519552}}], 10, 767, NULL, 16) = 1
12:01:14.188919 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\2&\315nCv4\0\0\2L", iov_len=12}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 12
12:01:14.191116 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\3\0\0\10nCv4\7\0\2@\203\0\0\30\0\6status\0\0\0\0ENAB"..., iov_len=584}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 584
12:01:14.193399 epoll_pwait(3, [{events=EPOLLIN, data={u32=2010672012, u64=8635770534522519552}}], 10, 761, NULL, 16) = 1
12:01:14.195360 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\1&\315nCv4\0\0\0\24", iov_len=12}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 12
12:01:14.197591 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\1\0\0\10\0\0\0\0\3\0\0\10nCv4", iov_len=16}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 16
12:01:14.199915 sendmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\5&\317nCv4", iov_len=8}, {iov_base="\0\0\0,\3\0\0\10nCv4\4\0\0\17rrm_nr_set\0\0\7\0\0\20"..., iov_len=44}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, 0) = 52
12:01:14.203010 epoll_pwait(3, [{events=EPOLLIN, data={u32=2010672012, u64=8635770534522519552}}], 10, 751, NULL, 16) = 1
12:01:14.547280 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\0\2&\316<\323\260-\0\0\2L", iov_len=12}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 12
12:01:14.549211 recvmsg(6, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="\3\0\0\10<\323\260-\7\0\2@\203\0\0\30\0\6status\0\0\0\0ENAB"..., iov_len=584}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 584

(I attach longer portion as a file)
usteer-strace.txt.gz

from ath10k-ct.

olewales avatar olewales commented on July 17, 2024

Finally I had some time to do more experiments and I believe the problem is related to management frames.
Running AP in psk (wpa) or none (open) encryption mode - stable
Running AP in psk2 (wpa2) mode with no additional options - stable
Running AP in psk2 (wpa2) mode with management frame protection enforced (option ieee80211w '2') - firmware crashes
Running AP in sae (wpa3) mode (which has management frame protection built in) - firmware crashes

Still, if usteer is not running then every mode is fine so I guess it might be related to "steering" done to client via netlink?

I have yet to try different firmware version to see if behavior changes.
I hope it does not bother you that I reply to myself under this issue but its easier for me to document what I found as I go.

from ath10k-ct.

olewales avatar olewales commented on July 17, 2024

I spent my evening testing different firmwares. To keep it brief, here is a list of ones I tested and they still crashed: (version as reported, source URL, sha256 sum of firmware file)

the oldest firmware from lede series did "work" (it did not crash that is) but I suspect the reason it did is because being so old it wasn't able to do what driver wanted from it. In syslog I got messages similiar to this:
"ath10k_pci 0000:00:00.0: failed to find peer id 1 for security indication"
for completness the firmware was:

HOWEVER what did work for me (I don't know I can declare it 100% stable but it did not crash on me so far with usteer running and management frame protection enabled) was using NRCC firmware with options suggested in the manual (vdevs = 4, peers = 80)

To me this is obviously testing a black box but maybe this data will help connect the dots and get to the bottom of this.

from ath10k-ct.

greearb avatar greearb commented on July 17, 2024

This is good detective work. The nrcc thing would compile out the firmware logic to swap rate-ctrl memory to the host. It decreases the number of stations that can connect, but may be reasonable work-around. I am not sure I feel like spending the time to try to fix the root problem if it is down in the memory swapping logic. Does usteer + pmf/mfp work on stock ath10k firmware on this platform?

from ath10k-ct.

olewales avatar olewales commented on July 17, 2024

Ok, I tested some more firmware files ale I think that nrcc thing might have been a red herring and it is more random memory-related issue. If I were to guess I'd say that various versions of the firmware have slightly different memory layout which makes them more or less susceptible to crashing and while my environment (usteer + mfp + custom build) is a good catalyst for this problem to arise (crash within a minute or two) I fully expect eventually seeing "good" firmware experience a crash.

Some observations:

As I mentioned previously firmware

worked fine for me so I decided to try version without 988x suffix (not sure why I didnt previously)

and this one was unstable. Not sure what the difference is, does not seem to be documented anywhere.

The firmware:

was stable when run with vdevs = 4 peers = 80 config left over from nrcc firmware, started crashing after I deleted configuration. (note: this did not help on openwrt default firmware)

from (i presume) "latest stable" series those firmwares were ok:

and this one wasn't:

And yes, the latest official firmware does work OK (tested with ath10k-ct driver):

  • 10.2.4-1.0-00047 firmware-5.bin 15867031c87f1d7408c1b25fb6419077a1b97de208f2aa58c3266b60e1f8daa2

There isn't much consistency to all of this and I doubt there is really any usefull information here. Sorry for wasting your time. I am still hoping for a fix in the future but in the meantime I will probably pick a firmware that passed my initial test and see how it behaves "in production"

from ath10k-ct.

timocapa avatar timocapa commented on July 17, 2024

Can reproduce crashes on qca988x with DAWN (instead of usteer) as well, on Linux 5.15.98

[ 2918.034658] ath10k_pci 0000:00:00.0: firmware crashed! (guid 496ae3e6-0258-48fd-8b43-0647b249e3ea)
[ 2918.043846] ath10k_pci 0000:00:00.0: qca988x hw2.0 target 0x4100016c chip_id 0x043202ff sub 0000:0000
[ 2918.053283] ath10k_pci 0000:00:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 0
[ 2918.065238] ath10k_pci 0000:00:00.0: firmware ver 10.1-ct-8x-__fH-022-ecad3248 api 2 features wmi-10.x,mfp,txstatus-noack,wmi-10.x-CT,ratemask-CT,regdump-CT,txrate-CT,flush-all-CT,pingpong-CT,ch-regs-CT,nop-CT,set-special-CT,get-temp-CT,tx-rc-CT,cust-stats-CT,retry-gt2-CT,txrate2-CT,beacon-cb-CT,wmi-block-ack-CT crc32 1b2a161c
[ 2918.094698] ath10k_pci 0000:00:00.0: board_file api 1 bmi_id N/A crc32 bebc7c08
[ 2918.102130] ath10k_pci 0000:00:00.0: htt-ver 2.2 wmi-op 2 htt-op 2 cal file max-sta 128 raw 0 hwcrypto 1
[ 2918.111882] ath10k_pci 0000:00:00.0: firmware register dump:
[ 2918.117647] ath10k_pci 0000:00:00.0: [00]: 0x4100016C 0x00000000 0x0099483F 0x00000000
[ 2918.125724] ath10k_pci 0000:00:00.0: [04]: 0x00000000 0x00060324 0x00000000 0x00000000
[ 2918.133778] ath10k_pci 0000:00:00.0: [08]: 0x00000000 0x00000000 0x00000000 0x00000000
[ 2918.141827] ath10k_pci 0000:00:00.0: [12]: 0x00000005 0x00000000 0x00000000 0x00000000
[ 2918.149912] ath10k_pci 0000:00:00.0: [16]: 0x009B0BD3 0x0094085D 0x00000000 0x0099483F
[ 2918.157994] ath10k_pci 0000:00:00.0: [20]: 0x809430B8 0x00401A40 0x00000001 0x00000002
[ 2918.166058] ath10k_pci 0000:00:00.0: [24]: 0x80940975 0x00401A60 0x0000001F 0x00403BEC
[ 2918.174122] ath10k_pci 0000:00:00.0: [28]: 0x409406B9 0x00401A80 0x0000001F 0x00400000
[ 2918.182166] ath10k_pci 0000:00:00.0: [32]: 0x00000000 0x00401AA0 0x00050024 0x004D0000
[ 2918.190230] ath10k_pci 0000:00:00.0: [36]: 0x00000000 0x00000000 0x00000000 0x00000000
[ 2918.198285] ath10k_pci 0000:00:00.0: [40]: 0x00000000 0x00000000 0x00000000 0x00000000
[ 2918.206343] ath10k_pci 0000:00:00.0: [44]: 0x00000000 0x00000000 0x00000000 0x00000000
[ 2918.214404] ath10k_pci 0000:00:00.0: [48]: 0x00000000 0x00000000 0x00000000 0x00000000
[ 2918.222453] ath10k_pci 0000:00:00.0: [52]: 0x00000000 0x00000000 0x00000000 0x00000000
[ 2918.230721] ath10k_pci 0000:00:00.0: [56]: 0x00000000 0x00000000 0x00000000 0x00000000
[ 2918.238816] ath10k_pci 0000:00:00.0: Copy Engine register dump:
[ 2918.244838] ath10k_pci 0000:00:00.0: [00]: 0x00057400   7   7   3   3
[ 2918.251387] ath10k_pci 0000:00:00.0: [01]: 0x00057800  17  17 467 468
[ 2918.257944] ath10k_pci 0000:00:00.0: [02]: 0x00057c00  47  47  46  47
[ 2918.264499] ath10k_pci 0000:00:00.0: [03]: 0x00058000   4   4   8   4
[ 2918.271043] ath10k_pci 0000:00:00.0: [04]: 0x00058400 2991 2991 255 217
[ 2918.277785] ath10k_pci 0000:00:00.0: [05]: 0x00058800  21  21 148 149
[ 2918.284339] ath10k_pci 0000:00:00.0: [06]: 0x00058c00  23  23  23  23
[ 2918.290886] ath10k_pci 0000:00:00.0: [07]: 0x00059000   0   0   0   0
[ 2918.297811] ath10k_pci 0000:00:00.0: debug log header, dbuf: 0x411a98  dropped: 0
[ 2918.305551] ath10k_pci 0000:00:00.0: [0] next: 0x411ab0 buf: 0x40f8fc sz: 1500 len: 52 count: 2 free: 0
[ 2918.315186] ath10k_pci 0000:00:00.0: ath10k_pci ATH10K_DBG_BUFFER:
[ 2918.321485] ath10k: [0000]: 3BC42D00 0600FC13 00001091 00000000 00000000 50240000 3BC42D00 0100FC17
[ 2918.330919] ath10k: [0008]: 00000000 00000000 30194000 6C010041 00000000
[ 2918.337780] ath10k_pci 0000:00:00.0: ATH10K_END
[ 2918.342482] ath10k_pci 0000:00:00.0: [1] next: 0x411a98 buf: 0x40feec sz: 1500 len: 0 count: 0 free: 0
[ 2918.370585] ath10k_pci 0000:00:00.0: removing peer, cleanup-all, deleting: peer 69abfa31 vdev: 0 addr: 94:65:2d:7f:b1:34 
[ 2918.381781] ath10k_pci 0000:00:00.0: removing peer, cleanup-all, deleting: peer 884ee5b3 vdev: 0 addr: 20:a1:71:1d:80:83 
[ 2918.392930] ath10k_pci 0000:00:00.0: removing peer, cleanup-all, deleting: peer fd9060b0 vdev: 0 addr: 6c:99:9d:ae:20:3f 
[ 2918.404073] ath10k_pci 0000:00:00.0: removing peer, cleanup-all, deleting: peer 877fb748 vdev: 0 addr: e8:df:70:26:00:c9 
[ 2918.546684] ieee80211 phy2: Hardware restart was requested
[ 2919.518805] ath10k_pci 0000:00:00.0: 10.1 wmi init: vdevs: 16  peers: 127  tid: 256
[ 2919.536147] ath10k_pci 0000:00:00.0: wmi print 'P 128 V 8 T 410'
[ 2919.542459] ath10k_pci 0000:00:00.0: wmi print 'msdu-desc: 1424  sw-crypt: 0 ct-sta: 0'
[ 2919.550647] ath10k_pci 0000:00:00.0: wmi print 'alloc rem: 25000 iram: 38944'
[ 2919.620973] ath10k_pci 0000:00:00.0: pdev param 0 not supported by firmware
[ 2919.628316] ath10k_pci 0000:00:00.0: set-coverage-class, phyclk: 88  value: 0
[ 2919.637763] ath10k_pci 0000:00:00.0: rts threshold -1
[ 2919.654571] ath10k_pci 0000:00:00.0: device successfully recovered

from ath10k-ct.

Related Issues (20)

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.