Tune and add some more CAM_DEBUG() points for the probe sequences.

2 files changed, 44 insertions, 39 deletions

diff --git a/sys/cam/ata/ata_xpt.c b/sys/cam/ata/ata_xpt.c
index 36b2927..d7fe3d7 100644
--- a/sys/cam/ata/ata_xpt.c
+++ b/sys/cam/ata/ata_xpt.c
@@ -96,6 +96,7 @@ typedef enum {
 	PROBE_PM_PRV,
 	PROBE_IDENTIFY_SES,
 	PROBE_IDENTIFY_SAFTE,
+	PROBE_DONE,
 	PROBE_INVALID
 } probe_action;
 
@@ -115,6 +116,7 @@ static char *probe_action_text[] = {
 	"PROBE_PM_PRV",
 	"PROBE_IDENTIFY_SES",
 	"PROBE_IDENTIFY_SAFTE",
+	"PROBE_DONE",
 	"PROBE_INVALID"
 };
 
@@ -122,7 +124,7 @@ static char *probe_action_text[] = {
 do {									\
 	char **text;							\
 	text = probe_action_text;					\
-	CAM_DEBUG((softc)->periph->path, CAM_DEBUG_INFO,		\
+	CAM_DEBUG((softc)->periph->path, CAM_DEBUG_PROBE,		\
 	    ("Probe %s to %s\n", text[(softc)->action],			\
 	    text[(newaction)]));					\
 	(softc)->action = (newaction);					\
@@ -251,6 +253,8 @@ proberegister(struct cam_periph *periph, void *arg)
 	if (status != CAM_REQ_CMP) {
 		return (status);
 	}
+	CAM_DEBUG(periph->path, CAM_DEBUG_PROBE, ("Probe started\n"));
+
 	/*
 	 * Ensure nobody slip in until probe finish.
 	 */
@@ -653,11 +657,8 @@ negotiate:
 		ata_28bit_cmd(ataio, ATA_SEP_ATTN, 0xEC, 0x00,
 		    sizeof(softc->ident_data) / 4);
 		break;
-	case PROBE_INVALID:
-		CAM_DEBUG(path, CAM_DEBUG_INFO,
-		    ("probestart: invalid action state\n"));
 	default:
-		break;
+		panic("probestart: invalid action state 0x%x\n", softc->action);
 	}
 	xpt_action(start_ccb);
 }
@@ -776,6 +777,7 @@ probedone(struct cam_periph *periph, union ccb *done_ccb)
 		 */
 device_fail:	if ((path->device->flags & CAM_DEV_UNCONFIGURED) == 0)
 			xpt_async(AC_LOST_DEVICE, path, NULL);
+		PROBE_SET_ACTION(softc, PROBE_INVALID);
 		found = 0;
 		goto done;
 	}
@@ -787,8 +789,8 @@ noerror:
 	{
 		int sign = (done_ccb->ataio.res.lba_high << 8) +
 		    done_ccb->ataio.res.lba_mid;
-		if (bootverbose)
-			xpt_print(path, "SIGNATURE: %04x\n", sign);
+		CAM_DEBUG(path, CAM_DEBUG_PROBE,
+		    ("SIGNATURE: %04x\n", sign));
 		if (sign == 0x0000 &&
 		    done_ccb->ccb_h.target_id != 15) {
 			path->device->protocol = PROTO_ATA;
@@ -1053,6 +1055,7 @@ notsata:
 			xpt_async(AC_FOUND_DEVICE, done_ccb->ccb_h.path,
 			    done_ccb);
 		}
+		PROBE_SET_ACTION(softc, PROBE_DONE);
 		break;
 	case PROBE_INQUIRY:
 	case PROBE_FULL_INQUIRY:
@@ -1094,6 +1097,7 @@ notsata:
 			xpt_action(done_ccb);
 			xpt_async(AC_FOUND_DEVICE, done_ccb->ccb_h.path, done_ccb);
 		}
+		PROBE_SET_ACTION(softc, PROBE_DONE);
 		break;
 	}
 	case PROBE_PM_PID:
@@ -1162,6 +1166,7 @@ notsata:
 			xpt_action(done_ccb);
 			xpt_async(AC_SCSI_AEN, done_ccb->ccb_h.path, done_ccb);
 		}
