[PATCH RFC] IB/core, cma: Nice log-friendly string helpers

Sagi Grimberg
2015-05-10T10:36:26Z

Some of us keep revisiting the code to decode IB/RDMA_CM enumerations
that appear in our logs. Let's borrow the nice logging helpers xprtrdma
has for CMA events, IB events and WC statuses. Also, have srp, iser and
isert be early adopters.

Signed-off-by: Sagi Grimberg <sagig-VPRAkNaXOzVWk0Htik3J/w@public.gmane.org>
---
I have been using this patch for some time now so I thought
it would be nice to get it out.

drivers/infiniband/ulp/iser/iser_verbs.c | 25 +++++---
drivers/infiniband/ulp/srp/ib_srp.c | 15 +++--
include/rdma/ib_verbs.h | 55 ++++++++++++++++++
include/rdma/rdma_cm.h | 23 ++++++++
net/sunrpc/xprtrdma/verbs.c | 90 ++----------------------------
5 files changed, 106 insertions(+), 102 deletions(-)

diff --git a/drivers/infiniband/ulp/iser/iser_verbs.c b/drivers/infiniband/ulp/iser/iser_verbs.c
index cc2dd35..764f9f9 100644
--- a/drivers/infiniband/ulp/iser/iser_verbs.c
+++ b/drivers/infiniband/ulp/iser/iser_verbs.c
@@ -51,19 +51,20 @@ static void iser_cq_callback(struct ib_cq *cq, void *cq_context);

static void iser_cq_event_callback(struct ib_event *cause, void *context)
{
- iser_err("got cq event %d \n", cause->event);
+ iser_err("cq event %s(%d)\n", IB_EVENT(cause->event), cause->event);
}

static void iser_qp_event_callback(struct ib_event *cause, void *context)
{
- iser_err("got qp event %d\n",cause->event);
+ iser_err("qp event %s(%d)\n", IB_EVENT(cause->event), cause->event);
}

static void iser_event_handler(struct ib_event_handler *handler,
struct ib_event *event)
{
- iser_err("async event %d on device %s port %d\n", event->event,
- event->device->name, event->element.port_num);
+ iser_err("async event %s(%d) on device %s port %d\n",
+ IB_EVENT(event->event), event->event,
+ event->device->name, event->element.port_num);
}

/**
@@ -873,8 +874,9 @@ static int iser_cma_handler(struct rdma_cm_id *cma_id, struct rdma_cm_event *eve
int ret = 0;

iser_conn = (struct iser_conn *)cma_id->context;
- iser_info("event %d status %d conn %p id %p\n",
- event->event, event->status, cma_id->context, cma_id);
+ iser_info("event %s(%d) status %d conn %p id %p\n",
+ CMA_EVENT(event->event), event->event,
+ event->status, cma_id->context, cma_id);

mutex_lock(&iser_conn->state_mutex);
switch (event->event) {
@@ -913,7 +915,8 @@ static int iser_cma_handler(struct rdma_cm_id *cma_id, struct rdma_cm_event *eve
}
break;
default:
- iser_err("Unexpected RDMA CM event (%d)\n", event->event);
+ iser_err("Unexpected RDMA CM event %s(%d)\n",
+ CMA_EVENT(event->event), event->event);
break;
}
mutex_unlock(&iser_conn->state_mutex);
@@ -1173,10 +1176,12 @@ static void iser_handle_wc(struct ib_wc *wc)
}
} else {
if (wc->status != IB_WC_WR_FLUSH_ERR)
- iser_err("wr id %llx status %d vend_err %x\n",
- wc->wr_id, wc->status, wc->vendor_err);
+ iser_err("%s(%d): wr id %llx vend_err %x\n",
+ WC_STATUS(wc->status), wc->status, wc->wr_id,
+ wc->vendor_err);
else
- iser_dbg("flush error: wr id %llx\n", wc->wr_id);
+ iser_dbg("%s(%d): wr id %llx\n",
+ WC_STATUS(wc->status), wc->status, wc->wr_id);

if (wc->wr_id == ISER_BEACON_WRID)
/* all flush errors were consumed */
diff --git a/drivers/infiniband/ulp/srp/ib_srp.c b/drivers/infiniband/ulp/srp/ib_srp.c
index 918814c..6b211c4 100644
--- a/drivers/infiniband/ulp/srp/ib_srp.c
+++ b/drivers/infiniband/ulp/srp/ib_srp.c
@@ -253,7 +253,7 @@ static void srp_free_iu(struct srp_host *host, struct srp_iu *iu)

static void srp_qp_event(struct ib_event *event, void *context)
{
- pr_debug("QP event %d\n", event->event);
+ pr_debug("QP event %s(%d)\n", IB_EVENT(event->event), event->event);
}

