Final patch for -current

Sean Bruno <[email protected]>
Newsgroups gmane.os.freebsd.devel.firewire
Message-ID <[email protected]> 
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

_______________________________________________
[email protected] mailing list
http://lists.freebsd.org/mailman/listinfo/freebsd-firewire
To unsubscribe, send any mail to "[email protected]"
sbp.diff (text/x-patch, 28.2 KB) 
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)
lmpx.com only provides a reader for public news (NNTP) servers. It is not affiliated with the servers or forums shown here and is not responsible for the content of articles, which is written by their respective authors.