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