Author: scottl
Date: Fri Jul 19 00:12:41 2013
New Revision: 253460
URL: http://svnweb.freebsd.org/changeset/base/253460
Log:
Overhaul error, information, and debug logging.
Obtained from: Netflix
MFC after: 3 days
Modified:
head/sys/dev/mps/mps.c
head/sys/dev/mps/mps_mapping.c
head/sys/dev/mps/mps_pci.c
head/sys/dev/mps/mps_sas.c
head/sys/dev/mps/mps_sas_lsi.c
head/sys/dev/mps/mps_table.c
head/sys/dev/mps/mps_user.c
head/sys/dev/mps/mpsvar.h
Modified: head/sys/dev/mps/mps.c
==============================================================================
--- head/sys/dev/mps/mps.c Thu Jul 18 23:25:57 2013 (r253459)
+++ head/sys/dev/mps/mps.c Fri Jul 19 00:12:41 2013 (r253460)
@@ -81,7 +81,8 @@ static int mps_transition_operational(st
static void mps_startup(void *arg);
static int mps_send_iocinit(struct mps_softc *sc);
static int mps_attach_log(struct mps_softc *sc);
-static __inline void mps_complete_command(struct mps_command *cm);
+static __inline void mps_complete_command(struct mps_softc *sc,
+ struct mps_command *cm);
static void mps_dispatch_event(struct mps_softc *sc, uintptr_t data,
MPI2_EVENT_NOTIFICATION_REPLY *reply);
static void mps_config_complete(struct mps_softc *sc, struct mps_command *cm);
@@ -195,7 +196,7 @@ static int
mps_message_unit_reset(struct mps_softc *sc, int sleep_flag)
{
- mps_dprint(sc, MPS_TRACE, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
mps_regwrite(sc, MPI2_DOORBELL_OFFSET,
MPI2_FUNCTION_IOC_MESSAGE_UNIT_RESET <<
@@ -217,14 +218,14 @@ mps_transition_ready(struct mps_softc *s
int error, tries = 0;
int sleep_flags;
- mps_dprint(sc, MPS_TRACE, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
/* If we are in attach call, do not sleep */
sleep_flags = (sc->mps_flags & MPS_FLAGS_ATTACH_DONE)
? CAN_SLEEP:NO_SLEEP;
error = 0;
while (tries++ < 5) {
reg = mps_regread(sc, MPI2_DOORBELL_OFFSET);
- mps_dprint(sc, MPS_INFO, "Doorbell= 0x%x\n", reg);
+ mps_dprint(sc, MPS_INIT, "Doorbell= 0x%x\n", reg);
/*
* Ensure the IOC is ready to talk. If it's not, try
@@ -250,7 +251,7 @@ mps_transition_ready(struct mps_softc *s
error = 0;
break;
} else if (state == MPI2_IOC_STATE_FAULT) {
- mps_dprint(sc, MPS_INFO, "IOC in fault state 0x%x\n",
+ mps_dprint(sc, MPS_FAULT, "IOC in fault state 0x%x,
resetting\n",
state & MPI2_DOORBELL_FAULT_CODE_MASK);
mps_diag_reset(sc, sleep_flags);
} else if (state == MPI2_IOC_STATE_OPERATIONAL) {
@@ -283,11 +284,11 @@ mps_transition_operational(struct mps_so
uint32_t reg, state;
int error;
- mps_dprint(sc, MPS_TRACE, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
error = 0;
reg = mps_regread(sc, MPI2_DOORBELL_OFFSET);
- mps_dprint(sc, MPS_INFO, "Doorbell= 0x%x\n", reg);
+ mps_dprint(sc, MPS_INIT, "Doorbell= 0x%x\n", reg);
state = reg & MPI2_IOC_STATE_MASK;
if (state != MPI2_IOC_STATE_READY) {
@@ -318,25 +319,28 @@ mps_reinit(struct mps_softc *sc)
int error;
uint32_t db;
- mps_printf(sc, "%s sc %p\n", __func__, sc);
+ MPS_FUNCTRACE(sc);
mtx_assert(&sc->mps_mtx, MA_OWNED);
if (sc->mps_flags & MPS_FLAGS_DIAGRESET) {
- mps_printf(sc, "%s reset already in progress\n", __func__);
+ mps_dprint(sc, MPS_INIT, "%s reset already in progress\n",
+ __func__);
return 0;
}
+ mps_dprint(sc, MPS_INFO, "Reinitializing controller,\n");
/* make sure the completion callbacks can recognize they're getting
* a NULL cm_reply due to a reset.
*/
sc->mps_flags |= MPS_FLAGS_DIAGRESET;
- mps_printf(sc, "%s mask interrupts\n", __func__);
+ mps_dprint(sc, MPS_INIT, "%s mask interrupts\n", __func__);
mps_mask_intr(sc);
error = mps_diag_reset(sc, CAN_SLEEP);
if (error != 0) {
+ /* XXXSL No need to panic here */
panic("%s hard reset failed with error %d\n",
__func__, error);
}
@@ -354,6 +358,7 @@ mps_reinit(struct mps_softc *sc)
/* get the chip out of the reset state */
error = mps_transition_operational(sc);
if (error != 0)
+ /* XXXSL No need to panic here */
panic("%s transition operational failed with error %d\n",
__func__, error);
@@ -368,14 +373,14 @@ mps_reinit(struct mps_softc *sc)
mps_regwrite(sc, MPI2_REPLY_POST_HOST_INDEX_OFFSET, sc->replypostindex);
db = mps_regread(sc, MPI2_DOORBELL_OFFSET);
- mps_printf(sc, "%s doorbell 0x%08x\n", __func__, db);
+ mps_dprint(sc, MPS_INIT, "%s doorbell 0x%08x\n", __func__, db);
- mps_printf(sc, "%s unmask interrupts post %u free %u\n", __func__,
- sc->replypostindex, sc->replyfreeindex);
+ mps_dprint(sc, MPS_INIT, "%s unmask interrupts post %u free %u\n",
+ __func__, sc->replypostindex, sc->replyfreeindex);
mps_unmask_intr(sc);
- mps_printf(sc, "%s restarting post %u free %u\n", __func__,
+ mps_dprint(sc, MPS_INIT, "%s restarting post %u free %u\n", __func__,
sc->replypostindex, sc->replyfreeindex);
/* restart will reload the event masks clobbered by the reset, and
@@ -384,9 +389,8 @@ mps_reinit(struct mps_softc *sc)
mps_reregister_events(sc);
/* the end of discovery will release the simq, so we're done. */
- mps_printf(sc, "%s finished sc %p post %u free %u\n",
- __func__, sc,
- sc->replypostindex, sc->replyfreeindex);
+ mps_dprint(sc, MPS_INFO, "%s finished sc %p post %u free %u\n",
+ __func__, sc, sc->replypostindex, sc->replyfreeindex);
sc->mps_flags &= ~MPS_FLAGS_DIAGRESET;
@@ -411,7 +415,7 @@ mps_wait_db_ack(struct mps_softc *sc, in
do {
int_status = mps_regread(sc, MPI2_HOST_INTERRUPT_STATUS_OFFSET);
if (!(int_status & MPI2_HIS_SYS2IOC_DB_STATUS)) {
- mps_dprint(sc, MPS_INFO,
+ mps_dprint(sc, MPS_INIT,
"%s: successfull count(%d), timeout(%d)\n",
__func__, count, timeout);
return 0;
@@ -546,7 +550,7 @@ mps_request_sync(struct mps_softc *sc, v
count = MIN((reply_sz / 4), ioc_sz) * 2;
if (count < ioc_sz * 2) {
residual = ioc_sz * 2 - count;
- mps_dprint(sc, MPS_FAULT, "Driver error, throwing away %d "
+ mps_dprint(sc, MPS_ERROR, "Driver error, throwing away %d "
"residual message words\n", residual);
}
@@ -592,7 +596,8 @@ static void
mps_enqueue_request(struct mps_softc *sc, struct mps_command *cm)
{
reply_descriptor rd;
- mps_dprint(sc, MPS_TRACE, "%s SMID %u cm %p ccb %p\n", __func__,
+ MPS_FUNCTRACE(sc);
+ mps_dprint(sc, MPS_TRACE, "SMID %u cm %p ccb %p\n",
cm->cm_desc.Default.SMID, cm, cm->cm_ccb);
if (sc->mps_flags & MPS_FLAGS_ATTACH_DONE && !(sc->mps_flags &
MPS_FLAGS_SHUTDOWN))
@@ -620,7 +625,7 @@ mps_get_iocfacts(struct mps_softc *sc, M
MPI2_IOC_FACTS_REQUEST request;
int error, req_sz, reply_sz;
- mps_dprint(sc, MPS_TRACE, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
req_sz = sizeof(MPI2_IOC_FACTS_REQUEST);
reply_sz = sizeof(MPI2_IOC_FACTS_REPLY);
@@ -641,7 +646,7 @@ mps_get_portfacts(struct mps_softc *sc,
struct mps_command *cm;
int error;
- mps_dprint(sc, MPS_TRACE, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
if ((cm = mps_alloc_command(sc)) == NULL)
return (EBUSY);
@@ -677,7 +682,7 @@ mps_send_iocinit(struct mps_softc *sc)
MPI2_DEFAULT_REPLY reply;
int req_sz, reply_sz, error;
- mps_dprint(sc, MPS_TRACE, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
req_sz = sizeof(MPI2_IOC_INIT_REQUEST);
reply_sz = sizeof(MPI2_IOC_INIT_REPLY);
@@ -711,7 +716,7 @@ mps_send_iocinit(struct mps_softc *sc)
if ((reply.IOCStatus & MPI2_IOCSTATUS_MASK) != MPI2_IOCSTATUS_SUCCESS)
error = ENXIO;
- mps_dprint(sc, MPS_INFO, "IOCInit status= 0x%x\n", reply.IOCStatus);
+ mps_dprint(sc, MPS_INIT, "IOCInit status= 0x%x\n", reply.IOCStatus);
return (error);
}
@@ -1008,7 +1013,7 @@ mps_get_tunables(struct mps_softc *sc)
char tmpstr[80];
/* XXX default to some debugging for now */
- sc->mps_debug = MPS_FAULT;
+ sc->mps_debug = MPS_INFO|MPS_FAULT;
sc->disable_msix = 0;
sc->disable_msi = 0;
sc->max_chains = MPS_CHAIN_FRAMES;
@@ -1123,7 +1128,7 @@ mps_attach(struct mps_softc *sc)
mps_get_tunables(sc);
- mps_dprint(sc, MPS_TRACE, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
mtx_init(&sc->mps_mtx, "MPT2SAS lock", NULL, MTX_DEF);
callout_init_mtx(&sc->periodic, &sc->mps_mtx, 0);
@@ -1297,7 +1302,7 @@ mps_attach(struct mps_softc *sc)
sc->mps_ich.ich_func = mps_startup;
sc->mps_ich.ich_arg = sc;
if (config_intrhook_establish(&sc->mps_ich) != 0) {
- mps_dprint(sc, MPS_FAULT, "Cannot establish MPS config hook\n");
+ mps_dprint(sc, MPS_ERROR, "Cannot establish MPS config hook\n");
error = EINVAL;
}
@@ -1308,7 +1313,7 @@ mps_attach(struct mps_softc *sc)
mpssas_ir_shutdown, sc, SHUTDOWN_PRI_DEFAULT);
if (sc->shutdown_eh == NULL)
- mps_dprint(sc, MPS_FAULT, "shutdown event registration "
+ mps_dprint(sc, MPS_ERROR, "shutdown event registration "
"failed\n");
mps_setup_sysctl(sc);
@@ -1347,8 +1352,7 @@ mps_periodic(void *arg)
db = mps_regread(sc, MPI2_DOORBELL_OFFSET);
if ((db & MPI2_IOC_STATE_MASK) == MPI2_IOC_STATE_FAULT) {
- device_printf(sc->mps_dev, "IOC Fault 0x%08x, Resetting\n", db);
-
+ mps_dprint(sc, MPS_FAULT, "IOC Fault 0x%08x, Resetting\n", db);
mps_reinit(sc);
}
@@ -1365,12 +1369,13 @@ mps_log_evt_handler(struct mps_softc *sc
switch (event->Event) {
case MPI2_EVENT_LOG_DATA:
- device_printf(sc->mps_dev, "MPI2_EVENT_LOG_DATA:\n");
- hexdump(event->EventData, event->EventDataLength, NULL, 0);
+ mps_dprint(sc, MPS_EVENT, "MPI2_EVENT_LOG_DATA:\n");
+ if (sc->mps_debug & MPS_EVENT)
+ hexdump(event->EventData, event->EventDataLength, NULL,
0);
break;
case MPI2_EVENT_LOG_ENTRY_ADDED:
entry = (MPI2_EVENT_DATA_LOG_ENTRY_ADDED *)event->EventData;
- mps_dprint(sc, MPS_INFO, "MPI2_EVENT_LOG_ENTRY_ADDED event "
+ mps_dprint(sc, MPS_EVENT, "MPI2_EVENT_LOG_ENTRY_ADDED event "
"0x%x Sequence %d:\n", entry->LogEntryQualifier,
entry->LogSequence);
break;
@@ -1504,29 +1509,35 @@ mps_free(struct mps_softc *sc)
}
static __inline void
-mps_complete_command(struct mps_command *cm)
+mps_complete_command(struct mps_softc *sc, struct mps_command *cm)
{
+ MPS_FUNCTRACE(sc);
+
+ if (cm == NULL) {
+ mps_dprint(sc, MPS_ERROR, "Completing NULL command\n");
+ return;
+ }
+
if (cm->cm_flags & MPS_CM_FLAGS_POLLED)
cm->cm_flags |= MPS_CM_FLAGS_COMPLETE;
if (cm->cm_complete != NULL) {
- mps_dprint(cm->cm_sc, MPS_TRACE,
+ mps_dprint(sc, MPS_TRACE,
"%s cm %p calling cm_complete %p data %p reply %p\n",
__func__, cm, cm->cm_complete, cm->cm_complete_data,
cm->cm_reply);
- cm->cm_complete(cm->cm_sc, cm);
+ cm->cm_complete(sc, cm);
}
if (cm->cm_flags & MPS_CM_FLAGS_WAKEUP) {
- mps_dprint(cm->cm_sc, MPS_TRACE, "%s: waking up %p\n",
- __func__, cm);
+ mps_dprint(sc, MPS_TRACE, "waking up %p\n", cm);
wakeup(cm);
}
if (cm->cm_sc->io_cmds_active != 0) {
cm->cm_sc->io_cmds_active--;
} else {
- mps_dprint(cm->cm_sc, MPS_INFO, "Warning: io_cmds_active is "
+ mps_dprint(sc, MPS_ERROR, "Warning: io_cmds_active is "
"out of sync - resynching to 0\n");
}
}
@@ -1572,7 +1583,7 @@ mps_sas_log_info(struct mps_softc *sc ,
break;
}
- mps_dprint(sc, MPS_INFO, "log_info(0x%08x): originator(%s), "
+ mps_dprint(sc, MPS_LOG, "log_info(0x%08x): originator(%s), "
"code(0x%02x), sub_code(0x%04x)\n", log_info,
originator_str, sas_loginfo.dw.code,
sas_loginfo.dw.subcode);
@@ -1750,7 +1761,7 @@ mps_intr_locked(void *data)
case MPI2_RPY_DESCRIPT_FLAGS_RAID_ACCELERATOR_SUCCESS:
default:
/* Unhandled */
- device_printf(sc->mps_dev, "Unhandled reply 0x%x\n",
+ mps_dprint(sc, MPS_ERROR, "Unhandled reply 0x%x\n",
desc->Default.ReplyFlags);
cm = NULL;
break;
@@ -1761,7 +1772,7 @@ mps_intr_locked(void *data)
// Print Error reply frame
if (cm->cm_reply)
mps_display_reply_info(sc,cm->cm_reply);
- mps_complete_command(cm);
+ mps_complete_command(sc, cm);
}
desc->Words.Low = 0xffffffff;
@@ -1794,7 +1805,7 @@ mps_dispatch_event(struct mps_softc *sc,
}
if (handled == 0)
- device_printf(sc->mps_dev, "Unhandled event 0x%x\n",
le16toh(event));
+ mps_dprint(sc, MPS_EVENT, "Unhandled event 0x%x\n",
le16toh(event));
/*
* This is the only place that the event/reply should be freed.
@@ -2197,7 +2208,8 @@ mps_data_cb(void *arg, bus_dma_segment_t
* user they did the wrong thing.
*/
if ((cm->cm_max_segs != 0) && (nsegs > cm->cm_max_segs)) {
- mps_printf(sc, "%s: warning: busdma returned %d segments, "
+ mps_dprint(sc, MPS_ERROR,
+ "%s: warning: busdma returned %d segments, "
"more than the %d allowed\n", __func__, nsegs,
cm->cm_max_segs);
}
@@ -2243,9 +2255,10 @@ mps_data_cb(void *arg, bus_dma_segment_t
sflags, nsegs - i);
if (error != 0) {
/* Resource shortage, roll back! */
- mps_dprint(sc, MPS_INFO, "out of chain frames\n");
+ mps_dprint(sc, MPS_INFO, "Out of chain frames, "
+ "consider increasing hw.mps.max_chains.\n");
cm->cm_flags |= MPS_CM_FLAGS_CHAIN_FAILED;
- mps_complete_command(cm);
+ mps_complete_command(sc, cm);
return;
}
}
@@ -2444,6 +2457,7 @@ mps_config_complete(struct mps_softc *sc
MPI2_CONFIG_REPLY *reply;
struct mps_config_params *params;
+ MPS_FUNCTRACE(sc);
params = cm->cm_complete_data;
if (cm->cm_data != NULL) {
Modified: head/sys/dev/mps/mps_mapping.c
==============================================================================
--- head/sys/dev/mps/mps_mapping.c Thu Jul 18 23:25:57 2013
(r253459)
+++ head/sys/dev/mps/mps_mapping.c Fri Jul 19 00:12:41 2013
(r253460)
@@ -927,8 +927,9 @@ _mapping_get_dev_info(struct mps_softc *
sas_address = (sas_address << 32) |
sas_device_pg0.SASAddress.Low;
}
- mps_dprint(sc, MPS_INFO, "SAS Address for SATA "
- "device = %jx\n", sas_address);
+ mps_dprint(sc, MPS_MAPPING,
+ "SAS Address for SATA device = %jx\n",
+ sas_address);
} else {
sas_address =
sas_device_pg0.SASAddress.High;
Modified: head/sys/dev/mps/mps_pci.c
==============================================================================
--- head/sys/dev/mps/mps_pci.c Thu Jul 18 23:25:57 2013 (r253459)
+++ head/sys/dev/mps/mps_pci.c Fri Jul 19 00:12:41 2013 (r253460)
@@ -198,11 +198,11 @@ mps_pci_attach(device_t dev)
pci_write_config(dev, PCIR_COMMAND, command, 2);
command = pci_read_config(dev, PCIR_COMMAND, 2);
if ((command & PCIM_CMD_BUSMASTEREN) == 0) {
- device_printf(dev, "Cannot enable PCI busmaster\n");
+ mps_printf(sc, "Cannot enable PCI busmaster\n");
return (ENXIO);
}
if ((command & PCIM_CMD_MEMEN) == 0) {
- device_printf(dev, "PCI memory window not available\n");
+ mps_printf(sc, "PCI memory window not available\n");
return (ENXIO);
}
@@ -210,7 +210,7 @@ mps_pci_attach(device_t dev)
sc->mps_regs_rid = PCIR_BAR(1);
if ((sc->mps_regs_resource = bus_alloc_resource_any(dev,
SYS_RES_MEMORY, &sc->mps_regs_rid, RF_ACTIVE)) == NULL) {
- device_printf(dev, "Cannot allocate PCI registers\n");
+ mps_printf(sc, "Cannot allocate PCI registers\n");
return (ENXIO);
}
sc->mps_btag = rman_get_bustag(sc->mps_regs_resource);
@@ -228,7 +228,7 @@ mps_pci_attach(device_t dev)
0, /* flags */
NULL, NULL, /* lockfunc, lockarg */
&sc->mps_parent_dmat)) {
- device_printf(dev, "Cannot allocate parent DMA tag\n");
+ mps_printf(sc, "Cannot allocate parent DMA tag\n");
mps_pci_free(sc);
return (ENOMEM);
}
@@ -260,14 +260,14 @@ mps_pci_setup_interrupts(struct mps_soft
sc->mps_irq[0] = bus_alloc_resource_any(dev, SYS_RES_IRQ,
&sc->mps_irq_rid[0], RF_SHAREABLE | RF_ACTIVE);
if (sc->mps_irq[0] == NULL) {
- device_printf(dev, "Cannot allocate INTx interrupt\n");
+ mps_printf(sc, "Cannot allocate INTx interrupt\n");
return (ENXIO);
}
error = bus_setup_intr(dev, sc->mps_irq[0],
INTR_TYPE_BIO | INTR_MPSAFE, NULL, mps_intr, sc,
&sc->mps_intrhand[0]);
if (error)
- device_printf(dev, "Cannot setup INTx interrupt\n");
+ mps_printf(sc, "Cannot setup INTx interrupt\n");
} else {
sc->mps_flags |= MPS_FLAGS_MSI;
for (i = 0; i < MPS_MSI_COUNT; i++) {
@@ -275,7 +275,7 @@ mps_pci_setup_interrupts(struct mps_soft
sc->mps_irq[i] = bus_alloc_resource_any(dev,
SYS_RES_IRQ, &sc->mps_irq_rid[i], RF_ACTIVE);
if (sc->mps_irq[i] == NULL) {
- device_printf(dev,
+ mps_printf(sc,
"Cannot allocate MSI interrupt\n");
return (ENXIO);
}
@@ -283,7 +283,7 @@ mps_pci_setup_interrupts(struct mps_soft
INTR_TYPE_BIO | INTR_MPSAFE, NULL, mps_intr_msi,
sc, &sc->mps_intrhand[i]);
if (error) {
- device_printf(dev,
+ mps_printf(sc,
"Cannot setup MSI interrupt %d\n", i);
break;
}
Modified: head/sys/dev/mps/mps_sas.c
==============================================================================
--- head/sys/dev/mps/mps_sas.c Thu Jul 18 23:25:57 2013 (r253459)
+++ head/sys/dev/mps/mps_sas.c Fri Jul 19 00:12:41 2013 (r253460)
@@ -175,14 +175,16 @@ mpssas_find_target_by_handle(struct mpss
void
mpssas_startup_increment(struct mpssas_softc *sassc)
{
+ MPS_FUNCTRACE(sassc->sc);
+
if ((sassc->flags & MPSSAS_IN_STARTUP) != 0) {
if (sassc->startup_refcount++ == 0) {
/* just starting, freeze the simq */
- mps_dprint(sassc->sc, MPS_INFO,
+ mps_dprint(sassc->sc, MPS_INIT,
"%s freezing simq\n", __func__);
xpt_freeze_simq(sassc->sim, 1);
}
- mps_dprint(sassc->sc, MPS_TRACE, "%s refcount %u\n", __func__,
+ mps_dprint(sassc->sc, MPS_INIT, "%s refcount %u\n", __func__,
sassc->startup_refcount);
}
}
@@ -190,18 +192,20 @@ mpssas_startup_increment(struct mpssas_s
void
mpssas_startup_decrement(struct mpssas_softc *sassc)
{
+ MPS_FUNCTRACE(sassc->sc);
+
if ((sassc->flags & MPSSAS_IN_STARTUP) != 0) {
if (--sassc->startup_refcount == 0) {
/* finished all discovery-related actions, release
* the simq and rescan for the latest topology.
*/
- mps_dprint(sassc->sc, MPS_INFO,
+ mps_dprint(sassc->sc, MPS_INIT,
"%s releasing simq\n", __func__);
sassc->flags &= ~MPSSAS_IN_STARTUP;
xpt_release_simq(sassc->sim, 1);
mpssas_rescan_target(sassc->sc, NULL);
}
- mps_dprint(sassc->sc, MPS_TRACE, "%s refcount %u\n", __func__,
+ mps_dprint(sassc->sc, MPS_INIT, "%s refcount %u\n", __func__,
sassc->startup_refcount);
}
}
@@ -215,13 +219,15 @@ mpssas_alloc_tm(struct mps_softc *sc)
{
struct mps_command *tm;
+ MPS_FUNCTRACE(sc);
tm = mps_alloc_high_priority_command(sc);
if (tm != NULL) {
if (sc->sassc->tm_count++ == 0) {
- mps_printf(sc, "%s freezing simq\n", __func__);
+ mps_dprint(sc, MPS_RECOVERY,
+ "%s freezing simq\n", __func__);
xpt_freeze_simq(sc->sassc->sim, 1);
}
- mps_dprint(sc, MPS_TRACE, "%s tm_count %u\n", __func__,
+ mps_dprint(sc, MPS_RECOVERY, "%s tm_count %u\n", __func__,
sc->sassc->tm_count);
}
return tm;
@@ -230,6 +236,7 @@ mpssas_alloc_tm(struct mps_softc *sc)
void
mpssas_free_tm(struct mps_softc *sc, struct mps_command *tm)
{
+ mps_dprint(sc, MPS_TRACE, "%s", __func__);
if (tm == NULL)
return;
@@ -238,10 +245,10 @@ mpssas_free_tm(struct mps_softc *sc, str
* release the simq.
*/
if (--sc->sassc->tm_count == 0) {
- mps_printf(sc, "%s releasing simq\n", __func__);
+ mps_dprint(sc, MPS_RECOVERY, "%s releasing simq\n", __func__);
xpt_release_simq(sc->sassc->sim, 1);
}
- mps_dprint(sc, MPS_TRACE, "%s tm_count %u\n", __func__,
+ mps_dprint(sc, MPS_RECOVERY, "%s tm_count %u\n", __func__,
sc->sassc->tm_count);
mps_free_high_priority_command(sc, tm);
@@ -256,6 +263,7 @@ mpssas_rescan_target(struct mps_softc *s
target_id_t targetid;
union ccb *ccb;
+ MPS_FUNCTRACE(sc);
pathid = cam_sim_path(sassc->sim);
if (targ == NULL)
targetid = CAM_TARGET_WILDCARD;
@@ -267,13 +275,13 @@ mpssas_rescan_target(struct mps_softc *s
*/
ccb = xpt_alloc_ccb_nowait();
if (ccb == NULL) {
- mps_dprint(sc, MPS_FAULT, "unable to alloc CCB for rescan\n");
+ mps_dprint(sc, MPS_ERROR, "unable to alloc CCB for rescan\n");
return;
}
if (xpt_create_path(&ccb->ccb_h.path, NULL, pathid,
targetid, CAM_LUN_WILDCARD) != CAM_REQ_CMP) {
- mps_dprint(sc, MPS_FAULT, "unable to create path for rescan\n");
+ mps_dprint(sc, MPS_ERROR, "unable to create path for rescan\n");
xpt_free_ccb(ccb);
return;
}
@@ -288,7 +296,7 @@ mpssas_rescan_target(struct mps_softc *s
}
static void
-mpssas_log_command(struct mps_command *cm, const char *fmt, ...)
+mpssas_log_command(struct mps_command *cm, u_int level, const char *fmt, ...)
{
struct sbuf sb;
va_list ap;
@@ -324,7 +332,7 @@ mpssas_log_command(struct mps_command *c
sbuf_printf(&sb, "SMID %u ", cm->cm_desc.Default.SMID);
sbuf_vprintf(&sb, fmt, ap);
sbuf_finish(&sb);
- printf("%s", sbuf_data(&sb));
+ mps_dprint_field(cm->cm_sc, level, "%s", sbuf_data(&sb));
va_end(ap);
}
@@ -337,7 +345,7 @@ mpssas_remove_volume(struct mps_softc *s
struct mpssas_target *targ;
uint16_t handle;
- mps_dprint(sc, MPS_INFO, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
reply = (MPI2_SCSI_TASK_MANAGE_REPLY *)tm->cm_reply;
handle = (uint16_t)(uintptr_t)tm->cm_complete_data;
@@ -345,24 +353,27 @@ mpssas_remove_volume(struct mps_softc *s
if (reply == NULL) {
/* XXX retry the remove after the diag reset completes? */
- mps_printf(sc, "%s NULL reply reseting device 0x%04x\n",
- __func__, handle);
+ mps_dprint(sc, MPS_FAULT,
+ "%s NULL reply reseting device 0x%04x\n", __func__, handle);
mpssas_free_tm(sc, tm);
return;
}
if (reply->IOCStatus != MPI2_IOCSTATUS_SUCCESS) {
- mps_printf(sc, "IOCStatus = 0x%x while resetting device 0x%x\n",
+ mps_dprint(sc, MPS_FAULT,
+ "IOCStatus = 0x%x while resetting device 0x%x\n",
reply->IOCStatus, handle);
mpssas_free_tm(sc, tm);
return;
}
- mps_printf(sc, "Reset aborted %u commands\n", reply->TerminationCount);
+ mps_dprint(sc, MPS_XINFO,
+ "Reset aborted %u commands\n", reply->TerminationCount);
mps_free_reply(sc, tm->cm_reply_data);
tm->cm_reply = NULL; /* Ensures the reply won't get re-freed */
- mps_printf(sc, "clearing target %u handle 0x%04x\n", targ->tid, handle);
+ mps_dprint(sc, MPS_XINFO,
+ "clearing target %u handle 0x%04x\n", targ->tid, handle);
/*
* Don't clear target if remove fails because things will get confusing.
@@ -398,7 +409,7 @@ mpssas_prepare_volume_remove(struct mpss
struct mps_command *cm;
struct mpssas_target *targ = NULL;
- mps_dprint(sassc->sc, MPS_INFO, "%s\n", __func__);
+ MPS_FUNCTRACE(sassc->sc);
sc = sassc->sc;
#ifdef WD_SUPPORT
@@ -417,7 +428,8 @@ mpssas_prepare_volume_remove(struct mpss
if (targ == NULL) {
/* FIXME: what is the action? */
/* We don't know about this device? */
- printf("%s %d : invalid handle 0x%x \n", __func__,__LINE__,
handle);
+ mps_dprint(sc, MPS_ERROR,
+ "%s %d : invalid handle 0x%x \n", __func__,__LINE__, handle);
return;
}
@@ -425,7 +437,8 @@ mpssas_prepare_volume_remove(struct mpss
cm = mpssas_alloc_tm(sc);
if (cm == NULL) {
- mps_printf(sc, "%s: command alloc failure\n", __func__);
+ mps_dprint(sc, MPS_ERROR,
+ "%s: command alloc failure\n", __func__);
return;
}
@@ -465,7 +478,7 @@ mpssas_prepare_remove(struct mpssas_soft
struct mps_command *cm;
struct mpssas_target *targ = NULL;
- mps_dprint(sassc->sc, MPS_INFO, "%s\n", __func__);
+ MPS_FUNCTRACE(sassc->sc);
sc = sassc->sc;
@@ -473,7 +486,8 @@ mpssas_prepare_remove(struct mpssas_soft
if (targ == NULL) {
/* FIXME: what is the action? */
/* We don't know about this device? */
- printf("%s %d : invalid handle 0x%x \n", __func__,__LINE__,
handle);
+ mps_dprint(sc, MPS_ERROR,
+ "%s : invalid handle 0x%x \n", __func__, handle);
return;
}
@@ -481,7 +495,8 @@ mpssas_prepare_remove(struct mpssas_soft
cm = mpssas_alloc_tm(sc);
if (cm == NULL) {
- mps_printf(sc, "%s: command alloc failure\n", __func__);
+ mps_dprint(sc, MPS_ERROR,
+ "%s: command alloc failure\n", __func__);
return;
}
@@ -513,7 +528,7 @@ mpssas_remove_device(struct mps_softc *s
struct mps_command *next_cm;
uint16_t handle;
- mps_dprint(sc, MPS_INFO, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
reply = (MPI2_SCSI_TASK_MANAGE_REPLY *)tm->cm_reply;
handle = (uint16_t)(uintptr_t)tm->cm_complete_data;
@@ -525,29 +540,31 @@ mpssas_remove_device(struct mps_softc *s
* task management commands don't have S/G lists.
*/
if ((tm->cm_flags & MPS_CM_FLAGS_ERROR_MASK) != 0) {
- mps_printf(sc, "%s: cm_flags = %#x for remove of handle %#04x! "
- "This should not happen!\n", __func__, tm->cm_flags,
- handle);
+ mps_dprint(sc, MPS_ERROR,
+ "%s: cm_flags = %#x for remove of handle %#04x! "
+ "This should not happen!\n", __func__, tm->cm_flags,
+ handle);
mpssas_free_tm(sc, tm);
return;
}
if (reply == NULL) {
/* XXX retry the remove after the diag reset completes? */
- mps_printf(sc, "%s NULL reply reseting device 0x%04x\n",
- __func__, handle);
+ mps_dprint(sc, MPS_FAULT,
+ "%s NULL reply reseting device 0x%04x\n", __func__, handle);
mpssas_free_tm(sc, tm);
return;
}
if (le16toh(reply->IOCStatus) != MPI2_IOCSTATUS_SUCCESS) {
- mps_printf(sc, "IOCStatus = 0x%x while resetting device 0x%x\n",
+ mps_dprint(sc, MPS_FAULT,
+ "IOCStatus = 0x%x while resetting device 0x%x\n",
le16toh(reply->IOCStatus), handle);
mpssas_free_tm(sc, tm);
return;
}
- mps_dprint(sc, MPS_INFO, "Reset aborted %u commands\n",
+ mps_dprint(sc, MPS_XINFO, "Reset aborted %u commands\n",
le32toh(reply->TerminationCount));
mps_free_reply(sc, tm->cm_reply_data);
tm->cm_reply = NULL; /* Ensures the reply won't get re-freed */
@@ -565,12 +582,12 @@ mpssas_remove_device(struct mps_softc *s
mps_map_command(sc, tm);
- mps_dprint(sc, MPS_INFO, "clearing target %u handle 0x%04x\n",
+ mps_dprint(sc, MPS_XINFO, "clearing target %u handle 0x%04x\n",
targ->tid, handle);
TAILQ_FOREACH_SAFE(tm, &targ->commands, cm_link, next_cm) {
union ccb *ccb;
- mps_dprint(sc, MPS_INFO, "Completing missed command %p\n", tm);
+ mps_dprint(sc, MPS_XINFO, "Completing missed command %p\n", tm);
ccb = tm->cm_complete_data;
ccb->ccb_h.status = CAM_DEV_NOT_THERE;
mpssas_scsiio_complete(sc, tm);
@@ -585,7 +602,7 @@ mpssas_remove_complete(struct mps_softc
struct mpssas_target *targ;
struct mpssas_lun *lun;
- mps_dprint(sc, MPS_INFO, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
reply = (MPI2_SAS_IOUNIT_CONTROL_REPLY *)tm->cm_reply;
handle = (uint16_t)(uintptr_t)tm->cm_complete_data;
@@ -596,7 +613,8 @@ mpssas_remove_complete(struct mps_softc
* task management commands don't have S/G lists.
*/
if ((tm->cm_flags & MPS_CM_FLAGS_ERROR_MASK) != 0) {
- mps_printf(sc, "%s: cm_flags = %#x for remove of handle %#04x! "
+ mps_dprint(sc, MPS_XINFO,
+ "%s: cm_flags = %#x for remove of handle %#04x! "
"This should not happen!\n", __func__, tm->cm_flags,
handle);
mpssas_free_tm(sc, tm);
@@ -605,13 +623,14 @@ mpssas_remove_complete(struct mps_softc
if (reply == NULL) {
/* most likely a chip reset */
- mps_printf(sc, "%s NULL reply removing device 0x%04x\n",
- __func__, handle);
+ mps_dprint(sc, MPS_FAULT,
+ "%s NULL reply removing device 0x%04x\n", __func__, handle);
mpssas_free_tm(sc, tm);
return;
}
- mps_printf(sc, "%s on handle 0x%04x, IOCStatus= 0x%x\n", __func__,
+ mps_dprint(sc, MPS_XINFO,
+ "%s on handle 0x%04x, IOCStatus= 0x%x\n", __func__,
handle, le16toh(reply->IOCStatus));
/*
@@ -676,7 +695,7 @@ mps_attach_sas(struct mps_softc *sc)
#endif
int unit, error = 0;
- mps_dprint(sc, MPS_TRACE, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
sassc = malloc(sizeof(struct mpssas_softc), M_MPT2, M_WAITOK|M_ZERO);
if(!sassc) {
@@ -696,7 +715,7 @@ mps_attach_sas(struct mps_softc *sc)
sassc->sc = sc;
if ((sassc->devq = cam_simq_alloc(sc->num_reqs)) == NULL) {
- mps_dprint(sc, MPS_FAULT, "Cannot allocate SIMQ\n");
+ mps_dprint(sc, MPS_ERROR, "Cannot allocate SIMQ\n");
error = ENOMEM;
goto out;
}
@@ -705,7 +724,7 @@ mps_attach_sas(struct mps_softc *sc)
sassc->sim = cam_sim_alloc(mpssas_action, mpssas_poll, "mps", sassc,
unit, &sc->mps_mtx, sc->num_reqs, sc->num_reqs, sassc->devq);
if (sassc->sim == NULL) {
- mps_dprint(sc, MPS_FAULT, "Cannot allocate SIM\n");
+ mps_dprint(sc, MPS_ERROR, "Cannot allocate SIM\n");
error = EINVAL;
goto out;
}
@@ -738,7 +757,7 @@ mps_attach_sas(struct mps_softc *sc)
* everything is just a target on a single bus.
*/
if ((error = xpt_bus_register(sassc->sim, sc->mps_dev, 0)) != 0) {
- mps_dprint(sc, MPS_FAULT, "Error %d registering SCSI bus\n",
+ mps_dprint(sc, MPS_ERROR, "Error %d registering SCSI bus\n",
error);
mps_unlock(sc);
goto out;
@@ -761,8 +780,9 @@ mps_attach_sas(struct mps_softc *sc)
#if __FreeBSD_version >= 1000006
status = xpt_register_async(AC_ADVINFO_CHANGED, mpssas_async, sc, NULL);
if (status != CAM_REQ_CMP) {
- mps_printf(sc, "Error %#x registering async handler for "
- "AC_ADVINFO_CHANGED events\n", status);
+ mps_dprint(sc, MPS_ERROR,
+ "Error %#x registering async handler for "
+ "AC_ADVINFO_CHANGED events\n", status);
}
#endif
@@ -783,7 +803,7 @@ mps_detach_sas(struct mps_softc *sc)
struct mpssas_target *targ;
int i;
- mps_dprint(sc, MPS_INFO, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
if (sc->sassc == NULL)
return (0);
@@ -826,7 +846,6 @@ mps_detach_sas(struct mps_softc *sc)
}
mps_unlock(sc);
- mps_dprint(sc, MPS_INFO, "%s:%d\n", __func__,__LINE__);
if (sassc->devq != NULL)
cam_simq_free(sassc->devq);
@@ -848,7 +867,7 @@ mpssas_discovery_end(struct mpssas_softc
{
struct mps_softc *sc = sassc->sc;
- mps_dprint(sc, MPS_TRACE, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
if (sassc->flags & MPSSAS_DISCOVERY_TIMEOUT_PENDING)
callout_stop(&sassc->discovery_callout);
@@ -862,17 +881,17 @@ mpssas_discovery_timeout(void *data)
struct mps_softc *sc;
sc = sassc->sc;
- mps_dprint(sc, MPS_TRACE, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
mps_lock(sc);
- mps_printf(sc,
+ mps_dprint(sc, MPS_INFO,
"Timeout waiting for discovery, interrupts may not be working!\n");
sassc->flags &= ~MPSSAS_DISCOVERY_TIMEOUT_PENDING;
/* Poll the hardware for events in case interrupts aren't working */
mps_intr_locked(sc);
- mps_printf(sassc->sc,
+ mps_dprint(sassc->sc, MPS_INFO,
"Finished polling after discovery timeout at %d\n", ticks);
if ((sassc->flags & MPSSAS_IN_DISCOVERY) == 0) {
@@ -902,7 +921,8 @@ mpssas_action(struct cam_sim *sim, union
sassc = cam_sim_softc(sim);
- mps_dprint(sassc->sc, MPS_TRACE, "%s func 0x%x\n", __func__,
+ MPS_FUNCTRACE(sassc->sc);
+ mps_dprint(sassc->sc, MPS_TRACE, "ccb func_code 0x%x\n",
ccb->ccb_h.func_code);
mtx_assert(&sassc->sc->mps_mtx, MA_OWNED);
@@ -986,14 +1006,14 @@ mpssas_action(struct cam_sim *sim, union
ccb->ccb_h.status = CAM_REQ_CMP;
break;
case XPT_RESET_DEV:
- mps_printf(sassc->sc, "mpssas_action XPT_RESET_DEV\n");
+ mps_dprint(sassc->sc, MPS_XINFO, "mpssas_action
XPT_RESET_DEV\n");
mpssas_action_resetdev(sassc, ccb);
return;
case XPT_RESET_BUS:
case XPT_ABORT:
case XPT_TERM_IO:
- mps_printf(sassc->sc, "mpssas_action faking success for "
- "abort or reset\n");
+ mps_dprint(sassc->sc, MPS_XINFO,
+ "mpssas_action faking success for abort or reset\n");
ccb->ccb_h.status = CAM_REQ_CMP;
break;
case XPT_SCSI_IO:
@@ -1019,12 +1039,12 @@ mpssas_announce_reset(struct mps_softc *
path_id_t path_id = cam_sim_path(sc->sassc->sim);
struct cam_path *path;
- mps_printf(sc, "%s code %x target %d lun %d\n", __func__,
+ mps_dprint(sc, MPS_XINFO, "%s code %x target %d lun %d\n", __func__,
ac_code, target_id, lun_id);
if (xpt_create_path(&path, NULL,
path_id, target_id, lun_id) != CAM_REQ_CMP) {
- mps_printf(sc, "unable to create path for reset "
+ mps_dprint(sc, MPS_ERROR, "unable to create path for reset "
"notification\n");
return;
}
@@ -1040,7 +1060,7 @@ mpssas_complete_all_commands(struct mps_
int i;
int completed;
- mps_printf(sc, "%s\n", __func__);
+ MPS_FUNCTRACE(sc);
mtx_assert(&sc->mps_mtx, MA_OWNED);
/* complete all commands with a NULL reply */
@@ -1053,7 +1073,7 @@ mpssas_complete_all_commands(struct mps_
cm->cm_flags |= MPS_CM_FLAGS_COMPLETE;
if (cm->cm_complete != NULL) {
- mpssas_log_command(cm,
+ mpssas_log_command(cm, MPS_RECOVERY,
"completing cm %p state %x ccb %p for diag
reset\n",
cm, cm->cm_state, cm->cm_ccb);
@@ -1062,7 +1082,7 @@ mpssas_complete_all_commands(struct mps_
}
if (cm->cm_flags & MPS_CM_FLAGS_WAKEUP) {
- mpssas_log_command(cm,
+ mpssas_log_command(cm, MPS_RECOVERY,
"waking up cm %p state %x ccb %p for diag reset\n",
cm, cm->cm_state, cm->cm_ccb);
wakeup(cm);
@@ -1071,7 +1091,7 @@ mpssas_complete_all_commands(struct mps_
if ((completed == 0) && (cm->cm_state != MPS_CM_STATE_FREE)) {
/* this should never happen, but if it does, log */
- mpssas_log_command(cm,
+ mpssas_log_command(cm, MPS_RECOVERY,
"cm %p state %x flags 0x%x ccb %p during diag "
"reset\n", cm, cm->cm_state, cm->cm_flags,
cm->cm_ccb);
@@ -1092,7 +1112,7 @@ mpssas_handle_reinit(struct mps_softc *s
* discovery-related activities have finished, the simq will be
* released.
*/
- mps_printf(sc, "%s startup\n", __func__);
+ mps_dprint(sc, MPS_INIT, "%s startup\n", __func__);
sc->sassc->flags |= MPSSAS_IN_STARTUP;
sc->sassc->flags |= MPSSAS_IN_DISCOVERY;
xpt_freeze_simq(sc->sassc->sim, 1);
@@ -1104,7 +1124,8 @@ mpssas_handle_reinit(struct mps_softc *s
/* complete and cleanup after all outstanding commands */
mpssas_complete_all_commands(sc);
- mps_printf(sc, "%s startup %u tm %u after command completion\n",
+ mps_dprint(sc, MPS_INIT,
+ "%s startup %u tm %u after command completion\n",
__func__, sc->sassc->startup_refcount, sc->sassc->tm_count);
/*
@@ -1119,7 +1140,7 @@ mpssas_handle_reinit(struct mps_softc *s
*/
for (i = 0; i < sc->facts->MaxTargets; i++) {
if (sc->sassc->targets[i].outstanding != 0)
- mps_printf(sc, "target %u outstanding %u\n",
+ mps_dprint(sc, MPS_INIT, "target %u outstanding %u\n",
i, sc->sassc->targets[i].outstanding);
sc->sassc->targets[i].handle = 0x0;
sc->sassc->targets[i].exp_dev_handle = 0x0;
@@ -1127,6 +1148,7 @@ mpssas_handle_reinit(struct mps_softc *s
sc->sassc->targets[i].flags = MPSSAS_TARGET_INDIAGRESET;
}
}
+
static void
mpssas_tm_timeout(void *data)
{
@@ -1135,7 +1157,8 @@ mpssas_tm_timeout(void *data)
mtx_assert(&sc->mps_mtx, MA_OWNED);
- mpssas_log_command(tm, "task mgmt %p timed out\n", tm);
+ mpssas_log_command(tm, MPS_INFO|MPS_RECOVERY,
+ "task mgmt %p timed out\n", tm);
mps_reinit(sc);
}
@@ -1158,16 +1181,18 @@ mpssas_logical_unit_reset_complete(struc
* Currently there should be no way we can hit this case. It only
* happens when we have a failure to allocate chain frames, and
* task management commands don't have S/G lists.
*** DIFF OUTPUT TRUNCATED AT 1000 LINES ***
_______________________________________________
svn-src-head@freebsd.org mailing list
http://lists.freebsd.org/mailman/listinfo/svn-src-head
To unsubscribe, send any mail to "svn-src-head-unsubscr...@freebsd.org"
