diff --git a/sys/dev/ioat/ioat.c b/sys/dev/ioat/ioat.c index ccf9166f8abb..26b465de69aa 100644 --- a/sys/dev/ioat/ioat.c +++ b/sys/dev/ioat/ioat.c @@ -693,8 +693,8 @@ ioat_process_events(struct ioat_softc *ioat) while (desc->hw_desc_bus_addr != status && ioat_get_active(ioat) > 0) { desc = ioat_get_ring_entry(ioat, ioat->tail); dmadesc = &desc->bus_dmadesc; - CTR4(KTR_IOAT, "channel=%u completing desc %u ok cb %p(%p)", - ioat->chan_idx, ioat->tail, dmadesc->callback_fn, + CTR5(KTR_IOAT, "channel=%u completing desc idx %u (%p) ok cb %p(%p)", + ioat->chan_idx, ioat->tail, dmadesc, dmadesc->callback_fn, dmadesc->callback_arg); if (dmadesc->callback_fn != NULL) @@ -703,6 +703,8 @@ ioat_process_events(struct ioat_softc *ioat) completed++; ioat->tail++; } + CTR5(KTR_IOAT, "%s channel=%u head=%u tail=%u active=%u", __func__, + ioat->chan_idx, ioat->head, ioat->tail, ioat_get_active(ioat)); if (completed != 0) { ioat->last_seen = desc->hw_desc_bus_addr; @@ -760,8 +762,8 @@ ioat_process_events(struct ioat_softc *ioat) while (ioat_get_active(ioat) > 0) { desc = ioat_get_ring_entry(ioat, ioat->tail); dmadesc = &desc->bus_dmadesc; - CTR4(KTR_IOAT, "channel=%u completing desc %u err cb %p(%p)", - ioat->chan_idx, ioat->tail, dmadesc->callback_fn, + CTR5(KTR_IOAT, "channel=%u completing desc idx %u (%p) err cb %p(%p)", + ioat->chan_idx, ioat->tail, dmadesc, dmadesc->callback_fn, dmadesc->callback_arg); if (dmadesc->callback_fn != NULL) @@ -773,6 +775,8 @@ ioat_process_events(struct ioat_softc *ioat) ioat->stats.descriptors_processed++; ioat->stats.descriptors_error++; } + CTR5(KTR_IOAT, "%s channel=%u head=%u tail=%u active=%u", __func__, + ioat->chan_idx, ioat->head, ioat->tail, ioat_get_active(ioat)); if (ioat->is_completion_pending) { ioat->is_completion_pending = FALSE; @@ -947,7 +951,8 @@ ioat_release(bus_dmaengine_t dmaengine) struct ioat_softc *ioat; ioat = to_ioat_softc(dmaengine); - CTR2(KTR_IOAT, "%s channel=%u", __func__, ioat->chan_idx); + CTR3(KTR_IOAT, "%s channel=%u dispatch hw_head=%u", __func__, + ioat->chan_idx, ioat->hw_head & UINT16_MAX); ioat_write_2(ioat, IOAT_DMACOUNT_OFFSET, (uint16_t)ioat->hw_head); if (!ioat->is_completion_pending) { @@ -1040,7 +1045,6 @@ ioat_copy(bus_dmaengine_t dmaengine, bus_addr_t dst, struct ioat_softc *ioat; ioat = to_ioat_softc(dmaengine); - CTR2(KTR_IOAT, "%s channel=%u", __func__, ioat->chan_idx); if (((src | dst) & (0xffffull << 48)) != 0) { ioat_log_message(0, "%s: High 16 bits of src/dst invalid\n", @@ -1058,6 +1062,8 @@ ioat_copy(bus_dmaengine_t dmaengine, bus_addr_t dst, dump_descriptor(hw_desc); ioat_submit_single(ioat); + CTR6(KTR_IOAT, "%s channel=%u desc=%p dest=%lx src=%lx len=%lx", + __func__, ioat->chan_idx, &desc->bus_dmadesc, dst, src, len); return (&desc->bus_dmadesc); } @@ -1414,11 +1420,16 @@ ioat_reserve_space(struct ioat_softc *ioat, uint32_t num_descs, int mflags) if (ioat_get_ring_space(ioat) >= num_descs) goto out; + CTR3(KTR_IOAT, "%s channel=%u starved (%u)", __func__, + ioat->chan_idx, num_descs); + if (!dug && !ioat->is_submitter_processing && (1 << ioat->ring_size_order) > num_descs) { ioat->is_submitter_processing = TRUE; mtx_unlock(&ioat->submit_lock); + CTR2(KTR_IOAT, "%s channel=%u attempting to process events", + __func__, ioat->chan_idx); ioat_process_events(ioat); mtx_lock(&ioat->submit_lock); @@ -1433,6 +1444,8 @@ ioat_reserve_space(struct ioat_softc *ioat, uint32_t num_descs, int mflags) order = ioat->ring_size_order; if (ioat->is_resize_pending || order == IOAT_MAX_ORDER) { if ((mflags & M_WAITOK) != 0) { + CTR2(KTR_IOAT, "%s channel=%u blocking on completions", + __func__, ioat->chan_idx); msleep(&ioat->tail, &ioat->submit_lock, 0, "ioat_rsz", 0); continue; @@ -1794,6 +1807,9 @@ ioat_submit_single(struct ioat_softc *ioat) ioat_get(ioat, IOAT_ACTIVE_DESCR_REF); atomic_add_rel_int(&ioat->head, 1); atomic_add_rel_int(&ioat->hw_head, 1); + CTR5(KTR_IOAT, "%s channel=%u head=%u hw_head=%u tail=%u", __func__, + ioat->chan_idx, ioat->head, ioat->hw_head & UINT16_MAX, + ioat->tail); ioat->stats.descriptors_submitted++; }