HS 2.0R2: Add GAS operation duration statistics into debug

Signed-off-by: Jouni Malinen <jouni@qca.qualcomm.com>

diff --git a/wpa_supplicant/gas_query.c b/wpa_supplicant/gas_query.c
index b2558470dfebc976d41fc3ec3849804ab755d477..a63ee6c1bbd44e02436bca54874dfa6f6f5401cc 100644 (file)
--- a/wpa_supplicant/gas_query.c
+++ b/wpa_supplicant/gas_query.c
@@ -42,6 +42,7 @@ struct gas_query_pending {
        struct wpabuf *req;
        struct wpabuf *adv_proto;
        struct wpabuf *resp;
+       struct os_reltime last_oper;
        void (*cb)(void *ctx, const u8 *dst, u8 dialog_token,
                   enum gas_query_result result,
                   const struct wpabuf *adv_proto,
@@ -64,6 +65,16 @@ static void gas_query_tx_comeback_timeout(void *eloop_data, void *user_ctx);
 static void gas_query_timeout(void *eloop_data, void *user_ctx);
 
 
+static int ms_from_time(struct os_reltime *last)
+{
+       struct os_reltime now, res;
+
+       os_get_reltime(&now);
+       os_reltime_sub(&now, last, &res);
+       return res.sec * 1000 + res.usec / 1000;
+}
+
+
 /**
  * gas_query_init - Initialize GAS query component
  * @wpa_s: Pointer to wpa_supplicant data
@@ -199,6 +210,7 @@ static void gas_query_tx_status(struct wpa_supplicant *wpa_s,
 {
        struct gas_query_pending *query;
        struct gas_query *gas = wpa_s->gas;
+       int dur;
 
        if (gas->current == NULL) {
                wpa_printf(MSG_DEBUG, "GAS: Unexpected TX status: freq=%u dst="
@@ -209,13 +221,15 @@ static void gas_query_tx_status(struct wpa_supplicant *wpa_s,
 
        query = gas->current;
 
+       dur = ms_from_time(&query->last_oper);
        wpa_printf(MSG_DEBUG, "GAS: TX status: freq=%u dst=" MACSTR
-                  " result=%d query=%p dialog_token=%u",
-                  freq, MAC2STR(dst), result, query, query->dialog_token);
+                  " result=%d query=%p dialog_token=%u dur=%d ms",
+                  freq, MAC2STR(dst), result, query, query->dialog_token, dur);
        if (os_memcmp(dst, query->addr, ETH_ALEN) != 0) {
                wpa_printf(MSG_DEBUG, "GAS: TX status for unexpected destination");
                return;
        }
+       os_get_reltime(&query->last_oper);
 
        if (result == OFFCHANNEL_SEND_ACTION_SUCCESS) {
                eloop_cancel_timeout(gas_query_timeout, gas, query);
@@ -251,6 +265,7 @@ static int gas_query_tx(struct gas_query *gas, struct gas_query_pending *query,
                u8 *categ = wpabuf_mhead_u8(req);
                *categ = WLAN_ACTION_PROTECTED_DUAL;
        }
+       os_get_reltime(&query->last_oper);
        res = offchannel_send_action(gas->wpa_s, query->freq, query->addr,
                                     gas->wpa_s->own_addr, query->addr,
                                     wpabuf_head(req), wpabuf_len(req), 1000,
@@ -452,6 +467,9 @@ int gas_query_rx(struct gas_query *gas, const u8 *da, const u8 *sa,
                return -1;
        }
 
+       wpa_printf(MSG_DEBUG, "GAS: Response in %d ms from " MACSTR,
+                  ms_from_time(&query->last_oper), MAC2STR(sa));
+
        if (query->wait_comeback && action == WLAN_PA_GAS_INITIAL_RESP) {
                wpa_printf(MSG_DEBUG, "GAS: Unexpected initial response from "
                           MACSTR " dialog token %u when waiting for comeback "

diff --git a/wpa_supplicant/hs20_supplicant.c b/wpa_supplicant/hs20_supplicant.c
index 4f1ce9858013ad68913f32e3f6265268be3a3440..186faa573b7e0bb844b6a737c1811712fb1a5910 100644 (file)
--- a/wpa_supplicant/hs20_supplicant.c
+++ b/wpa_supplicant/hs20_supplicant.c
@@ -284,6 +284,15 @@ static void hs20_continue_icon_fetch(void *eloop_ctx, void *sock_ctx)
 static void hs20_osu_icon_fetch_result(struct wpa_supplicant *wpa_s, int res)
 {
        size_t i, j;
+       struct os_reltime now, tmp;
+       int dur;
+
+       os_get_reltime(&now);
+       os_reltime_sub(&now, &wpa_s->osu_icon_fetch_start, &tmp);
+       dur = tmp.sec * 1000 + tmp.usec / 1000;
+       wpa_printf(MSG_DEBUG, "HS 2.0: Icon fetch dur=%d ms res=%d",
+                  dur, res);
+
        for (i = 0; i < wpa_s->osu_prov_count; i++) {
                struct osu_provider *osu = &wpa_s->osu_prov[i];
                for (j = 0; j < osu->icon_count; j++) {
@@ -510,6 +519,7 @@ void hs20_next_osu_icon(struct wpa_supplicant *wpa_s)
                        wpa_printf(MSG_DEBUG, "HS 2.0: Try to fetch icon '%s' "
                                   "from " MACSTR, icon->filename,
                                   MAC2STR(osu->bssid));
+                       os_get_reltime(&wpa_s->osu_icon_fetch_start);
                        if (hs20_anqp_send_req(wpa_s, osu->bssid,
                                               BIT(HS20_STYPE_ICON_REQUEST),
                                               (u8 *) icon->filename,

diff --git a/wpa_supplicant/wpa_supplicant_i.h b/wpa_supplicant/wpa_supplicant_i.h
index 92e937e1c10b947b0cf5d23ab405c2c2ea1deeb8..0b505ff77ad49da2677a18c19c7f2dd25392ae7d 100644 (file)
--- a/wpa_supplicant/wpa_supplicant_i.h
+++ b/wpa_supplicant/wpa_supplicant_i.h
@@ -777,6 +777,7 @@ struct wpa_supplicant {
        unsigned int osu_icon_id;
        struct osu_provider *osu_prov;
        size_t osu_prov_count;
+       struct os_reltime osu_icon_fetch_start;
 #endif /* CONFIG_INTERWORKING */
        unsigned int drv_capa_known;