6 #include <sys/syslog.h>
12 #include "dinit-log.h"
15 extern eventloop_t event_loop;
17 static bool log_current_line[2]; // Whether the current line is being logged (for console, main log)
18 loglevel_t log_level[2] = { loglevel_t::WARN, loglevel_t::WARN };
20 static service_set *services = nullptr; // Reference to service set
22 using rearm = dasynq::rearm;
25 class BufferedLogStream : public eventloop_t::fd_watcher_impl<BufferedLogStream>
30 bool partway = false; // if we are partway throught output of a log message
31 bool discarded = false; // if we have discarded a message
32 bool release = true; // if we should inhibit output and release console
34 // A "special message" is not stored in the circular buffer; instead
35 // it is delivered from an external buffer not managed by BufferedLogger.
36 bool special = false; // currently outputting special message?
37 const char *special_buf; // buffer containing special message
38 int msg_index; // index into special message
40 cpbuffer<4096> log_buffer;
45 int current_index = 0; // current/next incoming message index
55 rearm fd_event(eventloop_t &loop, int fd, int flags) noexcept;
57 // Check whether the console can be released.
58 void flushForRelease();
59 void release_console();
60 bool is_release_set() { return release; }
62 // Commit a log message
65 bool was_first = current_index == 0;
66 current_index = log_buffer.get_length();
67 if (was_first && ! release) {
68 set_enabled(event_loop, true);
74 log_buffer.trim_to(current_index);
79 return log_buffer.get_free();
82 void append(const char *s, size_t len)
84 log_buffer.append(s, len);
87 // Discard buffer; call only when the stream isn't active.
91 log_buffer.trim_to(0);
94 // Mark that a message was discarded due to full buffer
103 // (One for main log, one for console)
104 static BufferedLogStream log_stream[2];
106 constexpr static int DLOG_MAIN = 0; // main log facility
107 constexpr static int DLOG_CONS = 1; // console
109 void BufferedLogStream::release_console()
112 int flags = fcntl(1, F_GETFL, 0);
113 fcntl(1, F_SETFL, flags & ~O_NONBLOCK);
114 services->pull_console_queue();
118 void BufferedLogStream::flushForRelease()
122 // Try to flush any messages that are currently buffered. (Console is non-blocking
123 // so it will fail gracefully).
124 if (fd_event(event_loop, fd, dasynq::OUT_EVENTS) == rearm::DISARM) {
125 // Console has already been released at this point.
126 set_enabled(event_loop, false);
128 // fd_event didn't want to disarm, so must be partway through a message; will
129 // release when it's finished.
132 rearm BufferedLogStream::fd_event(eventloop_t &loop, int fd, int flags) noexcept
134 if ((! partway) && (! special) && discarded) {
135 special_buf = "dinit: *** message discarded due to full buffer ****\n";
139 if ((! partway) && special) {
140 const char * start = special_buf + msg_index;
141 const char * end = std::find(special_buf + msg_index, (const char *)nullptr, '\n');
142 int r = write(fd, start, end - start + 1);
144 if (start + r > end) {
145 // All written: go on to next message in queue
152 return rearm::DISARM;
160 else if (errno != EAGAIN && errno != EINTR && errno != EWOULDBLOCK) {
161 return rearm::REMOVE;
166 // Writing from the regular circular buffer
168 if (current_index == 0) {
170 return rearm::DISARM;
173 // We try to find a complete line (terminated by '\n') in the buffer, and write it
174 // out. Since it may span the circular buffer end, it may consist of two distinct spans,
175 // and so we use writev to write them atomically.
177 struct iovec logiov[2];
179 char *ptr = log_buffer.get_ptr(0);
180 int len = log_buffer.get_contiguous_length(ptr);
181 char *creptr = ptr + len; // contiguous region end
182 char *eptr = std::find(ptr, creptr, '\n');
184 bool will_complete = false; // will complete this message?
185 if (eptr != creptr) {
186 eptr++; // include '\n'
187 will_complete = true;
192 logiov[0].iov_base = ptr;
193 logiov[0].iov_len = len;
194 int iovs_to_write = 1;
196 // Do we need the second span?
197 if (! will_complete && len != log_buffer.get_length()) {
198 ptr = log_buffer.get_buf_base();
199 creptr = ptr + log_buffer.get_length() - len;
200 eptr = std::find(ptr, creptr, '\n');
201 if (eptr != creptr) {
202 eptr++; // include '\n'
203 // It should not ever be the case that we do not now have a complete message
204 will_complete = true;
206 logiov[1].iov_base = ptr;
207 logiov[1].iov_len = eptr - ptr;
208 len += logiov[1].iov_len;
212 ssize_t r = writev(fd, logiov, iovs_to_write);
215 bool complete = (r == len) && will_complete;
216 log_buffer.consume(len);
217 partway = ! complete;
219 current_index -= len;
220 if (current_index == 0 || release) {
221 // No more messages buffered / stop logging to console:
223 return rearm::DISARM;
227 else if (errno != EAGAIN && errno != EINTR && errno != EWOULDBLOCK) {
228 return rearm::REMOVE;
232 // We've written something by the time we get here. We could fall through to below, but
233 // let's give other events a chance to be processed by returning now.
237 // Initialise the logging subsystem
238 // Potentially throws std::bad_alloc or std::system_error
239 void init_log(service_set *sset)
242 log_stream[DLOG_CONS].add_watch(event_loop, STDOUT_FILENO, dasynq::OUT_EVENTS, false);
243 enable_console_log(true);
246 // Set up the main log to output to the given file descriptor.
247 // Potentially throws std::bad_alloc or std::system_error
248 void setup_main_log(int fd)
250 log_stream[DLOG_MAIN].init(fd);
251 log_stream[DLOG_MAIN].add_watch(event_loop, fd, dasynq::OUT_EVENTS);
254 bool is_log_flushed() noexcept
256 return log_stream[DLOG_CONS].current_index == 0;
259 // Enable or disable console logging. If disabled, console logging will be disabled on the
260 // completion of output of the current message (if any), at which point the first service record
261 // queued in the service set will acquire the console.
262 void enable_console_log(bool enable) noexcept
264 bool log_to_console = ! log_stream[DLOG_CONS].is_release_set();
265 if (enable && ! log_to_console) {
266 // Console is fd 1 - stdout
267 // Set non-blocking IO:
268 int flags = fcntl(1, F_GETFL, 0);
269 fcntl(1, F_SETFL, flags | O_NONBLOCK);
271 log_stream[DLOG_CONS].init(STDOUT_FILENO);
272 log_stream[DLOG_CONS].set_enabled(event_loop, true);
274 else if (! enable && log_to_console) {
275 log_stream[DLOG_CONS].flushForRelease();
279 void discard_console_log_buffer() noexcept
281 log_stream[DLOG_CONS].discard();
284 // Variadic method to calculate the sum of string lengths:
285 static int sum_length(const char *arg) noexcept
287 return std::strlen(arg);
290 template <typename ... T> static int sum_length(const char * first, T ... args) noexcept
292 return sum_length(first) + sum_length(args...);
295 // Variadic method to append strings to a buffer:
296 static void append(BufferedLogStream &buf, const char *s)
298 buf.append(s, std::strlen(s));
301 template <typename ... T> static void append(BufferedLogStream &buf, const char *u, T ... t)
307 static int log_level_to_syslog_level(loglevel_t l)
310 case loglevel_t::DEBUG:
312 case loglevel_t::INFO:
314 case loglevel_t::WARN:
316 case loglevel_t::ERROR:
324 // Variadic method to log a sequence of strings as a single message to a particular facility:
325 template <typename ... T> static void push_to_log(int idx, T ... args) noexcept
327 if (! log_current_line[idx]) return;
328 int amount = sum_length(args...);
329 if (log_stream[idx].get_free() >= amount) {
330 append(log_stream[idx], args...);
331 log_stream[idx].commit_msg();
334 log_stream[idx].mark_discarded();
338 // Variadic method to potentially log a sequence of strings as a single message with the given log level:
339 template <typename ... T> static void do_log(loglevel_t lvl, T ... args) noexcept
341 log_current_line[DLOG_CONS] = lvl >= log_level[DLOG_CONS];
342 log_current_line[DLOG_MAIN] = lvl >= log_level[DLOG_MAIN];
343 push_to_log(DLOG_CONS, args...);
345 if (log_current_line[DLOG_MAIN]) {
347 snprintf(svcbuf, 10, "<%d>", LOG_DAEMON | log_level_to_syslog_level(lvl));
349 push_to_log(DLOG_MAIN, svcbuf, args...);
353 template <typename ... T> static void do_log_cons(T ... args) noexcept
355 log_current_line[DLOG_CONS] = true;
356 log_current_line[DLOG_MAIN] = false;
357 push_to_log(DLOG_CONS, args...);
360 // Log to the main facility at NOTICE level
361 template <typename ... T> static void do_log_main(T ... args) noexcept
363 log_current_line[DLOG_CONS] = false;
364 log_current_line[DLOG_MAIN] = true;
367 snprintf(svcbuf, 10, "<%d>", LOG_DAEMON | LOG_NOTICE);
369 push_to_log(DLOG_MAIN, svcbuf, args...);
372 // Log a message. A newline will be appended.
373 void log(loglevel_t lvl, const char *msg) noexcept
375 do_log(lvl, "dinit: ", msg, "\n");
378 // Log part of a message. A series of calls to do_log_part must be followed by a call to do_log_commit.
379 template <typename T> static void do_log_part(int idx, T arg) noexcept
381 if (log_current_line[idx]) {
382 int amount = sum_length(arg);
383 if (log_stream[idx].get_free() >= amount) {
384 append(log_stream[idx], arg);
387 log_stream[idx].rollback_msg();
388 log_current_line[idx] = false;
389 log_stream[idx].mark_discarded();
394 // Commit a message that was issued as a series of parts (via do_log_part).
395 static void do_log_commit(int idx) noexcept
397 if (log_current_line[idx]) {
398 log_stream[idx].commit_msg();
402 // Log a multi-part message beginning
403 void log_msg_begin(loglevel_t lvl, const char *msg) noexcept
405 log_current_line[DLOG_CONS] = lvl >= log_level[DLOG_CONS];
406 log_current_line[DLOG_MAIN] = lvl >= log_level[DLOG_MAIN];
408 if (log_current_line[DLOG_MAIN]) {
410 snprintf(svcbuf, 10, "<%d>", LOG_DAEMON | log_level_to_syslog_level(lvl));
411 do_log_part(DLOG_MAIN, svcbuf);
414 for (int i = 0; i < 2; i++) {
415 do_log_part(i, "dinit: ");
420 // Continue a multi-part log message
421 void log_msg_part(const char *msg) noexcept
423 do_log_part(DLOG_CONS, msg);
424 do_log_part(DLOG_MAIN, msg);
427 // Complete a multi-part log message
428 void log_msg_end(const char *msg) noexcept
430 for (int i = 0; i < 2; i++) {
432 do_log_part(i, "\n");
437 void log_service_started(const char *service_name) noexcept
439 do_log_cons("[ OK ] ", service_name, "\n");
440 do_log_main("dinit: service ", service_name, " started.\n");
443 void log_service_failed(const char *service_name) noexcept
445 do_log_cons("[FAILED] ", service_name, "\n");
446 do_log_main("dinit: service ", service_name, " failed to start.\n");
449 void log_service_stopped(const char *service_name) noexcept
451 do_log_cons("[STOPPD] ", service_name, "\n");
452 do_log_main("dinit: service ", service_name, " stopped.\n");