dlog_logger: refactor QoS distributions

[platform/core/system/dlog.git] / src / logger / logger.c

/*
 * Copyright (c) 2016, Samsung Electronics Co., Ltd. All rights reserved.
 *
 * Licensed under the Apache License, Version 2.0 (the "License");
 * you may not use this file except in compliance with the License.
 * You may obtain a copy of the License at
 *
 *              http://www.apache.org/licenses/LICENSE-2.0
 *
 * Unless required by applicable law or agreed to in writing, software
 * distributed under the License is distributed on an "AS IS" BASIS,
 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 * See the License for the specific language governing permissions and
 * limitations under the License.
 */

#ifndef _GNU_SOURCE
#define _GNU_SOURCE
#endif

#include "logger_internal.h"
#include "logger_privileges.h"
#include "subreader_file.h"
#include "subreader_metrics.h"
#include "subreader_memory.h"

#include <metrics.h>
#include <getopt.h>
#include <dynamic_config.h>
#include <qos_defaults.h>

/**
 * @addtogroup DLOG_IMPLEMENTATION
 * @{
 * @defgroup DLOG_LOGGER Logger
 * @brief Logger daemon
 * @details The logger is the core component of the logging framework. It is responsible for collecting, processing and exposing logs.
 * @{
 */

// function prototypes
static int initialize_epoll_size(struct epoll_event **events, unsigned *size);

/** global state when logger is not interrupted by any handled signals */
static volatile sig_atomic_t g_logger_run = 1;

static const int DEFAULT_EPOLL_TIME_MS = 1000;

static const int DEFAULT_LAZY_POLLING_TOTAL_MS = 0;
static const int DEFAULT_LAZY_POLLING_SLEEP_MS = 1000;

static const int S_TO_MS = 1000;
static const int MS_TO_NS = 1000000;

struct backend_data g_backend = {};

static bool cond_reader_logger_free(void *ptr, void *user_data)
{
        struct reader_logger *reader = (struct reader_logger *)ptr;
        struct logger *logger = (struct logger *)user_data;
        assert(reader);
        // TODO: This is absurd, why isn't this in the reader_logger_free function?
        if (reader->common.fd_entity_sink.fd >= 0)
                remove_fd_entity(&logger->epoll_common, &reader->common.fd_entity_sink);
        if (reader->common.fd_entity_source.fd >= 0)
                remove_fd_entity(&logger->epoll_common, &reader->common.fd_entity_source);
        reader_free(&reader->common);
        return true;
}

// TODO: Consider inlining struct now_t everywhere
int get_now(struct now_t *now)
{
        if (clock_gettime(CLOCK_MONOTONIC, &now->mono))
                return -errno;
        if (clock_gettime(CLOCK_REALTIME, &now->real))
                return -errno;
        return 0;
}

void qos_periodic_check(struct logger *server)
{
        struct qos_module *const qos = &server->qos;
        struct timespec ts_mono;
        if (clock_gettime(CLOCK_MONOTONIC, &ts_mono))
                return;

        if (ts_mono.tv_sec < qos->cancel_limits_at.tv_sec)
                return;
        if (ts_mono.tv_sec == qos->cancel_limits_at.tv_sec
        &&  ts_mono.tv_nsec < qos->cancel_limits_at.tv_nsec)
                return;

        if (metrics_get_total(qos->log_metrics) >= qos->threshold)
                qos_apply_limits(qos);
        else
                qos_relax_limits(qos);

        qos_set_next_update_time(qos, ts_mono);
        metrics_clear(qos->log_metrics);
}

/**
 * @brief FD limit handler
 * @details Checks whether the FD limit was reached and leaves logs about it if so
 * @param[in] server The logger server
 * @param[in] err errno from the call that failed to create an FD
 */
void check_if_fd_limit_reached(struct logger *server, int err)
{
        assert(server);

        if (err != ENFILE && err != EMFILE)
                return;

        printf("ERROR: dlog_logger fd limit reached!\n");

        /* pick one representative buffer to send the log to;
         * no point spamming all the buffers, especially since
         * default dlogutil invocations display 3 buffers so
         * it would appear multiple times */
        struct log_buffer *const buf = server->buffers[LOG_ID_MAIN];
        if (!buf)
                return;

        struct dlogutil_entry_with_msg entry;
        create_pipe_message(&entry,
                DLOG_FATAL, /* not really FATAL, but since we're at the FD limit
                             * there are thousands of logging programs so this one
                             * would likely get lost in the flood since developers
                             * tend to overuse ERROR (and FATAL is the one above) */
                "DLOG",
                "\x1b[31m DLOG DAEMON FD LIMIT REACHED \x1b[0m" // make it stand out
                , getpid(), gettid()
        );
        struct now_t now;
        int r = get_now(&now);
        if (r < 0)
                return;
        set_pipe_message_sent_timestamp((struct pipe_logger_entry *) &entry, &now.mono, &now.real);

        if (buffer_append(&entry.header, buf))
                printf("ERROR: not enough memory either, please check platform settings as the daemon is seriously resource-starved!\n");
}

void flush_logfile_timely(struct log_file *file, struct timespec ts, int flush_time)
{
        if (file->buffer.position > 0) {
                if (ts.tv_sec - file->buffer.oldest_log.tv_sec +
                                        (ts.tv_nsec > file->buffer.oldest_log.tv_nsec ? 1 : 0) >
                                flush_time)
                        logfile_flush(file);
        }
}

void reader_pipe_notify_losing_log(const dlogutil_entry_s *le, void *reader_)
{
        struct reader_pipe *reader = (struct reader_pipe *) reader_;
        assert(le);
        assert(reader);
        reader_pipe_print_out_single_log(reader, (dlogutil_entry_s *)le);
}

/**
 * @brief Add reader to log buffer
 * @details Adds a reader to the log buffers reader list
 * @param[in] log_buffer The buffer whither to add the reader
 * @param[in] reader The reader to add to the buffer
 * @return 0 on success, -ENOMEM on memory allocation error
 */
