On 12 22:52:13, Jan Hendrik Farr wrote: > On 09 22:42:10, Jan Hendrik Farr wrote: > > > Could you do trace and sniffer at the same time? According to the trace > > > there was no authentication frame from the AP. In the sniffer capture it > > > _is_ there, of course, but I'd like to look at the timing. > > > > > > Ok, I did another capture. > > > > 1. iwd only knows credentials for a single SSID: kepler_test > > 2. kepler_test is the only SSID broadcasting on 6GHz channel 37 (or any > > 6GHz channel) > > 3. I captured 802.11 frames using a second device > > 4. I did a trace on the client in question > > 5. I captured dmesg and iwd logs > > 6. All captures were done simultaneously > > > > All attached to capture2.tar. Contents: > > capture2/dmesg2.txt : dmesg > > capture2/iwd_log2.txt : iwd log using IWD_SAE_DEBUG=1 > > capture2/trace2.dat : trace-cmd (iwlwifi, mac80211, cfg80211, iwlwifi_msg) > > capture2/iwd_main.conf : iwd config (/etc/iwd/main.conf) > > capture2/kepler_test.psk : ssid config for iwd (/var/lib/kepler_test.psk) > > capture2/capture2.pcapng : the external 802.11 frame capture > > > > > > I disabled 5Ghz via BandModifier5GHz=0.0 (couldn't disable 2.4GHz as iwd > > then complains about not being able to disable both) > > > > > > One note about the client: It's running an Intel N100, so it's probably > > on the lower end of devices that will be running a modern wifi 6e card. > > So this increases the chances that the AP will send it's confirm before > > the client will. > > > > > > Best Regards > > Jan > > I think there is something weird going on with the system time. I tried > lining up the times of frames in the packet capture with the > iwlwifi/iwlwifi_dev_(rx/tx) events and noticed that it's not possible to > get them to line up. > > For example time between STA sending commit and sending it's own confirm > is 41.85 ms according to the packed capture. But the time between what I > think are the corresponding events in the trace is 106.63 ms. > > Then I noticed that the time in dmesg -T was running ahead of the > correct time even though it was synced at boot. clock source is tsc. Did a small experiment by running echo 'before sleep 10' > /dev/kmsg && sleep 10 && echo 'after sleep 10' > /dev/kmsg It does take ~10 seconds to complete (checked against smartphone stopwatch). dmesg output shows 10 seconds passing: [326951.572303] before sleep 10 [326961.575732] after sleep 10 demsg -T shows 10 seconds as well: [Fri May 16 06:35:58 2025] before sleep 10 [Fri May 16 06:36:08 2025] after sleep 10 I assume the incorrect time has something todo with suspend... But at least the timestamps in the trace seem to be ticking at the correct rate then. They still don't line up with the packet capture for me though. Should the iwlwifi/iwlwifi_dev_tx events roughly match up with frames sent by the client? > > This is making analysis very annoying, but could it also be causing the > issue in the first place? > > Best Regards > Jan >
