src/dinit-log.cc

   1 #include <iostream>
   2 #include <algorithm>
   3
   4 #include <ev.h>
   5 #include <unistd.h>
   6 #include <fcntl.h>
   7
   8 #include "service.h"
   9 #include "dinit-log.h"
  10 #include "cpbuffer.h"
  11
  12 LogLevel log_level = LogLevel::WARN;
  13 LogLevel cons_log_level = LogLevel::WARN;
  14 static bool log_to_console = false;   // whether we should output log messages to
  15                                      // console immediately
  16 static bool log_current_line;  // Whether the current line is being logged
  17
  18 static ServiceSet *service_set = nullptr;  // Reference to service set
  19
  20
  21 static void log_conn_callback(struct ev_loop *loop, struct ev_io *w, int revents) noexcept;
  22
  23 class BufferedLogStream
  24 {
  25     public:
  26     CPBuffer<4096> log_buffer;
  27
  28     struct ev_io eviocb;
  29
  30     // Outgoing:
  31     bool partway = false;     // if we are partway throught output of a log message
  32     bool discarded = false;   // if we have discarded a message
  33
  34     // Incoming:
  35     int current_index = 0;    // current/next incoming message index
  36        // ^^ TODO is this always just the length of log_buffer?
  37
  38     // A "special message" is not stored in the circular buffer; instead
  39     // it is delivered from an external buffer not managed by BufferedLogger.
  40     bool special = false;      // currently outputting special message?
  41     char *special_buf; // buffer containing special message
  42     int msg_index;     // index into special message
  43
  44     void init(int fd)
  45     {
  46         ev_io_init(&eviocb, log_conn_callback, fd, EV_WRITE);
  47         eviocb.data = this;
  48     }
  49 };
  50
  51 // Two log streams:
  52 // (One for main log, one for console)
  53 static BufferedLogStream log_stream[2];
  54
  55 constexpr static int DLOG_MAIN = 0; // main log facility
  56 constexpr static int DLOG_CONS = 1; // console
  57
  58
  59 static void release_console()
  60 {
  61     ev_io_stop(ev_default_loop(EVFLAG_AUTO), & log_stream[DLOG_CONS].eviocb);
  62     if (! log_to_console) {
  63         int flags = fcntl(1, F_GETFL, 0);
  64         fcntl(1, F_SETFL, flags & ~O_NONBLOCK);
  65         service_set->pullConsoleQueue();
  66     }
  67 }
  68
  69 static void log_conn_callback(struct ev_loop * loop, ev_io * w, int revents) noexcept
  70 {
  71     auto &log_stream = *static_cast<BufferedLogStream *>(w->data);
  72
  73     if (log_stream.special) {
  74         char * start = log_stream.special_buf + log_stream.msg_index;
  75         char * end = std::find(log_stream.special_buf + log_stream.msg_index, (char *)nullptr, '\n');
  76         int r = write(w->fd, start, end - start + 1);
  77         if (r >= 0) {
  78             if (start + r > end) {
  79                 // All written: go on to next message in queue
  80                 log_stream.special = false;
  81                 log_stream.partway = false;
  82                 log_stream.msg_index = 0;
  83             }
  84             else {
  85                 log_stream.msg_index += r;
  86                 return;
  87             }
  88         }
  89         else {
  90             // spurious readiness - EAGAIN or EWOULDBLOCK?
  91             // other error?
  92             // TODO
  93         }
  94         return;
  95     }
  96     else {
  97         // Writing from the regular circular buffer
  98
  99         // TODO issue special message if we have discarded a log message
 100
 101         if (log_stream.current_index == 0) {
 102             release_console();
 103             return;
 104         }
 105
 106         char *ptr = log_stream.log_buffer.get_ptr(0);
 107         int len = log_stream.log_buffer.get_contiguous_length(ptr);
 108         char *creptr = ptr + len;  // contiguous region end
 109         char *eptr = std::find(ptr, creptr, '\n');
 110
 111         bool will_complete = false;  // will complete this message?
 112         if (eptr != creptr) {
 113             eptr++;  // include '\n'
 114             will_complete = true;
 115         }
 116
 117         len = eptr - ptr;
 118
 119         int r = write(w->fd, ptr, len);
 120
 121         if (r >= 0) {
 122             bool complete = (r == len) && will_complete;
 123             log_stream.log_buffer.consume(len);
 124             log_stream.partway = ! complete;
 125             if (complete) {
 126                 log_stream.current_index -= len;
 127                 if (log_stream.current_index == 0 || !log_to_console) {
 128                     // No more messages buffered / stop logging to console:
 129                     release_console();
 130                 }
 131             }
 132         }
 133         else {
 134             // TODO
 135             // EAGAIN / EWOULDBLOCK?
 136             // error?
 137             return;
 138         }
 139     }
 140
 141     // We've written something by the time we get here. We could fall through to below, but
 142     // let's give other events a chance to be processed by returning now.
 143     return;
 144 }
 145
 146 void init_log(ServiceSet *sset) noexcept
 147 {
 148     service_set = sset;
 149     enable_console_log(true);
 150 }
 151
 152 // Enable or disable console logging. If disabled, console logging will be disabled on the
 153 // completion of output of the current message (if any), at which point the first service record
 154 // queued in the service set will acquire the console.
 155 void enable_console_log(bool enable) noexcept
 156 {
 157     if (enable && ! log_to_console) {
 158         // Console is fd 1 - stdout
 159         // Set non-blocking IO:
 160         int flags = fcntl(1, F_GETFL, 0);
 161         fcntl(1, F_SETFL, flags | O_NONBLOCK);
 162         // Activate watcher:
 163         //ev_io_init(& log_stream[DLOG_CONS].eviocb, log_conn_callback, 1, EV_WRITE);
 164         log_stream[DLOG_CONS].init(STDOUT_FILENO);
 165         if (log_stream[DLOG_CONS].current_index > 0) {
 166             ev_io_start(ev_default_loop(EVFLAG_AUTO), & log_stream[DLOG_CONS].eviocb);
 167         }
 168         log_to_console = true;
 169     }
 170     else if (! enable && log_to_console) {
 171         log_to_console = false;
 172         if (! log_stream[DLOG_CONS].partway) {
 173             if (log_stream[DLOG_CONS].current_index > 0) {
 174                 // Try to flush any messages that are currently buffered. (Console is non-blocking
 175                 // so it will fail gracefully).
 176                 log_conn_callback(ev_default_loop(EVFLAG_AUTO), & log_stream[DLOG_CONS].eviocb, EV_WRITE);
 177             }
 178             else {
 179                 release_console();
 180             }
 181         }
 182         // (if we're partway through logging a message, we release the console when
 183         // finished).
 184     }
 185 }
 186
 187
 188 // Variadic method to calculate the sum of string lengths:
 189 static int sum_length(const char *arg) noexcept
 190 {
 191     return std::strlen(arg);
 192 }
 193
 194 template <typename U, typename ... T> static int sum_length(U first, T ... args) noexcept
 195 {
 196     return sum_length(first) + sum_length(args...);
 197 }
 198
 199 // Variadic method to append strings to a buffer:
 200 static void append(CPBuffer<4096> &buf, const char *s)
 201 {
 202     buf.append(s, std::strlen(s));
 203 }
 204
 205 template <typename U, typename ... T> static void append(CPBuffer<4096> &buf, U u, T ... t)
 206 {
 207     append(buf, u);
 208     append(buf, t...);
 209 }
 210
 211 // Variadic method to log a sequence of strings as a single message:
 212 template <typename ... T> static void do_log(T ... args) noexcept
 213 {
 214     int amount = sum_length(args...);
 215     if (log_stream[DLOG_CONS].log_buffer.get_free() >= amount) {
 216         append(log_stream[DLOG_CONS].log_buffer, args...);
 217
 218         bool was_first = (log_stream[DLOG_CONS].current_index == 0);
 219         log_stream[DLOG_CONS].current_index += amount;
 220         if (was_first && log_to_console) {
 221             ev_io_start(ev_default_loop(EVFLAG_AUTO), & log_stream[DLOG_CONS].eviocb);
 222         }
 223     }
 224     else {
 225         // TODO mark a discarded message
 226     }
 227 }
 228
 229 // Variadic method to potentially log a sequence of strings as a single message with the given log level:
 230 template <typename ... T> static void do_log(LogLevel lvl, T ... args) noexcept
 231 {
 232     if (lvl >= cons_log_level) {
 233         do_log(args...);
 234     }
 235 }
 236
 237
 238 // Log a message. A newline will be appended.
 239 void log(LogLevel lvl, const char *msg) noexcept
 240 {
 241     do_log(lvl, "dinit: ", msg, "\n");
 242 }
 243
 244 // Log a multi-part message beginning
 245 void logMsgBegin(LogLevel lvl, const char *msg) noexcept
 246 {
 247     // TODO use buffer
 248     log_current_line = lvl >= log_level;
 249     if (log_current_line) {
 250         if (log_to_console) {
 251             std::cout << "dinit: " << msg;
 252         }
 253     }
 254 }
 255
 256 // Continue a multi-part log message
 257 void logMsgPart(const char *msg) noexcept
 258 {
 259     // TODO use buffer
 260     if (log_current_line) {
 261         if (log_to_console) {
 262             std::cout << msg;
 263         }
 264     }
 265 }
 266
 267 // Complete a multi-part log message
 268 void logMsgEnd(const char *msg) noexcept
 269 {
 270     // TODO use buffer
 271     if (log_current_line) {
 272         if (log_to_console) {
 273             std::cout << msg << std::endl;
 274         }
 275     }
 276 }
 277
 278 void logServiceStarted(const char *service_name) noexcept
 279 {
 280     do_log("[  OK  ] ", service_name, "\n");
 281 }
 282
 283 void logServiceFailed(const char *service_name) noexcept
 284 {
 285     do_log("[FAILED] ", service_name, "\n");
 286 }
 287
 288 void logServiceStopped(const char *service_name) noexcept
 289 {
 290     do_log("[STOPPD] ", service_name, "\n");
 291 }