int add_buffer_reader(struct log_buffer *buffer, struct reader_pipe *reader)
{
        assert(reader);
        assert(buffer);

        reader->log_storage_reader_ptr = log_storage_new_reader(buffer->log_storage_ptr,
                        reader->is_dumping, reader->monitor, reader_pipe_notify_losing_log, reader);

        if (!reader->log_storage_reader_ptr)
                return -ENOMEM;

        return list_add(&buffer->readers_pipe, reader) ? 0 : -ENOMEM;
}

static int add_reader_common(struct logger *server, struct reader_common *reader)
{
        assert(reader);
        assert(server);

        if (reader->fd_entity_sink.fd >= 0) {
                /* Readers who write to file have no sink FD entity (or, strictly
                 * speaking, they do have one but it is not filled) since a file
                 * is not eligible to be added to epoll. However, the entity primarily
                 * serves to handle pipes getting clogged mid-write (which cannot
                 * happen for files) and is not involved in starting a write,
                 * which is handled by the source FD entity, not sink (and which is
                 * also done periodically for all readers anyway regardless
                 * of whether they've been added to epoll or not). The other use
                 * case for epoll - the one where connection FDs leak for unused
                 * buffers - is not a problem here because the daemon is not
                 * supposed to ever stop writing to files. */

                int r = add_fd_entity(&server->epoll_common, &reader->fd_entity_sink);
                if (r < 0)
                        return r;
        }

        return 0;
}

int add_reader_pipe(struct logger *server, struct reader_pipe *reader)
{
        assert(reader);
        assert(server);

        int ret = add_reader_common(server, &reader->common);
        if (ret < 0)
                return ret;

        ret = add_buffer_reader(reader->buf_ptr, reader);
        if (ret < 0 && reader->common.fd_entity_sink.fd >= 0)
                remove_fd_entity(&server->epoll_common, &reader->common.fd_entity_sink);

        return ret;
}

int add_reader_memory(struct logger *server, struct reader_memory *reader)
{
        assert(reader);
        assert(server);

        int ret = add_reader_common(server, &reader->common);
        if (ret < 0)
                return ret;

        // `readers_logger` actually accepts any readers
        if (!list_add(&server->readers_logger, reader)) {
                if (reader->common.fd_entity_sink.fd >= 0)
                        remove_fd_entity(&server->epoll_common, &reader->common.fd_entity_sink);
                return -ENOMEM;
        }

        return 0;
}

#ifndef UNIT_TEST
/* This really belongs to the UNIT_TEST block at the bottom since it is only used
 * by a function living there, but has not been moved there to keep patches small
 * and because this function is going to be removed soon in an upcoming patch. */

static int add_reader_logger(struct logger *server, struct reader_logger *reader)
{
        assert(reader);
        assert(server);

        int ret = add_reader_common(server, &reader->common);
        if (ret < 0)
                return ret;

        assert(reader->common.fd_entity_source.fd >= 0);
        ret = add_fd_entity(&server->epoll_common, &reader->common.fd_entity_source);
        if (ret < 0)
                goto failure;

        if (!list_add(&server->readers_logger, reader)) {
                remove_fd_entity(&server->epoll_common, &reader->common.fd_entity_source);
                ret = -ENOMEM;
                goto failure;
        }

        return 0;

failure:
        if (reader->common.fd_entity_sink.fd >= 0)
                remove_fd_entity(&server->epoll_common, &reader->common.fd_entity_sink);

        return ret;
}
#endif

int create_fifo_fds(struct logger *server, int pipe_fd[2], int flags, bool dump)
{
        int ret = get_nonblocking_fifo(pipe_fd, flags);
        if (ret < 0)
                return ret;

        /* Speed up dumping dlogutils by increasing their pipe size,
         * as otherwise this pipe's size becomes a major bottleneck.
         *
         * Continuous connections don't really care if the initial
         * burst of "historic" logs is slow and the following flow
         * of logs is just fine with a small pipe. Meanwhile they
         * live for a long time during which they would take away
         * from the valuable total pipe size. */
        if (dump)
                if (fcntl(pipe_fd[1], F_SETPIPE_SZ, DUMPING_READER_PIPE_SIZE) < 0) {
                        /* Ignore; this is just a performance optimisation
                         * and doesn't affect functionality so while errors
                         * are worrisome they not a big deal or something
                         * we can do anything about, at any rate. */
                }

        return ret;
}

static int create_memory_subreader_for_common(struct dlogutil_line_params *params, struct reader_common *reader, struct logger *server)
{
        struct log_compressed_storage *storage = log_compressed_storage_create(params->file.rotate_size_kbytes * 1024, params->compression, params->mem_algo);
        if (!storage)
                return -ENOMEM;

        list_add(&server->compressed_memories, storage);

        return reader_add_subreader_memory(reader, params->filter, storage);
}

static int create_memory_subreader_from_dlogutil_line(struct dlogutil_line_params *params, struct logger *server)
{
        assert(params);
        assert(params->compression);

        if (params->file_path) // We're writing to memory, not to file
                return -EINVAL;

        if (params->buf_id == LOG_ID_INVALID)
                return -EINVAL;

        struct reader_logger *const reader = g_backend.logger_readers[params->buf_id];
        if (!reader)
                return -ENOENT;

        return create_memory_subreader_for_common(params, &reader->common, server);
}

static int create_logger_subreader_from_dlogutil_line(struct dlogutil_line_params *params)
{
        assert(params);
        assert(!params->compression);

        if (params->file_path) {
                int retval = logfile_set_path(&params->file, params->file_path);
                if (retval < 0)
                        return retval;

                retval = logfile_open(&params->file);
                if (retval < 0)
                        return retval;
        }

        if (params->buf_id == LOG_ID_INVALID)
                return -EINVAL;

        if (params->file.path == NULL)
                return -EINVAL;

        struct reader_logger *const reader = g_backend.logger_readers[params->buf_id];
        if (!reader)
                return -ENOENT;

        return reader_add_subreader_file(&reader->common, params->filter, &params->file, DLOGUTIL_SORT_SENT_REAL);
}

