mlxcx: add tx latency timers with DEBUG

Author: arekinath

usr/src/uts/common/io/mlxcx/mlxcx.h

@@ -246,6 +246,21 @@ extern uint_t mlxcx_stuck_intr_count;
  */
 #define	MLXCX_FUNC_ID_MAX	0
 
+#if defined(DEBUG)
+#define	MLXCX_PERF_TIMERS
+#endif
+
+#if defined(MLXCX_PERF_TIMERS)
+static inline void
+mlxcx_ptimer(hrtime_t *arr, uint idx)
+{
+	arr[idx] = gethrtime();
+}
+#define	MLXCX_PTIMER(A, I)	mlxcx_ptimer(A, I)
+#else
+#define	MLXCX_PTIMER(A, I)
+#endif
+
 /*
  * Forwards
  */
@@ -547,6 +562,25 @@ typedef struct mlxcx_buf_shard {
 	kcondvar_t		mlbs_free_nonempty;
 } mlxcx_buf_shard_t;
 
+typedef enum {
+	MLXCX_BUF_TIMER_PRE_RING_TX,
+	MLXCX_BUF_TIMER_POST_OFFLOAD_INFO,
+	MLXCX_BUF_TIMER_POST_INLINE_BCOPY,
+	MLXCX_BUF_TIMER_POST_BUF_BIND_COPY,
+	MLXCX_BUF_TIMER_POST_SQE_BUF,
+	MLXCX_BUF_TIMER_POST_PREPARE_SQE_INLINE,
+	MLXCX_BUF_TIMER_POST_PREPARE_SQE,
+	MLXCX_BUF_TIMER_POST_WQ_MTX,
+	MLXCX_BUF_TIMER_POST_SQE_IN_RING,
+	MLXCX_BUF_TIMER_POST_SQ_ADD_BUF,
+	MLXCX_BUF_TIMER_PRE_TX_COMP,
+	MLXCX_BUF_TIMER_PRE_STEP2,
+	MLXCX_BUF_TIMER_COPY_TOTAL,
+	MLXCX_BUF_TIMER_TAKE_FOREIGN_TOTAL,
+	MLXCX_BUF_TIMER_BIND_MBLK_TOTAL,
+	MLXCX_BUF_TIMER_MAX
+} mlxcx_buf_timer_t;
+
 typedef struct mlxcx_buffer {
 	mlxcx_buf_shard_t	*mlb_shard;
 	list_node_t		mlb_entry;
@@ -579,6 +613,10 @@ typedef struct mlxcx_buffer {
 	};
 	size_t			mlb_sqe_size;
 	uint_t			mlb_sqe_count;
+
+#if defined(MLXCX_PERF_TIMERS)
+	hrtime_t		mlb_t[MLXCX_BUF_TIMER_MAX];
+#endif
 } mlxcx_buffer_t;
 
 typedef enum {

usr/src/uts/common/io/mlxcx/mlxcx_gld.c

@@ -634,9 +634,18 @@ mlxcx_mac_ring_tx(void *arg, mblk_t *mp)
 	size_t take = 0;
 	uint_t bcount;
 	mlxcx_tx_ctx_t ctx;
+#if defined(MLXCX_PERF_TIMERS)
+	hrtime_t times[MLXCX_BUF_TIMER_MAX];
+	uint i;
+#endif
 
 	VERIFY(mp->b_next == NULL);
 
+#if defined(MLXCX_PERF_TIMERS)
+	bzero(times, sizeof (times));
+	times[MLXCX_BUF_TIMER_PRE_RING_TX] = gethrtime();
+#endif
+
 	mac_hcksum_get(mp, NULL, NULL, NULL, NULL, &ctx.mtc_chkflags);
 	mac_lso_get(mp, &ctx.mtc_mss, &ctx.mtc_lsoflags);
 
@@ -653,6 +662,10 @@ mlxcx_mac_ring_tx(void *arg, mblk_t *mp)
 		return (NULL);
 	}
 
