Use the logger instead of fprintf

7 files changed, 136 insertions, 74 deletions

diff --git a/daemon/isasl.c b/daemon/isasl.c
index 9305ba6..5ca1a39 100644
--- a/daemon/isasl.c
+++ b/daemon/isasl.c
@@ -9,6 +9,7 @@
 #include <pthread.h>
 #include <stdbool.h>
 #include <sys/stat.h>
+#include <errno.h>
 
 #include "hash.h"
 #include "isasl.h"
@@ -171,7 +172,9 @@ static int load_user_db(void)
     fclose(sfile);
 
     if (settings.verbose) {
-        fprintf(stderr, "Loaded isasl db from %s\n", filename);
+        settings.extensions.logger->log(EXTENSION_LOG_INFO, NULL,
+                                        "Loaded isasl db from %s\n",
+                                        filename);
     }
 
     return SASL_OK;
@@ -206,7 +209,9 @@ static void* check_isasl_db_thread(void* arg)
 {
     uint32_t sleep_time = *(int*)arg;
     if (settings.verbose > 1) {
-        fprintf(stderr, "isasl checking DB every %ds\n", sleep_time);
+        settings.extensions.logger->log(EXTENSION_LOG_INFO, NULL,
+                                        "isasl checking DB every %ds",
+                                        sleep_time);
     }
 
     run_sasl_db_thread = true;
@@ -248,7 +253,9 @@ int sasl_server_init(const sasl_callback_t *callbacks,
         if (pthread_attr_init(&attr) != 0 ||
             pthread_attr_setdetachstate(&attr, PTHREAD_CREATE_DETACHED) != 0)
         {
-           perror("Failed to initialize pthread attributes");
+            settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                            "Failed to initialize pthread attributes: %s",
+                                            strerror(errno));
            exit(EX_OSERR);
         }
 
@@ -260,7 +267,8 @@ int sasl_server_init(const sasl_callback_t *callbacks,
             pthread_create(&sasl_db_thread_tid, &attr, check_isasl_db_thread,
                            &sleep_time) != 0)
         {
-            perror("couldn't create isasl db update thread.");
+            settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                            "couldn't create isasl db update thread.");
             exit(EX_OSERR);
         }
     }
diff --git a/daemon/memcached.c b/daemon/memcached.c
index cc11e2e..55a49c5 100644
--- a/daemon/memcached.c
+++ b/daemon/memcached.c
@@ -4970,8 +4970,11 @@ static enum transmit_result transmit(conn *c) {
         }
         /* if res == 0 or res == -1 and error is not EAGAIN or EWOULDBLOCK,
            we have a real error, on which we close the connection */
-        if (settings.verbose > 0)
-            perror("Failed to write, and not due to blocking");
+        if (settings.verbose > 0) {
+            settings.extensions.logger->log(EXTENSION_LOG_WARNING, c,
+                                            "Failed to write, and not due to blocking: %s",
+                                            strerror(errno));
+        }
 
         if (IS_UDP(c->transport))
             conn_set_state(c, conn_read);
@@ -5588,8 +5591,12 @@ static void maximize_sndbuf(const int sfd) {
 
     /* Start with the default size. */
     if (getsockopt(sfd, SOL_SOCKET, SO_SNDBUF, (void *)&old_size, &intsize) != 0) {
-        if (settings.verbose > 0)
-            perror("getsockopt(SO_SNDBUF)");
+        if (settings.verbose > 0) {
+            settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                            "getsockopt(SO_SNDBUF): %s",
+                                            strerror(errno));
+        }
+
         return;
     }
 
@@ -5670,7 +5677,9 @@ static int server_socket(const char *interface,
         if (next->ai_family == AF_INET6) {
             error = setsockopt(sfd, IPPROTO_IPV6, IPV6_V6ONLY, (char *) &flags, sizeof(flags));
             if (error != 0) {
-                perror("setsockopt");
+                settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                                "setsockopt(IPV6_V6ONLY): %s",
+                                                strerror(errno));
                 safe_close(sfd);
                 continue;
             }
@@ -5682,21 +5691,32 @@ static int server_socket(const char *interface,
             maximize_sndbuf(sfd);
         } else {
             error = setsockopt(sfd, SOL_SOCKET, SO_KEEPALIVE, (void *)&flags, sizeof(flags));
-            if (error != 0)
-                perror("setsockopt");
+            if (error != 0) {
+                settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                                "setsockopt(SO_KEEPALIVE): %s",
+                                                strerror(errno));
+            }
 
             error = setsockopt(sfd, SOL_SOCKET, SO_LINGER, (void *)&ling, sizeof(ling));
-            if (error != 0)
-                perror("setsockopt");
+            if (error != 0) {
+                settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                                "setsockopt(SO_LINGER): %s",
+                                                strerror(errno));
+            }
 
             error = setsockopt(sfd, IPPROTO_TCP, TCP_NODELAY, (void *)&flags, sizeof(flags));
