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