olewales
commented
2 years ago Sorry, I have just noticed #180 which looks awfully similar Can you confirm that its the same issue?
Open olewales opened 2 years ago
olewales
commented
2 years ago Sorry, I have just noticed #180 which looks awfully similar Can you confirm that its the same issue?
greearb
commented
2 years ago 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
olewales
commented
2 years ago 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] markstrace 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
olewales
commented
2 years ago 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.
olewales
commented
2 years ago 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)
10.1-ct-8x-__fH-022-d8dab8e8 firmware-2-ct-full-htt-mgt-community.bin ca205e4b084668afe9e0dc9fb0d1010c4b30240ac12214baab22bf24656df31310.1-ct-8x-__tH-023-1d83261a firmware-2-ct-full-htt-mgt-community.bin 4b4ece4df9e95df362490626917f1f2400267b025f45310f2b5a496cbbbdcda210.1-ct-8x-__fH-022-ecad3248 firmware-2-ct-full-htt-mgt-community-22.bin.lede.022 990d9cbf79dd81f141257a289f89808bd7726406c9ed845a7e49e5167002ffde10.1-ct-8x-__fH-022-538f0906 firmware-2-ct-full-htt-mgt-community-22.bin.lede.018 a7168916d6aa5e4d7858f8b620c0c980c76d03f390929db6f4077685ce2051e710.1-ct-8x-__fH-022-64cc8007 firmware-2-ct-full-htt-mgt-community-22.bin.lede.012 a7042b2c90de82b21e87f243411b6fb12142bb4fb28266ea92cdf3101557b6de10.1-ct-8x-__fH-022-6d741b3d firmware-2-ct-full-htt-mgt-community-22.bin.lede.001 afe5ead5058727ed3fc8a0fdc738e705d53295369691e4d1376f85f8a98cefb110.1-ct-8x-__fH-021-4fa9f30 firmware-2-ct-full-htt-mgt-community-21.bin.lede.001 8666523a6271c4aa6409880d2efd52643258c21464d6bf5948507bcb72d3e35010.1-ct-8x-__fH-020-f13cbf0 firmware-2-ct-full-htt-mgt-community-20.bin.lede.006 08dd8d339079c9a704cf3f91787cc06a73168a9f57eeb777edaa9cd4194c246cthe 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:
10.1-ct-8x-__fH-020-0e04baf firmware-2-ct-full-htt-mgt-community-20.bin.lede.001 a1f90d9de19bb148f3e4c6570bf7572cf90c7c6870d0afcf8a87d67114eab701HOWEVER 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)
10.1-ct-8x-_AtW-023-1d83261a firmware-2-ct-htt-mgt-nrcc-community-ath10k-988x.bin 81a2c7e01d2d1664dc1e1654fc59c834fc8f137260a2281ed0e6c688a2bf9ee5To me this is obviously testing a black box but maybe this data will help connect the dots and get to the bottom of this.
greearb
commented
2 years ago 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?
olewales
commented
2 years ago 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
10.1-ct-8x-_AtW-023-1d83261a firmware-2-ct-htt-mgt-nrcc-community-ath10k-988x.bin 81a2c7e01d2d1664dc1e1654fc59c834fc8f137260a2281ed0e6c688a2bf9ee5worked fine for me so I decided to try version without 988x suffix (not sure why I didnt previously)
10.1-ct-8x-_AfH-023-1d83261a firmware-2-ct-full-htt-mgt-nrcc-community.bin 3bd626c814e29452a59f569cf9d460c74265e6bf5360ff824c191b35dd354854and this one was unstable. Not sure what the difference is, does not seem to be documented anywhere.
The firmware:
10.1-ct-8x-__xtH-023-1d83261a firmware-2-ct-non-commercial-htt-mgt-ath10k-988x.bin eae6e8a9e94a497505e50a78ee5fc6e1ea580ddff8510863ae1e2f81f019c6e8was 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:
10.1-ct-8x-_AtW-022-d8dab8e8 firmware-2-ct-htt-mgt-nrcc-community-ath10k-988x-22.bin eb70511eb072761bbc967a8508f3dccf750d580084ab50c807c82d7645ef7e7010.1-ct-8x-_AfH-022-d8dab8e8 - firmware-2-ct-full-htt-mgt-nrcc-community-22.bin - 265553bf6e54ccaf129c372083cdda37b67c6cb795a2e0e9ba6d4dc9a097ffdeand this one wasn't:
10.1-ct-8x-__xtH-022-d8dab8e8 firmware-2-ct-non-commercial-htt-mgt-ath10k-988x-22.bin 3125eda600fc9b649d5749c50fd9524107eed23b5a46bbcaebfb3ef94f8c7638And yes, the latest official firmware does work OK (tested with ath10k-ct driver):
10.2.4-1.0-00047 firmware-5.bin 15867031c87f1d7408c1b25fb6419077a1b97de208f2aa58c3266b60e1f8daa2There 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"
timocapa
commented
1 year ago 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
Hello, I've been experimenting with openwrt on QCA9558, specifically OpenMesh MR1750 AP to see if I can use it as reasonably fast, reliable, modern access point and I got into situation where I repeatably (every 30s or so) get firmware crashes if I am running openwrts usteer daemon. When I stop usteer service wifi stack seems to be rock stable. I have not (yet) investigated how this service interacts with wifi driver but this might be a clue anyway.
At the moment I am running custom openwrt build (minimal kernel, ALSR disabled and so on to check if I can gain any performance this way) so I can't be sure that this applies to more common setups but if firmware really crashes because of it then it might.
in regards of non-default options in wireless config i have:
crash frequency: (usteer running [stock config], single station connected)
single occurrence in dmesg:
binary dump: crash-ath10k-ct.bin.gz