diff options
author | scottl <scottl@FreeBSD.org> | 2013-07-19 00:12:41 +0000 |
---|---|---|
committer | scottl <scottl@FreeBSD.org> | 2013-07-19 00:12:41 +0000 |
commit | 6931e864011808907fcb545c1c64ad91aaf7f8cd (patch) | |
tree | 054c1447ec723a8e3ea8b14c7b289026944641fe /sys | |
parent | 1b0750b86c77afe56bc851b72ab13a0d7536d066 (diff) | |
download | FreeBSD-src-6931e864011808907fcb545c1c64ad91aaf7f8cd.zip FreeBSD-src-6931e864011808907fcb545c1c64ad91aaf7f8cd.tar.gz |
Overhaul error, information, and debug logging.
Obtained from: Netflix
MFC after: 3 days
Diffstat (limited to 'sys')
-rw-r--r-- | sys/dev/mps/mps.c | 106 | ||||
-rw-r--r-- | sys/dev/mps/mps_mapping.c | 5 | ||||
-rw-r--r-- | sys/dev/mps/mps_pci.c | 16 | ||||
-rw-r--r-- | sys/dev/mps/mps_sas.c | 390 | ||||
-rw-r--r-- | sys/dev/mps/mps_sas_lsi.c | 36 | ||||
-rw-r--r-- | sys/dev/mps/mps_table.c | 36 | ||||
-rw-r--r-- | sys/dev/mps/mps_user.c | 20 | ||||
-rw-r--r-- | sys/dev/mps/mpsvar.h | 33 |
8 files changed, 356 insertions, 286 deletions
diff --git a/sys/dev/mps/mps.c b/sys/dev/mps/mps.c index a842373..1bb693f 100644 --- a/sys/dev/mps/mps.c +++ b/sys/dev/mps/mps.c @@ -81,7 +81,8 @@ static int mps_transition_operational(struct mps_softc *sc); 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 *sc) 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 *sc) 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_softc *sc) 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, int timeout, int sleep_flag) 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, void *req, MPI2_DEFAULT_REPLY *reply, 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, MPI2_IOC_FACTS_REPLY *facts) 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, MPI2_PORT_FACTS_REPLY *facts, int port) 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, uintptr_t data, 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 , u32 log_info) 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, uintptr_t data, } 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 *segs, int nsegs, int error) * 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 *segs, int nsegs, int error) 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, struct mps_command *cm) MPI2_CONFIG_REPLY *reply; struct mps_config_params *params; + MPS_FUNCTRACE(sc); params = cm->cm_complete_data; if (cm->cm_data != NULL) { diff --git a/sys/dev/mps/mps_mapping.c b/sys/dev/mps/mps_mapping.c index 585d54a..c486ecb 100644 --- a/sys/dev/mps/mps_mapping.c +++ b/sys/dev/mps/mps_mapping.c @@ -927,8 +927,9 @@ _mapping_get_dev_info(struct mps_softc *sc, 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; diff --git a/sys/dev/mps/mps_pci.c b/sys/dev/mps/mps_pci.c index 3f8739d..e64acdc 100644 --- a/sys/dev/mps/mps_pci.c +++ b/sys/dev/mps/mps_pci.c @@ -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_softc *sc) 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_softc *sc) 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_softc *sc) 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; } diff --git a/sys/dev/mps/mps_sas.c b/sys/dev/mps/mps_sas.c index 0d0dbd0..80a0f52 100644 --- a/sys/dev/mps/mps_sas.c +++ b/sys/dev/mps/mps_sas.c @@ -175,14 +175,16 @@ mpssas_find_target_by_handle(struct mpssas_softc *sassc, int start, uint16_t han 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_softc *sassc) 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, struct mps_command *tm) * 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 *sc, struct mpssas_target *targ) 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 *sc, struct mpssas_target *targ) */ 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 *sc, struct mpssas_target *targ) } 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 *cm, const char *fmt, ...) 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 *sc, struct mps_command *tm) 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 *sc, struct mps_command *tm) 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 mpssas_softc *sassc, uint16_t handle) 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 mpssas_softc *sassc, uint16_t handle) 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 mpssas_softc *sassc, uint16_t handle) 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_softc *sassc, uint16_t handle) 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_softc *sassc, uint16_t handle) 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_softc *sassc, uint16_t handle) 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 *sc, struct mps_command *tm) 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 *sc, struct mps_command *tm) * 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 *sc, struct mps_command *tm) 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 *sc, struct mps_command *tm) 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 *sc, struct mps_command *tm) * 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 *sc, struct mps_command *tm) 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 *sassc) { 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 ccb *ccb) 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) 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 *sc, uint32_t ac_code, 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_softc *sc) 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_softc *sc) 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_softc *sc) } 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_softc *sc) 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 *sc) * 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 *sc) /* 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 *sc) */ 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 *sc) 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(struct mps_softc *sc, struct mps_command *tm) * 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. + * XXXSL So should it be an assertion? */ if ((tm->cm_flags & MPS_CM_FLAGS_ERROR_MASK) != 0) { - mps_printf(sc, "%s: cm_flags = %#x for LUN reset! " + mps_dprint(sc, MPS_ERROR, "%s: cm_flags = %#x for LUN reset! " "This should not happen!\n", __func__, tm->cm_flags); mpssas_free_tm(sc, tm); return; } if (reply == NULL) { - mpssas_log_command(tm, "NULL reset reply for tm %p\n", tm); + mpssas_log_command(tm, MPS_RECOVERY, + "NULL reset reply for tm %p\n", tm); if ((sc->mps_flags & MPS_FLAGS_DIAGRESET) != 0) { /* this completion was due to a reset, just cleanup */ targ->flags &= ~MPSSAS_TARGET_INRESET; @@ -1181,7 +1206,7 @@ mpssas_logical_unit_reset_complete(struct mps_softc *sc, struct mps_command *tm) return; } - mpssas_log_command(tm, + mpssas_log_command(tm, MPS_RECOVERY, "logical unit reset status 0x%x code 0x%x count %u\n", le16toh(reply->IOCStatus), le32toh(reply->ResponseCode), le32toh(reply->TerminationCount)); @@ -1196,7 +1221,7 @@ mpssas_logical_unit_reset_complete(struct mps_softc *sc, struct mps_command *tm) } if (cm_count == 0) { - mpssas_log_command(tm, + mpssas_log_command(tm, MPS_RECOVERY|MPS_INFO, "logical unit %u finished recovery after reset\n", tm->cm_lun, tm); @@ -1221,7 +1246,7 @@ mpssas_logical_unit_reset_complete(struct mps_softc *sc, struct mps_command *tm) * effectively failed, regardless of the status reported. * Escalate to a target reset. */ - mpssas_log_command(tm, + mpssas_log_command(tm, MPS_RECOVERY, "logical unit reset complete for tm %p, but still have %u command(s)\n", tm, cm_count); mpssas_send_reset(sc, tm, @@ -1248,14 +1273,15 @@ mpssas_target_reset_complete(struct mps_softc *sc, struct mps_command *tm) * 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 target reset! " + mps_dprint(sc, MPS_ERROR,"%s: cm_flags = %#x for target reset! " "This should not happen!\n", __func__, tm->cm_flags); mpssas_free_tm(sc, tm); return; } if (reply == NULL) { - mpssas_log_command(tm, "NULL reset reply for tm %p\n", tm); + mpssas_log_command(tm, MPS_RECOVERY, + "NULL reset reply for tm %p\n", tm); if ((sc->mps_flags & MPS_FLAGS_DIAGRESET) != 0) { /* this completion was due to a reset, just cleanup */ targ->flags &= ~MPSSAS_TARGET_INRESET; @@ -1269,7 +1295,7 @@ mpssas_target_reset_complete(struct mps_softc *sc, struct mps_command *tm) return; } - mpssas_log_command(tm, + mpssas_log_command(tm, MPS_RECOVERY, "target reset status 0x%x code 0x%x count %u\n", le16toh(reply->IOCStatus), le32toh(reply->ResponseCode), le32toh(reply->TerminationCount)); @@ -1280,7 +1306,7 @@ mpssas_target_reset_complete(struct mps_softc *sc, struct mps_command *tm) /* we've finished recovery for this target and all * of its logical units. */ - mpssas_log_command(tm, + mpssas_log_command(tm, MPS_RECOVERY|MPS_INFO, "recovery finished after target reset\n"); mpssas_announce_reset(sc, AC_SENT_BDR, tm->cm_targ->tid, @@ -1294,7 +1320,7 @@ mpssas_target_reset_complete(struct mps_softc *sc, struct mps_command *tm) * outstanding commands, the reset effectively failed, * regardless of the status reported. escalate. */ - mpssas_log_command(tm, + mpssas_log_command(tm, MPS_RECOVERY, "target reset complete for tm %p, but still have %u command(s)\n", tm, targ->outstanding); mps_reinit(sc); @@ -1312,7 +1338,7 @@ mpssas_send_reset(struct mps_softc *sc, struct mps_command *tm, uint8_t type) target = tm->cm_targ; if (target->handle == 0) { - mps_printf(sc, "%s null devhandle for target_id %d\n", + mps_dprint(sc, MPS_ERROR,"%s null devhandle for target_id %d\n", __func__, target->tid); return -1; } @@ -1326,7 +1352,8 @@ mpssas_send_reset(struct mps_softc *sc, struct mps_command *tm, uint8_t type) /* XXX Need to handle invalid LUNs */ MPS_SET_LUN(req->LUN, tm->cm_lun); tm->cm_targ->logical_unit_resets++; - mpssas_log_command(tm, "sending logical unit reset\n"); + mpssas_log_command(tm, MPS_RECOVERY|MPS_INFO, + "sending logical unit reset\n"); tm->cm_complete = mpssas_logical_unit_reset_complete; } else if (type == MPI2_SCSITASKMGMT_TASKTYPE_TARGET_RESET) { @@ -1334,11 +1361,12 @@ mpssas_send_reset(struct mps_softc *sc, struct mps_command *tm, uint8_t type) req->MsgFlags = MPI2_SCSITASKMGMT_MSGFLAGS_LINK_RESET; tm->cm_targ->target_resets++; tm->cm_targ->flags |= MPSSAS_TARGET_INRESET; - mpssas_log_command(tm, "sending target reset\n"); + mpssas_log_command(tm, MPS_RECOVERY|MPS_INFO, + "sending target reset\n"); tm->cm_complete = mpssas_target_reset_complete; } else { - mps_printf(sc, "unexpected reset type 0x%x\n", type); + mps_dprint(sc, MPS_ERROR, "unexpected reset type 0x%x\n", type); return -1; } @@ -1351,7 +1379,7 @@ mpssas_send_reset(struct mps_softc *sc, struct mps_command *tm, uint8_t type) err = mps_map_command(sc, tm); if (err) - mpssas_log_command(tm, + mpssas_log_command(tm, MPS_RECOVERY, "error %d sending reset type %u\n", err, type); @@ -1379,7 +1407,7 @@ mpssas_abort_complete(struct mps_softc *sc, struct mps_command *tm) * task management commands don't have S/G lists. */ if ((tm->cm_flags & MPS_CM_FLAGS_ERROR_MASK) != 0) { - mpssas_log_command(tm, + mpssas_log_command(tm, MPS_RECOVERY, "cm_flags = %#x for abort %p TaskMID %u!\n", tm->cm_flags, tm, le16toh(req->TaskMID)); mpssas_free_tm(sc, tm); @@ -1387,7 +1415,7 @@ mpssas_abort_complete(struct mps_softc *sc, struct mps_command *tm) } if (reply == NULL) { - mpssas_log_command(tm, + mpssas_log_command(tm, MPS_RECOVERY, "NULL abort reply for tm %p TaskMID %u\n", tm, le16toh(req->TaskMID)); if ((sc->mps_flags & MPS_FLAGS_DIAGRESET) != 0) { @@ -1402,7 +1430,7 @@ mpssas_abort_complete(struct mps_softc *sc, struct mps_command *tm) return; } - mpssas_log_command(tm, + mpssas_log_command(tm, MPS_RECOVERY, "abort TaskMID %u status 0x%x code 0x%x count %u\n", le16toh(req->TaskMID), le16toh(reply->IOCStatus), le32toh(reply->ResponseCode), @@ -1413,7 +1441,7 @@ mpssas_abort_complete(struct mps_softc *sc, struct mps_command *tm) /* if there are no more timedout commands, we're done with * error recovery for this target. */ - mpssas_log_command(tm, + mpssas_log_command(tm, MPS_RECOVERY, "finished recovery after aborting TaskMID %u\n", le16toh(req->TaskMID)); @@ -1422,7 +1450,7 @@ mpssas_abort_complete(struct mps_softc *sc, struct mps_command *tm) } else if (le16toh(req->TaskMID) != cm->cm_desc.Default.SMID) { /* abort success, but we have more timedout commands to abort */ - mpssas_log_command(tm, + mpssas_log_command(tm, MPS_RECOVERY, "continuing recovery after aborting TaskMID %u\n", le16toh(req->TaskMID)); @@ -1432,7 +1460,7 @@ mpssas_abort_complete(struct mps_softc *sc, struct mps_command *tm) /* we didn't get a command completion, so the abort * failed as far as we're concerned. escalate. */ - mpssas_log_command(tm, + mpssas_log_command(tm, MPS_RECOVERY, "abort failed for TaskMID %u tm %p\n", le16toh(req->TaskMID), tm); @@ -1452,11 +1480,14 @@ mpssas_send_abort(struct mps_softc *sc, struct mps_command *tm, struct mps_comma targ = cm->cm_targ; if (targ->handle == 0) { - mps_printf(sc, "%s null devhandle for target_id %d\n", + mps_dprint(sc, MPS_ERROR,"%s null devhandle for target_id %d\n", __func__, cm->cm_ccb->ccb_h.target_id); return -1; } + mpssas_log_command(tm, MPS_RECOVERY|MPS_INFO, + "Aborting command %p\n", cm); + req = (MPI2_SCSI_TASK_MANAGE_REQUEST *)tm->cm_req; req->DevHandle = htole16(targ->handle); req->Function = MPI2_FUNCTION_SCSI_TASK_MGMT; @@ -1481,7 +1512,7 @@ mpssas_send_abort(struct mps_softc *sc, struct mps_command *tm, struct mps_comma err = mps_map_command(sc, tm); if (err) - mpssas_log_command(tm, + mpssas_log_command(tm, MPS_RECOVERY, "error %d sending abort for cm %p SMID %u\n", err, cm, req->TaskMID); return err; @@ -1498,9 +1529,10 @@ mpssas_scsiio_timeout(void *data) cm = (struct mps_command *)data; sc = cm->cm_sc; + MPS_FUNCTRACE(sc); mtx_assert(&sc->mps_mtx, MA_OWNED); - mps_printf(sc, "%s checking sc %p cm %p\n", __func__, sc, cm); + mps_dprint(sc, MPS_XINFO, "Timeout checking cm %p\n", sc); /* * Run the interrupt handler to make sure it's not pending. This @@ -1509,16 +1541,17 @@ mpssas_scsiio_timeout(void *data) */ mps_intr_locked(sc); if (cm->cm_state == MPS_CM_STATE_FREE) { - mps_printf(sc, "SCSI command %p sc %p almost timed out\n", cm, sc); + mpssas_log_command(cm, MPS_XINFO, + "SCSI command %p almost timed out\n", cm); return; } if (cm->cm_ccb == NULL) { - mps_printf(sc, "command timeout with NULL ccb\n"); + mps_dprint(sc, MPS_ERROR, "command timeout with NULL ccb\n"); return; } - mpssas_log_command(cm, "command timeout cm %p ccb %p\n", + mpssas_log_command(cm, MPS_INFO, "command timeout cm %p ccb %p\n", cm, cm->cm_ccb); targ = cm->cm_targ; @@ -1536,11 +1569,12 @@ mpssas_scsiio_timeout(void *data) /* target already in recovery, just queue up another * timedout command to be processed later. */ - mps_printf(sc, "queued timedout cm %p for processing by tm %p\n", + mps_dprint(sc, MPS_RECOVERY, + "queued timedout cm %p for processing by tm %p\n", cm, targ->tm); } else if ((targ->tm = mpssas_alloc_tm(sc)) != NULL) { - mps_printf(sc, "timedout cm %p allocated tm %p\n", + mps_dprint(sc, MPS_RECOVERY, "timedout cm %p allocated tm %p\n", cm, targ->tm); /* start recovery by aborting the first timedout command */ @@ -1556,8 +1590,8 @@ mpssas_scsiio_timeout(void *data) * more credits than disks in an enclosure, and limit * ourselves to one TM per target for recovery. */ - mps_printf(sc, "timedout cm %p failed to allocate a tm\n", - cm); + mps_dprint(sc, MPS_RECOVERY, + "timedout cm %p failed to allocate a tm\n", cm); } } @@ -1576,20 +1610,21 @@ mpssas_action_scsiio(struct mpssas_softc *sassc, union ccb *ccb) uint32_t mpi_control; sc = sassc->sc; + MPS_FUNCTRACE(sc); mtx_assert(&sc->mps_mtx, MA_OWNED); csio = &ccb->csio; targ = &sassc->targets[csio->ccb_h.target_id]; - mps_dprint(sc, MPS_TRACE, "%s ccb %p target flag %x\n", __func__, ccb, targ->flags); + mps_dprint(sc, MPS_TRACE, "ccb %p target flag %x\n", ccb, targ->flags); if (targ->handle == 0x0) { - mps_dprint(sc, MPS_TRACE, "%s NULL handle for target %u\n", + mps_dprint(sc, MPS_ERROR, "%s NULL handle for target %u\n", __func__, csio->ccb_h.target_id); csio->ccb_h.status = CAM_SEL_TIMEOUT; xpt_done(ccb); return; } if (targ->flags & MPS_TARGET_FLAGS_RAID_COMPONENT) { - mps_dprint(sc, MPS_TRACE, "%s Raid component no SCSI IO supported %u\n", + mps_dprint(sc, MPS_ERROR, "%s Raid component no SCSI IO supported %u\n", __func__, csio->ccb_h.target_id); csio->ccb_h.status = CAM_TID_INVALID; xpt_done(ccb); @@ -1610,7 +1645,7 @@ mpssas_action_scsiio(struct mpssas_softc *sassc, union ccb *ccb) } if ((sc->mps_flags & MPS_FLAGS_SHUTDOWN) != 0) { - mps_dprint(sc, MPS_TRACE, "%s shutting down\n", __func__); + mps_dprint(sc, MPS_INFO, "%s shutting down\n", __func__); csio->ccb_h.status = CAM_TID_INVALID; xpt_done(ccb); return; @@ -1792,9 +1827,8 @@ mpssas_action_scsiio(struct mpssas_softc *sassc, union ccb *ccb) targ->outstanding++; TAILQ_INSERT_TAIL(&targ->commands, cm, cm_link); - if ((sc->mps_debug & MPS_TRACE) != 0) - mpssas_log_command(cm, "%s cm %p ccb %p outstanding %u\n", - __func__, cm, ccb, targ->outstanding); + mpssas_log_command(cm, MPS_XINFO, "%s cm %p ccb %p outstanding %u\n", + __func__, cm, ccb, targ->outstanding); mps_map_command(sc, cm); return; @@ -1834,7 +1868,7 @@ mps_response_code(struct mps_softc *sc, u8 response_code) desc = "unknown"; break; } - mps_dprint(sc, MPS_INFO, "response_code(0x%01x): %s\n", + mps_dprint(sc, MPS_XINFO, "response_code(0x%01x): %s\n", response_code, desc); } /** @@ -1968,21 +2002,20 @@ mps_sc_failed_io_info(struct mps_softc *sc, struct ccb_scsiio *csio, if (scsi_state & MPI2_SCSI_STATE_AUTOSENSE_VALID) strcat(desc_scsi_state, "autosense valid "); - mps_dprint(sc, MPS_INFO, "\thandle(0x%04x), ioc_status(%s)(0x%04x), \n", - le16toh(mpi_reply->DevHandle), - desc_ioc_state, ioc_status); + mps_dprint(sc, MPS_XINFO, "\thandle(0x%04x), ioc_status(%s)(0x%04x)\n", + le16toh(mpi_reply->DevHandle), desc_ioc_state, ioc_status); /* We can add more detail about underflow data here * TO-DO * */ - mps_dprint(sc, MPS_INFO, "\tscsi_status(%s)(0x%02x), " + mps_dprint(sc, MPS_XINFO, "\tscsi_status(%s)(0x%02x), " "scsi_state(%s)(0x%02x)\n", desc_scsi_status, scsi_status, desc_scsi_state, scsi_state); - if (sc->mps_debug & MPS_INFO && + if (sc->mps_debug & MPS_XINFO && scsi_state & MPI2_SCSI_STATE_AUTOSENSE_VALID) { - mps_dprint(sc, MPS_INFO, "-> Sense Buffer Data : Start :\n"); + mps_dprint(sc, MPS_XINFO, "-> Sense Buffer Data : Start :\n"); scsi_sense_print(csio); - mps_dprint(sc, MPS_INFO, "-> Sense Buffer Data : End :\n"); + mps_dprint(sc, MPS_XINFO, "-> Sense Buffer Data : End :\n"); } if (scsi_state & MPI2_SCSI_STATE_RESPONSE_INFO_VALID) { @@ -2004,9 +2037,10 @@ mpssas_scsiio_complete(struct mps_softc *sc, struct mps_command *cm) int dir = 0, i; u16 alloc_len; + MPS_FUNCTRACE(sc); mps_dprint(sc, MPS_TRACE, - "%s cm %p SMID %u ccb %p reply %p outstanding %u\n", - __func__, cm, cm->cm_desc.Default.SMID, cm->cm_ccb, cm->cm_reply, + "cm %p SMID %u ccb %p reply %p outstanding %u\n", cm, + cm->cm_desc.Default.SMID, cm->cm_ccb, cm->cm_reply, cm->cm_targ->outstanding); callout_stop(&cm->cm_callout); @@ -2037,30 +2071,30 @@ mpssas_scsiio_complete(struct mps_softc *sc, struct mps_command *cm) if (cm->cm_state == MPS_CM_STATE_TIMEDOUT) { TAILQ_REMOVE(&cm->cm_targ->timedout_commands, cm, cm_recovery); if (cm->cm_reply != NULL) - mpssas_log_command(cm, + mpssas_log_command(cm, MPS_RECOVERY, "completed timedout cm %p ccb %p during recovery " "ioc %x scsi %x state %x xfer %u\n", cm, cm->cm_ccb, le16toh(rep->IOCStatus), rep->SCSIStatus, rep->SCSIState, le32toh(rep->TransferCount)); else - mpssas_log_command(cm, + mpssas_log_command(cm, MPS_RECOVERY, "completed timedout cm %p ccb %p during recovery\n", cm, cm->cm_ccb); } else if (cm->cm_targ->tm != NULL) { if (cm->cm_reply != NULL) - mpssas_log_command(cm, + mpssas_log_command(cm, MPS_RECOVERY, "completed cm %p ccb %p during recovery " "ioc %x scsi %x state %x xfer %u\n", cm, cm->cm_ccb, le16toh(rep->IOCStatus), rep->SCSIStatus, rep->SCSIState, le32toh(rep->TransferCount)); else - mpssas_log_command(cm, + mpssas_log_command(cm, MPS_RECOVERY, "completed cm %p ccb %p during recovery\n", cm, cm->cm_ccb); } else if ((sc->mps_flags & MPS_FLAGS_DIAGRESET) != 0) { - mpssas_log_command(cm, + mpssas_log_command(cm, MPS_RECOVERY, "reset completed cm %p ccb %p\n", cm, cm->cm_ccb); } @@ -2090,7 +2124,7 @@ mpssas_scsiio_complete(struct mps_softc *sc, struct mps_command *cm) if ((sassc->flags & MPSSAS_QUEUE_FROZEN) == 0) { xpt_freeze_simq(sassc->sim, 1); sassc->flags |= MPSSAS_QUEUE_FROZEN; - mps_dprint(sc, MPS_INFO, "Error sending command, " + mps_dprint(sc, MPS_XINFO, "Error sending command, " "freezing SIM queue\n"); } } @@ -2107,7 +2141,7 @@ mpssas_scsiio_complete(struct mps_softc *sc, struct mps_command *cm) if (sassc->flags & MPSSAS_QUEUE_FROZEN) { ccb->ccb_h.status |= CAM_RELEASE_SIMQ; sassc->flags &= ~MPSSAS_QUEUE_FROZEN; - mps_dprint(sc, MPS_INFO, + mps_dprint(sc, MPS_XINFO, "Unfreezing SIM queue\n"); } } @@ -2131,11 +2165,10 @@ mpssas_scsiio_complete(struct mps_softc *sc, struct mps_command *cm) return; } - if (sc->mps_debug & MPS_TRACE) - mpssas_log_command(cm, - "ioc %x scsi %x state %x xfer %u\n", - le16toh(rep->IOCStatus), rep->SCSIStatus, rep->SCSIState, - le32toh(rep->TransferCount)); + mpssas_log_command(cm, MPS_XINFO, + "ioc %x scsi %x state %x xfer %u\n", + le16toh(rep->IOCStatus), rep->SCSIStatus, rep->SCSIState, + le32toh(rep->TransferCount)); /* * If this is a Direct Drive I/O, reissue the I/O to the original IR @@ -2159,7 +2192,7 @@ mpssas_scsiio_complete(struct mps_softc *sc, struct mps_command *cm) if ((le16toh(rep->IOCStatus) & MPI2_IOCSTATUS_MASK) == MPI2_IOCSTATUS_SCSI_RECOVERED_ERROR) - mpssas_log_command(cm, "recovered error\n"); + mpssas_log_command(cm, MPS_XINFO, "recovered error\n"); /* Completion failed at the transport level. */ if (rep->SCSIState & (MPI2_SCSI_STATE_NO_SCSI_STATUS | @@ -2304,10 +2337,10 @@ mpssas_scsiio_complete(struct mps_softc *sc, struct mps_command *cm) * decrementing the retry count. */ ccb->ccb_h.status = CAM_REQUEUE_REQ; - mpssas_log_command(cm, + mpssas_log_command(cm, MPS_INFO, "terminated ioc %x scsi %x state %x xfer %u\n", - le16toh(rep->IOCStatus), rep->SCSIStatus, rep->SCSIState, - le32toh(rep->TransferCount)); + le16toh(rep->IOCStatus), rep->SCSIStatus, rep->SCSIState, + le32toh(rep->TransferCount)); break; case MPI2_IOCSTATUS_INVALID_FUNCTION: case MPI2_IOCSTATUS_INTERNAL_ERROR: @@ -2320,10 +2353,10 @@ mpssas_scsiio_complete(struct mps_softc *sc, struct mps_command *cm) case MPI2_IOCSTATUS_SCSI_RESIDUAL_MISMATCH: case MPI2_IOCSTATUS_SCSI_TASK_MGMT_FAILED: default: - mpssas_log_command(cm, + mpssas_log_command(cm, MPS_XINFO, "completed ioc %x scsi %x state %x xfer %u\n", - le16toh(rep->IOCStatus), rep->SCSIStatus, rep->SCSIState, - le32toh(rep->TransferCount)); + le16toh(rep->IOCStatus), rep->SCSIStatus, rep->SCSIState, + le32toh(rep->TransferCount)); csio->resid = cm->cm_length; ccb->ccb_h.status = CAM_REQ_CMP_ERR; break; @@ -2334,7 +2367,7 @@ mpssas_scsiio_complete(struct mps_softc *sc, struct mps_command *cm) if (sassc->flags & MPSSAS_QUEUE_FROZEN) { ccb->ccb_h.status |= CAM_RELEASE_SIMQ; sassc->flags &= ~MPSSAS_QUEUE_FROZEN; - mps_dprint(sc, MPS_INFO, "Command completed, " + mps_dprint(sc, MPS_XINFO, "Command completed, " "unfreezing SIM queue\n"); } @@ -2634,7 +2667,7 @@ mpssas_smpio_complete(struct mps_softc *sc, struct mps_command *cm) * in the standard request size. */ if ((cm->cm_flags & MPS_CM_FLAGS_ERROR_MASK) != 0) { - mps_printf(sc, "%s: cm_flags = %#x on SMP request!\n", + mps_dprint(sc, MPS_ERROR,"%s: cm_flags = %#x on SMP request!\n", __func__, cm->cm_flags); ccb->ccb_h.status = CAM_REQ_CMP_ERR; goto bailout; @@ -2642,7 +2675,7 @@ mpssas_smpio_complete(struct mps_softc *sc, struct mps_command *cm) rpl = (MPI2_SMP_PASSTHROUGH_REPLY *)cm->cm_reply; if (rpl == NULL) { - mps_dprint(sc, MPS_INFO, "%s: NULL cm_reply!\n", __func__); + mps_dprint(sc, MPS_ERROR, "%s: NULL cm_reply!\n", __func__); ccb->ccb_h.status = CAM_REQ_CMP_ERR; goto bailout; } @@ -2653,13 +2686,13 @@ mpssas_smpio_complete(struct mps_softc *sc, struct mps_command *cm) if ((le16toh(rpl->IOCStatus) & MPI2_IOCSTATUS_MASK) != MPI2_IOCSTATUS_SUCCESS || rpl->SASStatus != MPI2_SASSTATUS_SUCCESS) { - mps_dprint(sc, MPS_INFO, "%s: IOCStatus %04x SASStatus %02x\n", + mps_dprint(sc, MPS_XINFO, "%s: IOCStatus %04x SASStatus %02x\n", __func__, le16toh(rpl->IOCStatus), rpl->SASStatus); ccb->ccb_h.status = CAM_REQ_CMP_ERR; goto bailout; } - mps_dprint(sc, MPS_INFO, "%s: SMP request to SAS address " + mps_dprint(sc, MPS_XINFO, "%s: SMP request to SAS address " "%#jx completed successfully\n", __func__, (uintmax_t)sasaddr); @@ -2700,8 +2733,8 @@ mpssas_send_smpcmd(struct mpssas_softc *sassc, union ccb *ccb, uint64_t sasaddr) switch ((ccb->ccb_h.flags & CAM_DATA_MASK)) { case CAM_DATA_PADDR: case CAM_DATA_SG_PADDR: - mps_printf(sc, "%s: physical addresses not supported\n", - __func__); + mps_dprint(sc, MPS_ERROR, + "%s: physical addresses not supported\n", __func__); ccb->ccb_h.status = CAM_REQ_INVALID; xpt_done(ccb); return; @@ -2712,7 +2745,8 @@ mpssas_send_smpcmd(struct mpssas_softc *sassc, union ccb *ccb, uint64_t sasaddr) */ if ((ccb->smpio.smp_request_sglist_cnt > 1) || (ccb->smpio.smp_response_sglist_cnt > 1)) { - mps_printf(sc, "%s: multiple request or response " + mps_dprint(sc, MPS_ERROR, + "%s: multiple request or response " "buffer segments not supported for SMP\n", __func__); ccb->ccb_h.status = CAM_REQ_INVALID; @@ -2756,7 +2790,8 @@ mpssas_send_smpcmd(struct mpssas_softc *sassc, union ccb *ccb, uint64_t sasaddr) cm = mps_alloc_command(sc); if (cm == NULL) { - mps_printf(sc, "%s: cannot allocate command\n", __func__); + mps_dprint(sc, MPS_ERROR, + "%s: cannot allocate command\n", __func__); ccb->ccb_h.status = CAM_RESRC_UNAVAIL; xpt_done(ccb); return; @@ -2773,7 +2808,7 @@ mpssas_send_smpcmd(struct mpssas_softc *sassc, union ccb *ccb, uint64_t sasaddr) req->SGLFlags = MPI2_SGLFLAGS_SYSTEM_ADDRESS_SPACE | MPI2_SGLFLAGS_SGL_TYPE_MPI; - mps_dprint(sc, MPS_INFO, "%s: sending SMP request to SAS " + mps_dprint(sc, MPS_XINFO, "%s: sending SMP request to SAS " "address %#jx\n", __func__, (uintmax_t)sasaddr); mpi_init_sge(cm, req, &req->SGL); @@ -2835,7 +2870,8 @@ mpssas_send_smpcmd(struct mpssas_softc *sassc, union ccb *ccb, uint64_t sasaddr) */ error = mps_map_command(sc, cm); if ((error != 0) && (error != EINPROGRESS)) { - mps_printf(sc, "%s: error %d returned from mps_map_command()\n", + mps_dprint(sc, MPS_ERROR, + "%s: error %d returned from mps_map_command()\n", __func__, error); goto bailout_error; } @@ -2864,7 +2900,8 @@ mpssas_action_smpio(struct mpssas_softc *sassc, union ccb *ccb) */ targ = &sassc->targets[ccb->ccb_h.target_id]; if (targ->handle == 0x0) { - mps_printf(sc, "%s: target %d does not exist!\n", __func__, + mps_dprint(sc, MPS_ERROR, + "%s: target %d does not exist!\n", __func__, ccb->ccb_h.target_id); ccb->ccb_h.status = CAM_SEL_TIMEOUT; xpt_done(ccb); @@ -2912,7 +2949,8 @@ mpssas_action_smpio(struct mpssas_softc *sassc, union ccb *ccb) #endif if (targ->parent_handle == 0x0) { - mps_printf(sc, "%s: handle %d does not have a valid " + mps_dprint(sc, MPS_ERROR, + "%s: handle %d does not have a valid " "parent handle!\n", __func__, targ->handle); ccb->ccb_h.status = CAM_REQ_INVALID; goto bailout; @@ -2922,7 +2960,8 @@ mpssas_action_smpio(struct mpssas_softc *sassc, union ccb *ccb) targ->parent_handle); if (parent_target == NULL) { - mps_printf(sc, "%s: handle %d does not have a valid " + mps_dprint(sc, MPS_ERROR, + "%s: handle %d does not have a valid " "parent target!\n", __func__, targ->handle); ccb->ccb_h.status = CAM_REQ_INVALID; goto bailout; @@ -2930,7 +2969,8 @@ mpssas_action_smpio(struct mpssas_softc *sassc, union ccb *ccb) if ((parent_target->devinfo & MPI2_SAS_DEVICE_INFO_SMP_TARGET) == 0) { - mps_printf(sc, "%s: handle %d parent %d does not " + mps_dprint(sc, MPS_ERROR, + "%s: handle %d parent %d does not " "have an SMP target!\n", __func__, targ->handle, parent_target->handle); ccb->ccb_h.status = CAM_REQ_INVALID; @@ -2942,7 +2982,8 @@ mpssas_action_smpio(struct mpssas_softc *sassc, union ccb *ccb) #else /* OLD_MPS_PROBE */ if ((targ->parent_devinfo & MPI2_SAS_DEVICE_INFO_SMP_TARGET) == 0) { - mps_printf(sc, "%s: handle %d parent %d does not " + mps_dprint(sc, MPS_ERROR, + "%s: handle %d parent %d does not " "have an SMP target!\n", __func__, targ->handle, targ->parent_handle); ccb->ccb_h.status = CAM_REQ_INVALID; @@ -2950,7 +2991,8 @@ mpssas_action_smpio(struct mpssas_softc *sassc, union ccb *ccb) } if (targ->parent_sasaddr == 0x0) { - mps_printf(sc, "%s: handle %d parent handle %d does " + mps_dprint(sc, MPS_ERROR, + "%s: handle %d parent handle %d does " "not have a valid SAS address!\n", __func__, targ->handle, targ->parent_handle); ccb->ccb_h.status = CAM_REQ_INVALID; @@ -2963,7 +3005,8 @@ mpssas_action_smpio(struct mpssas_softc *sassc, union ccb *ccb) } if (sasaddr == 0) { - mps_printf(sc, "%s: unable to find SAS address for handle %d\n", + mps_dprint(sc, MPS_INFO, + "%s: unable to find SAS address for handle %d\n", __func__, targ->handle); ccb->ccb_h.status = CAM_REQ_INVALID; goto bailout; @@ -2986,13 +3029,14 @@ mpssas_action_resetdev(struct mpssas_softc *sassc, union ccb *ccb) struct mps_command *tm; struct mpssas_target *targ; - mps_dprint(sassc->sc, MPS_TRACE, __func__); + MPS_FUNCTRACE(sassc->sc); mtx_assert(&sassc->sc->mps_mtx, MA_OWNED); sc = sassc->sc; tm = mps_alloc_command(sc); if (tm == NULL) { - mps_printf(sc, "comand alloc failure in mpssas_action_resetdev\n"); + mps_dprint(sc, MPS_ERROR, + "comand alloc failure in mpssas_action_resetdev\n"); ccb->ccb_h.status = CAM_RESRC_UNAVAIL; xpt_done(ccb); return; @@ -3021,7 +3065,7 @@ mpssas_resetdev_complete(struct mps_softc *sc, struct mps_command *tm) MPI2_SCSI_TASK_MANAGE_REPLY *resp; union ccb *ccb; - mps_dprint(sc, MPS_TRACE, __func__); + MPS_FUNCTRACE(sc); mtx_assert(&sc->mps_mtx, MA_OWNED); resp = (MPI2_SCSI_TASK_MANAGE_REPLY *)tm->cm_reply; @@ -3037,14 +3081,16 @@ mpssas_resetdev_complete(struct mps_softc *sc, struct mps_command *tm) req = (MPI2_SCSI_TASK_MANAGE_REQUEST *)tm->cm_req; - mps_printf(sc, "%s: cm_flags = %#x for reset of handle %#04x! " + mps_dprint(sc, MPS_ERROR, + "%s: cm_flags = %#x for reset of handle %#04x! " "This should not happen!\n", __func__, tm->cm_flags, req->DevHandle); ccb->ccb_h.status = CAM_REQ_CMP_ERR; goto bailout; } - printf("%s: IOCStatus = 0x%x ResponseCode = 0x%x\n", __func__, + mps_dprint(sc, MPS_XINFO, + "%s: IOCStatus = 0x%x ResponseCode = 0x%x\n", __func__, le16toh(resp->IOCStatus), le32toh(resp->ResponseCode)); if (le32toh(resp->ResponseCode) == MPI2_SCSITASKMGMT_RSP_TM_COMPLETE) { @@ -3093,7 +3139,7 @@ mpssas_rescan_done(struct cam_periph *periph, union ccb *done_ccb) mtx_assert(&sassc->sc->mps_mtx, MA_OWNED); xpt_path_string(done_ccb->ccb_h.path, path_str, sizeof(path_str)); - mps_dprint(sassc->sc, MPS_INFO, "Completing rescan for %s\n", path_str); + mps_dprint(sassc->sc, MPS_XINFO, "Completing rescan for %s\n", path_str); xpt_free_path(done_ccb->ccb_h.path); xpt_free_ccb(done_ccb); @@ -3119,7 +3165,7 @@ mpssas_scanner_thread(void *arg) sassc = (struct mpssas_softc *)arg; sc = sassc->sc; - mps_dprint(sc, MPS_TRACE, "%s\n", __func__); + MPS_FUNCTRACE(sc); mps_lock(sc); for (;;) { @@ -3127,7 +3173,7 @@ mpssas_scanner_thread(void *arg) msleep(&sassc->ccb_scanq, &sc->mps_mtx, PRIBIO, "mps_scanq", 1 * hz); if (sassc->flags & MPSSAS_SHUTDOWN) { - mps_dprint(sc, MPS_TRACE, "Scanner shutting down\n"); + mps_dprint(sc, MPS_XINFO, "Scanner shutting down\n"); break; } next_work: @@ -3139,7 +3185,7 @@ next_work: TAILQ_REMOVE(&sassc->ccb_scanq, &ccb->ccb_h, sim_links.tqe); xpt_action(ccb); if (sassc->flags & MPSSAS_SHUTDOWN) { - mps_dprint(sc, MPS_TRACE, "Scanner shutting down\n"); + mps_dprint(sc, MPS_XINFO, "Scanner shutting down\n"); break; } goto next_work; @@ -3168,7 +3214,7 @@ mpssas_rescan(struct mpssas_softc *sassc, union ccb *ccb) { char path_str[64]; - mps_dprint(sassc->sc, MPS_TRACE, "%s\n", __func__); + MPS_FUNCTRACE(sassc->sc); mtx_assert(&sassc->sc->mps_mtx, MA_OWNED); @@ -3176,7 +3222,7 @@ mpssas_rescan(struct mpssas_softc *sassc, union ccb *ccb) return; xpt_path_string(ccb->ccb_h.path, path_str, sizeof(path_str)); - mps_dprint(sassc->sc, MPS_INFO, "Queueing rescan for %s\n", path_str); + mps_dprint(sassc->sc, MPS_XINFO, "Queueing rescan for %s\n", path_str); /* Prepare request */ ccb->ccb_h.ppriv_ptr1 = sassc; @@ -3244,7 +3290,7 @@ mpssas_async(void *callback_arg, uint32_t code, struct cam_path *path, lun = malloc(sizeof(struct mpssas_lun), M_MPT2, M_NOWAIT | M_ZERO); if (lun == NULL) { - mps_dprint(sc, MPS_FAULT, "Unable to alloc " + mps_dprint(sc, MPS_ERROR, "Unable to alloc " "LUN for EEDP support.\n"); break; } @@ -3313,14 +3359,14 @@ mpssas_check_eedp(struct mpssas_softc *sassc) do { ccb = xpt_alloc_ccb_nowait(); if (ccb == NULL) { - mps_dprint(sc, MPS_FAULT, "Unable to alloc CCB " + mps_dprint(sc, MPS_ERROR, "Unable to alloc CCB " "for EEDP support.\n"); return; } if (xpt_create_path(&ccb->ccb_h.path, NULL, pathid, targetid, lunid) != CAM_REQ_CMP) { - mps_dprint(sc, MPS_FAULT, "Unable to create " + mps_dprint(sc, MPS_ERROR, "Unable to create " "path for EEDP support\n"); xpt_free_ccb(ccb); return; @@ -3347,7 +3393,7 @@ mpssas_check_eedp(struct mpssas_softc *sassc) lun = malloc(sizeof(struct mpssas_lun), M_MPT2, M_NOWAIT | M_ZERO); if (lun == NULL) { - mps_dprint(sc, MPS_FAULT, + mps_dprint(sc, MPS_ERROR, "Unable to alloc LUN for " "EEDP support.\n"); xpt_free_path(ccb->ccb_h.path); @@ -3385,7 +3431,7 @@ mpssas_check_eedp(struct mpssas_softc *sassc) continue; } - mps_dprint(sc, MPS_INFO, + mps_dprint(sc, MPS_XINFO, "Sending read cap: path %s" " handle %d\n", path_str, target->handle ); @@ -3398,7 +3444,7 @@ mpssas_check_eedp(struct mpssas_softc *sassc) malloc(sizeof(struct scsi_read_capacity_eedp), M_MPT2, M_NOWAIT| M_ZERO); if (rcap_buf == NULL) { - mps_dprint(sc, MPS_FAULT, "Unable to alloc read " + mps_dprint(sc, MPS_ERROR, "Unable to alloc read " "capacity buffer for EEDP support.\n"); xpt_free_path(ccb->ccb_h.path); xpt_free_ccb(ccb); @@ -3535,7 +3581,7 @@ mpssas_send_portenable(struct mps_softc *sc) MPI2_PORT_ENABLE_REQUEST *request; struct mps_command *cm; - mps_dprint(sc, MPS_TRACE, "%s\n", __func__); + MPS_FUNCTRACE(sc); if ((cm = mps_alloc_command(sc)) == NULL) return (EBUSY); @@ -3549,7 +3595,7 @@ mpssas_send_portenable(struct mps_softc *sc) cm->cm_sge = NULL; mps_map_command(sc, cm); - mps_dprint(sc, MPS_TRACE, + mps_dprint(sc, MPS_XINFO, "mps_send_portenable finished cm %p req %p complete %p\n", cm, cm->cm_req, cm->cm_complete); return (0); @@ -3561,7 +3607,7 @@ mpssas_portenable_complete(struct mps_softc *sc, struct mps_command *cm) MPI2_PORT_ENABLE_REPLY *reply; struct mpssas_softc *sassc; - mps_dprint(sc, MPS_TRACE, "%s\n", __func__); + MPS_FUNCTRACE(sc); sassc = sc->sassc; /* @@ -3570,7 +3616,7 @@ mpssas_portenable_complete(struct mps_softc *sc, struct mps_command *cm) * port enable commands don't have S/G lists. */ if ((cm->cm_flags & MPS_CM_FLAGS_ERROR_MASK) != 0) { - mps_printf(sc, "%s: cm_flags = %#x for port enable! " + mps_dprint(sc, MPS_ERROR, "%s: cm_flags = %#x for port enable! " "This should not happen!\n", __func__, cm->cm_flags); } @@ -3583,7 +3629,7 @@ mpssas_portenable_complete(struct mps_softc *sc, struct mps_command *cm) mps_free_command(sc, cm); if (sc->mps_ich.ich_arg != NULL) { - mps_dprint(sc, MPS_INFO, "disestablish config intrhook\n"); + mps_dprint(sc, MPS_XINFO, "disestablish config intrhook\n"); config_intrhook_disestablish(&sc->mps_ich); sc->mps_ich.ich_arg = NULL; } diff --git a/sys/dev/mps/mps_sas_lsi.c b/sys/dev/mps/mps_sas_lsi.c index 4763192..18450ab 100644 --- a/sys/dev/mps/mps_sas_lsi.c +++ b/sys/dev/mps/mps_sas_lsi.c @@ -191,7 +191,7 @@ mpssas_fw_work(struct mps_softc *sc, struct mps_fw_event_work *fw_event) struct mpssas_softc *sassc; sassc = sc->sassc; - mps_dprint(sc, MPS_INFO, "(%d)->(%s) Working on Event: [%x]\n", + mps_dprint(sc, MPS_EVENT, "(%d)->(%s) Working on Event: [%x]\n", event_count++,__func__,fw_event->event); switch (fw_event->event) { case MPI2_EVENT_SAS_TOPOLOGY_CHANGE_LIST: @@ -374,24 +374,24 @@ mpssas_fw_work(struct mps_softc *sc, struct mps_fw_event_work *fw_event) /* * Informational only. */ - mps_dprint(sc, MPS_INFO, "Received IR Volume event:\n"); + mps_dprint(sc, MPS_EVENT, "Received IR Volume event:\n"); switch (event_data->ReasonCode) { case MPI2_EVENT_IR_VOLUME_RC_SETTINGS_CHANGED: - mps_dprint(sc, MPS_INFO, " Volume Settings " + mps_dprint(sc, MPS_EVENT, " Volume Settings " "changed from 0x%x to 0x%x for Volome with " "handle 0x%x", le32toh(event_data->PreviousValue), le32toh(event_data->NewValue), le16toh(event_data->VolDevHandle)); break; case MPI2_EVENT_IR_VOLUME_RC_STATUS_FLAGS_CHANGED: - mps_dprint(sc, MPS_INFO, " Volume Status " + mps_dprint(sc, MPS_EVENT, " Volume Status " "changed from 0x%x to 0x%x for Volome with " "handle 0x%x", le32toh(event_data->PreviousValue), le32toh(event_data->NewValue), le16toh(event_data->VolDevHandle)); break; case MPI2_EVENT_IR_VOLUME_RC_STATE_CHANGED: - mps_dprint(sc, MPS_INFO, " Volume State " + mps_dprint(sc, MPS_EVENT, " Volume State " "changed from 0x%x to 0x%x for Volome with " "handle 0x%x", le32toh(event_data->PreviousValue), le32toh(event_data->NewValue), @@ -440,10 +440,10 @@ mpssas_fw_work(struct mps_softc *sc, struct mps_fw_event_work *fw_event) /* * Informational only. */ - mps_dprint(sc, MPS_INFO, "Received IR Phys Disk event:\n"); + mps_dprint(sc, MPS_EVENT, "Received IR Phys Disk event:\n"); switch (event_data->ReasonCode) { case MPI2_EVENT_IR_PHYSDISK_RC_SETTINGS_CHANGED: - mps_dprint(sc, MPS_INFO, " Phys Disk Settings " + mps_dprint(sc, MPS_EVENT, " Phys Disk Settings " "changed from 0x%x to 0x%x for Phys Disk Number " "%d and handle 0x%x at Enclosure handle 0x%x, Slot " "%d", le32toh(event_data->PreviousValue), @@ -453,7 +453,7 @@ mpssas_fw_work(struct mps_softc *sc, struct mps_fw_event_work *fw_event) le16toh(event_data->EnclosureHandle), le16toh(event_data->Slot)); break; case MPI2_EVENT_IR_PHYSDISK_RC_STATUS_FLAGS_CHANGED: - mps_dprint(sc, MPS_INFO, " Phys Disk Status changed " + mps_dprint(sc, MPS_EVENT, " Phys Disk Status changed " "from 0x%x to 0x%x for Phys Disk Number %d and " "handle 0x%x at Enclosure handle 0x%x, Slot %d", le32toh(event_data->PreviousValue), @@ -462,7 +462,7 @@ mpssas_fw_work(struct mps_softc *sc, struct mps_fw_event_work *fw_event) le16toh(event_data->EnclosureHandle), le16toh(event_data->Slot)); break; case MPI2_EVENT_IR_PHYSDISK_RC_STATE_CHANGED: - mps_dprint(sc, MPS_INFO, " Phys Disk State changed " + mps_dprint(sc, MPS_EVENT, " Phys Disk State changed " "from 0x%x to 0x%x for Phys Disk Number %d and " "handle 0x%x at Enclosure handle 0x%x, Slot %d", le32toh(event_data->PreviousValue), @@ -518,8 +518,8 @@ mpssas_fw_work(struct mps_softc *sc, struct mps_fw_event_work *fw_event) /* * Informational only. */ - mps_dprint(sc, MPS_INFO, "Received IR Op Status event:\n"); - mps_dprint(sc, MPS_INFO, " RAID Operation of %d is %d " + mps_dprint(sc, MPS_EVENT, "Received IR Op Status event:\n"); + mps_dprint(sc, MPS_EVENT, " RAID Operation of %d is %d " "percent complete for Volume with handle 0x%x", event_data->RAIDOperation, event_data->PercentComplete, le16toh(event_data->VolDevHandle)); @@ -577,7 +577,7 @@ mpssas_fw_work(struct mps_softc *sc, struct mps_fw_event_work *fw_event) break; } - mps_dprint(sc, MPS_INFO, "(%d)->(%s) Event Free: [%x]\n",event_count,__func__, fw_event->event); + mps_dprint(sc, MPS_EVENT, "(%d)->(%s) Event Free: [%x]\n",event_count,__func__, fw_event->event); mpssas_fw_event_free(sc, fw_event); } @@ -669,7 +669,7 @@ mpssas_add_device(struct mps_softc *sc, u16 handle, u8 linkrate){ error = ENXIO; goto out; } - mps_dprint(sc, MPS_INFO, "SAS Address from SAS device page0 = %jx\n", + mps_dprint(sc, MPS_MAPPING, "SAS Address from SAS device page0 = %jx\n", sas_address); targ = &sassc->targets[id]; targ->devinfo = device_info; @@ -696,12 +696,12 @@ mpssas_add_device(struct mps_softc *sc, u16 handle, u8 linkrate){ SLIST_INIT(&targ->luns); mps_describe_devinfo(targ->devinfo, devstring, 80); - mps_dprint(sc, MPS_INFO, "Found device <%s> <%s> <0x%04x> <%d/%d>\n", devstring, + mps_dprint(sc, MPS_MAPPING, "Found device <%s> <%s> <0x%04x> <%d/%d>\n", devstring, mps_describe_table(mps_linkrate_names, targ->linkrate), targ->handle, targ->encl_handle, targ->encl_slot); if ((sassc->flags & MPSSAS_IN_STARTUP) == 0) mpssas_rescan_target(sc, targ); - mps_dprint(sc, MPS_INFO, "Target id 0x%x added\n", targ->tid); + mps_dprint(sc, MPS_MAPPING, "Target id 0x%x added\n", targ->tid); out: mpssas_startup_decrement(sassc); return (error); @@ -734,11 +734,11 @@ mpssas_get_sas_address_for_sata_disk(struct mps_softc *sc, (try_count < 5)); if (rc == 0 && !ioc_status && !sas_status) { - mps_dprint(sc, MPS_INFO, "%s: got SATA identify successfully " + mps_dprint(sc, MPS_MAPPING, "%s: got SATA identify successfully " "for handle = 0x%x with try_count = %d\n", __func__, handle, try_count); } else { - mps_dprint(sc, MPS_INFO, "%s: handle = 0x%x failed\n", + mps_dprint(sc, MPS_MAPPING, "%s: handle = 0x%x failed\n", __func__, handle); return -1; } @@ -887,7 +887,7 @@ mpssas_volume_add(struct mps_softc *sc, u16 handle) SLIST_INIT(&targ->luns); if ((sassc->flags & MPSSAS_IN_STARTUP) == 0) mpssas_rescan_target(sc, targ); - mps_dprint(sc, MPS_INFO, "RAID target id %d added (WWID = 0x%jx)\n", + mps_dprint(sc, MPS_MAPPING, "RAID target id %d added (WWID = 0x%jx)\n", targ->tid, wwid); out: mpssas_startup_decrement(sassc); diff --git a/sys/dev/mps/mps_table.c b/sys/dev/mps/mps_table.c index e004f8d..f6e125d 100644 --- a/sys/dev/mps/mps_table.c +++ b/sys/dev/mps/mps_table.c @@ -205,17 +205,17 @@ mps_print_iocfacts(struct mps_softc *sc, MPI2_IOC_FACTS_REPLY *facts) MPS_PRINTFIELD(sc, facts, IOCNumber, %d); MPS_PRINTFIELD(sc, facts, IOCExceptions, 0x%x); MPS_PRINTFIELD(sc, facts, MaxChainDepth, %d); - mps_dprint_field(sc, MPS_INFO, "WhoInit: %s\n", + mps_dprint_field(sc, MPS_XINFO, "WhoInit: %s\n", mps_describe_table(mps_whoinit_names, facts->WhoInit)); MPS_PRINTFIELD(sc, facts, NumberOfPorts, %d); MPS_PRINTFIELD(sc, facts, RequestCredit, %d); MPS_PRINTFIELD(sc, facts, ProductID, 0x%x); - mps_dprint_field(sc, MPS_INFO, "IOCCapabilities: %b\n", + mps_dprint_field(sc, MPS_XINFO, "IOCCapabilities: %b\n", facts->IOCCapabilities, "\20" "\3ScsiTaskFull" "\4DiagTrace" "\5SnapBuf" "\6ExtBuf" "\7EEDP" "\10BiDirTarg" "\11Multicast" "\14TransRetry" "\15IR" "\16EventReplay" "\17RaidAccel" "\20MSIXIndex" "\21HostDisc"); - mps_dprint_field(sc, MPS_INFO, "FWVersion= %d-%d-%d-%d\n", + mps_dprint_field(sc, MPS_XINFO, "FWVersion= %d-%d-%d-%d\n", facts->FWVersion.Struct.Major, facts->FWVersion.Struct.Minor, facts->FWVersion.Struct.Unit, @@ -225,7 +225,7 @@ mps_print_iocfacts(struct mps_softc *sc, MPI2_IOC_FACTS_REPLY *facts) MPS_PRINTFIELD(sc, facts, MaxTargets, %d); MPS_PRINTFIELD(sc, facts, MaxSasExpanders, %d); MPS_PRINTFIELD(sc, facts, MaxEnclosures, %d); - mps_dprint_field(sc, MPS_INFO, "ProtocolFlags: %b\n", + mps_dprint_field(sc, MPS_XINFO, "ProtocolFlags: %b\n", facts->ProtocolFlags, "\20" "\1ScsiTarg" "\2ScsiInit"); MPS_PRINTFIELD(sc, facts, HighPriorityCredit, %d); MPS_PRINTFIELD(sc, facts, MaxReplyDescriptorPostQueueDepth, %d); @@ -263,7 +263,7 @@ mps_print_sasdev0(struct mps_softc *sc, MPI2_CONFIG_PAGE_SAS_DEV_0 *buf) MPS_PRINTFIELD_START(sc, "SAS Device Page 0"); MPS_PRINTFIELD(sc, buf, Slot, %d); MPS_PRINTFIELD(sc, buf, EnclosureHandle, 0x%x); - mps_dprint_field(sc, MPS_INFO, "SASAddress: 0x%jx\n", + mps_dprint_field(sc, MPS_XINFO, "SASAddress: 0x%jx\n", mps_to_u64(&buf->SASAddress)); MPS_PRINTFIELD(sc, buf, ParentDevHandle, 0x%x); MPS_PRINTFIELD(sc, buf, PhyNum, %d); @@ -271,7 +271,7 @@ mps_print_sasdev0(struct mps_softc *sc, MPI2_CONFIG_PAGE_SAS_DEV_0 *buf) MPS_PRINTFIELD(sc, buf, DevHandle, 0x%x); MPS_PRINTFIELD(sc, buf, AttachedPhyIdentifier, 0x%x); MPS_PRINTFIELD(sc, buf, ZoneGroup, %d); - mps_dprint_field(sc, MPS_INFO, "DeviceInfo: %b,%s\n", buf->DeviceInfo, + mps_dprint_field(sc, MPS_XINFO, "DeviceInfo: %b,%s\n", buf->DeviceInfo, "\20" "\4SataHost" "\5SmpInit" "\6StpInit" "\7SspInit" "\10SataDev" "\11SmpTarg" "\12StpTarg" "\13SspTarg" "\14Direct" "\15LsiDev" "\16AtapiDev" "\17SepDev", @@ -279,7 +279,7 @@ mps_print_sasdev0(struct mps_softc *sc, MPI2_CONFIG_PAGE_SAS_DEV_0 *buf) MPS_PRINTFIELD(sc, buf, Flags, 0x%x); MPS_PRINTFIELD(sc, buf, PhysicalPort, %d); MPS_PRINTFIELD(sc, buf, MaxPortConnections, %d); - mps_dprint_field(sc, MPS_INFO, "DeviceName: 0x%jx\n", + mps_dprint_field(sc, MPS_XINFO, "DeviceName: 0x%jx\n", mps_to_u64(&buf->DeviceName)); MPS_PRINTFIELD(sc, buf, PortGroups, %d); MPS_PRINTFIELD(sc, buf, DmaGroup, %d); @@ -390,17 +390,17 @@ mps_print_expander1(struct mps_softc *sc, MPI2_CONFIG_PAGE_EXPANDER_1 *buf) MPS_PRINTFIELD(sc, buf, NumPhys, %d); MPS_PRINTFIELD(sc, buf, Phy, %d); MPS_PRINTFIELD(sc, buf, NumTableEntriesProgrammed, %d); - mps_dprint_field(sc, MPS_INFO, "ProgrammedLinkRate: %s (0x%x)\n", + mps_dprint_field(sc, MPS_XINFO, "ProgrammedLinkRate: %s (0x%x)\n", mps_describe_table(mps_linkrate_names, (buf->ProgrammedLinkRate >> 4) & 0xf), buf->ProgrammedLinkRate); - mps_dprint_field(sc, MPS_INFO, "HwLinkRate: %s (0x%x)\n", + mps_dprint_field(sc, MPS_XINFO, "HwLinkRate: %s (0x%x)\n", mps_describe_table(mps_linkrate_names, (buf->HwLinkRate >> 4) & 0xf), buf->HwLinkRate); MPS_PRINTFIELD(sc, buf, AttachedDevHandle, 0x%04x); - mps_dprint_field(sc, MPS_INFO, "PhyInfo Reason: %s (0x%x)\n", + mps_dprint_field(sc, MPS_XINFO, "PhyInfo Reason: %s (0x%x)\n", mps_describe_table(mps_phyinfo_reason_names, (buf->PhyInfo >> 16) & 0xf), buf->PhyInfo); - mps_dprint_field(sc, MPS_INFO, "AttachedDeviceInfo: %b,%s\n", + mps_dprint_field(sc, MPS_XINFO, "AttachedDeviceInfo: %b,%s\n", buf->AttachedDeviceInfo, "\20" "\4SATAhost" "\5SMPinit" "\6STPinit" "\7SSPinit" "\10SATAdev" "\11SMPtarg" "\12STPtarg" "\13SSPtarg" "\14Direct" "\15LSIdev" "\16ATAPIdev" "\17SEPdev", @@ -408,14 +408,14 @@ mps_print_expander1(struct mps_softc *sc, MPI2_CONFIG_PAGE_EXPANDER_1 *buf) buf->AttachedDeviceInfo & 0x03)); MPS_PRINTFIELD(sc, buf, ExpanderDevHandle, 0x%04x); MPS_PRINTFIELD(sc, buf, ChangeCount, %d); - mps_dprint_field(sc, MPS_INFO, "NegotiatedLinkRate: %s (0x%x)\n", + mps_dprint_field(sc, MPS_XINFO, "NegotiatedLinkRate: %s (0x%x)\n", mps_describe_table(mps_linkrate_names, buf->NegotiatedLinkRate & 0xf), buf->NegotiatedLinkRate); MPS_PRINTFIELD(sc, buf, PhyIdentifier, %d); MPS_PRINTFIELD(sc, buf, AttachedPhyIdentifier, %d); MPS_PRINTFIELD(sc, buf, DiscoveryInfo, 0x%x); MPS_PRINTFIELD(sc, buf, AttachedPhyInfo, 0x%x); - mps_dprint_field(sc, MPS_INFO, "AttachedPhyInfo Reason: %s (0x%x)\n", + mps_dprint_field(sc, MPS_XINFO, "AttachedPhyInfo Reason: %s (0x%x)\n", mps_describe_table(mps_phyinfo_reason_names, buf->AttachedPhyInfo & 0xf), buf->AttachedPhyInfo); MPS_PRINTFIELD(sc, buf, ZoneGroup, %d); @@ -429,21 +429,21 @@ mps_print_sasphy0(struct mps_softc *sc, MPI2_CONFIG_PAGE_SAS_PHY_0 *buf) MPS_PRINTFIELD(sc, buf, OwnerDevHandle, 0x%04x); MPS_PRINTFIELD(sc, buf, AttachedDevHandle, 0x%04x); MPS_PRINTFIELD(sc, buf, AttachedPhyIdentifier, %d); - mps_dprint_field(sc, MPS_INFO, "AttachedPhyInfo Reason: %s (0x%x)\n", + mps_dprint_field(sc, MPS_XINFO, "AttachedPhyInfo Reason: %s (0x%x)\n", mps_describe_table(mps_phyinfo_reason_names, buf->AttachedPhyInfo & 0xf), buf->AttachedPhyInfo); - mps_dprint_field(sc, MPS_INFO, "ProgrammedLinkRate: %s (0x%x)\n", + mps_dprint_field(sc, MPS_XINFO, "ProgrammedLinkRate: %s (0x%x)\n", mps_describe_table(mps_linkrate_names, (buf->ProgrammedLinkRate >> 4) & 0xf), buf->ProgrammedLinkRate); - mps_dprint_field(sc, MPS_INFO, "HwLinkRate: %s (0x%x)\n", + mps_dprint_field(sc, MPS_XINFO, "HwLinkRate: %s (0x%x)\n", mps_describe_table(mps_linkrate_names, (buf->HwLinkRate >> 4) & 0xf), buf->HwLinkRate); MPS_PRINTFIELD(sc, buf, ChangeCount, %d); MPS_PRINTFIELD(sc, buf, Flags, 0x%x); - mps_dprint_field(sc, MPS_INFO, "PhyInfo Reason: %s (0x%x)\n", + mps_dprint_field(sc, MPS_XINFO, "PhyInfo Reason: %s (0x%x)\n", mps_describe_table(mps_phyinfo_reason_names, (buf->PhyInfo >> 16) & 0xf), buf->PhyInfo); - mps_dprint_field(sc, MPS_INFO, "NegotiatedLinkRate: %s (0x%x)\n", + mps_dprint_field(sc, MPS_XINFO, "NegotiatedLinkRate: %s (0x%x)\n", mps_describe_table(mps_linkrate_names, buf->NegotiatedLinkRate & 0xf), buf->NegotiatedLinkRate); } diff --git a/sys/dev/mps/mps_user.c b/sys/dev/mps/mps_user.c index c7bd89a..9a03d8e 100644 --- a/sys/dev/mps/mps_user.c +++ b/sys/dev/mps/mps_user.c @@ -677,7 +677,7 @@ mps_user_command(struct mps_softc *sc, struct mps_usr_command *cmd) hdr = (MPI2_REQUEST_HEADER *)cm->cm_req; - mps_dprint(sc, MPS_INFO, "mps_user_command: req %p %d rpl %p %d\n", + mps_dprint(sc, MPS_USER, "mps_user_command: req %p %d rpl %p %d\n", cmd->req, cmd->req_len, cmd->rpl, cmd->rpl_len ); if (cmd->req_len > (int)sc->facts->IOCRequestFrameSize * 4) { @@ -688,7 +688,7 @@ mps_user_command(struct mps_softc *sc, struct mps_usr_command *cmd) if (err != 0) goto RetFreeUnlocked; - mps_dprint(sc, MPS_INFO, "mps_user_command: Function %02X " + mps_dprint(sc, MPS_USER, "mps_user_command: Function %02X " "MsgFlags %02X\n", hdr->Function, hdr->MsgFlags ); if (cmd->len > 0) { @@ -742,7 +742,7 @@ mps_user_command(struct mps_softc *sc, struct mps_usr_command *cmd) copyout(rpl, cmd->rpl, sz); if (buf != NULL) copyout(buf, cmd->buf, cmd->len); - mps_dprint(sc, MPS_INFO, "mps_user_command: reply size %d\n", sz ); + mps_dprint(sc, MPS_USER, "mps_user_command: reply size %d\n", sz ); RetFreeUnlocked: mps_lock(sc); @@ -771,7 +771,7 @@ mps_user_pass_thru(struct mps_softc *sc, mps_pass_thru_t *data) */ mps_lock(sc); if (sc->mps_flags & MPS_FLAGS_BUSY) { - mps_dprint(sc, MPS_INFO, "%s: Only one passthru command " + mps_dprint(sc, MPS_USER, "%s: Only one passthru command " "allowed at a single time.", __func__); mps_unlock(sc); return (EBUSY); @@ -803,7 +803,7 @@ mps_user_pass_thru(struct mps_softc *sc, mps_pass_thru_t *data) } else return (EINVAL); - mps_dprint(sc, MPS_INFO, "%s: req 0x%jx %d rpl 0x%jx %d " + mps_dprint(sc, MPS_USER, "%s: req 0x%jx %d rpl 0x%jx %d " "data in 0x%jx %d data out 0x%jx %d data dir %d\n", __func__, data->PtrRequest, data->RequestSize, data->PtrReply, data->ReplySize, data->PtrData, data->DataSize, @@ -823,7 +823,7 @@ mps_user_pass_thru(struct mps_softc *sc, mps_pass_thru_t *data) } function = tmphdr.Function; - mps_dprint(sc, MPS_INFO, "%s: Function %02X MsgFlags %02X\n", __func__, + mps_dprint(sc, MPS_USER, "%s: Function %02X MsgFlags %02X\n", __func__, function, tmphdr.MsgFlags); /* @@ -1252,7 +1252,7 @@ mps_release_fw_diag_buffer(struct mps_softc *sc, */ *return_code = MPS_FW_DIAG_ERROR_RELEASE_FAILED; if (!pBuffer->enabled) { - mps_dprint(sc, MPS_INFO, "%s: This buffer type is not supported " + mps_dprint(sc, MPS_USER, "%s: This buffer type is not supported " "by the IOC", __func__); return (MPS_DIAG_FAILURE); } @@ -1795,7 +1795,7 @@ mps_user_diag_action(struct mps_softc *sc, mps_diag_action_t *data) * Only allow one diag action at one time. */ if (sc->mps_flags & MPS_FLAGS_BUSY) { - mps_dprint(sc, MPS_INFO, "%s: Only one FW diag command " + mps_dprint(sc, MPS_USER, "%s: Only one FW diag command " "allowed at a single time.", __func__); return (EBUSY); } @@ -1982,7 +1982,7 @@ mps_user_reg_access(struct mps_softc *sc, mps_reg_access_t *data) */ case REG_IO_READ: case REG_IO_WRITE: - mps_dprint(sc, MPS_INFO, "IO access is not supported. " + mps_dprint(sc, MPS_USER, "IO access is not supported. " "Use memory access."); status = EINVAL; break; @@ -2170,7 +2170,7 @@ mps_ioctl(struct cdev *dev, u_long cmd, void *arg, int flag, printf("Port Enable did not complete after Diag " "Reset msleep error %d.\n", msleep_ret); else - mps_dprint(sc, MPS_INFO, + mps_dprint(sc, MPS_USER, "Hard Reset with Port Enable completed in %d seconds.\n", (uint32_t) (time_uptime - reinit_start)); break; diff --git a/sys/dev/mps/mpsvar.h b/sys/dev/mps/mpsvar.h index 5d14b5f..c30ee2c 100644 --- a/sys/dev/mps/mpsvar.h +++ b/sys/dev/mps/mpsvar.h @@ -581,11 +581,17 @@ mps_unlock(struct mps_softc *sc) mtx_unlock(&sc->mps_mtx); } -#define MPS_INFO (1 << 0) -#define MPS_TRACE (1 << 1) -#define MPS_FAULT (1 << 2) -#define MPS_EVENT (1 << 3) -#define MPS_LOG (1 << 4) +#define MPS_INFO (1 << 0) /* Basic info */ +#define MPS_FAULT (1 << 1) /* Hardware faults */ +#define MPS_EVENT (1 << 2) /* Event data from the controller */ +#define MPS_LOG (1 << 3) /* Log data from the controller */ +#define MPS_RECOVERY (1 << 4) /* Command error recovery tracing */ +#define MPS_ERROR (1 << 5) /* Parameter errors, programming bugs */ +#define MPS_INIT (1 << 6) /* Things related to system init */ +#define MPS_XINFO (1 << 7) /* More detailed/noisy info */ +#define MPS_USER (1 << 8) /* Trace user-generated commands */ +#define MPS_MAPPING (1 << 9) /* Trace device mappings */ +#define MPS_TRACE (1 << 10) /* Function-by-function trace */ #define mps_printf(sc, args...) \ device_printf((sc)->mps_dev, ##args) @@ -598,23 +604,23 @@ do { \ #define mps_dprint(sc, level, msg, args...) \ do { \ - if (sc->mps_debug & level) \ - device_printf(sc->mps_dev, msg, ##args); \ + if ((sc)->mps_debug & (level)) \ + device_printf((sc)->mps_dev, msg, ##args); \ } while (0) #define mps_dprint_field(sc, level, msg, args...) \ do { \ - if (sc->mps_debug & level) \ + if ((sc)->mps_debug & (level)) \ printf("\t" msg, ##args); \ } while (0) #define MPS_PRINTFIELD_START(sc, tag...) \ - mps_dprint((sc), MPS_INFO, ##tag); \ - mps_dprint_field((sc), MPS_INFO, ":\n") + mps_dprint((sc), MPS_XINFO, ##tag); \ + mps_dprint_field((sc), MPS_XINFO, ":\n") #define MPS_PRINTFIELD_END(sc, tag) \ - mps_dprint((sc), MPS_INFO, tag "\n") + mps_dprint((sc), MPS_XINFO, tag "\n") #define MPS_PRINTFIELD(sc, facts, attr, fmt) \ - mps_dprint_field((sc), MPS_INFO, #attr ": " #fmt "\n", (facts)->attr) + mps_dprint_field((sc), MPS_XINFO, #attr ": " #fmt "\n", (facts)->attr) #define MPS_EVENTFIELD_START(sc, tag...) \ mps_dprint((sc), MPS_EVENT, ##tag); \ @@ -622,6 +628,9 @@ do { \ #define MPS_EVENTFIELD(sc, facts, attr, fmt) \ mps_dprint_field((sc), MPS_EVENT, #attr ": " #fmt "\n", (facts)->attr) +#define MPS_FUNCTRACE(sc) \ + mps_dprint((sc), MPS_TRACE, "%s\n", __func__) + #define CAN_SLEEP 1 #define NO_SLEEP 0 |