Confusing TSF values for WiFi...
Posted: Thu Jan 30, 2025 6:50 pm
Using the promiscuous callback, I can sniff on beacon frames and I get the beacon timestamp (at +24 offset) as expected:
...
I (35263) ESPNOW_REC: Beacon timestamp 17893982617990 (rx = 35260724, diff = 17893947357266)
I (35468) ESPNOW_REC: Beacon timestamp 17893982822802 (rx = 35465537, diff = 17893947357265)
I (35673) ESPNOW_REC: Beacon timestamp 17893983027598 (rx = 35670334, diff = 17893947357264)
I (35775) ESPNOW_REC: Beacon timestamp 17893983130004 (rx = 35772741, diff = 17893947357263)
I (35878) ESPNOW_REC: Beacon timestamp 17893983232394 (rx = 35875131, diff = 17893947357263)
I (35980) ESPNOW_REC: Beacon timestamp 17893983334801 (rx = 35977538, diff = 17893947357263)
I (36185) ESPNOW_REC: Beacon timestamp 17893983539589 (rx = 36182328, diff = 17893947357261)
I (36287) ESPNOW_REC: Beacon timestamp 17893983641996 (rx = 36284735, diff = 17893947357261)
I (36390) ESPNOW_REC: Beacon timestamp 17893983744403 (rx = 36387143, diff = 17893947357260)
I (36492) ESPNOW_REC: Beacon timestamp 17893983846811 (rx = 36489551, diff = 17893947357260)
I (36595) ESPNOW_REC: Beacon timestamp 17893983949214 (rx = 36591955, diff = 17893947357259)
I (36697) ESPNOW_REC: Beacon timestamp 17893984051604 (rx = 36694345, diff = 17893947357259)
I (36902) ESPNOW_REC: Beacon timestamp 17893984256395 (rx = 36899138, diff = 17893947357257)
I (37107) ESPNOW_REC: Beacon timestamp 17893984461214 (rx = 37103958, diff = 17893947357256)
I (37209) ESPNOW_REC: Beacon timestamp 17893984563589 (rx = 37206333, diff = 17893947357256)
I (37311) ESPNOW_REC: Beacon timestamp 17893984665996 (rx = 37308741, diff = 17893947357255)
I (37414) ESPNOW_REC: Beacon timestamp 17893984768399 (rx = 37411144, diff = 17893947357255)
rx being the value in buf->rx_ctrl.timestamp and diff indicates a ~10 us/s drift between timestamp and rx value.
However, during this time, esp_wifi_get_tsf_time(ESP_IF_WIFI_STA) returns zero. It's not until I get a beacon timeout (which in itself is odd given the above beacon frames) I get this:
I (37415) wifi:bcn_timeout,ap_probe_send_start
I (37416) ESPNOW_REC: Beacon timestamp 12225653447 (rx = 37416490, diff = 12188236957)
I (37424) ESPNOW_REC: Beacon timestamp 12225653956 (rx = 37416999, diff = 12188236957)
Notice the totally different timestamp value?? At this time, esp_wifi_get_tsf_time(ESP_IP_WIFI_STA) doesn't return zero anymore, and the value it returns matches this "new" timestamp value.
Then, after this, the timestamp goes back to the previous values...
I (37516) ESPNOW_REC: Beacon timestamp 17893984870789 (rx = 37513535, diff = 17893947357254)
I (37619) ESPNOW_REC: Beacon timestamp 17893984973214 (rx = 37615961, diff = 17893947357253)
I (37823) ESPNOW_REC: Beacon timestamp 17893985177989 (rx = 37820737, diff = 17893947357252)
I (37926) ESPNOW_REC: Beacon timestamp 17893985280405 (rx = 37923153, diff = 17893947357252)
...
What's going on here? I am very confused right now.
...
I (35263) ESPNOW_REC: Beacon timestamp 17893982617990 (rx = 35260724, diff = 17893947357266)
I (35468) ESPNOW_REC: Beacon timestamp 17893982822802 (rx = 35465537, diff = 17893947357265)
I (35673) ESPNOW_REC: Beacon timestamp 17893983027598 (rx = 35670334, diff = 17893947357264)
I (35775) ESPNOW_REC: Beacon timestamp 17893983130004 (rx = 35772741, diff = 17893947357263)
I (35878) ESPNOW_REC: Beacon timestamp 17893983232394 (rx = 35875131, diff = 17893947357263)
I (35980) ESPNOW_REC: Beacon timestamp 17893983334801 (rx = 35977538, diff = 17893947357263)
I (36185) ESPNOW_REC: Beacon timestamp 17893983539589 (rx = 36182328, diff = 17893947357261)
I (36287) ESPNOW_REC: Beacon timestamp 17893983641996 (rx = 36284735, diff = 17893947357261)
I (36390) ESPNOW_REC: Beacon timestamp 17893983744403 (rx = 36387143, diff = 17893947357260)
I (36492) ESPNOW_REC: Beacon timestamp 17893983846811 (rx = 36489551, diff = 17893947357260)
I (36595) ESPNOW_REC: Beacon timestamp 17893983949214 (rx = 36591955, diff = 17893947357259)
I (36697) ESPNOW_REC: Beacon timestamp 17893984051604 (rx = 36694345, diff = 17893947357259)
I (36902) ESPNOW_REC: Beacon timestamp 17893984256395 (rx = 36899138, diff = 17893947357257)
I (37107) ESPNOW_REC: Beacon timestamp 17893984461214 (rx = 37103958, diff = 17893947357256)
I (37209) ESPNOW_REC: Beacon timestamp 17893984563589 (rx = 37206333, diff = 17893947357256)
I (37311) ESPNOW_REC: Beacon timestamp 17893984665996 (rx = 37308741, diff = 17893947357255)
I (37414) ESPNOW_REC: Beacon timestamp 17893984768399 (rx = 37411144, diff = 17893947357255)
rx being the value in buf->rx_ctrl.timestamp and diff indicates a ~10 us/s drift between timestamp and rx value.
However, during this time, esp_wifi_get_tsf_time(ESP_IF_WIFI_STA) returns zero. It's not until I get a beacon timeout (which in itself is odd given the above beacon frames) I get this:
I (37415) wifi:bcn_timeout,ap_probe_send_start
I (37416) ESPNOW_REC: Beacon timestamp 12225653447 (rx = 37416490, diff = 12188236957)
I (37424) ESPNOW_REC: Beacon timestamp 12225653956 (rx = 37416999, diff = 12188236957)
Notice the totally different timestamp value?? At this time, esp_wifi_get_tsf_time(ESP_IP_WIFI_STA) doesn't return zero anymore, and the value it returns matches this "new" timestamp value.
Then, after this, the timestamp goes back to the previous values...
I (37516) ESPNOW_REC: Beacon timestamp 17893984870789 (rx = 37513535, diff = 17893947357254)
I (37619) ESPNOW_REC: Beacon timestamp 17893984973214 (rx = 37615961, diff = 17893947357253)
I (37823) ESPNOW_REC: Beacon timestamp 17893985177989 (rx = 37820737, diff = 17893947357252)
I (37926) ESPNOW_REC: Beacon timestamp 17893985280405 (rx = 37923153, diff = 17893947357252)
...
What's going on here? I am very confused right now.