static int create_reader_pipe_from_dlogutil_line(struct dlogutil_line_params *params, struct logger *server, struct reader_pipe **rd)
{
        assert(server);
        assert(rd);

        __attribute__((cleanup(reader_free_ptr))) struct reader_pipe *reader = NULL;
        int retval;

        if (params->file_path) {
                retval = logfile_set_path(&params->file, params->file_path);
                if (retval < 0)
                        return retval;

                retval = logfile_open(&params->file);
                if (retval < 0)
                        return retval;
        }

        if (params->buf_id == LOG_ID_INVALID)
                return -EINVAL;

        if ((params->file.path == NULL && !params->compression)
        ||  (params->file.path != NULL &&  params->compression))
                return -EINVAL;

        retval = reader_pipe_init(&reader, params->buf_id, server, params->monitor, params->is_dumping);
        if (retval != 0)
                return retval;

        if (params->file.path == NULL) {
                assert(params->compression);
                retval = create_memory_subreader_for_common(params, &reader->common, server);
                if (retval != 0)
                        return retval;
        } else {
                /* FIXME: in theory these could be added independently (1 reader 2 subs),
                 * but so far that has not been needed and it sounds too fragile to do in haste.
                 * Keep in mind the reader only has one sink FD entity though, so unless
                 * that is rewritten, there can be only one sub with poll-dependent output. */
                assert(!params->compression);
                retval = reader_add_subreader_file(&reader->common, params->filter, &params->file, server->buffers[params->buf_id]->sort_by);
                if (retval != 0)
                        return retval;
        }

        *rd = reader;
        reader = NULL;

        return 0;
}

/**
 * @brief Service a socket request
 * @details Handle a socket request
 * @param[in] server The logger server
 * @param[in] wr The writer who sent the request
 * @param[in] event The event containing the request
 * @return 0 on success, else -errno
 */
int service_writer_socket(struct logger *server, struct writer *wr, struct epoll_event *event)
{
        int r = 0;

        assert(wr);
        struct dlog_control_msg *const msg = (struct dlog_control_msg *) wr->buffer;

        assert(event);
        if (event->events & EPOLLIN)
                r = read(wr->fd_entity.fd, wr->buffer + wr->readed, sizeof wr->buffer - wr->readed);

        if ((r == 0 || r == -1) && event->events & EPOLLHUP)
                return -EINVAL;

        do {
                if (r > 0)
                        wr->readed += r;

                /* The socket is SOCK_STREAM (see `listen_fd_create`), so one message
                 * could be split into chunks returned across multiple read() calls. */
                if (wr->readed < sizeof(msg->length)
                ||  wr->readed < msg->length)
                        goto dont_process_yet_and_read_more_data;

                assert(wr->service_socket);
                r = wr->service_socket(server, wr, msg);
                if (r <= 0)
                        return r;

dont_process_yet_and_read_more_data:
                r = read(wr->fd_entity.fd, wr->buffer + wr->readed, sizeof wr->buffer - wr->readed);
        } while (r > 0 || ((wr->readed >= sizeof(msg->length) && wr->readed >= msg->length)));

        return (r >= 0 || errno == EAGAIN)  ? 0 : r;
}

/**
 * @brief Service /dev/kmsg
 * @details Read from the /dev/kmsg device
 * @param[in] server The logger server
 * @param[in] wr The writer who sent the request
 * @param[in] event The relevant event
 * @return 0 on success, else -errno
 */
int service_writer_kmsg(struct logger *server, struct writer *wr, struct epoll_event *event)
{
        (void) server;
        if (event->events & EPOLLHUP)
                return -EBADF;
        if (!(event->events & EPOLLIN))
                return 0;

        /* The KMSG device returns just 1 log per read() so it is done in a loop.
         * In theory this could starve everything else out if logs appeared faster
         * than the daemon could process them, which would then necessitate some
         * sort of throttling. In practice, KMSG doesn't really get flooded with
         * logs the same way Android Logger devices are so the throttling is mostly
         * there because we get it for free anyway and consistency doesn't hurt. */

        int max_loop_iterations = g_backend.logger_device_throttling[LOG_ID_KMSG];
        while (max_loop_iterations--) {
                int r = read(wr->fd_entity.fd, wr->buffer, sizeof wr->buffer - 1);

                if (r == -1 && (errno == EAGAIN || errno == EPIPE))
                        return 0;
                else if ((r == 0 || r == -1) && event->events & EPOLLHUP)
                        return -EINVAL;
                else if (r == 0)
                        return -EBADF;
                else if (r == -1)
                        return -errno;

                wr->buffer[r] = '\0';
                struct dlogutil_entry_with_msg lem;
                if (parse_kmsg_message(wr->buffer, &lem, r)) {
                        // don't signal an error: KMSG writer is too important to remove; besides, it would not get fixed that way.
                        return 0;
                }

                struct now_t now;
                r = get_now(&now);
                if (r < 0)
                        return r;
                add_recv_timestamp(&lem.header, now);

                r = buffer_append(&lem.header, wr->buf_ptr);
                if (r < 0)
                        return r;
        }

        return 0;
}

void remove_reader_fd_entities(struct logger *server, struct reader_common *reader)
{
        assert(reader);

        if (reader->fd_entity_sink.fd >= 0)
                remove_fd_entity(&server->epoll_common, &reader->fd_entity_sink);
        if (reader->fd_entity_source.fd >= 0)
                remove_fd_entity(&server->epoll_common, &reader->fd_entity_source);
}

static bool cond_service_reader_common(void *ptr, void *user_data)
{
        struct reader_common *reader = (struct reader_common *)ptr;
        struct logger *logger = (struct logger *)user_data;

        assert(reader);
        assert(logger);

        struct now_t now;
        int r = get_now(&now);
        if (r < 0) {
                remove_reader_fd_entities(logger, reader);
                reader_free(reader);
                return true;
        }

        r = reader->service_reader(reader, now);
        if (r > 0) {
                remove_reader_fd_entities(logger, reader);
                reader_free(reader);
                return true;
        }

        /* `service_reader()` returns -1 if everything was flushed, or 0 if
         * a mild error happened that can be recovered from simply by waiting,
         * the prime example being the pipe getting clogged. As soon as the
         * reader is available again, we'd like to know about it to ensure
         * logs are flushed as quickly as possible, which is why the EPOLLOUT.
         *
         * On the other hand, we don't want to remove readers from epoll even
         * if they successfully flushed and have no logs to wait for. Consider
         * the case where a buffer is unused (for example through libdlog's
         * buffer disabling feature). If we relied on receiving an error on
         * calling `write()` to learn that the connection had been closed,
         * we would never learn about it because there would be no incoming
         * logs to trigger the flush and so any FDs representing connections
         * to such buffer would leak until a log finally arrived (which could
         * be never). This is why waiting is also done on EPOLLHUP. */
        if (modify_fd_entity(&logger->epoll_common, &reader->fd_entity_sink, (r == 0) ? EPOLLOUT : EPOLLHUP) < 0) {
                /* ignore, can't really happen and it's not
                 * like we can do anything about it either */
        }

        // Ditto, can't do much about it
        (void) reader_flush(reader, now.mono, logger->buf_params.time);

        return false;
}

