Skip to contentSkip to conversation

RFC: Add precise timing to wifi association messages?

PATCH Ben Greear 2 participants 6 messages Nov 13, 2013 mac80211

lore
Share & tools
lore

Ben Greear

author
#0 lore raw

Any interest in a patch looking similar to that below for the 5 or so messages related to association? I found it useful for tracking down why it was taking longer than expected to roam to a new AP...

net/mac80211/mlme.c +6 -0
index d2510c0..2e96813 100644
@@ -908,6 +908,12 @@ static void ieee80211_send_assoc(struct ieee80211_sub_if_data *sdata)
                memcpy(pos, assoc_data->ie + offset, noffset - offset);
        }
 
+       {
+               struct timeval tv;
+               do_gettimeofday(&tv);
+               sdata_info(sdata, "send_assoc, calling prepare_tx at: %lu.%lu\n",
+                          tv.tv_sec, tv.tv_usec);
+       }
        drv_mgd_prepare_tx(local, sdata);
 
        IEEE80211_SKB_CB(skb)->flags |= IEEE80211_TX_INTFL_DONT_ENCRYPT;

Thanks,
Ben

Signature · 2 lines
Ben Greear <[email protected]>
Candela Technologies Inc  http://www.candelatech.com
author
#1 lore raw
Quoted 13 lines · Ben Greear

Any interest in a patch looking similar to that below for the 5 or so messages related to association? I found it useful for tracking down why it was taking longer than expected to roam to a new AP...

net/mac80211/mlme.c +0 -0
index d2510c0..2e96813 100644
@@ -908,6 +908,12 @@ static void ieee80211_send_assoc(struct ieee80211_sub_if_data *sdata)
                memcpy(pos, assoc_data->ie + offset, noffset - offset);
        }

net/mac80211/mlme.c static void ieee80211_send_assoc(struct ieee80211_sub_if_data *sdata) · line 919

Quoted 10 lines
net/mac80211/mlme.c +6 -0
 
+       {
+               struct timeval tv;
+               do_gettimeofday(&tv);
+               sdata_info(sdata, "send_assoc, calling prepare_tx at: %lu.%lu\n",
+                          tv.tv_sec, tv.tv_usec);
+       }
        drv_mgd_prepare_tx(local, sdata);
 
        IEEE80211_SKB_CB(skb)->flags |= IEEE80211_TX_INTFL_DONT_ENCRYPT;

I chose a poor example here...my intention is to just add timers to existing messages...

Thanks,
Ben

Quoted 5 lines

Thanks,
Ben

Signature · 2 lines
Ben Greear <[email protected]>
Candela Technologies Inc  http://www.candelatech.com
maintainer
#2 lore raw
Quoted 2 lines · Ben Greear

I chose a poor example here...my intention is to just add timers to existing messages...

What does this do that printk timestamps don't?

johannes

author
#3 lore raw
Quoted 6 lines · Johannes Berg
Quoted 2 lines · Ben Greear

I chose a poor example here...my intention is to just add timers to existing messages...

What does this do that printk timestamps don't?

Sub-second precision, and the same in 'dmesg' output.

There may be a way to get /var/log/messages to show sub-second precision, but at least it is not enabled by default on the systems I use. dmesg has no timestamps at all from what I can tell.

Things like ath9k debugging typically do not go to /var/log/messages at all, so I was stuck using dmesg (I'll post a similar patch for ath9k debugging in case someone likes it.)

The format I chose matches wpa_supplicant logs as well, which I found useful.

Thanks,
Ben

Signature · 2 lines
Ben Greear <[email protected]>
Candela Technologies Inc  http://www.candelatech.com
maintainer
#4 lore raw
Quoted 6 lines · Ben Greear
Quoted 5 lines · Johannes Berg
Quoted 2 lines · Ben Greear

I chose a poor example here...my intention is to just add timers to existing messages...

Quoted 7 lines
Quoted 1 line

What does this do that printk timestamps don't?

Sub-second precision, and the same in 'dmesg' output.

There may be a way to get /var/log/messages to show sub-second precision, but at least it is not enabled by default on the systems I use. dmesg has no timestamps at all from what I can tell.

Err. Just set CONFIG_PRINTK_TIME in your kernel.

johannes

author
#5 lore raw
Quoted 9 lines · Johannes Berg
Quoted 8 lines · Ben Greear
Quoted 6 lines · Johannes Berg
Quoted 2 lines · Ben Greear

I chose a poor example here...my intention is to just add timers to existing messages...

What does this do that printk timestamps don't?

Quoted 7 lines
Quoted 5 lines

Sub-second precision, and the same in 'dmesg' output.

There may be a way to get /var/log/messages to show sub-second precision, but at least it is not enabled by default on the systems I use. dmesg has no timestamps at all from what I can tell.

Err. Just set CONFIG_PRINTK_TIME in your kernel.

Ok, I didn't realize that was available.

Thanks,
Ben

Quoted 3 lines

johannes

Signature · 2 lines
Ben Greear <[email protected]>
Candela Technologies Inc  http://www.candelatech.com