by Maya Erez

[permalink] [raw]

Subject: [PATCH 03/20] wil6210: add TX latency statistics

From: Dedy Lansky <[email protected]>

Collect statistics of TX latency. The latency is measured from the time
the HW gets aware of new SKB to transmit until the HW indicates tx
complete for this SKB.
The statistics are shown via new "tx_latency" debugfs.

Signed-off-by: Dedy Lansky <[email protected]>
Signed-off-by: Maya Erez <[email protected]>
---
drivers/net/wireless/ath/wil6210/debugfs.c | 125 +++++++++++++++++++++++++++
drivers/net/wireless/ath/wil6210/main.c | 1 +
drivers/net/wireless/ath/wil6210/txrx.c | 38 ++++++++
drivers/net/wireless/ath/wil6210/txrx.h | 2 +
drivers/net/wireless/ath/wil6210/txrx_edma.c | 8 ++
drivers/net/wireless/ath/wil6210/wil6210.h | 14 +++
6 files changed, 188 insertions(+)

diff --git a/drivers/net/wireless/ath/wil6210/debugfs.c b/drivers/net/wireless/ath/wil6210/debugfs.c
index 99b1fc5..5d1e48d 100644
--- a/drivers/net/wireless/ath/wil6210/debugfs.c
+++ b/drivers/net/wireless/ath/wil6210/debugfs.c
@@ -1800,6 +1800,126 @@ static int wil_mids_seq_open(struct inode *inode, struct file *file)
.llseek = seq_lseek,
};