/**
 * @brief Service syslog
 * @details Read from the syslog socket
 * @param[in] server The logger server
 * @param[in] wr The writer who sent the request
 * @param[in] event The relevant event
 * @return 0 on success, else -errno
 */
int service_writer_syslog(struct logger *server, struct writer *wr, struct epoll_event *event)
{
        if (event->events & EPOLLHUP)
                return -EBADF;
        if (!(event->events & EPOLLIN))
                return 0;

        int r = read(wr->fd_entity.fd, wr->buffer, sizeof wr->buffer - 1);

        if (r == -1 && (errno == EAGAIN || errno == EPIPE))
                return 0;
        else if ((r == 0 || r == -1) && event->events & EPOLLHUP)
                return -EINVAL;
        else if (r == 0)
                return -EBADF;
        else if (r == -1)
                return -errno;

        wr->buffer[r] = '\0';

        struct dlogutil_entry_with_msg lem;
        if (parse_syslog_datagram(wr->buffer, r + 1, &lem.header)) {
                /* don't return parse error as writers are removed then */
                return 0;
        }

        struct now_t now;
        r = get_now(&now);
        if (r < 0)
                return r;
        add_recv_timestamp(&lem.header, now);

        return buffer_append(&lem.header, wr->buf_ptr);
}

/**
 * @brief Service all readers
 * @details Update all readers with latest data
 * @param[in] server The logger server
 * @param[in] force_push Whether to force logs to be pushed to the readers
 */
static void service_all_readers(struct logger *server)
{
        for (int i = 0; i < LOG_ID_MAX; i++) {
                struct log_buffer *const buffer = server->buffers[i];
                if (!buffer)
                        continue;

                list_remove_if(&buffer->readers_pipe, server, cond_service_reader_common);
        }
        list_remove_if(&server->readers_logger, server, cond_service_reader_common);
}

/**
 * @brief Add writer to server
 * @details Adds a writer to the server's witers list and registers its event to epoll loop
 * @param[in] l The server to add the writer to
 * @param[in] writer The writer to add to the server and register its working_fd to epoll loop
 */
void logger_add_writer(struct logger *l, struct writer *wr)
{
        assert(l);
        assert(wr);

        list_add(&l->writers, wr);
        add_fd_entity(&l->epoll_common, &wr->fd_entity);
}

int epoll_metadata_initialize(struct epoll_metadata *metadata)
{
        metadata->fd = epoll_create1(0);
        if (metadata->fd < 0)
                return -errno;

        int r = initialize_epoll_size(&metadata->events, &metadata->events_size);
        if (r < 0) {
                close(metadata->fd);
                metadata->fd = -1;
                return r;
        }

        metadata->cnt = 0;
        return 0;
}

void epoll_metadata_destroy(struct epoll_metadata *metadata)
{
        if (metadata->fd >= 0)
                close(metadata->fd);

        free(metadata->events);
}

/**
 * @brief Create the logger server
 * @details Allocate the logger server's auxiliary structures (buffers etc.)
 * @param[in] data Initialisation data
 * @param[out] l The logger server
 * @return 0 on success, -errno on failure
 */
#ifndef UNIT_TEST
static
#endif
int logger_create(struct logger_config_data *data, struct logger *l)
{
        memset(l, 0, sizeof *l);
        l->epoll_socket.fd = -1;

        int r = epoll_metadata_initialize(&l->epoll_common);
        if (r < 0)
                return r;
        r = epoll_metadata_initialize(&l->epoll_socket);
        if (r < 0)
                return r;

        l->epolltime = data->epoll_time;

        l->buf_params = data->buf_params;

        l->qos.log_metrics = metrics_create();
        if (!l->qos.log_metrics)
                return -ENOMEM;

        l->qos.max_throughput = data->qos_max_throughput;
        l->qos.threshold = data->qos_threshold;
        l->qos.threshold_reapply = data->qos_threshold_reapply;
        l->qos.limit_duration = data->qos_limit_duration;
        l->qos.file_path = data->qos_file_path;
        l->qos.distribution_func = data->distribution_func;
        data->qos_file_path = NULL;

        // Check if the daemon is being launched for the first time since reboot
        bool first_time;
        if (data->first_time_file_path) {
                int fd = open(data->first_time_file_path, O_CREAT | O_EXCL | O_RDONLY, 0644);
                if (fd == -1) {
                        if (errno == EEXIST)
                                first_time = false;
                        else
                                return -errno;
                } else {
                        first_time = true;
                        close(fd);
                }
        } else
                // If no path, assume first time
                first_time = true;

        if (g_backend.use_logger_by_default)
                for (log_id_t id = 0; id < LOG_ID_MAX; ++id) {
                        if (!is_core_buffer(id))
                                continue;

                        int r = reader_logger_init(g_backend.logger_readers + id, id, l, !first_time);
                        if (r < 0)
                                return r;
                        if (!g_backend.logger_readers[id])
                                continue;

                        if (qos_is_enabled(&l->qos)) {
                                r = reader_add_subreader_metrics(&g_backend.logger_readers[id]->common, &l->qos);
                                if (r < 0) {
                                        reader_free(&g_backend.logger_readers[id]->common);
                                        g_backend.logger_readers[id] = NULL;
                                        return r;
                                }
                        }

                        /* The reader is not yet complete; later in `finalize_init`
                         * it will receive further readers and be added to epoll
                         * or alternatively get culled if it gets no sub-readers. */
                }

        for (log_id_t id = 0; id < LOG_ID_MAX; id++)
                if (data->is_buffer_enabled[id]) {
                        int r = buffer_create(&l->buffers[id], id, data->buffers + id);
                        if (r < 0)
                                return r;
                }

        for (log_id_t id = 0; id < LOG_ID_MAX; id++)
                if (l->buffers[id]) {
                        add_fd_entity(&l->epoll_common, &l->buffers[id]->sock_ctl.fd_entity);
                        add_fd_entity(&l->epoll_common, &l->buffers[id]->sock_conn.fd_entity);

                        add_fd_entity(&l->epoll_socket, &l->buffers[id]->sock_ctl.fd_entity);
                        add_fd_entity(&l->epoll_socket, &l->buffers[id]->sock_conn.fd_entity);
                }

        /* TODO: make writers creation optional/configurable */
        int (*writers_factories[LOG_ID_MAX])(struct writer **writer, struct log_buffer *log_buf) = {
                [LOG_ID_KMSG] = create_kmsg_writer,
                [LOG_ID_SYSLOG] = create_syslog_writer,
        };
        for (unsigned u = 0; u < NELEMS(writers_factories); ++u)
                if (writers_factories[u] && data->is_buffer_enabled[u]) {
                        struct writer *wr;
                        int r = writers_factories[u](&wr, l->buffers[u]);
                        if (r < 0)
                                return r;

                        logger_add_writer(l, wr);
                }

        return 0;
}

