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