+		PROBE_SET_ACTION(softc, PROBE_DONE);
 		break;
 	case PROBE_IDENTIFY_SES:
 	case PROBE_IDENTIFY_SAFTE:
@@ -1204,12 +1209,10 @@ notsata:
 			xpt_async(AC_FOUND_DEVICE, done_ccb->ccb_h.path,
 			    done_ccb);
 		}
+		PROBE_SET_ACTION(softc, PROBE_DONE);
 		break;
-	case PROBE_INVALID:
-		CAM_DEBUG(done_ccb->ccb_h.path, CAM_DEBUG_INFO,
-		    ("probedone: invalid action state\n"));
 	default:
-		break;
+		panic("probedone: invalid action state 0x%x\n", softc->action);
 	}
 done:
 	if (softc->restart) {
@@ -1219,6 +1222,7 @@ done:
 		return;
 	}
 	xpt_release_ccb(done_ccb);
+	CAM_DEBUG(periph->path, CAM_DEBUG_PROBE, ("Probe completed\n"));
 	while ((done_ccb = (union ccb *)TAILQ_FIRST(&softc->request_ccbs))) {
 		TAILQ_REMOVE(&softc->request_ccbs,
 		    &done_ccb->ccb_h, periph_links.tqe);
diff --git a/sys/cam/scsi/scsi_xpt.c b/sys/cam/scsi/scsi_xpt.c
index 3805a68..fa69bc0 100644
--- a/sys/cam/scsi/scsi_xpt.c
+++ b/sys/cam/scsi/scsi_xpt.c
@@ -141,6 +141,7 @@ typedef enum {
 	PROBE_INQUIRY_BASIC_DV1,
 	PROBE_INQUIRY_BASIC_DV2,
 	PROBE_DV_EXIT,
+	PROBE_DONE,
 	PROBE_INVALID
 } probe_action;
 
@@ -157,6 +158,7 @@ static char *probe_action_text[] = {
 	"PROBE_INQUIRY_BASIC_DV1",
 	"PROBE_INQUIRY_BASIC_DV2",
 	"PROBE_DV_EXIT",
+	"PROBE_DONE",
 	"PROBE_INVALID"
 };
 
@@ -164,7 +166,7 @@ static char *probe_action_text[] = {
 do {									\
 	char **text;							\
 	text = probe_action_text;					\
-	CAM_DEBUG((softc)->periph->path, CAM_DEBUG_INFO,		\
+	CAM_DEBUG((softc)->periph->path, CAM_DEBUG_PROBE,		\
 	    ("Probe %s to %s\n", text[(softc)->action],			\
 	    text[(newaction)]));					\
 	(softc)->action = (newaction);					\
@@ -642,7 +644,7 @@ proberegister(struct cam_periph *periph, void *arg)
 	if (status != CAM_REQ_CMP) {
 		return (status);
 	}
-
+	CAM_DEBUG(periph->path, CAM_DEBUG_PROBE, ("Probe started\n"));
 
 	/*
 	 * Ensure we've waited at least a bus settle
@@ -981,11 +983,8 @@ again:
 		probedone(periph, start_ccb);
 		return;
 	}
-	case PROBE_INVALID:
-		CAM_DEBUG(start_ccb->ccb_h.path, CAM_DEBUG_INFO,
-		    ("probestart: invalid action state\n"));
 	default:
-		break;
+		panic("probestart: invalid action state 0x%x\n", softc->action);
 	}
 	xpt_action(start_ccb);
 }
@@ -1065,7 +1064,7 @@ proberequestbackoff(struct cam_periph *periph, struct cam_ed *device)
 	}
 
 	if (device->flags & CAM_DEV_DV_HIT_BOTTOM) {
-		CAM_DEBUG(periph->path, CAM_DEBUG_INFO,
+		CAM_DEBUG(periph->path, CAM_DEBUG_PROBE,
 		    ("hit async: giving up on DV\n"));
 		return (0);
 	}
@@ -1085,7 +1084,7 @@ proberequestbackoff(struct cam_periph *periph, struct cam_ed *device)
 		if (spi->sync_period >= 0xf) {
 			spi->sync_period = 0;
 			spi->sync_offset = 0;
-			CAM_DEBUG(periph->path, CAM_DEBUG_INFO,
+			CAM_DEBUG(periph->path, CAM_DEBUG_PROBE,
 			    ("setting to async for DV\n"));
 			/*
 			 * Once we hit async, we don't want to try
@@ -1093,7 +1092,7 @@ proberequestbackoff(struct cam_periph *periph, struct cam_ed *device)
 			 */
 			device->flags |= CAM_DEV_DV_HIT_BOTTOM;
 		} else if (bootverbose) {
-			CAM_DEBUG(periph->path, CAM_DEBUG_INFO,
+			CAM_DEBUG(periph->path, CAM_DEBUG_PROBE,
 			    ("DV: period 0x%x\n", spi->sync_period));
 			printf("setting period to 0x%x\n", spi->sync_period);
 		}
@@ -1103,7 +1102,7 @@ proberequestbackoff(struct cam_periph *periph, struct cam_ed *device)
 		if ((cts.ccb_h.status & CAM_STATUS_MASK) == CAM_REQ_CMP) {
 			break;
 		}
-		CAM_DEBUG(periph->path, CAM_DEBUG_INFO,
+		CAM_DEBUG(periph->path, CAM_DEBUG_PROBE,
 		    ("DV: failed to set period 0x%x\n", spi->sync_period));
 		if (spi->sync_period == 0) {
 			return (0);
@@ -1250,6 +1249,7 @@ probedone(struct cam_periph *periph, union ccb *done_ccb)
 		if ((path->device->flags & CAM_DEV_UNCONFIGURED) == 0)
 			/* Send the async notification. */
 			xpt_async(AC_LOST_DEVICE, path, NULL);
+		PROBE_SET_ACTION(softc, PROBE_INVALID);
 
 		xpt_release_ccb(done_ccb);
 		break;
@@ -1283,8 +1283,9 @@ probedone(struct cam_periph *periph, union ccb *done_ccb)
 			/*
 			 * Reallocate and retry to cover all luns
 			 */
-			CAM_DEBUG_PATH_PRINT(CAM_DEBUG_PROBE, path,
-			    ("reallocating REPORT_LUNS for %u luns\n", nlun));
+			CAM_DEBUG(path, CAM_DEBUG_PROBE,
+			    ("Probe: reallocating REPORT_LUNS for %u luns\n",
+			     nlun));
 			free(lp, M_CAMXPT);
 			path->target->rpl_size = (nlun << 3) + 8;
 			xpt_release_ccb(done_ccb);
@@ -1307,8 +1308,8 @@ probedone(struct cam_periph *periph, union ccb *done_ccb)
 			lun_id_t lun;
 			int idx;
 
-			CAM_DEBUG_PATH_PRINT(CAM_DEBUG_PROBE, path,
-			   ("%u luns reported\n", nlun));
+			CAM_DEBUG(path, CAM_DEBUG_PROBE,
+			   ("Probe: %u lun(s) reported\n", nlun));
 
 			CAM_GET_SIMPLE_LUN(lp, 0, lun);
 			/*
@@ -1330,8 +1331,8 @@ probedone(struct cam_periph *periph, union ccb *done_ccb)
 					    lp->luns[idx].lundata, 8);
 					memcpy(lp->luns[idx].lundata,
 					    tlun, 8);
-					CAM_DEBUG_PATH_PRINT(CAM_DEBUG_PROBE,
-					    path, ("lun 0 in position %u\n", idx));
+					CAM_DEBUG(path, CAM_DEBUG_PROBE,
+					    ("lun 0 in position %u\n", idx));
 				} else {
 					/*
 					 * There is no lun 0 in our list. Destroy
@@ -1616,7 +1617,7 @@ probe_device_check:
 		 && done_ccb->ccb_h.target_lun == 0
 		 && (path->device->inq_data.flags & SID_Sync) != 0
                  && (path->device->flags & CAM_DEV_IN_DV) == 0) {
-			CAM_DEBUG(periph->path, CAM_DEBUG_INFO,
+			CAM_DEBUG(periph->path, CAM_DEBUG_PROBE,
 			    ("Begin Domain Validation\n"));
 			path->device->flags |= CAM_DEV_IN_DV;
 			xpt_release_ccb(done_ccb);
@@ -1625,7 +1626,7 @@ probe_device_check:
 			return;
 		}
 		if (softc->action == PROBE_DV_EXIT) {
-			CAM_DEBUG(periph->path, CAM_DEBUG_INFO,
+			CAM_DEBUG(periph->path, CAM_DEBUG_PROBE,
 			    ("Leave Domain Validation\n"));
 		}
 		if (path->device->flags & CAM_DEV_UNCONFIGURED) {
@@ -1641,6 +1642,7 @@ probe_device_check:
 			xpt_async(AC_FOUND_DEVICE, done_ccb->ccb_h.path,
 				  done_ccb);
 		}
+		PROBE_SET_ACTION(softc, PROBE_DONE);
 		xpt_release_ccb(done_ccb);
 		break;
 	case PROBE_INQUIRY_BASIC_DV1:
@@ -1680,7 +1682,7 @@ probe_device_check:
 			return;
 		}
 		if (softc->action == PROBE_INQUIRY_BASIC_DV2) {
-			CAM_DEBUG(periph->path, CAM_DEBUG_INFO,
+			CAM_DEBUG(periph->path, CAM_DEBUG_PROBE,
 			    ("Leave Domain Validation Successfully\n"));
 		}
 		if (path->device->flags & CAM_DEV_UNCONFIGURED) {
@@ -1696,20 +1698,19 @@ probe_device_check:
 			xpt_async(AC_FOUND_DEVICE, done_ccb->ccb_h.path,
 				  done_ccb);
 		}
+		PROBE_SET_ACTION(softc, PROBE_DONE);
 		xpt_release_ccb(done_ccb);
 		break;
 	}
-	case PROBE_INVALID:
-		CAM_DEBUG(done_ccb->ccb_h.path, CAM_DEBUG_INFO,
-		    ("probedone: invalid action state\n"));
 	default:
-		break;
+		panic("probedone: invalid action state 0x%x\n", softc->action);
 	}
 	done_ccb = (union ccb *)TAILQ_FIRST(&softc->request_ccbs);
 	TAILQ_REMOVE(&softc->request_ccbs, &done_ccb->ccb_h, periph_links.tqe);
 	done_ccb->ccb_h.status = CAM_REQ_CMP;
 	xpt_done(done_ccb);
 	if (TAILQ_FIRST(&softc->request_ccbs) == NULL) {
+		CAM_DEBUG(periph->path, CAM_DEBUG_PROBE, ("Probe completed\n"));
 		cam_periph_invalidate(periph);
 		cam_release_devq(periph->path,
 		    RELSIM_RELEASE_RUNLEVEL, 0, CAM_RL_XPT + 1, FALSE);
@@ -1922,7 +1923,7 @@ scsi_scan_bus(struct cam_periph *periph, union ccb *request_ccb)
 			xpt_done(request_ccb);
 			return;
 		}
-		CAM_DEBUG_PATH_PRINT(CAM_DEBUG_PROBE, request_ccb->ccb_h.path,
+		CAM_DEBUG(request_ccb->ccb_h.path, CAM_DEBUG_TRACE,
 		   ("SCAN start for %p\n", scan_info));
 		scan_info->request_ccb = request_ccb;
 		scan_info->cpi = &work_ccb->cpi;
@@ -2035,8 +2036,8 @@ scsi_scan_bus(struct cam_periph *periph, union ccb *request_ccb)
 				CAM_GET_SIMPLE_LUN(target->luns,
 				    scan_info->lunindex[target_id], lun_id);
 				next_target = 0;
-				CAM_DEBUG_PATH_PRINT(CAM_DEBUG_PROBE,
-				    request_ccb->ccb_h.path,
+				CAM_DEBUG(request_ccb->ccb_h.path,
+				    CAM_DEBUG_PROBE,
 				   ("next lun to try at index %u is %u\n",
 				   scan_info->lunindex[target_id], lun_id));
 				scan_info->lunindex[target_id]++;
@@ -2143,8 +2144,8 @@ scsi_scan_bus(struct cam_periph *periph, union ccb *request_ccb)
 				xpt_free_ccb(request_ccb);
 				xpt_free_ccb((union ccb *)scan_info->cpi);
 				request_ccb = scan_info->request_ccb;
-				CAM_DEBUG_PATH_PRINT(CAM_DEBUG_PROBE,
-				    request_ccb->ccb_h.path,
+				CAM_DEBUG(request_ccb->ccb_h.path,
+				    CAM_DEBUG_TRACE,
 				   ("SCAN done for %p\n", scan_info));
 				free(scan_info, M_CAMXPT);
 				request_ccb->ccb_h.status = CAM_REQ_CMP;