kclient: clean up some debug output

diff --git a/src/kernel/client.c b/src/kernel/client.c
index 2706d9e1a2cb18654bb06a56921d886628577e94..04ff00a4c555c48eaf17abbb5ebf040d2f1a19bf 100644 (file)
--- a/src/kernel/client.c
+++ b/src/kernel/client.c
@@ -27,7 +27,7 @@ static void get_client_counter(void)
 {
        spin_lock(&ceph_client_spinlock);
        if (ceph_num_clients == 0) {
-               dout(1, "first client, setting up workqueues\n");
+               dout(10, "first client, setting up workqueues\n");
                ceph_workqueue_init();
        }
        ceph_num_clients++;
@@ -39,7 +39,7 @@ static void put_client_counter(void)
        spin_lock(&ceph_client_spinlock);
        ceph_num_clients--;
        if (ceph_num_clients == 0) {
-               dout(1, "last client, shutting down workqueues\n");
+               dout(10, "last client, shutting down workqueues\n");
                ceph_workqueue_shutdown();
        }
        spin_unlock(&ceph_client_spinlock);
@@ -144,7 +144,7 @@ static void handle_monmap(struct ceph_client *client, struct ceph_msg *msg)
        int first = (client->monc.monmap->epoch == 0);
        void *new;
 
-       dout(1, "handle_monmap had epoch %d\n", client->monc.monmap->epoch);
+       dout(2, "handle_monmap had epoch %d\n", client->monc.monmap->epoch);
        new = ceph_monmap_decode(msg->front.iov_base, 
                                 msg->front.iov_base + msg->front.iov_len);
        if (IS_ERR(new)) {
@@ -350,8 +350,7 @@ void ceph_peer_reset(void *p, struct ceph_entity_name *peer_name)
 {
        struct ceph_client *client = p;
        
-       dout(30, "ceph_peer_reset peer_name = %s%d\n", 
-            ceph_name_type_str(peer_name->type), le32_to_cpu(peer_name->num));
+       dout(30, "ceph_peer_reset peer_name = %s%d\n", ENTITY_NAME(*peer_name));
 
        /* write me */
 }

diff --git a/src/kernel/ktcp.c b/src/kernel/ktcp.c
index f308f20a9d43ebb6e65962f092e1027a0630792e..57eec78e9e6514fb31c5cc6d5910d96e7d38dae9 100644 (file)
--- a/src/kernel/ktcp.c
+++ b/src/kernel/ktcp.c
@@ -75,6 +75,10 @@ static void ceph_state_change(struct sock *sk)
                case TCP_CLOSE_WAIT:
                        dout(30, "ceph_state_change TCP_CLOSE_WAIT\n");
                        set_bit(SOCK_CLOSE, &con->state);
+                       if (test_bit(CONNECTING, &con->state))
+                               con->error_msg = "connection refused";
+                       else 
+                               con->error_msg = "socket closed";
                        ceph_queue_write(con);
                        break;
                case TCP_ESTABLISHED:

diff --git a/src/kernel/mds_client.c b/src/kernel/mds_client.c
index be00fa7ce9d2008ca06dcc2e76c600dd05641796..2d052a9a147092d8d6644a085b8369b66ab8f0ad 100644 (file)
--- a/src/kernel/mds_client.c
+++ b/src/kernel/mds_client.c
@@ -759,21 +759,21 @@ void ceph_mdsc_handle_session(struct ceph_mds_client *mdsc,
        session = __get_session(mdsc, mds);
        down(&session->s_mutex);
        
-       dout(1, "handle_session %p op %d seq %llu\n", session, op, seq);
+       dout(2, "handle_session %p op %d seq %llu\n", session, op, seq);
        switch (op) {
        case CEPH_SESSION_OPEN:
-               dout(1, "session open from mds%d\n", mds);
+               dout(2, "session open from mds%d\n", mds);
                session->s_state = CEPH_MDS_SESSION_OPEN;
                complete(&session->s_completion);
                break;
 
        case CEPH_SESSION_CLOSE:
                if (session->s_cap_seq == seq) {
-                       dout(1, "session close from mds%d\n", mds);
+                       dout(2, "session close from mds%d\n", mds);
                        complete(&session->s_completion); /* for good measure */
                        __unregister_session(mdsc, mds);
                } else {
-                       dout(1, "ignoring session close from mds%d, "
+                       dout(2, "ignoring session close from mds%d, "
                             "seq %llu < my seq %llu\n",
                             le32_to_cpu(msg->hdr.src.name.num),
                             seq, session->s_cap_seq);
@@ -807,7 +807,7 @@ void ceph_mdsc_handle_session(struct ceph_mds_client *mdsc,
        return;
 
 bad:
-       dout(1, "corrupt session message, len %d, expected %d\n",
+       derr(1, "corrupt session message, len %d, expected %d\n",
             (int)msg->front.iov_len, (int)sizeof(*h));
        return;
 }
@@ -991,7 +991,7 @@ void ceph_mdsc_handle_reply(struct ceph_mds_client *mdsc, struct ceph_msg *msg)
 
        /* extract tid */
        if (msg->front.iov_len < sizeof(*head)) {
-               dout(1, "handle_reply got corrupt (short) reply\n");
+               derr(1, "handle_reply got corrupt (short) reply\n");
                return;
        }
        tid = le64_to_cpu(head->tid);
@@ -1804,10 +1804,10 @@ void ceph_mdsc_handle_map(struct ceph_mds_client *mdsc, struct ceph_msg *msg)
        return;
 
 bad:
-       dout(1, "corrupt map\n");
+       derr(1, "corrupt mds map\n");
        return;
 bad2:
-       dout(1, "no memory to decode new mdsmap\n");
+       derr(1, "no memory to decode new mdsmap\n");
        return;
 }
 

diff --git a/src/kernel/messenger.c b/src/kernel/messenger.c
index 8f7295437e1b446674790aa6d5a4d5c2c9941d0f..c97b7a928cf12438140d39d81545b8b450a23a7a 100644 (file)
--- a/src/kernel/messenger.c
+++ b/src/kernel/messenger.c
@@ -232,7 +232,8 @@ void ceph_queue_delayed_write(struct ceph_connection *con)
 {
        dout(40, "ceph_queue_delayed_write %p delay %lu\n", con, con->delay);
        atomic_inc(&con->nref);
-       if (!queue_delayed_work(send_wq, &con->swork, con->delay)) {
+       if (!queue_delayed_work(send_wq, &con->swork, 
+                               round_jiffies_relative(con->delay))) {
                dout(40, "ceph_queue_delayed_write %p - already queued\n", con);
                put_connection(con);
        }
@@ -258,18 +259,19 @@ void ceph_queue_read(struct ceph_connection *con)
  */
 static void ceph_send_fault(struct ceph_connection *con)
 {
-       derr(1, "ceph_send_fault %p state %lu to peer %u.%u.%u.%u:%u\n",
-            con, con->state,
-            IPQUADPORT(con->peer_addr.ipaddr));
+       derr(1, "%s%d %u.%u.%u.%u:%u %s\n", ENTITY_NAME(con->peer_name),
+            IPQUADPORT(con->peer_addr.ipaddr), con->error_msg);
+       dout(10, "fault %p state %lu to peer %u.%u.%u.%u:%u\n",
+            con, con->state, IPQUADPORT(con->peer_addr.ipaddr));
 
        /* PW if never get here remove */
        if (test_bit(WAIT, &con->state)) {
-               derr(30, "ceph_send_fault socket close during WAIT state\n");
+               derr(30, "fault socket close during WAIT state\n");
                return;
        }
 
        if (con->delay) {
-               derr(30, "ceph_send_fault tcp_close delay != 0\n");
+               dout(30, "fault tcp_close delay != 0\n");
                if (con->sock)
                        sock_release(con->sock);
                con->sock = NULL;
@@ -301,7 +303,7 @@ static void ceph_send_fault(struct ceph_connection *con)
                else
                        con->delay = MAX_DELAY_INTERVAL;
        } else {
-               dout(30, "ceph_send_fault tcp_close delay = 0\n");
+               dout(30, "fault tcp_close delay = 0\n");
                remove_connection(con->msgr, con);
        }
 }
@@ -567,7 +569,8 @@ more:
                /* hmm, nothing to do! No more writes pending? */
                dout(30, "try_write nothing else to write.\n");
                spin_unlock(&con->out_queue_lock);
-               if (con->delay > 1) con->delay = BASE_DELAY_INTERVAL;
+               if (con->delay > 0) 
+                       con->delay = BASE_DELAY_INTERVAL;
                goto done;
        }
        spin_unlock(&con->out_queue_lock);
@@ -855,7 +858,8 @@ static void process_connect(struct ceph_connection *con)
                break;
        default:
                derr(1, "process_connect protocol error, will retry\n");
-               con->delay = 10 * HZ;  /* maybe use default.. */
+               con->delay = BASE_DELAY_INTERVAL;
+               con->error_msg = "protocol error";
                ceph_send_fault(con);
        }
        if (test_bit(WRITE_PENDING, &con->state)) {
@@ -1075,8 +1079,7 @@ more:
 
                dout(1, "===== %p from %s%d %d=%s len %d+%d =====\n", 
                     con->in_msg,
-                    ceph_name_type_str(le32_to_cpu(con->in_msg->hdr.src.name.type)),
-                    le32_to_cpu(con->in_msg->hdr.src.name.num),
+                    ENTITY_NAME(con->in_msg->hdr.src.name),
                     le32_to_cpu(con->in_msg->hdr.type),
                     ceph_msg_type_name(le32_to_cpu(con->in_msg->hdr.type)),
                     le32_to_cpu(con->in_msg->hdr.front_len),
@@ -1188,7 +1191,7 @@ struct ceph_messenger *ceph_messenger_create(struct ceph_entity_addr *myaddr)
        if (myaddr)
                msgr->inst.addr.ipaddr.sin_addr = myaddr->ipaddr.sin_addr;
 
-       dout(1, "create %p listening on %u.%u.%u.%u:%u\n", msgr,
+       dout(1, "messenger %p listening on %u.%u.%u.%u:%u\n", msgr,
             IPQUADPORT(msgr->inst.addr.ipaddr));
        return msgr;
 }
@@ -1197,14 +1200,14 @@ void ceph_messenger_destroy(struct ceph_messenger *msgr)
 {
        struct ceph_connection *con;
 
-       dout(1, "destroy %p\n", msgr);
+       dout(2, "destroy %p\n", msgr);
 
        /* kill off connections */
        spin_lock(&msgr->con_lock);
        while (!list_empty(&msgr->con_all)) {
-               dout(1, "con_all isn't empty\n");
                con = list_entry(msgr->con_all.next, struct ceph_connection,
                                 list_all);
+               dout(10, "destroy removing connection %p\n", con);
                __remove_connection(msgr, con);
        }
        spin_unlock(&msgr->con_lock);
@@ -1223,13 +1226,15 @@ void ceph_messenger_mark_down(struct ceph_messenger *msgr,
 {
        struct ceph_connection *con;
 
-       dout(1, "mark_down peer %u.%u.%u.%u:%u\n",
+       dout(2, "mark_down peer %u.%u.%u.%u:%u\n",
             IPQUADPORT(addr->ipaddr));
 
        spin_lock(&msgr->con_lock);
        con = __get_connection(msgr, addr);
        if (con) {
-               dout(10, "mark_down dropping %p\n", con);
+               dout(1, "mark_down %s%d %u.%u.%u.%u:%u (%p)\n", 
+                    ENTITY_NAME(con->peer_name),
+                    IPQUADPORT(con->peer_addr.ipaddr), con);
                set_bit(CLOSED, &con->state);  /* in case there's queued work */
                __remove_connection(msgr, con);
                put_connection(con);
@@ -1291,16 +1296,13 @@ int ceph_msg_send(struct ceph_messenger *msgr, struct ceph_msg *msg,
        spin_lock(&con->out_queue_lock);
        msg->hdr.seq = cpu_to_le64(++con->out_seq);
        dout(1, "----- %p to %s%d %d=%s len %d+%d -----\n", msg,
-            ceph_name_type_str(le32_to_cpu(msg->hdr.dst.name.type)),
-            le32_to_cpu(msg->hdr.dst.name.num),
+            ENTITY_NAME(msg->hdr.dst.name),
             le32_to_cpu(msg->hdr.type),
             ceph_msg_type_name(le32_to_cpu(msg->hdr.type)),
             le32_to_cpu(msg->hdr.front_len),
             le32_to_cpu(msg->hdr.data_len));
        dout(2, "ceph_msg_send queuing %p seq %llu for %s%d on %p\n", msg,
-            le64_to_cpu(msg->hdr.seq),
-            ceph_name_type_str(le32_to_cpu(msg->hdr.dst.name.type)),
-            le32_to_cpu(msg->hdr.dst.name.num), con);
+            le64_to_cpu(msg->hdr.seq), ENTITY_NAME(msg->hdr.dst.name), con);
        //ceph_msg_get(msg);
        list_add_tail(&msg->list_head, &con->out_queue);
        spin_unlock(&con->out_queue_lock);

diff --git a/src/kernel/messenger.h b/src/kernel/messenger.h
index c3a8cf3b493748de6119e419bca948862a695e75..c11160a1ac21a24c2f18a4022ac376d00ca15de6 100644 (file)
--- a/src/kernel/messenger.h
+++ b/src/kernel/messenger.h
@@ -26,6 +26,10 @@ static __inline__ const char *ceph_name_type_str(int t) {
        }
 }
 
+/* use format string %s%d */
+#define ENTITY_NAME(n)                            \
+       ceph_name_type_str(le32_to_cpu((n).type)), \
+               le32_to_cpu((n).num)
 
 struct ceph_messenger {
        void *parent;
@@ -56,7 +60,7 @@ struct ceph_msg_pos {
 };
 
 /* ceph connection fault delay defaults */
-#define BASE_DELAY_INTERVAL    1
+#define BASE_DELAY_INTERVAL    (HZ/2)
 #define MAX_DELAY_INTERVAL     (5U * 60 * HZ)
 
 /* ceph_connection state bit flags */
@@ -76,6 +80,7 @@ struct ceph_connection {
        struct ceph_messenger *msgr;
        struct socket *sock;    /* connection socket */
        unsigned long state;    /* connection state */
+       const char *error_msg;
 
        atomic_t nref;
 

diff --git a/src/kernel/super.c b/src/kernel/super.c
index b2b651879a31b7f1d38f2592e4774f8cbf56cda8..e16317496613cd696f5e0b13b9924fb0d648ccad 100644 (file)
--- a/src/kernel/super.c
+++ b/src/kernel/super.c
@@ -15,7 +15,7 @@
  * if the per-file debug level >= 0, then that overrides this  global
  * debug level.
  */
-int ceph_debug = 0;
+int ceph_debug = 1;
 
 /* for this file */
 int ceph_debug_super = -1;
@@ -290,7 +290,7 @@ static int parse_ip(const char *c, int len, struct ceph_entity_addr *addr)
        return 0;
 
 bad:
-       dout(1, "parse_ip bad ip '%s'\n", c);
+       derr(1, "parse_ip bad ip '%s'\n", c);
        return -EINVAL;
 }
 

diff --git a/src/kernel/super.h b/src/kernel/super.h
index 08a9f47356ddf987b47ab71843c80e2318777c41..05ff42cacc91e63ce5c6e4c3ae8520a08dd9b67b 100644 (file)
--- a/src/kernel/super.h
+++ b/src/kernel/super.h
@@ -30,7 +30,7 @@ extern int ceph_debug_addr;
 
 #ifdef CEPH_DUMP_ERROR_ALWAYS
 #define derr(x, args...) do {                                          \
-               printk(KERN_ERR "ceph_" DOUT_PREFIX args);      \
+               printk(KERN_ERR "ceph: " args); \
        } while (0)
 #else
 #define derr(x, args...) do {                                          \