Refactoring. Move buffered output management (variables) into a
[oweals/dinit.git] / 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 }