1 module glued.logging; 2 3 import std.conv: to, text; 4 import std.traits: EnumMembers; 5 import std.algorithm: maxElement, min, startsWith; 6 7 import optional; 8 import properd; 9 10 //todo this module could really use splitting down to package 11 12 enum ___Module___; 13 14 enum Level { 15 ANY, 16 DEVELOPMENT, 17 TRACE, 18 DEBUG, 19 INFO, 20 WARN, 21 ERROR, 22 NONE 23 } 24 25 Level toLevel(string s){ 26 foreach (v; EnumMembers!Level){ 27 if (v.to!string == s){ 28 return v; 29 } 30 } 31 throw new Exception("No level named "~s); 32 } 33 34 immutable maxLevelNameLength = (cast(Level[]) [ EnumMembers!Level ]).maxElement!"to!string(a).length".to!string.length; 35 36 string cutDown(string s, size_t len){ 37 return s[0..min(len, s.length)]; 38 } 39 40 string enforceLength(string s, int maxLength){ 41 if (s.length > 40){ 42 s = s.normalize; 43 } 44 if (s.length > 40){ 45 s = s.shorten; 46 } 47 if (s.length > 40){ 48 s = s.shortenLastSegmentTemplating; 49 } 50 if (s.length > 40){ 51 s = s.collapse(40); 52 } 53 if (s.length > 40){ 54 s = "..."~s[$-37..$]; 55 } 56 return s; 57 } 58 59 string format(LogEvent e){ 60 import std..string; 61 string lvl = to!string(e.level).center(maxLevelNameLength, ' '); 62 string path = e.loggerLocation.path; 63 //if log happens in same aggregate place as logger was declared, use event path 64 //if not, that means that logger was passed around to another piece of code 65 // in such case we should still show path of logger, since its the logger 66 // that is communicating to the reader of log 67 if (e.eventLocation.path.startsWith(path)) 68 path = e.eventLocation.path; 69 path = path.enforceLength(40); 70 //todo enforce filename length in similar fashion; probably wrap these functions into struct that takes separator as field 71 string filename = e.eventLocation.filename; 72 string tid; 73 return (filename~":"~to!string(e.eventLocation.line)).leftJustify(55)~" @ "~ 74 ( e.timestamp.empty ? 75 "N/A (compile-time)".center(25, ' ') : 76 e.timestamp.front().to!string.cutDown(25).leftJustify(25, ' ') 77 ) ~ " ( " ~ 78 ( e.tid.empty ? 79 "N/A".center(12, ' ') : 80 e.tid.front().to!string["Tid(".length..$-")".length].center(12, ' ') 81 ) ~ 82 " ) [ " ~ lvl ~ " ] " ~ 83 path.leftJustify(40, ' ')~" | "~ 84 to!string(e.message); 85 } 86 87 struct StaticSink { 88 import std.array; 89 import std.conv; 90 91 private static string getBuildLogConfig(string filename)(){ 92 static if (__traits(compiles, import(filename)) && !import(filename).empty){ 93 return import(filename); 94 } else { 95 version(silent_build) {} 96 else 97 { 98 pragma(msg, "Build log configuration ("~filename~") is missing or is empty!"); 99 } 100 return ""; 101 } 102 } 103 104 //todo this can be useful for runtime logging as well 105 //fixme there is similar class-based structure in utils (treepath) - it would be useful here if it would be a struct 106 private struct PackageLogEntry { 107 string fullModuleName; 108 PackageLogEntry[string] subModules; 109 Optional!Level explicitDefinition = no!Level; 110 111 void put(string modName, Level lvl){ 112 put(modName.split("."), lvl); 113 } 114 115 void put(string[] modName, Level lvl){ 116 if (modName.empty){ 117 explicitDefinition = lvl; 118 } else { 119 if (!(modName[0] in subModules)){ 120 string subName = (this.fullModuleName.empty ? "" : this.fullModuleName~".")~modName[0]; 121 subModules[modName[0]] = PackageLogEntry(subName); 122 } 123 subModules[modName[0]].put(modName[1..$], lvl); 124 } 125 } 126 127 Optional!Level get(string modName){ 128 return get(modName.split(".")); 129 } 130 131 Optional!Level get(string[] modName){ 132 if (modName.empty){ 133 return explicitDefinition; 134 } 135 auto deeperResult = modName[0] in subModules ? subModules[modName[0]].get(modName[1..$]) : no!Level; 136 if (deeperResult.empty){ 137 return explicitDefinition; 138 } 139 return deeperResult; 140 } 141 } 142 143 private static PackageLogEntry getBuildLogProperd(){ 144 PackageLogEntry[string] x; 145 PackageLogEntry root = PackageLogEntry("", x, no!Level); 146 void load(string filename)() 147 { 148 auto props = parseProperties(getBuildLogConfig!(filename)()); 149 150 foreach (k; props.keys()){ 151 auto name = k; 152 if (name.startsWith("log.level")) { 153 name = name["log.level".length..$]; 154 if (name.startsWith(".")) 155 name = name[1..$]; 156 root.put(name, props[k].toLevel); 157 } 158 } 159 } 160 //todo test this finally... 161 load!"buildLog.conf"(); 162 version(unittest) 163 { 164 load!"buildLog.test.conf"(); 165 } 166 167 if (root.explicitDefinition.empty) 168 { 169 version (silent_build) 170 { 171 root.explicitDefinition = Level.NONE.some; 172 } 173 else 174 { 175 root.explicitDefinition = Level.INFO.some; 176 } 177 } 178 return root; 179 } 180 181 private static string formatLogEvent(LogEvent e){ 182 //todo add format specified in build log config 183 return format(e); 184 } 185 186 static bool shouldShow(LogEvent e){ 187 //todo would checking eventLocation make more sense? maybe per-type filtering as well? 188 //we can safely call front() without worrying about empty optional, because root always have a default 189 return getBuildLogProperd().get(e.loggerLocation.moduleName).front() <= e.level; 190 } 191 192 static void consume(LogEvent e)(){ 193 static if (shouldShow(e)){ 194 pragma(msg, formatLogEvent(e)); 195 } 196 } 197 } 198 199 interface LogSink { 200 void consume(LogEvent e); 201 } 202 203 204 class DeferredLogSink: LogSink { 205 private LogEvent[] _deferred; 206 private LogSink _delegate = null; 207 208 void consume(LogEvent e){ 209 if (_delegate is null){ 210 _deferred ~= e; 211 } else { 212 _delegate.consume(e); 213 } 214 } 215 216 @property 217 bool resolved(){ 218 return _delegate !is null; 219 } 220 221 void resolve(LogSink sink){ 222 if (_delegate is null){ 223 _delegate = sink; 224 flushDeferred(); 225 } else { 226 assert(false); //todo exception 227 } 228 } 229 230 private void flushDeferred(){ 231 foreach (e; _deferred) 232 _delegate.consume(e); 233 _deferred = []; 234 } 235 } 236 237 ///Trivial sink, useful mostly for debugging, development and testing 238 class StdoutSink: LogSink { 239 import std.stdio; 240 241 override void consume(LogEvent e){ 242 //todo if dev.emit is used, be angry? I mean, that method shouldn't be used in the final commit 243 //todo this is a quickfix for log filtering; use this to implement bundles, then use bundles to load runtime config in... well, runtime 244 if (StaticSink.shouldShow(e)){ 245 stdout.writeln(format(e)); 246 stdout.flush(); 247 } 248 } 249 } 250 251 ///No-op sink, usually used as a default param value 252 class VoidSink: LogSink { 253 override void consume(LogEvent e){} 254 } 255 256 /** 257 * if p="a.b!(c.d).e", then segments = ["a", "b!(c", "d)", "e"] 258 * this foo turns that back to ["a", "b!(c.d)", "e"] 259 */ 260 string[] mergeBrokenSegments(string[] segs) { 261 bool isBalanced(string s){ 262 import std.algorithm: canFind, sum; 263 char[char] closingToOpen; 264 closingToOpen[')'] = '('; 265 closingToOpen[']'] = '['; 266 int[char] counts; 267 foreach (c; s){ 268 if (closingToOpen.values.canFind(c)){ 269 counts[c] += 1; 270 } else if (c in closingToOpen){ 271 counts[closingToOpen[c]] -= 1; 272 } 273 } 274 return counts.values.sum == 0; 275 } 276 string[] result; 277 int i; 278 while (i < segs.length){ 279 string current = segs[i]; 280 while (!isBalanced(current)){ 281 i += 1; 282 if (i < segs.length){ 283 current ~= "."~segs[i]; 284 } else { 285 if (!isBalanced(current)){ 286 throw new Exception("Segments: "~to!string(segs)~" cannot be merged; the whole path doesn't seem to be balanced!"); 287 } 288 } 289 } 290 i += 1; 291 result ~= current; 292 } 293 return result; 294 } 295 296 297 /** 298 * turn ["a", "b!(x)", "b"] (path "a.b!(x).b") into ["a, "b!(x)"] ("a.b!(x)") 299 * Assumes that input was already fixed with mergeBrokenSegments 300 */ 301 string[] normalizeSegments(string[] segs){ 302 import std.algorithm: startsWith; 303 string[] result; 304 int i; 305 while (i < segs.length-1){ 306 result ~= segs[i]; 307 if (segs[i].startsWith(segs[i+1]~"!")){ 308 i += 2; 309 } else { 310 i += 1; 311 } 312 } 313 //todo there is probably some smarter condition to be used here 314 if (result[$-1] != segs[$-1] && !result[$-1].startsWith(segs[$-1])) 315 result ~= segs[$-1]; 316 return result; 317 } 318 319 string normalize(string p){ 320 import std..string; 321 string[] segments= p.split("."); 322 323 string[] merged = mergeBrokenSegments(segments); 324 325 string[] normalized = normalizeSegments(merged); 326 return normalized.join("."); 327 } 328 329 //todo params fromRight/fromLeft and maxLength 330 string[] shortenSegments(string[] segs){ 331 import std..string; 332 import std.algorithm; 333 string shortenSegment(string seg){ 334 string result = seg[0..1]; 335 if (seg.canFind("!")){ 336 result ~= "!("; 337 string toAdd = seg.split("!")[1]; 338 while (toAdd.startsWith("!") || toAdd.startsWith("(")) 339 toAdd = toAdd[1..$]; 340 bool closeBrace = false; 341 if (toAdd.startsWith("[")){ 342 closeBrace = true; 343 result ~= "["; 344 toAdd = toAdd[1..$]; 345 while (toAdd.startsWith("!") || toAdd.startsWith("(")) 346 toAdd = toAdd[1..$]; 347 } 348 result ~= toAdd[0]; 349 if (closeBrace) 350 result ~= "...]"; 351 result ~= ")"; 352 } 353 return result; 354 } 355 string[] result; 356 foreach (s; segs[0..$-1]){ 357 result ~= shortenSegment(s); 358 } 359 result ~= segs[$-1]; 360 return result; 361 } 362 363 string shorten(string p){ 364 import std..string; 365 string[] segments= p.split("."); 366 367 string[] merged = mergeBrokenSegments(segments); 368 369 string[] shortened = shortenSegments(merged); 370 return shortened.join("."); 371 } 372 373 string shortenLastSegmentTemplating(string p){ 374 import std..string; 375 import std.algorithm; 376 string[] segments= p.split("."); 377 378 string[] merged = mergeBrokenSegments(segments); 379 string foo(string seg){ 380 string result = seg.split("!")[0]; 381 if (seg.canFind("!")){ 382 result ~= "!("; 383 string toAdd = seg.split("!")[1]; 384 while (toAdd.startsWith("!") || toAdd.startsWith("(")) 385 toAdd = toAdd[1..$]; 386 bool closeBrace = false; 387 if (toAdd.startsWith("[")){ 388 closeBrace = true; 389 result ~= "["; 390 toAdd = toAdd[1..$]; 391 while (toAdd.startsWith("!") || toAdd.startsWith("(")) 392 toAdd = toAdd[1..$]; 393 } 394 result ~= toAdd[0]; 395 if (closeBrace) 396 result ~= "...]"; 397 result ~= ")"; 398 } 399 return result; 400 } 401 string[] shortened = segments[0..$-1] ~ foo(segments[$-1]); 402 return shortened.join("."); 403 } 404 405 406 string collapse(string p, int maxLength){ 407 if (p.length <= maxLength){ 408 return p; 409 } 410 import std..string; 411 import std.stdio; 412 string[] segments= p.split("."); 413 414 string[] merged = mergeBrokenSegments(segments); 415 string[] pre; 416 string[] post; 417 immutable filler = "(...)"; 418 string result(){ 419 return (pre ~ (merged.empty ? [] : [filler]) ~ post).join("."); 420 } 421 bool fromRight = true; 422 while (!merged.empty){ 423 if (fromRight){ 424 post = [ merged[$-1] ]~post; 425 merged = merged[0..$-1]; 426 if (result().length > maxLength){ 427 merged ~= post[0]; 428 post = post[1..$]; 429 break; 430 } 431 fromRight = false; 432 } else { 433 pre ~= merged[0]; 434 merged = merged[1..$]; 435 if (result().length > maxLength){ 436 merged = pre[$-1] ~ merged; 437 pre = pre[0..$-1]; 438 break; 439 } 440 fromRight = true; 441 } 442 } 443 //if this couldn't produce a valid result, or the result was just (...), then 444 //just return original version and let the caller worry about it, we cannot 445 //collapse it any better 446 if (result().length > maxLength || (pre.empty && post.empty)) 447 return p; 448 return result(); 449 } 450 451 452 struct CodeLocation { 453 string filename; 454 int line; 455 string moduleName; 456 string aggregateName; 457 string functionName; 458 string prettyFunctionName; 459 460 @property 461 string path(){ 462 if (functionName.length) 463 return functionName; 464 if (aggregateName.length) 465 return aggregateName; 466 if (moduleName.length) 467 return moduleName; 468 assert(false); 469 } 470 } 471 472 struct LogEvent { 473 import optional: Optional; 474 import std.datetime: SysTime; 475 import std.concurrency: Tid; 476 477 Level level; 478 CodeLocation loggerLocation; 479 CodeLocation eventLocation; 480 string message; 481 482 Optional!SysTime timestamp; 483 Optional!Tid tid; 484 } 485 486 mixin template CreateLogger(string f=__FILE__, int l=__LINE__, string m=__MODULE__, string foo=__FUNCTION__, string prettyFoo=__PRETTY_FUNCTION__){ 487 static if (__traits(compiles, typeof(this))){ 488 alias Here = typeof(this); 489 } else { 490 alias Here = ___Module___; 491 } 492 493 struct Logger { 494 import std.traits: fullyQualifiedName; 495 import std.meta: staticMap; 496 import std.conv: to; 497 import std..string: join; 498 import std.algorithm: startsWith; 499 import std.array: split; 500 import std.datetime: Clock, SysTime; 501 import std.concurrency: thisTid, Tid; 502 import optional: Optional, no, some; 503 504 LogSink logSink; 505 506 this(LogSink logSink){ 507 this.logSink = logSink; 508 } 509 510 this(string f=__FILE__, int l=__LINE__, string m=__MODULE__, string foo=__FUNCTION__, string prettyFoo=__PRETTY_FUNCTION__)(){ 511 Warn!(f, l, m, foo, prettyFoo).Emit!("Creating logger with default sink! You're probably misconfigured!"); 512 this(new StdoutSink); 513 } 514 515 @property 516 static CodeLocation location(){ 517 static if (is(Here == ___Module___)){ 518 return CodeLocation(f, l, m, "", foo, prettyFoo); 519 } else { 520 return CodeLocation(f, l, m, fullyQualifiedName!Here, foo, prettyFoo); 521 } 522 } 523 524 static LogEvent event(Level level, string message, CodeLocation eventLocation, bool figureOutEventAggregate=true){ 525 if (figureOutEventAggregate) { //todo you removed config, it was there; what to do with this? 526 527 if (location.moduleName == eventLocation.moduleName && 528 location.aggregateName.length > 0 && eventLocation.functionName.length > 0 && 529 eventLocation.functionName.startsWith(location.aggregateName)){ 530 eventLocation.aggregateName = eventLocation.functionName.split(".")[0..$-1].join("."); 531 } 532 } 533 if (__ctfe){ 534 return LogEvent(level, location, eventLocation, message, no!SysTime, no!Tid); 535 } else { 536 return LogEvent(level, location, eventLocation, message, Clock.currTime().some, thisTid.some); 537 } 538 } 539 540 struct LogClosure(string f=__FILE__, int l=__LINE__, string m=__MODULE__, string foo=__FUNCTION__, string prettyFoo=__PRETTY_FUNCTION__) { 541 void Emit(Level level, T...)(){ 542 //todo figureOutEventAggregate was here 543 StaticSink.consume!(event(level, txt!T, CodeLocation(f, l, m, "", foo, prettyFoo)))(); 544 } 545 } 546 547 static auto Log(string f=__FILE__, int l=__LINE__, string m=__MODULE__, string foo=__FUNCTION__, string prettyFoo=__PRETTY_FUNCTION__)(){ 548 return LogClosure!(f, l, m, foo, prettyFoo)(); 549 } 550 551 //todo private 552 mixin template StaticLevelMixin(string method, string member){ 553 mixin("struct "~method~"Closure(string f=__FILE__, int l=__LINE__, string m=__MODULE__, string foo=__FUNCTION__, string prettyFoo=__PRETTY_FUNCTION__) { 554 void Emit(T...)(){ 555 Log!(f, l, m, foo, prettyFoo).Emit!(Level."~member~", T); 556 } 557 }"); 558 mixin("@property static auto "~method~"(string f=__FILE__, int l=__LINE__, string m=__MODULE__, string foo=__FUNCTION__, string prettyFoo=__PRETTY_FUNCTION__)(){ 559 return "~method~"Closure!(f, l, m, foo, prettyFoo)(); 560 }"); 561 } 562 563 564 struct logClosure(string f=__FILE__, int l=__LINE__, string m=__MODULE__, string foo=__FUNCTION__, string prettyFoo=__PRETTY_FUNCTION__) { 565 LogSink logSink; 566 567 void emit(T...)(Level level, T t){ 568 import std.conv; 569 //fixme figureOutEventAggregate was here 570 auto e = event(level, text!(T)(t), CodeLocation(f, l, m, "", foo, prettyFoo)); 571 logSink.consume(e); 572 } 573 } 574 575 @property 576 auto log(string f=__FILE__, int l=__LINE__, string m=__MODULE__, string foo=__FUNCTION__, string prettyFoo=__PRETTY_FUNCTION__)(){ 577 return logClosure!(f, l, m, foo, prettyFoo)(logSink); 578 } 579 580 //todo private 581 mixin template RuntimeLevelMixin(string method, string member){ 582 mixin("struct "~method~"Closure(string f=__FILE__, int l=__LINE__, string m=__MODULE__, string foo=__FUNCTION__, string prettyFoo=__PRETTY_FUNCTION__) { 583 Logger logger; 584 585 void emit(T...)(T t){ 586 logger.log!(f, l, m, foo, prettyFoo)().emit(Level."~member~", t); 587 } 588 }"); 589 mixin("@property 590 auto "~method~"(string f=__FILE__, int l=__LINE__, string m=__MODULE__, string foo=__FUNCTION__, string prettyFoo=__PRETTY_FUNCTION__)(){ 591 return "~method~"Closure!(f, l, m, foo, prettyFoo)(this); 592 }"); 593 } 594 595 mixin template LevelMixin(string staticMethod, string runtimeMethod, string member){ 596 mixin StaticLevelMixin!(staticMethod, member); 597 mixin RuntimeLevelMixin!(runtimeMethod, member); 598 } 599 600 601 private struct Triple { string s, r, m; } 602 603 static foreach (t; [ 604 Triple("Error", "error", "ERROR"), 605 Triple("Warn", "warn", "WARN"), 606 Triple("Info", "info", "INFO"), 607 Triple("Debug", "debug_", "DEBUG"), 608 Triple("Trace", "trace", "TRACE"), 609 Triple("Dev", "dev", "DEVELOPMENT") 610 ]){ 611 mixin LevelMixin!(t.s, t.r, t.m); 612 } 613 614 static string txt(T...)(){ 615 string asString(X...)(){ 616 static if (is(X)){ 617 return fullyQualifiedName!X; 618 } else static if (is(typeof(X))){ 619 return to!string(X); 620 } else { 621 static assert(false); //no support yet 622 } 623 } 624 string fold(int i, string acc)(){ 625 static if (i<T.length){ 626 return fold!(i+1, acc~asString!(T[i]))(); 627 } else { 628 return acc; 629 } 630 } 631 return fold!(0, "")(); 632 } 633 634 static string numberLines(string s, int l){ 635 import std..string: splitLines, leftJustify; 636 import std.conv: to; 637 638 string[] lines = s.splitLines(); 639 string result; 640 foreach (i, line; lines){ 641 result ~= to!string(l+i).leftJustify(4, ' ')~" |"~line~"\n"; //padding 642 } 643 return result; 644 } 645 646 static string indentLines(string s, string onLeft="\t"){ 647 import std..string: splitLines, leftJustify; 648 import std.conv: to; 649 650 string[] lines = s.splitLines(); 651 string result; 652 foreach (i, line; lines){ 653 result ~= onLeft~line~"\n"; 654 } 655 return result; 656 } 657 658 struct LoggedClosure(string f=__FILE__, int l=__LINE__, string m=__MODULE__, string foo=__FUNCTION__, string prettyFoo=__PRETTY_FUNCTION__) { 659 //todo prefix/suffix should be customizable when obtaining this closure 660 string value(string s)(){ 661 Debug!(f, l, m, foo, prettyFoo).Emit!("mixing in:\n"~indentLines(numberLines(s, l))~"--- END OF MIXIN ---")(); 662 return s; 663 } 664 } 665 666 @property 667 static auto logged(string f=__FILE__, int l=__LINE__, string m=__MODULE__, string foo=__FUNCTION__, string prettyFoo=__PRETTY_FUNCTION__)(){ 668 return LoggedClosure!(f, l, m, foo, prettyFoo)(); 669 } 670 } 671 } 672