iwlwifi: mvm: rs: improve debug prints

Enable better tracking of different decisions made
by the rate scale algorithm.

Signed-off-by: Eyal Shapira <eyal@wizery.com>
Signed-off-by: Emmanuel Grumbach <emmanuel.grumbach@intel.com>

diff --git a/drivers/net/wireless/iwlwifi/mvm/rs.c b/drivers/net/wireless/iwlwifi/mvm/rs.c
index a7efeb31c2583f6ddc54de70dd941db0ca5c1476..065520968d2903fbf3734ff46b4cd1dacc04b0da 100644 (file)
--- a/drivers/net/wireless/iwlwifi/mvm/rs.c
+++ b/drivers/net/wireless/iwlwifi/mvm/rs.c
@@ -174,7 +174,7 @@ static void rs_fill_link_cmd(struct iwl_mvm *mvm,
                             struct ieee80211_sta *sta,
                             struct iwl_lq_sta *lq_sta, u32 rate_n_flags);
 static void rs_stay_in_table(struct iwl_lq_sta *lq_sta, bool force_search);
-
+static const char *rs_pretty_lq_type(enum iwl_table_type type);
 
 #ifdef CONFIG_MAC80211_DEBUGFS
 static void rs_dbgfs_set_mcs(struct iwl_lq_sta *lq_sta,
@@ -778,9 +778,6 @@ static void rs_tx_status(void *mvm_r, struct ieee80211_supported_band *sband,
        struct iwl_scale_tbl_info tbl_type;
        struct iwl_scale_tbl_info *curr_tbl, *other_tbl, *tmp_tbl;
 
-       IWL_DEBUG_RATE_LIMIT(mvm,
-                            "get frame ack response, update rate scale window\n");
-
        /* Treat uninitialized rate scaling data same as non-existing. */
        if (!lq_sta) {
                IWL_DEBUG_RATE(mvm, "Station rate scaling not created yet.\n");
@@ -1499,8 +1496,10 @@ static int rs_move_mimo2_to_other(struct iwl_mvm *mvm,
        u8 update_search_tbl_counter = 0;
        int ret;
 
-       if (!iwl_mvm_bt_coex_is_mimo_allowed(mvm, sta))
+       if (!iwl_mvm_bt_coex_is_mimo_allowed(mvm, sta)) {
+               IWL_DEBUG_RATE(mvm, "BT COEX force switch to SISO A\n");
                tbl->action = IWL_MIMO2_SWITCH_SISO_A;
+       }
 
        start_action = tbl->action;
        while (1) {
@@ -1721,8 +1720,6 @@ static void rs_rate_scale_perform(struct iwl_mvm *mvm,
        struct iwl_mvm_sta *sta_priv = (void *)sta->drv_priv;
        struct iwl_mvm_tid_data *tid_data;
 
-       IWL_DEBUG_RATE(mvm, "rate scale calculate new rate for skb\n");
-
        /* Send management frames and NO_ACK data using lowest rate. */
        /* TODO: this could probably be improved.. */
        if (!ieee80211_is_data(hdr->frame_control) ||
@@ -1758,14 +1755,9 @@ static void rs_rate_scale_perform(struct iwl_mvm *mvm,
        /* current tx rate */
        index = lq_sta->last_txrate_idx;
 
-       IWL_DEBUG_RATE(mvm, "Rate scale index %d for type %d\n", index,
-                      tbl->lq_type);
-
        /* rates available for this association, and for modulation mode */
        rate_mask = rs_get_supported_rates(lq_sta, hdr, tbl->lq_type);
 
-       IWL_DEBUG_RATE(mvm, "mask 0x%04X\n", rate_mask);
-
        /* mask with station rate restriction */
        if (is_legacy(tbl->lq_type)) {
                if (lq_sta->band == IEEE80211_BAND_5GHZ)
@@ -1809,6 +1801,9 @@ static void rs_rate_scale_perform(struct iwl_mvm *mvm,
                index = lq_sta->max_rate_idx;
                update_lq = 1;
                window = &(tbl->win[index]);
+               IWL_DEBUG_RATE(mvm,
+                              "Forcing user max rate %d\n",
+                              index);
                goto lq_update;
        }
 
@@ -1825,8 +1820,9 @@ static void rs_rate_scale_perform(struct iwl_mvm *mvm,
        if ((fail_count < IWL_RATE_MIN_FAILURE_TH) &&
            (window->success_counter < IWL_RATE_MIN_SUCCESS_TH)) {
                IWL_DEBUG_RATE(mvm,
-                              "LQ: still below TH. succ=%d total=%d for index %d\n",
-                              window->success_counter, window->counter, index);
+                              "(%s: %d): Test Window: succ %d total %d\n",
+                              rs_pretty_lq_type(tbl->lq_type),
+                              index, window->success_counter, window->counter);
 
                /* Can't calculate this yet; not enough history */
                window->average_tpt = IWL_INVALID_VALUE;
@@ -1854,7 +1850,8 @@ static void rs_rate_scale_perform(struct iwl_mvm *mvm,
                 * continuing to use the setup that we've been trying. */
                if (window->average_tpt > lq_sta->last_tpt) {
                        IWL_DEBUG_RATE(mvm,
-                                      "LQ: SWITCHING TO NEW TABLE suc=%d cur-tpt=%d old-tpt=%d\n",
+                                      "SWITCHING TO NEW TABLE SR: %d "
+                                      "cur-tpt %d old-tpt %d\n",
                                       window->success_ratio,
                                       window->average_tpt,
                                       lq_sta->last_tpt);
@@ -1868,7 +1865,8 @@ static void rs_rate_scale_perform(struct iwl_mvm *mvm,
                /* Else poor success; go back to mode in "active" table */
                } else {
                        IWL_DEBUG_RATE(mvm,
-                                      "LQ: GOING BACK TO THE OLD TABLE suc=%d cur-tpt=%d old-tpt=%d\n",
+                                      "GOING BACK TO THE OLD TABLE: SR %d "
+                                      "cur-tpt %d old-tpt %d\n",
                                       window->success_ratio,
                                       window->average_tpt,
                                       lq_sta->last_tpt);
@@ -1916,20 +1914,31 @@ static void rs_rate_scale_perform(struct iwl_mvm *mvm,
        if (high != IWL_RATE_INVALID)
                high_tpt = tbl->win[high].average_tpt;
 
+       IWL_DEBUG_RATE(mvm,
+                      "(%s: %d): cur_tpt %d SR %d low %d high %d low_tpt %d high_tpt %d\n",
+                      rs_pretty_lq_type(tbl->lq_type), index, current_tpt,
+                      sr, low, high, low_tpt, high_tpt);
+
        scale_action = 0;
 
        /* Too many failures, decrease rate */
        if ((sr <= IWL_RATE_DECREASE_TH) || (current_tpt == 0)) {
                IWL_DEBUG_RATE(mvm,
-                              "decrease rate because of low success_ratio\n");
+                              "decrease rate because of low SR\n");
                scale_action = -1;
        /* No throughput measured yet for adjacent rates; try increase. */
        } else if ((low_tpt == IWL_INVALID_VALUE) &&
                   (high_tpt == IWL_INVALID_VALUE)) {
-               if (high != IWL_RATE_INVALID && sr >= IWL_RATE_INCREASE_TH)
+               if (high != IWL_RATE_INVALID && sr >= IWL_RATE_INCREASE_TH) {
+                       IWL_DEBUG_RATE(mvm,
+                                      "Good SR and no high rate measurement. "
+                                      "Increase rate\n");
                        scale_action = 1;
-               else if (low != IWL_RATE_INVALID)
+               } else if (low != IWL_RATE_INVALID) {
+                       IWL_DEBUG_RATE(mvm,
+                                      "Remain in current rate\n");
                        scale_action = 0;
+               }
        }
 
        /* Both adjacent throughputs are measured, but neither one has better
@@ -1937,8 +1946,12 @@ static void rs_rate_scale_perform(struct iwl_mvm *mvm,
        else if ((low_tpt != IWL_INVALID_VALUE) &&
                 (high_tpt != IWL_INVALID_VALUE) &&
                 (low_tpt < current_tpt) &&
-                (high_tpt < current_tpt))
+                (high_tpt < current_tpt)) {
+               IWL_DEBUG_RATE(mvm,
+                              "Both high and low are worse. "
+                              "Maintain rate\n");
                scale_action = 0;
+       }
 
        /* At least one adjacent rate's throughput is measured,
         * and may have better performance. */
@@ -1948,8 +1961,14 @@ static void rs_rate_scale_perform(struct iwl_mvm *mvm,
                        /* Higher rate has better throughput */
                        if (high_tpt > current_tpt &&
                            sr >= IWL_RATE_INCREASE_TH) {
+                               IWL_DEBUG_RATE(mvm,
+                                              "Higher rate is better and good "
+                                              "SR. Increate rate\n");
                                scale_action = 1;
                        } else {
+                               IWL_DEBUG_RATE(mvm,
+                                              "Higher rate isn't better OR "
+                                              "no good SR. Maintain rate\n");
                                scale_action = 0;
                        }
 
@@ -1958,9 +1977,13 @@ static void rs_rate_scale_perform(struct iwl_mvm *mvm,
                        /* Lower rate has better throughput */
                        if (low_tpt > current_tpt) {
                                IWL_DEBUG_RATE(mvm,
-                                              "decrease rate because of low tpt\n");
+                                              "Lower rate is better. "
+                                              "Decrease rate\n");
                                scale_action = -1;
                        } else if (sr >= IWL_RATE_INCREASE_TH) {
+                               IWL_DEBUG_RATE(mvm,
+                                              "Lower rate isn't better and "
+                                              "good SR. Increase rate\n");
                                scale_action = 1;
                        }
                }
@@ -1970,12 +1993,17 @@ static void rs_rate_scale_perform(struct iwl_mvm *mvm,
         * has been good at old rate.  Don't change it. */
        if ((scale_action == -1) && (low != IWL_RATE_INVALID) &&
            ((sr > IWL_RATE_HIGH_TH) ||
-            (current_tpt > (100 * tbl->expected_tpt[low]))))
+            (current_tpt > (100 * tbl->expected_tpt[low])))) {
+               IWL_DEBUG_RATE(mvm,
+                              "Sanity check failed. Maintain rate\n");
                scale_action = 0;
+       }
 
        /* Force a search in case BT doesn't like us being in MIMO */
        if (is_mimo(tbl->lq_type) &&
            !iwl_mvm_bt_coex_is_mimo_allowed(mvm, sta)) {
+               IWL_DEBUG_RATE(mvm,
+                              "BT Coex forbids MIMO. Search for new config\n");
                rs_stay_in_table(lq_sta, true);
                goto lq_update;
        }
@@ -1986,6 +2014,9 @@ static void rs_rate_scale_perform(struct iwl_mvm *mvm,
                if (low != IWL_RATE_INVALID) {
                        update_lq = 1;
                        index = low;
+               } else {
+                       IWL_DEBUG_RATE(mvm,
+                                      "At the bottom rate. Can't decrease\n");
                }
 
                break;
@@ -1994,6 +2025,9 @@ static void rs_rate_scale_perform(struct iwl_mvm *mvm,
                if (high != IWL_RATE_INVALID) {
                        update_lq = 1;
                        index = high;
+               } else {
+                       IWL_DEBUG_RATE(mvm,
+                                      "At the top rate. Can't increase\n");
                }
 
                break;
@@ -2003,10 +2037,6 @@ static void rs_rate_scale_perform(struct iwl_mvm *mvm,
                break;
        }
 
-       IWL_DEBUG_RATE(mvm,
-                      "choose rate scale index %d action %d low %d high %d type %d\n",
-                      index, scale_action, low, high, tbl->lq_type);
-
 lq_update:
        /* Replace uCode's rate table for the destination station. */
        if (update_lq)
@@ -2025,6 +2055,10 @@ lq_update:
                /* Save current throughput to compare with "search" throughput*/
                lq_sta->last_tpt = current_tpt;
 
+               IWL_DEBUG_RATE(mvm,
+                              "Start Search: update_lq %d done_search %d stay_in_tbl %d win->counter %d\n",
+                              update_lq, done_search, lq_sta->stay_in_tbl,
+                              window->counter);
                /* Select a new "search" modulation mode to try.
                 * If one is found, set up the new "search" table. */
                if (is_legacy(tbl->lq_type))
@@ -2047,8 +2081,11 @@ lq_update:
                        index = iwl_hwrate_to_plcp_idx(tbl->current_rate);
 
                        IWL_DEBUG_RATE(mvm,
-                                      "Switch current  mcs: %X index: %d\n",
-                                      tbl->current_rate, index);
+                                      "Switch to SEARCH TABLE: "
+                                      "mcs %X (%s: %d)\n",
+                                      tbl->current_rate,
+                                      rs_pretty_lq_type(tbl->lq_type),
+                                      index);
                        rs_fill_link_cmd(mvm, sta, lq_sta, tbl->current_rate);
                        iwl_mvm_send_lq_cmd(mvm, &lq_sta->lq, false);
                } else {
@@ -2169,8 +2206,6 @@ static void rs_get_rate(void *mvm_r, struct ieee80211_sta *sta, void *mvm_sta,
        struct ieee80211_tx_info *info = IEEE80211_SKB_CB(skb);
        struct iwl_lq_sta *lq_sta = mvm_sta;
 
-       IWL_DEBUG_RATE_LIMIT(mvm, "rate scale calculate new rate for skb\n");
-
        /* Get max rate if user set max rate */
        if (lq_sta) {
                lq_sta->max_rate_idx = txrc->max_rate_idx;
@@ -2554,7 +2589,6 @@ static void rs_dbgfs_set_mcs(struct iwl_lq_sta *lq_sta,
                  >> RATE_MCS_ANT_POS);
                if ((valid_tx_ant & ant_sel_tx) == ant_sel_tx) {
                        *rate_n_flags = lq_sta->dbg_fixed_rate;
-                       IWL_DEBUG_RATE(mvm, "Fixed rate ON\n");
                } else {
                        lq_sta->dbg_fixed_rate = 0;
                        IWL_ERR(mvm,
@@ -2562,8 +2596,6 @@ static void rs_dbgfs_set_mcs(struct iwl_lq_sta *lq_sta,
                                ant_sel_tx, valid_tx_ant);
                        IWL_DEBUG_RATE(mvm, "Fixed rate OFF\n");
                }
-       } else {
-               IWL_DEBUG_RATE(mvm, "Fixed rate OFF\n");
        }
 }
 
@@ -2593,6 +2625,24 @@ static ssize_t rs_sta_dbgfs_scale_table_write(struct file *file,
        return count;
 }
 
+static const char *rs_pretty_lq_type(enum iwl_table_type type)
+{
+       static const char * const lq_type[] = {
+               [LQ_NONE] = "NONE",
+               [LQ_LEGACY_A] = "LEGACY_A",
+               [LQ_LEGACY_G] = "LEGACY_G",
+               [LQ_HT_SISO] = "HT SISO",
+               [LQ_HT_MIMO2] = "HT MIMO",
+               [LQ_VHT_SISO] = "VHT SISO",
+               [LQ_VHT_MIMO2] = "VHT MIMO",
+       };
+
+       if (type < LQ_NONE || type >= LQ_MAX)
+               return "UNKNOWN";
+
+       return lq_type[type];
+}
+
 static int rs_pretty_print_rate(char *buf, const u32 rate)
 {
        static const char * const ant_name[] = {