src/dinit-log.cc

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