+#if defined(MLXCX_PERF_TIMERS)
+	times[MLXCX_BUF_TIMER_POST_OFFLOAD_INFO] = gethrtime();
+#endif
+
 	ctx.mtc_inline_hdrlen = meoi.meoi_l2hlen;
 
 	/*
@@ -698,23 +711,37 @@ mlxcx_mac_ring_tx(void *arg, mblk_t *mp)
 		}
 	}
 
+	MLXCX_PTIMER(times, MLXCX_BUF_TIMER_POST_INLINE_BCOPY);
+
 	bcount = mlxcx_buf_bind_or_copy(mlxp, sq, mp, kmp, take, &b);
 	if (bcount == 0) {
 		atomic_or_uint(&sq->mlwq_state, MLXCX_WQ_BLOCKED_MAC);
 		return (mp);
 	}
 
+	MLXCX_PTIMER(times, MLXCX_BUF_TIMER_POST_BUF_BIND_COPY);
+
+#if defined(MLXCX_PERF_TIMERS)
+	/* Copy our temporary timers over to the buffer_t */
+	for (i = 0; i <= MLXCX_BUF_TIMER_POST_BUF_BIND_COPY; ++i)
+		b->mlb_t[i] = times[i];
+#endif
+
 	if (!mlxcx_buf_prepare_sqe(mlxp, sq, b, &ctx)) {
 		mlxcx_warn(mlxp, "!tried to tx packet that couldn't fit in "
 		    "an SQE, dropping");
 		freemsg(mp);
 		return (NULL);
 	}
 
+	MLXCX_PTIMER(b->mlb_t, MLXCX_BUF_TIMER_POST_PREPARE_SQE);
+
 	mutex_enter(&sq->mlwq_mtx);
 	VERIFY3U(sq->mlwq_inline_mode, <=, MLXCX_ETH_INLINE_L2);
 	cq = sq->mlwq_cq;
 
