ctdb/server/ctdb_logging.c

   1 /*
   2    ctdb logging code
   3
   4    Copyright (C) Andrew Tridgell  2008
   5
   6    This program is free software; you can redistribute it and/or modify
   7    it under the terms of the GNU General Public License as published by
   8    the Free Software Foundation; either version 3 of the License, or
   9    (at your option) any later version.
  10
  11    This program is distributed in the hope that it will be useful,
  12    but WITHOUT ANY WARRANTY; without even the implied warranty of
  13    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  14    GNU General Public License for more details.
  15
  16    You should have received a copy of the GNU General Public License
  17    along with this program; if not, see <http://www.gnu.org/licenses/>.
  18 */
  19
  20 #include "replace.h"
  21 #include "system/filesys.h"
  22 #include "system/network.h"
  23 #include "system/time.h"
  24
  25 #include <talloc.h>
  26 #include <tevent.h>
  27
  28 #include "lib/util/dlinklist.h"
  29 #include "lib/util/debug.h"
  30 #include "lib/util/blocking.h"
  31 #include "lib/util/sys_rw.h"
  32 #include "lib/util/time.h"
  33
  34 #include "ctdb_private.h"
  35 #include "ctdb_client.h"
  36
  37 #include "common/common.h"
  38 #include "common/logging.h"
  39
  40 struct ctdb_log_state {
  41         const char *prefix;
  42         int fd, pfd;
  43         char buf[1024];
  44         uint16_t buf_used;
  45         void (*logfn)(const char *, uint16_t, void *);
  46         void *logfn_private;
  47 };
  48
  49 /* Used by ctdb_set_child_logging() */
  50 static struct ctdb_log_state *log_state;
  51
  52 /* Initialise logging */
  53 bool ctdb_logging_init(TALLOC_CTX *mem_ctx, const char *logging,
  54                        const char *debug_level)
  55 {
  56         int ret;
  57
  58         log_state = talloc_zero(mem_ctx, struct ctdb_log_state);
  59         if (log_state == NULL) {
  60                 return false;
  61         }
  62
  63         ret = logging_init(mem_ctx, logging, debug_level, "ctdbd");
  64         if (ret != 0) {
  65                 return false;
  66         }
  67
  68         return true;
  69 }
  70
  71 /* Note that do_debug always uses the global log state. */
  72 static void write_to_log(struct ctdb_log_state *log,
  73                          const char *buf, unsigned int len)
  74 {
  75         if (script_log_level <= DEBUGLEVEL) {
  76                 if (log != NULL && log->prefix != NULL) {
  77                         dbgtext("%s: %*.*s\n", log->prefix, len, len, buf);
  78                 } else {
  79                         dbgtext("%*.*s\n", len, len, buf);
  80                 }
  81                 /* log it in the eventsystem as well */
  82                 if (log && log->logfn) {
  83                         log->logfn(log->buf, len, log->logfn_private);
  84                 }
  85         }
  86 }
  87
  88 /*
  89   called when log data comes in from a child process
  90  */
  91 static void ctdb_child_log_handler(struct tevent_context *ev,
  92                                    struct tevent_fd *fde,
  93                                    uint16_t flags, void *private)
  94 {
  95         struct ctdb_log_state *log = talloc_get_type(private, struct ctdb_log_state);
  96         char *p;
  97         int n;
  98
  99         if (!(flags & TEVENT_FD_READ)) {
 100                 return;
 101         }
 102
 103         n = sys_read(log->pfd, &log->buf[log->buf_used],
 104                  sizeof(log->buf) - log->buf_used);
 105         if (n > 0) {
 106                 log->buf_used += n;
 107         } else if (n == 0) {
 108                 if (log != log_state) {
 109                         talloc_free(log);
 110                 }
 111                 return;
 112         }
 113
 114         while (log->buf_used > 0 &&
 115                (p = memchr(log->buf, '\n', log->buf_used)) != NULL) {
 116                 int n1 = (p - log->buf)+1;
 117                 int n2 = n1 - 1;
 118                 /* swallow \r from child processes */
 119                 if (n2 > 0 && log->buf[n2-1] == '\r') {
 120                         n2--;
 121                 }
 122                 write_to_log(log, log->buf, n2);
 123                 memmove(log->buf, p+1, sizeof(log->buf) - n1);
 124                 log->buf_used -= n1;
 125         }
 126
 127         /* the buffer could have completely filled - unfortunately we have
 128            no choice but to dump it out straight away */
 129         if (log->buf_used == sizeof(log->buf)) {
 130                 write_to_log(log, log->buf, log->buf_used);
 131                 log->buf_used = 0;
 132         }
 133 }
 134
 135 static int log_context_destructor(struct ctdb_log_state *log)
 136 {
 137         /* Flush buffer in case it wasn't \n-terminated. */
 138         if (log->buf_used > 0) {
 139                 write_to_log(log, log->buf, log->buf_used);
 140         }
 141         return 0;
 142 }
 143
 144 /*
 145  * vfork + exec, redirecting child output to logging and specified callback.
 146  */
 147 struct ctdb_log_state *ctdb_vfork_with_logging(TALLOC_CTX *mem_ctx,
 148                                                struct ctdb_context *ctdb,
 149                                                const char *log_prefix,
 150                                                const char *helper,
 151                                                int helper_argc,
 152                                                const char **helper_argv,
 153                                                void (*logfn)(const char *, uint16_t, void *),
 154                                                void *logfn_private, pid_t *pid)
 155 {
 156         int p[2];
 157         struct ctdb_log_state *log;
 158         struct tevent_fd *fde;
 159         char **argv;
 160         int i;
 161         struct timeval before;
 162         double delta_t;
 163
 164         log = talloc_zero(mem_ctx, struct ctdb_log_state);
 165         CTDB_NO_MEMORY_NULL(ctdb, log);
 166
 167         log->prefix = log_prefix;
 168         log->logfn = logfn;
 169         log->logfn_private = logfn_private;
 170
 171         if (pipe(p) != 0) {
 172                 DEBUG(DEBUG_ERR, (__location__ " Failed to setup pipe for child logging:"
 173                                 " %s\n", strerror(errno)));
 174                 goto free_log;
 175         }
 176
 177         argv = talloc_array(mem_ctx, char *, helper_argc + 2);
 178         if (argv == NULL) {
 179                 DEBUG(DEBUG_ERR, (__location__ "Failed to allocate memory for helper\n"));
 180                 goto free_log;
 181         }
 182         argv[0] = discard_const(helper);
 183         argv[1] = talloc_asprintf(argv, "%d", p[1]);
 184         if (argv[1] == NULL) {
 185                 DEBUG(DEBUG_ERR, (__location__ "Failed to allocate memory for helper\n"));
 186                 talloc_free(argv);
 187                 goto free_log;
 188         }
 189
 190         for (i=0; i<helper_argc; i++) {
 191                 argv[i+2] = discard_const(helper_argv[i]);
 192         }
 193
 194         before = timeval_current();
 195
 196         *pid = vfork();
 197         if (*pid == 0) {
 198                 execv(helper, argv);
 199                 _exit(1);
 200         }
 201         close(p[1]);
 202
 203         if (*pid < 0) {
 204                 DEBUG(DEBUG_ERR, (__location__ "vfork failed for helper process\n"));
 205                 close(p[0]);
 206                 goto free_log;
 207         }
 208
 209         delta_t = timeval_elapsed(&before);
 210         if (delta_t > 3.0) {
 211                 DEBUG(DEBUG_WARNING, ("vfork() took %lf seconds\n", delta_t));
 212         }
 213
 214         ctdb_track_child(ctdb, *pid);
 215
 216         log->pfd = p[0];
 217         set_close_on_exec(log->pfd);
 218         talloc_set_destructor(log, log_context_destructor);
 219         fde = tevent_add_fd(ctdb->ev, log, log->pfd, TEVENT_FD_READ,
 220                             ctdb_child_log_handler, log);
 221         tevent_fd_set_auto_close(fde);
 222
 223         return log;
 224
 225 free_log:
 226         talloc_free(log);
 227         return NULL;
 228 }
 229
 230
 231 /*
 232   setup for logging of child process stdout
 233 */
 234 int ctdb_set_child_logging(struct ctdb_context *ctdb)
 235 {
 236         int p[2];
 237         int old_stdout, old_stderr;
 238         struct tevent_fd *fde;
 239
 240         /* setup a pipe to catch IO from subprocesses */
 241         if (pipe(p) != 0) {
 242                 DEBUG(DEBUG_ERR,(__location__ " Failed to setup for child logging pipe\n"));
 243                 return -1;
 244         }
 245
 246         /* We'll fail if stderr/stdout not already open; it's simpler. */
 247         old_stdout = dup(STDOUT_FILENO);
 248         if (old_stdout < 0) {
 249                 DEBUG(DEBUG_ERR, ("Failed to dup stdout for child logging\n"));
 250                 return -1;
 251         }
 252         old_stderr = dup(STDERR_FILENO);
 253         if (old_stderr < 0) {
 254                 DEBUG(DEBUG_ERR, ("Failed to dup stderr for child logging\n"));
 255                 close(old_stdout);
 256                 return -1;
 257         }
 258         if (dup2(p[1], STDOUT_FILENO) < 0 || dup2(p[1], STDERR_FILENO) < 0) {
 259                 int saved_errno = errno;
 260                 dup2(old_stdout, STDOUT_FILENO);
 261                 dup2(old_stderr, STDERR_FILENO);
 262                 close(old_stdout);
 263                 close(old_stderr);
 264                 close(p[0]);
 265                 close(p[1]);
 266                 errno = saved_errno;
 267
 268                 printf(__location__ " dup2 failed: %s\n",
 269                         strerror(errno));
 270                 return -1;
 271         }
 272         close(p[1]);
 273         close(old_stdout);
 274         close(old_stderr);
 275
 276         fde = tevent_add_fd(ctdb->ev, log_state, p[0], TEVENT_FD_READ,
 277                             ctdb_child_log_handler, log_state);
 278         tevent_fd_set_auto_close(fde);
 279
 280         log_state->pfd = p[0];
 281
 282         DEBUG(DEBUG_DEBUG, (__location__ " Created PIPE FD:%d for logging\n", p[0]));
 283
 284         return 0;
 285 }