Skip site navigation (1)Skip section navigation (2)
Date:      Wed, 11 Feb 2009 20:48:02 -0800
From:      Sean Bruno <sean.bruno@dsl-only.net>
To:        freebsd-firewire@FreeBSD.org
Cc:        scottl@freebsd.org
Subject:   Final patch for -current
Message-ID:  <1234414082.30696.185.camel@localhost.localdomain>

next in thread | raw e-mail | index | archive | help

--=-mR2xUljFgHtpdoYHpMFh
Content-Type: text/plain
Content-Transfer-Encoding: 7bit

Allrighty, this patch wraps up my -current work and should establish a
nice baseline for my debugging of problems.

Introduce struct sbp_dev.bustgtlun to replace the overloaded
show_sdev_info() in most places.  This is an optimization of the debug
case fortunately.  Stash the BB:TT:LL string here for later
device_printf() goodness.

More debugging cleanup printf()-->device_printf()

Explicity set the callout sdev->login_callout  to acquire the sbp mtx.

Rename sbp_alloc_target() variable i to new_target_id.  Clarity is good,
even in temporary variables.

Cleanup and document the sbp_login() function.  This function is a bit
hairy, so document what it's supposed to do.

Add some locking in sbp_probe_target()

Assert the sbp mtx in sbp_write_cmd_locked()

Avoid LoR in sbp_mgm_orb() and assert sbp mtx locked.

Acquire sbp mtx before sbp_mgm_orb() is invoked.

Sean

--=-mR2xUljFgHtpdoYHpMFh
Content-Disposition: attachment; filename="sbp.diff"
Content-Type: text/x-patch; name="sbp.diff"; charset="UTF-8"
Content-Transfer-Encoding: 7bit

Index: sbp.c
===================================================================
--- sbp.c	(revision 188508)
+++ sbp.c	(working copy)
@@ -31,7 +31,7 @@
  * ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
  * POSSIBILITY OF SUCH DAMAGE.
  * 
- * $FreeBSD$
+ * $FreeBSD: head/sys/dev/firewire/sbp.c 187993 2009-02-01 23:28:52Z sbruno $
  *
  */
 
@@ -218,6 +218,7 @@
 	char vendor[32];
 	char product[32];
 	char revision[10];
+	char bustgtlun[32];
 };
 
 struct sbp_target {
@@ -331,7 +332,7 @@
 sbp_identify(driver_t *driver, device_t parent)
 {
 SBP_DEBUG(0)
-	printf("sbp_identify\n");
+	printf("%s\n", __func__);
 END_DEBUG
 
 	BUS_ADD_CHILD(parent, 0, "sbp", device_get_unit(parent));
@@ -346,7 +347,7 @@
 	device_t pa;
 
 SBP_DEBUG(0)
-	printf("sbp_probe\n");
+	printf("%s\n", __func__);
 END_DEBUG
 
 	pa = device_get_parent(dev);
@@ -364,36 +365,35 @@
 	return (0);
 }
 
+/*
+ * Display device characteristics on the console
+ */
 static void
-sbp_show_sdev_info(struct sbp_dev *sdev, int new)
+sbp_show_sdev_info(struct sbp_dev *sdev)
 {
 	struct fw_device *fwdev;
 
-	printf("%s:%d:%d ",
-		device_get_nameunit(sdev->target->sbp->fd.dev),
-		sdev->target->target_id,
-		sdev->lun_id
-	);
-	if (new == 2) {
-		return;
-	}
 	fwdev = sdev->target->fwdev;
-	printf("ordered:%d type:%d EUI:%08x%08x node:%d "
-		"speed:%d maxrec:%d",
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s: %s: ordered:%d type:%d EUI:%08x%08x node:%d "
+		"speed:%d maxrec:%d\n",
+		__func__,
+		sdev->bustgtlun,
 		(sdev->type & 0x40) >> 6,
 		(sdev->type & 0x1f),
 		fwdev->eui.hi,
 		fwdev->eui.lo,
 		fwdev->dst,
 		fwdev->speed,
-		fwdev->maxrec
-	);
-	if (new)
-		printf(" new!\n");
-	else
-		printf("\n");
-	sbp_show_sdev_info(sdev, 2);
-	printf("'%s' '%s' '%s'\n", sdev->vendor, sdev->product, sdev->revision);
+		fwdev->maxrec);
+
+	device_printf(sdev->target->sbp->fd.dev,
+			"%s:%s '%s' '%s' '%s'\n",
+			__func__,
+			sdev->bustgtlun,
+			sdev->vendor,
+			sdev->product,
+			sdev->revision);
 }
 
 static struct {
@@ -467,14 +467,16 @@
 			break;
 		lun = reg->val & 0xffff;
 SBP_DEBUG(0)
-		printf("target %d lun %d found\n", target->target_id, lun);
+		device_printf(sbp->fd.dev, "%s: target %d lun %d found\n",
+					__func__, target->target_id, lun);
 END_DEBUG
 		if (maxlun < lun)
 			maxlun = lun;
 		crom_next(&cc);
 	}
 	if (maxlun < 0)
-		printf("%s:%d no LUN found\n",
+		device_printf(sbp->fd.dev, "%s: %s:%d no LUN found\n",
+		    __func__,
 		    device_get_nameunit(target->sbp->fd.dev),
 		    target->target_id);
 
@@ -503,7 +505,7 @@
 		    M_SBP, M_NOWAIT | M_ZERO);
 		
 		if (newluns == NULL) {
-			printf("%s: realloc failed\n", __func__);
+			device_printf(sbp->fd.dev, "%s: realloc failed\n", __func__);
 			newluns = target->luns;
 			maxlun = target->num_lun;
 		}