static bool cond_writer_free(void *ptr, void *user_data)
{
        writer_free((struct writer *)ptr, (struct logger *)user_data);
        return true;
}

/**
 * @brief Free logger
 * @details Deallocate the logger and its auxiliary structures
 * @param[in] l The logger server
 */
#ifndef UNIT_TEST
static
#endif
void logger_free(struct logger *l)
{
        assert(l);

        list_remove_if(&l->writers, l, cond_writer_free);
        list_remove_if(&l->readers_logger, l, cond_reader_logger_free);

        int j;
        for (j = 0; j < LOG_ID_MAX; j++)
                if (l->buffers[j])
                        buffer_free(l->buffers[j], l);

        epoll_metadata_destroy(&l->epoll_common);
        epoll_metadata_destroy(&l->epoll_socket);

        qos_free(&l->qos);
}

/**
 * @brief Handle interrupting/terminating signals
 * @details Clears global flag to stop main loop
 * @param[in] signo signal number
 */
static void handle_signals(int signo)
{
        (void) signo;
        g_logger_run = 0;
}

static void ensure_epoll_size(struct epoll_event **events, unsigned *size, unsigned wanted_size)
{
        assert(events);
        assert(size);

        if (wanted_size <= *size)
                return;

        typeof(*events) temp = realloc(*events, wanted_size * sizeof **events);
        if (!temp)
                return;

        *events = temp;
        *size = wanted_size;
}

static int initialize_epoll_size(struct epoll_event **events, unsigned *size)
{
        assert(events);
        assert(size);

        static const size_t default_size = 16U;
        typeof(*events) ev = malloc(default_size * sizeof *ev);
        if (!ev)
                return -ENOMEM;

        *events = ev;
        *size = default_size;
        return 0;
}

void dispatch_epoll_event(struct logger *server, struct epoll_event *event)
{
        struct fd_entity *const entity = (struct fd_entity *) event->data.ptr;
        assert(entity->dispatch_event);
        entity->dispatch_event(server, event, entity->dispatch_data);
}

int handle_epoll_events(struct logger *server, struct epoll_metadata *metadata, int timeout)
{
        ensure_epoll_size(&metadata->events, &metadata->events_size, metadata->cnt);

        int nfds = epoll_wait(metadata->fd, metadata->events, metadata->events_size, timeout);
        if (nfds < 0)
                return errno == EINTR ? 0 : -errno;

        for (int i = 0; i < nfds; i++)
                dispatch_epoll_event(server, metadata->events + i);

        return 0;
}

int sleep_while_handling_socket(struct logger *server, struct epoll_metadata *metadata, int timeout)
{
        struct timespec ts_start;
        if (clock_gettime(CLOCK_MONOTONIC, &ts_start))
                return -errno;
        struct timespec ts_current;

        do {
                int r = handle_epoll_events(server, metadata, timeout);
                if (r < 0)
                        return r;
                if (clock_gettime(CLOCK_MONOTONIC, &ts_current))
                        return -errno;
        } while (
                timeout > (ts_current.tv_sec  - ts_start.tv_sec ) *  S_TO_MS
                        + (ts_current.tv_nsec - ts_start.tv_nsec) / MS_TO_NS
        );

        return 0;
}

void setup_signals(struct logger *server)
{
        struct sigaction action = {
                .sa_handler = handle_signals,
                .sa_flags   = 0
        };
        sigemptyset(&action.sa_mask);

        static const int handled_signals[] = { SIGINT, SIGTERM };
        for (unsigned u = 0; u < NELEMS(handled_signals); ++u)
                sigaction(handled_signals[u], &action, NULL);
}

static bool do_logger_one_iteration(struct logger *server, bool *use_lazy_polling)
{
        if (*use_lazy_polling)
                sleep_while_handling_socket(server, &server->epoll_socket, g_backend.lazy_polling_sleep);

        if (g_backend.lazy_polling_total > 0) {
                g_backend.lazy_polling_total -= g_backend.lazy_polling_sleep;
                *use_lazy_polling = (g_backend.lazy_polling_total > 0);
        }

        int r = handle_epoll_events(server, &server->epoll_common, server->epolltime * !*use_lazy_polling);
        if (r < 0)
                return false;

        service_all_readers(server);
        qos_periodic_check(server);
        return true;
}

/**
 * @brief Do logging
 * @details The main logging loop
 * @param[in] server The logger server
 * @return 0 on success, else -errno
 */
