Version: 1
-Previous: 5a0a8096dbe2966f8bfb5ee3e495b1c8536b3ad8
+Previous: c24bb24d064408d17603cf4dcd569ea0a0aa8fb5
Head: c17b34344b1983b71aebeed9d5dd0d553e014b3b
Applied:
- ibacm-enhance-debug-logging: c17b34344b1983b71aebeed9d5dd0d553e014b3b
+ logging: c17b34344b1983b71aebeed9d5dd0d553e014b3b
Unapplied:
acm_snoop: a8dc60dcbdd2ab3da998585bc84770e6d59f0114
log_lid: a447930f64695cb689443978bf381f00a60eac03
+++ /dev/null
-Bottom: 30326a5093b7b177c8d7612eba401d4999793f71
-Top: 18456ee741149c35b5859c6627ad1b4824322404
-Author: Sean Hefty <sean.hefty@intel.com>
-Date: 2010-11-15 14:08:15 -0800
-
-ibacm: enhance debug logging
-
-Prefix all log messages with time stamp information. This
-provides useful debugging information regarding the timing of
-various operations. Also provide some additional information
-to log messages, so that different operations can be matched
-to each other.
-
-Signed-off-by: Sean Hefty <sean.hefty@intel.com>
-
----
-
-diff --git a/src/acm.c b/src/acm.c
-index 820365c..27a6a25 100644
---- a/src/acm.c
-+++ b/src/acm.c
-@@ -37,6 +37,7 @@
- #include <osd.h>
- #include <arpa/inet.h>
- #include <sys/stat.h>
-+#include <sys/time.h>
- #include <infiniband/acm.h>
- #include <infiniband/umad.h>
- #include <infiniband/verbs.h>
-@@ -216,12 +217,15 @@ static uint8_t min_rate = IBV_RATE_10_GBPS;
- static void acm_write(int level, const char *format, ...)
- {
- va_list args;
-+ struct timeval tv;
-
- if (level > log_level)
- return;
-
-+ gettimeofday(&tv, NULL);
- va_start(args, format);
- lock_acquire(&log_lock);
-+ fprintf(flog, "%u.%03u: ", (unsigned) tv.tv_sec, (unsigned) (tv.tv_usec / 1000));
- vfprintf(flog, format, args);
- fflush(flog);
- lock_release(&log_lock);
-@@ -232,11 +236,14 @@ static void acm_log_addr(int level, const char *msg, uint16_t addr_type, uint8_t
- {
- struct ibv_path_record *path;
- char ip_addr[ACM_MAX_ADDRESS];
-+ struct timeval tv;
-
- if (level > log_level)
- return;
-
-+ gettimeofday(&tv, NULL);
- lock_acquire(&log_lock);
-+ fprintf(flog, "%u.%03u: ", (unsigned) tv.tv_sec, (unsigned) (tv.tv_usec / 1000));
- fprintf(flog, msg);
- switch (addr_type) {
- case ACM_EP_INFO_NAME:
-@@ -289,7 +296,7 @@ acm_alloc_dest(uint8_t addr_type, uint8_t *addr)
- }
-
- acm_init_dest(dest, addr_type, addr, ACM_MAX_ADDRESS);
-- acm_log(1, "%p\n", dest);
-+ acm_log_addr(1, "acm_alloc_dest: ", addr_type, addr);
- return dest;
- }
-
-@@ -303,17 +310,18 @@ acm_get_dest(struct acm_ep *ep, uint8_t addr_type, uint8_t *addr)
- if (tdest) {
- dest = *tdest;
- (void) atomic_inc(&dest->refcnt);
-+ acm_log_addr(2, "acm_get_dest: ", dest->addr_type, dest->address);
- } else {
- dest = NULL;
-+ acm_log_addr(2, "acm_get_dest: not found ", addr_type, addr);
- }
-- acm_log(2, "%p\n", dest);
- return dest;
- }
-
- static void
- acm_put_dest(struct acm_dest *dest)
- {
-- acm_log(2, "%p\n", dest);
-+ acm_log_addr(2, "acm_put_dest: ", dest->addr_type, dest->address);
- if (atomic_dec(&dest->refcnt) == 0) {
- free(dest);
- }
-@@ -361,7 +369,7 @@ acm_alloc_req(struct acm_client *client, struct acm_resolve_msg *msg)
- (void) atomic_inc(&client->refcnt);
- req->client = client;
- memcpy(&req->msg, msg, sizeof(req->msg));
-- acm_log(2, "%p\n", req);
-+ acm_log(2, "client %d, req %p\n", client->index, req);
- return req;
- }
-
-@@ -736,7 +744,7 @@ static uint8_t acm_resolve_path(struct acm_ep *ep, struct acm_dest *dest,
- struct acm_send_msg *msg;
- struct ib_sa_mad *mad;
-
-- acm_log(2, "\n");
-+ acm_log_addr(2, "acm_resolve_path: ", dest->addr_type, dest->address);
- msg = acm_alloc_send(ep, &ep->port->sa_dest, sizeof(*mad));
- if (!msg) {
- acm_log(0, "ERROR - cannot allocate send msg\n");
-@@ -764,7 +772,7 @@ acm_record_acm_addr(struct acm_ep *ep, struct acm_dest *dest, struct ibv_wc *wc,
- {
- int index;
-
-- acm_log(2, "\n");
-+ acm_log_addr(2, "acm_record_acm_addr: ", dest->addr_type, dest->address);
- index = acm_best_mc_index(ep, rec);
- if (index < 0) {
- acm_log(0, "ERROR - no shared multicast groups\n");
-@@ -814,7 +822,7 @@ acm_send_addr_resp(struct acm_ep *ep, struct acm_dest *dest)
- struct acm_send_msg *msg;
- struct acm_mad *mad;
-
-- acm_log(2, "\n");
-+ acm_log_addr(2, "acm_send_addr_resp: ", dest->addr_type, dest->address);
- msg = acm_alloc_send(ep, dest, sizeof (*mad));
- if (!msg) {
- acm_log(0, "ERROR - failed to allocate message\n");
-@@ -845,7 +853,7 @@ acm_client_resolve_resp(struct acm_client *client, struct acm_resolve_msg *req_m
- struct acm_resolve_msg *resp_msg = (struct acm_resolve_msg *) &msg;
- int ret;
-
-- acm_log(1, "status 0x%x\n", status);
-+ acm_log(1, "client %d, status 0x%x\n", client->index, status);
- memset(&msg, 0, sizeof msg);
-
- lock_acquire(&client->lock);
-@@ -900,7 +908,7 @@ acm_complete_queued_req(struct acm_dest *dest, uint8_t status)
- req = container_of(entry, struct acm_request, entry);
- lock_release(&dest->lock);
-
-- acm_log(2, "completing client request\n");
-+ acm_log(2, "completing request, client %d\n", req->client->index);
- acm_client_resolve_resp(req->client,
- (struct acm_resolve_msg *) &req->msg, dest, status);
- acm_free_req(req);
-@@ -923,9 +931,11 @@ acm_dest_sa_resp(struct acm_send_msg *msg, struct ibv_wc *wc, struct acm_mad *ma
- status = ACM_STATUS_ETIMEDOUT;
- }
- acm_log(2, "resp status 0x%x\n", status);
-+ acm_log_addr(2, "acm_dest_sa_resp: ", dest->addr_type, dest->address);
-
- lock_acquire(&dest->lock);
- if (dest->state != ACM_QUERY_ROUTE) {
-+ acm_log(2, "discarding SA response\n");
- lock_release(&dest->lock);
- return;
- }
-@@ -992,11 +1002,13 @@ acm_process_addr_req(struct acm_ep *ep, struct ibv_wc *wc, struct acm_mad *mad)
- dest->req_id = mad->tid;
-
- lock_acquire(&dest->lock);
-+ acm_log(2, "dest state %d\n", dest->state);
- switch (dest->state) {
- case ACM_READY:
- if (dest->remote_qpn == wc->src_qp)
- break;
-
-+ acm_log(2, "src service has new qp, resetting\n");
- ibv_destroy_ah(dest->ah); // TODO: ah could be in use
- /* fall through */
- case ACM_INIT:
-@@ -1078,6 +1090,7 @@ put:
- static void acm_process_acm_recv(struct acm_ep *ep, struct ibv_wc *wc, struct acm_mad *mad)
- {
- struct acm_send_msg *req;
-+ struct acm_resolve_rec *rec;
- int free;
-
- acm_log(2, "\n");
-@@ -1092,6 +1105,9 @@ static void acm_process_acm_recv(struct acm_ep *ep, struct ibv_wc *wc, struct ac
- return;
- }
-
-+ rec = (struct acm_resolve_rec *) mad->data;
-+ acm_log_addr(2, "acm_process_acm_recv: src ", rec->src_type, rec->src);
-+ acm_log_addr(2, "acm_process_acm_recv: dest ", rec->dest_type, rec->dest);
- if (mad->method & IB_METHOD_RESP) {
- acm_log(2, "received response\n");
- req = acm_get_request(ep, mad->tid, &free);
-@@ -1187,7 +1203,7 @@ static void acm_process_recv(struct acm_ep *ep, struct ibv_wc *wc)
- {
- struct acm_mad *mad;
-
-- acm_log(2, "\n");
-+ acm_log_addr(2, "acm_process_recv: ep ", ep->addr_type[0], ep->addr[0].addr);
- mad = (struct acm_mad *) (uintptr_t) (wc->wr_id + sizeof(struct ibv_grh));
- switch (mad->mgmt_class) {
- case IB_MGMT_CLASS_SA:
-@@ -1635,7 +1651,7 @@ static void acm_svr_accept(void)
-
- client[i].sock = s;
- atomic_set(&client[i].refcnt, 1);
-- acm_log(2, "assigned client id %d\n", i);
-+ acm_log(2, "assigned client %d\n", i);
- }
-
- static uint8_t acm_svr_query_sa(struct acm_ep *ep, struct acm_request *req)
-@@ -1711,7 +1727,7 @@ acm_svr_query(struct acm_client *client, struct acm_resolve_msg *msg)
- struct acm_ep *ep;
- uint8_t status;
-
-- acm_log(2, "processing client query\n");
-+ acm_log(2, "client %d\n", client->index);
- if (msg->hdr.length != ACM_MSG_HDR_LENGTH + ACM_MSG_EP_LENGTH) {
- acm_log(0, "ERROR - invalid length: 0x%x\n", msg->hdr.length);
- status = ACM_STATUS_EINVAL;
-@@ -1916,7 +1932,7 @@ acm_svr_queue_req(struct acm_dest *dest, struct acm_client *client,
- {
- struct acm_request *req;
-
-- acm_log(2, "\n");
-+ acm_log(2, "client %d\n", client->index);
- req = acm_alloc_req(client, msg);
- if (!req) {
- return ACM_STATUS_ENOMEM;
-@@ -1935,6 +1951,7 @@ acm_svr_resolve(struct acm_client *client, struct acm_resolve_msg *msg)
- uint8_t status;
- int ret;
-
-+ acm_log(2, "client %d\n", client->index);
- status = acm_svr_verify_resolve(msg, &saddr, &daddr);
- if (status) {
- acm_log(0, "misformatted or unsupported request\n");
-@@ -2006,7 +2023,7 @@ static void acm_svr_receive(struct acm_client *client)
- struct acm_resolve_msg *resolve_msg = (struct acm_resolve_msg *) &msg;
- int ret;
-
-- acm_log(2, "\n");
-+ acm_log(2, "client %d\n", client->index);
- ret = recv(client->sock, (char *) &msg, sizeof msg, 0);
- if (ret <= 0 || ret != msg.hdr.length) {
- acm_log(2, "client disconnected\n");
--- /dev/null
+Bottom: 30326a5093b7b177c8d7612eba401d4999793f71
+Top: 18456ee741149c35b5859c6627ad1b4824322404
+Author: Sean Hefty <sean.hefty@intel.com>
+Date: 2010-11-15 14:08:15 -0800
+
+ibacm: enhance debug logging
+
+Prefix all log messages with time stamp information. This
+provides useful debugging information regarding the timing of
+various operations. Also provide some additional information
+to log messages, so that different operations can be matched
+to each other.
+
+Signed-off-by: Sean Hefty <sean.hefty@intel.com>
+
+---
+
+diff --git a/src/acm.c b/src/acm.c
+index 820365c..27a6a25 100644
+--- a/src/acm.c
++++ b/src/acm.c
+@@ -37,6 +37,7 @@
+ #include <osd.h>
+ #include <arpa/inet.h>
+ #include <sys/stat.h>
++#include <sys/time.h>
+ #include <infiniband/acm.h>
+ #include <infiniband/umad.h>
+ #include <infiniband/verbs.h>
+@@ -216,12 +217,15 @@ static uint8_t min_rate = IBV_RATE_10_GBPS;
+ static void acm_write(int level, const char *format, ...)
+ {
+ va_list args;
++ struct timeval tv;
+
+ if (level > log_level)
+ return;
+
++ gettimeofday(&tv, NULL);
+ va_start(args, format);
+ lock_acquire(&log_lock);
++ fprintf(flog, "%u.%03u: ", (unsigned) tv.tv_sec, (unsigned) (tv.tv_usec / 1000));
+ vfprintf(flog, format, args);
+ fflush(flog);
+ lock_release(&log_lock);
+@@ -232,11 +236,14 @@ static void acm_log_addr(int level, const char *msg, uint16_t addr_type, uint8_t
+ {
+ struct ibv_path_record *path;
+ char ip_addr[ACM_MAX_ADDRESS];
++ struct timeval tv;
+
+ if (level > log_level)
+ return;
+
++ gettimeofday(&tv, NULL);
+ lock_acquire(&log_lock);
++ fprintf(flog, "%u.%03u: ", (unsigned) tv.tv_sec, (unsigned) (tv.tv_usec / 1000));
+ fprintf(flog, msg);
+ switch (addr_type) {
+ case ACM_EP_INFO_NAME:
+@@ -289,7 +296,7 @@ acm_alloc_dest(uint8_t addr_type, uint8_t *addr)
+ }
+
+ acm_init_dest(dest, addr_type, addr, ACM_MAX_ADDRESS);
+- acm_log(1, "%p\n", dest);
++ acm_log_addr(1, "acm_alloc_dest: ", addr_type, addr);
+ return dest;
+ }
+
+@@ -303,17 +310,18 @@ acm_get_dest(struct acm_ep *ep, uint8_t addr_type, uint8_t *addr)
+ if (tdest) {
+ dest = *tdest;
+ (void) atomic_inc(&dest->refcnt);
++ acm_log_addr(2, "acm_get_dest: ", dest->addr_type, dest->address);
+ } else {
+ dest = NULL;
++ acm_log_addr(2, "acm_get_dest: not found ", addr_type, addr);
+ }
+- acm_log(2, "%p\n", dest);
+ return dest;
+ }
+
+ static void
+ acm_put_dest(struct acm_dest *dest)
+ {
+- acm_log(2, "%p\n", dest);
++ acm_log_addr(2, "acm_put_dest: ", dest->addr_type, dest->address);
+ if (atomic_dec(&dest->refcnt) == 0) {
+ free(dest);
+ }
+@@ -361,7 +369,7 @@ acm_alloc_req(struct acm_client *client, struct acm_resolve_msg *msg)
+ (void) atomic_inc(&client->refcnt);
+ req->client = client;
+ memcpy(&req->msg, msg, sizeof(req->msg));
+- acm_log(2, "%p\n", req);
++ acm_log(2, "client %d, req %p\n", client->index, req);
+ return req;
+ }
+
+@@ -736,7 +744,7 @@ static uint8_t acm_resolve_path(struct acm_ep *ep, struct acm_dest *dest,
+ struct acm_send_msg *msg;
+ struct ib_sa_mad *mad;
+
+- acm_log(2, "\n");
++ acm_log_addr(2, "acm_resolve_path: ", dest->addr_type, dest->address);
+ msg = acm_alloc_send(ep, &ep->port->sa_dest, sizeof(*mad));
+ if (!msg) {
+ acm_log(0, "ERROR - cannot allocate send msg\n");
+@@ -764,7 +772,7 @@ acm_record_acm_addr(struct acm_ep *ep, struct acm_dest *dest, struct ibv_wc *wc,
+ {
+ int index;
+
+- acm_log(2, "\n");
++ acm_log_addr(2, "acm_record_acm_addr: ", dest->addr_type, dest->address);
+ index = acm_best_mc_index(ep, rec);
+ if (index < 0) {
+ acm_log(0, "ERROR - no shared multicast groups\n");
+@@ -814,7 +822,7 @@ acm_send_addr_resp(struct acm_ep *ep, struct acm_dest *dest)
+ struct acm_send_msg *msg;
+ struct acm_mad *mad;
+
+- acm_log(2, "\n");
++ acm_log_addr(2, "acm_send_addr_resp: ", dest->addr_type, dest->address);
+ msg = acm_alloc_send(ep, dest, sizeof (*mad));
+ if (!msg) {
+ acm_log(0, "ERROR - failed to allocate message\n");
+@@ -845,7 +853,7 @@ acm_client_resolve_resp(struct acm_client *client, struct acm_resolve_msg *req_m
+ struct acm_resolve_msg *resp_msg = (struct acm_resolve_msg *) &msg;
+ int ret;
+
+- acm_log(1, "status 0x%x\n", status);
++ acm_log(1, "client %d, status 0x%x\n", client->index, status);
+ memset(&msg, 0, sizeof msg);
+
+ lock_acquire(&client->lock);
+@@ -900,7 +908,7 @@ acm_complete_queued_req(struct acm_dest *dest, uint8_t status)
+ req = container_of(entry, struct acm_request, entry);
+ lock_release(&dest->lock);
+
+- acm_log(2, "completing client request\n");
++ acm_log(2, "completing request, client %d\n", req->client->index);
+ acm_client_resolve_resp(req->client,
+ (struct acm_resolve_msg *) &req->msg, dest, status);
+ acm_free_req(req);
+@@ -923,9 +931,11 @@ acm_dest_sa_resp(struct acm_send_msg *msg, struct ibv_wc *wc, struct acm_mad *ma
+ status = ACM_STATUS_ETIMEDOUT;
+ }
+ acm_log(2, "resp status 0x%x\n", status);
++ acm_log_addr(2, "acm_dest_sa_resp: ", dest->addr_type, dest->address);
+
+ lock_acquire(&dest->lock);
+ if (dest->state != ACM_QUERY_ROUTE) {
++ acm_log(2, "discarding SA response\n");
+ lock_release(&dest->lock);
+ return;
+ }
+@@ -992,11 +1002,13 @@ acm_process_addr_req(struct acm_ep *ep, struct ibv_wc *wc, struct acm_mad *mad)
+ dest->req_id = mad->tid;
+
+ lock_acquire(&dest->lock);
++ acm_log(2, "dest state %d\n", dest->state);
+ switch (dest->state) {
+ case ACM_READY:
+ if (dest->remote_qpn == wc->src_qp)
+ break;
+
++ acm_log(2, "src service has new qp, resetting\n");
+ ibv_destroy_ah(dest->ah); // TODO: ah could be in use
+ /* fall through */
+ case ACM_INIT:
+@@ -1078,6 +1090,7 @@ put:
+ static void acm_process_acm_recv(struct acm_ep *ep, struct ibv_wc *wc, struct acm_mad *mad)
+ {
+ struct acm_send_msg *req;
++ struct acm_resolve_rec *rec;
+ int free;
+
+ acm_log(2, "\n");
+@@ -1092,6 +1105,9 @@ static void acm_process_acm_recv(struct acm_ep *ep, struct ibv_wc *wc, struct ac
+ return;
+ }
+
++ rec = (struct acm_resolve_rec *) mad->data;
++ acm_log_addr(2, "acm_process_acm_recv: src ", rec->src_type, rec->src);
++ acm_log_addr(2, "acm_process_acm_recv: dest ", rec->dest_type, rec->dest);
+ if (mad->method & IB_METHOD_RESP) {
+ acm_log(2, "received response\n");
+ req = acm_get_request(ep, mad->tid, &free);
+@@ -1187,7 +1203,7 @@ static void acm_process_recv(struct acm_ep *ep, struct ibv_wc *wc)
+ {
+ struct acm_mad *mad;
+
+- acm_log(2, "\n");
++ acm_log_addr(2, "acm_process_recv: ep ", ep->addr_type[0], ep->addr[0].addr);
+ mad = (struct acm_mad *) (uintptr_t) (wc->wr_id + sizeof(struct ibv_grh));
+ switch (mad->mgmt_class) {
+ case IB_MGMT_CLASS_SA:
+@@ -1635,7 +1651,7 @@ static void acm_svr_accept(void)
+
+ client[i].sock = s;
+ atomic_set(&client[i].refcnt, 1);
+- acm_log(2, "assigned client id %d\n", i);
++ acm_log(2, "assigned client %d\n", i);
+ }
+
+ static uint8_t acm_svr_query_sa(struct acm_ep *ep, struct acm_request *req)
+@@ -1711,7 +1727,7 @@ acm_svr_query(struct acm_client *client, struct acm_resolve_msg *msg)
+ struct acm_ep *ep;
+ uint8_t status;
+
+- acm_log(2, "processing client query\n");
++ acm_log(2, "client %d\n", client->index);
+ if (msg->hdr.length != ACM_MSG_HDR_LENGTH + ACM_MSG_EP_LENGTH) {
+ acm_log(0, "ERROR - invalid length: 0x%x\n", msg->hdr.length);
+ status = ACM_STATUS_EINVAL;
+@@ -1916,7 +1932,7 @@ acm_svr_queue_req(struct acm_dest *dest, struct acm_client *client,
+ {
+ struct acm_request *req;
+
+- acm_log(2, "\n");
++ acm_log(2, "client %d\n", client->index);
+ req = acm_alloc_req(client, msg);
+ if (!req) {
+ return ACM_STATUS_ENOMEM;
+@@ -1935,6 +1951,7 @@ acm_svr_resolve(struct acm_client *client, struct acm_resolve_msg *msg)
+ uint8_t status;
+ int ret;
+
++ acm_log(2, "client %d\n", client->index);
+ status = acm_svr_verify_resolve(msg, &saddr, &daddr);
+ if (status) {
+ acm_log(0, "misformatted or unsupported request\n");
+@@ -2006,7 +2023,7 @@ static void acm_svr_receive(struct acm_client *client)
+ struct acm_resolve_msg *resolve_msg = (struct acm_resolve_msg *) &msg;
+ int ret;
+
+- acm_log(2, "\n");
++ acm_log(2, "client %d\n", client->index);
+ ret = recv(client->sock, (char *) &msg, sizeof msg, 0);
+ if (ret <= 0 || ret != msg.hdr.length) {
+ acm_log(2, "client disconnected\n");
projects / ~shefty / ibacm.git / commitdiff