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