#ifndef UNIT_TEST
static
#endif
int do_logger(struct logger *server)
{
        setup_signals(server);

        /* Note, negative values are applied here, but not in the check in
         * the inner function. This leaves lazy polling enabled forever
         * and is a feature. */
        bool use_lazy_polling = (g_backend.lazy_polling_total != 0);
        while (g_logger_run)
                if (!do_logger_one_iteration(server, &use_lazy_polling))
                        break;

        /* ensure all logs are written no matter when the program was interrupted */
        server->exiting = 1;
        service_all_readers(server);

        return 0;
}

/**
 * @brief Prepare socket data
 * @details Extracts initialisation data specific to each socket
 * @param[in] conf Config database
 * @param[out] data Socket init config data
 * @param[in] buf_name The name of the buffer the socket belongs to
 * @param[in] type The name of the buffer type
 * @return 0 on success, -errno on failure
 */
int prepare_socket_data(const struct log_config *conf, struct socket_config_data *data, char *buf_name, const char *type)
{
        char conf_key[MAX_CONF_KEY_LEN];
        int r;

        r = snprintf(conf_key, MAX_CONF_KEY_LEN, "%s_%s_sock", buf_name, type);
        if (r < 0)
                return -errno;
        const char * const path = log_config_get(conf, conf_key);

        r = snprintf(conf_key, MAX_CONF_KEY_LEN, "%s_%s_sock_rights", buf_name, type);
        if (r < 0)
                return -errno;
        const char * const permissions_str = log_config_get(conf, conf_key);

        if (!permissions_str || !path)
                return -ENOENT;

        data->permissions = parse_permissions(permissions_str);
        if (data->permissions <= 0)
                return -EINVAL;

        strncpy(data->path, path, MAX_CONF_VAL_LEN - 1);

        return 0;
}

/**
 * @brief Prepare buffer data
 * @details Extracts data specific for each buffer
 * @param[in] conf Config database
 * @param[out] data Buffer init config data
 * @param[in] buf_id Index of the buffer to work with
 * @return 0 on success, -errno on failure
 */
int prepare_buffer_data(const struct log_config *conf, struct buffer_config_data *data, log_id_t buf_id)
{
        char * const buf_name = log_name_by_id(buf_id);
        char * validity_check_ptr;
        char conf_key[MAX_CONF_KEY_LEN];
        int r;

        r = prepare_socket_data(conf, &data->conn_socket, buf_name, "conn");
        if (r < 0)
                return r;

        r = prepare_socket_data(conf, &data->ctl_socket, buf_name, "ctl");
        if (r < 0)
                return r;

        r = snprintf(conf_key, MAX_CONF_KEY_LEN, "%s_size", buf_name);
        if (r < 0)
                return -errno;

        const char * const size_str = log_config_get(conf, conf_key);
        if (!size_str)
                return -ENOENT;

        data->size = strtol(size_str, &validity_check_ptr, 10);
        if (*validity_check_ptr)
                return -EINVAL;
        if (data->size <= 0)
                return -EINVAL;

        return 0;
}

/**
 * @brief Save logfile line
 * @detail Saves logfile config line in user_data list
 * @param[in] key Config entry key
 * @param[in] value Config entry value
 * @param[in] userdata Userdata
 */
void save_logfile_config(char const *key, char const *value, void *userdata)
{
        assert(userdata);
        if (strncmp(key, CONF_PREFIX, sizeof CONF_PREFIX - 1))
                return;

        struct logger_config_data *data = (struct logger_config_data *)userdata;
        void *cmd = (void *)strdup(value);
        if (cmd)
                list_add(&data->logfile_configs, cmd);
        //ignore errors
}

/**
 * @brief Initialize config data
 * @param[out] The data structure to fill with initial values
 */
void initialize_config_data(struct logger_config_data *data)
{
        memset(data, 0, sizeof *data);
}

/**
 * @brief Prepare config data
 * @details Extracts relevant config data for logger initialisation
 * @param[out] data Parsed configuration
 * @return 0 on success, -errno on failure
 */
