logger: introduce lazy/hybrid approach to early logging 41/230841/5
authorMichal Bloch <m.bloch@samsung.com>
Wed, 22 Apr 2020 18:28:09 +0000 (20:28 +0200)
committerMichal Bloch <m.bloch@samsung.com>
Tue, 28 Apr 2020 10:27:32 +0000 (12:27 +0200)
This mode is introduced in an attempt to limit CPU usage during boot time.
The logger will now wake up exactly after (instead of up to) the epoll delay
for some configurable amount of time (by default 10s). Ideally this would
just be waiting on BootingDone but the daemon doesn't handle DBus yet, which
would be a larger undertaking. After that delay, it switches back to usual
epoll behaviour (waking up on each log, limiting log loss).

Change-Id: I55555978902d18b2d922663a24fe1caeb6d330e8
Signed-off-by: Michal Bloch <m.bloch@samsung.com>
configs/dlog.conf
src/logger/logger.c
src/logger/logger_internal.h

index f50a6fd..b133b94 100644 (file)
@@ -69,6 +69,14 @@ handle_kmsg=1
 # for continuous dlogutil instances.
 epoll_time_ms=1000
 
+# How long after start the daemon works in "lazy" mode, which means that it
+# wakes up exactly after specified time (unlike regular polling, where it
+# might wake up immediately if logs are available). This reduces the overhead
+# for waking up, but can result in log loss under heavy load. Use -1 as the
+# total time to keep the daemon in the lazy mode permanently.
+lazy_polling_total_ms=-1
+lazy_polling_sleep_ms=1000
+
 # Syslog handling currently disabled in the daemon - not needed in Tizen.
 #dlog_logger_conf_syslog=dlogutil -b syslog -r 256 -n 1 -f /var/log/dlog/syslog -v recv_realtime
 
index 7487836..ea29622 100644 (file)
@@ -58,6 +58,11 @@ static struct {
 
 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 MS_TO_US = 1000;
+
 /**
  * @brief Parse permissions
  * @details Parse a string representation of permissions to the internal integral one
@@ -1764,6 +1769,9 @@ static int logger_create(struct logger_config_data *data, struct logger *l)
                return -errno;
        l->epolltime = data->epoll_time;
 
+       l->lazy_polling_total = data->lazy_polling_total;
+       l->lazy_polling_sleep = data->lazy_polling_sleep;
+
        l->buf_params = data->buf_params;
 
        for (log_id_t id = 0; id < LOG_ID_MAX; id++)
@@ -1935,12 +1943,20 @@ static int do_logger(struct logger* server)
        if (r < 0)
                return r;
 
+       bool use_lazy_polling = true;
        while (g_logger_run) {
                clock_gettime(CLOCK_MONOTONIC, &server->now);
 
+               if (server->lazy_polling_total >= 0) {
+                       server->lazy_polling_total -= server->lazy_polling_sleep;
+                       use_lazy_polling = (server->lazy_polling_total >= 0);
+               }
+               if (use_lazy_polling)
+                       usleep(MS_TO_US * server->lazy_polling_sleep);
+
                ensure_epoll_size(&events, &events_size, server->epollcnt);
 
-               int nfds = epoll_wait(server->epollfd, events, events_size, server->epolltime);
+               int nfds = epoll_wait(server->epollfd, events, events_size, server->epolltime * !use_lazy_polling);
                if (nfds < 0 && errno == EINTR) // TODO: This is *almost* TEMP_FAILURE_RETRY. Is it equivalent?
                        continue;
 
@@ -2105,6 +2121,8 @@ int prepare_config_data(struct logger_config_data *data)
        }
 
        data->epoll_time = log_config_get_int(&conf, "epoll_time_ms", DEFAULT_EPOLL_TIME_MS);
+       data->lazy_polling_total = log_config_get_int(&conf, "lazy_polling_total_ms", DEFAULT_LAZY_POLLING_TOTAL_MS);
+       data->lazy_polling_sleep = log_config_get_int(&conf, "lazy_polling_sleep_ms", DEFAULT_LAZY_POLLING_SLEEP_MS);
 
        memset(data->is_buffer_enabled, 0, sizeof(data->is_buffer_enabled));
        if (!strcmp(backend, "pipe")) {
index c32dd62..9a0bbbb 100644 (file)
@@ -205,6 +205,8 @@ struct logger {
        int                 epollfd;
        unsigned            epollcnt;
        int                 epolltime;
+       int                 lazy_polling_total;
+       int                 lazy_polling_sleep;
        list_head           writers;
        list_head           extra_readers;
        struct log_buffer*  buffers[LOG_ID_MAX];
@@ -228,6 +230,8 @@ struct buffer_config_data {
 struct logger_config_data {
        struct buf_params buf_params;
        list_head logfile_configs;
+       int lazy_polling_total;
+       int lazy_polling_sleep;
        int epoll_time;
        int is_buffer_enabled[LOG_ID_MAX];
        struct buffer_config_data buffers[LOG_ID_MAX];