LU-15234 lnet: add mechanism for dumping lnd peer debug info

Add ability to dump lnd peer debug info:
	lnetctl debug peer --nid=<nid>

The debug info is dumped to the log as D_CONSOLE by the respective
lnd and can be retrieved with "lctl dk" or seen in syslog.
This mechanism has been added for socklnd and o2iblnd peers.

Lustre-change: https://review.whamcloud.com/48566
Lustre-commit: 950e59ced18d49e9fdd31c1e9de43b89a0bc1c1d

Test-Parameters: trivial testlist=sanity-lnet
Signed-off-by: Serguei Smirnov <ssmirnov@whamcloud.com>
Change-Id: Ia9c4d59143206bcb7ec43806594cf0cfaed5f0a9
Reviewed-on: https://review.whamcloud.com/c/ex/lustre-release/+/49038
Tested-by: jenkins <devops@whamcloud.com>
Tested-by: Maloo <maloo@whamcloud.com>
Reviewed-by: Frank Sehr <fsehr@whamcloud.com>
Reviewed-by: Andreas Dilger <adilger@whamcloud.com>

diff --git a/lnet/klnds/o2iblnd/o2iblnd.c b/lnet/klnds/o2iblnd/o2iblnd.c
index cd3ba2f..1ecc900 100644 (file)
--- a/lnet/klnds/o2iblnd/o2iblnd.c
+++ b/lnet/klnds/o2iblnd/o2iblnd.c
@@ -422,8 +422,98 @@ kiblnd_unlink_peer_locked(struct kib_peer_ni *peer_ni)
         kiblnd_peer_decref(peer_ni);
 }
 
+
+static void
+kiblnd_debug_rx(struct kib_rx *rx)
+{
+       CDEBUG(D_CONSOLE, "      %p msg_type %x cred %d\n",
+              rx, rx->rx_msg->ibm_type,
+              rx->rx_msg->ibm_credits);
+}
+
+static void
+kiblnd_debug_tx(struct kib_tx *tx)
+{
+       CDEBUG(D_CONSOLE, "      %p snd %d q %d w %d rc %d dl %lld "
+              "cookie %#llx msg %s%s type %x cred %d\n",
+              tx, tx->tx_sending, tx->tx_queued, tx->tx_waiting,
+              tx->tx_status, ktime_to_ns(tx->tx_deadline), tx->tx_cookie,
+              tx->tx_lntmsg[0] == NULL ? "-" : "!",
+              tx->tx_lntmsg[1] == NULL ? "-" : "!",
+              tx->tx_msg->ibm_type, tx->tx_msg->ibm_credits);
+}
+
+static void
+kiblnd_debug_conn(struct kib_conn *conn)
+{
+       struct list_head        *tmp;
+       int                     i;
+
+       spin_lock(&conn->ibc_lock);
+
+       CDEBUG(D_CONSOLE, "conn[%d] %p [version %x] -> %s:\n",
+              atomic_read(&conn->ibc_refcount), conn,
+              conn->ibc_version, libcfs_nid2str(conn->ibc_peer->ibp_nid));
+       CDEBUG(D_CONSOLE, "   state %d nposted %d/%d cred %d o_cred %d "
+              " r_cred %d\n", conn->ibc_state, conn->ibc_noops_posted,
+              conn->ibc_nsends_posted, conn->ibc_credits,
+              conn->ibc_outstanding_credits, conn->ibc_reserved_credits);
+       CDEBUG(D_CONSOLE, "   comms_err %d\n", conn->ibc_comms_error);
+
+       CDEBUG(D_CONSOLE, "   early_rxs:\n");
+       list_for_each(tmp, &conn->ibc_early_rxs)
+               kiblnd_debug_rx(list_entry(tmp, struct kib_rx, rx_list));
+
+       CDEBUG(D_CONSOLE, "   tx_noops:\n");
+       list_for_each(tmp, &conn->ibc_tx_noops)
+               kiblnd_debug_tx(list_entry(tmp, struct kib_tx, tx_list));
+
+       CDEBUG(D_CONSOLE, "   tx_queue_nocred:\n");
+       list_for_each(tmp, &conn->ibc_tx_queue_nocred)
+               kiblnd_debug_tx(list_entry(tmp, struct kib_tx, tx_list));
+
+       CDEBUG(D_CONSOLE, "   tx_queue_rsrvd:\n");
+       list_for_each(tmp, &conn->ibc_tx_queue_rsrvd)
+               kiblnd_debug_tx(list_entry(tmp, struct kib_tx, tx_list));
+
+       CDEBUG(D_CONSOLE, "   tx_queue:\n");
+       list_for_each(tmp, &conn->ibc_tx_queue)
+               kiblnd_debug_tx(list_entry(tmp, struct kib_tx, tx_list));
+
+       CDEBUG(D_CONSOLE, "   active_txs:\n");
+       list_for_each(tmp, &conn->ibc_active_txs)
+               kiblnd_debug_tx(list_entry(tmp, struct kib_tx, tx_list));
+
+       CDEBUG(D_CONSOLE, "   rxs:\n");
+       for (i = 0; i < IBLND_RX_MSGS(conn); i++)
+               kiblnd_debug_rx(&conn->ibc_rxs[i]);
+
+       spin_unlock(&conn->ibc_lock);
+}
+
+static void
+kiblnd_dump_peer_debug_info(struct kib_peer_ni *peer_ni)
+{
+       struct kib_conn *conn;
+       struct kib_conn *cnxt;
+       int count = 0;
+
+       CDEBUG(D_CONSOLE, "[last_alive, races, reconnected, error]: %lld, %d, %d, %d\n",
+              peer_ni->ibp_last_alive,
+              peer_ni->ibp_races,
+              peer_ni->ibp_reconnected,
+              peer_ni->ibp_error);
+       list_for_each_entry_safe(conn, cnxt, &peer_ni->ibp_conns,
+                                ibc_list) {
+               CDEBUG(D_CONSOLE, "Conn %d:\n", count);
+               kiblnd_debug_conn(conn);
+               count++;
+       }
+}
+
+
 static int
