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