X-Git-Url: https://git.librecmc.org/?a=blobdiff_plain;f=src%2Fdinit-log.cc;h=43062f0f15a400ca938c7d188be6b9f9d5dcc28b;hb=100650949c81204d8d52002e028aa8858a406bce;hp=b1bdf2fb896dfa3eccc33ab6c9420dc05fc4fc81;hpb=46f77653ae0b2ef1d6fa031aa2eb77c85f464aaa;p=oweals%2Fdinit.git diff --git a/src/dinit-log.cc b/src/dinit-log.cc index b1bdf2f..43062f0 100644 --- a/src/dinit-log.cc +++ b/src/dinit-log.cc @@ -3,8 +3,10 @@ #include #include +#include +#include -#include "dasync.h" +#include "dasynq.h" #include "service.h" #include "dinit-log.h" @@ -12,15 +14,13 @@ extern EventLoop_t eventLoop; -LogLevel log_level = LogLevel::WARN; -LogLevel cons_log_level = LogLevel::WARN; - -static bool log_current_line; // Whether the current line is being logged +static bool log_current_line[2]; // Whether the current line is being logged (for console, main log) +LogLevel log_level[2] = { LogLevel::WARN, LogLevel::WARN }; static ServiceSet *service_set = nullptr; // Reference to service set namespace { -class BufferedLogStream : public PosixFdWatcher +class BufferedLogStream : public EventLoop_t::FdWatcher { private: @@ -42,7 +42,7 @@ class BufferedLogStream : public PosixFdWatcher // Incoming: int current_index = 0; // current/next incoming message index - int fd; + int fd = -1; void init(int fd) { @@ -91,7 +91,6 @@ static BufferedLogStream log_stream[2]; constexpr static int DLOG_MAIN = 0; // main log facility constexpr static int DLOG_CONS = 1; // console - void BufferedLogStream::release_console() { if (release) { @@ -107,7 +106,7 @@ void BufferedLogStream::flushForRelease() // Try to flush any messages that are currently buffered. (Console is non-blocking // so it will fail gracefully). - if (gotEvent(&eventLoop, fd, out_events) == Rearm::DISARM) { + if (gotEvent(&eventLoop, fd, OUT_EVENTS) == Rearm::DISARM) { // Console has already been released at this point. setEnabled(&eventLoop, false); } @@ -117,10 +116,8 @@ void BufferedLogStream::flushForRelease() Rearm BufferedLogStream::gotEvent(EventLoop_t *loop, int fd, int flags) noexcept { - // TODO correct for the case that this is *not* the console log stream. - auto &log_stream = *this; - + if ((! partway) && log_stream.special) { char * start = log_stream.special_buf + log_stream.msg_index; char * end = std::find(log_stream.special_buf + log_stream.msg_index, (char *)nullptr, '\n'); @@ -142,10 +139,8 @@ Rearm BufferedLogStream::gotEvent(EventLoop_t *loop, int fd, int flags) noexcept return Rearm::REARM; } } - else { - // spurious readiness - EAGAIN or EWOULDBLOCK? - // other error? - // TODO + else if (errno != EAGAIN && errno != EINTR && errno != EWOULDBLOCK) { + return Rearm::REMOVE; } return Rearm::REARM; } @@ -154,13 +149,19 @@ Rearm BufferedLogStream::gotEvent(EventLoop_t *loop, int fd, int flags) noexcept // TODO issue special message if we have discarded a log message - if (log_stream.current_index == 0) { + if (current_index == 0) { release_console(); return Rearm::DISARM; } - char *ptr = log_stream.log_buffer.get_ptr(0); - int len = log_stream.log_buffer.get_contiguous_length(ptr); + // We try to find a complete line (terminated by '\n') in the buffer, and write it + // out. Since it may span the circular buffer end, it may consist of two distinct spans, + // and so we use writev to write them atomically. + + struct iovec logiov[2]; + + char *ptr = log_buffer.get_ptr(0); + int len = log_buffer.get_contiguous_length(ptr); char *creptr = ptr + len; // contiguous region end char *eptr = std::find(ptr, creptr, '\n'); @@ -172,7 +173,27 @@ Rearm BufferedLogStream::gotEvent(EventLoop_t *loop, int fd, int flags) noexcept len = eptr - ptr; - int r = write(fd, ptr, len); + logiov[0].iov_base = ptr; + logiov[0].iov_len = len; + int iovs_to_write = 1; + + // Do we need the second span? + if (! will_complete && len != log_buffer.get_length()) { + ptr = log_buffer.get_buf_base(); + creptr = static_cast(logiov[1].iov_base) + log_buffer.get_length() - len; + eptr = std::find(ptr, creptr, '\n'); + if (eptr != creptr) { + eptr++; // include '\n' + // It should not ever be the case that we do not now have a complete message + will_complete = true; + } + logiov[1].iov_base = ptr; + logiov[1].iov_len = eptr - ptr; + len += logiov[1].iov_len; + iovs_to_write = 2; + } + + ssize_t r = writev(fd, logiov, iovs_to_write); if (r >= 0) { bool complete = (r == len) && will_complete; @@ -187,11 +208,8 @@ Rearm BufferedLogStream::gotEvent(EventLoop_t *loop, int fd, int flags) noexcept } } } - else { - // TODO - // EAGAIN / EWOULDBLOCK? - // error? - return Rearm::REARM; + else if (errno != EAGAIN && errno != EINTR && errno != EWOULDBLOCK) { + return Rearm::REMOVE; } } @@ -200,13 +218,23 @@ Rearm BufferedLogStream::gotEvent(EventLoop_t *loop, int fd, int flags) noexcept return Rearm::REARM; } -void init_log(ServiceSet *sset) noexcept +// Initialise the logging subsystem +// Potentially throws std::bad_alloc or std::system_error +void init_log(ServiceSet *sset) { service_set = sset; - log_stream[DLOG_CONS].registerWith(&eventLoop, STDOUT_FILENO, out_events); // TODO register in disabled state + log_stream[DLOG_CONS].registerWith(&eventLoop, STDOUT_FILENO, OUT_EVENTS); // TODO register in disabled state enable_console_log(true); } +// Set up the main log to output to the given file descriptor. +// Potentially throws std::bad_alloc or std::system_error +void setup_main_log(int fd) +{ + log_stream[DLOG_MAIN].init(fd); + log_stream[DLOG_MAIN].registerWith(&eventLoop, fd, OUT_EVENTS); +} + bool is_log_flushed() noexcept { return log_stream[DLOG_CONS].current_index == 0; @@ -239,7 +267,7 @@ static int sum_length(const char *arg) noexcept return std::strlen(arg); } -template static int sum_length(U first, T ... args) noexcept +template static int sum_length(const char * first, T ... args) noexcept { return sum_length(first) + sum_length(args...); } @@ -250,19 +278,37 @@ static void append(BufferedLogStream &buf, const char *s) buf.append(s, std::strlen(s)); } -template static void append(BufferedLogStream &buf, U u, T ... t) +template static void append(BufferedLogStream &buf, const char *u, T ... t) { append(buf, u); append(buf, t...); } -// Variadic method to log a sequence of strings as a single message: -template static void do_log_cons(T ... args) noexcept +static int log_level_to_syslog_level(LogLevel l) +{ + switch (l) { + case LogLevel::DEBUG: + return LOG_DEBUG; + case LogLevel::INFO: + return LOG_INFO; + case LogLevel::WARN: + return LOG_WARNING; + case LogLevel::ERROR: + return LOG_ERR; + default: ; + } + + return LOG_CRIT; +} + +// Variadic method to log a sequence of strings as a single message to a particular facility: +template static void push_to_log(int idx, T ... args) noexcept { + if (! log_current_line[idx]) return; int amount = sum_length(args...); - if (log_stream[DLOG_CONS].get_free() >= amount) { - append(log_stream[DLOG_CONS], args...); - log_stream[DLOG_CONS].commit_msg(); + if (log_stream[idx].get_free() >= amount) { + append(log_stream[idx], args...); + log_stream[idx].commit_msg(); } else { // TODO mark a discarded message @@ -272,11 +318,37 @@ template static void do_log_cons(T ... args) noexcept // Variadic method to potentially log a sequence of strings as a single message with the given log level: template static void do_log(LogLevel lvl, T ... args) noexcept { - if (lvl >= cons_log_level) { - do_log_cons(args...); + log_current_line[DLOG_CONS] = lvl >= log_level[DLOG_CONS]; + log_current_line[DLOG_MAIN] = lvl >= log_level[DLOG_MAIN]; + push_to_log(DLOG_CONS, args...); + + if (log_current_line[DLOG_MAIN]) { + char svcbuf[10]; + snprintf(svcbuf, 10, "<%d>", LOG_DAEMON | log_level_to_syslog_level(lvl)); + + push_to_log(DLOG_MAIN, svcbuf, args...); } } +template static void do_log_cons(T ... args) noexcept +{ + log_current_line[DLOG_CONS] = true; + log_current_line[DLOG_MAIN] = false; + push_to_log(DLOG_CONS, args...); +} + +// Log to the main facility at NOTICE level +template static void do_log_main(T ... args) noexcept +{ + log_current_line[DLOG_CONS] = false; + log_current_line[DLOG_MAIN] = true; + + char svcbuf[10]; + snprintf(svcbuf, 10, "<%d>", LOG_DAEMON | LOG_NOTICE); + + push_to_log(DLOG_MAIN, svcbuf, args...); +} + // Log a message. A newline will be appended. void log(LogLevel lvl, const char *msg) noexcept { @@ -284,69 +356,78 @@ void log(LogLevel lvl, const char *msg) noexcept } // Log part of a message. A series of calls to do_log_part must be followed by a call to do_log_commit. -template static void do_log_part(T arg) noexcept +template static void do_log_part(int idx, T arg) noexcept { - int amount = sum_length(arg); - if (log_stream[DLOG_CONS].get_free() >= amount) { - append(log_stream[DLOG_CONS], arg); - } - else { - log_stream[DLOG_CONS].rollback_msg(); - log_current_line = false; - // TODO mark discarded message + if (log_current_line[idx]) { + int amount = sum_length(arg); + if (log_stream[idx].get_free() >= amount) { + append(log_stream[idx], arg); + } + else { + log_stream[idx].rollback_msg(); + log_current_line[idx] = false; + // TODO mark discarded message + } } } // Commit a message that was issued as a series of parts (via do_log_part). -static void do_log_commit() noexcept +static void do_log_commit(int idx) noexcept { - if (log_current_line) { - log_stream[DLOG_CONS].commit_msg(); + if (log_current_line[idx]) { + log_stream[idx].commit_msg(); } } // Log a multi-part message beginning void logMsgBegin(LogLevel lvl, const char *msg) noexcept { - // TODO use buffer - log_current_line = lvl >= log_level; - if (log_current_line) { - do_log_part("dinit: "); - do_log_part(msg); + log_current_line[DLOG_CONS] = lvl >= log_level[DLOG_CONS]; + log_current_line[DLOG_MAIN] = lvl >= log_level[DLOG_MAIN]; + + if (log_current_line[DLOG_MAIN]) { + char svcbuf[10]; + snprintf(svcbuf, 10, "<%d>", LOG_DAEMON | log_level_to_syslog_level(lvl)); + do_log_part(DLOG_MAIN, svcbuf); + } + + for (int i = 0; i < 2; i++) { + do_log_part(i, "dinit: "); + do_log_part(i, msg); } } // Continue a multi-part log message void logMsgPart(const char *msg) noexcept { - // TODO use buffer - if (log_current_line) { - do_log_part(msg); - } + do_log_part(DLOG_CONS, msg); + do_log_part(DLOG_MAIN, msg); } // Complete a multi-part log message void logMsgEnd(const char *msg) noexcept { - // TODO use buffer - if (log_current_line) { - do_log_part(msg); - do_log_part("\n"); - do_log_commit(); + for (int i = 0; i < 2; i++) { + do_log_part(i, msg); + do_log_part(i, "\n"); + do_log_commit(i); } } void logServiceStarted(const char *service_name) noexcept { do_log_cons("[ OK ] ", service_name, "\n"); + do_log_main("dinit: service ", service_name, " started.\n"); } void logServiceFailed(const char *service_name) noexcept { do_log_cons("[FAILED] ", service_name, "\n"); + do_log_main("dinit: service ", service_name, " failed to start.\n"); } void logServiceStopped(const char *service_name) noexcept { do_log_cons("[STOPPD] ", service_name, "\n"); + do_log_main("dinit: service ", service_name, " stopped.\n"); }