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 std.stream;
18 import std.path;
19 import std.stdio;
20 import std.file;
21 import std.conv;
22 import std.datetime;
23 import std.traits;
24 
25 /**
26 *   Standard implementation of ILogger interface.
27 *
28 *   Example:
29 *   -----------
30 *   shared ILogger logger = new StrictLogger("my_awesome_log.log");
31 *   logger.minOutputLevel = LoggingLevel.Warning; // info msgs won't be printed in console 
32 *   logger.logInfo("Info message!");
33 *   logger.logError("Error message!");
34 *   logger.logDebug("Debug message!");
35 *
36 *   // received USR1 signal from logrotate
37 *   logger.reload;
38 *   -----------
39 */
40 synchronized class StrictLogger : ILogger
41 {
42     /// Option how to open logging file
43     enum Mode
44     {
45         /// Don't override, append to end
46         Append,
47         /// Override, start new file
48         Rewrite
49     }
50     
51   
52     /**
53     *   Log file name.
54     */
55     string name() const nothrow @property @safe
56     {
57         return mName;
58     }
59 
60     /**
61     *   Setting new log file name. If the $(B value)
62     *   differs from old one, logger should close
63     *   old one and open new file.
64     */
65     void name(string value) @property @trusted
66     {
67         if(mName == value) return;
68         
69         close();
70         mName = value;
71         initialize(mSavedMode);
72     }
73     
74     nothrow
75     { 
76         /**
77         *   Prints message into log. Displaying in the console
78         *   controlled by minOutputLevel property.
79         */
80         void log(lazy string message, LoggingLevel level) @trusted
81         {
82             scope(failure) {}
83 
84             if(level >= mMinOutputLevel)
85                 writeln(logsStyles[level]~message);
86 
87             try
88             {
89                 rawInput(formatString(message, level));
90             }
91             catch(Exception e)
92             {
93                 if(minOutputLevel != LoggingLevel.Muted)
94                     writeln(logsStyles[LoggingLevel.Warning], "Failed to write into log ", name);
95             }
96         }
97         
98         /**
99         *   Returns: minimum log level,  will be printed in the console.
100         */
101         LoggingLevel minOutputLevel() const @property @trusted
102         {
103             return mMinOutputLevel;
104         }
105 
106         /**
107         *   Setups minimum log level, 
108         */
109         void minOutputLevel(LoggingLevel level) @property @trusted
110         {
111             mMinOutputLevel = level;
112         }
113     }
114 
115     /**
116     *   Checks if the log file is exists at specified $(B location) and
117     *   if can't find it, recreates the file and continues write into it.
118     *
119     *   Useful for $(B logrotate) utility. GNU/Linux system checks file identity by
120     *   inode, that doesn't change while renaming. Thus after renaming the file at 
121     *   $(B location) log continues write into the renamed file. The call to the
122     *   $(B reload) method force splitting log into two parts.
123     */
124     void reload()
125     {
126         if(!name.exists)
127         {
128             initialize(mSavedMode);
129         }
130     }
131     
132     /**
133     *   Creates log at $(B dir)/$(B name). Tries to create parent directory
134     *   and all sub directories.
135     *
136     *   Note: Can throw if there is a problem with access permissions.
137     */ 
138     this(string name, Mode mode = Mode.Rewrite) @trusted
139     {
140         mName = name;
141         mSavedMode = mode;
142         initialize(mode);
143     }
144     
145     /**
146     *   Tries to create log file at $(B location).
147     */
148     protected void initialize(Mode mode = Mode.Rewrite) @trusted
149     {
150         auto dir = name.dirName;
151         try
152         {
153             if (!dir.exists)
154             {
155                 dir.mkdirRecurse;
156             }
157             mLogFiles[this] = new std.stream.File(name, mapMode(mode));
158         } 
159         catch(OpenException e)
160         {
161             throw new Exception(text("Failed to create log at '", name, "'. Details: ", e.msg));
162         }
163     }
164     
165     /// Transforms custom mode to file open mode
166     private static FileMode mapMode(Mode mode)
167     {
168         final switch(mode)
169         {
170             case(Mode.Append): return FileMode.Append;
171             case(Mode.Rewrite): return FileMode.OutNew;
172         }
173     } 
174     
175     protected this()
176     {
177         mName = "";
178         mMinOutputLevel = LoggingLevel.Notice;
179     }
180     
181     /**
182     *   Format message with default logging style (etc. time and level string).
183     */
184     string formatString(lazy string message, LoggingLevel level) @trusted
185     {
186         auto timeString = Clock.currTime.toISOExtString();
187         return text("[", timeString, "]:", logsStyles[level], message);
188     }
189     
190     /**
191     *   Unsafe write down the message without any meta information.
192     */
193     void rawInput(string message)  @trusted
194     {
195         mLogFiles[this].writeLine(message);
196     }
197     
198     /**
199     *   Used to manual shutdown protocols.
200     */
201     void finalize() @trusted
202     {
203         if(finalized) return;
204         
205         scope(failure) {}
206         scope(exit) finalized = true;
207         
208         close();
209     }
210     
211     ~this()
212     {
213         finalize();
214     }
215 
216     private
217     {
218         string mName;
219         __gshared std.stream.File[shared StrictLogger] mLogFiles;
220         shared LoggingLevel mMinOutputLevel;
221         bool finalized = false;
222         Mode mSavedMode;
223         
224         void close()
225         {
226             mLogFiles[this].close();
227         }
228     }
229 }
230 
231 /// Display styles
232 private immutable(string[LoggingLevel]) logsStyles;
233 
234 static this() 
235 {
236     logsStyles = [
237         LoggingLevel.Notice  :   "Notice: ",
238         LoggingLevel.Warning :   "Warning: ",
239         LoggingLevel.Debug   :   "Debug: ",
240         LoggingLevel.Fatal   :   "Error: ",
241         LoggingLevel.Muted   :   "",
242     ];
243 }
244 
245 version(unittest)
246 {
247     import std.concurrency;
248     
249     void testThread(shared ILogger logger, Tid owner, int i, uint n)
250     {
251         foreach(j; 1 .. n)
252         {
253             logger.logInfo(to!string(j));
254             logger.logError(to!string(j));
255         }
256         
257         send(owner, true);
258     }
259 }
260 unittest
261 {
262     import std.regex;
263     import std.path;
264     import std.file;
265     import std.stdio;
266 
267     write("Testing log system... ");
268     scope(success) writeln("Finished!");
269     scope(failure) writeln("Failed!");
270 
271     auto logger = new shared StrictLogger("TestLog");
272     logger.minOutputLevel = LoggingLevel.Muted;
273     logger.log("Notice msg!", LoggingLevel.Notice);
274     logger.log("Warning msg!", LoggingLevel.Warning);
275     logger.log("Debug msg!", LoggingLevel.Debug);
276     logger.log("Fatal msg!", LoggingLevel.Fatal);
277     logger.close();
278 
279     auto f = new std.stdio.File(logger.name, "r");
280     // Delete date string before cheking string
281     assert(replace(f.readln()[0..$-1], regex(r"[\[][\p{InBasicLatin}]*[\]][:]"), "") == logsStyles[LoggingLevel.Notice]~"Notice msg!", "Log notice testing fail!");
282     assert(replace(f.readln()[0..$-1], regex(r"[\[][\p{InBasicLatin}]*[\]][:]"), "") == logsStyles[LoggingLevel.Warning]~"Warning msg!", "Log warning testing fail!");
283     assert(replace(f.readln()[0..$-1], regex(r"[\[][\p{InBasicLatin}]*[\]][:]"), "") == logsStyles[LoggingLevel.Debug]~"Debug msg!", "Log debug testing fail!");
284     assert(replace(f.readln()[0..$-1], regex(r"[\[][\p{InBasicLatin}]*[\]][:]"), "") == logsStyles[LoggingLevel.Fatal]~"Fatal msg!", "Log fatal testing fail!");
285     f.close();
286 
287     immutable n = 10;
288     foreach(i; 1 .. n)
289     {
290         spawn(&testThread, logger, thisTid, i, n);
291     }
292     
293     auto t = TickDuration.currSystemTick + cast(TickDuration)dur!"seconds"(2);
294     auto ni = 0;
295     while(ni < n && t > TickDuration.currSystemTick) 
296     {
297         ni += 1;
298     }
299     assert(ni == n, "Concurrent logging test is failed!");
300     
301     remove(logger.name);
302 }