Skip site navigation (1)Skip section navigation (2) 
Date:      Fri, 28 Oct 2016 23:53:33 +0000 (UTC)
From:      "Conrad E. Meyer" <cem@FreeBSD.org>
To:        src-committers@freebsd.org, svn-src-all@freebsd.org, svn-src-head@freebsd.org
Subject:   svn commit: r308067 - head/sys/dev/ioat
Message-ID:  <201610282353.u9SNrX2j094266@repo.freebsd.org>
next in thread | raw e-mail | index | archive | help 
Author: cem
Date: Fri Oct 28 23:53:33 2016
New Revision: 308067
URL: https://svnweb.freebsd.org/changeset/base/308067

Log:
  ioat(4): Add additional tracing
  
  These probes help track down driver bugs.
  
  Sponsored by:	Dell EMC Isilon

Modified:
  head/sys/dev/ioat/ioat.c

Modified: head/sys/dev/ioat/ioat.c
==============================================================================
--- head/sys/dev/ioat/ioat.c	Fri Oct 28 23:01:11 2016	(r308066)
+++ head/sys/dev/ioat/ioat.c	Fri Oct 28 23:53:33 2016	(r308067)
@@ -693,8 +693,8 @@ ioat_process_events(struct ioat_softc *i
 	while (desc->hw_desc_bus_addr != status && ioat_get_active(ioat) > 0) {
 		desc = ioat_get_ring_entry(ioat, ioat->tail);
 		dmadesc = &desc->bus_dmadesc;
-		CTR4(KTR_IOAT, "channel=%u completing desc %u ok  cb %p(%p)",
-		    ioat->chan_idx, ioat->tail, dmadesc->callback_fn,
+		CTR5(KTR_IOAT, "channel=%u completing desc idx %u (%p) ok  cb %p(%p)",
+		    ioat->chan_idx, ioat->tail, dmadesc, dmadesc->callback_fn,
 		    dmadesc->callback_arg);
 
 		if (dmadesc->callback_fn != NULL)
@@ -703,6 +703,8 @@ ioat_process_events(struct ioat_softc *i
 		completed++;
 		ioat->tail++;
 	}
+	CTR5(KTR_IOAT, "%s channel=%u head=%u tail=%u active=%u", __func__,
+	    ioat->chan_idx, ioat->head, ioat->tail, ioat_get_active(ioat));
 
 	if (completed != 0) {
 		ioat->last_seen = desc->hw_desc_bus_addr;
@@ -760,8 +762,8 @@ out:
 	while (ioat_get_active(ioat) > 0) {
 		desc = ioat_get_ring_entry(ioat, ioat->tail);
 		dmadesc = &desc->bus_dmadesc;
-		CTR4(KTR_IOAT, "channel=%u completing desc %u err cb %p(%p)",
-		    ioat->chan_idx, ioat->tail, dmadesc->callback_fn,
+		CTR5(KTR_IOAT, "channel=%u completing desc idx %u (%p) err cb %p(%p)",
+		    ioat->chan_idx, ioat->tail, dmadesc, dmadesc->callback_fn,
 		    dmadesc->callback_arg);
 
 		if (dmadesc->callback_fn != NULL)
@@ -773,6 +775,8 @@ out:
 		ioat->stats.descriptors_processed++;
 		ioat->stats.descriptors_error++;
 	}
+	CTR5(KTR_IOAT, "%s channel=%u head=%u tail=%u active=%u", __func__,
+	    ioat->chan_idx, ioat->head, ioat->tail, ioat_get_active(ioat));
 
 	if (ioat->is_completion_pending) {
 		ioat->is_completion_pending = FALSE;
@@ -947,7 +951,8 @@ ioat_release(bus_dmaengine_t dmaengine)
 	struct ioat_softc *ioat;
 
 	ioat = to_ioat_softc(dmaengine);
-	CTR2(KTR_IOAT, "%s channel=%u", __func__, ioat->chan_idx);
+	CTR3(KTR_IOAT, "%s channel=%u dispatch hw_head=%u", __func__,
+	    ioat->chan_idx, ioat->hw_head & UINT16_MAX);
 	ioat_write_2(ioat, IOAT_DMACOUNT_OFFSET, (uint16_t)ioat->hw_head);
 
 	if (!ioat->is_completion_pending) {
@@ -1040,7 +1045,6 @@ ioat_copy(bus_dmaengine_t dmaengine, bus
 	struct ioat_softc *ioat;
 
 	ioat = to_ioat_softc(dmaengine);
-	CTR2(KTR_IOAT, "%s channel=%u", __func__, ioat->chan_idx);
 
 	if (((src | dst) & (0xffffull << 48)) != 0) {
 		ioat_log_message(0, "%s: High 16 bits of src/dst invalid\n",
@@ -1058,6 +1062,8 @@ ioat_copy(bus_dmaengine_t dmaengine, bus
 		dump_descriptor(hw_desc);
 
 	ioat_submit_single(ioat);
+	CTR6(KTR_IOAT, "%s channel=%u desc=%p dest=%lx src=%lx len=%lx",
+	    __func__, ioat->chan_idx, &desc->bus_dmadesc, dst, src, len);
 	return (&desc->bus_dmadesc);
 }
 
@@ -1414,11 +1420,16 @@ ioat_reserve_space(struct ioat_softc *io
 		if (ioat_get_ring_space(ioat) >= num_descs)
 			goto out;
 
+		CTR3(KTR_IOAT, "%s channel=%u starved (%u)", __func__,
+		    ioat->chan_idx, num_descs);
+
 		if (!dug && !ioat->is_submitter_processing &&
 		    (1 << ioat->ring_size_order) > num_descs) {
 			ioat->is_submitter_processing = TRUE;
 			mtx_unlock(&ioat->submit_lock);
 
+			CTR2(KTR_IOAT, "%s channel=%u attempting to process events",
+			    __func__, ioat->chan_idx);
 			ioat_process_events(ioat);
 
 			mtx_lock(&ioat->submit_lock);
@@ -1433,6 +1444,8 @@ ioat_reserve_space(struct ioat_softc *io
 		order = ioat->ring_size_order;
 		if (ioat->is_resize_pending || order == IOAT_MAX_ORDER) {
 			if ((mflags & M_WAITOK) != 0) {
+				CTR2(KTR_IOAT, "%s channel=%u blocking on completions",
+				    __func__, ioat->chan_idx);
 				msleep(&ioat->tail, &ioat->submit_lock, 0,
 				    "ioat_rsz", 0);
 				continue;
@@ -1794,6 +1807,9 @@ ioat_submit_single(struct ioat_softc *io
 	ioat_get(ioat, IOAT_ACTIVE_DESCR_REF);
 	atomic_add_rel_int(&ioat->head, 1);
 	atomic_add_rel_int(&ioat->hw_head, 1);
+	CTR5(KTR_IOAT, "%s channel=%u head=%u hw_head=%u tail=%u", __func__,
+	    ioat->chan_idx, ioat->head, ioat->hw_head & UINT16_MAX,
+	    ioat->tail);
 
 	ioat->stats.descriptors_submitted++;
 }

Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?201610282353.u9SNrX2j094266>