patch libctdb-use-logging.patch

diff --git a/libctdb/control.c b/libctdb/control.c
index 609466c3380dfe61f4d51998b7fe4ea76e7cac30..f861146b4362991db94c3736fa95f38f42d3bd5d 100644 (file)
--- a/libctdb/control.c
+++ b/libctdb/control.c
@@ -30,8 +30,13 @@ int ctdb_getrecmaster_recv(struct ctdb_connection *ctdb,
        struct ctdb_reply_control *reply;
 
        reply = unpack_reply_control(ctdb, req, CTDB_CONTROL_GET_RECMASTER);
-       if (!reply || reply->status == -1)
+       if (!reply) {
                return -1;
+       }
+       if (reply->status == -1) {
+               DEBUG(ctdb, LOG_ERR, "ctdb_getrecmaster_recv: status -1");
+               return -1;
+       }
        *recmaster = reply->status;
        return 0;
 }
@@ -52,8 +57,13 @@ int ctdb_getpnn_recv(struct ctdb_connection *ctdb,
        struct ctdb_reply_control *reply;
 
        reply = unpack_reply_control(ctdb, req, CTDB_CONTROL_GET_PNN);
-       if (!reply || reply->status == -1)
+       if (!reply) {
+               return -1;
+       }
+       if (reply->status == -1) {
+               DEBUG(ctdb, LOG_ERR, "ctdb_getpnn_recv: status -1");
                return -1;
+       }
        *pnn = reply->status;
        return 0;
 }

