#include <unistd.h>
#include <fcntl.h>
+#include <sys/syslog.h>
+#include <sys/uio.h>
-#include "dasync.h"
+#include "dasynq.h"
#include "service.h"
#include "dinit-log.h"
extern EventLoop_t eventLoop;
-LogLevel log_level = LogLevel::WARN;
-LogLevel cons_log_level = LogLevel::WARN;
-
-static bool log_to_console = false; // whether we should output log messages to
- // console immediately
-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<NullMutex>
+class BufferedLogStream : public EventLoop_t::FdWatcher
{
private:
// Outgoing:
bool partway = false; // if we are partway throught output of a log message
bool discarded = false; // if we have discarded a message
+ bool release = true; // if we should inhibit output and release console
// A "special message" is not stored in the circular buffer; instead
// it is delivered from an external buffer not managed by BufferedLogger.
// Incoming:
int current_index = 0; // current/next incoming message index
- int fd;
+ int fd = -1;
void init(int fd)
{
this->fd = fd;
+ release = false;
}
Rearm gotEvent(EventLoop_t *loop, int fd, int flags) noexcept override;
// Check whether the console can be released.
void flushForRelease();
+ void release_console();
+ bool is_release_set() { return release; }
// Commit a log message
void commit_msg()
{
bool was_first = current_index == 0;
current_index = log_buffer.get_length();
- if (was_first && log_to_console) {
+ if (was_first && ! release) {
setEnabled(&eventLoop, true);
- }
+ }
}
void rollback_msg()
{
- log_buffer.trim_to(current_index);
+ log_buffer.trim_to(current_index);
}
int get_free()
constexpr static int DLOG_MAIN = 0; // main log facility
constexpr static int DLOG_CONS = 1; // console
-
-static void release_console()
+void BufferedLogStream::release_console()
{
- if (! log_to_console) {
+ if (release) {
int flags = fcntl(1, F_GETFL, 0);
fcntl(1, F_SETFL, flags & ~O_NONBLOCK);
service_set->pullConsoleQueue();
void BufferedLogStream::flushForRelease()
{
+ release = true;
+
// 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);
}
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');
log_stream.partway = false;
log_stream.msg_index = 0;
- if (!log_to_console) {
+ if (release) {
release_console();
return Rearm::DISARM;
}
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;
}
// 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');
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<char *>(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;
log_stream.partway = ! complete;
if (complete) {
log_stream.current_index -= len;
- if (log_stream.current_index == 0 || !log_to_console) {
+ if (log_stream.current_index == 0 || release) {
// No more messages buffered / stop logging to console:
release_console();
return Rearm::DISARM;
}
}
}
- else {
- // TODO
- // EAGAIN / EWOULDBLOCK?
- // error?
- return Rearm::REARM;
+ else if (errno != EAGAIN && errno != EINTR && errno != EWOULDBLOCK) {
+ return Rearm::REMOVE;
}
}
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;
// queued in the service set will acquire the console.
void enable_console_log(bool enable) noexcept
{
+ bool log_to_console = ! log_stream[DLOG_CONS].is_release_set();
if (enable && ! log_to_console) {
// Console is fd 1 - stdout
// Set non-blocking IO:
// Activate watcher:
log_stream[DLOG_CONS].init(STDOUT_FILENO);
log_stream[DLOG_CONS].setEnabled(&eventLoop, true);
- log_to_console = true;
}
else if (! enable && log_to_console) {
- log_to_console = false;
log_stream[DLOG_CONS].flushForRelease();
}
}
return std::strlen(arg);
}
-template <typename U, typename ... T> static int sum_length(U first, T ... args) noexcept
+template <typename ... T> static int sum_length(const char * first, T ... args) noexcept
{
return sum_length(first) + sum_length(args...);
}
buf.append(s, std::strlen(s));
}
-template <typename U, typename ... T> static void append(BufferedLogStream &buf, U u, T ... t)
+template <typename ... T> 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 <typename ... T> static void do_log(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 <typename ... T> 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...);
-
- bool was_first = (log_stream[DLOG_CONS].current_index == 0);
- log_stream[DLOG_CONS].current_index += amount;
- if (was_first && log_to_console) {
- log_stream[DLOG_CONS].setEnabled(&eventLoop, true);
- }
+ if (log_stream[idx].get_free() >= amount) {
+ append(log_stream[idx], args...);
+ log_stream[idx].commit_msg();
}
else {
// TODO mark a discarded message
// Variadic method to potentially log a sequence of strings as a single message with the given log level:
template <typename ... T> static void do_log(LogLevel lvl, T ... args) noexcept
{
- if (lvl >= cons_log_level) {
- do_log(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 <typename ... T> 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 <typename ... T> 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
{
}
// Log part of a message. A series of calls to do_log_part must be followed by a call to do_log_commit.
-template <typename T> static void do_log_part(T arg) noexcept
+template <typename T> 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) {
- if (log_to_console) {
- 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) {
- if (log_to_console) {
- 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) {
- if (log_to_console) {
- 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("[ OK ] ", service_name, "\n");
+ 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("[FAILED] ", service_name, "\n");
+ 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("[STOPPD] ", service_name, "\n");
+ do_log_cons("[STOPPD] ", service_name, "\n");
+ do_log_main("dinit: service ", service_name, " stopped.\n");
}
projects / oweals / dinit.git / blobdiff