static int srp_init_qp(struct srp_target_port *target,
@@ -1932,17 +1932,18 @@ static void srp_handle_qp_err(u64 wr_id, enum ib_wc_status wc_status,
if (target->connected && !target->qp_in_error) {
if (wr_id & LOCAL_INV_WR_ID_MASK) {
shost_printk(KERN_ERR, target->scsi_host, PFX
- "LOCAL_INV failed with status %d\n",
- wc_status);
+ "LOCAL_INV failed with status %s(%d)\n",
+ WC_STATUS(wc_status), wc_status);
} else if (wr_id & FAST_REG_WR_ID_MASK) {
shost_printk(KERN_ERR, target->scsi_host, PFX
- "FAST_REG_MR failed status %d\n",
- wc_status);
+ "FAST_REG_MR failed status %s(%d)\n",
+ WC_STATUS(wc_status), wc_status);
} else {
shost_printk(KERN_ERR, target->scsi_host,
- PFX "failed %s status %d for iu %p\n",
+ PFX "failed %s status %s(%d) for iu %p\n",
send_err ? "send" : "receive",
- wc_status, (void *)(uintptr_t)wr_id);
+ WC_STATUS(wc_status), wc_status,
+ (void *)(uintptr_t)wr_id);
}
queue_work(system_long_wq, &target->tl_err_work);
}
diff --git a/include/rdma/ib_verbs.h b/include/rdma/ib_verbs.h
index 65994a1..d615e63 100644
--- a/include/rdma/ib_verbs.h
+++ b/include/rdma/ib_verbs.h
@@ -412,6 +412,32 @@ enum ib_event_type {
IB_EVENT_GID_CHANGE,
};

