diff mbox

RFC: Add precise timing to wifi association messages?

Message ID 5283BDB6.5020700@candelatech.com (mailing list archive)
State Not Applicable, archived
Headers show

Commit Message

Ben Greear Nov. 13, 2013, 5:58 p.m. UTC
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...




Thanks,
Ben

Comments

Ben Greear Nov. 13, 2013, 6:01 p.m. UTC | #1
On 11/13/2013 09:58 AM, Ben Greear wrote:
> 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...
> 
> 
> diff --git a/net/mac80211/mlme.c b/net/mac80211/mlme.c
> index d2510c0..2e96813 100644
> --- a/net/mac80211/mlme.c
> +++ b/net/mac80211/mlme.c
> @@ -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;

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

Thanks,
Ben

> 
> 
> Thanks,
> Ben
>
Johannes Berg Nov. 13, 2013, 6:18 p.m. UTC | #2
On Wed, 2013-11-13 at 10:01 -0800, Ben Greear wrote:

> 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

--
To unsubscribe from this list: send the line "unsubscribe linux-wireless" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Ben Greear Nov. 13, 2013, 6:24 p.m. UTC | #3
On 11/13/2013 10:18 AM, Johannes Berg wrote:
> On Wed, 2013-11-13 at 10:01 -0800, Ben Greear wrote:
> 
>> 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
Johannes Berg Nov. 13, 2013, 6:32 p.m. UTC | #4
On Wed, 2013-11-13 at 10:24 -0800, Ben Greear wrote:
> On 11/13/2013 10:18 AM, Johannes Berg wrote:
> > On Wed, 2013-11-13 at 10:01 -0800, Ben Greear wrote:
> > 
> >> 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.

Err. Just set CONFIG_PRINTK_TIME in your kernel.

johannes

--
To unsubscribe from this list: send the line "unsubscribe linux-wireless" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Ben Greear Nov. 13, 2013, 6:39 p.m. UTC | #5
On 11/13/2013 10:32 AM, Johannes Berg wrote:
> On Wed, 2013-11-13 at 10:24 -0800, Ben Greear wrote:
>> On 11/13/2013 10:18 AM, Johannes Berg wrote:
>>> On Wed, 2013-11-13 at 10:01 -0800, Ben Greear wrote:
>>>
>>>> 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.
> 
> Err. Just set CONFIG_PRINTK_TIME in your kernel.

Ok, I didn't realize that was available.

Thanks,
Ben

> 
> johannes
>
diff mbox

Patch

diff --git a/net/mac80211/mlme.c b/net/mac80211/mlme.c
index d2510c0..2e96813 100644
--- a/net/mac80211/mlme.c
+++ b/net/mac80211/mlme.c
@@ -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;