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