+static int wil_tx_latency_debugfs_show(struct seq_file *s, void *data)
+__acquires(&p->tid_rx_lock) __releases(&p->tid_rx_lock)
+{
+ struct wil6210_priv *wil = s->private;
+ int i, bin;
+
+ for (i = 0; i < ARRAY_SIZE(wil->sta); i++) {
+ struct wil_sta_info *p = &wil->sta[i];
+ char *status = "unknown";
+ u8 aid = 0;
+ u8 mid;
+
+ if (!p->tx_latency_bins)
+ continue;
+
+ switch (p->status) {
+ case wil_sta_unused:
+ status = "unused ";
+ break;
+ case wil_sta_conn_pending:
+ status = "pending ";
+ break;
+ case wil_sta_connected:
+ status = "connected";
+ aid = p->aid;
+ break;
+ }
+ mid = (p->status != wil_sta_unused) ? p->mid : U8_MAX;
+ seq_printf(s, "[%d] %pM %s MID %d AID %d\n", i, p->addr, status,
+ mid, aid);
+
+ if (p->status == wil_sta_connected) {
+ u64 num_packets = 0;
+ u64 tx_latency_avg = p->stats.tx_latency_total_us;
+
+ seq_puts(s, "Tx/Latency bin:");
+ for (bin = 0; bin < WIL_NUM_LATENCY_BINS; bin++) {
+ seq_printf(s, " %lld",
+ p->tx_latency_bins[bin]);
+ num_packets += p->tx_latency_bins[bin];
+ }
+ seq_puts(s, "\n");
+ if (!num_packets)
+ continue;
+ do_div(tx_latency_avg, num_packets);
+ seq_printf(s, "Tx/Latency min/avg/max (us): %d/%lld/%d",
+ p->stats.tx_latency_min_us,
+ tx_latency_avg,
+ p->stats.tx_latency_max_us);
+
+ seq_puts(s, "\n");
+ }
+ }
+
+ return 0;
+}
+
+static int wil_tx_latency_seq_open(struct inode *inode, struct file *file)
+{
+ return single_open(file, wil_tx_latency_debugfs_show,
+ inode->i_private);
+}
+
+static ssize_t wil_tx_latency_write(struct file *file, const char __user *buf,
+ size_t len, loff_t *ppos)
+{
+ struct seq_file *s = file->private_data;
+ struct wil6210_priv *wil = s->private;
+ int val, rc, i;
+ bool enable;
+
+ rc = kstrtoint_from_user(buf, len, 0, &val);
+ if (rc) {
+ wil_err(wil, "Invalid argument\n");
+ return rc;
+ }
+ if (val == 1)
+ /* default resolution */
+ val = 500;
+ if (val && (val < 50 || val > 1000)) {
+ wil_err(wil, "Invalid resolution %d\n", val);
+ return -EINVAL;
+ }
+
+ enable = !!val;
+ if (wil->tx_latency == enable)
+ return len;
+
+ wil_info(wil, "%s TX latency measurements (resolution %dusec)\n",
+ enable ? "Enabling" : "Disabling", val);
+
+ if (enable) {
+ size_t sz = sizeof(u64) * WIL_NUM_LATENCY_BINS;
+
+ wil->tx_latency_res = val;
+ for (i = 0; i < ARRAY_SIZE(wil->sta); i++) {
+ struct wil_sta_info *sta = &wil->sta[i];
+
+ kfree(sta->tx_latency_bins);
+ sta->tx_latency_bins = kzalloc(sz, GFP_KERNEL);
+ if (!sta->tx_latency_bins)
+ return -ENOMEM;
+ sta->stats.tx_latency_min_us = U32_MAX;
+ sta->stats.tx_latency_max_us = 0;
+ sta->stats.tx_latency_total_us = 0;
+ }
+ }
+ wil->tx_latency = enable;
+
+ return len;
+}
+
+static const struct file_operations fops_tx_latency = {
+ .open = wil_tx_latency_seq_open,
+ .release = single_release,
+ .read = seq_read,
+ .write = wil_tx_latency_write,
+ .llseek = seq_lseek,
+};
+
static ssize_t wil_read_file_led_cfg(struct file *file, char __user *user_buf,
size_t count, loff_t *ppos)
{
@@ -2133,6 +2253,7 @@ static void wil6210_debugfs_init_blobs(struct wil6210_priv *wil,
{"srings", 0444, &fops_srings},
{"status_msg", 0444, &fops_status_msg},
{"rx_buff_mgmt", 0444, &fops_rx_buff_mgmt},
+ {"tx_latency", 0644, &fops_tx_latency},
};

static void wil6210_debugfs_init_files(struct wil6210_priv *wil,
@@ -2249,10 +2370,14 @@ int wil6210_debugfs_init(struct wil6210_priv *wil)

void wil6210_debugfs_remove(struct wil6210_priv *wil)
{
+ int i;
+
debugfs_remove_recursive(wil->debug);
wil->debug = NULL;

kfree(wil->dbg_data.data_arr);
+ for (i = 0; i < ARRAY_SIZE(wil->sta); i++)
+ kfree(wil->sta[i].tx_latency_bins);

/* free pmc memory without sending command to fw, as it will
* be reset on the way down anyway
diff --git a/drivers/net/wireless/ath/wil6210/main.c b/drivers/net/wireless/ath/wil6210/main.c
index 4de19bd..7e4ccd9 100644
--- a/drivers/net/wireless/ath/wil6210/main.c
+++ b/drivers/net/wireless/ath/wil6210/main.c
@@ -278,6 +278,7 @@ static void wil_disconnect_cid(struct wil6210_vif *vif, int cid,
}
/* statistics */
memset(&sta->stats, 0, sizeof(sta->stats));
+ sta->stats.tx_latency_min_us = U32_MAX;
}

static bool wil_vif_is_connected(struct wil6210_priv *wil, u8 mid)
diff --git a/drivers/net/wireless/ath/wil6210/txrx.c b/drivers/net/wireless/ath/wil6210/txrx.c
index 9ac8674..6707af6 100644
--- a/drivers/net/wireless/ath/wil6210/txrx.c
+++ b/drivers/net/wireless/ath/wil6210/txrx.c
@@ -1693,6 +1693,11 @@ static int __wil_tx_vring_tso(struct wil6210_priv *wil, struct wil6210_vif *vif,
*/
wmb();

+ if (wil->tx_latency)
+ *(ktime_t *)&skb->cb = ktime_get();
+ else
+ memset(skb->cb, 0, sizeof(ktime_t));
+
wil_w(wil, vring->hwtail, vring->swhead);
return 0;

@@ -1844,6 +1849,11 @@ static int __wil_tx_ring(struct wil6210_priv *wil, struct wil6210_vif *vif,
*/
wmb();

+ if (wil->tx_latency)
+ *(ktime_t *)&skb->cb = ktime_get();
+ else
+ memset(skb->cb, 0, sizeof(ktime_t));
+
wil_w(wil, ring->hwtail, ring->swhead);

return 0;
@@ -2065,6 +2075,31 @@ netdev_tx_t wil_start_xmit(struct sk_buff *skb, struct net_device *ndev)
return NET_XMIT_DROP;
}

+void wil_tx_latency_calc(struct wil6210_priv *wil, struct sk_buff *skb,
+ struct wil_sta_info *sta)
+{
+ int skb_time_us;
+ int bin;
+
+ if (!wil->tx_latency)
+ return;
+
+ if (ktime_to_ms(*(ktime_t *)&skb->cb) == 0)
+ return;
+
+ skb_time_us = ktime_us_delta(ktime_get(), *(ktime_t *)&skb->cb);
+ bin = skb_time_us / wil->tx_latency_res;
+ bin = min_t(int, bin, WIL_NUM_LATENCY_BINS - 1);
+
+ wil_dbg_txrx(wil, "skb time %dus => bin %d\n", skb_time_us, bin);
+ sta->tx_latency_bins[bin]++;
+ sta->stats.tx_latency_total_us += skb_time_us;
+ if (skb_time_us < sta->stats.tx_latency_min_us)
+ sta->stats.tx_latency_min_us = skb_time_us;
+ if (skb_time_us > sta->stats.tx_latency_max_us)
+ sta->stats.tx_latency_max_us = skb_time_us;
+}
+
/**
* Clean up transmitted skb's from the Tx VRING
*
@@ -2151,6 +2186,9 @@ int wil_tx_complete(struct wil6210_vif *vif, int ringid)
if (stats) {
stats->tx_packets++;
stats->tx_bytes += skb->len;
+
+ wil_tx_latency_calc(wil, skb,
+ &wil->sta[cid]);
}
} else {
ndev->stats.tx_errors++;
diff --git a/drivers/net/wireless/ath/wil6210/txrx.h b/drivers/net/wireless/ath/wil6210/txrx.h
index 3dfd7f9..9d83be4 100644
--- a/drivers/net/wireless/ath/wil6210/txrx.h
+++ b/drivers/net/wireless/ath/wil6210/txrx.h
@@ -620,5 +620,7 @@ void wil_tid_ampdu_rx_free(struct wil6210_priv *wil,
struct wil_tid_ampdu_rx *r);
void wil_tx_data_init(struct wil_ring_tx_data *txdata);
void wil_init_txrx_ops_legacy_dma(struct wil6210_priv *wil);
+void wil_tx_latency_calc(struct wil6210_priv *wil, struct sk_buff *skb,
+ struct wil_sta_info *sta);

#endif /* WIL6210_TXRX_H */
diff --git a/drivers/net/wireless/ath/wil6210/txrx_edma.c b/drivers/net/wireless/ath/wil6210/txrx_edma.c
index b5d399f..2ea9767 100644
--- a/drivers/net/wireless/ath/wil6210/txrx_edma.c
+++ b/drivers/net/wireless/ath/wil6210/txrx_edma.c
@@ -1217,6 +1217,9 @@ int wil_tx_sring_handler(struct wil6210_priv *wil,
if (stats) {
stats->tx_packets++;
stats->tx_bytes += skb->len;
+
+ wil_tx_latency_calc(wil, skb,
+ &wil->sta[cid]);
}
} else {
ndev->stats.tx_errors++;
@@ -1467,6 +1470,11 @@ static int __wil_tx_ring_tso_edma(struct wil6210_priv *wil,
*/
wmb();

+ if (wil->tx_latency)
+ *(ktime_t *)&skb->cb = ktime_get();
+ else
+ memset(skb->cb, 0, sizeof(ktime_t));
+
wil_w(wil, ring->hwtail, ring->swhead);

return 0;
diff --git a/drivers/net/wireless/ath/wil6210/wil6210.h b/drivers/net/wireless/ath/wil6210/wil6210.h
index 002d336..1a7a1ad 100644
--- a/drivers/net/wireless/ath/wil6210/wil6210.h
+++ b/drivers/net/wireless/ath/wil6210/wil6210.h
@@ -55,6 +55,8 @@
#define WIL_DEFAULT_BUS_REQUEST_KBPS 128000 /* ~1Gbps */
#define WIL_MAX_BUS_REQUEST_KBPS 800000 /* ~6.1Gbps */

+#define WIL_NUM_LATENCY_BINS 200
+
/* maximum number of virtual interfaces the driver supports
* (including the main interface)
*/
@@ -552,6 +554,9 @@ struct wil_net_stats {
unsigned long rx_bytes;
unsigned long tx_bytes;
unsigned long tx_errors;
+ u32 tx_latency_min_us;
+ u32 tx_latency_max_us;
+ u64 tx_latency_total_us;
unsigned long rx_dropped;
unsigned long rx_non_data_frame;
unsigned long rx_short_frame;
@@ -712,6 +717,13 @@ struct wil_sta_info {
u8 mid;
enum wil_sta_status status;
struct wil_net_stats stats;
+ /**
+ * 20 latency bins. 1st bin counts packets with latency
+ * of 0..tx_latency_res, last bin counts packets with latency
+ * of 19*tx_latency_res and above.
+ * tx_latency_res is configured from "tx_latency" debug-fs.
+ */
+ u64 *tx_latency_bins;
/* Rx BACK */
struct wil_tid_ampdu_rx *tid_rx[WIL_STA_TID_NUM];
spinlock_t tid_rx_lock; /* guarding tid_rx array */
@@ -943,6 +955,8 @@ struct wil6210_priv {
u8 wakeup_trigger;
struct wil_suspend_stats suspend_stats;
struct wil_debugfs_data dbg_data;
+ bool tx_latency; /* collect TX latency measurements */
+ size_t tx_latency_res; /* bin resolution in usec */

void *platform_handle;
struct wil_platform_ops platform_ops;
--
1.9.1