Version: 1
-Previous: 8b6344138616e8ee75043b59fa9c207174603582
+Previous: aa24cdbfd1ff0a504691ebca0234ca7eaf75ccd1
Head: cd954cf747410a9beb309cfc79b093fa3117e14f
Applied:
- ts: cd954cf747410a9beb309cfc79b093fa3117e14f
+ logging: cd954cf747410a9beb309cfc79b093fa3117e14f
Unapplied:
loopback: 8c3473645ff2d6097b6a9c351a726ea48c1d8165
Hidden:
--- /dev/null
+Bottom: 30326a5093b7b177c8d7612eba401d4999793f71
+Top: 1df1d44b89d4161f2d3d3274603c0435ddfdd479
+Author: Sean Hefty <sean.hefty@intel.com>
+Date: 2010-11-11 16:51:45 -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..fd61a9d 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 ", dest->addr_type, dest->address);
+ }
+- 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 id %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->addr);
+ 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->addr);
+ 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->addr);
+ 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 id %d, status 0x%x\n", client->index, status);
+ memset(&msg, 0, sizeof msg);
+
+ lock_acquire(&client->lock);
+@@ -1187,7 +1195,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, ep->addr);
+ mad = (struct acm_mad *) (uintptr_t) (wc->wr_id + sizeof(struct ibv_grh));
+ switch (mad->mgmt_class) {
+ case IB_MGMT_CLASS_SA:
+@@ -1711,7 +1719,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 id %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 +1924,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 id %d\n", client->index);
+ req = acm_alloc_req(client, msg);
+ if (!req) {
+ return ACM_STATUS_ENOMEM;
+@@ -1935,6 +1943,7 @@ acm_svr_resolve(struct acm_client *client, struct acm_resolve_msg *msg)
+ uint8_t status;
+ int ret;
+
++ acm_log(2, "client id %d\n", client->index);
+ status = acm_svr_verify_resolve(msg, &saddr, &daddr);
+ if (status) {
+ acm_log(0, "misformatted or unsupported request\n");
+@@ -2006,7 +2015,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 id %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: 1df1d44b89d4161f2d3d3274603c0435ddfdd479
-Author: Sean Hefty <sean.hefty@intel.com>
-Date: 2010-11-11 16:51:45 -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..fd61a9d 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 ", dest->addr_type, dest->address);
- }
-- 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 id %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->addr);
- 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->addr);
- 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->addr);
- 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 id %d, status 0x%x\n", client->index, status);
- memset(&msg, 0, sizeof msg);
-
- lock_acquire(&client->lock);
-@@ -1187,7 +1195,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, ep->addr);
- mad = (struct acm_mad *) (uintptr_t) (wc->wr_id + sizeof(struct ibv_grh));
- switch (mad->mgmt_class) {
- case IB_MGMT_CLASS_SA:
-@@ -1711,7 +1719,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 id %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 +1924,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 id %d\n", client->index);
- req = acm_alloc_req(client, msg);
- if (!req) {
- return ACM_STATUS_ENOMEM;
-@@ -1935,6 +1943,7 @@ acm_svr_resolve(struct acm_client *client, struct acm_resolve_msg *msg)
- uint8_t status;
- int ret;
-
-+ acm_log(2, "client id %d\n", client->index);
- status = acm_svr_verify_resolve(msg, &saddr, &daddr);
- if (status) {
- acm_log(0, "misformatted or unsupported request\n");
-@@ -2006,7 +2015,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 id %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");