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
  27 struct syslog_message {
  28         uint32_t level;
  29         uint32_t len;
  30         char message[1];
  31 };
  32
  33
  34 struct ctdb_syslog_state {
  35         int syslog_fd;
  36         int fd[2];
  37 };
  38
  39 static int syslogd_is_started = 0;
  40
  41
  42 /* called when child is finished
  43  * this is for the syslog daemon, we can not use DEBUG here
  44  */
  45 static void ctdb_syslog_handler(struct event_context *ev, struct fd_event *fde,
  46                                       uint16_t flags, void *p)
  47 {
  48         struct ctdb_syslog_state *state = talloc_get_type(p, struct ctdb_syslog_state);
  49
  50         int count;
  51         char str[65536];
  52         struct syslog_message *msg;
  53
  54         if (state == NULL) {
  55                 return;
  56         }
  57
  58         count = recv(state->syslog_fd, str, sizeof(str), 0);
  59         if (count < sizeof(struct syslog_message)) {
  60                 return;
  61         }
  62         msg = (struct syslog_message *)str;
  63
  64         syslog(msg->level, "%s", msg->message);
  65 }
  66
  67
  68 /* called when the pipe from the main daemon has closed
  69  * this is for the syslog daemon, we can not use DEBUG here
  70  */
  71 static void ctdb_syslog_terminate_handler(struct event_context *ev, struct fd_event *fde,
  72                                       uint16_t flags, void *p)
  73 {
  74         syslog(LOG_ERR, "Shutting down SYSLOG daemon with pid:%d", (int)getpid());
  75         _exit(0);
  76 }
  77
  78
  79
  80 /*
  81  * this is for the syslog daemon, we can not use DEBUG here
  82  */
  83 int start_syslog_daemon(struct ctdb_context *ctdb)
  84 {
  85         struct sockaddr_in syslog_sin;
  86         struct ctdb_syslog_state *state;
  87         struct tevent_fd *fde;
  88         int startup_fd[2];
  89         int ret = -1;
  90
  91         state = talloc(ctdb, struct ctdb_syslog_state);
  92         CTDB_NO_MEMORY(ctdb, state);
  93
  94         if (pipe(state->fd) != 0) {
  95                 printf("Failed to create syslog pipe\n");
  96                 talloc_free(state);
  97                 return -1;
  98         }
  99
 100         if (pipe(startup_fd) != 0) {
 101                 printf("Failed to create syslog startup pipe\n");
 102                 close(state->fd[0]);
 103                 close(state->fd[1]);
 104                 talloc_free(state);
 105                 return -1;
 106         }
 107
 108         ctdb->syslogd_pid = ctdb_fork(ctdb);
 109         if (ctdb->syslogd_pid == (pid_t)-1) {
 110                 printf("Failed to create syslog child process\n");
 111                 close(state->fd[0]);
 112                 close(state->fd[1]);
 113                 close(startup_fd[0]);
 114                 close(startup_fd[1]);
 115                 talloc_free(state);
 116                 return -1;
 117         }
 118
 119         if (ctdb->syslogd_pid != 0) {
 120                 ssize_t n;
 121                 int dummy;
 122
 123                 DEBUG(DEBUG_ERR,("Starting SYSLOG child process with pid:%d\n", (int)ctdb->syslogd_pid));
 124
 125                 close(state->fd[1]);
 126                 set_close_on_exec(state->fd[0]);
 127
 128                 close(startup_fd[1]);
 129                 n = read(startup_fd[0], &dummy, sizeof(dummy));
 130                 close(startup_fd[0]);
 131                 if (n < sizeof(dummy)) {
 132                         return -1;
 133                 }
 134
 135                 syslogd_is_started = 1;
 136                 return 0;
 137         }
 138
 139         debug_extra = talloc_asprintf(NULL, "syslogd:");
 140         talloc_free(ctdb->ev);
 141         ctdb->ev = event_context_init(NULL);
 142
 143         syslog(LOG_ERR, "Starting SYSLOG daemon with pid:%d", (int)getpid());
 144         ctdb_set_process_name("ctdb_syslogd");
 145
 146         close(state->fd[0]);
 147         close(startup_fd[0]);
 148         set_close_on_exec(state->fd[1]);
 149         set_close_on_exec(startup_fd[1]);
 150         fde = event_add_fd(ctdb->ev, state, state->fd[1], EVENT_FD_READ,
 151                      ctdb_syslog_terminate_handler, state);
 152         tevent_fd_set_auto_close(fde);
 153
 154         state->syslog_fd = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);
 155         if (state->syslog_fd == -1) {
 156                 printf("Failed to create syslog socket\n");
 157                 close(startup_fd[1]);
 158                 return ret;
 159         }
 160
 161         set_close_on_exec(state->syslog_fd);
 162
 163         syslog_sin.sin_family = AF_INET;
 164         syslog_sin.sin_port   = htons(CTDB_PORT);
 165         syslog_sin.sin_addr.s_addr = htonl(INADDR_LOOPBACK);
 166
 167         if (bind(state->syslog_fd, (struct sockaddr *)&syslog_sin,
 168                  sizeof(syslog_sin)) == -1)
 169         {
 170                 printf("syslog daemon failed to bind to socket. errno:%d(%s)\n", errno, strerror(errno));
 171                 close(startup_fd[1]);
 172                 _exit(10);
 173         }
 174
 175
 176         fde = event_add_fd(ctdb->ev, state, state->syslog_fd, EVENT_FD_READ,
 177                      ctdb_syslog_handler, state);
 178         tevent_fd_set_auto_close(fde);
 179
 180         /* Tell parent that we're up */
 181         ret = 0;
 182         write(startup_fd[1], &ret, sizeof(ret));
 183         close(startup_fd[1]);
 184
 185         event_loop_wait(ctdb->ev);
 186
 187         /* this should not happen */
 188         _exit(10);
 189 }
 190
 191 struct ctdb_log_state {
 192         struct ctdb_context *ctdb;
 193         const char *prefix;
 194         int fd, pfd;
 195         char buf[1024];
 196         uint16_t buf_used;
 197         bool use_syslog;
 198         void (*logfn)(const char *, uint16_t, void *);
 199         void *logfn_private;
 200 };
 201
 202 /* we need this global to keep the DEBUG() syntax */
 203 static struct ctdb_log_state *log_state;
 204
 205 /*
 206   syslog logging function
 207  */
 208 static void ctdb_syslog_log(const char *format, va_list ap)
 209 {
 210         struct syslog_message *msg;
 211         int level = LOG_DEBUG;
 212         char *s = NULL;
 213         int len, ret;
 214         int syslog_fd;
 215         struct sockaddr_in syslog_sin;
 216
 217         ret = vasprintf(&s, format, ap);
 218         if (ret == -1) {
 219                 return;
 220         }
 221
 222         switch (this_log_level) {
 223         case DEBUG_EMERG:
 224                 level = LOG_EMERG;
 225                 break;
 226         case DEBUG_ALERT:
 227                 level = LOG_ALERT;
 228                 break;
 229         case DEBUG_CRIT:
 230                 level = LOG_CRIT;
 231                 break;
 232         case DEBUG_ERR:
 233                 level = LOG_ERR;
 234                 break;
 235         case DEBUG_WARNING:
 236                 level = LOG_WARNING;
 237                 break;
 238         case DEBUG_NOTICE:
 239                 level = LOG_NOTICE;
 240                 break;
 241         case DEBUG_INFO:
 242                 level = LOG_INFO;
 243                 break;
 244         default:
 245                 level = LOG_DEBUG;
 246                 break;
 247         }
 248
 249         len = offsetof(struct syslog_message, message) + strlen(debug_extra) + strlen(s) + 1;
 250         msg = malloc(len);
 251         if (msg == NULL) {
 252                 free(s);
 253                 return;
 254         }
 255         msg->level = level;
 256         msg->len   = strlen(debug_extra) + strlen(s);
 257         strcpy(msg->message, debug_extra);
 258         strcat(msg->message, s);
 259
 260         if (syslogd_is_started == 0) {
 261                 syslog(msg->level, "%s", msg->message);
 262         } else {
 263                 syslog_fd = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);
 264                 if (syslog_fd == -1) {
 265                         printf("Failed to create syslog socket\n");
 266                         free(s);
 267                         free(msg);
 268                         return;
 269                 }
 270
 271                 syslog_sin.sin_family = AF_INET;
 272                 syslog_sin.sin_port   = htons(CTDB_PORT);
 273                 syslog_sin.sin_addr.s_addr = htonl(INADDR_LOOPBACK);
 274
 275                 ret = sendto(syslog_fd, msg, len, 0,
 276                              (struct sockaddr *)&syslog_sin,
 277                              sizeof(syslog_sin));
 278                 /* no point in checking here since we cant log an error */
 279
 280                 close(syslog_fd);
 281         }
 282
 283         free(s);
 284         free(msg);
 285 }
 286
 287
 288 /*
 289   log file logging function
 290  */
 291 static void ctdb_logfile_log(const char *format, va_list ap)
 292 {
 293         struct timeval t;
 294         char *s = NULL;
 295         struct tm *tm;
 296         char tbuf[100];
 297         char *s2 = NULL;
 298         int ret;
 299
 300         ret = vasprintf(&s, format, ap);
 301         if (ret == -1) {
 302                 const char *errstr = "vasprintf failed\n";
 303
 304                 write(log_state->fd, errstr, strlen(errstr));
 305                 return;
 306         }
 307
 308         t = timeval_current();
 309         tm = localtime(&t.tv_sec);
 310
 311         strftime(tbuf,sizeof(tbuf)-1,"%Y/%m/%d %H:%M:%S", tm);
 312
 313         ret = asprintf(&s2, "%s.%06u [%s%5u]: %s",
 314                        tbuf, (unsigned)t.tv_usec,
 315                        debug_extra, (unsigned)getpid(), s);
 316         free(s);
 317         if (ret == -1) {
 318                 const char *errstr = "asprintf failed\n";
 319                 write(log_state->fd, errstr, strlen(errstr));
 320                 return;
 321         }
 322         if (s2) {
 323                 write(log_state->fd, s2, strlen(s2));
 324                 free(s2);
 325         }
 326 }
 327
 328 static void ctdb_logfile_log_add(const char *format, va_list ap)
 329 {
 330         char *s = NULL;
 331         int ret;
 332
 333         ret = vasprintf(&s, format, ap);
 334         if (ret == -1) {
 335                 const char *errstr = "vasprintf failed\n";
 336
 337                 write(log_state->fd, errstr, strlen(errstr));
 338                 return;
 339         }
 340
 341         if (s) {
 342                 write(log_state->fd, s, strlen(s));
 343                 free(s);
 344         }
 345 }
 346
 347
 348
 349 /*
 350   choose the logfile location
 351 */
 352 int ctdb_set_logfile(struct ctdb_context *ctdb, const char *logfile, bool use_syslog)
 353 {
 354         int ret;
 355
 356         ctdb->log = talloc_zero(ctdb, struct ctdb_log_state);
 357         if (ctdb->log == NULL) {
 358                 printf("talloc_zero failed\n");
 359                 abort();
 360         }
 361
 362         ctdb->log->ctdb = ctdb;
 363         log_state = ctdb->log;
 364
 365         if (use_syslog) {
 366                 do_debug_v = ctdb_syslog_log;
 367                 do_debug_add_v = ctdb_syslog_log;
 368                 ctdb->log->use_syslog = true;
 369         } else if (logfile == NULL || strcmp(logfile, "-") == 0) {
 370                 do_debug_v = ctdb_logfile_log;
 371                 do_debug_add_v = ctdb_logfile_log_add;
 372                 ctdb->log->fd = 1;
 373                 /* also catch stderr of subcommands to stdout */
 374                 ret = dup2(1, 2);
 375                 if (ret == -1) {
 376                         printf("dup2 failed: %s\n", strerror(errno));
 377                         abort();
 378                 }
 379         } else {
 380                 do_debug_v = ctdb_logfile_log;
 381                 do_debug_add_v = ctdb_logfile_log_add;
 382
 383                 ctdb->log->fd = open(logfile, O_WRONLY|O_APPEND|O_CREAT, 0666);
 384                 if (ctdb->log->fd == -1) {
 385                         printf("Failed to open logfile %s\n", logfile);
 386                         abort();
 387                 }
 388         }
 389
 390         return 0;
 391 }
 392
 393 /* Note that do_debug always uses the global log state. */
 394 static void write_to_log(struct ctdb_log_state *log,
 395                          const char *buf, unsigned int len)
 396 {
 397         if (script_log_level <= LogLevel) {
 398                 if (log != NULL && log->prefix != NULL) {
 399                         do_debug("%s: %*.*s\n", log->prefix, len, len, buf);
 400                 } else {
 401                         do_debug("%*.*s\n", len, len, buf);
 402                 }
 403                 /* log it in the eventsystem as well */
 404                 if (log->logfn)
 405                         log->logfn(log->buf, len, log->logfn_private);
 406         }
 407 }
 408
 409 /*
 410   called when log data comes in from a child process
 411  */
 412 static void ctdb_log_handler(struct event_context *ev, struct fd_event *fde,
 413                              uint16_t flags, void *private)
 414 {
 415         struct ctdb_log_state *log = talloc_get_type(private, struct ctdb_log_state);
 416         char *p;
 417         int n;
 418
 419         if (!(flags & EVENT_FD_READ)) {
 420                 return;
 421         }
 422
 423         n = read(log->pfd, &log->buf[log->buf_used],
 424                  sizeof(log->buf) - log->buf_used);
 425         if (n > 0) {
 426                 log->buf_used += n;
 427         } else if (n == 0) {
 428                 if (log != log_state) {
 429                         talloc_free(log);
 430                 }
 431                 return;
 432         }
 433
 434         this_log_level = script_log_level;
 435
 436         while (log->buf_used > 0 &&
 437                (p = memchr(log->buf, '\n', log->buf_used)) != NULL) {
 438                 int n1 = (p - log->buf)+1;
 439                 int n2 = n1 - 1;
 440                 /* swallow \r from child processes */
 441                 if (n2 > 0 && log->buf[n2-1] == '\r') {
 442                         n2--;
 443                 }
 444                 write_to_log(log, log->buf, n2);
 445                 memmove(log->buf, p+1, sizeof(log->buf) - n1);
 446                 log->buf_used -= n1;
 447         }
 448
 449         /* the buffer could have completely filled - unfortunately we have
 450            no choice but to dump it out straight away */
 451         if (log->buf_used == sizeof(log->buf)) {
 452                 write_to_log(log, log->buf, log->buf_used);
 453                 log->buf_used = 0;
 454         }
 455 }
 456
 457 static int log_context_destructor(struct ctdb_log_state *log)
 458 {
 459         /* Flush buffer in case it wasn't \n-terminated. */
 460         if (log->buf_used > 0) {
 461                 this_log_level = script_log_level;
 462                 write_to_log(log, log->buf, log->buf_used);
 463         }
 464         return 0;
 465 }
 466
 467 /*
 468    fork(), redirecting child output to logging and specified callback.
 469 */
 470 struct ctdb_log_state *ctdb_fork_with_logging(TALLOC_CTX *mem_ctx,
 471                                               struct ctdb_context *ctdb,
 472                                               const char *log_prefix,
 473                                               void (*logfn)(const char *, uint16_t, void *),
 474                                               void *logfn_private, pid_t *pid)
 475 {
 476         int p[2];
 477         struct ctdb_log_state *log;
 478         struct tevent_fd *fde;
 479
 480         log = talloc_zero(mem_ctx, struct ctdb_log_state);
 481         CTDB_NO_MEMORY_NULL(ctdb, log);
 482         log->ctdb = ctdb;
 483         log->prefix = log_prefix;
 484         log->logfn = logfn;
 485         log->logfn_private = (void *)logfn_private;
 486
 487         if (pipe(p) != 0) {
 488                 DEBUG(DEBUG_ERR,(__location__ " Failed to setup for child logging pipe\n"));
 489                 goto free_log;
 490         }
 491
 492         *pid = ctdb_fork(ctdb);
 493
 494         /* Child? */
 495         if (*pid == 0) {
 496                 close(STDOUT_FILENO);
 497                 close(STDERR_FILENO);
 498                 dup2(p[1], STDOUT_FILENO);
 499                 dup2(p[1], STDERR_FILENO);
 500                 close(p[0]);
 501                 close(p[1]);
 502                 return log;
 503         }
 504         close(p[1]);
 505
 506         /* We failed? */
 507         if (*pid < 0) {
 508                 DEBUG(DEBUG_ERR, (__location__ " fork failed for child process\n"));
 509                 close(p[0]);
 510                 goto free_log;
 511         }
 512
 513         log->pfd = p[0];
 514         set_close_on_exec(log->pfd);
 515         talloc_set_destructor(log, log_context_destructor);
 516         fde = event_add_fd(ctdb->ev, log, log->pfd,
 517                            EVENT_FD_READ, ctdb_log_handler, log);
 518         tevent_fd_set_auto_close(fde);
 519
 520         return log;
 521
 522 free_log:
 523         talloc_free(log);
 524         return NULL;
 525 }
 526
 527 /*
 528   setup for logging of child process stdout
 529 */
 530 int ctdb_set_child_logging(struct ctdb_context *ctdb)
 531 {
 532         int p[2];
 533         int old_stdout, old_stderr;
 534         struct tevent_fd *fde;
 535
 536         if (ctdb->log->fd == STDOUT_FILENO) {
 537                 /* not needed for stdout logging */
 538                 return 0;
 539         }
 540
 541         /* setup a pipe to catch IO from subprocesses */
 542         if (pipe(p) != 0) {
 543                 DEBUG(DEBUG_ERR,(__location__ " Failed to setup for child logging pipe\n"));
 544                 return -1;
 545         }
 546
 547         /* We'll fail if stderr/stdout not already open; it's simpler. */
 548         old_stdout = dup(STDOUT_FILENO);
 549         old_stderr = dup(STDERR_FILENO);
 550         if (old_stdout < 0 || old_stderr < 0) {
 551                 DEBUG(DEBUG_ERR, ("Failed to dup stdout/stderr for child logging\n"));
 552                 return -1;
 553         }
 554         if (dup2(p[1], STDOUT_FILENO) < 0 || dup2(p[1], STDERR_FILENO) < 0) {
 555                 int saved_errno = errno;
 556                 dup2(old_stdout, STDOUT_FILENO);
 557                 dup2(old_stderr, STDERR_FILENO);
 558                 close(old_stdout);
 559                 close(old_stderr);
 560                 close(p[0]);
 561                 close(p[1]);
 562                 errno = saved_errno;
 563
 564                 printf(__location__ " dup2 failed: %s\n",
 565                         strerror(errno));
 566                 return -1;
 567         }
 568         close(p[1]);
 569         close(old_stdout);
 570         close(old_stderr);
 571
 572         fde = event_add_fd(ctdb->ev, ctdb->log, p[0],
 573                            EVENT_FD_READ, ctdb_log_handler, ctdb->log);
 574         tevent_fd_set_auto_close(fde);
 575
 576         ctdb->log->pfd = p[0];
 577
 578         DEBUG(DEBUG_DEBUG, (__location__ " Created PIPE FD:%d for logging\n", p[0]));
 579
 580         return 0;
 581 }
 582
 583
 584 /*
 585  * set up a log handler to catch logging from TEVENT
 586  */
 587 static void ctdb_tevent_logging(void *private_data,
 588                                 enum tevent_debug_level level,
 589                                 const char *fmt,
 590                                 va_list ap)
 591 {
 592         enum debug_level lvl = DEBUG_CRIT;
 593
 594         switch (level) {
 595         case TEVENT_DEBUG_FATAL:
 596                 lvl = DEBUG_CRIT;
 597                 break;
 598         case TEVENT_DEBUG_ERROR:
 599                 lvl = DEBUG_ERR;
 600                 break;
 601         case TEVENT_DEBUG_WARNING:
 602                 lvl = DEBUG_WARNING;
 603                 break;
 604         case TEVENT_DEBUG_TRACE:
 605                 lvl = DEBUG_DEBUG;
 606                 break;
 607         }
 608
 609         if (lvl <= LogLevel) {
 610                 this_log_level = lvl;
 611                 do_debug_v(fmt, ap);
 612         }
 613 }
 614
 615 int ctdb_init_tevent_logging(struct ctdb_context *ctdb)
 616 {
 617         int ret;
 618
 619         ret = tevent_set_debug(ctdb->ev,
 620                         ctdb_tevent_logging,
 621                         ctdb);
 622         return ret;
 623 }
 624
 625
 626