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/events/events.h"
  22 #include "../include/ctdb.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
  89         state = talloc(ctdb, struct ctdb_syslog_state);
  90         CTDB_NO_MEMORY(ctdb, state);
  91
  92         if (pipe(state->fd) != 0) {
  93                 printf("Failed to create syslog pipe\n");
  94                 talloc_free(state);
  95                 return -1;
  96         }
  97
  98         ctdb->syslogd_pid = fork();
  99         if (ctdb->syslogd_pid == (pid_t)-1) {
 100                 printf("Failed to create syslog child process\n");
 101                 close(state->fd[0]);
 102                 close(state->fd[1]);
 103                 talloc_free(state);
 104                 return -1;
 105         }
 106
 107         syslogd_is_started = 1;
 108
 109         if (ctdb->syslogd_pid != 0) {
 110                 DEBUG(DEBUG_ERR,("Starting SYSLOG child process with pid:%d\n", (int)ctdb->syslogd_pid));
 111
 112                 close(state->fd[1]);
 113                 set_close_on_exec(state->fd[0]);
 114
 115                 return 0;
 116         }
 117
 118         talloc_free(ctdb->ev);
 119         ctdb->ev = event_context_init(NULL);
 120
 121         syslog(LOG_ERR, "Starting SYSLOG daemon with pid:%d", (int)getpid());
 122
 123         close(state->fd[0]);
 124         set_close_on_exec(state->fd[1]);
 125         event_add_fd(ctdb->ev, state, state->fd[1], EVENT_FD_READ|EVENT_FD_AUTOCLOSE,
 126                      ctdb_syslog_terminate_handler, state);
 127
 128         state->syslog_fd = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);
 129         if (state->syslog_fd == -1) {
 130                 printf("Failed to create syslog socket\n");
 131                 return -1;
 132         }
 133
 134         set_close_on_exec(state->syslog_fd);
 135
 136         syslog_sin.sin_family = AF_INET;
 137         syslog_sin.sin_port   = htons(CTDB_PORT);
 138         syslog_sin.sin_addr.s_addr = htonl(INADDR_LOOPBACK);
 139
 140         if (bind(state->syslog_fd, &syslog_sin, sizeof(syslog_sin)) == -1) {
 141                 if (errno == EADDRINUSE) {
 142                         /* this is ok, we already have a syslog daemon */
 143                         _exit(0);
 144                 }
 145                 printf("syslog daemon failed to bind to socket. errno:%d(%s)\n", errno, strerror(errno));
 146                 _exit(10);
 147         }
 148
 149
 150         event_add_fd(ctdb->ev, state, state->syslog_fd, EVENT_FD_READ|EVENT_FD_AUTOCLOSE,
 151                      ctdb_syslog_handler, state);
 152
 153         event_loop_wait(ctdb->ev);
 154
 155         /* this should not happen */
 156         _exit(10);
 157 }
 158
 159 struct ctdb_log_state {
 160         struct ctdb_context *ctdb;
 161         int fd, pfd;
 162         char buf[1024];
 163         uint16_t buf_used;
 164         bool use_syslog;
 165         void (*logfn)(const char *, uint16_t, void *);
 166         void *logfn_private;
 167 };
 168
 169 /* we need this global to keep the DEBUG() syntax */
 170 static struct ctdb_log_state *log_state;
 171
 172 /*
 173   syslog logging function
 174  */
 175 static void ctdb_syslog_log(const char *format, va_list ap)
 176 {
 177         struct syslog_message *msg;
 178         int level = LOG_DEBUG;
 179         char *s = NULL;
 180         int len, ret;
 181         int syslog_fd;
 182         struct sockaddr_in syslog_sin;
 183
 184         ret = vasprintf(&s, format, ap);
 185         if (ret == -1) {
 186                 return;
 187         }
 188
 189         switch (this_log_level) {
 190         case DEBUG_EMERG:
 191                 level = LOG_EMERG;
 192                 break;
 193         case DEBUG_ALERT:
 194                 level = LOG_ALERT;
 195                 break;
 196         case DEBUG_CRIT:
 197                 level = LOG_CRIT;
 198                 break;
 199         case DEBUG_ERR:
 200                 level = LOG_ERR;
 201                 break;
 202         case DEBUG_WARNING:
 203                 level = LOG_WARNING;
 204                 break;
 205         case DEBUG_NOTICE:
 206                 level = LOG_NOTICE;
 207                 break;
 208         case DEBUG_INFO:
 209                 level = LOG_INFO;
 210                 break;
 211         default:
 212                 level = LOG_DEBUG;
 213                 break;
 214         }
 215
 216         len = offsetof(struct syslog_message, message) + strlen(s) + 1;
 217         msg = malloc(len);
 218         if (msg == NULL) {
 219                 free(s);
 220                 return;
 221         }
 222         msg->level = level;
 223         msg->len   = strlen(s);
 224         strcpy(msg->message, s);
 225
 226         if (syslogd_is_started == 0) {
 227                 syslog(msg->level, "%s", msg->message);
 228         } else {
 229                 syslog_fd = socket(AF_INET, SOCK_DGRAM, IPPROTO_UDP);
 230                 if (syslog_fd == -1) {
 231                         printf("Failed to create syslog socket\n");
 232                         free(s);
 233                         free(msg);
 234                         return;
 235                 }
 236
 237                 syslog_sin.sin_family = AF_INET;
 238                 syslog_sin.sin_port   = htons(CTDB_PORT);
 239                 syslog_sin.sin_addr.s_addr = htonl(INADDR_LOOPBACK);
 240
 241
 242                 ret = sendto(syslog_fd, msg, len, 0, &syslog_sin, sizeof(syslog_sin));
 243                 /* no point in checking here since we cant log an error */
 244
 245                 close(syslog_fd);
 246         }
 247
 248         free(s);
 249         free(msg);
 250 }
 251
 252
 253 /*
 254   log file logging function
 255  */
 256 static void ctdb_logfile_log(const char *format, va_list ap)
 257 {
 258         struct timeval t;
 259         char *s = NULL;
 260         struct tm *tm;
 261         char tbuf[100];
 262         char *s2 = NULL;
 263         int ret;
 264
 265         ret = vasprintf(&s, format, ap);
 266         if (ret == -1) {
 267                 const char *errstr = "vasprintf failed\n";
 268
 269                 write(log_state->fd, errstr, strlen(errstr));
 270                 return;
 271         }
 272
 273         t = timeval_current();
 274         tm = localtime(&t.tv_sec);
 275
 276         strftime(tbuf,sizeof(tbuf)-1,"%Y/%m/%d %H:%M:%S", tm);
 277
 278         ret = asprintf(&s2, "%s.%06u [%5u]: %s",
 279                  tbuf, (unsigned)t.tv_usec, (unsigned)getpid(), s);
 280         free(s);
 281         if (ret == -1) {
 282                 const char *errstr = "asprintf failed\n";
 283                 write(log_state->fd, errstr, strlen(errstr));
 284                 return;
 285         }
 286         if (s2) {
 287                 write(log_state->fd, s2, strlen(s2));
 288                 free(s2);
 289         }
 290 }
 291
 292 static void ctdb_logfile_log_add(const char *format, va_list ap)
 293 {
 294         char *s = NULL;
 295         int ret;
 296
 297         ret = vasprintf(&s, format, ap);
 298         if (ret == -1) {
 299                 const char *errstr = "vasprintf failed\n";
 300
 301                 write(log_state->fd, errstr, strlen(errstr));
 302                 return;
 303         }
 304
 305         if (s) {
 306                 write(log_state->fd, s, strlen(s));
 307                 free(s);
 308         }
 309 }
 310
 311
 312
 313 /*
 314   choose the logfile location
 315 */
 316 int ctdb_set_logfile(struct ctdb_context *ctdb, const char *logfile, bool use_syslog)
 317 {
 318         int ret;
 319
 320         ctdb_init_log();
 321
 322         ctdb->log = talloc_zero(ctdb, struct ctdb_log_state);
 323         if (ctdb->log == NULL) {
 324                 printf("talloc_zero failed\n");
 325                 abort();
 326         }
 327
 328         ctdb->log->ctdb = ctdb;
 329         log_state = ctdb->log;
 330
 331         if (use_syslog) {
 332                 do_debug_v = ctdb_syslog_log;
 333                 do_debug_add_v = ctdb_syslog_log;
 334                 ctdb->log->use_syslog = true;
 335         } else if (logfile == NULL || strcmp(logfile, "-") == 0) {
 336                 do_debug_v = ctdb_logfile_log;
 337                 do_debug_add_v = ctdb_logfile_log_add;
 338                 ctdb->log->fd = 1;
 339                 /* also catch stderr of subcommands to stdout */
 340                 ret = dup2(1, 2);
 341                 if (ret == -1) {
 342                         printf("dup2 failed: %s\n", strerror(errno));
 343                         abort();
 344                 }
 345         } else {
 346                 do_debug_v = ctdb_logfile_log;
 347                 do_debug_add_v = ctdb_logfile_log_add;
 348
 349                 ctdb->log->fd = open(logfile, O_WRONLY|O_APPEND|O_CREAT, 0666);
 350                 if (ctdb->log->fd == -1) {
 351                         printf("Failed to open logfile %s\n", logfile);
 352                         abort();
 353                 }
 354         }
 355
 356         return 0;
 357 }
 358
 359 /* Note that do_debug always uses the global log state. */
 360 static void write_to_log(struct ctdb_log_state *log,
 361                          const char *buf, unsigned int len)
 362 {
 363         if (script_log_level <= LogLevel) {
 364                 do_debug("%*.*s\n", len, len, buf);
 365                 /* log it in the eventsystem as well */
 366                 if (log->logfn)
 367                         log->logfn(log->buf, len, log->logfn_private);
 368         }
 369 }
 370
 371 /*
 372   called when log data comes in from a child process
 373  */
 374 static void ctdb_log_handler(struct event_context *ev, struct fd_event *fde,
 375                              uint16_t flags, void *private)
 376 {
 377         struct ctdb_log_state *log = talloc_get_type(private, struct ctdb_log_state);
 378         char *p;
 379         int n;
 380
 381         if (!(flags & EVENT_FD_READ)) {
 382                 return;
 383         }
 384
 385         n = read(log->pfd, &log->buf[log->buf_used],
 386                  sizeof(log->buf) - log->buf_used);
 387         if (n > 0) {
 388                 log->buf_used += n;
 389         } else if (n == 0) {
 390                 if (log != log_state) {
 391                         talloc_free(log);
 392                 }
 393                 return;
 394         }
 395
 396         this_log_level = script_log_level;
 397
 398         while (log->buf_used > 0 &&
 399                (p = memchr(log->buf, '\n', log->buf_used)) != NULL) {
 400                 int n1 = (p - log->buf)+1;
 401                 int n2 = n1 - 1;
 402                 /* swallow \r from child processes */
 403                 if (n2 > 0 && log->buf[n2-1] == '\r') {
 404                         n2--;
 405                 }
 406                 write_to_log(log, log->buf, n2);
 407                 memmove(log->buf, p+1, sizeof(log->buf) - n1);
 408                 log->buf_used -= n1;
 409         }
 410
 411         /* the buffer could have completely filled - unfortunately we have
 412            no choice but to dump it out straight away */
 413         if (log->buf_used == sizeof(log->buf)) {
 414                 write_to_log(log, log->buf, log->buf_used);
 415                 log->buf_used = 0;
 416         }
 417 }
 418
 419 static int log_context_destructor(struct ctdb_log_state *log)
 420 {
 421         /* Flush buffer in case it wasn't \n-terminated. */
 422         if (log->buf_used > 0) {
 423                 this_log_level = script_log_level;
 424                 write_to_log(log, log->buf, log->buf_used);
 425         }
 426         return 0;
 427 }
 428
 429 /*
 430    fork(), redirecting child output to logging and specified callback.
 431 */
 432 struct ctdb_log_state *ctdb_fork_with_logging(TALLOC_CTX *mem_ctx,
 433                                               struct ctdb_context *ctdb,
 434                                               void (*logfn)(const char *, uint16_t, void *),
 435                                               void *logfn_private, pid_t *pid)
 436 {
 437         int p[2];
 438         struct ctdb_log_state *log;
 439
 440         log = talloc_zero(mem_ctx, struct ctdb_log_state);
 441         CTDB_NO_MEMORY_NULL(ctdb, log);
 442         log->ctdb = ctdb;
 443         log->logfn = logfn;
 444         log->logfn_private = (void *)logfn_private;
 445
 446         if (pipe(p) != 0) {
 447                 DEBUG(DEBUG_ERR,(__location__ " Failed to setup for child logging pipe\n"));
 448                 goto free_log;
 449         }
 450
 451         *pid = fork();
 452
 453         /* Child? */
 454         if (*pid == 0) {
 455                 close(STDOUT_FILENO);
 456                 close(STDERR_FILENO);
 457                 dup2(p[1], STDOUT_FILENO);
 458                 dup2(p[1], STDERR_FILENO);
 459                 close(p[0]);
 460                 close(p[1]);
 461                 return log;
 462         }
 463         close(p[1]);
 464
 465         /* We failed? */
 466         if (*pid < 0) {
 467                 DEBUG(DEBUG_ERR, (__location__ " fork failed for child process\n"));
 468                 close(p[0]);
 469                 goto free_log;
 470         }
 471
 472         log->pfd = p[0];
 473         set_close_on_exec(log->pfd);
 474         talloc_set_destructor(log, log_context_destructor);
 475         event_add_fd(ctdb->ev, log, log->pfd,
 476                      EVENT_FD_READ | EVENT_FD_AUTOCLOSE,
 477                      ctdb_log_handler, log);
 478         return log;
 479
 480 free_log:
 481         talloc_free(log);
 482         return NULL;
 483 }
 484
 485 /*
 486   setup for logging of child process stdout
 487 */
 488 int ctdb_set_child_logging(struct ctdb_context *ctdb)
 489 {
 490         int p[2];
 491         int old_stdout, old_stderr;
 492
 493         if (ctdb->log->fd == STDOUT_FILENO) {
 494                 /* not needed for stdout logging */
 495                 return 0;
 496         }
 497
 498         /* setup a pipe to catch IO from subprocesses */
 499         if (pipe(p) != 0) {
 500                 DEBUG(DEBUG_ERR,(__location__ " Failed to setup for child logging pipe\n"));
 501                 return -1;
 502         }
 503
 504         /* We'll fail if stderr/stdout not already open; it's simpler. */
 505         old_stdout = dup(STDOUT_FILENO);
 506         old_stderr = dup(STDERR_FILENO);
 507         if (dup2(p[1], STDOUT_FILENO) < 0 || dup2(p[1], STDERR_FILENO) < 0) {
 508                 int saved_errno = errno;
 509                 dup2(old_stdout, STDOUT_FILENO);
 510                 dup2(old_stderr, STDERR_FILENO);
 511                 close(old_stdout);
 512                 close(old_stderr);
 513                 close(p[0]);
 514                 close(p[1]);
 515                 errno = saved_errno;
 516
 517                 printf(__location__ " dup2 failed: %s\n",
 518                         strerror(errno));
 519                 return -1;
 520         }
 521         close(p[1]);
 522         close(old_stdout);
 523         close(old_stderr);
 524
 525         /* Is this correct for STDOUT and STDERR ? */
 526         set_close_on_exec(STDOUT_FILENO);
 527         set_close_on_exec(STDERR_FILENO);
 528         set_close_on_exec(p[0]);
 529
 530         event_add_fd(ctdb->ev, ctdb->log, p[0],
 531                      EVENT_FD_READ | EVENT_FD_AUTOCLOSE,
 532                      ctdb_log_handler, ctdb->log);
 533         ctdb->log->pfd = p[0];
 534
 535         DEBUG(DEBUG_DEBUG, (__location__ " Created PIPE FD:%d for logging\n", p[0]));
 536
 537         return 0;
 538 }
 539
 540
 541
 542
 543