int prepare_config_data(struct logger_config_data *data)
{
        assert(data);

        struct log_config conf;
        int ret = log_config_read(&conf);
        if (ret < 0)
                return ret;

        const dlogutil_sorting_order_e sort_by = get_order_from_config(&conf);

        int throttling_default = log_config_get_int(&conf, "logger_dev_throttling", LOGGER_DEVICE_THROTTLING_DEFAULT);
        const char *const dynamic_config_dir = log_config_get(&conf, DYNAMIC_CONFIG_CONF_KEY);

        const char * const backend = log_config_claim_backend(&conf);
        if (!backend) {
                ret = -ENOENT;
                goto end;
        }

        if (!strcmp(backend, "null")) {
                ret = -ENODATA;
                goto end;
        }

        for (int i = 0; i < LOG_ID_MAX; i++) {
                char key[MAX_CONF_KEY_LEN];
                const int r = snprintf(key, sizeof key, "logger_dev_throttling_%s", log_name_by_id((log_id_t)i));
                if (r < 0)
                        continue;

                g_backend.logger_device_throttling[i] = max_int(1, log_config_get_int(&conf, key, throttling_default));
        }

        if (dynamic_config_dir && dynamic_config_dir[0] == '/') {
                data->dynamic_config_dir = strdup(dynamic_config_dir);
                if (!data->dynamic_config_dir) {
                        ret = -ENOMEM;
                        goto end;
                }
        } else {
                data->dynamic_config_dir = NULL; // Technically unnecessary but no reason not to put it
        }

        data->epoll_time = log_config_get_int(&conf, "epoll_time_ms", DEFAULT_EPOLL_TIME_MS);
        g_backend.lazy_polling_total = 0; // Android Logger backend only, read below

        const char *const qos_file_path = log_config_get(&conf, "qos_file_path");
        data->qos_file_path = qos_file_path ? strdup(qos_file_path) : NULL;

        data->qos_limit_duration = log_config_get_int(&conf, "qos_refresh_rate_s", DEFAULT_QOS_LIMIT_DURATION_S);
        data->qos_max_throughput = log_config_get_int(&conf, "qos_max_throughput_logs", DEFAULT_QOS_THROUGHPUT_LOGS);
        data->qos_threshold = log_config_get_int(&conf, "qos_threshold_logs", DEFAULT_QOS_THRESHOLD_LOGS);
        data->qos_threshold_reapply = log_config_get_int(&conf, "qos_threshold_reapply_logs", DEFAULT_QOS_THRESHOLD_REAPPLY_LOGS);
        data->distribution_func = qos_get_distribution_func_by_name(log_config_get(&conf, "qos_method"));

        const char *const first_time_file_path = log_config_get(&conf, "first_time_file_path");
        data->first_time_file_path = first_time_file_path ? strdup(first_time_file_path) : NULL;

        memset(data->is_buffer_enabled, 0, sizeof(data->is_buffer_enabled));
        if (!strcmp(backend, "pipe")) {
                data->is_buffer_enabled[LOG_ID_MAIN] =
                        data->is_buffer_enabled[LOG_ID_RADIO] =
                        data->is_buffer_enabled[LOG_ID_SYSTEM] =
                        data->is_buffer_enabled[LOG_ID_APPS] = 1;
                g_backend.use_logger_by_default = false;
        } else if (!strcmp(backend, "logger")) {
                g_backend.use_logger_by_default = true;
                for (log_id_t buf_id = 0; buf_id < LOG_ID_MAX; ++buf_id) {
                        const char *const logger_device = log_config_get(&conf, log_name_by_id(buf_id));
                        if (logger_device)
                                strncpy(g_backend.logger_devices[buf_id], logger_device,
                                        NELEMS(g_backend.logger_devices[buf_id]) - 1);
                }
                g_backend.lazy_polling_total = log_config_get_int(&conf, "lazy_polling_total_ms", DEFAULT_LAZY_POLLING_TOTAL_MS);
                g_backend.lazy_polling_sleep = log_config_get_int(&conf, "lazy_polling_sleep_ms", DEFAULT_LAZY_POLLING_SLEEP_MS);

                /* The total can be 0 (no lazy polling) or negative (infinite),
                 * but the sleep length has to be positive. */
                if (g_backend.lazy_polling_sleep < 1)
                        g_backend.lazy_polling_sleep = 1;

        } else if (!strcmp(backend, "zero-copy")) {
                /* HACK: This essentially skips reading the most important configuration fields
                 * (buffer reading and persistent logs) while ensuring the variables are initialized.
                 * This will result in daemon quitting. Hopefully we will either reenable some of these
                 * in the future or at least make it exit more gracefully (TODO), but for now this is ok. */
                g_backend.use_logger_by_default = false;
                data->logfile_configs = NULL;
                goto end;
        } else {
                ret = -ENOENT;
                goto end;
        }
        data->is_buffer_enabled[LOG_ID_KMSG] = log_config_get_boolean(&conf, "handle_kmsg", true);
        data->is_buffer_enabled[LOG_ID_SYSLOG] =
                dev_log_sock_get() >= 0 || log_config_get_boolean(&conf, "syslog_force", false);

        for (log_id_t buf_id = 0; buf_id < LOG_ID_MAX; ++buf_id) {
                if (data->is_buffer_enabled[buf_id]) {
                        ret = prepare_buffer_data(&conf, data->buffers + buf_id, buf_id);
                        if (ret < 0)
                                goto end;
                        data->buffers[buf_id].sort_by = sort_by;
                }
        }
        data->logfile_configs = NULL;
        log_config_foreach(&conf, save_logfile_config, data);

        data->default_format = get_default_format_from_config(&conf);

end:
        log_config_free(&conf);
        return ret;
}

static bool cond_string_free(void *ptr, void *user_data)
{
        (void) user_data;
        free(ptr);
        return true;
}

#ifndef UNIT_TEST
static
#endif
void free_config_data(struct logger_config_data *data)
{
        list_remove_if(&data->logfile_configs, NULL, cond_string_free);
        free(data->dynamic_config_dir);
        free(data->qos_file_path);
        free(data->first_time_file_path);
}

struct parse_logfile_config_data {
        struct logger *server;
        struct logger_config_data *data;
};

/**
 * @brief Parse logfile line
 * @detail Parses a logfile config line
 * @param[in] key Config entry key
 * @param[in] value Config entry value
 * @param[in] userdata Userdata
 */
void parse_logfile_config(void *value, void *userdata)
{
        assert(value);
        assert(userdata);

        struct logger *server = ((struct parse_logfile_config_data *) userdata)->server;
        struct logger_config_data *data = ((struct parse_logfile_config_data *) userdata)->data;
        char *configline = (char *) value;

        __attribute__((cleanup(free_dlogutil_line_params))) struct dlogutil_line_params params;
        if (!initialize_dlogutil_line_params(&params, server->buf_params))
                return;

        get_dlogutil_line_params(configline, data->default_format, &params);

        int r;
        if (g_backend.use_logger_by_default && is_core_buffer(params.buf_id)) {
                r = params.compression
                        ? create_memory_subreader_from_dlogutil_line(&params, server)
                        : create_logger_subreader_from_dlogutil_line(&params)
                ;
        } else {
                struct reader_pipe *reader = NULL;
                r = create_reader_pipe_from_dlogutil_line(&params, server, &reader);
                if (r == 0)
                        add_reader_pipe(server, reader);
        }

        if (r != 0) {
                errno = -r;
                printf("Warning: unable to add logutil reader for provided configuration. Ignoring.\n"
                       "  Config line: %s\n"
                       "  Reason given: %m\n",
                       configline);
        }
}

#ifndef UNIT_TEST
/**
 * @brief Print help
 * @details Prints basic usage tips
 */
static void help(void)
{
        printf("Usage: %s [options]\n"
               "\t-h    Show this help\n"
               "\t-b N  Set the size of the log buffer (in bytes)\n"
               "\t-t N  Set time between writes to file (in seconds)\n",
               program_invocation_short_name);
}

/**
 * @brief Parse args
 * @details Parses execution parameters of the program
 * @param[in] argc Argument count
 * @param[in] argv Argument values
 * @param[out] b Buffering parameters
 * @return 0 or 1 on success, else -errno. Nonzero if the program is to close.
 */