@@ -530,7 +532,8 @@
 			break;
 		lun = reg->val & 0xffff;
 		if (lun >= SBP_NUM_LUNS) {
-			printf("too large lun %d\n", lun);
+			device_printf(sbp->fd.dev, "%s: too large lun %d\n",
+							__func__, lun);
 			goto next;
 		}
 
@@ -539,16 +542,23 @@
 			sdev = malloc(sizeof(struct sbp_dev),
 			    M_SBP, M_NOWAIT | M_ZERO);
 			if (sdev == NULL) {
-				printf("%s: malloc failed\n", __func__);
+				device_printf(sbp->fd.dev, "%s: malloc failed\n", __func__);
 				goto next;
 			}
 			target->luns[lun] = sdev;
 			sdev->lun_id = lun;
 			sdev->target = target;
 			STAILQ_INIT(&sdev->ocbs);
-			CALLOUT_INIT(&sdev->login_callout);
+			callout_init_mtx(&sdev->login_callout,
+					 &sdev->target->sbp->mtx,
+					0);
 			sdev->status = SBP_DEV_RESET;
 			new = 1;
+			snprintf(sdev->bustgtlun, 32, "%s:%d:%d",
+					device_get_nameunit(sdev->target->sbp->fd.dev),
+					sdev->target->target_id,
+					sdev->lun_id);
+
 		}
 		sdev->flags |= VALID_LUN;
 		sdev->type = (reg->val & 0xff0000) >> 16;
