From patchwork Sun May 10 10:36:26 2015 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Sagi Grimberg X-Patchwork-Id: 6371571 Return-Path: X-Original-To: patchwork-linux-rdma@patchwork.kernel.org Delivered-To: patchwork-parsemail@patchwork2.web.kernel.org Received: from mail.kernel.org (mail.kernel.org [198.145.29.136]) by patchwork2.web.kernel.org (Postfix) with ESMTP id 25390BEEE1 for ; Sun, 10 May 2015 10:36:57 +0000 (UTC) Received: from mail.kernel.org (localhost [127.0.0.1]) by mail.kernel.org (Postfix) with ESMTP id C434A202E9 for ; Sun, 10 May 2015 10:36:55 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.kernel.org (Postfix) with ESMTP id 4BA3C20256 for ; Sun, 10 May 2015 10:36:54 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752361AbbEJKgx (ORCPT ); Sun, 10 May 2015 06:36:53 -0400 Received: from ns1327.ztomy.com ([193.47.165.129]:50293 "EHLO mellanox.co.il" rhost-flags-OK-FAIL-OK-FAIL) by vger.kernel.org with ESMTP id S1752303AbbEJKgw (ORCPT ); Sun, 10 May 2015 06:36:52 -0400 Received: from Internal Mail-Server by MTLPINE1 (envelope-from sagig@mellanox.com) with ESMTPS (AES256-SHA encrypted); 10 May 2015 13:36:21 +0300 Received: from r-vnc05.mtr.labs.mlnx (r-vnc05.mtr.labs.mlnx [10.208.0.115]) by labmailer.mlnx (8.13.8/8.13.8) with ESMTP id t4AAaRON030846 for ; Sun, 10 May 2015 13:36:27 +0300 Received: from r-vnc05.mtr.labs.mlnx (localhost [127.0.0.1]) by r-vnc05.mtr.labs.mlnx (8.14.4/8.14.4) with ESMTP id t4AAaRAO023593 for ; Sun, 10 May 2015 13:36:27 +0300 Received: (from sagig@localhost) by r-vnc05.mtr.labs.mlnx (8.14.4/8.14.4/Submit) id t4AAaQs6023589 for linux-rdma@vger.kernel.org; Sun, 10 May 2015 13:36:26 +0300 From: Sagi Grimberg To: linux-rdma@vger.kernel.org Subject: [PATCH RFC] IB/core, cma: Nice log-friendly string helpers Date: Sun, 10 May 2015 13:36:26 +0300 Message-Id: <1431254186-23554-1-git-send-email-sagig@mellanox.com> X-Mailer: git-send-email 1.8.4.3 Sender: linux-rdma-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-rdma@vger.kernel.org X-Spam-Status: No, score=-6.9 required=5.0 tests=BAYES_00, RCVD_IN_DNSWL_HI, T_RP_MATCHES_RCVD, UNPARSEABLE_RELAY autolearn=ham version=3.3.1 X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on mail.kernel.org X-Virus-Scanned: ClamAV using ClamSMTP 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 --- 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; }