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/syslog.h"
  24 #include "system/time.h"
  25
  26 #include <talloc.h>
  27 #include <tevent.h>
  28
  29 #include "lib/util/dlinklist.h"
  30 #include "lib/util/debug.h"
  31 #include "lib/util/blocking.h"
  32
  33 #include "ctdb_private.h"
  34 #include "ctdb_client.h"
  35
  36 #include "common/system.h"
  37 #include "common/common.h"
  38 #include "common/logging.h"
  39
  40 const char *debug_extra = "";
  41
  42 struct ctdb_log_backend {
  43         struct ctdb_log_backend *prev, *next;
  44         const char *prefix;
  45         ctdb_log_setup_fn_t setup;
  46 };
  47
  48 struct ctdb_log_state {
  49         const char *prefix;
  50         int fd, pfd;
  51         char buf[1024];
  52         uint16_t buf_used;
  53         void (*logfn)(const char *, uint16_t, void *);
  54         void *logfn_private;
  55         struct ctdb_log_backend *backends;
  56 };
  57
  58 /* Used by ctdb_set_child_logging() */
  59 static struct ctdb_log_state *log_state;
  60
  61 void ctdb_log_register_backend(const char *prefix, ctdb_log_setup_fn_t setup)
  62 {
  63         struct ctdb_log_backend *b;
  64
  65         b = talloc_zero(log_state, struct ctdb_log_backend);
  66         if (b == NULL) {
  67                 printf("Failed to register backend \"%s\" - no memory\n",
  68                        prefix);
  69                 return;
  70         }
  71
  72         b->prefix = prefix;
  73         b->setup = setup;
  74
  75         DLIST_ADD_END(log_state->backends, b);
  76 }
  77
  78
  79 /* Initialise logging */
  80 bool ctdb_logging_init(TALLOC_CTX *mem_ctx, const char *logging)
  81 {
  82         struct ctdb_log_backend *b;
  83         int ret;
  84
  85         log_state = talloc_zero(mem_ctx, struct ctdb_log_state);
  86         if (log_state == NULL) {
  87                 printf("talloc_zero failed\n");
  88                 abort();
  89         }
  90
  91         ctdb_log_init_file();
  92         ctdb_log_init_syslog();
  93
  94         for (b = log_state->backends; b != NULL; b = b->next) {
  95                 size_t l = strlen(b->prefix);
  96                 /* Exact match with prefix or prefix followed by ':' */
  97                 if (strncmp(b->prefix, logging, l) == 0 &&
  98                     (logging[l] == '\0' || logging[l] == ':')) {
  99                         ret = b->setup(mem_ctx, logging, "ctdbd");
 100                         if (ret == 0) {
 101                                 return true;
 102                         }
 103                         printf("Log init for \"%s\" failed with \"%s\"\n",
 104                                logging, strerror(ret));
 105                         return false;
 106                 }
 107         }
 108
 109         printf("Unable to find log backend for \"%s\"\n", logging);
 110         return false;
 111 }
 112
 113 /* Note that do_debug always uses the global log state. */
 114 static void write_to_log(struct ctdb_log_state *log,
 115                          const char *buf, unsigned int len)
 116 {
 117         if (script_log_level <= DEBUGLEVEL) {
 118                 if (log != NULL && log->prefix != NULL) {
 119                         dbgtext("%s: %*.*s\n", log->prefix, len, len, buf);
 120                 } else {
 121                         dbgtext("%*.*s\n", len, len, buf);
 122                 }
 123                 /* log it in the eventsystem as well */
 124                 if (log && log->logfn) {
 125                         log->logfn(log->buf, len, log->logfn_private);
 126                 }
 127         }
 128 }
 129
 130 /*
 131   called when log data comes in from a child process
 132  */
 133 static void ctdb_child_log_handler(struct tevent_context *ev,
 134                                    struct tevent_fd *fde,
 135                                    uint16_t flags, void *private)
 136 {
 137         struct ctdb_log_state *log = talloc_get_type(private, struct ctdb_log_state);
 138         char *p;
 139         int n;
 140
 141         if (!(flags & TEVENT_FD_READ)) {
 142                 return;
 143         }
 144
 145         n = sys_read(log->pfd, &log->buf[log->buf_used],
 146                  sizeof(log->buf) - log->buf_used);
 147         if (n > 0) {
 148                 log->buf_used += n;
 149         } else if (n == 0) {
 150                 if (log != log_state) {
 151                         talloc_free(log);
 152                 }
 153                 return;
 154         }
 155
 156         while (log->buf_used > 0 &&
 157                (p = memchr(log->buf, '\n', log->buf_used)) != NULL) {
 158                 int n1 = (p - log->buf)+1;
 159                 int n2 = n1 - 1;
 160                 /* swallow \r from child processes */
 161                 if (n2 > 0 && log->buf[n2-1] == '\r') {
 162                         n2--;
 163                 }
 164                 write_to_log(log, log->buf, n2);
 165                 memmove(log->buf, p+1, sizeof(log->buf) - n1);
 166                 log->buf_used -= n1;
 167         }
 168
 169         /* the buffer could have completely filled - unfortunately we have
 170            no choice but to dump it out straight away */
 171         if (log->buf_used == sizeof(log->buf)) {
 172                 write_to_log(log, log->buf, log->buf_used);
 173                 log->buf_used = 0;
 174         }
 175 }
 176
 177 static int log_context_destructor(struct ctdb_log_state *log)
 178 {
 179         /* Flush buffer in case it wasn't \n-terminated. */
 180         if (log->buf_used > 0) {
 181                 write_to_log(log, log->buf, log->buf_used);
 182         }
 183         return 0;
 184 }
 185
 186 /*
 187  * vfork + exec, redirecting child output to logging and specified callback.
 188  */
 189 struct ctdb_log_state *ctdb_vfork_with_logging(TALLOC_CTX *mem_ctx,
 190                                                struct ctdb_context *ctdb,
 191                                                const char *log_prefix,
 192                                                const char *helper,
 193                                                int helper_argc,
 194                                                const char **helper_argv,
 195                                                void (*logfn)(const char *, uint16_t, void *),
 196                                                void *logfn_private, pid_t *pid)
 197 {
 198         int p[2];
 199         struct ctdb_log_state *log;
 200         struct tevent_fd *fde;
 201         char **argv;
 202         int i;
 203
 204         log = talloc_zero(mem_ctx, struct ctdb_log_state);
 205         CTDB_NO_MEMORY_NULL(ctdb, log);
 206
 207         log->prefix = log_prefix;
 208         log->logfn = logfn;
 209         log->logfn_private = logfn_private;
 210
 211         if (pipe(p) != 0) {
 212                 DEBUG(DEBUG_ERR, (__location__ " Failed to setup pipe for child logging\n"));
 213                 goto free_log;
 214         }
 215
 216         argv = talloc_array(mem_ctx, char *, helper_argc + 2);
 217         if (argv == NULL) {
 218                 DEBUG(DEBUG_ERR, (__location__ "Failed to allocate memory for helper\n"));
 219                 goto free_log;
 220         }
 221         argv[0] = discard_const(helper);
 222         argv[1] = talloc_asprintf(argv, "%d", p[1]);
 223         if (argv[1] == NULL) {
 224                 DEBUG(DEBUG_ERR, (__location__ "Failed to allocate memory for helper\n"));
 225                 talloc_free(argv);
 226                 goto free_log;
 227         }
 228
 229         for (i=0; i<helper_argc; i++) {
 230                 argv[i+2] = discard_const(helper_argv[i]);
 231         }
 232
 233         *pid = vfork();
 234         if (*pid == 0) {
 235                 execv(helper, argv);
 236                 _exit(1);
 237         }
 238         close(p[1]);
 239
 240         if (*pid < 0) {
 241                 DEBUG(DEBUG_ERR, (__location__ "vfork failed for helper process\n"));
 242                 close(p[0]);
 243                 goto free_log;
 244         }
 245
 246         ctdb_track_child(ctdb, *pid);
 247
 248         log->pfd = p[0];
 249         set_close_on_exec(log->pfd);
 250         talloc_set_destructor(log, log_context_destructor);
 251         fde = tevent_add_fd(ctdb->ev, log, log->pfd, TEVENT_FD_READ,
 252                             ctdb_child_log_handler, log);
 253         tevent_fd_set_auto_close(fde);
 254
 255         return log;
 256
 257 free_log:
 258         talloc_free(log);
 259         return NULL;
 260 }
 261
 262
 263 /*
 264   setup for logging of child process stdout
 265 */
 266 int ctdb_set_child_logging(struct ctdb_context *ctdb)
 267 {
 268         int p[2];
 269         int old_stdout, old_stderr;
 270         struct tevent_fd *fde;
 271
 272         if (log_state->fd == STDOUT_FILENO) {
 273                 /* not needed for stdout logging */
 274                 return 0;
 275         }
 276
 277         /* setup a pipe to catch IO from subprocesses */
 278         if (pipe(p) != 0) {
 279                 DEBUG(DEBUG_ERR,(__location__ " Failed to setup for child logging pipe\n"));
 280                 return -1;
 281         }
 282
 283         /* We'll fail if stderr/stdout not already open; it's simpler. */
 284         old_stdout = dup(STDOUT_FILENO);
 285         old_stderr = dup(STDERR_FILENO);
 286         if (old_stdout < 0 || old_stderr < 0) {
 287                 DEBUG(DEBUG_ERR, ("Failed to dup stdout/stderr for child logging\n"));
 288                 return -1;
 289         }
 290         if (dup2(p[1], STDOUT_FILENO) < 0 || dup2(p[1], STDERR_FILENO) < 0) {
 291                 int saved_errno = errno;
 292                 dup2(old_stdout, STDOUT_FILENO);
 293                 dup2(old_stderr, STDERR_FILENO);
 294                 close(old_stdout);
 295                 close(old_stderr);
 296                 close(p[0]);
 297                 close(p[1]);
 298                 errno = saved_errno;
 299
 300                 printf(__location__ " dup2 failed: %s\n",
 301                         strerror(errno));
 302                 return -1;
 303         }
 304         close(p[1]);
 305         close(old_stdout);
 306         close(old_stderr);
 307
 308         fde = tevent_add_fd(ctdb->ev, log_state, p[0], TEVENT_FD_READ,
 309                             ctdb_child_log_handler, log_state);
 310         tevent_fd_set_auto_close(fde);
 311
 312         log_state->pfd = p[0];
 313
 314         DEBUG(DEBUG_DEBUG, (__location__ " Created PIPE FD:%d for logging\n", p[0]));
 315
 316         return 0;
 317 }
 318
 319
 320 /*
 321  * set up a log handler to catch logging from TEVENT
 322  */
 323 static void ctdb_tevent_logging(void *private_data,
 324                                 enum tevent_debug_level level,
 325                                 const char *fmt,
 326                                 va_list ap) PRINTF_ATTRIBUTE(3, 0);
 327 static void ctdb_tevent_logging(void *private_data,
 328                                 enum tevent_debug_level level,
 329                                 const char *fmt,
 330                                 va_list ap)
 331 {
 332         enum debug_level lvl = DEBUG_CRIT;
 333
 334         switch (level) {
 335         case TEVENT_DEBUG_FATAL:
 336                 lvl = DEBUG_CRIT;
 337                 break;
 338         case TEVENT_DEBUG_ERROR:
 339                 lvl = DEBUG_ERR;
 340                 break;
 341         case TEVENT_DEBUG_WARNING:
 342                 lvl = DEBUG_WARNING;
 343                 break;
 344         case TEVENT_DEBUG_TRACE:
 345                 lvl = DEBUG_DEBUG;
 346                 break;
 347         }
 348
 349         if (lvl <= DEBUGLEVEL) {
 350                 dbgtext_va(fmt, ap);
 351         }
 352 }
 353
 354 int ctdb_init_tevent_logging(struct ctdb_context *ctdb)
 355 {
 356         int ret;
 357
 358         ret = tevent_set_debug(ctdb->ev,
 359                         ctdb_tevent_logging,
 360                         ctdb);
 361         return ret;
 362 }