diff --git a/libctdb/ctdb.c b/libctdb/ctdb.c
index b6ea121c5ecf1772d7bdc4b07b7192ab34d9696d..915e496f54233d76d7c7173181ff84d4c32c9d9d 100644 (file)
--- a/libctdb/ctdb.c
+++ b/libctdb/ctdb.c
@@ -73,7 +73,8 @@ static void set_pnn(struct ctdb_connection *ctdb,
                    void *unused)
 {
        if (ctdb_getpnn_recv(ctdb, req, &ctdb->pnn) != 0) {
-               /* FIXME: Report error. */
+               DEBUG(ctdb, LOG_CRIT,
+                     "ctdb_connect(async): failed to get pnn");
                ctdb->broken = true;
        }
        ctdb_request_free(ctdb, req);
@@ -86,8 +87,14 @@ struct ctdb_connection *ctdb_connect(const char *addr,
        struct sockaddr_un sun;
 
        ctdb = malloc(sizeof(*ctdb));
-       if (!ctdb)
+       if (!ctdb) {
+               /* With no format string, we hope it doesn't use ap! */
+               va_list ap;
+               memset(&ap, 0, sizeof(ap));
+               errno = ENOMEM;
+               log_fn(log_priv, LOG_ERR, "ctdb_connect: no memory", ap);
                goto fail;
+       }
        ctdb->outq = NULL;
        ctdb->doneq = NULL;
        ctdb->in = NULL;
@@ -172,8 +179,7 @@ void ctdb_request_free(struct ctdb_connection *ctdb, struct ctdb_request *req)
        free(req);
 }
 
-/* Sanity-checking wrapper for reply.
- * FIXME: logging! */
+/* Sanity-checking wrapper for reply. */
 static struct ctdb_reply_call *unpack_reply_call(struct ctdb_connection *ctdb,
                                                 struct ctdb_request *req,
                                                 uint32_t callid)
@@ -181,24 +187,36 @@ static struct ctdb_reply_call *unpack_reply_call(struct ctdb_connection *ctdb,
        size_t len;
        struct ctdb_reply_call *inhdr = io_elem_data(req->reply, &len);
 
-       /* ctdbd or our error if this isn't a reply call. */
-       if (len < sizeof(*inhdr) || inhdr->hdr.operation != CTDB_REPLY_CALL) {
-               errno = EIO;
+       /* Library user error if this isn't a reply to a call. */
+       if (req->hdr.hdr->operation != CTDB_REQ_CALL) {
+               errno = EINVAL;
+               DEBUG(ctdb, LOG_ERR,
+                     "This was not a ctdbd call request: operation %u",
+                     req->hdr.hdr->operation);
                return NULL;
        }
 
-       /* Library user error if this isn't a reply to a call. */
-       if (req->hdr.hdr->operation != CTDB_REQ_CALL
-           || req->hdr.call->callid != callid) {
+       if (req->hdr.call->callid != callid) {
                errno = EINVAL;
+               DEBUG(ctdb, LOG_ERR,
+                     "This was not a ctdbd %u call request: %u",
+                     callid, req->hdr.call->callid);
+               return NULL;
+       }
+
+       /* ctdbd or our error if this isn't a reply call. */
+       if (len < sizeof(*inhdr) || inhdr->hdr.operation != CTDB_REPLY_CALL) {
+               errno = EIO;
+               DEBUG(ctdb, LOG_CRIT,
+                     "Invalid ctdbd call reply: len %zu, operation %u",
+                     len, inhdr->hdr.operation);
                return NULL;
        }
 
        return inhdr;
 }
 
-/* Sanity-checking wrapper for reply.
- * FIXME: logging! */
+/* Sanity-checking wrapper for reply. */
 struct ctdb_reply_control *unpack_reply_control(struct ctdb_connection *ctdb,
                                                struct ctdb_request *req,
                                                enum ctdb_controls control)
@@ -207,21 +225,35 @@ struct ctdb_reply_control *unpack_reply_control(struct ctdb_connection *ctdb,
        struct ctdb_reply_control *inhdr = io_elem_data(req->reply, &len);
 
        /* Library user error if this isn't a reply to a call. */
-       if (len < sizeof(*inhdr)
-           || req->hdr.hdr->operation != CTDB_REQ_CONTROL) {
+       if (len < sizeof(*inhdr)) {
+               errno = EINVAL;
+               DEBUG(ctdb, LOG_CRIT,
+                     "Short ctdbd control reply: %zu bytes", len);
+               return NULL;
+       }
+       if (req->hdr.hdr->operation != CTDB_REQ_CONTROL) {
                errno = EINVAL;
+               DEBUG(ctdb, LOG_ERR,
+                     "This was not a ctdbd control request: operation %u",
+                     req->hdr.hdr->operation);
                return NULL;
        }
 
        /* ... or if it was a different control from what we expected. */
        if (req->hdr.control->opcode != control) {
                errno = EINVAL;
+               DEBUG(ctdb, LOG_ERR,
+                     "This was not an opcode %u ctdbd control request: %u",
+                     control, req->hdr.control->opcode);
                return NULL;
        }
 
        /* ctdbd or our error if this isn't a reply call. */
        if (inhdr->hdr.operation != CTDB_REPLY_CONTROL) {
                errno = EIO;
+               DEBUG(ctdb, LOG_CRIT,
+                     "Invalid ctdbd control reply: operation %u",
+                     inhdr->hdr.operation);
                return NULL;
        }
 
@@ -250,7 +282,9 @@ static void handle_incoming(struct ctdb_connection *ctdb, struct io_elem *in)
                        return;
                }
        }
-       /* FIXME: report this error. */
+       DEBUG(ctdb, LOG_WARNING,
+             "Unexpected ctdbd request reply: operation %u reqid %u",
+             hdr->operation, hdr->reqid);
        free_io_elem(in);
 }
 
@@ -272,6 +306,8 @@ int ctdb_service(struct ctdb_connection *ctdb, int revents)
                while (ctdb->outq) {
                        if (real_error(write_io_elem(ctdb->fd,
                                                     ctdb->outq->io)) < 0) {
+                               DEBUG(ctdb, LOG_ERR,
+                                     "ctdb_service: error writing to ctdbd");
                                ctdb->broken = true;
                                return -1;
                        }
@@ -291,6 +327,8 @@ int ctdb_service(struct ctdb_connection *ctdb, int revents)
                if (!ctdb->in) {
                        ctdb->in = new_io_elem(sizeof(struct ctdb_req_header));
                        if (!ctdb->in) {
+                               DEBUG(ctdb, LOG_ERR,
+                                     "ctdb_service: allocating readbuf");
                                ctdb->broken = true;
                                return -1;
                        }
@@ -301,6 +339,8 @@ int ctdb_service(struct ctdb_connection *ctdb, int revents)
                        /* They closed fd? */
                        if (ret == 0)
                                errno = EBADF;
+                       DEBUG(ctdb, LOG_ERR,
+                             "ctdb_service: error reading from ctdbd");
                        ctdb->broken = true;
                        return -1;
                } else if (ret < 0) {
@@ -380,6 +420,9 @@ void ctdb_cancel_callback(struct ctdb_connection *ctdb,
 
 int ctdb_cancel(struct ctdb_connection *ctdb, struct ctdb_request *req)
 {
+       DEBUG(ctdb, LOG_DEBUG, "ctdb_cancel: %p (id %u)",
+             req, req->hdr.hdr ? req->hdr.hdr->reqid : 0);
+
        /* FIXME: If it's not sent, we could just free it right now. */
        req->callback = ctdb_cancel_callback;
        return 0;
@@ -422,20 +465,31 @@ struct ctdb_db *ctdb_attachdb_recv(struct ctdb_connection *ctdb,
        }
 
        reply = unpack_reply_control(ctdb, dbpath_req, CTDB_CONTROL_GETDBPATH);
-       if (!reply || reply->status != 0) {
+       if (!reply) {
+               return NULL;
+       }
+       if (reply->status != 0) {
+               DEBUG(db->ctdb, LOG_ERR,
+                     "ctdb_attachdb_recv: reply status %i", reply->status);
                return NULL;
        }
 
        tdb_flags = db->persistent ? TDB_DEFAULT : TDB_NOSYNC;
        tdb_flags |= TDB_DISALLOW_NESTING;
 
+       /* FIXME: Setup logging to go through our logging. */
        db->tdb = tdb_open((char *)reply->data, 0, tdb_flags, O_RDWR, 0);
        if (db->tdb == NULL) {
+               DEBUG(db->ctdb, LOG_ERR,
+                     "ctdb_attachdb_recv: failed to tdb_open %s",
+                     (char *)reply->data);
                return NULL;
        }
 
        /* Finally, separate the db from the request (see destroy_req_db). */
        req->priv_data = NULL;
+       DEBUG(db->ctdb, LOG_DEBUG,
+             "ctdb_attachdb_recv: db %p, tdb %s", db, (char *)reply->data);
        return db;
 }
 
@@ -454,6 +508,11 @@ static void attachdb_done(struct ctdb_connection *ctdb,
 
        reply = unpack_reply_control(ctdb, req, control);
        if (!reply || reply->status != 0) {
+               if (reply) {
+                       DEBUG(ctdb, LOG_ERR,
+                             "ctdb_attachdb_send(async): DB_ATTACH status %i",
+                             reply->status);
+               }
                /* We failed.  Hand request to user and have them discover it
                 * via ctdb_attachdb_recv. */
                db->callback(ctdb, req, db->private_data);
@@ -467,11 +526,15 @@ static void attachdb_done(struct ctdb_connection *ctdb,
                                        &db->id, sizeof(db->id),
                                        attachdb_getdbpath_done, db);
        if (!req2) {
+               DEBUG(db->ctdb, LOG_ERR,
+                     "ctdb_attachdb_send(async): failed to allocate");
                db->callback(ctdb, req, db->private_data);
                return;
        }
        req->extra = req2;
        req2->extra = req;
+       DEBUG(db->ctdb, LOG_DEBUG,
+             "ctdb_attachdb_send(async): created getdbpath request");
 }
 
 static void destroy_req_db(struct ctdb_connection *ctdb,
@@ -509,6 +572,8 @@ ctdb_attachdb_send(struct ctdb_connection *ctdb,
        req = new_ctdb_control_request(ctdb, opcode, CTDB_CURRENT_NODE, name,
                                       strlen(name) + 1, attachdb_done, db);
        if (!req) {
+               DEBUG(db->ctdb, LOG_ERR,
+                     "ctdb_attachdb_send: failed allocating DB_ATTACH");
                free(db);
                return NULL;
        }
@@ -525,6 +590,8 @@ ctdb_attachdb_send(struct ctdb_connection *ctdb,
 
        /* Flags get overloaded into srvid. */
        req->hdr.control->srvid = tdb_flags;
+       DEBUG(db->ctdb, LOG_DEBUG,
+             "ctdb_attachdb_send: DB_ATTACH request %p", req);
        return req;
 }
 
@@ -543,6 +610,8 @@ struct ctdb_lock {
 void ctdb_release_lock(struct ctdb_lock *lock)
 {
        if (lock->held) {
+               DEBUG(lock->ctdb_db->ctdb, LOG_DEBUG,
+                     "ctdb_attachdb_send: ctdb_release_lock %p", lock);
                tdb_chainunlock(lock->ctdb_db->tdb, lock->key);
                lock->held = false;
        }
@@ -565,11 +634,15 @@ static bool try_readrecordlock(struct ctdb_lock *lock, TDB_DATA *data)
        struct ctdb_ltdb_header *hdr;
 
        if (tdb_chainlock(lock->ctdb_db->tdb, lock->key) != 0) {
+               DEBUG(lock->ctdb_db->ctdb, LOG_WARNING,
+                     "ctdb_readrecordlock_async: failed to chainlock");
                return NULL;
        }
 
        hdr = ctdb_local_fetch(lock->ctdb_db->tdb, lock->key, data);
        if (hdr && hdr->dmaster == lock->ctdb_db->ctdb->pnn) {
+               DEBUG(lock->ctdb_db->ctdb, LOG_DEBUG,
+                     "ctdb_readrecordlock_async: got local lock");
                lock->held = true;
                lock->hdr = hdr;
                return true;
@@ -598,6 +671,11 @@ static void readrecordlock_retry(struct ctdb_connection *ctdb,
        /* OK, we've received reply to noop migration */
        reply = unpack_reply_call(ctdb, req, CTDB_NULL_FUNC);
        if (!reply || reply->status != 0) {
+               if (reply) {
+                       DEBUG(ctdb, LOG_ERR,
+                             "ctdb_readrecordlock_async(async):"
+                             " NULL_FUNC returned %i", reply->status);
+               }
                lock->callback(lock->ctdb_db, NULL, tdb_null, private);
                ctdb_request_free(ctdb, req); /* Also frees lock. */
                ctdb_free_lock(lock);
@@ -629,6 +707,8 @@ ctdb_readrecordlock_async(struct ctdb_db *ctdb_db, TDB_DATA key,
        /* Setup lock */
        lock = malloc(sizeof(*lock) + key.dsize);
        if (!lock) {
+               DEBUG(ctdb_db->ctdb, LOG_ERR,
+                     "ctdb_readrecordlock_async: lock allocation failed");
                return false;
        }
        lock->key.dptr = (void *)(lock + 1);
@@ -649,6 +729,8 @@ ctdb_readrecordlock_async(struct ctdb_db *ctdb_db, TDB_DATA key,
        req = new_ctdb_request(offsetof(struct ctdb_req_call, data)
                               + key.dsize, readrecordlock_retry, cbdata);
        if (!req) {
+               DEBUG(ctdb_db->ctdb, LOG_ERR,
+                     "ctdb_readrecordlock_async: allocation failed");
                ctdb_release_lock(lock);
                ctdb_free_lock(lock);
                return NULL;
@@ -675,7 +757,9 @@ ctdb_readrecordlock_async(struct ctdb_db *ctdb_db, TDB_DATA key,
 int ctdb_writerecord(struct ctdb_lock *lock, TDB_DATA data)
 {
        if (lock->ctdb_db->persistent) {
-               /* FIXME: Report error. */
+               errno = EINVAL;
+               DEBUG(lock->ctdb_db->ctdb, LOG_ERR,
+                     "ctdb_writerecord: cannot write to persistent db");
                return -1;
        }
 

diff --git a/libctdb/messages.c b/libctdb/messages.c
index a3a28a68c546beeda5f0bfb40a46003e3a70e066..e4b03d9e9ef192e4fb51eb542faf0dd9f16b5b77 100644 (file)
--- a/libctdb/messages.c
+++ b/libctdb/messages.c
@@ -25,6 +25,7 @@ void deliver_message(struct ctdb_connection *ctdb, struct ctdb_req_header *hdr)
        struct message_handler_info *i;
        struct ctdb_req_message *msg = (struct ctdb_req_message *)hdr;
        TDB_DATA data;
+       bool found;
 
        data.dptr = msg->data;
        data.dsize = msg->datalen;
@@ -32,9 +33,14 @@ void deliver_message(struct ctdb_connection *ctdb, struct ctdb_req_header *hdr)
        for (i = ctdb->message_handlers; i; i = i->next) {
                if (i->srvid == msg->srvid) {
                        i->handler(ctdb, msg->srvid, data, i->private_data);
+                       found = true;
                }
        }
-       /* FIXME: Report unknown messages */
+       if (!found) {
+               DEBUG(ctdb, LOG_WARNING,
+                     "ctdb_service: messsage for unregistered srvid %llu",
+                     msg->srvid);
+       }
 }
 
 int ctdb_set_message_handler_recv(struct ctdb_connection *ctdb,
@@ -44,7 +50,13 @@ int ctdb_set_message_handler_recv(struct ctdb_connection *ctdb,
        struct ctdb_reply_control *reply;
 
        reply = unpack_reply_control(ctdb, req, CTDB_CONTROL_REGISTER_SRVID);
-       if (!reply || reply->status != 0) {
+       if (!reply) {
+               return -1;
+       }
+       if (reply->status != 0) {
+               DEBUG(ctdb, LOG_WARNING,
+                     "ctdb_set_message_handler_recv: status %i",
+                     reply->status);
                return -1;
        }
 
@@ -70,6 +82,8 @@ ctdb_set_message_handler_send(struct ctdb_connection *ctdb, uint64_t srvid,
 
        info = malloc(sizeof(*info));
        if (!info) {
+               DEBUG(ctdb, LOG_ERR,
+                     "ctdb_set_message_handler_send: allocating info");
                return NULL;
        }
 
@@ -77,6 +91,8 @@ ctdb_set_message_handler_send(struct ctdb_connection *ctdb, uint64_t srvid,
                                       CTDB_CURRENT_NODE, NULL, 0,
                                       callback, private_data);
        if (!req) {
+               DEBUG(ctdb, LOG_ERR,
+                     "ctdb_set_message_handler_send: allocating request");
                free(info);
                return NULL;
        }
@@ -88,6 +104,9 @@ ctdb_set_message_handler_send(struct ctdb_connection *ctdb, uint64_t srvid,
        info->handler = handler;
        info->private_data = private_data;
 
+       DEBUG(ctdb, LOG_DEBUG,
+             "ctdb_set_message_handler_send: sending request %u for id %llu",
+             req->hdr.hdr->reqid, srvid);
        return req;
 }
 
@@ -102,6 +121,7 @@ int ctdb_send_message(struct ctdb_connection *ctdb,
        req = new_ctdb_request(offsetof(struct ctdb_req_message, data) + data.dsize,
                               ctdb_cancel_callback, NULL);
        if (!req) {
+               DEBUG(ctdb, LOG_ERR, "ctdb_set_message: allocating message");
                return -1;
        }
 

diff --git a/libctdb/sync.c b/libctdb/sync.c
index ece5408d1640a7598e84486ad95ccade9aade734..b4c7b06246576cbebc9c2bdce4d1eb67e8b98c36 100644 (file)
--- a/libctdb/sync.c
+++ b/libctdb/sync.c
@@ -42,6 +42,7 @@ static struct ctdb_request *synchronous(struct ctdb_connection *ctdb,
                        if (errno == EINTR)
                                continue;
                        ctdb_request_free(ctdb, req);
+                       DEBUG(ctdb, LOG_ERR, "ctdb_synchronous: poll failed");
                        return NULL;
                }
                if (ctdb_service(ctdb, fds.revents) < 0) {

diff --git a/libctdb/tst.c b/libctdb/tst.c
index 530125c792ab4d4ec38672b59c37be42e930ab66..d3afe8d8d173ec73efe33cbe1ac67af6c1339587 100644 (file)
--- a/libctdb/tst.c
+++ b/libctdb/tst.c
@@ -33,6 +33,7 @@
 #include <stdlib.h>
 #include <err.h>
 #include <stdbool.h>
+#include <syslog.h>
 #include <tdb.h>
 #include <ctdb.h>
 
@@ -136,7 +137,7 @@ int main(int argc, char *argv[])
        TDB_DATA msg;
        bool rrl_cb_called = false;
 
-
+       ctdb_log_level = LOG_DEBUG;
        ctdb_connection = ctdb_connect("/tmp/ctdb.socket",
                                       ctdb_log_file, stderr);
        if (!ctdb_connection)