-kiblnd_get_peer_info(struct lnet_ni *ni, int index,
+kiblnd_get_peer_info(struct lnet_ni *ni, lnet_nid_t nid, int index,
                     lnet_nid_t *nidp, int *count)
 {
        struct kib_peer_ni              *peer_ni;
@@ -436,13 +526,15 @@ kiblnd_get_peer_info(struct lnet_ni *ni, int index,
         for (i = 0; i < kiblnd_data.kib_peer_hash_size; i++) {
 
                list_for_each(ptmp, &kiblnd_data.kib_peers[i]) {
-
                        peer_ni = list_entry(ptmp, struct kib_peer_ni, ibp_list);
                        LASSERT(!kiblnd_peer_idle(peer_ni));
 
                        if (peer_ni->ibp_ni != ni)
                                continue;
 
+                       if (peer_ni->ibp_nid == nid)
+                               kiblnd_dump_peer_debug_info(peer_ni);
+
                        if (index-- > 0)
                                continue;
 
@@ -568,74 +660,6 @@ kiblnd_get_conn_by_idx(struct lnet_ni *ni, int index)
 }
 
 static void
-kiblnd_debug_rx(struct kib_rx *rx)
-{
-       CDEBUG(D_CONSOLE, "      %p msg_type %x cred %d\n",
-              rx, rx->rx_msg->ibm_type,
-              rx->rx_msg->ibm_credits);
-}
-
-static void
-kiblnd_debug_tx(struct kib_tx *tx)
-{
-       CDEBUG(D_CONSOLE, "      %p snd %d q %d w %d rc %d dl %lld "
-              "cookie %#llx msg %s%s type %x cred %d\n",
-               tx, tx->tx_sending, tx->tx_queued, tx->tx_waiting,
-              tx->tx_status, ktime_to_ns(tx->tx_deadline), tx->tx_cookie,
-               tx->tx_lntmsg[0] == NULL ? "-" : "!",
-               tx->tx_lntmsg[1] == NULL ? "-" : "!",
-               tx->tx_msg->ibm_type, tx->tx_msg->ibm_credits);
-}
-
-void
-kiblnd_debug_conn(struct kib_conn *conn)
-{
-       struct list_head        *tmp;
-       int                     i;
-
-       spin_lock(&conn->ibc_lock);
-
-       CDEBUG(D_CONSOLE, "conn[%d] %p [version %x] -> %s:\n",
-              atomic_read(&conn->ibc_refcount), conn,
-              conn->ibc_version, libcfs_nid2str(conn->ibc_peer->ibp_nid));
-       CDEBUG(D_CONSOLE, "   state %d nposted %d/%d cred %d o_cred %d "
-              " r_cred %d\n", conn->ibc_state, conn->ibc_noops_posted,
-              conn->ibc_nsends_posted, conn->ibc_credits,
-              conn->ibc_outstanding_credits, conn->ibc_reserved_credits);
-       CDEBUG(D_CONSOLE, "   comms_err %d\n", conn->ibc_comms_error);
-
-       CDEBUG(D_CONSOLE, "   early_rxs:\n");
-       list_for_each(tmp, &conn->ibc_early_rxs)
-               kiblnd_debug_rx(list_entry(tmp, struct kib_rx, rx_list));
-
-       CDEBUG(D_CONSOLE, "   tx_noops:\n");
-       list_for_each(tmp, &conn->ibc_tx_noops)
-               kiblnd_debug_tx(list_entry(tmp, struct kib_tx, tx_list));
-
-       CDEBUG(D_CONSOLE, "   tx_queue_nocred:\n");
-       list_for_each(tmp, &conn->ibc_tx_queue_nocred)
-               kiblnd_debug_tx(list_entry(tmp, struct kib_tx, tx_list));
-
-       CDEBUG(D_CONSOLE, "   tx_queue_rsrvd:\n");
-       list_for_each(tmp, &conn->ibc_tx_queue_rsrvd)
-               kiblnd_debug_tx(list_entry(tmp, struct kib_tx, tx_list));
-
-       CDEBUG(D_CONSOLE, "   tx_queue:\n");
-       list_for_each(tmp, &conn->ibc_tx_queue)
-               kiblnd_debug_tx(list_entry(tmp, struct kib_tx, tx_list));
-
-       CDEBUG(D_CONSOLE, "   active_txs:\n");
-       list_for_each(tmp, &conn->ibc_active_txs)
-               kiblnd_debug_tx(list_entry(tmp, struct kib_tx, tx_list));
-
-       CDEBUG(D_CONSOLE, "   rxs:\n");
-       for (i = 0; i < IBLND_RX_MSGS(conn); i++)
-               kiblnd_debug_rx(&conn->ibc_rxs[i]);
-
-       spin_unlock(&conn->ibc_lock);
-}
-
-static void
 kiblnd_setup_mtu_locked(struct rdma_cm_id *cmid)
 {
         /* XXX There is no path record for iWARP, set by netdev->change_mtu? */
@@ -1155,7 +1179,7 @@ kiblnd_ctl(struct lnet_ni *ni, unsigned int cmd, void *arg)
                 lnet_nid_t   nid = 0;
                 int          count = 0;
 
-                rc = kiblnd_get_peer_info(ni, data->ioc_count,
+               rc = kiblnd_get_peer_info(ni, data->ioc_nid, data->ioc_count,
                                           &nid, &count);
                 data->ioc_nid    = nid;
                 data->ioc_count  = count;

diff --git a/lnet/klnds/socklnd/socklnd.c b/lnet/klnds/socklnd/socklnd.c
index 61c46ac..9097245 100644 (file)
--- a/lnet/klnds/socklnd/socklnd.c
+++ b/lnet/klnds/socklnd/socklnd.c
@@ -281,6 +281,52 @@ ksocknal_unlink_peer_locked(struct ksock_peer_ni *peer_ni)
        ksocknal_peer_decref(peer_ni);
 }
 
+
+static void
+ksocknal_dump_peer_debug_info(struct ksock_peer_ni *peer_ni)
+{
+       struct ksock_conn *conn;
+       struct list_head *ctmp;
+       struct list_head *txtmp;
+       int ccount = 0;
+       int txcount = 0;
+
+       list_for_each(ctmp, &peer_ni->ksnp_conns) {
+               conn = list_entry(ctmp, struct ksock_conn, ksnc_list);
+
+               if (!list_empty(&conn->ksnc_tx_queue))
+                       list_for_each(txtmp, &conn->ksnc_tx_queue) txcount++;
+
+               CDEBUG(D_CONSOLE, "Conn %d [type, closing, crefcnt, srefcnt]: %d, %d, %d, %d\n",
+                      ccount,
+                      conn->ksnc_type,
+                      conn->ksnc_closing,
+                      refcount_read(&conn->ksnc_conn_refcount),
+                      refcount_read(&conn->ksnc_sock_refcount));
+               CDEBUG(D_CONSOLE, "Conn %d rx [scheduled, ready, state]: %d, %d, %d\n",
+                      ccount,
+                      conn->ksnc_rx_scheduled,
+                      conn->ksnc_rx_ready,
+                      conn->ksnc_rx_state);
+               CDEBUG(D_CONSOLE, "Conn %d tx [txqcnt, scheduled, last_post, ready, deadline]: %d, %d, %lld, %d, %lld\n",
+                      ccount,
+                      txcount,
+                      conn->ksnc_tx_scheduled,
+                      conn->ksnc_tx_last_post,
+                      conn->ksnc_rx_ready,
+                      conn->ksnc_rx_deadline);
+
+               if (conn->ksnc_scheduler)
+                       CDEBUG(D_CONSOLE, "Conn %d sched [nconns, cpt]: %d, %d\n",
+                              ccount,
+                              conn->ksnc_scheduler->kss_nconns,
+                              conn->ksnc_scheduler->kss_cpt);
+
+               txcount = 0;
+               ccount++;
+       }
+}
+
 static int
 ksocknal_get_peer_info(struct lnet_ni *ni, int index,
                       struct lnet_process_id *id, __u32 *myip, __u32 *peer_ip,
@@ -332,6 +378,7 @@ ksocknal_get_peer_info(struct lnet_ni *ni, int index,
                        if (index-- > 0)
                                continue;
 
+                       ksocknal_dump_peer_debug_info(peer_ni);
                        conn_cb = peer_ni->ksnp_conn_cb;
 
                        *id = peer_ni->ksnp_id;

diff --git a/lnet/utils/lnetconfig/liblnetconfig.c b/lnet/utils/lnetconfig/liblnetconfig.c
index d08bcd2..4ba97d4 100644 (file)
--- a/lnet/utils/lnetconfig/liblnetconfig.c
+++ b/lnet/utils/lnetconfig/liblnetconfig.c
@@ -3747,6 +3747,43 @@ out:
        return rc;
 }
 
+int lustre_lnet_show_peer_debug_info(char *peer_nid, int seq_no,
+                                    struct cYAML **err_rc)
+{
+       struct libcfs_ioctl_data data;
+       int rc;
+       char err_str[LNET_MAX_STR_LEN] = "Error";
+       lnet_nid_t pnid = LNET_NID_ANY;
+
+       if (!peer_nid) {
+               rc = LUSTRE_CFG_RC_BAD_PARAM;
+               snprintf(err_str, LNET_MAX_STR_LEN,
+                        "--nid must be specified");
+               goto out;
+       }
+
+       pnid = libcfs_str2nid(peer_nid);
+       if (pnid == LNET_NID_ANY) {
+               rc = LUSTRE_CFG_RC_BAD_PARAM;
+               snprintf(err_str, LNET_MAX_STR_LEN,
+                       "badly formatted primary NID: %s", peer_nid);
+               goto out;
+       }
+
+       LIBCFS_IOC_INIT(data);
+       data.ioc_net = LNET_NIDNET(pnid);
+       data.ioc_nid = pnid;
+
+       rc = l_ioctl(LNET_DEV_ID, IOC_LIBCFS_GET_PEER, &data);
+
+out:
+       if (rc != 0)
+               cYAML_build_error(rc, seq_no, "debug", "peer", err_str,
+                                 err_rc);
+
+       return rc;
+}
+
 int lustre_lnet_show_local_ni_recovq(int seq_no, struct cYAML **show_rc,
                                     struct cYAML **err_rc)
 {

diff --git a/lnet/utils/lnetconfig/liblnetconfig.h b/lnet/utils/lnetconfig/liblnetconfig.h
index 84938f1..055b4d3 100644 (file)
--- a/lnet/utils/lnetconfig/liblnetconfig.h
+++ b/lnet/utils/lnetconfig/liblnetconfig.h
@@ -736,4 +736,13 @@ int lustre_lnet_parse_interfaces(char *intf_str,
 int lustre_lnet_parse_nidstr(char *nidstr, lnet_nid_t *lnet_nidlist,
                             int max_nids, char *err_str);
 
+/* lustre_lnet_show_peer_debug_info
+ *     dump peer debug info
+ *     peer_nid - nid of the peer to show
+ *     seq_no - sequence number of the request
+ *     err_rc - [OUT] struct cYAML tree describing the error. Freed by
+ *     caller
+ */
+int lustre_lnet_show_peer_debug_info(char *peer_nid, int seq_no,
+                                    struct cYAML **err_rc);
 #endif /* LIB_LNET_CONFIG_API_H */

diff --git a/lnet/utils/lnetctl.c b/lnet/utils/lnetctl.c
index 3afdb36..906d6e0 100644 (file)
--- a/lnet/utils/lnetctl.c
+++ b/lnet/utils/lnetctl.c
@@ -87,6 +87,7 @@ static int jt_set_response_tracking(int argc, char **argv);
 static int jt_set_recovery_limit(int argc, char **argv);
 static int jt_setup_mrrouting(int argc, char **argv);
 static int jt_calc_cpt_of_nid(int argc, char **argv);
+static int jt_show_peer_debug_info(int argc, char **argv);
 
 command_t cmd_list[] = {
        {"lnet", jt_lnet, 0, "lnet {configure | unconfigure} [--all]"},
@@ -102,7 +103,7 @@ command_t cmd_list[] = {
        {"import", jt_import, 0, "import FILE.yaml"},
        {"export", jt_export, 0, "export FILE.yaml"},
        {"stats", jt_stats, 0, "stats {show | help}"},
-       {"debug", jt_debug, 0, "debug recovery {local | peer}"},
+       {"debug", jt_debug, 0, "debug {recovery {local | peer} | peer}"},
        {"global", jt_global, 0, "global {show | help}"},
        {"peer", jt_peers, 0, "peer {add | del | show | list | set | help}"},
        {"ping", jt_ping, 0, "ping nid,[nid,...]"},
@@ -188,6 +189,8 @@ command_t debug_cmds[] = {
        {"recovery", jt_show_recovery, 0, "list recovery queues\n"
                "\t--local : list local recovery queue\n"
                "\t--peer : list peer recovery queue\n"},
+       {"peer", jt_show_peer_debug_info, 0, "show peer debug info\n"
+               "\t--nid: peer's NID\n"},
        { 0, 0, 0, NULL }
 };
 
@@ -1410,14 +1413,13 @@ static int jt_show_recovery(int argc, char **argv)
 {
        int rc, opt;
        struct cYAML *err_rc = NULL, *show_rc = NULL;
-
        const char *const short_options = "lp";
        static const struct option long_options[] = {
                { .name = "local", .has_arg = no_argument, .val = 'l' },
                { .name = "peer", .has_arg = no_argument, .val = 'p' },
                { .name = NULL } };
 
-       rc = check_cmd(debug_cmds, "recovery", NULL, 0, argc, argv);
+       rc = check_cmd(debug_cmds, "debug", "recovery", 0, argc, argv);
        if (rc)
                return rc;
 
@@ -1446,6 +1448,42 @@ static int jt_show_recovery(int argc, char **argv)
        return rc;
 }
 
+static int jt_show_peer_debug_info(int argc, char **argv)
+{
+       int rc, opt;
+       struct cYAML *err_rc = NULL;
+       char *peer_nid = optarg;
+       const char *const short_opts = "k";
+       const struct option long_opts[] = {
+       { .name = "nid", .has_arg = required_argument, .val = 'k' },
+       { .name = NULL } };
+
+       rc = check_cmd(debug_cmds, "debug", "peer", 0, argc, argv);
+
+       if (rc)
+               return rc;
+
+       while ((opt = getopt_long(argc, argv, short_opts,
+                                  long_opts, NULL)) != -1) {
+               switch (opt) {
+               case 'k':
+                       peer_nid = optarg;
+                       break;
+               default:
+                       return 0;
+               }
+       }
+
+       rc = lustre_lnet_show_peer_debug_info(peer_nid, -1, &err_rc);
+
+       if (rc != LUSTRE_CFG_RC_NO_ERR)
+               cYAML_print_tree2file(stderr, err_rc);
+
+       cYAML_free_tree(err_rc);
+
+       return rc;
+}
+
 static int jt_show_net(int argc, char **argv)
 {
        char *network = NULL;
@@ -1693,7 +1731,7 @@ static int jt_debug(int argc, char **argv)
 {
        int rc;
 
-       rc = check_cmd(debug_cmds, "recovery", NULL, 2, argc, argv);
+       rc = check_cmd(debug_cmds, "debug", NULL, 2, argc, argv);
        if (rc)
                return rc;
 

diff --git a/lustre/doc/lnetctl.8 b/lustre/doc/lnetctl.8
index 6e04865..204424f 100644 (file)
--- a/lustre/doc/lnetctl.8
+++ b/lustre/doc/lnetctl.8
@@ -322,7 +322,7 @@ of the \fBexport\fR command can be used as input to the \fBimport\fR command\.
 .SS "LNet Statistics"
 .
 .TP
-\fBlnetctl stats\fR
+\fBlnetctl stats\fR show
 Show LNET statistics
 .
 .br
@@ -385,6 +385,29 @@ Show details on configured peer credits
 .br
 \-> Minimum router credits\.
 .
+.SS "Debugging"
+.
+.TP
+\fBlnetctl debug\fR recovery
+List NIDs on recovery queue
+.
+.br
+\-\-local : list NIDs on local recovery queue
+.
+.br
+\-\-peer : list NIDs on peer recovery queue
+.
+.br
+.
+.TP
+\fBlnetctl debug\fR peer
+Dump peer debug info to debug log and console
+.
+.br
+\-\-nid : peer's NID
+.
+.br
+.
 .SH "OPTIONS"
 .TP
 .B --list-commands

diff --git a/lustre/tests/sanity-lnet.sh b/lustre/tests/sanity-lnet.sh
index 2b81112..0807942 100755 (executable)
--- a/lustre/tests/sanity-lnet.sh
+++ b/lustre/tests/sanity-lnet.sh
@@ -2153,6 +2153,21 @@ test_300() {
 }
 run_test 300 "packaged LNet UAPI headers can be compiled"
 
+test_302() {
+       ! [[ $NETTYPE =~ (tcp|o2ib) ]] && skip "Need tcp or o2ib NETTYPE"
+       reinit_dlc || return $?
+
+       add_net "${NETTYPE}" "${INTERFACES[0]}" || return $?
+
+       local nid=$($LCTL list_nids)
+
+       do_lnetctl ping ${nid} ||
+               error "pinging self failed $?"
+       do_lnetctl debug peer --nid ${nid} ||
+               error "failed to dump peer debug info $?"
+}
+run_test 302 "Check that peer debug info can be dumped"
+
 complete $SECONDS
 
 cleanup_testsuite