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