1 /++ 2 Implementation of Printer plugin functionality that concerns logging. 3 For internal use. 4 5 The [dialect.defs.IRCEvent|IRCEvent]-annotated handlers must be in the same module 6 as the [kameloso.plugins.admin.base.AdminPlugin|AdminPlugin], but these implementation 7 functions can be offloaded here to limit module size a bit. 8 9 See_Also: 10 [kameloso.plugins.printer.base], 11 [kameloso.plugins.printer.formatting] 12 13 Copyright: [JR](https://github.com/zorael) 14 License: [Boost Software License 1.0](https://www.boost.org/users/license.html) 15 16 Authors: 17 [JR](https://github.com/zorael) 18 +/ 19 module kameloso.plugins.printer.logging; 20 21 version(WithPrinterPlugin): 22 23 private: 24 25 import kameloso.plugins.printer.base; 26 27 import kameloso.common : logger; 28 import dialect.defs; 29 import std.typecons : Flag, No, Yes; 30 31 32 package: 33 34 35 // LogLineBuffer 36 /++ 37 A struct containing lines to write to a log file when next committing such. 38 39 This is only relevant if 40 [kameloso.plugins.printer.base.PrinterSettings.bufferedWrites|PrinterSettings.bufferedWrites] 41 is set. 42 43 As a micro-optimisation an [std.array.Appender|Appender] is used to store the lines, 44 instead of a normal `string[]`. 45 +/ 46 struct LogLineBuffer 47 { 48 private: 49 import std.array : Appender; 50 import std.datetime.systime : SysTime; 51 52 public: 53 /// Basename directory this buffer will be saved to. 54 string dir; 55 56 /// Fully qualified filename this buffer will be saved to. 57 string file; 58 59 /// Buffered lines that will be saved to [file], in [dir]. 60 Appender!(string[]) lines; 61 62 /++ 63 Constructor taking a [std.datetime.systime.SysTime|SysTime], to save as the date 64 the buffer was created. 65 +/ 66 this(const string dir, const SysTime now) 67 { 68 import std.datetime.date : Date; 69 import std.path : buildNormalizedPath; 70 71 static string yyyyMMOf(const SysTime date) 72 { 73 // Cut the day from the date string, keep YYYY-MM 74 return (cast(Date)date).toISOExtString[0..7]; 75 } 76 77 this.dir = dir; 78 this.file = buildNormalizedPath(this.dir, yyyyMMOf(now) ~ ".log"); 79 } 80 81 /++ 82 Constructor not taking a [std.datetime.systime.SysTime|SysTime], for use with 83 buffers that should not be dated, such as the error log and the raw log. 84 +/ 85 this(const string dir, const string filename) 86 { 87 import std.path : buildNormalizedPath; 88 89 this.dir = dir; 90 this.file = buildNormalizedPath(this.dir, filename); 91 } 92 } 93 94 95 // onLoggableEventImpl 96 /++ 97 Logs an event to disk. 98 99 It is set to [kameloso.plugins.common.core.ChannelPolicy.any|ChannelPolicy.any], 100 and configuration dictates whether or not non-home events should be logged. 101 Likewise whether or not raw events should be logged. 102 103 Lines will either be saved immediately to disk, opening a [std.stdio.File|File] 104 with appending privileges for each event as they occur, or buffered by 105 populating arrays of lines to be written in bulk, once in a while. 106 107 See_Also: 108 [commitAllLogsImpl] 109 +/ 110 void onLoggableEventImpl(PrinterPlugin plugin, const ref IRCEvent event) 111 { 112 import kameloso.plugins.printer.formatting : formatMessageMonochrome; 113 import std.typecons : Flag, No, Yes; 114 115 if (!plugin.printerSettings.logs) return; 116 117 /// Write buffered lines. 118 static void writeEventToFile( 119 PrinterPlugin plugin, 120 const ref IRCEvent event, 121 const string key, 122 const string givenPath = string.init, 123 const Flag!"extendPath" extendPath = Yes.extendPath, 124 const Flag!"raw" raw = No.raw, 125 const Flag!"errors" errors = No.errors) 126 { 127 import std.exception : ErrnoException; 128 import std.file : FileException; 129 130 immutable path = givenPath.length ? givenPath.escapedPath : key.escapedPath; 131 132 try 133 { 134 /// Write datestamp to file immediately, bypassing any buffers. 135 static void insertDatestamp(const LogLineBuffer* buffer) 136 { 137 assert(buffer, "Tried to add datestamp to null buffer"); 138 assert((buffer.file.length && buffer.dir.length), 139 "Tried to add datestamp to uninitialised buffer"); 140 141 import std.file : exists, isDir, mkdirRecurse; 142 import std.stdio : File; 143 144 if (!buffer.dir.exists) 145 { 146 mkdirRecurse(buffer.dir); 147 } 148 else if (!buffer.dir.isDir) 149 { 150 // Something is in the way of the log's directory 151 return; 152 } 153 154 // Insert an empty space if the file exists, to separate old content from new 155 // Cache .exists, because opening the file creates it 156 // (and thus a non-existing file would still get the spacing writeln) 157 immutable fileExists = buffer.file.exists; 158 File file = File(buffer.file, "a"); 159 if (fileExists) file.writeln(); 160 file.writeln(datestamp); 161 //file.flush(); 162 } 163 164 if (!errors) 165 { 166 LogLineBuffer* buffer = key in plugin.buffers; 167 168 if (!buffer) 169 { 170 if (extendPath) 171 { 172 import std.datetime.systime : Clock; 173 import std.path : buildNormalizedPath; 174 175 immutable subdir = buildNormalizedPath(plugin.logDirectory, path); 176 plugin.buffers[key] = LogLineBuffer(subdir, Clock.currTime); 177 } 178 else 179 { 180 plugin.buffers[key] = LogLineBuffer(plugin.logDirectory, path); 181 } 182 183 buffer = key in plugin.buffers; 184 if (!raw) insertDatestamp(buffer); // New buffer, new "day", except if raw 185 } 186 187 if (!raw) 188 { 189 // Normal buffers 190 if (plugin.printerSettings.bufferedWrites) 191 { 192 // Normal log 193 formatMessageMonochrome( 194 plugin, 195 plugin.linebuffer, 196 event, 197 No.bellOnMention, 198 No.bellOnError); 199 buffer.lines ~= plugin.linebuffer.data.idup; 200 plugin.linebuffer.clear(); 201 } 202 else 203 { 204 import std.file : exists, isDir, mkdirRecurse; 205 import std.stdio : File; 206 207 if (!buffer.dir.exists) 208 { 209 mkdirRecurse(buffer.dir); 210 } 211 else if (!buffer.dir.isDir) 212 { 213 // Something is in the way of the log's directory 214 return; 215 } 216 217 formatMessageMonochrome( 218 plugin, 219 plugin.linebuffer, 220 event, 221 No.bellOnMention, 222 No.bellOnError); 223 scope(exit) plugin.linebuffer.clear(); 224 225 auto file = File(buffer.file, "a"); 226 file.writeln(plugin.linebuffer); 227 } 228 } 229 else 230 { 231 // Raw log 232 if (plugin.printerSettings.bufferedWrites) 233 { 234 buffer.lines ~= event.raw; 235 } 236 else 237 { 238 import std.stdio : File; 239 240 auto file = File(buffer.file, "a"); 241 file.writeln(event.raw); 242 //file.flush(); 243 } 244 } 245 } 246 else 247 { 248 LogLineBuffer* errBuffer = key in plugin.buffers; 249 250 if (!errBuffer) 251 { 252 plugin.buffers[key] = LogLineBuffer(plugin.logDirectory, givenPath); 253 errBuffer = key in plugin.buffers; 254 insertDatestamp(errBuffer); // New buffer, new "day" 255 } 256 257 if (plugin.printerSettings.bufferedWrites) 258 { 259 version(IncludeHeavyStuff) 260 { 261 import kameloso.printing : formatObjects; 262 263 errBuffer.lines ~= formatObjects!(Yes.all, No.coloured) 264 (No.brightTerminal, event); 265 266 if (event.sender.nickname.length || event.sender.address.length) 267 { 268 errBuffer.lines ~= formatObjects!(Yes.all, No.coloured) 269 (No.brightTerminal, event.sender); 270 } 271 272 if (event.target.nickname.length || event.target.address.length) 273 { 274 errBuffer.lines ~= formatObjects!(Yes.all, No.coloured) 275 (No.brightTerminal, event.target); 276 } 277 } 278 else 279 { 280 import lu.conv : Enum; 281 import std.conv : text; 282 283 errBuffer.lines ~= text('@', event.tags, ' ', event.raw); 284 285 if (event.sender.nickname.length || event.sender.address.length) 286 { 287 errBuffer.lines ~= text( 288 event.sender.nickname, '!', 289 event.sender.ident, '@', 290 event.sender.address, ':', 291 event.sender.account, " -- ", 292 Enum!(IRCUser.Class).toString(event.sender.class_), "\n\n"); 293 } 294 295 if (event.target.nickname.length || event.target.address.length) 296 { 297 errBuffer.lines ~= text( 298 event.target.nickname, '!', 299 event.target.ident, '@', 300 event.target.address, ':', 301 event.target.account, " -- ", 302 Enum!(IRCUser.Class).toString(event.target.class_), "\n\n"); 303 } 304 } 305 306 errBuffer.lines ~= "/////////////////////////////////////" ~ 307 "///////////////////////////////////////////\n"; // 80c 308 } 309 else 310 { 311 import std.stdio : File; 312 313 auto errFile = File(errBuffer.file, "a"); 314 315 // This is an abuse of plugin.linebuffer and is pretty much 316 // guaranteed to grow it, but what do? 317 318 version(IncludeHeavyStuff) 319 { 320 import kameloso.printing : formatObjects; 321 322 formatObjects!(Yes.all, No.coloured) 323 (plugin.linebuffer, 324 No.brightTerminal, 325 event); 326 errFile.writeln(plugin.linebuffer.data); 327 plugin.linebuffer.clear(); 328 329 if (event.sender.nickname.length || event.sender.address.length) 330 { 331 formatObjects!(Yes.all, No.coloured) 332 (plugin.linebuffer, 333 No.brightTerminal, 334 event.sender); 335 errFile.writeln(plugin.linebuffer.data); 336 plugin.linebuffer.clear(); 337 } 338 339 if (event.target.nickname.length || event.target.address.length) 340 { 341 formatObjects!(Yes.all, No.coloured) 342 (plugin.linebuffer, 343 No.brightTerminal, 344 event.target); 345 errFile.writeln(plugin.linebuffer.data); 346 plugin.linebuffer.clear(); 347 } 348 } 349 else 350 { 351 import lu.conv : Enum; 352 import std.conv : text; 353 354 errFile.writeln('@', event.tags, ' ', event.raw); 355 356 if (event.sender.nickname.length || event.sender.address.length) 357 { 358 errFile.writeln( 359 event.sender.nickname, '!', 360 event.sender.ident, '@', 361 event.sender.address, ':', 362 event.sender.account, " -- ", 363 Enum!(IRCUser.Class).toString(event.sender.class_), "\n\n"); 364 } 365 366 if (event.target.nickname.length || event.target.address.length) 367 { 368 errFile.writeln( 369 event.target.nickname, '!', 370 event.target.ident, '@', 371 event.target.address, ':', 372 event.target.account, " -- ", 373 Enum!(IRCUser.Class).toString(event.target.class_), "\n\n"); 374 } 375 } 376 377 errFile.writeln("/////////////////////////////////////" ~ 378 "///////////////////////////////////////////\n"); // 80c 379 //errFile.flush(); 380 } 381 } 382 } 383 catch (FileException e) 384 { 385 enum pattern = "File exception caught when writing to log: <t>%s"; 386 logger.warningf(pattern, e.msg); 387 version(PrintStacktraces) logger.trace(e.info); 388 } 389 catch (ErrnoException e) 390 { 391 version(Posix) 392 { 393 import kameloso.common : errnoStrings; 394 import core.stdc.errno : errno; 395 396 enum pattern = "ErrnoException (<l>%s</>) caught when writing to log: <t>%s"; 397 logger.warningf(pattern, errnoStrings[errno], e.msg); 398 } 399 else version(Windows) 400 { 401 import core.stdc.errno : errno; 402 403 enum pattern = "ErrnoException (<l>%d</>) caught when writing to log: <t>%s"; 404 logger.warningf(pattern, errno, e.msg); 405 } 406 else 407 { 408 static assert(0, "Unsupported platform, please file a bug."); 409 } 410 411 version(PrintStacktraces) logger.trace(e.info); 412 } 413 catch (Exception e) 414 { 415 enum pattern = "Unhandles exception caught when writing to log: <t>%s"; 416 logger.warningf(pattern, e.msg); 417 version(PrintStacktraces) logger.trace(e); 418 } 419 } 420 421 // Write raw (if we should) before exiting early due to not a home (if we should) 422 if (plugin.printerSettings.logRaw) 423 { 424 writeEventToFile( 425 plugin, 426 event, 427 "<raw>", 428 "raw.log", 429 No.extendPath, 430 Yes.raw); 431 } 432 433 if (event.errors.length && plugin.printerSettings.logErrors) 434 { 435 // This logs errors in guest channels. Consider making configurable. 436 writeEventToFile( 437 plugin, 438 event, 439 "<error>", 440 "error.log", 441 No.extendPath, 442 No.raw, 443 Yes.errors); 444 } 445 446 import std.algorithm.searching : canFind; 447 448 if (!plugin.printerSettings.logGuestChannels && 449 event.channel.length && 450 !plugin.state.bot.homeChannels.canFind(event.channel)) 451 { 452 // Not logging all channels and this is not a home. 453 return; 454 } 455 456 with (IRCEvent.Type) 457 switch (event.type) 458 { 459 case PING: 460 case SELFMODE: 461 // Not of formatted loggable interest (raw will have been logged above) 462 return; 463 464 case QUIT: 465 case NICK: 466 case ACCOUNT: 467 case AWAY: 468 case BACK: 469 case CHGHOST: 470 // These don't carry a channel; instead have them be logged in all 471 // channels this user is in (that the bot is also in) 472 foreach (immutable channelName, const foreachChannel; plugin.state.channels) 473 { 474 if (!plugin.printerSettings.logGuestChannels && 475 !plugin.state.bot.homeChannels.canFind(channelName)) 476 { 477 // Not logging all channels and this is not a home. 478 continue; 479 } 480 481 if (event.sender.nickname in foreachChannel.users) 482 { 483 // Channel message 484 writeEventToFile(plugin, event, channelName); 485 } 486 } 487 488 if (event.sender.nickname.length && event.sender.nickname in plugin.buffers) 489 { 490 // There is an open query buffer; write to it too 491 writeEventToFile(plugin, event, event.sender.nickname); 492 } 493 break; 494 495 version(TwitchSupport) 496 { 497 case JOIN: 498 case PART: 499 if (plugin.state.server.daemon == IRCServer.Daemon.twitch) 500 { 501 // These Twitch events are just noise. 502 return; 503 } 504 else 505 { 506 goto default; 507 } 508 509 case USERSTATE: 510 case GLOBALUSERSTATE: 511 // Always on Twitch, no need to check plugin.state.server.daemon 512 return; 513 } 514 515 default: 516 if (event.channel.length && (event.sender.nickname.length || (event.type == MODE))) 517 { 518 // Channel message, or specialcased server-sent MODEs 519 writeEventToFile(plugin, event, event.channel); 520 } 521 else if (event.sender.nickname.length) 522 { 523 // Not a channel; query or other server-wide message 524 if (plugin.printerSettings.logPrivateMessages) 525 { 526 writeEventToFile(plugin, event, event.sender.nickname); 527 } 528 } 529 else if (plugin.printerSettings.logServer && 530 !event.sender.nickname.length && 531 event.sender.address.length) 532 { 533 // Server 534 writeEventToFile( 535 plugin, 536 event, 537 plugin.state.server.address, 538 "server.log", 539 No.extendPath); 540 } 541 else 542 { 543 // logServer is probably false and event shouldn't be logged 544 // OR we don't know how to deal with this event type 545 /*import kameloso.printing : printObject; 546 printObject(event);*/ 547 return; 548 } 549 break; 550 } 551 } 552 553 554 // establishLogLocation 555 /++ 556 Verifies that a log directory exists, complaining if it's invalid, creating 557 it if it doesn't exist. 558 559 Example: 560 --- 561 assert(!("~/logs".isDir)); 562 bool locationIsOkay = establishLogLocation(plugin, "~/logs"); 563 assert("~/logs".isDir); 564 --- 565 566 Params: 567 logLocation = String of the location directory we want to store logs in. 568 connectionID = ID of the current connection, so as not to spam error messages. 569 570 Returns: 571 A bool whether or not the log location is valid. 572 +/ 573 auto establishLogLocation(const string logLocation, const uint connectionID) 574 { 575 import std.file : exists, isDir; 576 577 if (logLocation.exists) 578 { 579 if (logLocation.isDir) return true; 580 581 static uint idWhenNaggedAboutDir; 582 583 if (idWhenNaggedAboutDir != connectionID) 584 { 585 enum pattern = "Specified log directory (<l>%s</>) is not a directory."; 586 logger.warningf(pattern, logLocation); 587 idWhenNaggedAboutDir = connectionID; 588 } 589 590 return false; 591 } 592 else 593 { 594 // Create missing log directory 595 import std.file : mkdirRecurse; 596 597 mkdirRecurse(logLocation); 598 enum pattern = "Created log directory: <i>%s"; 599 logger.logf(pattern, logLocation); 600 } 601 602 return true; 603 } 604 605 606 // commitAllLogsImpl 607 /++ 608 Writes all buffered log lines to disk. 609 610 Merely wraps [commitLog] by iterating over all buffers and invoking it. 611 612 Params: 613 plugin = The current [kameloso.plugins.printer.base.PrinterPlugin|PrinterPlugin]. 614 615 See_Also: 616 [commitLog] 617 +/ 618 void commitAllLogsImpl(PrinterPlugin plugin) 619 { 620 if (!plugin.printerSettings.logs || !plugin.printerSettings.bufferedWrites) return; 621 622 foreach (ref buffer; plugin.buffers) 623 { 624 commitLog(plugin, buffer); 625 } 626 } 627 628 629 // commitLog 630 /++ 631 Writes a single log buffer to disk. 632 633 This is a way of queuing writes so that they can be committed seldom and 634 in bulk, supposedly being nicer to the hardware at the cost of the risk of 635 losing uncommitted lines in a catastrophical crash. 636 637 Params: 638 plugin = The current [kameloso.plugins.printer.base.PrinterPlugin|PrinterPlugin]. 639 buffer = [LogLineBuffer] whose lines to commit to disk. 640 641 See_Also: 642 [commitAllLogsImpl] 643 +/ 644 void commitLog(PrinterPlugin plugin, ref LogLineBuffer buffer) 645 { 646 import kameloso.string : doublyBackslashed; 647 import std.exception : ErrnoException; 648 import std.file : FileException; 649 import std.utf : UTFException; 650 651 if (!buffer.lines.data.length) return; 652 653 try 654 { 655 import std.algorithm.iteration : map; 656 import std.array : join; 657 import std.encoding : sanitize; 658 import std.file : exists, isDir, mkdirRecurse; 659 import std.stdio : File; 660 661 if (!buffer.dir.exists) 662 { 663 mkdirRecurse(buffer.dir); 664 } 665 else if (!buffer.dir.isDir) 666 { 667 // Something is in the way of the log's directory 668 // Discard accumulated lines 669 buffer.lines.clear(); 670 return; 671 } 672 673 // Write all in one go 674 const lines = buffer.lines.data 675 .map!sanitize 676 .join("\n"); 677 678 { 679 File file = File(buffer.file, "a"); 680 file.writeln(lines); 681 } 682 683 // If we're here, no exceptions were thrown 684 // Only clear if we managed to write everything, otherwise accumulate 685 buffer.lines.clear(); 686 } 687 catch (FileException e) 688 { 689 enum pattern = "File exception caught when committing log <l>%s</>: <t>%s%s"; 690 logger.warningf(pattern, buffer.file.doublyBackslashed, e.msg, plugin.bell); 691 version(PrintStacktraces) logger.trace(e.info); 692 } 693 catch (ErrnoException e) 694 { 695 version(Posix) 696 { 697 import kameloso.common : errnoStrings; 698 enum pattern = "ErrnoException <l>%s</> caught when committing log to <l>%s</>: <t>%s%s"; 699 logger.warningf(pattern, errnoStrings[e.errno], buffer.file.doublyBackslashed, e.msg, plugin.bell); 700 } 701 else version(Windows) 702 { 703 enum pattern = "ErrnoException <l>%d</> caught when committing log to <l>%s</>: <t>%s%s"; 704 logger.warningf(pattern, e.errno, buffer.file.doublyBackslashed, e.msg, plugin.bell); 705 } 706 else 707 { 708 static assert(0, "Unsupported platform, please file a bug."); 709 } 710 711 version(PrintStacktraces) logger.trace(e.info); 712 } 713 catch (Exception e) 714 { 715 enum pattern = "Unexpected exception caught when committing log <l>%s</>: <t>%s%s"; 716 logger.warningf(pattern, buffer.file.doublyBackslashed, e.msg, plugin.bell); 717 version(PrintStacktraces) logger.trace(e); 718 } 719 } 720 721 722 // escapedPath 723 /++ 724 Replaces some invalid filenames to something that can be stored on the filesystem. 725 726 This is really only a problem on Windows, as the Posix 727 [std.path.dirSeparator|dirSeparator] is not a valid IRC character, nor does 728 it have special legacy filenames like `NUL` and `CON`. 729 730 Params: 731 path = A filesystem path in string form. 732 733 Returns: 734 The passed path with some characters potentially added or replaced. 735 The original string is returned as-was if nothing no changes were needed. 736 +/ 737 auto escapedPath(/*const*/ string path) 738 { 739 version(Windows) 740 { 741 import std.algorithm.comparison : among; 742 import std.array : replace; 743 import std.uni : toUpper; 744 745 // Tilde is not a valid IRC nickname character, so it's safe to use as placeholder 746 enum replacementCharacter = '~'; 747 enum alternateReplacementCharacter = ')'; 748 749 if (path.toUpper.among!("CON", "PRN", "AUX", "NUL", 750 "COM0", "COM1", "COM2", "COM3", "COM4", "COM5", "COM6", "COM7", "COM8", "COM9", 751 "LPT0", "LPT1", "LPT2", "LPT3", "LPT4", "LPT5", "LPT6", "LPT7", "LPT8", "LPT9")) 752 { 753 path ~= replacementCharacter; 754 } 755 756 return path 757 .replace('\\', replacementCharacter) 758 .replace('|', alternateReplacementCharacter); // Don't collide 759 } 760 else version(Posix) 761 { 762 return path; 763 } 764 else 765 { 766 static assert(0, "Unsupported platform, please file a bug."); 767 } 768 } 769 770 /// 771 unittest 772 { 773 version(Windows) 774 { 775 { 776 immutable before = "a\\b"; 777 immutable after = escapedPath(before); 778 immutable expected = "a~b"; 779 assert((after == expected), after); 780 } 781 { 782 immutable before = "CON"; 783 immutable after = escapedPath(before); 784 immutable expected = "CON~"; 785 assert((after == expected), after); 786 } 787 { 788 immutable before = "NUL"; 789 immutable after = escapedPath(before); 790 immutable expected = "NUL~"; 791 assert((after == expected), after); 792 } 793 { 794 immutable before = "aUx"; 795 immutable after = escapedPath(before); 796 immutable expected = "aUx~"; 797 assert((after == expected), after); 798 } 799 { 800 immutable before = "con-"; 801 immutable after = escapedPath(before); 802 assert((after is before), after); 803 } 804 { 805 immutable before = "con|"; 806 immutable after = escapedPath(before); 807 immutable expected = "con)"; 808 assert((after == expected), after); 809 } 810 } 811 else version(Posix) 812 { 813 immutable before = "passthrough"; 814 immutable after = escapedPath(before); 815 assert((after is before), after); 816 } 817 }