-            if (error != 0)
-                perror("setsockopt");
+            if (error != 0) {
+                settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                                "setsockopt(TCP_NODELAY): %s",
+                                                strerror(errno));
+            }
         }
 
         if (bind(sfd, next->ai_addr, next->ai_addrlen) == SOCKET_ERROR) {
             if (errno != EADDRINUSE) {
-                perror("bind()");
+                settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                                "bind(): %s",
+                                                strerror(errno));
                 safe_close(sfd);
                 freeaddrinfo(ai);
                 return 1;
@@ -5706,7 +5726,9 @@ static int server_socket(const char *interface,
         } else {
             success++;
             if (!IS_UDP(transport) && listen(sfd, settings.backlog) == SOCKET_ERROR) {
-                perror("listen()");
+                settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                                "listen(): %s",
+                                                strerror(errno));
                 safe_close(sfd);
                 freeaddrinfo(ai);
                 return 1;
@@ -5812,7 +5834,9 @@ static int new_socket_unix(void) {
     int sfd;
 
     if ((sfd = socket(AF_UNIX, SOCK_STREAM, 0)) == INVALID_SOCKET) {
-        perror("socket()");
+        settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                        "socket(AF_UNIX, SOCK_STREAM, 0): %s",
+                                        strerror(errno));
         return INVALID_SOCKET;
     }
 
@@ -5863,14 +5887,18 @@ static int server_socket_unix(const char *path, int access_mask) {
     assert(strcmp(addr.sun_path, path) == 0);
     old_umask = umask( ~(access_mask&0777));
     if (bind(sfd, (struct sockaddr *)&addr, sizeof(addr)) == -1) {
-        perror("bind()");
+        settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                        "bind(): %s",
+                                        strerror(errno));
         safe_close(sfd);
         umask(old_umask);
         return 1;
     }
     umask(old_umask);
     if (listen(sfd, settings.backlog) == -1) {
-        perror("listen()");
+        settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                        "listen(): %s",
+                                        strerror(errno));
         safe_close(sfd);
         return 1;
     }
@@ -6065,7 +6093,8 @@ static void save_pid(const char *pid_file) {
             if (fgets(buffer, sizeof(buffer), fp) != NULL) {
                 unsigned int pid;
                 if (safe_strtoul(buffer, &pid) && kill((pid_t)pid, 0) == 0) {
-                    fprintf(stderr, "WARNING: The pid file contained the following (running) pid: %u\n", pid);
+                    settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                               "WARNING: The pid file contained the following (running) pid: %u\n", pid);
                 }
             }
             fclose(fp);
@@ -6717,7 +6746,8 @@ static bool sanitycheck(void) {
         if (strncmp(ever, "1.", 2) == 0) {
             /* Require at least 1.3 (that's still a couple of years old) */
             if ((ever[2] == '1' || ever[2] == '2') && !isdigit(ever[3])) {
-                fprintf(stderr, "You are using libevent %s.\nPlease upgrade to"
+                settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                        "You are using libevent %s.\nPlease upgrade to"
                         " a more recent version (1.3 or newer)\n",
                         event_get_version());
                 return false;
@@ -6750,10 +6780,6 @@ int main (int argc, char **argv) {
     char old_options[1024] = { [0] = '\0' };
     char *old_opts = old_options;
 
-    if (!sanitycheck()) {
-        return EX_OSERR;
-    }
-
     /* make the time we started always be 2 seconds before we really
        did, so time(0) - time.started is never zero.  if so, things
        like 'settings.oldest_live' which act as booleans as well as
@@ -6772,6 +6798,10 @@ int main (int argc, char **argv) {
         return EX_OSERR;
     }
 
+    if (!sanitycheck()) {
+        return EX_OSERR;
+    }
+
     /* process arguments */
     while (-1 != (c = getopt(argc, argv,
           "a:"  /* access mask for unix socket */
@@ -7288,7 +7318,9 @@ int main (int argc, char **argv) {
     /* create unix mode sockets after dropping privileges */
     if (settings.socketpath != NULL) {
         if (server_socket_unix(settings.socketpath,settings.access)) {
-            vperror("failed to listen on UNIX socket: %s", settings.socketpath);
+            settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                            "failed to listen on UNIX socket \"%s\": %s",
+                                            settings.socketpath, strerror(errno));
             exit(EX_OSERR);
         }
     }
@@ -7316,7 +7348,9 @@ int main (int argc, char **argv) {
 
         if (settings.port && server_sockets(settings.port, tcp_transport,
                                             portnumber_file)) {
-            vperror("failed to listen on TCP port %d", settings.port);
+            settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                            "failed to listen on TCP port %d: %s",
+                                            settings.port, strerror(errno));
             exit(EX_OSERR);
         }
 
@@ -7331,7 +7365,9 @@ int main (int argc, char **argv) {
         /* create the UDP listening socket and bind it */
         if (settings.udpport && server_sockets(settings.udpport, udp_transport,
                                                portnumber_file)) {
-            vperror("failed to listen on UDP port %d", settings.udpport);
+            settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                            "failed to listen on UDP port %d: %s",
+                                            settings.port, strerror(errno));
             exit(EX_OSERR);
         }
 
diff --git a/daemon/sasl_defs.c b/daemon/sasl_defs.c
index 9b08b4b..ed4b1ba 100644
--- a/daemon/sasl_defs.c
+++ b/daemon/sasl_defs.c
@@ -30,8 +30,8 @@ static int sasl_server_userdb_checkpass(sasl_conn_t *conn,
 {
     size_t unmlen = strlen(user);
     if ((passlen + unmlen) > (MAX_ENTRY_LEN - 4)) {
-        fprintf(stderr,
-                "WARNING: Failed to authenticate <%s> due to too long password (%d)\n",
+        settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                "WARNING: Failed to authenticate <%s> due to too long password (%d)",
                 user, passlen);
         return SASL_NOAUTHZ;
     }
@@ -39,8 +39,9 @@ static int sasl_server_userdb_checkpass(sasl_conn_t *conn,
     FILE *pwfile = fopen(memcached_sasl_pwdb, "r");
     if (pwfile == NULL) {
         if (settings.verbose) {
-            vperror("WARNING: Failed to open sasl database <%s>",
-                    memcached_sasl_pwdb);
+            settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                     "WARNING: Failed to open sasl database <%s>: %s",
+                     memcached_sasl_pwdb, strerror(errno));
         }
         return SASL_NOAUTHZ;
     }
@@ -69,7 +70,9 @@ static int sasl_server_userdb_checkpass(sasl_conn_t *conn,
     }
 
     if (settings.verbose) {
-        fprintf(stderr, "INFO: User <%s> failed to authenticate\n", user);
+        settings.extensions.logger->log(EXTENSION_LOG_INFO, NULL,
+                             "INFO: User <%s> failed to authenticate",
+                              user);
     }
 
     return SASL_NOAUTHZ;
@@ -92,9 +95,11 @@ static int sasl_getconf(void *context, const char **path)
 
     if (settings.verbose) {
         if (*path != NULL) {
-            fprintf(stderr, "Reading configuration from: <%s>\n", *path);
+            settings.extensions.logger->log(EXTENSION_LOG_INFO, NULL,
+                           "Reading configuration from: <%s>", *path);
         } else {
-            fprintf(stderr, "Failed to locate a config path\n");
+            settings.extensions.logger->log(EXTENSION_LOG_INFO, NULL,
+                             "Failed to locate a config path");
         }
 
     }
@@ -106,34 +111,28 @@ static int sasl_getconf(void *context, const char **path)
 #ifdef ENABLE_SASL
 static int sasl_log(void *context, int level, const char *message)
 {
-    bool log = true;
+    EXTENSION_LOG_LEVEL lvl = EXTENSION_LOG_DETAIL;
 
     switch (level) {
     case SASL_LOG_NONE:
-        log = false;
         break;
     case SASL_LOG_PASS:
     case SASL_LOG_TRACE:
     case SASL_LOG_DEBUG:
     case SASL_LOG_NOTE:
-        if (settings.verbose < 2) {
-            log = false;
-        }
+        lvl = EXTENSION_LOG_DEBUG;
         break;
     case SASL_LOG_WARN:
     case SASL_LOG_FAIL:
-        if (settings.verbose < 1) {
-            log = false;
-        }
+        lvl = EXTENSION_LOG_INFO;
         break;
     default:
         /* This is an error */
         ;
     }
 
-    if (log) {
-        fprintf(stderr, "SASL (severity %d): %s\n", level, message);
-    }
+    settings.extensions.logger->log(lvl, NULL,
+                                    "SASL (severity %d): %s", level, message);
 
     return SASL_OK;
 }
@@ -160,9 +159,9 @@ void init_sasl(void) {
     memcached_sasl_pwdb = getenv("MEMCACHED_SASL_PWDB");
     if (memcached_sasl_pwdb == NULL) {
        if (settings.verbose) {
-          fprintf(stderr,
+           settings.extensions.logger->log(EXTENSION_LOG_INFO, NULL,
                   "INFO: MEMCACHED_SASL_PWDB not specified. "
-                  "Internal passwd database disabled\n");
+                  "Internal passwd database disabled.");
        }
        sasl_callbacks[0].id = SASL_CB_LIST_END;
        sasl_callbacks[0].proc = NULL;
@@ -170,11 +169,13 @@ void init_sasl(void) {
 #endif
 
     if (sasl_server_init(sasl_callbacks, "memcached") != SASL_OK) {
-        fprintf(stderr, "Error initializing sasl.\n");
+        settings.extensions.logger->log(EXTENSION_LOG_WARNING, NULL,
+                                        "Error initializing sasl.");
         exit(EXIT_FAILURE);
     } else {
         if (settings.verbose) {
-            fprintf(stderr, "Initialized SASL.\n");
+            settings.extensions.logger->log(EXTENSION_LOG_INFO, NULL,
+                                            "Initialized SASL.");
         }
     }
 }
diff --git a/daemon/thread.c b/daemon/thread.c
index 47efb09..9ac5d34 100644
--- a/daemon/thread.c
+++ b/daemon/thread.c
@@ -455,14 +455,6 @@ static void libevent_tap_process(int fd, short which, void *arg) {
     conn *pending_io[max_items];
     size_t n_items = list_to_array(pending_io, max_items, &me->pending_io);
 
-    if (n_items > 0 && settings.verbose > 1) {
-        fprintf(stderr, "Going to handle tap io for ");
-        for (size_t i = 0; i < n_items; ++i) {
-            fprintf(stderr, "%d ", pending_io[i]->sfd);
-        }
-        fprintf(stderr, "\n");
-    }
-
     UNLOCK_THREAD(me);
     for (size_t i = 0; i < n_items; ++i) {
         conn *c = pending_io[i];
diff --git a/engines/default_engine/assoc.c b/engines/default_engine/assoc.c
index 9073f2c..823adbc 100644
--- a/engines/default_engine/assoc.c
+++ b/engines/default_engine/assoc.c
@@ -94,7 +94,10 @@ static void assoc_expand(struct default_engine *engine) {
             (ret = pthread_create(&tid, &attr,
                                   assoc_maintenance_thread, engine)) != 0)
         {
-            fprintf(stderr, "Can't create thread: %s\n", strerror(ret));
+            EXTENSION_LOGGER_DESCRIPTOR *logger;
+            logger = (void*)engine->server.extension->get_extension(EXTENSION_LOGGER);
+            logger->log(EXTENSION_LOG_WARNING, NULL,
+                        "Can't create thread: %s\n", strerror(ret));
             engine->assoc.hashpower--;
             engine->assoc.expanding = false;
             free(engine->assoc.primary_hashtable);
@@ -183,7 +186,10 @@ static void *assoc_maintenance_thread(void *arg) {
                 engine->assoc.expanding = false;
                 free(engine->assoc.old_hashtable);
                 if (engine->config.verbose > 1) {
-                    fprintf(stderr, "Hash table expansion done\n");
+                    EXTENSION_LOGGER_DESCRIPTOR *logger;
+                    logger = (void*)engine->server.extension->get_extension(EXTENSION_LOGGER);
+                    logger->log(EXTENSION_LOG_INFO, NULL,
+                                "Hash table expansion done\n");
                 }
             }
         }
diff --git a/engines/default_engine/items.c b/engines/default_engine/items.c
index cd09058..19c0070 100644
--- a/engines/default_engine/items.c
+++ b/engines/default_engine/items.c
@@ -501,10 +501,15 @@ hash_item *do_item_get(struct default_engine *engine,
     int was_found = 0;
 
     if (engine->config.verbose > 2) {
+        EXTENSION_LOGGER_DESCRIPTOR *logger;
+        logger = (void*)engine->server.extension->get_extension(EXTENSION_LOGGER);
         if (it == NULL) {
-            fprintf(stderr, "> NOT FOUND %s", key);
+            logger->log(EXTENSION_LOG_DEBUG, NULL,
+                        "> NOT FOUND %s", key);
         } else {
-            fprintf(stderr, "> FOUND KEY %s", (const char*)item_get_key(it));
+            logger->log(EXTENSION_LOG_DEBUG, NULL,
+                        "> FOUND KEY %s",
+                        (const char*)item_get_key(it));
             was_found++;
         }
     }
@@ -517,7 +522,9 @@ hash_item *do_item_get(struct default_engine *engine,
     }
 
     if (it == NULL && was_found) {
-        fprintf(stderr, " -nuked by flush");
+        EXTENSION_LOGGER_DESCRIPTOR *logger;
+        logger = (void*)engine->server.extension->get_extension(EXTENSION_LOGGER);
+        logger->log(EXTENSION_LOG_DEBUG, NULL, " -nuked by flush");
         was_found--;
     }
 
@@ -527,7 +534,9 @@ hash_item *do_item_get(struct default_engine *engine,
     }
 
     if (it == NULL && was_found) {
-        fprintf(stderr, " -nuked by expire");
+        EXTENSION_LOGGER_DESCRIPTOR *logger;
+        logger = (void*)engine->server.extension->get_extension(EXTENSION_LOGGER);
+        logger->log(EXTENSION_LOG_DEBUG, NULL, " -nuked by expire");
         was_found--;
     }
 
@@ -537,9 +546,6 @@ hash_item *do_item_get(struct default_engine *engine,
         do_item_update(engine, it);
     }
 
-    if (engine->config.verbose > 2)
-        fprintf(stderr, "\n");
-
     return it;
 }
 
@@ -580,7 +586,9 @@ static ENGINE_ERROR_CODE do_store_item(struct default_engine *engine,
             stored = ENGINE_SUCCESS;
         } else {
             if (engine->config.verbose > 1) {
-                fprintf(stderr,
+                EXTENSION_LOGGER_DESCRIPTOR *logger;
+                logger = (void*)engine->server.extension->get_extension(EXTENSION_LOGGER);
+                logger->log(EXTENSION_LOG_INFO, NULL,
                         "CAS:  failure: expected %"PRIu64", got %"PRIu64"\n",
                         item_get_cas(old_it),
                         item_get_cas(it));
diff --git a/engines/default_engine/slabs.c b/engines/default_engine/slabs.c
index 4d69d0e..7dc0795 100644
--- a/engines/default_engine/slabs.c
+++ b/engines/default_engine/slabs.c
@@ -91,8 +91,12 @@ ENGINE_ERROR_CODE slabs_init(struct default_engine *engine,
         engine->slabs.slabclass[i].perslab = engine->config.item_size_max / engine->slabs.slabclass[i].size;
         size *= factor;
         if (engine->config.verbose > 1) {
-            fprintf(stderr, "slab class %3d: chunk size %9u perslab %7u\n",
-                    i, engine->slabs.slabclass[i].size, engine->slabs.slabclass[i].perslab);
+            EXTENSION_LOGGER_DESCRIPTOR *logger;
+            logger = (void*)engine->server.extension->get_extension(EXTENSION_LOGGER);
+            logger->log(EXTENSION_LOG_INFO, NULL,
+                        "slab class %3d: chunk size %9u perslab %7u\n",
+                        i, engine->slabs.slabclass[i].size,
+                        engine->slabs.slabclass[i].perslab);
         }
     }
 
@@ -100,8 +104,12 @@ ENGINE_ERROR_CODE slabs_init(struct default_engine *engine,
     engine->slabs.slabclass[engine->slabs.power_largest].size = engine->config.item_size_max;
     engine->slabs.slabclass[engine->slabs.power_largest].perslab = 1;
     if (engine->config.verbose > 1) {
-        fprintf(stderr, "slab class %3d: chunk size %9u perslab %7u\n",
-                i, engine->slabs.slabclass[i].size, engine->slabs.slabclass[i].perslab);
+        EXTENSION_LOGGER_DESCRIPTOR *logger;
+        logger = (void*)engine->server.extension->get_extension(EXTENSION_LOGGER);
+        logger->log(EXTENSION_LOG_INFO, NULL,
+                    "slab class %3d: chunk size %9u perslab %7u\n",
+                    i, engine->slabs.slabclass[i].size,
+                    engine->slabs.slabclass[i].perslab);
     }
 
     /* for the test suite:  faking of how much we've already malloc'd */
@@ -403,7 +411,10 @@ void slabs_adjust_mem_requested(struct default_engine *engine, unsigned int id,
     pthread_mutex_lock(&engine->slabs.lock);
     slabclass_t *p;
     if (id < POWER_SMALLEST || id > engine->slabs.power_largest) {
-        fprintf(stderr, "Internal error! Invalid slab class\n");
+        EXTENSION_LOGGER_DESCRIPTOR *logger;
+        logger = (void*)engine->server.extension->get_extension(EXTENSION_LOGGER);
+        logger->log(EXTENSION_LOG_WARNING, NULL,
+                    "Internal error! Invalid slab class\n");
         abort();
     }