src/logger/logger.c

   1 /*
   2  * Copyright (c) 2016, Samsung Electronics Co., Ltd. All rights reserved.
   3  *
   4  * Licensed under the Apache License, Version 2.0 (the "License");
   5  * you may not use this file except in compliance with the License.
   6  * You may obtain a copy of the License at
   7  *
   8  *              http://www.apache.org/licenses/LICENSE-2.0
   9  *
  10  * Unless required by applicable law or agreed to in writing, software
  11  * distributed under the License is distributed on an "AS IS" BASIS,
  12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13  * See the License for the specific language governing permissions and
  14  * limitations under the License.
  15  */
  16
  17 #ifndef _GNU_SOURCE
  18 #define _GNU_SOURCE
  19 #endif
  20
  21 #include "logger_internal.h"
  22 #include "logger_privileges.h"
  23 #include "subreader_file.h"
  24 #include "subreader_metrics.h"
  25 #include "subreader_memory.h"
  26
  27 #include <buffer_traits.h>
  28 #include <metrics.h>
  29 #include <getopt.h>
  30 #include <dynamic_config.h>
  31 #include <qos_defaults.h>
  32
  33 /**
  34  * @addtogroup DLOG_IMPLEMENTATION
  35  * @{
  36  * @defgroup DLOG_LOGGER Logger
  37  * @brief Logger daemon
  38  * @details The logger is the core component of the logging framework. It is responsible for collecting, processing and exposing logs.
  39  * @{
  40  */
  41
  42 /** global state when logger is not interrupted by any handled signals */
  43 static volatile sig_atomic_t g_logger_run = 1;
  44
  45 static const int DEFAULT_EPOLL_TIME_MS = 1000;
  46
  47 static const int DEFAULT_LAZY_POLLING_TOTAL_MS = 0;
  48 static const int DEFAULT_LAZY_POLLING_SLEEP_MS = 1000;
  49
  50 struct backend_data g_backend = {};
  51
  52 // TODO: Consider inlining struct now_t everywhere
  53 int get_now(struct now_t *now)
  54 {
  55         if (clock_gettime(CLOCK_MONOTONIC, &now->mono))
  56                 return -errno;
  57         if (clock_gettime(CLOCK_REALTIME, &now->real))
  58                 return -errno;
  59         return 0;
  60 }
  61
  62 /**
  63  * @brief FD limit handler
  64  * @details Checks whether the FD limit was reached and leaves logs about it if so
  65  * @param[in] server The logger server
  66  * @param[in] err errno from the call that failed to create an FD
  67  */
  68 void check_if_fd_limit_reached(struct logger *server, int err)
  69 {
  70         assert(server);
  71
  72         if (err != ENFILE && err != EMFILE)
  73                 return;
  74
  75         printf("ERROR: dlog_logger fd limit reached!\n");
  76
  77         /* pick one representative buffer to send the log to;
  78          * no point spamming all the buffers, especially since
  79          * default dlogutil invocations display 3 buffers so
  80          * it would appear multiple times */
  81         struct log_buffer *const buf = server->buffers[LOG_ID_MAIN];
  82         if (!buf)
  83                 return;
  84
  85         struct dlogutil_entry_with_msg entry;
  86         create_pipe_message(&entry,
  87                 DLOG_FATAL, /* not really FATAL, but since we're at the FD limit
  88                              * there are thousands of logging programs so this one
  89                              * would likely get lost in the flood since developers
  90                              * tend to overuse ERROR (and FATAL is the one above) */
  91                 "DLOG",
  92                 "\x1b[31m DLOG DAEMON FD LIMIT REACHED \x1b[0m" // make it stand out
  93                 , getpid(), gettid()
  94         );
  95         struct now_t now;
  96         int r = get_now(&now);
  97         if (r < 0)
  98                 return;
  99         set_pipe_message_sent_timestamp((struct pipe_logger_entry *) &entry, &now.mono, &now.real);
 100
 101         if (buffer_append(&entry.header, buf))
 102                 printf("ERROR: not enough memory either, please check platform settings as the daemon is seriously resource-starved!\n");
 103 }
 104
 105 void flush_logfile_timely(struct log_file *file, struct timespec ts, int flush_time)
 106 {
 107         if (file->buffer.position > 0) {
 108                 if (ts.tv_sec - file->buffer.oldest_log.tv_sec +
 109                                         (ts.tv_nsec > file->buffer.oldest_log.tv_nsec ? 1 : 0) >
 110                                 flush_time)
 111                         logfile_flush(file);
 112         }
 113 }
 114
 115 void reader_pipe_notify_losing_log(const dlogutil_entry_s *le, void *reader_)
 116 {
 117         struct reader_pipe *reader = (struct reader_pipe *) reader_;
 118         assert(le);
 119         assert(reader);
 120         reader_pipe_print_out_single_log(reader, (dlogutil_entry_s *)le);
 121 }
 122
 123 /**
 124  * @brief Add reader to log buffer
 125  * @details Adds a reader to the log buffers reader list
 126  * @param[in] log_buffer The buffer whither to add the reader
 127  * @param[in] reader The reader to add to the buffer
 128  * @return 0 on success, -ENOMEM on memory allocation error
 129  */
 130 int add_buffer_reader(struct log_buffer *buffer, struct reader_pipe *reader)
 131 {
 132         assert(reader);
 133         assert(buffer);
 134
 135         reader->log_storage_reader_ptr = log_storage_new_reader(buffer->log_storage_ptr,
 136                         reader->is_dumping, reader->monitor, reader_pipe_notify_losing_log, reader);
 137
 138         if (!reader->log_storage_reader_ptr)
 139                 return -ENOMEM;
 140
 141         return list_add(&buffer->readers_pipe, reader) ? 0 : -ENOMEM;
 142 }
 143
 144 static int add_reader_common(struct logger *server, struct reader_common *reader)
 145 {
 146         assert(reader);
 147         assert(server);
 148
 149         if (reader->fd_entity_sink.fd >= 0) {
 150                 /* Readers who write to file have no sink FD entity (or, strictly
 151                  * speaking, they do have one but it is not filled) since a file
 152                  * is not eligible to be added to epoll. However, the entity primarily
 153                  * serves to handle pipes getting clogged mid-write (which cannot
 154                  * happen for files) and is not involved in starting a write,
 155                  * which is handled by the source FD entity, not sink (and which is
 156                  * also done periodically for all readers anyway regardless
 157                  * of whether they've been added to epoll or not). The other use
 158                  * case for epoll - the one where connection FDs leak for unused
 159                  * buffers - is not a problem here because the daemon is not
 160                  * supposed to ever stop writing to files. */
 161
 162                 int r = add_fd_entity(&server->epoll_common, &reader->fd_entity_sink);
 163                 if (r < 0)
 164                         return r;
 165         }
 166
 167         return 0;
 168 }
 169
 170 int add_reader_pipe(struct logger *server, struct reader_pipe *reader)
 171 {
 172         assert(reader);
 173         assert(server);
 174
 175         int ret = add_reader_common(server, &reader->common);
 176         if (ret < 0)
 177                 return ret;
 178
 179         ret = add_buffer_reader(reader->buf_ptr, reader);
 180         if (ret < 0 && reader->common.fd_entity_sink.fd >= 0)
 181                 remove_fd_entity(&server->epoll_common, &reader->common.fd_entity_sink);
 182
 183         return ret;
 184 }
 185
 186 int add_reader_memory(struct logger *server, struct reader_memory *reader)
 187 {
 188         assert(reader);
 189         assert(server);
 190
 191         int ret = add_reader_common(server, &reader->common);
 192         if (ret < 0)
 193                 return ret;
 194
 195         // `readers_logger` actually accepts any readers
 196         if (!list_add(&server->readers_logger, reader)) {
 197                 if (reader->common.fd_entity_sink.fd >= 0)
 198                         remove_fd_entity(&server->epoll_common, &reader->common.fd_entity_sink);
 199                 return -ENOMEM;
 200         }
 201
 202         return 0;
 203 }
 204
 205 #ifndef UNIT_TEST
 206 /* This really belongs to the UNIT_TEST block at the bottom since it is only used
 207  * by a function living there, but has not been moved there to keep patches small
 208  * and because this function is going to be removed soon in an upcoming patch. */
 209
 210 static int add_reader_logger(struct logger *server, struct reader_logger *reader)
 211 {
 212         assert(reader);
 213         assert(server);
 214
 215         int ret = add_reader_common(server, &reader->common);
 216         if (ret < 0)
 217                 return ret;
 218
 219         assert(reader->common.fd_entity_source.fd >= 0);
 220         ret = add_fd_entity(&server->epoll_common, &reader->common.fd_entity_source);
 221         if (ret < 0)
 222                 goto failure;
 223
 224         if (!list_add(&server->readers_logger, reader)) {
 225                 remove_fd_entity(&server->epoll_common, &reader->common.fd_entity_source);
 226                 ret = -ENOMEM;
 227                 goto failure;
 228         }
 229
 230         return 0;
 231
 232 failure:
 233         if (reader->common.fd_entity_sink.fd >= 0)
 234                 remove_fd_entity(&server->epoll_common, &reader->common.fd_entity_sink);
 235
 236         return ret;
 237 }
 238 #endif
 239
 240 int create_fifo_fds(struct logger *server, int pipe_fd[2], int flags, bool dump)
 241 {
 242         int ret = get_nonblocking_fifo(pipe_fd, flags);
 243         if (ret < 0)
 244                 return ret;
 245
 246         /* Speed up dumping dlogutils by increasing their pipe size,
 247          * as otherwise this pipe's size becomes a major bottleneck.
 248          *
 249          * Continuous connections don't really care if the initial
 250          * burst of "historic" logs is slow and the following flow
 251          * of logs is just fine with a small pipe. Meanwhile they
 252          * live for a long time during which they would take away
 253          * from the valuable total pipe size. */
 254         if (dump)
 255                 if (fcntl(pipe_fd[1], F_SETPIPE_SZ, DUMPING_READER_PIPE_SIZE) < 0) {
 256                         /* Ignore; this is just a performance optimisation
 257                          * and doesn't affect functionality so while errors
 258                          * are worrisome they not a big deal or something
 259                          * we can do anything about, at any rate. */
 260                 }
 261
 262         return ret;
 263 }
 264
 265 static int create_memory_subreader_for_common(struct dlogutil_line_params *params, struct reader_common *reader, struct logger *server)
 266 {
 267         struct log_compressed_storage *storage = log_compressed_storage_create(params->file.rotate_size_kbytes * 1024, params->compression, params->mem_algo);
 268         if (!storage)
 269                 return -ENOMEM;
 270
 271         list_add(&server->compressed_memories, storage);
 272
 273         return reader_add_subreader_memory(reader, params->filter, storage);
 274 }
 275
 276 static int create_memory_subreader_from_dlogutil_line(struct dlogutil_line_params *params, struct logger *server)
 277 {
 278         assert(params);
 279         assert(params->compression);
 280
 281         if (params->file_path) // We're writing to memory, not to file
 282                 return -EINVAL;
 283
 284         if (params->buf_id == LOG_ID_INVALID)
 285                 return -EINVAL;
 286
 287         struct reader_logger *const reader = g_backend.logger_readers[params->buf_id];
 288         if (!reader)
 289                 return -ENOENT;
 290
 291         return create_memory_subreader_for_common(params, &reader->common, server);
 292 }
 293
 294 static int create_logger_subreader_from_dlogutil_line(struct dlogutil_line_params *params)
 295 {
 296         assert(params);
 297         assert(!params->compression);
 298
 299         if (params->file_path) {
 300                 int retval = logfile_set_path(&params->file, params->file_path);
 301                 if (retval < 0)
 302                         return retval;
 303
 304                 retval = logfile_open(&params->file);
 305                 if (retval < 0)
 306                         return retval;
 307         }
 308
 309         if (params->buf_id == LOG_ID_INVALID)
 310                 return -EINVAL;
 311
 312         if (params->file.path == NULL)
 313                 return -EINVAL;
 314
 315         struct reader_logger *const reader = g_backend.logger_readers[params->buf_id];
 316         if (!reader)
 317                 return -ENOENT;
 318
 319         return reader_add_subreader_file(&reader->common, params->filter, &params->file, DLOGUTIL_SORT_SENT_REAL);
 320 }
 321
 322 static int create_reader_pipe_from_dlogutil_line(struct dlogutil_line_params *params, struct logger *server, struct reader_pipe **rd)
 323 {
 324         assert(server);
 325         assert(rd);
 326
 327         __attribute__((cleanup(reader_free_ptr))) struct reader_pipe *reader = NULL;
 328         int retval;
 329
 330         if (params->file_path) {
 331                 retval = logfile_set_path(&params->file, params->file_path);
 332                 if (retval < 0)
 333                         return retval;
 334
 335                 retval = logfile_open(&params->file);
 336                 if (retval < 0)
 337                         return retval;
 338         }
 339
 340         if (params->buf_id == LOG_ID_INVALID)
 341                 return -EINVAL;
 342
 343         if ((params->file.path == NULL && !params->compression)
 344         ||  (params->file.path != NULL &&  params->compression))
 345                 return -EINVAL;
 346
 347         retval = reader_pipe_init(&reader, params->buf_id, server, params->monitor, params->is_dumping);
 348         if (retval != 0)
 349                 return retval;
 350
 351         if (params->file.path == NULL) {
 352                 assert(params->compression);
 353                 retval = create_memory_subreader_for_common(params, &reader->common, server);
 354                 if (retval != 0)
 355                         return retval;
 356         } else {
 357                 /* FIXME: in theory these could be added independently (1 reader 2 subs),
 358                  * but so far that has not been needed and it sounds too fragile to do in haste.
 359                  * Keep in mind the reader only has one sink FD entity though, so unless
 360                  * that is rewritten, there can be only one sub with poll-dependent output. */
 361                 assert(!params->compression);
 362                 retval = reader_add_subreader_file(&reader->common, params->filter, &params->file, server->buffers[params->buf_id]->sort_by);
 363                 if (retval != 0)
 364                         return retval;
 365         }
 366
 367         *rd = reader;
 368         reader = NULL;
 369
 370         return 0;
 371 }
 372
 373 /**
 374  * @brief Service a socket request
 375  * @details Handle a socket request
 376  * @param[in] server The logger server
 377  * @param[in] wr The writer who sent the request
 378  * @param[in] event The event containing the request
 379  * @return 0 on success, else -errno
 380  */
 381 int service_writer_socket(struct logger *server, struct writer *wr, struct epoll_event *event)
 382 {
 383         int r = 0;
 384
 385         assert(wr);
 386         struct dlog_control_msg *const msg = (struct dlog_control_msg *) wr->buffer;
 387
 388         assert(event);
 389         if (event->events & EPOLLIN)
 390                 r = read(wr->fd_entity.fd, wr->buffer + wr->readed, sizeof wr->buffer - wr->readed);
 391
 392         if ((r == 0 || r == -1) && event->events & EPOLLHUP)
 393                 return -EINVAL;
 394
 395         do {
 396                 if (r > 0)
 397                         wr->readed += r;
 398
 399                 /* The socket is SOCK_STREAM (see `listen_fd_create`), so one message
 400                  * could be split into chunks returned across multiple read() calls. */
 401                 if (wr->readed < sizeof(msg->length)
 402                 ||  wr->readed < msg->length)
 403                         goto dont_process_yet_and_read_more_data;
 404
 405                 assert(wr->service_socket);
 406                 r = wr->service_socket(server, wr, msg);
 407                 if (r <= 0)
 408                         return r;
 409
 410 dont_process_yet_and_read_more_data:
 411                 r = read(wr->fd_entity.fd, wr->buffer + wr->readed, sizeof wr->buffer - wr->readed);
 412         } while (r > 0 || ((wr->readed >= sizeof(msg->length) && wr->readed >= msg->length)));
 413
 414         return (r >= 0 || errno == EAGAIN)  ? 0 : r;
 415 }
 416
 417 /**
 418  * @brief Service /dev/kmsg
 419  * @details Read from the /dev/kmsg device
 420  * @param[in] server The logger server
 421  * @param[in] wr The writer who sent the request
 422  * @param[in] event The relevant event
 423  * @return 0 on success, else -errno
 424  */
 425 int service_writer_kmsg(struct logger *server, struct writer *wr, struct epoll_event *event)
 426 {
 427         (void) server;
 428         if (event->events & EPOLLHUP)
 429                 return -EBADF;
 430         if (!(event->events & EPOLLIN))
 431                 return 0;
 432
 433         /* The KMSG device returns just 1 log per read() so it is done in a loop.
 434          * In theory this could starve everything else out if logs appeared faster
 435          * than the daemon could process them, which would then necessitate some
 436          * sort of throttling. In practice, KMSG doesn't really get flooded with
 437          * logs the same way Android Logger devices are so the throttling is mostly
 438          * there because we get it for free anyway and consistency doesn't hurt. */
 439
 440         int max_loop_iterations = g_backend.logger_device_throttling[LOG_ID_KMSG];
 441         while (max_loop_iterations--) {
 442                 int r = read(wr->fd_entity.fd, wr->buffer, sizeof wr->buffer - 1);
 443
 444                 if (r == -1 && (errno == EAGAIN || errno == EPIPE))
 445                         return 0;
 446                 else if ((r == 0 || r == -1) && event->events & EPOLLHUP)
 447                         return -EINVAL;
 448                 else if (r == 0)
 449                         return -EBADF;
 450                 else if (r == -1)
 451                         return -errno;
 452
 453                 wr->buffer[r] = '\0';
 454                 struct dlogutil_entry_with_msg lem;
 455                 if (parse_kmsg_message(wr->buffer, &lem, r)) {
 456                         // don't signal an error: KMSG writer is too important to remove; besides, it would not get fixed that way.
 457                         return 0;
 458                 }
 459
 460                 struct now_t now;
 461                 r = get_now(&now);
 462                 if (r < 0)
 463                         return r;
 464                 add_recv_timestamp(&lem.header, now);
 465
 466                 r = buffer_append(&lem.header, wr->buf_ptr);
 467                 if (r < 0)
 468                         return r;
 469         }
 470
 471         return 0;
 472 }
 473
 474 /**
 475  * @brief Service syslog
 476  * @details Read from the syslog socket
 477  * @param[in] server The logger server
 478  * @param[in] wr The writer who sent the request
 479  * @param[in] event The relevant event
 480  * @return 0 on success, else -errno
 481  */
 482 int service_writer_syslog(struct logger *server, struct writer *wr, struct epoll_event *event)
 483 {
 484         if (event->events & EPOLLHUP)
 485                 return -EBADF;
 486         if (!(event->events & EPOLLIN))
 487                 return 0;
 488
 489         int r = read(wr->fd_entity.fd, wr->buffer, sizeof wr->buffer - 1);
 490
 491         if (r == -1 && (errno == EAGAIN || errno == EPIPE))
 492                 return 0;
 493         else if ((r == 0 || r == -1) && event->events & EPOLLHUP)
 494                 return -EINVAL;
 495         else if (r == 0)
 496                 return -EBADF;
 497         else if (r == -1)
 498                 return -errno;
 499
 500         wr->buffer[r] = '\0';
 501
 502         struct dlogutil_entry_with_msg lem;
 503         if (parse_syslog_datagram(wr->buffer, r + 1, &lem.header)) {
 504                 /* don't return parse error as writers are removed then */
 505                 return 0;
 506         }
 507
 508         struct now_t now;
 509         r = get_now(&now);
 510         if (r < 0)
 511                 return r;
 512         add_recv_timestamp(&lem.header, now);
 513
 514         return buffer_append(&lem.header, wr->buf_ptr);
 515 }
 516
 517 /**
 518  * @brief Add writer to server
 519  * @details Adds a writer to the server's witers list and registers its event to epoll loop
 520  * @param[in] l The server to add the writer to
 521  * @param[in] writer The writer to add to the server and register its working_fd to epoll loop
 522  */
 523 void logger_add_writer(struct logger *l, struct writer *wr)
 524 {
 525         assert(l);
 526         assert(wr);
 527
 528         list_add(&l->writers, wr);
 529         add_fd_entity(&l->epoll_common, &wr->fd_entity);
 530 }
 531
 532 /**
 533  * @brief Create the logger server
 534  * @details Allocate the logger server's auxiliary structures (buffers etc.)
 535  * @param[in] data Initialisation data
 536  * @param[out] l The logger server
 537  * @return 0 on success, -errno on failure
 538  */
 539 #ifndef UNIT_TEST
 540 static
 541 #endif
 542 int logger_create(struct logger_config_data *data, struct logger *l)
 543 {
 544         memset(l, 0, sizeof *l);
 545         l->epoll_socket.fd = -1;
 546
 547         int r = epoll_metadata_initialize(&l->epoll_common);
 548         if (r < 0)
 549                 return r;
 550         r = epoll_metadata_initialize(&l->epoll_socket);
 551         if (r < 0)
 552                 return r;
 553
 554         l->epolltime = data->epoll_time;
 555
 556         l->buf_params = data->buf_params;
 557
 558         if (data->qos) {
 559                 l->qos = data->qos;
 560                 data->qos = NULL;
 561
 562                 l->qos->log_metrics = metrics_create();
 563                 if (!l->qos->log_metrics)
 564                         return -ENOMEM;
 565         }
 566
 567         // Check if the daemon is being launched for the first time since reboot
 568         bool first_time;
 569         if (data->first_time_file_path) {
 570                 int fd = open(data->first_time_file_path, O_CREAT | O_EXCL | O_RDONLY, 0644);
 571                 if (fd == -1) {
 572                         if (errno == EEXIST)
 573                                 first_time = false;
 574                         else
 575                                 return -errno;
 576                 } else {
 577                         first_time = true;
 578                         close(fd);
 579                 }
 580         } else
 581                 // If no path, assume first time
 582                 first_time = true;
 583
 584         if (g_backend.use_logger_by_default)
 585                 for (log_id_t id = 0; id < LOG_ID_MAX; ++id) {
 586                         if (!is_core_buffer(id))
 587                                 continue;
 588
 589                         int r = reader_logger_init(g_backend.logger_readers + id, id, l, !first_time);
 590                         if (r < 0)
 591                                 return r;
 592                         if (!g_backend.logger_readers[id])
 593                                 continue;
 594
 595                         if (l->qos) {
 596                                 r = reader_add_subreader_metrics(&g_backend.logger_readers[id]->common, l->qos);
 597                                 if (r < 0) {
 598                                         reader_free(&g_backend.logger_readers[id]->common);
 599                                         g_backend.logger_readers[id] = NULL;
 600                                         return r;
 601                                 }
 602                         }
 603
 604                         /* The reader is not yet complete; later in `finalize_init`
 605                          * it will receive further readers and be added to epoll
 606                          * or alternatively get culled if it gets no sub-readers. */
 607                 }
 608
 609         for (log_id_t id = 0; id < LOG_ID_MAX; id++)
 610                 if (data->is_buffer_enabled[id]) {
 611                         int r = buffer_create(&l->buffers[id], id, data->buffers + id);
 612                         if (r < 0)
 613                                 return r;
 614                 }
 615
 616         for (log_id_t id = 0; id < LOG_ID_MAX; id++)
 617                 if (l->buffers[id]) {
 618                         add_fd_entity(&l->epoll_common, &l->buffers[id]->sock_ctl.fd_entity);
 619                         add_fd_entity(&l->epoll_common, &l->buffers[id]->sock_conn.fd_entity);
 620
 621                         add_fd_entity(&l->epoll_socket, &l->buffers[id]->sock_ctl.fd_entity);
 622                         add_fd_entity(&l->epoll_socket, &l->buffers[id]->sock_conn.fd_entity);
 623                 }
 624
 625         /* TODO: make writers creation optional/configurable */
 626         int (*writers_factories[LOG_ID_MAX])(struct writer **writer, struct log_buffer *log_buf) = {
 627                 [LOG_ID_KMSG] = create_kmsg_writer,
 628                 [LOG_ID_SYSLOG] = create_syslog_writer,
 629         };
 630         for (unsigned u = 0; u < NELEMS(writers_factories); ++u)
 631                 if (writers_factories[u] && data->is_buffer_enabled[u]) {
 632                         struct writer *wr;
 633                         int r = writers_factories[u](&wr, l->buffers[u]);
 634                         if (r < 0)
 635                                 return r;
 636
 637                         logger_add_writer(l, wr);
 638                 }
 639
 640         return 0;
 641 }
 642
 643 /**
 644  * @brief Handle interrupting/terminating signals
 645  * @details Clears global flag to stop main loop
 646  * @param[in] signo signal number
 647  */
 648 static void handle_signals(int signo)
 649 {
 650         (void) signo;
 651         g_logger_run = 0;
 652 }
 653
 654 void setup_signals(struct logger *server)
 655 {
 656         struct sigaction action = {
 657                 .sa_handler = handle_signals,
 658                 .sa_flags   = 0
 659         };
 660         sigemptyset(&action.sa_mask);
 661
 662         static const int handled_signals[] = { SIGINT, SIGTERM };
 663         for (unsigned u = 0; u < NELEMS(handled_signals); ++u)
 664                 sigaction(handled_signals[u], &action, NULL);
 665 }
 666
 667 static bool do_logger_one_iteration(struct logger *server, bool *use_lazy_polling)
 668 {
 669         if (*use_lazy_polling)
 670                 sleep_while_handling_socket(server, &server->epoll_socket, g_backend.lazy_polling_sleep);
 671
 672         if (g_backend.lazy_polling_total > 0) {
 673                 g_backend.lazy_polling_total -= g_backend.lazy_polling_sleep;
 674                 *use_lazy_polling = (g_backend.lazy_polling_total > 0);
 675         }
 676
 677         int r = handle_epoll_events(server, &server->epoll_common, server->epolltime * !*use_lazy_polling);
 678         if (r < 0)
 679                 return false;
 680
 681         service_all_readers(server);
 682
 683         if (server->qos)
 684                 qos_periodic_check(server->qos);
 685
 686         return true;
 687 }
 688
 689 /**
 690  * @brief Do logging
 691  * @details The main logging loop
 692  * @param[in] server The logger server
 693  * @return 0 on success, else -errno
 694  */
 695 #ifndef UNIT_TEST
 696 static
 697 #endif
 698 int do_logger(struct logger *server)
 699 {
 700         setup_signals(server);
 701
 702         /* Note, negative values are applied here, but not in the check in
 703          * the inner function. This leaves lazy polling enabled forever
 704          * and is a feature. */
 705         bool use_lazy_polling = (g_backend.lazy_polling_total != 0);
 706         while (g_logger_run)
 707                 if (!do_logger_one_iteration(server, &use_lazy_polling))
 708                         break;
 709
 710         /* ensure all logs are written no matter when the program was interrupted */
 711         service_all_readers(server);
 712
 713         return 0;
 714 }
 715
 716 /**
 717  * @brief Prepare socket data
 718  * @details Extracts initialisation data specific to each socket
 719  * @param[in] conf Config database
 720  * @param[out] data Socket init config data
 721  * @param[in] buf_name The name of the buffer the socket belongs to
 722  * @param[in] type The name of the buffer type
 723  * @return 0 on success, -errno on failure
 724  */
 725 int prepare_socket_data(const struct log_config *conf, struct socket_config_data *data, char *buf_name, const char *type)
 726 {
 727         char conf_key[MAX_CONF_KEY_LEN];
 728         int r;
 729
 730         r = snprintf(conf_key, MAX_CONF_KEY_LEN, "%s_%s_sock", buf_name, type);
 731         if (r < 0)
 732                 return -errno;
 733         const char * const path = log_config_get(conf, conf_key);
 734
 735         r = snprintf(conf_key, MAX_CONF_KEY_LEN, "%s_%s_sock_rights", buf_name, type);
 736         if (r < 0)
 737                 return -errno;
 738         const char * const permissions_str = log_config_get(conf, conf_key);
 739
 740         if (!permissions_str || !path)
 741                 return -ENOENT;
 742
 743         data->permissions = parse_permissions(permissions_str);
 744         if (data->permissions <= 0)
 745                 return -EINVAL;
 746
 747         strncpy(data->path, path, MAX_CONF_VAL_LEN - 1);
 748
 749         return 0;
 750 }
 751
 752 /**
 753  * @brief Prepare buffer data
 754  * @details Extracts data specific for each buffer
 755  * @param[in] conf Config database
 756  * @param[out] data Buffer init config data
 757  * @param[in] buf_id Index of the buffer to work with
 758  * @return 0 on success, -errno on failure
 759  */
 760 int prepare_buffer_data(const struct log_config *conf, struct buffer_config_data *data, log_id_t buf_id)
 761 {
 762         char * const buf_name = log_name_by_id(buf_id);
 763         char * validity_check_ptr;
 764         char conf_key[MAX_CONF_KEY_LEN];
 765         int r;
 766
 767         r = prepare_socket_data(conf, &data->conn_socket, buf_name, "conn");
 768         if (r < 0)
 769                 return r;
 770
 771         r = prepare_socket_data(conf, &data->ctl_socket, buf_name, "ctl");
 772         if (r < 0)
 773                 return r;
 774
 775         r = snprintf(conf_key, MAX_CONF_KEY_LEN, "%s_size", buf_name);
 776         if (r < 0)
 777                 return -errno;
 778
 779         const char * const size_str = log_config_get(conf, conf_key);
 780         if (!size_str)
 781                 return -ENOENT;
 782
 783         data->size = strtol(size_str, &validity_check_ptr, 10);
 784         if (*validity_check_ptr)
 785                 return -EINVAL;
 786         if (data->size <= 0)
 787                 return -EINVAL;
 788
 789         return 0;
 790 }
 791
 792 /**
 793  * @brief Save logfile line
 794  * @detail Saves logfile config line in user_data list
 795  * @param[in] key Config entry key
 796  * @param[in] value Config entry value
 797  * @param[in] userdata Userdata
 798  */
 799 void save_logfile_config(char const *key, char const *value, void *userdata)
 800 {
 801         assert(userdata);
 802         if (strncmp(key, CONF_PREFIX, sizeof CONF_PREFIX - 1))
 803                 return;
 804
 805         struct logger_config_data *data = (struct logger_config_data *)userdata;
 806         char *cmd = strdup(value);
 807         if (cmd)
 808                 list_add(&data->logfile_configs, cmd);
 809         //ignore errors
 810 }
 811
 812 /**
 813  * @brief Initialize config data
 814  * @param[out] The data structure to fill with initial values
 815  */
 816 void initialize_config_data(struct logger_config_data *data)
 817 {
 818         memset(data, 0, sizeof *data);
 819 }
 820
 821 /**
 822  * @brief Prepare config data
 823  * @details Extracts relevant config data for logger initialisation
 824  * @param[out] data Parsed configuration
 825  * @return 0 on success, -errno on failure
 826  */
 827 int prepare_config_data(struct logger_config_data *data)
 828 {
 829         assert(data);
 830
 831         struct log_config conf;
 832         int ret = log_config_read(&conf);
 833         if (ret < 0)
 834                 return ret;
 835
 836         const dlogutil_sorting_order_e sort_by = get_order_from_config(&conf);
 837
 838         int throttling_default = log_config_get_int(&conf, "logger_dev_throttling", LOGGER_DEVICE_THROTTLING_DEFAULT);
 839         const char *const dynamic_config_dir = log_config_get(&conf, DYNAMIC_CONFIG_CONF_KEY);
 840
 841         const char * const backend = log_config_claim_backend(&conf);
 842         if (!backend) {
 843                 ret = -ENOENT;
 844                 goto end;
 845         }
 846
 847         if (!strcmp(backend, "null")) {
 848                 ret = -ENODATA;
 849                 goto end;
 850         }
 851
 852         for (int i = 0; i < LOG_ID_MAX; i++) {
 853                 char key[MAX_CONF_KEY_LEN];
 854                 const int r = snprintf(key, sizeof key, "logger_dev_throttling_%s", log_name_by_id((log_id_t)i));
 855                 if (r < 0)
 856                         continue;
 857
 858                 g_backend.logger_device_throttling[i] = max_int(1, log_config_get_int(&conf, key, throttling_default));
 859         }
 860
 861         if (dynamic_config_dir && dynamic_config_dir[0] == '/') {
 862                 data->dynamic_config_dir = strdup(dynamic_config_dir);
 863                 if (!data->dynamic_config_dir) {
 864                         ret = -ENOMEM;
 865                         goto end;
 866                 }
 867         } else {
 868                 data->dynamic_config_dir = NULL; // Technically unnecessary but no reason not to put it
 869         }
 870
 871         data->epoll_time = log_config_get_int(&conf, "epoll_time_ms", DEFAULT_EPOLL_TIME_MS);
 872         g_backend.lazy_polling_total = 0; // Android Logger backend only, read below
 873
 874         struct qos_module qos = {0, };
 875
 876         qos.file_path = (char *) log_config_get(&conf, "qos_file_path");
 877         qos.limit_duration = log_config_get_int(&conf, "qos_refresh_rate_s", DEFAULT_QOS_LIMIT_DURATION_S);
 878         qos.max_throughput = log_config_get_int(&conf, "qos_max_throughput_logs", DEFAULT_QOS_THROUGHPUT_LOGS);
 879         qos.threshold = log_config_get_int(&conf, "qos_threshold_logs", DEFAULT_QOS_THRESHOLD_LOGS);
 880         qos.threshold_reapply = log_config_get_int(&conf, "qos_threshold_reapply_logs", DEFAULT_QOS_THRESHOLD_REAPPLY_LOGS);
 881         qos.distribution_func = qos_get_distribution_func_by_name(log_config_get(&conf, "qos_method"));
 882
 883         if (qos.threshold > 0
 884         &&  qos.max_throughput > 0
 885         &&  qos.file_path && strlen(qos.file_path) > 0) {
 886                 data->qos = malloc(sizeof *data->qos);
 887                 if (!data->qos) {
 888                         ret = -ENOMEM;
 889                         goto end;
 890                 }
 891                 *data->qos = qos;
 892                 data->qos->file_path = strdup(qos.file_path);
 893                 if (!data->qos->file_path) {
 894                         ret = -ENOMEM;
 895                         goto end;
 896                 }
 897         }
 898
 899         const char *const first_time_file_path = log_config_get(&conf, "first_time_file_path");
 900         data->first_time_file_path = first_time_file_path ? strdup(first_time_file_path) : NULL;
 901
 902         memset(data->is_buffer_enabled, 0, sizeof(data->is_buffer_enabled));
 903         if (!strcmp(backend, "pipe")) {
 904                 for (int i = 0; i < LOG_ID_MAX; ++i)
 905                         if (is_core_buffer(i))
 906                                 data->is_buffer_enabled[i] = true;
 907                 g_backend.use_logger_by_default = false;
 908         } else if (!strcmp(backend, "logger")) {
 909                 g_backend.use_logger_by_default = true;
 910                 for (log_id_t buf_id = 0; buf_id < LOG_ID_MAX; ++buf_id) {
 911                         const char *const logger_device = log_config_get(&conf, log_name_by_id(buf_id));
 912                         if (logger_device)
 913                                 strncpy(g_backend.logger_devices[buf_id], logger_device,
 914                                         NELEMS(g_backend.logger_devices[buf_id]) - 1);
 915                 }
 916                 g_backend.lazy_polling_total = log_config_get_int(&conf, "lazy_polling_total_ms", DEFAULT_LAZY_POLLING_TOTAL_MS);
 917                 g_backend.lazy_polling_sleep = log_config_get_int(&conf, "lazy_polling_sleep_ms", DEFAULT_LAZY_POLLING_SLEEP_MS);
 918
 919                 /* The total can be 0 (no lazy polling) or negative (infinite),
 920                  * but the sleep length has to be positive. */
 921                 if (g_backend.lazy_polling_sleep < 1)
 922                         g_backend.lazy_polling_sleep = 1;
 923
 924         } else if (!strcmp(backend, "zero-copy")) {
 925                 /* HACK: This essentially skips reading the most important configuration fields
 926                  * (buffer reading and persistent logs) while ensuring the variables are initialized.
 927                  * This will result in daemon quitting. Hopefully we will either reenable some of these
 928                  * in the future or at least make it exit more gracefully (TODO), but for now this is ok. */
 929                 g_backend.use_logger_by_default = false;
 930                 goto end;
 931         } else {
 932                 ret = -ENOENT;
 933                 goto end;
 934         }
 935         data->is_buffer_enabled[LOG_ID_KMSG] = log_config_get_boolean(&conf, "handle_kmsg", true);
 936         data->is_buffer_enabled[LOG_ID_SYSLOG] =
 937                 dev_log_sock_get() >= 0 || log_config_get_boolean(&conf, "syslog_force", false);
 938
 939         for (log_id_t buf_id = 0; buf_id < LOG_ID_MAX; ++buf_id) {
 940                 if (data->is_buffer_enabled[buf_id]) {
 941                         ret = prepare_buffer_data(&conf, data->buffers + buf_id, buf_id);
 942                         if (ret < 0)
 943                                 goto end;
 944                         data->buffers[buf_id].sort_by = sort_by;
 945                 }
 946         }
 947         log_config_foreach(&conf, save_logfile_config, data);
 948
 949         data->default_format = get_default_format_from_config(&conf);
 950
 951 end:
 952         log_config_free(&conf);
 953         return ret;
 954 }
 955
 956 #ifndef UNIT_TEST
 957 static
 958 #endif
 959 void free_config_data(struct logger_config_data *data)
 960 {
 961         list_clear_free_contents(&data->logfile_configs);
 962         free(data->dynamic_config_dir);
 963         qos_free(data->qos);
 964         free(data->first_time_file_path);
 965 }
 966
 967 struct parse_logfile_config_data {
 968         struct logger *server;
 969         struct logger_config_data *data;
 970 };
 971
 972 /**
 973  * @brief Parse logfile line
 974  * @detail Parses a logfile config line
 975  * @param[in] key Config entry key
 976  * @param[in] value Config entry value
 977  * @param[in] userdata Userdata
 978  */
 979 void parse_logfile_config(void *value, void *userdata)
 980 {
 981         assert(value);
 982         assert(userdata);
 983
 984         struct logger *server = ((struct parse_logfile_config_data *) userdata)->server;
 985         struct logger_config_data *data = ((struct parse_logfile_config_data *) userdata)->data;
 986         char *configline = (char *) value;
 987
 988         __attribute__((cleanup(free_dlogutil_line_params))) struct dlogutil_line_params params;
 989         if (!initialize_dlogutil_line_params(&params, server->buf_params))
 990                 return;
 991
 992         get_dlogutil_line_params(configline, data->default_format, &params);
 993
 994         int r;
 995         if (g_backend.use_logger_by_default && is_core_buffer(params.buf_id)) {
 996                 r = params.compression
 997                         ? create_memory_subreader_from_dlogutil_line(&params, server)
 998                         : create_logger_subreader_from_dlogutil_line(&params)
 999                 ;
1000         } else {
1001                 struct reader_pipe *reader = NULL;
1002                 r = create_reader_pipe_from_dlogutil_line(&params, server, &reader);
1003                 if (r == 0)
1004                         add_reader_pipe(server, reader);
1005         }
1006
1007         if (r != 0) {
1008                 errno = -r;
1009                 printf("Warning: unable to add logutil reader for provided configuration. Ignoring.\n"
1010                        "  Config line: %s\n"
1011                        "  Reason given: %m\n",
1012                        configline);
1013         }
1014 }
1015
1016 #ifndef UNIT_TEST
1017 /**
1018  * @brief Print help
1019  * @details Prints basic usage tips
1020  */
1021 static void help(void)
1022 {
1023         printf("Usage: %s [options]\n"
1024                "\t-h    Show this help\n"
1025                "\t-b N  Set the size of the log buffer (in bytes)\n"
1026                "\t-t N  Set time between writes to file (in seconds)\n",
1027                program_invocation_short_name);
1028 }
1029
1030 /**
1031  * @brief Parse args
1032  * @details Parses execution parameters of the program
1033  * @param[in] argc Argument count
1034  * @param[in] argv Argument values
1035  * @param[out] b Buffering parameters
1036  * @return 0 or 1 on success, else -errno. Nonzero if the program is to close.
1037  */
1038 static int parse_args(int argc, char **argv, struct buf_params *b)
1039 {
1040         b->time = BUF_PARAM_TIME_DEFAULT;
1041         b->bytes = BUF_PARAM_BYTES_DEFAULT;
1042
1043         int option;
1044         while ((option = getopt(argc, argv, "hb:t:")) != -1) {
1045                 switch (option) {
1046                 case 't':
1047                         if (!isdigit(optarg[0]))
1048                                 return -EINVAL;
1049                         b->time = clamp_int(atoi(optarg), BUF_PARAM_TIME_MIN, BUF_PARAM_TIME_MAX);
1050                         break;
1051                 case 'b':
1052                         if (!isdigit(optarg[0]))
1053                                 return -EINVAL;
1054                         b->bytes = clamp_int(atoi(optarg), BUF_PARAM_BYTES_MIN, BUF_PARAM_BYTES_MAX);
1055                         break;
1056                 case 'h':
1057                         return 1;
1058                 default:
1059                         return -EINVAL;
1060                 }
1061         }
1062
1063         return 0;
1064 }
1065
1066 /**
1067  * @brief Finalize initialisation
1068  * @details Do misc stuff needed at the end of the initialisation
1069  * @param[in] data configuration dat to read logfiles config lines from
1070  * @param[in] server logger instance to configure
1071  * @return 0 on success, -errno on failure
1072  */
1073 static int finalize_init(struct logger_config_data *data, struct logger *server)
1074 {
1075         int r = sd_notify(0, "READY=1");
1076         if (r < 0)
1077                 return r;
1078
1079         //create files after resetting self privileges
1080         list_foreach(data->logfile_configs, &(struct parse_logfile_config_data) {
1081                 .server = server,
1082                 .data = data,
1083         }, parse_logfile_config);
1084
1085         /* The above created subs for logger readers.
1086          * There is no way for them to gain more at
1087          * runtime, so this is the time to do some
1088          * processing that relies on subs being ready. */
1089         for (log_id_t id = 0; id < LOG_ID_MAX; ++id) {
1090                 struct reader_logger *const reader = g_backend.logger_readers[id];
1091                 if (!reader)
1092                         continue;
1093
1094                 if (reader->common.subs == NULL) {
1095                         reader_free(&reader->common);
1096                         g_backend.logger_readers[id] = NULL;
1097                         continue;
1098                 }
1099
1100                 r = add_reader_logger(server, reader);
1101                 if (r < 0) {
1102                         reader_free(&reader->common);
1103                         g_backend.logger_readers[id] = NULL;
1104                         return r;
1105                 }
1106         }
1107
1108         return 0;
1109 }
1110
1111 static void precreate_logctl_file(struct logger_config_data *data)
1112 {
1113         __attribute__((cleanup(free_ptr))) char *logctl_file_path = NULL;
1114         if (asprintf(&logctl_file_path, "%s/%s", data->dynamic_config_dir, DYNAMIC_CONFIG_FILENAME) < 0)
1115                 // This is worrying but unimportant
1116                 return;
1117
1118         int fd = open(logctl_file_path, O_RDONLY | O_CREAT, 0644);
1119         if (fd < 0)
1120                 // Again, no big deal
1121                 return;
1122
1123         close(fd);
1124 }
1125
1126 bool early_termination(const struct logger_config_data *data, const struct logger *logger) {
1127         /* In order to check if the deamon will be doing nothing
1128          * and can quit instantaneously, we do three checks: */
1129
1130         /* 1. We make sure that there are no Android Logger readers.
1131          * Note that an earlier function gets rid of any readers that
1132          * don't do anything (i.e. have no subs and no way to get them). */
1133         for (log_id_t id = 0; id < LOG_ID_MAX; ++id) {
1134                 const struct reader_logger *const reader = g_backend.logger_readers[id];
1135                 if (!reader)
1136                         continue;
1137
1138                 assert(reader->common.subs != NULL);
1139                 return false;
1140         }
1141
1142         /* 2. We make sure that no pipe-like buffer is enabled.
1143          * When the pipe backend is being used or pipe-like buffers
1144          * (i.e. KMSG, SYSLOG) are handled, the logger allocates space for them.
1145          * In this case, we cannot terminate even if the buffer is enabled
1146          * but unused at the moment, since it might be connected to
1147          * (for instance by dlogutil). */
1148         for (log_id_t id = 0; id < LOG_ID_MAX; id++)
1149                 if (data->is_buffer_enabled[id])
1150                         return false;
1151
1152         /* 3. We make sure that there are no writers.
1153          * In theory, previous checks are sufficient.
1154          * However, we do another check just to be sure
1155          * (since if there are writers, we shouldn't terminate).
1156          * Additionally, this could change in the future,
1157          * so let's hedge against someone forgetting that this function exists. */
1158         return logger->writers == NULL;
1159 }
1160
1161 /**
1162  * @brief The logger
1163  * @return 0 on success, nonzero on failure
1164  * @retval 1 Configuration error
1165  * @retval 2 Runtime error
1166  */
1167 int main(int argc, char **argv)
1168 {
1169         int r, ret;
1170
1171         signal(SIGPIPE, SIG_IGN);
1172
1173         r = reset_self_privileges();
1174         if (r < 0) {
1175                 errno = -r;
1176                 printf("Unable to drop privileges to build-time defaults (%m). Exiting.\n");
1177                 return DLOG_EXIT_ERR_RUNTIME;
1178         }
1179
1180         struct logger_config_data data;
1181         initialize_config_data(&data);
1182
1183         if ((r = parse_args(argc, argv, &data.buf_params)) != 0) {
1184                 help();
1185
1186                 if (r > 0)
1187                         return DLOG_EXIT_SUCCESS; // --help option
1188
1189                 errno = -r;
1190                 printf("Unable to parse command line args (%m). Exiting.\n");
1191                 return DLOG_EXIT_ERR_CONFIG;
1192         }
1193
1194         if ((r = prepare_config_data(&data)) != 0) {
1195                 errno = -r;
1196                 printf("Unable to prepare config (%m). Exiting.\n");
1197                 return DLOG_EXIT_ERR_CONFIG;
1198         }
1199
1200         precreate_logctl_file(&data);
1201
1202         struct logger server;
1203         if ((r = logger_create(&data, &server)) < 0) {
1204                 errno = -r;
1205                 printf("Unable to initialize logger with provided configuration (%m). Exiting.\n");
1206                 ret = DLOG_EXIT_ERR_CONFIG;
1207                 goto cleanup;
1208         }
1209
1210         if ((r = finalize_init(&data, &server)) < 0) {
1211                 errno = -r;
1212                 printf("Unable to finalize initialisation (%m). Exiting.\n");
1213                 ret = DLOG_EXIT_ERR_CONFIG;
1214                 goto cleanup;
1215         }
1216
1217         if (early_termination(&data, &server)) {
1218                 printf("No work to do according to provided configuration. Exiting.\n");
1219                 ret = DLOG_EXIT_SUCCESS;
1220                 goto cleanup;
1221         }
1222
1223         if ((r = do_logger(&server)) < 0) {
1224                 errno = -r;
1225                 printf("Runtime failure (%m). Exiting.\n");
1226                 ret = DLOG_EXIT_ERR_RUNTIME;
1227                 goto cleanup;
1228         }
1229
1230         ret = DLOG_EXIT_SUCCESS;
1231
1232 cleanup:
1233         free_config_data(&data);
1234         logger_free(&server);
1235         return ret;
1236 }
1237 #endif
1238
1239 /**
1240  * @}
1241  * @}
1242  */