static int parse_args(int argc, char **argv, struct buf_params *b)
{
        b->time = BUF_PARAM_TIME_DEFAULT;
        b->bytes = BUF_PARAM_BYTES_DEFAULT;

        int option;
        while ((option = getopt(argc, argv, "hb:t:")) != -1) {
                switch (option) {
                case 't':
                        if (!isdigit(optarg[0]))
                                return -EINVAL;
                        b->time = clamp_int(atoi(optarg), BUF_PARAM_TIME_MIN, BUF_PARAM_TIME_MAX);
                        break;
                case 'b':
                        if (!isdigit(optarg[0]))
                                return -EINVAL;
                        b->bytes = clamp_int(atoi(optarg), BUF_PARAM_BYTES_MIN, BUF_PARAM_BYTES_MAX);
                        break;
                case 'h':
                        return 1;
                default:
                        return -EINVAL;
                }
        }

        return 0;
}

/**
 * @brief Finalize initialisation
 * @details Do misc stuff needed at the end of the initialisation
 * @param[in] data configuration dat to read logfiles config lines from
 * @param[in] server logger instance to configure
 * @return 0 on success, -errno on failure
 */
static int finalize_init(struct logger_config_data *data, struct logger *server)
{
        int r = sd_notify(0, "READY=1");
        if (r < 0)
                return r;

        //create files after resetting self privileges
        list_foreach(data->logfile_configs, &(struct parse_logfile_config_data) {
                .server = server,
                .data = data,
        }, parse_logfile_config);

        /* The above created subs for logger readers.
         * There is no way for them to gain more at
         * runtime, so this is the time to do some
         * processing that relies on subs being ready. */
        for (log_id_t id = 0; id < LOG_ID_MAX; ++id) {
                struct reader_logger *const reader = g_backend.logger_readers[id];
                if (!reader)
                        continue;

                if (reader->common.subs == NULL) {
                        reader_free(&reader->common);
                        g_backend.logger_readers[id] = NULL;
                        continue;
                }

                r = add_reader_logger(server, reader);
                if (r < 0) {
                        reader_free(&reader->common);
                        g_backend.logger_readers[id] = NULL;
                        return r;
                }
        }

        return 0;
}

static void precreate_logctl_file(struct logger_config_data *data)
{
        __attribute__((cleanup(free_ptr))) char *logctl_file_path = NULL;
        if (asprintf(&logctl_file_path, "%s/%s", data->dynamic_config_dir, DYNAMIC_CONFIG_FILENAME) < 0)
                // This is worrying but unimportant
                return;

        int fd = open(logctl_file_path, O_RDONLY | O_CREAT, 0644);
        if (fd < 0)
                // Again, no big deal
                return;

        close(fd);
}

bool early_termination(const struct logger_config_data *data, const struct logger *logger) {
        /* In order to check if the deamon will be doing nothing
         * and can quit instantaneously, we do three checks: */

        /* 1. We make sure that there are no Android Logger readers.
         * Note that an earlier function gets rid of any readers that
         * don't do anything (i.e. have no subs and no way to get them). */
        for (log_id_t id = 0; id < LOG_ID_MAX; ++id) {
                const struct reader_logger *const reader = g_backend.logger_readers[id];
                if (!reader)
                        continue;

                assert(reader->common.subs != NULL);
                return false;
        }

        /* 2. We make sure that no pipe-like buffer is enabled.
         * When the pipe backend is being used or pipe-like buffers
         * (i.e. KMSG, SYSLOG) are handled, the logger allocates space for them.
         * In this case, we cannot terminate even if the buffer is enabled
         * but unused at the moment, since it might be connected to
         * (for instance by dlogutil). */
        for (log_id_t id = 0; id < LOG_ID_MAX; id++)
                if (data->is_buffer_enabled[id])
                        return false;

        /* 3. We make sure that there are no writers.
         * In theory, previous checks are sufficient.
         * However, we do another check just to be sure
         * (since if there are writers, we shouldn't terminate).
         * Additionally, this could change in the future,
         * so let's hedge against someone forgetting that this function exists. */
        return logger->writers == NULL;
}

/**
 * @brief The logger
 * @return 0 on success, nonzero on failure
 * @retval 1 Configuration error
 * @retval 2 Runtime error
 */
int main(int argc, char **argv)
{
        int r, ret;

        signal(SIGPIPE, SIG_IGN);

        r = reset_self_privileges();
        if (r < 0) {
                errno = -r;
                printf("Unable to drop privileges to build-time defaults (%m). Exiting.\n");
                return DLOG_EXIT_ERR_RUNTIME;
        }

        struct logger_config_data data;
        initialize_config_data(&data);

        if ((r = parse_args(argc, argv, &data.buf_params)) != 0) {
                help();

                if (r > 0)
                        return DLOG_EXIT_SUCCESS; // --help option

                errno = -r;
                printf("Unable to parse command line args (%m). Exiting.\n");
                return DLOG_EXIT_ERR_CONFIG;
        }

        if ((r = prepare_config_data(&data)) != 0) {
                errno = -r;
                printf("Unable to prepare config (%m). Exiting.\n");
                return DLOG_EXIT_ERR_CONFIG;
        }

        precreate_logctl_file(&data);

        struct logger server;
        if ((r = logger_create(&data, &server)) < 0) {
                errno = -r;
                printf("Unable to initialize logger with provided configuration (%m). Exiting.\n");
                ret = DLOG_EXIT_ERR_CONFIG;
                goto cleanup;
        }

        if ((r = finalize_init(&data, &server)) < 0) {
                errno = -r;
                printf("Unable to finalize initialisation (%m). Exiting.\n");
                ret = DLOG_EXIT_ERR_CONFIG;
                goto cleanup;
        }

        if (early_termination(&data, &server)) {
                printf("No work to do according to provided configuration. Exiting.\n");
                ret = DLOG_EXIT_SUCCESS;
                goto cleanup;
        }

        if ((r = do_logger(&server)) < 0) {
                errno = -r;
                printf("Runtime failure (%m). Exiting.\n");
                ret = DLOG_EXIT_ERR_RUNTIME;
                goto cleanup;
        }

        ret = DLOG_EXIT_SUCCESS;

cleanup:
        free_config_data(&data);
        logger_free(&server);
        return ret;
}
#endif

/**
 * @}
 * @}
 */