1 //          Copyright Mario Kröplin 2019.
2 // Distributed under the Boost Software License, Version 1.0.
3 //    (See accompanying file LICENSE_1_0.txt or copy at
4 //          http://www.boost.org/LICENSE_1_0.txt)
5 
6 module util.log;
7 
8 import std.algorithm;
9 import std.array;
10 import std.conv;
11 import std.datetime;
12 import std.format;
13 import std.range;
14 import std.stdio;
15 import std.string;
16 import std.traits;
17 import std.typecons;
18 
19 /// Defines the importance of a log message.
20 enum LogLevel
21 {
22     /// detailed tracing
23     trace = 1,
24     /// useful information
25     info = 2,
26     /// potential problem
27     warn = 4,
28     /// recoverable _error
29     error = 8,
30     /// _fatal failure
31     fatal = 16,
32 }
33 
34 /// Returns a bit set containing the level and all levels above.
35 @safe
36 uint orAbove(LogLevel level) pure
37 {
38     return [EnumMembers!LogLevel].find(level).reduce!"a | b";
39 }
40 
41 ///
42 unittest
43 {
44     with (LogLevel)
45     {
46         assert(trace.orAbove == (trace | info | warn | error | fatal));
47         assert(fatal.orAbove == fatal);
48     }
49 }
50 
51 /// Returns a bit set containing the level and all levels below.
52 @safe
53 uint orBelow(LogLevel level) pure
54 {
55     return [EnumMembers!LogLevel].retro.find(level).reduce!"a | b";
56 }
57 
58 ///
59 unittest
60 {
61     with (LogLevel)
62     {
63         assert(trace.orBelow == trace);
64         assert(fatal.orBelow == (trace | info | warn | error | fatal));
65     }
66 }
67 
68 @safe
69 bool disabled(LogLevel level) pure
70 {
71     uint levels = 0;
72 
73     with (LogLevel)
74     {
75         version (DisableTrace)
76             levels |= trace;
77         version (DisableInfo)
78             levels |= info;
79         version (DisableWarn)
80             levels |= warn;
81         version (DisableError)
82             levels |= error;
83         version (DisableFatal)
84             levels |= fatal;
85     }
86     return (level & levels) != 0;
87 }
88 
89 private alias Sink = OutputRange!(const(char)[]);
90 
91 struct Log
92 {
93     private Logger[] loggers;
94 
95     // preallocate so we can fill it in @nogc fileDescriptors()
96     private int[] buffer;
97 
98     private uint levels;
99 
100     this(Logger[] loggers ...)
101     in (loggers.all!"a !is null")
102     {
103         this.loggers = loggers.dup;
104         buffer = new int[this.loggers.length];
105         levels = reduce!((a, b) => a | b.levels)(0, this.loggers);
106     }
107 
108     public int[] fileDescriptors() @nogc nothrow @safe
109     in (buffer.length >= loggers.length)
110     {
111         size_t length = 0;
112 
113         foreach (logger; loggers)
114         {
115             const fileDescriptor = logger.fileDescriptor;
116 
117             if (!fileDescriptor.isNull)
118                 buffer[length++] = fileDescriptor.get;
119         }
120         return buffer[0 .. length];
121     }
122 
123     alias trace = append!(LogLevel.trace);
124     alias info = append!(LogLevel.info);
125     alias warn = append!(LogLevel.warn);
126     alias error = append!(LogLevel.error);
127     alias fatal = append!(LogLevel.fatal);
128 
129     private struct Fence {}  // argument cannot be provided explicitly
130 
131     template append(LogLevel level)
132     {
133         void append(alias fmt, Fence _ = Fence(), string file = __FILE__, size_t line = __LINE__, A...)
134             (lazy A args)
135         if (isSomeString!(typeof(fmt)))
136         {
137             static if (!level.disabled)
138             {
139                 if (level & levels)
140                 {
141                     A evaluatedArgs = args;
142 
143                     _append(level, file, line,
144                         (scope Sink sink) { sink.formattedWrite!fmt(evaluatedArgs); });
145                 }
146             }
147         }
148 
149         void append(Fence _ = Fence(), string file = __FILE__, size_t line = __LINE__, Char, A...)
150             (const Char[] fmt, lazy A args)
151         {
152 
153             static if (!level.disabled)
154             {
155                 if (level & levels)
156                 {
157                     A evaluatedArgs = args;
158 
159                     _append(level, file, line,
160                         (scope Sink sink) { sink.formattedWrite(fmt, evaluatedArgs); });
161                 }
162             }
163         }
164 
165         void append(Fence _ = Fence(), string file = __FILE__, size_t line = __LINE__, A)
166             (lazy A arg)
167         {
168 
169             static if (!level.disabled)
170             {
171                 if (level & levels)
172                 {
173                     A evaluatedArg = arg;
174 
175                     _append(level, file, line,
176                         (scope Sink sink) { sink.put(evaluatedArg.to!string); });
177                 }
178             }
179         }
180     }
181 
182     private void _append(LogLevel level, string file, size_t line,
183         scope void delegate(scope Sink sink) putMessage)
184     {
185         EventInfo eventInfo;
186 
187         eventInfo.time = Clock.currTime;
188         eventInfo.level = level;
189         eventInfo.file = file;
190         eventInfo.line = line;
191 
192         foreach (logger; loggers)
193             if (level & logger.levels)
194                 logger.append(eventInfo, putMessage);
195     }
196 }
197 
198 __gshared Log log;
199 
200 shared static this()
201 {
202     log = Log(stderrLogger(new Layout));
203 }
204 
205 /// Represents information about a logging event.
206 struct EventInfo
207 {
208     /// local _time of the event
209     SysTime time;
210     /// importance of the event
211     LogLevel level;
212     /// _file name of the event source
213     string file;
214     /// _line number of the event source
215     size_t line;
216 }
217 
218 auto fileLogger(Layout)
219     (Layout layout, string name, uint levels = LogLevel.info.orAbove)
220 in (layout !is null)
221 {
222     return new FileLogger!Layout(layout, name, levels);
223 }
224 
225 auto stderrLogger(Layout)
226     (Layout layout, uint levels = LogLevel.warn.orAbove)
227 in (layout !is null)
228 {
229     return new FileLogger!Layout(layout, stderr, levels);
230 }
231 
232 auto stdoutLogger(Layout)
233     (Layout layout, uint levels = LogLevel.info.orAbove)
234 in (layout !is null)
235 {
236     return new FileLogger!Layout(layout, stdout, levels);
237 }
238 
239 auto rollingFileLogger(Layout)
240     (Layout layout, string name, size_t count, size_t size, uint levels = LogLevel.info.orAbove)
241 in (layout !is null)
242 {
243     return new RollingFileLogger!Layout(layout, name ~ count.archiveFiles(name), size, levels);
244 }
245 
246 version (Posix)
247     auto rotatingFileLogger(Layout)
248         (Layout layout, string name, uint levels = LogLevel.info.orAbove)
249     in (layout !is null)
250     {
251         return new RotatingFileLogger!Layout(layout, name, levels);
252     }
253 
254 version (Posix)
255     auto syslogLogger(Layout = SyslogLayout)
256         (Layout layout, string name = null, uint levels = LogLevel.info.orAbove)
257     in (layout !is null)
258     {
259         return new SyslogLogger!Layout(layout, name, levels);
260     }
261 
262 /// Returns n file names based on path for archived files.
263 @safe
264 string[] archiveFiles(size_t n, string path)
265 {
266     import std.path : extension, stripExtension;
267     import std.range : iota;
268 
269     auto length = n.to!string.length;
270 
271     return n.iota
272         .map!(i => format!"%s-%0*s%s"(path.stripExtension, length, i + 1, path.extension))
273         .array;
274 }
275 
276 ///
277 unittest
278 {
279     assert(1.archiveFiles("dir/log.ext") == ["dir/log-1.ext"]);
280     assert(10.archiveFiles("log").startsWith("log-01"));
281     assert(10.archiveFiles("log").endsWith("log-10"));
282 }
283 
284 abstract class Logger
285 {
286     private uint levels;
287 
288     this(uint levels)
289     {
290         this.levels = levels;
291     }
292 
293     abstract void append(const ref EventInfo eventInfo,
294         scope void delegate(scope Sink sink) putMessage);
295 
296     // Exposed so that client code can write data to the log file directly in
297     // emergency situations, such as a crash.
298     // Returns null if the logger does not use a straightforward file descriptor.
299     // The effect of writing to the returned handle should be some form of
300     // readable logging.
301     Nullable!int fileDescriptor() const @nogc nothrow @safe
302     {
303         return Nullable!int();
304     }
305 }
306 
307 class FileLogger(Layout) : Logger
308 {
309     // must be static to be thread-local
310     private static Appender!(char[]) buffer;
311 
312     private File file;
313 
314     // store cause it's awkward to derive in fileDescriptor, which must be signal-safe
315     private int fileno;
316 
317     private Layout layout;
318 
319     this(Layout layout, string name, uint levels = LogLevel.info.orAbove)
320     in (layout !is null)
321     {
322         super(levels);
323         file = File(name, "ab");
324         fileno = file.fileno;
325         this.layout = layout;
326     }
327 
328     this(Layout layout, File file, uint levels = LogLevel.info.orAbove)
329     in (layout !is null)
330     {
331         super(levels);
332         this.file = file;
333         fileno = this.file.fileno;
334         this.layout = layout;
335     }
336 
337     override void append(const ref EventInfo eventInfo,
338         scope void delegate(scope Sink sink) putMessage)
339     {
340         import std.algorithm.mutation : swap;
341 
342         // avoid problems if toString functions call log - "borrow" static buffer
343         Appender!(char[]) buffer;
344 
345         buffer.swap(this.buffer);
346 
347         // put it back on exit, so the next call can use it
348         scope(exit)
349         {
350             buffer.clear;
351             buffer.swap(this.buffer);
352         }
353 
354         layout.write(buffer, eventInfo, putMessage);
355         file.lockingTextWriter.put(buffer.data);
356         file.flush;
357     }
358 
359     override Nullable!int fileDescriptor() const @nogc nothrow @safe
360     {
361         return Nullable!int(fileno);
362     }
363 }
364 
365 class RollingFileLogger(Layout) : FileLogger!Layout
366 {
367     private string[] names;
368 
369     private size_t size;
370 
371     this(Layout layout, const string[] names, size_t size, uint levels = LogLevel.info.orAbove)
372     in (layout !is null)
373     in(!names.empty)
374     {
375         super(layout, names.front, levels);
376         this.names = names.dup;
377         this.size = size;
378     }
379 
380     override void append(const ref EventInfo eventInfo,
381         scope void delegate(scope Sink sink) putMessage)
382     {
383         synchronized (this)
384         {
385             if (file.size >= size)
386                 roll;
387             super.append(eventInfo, putMessage);
388         }
389     }
390 
391     private void roll()
392     {
393         import std.file : exists, rename;
394 
395         foreach_reverse (i, destination; names[1 .. $])
396         {
397             const source = names[i];
398 
399             if (source.exists)
400                 rename(source, destination);
401         }
402         file.open(names.front, "wb");
403         fileno = file.fileno;
404     }
405 }
406 
407 version (Posix)
408 {
409     private shared uint _count = 0;
410 
411     private extern (C) void hangup(int sig) nothrow @nogc
412     {
413         import core.atomic : atomicOp;
414 
415        _count.atomicOp!"+="(1);
416     }
417 
418     class RotatingFileLogger(Layout) : FileLogger!Layout
419     {
420         private uint count = 0;
421 
422         this(Layout layout, string name, uint levels = LogLevel.info.orAbove)
423         {
424             super(layout, name, levels);
425             setUpSignalHandler;
426         }
427 
428         private void setUpSignalHandler()
429         {
430             import core.stdc.signal : signal, SIG_ERR;
431             import core.sys.posix.signal : SIGHUP;
432             import std.exception : enforce;
433 
434             enforce(signal(SIGHUP, &hangup) !is SIG_ERR);
435         }
436 
437         override void append(const ref EventInfo eventInfo,
438             scope void delegate(scope Sink sink) putMessage)
439         {
440             import core.atomic : atomicLoad;
441 
442             uint count = _count.atomicLoad;
443 
444             synchronized (this)
445             {
446                 if (this.count != count)
447                 {
448                     reopen;
449                     this.count = count;
450                 }
451                 super.append(eventInfo, putMessage);
452             }
453         }
454 
455         private void reopen()
456         {
457             if (!file.name.empty)
458             {
459                 file.close;
460                 file.open(file.name, "ab");
461                 fileno = file.fileno;
462             }
463         }
464     }
465 }
466 
467 version (Posix)
468 {
469     private extern (C) void openlog(const char *ident, int option, int facility);
470 
471     private extern (C) void syslog(int priority, const char *format, ...);
472 
473     class SyslogLogger(Layout) : Logger
474     {
475         enum SyslogLevel
476         {
477             LOG_EMERG   = 0,  // system is unusable
478             LOG_ALERT   = 1,  // action must be taken immediately
479             LOG_CRIT    = 2,  // critical conditions
480             LOG_ERR     = 3,  // error conditions
481             LOG_WARNING = 4,  // warning conditions
482             LOG_NOTICE  = 5,  // normal but significant condition
483             LOG_INFO    = 6,  // informational
484             LOG_DEBUG   = 7,  // debug-level messages
485         }
486 
487         private Layout layout;
488 
489         this(Layout layout, string identifier = null, uint levels = LogLevel.info.orAbove)
490         in (layout !is null)
491         {
492             enum LOG_USER = 1 << 3;
493 
494             super(levels);
495             this.layout = layout;
496             openlog(identifier.empty ? null : identifier.toStringz, 0, LOG_USER);
497         }
498 
499         override void append(const ref EventInfo eventInfo,
500             scope void delegate(scope Sink sink) putMessage)
501         {
502             auto writer = appender!string;
503 
504             layout.write(writer, eventInfo, putMessage);
505             writer.put('\0');
506             syslog(priority(eventInfo.level), "%s", writer.data.ptr);
507         }
508 
509         static SyslogLevel priority(LogLevel level) pure
510         {
511             final switch (level) with (LogLevel) with (SyslogLevel)
512             {
513                 case trace:
514                     return LOG_DEBUG;
515                 case info:
516                     return LOG_INFO;
517                 case warn:
518                     return LOG_WARNING;
519                 case error:
520                     return LOG_ERR;
521                 case fatal:
522                     return LOG_CRIT;
523             }
524         }
525     }
526 
527     final class SyslogLayout
528     {
529         public void write(Writer)(ref Writer writer, const ref EventInfo eventInfo,
530             scope void delegate(scope Sink sink) putMessage)
531         {
532             putMessage(outputRangeObject!(const(char)[])(writer));
533         }
534     }
535 }
536 
537 // Time Thread Category Context layout
538 final class Layout
539 {
540     void write(Writer)(ref Writer writer, const ref EventInfo eventInfo,
541         scope void delegate(scope Sink sink) putMessage)
542     {
543         import core.thread : Thread;
544 
545         with (eventInfo)
546         {
547             time._toISOExtString(writer);
548             writer.formattedWrite!" %-5s %s:%s"(level, file, line);
549 
550             if (Thread thread = Thread.getThis)
551             {
552                 string name = thread.name;
553 
554                 if (!name.empty)
555                     writer.formattedWrite!" [%s]"(name);
556             }
557 
558             writer.put(' ');
559             putMessage(outputRangeObject!(const(char)[])(writer));
560             writer.put('\n');
561         }
562     }
563 }
564 
565 unittest
566 {
567     EventInfo eventInfo;
568 
569     eventInfo.time = SysTime.fromISOExtString("2003-02-01T11:55:00.123456Z");
570     eventInfo.level = LogLevel.error;
571     eventInfo.file = "log.d";
572     eventInfo.line = 42;
573 
574     auto writer = appender!string;
575     auto layout = new Layout;
576 
577     layout.write(writer, eventInfo, (scope Sink sink) { sink.put("don't panic"); });
578     assert(writer.data == "2003-02-01T11:55:00.123+00:00 error log.d:42 don't panic\n");
579 }
580 
581 // SysTime.toISOExtString has no fixed length and no time-zone offset for local time
582 private void _toISOExtString(W)(SysTime time, ref W writer)
583 if (isOutputRange!(W, char))
584 {
585     (cast (DateTime) time).toISOExtString(writer);
586     writer.formattedWrite!".%03d"(time.fracSecs.total!"msecs");
587     time.utcOffset._toISOString(writer);
588 }
589 
590 unittest
591 {
592     auto dateTime = DateTime(2003, 2, 1, 12);
593     auto fracSecs = 123_456.usecs;
594     auto timeZone =  new immutable SimpleTimeZone(1.hours);
595     auto time = SysTime(dateTime, fracSecs, timeZone);
596     auto writer = appender!string;
597 
598     time._toISOExtString(writer);
599     assert(writer.data == "2003-02-01T12:00:00.123+01:00");
600 }
601 
602 // SimpleTimeZone.toISOString is private
603 @safe
604 private void _toISOString(W)(Duration offset, ref W writer)
605 if (isOutputRange!(W, char))
606 {
607     uint hours;
608     uint minutes;
609 
610     abs(offset).split!("hours", "minutes")(hours, minutes);
611     writer.formattedWrite!"%s%02d:%02d"(offset.isNegative ? '-' : '+', hours, minutes);
612 }
613 
614 unittest
615 {
616     auto writer = appender!string;
617 
618     90.minutes._toISOString(writer);
619     assert(writer.data == "+01:30");
620 }
621 
622 unittest
623 {
624     auto writer = appender!string;
625 
626     (-90).minutes._toISOString(writer);
627     assert(writer.data == "-01:30");
628 }