+static const char * const ib_events[] = {
+ "CQ_ERR",
+ "QP_FATAL",
+ "QP_REQ_ERR",
+ "QP_ACCESS_ERR",
+ "COMM_EST",
+ "SQ_DRAINED",
+ "PATH_MIG",
+ "PATH_MIG_ERR",
+ "DEVICE_FATAL",
+ "PORT_ACTIVE",
+ "PORT_ERR",
+ "LID_CHANGE",
+ "PKEY_CHANGE",
+ "SM_CHANGE",
+ "SRQ_ERR",
+ "SRQ_LIMIT_REACHED",
+ "QP_LAST_WQE_REACHED",
+ "CLIENT_REREGISTER",
+ "GID_CHANGE",
+};
+
+#define IB_EVENT(event) \
+ ((event) < ARRAY_SIZE(ib_events) ? \
+ ib_events[(event)] : "UNRECOGNIZED_EVENT")
+
struct ib_event {
struct ib_device *device;
union {
@@ -663,6 +689,35 @@ enum ib_wc_status {
IB_WC_GENERAL_ERR
};

+static const char * const wc_statuses[] = {
+ "SUCCESS",
+ "LOC_LEN_ERR",
+ "LOC_QP_OP_ERR",
+ "LOC_EEC_OP_ERR",
+ "LOC_PROT_ERR",
+ "WR_FLUSH_ERR",
+ "MW_BIND_ERR",
+ "BAD_RESP_ERR",
+ "LOC_ACCESS_ERR",
+ "REM_INV_REQ_ERR",
+ "REM_ACCESS_ERR",
+ "REM_OP_ERR",
+ "RETRY_EXC_ERR",
+ "RNR_RETRY_EXC_ERR",
+ "LOC_RDD_VIOL_ERR",
+ "REM_INV_RD_REQ_ERR",
+ "REM_ABORT_ERR",
+ "INV_EECN_ERR",
+ "INV_EEC_STATE_ERR",
+ "FATAL_ERR",
+ "RESP_TIMEOUT_ERR",
+ "GENERAL_ERR",
+};
+
+#define WC_STATUS(status) \
+ ((status) < ARRAY_SIZE(wc_statuses) ? \
+ wc_statuses[(status)] : "UNRECOGNIZED_STATUS")
+
enum ib_wc_opcode {
IB_WC_SEND,
IB_WC_RDMA_WRITE,
diff --git a/include/rdma/rdma_cm.h b/include/rdma/rdma_cm.h
index 1ed2088..4eec92c 100644
--- a/include/rdma/rdma_cm.h
+++ b/include/rdma/rdma_cm.h
@@ -62,6 +62,29 @@ enum rdma_cm_event_type {
RDMA_CM_EVENT_TIMEWAIT_EXIT
};

+static const char * const cma_events[] = {
+ "ADDR_RESOLVED",
+ "ADDR_ERROR",
+ "ROUTE_RESOLVED",
+ "ROUTE_ERROR",
+ "CONNECT_REQUEST",
+ "CONNECT_RESPONSE",
+ "CONNECT_ERROR",
+ "UNREACHABLE",
+ "REJECTED",
+ "ESTABLISHED",
+ "DISCONNECTED",
+ "DEVICE_REMOVAL",
+ "MULTICAST_JOIN",
+ "MULTICAST_ERROR",
+ "ADDR_CHANGE",
+ "TIMEWAIT_EXIT",
+};
+
+#define CMA_EVENT(event) \
+ ((event) < ARRAY_SIZE(cma_events) ? \
+ cma_events[(event)] : "UNRECOGNIZED_EVENT")
+
enum rdma_port_space {
RDMA_PS_SDP = 0x0001,
RDMA_PS_IPOIB = 0x0002,
diff --git a/net/sunrpc/xprtrdma/verbs.c b/net/sunrpc/xprtrdma/verbs.c
index 4870d27..8423dd2 100644
--- a/net/sunrpc/xprtrdma/verbs.c
+++ b/net/sunrpc/xprtrdma/verbs.c
@@ -105,32 +105,6 @@ rpcrdma_run_tasklet(unsigned long data)

static DECLARE_TASKLET(rpcrdma_tasklet_g, rpcrdma_run_tasklet, 0UL);

-static const char * const async_event[] = {
- "CQ error",
- "QP fatal error",
- "QP request error",
- "QP access error",
- "communication established",
- "send queue drained",
- "path migration successful",
- "path mig error",
- "device fatal error",
- "port active",
- "port error",
- "LID change",
- "P_key change",
- "SM change",
- "SRQ error",
- "SRQ limit reached",
- "last WQE reached",
- "client reregister",
- "GID change",
-};
-
-#define ASYNC_MSG(status) \
- ((status) < ARRAY_SIZE(async_event) ? \
- async_event[(status)] : "unknown async error")
-
static void
rpcrdma_schedule_tasklet(struct list_head *sched_list)
{
@@ -148,7 +122,7 @@ rpcrdma_qp_async_error_upcall(struct ib_event *event, void *context)
struct rpcrdma_ep *ep = context;

pr_err("RPC: %s: %s on device %s ep %p\n",
- __func__, ASYNC_MSG(event->event),
+ __func__, IB_EVENT(event->event),
event->device->name, context);
if (ep->rep_connected == 1) {
ep->rep_connected = -EIO;
@@ -163,7 +137,7 @@ rpcrdma_cq_async_error_upcall(struct ib_event *event, void *context)
struct rpcrdma_ep *ep = context;

pr_err("RPC: %s: %s on device %s ep %p\n",
- __func__, ASYNC_MSG(event->event),
+ __func__, IB_EVENT(event->event),
event->device->name, context);
if (ep->rep_connected == 1) {
ep->rep_connected = -EIO;
@@ -172,35 +146,6 @@ rpcrdma_cq_async_error_upcall(struct ib_event *event, void *context)
}
}

-static const char * const wc_status[] = {
- "success",
- "local length error",
- "local QP operation error",
- "local EE context operation error",
- "local protection error",
- "WR flushed",
- "memory management operation error",
- "bad response error",
- "local access error",
- "remote invalid request error",
- "remote access error",
- "remote operation error",
- "transport retry counter exceeded",
- "RNR retry counter exceeded",
- "local RDD violation error",
- "remove invalid RD request",
- "operation aborted",
- "invalid EE context number",
- "invalid EE context state",
- "fatal error",
- "response timeout error",
- "general error",
-};
-
-#define COMPLETION_MSG(status) \
- ((status) < ARRAY_SIZE(wc_status) ? \
- wc_status[(status)] : "unexpected completion error")
-
static void
rpcrdma_sendcq_process_wc(struct ib_wc *wc)
{
@@ -209,7 +154,7 @@ rpcrdma_sendcq_process_wc(struct ib_wc *wc)
if (wc->status != IB_WC_SUCCESS &&
wc->status != IB_WC_WR_FLUSH_ERR)
pr_err("RPC: %s: SEND: %s\n",
- __func__, COMPLETION_MSG(wc->status));
+ __func__, WC_STATUS(wc->status));
} else {
struct rpcrdma_mw *r;

@@ -302,7 +247,7 @@ out_schedule:
out_fail:
if (wc->status != IB_WC_WR_FLUSH_ERR)
pr_err("RPC: %s: rep %p: %s\n",
- __func__, rep, COMPLETION_MSG(wc->status));
+ __func__, rep, WC_STATUS(wc->status));
rep->rr_len = ~0U;
goto out_schedule;
}
@@ -386,31 +331,6 @@ rpcrdma_flush_cqs(struct rpcrdma_ep *ep)
rpcrdma_sendcq_process_wc(&wc);
}

-#if IS_ENABLED(CONFIG_SUNRPC_DEBUG)
-static const char * const conn[] = {
- "address resolved",
- "address error",
- "route resolved",
- "route error",
- "connect request",
- "connect response",
- "connect error",
- "unreachable",
- "rejected",
- "established",
- "disconnected",
- "device removal",
- "multicast join",
- "multicast error",
- "address change",
- "timewait exit",
-};
-
-#define CONNECTION_MSG(status) \
- ((status) < ARRAY_SIZE(conn) ? \
- conn[(status)] : "unrecognized connection error")
-#endif
-
static int
rpcrdma_conn_upcall(struct rdma_cm_id *id, struct rdma_cm_event *event)
{
@@ -476,7 +396,7 @@ connected:
default:
dprintk("RPC: %s: %pIS:%u (ep 0x%p): %s\n",
__func__, sap, rpc_get_port(sap), ep,
- CONNECTION_MSG(event->event));
+ CMA_EVENT(event->event));
break;
}

--
1.7.1