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