@@ -560,8 +570,8 @@
 			/* alignment */ sizeof(uint32_t),
 			SBP_DMA_SIZE, &sdev->dma, BUS_DMA_NOWAIT);
 		if (sdev->dma.v_addr == NULL) {
-			printf("%s: dma space allocation failed\n",
-							__func__);
+			device_printf(sbp->fd.dev, "%s: dma space allocation failed\n",
+						__func__);
 			free(sdev, M_SBP);
 			target->luns[lun] = NULL;
 			goto next;
@@ -581,7 +591,8 @@
 				+ sizeof(struct sbp_ocb) * i
 				+ offsetof(struct sbp_ocb, orb[0]);
 			if (bus_dmamap_create(sbp->dmat, 0, &ocb->dmamap)) {
-				printf("sbp_attach: cannot create dmamap\n");
+				device_printf(sbp->fd.dev, "%s: cannot create dmamap\n",
+							__func__);
 				/* XXX */
 				goto next;
 			}
@@ -604,30 +615,32 @@
 static struct sbp_target *
 sbp_alloc_target(struct sbp_softc *sbp, struct fw_device *fwdev)
 {
-	int i;
+	int new_target_id;
 	struct sbp_target *target;
 	struct crom_context cc;
 	struct csrreg *reg;
 
 SBP_DEBUG(1)
-	printf("sbp_alloc_target\n");
+	device_printf(sbp->fd.dev, "%s: begin\n", __func__);
 END_DEBUG
-	i = sbp_new_target(sbp, fwdev);
-	if (i < 0) {
-		device_printf(sbp->fd.dev, "increase SBP_NUM_TARGETS!\n");
+	new_target_id = sbp_new_target(sbp, fwdev);
+	if (new_target_id < 0) {
+		device_printf(sbp->fd.dev, "%s: new_target_id(%d), increase SBP_NUM_TARGETS!\n",
+				__func__, new_target_id);
 		return NULL;
 	}
 	/* new target */
-	target = &sbp->targets[i];
+	target = &sbp->targets[new_target_id];
 	target->sbp = sbp;
 	target->fwdev = fwdev;
-	target->target_id = i;
+	target->target_id = new_target_id;
 	/* XXX we may want to reload mgm port after each bus reset */
 	/* XXX there might be multiple management agents */
 	crom_init_context(&cc, target->fwdev->csrrom);
 	reg = crom_search_key(&cc, CROM_MGM);
 	if (reg == NULL || reg->val == 0) {
-		printf("NULL management address\n");
+		device_printf(sbp->fd.dev, "%s: NULL management address\n",
+						__func__);
 		target->fwdev = NULL;
 		return NULL;
 	}
@@ -635,12 +648,16 @@
 	target->mgm_lo = 0xf0000000 | (reg->val << 2);
 	target->mgm_ocb_cur = NULL;
 SBP_DEBUG(1)
-	printf("target:%d mgm_port: %x\n", i, target->mgm_lo);
+	device_printf(sbp->fd.dev, "%s: target:%d mgm_port: %x\n",
+				__func__,
+				target->target_id, target->mgm_lo);
 END_DEBUG
 	STAILQ_INIT(&target->xferlist);
 	target->n_xfer = 0;
 	STAILQ_INIT(&target->mgm_ocb_queue);
-	CALLOUT_INIT(&target->mgm_ocb_timeout);
+	callout_init_mtx(&target->mgm_ocb_timeout,
+			 &sbp->mtx,
+			0);
 	CALLOUT_INIT(&target->scan_callout);
 
 	target->luns = NULL;
@@ -685,29 +702,50 @@
 sbp_login_callout(void *arg)
 {
 	struct sbp_dev *sdev = (struct sbp_dev *)arg;
+
+	mtx_assert(&sdev->target->sbp->mtx, MA_OWNED);
 	sbp_mgm_orb(sdev, ORB_FUN_LGI, NULL);
 }
 
+/*
+ * Login to the SBP capable device
+ * after the sysctl controlled login_delay
+ * variable.  If the last bus reset occured
+ * more than login_delay ms in the past
+ * set ticks to 0 and setup the handler
+ */
 static void
 sbp_login(struct sbp_dev *sdev)
 {
 	struct timeval delta;
-	struct timeval t;
-	int ticks = 0;
+	struct timeval tv_login_delay;
+	int ticks;
 
+	SBP_LOCK(sdev->target->sbp);
+
 	microtime(&delta);
 	timevalsub(&delta, &sdev->target->sbp->last_busreset);
-	t.tv_sec = login_delay / 1000;
-	t.tv_usec = (login_delay % 1000) * 1000;
-	timevalsub(&t, &delta);
-	if (t.tv_sec >= 0 && t.tv_usec > 0)
-		ticks = (t.tv_sec * 1000 + t.tv_usec / 1000) * hz / 1000;
+	tv_login_delay.tv_sec = login_delay / 1000;
+	tv_login_delay.tv_usec = (login_delay % 1000) * 1000;
+	timevalsub(&tv_login_delay, &delta);
+	if (tv_login_delay.tv_sec >= 0 && tv_login_delay.tv_usec > 0) {
+		ticks = (tv_login_delay.tv_sec * 1000 + tv_login_delay.tv_usec / 1000) * hz / 1000;
+	} else {
+		ticks = 0;
+	}
 SBP_DEBUG(0)
-	printf("%s: sec = %jd usec = %ld ticks = %d\n", __func__,
-	    (intmax_t)t.tv_sec, t.tv_usec, ticks);
+	device_printf(sdev->target->sbp->fd.dev,
+			"%s: sec = %d, usec = %ld, ticks = %d\n",
+			__func__, tv_login_delay.tv_sec, tv_login_delay.tv_usec, ticks);
+	device_printf(sdev->target->sbp->fd.dev,
+			"%s: tv_login_delay(%d), "
+			"delta(%d), last_busreset(%d)\n",
+			__func__, tvtohz(&tv_login_delay),
+			tvtohz(&delta), tvtohz(&sdev->target->sbp->last_busreset));
 END_DEBUG
 	callout_reset(&sdev->login_callout, ticks,
 			sbp_login_callout, (void *)(sdev));
+	SBP_UNLOCK(sdev->target->sbp);
 }
 
 #define SBP_FWDEV_ALIVE(fwdev) (((fwdev)->status == FWDEVATTACHED) \
@@ -717,20 +755,17 @@
 sbp_probe_target(void *arg)
 {
 	struct sbp_target *target = (struct sbp_target *)arg;
-	struct sbp_softc *sbp;
+	struct sbp_softc *sbp = target->sbp;
 	struct sbp_dev *sdev;
-	struct firewire_comm *fc;
 	int i, alive;
 
 	alive = SBP_FWDEV_ALIVE(target->fwdev);
 SBP_DEBUG(1)
-	printf("sbp_probe_target %d\n", target->target_id);
-	if (!alive)
-		printf("not alive\n");
+	device_printf(sbp->fd.dev, "%s %d%salive\n",
+		 __func__, target->target_id,
+		(!alive) ? " not " : "");
 END_DEBUG
 
-	sbp = target->sbp;
-	fc = target->sbp->fd.fc;
 	sbp_alloc_lun(target);
 
 	/* XXX untimeout mgm_ocb and dequeue */
@@ -747,8 +782,9 @@
 			}
 			sbp_probe_lun(sdev);
 SBP_DEBUG(0)
-			sbp_show_sdev_info(sdev, 
-					(sdev->status == SBP_DEV_RESET));
+			SBP_LOCK(sbp);
+			sbp_show_sdev_info(sdev);
+			SBP_UNLOCK(sbp);
 END_DEBUG
 
 			sbp_abort_all_ocbs(sdev, CAM_SCSI_BUS_RESET);
@@ -763,7 +799,9 @@
 			case SBP_DEV_ATTACHED:
 			case SBP_DEV_RETRY:
 			default:
+				SBP_LOCK(sbp);
 				sbp_mgm_orb(sdev, ORB_FUN_RCN, NULL);
+				SBP_UNLOCK(sbp);
 				break;
 			}
 		} else {
@@ -771,8 +809,8 @@
 			case SBP_DEV_ATTACHED:
 SBP_DEBUG(0)
 				/* the device has gone */
-				sbp_show_sdev_info(sdev, 2);
-				printf("lost target\n");
+				device_printf(sbp->fd.dev, "%s: lost target\n",
+					__func__);
 END_DEBUG
 				if (sdev->path) {
 					SBP_LOCK(sbp);
@@ -805,7 +843,7 @@
 
 	sbp = (struct sbp_softc *)arg;
 SBP_DEBUG(0)
-	printf("sbp_post_busreset\n");
+	device_printf(sbp->fd.dev,"%s\n", __func__);
 END_DEBUG
 	if ((sbp->sim->flags & SIMQ_FREEZED) == 0) {
 		SBP_LOCK(sbp);
@@ -825,7 +863,8 @@
 	int i, alive;
 
 SBP_DEBUG(0)
-	printf("sbp_post_explore (sbp_cold=%d)\n", sbp_cold);
+	device_printf(sbp->fd.dev, "%s: (sbp_cold=%d)\n",
+				__func__,  sbp_cold);
 END_DEBUG
 	/* We need physical access */
 	if (!firewire_phydma_enable)
@@ -857,12 +896,10 @@
 	/* traverse device list */
 	STAILQ_FOREACH(fwdev, &sbp->fd.fc->devices, link) {
 SBP_DEBUG(0)
-		printf("sbp_post_explore: EUI:%08x%08x ",
-				fwdev->eui.hi, fwdev->eui.lo);
-		if (fwdev->status != FWDEVATTACHED)
-			printf("not attached, state=%d.\n", fwdev->status);
-		else
-			printf("attached\n");
+		device_printf(sbp->fd.dev,"%s:: EUI:%08x%08x %s attached, state=%d\n",
+				__func__, fwdev->eui.hi, fwdev->eui.lo,
+				(fwdev->status != FWDEVATTACHED) ? "not" : "",
+				fwdev->status);
 END_DEBUG
 		alive = SBP_FWDEV_ALIVE(fwdev);
 		for(i = 0 ; i < SBP_NUM_TARGETS ; i ++){
@@ -899,8 +936,7 @@
 	struct sbp_dev *sdev;
 	sdev = (struct sbp_dev *)xfer->sc;
 SBP_DEBUG(1)
-	sbp_show_sdev_info(sdev, 2);
-	printf("sbp_loginres_callback\n");
+	device_printf(sdev->target->sbp->fd.dev,"%s\n", __func__);
 END_DEBUG
 	/* recycle */
 	s = splfw();
@@ -933,8 +969,8 @@
 	int i;
 
 	if (xfer->resp != 0) {
-		sbp_show_sdev_info(sdev, 2);
-		printf("sbp_reset_start failed: resp=%d\n", xfer->resp);
+		device_printf(sdev->target->sbp->fd.dev,
+			"%s: %s failed: resp=%d\n", __func__, sdev->bustgtlun, xfer->resp);
 	}
 
 	for (i = 0; i < target->num_lun; i++) {
@@ -951,8 +987,8 @@
 	struct fw_pkt *fp;
 
 SBP_DEBUG(0)
-	sbp_show_sdev_info(sdev, 2);
-	printf("sbp_reset_start\n");
+	device_printf(sdev->target->sbp->fd.dev,
+			"%s:%s\n", __func__,sdev->bustgtlun);
 END_DEBUG
 
 	xfer = sbp_write_cmd(sdev, FWTCODE_WREQQ, 0);
@@ -973,18 +1009,11 @@
 	sdev = (struct sbp_dev *)xfer->sc;
 
 SBP_DEBUG(1)
-	sbp_show_sdev_info(sdev, 2);
-	printf("sbp_mgm_callback\n");
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s\n", __func__, sdev->bustgtlun);
 END_DEBUG
 	resp = xfer->resp;
 	sbp_xfer_free(xfer);
-#if 0
-	if (resp != 0) {
-		sbp_show_sdev_info(sdev, 2);
-		printf("management ORB failed(%d) ... RESET_START\n", resp);
-		sbp_reset_start(sdev);
-	}
-#endif
 	return;
 }
 
@@ -1011,14 +1040,14 @@
 	sdev = (struct sbp_dev *) ccb->ccb_h.ccb_sdev_ptr;
 	target = sdev->target;
 SBP_DEBUG(0)
-	sbp_show_sdev_info(sdev, 2);
-	printf("sbp_cam_scan_lun\n");
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s\n", __func__, sdev->bustgtlun);
 END_DEBUG
 	if ((ccb->ccb_h.status & CAM_STATUS_MASK) == CAM_REQ_CMP) {
 		sdev->status = SBP_DEV_ATTACHED;
 	} else {
-		sbp_show_sdev_info(sdev, 2);
-		printf("scan failed\n");
+		device_printf(sdev->target->sbp->fd.dev,
+			"%s:%s failed\n", __func__, sdev->bustgtlun);
 	}
 	sdev = sbp_next_dev(target, sdev->lun_id + 1);
 	if (sdev == NULL) {
@@ -1047,8 +1076,8 @@
 		return;
 	}
 SBP_DEBUG(0)
-	sbp_show_sdev_info(sdev, 2);
-	printf("sbp_cam_scan_target\n");
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s\n", __func__, sdev->bustgtlun);
 END_DEBUG
 	ccb = malloc(sizeof(union ccb), M_SBP, M_NOWAIT | M_ZERO);
 	if (ccb == NULL) {
@@ -1089,8 +1118,8 @@
 	target = sdev->target;
 	sbp = target->sbp;
 SBP_DEBUG(0)
-	sbp_show_sdev_info(sdev, 2);
-	printf("sbp_do_attach\n");
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s\n", __func__, sdev->bustgtlun);
 END_DEBUG
 	sbp_xfer_free(xfer);
 
@@ -1120,12 +1149,12 @@
 
 	sdev = (struct sbp_dev *)xfer->sc;
 SBP_DEBUG(1)
-	sbp_show_sdev_info(sdev, 2);
-	printf("%s\n", __func__);
+	device_printf(sdev->target->sbp->fd.dev,
+			"%s:%s\n", __func__, sdev->bustgtlun);
 END_DEBUG
 	if (xfer->resp != 0) {
-		sbp_show_sdev_info(sdev, 2);
-		printf("%s: resp=%d\n", __func__, xfer->resp);
+		device_printf(sdev->target->sbp->fd.dev,
+			"%s:%s resp=%d\n", __func__, sdev->bustgtlun, xfer->resp);
 	}
 
 	sbp_xfer_free(xfer);
@@ -1144,8 +1173,8 @@
 	struct fw_pkt *fp;
 
 SBP_DEBUG(0)
-	sbp_show_sdev_info(sdev, 2);
-	printf("sbp_agent_reset\n");
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s\n", __func__, sdev->bustgtlun);
 END_DEBUG
 	xfer = sbp_write_cmd(sdev, FWTCODE_WREQQ, 0x04);
 	if (xfer == NULL)
@@ -1167,8 +1196,8 @@
 
 	sdev = (struct sbp_dev *)xfer->sc;
 SBP_DEBUG(1)
-	sbp_show_sdev_info(sdev, 2);
-	printf("sbp_busy_timeout_callback\n");
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s\n", __func__, sdev->bustgtlun);
 END_DEBUG
 	sbp_xfer_free(xfer);
 	sbp_agent_reset(sdev);
@@ -1180,8 +1209,8 @@
 	struct fw_pkt *fp;
 	struct fw_xfer *xfer;
 SBP_DEBUG(0)
-	sbp_show_sdev_info(sdev, 2);
-	printf("sbp_busy_timeout\n");
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s\n", __func__, sdev->bustgtlun);
 END_DEBUG
 	xfer = sbp_write_cmd(sdev, FWTCODE_WREQQ, 0);
 
@@ -1200,8 +1229,8 @@
 	sdev = (struct sbp_dev *)xfer->sc;
 
 SBP_DEBUG(2)
-	sbp_show_sdev_info(sdev, 2);
-	printf("%s\n", __func__);
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s\n", __func__, sdev->bustgtlun);
 END_DEBUG
 	if (xfer->resp != 0) {
 		/* XXX */
@@ -1230,8 +1259,10 @@
 	struct fw_xfer *xfer;
 	struct fw_pkt *fp;
 SBP_DEBUG(1)
-	sbp_show_sdev_info(sdev, 2);
-	printf("%s: 0x%08x\n", __func__, (uint32_t)ocb->bus_addr);
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s 0x%08x\n",
+		__func__, sdev->bustgtlun,
+		(uint32_t)ocb->bus_addr);
 END_DEBUG
 
 	mtx_assert(&sdev->target->sbp->mtx, MA_OWNED);
@@ -1278,12 +1309,13 @@
 	sdev = (struct sbp_dev *)xfer->sc;
 
 SBP_DEBUG(1)
-	sbp_show_sdev_info(sdev, 2);
-	printf("sbp_doorbell_callback\n");
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s\n", __func__, sdev->bustgtlun);
 END_DEBUG
 	if (xfer->resp != 0) {
 		/* XXX */
-		printf("%s: xfer->resp = %d\n", __func__, xfer->resp);
+		device_printf(sdev->target->sbp->fd.dev,
+			"%s: xfer->resp = %d\n", __func__, xfer->resp);
 	}
 	sbp_xfer_free(xfer);
 	sdev->flags &= ~ORB_DOORBELL_ACTIVE;
@@ -1302,8 +1334,8 @@
 	struct fw_xfer *xfer;
 	struct fw_pkt *fp;
 SBP_DEBUG(1)
-	sbp_show_sdev_info(sdev, 2);
-	printf("sbp_doorbell\n");
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s\n", __func__, sdev->bustgtlun);
 END_DEBUG
 
 	if ((sdev->flags & ORB_DOORBELL_ACTIVE) != 0) {
@@ -1335,19 +1367,25 @@
 	xfer = STAILQ_FIRST(&target->xferlist);
 	if (xfer == NULL) {
 		if (target->n_xfer > 5 /* XXX */) {
-			printf("sbp: no more xfer for this target\n");
+			device_printf(sdev->target->sbp->fd.dev,
+				"%s: no more xfer for this target\n",
+				__func__);
 			splx(s);
 			return(NULL);
 		}
 		xfer = fw_xfer_alloc_buf(M_SBP, 8, 0);
 		if(xfer == NULL){
-			printf("sbp: fw_xfer_alloc_buf failed\n");
+			device_printf(sdev->target->sbp->fd.dev,
+				"%s: fw_xfer_alloc_buf failed\n",
+				__func__);
 			splx(s);
 			return NULL;
 		}
 		target->n_xfer ++;
 		if (debug)
-			printf("sbp: alloc %d xfer\n", target->n_xfer);
+			device_printf(sdev->target->sbp->fd.dev,
+				"%s: alloc %d xfer\n",
+				__func__, target->n_xfer);
 		new = 1;
 	} else {
 		STAILQ_REMOVE_HEAD(&target->xferlist, link);
@@ -1398,31 +1436,24 @@
 	struct fw_pkt *fp;
 	struct sbp_ocb *ocb;
 	struct sbp_target *target;
-	int s, nid;
+	int nid;
 
+	mtx_assert(&sdev->target->sbp->mtx, MA_OWNED);
 	target = sdev->target;
 	nid = target->sbp->fd.fc->nodeid | FWLOCALBUS;
 
-	s = splfw();
-	SBP_LOCK(target->sbp);
 	if (func == ORB_FUN_RUNQUEUE) {
 		ocb = STAILQ_FIRST(&target->mgm_ocb_queue);
 		if (target->mgm_ocb_cur != NULL || ocb == NULL) {
-			SBP_UNLOCK(target->sbp);
-			splx(s);
 			return;
 		}
 		STAILQ_REMOVE_HEAD(&target->mgm_ocb_queue, ocb);
-		SBP_UNLOCK(target->sbp);
 		goto start;
 	}
 	if ((ocb = sbp_get_ocb(sdev)) == NULL) {
-		SBP_UNLOCK(target->sbp);
-		splx(s);
 		/* XXX */
 		return;
 	}
-	SBP_UNLOCK(target->sbp);
 	ocb->flags = OCB_ACT_MGM;
 	ocb->sdev = sdev;
 
@@ -1431,8 +1462,10 @@
 	ocb->orb[7] = htonl(SBP_DEV2ADDR(target->target_id, sdev->lun_id));
 
 SBP_DEBUG(0)
-	sbp_show_sdev_info(sdev, 2);
-	printf("%s\n", orb_fun_name[(func>>16)&0xf]);
+	device_printf(sdev->target->sbp->fd.dev,
+		 "%s:%s %s\n",
+		 __func__,sdev->bustgtlun,
+		 orb_fun_name[(func>>16)&0xf]);
 END_DEBUG
 	switch (func) {
 	case ORB_FUN_LGI:
@@ -1460,19 +1493,16 @@
 
 	if (target->mgm_ocb_cur != NULL) {
 		/* there is a standing ORB */
-		SBP_LOCK(target->sbp);
 		STAILQ_INSERT_TAIL(&sdev->target->mgm_ocb_queue, ocb, ocb);
-		SBP_UNLOCK(target->sbp);
-		splx(s);
 		return;
 	}
 start:
 	target->mgm_ocb_cur = ocb;
-	splx(s);
 
 	callout_reset(&target->mgm_ocb_timeout, 5*hz,
 				sbp_mgm_timeout, (caddr_t)ocb);
-	xfer = sbp_write_cmd(sdev, FWTCODE_WREQB, 0);
+
+	xfer = sbp_write_cmd_locked(sdev, FWTCODE_WREQB, 0);
 	if(xfer == NULL){
 		return;
 	}
@@ -1485,12 +1515,10 @@
 	fp->mode.wreqb.extcode = 0;
 	xfer->send.payload[0] = htonl(nid << 16);
 	xfer->send.payload[1] = htonl(ocb->bus_addr & 0xffffffff);
-SBP_DEBUG(0)
-	sbp_show_sdev_info(sdev, 2);
-	printf("mgm orb: %08x\n", (uint32_t)ocb->bus_addr);
-END_DEBUG
 
+	SBP_UNLOCK(sdev->target->sbp);
 	fw_asyreq(xfer->fc, -1, xfer);
+	SBP_LOCK(sdev->target->sbp);
 }
 
 static void
@@ -1532,8 +1560,8 @@
 SBP_DEBUG(0)
 	sbp_print_scsi_cmd(ocb);
 	/* XXX need decode status */
-	sbp_show_sdev_info(ocb->sdev, 2);
-	printf("SCSI status %x sfmt %x valid %x key %x code %x qlfr %x len %d\n",
+	printf("%s: SCSI status %x sfmt %x valid %x key %x code %x qlfr %x len %d\n",
+		ocb->sdev->bustgtlun,
 		sbp_cmd_status->status,
 		sbp_cmd_status->sfmt,
 		sbp_cmd_status->valid,
@@ -1601,9 +1629,10 @@
 */
 		break;
 	default:
-		sbp_show_sdev_info(ocb->sdev, 2);
-		printf("sbp_scsi_status: unknown scsi status 0x%x\n",
-						sbp_cmd_status->status);
+		device_printf(ocb->sdev->target->sbp->fd.dev,
+				"%s:%s unknown scsi status 0x%x\n",
+				__func__, ocb->sdev->bustgtlun,
+				sbp_cmd_status->status);
 	}
 }
 
@@ -1620,8 +1649,8 @@
 	if (ccb->csio.cdb_io.cdb_bytes[1] & SI_EVPD)
 		return;
 SBP_DEBUG(1)
-	sbp_show_sdev_info(sdev, 2);
-	printf("sbp_fix_inq_data\n");
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s\n", __func__, sdev->bustgtlun);
 END_DEBUG
 	inq = (struct scsi_inquiry_data *) ccb->csio.data_ptr;
 	switch (SID_TYPE(inq)) {
@@ -1723,30 +1752,35 @@
 		ocb  = target->mgm_ocb_cur;
 		if (ocb != NULL) {
 			if (OCB_MATCH(ocb, sbp_status)) {
+				SBP_LOCK(sdev->target->sbp);
 				callout_stop(&target->mgm_ocb_timeout);
+				SBP_UNLOCK(sdev->target->sbp);
 				target->mgm_ocb_cur = NULL;
 				break;
 			}
 		}
 		ocb = sbp_dequeue_ocb(sdev, sbp_status);
 		if (ocb == NULL) {
-			sbp_show_sdev_info(sdev, 2);
+			device_printf(sdev->target->sbp->fd.dev,
 #if defined(__DragonFly__) || __FreeBSD_version < 500000
-			printf("No ocb(%lx) on the queue\n",
+				"%s:%s No ocb(%lx) on the queue\n",
 #else
-			printf("No ocb(%x) on the queue\n",
+				"%s:%s No ocb(%x) on the queue\n",
 #endif
-					ntohl(sbp_status->orb_lo));
+				__func__,sdev->bustgtlun,
+				ntohl(sbp_status->orb_lo));
 		}
 		break;
 	case 2:
 		/* unsolicit */
-		sbp_show_sdev_info(sdev, 2);
-		printf("unsolicit status received\n");
+		device_printf(sdev->target->sbp->fd.dev,
+			"%s:%s unsolicit status received\n",
+			__func__, sdev->bustgtlun);
 		break;
 	default:
-		sbp_show_sdev_info(sdev, 2);
-		printf("unknown sbp_status->src\n");
+		device_printf(sdev->target->sbp->fd.dev,
+			"%s:%s unknown sbp_status->src\n",
+			__func__, sdev->bustgtlun);
 	}
 
 	status_valid0 = (sbp_status->src < 2
@@ -1757,18 +1791,20 @@
 	if (!status_valid0 || debug > 2){
 		int status;
 SBP_DEBUG(0)
-		sbp_show_sdev_info(sdev, 2);
-		printf("ORB status src:%x resp:%x dead:%x"
+		device_printf(sdev->target->sbp->fd.dev,
+			"%s:%s ORB status src:%x resp:%x dead:%x"
 #if defined(__DragonFly__) || __FreeBSD_version < 500000
 				" len:%x stat:%x orb:%x%08lx\n",
 #else
 				" len:%x stat:%x orb:%x%08x\n",
 #endif
+			__func__, sdev->bustgtlun,
 			sbp_status->src, sbp_status->resp, sbp_status->dead,
 			sbp_status->len, sbp_status->status,
 			ntohs(sbp_status->orb_hi), ntohl(sbp_status->orb_lo));
 END_DEBUG
-		sbp_show_sdev_info(sdev, 2);
+		device_printf(sdev->target->sbp->fd.dev,
+				"%s\n", sdev->bustgtlun);
 		status = sbp_status->status;
 		switch(sbp_status->resp) {
 		case 0:
@@ -1827,14 +1863,19 @@
 				login_res->cmd_lo = ntohl(login_res->cmd_lo);
 				if (status_valid) {
 SBP_DEBUG(0)
-sbp_show_sdev_info(sdev, 2);
-printf("login: len %d, ID %d, cmd %08x%08x, recon_hold %d\n", login_res->len, login_res->id, login_res->cmd_hi, login_res->cmd_lo, ntohs(login_res->recon_hold));
+					device_printf(sdev->target->sbp->fd.dev,
+						"%s:%s login: len %d, ID %d, cmd %08x%08x, recon_hold %d\n",
+						__func__, sdev->bustgtlun,
+						login_res->len, login_res->id,
+						login_res->cmd_hi, login_res->cmd_lo,
+						ntohs(login_res->recon_hold));
 END_DEBUG
 					sbp_busy_timeout(sdev);
 				} else {
 					/* forgot logout? */
-					sbp_show_sdev_info(sdev, 2);
-					printf("login failed\n");
+					device_printf(sdev->target->sbp->fd.dev,
+						"%s:%s login failed\n",
+						__func__, sdev->bustgtlun);
 					sdev->status = SBP_DEV_RESET;
 				}
 				break;
@@ -1842,23 +1883,22 @@
 				login_res = sdev->login;
 				if (status_valid) {
 SBP_DEBUG(0)
-sbp_show_sdev_info(sdev, 2);
-printf("reconnect: len %d, ID %d, cmd %08x%08x\n", login_res->len, login_res->id, login_res->cmd_hi, login_res->cmd_lo);
+					device_printf(sdev->target->sbp->fd.dev,
+						"%s:%s reconnect: len %d, ID %d, cmd %08x%08x\n",
+						__func__, sdev->bustgtlun,
+						login_res->len, login_res->id,
+						login_res->cmd_hi, login_res->cmd_lo);
 END_DEBUG
-#if 1
 					if (sdev->status == SBP_DEV_ATTACHED)
 						sbp_scan_dev(sdev);
 					else
 						sbp_agent_reset(sdev);
-#else
-					sdev->status = SBP_DEV_ATTACHED;
-					sbp_mgm_orb(sdev, ORB_FUN_ATS, NULL);
-#endif
 				} else {
 					/* reconnection hold time exceed? */
 SBP_DEBUG(0)
-					sbp_show_sdev_info(sdev, 2);
-					printf("reconnect failed\n");
+					device_printf(sdev->target->sbp->fd.dev,
+						"%s:%s reconnect failed\n",
+						__func__, sdev->bustgtlun);
 END_DEBUG
 					sbp_login(sdev);
 				}
@@ -1875,25 +1915,20 @@
 				sbp_agent_reset(sdev);
 				break;
 			default:
-				sbp_show_sdev_info(sdev, 2);
-				printf("unknown function %d\n", orb_fun);
+				device_printf(sdev->target->sbp->fd.dev,
+					"%s:%s unknown function %d\n",
+					__func__, sdev->bustgtlun, orb_fun);
 				break;
 			}
+			SBP_LOCK(sbp);
 			sbp_mgm_orb(sdev, ORB_FUN_RUNQUEUE, NULL);
+			SBP_UNLOCK(sbp);
 			break;
 		case OCB_ACT_CMD:
 			sdev->timeout = 0;
 			if(ocb->ccb != NULL){
 				union ccb *ccb;
-/*
-				uint32_t *ld;
-				ld = ocb->ccb->csio.data_ptr;
-				if(ld != NULL && ocb->ccb->csio.dxfer_len != 0)
-					printf("ptr %08x %08x %08x %08x\n", ld[0], ld[1], ld[2], ld[3]);
-				else
-					printf("ptr NULL\n");
-printf("len %d\n", sbp_status->len);
-*/
+
 				ccb = ocb->ccb;
 				if(sbp_status->len > 1){
 					sbp_scsi_status(sbp_status, ocb);
@@ -2101,10 +2136,13 @@
 			sdev = target->luns[j];
 			if (sdev == NULL)
 				continue;
+			SBP_LOCK(sdev->target->sbp);
 			callout_stop(&sdev->login_callout);
-			if (sdev->status >= SBP_DEV_TOATTACH &&
-					sdev->status <= SBP_DEV_ATTACHED)
+			if (sdev->status >= SBP_DEV_TOATTACH && 
+					sdev->status <= SBP_DEV_ATTACHED) {
 				sbp_mgm_orb(sdev, ORB_FUN_LGO, NULL);
+			}
+			SBP_UNLOCK(sdev->target->sbp);
 		}
 	}
 
@@ -2144,8 +2182,10 @@
 
 	if (target->luns == NULL)
 		return;
+	sbp = target->sbp;
+	SBP_LOCK(sbp);
 	callout_stop(&target->mgm_ocb_timeout);
-	sbp = target->sbp;
+	SBP_UNLOCK(sbp);
 	for (i = 0; i < target->num_lun; i++)
 		sbp_free_sdev(target->luns[i]);
 
@@ -2261,11 +2301,13 @@
 	}
 	switch(method) {
 	case 1:
-		printf("target reset\n");
+		device_printf(sdev->target->sbp->fd.dev,"target reset\n");
+		SBP_LOCK(sdev->target->sbp);
 		sbp_mgm_orb(sdev, ORB_FUN_RST, NULL);
+		SBP_UNLOCK(sdev->target->sbp);
 		break;
 	case 2:
-		printf("reset start\n");
+		device_printf(sdev->target->sbp->fd.dev,"reset start\n");
 		sbp_reset_start(sdev);
 		break;
 	}
@@ -2279,20 +2321,18 @@
 	struct sbp_dev *sdev = ocb->sdev;
 	struct sbp_target *target = sdev->target;
 
-	sbp_show_sdev_info(sdev, 2);
-	printf("request timeout(mgm orb:0x%08x) ... ",
-	    (uint32_t)ocb->bus_addr);
+	mtx_assert(&sdev->target->sbp->mtx, MA_OWNED);
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s request timeout(mgm orb:0x%08x)\n",
+		__func__, sdev->bustgtlun, (uint32_t)ocb->bus_addr);
 	target->mgm_ocb_cur = NULL;
+	SBP_UNLOCK(sdev->target->sbp);
 	sbp_free_ocb(sdev, ocb);
-#if 0
-	/* XXX */
-	printf("run next request\n");
-	sbp_mgm_orb(sdev, ORB_FUN_RUNQUEUE, NULL);
-#endif
-#if 1
-	printf("reset start\n");
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s run next request\n",
+		__func__, sdev->bustgtlun);
 	sbp_reset_start(sdev);
-#endif
+	SBP_LOCK(sdev->target->sbp);
 }
 
 static void
@@ -2301,9 +2341,9 @@
 	struct sbp_ocb *ocb = (struct sbp_ocb *)arg;
 	struct sbp_dev *sdev = ocb->sdev;
 
-	sbp_show_sdev_info(sdev, 2);
-	printf("request timeout(cmd orb:0x%08x) ... ",
-	    (uint32_t)ocb->bus_addr);
+	device_printf(sdev->target->sbp->fd.dev,
+		"%s:%s request timeout(cmd orb:0x%08x) ... ",
+		__func__, sdev->bustgtlun, (uint32_t)ocb->bus_addr);
 
 	sdev->timeout ++;
 	switch(sdev->timeout) {
@@ -2760,13 +2800,13 @@
 	int flags;
 
 SBP_DEBUG(1)
-	sbp_show_sdev_info(sdev, 2);
+	device_printf(sdev->target->sbp->fd.dev,
 #if defined(__DragonFly__) || __FreeBSD_version < 500000
-	printf("%s: 0x%08lx src %d\n",
+	"%s:%s 0x%08lx src %d\n",
 #else
-	printf("%s: 0x%08x src %d\n",
+	"%s:%s 0x%08x src %d\n",
 #endif
-	    __func__, ntohl(sbp_status->orb_lo), sbp_status->src);
+	    __func__, sdev->bustgtlun, ntohl(sbp_status->orb_lo), sbp_status->src);
 END_DEBUG
 	SBP_LOCK(sdev->target->sbp);
 	for (ocb = STAILQ_FIRST(&sdev->ocbs); ocb != NULL; ocb = next) {
@@ -2823,8 +2863,9 @@
 	splx(s);
 SBP_DEBUG(0)
 	if (ocb && order > 0) {
-		sbp_show_sdev_info(sdev, 2);
-		printf("unordered execution order:%d\n", order);
+		device_printf(sdev->target->sbp->fd.dev,
+			"%s:%s unordered execution order:%d\n",
+			__func__, sdev->bustgtlun, order);
 	}
 END_DEBUG
 	return (ocb);
@@ -2838,11 +2879,11 @@
 
 	mtx_assert(&sdev->target->sbp->mtx, MA_OWNED);
 SBP_DEBUG(1)
-	sbp_show_sdev_info(sdev, 2);
+	device_printf(sdev->target->sbp->fd.dev,
 #if defined(__DragonFly__) || __FreeBSD_version < 500000
-	printf("%s: 0x%08x\n", __func__, ocb->bus_addr);
+	"%s:%s 0x%08x\n", __func__, sdev->bustgtlun, ocb->bus_addr);
 #else
-	printf("%s: 0x%08jx\n", __func__, (uintmax_t)ocb->bus_addr);
+	"%s:%s 0x%08jx\n", __func__, sdev->bustgtlun, (uintmax_t)ocb->bus_addr);
 #endif
 END_DEBUG
 	prev2 = prev = STAILQ_LAST(&sdev->ocbs, sbp_ocb, ocb);
@@ -2924,11 +2965,11 @@
 
 	sdev = ocb->sdev;
 SBP_DEBUG(0)
-	sbp_show_sdev_info(sdev, 2);
+	device_printf(sdev->target->sbp->fd.dev,
 #if defined(__DragonFly__) || __FreeBSD_version < 500000
-	printf("sbp_abort_ocb 0x%x\n", ocb->bus_addr);
+	"%s:%s 0x%x\n", __func__, sdev->bustgtlun, ocb->bus_addr);
 #else
-	printf("sbp_abort_ocb 0x%jx\n", (uintmax_t)ocb->bus_addr);
+	"%s:%s 0x%jx\n", __func__, sdev->bustgtlun, (uintmax_t)ocb->bus_addr);
 #endif
 END_DEBUG
 SBP_DEBUG(1)

--=-mR2xUljFgHtpdoYHpMFh--




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