goto out;
}
- rdsdebug("allocated conn %p for %pI6c -> %pI6c over %s %s\n",
- conn, laddr, faddr,
- trans->t_name ? trans->t_name : "[unknown]",
- is_outgoing ? "(outgoing)" : "");
+ rds_rtd_ptr(RDS_RTD_CM_EXT,
+ "allocated conn %p for <%pI6c,%pI6c,%d> over %s %s\n",
+ conn, laddr, faddr, tos,
+ trans->t_name ? trans->t_name : "[unknown]",
+ is_outgoing ? "(outgoing)" : "");
/*
* Since we ran without holding the conn lock, someone could
/* shut it down unless it's down already */
if (!rds_conn_path_transition(cp, RDS_CONN_DOWN, RDS_CONN_DOWN)) {
rds_rtd_ptr(RDS_RTD_CM_EXT,
- "RDS/%s: shutdown init <%pI6c,%pI6c,%d>, cn %p, cn->c_p %p\n",
- conn->c_trans->t_type == RDS_TRANS_TCP ? "TCP" :
- "IB",
+ "RDS/%s: shutdown init conn %p conn->c_passive %p <%pI6c,%pI6c,%d>\n",
+ conn->c_trans->t_type == RDS_TRANS_TCP ? "TCP" : "IB",
+ conn, conn->c_passive,
&conn->c_laddr, &conn->c_faddr,
- conn->c_tos, conn, conn->c_passive);
+ conn->c_tos);
/*
* Quiesce the connection mgmt handlers before we start tearing
* things down. We don't hold the mutex for the entire
rcu_read_lock();
if (!hlist_unhashed(&conn->c_hash_node) && restart) {
rcu_read_unlock();
+ rds_rtd(RDS_RTD_CM,
+ "calling rds_queue_reconnect conn %p restart: %d\n",
+ cp->cp_conn, restart);
rds_queue_reconnect(cp);
} else {
rcu_read_unlock();
+ rds_rtd(RDS_RTD_CM,
+ "NOT calling rds_queue_reconnect conn %p restart: %d\n",
+ cp->cp_conn, restart);
}
}
atomic_set(&cp->cp_state, RDS_CONN_ERROR);
+ if (reason != DR_CONN_DESTROY && test_bit(RDS_DESTROY_PENDING, &cp->cp_flags)) {
+ rds_rtd_ptr(RDS_RTD_CM_EXT,
+ "RDS/%s: NOT queueing shutdown work, conn %p <%pI6c,%pI6c,%d>\n",
+ conn->c_trans->t_type == RDS_TRANS_TCP ? "TCP" : "IB",
+ conn, &conn->c_laddr, &conn->c_faddr,
+ conn->c_tos);
+ return;
+ }
+
rds_rtd_ptr(RDS_RTD_CM_EXT,
- "RDS/%s: queueing shutdown work, conn %p, <%pI6c,%pI6c,%d>\n",
+ "RDS/%s: queueing shutdown work, conn %p <%pI6c,%pI6c,%d>\n",
conn->c_trans->t_type == RDS_TRANS_TCP ? "TCP" : "IB",
conn, &conn->c_laddr, &conn->c_faddr,
conn->c_tos);
- if (reason != DR_CONN_DESTROY && test_bit(RDS_DESTROY_PENDING,
- &cp->cp_flags))
- return;
-
queue_work(cp->cp_wq, &cp->cp_down_w);
}
EXPORT_SYMBOL_GPL(rds_conn_path_drop);
break;
default:
rds_rtd_ptr(RDS_RTD_ERR,
- "Fatal QP Event %u (%s) - connection %pI6c->%pI6c tos %d, reconnecting\n",
+ "Fatal QP Event %u (%s) - conn %p <%pI6c,%pI6c,%d>, reconnecting\n",
event->event, rds_ib_event_str(event->event),
- &conn->c_laddr, &conn->c_faddr, conn->c_tos);
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos);
rds_conn_drop(conn, DR_IB_QP_EVENT);
break;
}
}
rds_rtd_ptr(RDS_RTD_CM,
- "saddr %pI6c daddr %pI6c RDSv%u.%u lguid 0x%llx fguid 0x%llx tos %d\n",
- saddr6, daddr6,
+ "<%pI6c,%pI6c,%d> RDSv%u.%u lguid 0x%llx fguid 0x%llx\n",
+ saddr6, daddr6, dp_cmn->ricpc_tos,
RDS_PROTOCOL_MAJOR(version),
RDS_PROTOCOL_MINOR(version),
(unsigned long long)be64_to_cpu(lguid),
- (unsigned long long)be64_to_cpu(fguid),
- dp_cmn->ricpc_tos);
+ (unsigned long long)be64_to_cpu(fguid));
acl_ret = rds_ib_match_acl(cm_id, saddr6);
if (acl_ret < 0) {
if (conn->c_route && !rds_conn_self_loopback_passive(conn)) {
rds_rtd_ptr(RDS_RTD_CM,
- "no route resolution saddr %pI4 daddr %pI4 RDSv%u.%u lguid 0x%llx fguid 0x%llx tos %d\n",
- saddr6, daddr6,
+ "no route resolution cm_id %p conn %p <%pI6c,%pI6c,%d> RDSv%u.%u lguid 0x%llx fguid 0x%llx\n",
+ cm_id, conn,
+ saddr6, daddr6, dp_cmn->ricpc_tos,
RDS_PROTOCOL_MAJOR(version),
RDS_PROTOCOL_MINOR(version),
(unsigned long long)be64_to_cpu(lguid),
- (unsigned long long)be64_to_cpu(fguid),
- dp_cmn->ricpc_tos);
+ (unsigned long long)be64_to_cpu(fguid));
goto out;
}
destroy = 0;
if (rds_conn_state(conn) == RDS_CONN_UP) {
rds_rtd(RDS_RTD_CM_EXT_P,
- "incoming connect while connecting\n");
+ "conn %p <%pI6c,%pI6c,%d> incoming connect in UP state\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos);
rds_conn_drop(conn, DR_IB_REQ_WHILE_CONN_UP);
rds_ib_stats_inc(s_ib_listen_closed_stale);
} else if (rds_conn_state(conn) == RDS_CONN_CONNECTING) {
*/
if (conn->c_reconnect_racing > 5) {
rds_rtd_ptr(RDS_RTD_CM,
- "RDS/IB: conn <%pI6c,%pI6c,%d> back-to-back REQ, reset\n",
- &conn->c_laddr, &conn->c_faddr,
- conn->c_tos);
+ "conn %p <%pI6c,%pI6c,%d> back-to-back REQ, reset\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos);
conn->c_reconnect_racing = 0;
rds_conn_drop(conn, DR_IB_REQ_WHILE_CONNECTING);
/* After 15 seconds, give up on existing connection
} else if (now > conn->c_connection_start &&
now - conn->c_connection_start > 15) {
rds_rtd_ptr(RDS_RTD_CM,
- "RDS/IB: connection <%pI6c,%pI6c,%d> racing for 15s, forcing reset",
- &conn->c_laddr,
- &conn->c_faddr,
- conn->c_tos);
+ "conn %p <%pI6c,%pI6c,%d> racing for 15s, forcing reset\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos);
rds_conn_drop(conn, DR_IB_REQ_WHILE_CONNECTING);
rds_ib_stats_inc(s_ib_listen_closed_stale);
} else {
/* Wait and see - our connect may still be succeeding */
+ rds_rtd_ptr(RDS_RTD_CM,
+ "conn %p <%pI6c,%pI6c,%d> racing, wait and see\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos);
rds_ib_stats_inc(s_ib_connect_raced);
}
}
ret = rds_ib_match_acl(ic->i_cm_id, &conn->c_faddr);
if (ret < 0) {
- pr_err("RDS: IB: active conn=%p, <%pI6c,%pI6c,%d> destroyed due ACL violation\n",
- conn, &conn->c_laddr, &conn->c_faddr,
- conn->c_tos);
+ pr_err("RDS: IB: active conn %p <%pI6c,%pI6c,%d> destroyed due ACL violation\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos);
+ rds_rtd_ptr(RDS_RTD_CM,
+ "active conn %p <%pI6c,%pI6c,%d> destroyed due ACL violation\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos);
rds_ib_conn_destroy_init(conn);
return 0;
}
*/
atomic_set(&ic->i_credits, IB_SET_POST_CREDITS(ic->i_flowctl));
- pr_debug("RDS/IB: Initiate conn <%pI6c, %pI6c,%d> with Frags <init,ic>: {%d,%d}\n",
- &conn->c_laddr, &conn->c_faddr, conn->c_tos,
- ib_init_frag_size / SZ_1K, ic->i_frag_sz / SZ_1K);
+ rds_rtd_ptr(RDS_RTD_CM,
+ "RDS/IB: Initiate conn %p <%pI6c,%pI6c,%d> with Frags <init,ic>: {%d,%d}\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos,
+ ib_init_frag_size / SZ_1K, ic->i_frag_sz / SZ_1K);
ret = rds_ib_setup_qp(conn);
if (ret) {
- pr_warn("RDS/IB: rds_ib_setup_qp failed (%d)\n", ret);
+ rds_rtd(RDS_RTD_CM, "RDS/IB: rds_ib_setup_qp failed (%d)\n", ret);
rds_conn_drop(conn, DR_IB_ACT_SETUP_QP_FAIL);
goto out;
}
frag, isv6, seq);
ret = rdma_connect(cm_id, &conn_param);
if (ret) {
- pr_warn("RDS/IB: rdma_connect failed (%d)\n", ret);
+ rds_rtd(RDS_RTD_CM, "RDS/IB: rdma_connect failed (%d)\n", ret);
rds_conn_drop(conn, DR_IB_RDMA_CONNECT_FAIL);
}
struct rds_ib_connection *ic = conn->c_transport_data;
int err = 0;
- rdsdebug("cm %p pd %p cq %p qp %p\n", ic->i_cm_id,
- ic->i_pd, ic->i_rcq, ic->i_cm_id ? ic->i_cm_id->qp : NULL);
+ rds_rtd_ptr(RDS_RTD_CM_EXT, "conn %p cm_id %p pd %p cq %p qp %p\n",
+ conn, ic->i_cm_id, ic->i_pd, ic->i_rcq, ic->i_cm_id ? ic->i_cm_id->qp : NULL);
if (ic->i_cm_id) {
struct ib_device *dev = ic->i_cm_id->device;
- rdsdebug("disconnecting cm %p\n", ic->i_cm_id);
+ rds_rtd_ptr(RDS_RTD_CM_EXT, "disconnecting conn %p cm_id %p\n", conn, ic->i_cm_id);
err = rdma_disconnect(ic->i_cm_id);
if (err) {
/* Actually this may happen quite frequently, when
int ret = 0;
int *err;
- rdsdebug("conn %p id %p handling event %u (%s)\n", conn, cm_id,
- event->event, rds_cm_event_str(event->event));
+ if (conn)
+ rds_rtd_ptr(RDS_RTD_CM,
+ "conn %p state %s cm_id %p <%pI6c,%pI6c,%d> handling event %u (%s) priv_dta_len %d\n",
+ conn, conn_state_mnem(rds_conn_state(conn)), cm_id,
+ &conn->c_laddr, &conn->c_faddr, conn->c_tos,
+ event->event, rds_cm_event_str(event->event),
+ event->param.conn.private_data_len);
+ else
+ rds_rtd(RDS_RTD_CM,
+ "conn %p cm_id %p handling event %u (%s) priv_dta_len %d\n",
+ conn, cm_id,
+ event->event, rds_cm_event_str(event->event),
+ event->param.conn.private_data_len);
+
if (cm_id->device->node_type == RDMA_NODE_IB_CA)
trans = &rds_ib_transport;
* down an existing one. */
if (event->event == RDMA_CM_EVENT_CONNECT_REQUEST)
ret = 1;
+ rds_rtd(RDS_RTD_CM, "Bailing, conn %p being shut down, ret: %d\n",
+ conn, ret);
goto out;
}
}
break;
case RDMA_CM_EVENT_ADDR_RESOLVED:
+ rds_rtd_ptr(RDS_RTD_CM,
+ "conn %p <%pI6c,%pI6c,%d> daddr resolved. dmac %pI6c\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos,
+ cm_id->route.addr.dev_addr.dst_dev_addr +
+ rdma_addr_gid_offset(&cm_id->route.addr.dev_addr));
rdma_set_service_type(cm_id, conn->c_tos);
/* XXX do we need to clean up if this fails? */
if (conn) {
struct rds_ib_connection *ibic;
- printk(KERN_CRIT "rds dropping connection after rdma_resolve_route failure connection %pI6c->%pI6c\n",
- &conn->c_laddr, &conn->c_faddr);
+ rds_rtd_ptr(RDS_RTD_CM,
+ "conn %p <%pI6c,%pI6c,%d> dropping connection after rdma_resolve_route failure %d\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos, ret);
ibic = conn->c_transport_data;
if (ibic && ibic->i_cm_id == cm_id)
ibic->i_cm_id = NULL;
* needs to update the sl manually. As for now, RDS is assuming
* that it is a 1:1 in tos to sl mapping.
*/
+ rds_rtd(RDS_RTD_CM, "ibic: %p cm_id: %p\n", ibic->i_cm_id->context, cm_id->context);
conn->c_route = 0;
cm_id->route.path_rec[0].sl = TOS_TO_SL(conn->c_tos);
cm_id->route.path_rec[0].qos_class = conn->c_tos;
+ rds_rtd_ptr(RDS_RTD_CM,
+ "conn %p <%pI6c,%pI6c,%d> initiate connect, smac %pI6c dmac %pI6c\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos,
+ cm_id->route.path_rec[0].sgid.raw,
+ cm_id->route.path_rec[0].dgid.raw);
ret = trans->cm_initiate_connect(cm_id, isv6);
} else {
rds_rtd_ptr(RDS_RTD_CM,
} else if (event->status == RDS_REJ_CONSUMER_DEFINED &&
(*err) == RDS_ACL_FAILURE) {
/* Rejection due to ACL violation */
- pr_err("RDS: IB: conn=%p, <%pI6c,%pI6c,%d> destroyed due to ACL violation\n",
- conn, &conn->c_laddr,
- &conn->c_faddr,
- conn->c_tos);
+ pr_err("RDS: IB: conn %p <%pI6c,%pI6c,%d> destroyed due to ACL violation\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos);
+
+ rds_rtd_ptr(RDS_RTD_CM,
+ "Rejected: active conn %p <%pI6c,%pI6c,%d> destroyed due to ACL violation\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos);
rds_ib_conn_destroy_init(conn);
} else {
rds_rtd_ptr(RDS_RTD_ERR,
&conn->c_faddr);
if (conn) {
rds_rtd_ptr(RDS_RTD_CM,
- "ADDR_CHANGE: calling rds_conn_drop <%pI6c,%pI6c,%d>\n",
- &conn->c_laddr, &conn->c_faddr,
- conn->c_tos);
+ "ADDR_CHANGE: calling rds_conn_drop conn %p <%pI6c,%pI6c,%d>\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos);
conn->c_reconnect_racing = 0;
/* reset route resolution flag */
conn->c_route = 1;
case RDMA_CM_EVENT_DISCONNECTED:
rds_rtd_ptr(RDS_RTD_CM,
- "DISCONNECT event - dropping connection %pI6c->%pI6c tos %d\n",
- &conn->c_laddr, &conn->c_faddr, conn->c_tos);
+ "DISCONNECT event - dropping conn %p <%pI6c,%pI6c,%d>\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos);
conn->c_reconnect_racing = 0;
/* reset route resolution flag */
conn->c_route = 1;
case RDMA_CM_EVENT_TIMEWAIT_EXIT:
if (conn) {
- printk(KERN_INFO "TIMEWAIT_EXIT event - dropping connection %pI6c->%pI6c\n",
- &conn->c_laddr, &conn->c_faddr);
+ rds_rtd_ptr(RDS_RTD_CM,
+ "TIMEWAIT_EXIT event - dropping conn %p <%pI6c,%pI6c,%d>\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos);
rds_conn_drop(conn, DR_IB_TIMEWAIT_EXIT);
} else
printk(KERN_INFO "TIMEWAIT_EXIT event - conn=NULL\n");
RDS_CONN_ERROR,
};
+static inline const char *conn_state_mnem(int state)
+{
+#define CASE_RET(s) case (s): return #s
+ switch (state) {
+ CASE_RET(RDS_CONN_DOWN);
+ CASE_RET(RDS_CONN_CONNECTING);
+ CASE_RET(RDS_CONN_DISCONNECTING);
+ CASE_RET(RDS_CONN_UP);
+ CASE_RET(RDS_CONN_RESETTING);
+ CASE_RET(RDS_CONN_ERROR);
+ default:
+ return "RDS_CONN_UNKNOWN";
+ }
+#undef CASE_RET
+}
+
/* Bits for c_flags */
#define RDS_LL_SEND_FULL 0
#define RDS_RECONNECT_PENDING 1
struct rds_connection *conn = cp->cp_conn;
if (!rds_conn_path_transition(cp, curr, RDS_CONN_UP)) {
- pr_warn("RDS: Cannot transition conn <%pI6c,%pI6c,%d> to state UP, current state is %d\n",
- &conn->c_laddr, &conn->c_faddr, conn->c_tos,
- atomic_read(&cp->cp_state));
+ rds_rtd_ptr(RDS_RTD_CM,
+ "conn %p <%pI6c,%pI6c,%d> cannot transition to state UP, current state is %s\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos,
+ conn_state_mnem(atomic_read(&cp->cp_state)));
rds_conn_path_drop(cp, DR_IB_NOT_CONNECTING_STATE);
return;
}
rds_rtd_ptr(RDS_RTD_CM_EXT,
- "conn %p for %pI6c to %pI6c tos %d complete\n",
+ "conn %p <%pI6c,%pI6c,%d> complete\n",
conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos);
cp->cp_reconnect_jiffies = 0;
bool is_tcp = conn->c_trans->t_type == RDS_TRANS_TCP;
rds_rtd_ptr(RDS_RTD_CM_EXT,
- "conn %p for %pI6c to %pI6c tos %d reconnect jiffies %lu\n",
- conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos,
+ "conn %p:%d <%pI6c,%pI6c,%d> reconnect jiffies %lu\n",
+ conn, !!conn->c_passive, &conn->c_laddr, &conn->c_faddr, conn->c_tos,
cp->cp_reconnect_jiffies);
/* let peer with smaller addr initiate reconnect, to avoid duels */
}
rds_rtd_ptr(RDS_RTD_CM_EXT,
- "delay %lu conn %p for %pI6c -> %pI6c tos %d\n",
+ "delay %lu conn %p <%pI6c,%pI6c,%d>\n",
cp->cp_reconnect_jiffies, conn, &conn->c_laddr,
&conn->c_faddr, conn->c_tos);
ret = conn->c_trans->conn_path_connect(cp);
rds_rtd_ptr(RDS_RTD_CM_EXT,
- "conn %p for %pI6c to %pI6c tos %d dispatched, ret %d\n",
+ "conn %p for <%pI6c,%pI6c,%d> dispatched, ret %d\n",
conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos,
ret);
}
} else {
rds_rtd(RDS_RTD_CM,
- "conn %p cannot trans from DOWN to CONNECTING state.\n",
- conn);
+ "conn %p cannot transition from allegedly DOWN(act %s) to CONNECTING state\n",
+ conn, conn_state_mnem(atomic_read(&cp->cp_state)));
}
}
if (!rds_conn_path_up(cp)) {
rds_rtd_ptr(RDS_RTD_CM,
- "conn <%pI6c,%pI6c,%d> not up, retry(%d)\n",
- &conn->c_laddr, &conn->c_faddr, conn->c_tos,
+ "conn %p <%pI6c,%pI6c,%d> not up, retry(%d)\n",
+ conn, &conn->c_laddr, &conn->c_faddr, conn->c_tos,
cp->cp_reconnect_retry_count);
cp->cp_reconnect_racing = 0;
rds_conn_path_drop(cp, DR_RECONNECT_TIMEOUT);