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 }