This thread has been locked.

If you have a related question, please click the "Ask a related question" button in the top right corner. The newly created question will be automatically linked to this question.

WL1837MOD: Large Toffset in Mesh network, kernel OOPS when reading /sys/kernel/debug/ieee80211/phy0/netdev:wlan0_mesh/tsf

Part Number: WL1837MOD

Mesh network with several nodes. We are observing that Toffset in "iw dev wlan0_mesh station dump" output is getting really high: After 24 hours of uptime, the offset is 13 hours on some links. Peer links stops working for no apparent reason. Additionally, doing:

cat /sys/kernel/debug/ieee80211/phy0/netdev:wlan0_mesh/tsf

...will cause an immediate kernel OOPS. Any ideas?

  • Hello Peter,

    Can you describe which kernel and wpa_supplicant versions you are using?

    Do you have any additional details on  your issue? What starts it? What devices are you connecting with, etc.? Can you provide an example log of the issue?

  • The crash happens with many versions of the kernel:

    * 5.4.47 with your patches

    * 5.10.72 with your patches

    * 5.15.71 with your patches

    * 6.6.52 with patches backported from 6.10

    Used both your version of wpa_supplicant as well as upstream 2.10 and 2.11.

    Traceback:

    /sys/kernel/debug/ieee80211/phy0/netdev:wlan0# cat tsf
    [  182.282540] BUG: scheduling while atomic: cat/269/0x00000002
    [  182.288304] Modules linked in: cts wlcore_sdio wl18xx wlcore mac80211 cfg80211
    [  182.295785] CPU: 0 PID: 269 Comm: cat Tainted: G        W          6.6.52-g0cdede7dcaea #1
    [  182.304695] Hardware name: Freescale i.MX6 Ultralite (Device Tree)
    [  182.310902]  unwind_backtrace from show_stack+0x10/0x14
    [  182.316188]  show_stack from dump_stack_lvl+0x40/0x4c
    [  182.321293]  dump_stack_lvl from __schedule_bug+0x54/0x68
    [  182.326758]  __schedule_bug from __schedule+0x5ac/0x728
    [  182.332030]  __schedule from schedule+0x5c/0xb8
    [  182.336593]  schedule from schedule_hrtimeout_range_clock+0x10c/0x184
    [  182.343074]  schedule_hrtimeout_range_clock from schedule_hrtimeout_range+0x1c/0x24
    [  182.350780]  schedule_hrtimeout_range from usleep_range_state+0x5c/0x88
    [  182.357438]  usleep_range_state from sdhci_start_signal_voltage_switch+0xc4/0x2c0
    [  182.364971]  sdhci_start_signal_voltage_switch from sdhci_runtime_resume_host+0x7c/0x268
    [  182.373106]  sdhci_runtime_resume_host from sdhci_esdhc_runtime_resume+0x168/0x1a0
    [  182.380727]  sdhci_esdhc_runtime_resume from __rpm_callback+0x3c/0x168
    [  182.387315]  __rpm_callback from rpm_callback+0x28/0x54
    [  182.392590]  rpm_callback from rpm_resume+0x438/0x5ec
    [  182.397690]  rpm_resume from __pm_runtime_resume+0x34/0x6c
    [  182.403226]  __pm_runtime_resume from __mmc_claim_host+0x1a8/0x1f4
    [  182.409460]  __mmc_claim_host from wl12xx_sdio_raw_write+0x4c/0x15c [wlcore_sdio]
    [  182.417019]  wl12xx_sdio_raw_write [wlcore_sdio] from wlcore_runtime_resume+0xc8/0x218 [wlcore]
    [  182.426200]  wlcore_runtime_resume [wlcore] from __rpm_callback+0x3c/0x168
    [  182.433441]  __rpm_callback from rpm_callback+0x28/0x54
    [  182.438729]  rpm_callback from rpm_resume+0x438/0x5ec
    [  182.443835]  rpm_resume from __pm_runtime_resume+0x34/0x6c
    [  182.449375]  __pm_runtime_resume from wl1271_op_get_tsf+0x70/0x140 [wlcore]
    [  182.456685]  wl1271_op_get_tsf [wlcore] from ieee80211_if_fmt_tsf+0x1c/0x44 [mac80211]
    [  182.465943]  ieee80211_if_fmt_tsf [mac80211] from ieee80211_if_read+0x58/0xb4 [mac80211]
    [  182.475359]  ieee80211_if_read [mac80211] from ieee80211_if_read_tsf+0x1c/0x24 [mac80211]
    [  182.484764]  ieee80211_if_read_tsf [mac80211] from full_proxy_read+0x54/0x84
    [  182.492486]  full_proxy_read from vfs_read+0x90/0x288
    [  182.497592]  vfs_read from ksys_read+0x70/0xf0
    [  182.502075]  ksys_read from ret_fast_syscall+0x0/0x64
    

  • Regarding the actual Toffset, here is the kernel debug log with CONFIG_MAC80211_MESH_SYNC_DEBUG=y:

    [   99.779857] wlcore: PHY firmware version: Rev 8.2.0.0.246
    [   99.830476] wlcore: firmware booted (Rev 8.9.1.0.2)
    [  117.703793] wlan0_mesh: TSF : max clockdrift=0; too small to adjust
    [  117.705909] wlan0_mesh: TSF : max clockdrift=0; too small to adjust
    [  118.680280] wlan0_mesh: TSF : max clockdrift=0; too small to adjust
    [  118.881456] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341219272
    [  119.225451] wlan0_mesh: STA 4c:3b:6c:00:91:a6 : offset was invalid, t_offset=26608265798
    [  119.230074] wlan0_mesh: TSF : max clockdrift=0; too small to adjust
    [  119.345623] wlan0_mesh: TSF : max clockdrift=0; too small to adjust
    [  119.383481] wlan0_mesh: TSF : max clockdrift=0; too small to adjust
    [  119.749563] wlan0_mesh: STA 4c:3b:6c:07:2f:96 : offset was invalid, t_offset=97363067702
    [  119.911389] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221829, t_offset_setpoint=12341219252, t_clockdrift=-2577
    [  119.911476] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=-2577 too large, setpoint reset
    [  120.210444] wlan0_mesh: STA 4c:3b:6c:00:91:a6 : t_offset=26608311258, t_offset_setpoint=26608265778, t_clockdrift=-45480
    [  120.210517] wlan0_mesh: STA 4c:3b:6c:00:91:a6 : t_clockdrift=-45480 too large, setpoint reset
    [  120.416410] wlan0_mesh: TSF : max clockdrift=0; too small to adjust
    [  120.777659] wlan0_mesh: STA 4c:3b:6c:07:2f:96 : t_offset=97363067908, t_offset_setpoint=97363067682, t_clockdrift=-226
    [  120.929221] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341221611
    [  121.226259] wlan0_mesh: STA 4c:3b:6c:00:91:a6 : offset was invalid, t_offset=26608310914
    [  121.797574] wlan0_mesh: STA 4c:3b:6c:07:2f:96 : t_offset=97363067602, t_offset_setpoint=97363067682, t_clockdrift=80
    [  122.252056] wlan0_mesh: STA 4c:3b:6c:00:91:a6 : t_offset=26608309286, t_offset_setpoint=26608310894, t_clockdrift=1608
    [  122.252219] wlan0_mesh: STA 4c:3b:6c:00:91:a6 : t_clockdrift=1608 too large, setpoint reset
    [  122.821388] wlan0_mesh: STA 4c:3b:6c:07:2f:96 : t_offset=97363067834, t_offset_setpoint=97363067682, t_clockdrift=-152
    [  122.971539] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221609, t_offset_setpoint=12341221591, t_clockdrift=-18
    [  123.273997] wlan0_mesh: STA 4c:3b:6c:00:91:a6 : offset was invalid, t_offset=26608311331
    [  123.846349] wlan0_mesh: STA 4c:3b:6c:07:2f:96 : t_offset=97363066590, t_offset_setpoint=97363067682, t_clockdrift=1092
    [  123.846430] wlan0_mesh: STA 4c:3b:6c:07:2f:96 : t_clockdrift=1092 too large, setpoint reset
    [  123.998382] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341218593, t_offset_setpoint=12341221591, t_clockdrift=2998
    [  123.998481] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=2998 too large, setpoint reset
    [  124.297458] wlan0_mesh: STA 4c:3b:6c:00:91:a6 : t_offset=26608311386, t_offset_setpoint=26608311311, t_clockdrift=-75
    [  124.869266] wlan0_mesh: STA 4c:3b:6c:07:2f:96 : offset was invalid, t_offset=97363067569
    [  125.022348] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341221917
    [  125.291667] wlan0_mesh: TSF : kicking off TSF adjustment with clockdrift_max=80
    [  125.294695] wlan0_mesh: TSF : max clockdrift=80; adjusting
    [  125.295388] wlan0_mesh: TSF : max clockdrift=0; too small to adjust
    [  125.364032] wlan0_mesh: STA 4c:3b:6c:00:91:a6 : t_offset=26608268857, t_offset_setpoint=26608311311, t_clockdrift=42454
    [  125.364117] wlan0_mesh: STA 4c:3b:6c:00:91:a6 : t_clockdrift=42454 too large, setpoint reset
    [  125.364245] wlan0_mesh: TSF : max clockdrift=0; too small to adjust
    [  129.116086] wlan0_mesh: TSF : max clockdrift=0; too small to adjust
    [  129.123211] wlan0_mesh: TSF : max clockdrift=0; too small to adjust
    [  130.524271] wlan0_mesh: TSF : max clockdrift=0; too small to adjust
    [  131.163679] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341221616
    [  131.612872] wlan0_mesh: TSF : max clockdrift=0; too small to adjust
    [  131.652575] wlan0_mesh: TSF : max clockdrift=0; too small to adjust
    [  132.206065] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222028, t_offset_setpoint=12341221596, t_clockdrift=-432
    [  133.218037] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221250, t_offset_setpoint=12341221596, t_clockdrift=346
    [  134.239471] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341218873, t_offset_setpoint=12341221596, t_clockdrift=2723
    [  134.239561] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=2723 too large, setpoint reset
    [  135.265122] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341218798
    [  136.289885] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222066, t_offset_setpoint=12341218778, t_clockdrift=-3288
    [  136.289961] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=-3288 too large, setpoint reset
    [  137.305941] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341222054
    [  138.330110] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222398, t_offset_setpoint=12341222034, t_clockdrift=-364
    [  139.356611] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341219995, t_offset_setpoint=12341222034, t_clockdrift=2039
    [  139.357832] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=2039 too large, setpoint reset
    [  140.384384] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341215413
    [  141.406586] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341218699, t_offset_setpoint=12341215393, t_clockdrift=-3306
    [  141.406685] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=-3306 too large, setpoint reset
    [  142.426698] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341222373
    [  143.449531] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222423, t_offset_setpoint=12341222353, t_clockdrift=-70
    [  144.472732] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222601, t_offset_setpoint=12341222353, t_clockdrift=-248
    [  145.503444] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341218743, t_offset_setpoint=12341222353, t_clockdrift=3610
    [  145.503573] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=3610 too large, setpoint reset
    [  146.523722] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341219928
    [  147.545112] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222037, t_offset_setpoint=12341219908, t_clockdrift=-2129
    [  147.545197] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=-2129 too large, setpoint reset
    [  148.583099] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341219439
    [  149.599035] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222379, t_offset_setpoint=12341219419, t_clockdrift=-2960
    [  149.599111] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=-2960 too large, setpoint reset
    [  150.617861] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341222002
    [  151.881896] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221118, t_offset_setpoint=12341221982, t_clockdrift=864
    [  151.881981] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=864 too large, setpoint reset
    [  152.673765] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341221609
    [  153.694276] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341216531, t_offset_setpoint=12341221589, t_clockdrift=5058
    [  153.694374] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=5058 too large, setpoint reset
    [  154.713277] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341221721
    [  155.736716] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221817, t_offset_setpoint=12341221701, t_clockdrift=-116
    [  156.760593] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221990, t_offset_setpoint=12341221701, t_clockdrift=-289
    [  157.818016] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221361, t_offset_setpoint=12341221701, t_clockdrift=340
    [  158.809831] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341220767, t_offset_setpoint=12341221701, t_clockdrift=934
    [  158.809907] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=934 too large, setpoint reset
    [  159.832083] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341222191
    [  160.979530] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222235, t_offset_setpoint=12341222171, t_clockdrift=-64
    [  161.880303] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222300, t_offset_setpoint=12341222171, t_clockdrift=-129
    [  163.928207] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221821, t_offset_setpoint=12341222171, t_clockdrift=350
    [  164.952889] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221416, t_offset_setpoint=12341222171, t_clockdrift=755
    [  165.975590] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222110, t_offset_setpoint=12341222171, t_clockdrift=61
    [  168.023677] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222346, t_offset_setpoint=12341222171, t_clockdrift=-175
    [  169.048184] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222344, t_offset_setpoint=12341222171, t_clockdrift=-173
    [  170.074010] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341219556, t_offset_setpoint=12341222171, t_clockdrift=2615
    [  170.074175] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=2615 too large, setpoint reset
    [  171.095418] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341221916
    [  172.121026] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222099, t_offset_setpoint=12341221896, t_clockdrift=-203
    [  173.144805] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341220520, t_offset_setpoint=12341221896, t_clockdrift=1376
    [  173.144968] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=1376 too large, setpoint reset
    [  174.169572] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341219997
    [  175.191751] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221586, t_offset_setpoint=12341219977, t_clockdrift=-1609
    [  175.191825] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=-1609 too large, setpoint reset
    [  176.267280] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341221966
    [  177.238878] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222033, t_offset_setpoint=12341221946, t_clockdrift=-87
    [  178.264119] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221046, t_offset_setpoint=12341221946, t_clockdrift=900
    [  178.264205] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=900 too large, setpoint reset
    [  179.326709] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341221931
    [  180.311921] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222106, t_offset_setpoint=12341221911, t_clockdrift=-195
    [  181.334452] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222101, t_offset_setpoint=12341221911, t_clockdrift=-190
    [  182.360391] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222016, t_offset_setpoint=12341221911, t_clockdrift=-105
    [  183.381770] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222604, t_offset_setpoint=12341221911, t_clockdrift=-693
    [  184.407587] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221188, t_offset_setpoint=12341221911, t_clockdrift=723
    [  185.430258] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222055, t_offset_setpoint=12341221911, t_clockdrift=-144
    [  186.522894] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221343, t_offset_setpoint=12341221911, t_clockdrift=568
    [  187.477438] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222601, t_offset_setpoint=12341221911, t_clockdrift=-690
    [  188.503551] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221813, t_offset_setpoint=12341221911, t_clockdrift=98
    [  189.527477] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221824, t_offset_setpoint=12341221911, t_clockdrift=87
    [  190.549807] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222150, t_offset_setpoint=12341221911, t_clockdrift=-239
    [  191.575834] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341220477, t_offset_setpoint=12341221911, t_clockdrift=1434
    [  191.575935] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=1434 too large, setpoint reset
    [  192.600334] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341222201
    [  193.621574] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222569, t_offset_setpoint=12341222181, t_clockdrift=-388
    [  194.645349] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222188, t_offset_setpoint=12341222181, t_clockdrift=-7
    [  195.668820] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222576, t_offset_setpoint=12341222181, t_clockdrift=-395
    [  196.692809] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222552, t_offset_setpoint=12341222181, t_clockdrift=-371
    [  197.717242] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221997, t_offset_setpoint=12341222181, t_clockdrift=184
    [  198.741458] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222312, t_offset_setpoint=12341222181, t_clockdrift=-131
    [  199.765398] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221946, t_offset_setpoint=12341222181, t_clockdrift=235
    [  200.797577] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221003, t_offset_setpoint=12341222181, t_clockdrift=1178
    [  200.797661] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=1178 too large, setpoint reset
    [  201.813447] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341222191
    [  202.843469] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341215893, t_offset_setpoint=12341222171, t_clockdrift=6278
    [  202.843569] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=6278 too large, setpoint reset
    [  203.869028] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341214912
    [  204.884860] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221988, t_offset_setpoint=12341214892, t_clockdrift=-7096
    [  204.885001] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=-7096 too large, setpoint reset
    [  205.911041] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341222366
    [  206.934094] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221396, t_offset_setpoint=12341222346, t_clockdrift=950
    [  206.934195] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=950 too large, setpoint reset
    [  207.958015] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341221045
    [  208.982305] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221205, t_offset_setpoint=12341221025, t_clockdrift=-180
    [  210.003922] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222408, t_offset_setpoint=12341221025, t_clockdrift=-1383
    [  210.003997] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=-1383 too large, setpoint reset
    [  211.028347] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341222030
    [  212.052214] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222428, t_offset_setpoint=12341222010, t_clockdrift=-418
    [  213.075934] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222577, t_offset_setpoint=12341222010, t_clockdrift=-567
    [  214.100681] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221844, t_offset_setpoint=12341222010, t_clockdrift=166
    [  215.123764] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222194, t_offset_setpoint=12341222010, t_clockdrift=-184
    [  216.148165] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222263, t_offset_setpoint=12341222010, t_clockdrift=-253
    [  217.171839] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222035, t_offset_setpoint=12341222010, t_clockdrift=-25
    [  218.195206] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222505, t_offset_setpoint=12341222010, t_clockdrift=-495
    [  219.228161] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341214029, t_offset_setpoint=12341222010, t_clockdrift=7981
    [  219.228246] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=7981 too large, setpoint reset
    [  220.243534] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341222398
    [  221.268407] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221618, t_offset_setpoint=12341222378, t_clockdrift=760
    [  222.291215] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222583, t_offset_setpoint=12341222378, t_clockdrift=-205
    [  223.315413] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222527, t_offset_setpoint=12341222378, t_clockdrift=-149
    [  224.339131] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222213, t_offset_setpoint=12341222378, t_clockdrift=165
    [  225.367191] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341219729, t_offset_setpoint=12341222378, t_clockdrift=2649
    [  225.367264] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=2649 too large, setpoint reset
    [  226.391028] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341222219
    [  227.411409] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221671, t_offset_setpoint=12341222199, t_clockdrift=528
    [  228.437840] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222389, t_offset_setpoint=12341222199, t_clockdrift=-190
    [  229.458620] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222236, t_offset_setpoint=12341222199, t_clockdrift=-37
    [  230.482073] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222692, t_offset_setpoint=12341222199, t_clockdrift=-493
    [  231.669692] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341219599, t_offset_setpoint=12341222199, t_clockdrift=2600
    [  231.669765] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=2600 too large, setpoint reset
    [  232.533022] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341219876
    [  233.555283] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221767, t_offset_setpoint=12341219856, t_clockdrift=-1911
    [  233.555371] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=-1911 too large, setpoint reset
    [  234.578589] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341221988
    [  235.602421] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221978, t_offset_setpoint=12341221968, t_clockdrift=-10
    [  236.626134] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222517, t_offset_setpoint=12341221968, t_clockdrift=-549
    [  237.658585] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222354, t_offset_setpoint=12341221968, t_clockdrift=-386
    [  238.673889] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222599, t_offset_setpoint=12341221968, t_clockdrift=-631
    [  239.701759] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341219251, t_offset_setpoint=12341221968, t_clockdrift=2717
    [  239.701842] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=2717 too large, setpoint reset
    [  240.722797] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341222583
    [  241.745672] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222250, t_offset_setpoint=12341222563, t_clockdrift=313
    [  242.769929] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222555, t_offset_setpoint=12341222563, t_clockdrift=8
    [  243.793810] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222061, t_offset_setpoint=12341222563, t_clockdrift=502
    [  244.832636] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341207111, t_offset_setpoint=12341222563, t_clockdrift=15452
    [  244.832736] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=15452 too large, setpoint reset
    [  245.841386] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341222242
    [  246.865486] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222469, t_offset_setpoint=12341222222, t_clockdrift=-247
    [  247.889830] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222147, t_offset_setpoint=12341222222, t_clockdrift=75
    [  248.913449] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222226, t_offset_setpoint=12341222222, t_clockdrift=-4
    [  249.936623] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222639, t_offset_setpoint=12341222222, t_clockdrift=-417
    [  250.963891] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221051, t_offset_setpoint=12341222222, t_clockdrift=1171
    [  250.964073] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=1171 too large, setpoint reset
    [  251.984412] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341222692
    [  253.008909] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222207, t_offset_setpoint=12341222672, t_clockdrift=465
    [  254.033661] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221641, t_offset_setpoint=12341222672, t_clockdrift=1031
    [  254.033743] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=1031 too large, setpoint reset
    [  255.056809] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : offset was invalid, t_offset=12341222156
    [  256.080370] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222680, t_offset_setpoint=12341222136, t_clockdrift=-544
    [  257.106098] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222264, t_offset_setpoint=12341222136, t_clockdrift=-128
    [  258.132964] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221800, t_offset_setpoint=12341222136, t_clockdrift=336
    [  259.152448] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222133, t_offset_setpoint=12341222136, t_clockdrift=3
    [  260.176226] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222275, t_offset_setpoint=12341222136, t_clockdrift=-139
    [  261.203681] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341221753, t_offset_setpoint=12341222136, t_clockdrift=383
    [  262.223975] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341222494, t_offset_setpoint=12341222136, t_clockdrift=-358
    [  263.249780] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_offset=12341220675, t_offset_setpoint=12341222136, t_clockdrift=1461
    [  263.249991] wlan0_mesh: STA 4c:3b:6c:12:e8:46 : t_clockdrift=1461 too large, setpoint reset
    

  • # iw dev wlan0_mesh scan | grep -A 2 4c:3b:6c:00:91:46
    BSS 4c:3b:6c:00:91:46(on wlan0_mesh)
    	last seen: 106526.103s [boottime]
    	TSF: 5579972760 usec (0d, 01:32:59)
    # 
    # 
    # iw dev wlan0_mesh scan | grep -A 2 4c:3b:6c:00:91:46
    BSS 4c:3b:6c:00:91:46(on wlan0_mesh)
    	last seen: 106694.113s [boottime]
    	TSF: 5388683619 usec (0d, 01:29:48)
    # 
    # iw dev wlan0_mesh scan | grep -A 2 4c:3b:6c:00:91:46
    BSS 4c:3b:6c:00:91:46(on wlan0_mesh)
    	last seen: 106912.010s [boottime]
    	TSF: 5965877904 usec (0d, 01:39:25)
    # 
    # 
    # iw dev wlan0_mesh scan | grep -A 2 4c:3b:6c:00:91:46
    BSS 4c:3b:6c:00:91:46(on wlan0_mesh)
    	last seen: 107040.577s [boottime]
    	TSF: 4952969548 usec (0d, 01:22:32)
    

  • Hi Peter,

    Thanks for this. And you are using the latest FW 8.9.1.2, correct?

    Can you describe the mesh network? What nodes are being used? Are they all wl1837MOD?

  • Yes, firmware 8.9.1.0.2. All nodes are charging stations with custom embedded system, based on i.IMX6ULL. All are using WL1837MOD. One node bridges the mesh network to Ethernet. 

    This thread/question actually covers two issues:

    1) Crash upon "cat tsf"

    2) Stability issues most likely caused by bad Toffset.

    Initially I thought these were related, but now I don't think so. 

    The second issue is the most important one. This issue has yet only been seen on Linux 6.6 with firmware 8.9.1.0.2. I have not seen it on Linux 5.15.71 with firmware 8.9.1.0.0. It seems to be an issue with receiving/decoding the TSF timestamp in the Beacon; after running for several hours.

  • Problem seen also on:

    * 5.15.71 (with net patches) and firmware 8.9.1.0.2

    * 6.6.52 (with net patches) and firmware 8.9.1.0.0

    * 6.6.52 (with net patches) and firmware 8.9.1.0.2

  • I have now written a script which checks TSF in "iw scan" output:

    #!/usr/bin/python3
    "Check TSF in iw scan"
    
    import os
    import time
    import random
    import subprocess
    
    def main():
        "Main"
        # Indexed on MAC, contains last TSF
        uptime = subprocess.run(["uptime"], text=True, stdout=subprocess.PIPE, check=True)
        print(f"Uptime: {uptime.stdout.strip()}")
    
        wilink = subprocess.run(["strings", "/lib/firmware/ti-connectivity/wl18xx-fw-4.bin"],
                                text=True, stdout=subprocess.PIPE, check=True)
        firmware = []
        for line in wilink.stdout.splitlines():
            if line.startswith("FRev "):
                firmware.append(line.split()[1])
        firmware = "/".join(firmware)
        print(f"Wilink firmware: {firmware}")
    
        uname = " ".join(os.uname())
        print(f"Scanning on {uname}")
        nodes = {}
    

        for dummy in range(10):
            found = set()
            time.sleep(random.randrange(1, 5))
            try:
                proc = subprocess.run(["iw", "dev", "wlan0_mesh", "scan"],
                                      text=True, stdout=subprocess.PIPE, check=True)
            except subprocess.CalledProcessError:
                continue
            for line in proc.stdout.splitlines():
                if line.startswith("BSS "):
                    dummy, mac_etc  = line.split(maxsplit=1)
                    mac, dummy = mac_etc.split("(", maxsplit=1)
                    mac = mac.lower()
                    if mac in found:
                        print(f"{mac}: appearing multiple times")
                    found.add(mac)
                elif line.startswith("\tTSF:"):
                    dummy, tsf, dummy = line.split(maxsplit=2)
                    tsf = int(tsf)
                    if nodes.get(mac):
                        diff = tsf - nodes[mac]
                        if not diff >= 0:
                            print(f"{mac}: TSF {tsf} < {nodes[mac]}, backwards")
                        #if diff > 30000000:
                        #    print(f"{mac}: TSF {tsf} > {nodes[mac]} by > 30 s")
                    nodes[mac] = tsf
            print(f"Found {len(found)} BSS")
    
    try:
        main()
    except KeyboardInterrupt:
        pass
    

    It shows that the problem is present even on 4.19.38 with all Wilink patches. Example:

    root@4C3B6C00BC00:~# ./checktsf.py 
    Uptime: 10:12:11 up 1 min,  load average: 1.54, 0.63, 0.23
    Wilink firmware: 8.9.1.0.2/8.2.0.0.246
    Scanning on Linux 4C3B6C00BC00 4.19.38-27 #1 SMP PREEMPT Mon Jan 12 09:41:52 UTC 2026 armv7l
    Found 18 BSS
    4c:3b:6c:00:21:56: appearing multiple times
    Found 22 BSS
    4c:3b:6c:00:21:56: TSF 33973783969 < 33978566736, backwards
    4c:3b:6c:00:91:a6: TSF 149390646957 < 245954713494, backwards
    4c:3b:6c:00:21:56: appearing multiple times
    Found 22 BSS
    4c:3b:6c:00:21:56: TSF 33973783969 < 33983354554, backwards
    4c:3b:6c:00:21:56: appearing multiple times
    Found 22 BSS
    4c:3b:6c:00:21:56: TSF 33973783969 < 33988164512, backwards
    4c:3b:6c:00:21:56: appearing multiple times
    Found 22 BSS
    4c:3b:6c:00:21:56: TSF 33973783969 < 33990942617, backwards
    4c:3b:6c:00:21:56: appearing multiple times
    Found 22 BSS
    4c:3b:6c:00:21:56: TSF 33973783969 < 33993699899, backwards
    4c:3b:6c:00:91:a6: TSF 149405783092 < 245969851357, backwards
    4c:3b:6c:00:21:56: appearing multiple times
    

    This is clearly an RX side issue. The problem with BSS appearing multiple times is not always present. Typically, there are two nodes with unstable TSF. If you reboot, two other nodes with unstable TSF are reported. Example:

    root@4C3B6C00BC00:~# ./checktsf.py 
    Uptime: 10:13:06 up 2 min,  load average: 1.12, 0.65, 0.26
    Wilink firmware: 8.9.1.0.2/8.2.0.0.246
    Scanning on Linux 4C3B6C00BC00 4.19.38-27 #1 SMP PREEMPT Mon Jan 12 09:41:52 UTC 2026 armv7l
    Found 22 BSS
    4c:3b:6c:00:91:a6: TSF 149438654029 < 246005767341, backwards
    Found 22 BSS
    Found 22 BSS
    4c:3b:6c:00:91:a6: TSF 149444173561 < 178542026880, backwards
    4c:3b:6c:12:e8:46: TSF 245725758238 < 247627666553, backwards
    

    Also interesting is that these are adjacent to each other in "iw scan output". 

  • Any update on this? What could be the cause of unstable TSF? Can you see it as well?

  • Hi again, any updates to this issue? Do you need any additional information to investigate?