+	MLXCX_PTIMER(b->mlb_t, MLXCX_BUF_TIMER_POST_WQ_MTX);
+
 	/*
 	 * state is a single int, so read-only access without the CQ lock
 	 * should be fine.
@@ -756,6 +783,7 @@ mlxcx_mac_ring_tx(void *arg, mblk_t *mp)
 	}
 
 	mutex_exit(&sq->mlwq_mtx);
+	MLXCX_PTIMER(b->mlb_t, MLXCX_BUF_TIMER_POST_SQ_ADD_BUF);
 
 	return (NULL);
 

usr/src/uts/common/io/mlxcx/mlxcx_intr.c

@@ -981,6 +981,8 @@ mlxcx_process_cq(mlxcx_t *mlxp, mlxcx_completion_queue_t *mlcq, mblk_t **mpp,
 		list_remove(&mlcq->mlcq_buffers, buf);
 		bufcnt++;
 
+		MLXCX_PTIMER(buf->mlb_t, MLXCX_BUF_TIMER_PRE_TX_COMP);
+
 		switch (mlcq->mlcq_wq->mlwq_type) {
 		case MLXCX_WQ_TYPE_SENDQ:
 			mlxcx_tx_completion(mlxp, mlcq, cent, buf, &rbatch);

usr/src/uts/common/io/mlxcx/mlxcx_ring.c

@@ -1674,6 +1674,8 @@ mlxcx_sq_add_buffer(mlxcx_t *mlxp, mlxcx_work_queue_t *mlwq,
 		return (B_FALSE);
 	}
 
+	MLXCX_PTIMER(b0->mlb_t, MLXCX_BUF_TIMER_POST_SQE_IN_RING);
+
 	/*
 	 * Stash the bufbgen counter, which is incremented every time
 	 * buffers_b is merged into buffers. This lets us easily tell which
@@ -2285,6 +2287,11 @@ mlxcx_bind_or_copy_mblk(mlxcx_t *mlxp, mlxcx_work_queue_t *wq,
 	size_t sz;
 	boolean_t ret;
 
+#if defined(MLXCX_PERF_TIMERS)
+	hrtime_t t0, t1;
+	t0 = gethrtime();
+#endif
+
 	rptr = mp->b_rptr;
 	sz = MBLKL(mp);
 
@@ -2299,17 +2306,37 @@ mlxcx_bind_or_copy_mblk(mlxcx_t *mlxp, mlxcx_work_queue_t *wq,
 
 	if (sz < mlxp->mlx_props.mldp_tx_bind_threshold) {
 		b = mlxcx_copy_data(mlxp, wq, rptr, sz);
+#if defined(MLXCX_PERF_TIMERS)
+		t1 = gethrtime();
+		b->mlb_t[MLXCX_BUF_TIMER_COPY_TOTAL] += t1 - t0;
+#endif
 	} else {
 		b = mlxcx_buf_take_foreign(mlxp, wq);
 		if (b == NULL)
 			return (NULL);
+#if defined(MLXCX_PERF_TIMERS)
+		t1 = gethrtime();
+		b->mlb_t[MLXCX_BUF_TIMER_TAKE_FOREIGN_TOTAL] += t1 - t0;
+		t0 = t1;
+#endif
 
 		ret = mlxcx_dma_bind_mblk(mlxp, &b->mlb_dma, mp, off, B_TRUE);
 
+#if defined(MLXCX_PERF_TIMERS)
+		t1 = gethrtime();
+		b->mlb_t[MLXCX_BUF_TIMER_BIND_MBLK_TOTAL] += t1 - t0;
+		t0 = t1;
+#endif
+
 		if (!ret) {
 			mlxcx_buf_return(mlxp, b);
 
 			b = mlxcx_copy_data(mlxp, wq, rptr, sz);
+
+#if defined(MLXCX_PERF_TIMERS)
+			t1 = gethrtime();
+			b->mlb_t[MLXCX_BUF_TIMER_COPY_TOTAL] += t1 - t0;
+#endif
 		}
 	}
 
@@ -2338,6 +2365,8 @@ mlxcx_buf_prepare_sqe(mlxcx_t *mlxp, mlxcx_work_queue_t *mlwq,
 		b0->mlb_sqe = kmem_zalloc(b0->mlb_sqe_size, KM_SLEEP);
 	}
 
+	MLXCX_PTIMER(b0->mlb_t, MLXCX_BUF_TIMER_POST_SQE_BUF);
+
 	ents = 1;
 	ent0 = &b0->mlb_sqe[0];
 
@@ -2418,6 +2447,8 @@ mlxcx_buf_prepare_sqe(mlxcx_t *mlxp, mlxcx_work_queue_t *mlwq,
 		ent0->mlsqe_eth.mles_mss = to_be16(ctx->mtc_mss);
 	}
 
+	MLXCX_PTIMER(b0->mlb_t, MLXCX_BUF_TIMER_POST_PREPARE_SQE_INLINE);
+
 	b = b0;
 	while (b != NULL) {
 		rem = b->mlb_used;
@@ -2502,8 +2533,17 @@ mlxcx_buf_bind_or_copy(mlxcx_t *mlxp, mlxcx_work_queue_t *wq,
 		b->mlb_tx_head = b0;
 		b->mlb_used = MBLKL(mp) - offset;
 
-		if (!first)
+		if (!first) {
 			list_insert_tail(&b0->mlb_tx_chain, b);
+#if defined(MLXCX_PERF_TIMERS)
+			b0->mlb_t[MLXCX_BUF_TIMER_COPY_TOTAL] +=
+			    b->mlb_t[MLXCX_BUF_TIMER_COPY_TOTAL];
+			b0->mlb_t[MLXCX_BUF_TIMER_TAKE_FOREIGN_TOTAL] +=
+			    b->mlb_t[MLXCX_BUF_TIMER_TAKE_FOREIGN_TOTAL];
+			b0->mlb_t[MLXCX_BUF_TIMER_BIND_MBLK_TOTAL] +=
+			    b->mlb_t[MLXCX_BUF_TIMER_BIND_MBLK_TOTAL];
+#endif
+		}
 		first = B_FALSE;
 		offset = 0;
 
@@ -2839,6 +2879,10 @@ mlxcx_buf_return_step2(mlxcx_t *mlxp, mlxcx_buffer_t *b)
 		break;
 	}
 
+#if defined(MLXCX_PERF_TIMERS)
+	bzero(b->mlb_t, sizeof (b->mlb_t));
+#endif
+
 	list_insert_tail(&s->mlbs_free, b);
 	cv_broadcast(&s->mlbs_free_nonempty);
 }
@@ -2858,6 +2902,7 @@ mlxcx_buf_return_batch_flush_shard(mlxcx_t *mlxp,
 	}
 	mutex_enter(&mbrb->mbrb_shard[i]->mlbs_mtx);
 	while ((b = list_remove_head(&mbrb->mbrb_list[i]))) {
+		MLXCX_PTIMER(b->mlb_t, MLXCX_BUF_TIMER_PRE_STEP2);
 		mlxcx_buf_return_step2(mlxp, b);
 	}
 	mutex_exit(&mbrb->mbrb_shard[i]->mlbs_mtx);