1 /**
2 Copyright: Copyright (c) 2018, Joakim Brännström. All rights reserved.
3 License: $(LINK2 http://www.boost.org/LICENSE_1_0.txt, Boost Software License 1.0)
4 Author: Joakim Brännström (joakim.brannstrom@gmx.com)
5 
6 Handles console logging in pretty colors.
7 
8 The module disables colors when stdout and stderr isn't a TTY that support
9 colors. This is to avoid ASCII escape sequences in piped output.
10 
11 The loggers use strings (their name) to form a hierarchy. Such that "a" is the
12 root and "a.b" is a child of "a". This can be used by you to change the log
13 level of a "sub tree" (`SpanMode.depth`).
14 */
15 module colorlog;
16 
17 import logger = std.experimental.logger;
18 import std.array : empty;
19 import std.conv : to;
20 import std.experimental.logger : LogLevel;
21 import std.stdio : writefln, stderr, stdout;
22 
23 public import my.term_color;
24 
25 /// The parent of all loggers.
26 immutable RootLogger = "";
27 
28 /// The verbosity level of the logging to use.
29 enum VerboseMode {
30     /// Info+
31     info,
32     /// Trace+
33     trace,
34     /// Warnings+
35     warning,
36 }
37 
38 LogLevel toLogLevel(VerboseMode mode) @safe pure nothrow @nogc {
39     final switch (mode) {
40     case VerboseMode.info:
41         return logger.LogLevel.info;
42     case VerboseMode.trace:
43         return logger.LogLevel.all;
44     case VerboseMode.warning:
45         return logger.LogLevel.warning;
46     }
47 }
48 
49 /** Configure `std.experimental.logger` `sharedLog` with a colorlog instance
50  * and register it with name "_".
51  */
52 void confLogger(VerboseMode mode) @safe {
53     logger.globalLogLevel = toLogLevel(mode);
54 
55     final switch (mode) {
56     case VerboseMode.info:
57         logger.sharedLog = new SimpleLogger(logger.LogLevel.info);
58         break;
59     case VerboseMode.trace:
60         logger.sharedLog = new DebugLogger(logger.LogLevel.all);
61         break;
62     case VerboseMode.warning:
63         logger.sharedLog = new SimpleLogger(logger.LogLevel.info);
64         break;
65     }
66 
67     () @trusted { register(logger.sharedLog, RootLogger); }();
68 }
69 
70 /** Default logger with low clutter in the console which mean it is suitable
71  * for use with user interfacing log messages.
72  *
73  * Automatically colors the log messages depending on their severity.
74  *
75  * As you may note the time is not printed. It isn't particularly useful for a
76  * user of your program as a CLI. A user would just be annoyed. But for e.g. a
77  * system log it may be. In that case, use another logger than this one.
78  */
79 class SimpleLogger : logger.Logger {
80     this(const LogLevel lvl = LogLevel.warning) @safe {
81         super(lvl);
82         initColors;
83     }
84 
85     override void writeLogMsg(ref LogEntry payload) @trusted {
86         auto out_ = stderr;
87         auto use_color = Color.red;
88         auto use_mode = Mode.bold;
89         const use_bg = Background.black;
90 
91         switch (payload.logLevel) {
92         case LogLevel.trace:
93             out_ = stdout;
94             use_color = Color.white;
95             use_mode = Mode.init;
96             break;
97         case LogLevel.info:
98             out_ = stdout;
99             use_color = Color.white;
100             break;
101         default:
102         }
103 
104         out_.writefln("%s: %s", payload.logLevel.to!string.color(use_color)
105                 .bg(use_bg).mode(use_mode), payload.msg);
106     }
107 }
108 
109 /** Logger focused on debugging a program with colorization of the severity.
110  *
111  * The logger print the `file:line` at the end of the message to make it easier
112  * to read a log.  By doing so this logger can be used to print e.g. an
113  * indented AST and still keep the `file:line`.
114  *
115  * Same motivation here as the `SimpleLogger` when it comes to the timestamp.
116  * It isn't particularly useful for what the logger is intended to be used for.
117  */
118 class DebugLogger : logger.Logger {
119     this(const logger.LogLevel lvl = LogLevel.trace) @safe {
120         super(lvl);
121         initColors;
122     }
123 
124     override void writeLogMsg(ref LogEntry payload) @trusted {
125         auto out_ = stderr;
126         auto use_color = Color.red;
127         auto use_mode = Mode.bold;
128         const use_bg = Background.black;
129 
130         switch (payload.logLevel) {
131         case LogLevel.trace:
132             out_ = stdout;
133             use_color = Color.white;
134             use_mode = Mode.init;
135             break;
136         case LogLevel.info:
137             out_ = stdout;
138             use_color = Color.white;
139             break;
140         default:
141         }
142 
143         out_.writefln("%s: %s [%s:%d]", payload.logLevel.to!string.color(use_color)
144                 .bg(use_bg).mode(use_mode), payload.msg, payload.funcName, payload.line);
145     }
146 }
147 
148 /// A string mixin to create a SimpleLogger for the module.
149 string mixinModuleLogger(logger.LogLevel defaultLogLvl = logger.LogLevel.all) @safe pure {
150     return "shared static this() { import std.experimental.logger : LogLevel; make!SimpleLogger(LogLevel."
151         ~ defaultLogLvl.to!string ~ "); }";
152 }
153 
154 /// Register a logger for the module and make it configurable from "outside" via the registry.
155 void register(logger.Logger logger, string name = __MODULE__) {
156     synchronized (poolLock) {
157         loggers[name] = cast(shared) logger;
158     }
159 }
160 
161 /// Create a logger for the module and make it configurable from "outside" via the registry.
162 void make(LoggerT)(const logger.LogLevel lvl = logger.LogLevel.all, string name = __MODULE__) @trusted {
163     register(new LoggerT(lvl), name);
164 }
165 
166 /// Returns: the name of all registered loggers.
167 string[] getRegisteredLoggers() @trusted {
168     import std.array : appender;
169 
170     auto app = appender!(string[])();
171     synchronized (poolLock) {
172         foreach (a; (cast() loggers).byKey)
173             app.put(a);
174     }
175 
176     return app.data;
177 }
178 
179 /// Remove all registered loggers.
180 void clearAllLoggers() @trusted {
181     synchronized (poolLock) {
182         loggers = null;
183     }
184 }
185 
186 enum SpanMode {
187     /// Set only the specified logger.
188     single,
189     /// Set the logger and all its children.
190     depth
191 }
192 
193 /// Set the log level for `name`.
194 void setLogLevel(const string name, const logger.LogLevel lvl, const SpanMode span = SpanMode
195         .single) @trusted {
196     static void setSingle(const string name, const logger.LogLevel lvl) {
197         if (auto v = name in loggers) {
198             auto uv = cast()*v;
199             uv.logLevel = lvl;
200         } else {
201             throw new UnknownLogger("no such logger registered: " ~ name);
202         }
203     }
204 
205     static void depth(string startName, const logger.LogLevel lvl) {
206         import std.algorithm : filter, startsWith;
207 
208         auto loggersU = cast(logger.Logger[string]) loggers;
209         foreach (a; loggersU.byKeyValue.filter!(a => a.key.startsWith(startName))) {
210             a.value.logLevel = lvl;
211         }
212     }
213 
214     synchronized (poolLock) {
215         final switch (span) {
216         case SpanMode.single:
217             setSingle(name, lvl);
218             break;
219         case SpanMode.depth:
220             setSingle(name, lvl);
221             depth(name, lvl);
222             break;
223         }
224     }
225 }
226 
227 /// Set the log level for all loggers in `names`.
228 void setLogLevel(const string[] names, const logger.LogLevel lvl,
229         const SpanMode span = SpanMode.single) @safe {
230     if (names.empty)
231         return;
232 
233     logger.globalLogLevel = lvl;
234     foreach (a; names)
235         setLogLevel(a, lvl, span);
236 }
237 
238 /// Set the log level for all loggers in `names`.
239 void setLogLevel(const NameLevel[] names, const SpanMode span = SpanMode.single) @safe {
240     import std.algorithm : min;
241 
242     if (names.empty)
243         return;
244 
245     auto global = logger.LogLevel.off;
246 
247     foreach (a; names) {
248         setLogLevel(a.name, a.level, span);
249         global = min(a.level, global);
250     }
251 
252     logger.globalLogLevel = global;
253 }
254 
255 /** Log a mesage to the specified logger.
256  *
257  * This only takes the global lock one time and then cache the logger.
258  */
259 logger.Logger log(string name = __MODULE__)() @trusted {
260     static logger.Logger local;
261 
262     if (local !is null)
263         return local;
264 
265     synchronized (poolLock) {
266         if (auto v = name in loggers) {
267             local = cast()*v;
268             return cast()*v;
269         }
270     }
271 
272     throw new UnknownLogger("no such logger registered: " ~ name);
273 }
274 
275 struct NameLevel {
276     string name;
277     LogLevel level;
278 }
279 
280 /// Parse a comma+equal separated string for logger names that can be used with `setLogLevel`.
281 NameLevel[] parseLogNames(string arg, logger.LogLevel defaultLogLvl = logger.LogLevel.all) @safe pure {
282     import std.algorithm : splitter, joiner, map;
283     import std.array : array;
284     import std..string : split;
285 
286     NameLevel[] conv(string s) {
287         try {
288             auto sp = split(s, '=');
289             if (sp.length != 2)
290                 return [NameLevel(s, defaultLogLvl)];
291             return [NameLevel(sp[0], sp[1].to!(logger.LogLevel))];
292         } catch (Exception e) {
293         }
294         return NameLevel[].init;
295     }
296 
297     return arg.splitter(',').map!conv.joiner.array;
298 }
299 
300 /** Always takes the global lock to find the logger.
301  *
302  * This is safe to use whenever because if they logger is replaced it will be
303  * returned.  Normally though this feature isn't needed. Normally all loggers
304  * are registered during module initialization and then they are not changed.
305  */
306 logger.Logger logSlow(string name = __MODULE__)() @trusted {
307     synchronized (poolLock) {
308         if (auto v = name in loggers) {
309             return cast()*v;
310         }
311     }
312 
313     throw new UnknownLogger("no such logger registered: " ~ name);
314 }
315 
316 /// Unknown logger.
317 class UnknownLogger : Exception {
318     this(string msg, string file = __FILE__, int line = __LINE__) @safe pure nothrow {
319         super(msg, file, line);
320     }
321 }
322 
323 @("shall instantiate a logger and register")
324 unittest {
325     scope (exit)
326         clearAllLoggers;
327     make!TestLogger();
328     assert([__MODULE__] == getRegisteredLoggers());
329 }
330 
331 @("shall register a logger and register")
332 unittest {
333     scope (exit)
334         clearAllLoggers;
335     register(new TestLogger);
336     assert([__MODULE__] == getRegisteredLoggers());
337 }
338 
339 @("shall log a message")
340 unittest {
341     scope (exit)
342         clearAllLoggers;
343     make!TestLogger();
344 
345     logSlow.warning("hej");
346 
347     synchronized (poolLock) {
348         assert(!((cast(TestLogger) loggers[__MODULE__]).lastMsg.empty), "no message logged");
349     }
350 }
351 
352 @("shall change the log level")
353 unittest {
354     scope (exit)
355         clearAllLoggers;
356     make!TestLogger(logger.LogLevel.warning);
357     make!TestLogger(logger.LogLevel.warning, __MODULE__ ~ ".b");
358 
359     setLogLevel(__MODULE__, logger.LogLevel.trace);
360 
361     logSlow.trace("hej");
362     logSlow!(__MODULE__ ~ ".b").trace("hej");
363 
364     synchronized (poolLock) {
365         assert(!((cast(TestLogger) loggers[__MODULE__]).lastMsg.empty),
366                 "message found when it shouldn't");
367         assert(((cast(TestLogger) loggers[__MODULE__ ~ ".b"]).lastMsg.empty),
368                 "message found when it shouldn't");
369     }
370 }
371 
372 @("shall change the log level from parent and up")
373 unittest {
374     scope (exit)
375         clearAllLoggers;
376     make!TestLogger(logger.LogLevel.warning);
377     make!TestLogger(logger.LogLevel.warning, __MODULE__ ~ ".b");
378 
379     setLogLevel(__MODULE__, logger.LogLevel.trace, SpanMode.depth);
380 
381     logSlow.trace("hej");
382     logSlow!(__MODULE__ ~ ".b").trace("hej");
383 
384     synchronized (poolLock) {
385         assert(!((cast(TestLogger) loggers[__MODULE__]).lastMsg.empty),
386                 "message found when it shouldn't");
387         assert(!((cast(TestLogger) loggers[__MODULE__ ~ ".b"]).lastMsg.empty),
388                 "message found when it shouldn't");
389     }
390 }
391 
392 @("shall parse a comma separate list")
393 unittest {
394     assert(parseLogNames("hej=trace,foo") == [
395             NameLevel("hej", logger.LogLevel.trace),
396             NameLevel("foo", logger.LogLevel.all)
397             ]);
398 }
399 
400 private:
401 
402 import core.sync.mutex : Mutex;
403 
404 // The width of the prefix.
405 immutable _prefixWidth = 8;
406 
407 // Mutex for the logger pool.
408 shared Mutex poolLock;
409 shared logger.Logger[string] loggers;
410 
411 shared static this() {
412     poolLock = cast(shared) new Mutex();
413 }
414 
415 class TestLogger : logger.Logger {
416     this(const logger.LogLevel lvl = LogLevel.trace) @safe {
417         super(lvl);
418     }
419 
420     string lastMsg;
421 
422     override void writeLogMsg(ref LogEntry payload) @trusted {
423         import std.format : format;
424 
425         lastMsg = format!"%s: %s [%s:%d]"(payload.logLevel, payload.msg,
426                 payload.funcName, payload.line);
427     }
428 }