1 // This file is written in D programming language
2 /**
3 *   Default synchronized log realization. The logging process performs
4 *   instantly (if it can be processed properly). Logger puts message
5 *   style string and current timestamp before the message.
6 *
7 *   Tested to be able operate in daemon mode and under heavy concurrent
8 *   writing.
9 *
10 *   Copyright: © 2013-2014 Anton Gushcha
11 *   License: Subject to the terms of the MIT license, as written in the included LICENSE file.
12 *   Authors: NCrashed <ncrashed@gmail.com>
13 */
14 module dlogg.strict;
15 
16 public import dlogg.log;
17 import dlogg.style;
18 
19 import std.stream;
20 import std.path;
21 import std.stdio;
22 import std.file;
23 import std.conv;
24 import std.datetime;
25 import std.traits;
26 
27 version(ColoredOutput)
28 {
29     import colorize;
30     
31     version(Windows)
32     {
33         /**
34         *   Standard implementation of IStyledLogger interface.
35         *
36         *   Example:
37         *   -----------
38         *   shared ILogger logger = new StrictLogger("my_awesome_log.log");
39         *   logger.minOutputLevel = LoggingLevel.Warning; // info msgs won't be printed in console 
40         *   logger.logInfo("Info message!");
41         *   logger.logError("Error message!");
42         *   logger.logDebug("Debug message!");
43         *
44         *   // received USR1 signal from logrotate
45         *   logger.reload;
46         *   -----------
47         */
48         alias StrictLogger = StyledStrictLogger!(LoggingLevel
49                         , LoggingLevel.Debug,   "Debug:".color(fg.light_magenta) ~ " %1$s",   "[%2$s]: Debug: %1$s"
50                         , LoggingLevel.Notice,  "Notice:".color(fg.light_green) ~ " %1$s",  "[%2$s]: Notice: %1$s"
51                         , LoggingLevel.Warning, "Warning:".color(fg.light_yellow) ~ " %1$s", "[%2$s]: Warning: %1$s"
52                         , LoggingLevel.Fatal,   "Fatal:".color(fg.light_red) ~ " %1$s",   "[%2$s]: Fatal: %1$s"
53                         , LoggingLevel.Muted,   "",              ""
54                         );
55     } else
56     {
57         /**
58         *   Standard implementation of IStyledLogger interface.
59         *
60         *   Example:
61         *   -----------
62         *   shared ILogger logger = new StrictLogger("my_awesome_log.log");
63         *   logger.minOutputLevel = LoggingLevel.Warning; // info msgs won't be printed in console 
64         *   logger.logInfo("Info message!");
65         *   logger.logError("Error message!");
66         *   logger.logDebug("Debug message!");
67         *
68         *   // received USR1 signal from logrotate
69         *   logger.reload;
70         *   -----------
71         */
72         alias StrictLogger = StyledStrictLogger!(LoggingLevel
73                         , LoggingLevel.Debug,   "Debug:".color(fg.magenta) ~ " %1$s",   "[%2$s]: Debug: %1$s"
74                         , LoggingLevel.Notice,  "Notice:".color(fg.green) ~ " %1$s",  "[%2$s]: Notice: %1$s"
75                         , LoggingLevel.Warning, "Warning:".color(fg.light_yellow) ~ " %1$s", "[%2$s]: Warning: %1$s"
76                         , LoggingLevel.Fatal,   "Fatal:".color(fg.light_red) ~ " %1$s",   "[%2$s]: Fatal: %1$s"
77                         , LoggingLevel.Muted,   "",              ""
78                         );
79     
80     }
81 } else
82 {
83     /**
84     *   Standard implementation of IStyledLogger interface.
85     *
86     *   Example:
87     *   -----------
88     *   shared ILogger logger = new StrictLogger("my_awesome_log.log");
89     *   logger.minOutputLevel = LoggingLevel.Warning; // info msgs won't be printed in console 
90     *   logger.logInfo("Info message!");
91     *   logger.logError("Error message!");
92     *   logger.logDebug("Debug message!");
93     *
94     *   // received USR1 signal from logrotate
95     *   logger.reload;
96     *   -----------
97     */
98     alias StrictLogger = StyledStrictLogger!(LoggingLevel
99                     , LoggingLevel.Debug,   "Debug: %1$s",   "[%2$s]: Debug: %1$s"
100                     , LoggingLevel.Notice,  "Notice: %1$s",  "[%2$s]: Notice: %1$s"
101                     , LoggingLevel.Warning, "Warning: %1$s", "[%2$s]: Warning: %1$s"
102                     , LoggingLevel.Fatal,   "Fatal: %1$s",   "[%2$s]: Fatal: %1$s"
103                     , LoggingLevel.Muted,   "",              ""
104                     );
105 }
106 /**
107 *   Implementation of $(B IStyledLogger) with custom style. Usually you want to use
108 *   $(B StrictLogger) alias, but there are cases where you want custom styles.
109 *
110 *   Example of custom styled logger:
111 *   --------------------------------
112 *   enum MyLevel
113 *   {
114 *       Error,
115 *       Debug
116 *   }
117 *   
118 *   alias MyLogger = StyledStrictLogger!(MyLevel
119 *               , MyLevel.Debug,   "Debug: %1$s",   "[%2$s] Debug: %1$s"
120 *               , MyLevel.Error,   "Fatal: %1$s",   "[%2$s] Fatal: %1$s");
121 *   --------------------------------
122 *
123 *   See_Also: dlogg.style
124 */
125 synchronized class StyledStrictLogger(StyleEnum, US...) : IStyledLogger!StyleEnum
126 {
127     mixin generateStyle!(StyleEnum, US);
128     alias thistype = StyledStrictLogger!(StyleEnum, US);
129     
130     /// Option how to open logging file
131     enum Mode
132     {
133         /// Don't override, append to end
134         Append,
135         /// Override, start new file
136         Rewrite
137     }
138     
139     /**
140     *   Log file name.
141     */
142     string name() const nothrow @property @safe
143     {
144         return mName;
145     }
146 
147     /**
148     *   Setting new log file name. If the $(B value)
149     *   differs from old one, logger should close
150     *   old one and open new file.
151     */
152     void name(string value) @property @trusted
153     {
154         if(mName == value) return;
155         
156         close();
157         mName = value;
158         initialize(mSavedMode);
159     }
160     
161     nothrow
162     { 
163         /**
164         *   Prints message into log. Displaying in the console
165         *   controlled by minOutputLevel property.
166         */
167         void log(lazy string message, StyleEnum level) @trusted
168         {
169             //scope(failure) {}
170             try
171             {
172 	            if(level >= mMinOutputLevel)
173 	            {
174 	                string msg = formatConsoleOutput(message, level);
175 	                version(ColoredOutput) cwriteln(msg);
176 	                else writeln(msg);
177 	            }
178 	            
179 	            if(level >= mMinLoggingLevel)
180 	            {
181 	                try
182 	                {
183 	                    rawInput(formatFileOutput(message, level));
184 	                }
185 	                catch(Exception e)
186 	                {
187 	                    if(minOutputLevel != LoggingLevel.Muted)
188 	                        writeln("Failed to write into log ", name);
189 	                }
190 	            }
191             } catch(Throwable th)
192             {
193             	
194             }
195         }
196         
197         /**
198         *   Returns: minimum log level,  will be printed in the console.
199         */
200         StyleEnum minOutputLevel() const @property @trusted
201         {
202             return mMinOutputLevel;
203         }
204 
205         /**
206         *   Setups minimum log level, 
207         */
208         void minOutputLevel(StyleEnum level) @property @trusted
209         {
210             mMinOutputLevel = level;
211         }
212         
213         /**
214         *   Setups minimum message level that goes to file.
215         */
216         StyleEnum minLoggingLevel() @property
217         {
218             return mMinLoggingLevel;
219         }
220         
221         /**
222         *   Setups minimum message level that goes to file.
223         */
224         void minLoggingLevel(StyleEnum level) @property
225         {
226             mMinLoggingLevel = level;
227         }
228     }
229 
230     /**
231     *   Checks if the log file is exists at specified $(B location) and
232     *   if can't find it, recreates the file and continues write into it.
233     *
234     *   Useful for $(B logrotate) utility. GNU/Linux system checks file identity by
235     *   inode, that doesn't change while renaming. Thus after renaming the file at 
236     *   $(B location) log continues write into the renamed file. The call to the
237     *   $(B reload) method force splitting log into two parts.
238     */
239     void reload()
240     {
241         if(!name.exists)
242         {
243             initialize(mSavedMode);
244         }
245     }
246     
247     /**
248     *   Creates log at $(B dir)/$(B name). Tries to create parent directory
249     *   and all sub directories.
250     *
251     *   Note: Can throw if there is a problem with access permissions.
252     */ 
253     this(string name, Mode mode = Mode.Rewrite) @trusted
254     {
255         mName = name;
256         mSavedMode = mode;
257         initialize(mode);
258     }
259     
260     /**
261     *   Tries to create log file at $(B location).
262     */
263     protected void initialize(Mode mode = Mode.Rewrite) @trusted
264     {
265         auto dir = name.dirName;
266         try
267         {
268             if (!dir.exists)
269             {
270                 dir.mkdirRecurse;
271             }
272             mLogFiles[this] = new std.stream.File(name, mapMode(mode));
273         } 
274         catch(OpenException e)
275         {
276             throw new Exception(text("Failed to create log at '", name, "'. Details: ", e.msg));
277         }
278     }
279     
280     /// Transforms custom mode to file open mode
281     private static FileMode mapMode(Mode mode)
282     {
283         final switch(mode)
284         {
285             case(Mode.Append): return FileMode.Append;
286             case(Mode.Rewrite): return FileMode.OutNew;
287         }
288     } 
289     
290     protected this()
291     {
292         mName = "";
293         mMinOutputLevel = StyleEnum.min;
294         mMinLoggingLevel = StyleEnum.min;
295     }
296     
297     /**
298     *   Unsafe write down the message without any meta information.
299     */
300     void rawInput(string message)  @trusted
301     {
302         if(this in mLogFiles)
303             mLogFiles[this].writeLine(message);
304     }
305     
306     /**
307     *   Used to manual shutdown protocols.
308     */
309     void finalize() @trusted
310     {
311         if(finalized) return;
312         
313         //scope(failure) {}
314         scope(exit) finalized = true;
315         
316         try close();
317         catch(Throwable th) {}
318     }
319     
320     ~this()
321     {
322         finalize();
323     }
324 
325     private
326     {
327         string mName;
328         __gshared std.stream.File[shared thistype] mLogFiles;
329         StyleEnum mMinOutputLevel;
330         StyleEnum mMinLoggingLevel;
331         bool finalized = false;
332         Mode mSavedMode;
333         
334         void close()
335         {
336             if(this in mLogFiles)
337             {
338                 mLogFiles[this].close();
339                 mLogFiles.remove(this);
340             }
341         }
342     }
343 }
344 
345 version(unittest)
346 {
347     import std.concurrency;
348     
349     void testThread(shared ILogger logger, Tid owner, int i, uint n)
350     {
351         foreach(j; 1 .. n)
352         {
353             logger.logInfo(to!string(j));
354             logger.logError(to!string(j));
355         }
356         
357         send(owner, true);
358     }
359 }
360 unittest
361 {
362     import std.regex;
363     import std.path;
364     import std.file;
365     import std.stdio;
366 
367     auto logger = new shared StrictLogger("TestLog");
368     logger.minOutputLevel = LoggingLevel.Notice;
369     logger.log("Notice msg!", LoggingLevel.Notice);
370     logger.log("Warning msg!", LoggingLevel.Warning);
371     logger.log("Debug msg!", LoggingLevel.Debug);
372     logger.log("Fatal msg!", LoggingLevel.Fatal);
373     logger.finalize();
374 
375     auto f = new std.stdio.File(logger.name, "r");
376     assert(replace(f.readln()[0..$-1], regex(r"[\[][\p{InBasicLatin}]*[\]][:]"), "") == logger.formatConsoleOutput("Notice msg!",  LoggingLevel.Notice),  "Log notice testing fail!");
377     assert(replace(f.readln()[0..$-1], regex(r"[\[][\p{InBasicLatin}]*[\]][:]"), "") == logger.formatConsoleOutput("Warning msg!", LoggingLevel.Warning), "Log warning testing fail!");
378     assert(replace(f.readln()[0..$-1], regex(r"[\[][\p{InBasicLatin}]*[\]][:]"), "") == logger.formatConsoleOutput("Debug msg!",   LoggingLevel.Debug),   "Log debug testing fail!");
379     assert(replace(f.readln()[0..$-1], regex(r"[\[][\p{InBasicLatin}]*[\]][:]"), "") == logger.formatConsoleOutput("Fatal msg!",   LoggingLevel.Fatal),   "Log fatal testing fail!");
380     f.close;
381 
382     logger = new shared StrictLogger("TestLog");
383     scope(exit) logger.close();
384     logger.minOutputLevel = LoggingLevel.Muted;
385     
386     immutable n = 10;
387     foreach(i; 1 .. n)
388     {
389         spawn(&testThread, logger, thisTid, i, n);
390     }
391     
392     auto t = TickDuration.currSystemTick + cast(TickDuration)dur!"seconds"(2);
393     auto ni = 0;
394     while(ni < n && t > TickDuration.currSystemTick) 
395     {
396         ni += 1;
397     }
398     assert(ni == n, "Concurrent logging test is failed!");
399     
400     // Testing overloading
401     logger.logInfo("some string");
402     logger.logInfo("first string", "second string");
403     logger.logWarning("some string");
404     logger.logWarning("first string", "second string");
405     logger.logError("some string");
406     logger.logError("first string", "second string");
407     
408     logger.close();
409     remove(logger.name);
410 }