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