Extract buffer trait functions from logcommon
[platform/core/system/dlog.git] / src / libdlog / log.c
1 /*  MIT License
2  *
3  * Copyright (c) 2012-2020 Samsung Electronics Co., Ltd
4  *
5  * Permission is hereby granted, free of charge, to any person obtaining a copy
6  * of this software and associated documentation files (the "Software"), to deal
7  * in the Software without restriction, including without limitation the rights
8  * to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
9  * copies of the Software, and to permit persons to whom the Software is furnished
10  * to do so, subject to the following conditions:
11  *
12  * The above copyright notice and this permission notice shall be included in all
13  * copies or substantial portions of the Software.
14  *
15  * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
16  * IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
17  * FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
18  * AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
19  * LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
20  * OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
21  * THE SOFTWARE. */
22
23 // C
24 #include <assert.h>
25 #include <stdbool.h>
26 #include <stdio.h>
27 #include <stdlib.h>
28
29 // POSIX
30 #include <pthread.h>
31 #include <sys/wait.h>
32 #include <unistd.h>
33
34 // Tizen
35 #include <tizen.h>
36
37 // DLog
38 #include <buffer_traits.h>
39 #include "deduplicate.h"
40 #include <dynamic_config.h>
41 #include <libdlog.h>
42 #include "logconfig.h"
43 #include "loglimiter.h"
44
45 #define DEFAULT_CONFIG_LIMITER false
46 #define DEFAULT_CONFIG_PLOG true
47 #define DEFAULT_CONFIG_DEBUGMODE 0
48 #define DEFAULT_CONFIG_LIMITER_APPLY_TO_ALL_BUFFERS 0
49
50
51 /* A pseudo-backend that does nothing. Useful for removing the overhead of dlog
52  * for debugging and measurement purposes, also it simplifies some checking as
53  * the `write_to_log` pointer below never needs to be NULL. Note that features
54  * independent of the backend (such as limiter or dynamic config) are controlled
55  * separately if dlog is to be disabled completely and that minimal overhead is
56  * always present (e.g. building the message via vprintf). */
57 static int write_to_log_null (log_id_t log_id, log_priority prio, const char *tag, const char *msg, struct timespec *tp_mono, int32_t pid, int32_t tid)
58 {
59         return DLOG_ERROR_NONE;
60 }
61
62 /**
63  * @brief Points to a function which writes a log message
64  * @details The function pointed to depends on the backend used
65  * @param[in] log_id ID of the buffer to log to. Belongs to (LOG_ID_INVALID, LOG_ID_MAX) non-inclusive
66  * @param[in] prio Priority of the message.
67  * @param[in] tag The message tag, identifies the sender.
68  * @param[in] msg The contents of the message.
69  * @return Returns the number of bytes written on success and a negative error value on error.
70  * @see __dlog_init_backend
71  */
72 int (*write_to_log)(log_id_t log_id, log_priority prio, const char *tag, const char *msg, struct timespec *tp_mono, int32_t pid, int32_t tid) = write_to_log_null;
73 void (*destroy_backend)(void);
74
75 int (*stash_failed_log)(log_id_t log_id, log_priority prio, const char *tag, const char *msg) = NULL;
76 #ifndef UNIT_TEST
77 static int stash_critical(log_id_t log_id, log_priority prio, const char *tag, const char *msg);
78 #endif
79
80 pthread_rwlock_t log_limiter_lock = PTHREAD_RWLOCK_INITIALIZER;
81 static pthread_mutex_t log_construction_lock = PTHREAD_MUTEX_INITIALIZER;
82 static bool is_initialized = false;
83
84 extern void __dlog_init_pipe(const struct log_config *conf);
85 extern void __dlog_init_android(const struct log_config *conf);
86 extern void __dlog_init_zero_copy();
87
88 extern void prepend_container_tag_if_in_container(size_t buf_size, char buf[static buf_size], int *len);
89
90 bool limiter;
91 struct limiter_data *limiter_data;
92 static bool dynamic_config;
93 static bool plog[LOG_ID_MAX];
94 static bool plog_default_values[LOG_ID_MAX];
95 static bool enable_secure_logs = true;
96 static bool enable_critical = true;
97
98 static bool should_disable_cancels;
99
100 static int debugmode;
101 static int fatal_assert;
102 static int limiter_apply_to_all_buffers;
103 static _Atomic log_priority priority_filter_level = DLOG_VERBOSE;
104
105 /* Cache pid and tid to avoid up to two syscalls per log. The update function
106  * is registered to happen when new threads are made (including a full fork). */
107 static int32_t cached_pid = 0;
108 _Thread_local int32_t cached_tid = 0;
109
110 static inline int32_t get_cached_pid()
111 {
112         return (cached_pid = cached_pid ?: getpid());
113 }
114
115 static inline int32_t get_cached_tid()
116 {
117         return (cached_tid = cached_tid ?: gettid());
118 }
119
120 static void update_thread_local_ids(void)
121 {
122         cached_pid = 0;
123         cached_tid = 0;
124 }
125
126 /* Here, static_config is the original config from /etc/dlog.conf{,.d} which can be overriden,
127  * but comes back if the override is removed. both_config additionally contains dynamic rules
128  * (by default from /run/dlog/filters.d) which can be changed in the runtime.
129  * The static_config has to be kept separately, so that we can go back to it when dynamic rules change.
130  * Note that most functions only use static_config, since the parameters can't be changed in runtime. */
131 static void __configure_limiter(struct log_config *static_config, struct log_config *both_config)
132 {
133         assert(static_config);
134         if (dynamic_config)
135                 assert(both_config);
136
137         if (!limiter)
138                 return;
139
140         limiter_data = __log_limiter_create(static_config);
141         if (limiter_data && dynamic_config)
142                 __log_limiter_update(limiter_data, both_config);
143         limiter = (bool)limiter_data;
144
145         should_disable_cancels |= limiter; // due to locks
146 }
147
148 static int __configure_backend(struct log_config *config)
149 {
150         assert(config);
151
152         const char *const backend = log_config_claim_backend(config);
153         if (!backend)
154                 return 0;
155
156         if (!strcmp(backend, "pipe")) {
157                 __dlog_init_pipe(config);
158                 should_disable_cancels = true;
159         } else if (!strcmp(backend, "logger"))
160                 __dlog_init_android(config);
161         else if (!strcmp(backend, "zero-copy"))
162                 __dlog_init_zero_copy(config);
163         else if (!strcmp(backend, "null"))
164                 ; // already the default
165         else
166                 return 0;
167
168         return 1;
169 }
170
171 static void __set_plog_default_values(void)
172 {
173         for (size_t i = 0; i < NELEMS(plog); ++i)
174                 plog_default_values[i] = plog[i];
175 }
176
177 static void __initialize_plog(const struct log_config *config)
178 {
179         assert(config);
180
181         const bool plog_default = log_config_get_boolean(config, "plog", DEFAULT_CONFIG_PLOG);
182         for (size_t i = 0; i < NELEMS(plog); ++i)
183                 plog[i] = plog_default;
184         plog[LOG_ID_APPS] = true; // the default does not apply here for backward compatibility reasons.
185         __set_plog_default_values();
186 }
187
188 static void __configure_parameters(struct log_config *static_config, struct log_config *both_config)
189 {
190         assert(static_config);
191         assert(both_config);
192
193         __initialize_plog(static_config);
194         __update_plog(static_config);
195         /* Like in __configure_limiter, we also check the dynamic rules. However, we make sure to
196      * set the default values to the ones generated by the static rules first. */
197         __set_plog_default_values();
198         __update_plog(both_config);
199
200         enable_secure_logs = log_config_get_boolean(both_config, "enable_secure_logs", enable_secure_logs);
201         enable_critical = log_config_get_boolean(both_config, "enable_critical", enable_critical);
202         debugmode = log_config_get_int(both_config, "debugmode", DEFAULT_CONFIG_DEBUGMODE);
203         fatal_assert = access(DEBUGMODE_FILE, F_OK) != -1;
204         limiter = log_config_get_boolean(both_config, "limiter", DEFAULT_CONFIG_LIMITER);
205         limiter_apply_to_all_buffers = log_config_get_int(both_config,
206                                                                         "limiter_apply_to_all_buffers",
207                                                                         DEFAULT_CONFIG_LIMITER_APPLY_TO_ALL_BUFFERS);
208
209         stash_failed_log = NULL;
210         const char *stash_failed_log_method = log_config_get(both_config, "stash_failed_log_method");
211         if (stash_failed_log_method) {
212 #ifndef UNIT_TEST
213                 if (strcmp(stash_failed_log_method, "critical") == 0)
214                         stash_failed_log = stash_critical;
215 #endif
216         }
217 }
218
219 void __update_plog(const struct log_config *conf)
220 {
221         assert(conf);
222
223         for (size_t i = 0; i < NELEMS(plog); ++i) {
224                 char key[MAX_CONF_KEY_LEN];
225                 const int r = snprintf(key, sizeof key, "enable_%s", log_name_by_id((log_id_t)i));
226                 if (r < 0)
227                         continue;
228                 plog[i] = log_config_get_boolean(conf, key, plog_default_values[i]);
229         }
230 }
231
232 /**
233  * @brief Configure the library
234  * @details Reads relevant config values
235  * @remarks This is more or less a constructor, but there are some obstacles
236  *          to using it as such (i.e. with attribute constructor):
237  *
238  *  - some important pieces of the system link to dlog, they start very early
239  *    such that dlog can't properly initialize (which lasts for program lifetime)
240  *    but don't actually log anything until later on and would be fine under lazy
241  *    initialisation. The way to do it "properly" would be to expose this function
242  *    into the API so that people can manually call it when they're ready, but
243  *    one of the design goals of the current API is that it requires absolutely no
244  *    other calls than `dlog_print`. Changing it would require somebody with a
245  *    bird's eye view of the system to produce a design so I wouldn't count on it.
246  *
247  *  - the constructor would need to have as high of a priority as possible (so as
248  *    to minimize the risk of another library's constructor using uninitialized data)
249  *    but at the same time others might want some room to wrap functions before
250  *    dlog uses them (think mprobe/mcheck). This would also require a design pass.
251  */
252 #ifndef UNIT_TEST
253 static
254 #endif
255 bool __configure(void)
256 {
257         __attribute__((cleanup(log_config_free))) struct log_config static_config = {};
258         __attribute__((cleanup(log_config_free))) struct log_config both_config = {};
259
260         if (log_config_read(&static_config) < 0)
261                 return false;
262         log_config_copy(&both_config, &static_config);
263
264         dynamic_config = __dynamic_config_create(&both_config);
265
266         __configure_parameters(&static_config, &both_config);
267
268         if (!__configure_backend(&both_config)) {
269                 __dynamic_config_destroy();
270                 dynamic_config = false;
271                 return false;
272         }
273
274         __configure_deduplicate(&both_config);
275         __configure_limiter(&static_config, &both_config);
276
277         /* The fork handler also runs when a new thread is made (not just
278          * when the whole process forks), so we can cache both pid and tid. */
279         pthread_atfork(NULL, NULL, update_thread_local_ids);
280
281         return true;
282 }
283
284 static void __attribute__((constructor(101))) __install_pipe_handler(void)
285 {
286         /* We mask SIGPIPE signal because most applications do not install their
287          * own SIGPIPE handler. Default behaviour in SIGPIPE case is to abort the
288          * process. SIGPIPE occurs when e.g. dlog daemon closes read pipe endpoint.
289          *
290          * We do this in the library constructor (at maximum priority) and not
291          * during regular (lazy) initialisation so as to prevent overwriting the
292          * program's actual signal handler, if it has one.
293          *
294          * In theory this is not required for the Android logger backend; however,
295          * this early we don't yet know the backend and also it is good to behave
296          * consistently in this regard anyway.
297          *
298          * We don't revert this in a destructor because Unix signals are bonkers
299          * and we have no way to do this cleanly. Most libdlog users don't use
300          * runtime linking so this would mostly done at program exit either way. */
301         signal(SIGPIPE, SIG_IGN);
302 }
303
304 static void __attribute__((constructor(102))) __set_output_buffering(void)
305 {
306         /* If stdout and/or stderr is redirected to dlog (service, driver)
307          * it is best if we buffer lines, otherwise the following can happen:
308          *  - no buffering: service/driver recives every single byte (precisely
309          *    every single write*(2) call), causing it to either buffer the data
310          *    anyway (service), or print logs at random places (driver)
311          *  - full buffering: service/driver receives several hundred lines,
312          *    which results in one giant entry being added (driver) or long delays
313          *    before logs appear (service) */
314         if (getenv(DLOG_ENV_STDOUT_LINE_BUFFERED))
315                 setlinebuf(stdout);
316
317         if (getenv(DLOG_ENV_STDERR_LINE_BUFFERED))
318                 setlinebuf(stderr);
319 }
320
321 static bool first = true;
322 static bool initialize(void)
323 {
324         if (is_initialized)
325                 return true;
326
327         /* The mutex acts as a barrier, but otherwise the C language's
328          * machine abstraction is single-threaded. This means that the
329          * compiler is free to rearrange calls inside the mutex according
330          * to the as-if rule because it doesn't care if another thread can
331          * access it in parallel. In particular, `is_initialized = true`
332          * directly after `__configure()` could be rearranged to go in
333          * front of it because it is not touched inside that function
334          * if the compiler thinks it helps somehow (not unlikely: since
335          * it is checked before the mutex, it is very probable for it to
336          * still be in the CPU register or something like that). On top
337          * of that, some architectures (in particular, armv7l) don't have
338          * strict memory guarantees and can reorder actual memory stores
339          * on their own, even if the compiler didn't do anything fancy
340          * when creating machine code. For more info about the issue,
341          * see https://www.aristeia.com/Papers/DDJ_Jul_Aug_2004_revised.pdf
342          *
343          * Ultimately this means that there needs to be some sort of
344          * barrier between `__configure` and `is_initialized = true`,
345          * and the simplest way to achieve that is to just wait until
346          * the second entry into the mutex. */
347
348         bool ret;
349         pthread_mutex_lock(&log_construction_lock);
350                 if (first)
351                         first = !__configure();
352                 else
353                         is_initialized = true;
354                 ret = !first;
355         pthread_mutex_unlock(&log_construction_lock);
356         return ret;
357 }
358
359 /**
360  * @brief Fatal assertion
361  * @details Conditionally crash the sucka who sent the log
362  * @param[in] prio Priority of the log
363  */
364 static void __dlog_fatal_assert(int prio)
365 {
366         assert(!fatal_assert || (prio != DLOG_FATAL));
367 }
368
369 /**
370  * @brief Check log validity
371  * @details Checks whether the log is valid and eligible for printing
372  * @param[in] log_id The target buffer ID
373  * @param[in] prio The log's priority
374  * @param[in] tag The log's tag
375  * @return DLOG_ERROR_NONE on success, else an error code.
376  * @retval DLOG_ERROR_INVALID_PARAMETER Invalid parameter
377  */
378 static int dlog_check_validity(log_id_t log_id, int prio, const char *tag)
379 {
380         (void) prio;
381         if (!tag)
382                 return DLOG_ERROR_INVALID_PARAMETER;
383
384         if (log_id <= LOG_ID_INVALID || LOG_ID_MAX <= log_id)
385                 return DLOG_ERROR_INVALID_PARAMETER;
386
387         return DLOG_ERROR_NONE;
388 }
389
390 /**
391  * @brief Check log against limiter rules
392  * @details Checks whether the log passes current limiter rules
393  * @param[in] log_id The target buffer ID
394  * @param[in] prio The log's priority
395  * @param[in] tag The log's tag
396  * @return DLOG_ERROR_NONE on success, else an error code.
397  * @retval DLOG_ERROR_NOT_PERMITTED Not permitted
398  */
399 static int dlog_check_limiter(log_id_t log_id, int prio, const char *tag)
400 {
401         if (!debugmode && prio <= DLOG_DEBUG)
402                 return DLOG_ERROR_NOT_PERMITTED;
403
404         if (dynamic_config)
405                 __dynamic_config_update(limiter_data);
406
407         if (limiter) {
408                 struct pass_log_result should_log = { .decision = DECISION_DENIED };
409
410                 /* Since the only `wrlock` is done by the dynamic config, we can avoid
411                  * the `rdlock` entirely if the config is static. This sounds unsafe
412                  * but lets us save an entire syscall, which is a lot (both comparatively
413                  * and because it compounds). */
414                 if (!dynamic_config || !pthread_rwlock_rdlock(&log_limiter_lock)) {
415                         should_log = __log_limiter_pass_log_pid(limiter_data, tag, prio, get_cached_pid());
416                         if (dynamic_config)
417                                 pthread_rwlock_unlock(&log_limiter_lock);
418                 }
419
420                 switch (should_log.decision) {
421                         case DECISION_DENIED:
422                                 return DLOG_ERROR_NOT_PERMITTED;
423
424                         case DECISION_TAG_LIMIT_EXCEEDED_MESSAGE:
425                         case DECISION_PID_LIMIT_EXCEEDED_MESSAGE: {
426                                 struct timespec tp;
427                                 int result = clock_gettime(CLOCK_MONOTONIC, &tp);
428                                 if (result < 0)
429                                         return DLOG_ERROR_NOT_PERMITTED;
430                                 char buf[100] = {};
431                                 snprintf(buf, sizeof(buf),
432                                                 "Your log has been blocked due to per-%s limit of %d logs per %d seconds.",
433                                                 should_log.decision == DECISION_TAG_LIMIT_EXCEEDED_MESSAGE ? "tag" : "PID",
434                                                 should_log.logs_per_period, should_log.period_s);
435                                 write_to_log(log_id, prio, tag, buf, &tp, get_cached_pid(), get_cached_tid());
436                                 return DLOG_ERROR_NOT_PERMITTED;
437                         }
438
439                         case DECISION_ALLOWED:
440                                 break;
441                 }
442         }
443
444         /* This can change due to __dynamic_config_update(), but is atomic and its
445          * value implies nothing else so does not need to be under a lock. */
446         if (!plog[log_id])
447                 return DLOG_ERROR_NOT_PERMITTED;
448
449         return DLOG_ERROR_NONE;
450 }
451
452 static int __write_to_log_critical_section(log_id_t log_id, int prio, const char *tag, const char *fmt, va_list ap, bool check_should_log)
453 {
454         if ((check_should_log || limiter_apply_to_all_buffers) && (dlog_check_limiter(log_id, prio, tag) < 0))
455                 return DLOG_ERROR_NONE;
456
457         char buf[LOG_MAX_PAYLOAD_SIZE];
458         int len = vsnprintf(buf, sizeof buf, fmt, ap);
459         if (len < 0)
460                 return DLOG_ERROR_NONE;
461         else if (len >= sizeof buf)
462                 len = sizeof buf - 1;
463
464         // Temporary workaround, see temporary.c
465         prepend_container_tag_if_in_container(sizeof buf, buf, &len);
466
467         struct timespec tp;
468         int r;
469         if (deduplicate_func && !clock_gettime(CLOCK_MONOTONIC, &tp)) {
470                 dlog_deduplicate_e ret = deduplicate_func(buf, len, &tp);
471                 if (ret == DLOG_DEDUPLICATE)
472                         return DLOG_ERROR_NONE;
473                 else if (ret == DLOG_DO_NOT_DEDUPLICATE_BUT_WARN)
474                         deduplicate_warn(buf, sizeof buf, len);
475                 r = write_to_log(log_id, prio, tag, buf, &tp, get_cached_pid(), get_cached_tid());
476         } else
477                 r = write_to_log(log_id, prio, tag, buf, NULL, get_cached_pid(), get_cached_tid());
478
479         if (r < 0 && stash_failed_log)
480                 r = stash_failed_log(log_id, prio, tag, buf);
481
482         return r;
483 }
484
485 static int __write_to_log(log_id_t log_id, int prio, const char *tag, const char *fmt, va_list ap, bool check_should_log, bool secure_log)
486 {
487         int ret = dlog_check_validity(log_id, prio, tag);
488         if (ret < 0)
489                 return ret;
490
491         if (check_should_log && prio < priority_filter_level)
492                 return DLOG_ERROR_NONE;
493
494         /* Threads can be cancelled before they give up a lock.
495          * Therefore cancellation is temporarily disabled as
496          * long as the current set of features uses a lock.
497          *
498          * This solution is comparatively simple and cheap.
499          * The other solutions (cleanup handlers, robust mutexes)
500          * would be much more complicated and also inflict larger
501          * runtime costs. The downside of disabling cancellation
502          * is not a problem in our case because it is temporary
503          * and very brief so we don't keep an obsolete thread
504          * for much longer than we otherwise would. */
505         int old_cancel_state;
506         if (should_disable_cancels)
507                 pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &old_cancel_state);
508
509         if (!initialize())
510                 // TODO: We could consider stashing the failed log here
511                 ret = DLOG_ERROR_NOT_PERMITTED;
512         else if (secure_log && !enable_secure_logs)
513                 ret = 0;
514         else
515                 ret = __write_to_log_critical_section(log_id, prio, tag, fmt, ap, check_should_log);
516
517         if (should_disable_cancels)
518                 pthread_setcancelstate(old_cancel_state, NULL);
519
520         return ret;
521 }
522
523 int __critical_log_append_timestamp(char *buf, size_t buflen)
524 {
525         /* NB: the timestamp may slightly differ from the one that gets
526          * added onto the copy that goes into the regular buffer, and
527          * timestamp acquisition is duplicated. This would ideally be
528          * solved, but timestamps are currently added fairly deep in
529          * backend-specific functions so for now this will have to do.
530          * Also, since we're the sender, there is just this one set of
531          * timestamps, i.e. the send timestamp! The usual alternative
532          * set of receive timestamps will never have the opportunity
533          * to get added to the entry since this log is supposed to end
534          * up straight in the file (there's potentially the trusted
535          * writer binary but we're trying to keep the set of actions
536          * it needs to do to the minimum and those timestamps would
537          * in practice be the same anyway). */
538
539         struct timespec ts;
540         clock_gettime(CLOCK_REALTIME, &ts);
541         const time_t tt = ts.tv_sec;
542         const long int real_millisec = ts.tv_nsec / 1000000;
543         clock_gettime(CLOCK_MONOTONIC, &ts);
544         struct tm tmBuf;
545         struct tm *const ptm = localtime_r(&tt, &tmBuf);
546         assert(ptm); // we're in a short lived fork so asserts are fine and make things simple
547
548         int len = strftime(buf, buflen, "%m-%d %H:%M:%S", ptm);
549         assert(len != 0);
550
551         int tmp_len = snprintf(buf + len, buflen - len, ".%03ld", real_millisec);
552         assert(tmp_len > 0);
553         assert(tmp_len < buflen - len);
554         len += tmp_len;
555
556         tmp_len = strftime(buf + len, buflen - len, "%z ", ptm);
557         assert(tmp_len != 0);
558         len += tmp_len;
559
560         tmp_len = snprintf(buf + len, buflen - len, "%5lu.%03ld", ts.tv_sec, ts.tv_nsec / 1000000);
561         assert(tmp_len > 0);
562         assert(tmp_len < buflen - len);
563         len += tmp_len;
564
565         return len;
566 }
567
568 int __critical_log_build_msg(char *buf, size_t buflen, pid_t main_pid, pid_t main_tid, log_id_t log_id, int prio, const char *tag, const char *fmt, va_list ap)
569 {
570         int len = __critical_log_append_timestamp(buf, buflen);
571         const int metadata_len = snprintf(buf + len, buflen - len, " P%5d T%5d B%-6s %c/%-8s: ",
572                 main_pid,
573                 main_tid,
574                 log_name_by_id(log_id),
575                 filter_pri_to_char(prio),
576                 tag ?: "CRITICAL_NO_TAG");
577         assert(metadata_len > 0);
578         if (metadata_len >= buflen - len)
579                 return buflen - 1; // can genuinely happen with an exceedingly large tag
580         len += metadata_len;
581
582         const int content_len = vsnprintf(buf + len, buflen - len, fmt, ap);
583         assert(content_len >= 0); // 0 is legit with format == ""
584         if (content_len >= buflen - len)
585                 return buflen - 1;
586         len += content_len;
587
588         return len;
589 }
590
591 #ifndef UNIT_TEST
592 __attribute__ ((noreturn))
593 #endif
594 void __critical_log_child(pid_t main_pid, pid_t main_tid, log_id_t log_id, int prio, const char *tag, const char *fmt, va_list ap)
595 {
596         char buf[LOG_MAX_PAYLOAD_SIZE + 128]; // extra space for some metadata
597         const int len = __critical_log_build_msg(buf, sizeof buf - 1, main_pid, main_tid, log_id, prio, tag, fmt, ap);
598         buf[len] = '\n';
599         buf[len + 1] = '\0';
600
601         static const char *const path = "/usr/libexec/dlog-log-critical";
602         execl(path, path /* argv[0] convention */, buf, (char *) NULL);
603
604 #ifndef UNIT_TEST
605         /* Compilers are sometimes smart enough to recognize _exit's
606          * noreturn attribute, even if we wrap it with something that
607          * returns. This causes it to behave in unexpected ways, for
608          * example it can blow up the program regardless or it can
609          * optimize some conditionals out (and incorrectly enter them
610          * after the exit call fails to actually exit). This makes it
611          * unsuitable for tests. */
612
613         _exit(1); // not the regular `exit` so as not to trigger any `atexit` handlers prematurely
614 #endif
615 }
616
617 #ifndef UNIT_TEST // contains forks and exits, these don't work well with wrapping (see above)
618 void __critical_log(log_id_t log_id, int prio, const char *tag, const char *fmt, va_list ap)
619 {
620         /* Critical log functionality is mostly done in a separate binary
621          * to handle security correctly (else every process would have to
622          * possess the necessary privilege to write onto that file, which
623          * would be opening a fairly nasty can of worms from the security
624          * point of view). Our use of exec() is why a simple thread would
625          * not suffice and we're resorting to a fork.
626          *
627          * The double fork, much like a double barreled 12 gauge shotgun,
628          * is an elegant solution designed to stop a zombie army. We'd be
629          * creating zombie processes if we didn't wait() for the children
630          * we spawn, but we don't really want to do that since it results
631          * in a needless delay. Instead, the writer process is actually a
632          * grandchild, with our direct child exiting immediately just for
633          * us to have something to wait on that is guaranteed not to take
634          * too long. The orphaned grandchild is adopted by init, who will
635          * take care to reap it when it dies. In addition to avoiding the
636          * delay, the client will not have any unexpected children (which
637          * could ruin logic in its own waits).
638          *
639          * Right after forks:
640          * ┌───────┐   ┌─────────┐   ┌─────────────┐   ┌────────┐
641          * │ pid 1 ├──>│ libdlog ├──>│ immediately ├──>│ execs  │
642          * │ init  │   │ client  │   │    exits    │   │ writer │
643          * └───────┘   └─────────┘   └─────────────┘   └────────┘
644          *
645          * Afterwards, libdlog has no children:
646          * ┌───────┐   ┌─────────┐                     ┌────────┐
647          * │ pid 1 ├──>│ libdlog │          ┌─────────>│ writer │
648          * │ init  ├─┐ │ client  │          │          │ binary │
649          * └───────┘ │ └─────────┘          │          └────────┘
650          *           └──────────────────────┘
651          */
652
653         initialize();
654
655         if (!enable_critical)
656                 return;
657
658         const pid_t main_pid = getpid();
659         const pid_t main_tid = gettid();
660
661         const int temporary_exiter_pid = fork();
662         if (temporary_exiter_pid < 0)
663                 return;
664         if (temporary_exiter_pid != 0) {
665                 waitpid(temporary_exiter_pid, NULL, 0);
666                 return;
667         }
668
669         const int child_pid = fork();
670         if (child_pid < 0)
671                 _exit(1);
672         if (child_pid != 0)
673                 _exit(0);
674
675         __critical_log_child(main_pid, main_tid, log_id, prio, tag, fmt, ap);
676 }
677
678 static void stash_critical_inner(log_id_t log_id, log_priority prio, const char *tag, const char *fmt, ...)
679 {
680         va_list ap;
681
682         va_start(ap, fmt);
683         __critical_log(log_id, prio, tag, fmt, ap);
684         va_end(ap);
685 }
686
687 static int stash_critical(log_id_t log_id, log_priority prio, const char *tag, const char *msg)
688 {
689         stash_critical_inner(log_id, prio, tag, "FAILED TO LOG: %s", msg);
690         return 0;
691 }
692
693 EXPORT_API int __dlog_critical_print(log_id_t log_id, int prio, const char *tag, const char *fmt, ...)
694 {
695         va_list ap;
696
697         va_start(ap, fmt);
698         __critical_log(log_id, prio, tag, fmt, ap);
699         va_end(ap);
700
701         va_start(ap, fmt);
702         int ret = __dlog_vprint(log_id, prio, tag, fmt, ap);
703         va_end(ap);
704
705         return ret;
706 }
707 #endif
708
709 EXPORT_API int dlog_set_minimum_priority(int priority)
710 {
711         if (priority < DLOG_DEFAULT || priority > DLOG_PRIO_MAX)
712                 return DLOG_ERROR_INVALID_PARAMETER;
713
714         priority_filter_level = priority;
715         return DLOG_ERROR_NONE;
716 }
717
718 /**
719  * @brief Print log
720  * @details Print a log line
721  * @param[in] log_id The target buffer ID
722  * @param[in] prio Priority
723  * @param[in] tag tag
724  * @param[in] fmt Format (same as printf)
725  * @param[in] ap Argument list
726  * @return Bytes written, or negative error
727  */
728 EXPORT_API int __dlog_vprint(log_id_t log_id, int prio, const char *tag, const char *fmt, va_list ap)
729 {
730         int ret = __write_to_log(log_id, prio, tag, fmt, ap, true, false);
731         __dlog_fatal_assert(prio);
732
733         return ret;
734 }
735
736 /**
737  * @brief Print log
738  * @details Print a log line
739  * @param[in] log_id The target buffer ID
740  * @param[in] prio Priority
741  * @param[in] tag tag
742  * @param[in] fmt Format (same as printf)
743  * @return Bytes written, or negative error
744  */
745 EXPORT_API int __dlog_print(log_id_t log_id, int prio, const char *tag, const char *fmt, ...)
746 {
747         va_list ap;
748
749         va_start(ap, fmt);
750         int ret = __dlog_vprint(log_id, prio, tag, fmt, ap);
751         va_end(ap);
752
753         return ret;
754 }
755
756 /**
757  * @brief Print log
758  * @details Print a log line
759  * @param[in] log_id The target buffer ID
760  * @param[in] prio Priority
761  * @param[in] tag tag
762  * @param[in] fmt Format (same as printf)
763  * @return Bytes written, or negative error
764  */
765 EXPORT_API int __dlog_sec_print(log_id_t log_id, int prio, const char *tag, const char *fmt, ...)
766 {
767         if (!enable_secure_logs)
768                 return 0;
769
770         va_list ap;
771
772         va_start(ap, fmt);
773         int ret = __write_to_log(log_id, prio, tag, fmt, ap, true, true);
774         __dlog_fatal_assert(prio);
775         va_end(ap);
776
777         return ret;
778 }
779
780 EXPORT_API int dlog_vprint(log_priority prio, const char *tag, const char *fmt, va_list ap)
781 {
782         return __write_to_log(LOG_ID_APPS, prio, tag, fmt, ap, false, false);
783 }
784
785 EXPORT_API int dlog_print(log_priority prio, const char *tag, const char *fmt, ...)
786 {
787         va_list ap;
788
789         va_start(ap, fmt);
790         int ret = dlog_vprint(prio, tag, fmt, ap);
791         va_end(ap);
792
793         return ret;
794 }
795
796 /**
797  * @brief Finalize DLog
798  * @details Finalizes and deallocates the library
799  * @notes Used directly in tests; brings back the pre-init state
800  */
801 void __dlog_fini(void)
802 {
803         if (destroy_backend) {
804                 destroy_backend();
805                 destroy_backend = NULL;
806         }
807         write_to_log = write_to_log_null;
808         stash_failed_log = NULL;
809         is_initialized = false;
810         first = true;
811
812         enable_secure_logs = true;
813         enable_critical = false;
814         __deduplicate_destroy();
815         __log_limiter_destroy(limiter_data);
816         limiter = false;
817         __dynamic_config_destroy();
818         should_disable_cancels = false;
819 }