// Written in the D programming language.

/++
Implements application level _logging mechanism.

This module defines a set of functions useful for many common _logging tasks.  The module must be initialized (ideally in single threaded mode) by calling $(D initializeLogging). Messages of different severity level are logged by calling the template functions $(D log) and $(D logf). Verbose messages can be logged by calling the template functions  $(D vlog) and $(D vlogf).

Examples:
---
import std.logging;

int main(string[] args)
{
   initializeLogging(ActorLogger.getCreator(args[0]));

   // ...
   logf(Level.info, "Log message from %s", args[0]);
}
---

Note:
Logging can be disable at compile time by defining the LOGGING_DISABLED version.

Macros:
D = $(B$(U $0))
+/
module std.logging;

import core.atomic : cas;
import std.stdio : File;
import std.conv : text, to;
import std.datetime: Clock, DateTime;
import std.exception : enforce;
import std.concurrency : spawn,
                         Tid,
                         send,
                         receive,
                         OwnerTerminated,
                         thisTid,
                         receiveOnly;
import std.traits : EnumMembers;
import std.array : appender, array;
import std.format : formattedWrite;
import std.algorithm : endsWith, startsWith, splitter;

version(unittest)
{
   import std.file : remove;
   import core.exception : AssertError;
}

version(LOGGING_DISABLED) {}
else { version = LOGGING; }

/++
Defines the severity levels supported by the logging library.

Logging messages of severity level Level.fatal will also cause the program to halt. Messages of a given severity will be written in the log file of that severity and the log files of lower severity.
+/
enum Level
{
   fatal = 0, ///
   error, /// ditto
   warning, /// ditto
   info /// ditto
}

/++
Initializes the logging infrastructure.

This function must be called ounce before calling any of the logging functions.

Params:
   logCreator = Delegate which creates the Logger used by the module.
   logConfig = Module configuration object. 

See_Also:
   LogConfig
+/
void initializeLogging(shared(Logger) delegate() logCreator,
                       LogConfig logConfig = LogConfig())
{
   _internal.init(logCreator, logConfig);
}

/++
Logs a formatted message.

Logs a formatted message if $(I level) is of higher or equal severity as that specified in the $(D LogConfig) object passed to $(D initializeLogging).

The first parameter in $(I args) will be used as the format string. See $(D std.format.formattedWrite) for a description of the format string.
+/
void logf(string file = __FILE__,
          int line = __LINE__,
          T...)
         (Level level,
          lazy T args)
{
   version(LOGGING) _internal.log(file, line, level, true, args);
}

/++
Logs a message

Logs a message if $(I level) is of higher or equal severity as that specified in the $(D LogConfig) object passed to $(D initializeLogging).
+/
void log(string file = __FILE__,
         int line = __LINE__,
         T...)
        (Level level,
         lazy T args)
{
   version(LOGGING) _internal.log(file, line, level, false, args);
}

/++
Logs a formatted verbose message

Logs a formatted verbose message if the $(B file) and $(I level) matches one of the entries specified in the $(D vLogConfigs) property of the $(D LogConfig) object passed to $(D initializeLogging).

The first parameter in $(I args) will be used as the format string. See $(D std.format.formattedWrite) for a description of the format string.
+/
void vlogf(string file = __FILE__,
           int line = __LINE__,
           T...)
          (uint level,
           lazy T args)
{
   version(LOGGING) _internal.vlog(file, line, level, true, args);
}

/++
Logs a verbose message

Logs a verbose message if the $(B file) and $(I level) matches one of the entries specified in the $(D vLogConfigs) property of the $(D LogConfig) object passed to $(D initializeLogging).
+/
void vlog(string file = __FILE__,
          int line = __LINE__,
          T...)
         (uint level,
          lazy T args)
{
   version(LOGGING) _internal.vlog(file, line, level, false, args);
}

/++
Configuration struct for the module.

This object must be used to configure the logging module at initialization.  All the properties are optional and can be use to configure the framework's behavior.
+/
struct LogConfig
{
/++
Level to use for _logging.

The logging framework will only log messages with a severity greater than or equal to the value of this property.
+/
   @property void level(Level level)
   {
      _level = level;
   }

/++
Verbose logging configuration.

Messages logged by using the template function $(D vlog) or $(D vlogf) will be filtered by comparing against each VLogConfig until a match is found. If no match is found the verbose message will not get logged.

See_Also:
   VLogConfig
+/
   @property void vLogConfigs(VLogConfig[] vLogConfigs)
   {
      _vLogConfigs = vLogConfigs;
   }

/++
Function pointer for handling log message with a severity of fatal.

This function will be called by the thread trying to log a fatal message by using $(D log) or $(D logf). The function $(I fatalHandler) should not return; otherwise the framework will assert(false).
+/
   @property void fatalHandler(void function() fatalHandler)
   {
      _fatalHandler = fatalHandler;
   }

   private string _name;
   private Level _level = Level.error;
   private VLogConfig[] _vLogConfigs;
   private void function() _fatalHandler;
}

/+
template isLogWriter(W)
{
   enum bool isLogWriter = is(typeof(
      {
         W w;
         w.log(Level.max, "");
         w.flush();
      }()));
}
+/

unittest
{
   // Test level filtering
   class LevelFilter : Logger
   {
      shared void log(Level level, string msg)
      {
         called = true;
         lastLevel = level;
         lastMsg = msg;
      }

      shared void flush()
      {
         flushCalled = true;
      }

      shared void clear()
      {
         lastMsg = string.init;
         lastLevel = Level.init;
         called = false;
         flushCalled = false;
      }

      string lastMsg;
      Level lastLevel;
      bool called;
      bool flushCalled;
   }

   LogConfig logConfig;
   logConfig.level = Level.warning;
   logConfig.vLogConfigs = VLogConfig.create("*logging.d=2");

   auto logger = cast(shared) new LevelFilter();
   InternalLogging logging;

   logging.init({ return cast(shared(Logger)) logger; },
                logConfig);

   auto loggedMessage = "logged message";

   // Test logging and level filtering
   logging.log("package/logging.d", 11, Level.info, false, loggedMessage);
   assert(!logger.called);

   logger.clear();
   logging.log("package/logging.d", 11, Level.warning, false, loggedMessage);
   assert(logger.called);
   assert(logger.lastLevel == Level.warning &&
          endsWith(logger.lastMsg, loggedMessage));

   logger.clear();
   logging.log("package/logging.d", 11, Level.error, false, loggedMessage);
   assert(logger.called);
   assert(logger.lastLevel == Level.error &&
          endsWith(logger.lastMsg, loggedMessage));

   logger.clear();
   logging.log("package/logging.d", 11, Level.error, false, loggedMessage);
   assert(logger.called);
   assert(logger.lastLevel == Level.error &&
          endsWith(logger.lastMsg, loggedMessage));

   // XXX this is ugly. Fix this test. look into using assertThrown
   logger.clear();
   try
   {
      logging.log("package/logging.d", 11, Level.fatal, false, loggedMessage);
      assert(false);
   }
   catch (AssertError e) {}
   assert(logger.called);
   assert(logger.lastLevel == Level.fatal &&
          endsWith(logger.lastMsg, loggedMessage));
   assert(logger.flushCalled);

   logger.clear();
   logging.log("package/logging.d",
               11,
               Level.warning,
               true,
               "%s",
               loggedMessage);
   assert(logger.called);
   assert(logger.lastLevel == Level.warning &&
          endsWith(logger.lastMsg, loggedMessage));

   // Test vlogging and module filtering
   logger.clear();
   logging.vlog("package/logging.d", 11, 2, false, loggedMessage);
   assert(logger.called);
   assert(logger.lastLevel == Level.info &&
          endsWith(logger.lastMsg, loggedMessage));

   logger.clear();
   logging.vlog("package/logging.d", 11, 3, false, loggedMessage);
   assert(!logger.called);

   logger.clear();
   logging.vlog("not_this_file", 22, 0, false, loggedMessage);
   assert(!logger.called); 

   logger.clear();
   logging.vlog("package/logging.d", 11, 2, true, loggedMessage);
   assert(logger.called);
   assert(logger.lastLevel == Level.info &&
	  endsWith(logger.lastMsg, loggedMessage));
}

private shared struct InternalLogging
{
   void init(shared(Logger) delegate() logCreator,
             LogConfig logConfig)
   { 
      enforce(cas(&_initialized, false, true));

      _vLogConfigs = logConfig._vLogConfigs.idup;
      _logger = logCreator();
      _level = logConfig._level;
      _fatalHandler =  logConfig._fatalHandler ? 
                       logConfig._fatalHandler :
                       function {};
   }

   void vlog(T...)
            (string file,
             int line,
             uint level,
             bool formatted,
             lazy T args)
   in
   {
      assert(_initialized);
   }
   body
   {

      if(logMatches(file, level, _vLogConfigs))
      {
         // TODO: fix core.Thread so that ThreadAddr is expose
         _logger.log(Level.info,
                     format(file, line, to!string(level), 0, formatted, args));
      }
   }

   void log(T...)
           (string file,
            int line,
            Level level,
            bool formatted,
            lazy T args)
   in
   {
      assert(_initialized);
   }
   body
   {
      if(level <= _level)
      {
         scope(exit)
         {
            if(level == Level.fatal)
            {
               /+
                + The other of the scope(exit) is important. We want
                + _fatalHandler to run before the assert.
                +/
               scope(exit) assert(false);
               scope(exit) _fatalHandler();
               _logger.flush();
            }
         }

         // TODO: fix core.Thread so that ThreadAddr is expose
         _logger.log(level,
                     format(file, line, to!string(level), 0, formatted, args));
      }
   }

   private bool _initialized;
   private Logger _logger;
   private Level _level;
   private immutable(VLogConfig)[] _vLogConfigs;
   private __gshared void function() _fatalHandler;
}

unittest
{
   // Test equals
   VLogConfig[] configs = [ VLogConfig("package/module",
                                       VLogConfig.Matching.equals,
                                       1) ];
   assert(logMatches("package/module", 1, configs));
   assert(logMatches("package/module.d", 1, configs));
   assert(logMatches("package/module", 0, configs));

   assert(!logMatches("module", 1, configs));
   assert(!logMatches("package/module", 2, configs));

   // Test startsWith
   configs[0]._pattern = "package";
   configs[0]._matching = VLogConfig.Matching.startsWith,
   configs[0]._level = 1;
   assert(logMatches("package/module", 1, configs));
   assert(logMatches("package/module.d", 1, configs));
   assert(logMatches("package/module", 0, configs));
   assert(logMatches("package/another.d", 1, configs));

   assert(!logMatches("module", 1, configs));
   assert(!logMatches("another/package/module", 1, configs));
   assert(!logMatches("package/module.d", 2, configs));

   // Test endsWith
   configs[0]._pattern = "module";
   configs[0]._matching = VLogConfig.Matching.endsWith,
   configs[0]._level = 1;
   assert(logMatches("package/module", 1, configs));
   assert(logMatches("package/module.d", 1, configs));
   assert(logMatches("package/module", 0, configs));
   assert(logMatches("module", 1, configs));

   assert(!logMatches("another", 1, configs));
   assert(!logMatches("package/module", 2, configs));
}

private bool logMatches(string file,
                        uint level,
                        const VLogConfig[] configs)
{
   foreach(config; configs)
   {
      if(config.match(file, level)) return true;
   }

   return false;
} 

private string format(T...)
                     (string file,
                      int line,
                      string level,
                      int threadId,
                      bool formatString,
                      T args)
{
   auto writer = appender!string();
   formattedWrite(writer,
                  "%s:%d:%s:%d ",
                  file,
                  line,
                  level,
                  threadId);
   if (formatString)
   {
      formattedWrite(writer, args[0], args[1 .. $]);
   }
   else
   {
      writer.put(text(args));
   }

   return writer.data;
}

unittest
{
   auto result = VLogConfig.create("module=1,*another=3,even*=2");
   assert(result.length == 3);
   assert(result[0]._pattern == "module");
   assert(result[0]._matching == VLogConfig.Matching.equals);
   assert(result[0]._level == 1);

   assert(result[1]._pattern == "another");
   assert(result[1]._matching == VLogConfig.Matching.endsWith);
   assert(result[1]._level == 3);

   assert(result[2]._pattern == "even");
   assert(result[2]._matching == VLogConfig.Matching.startsWith);
   assert(result[2]._level == 2);

   try
   {
      VLogConfig.create("module=2,");
      assert(false);
   }
   catch (Exception e) {}

   try
   {
      VLogConfig.create("module=a");
      assert(false);
   }
   catch (Exception e) {}

   try
   {
      VLogConfig.create("module=2,another=");
      assert(false);
   }
   catch (Exception e) {}

   try
   {
      VLogConfig.create("module=2,ano*ther=3");
      assert(false);
   }
   catch (Exception e) {}

   try
   {
      VLogConfig.create("module=2,*another*=3");
      assert(false);
   }
   catch (Exception e) {}
}

/++
Structure for configuring verbose logging.

This structure is used to control verbose logging on a per module basis. A verbose message with level $(I x) will get logged at severity level Level.info if there is a VLogConfig entry that matches to the source file and the verbose level of that entry is greater than or equal to $(I x).
+/
struct VLogConfig
{
   private enum Matching
   {
      startsWith,
      endsWith,
      equals
   } 

/++
Creates an array of $(D VLogConfig) based on a configuration string.

The format of the configuration string is as follow "$(B [pattern])=$(B [level]),...", where $(B [pattern]) may contain any character allowed in a file name and $(B [level]) must be convertible to an positive integer (greater than or equal to zero). If $(B [pattern]) contains a '*' then it must be at the start or the end. If $(B [pattern]) ends with a '*' then it will match any source file name that starts with the rest of $(B [pattern]). If $(B [pattern]) starts with a '*' then it will match any source file name that ends with a the rest of $(B [pattern]).

For every $(B [pattern])=$(B [level]) in the configuration string a $(D VLogConfig) will be created and included in the returned array.
+/
   static VLogConfig[] create(string config)
   {
      VLogConfig[] result;
      foreach(entry; splitter(config, ","))
      {
         enforce(entry != "");
         auto entryParts = array(splitter(entry, "="));
         enforce(entryParts.length == 2);

         auto mod = array(splitter(entryParts[0], "*"));
         enforce(mod.length == 1 || mod.length == 2);
         
         if(mod.length == 1 && mod[0] != "")
         {
            VLogConfig logConfig = VLogConfig(mod[0],
                                              Matching.equals,
                                              to!uint(entryParts[1]));
            result ~= logConfig;
         }
         else if(mod[0] != "" && mod[1] == "")
         {
            VLogConfig logConfig = VLogConfig(mod[0],
                                              Matching.startsWith,
                                              to!uint(entryParts[1]));
            result ~= logConfig;
         }
         else if(mod[0] == "" && mod[1] != "")
         {
            VLogConfig logConfig = VLogConfig(mod[1],
                                              Matching.endsWith,
                                              to!uint(entryParts[1]));
            result ~= logConfig;
         }
         else
         {
            enforce(false);
         }
      }

      return result;
   }

   private bool match(string file, uint level) const
   { 
      auto match = false;
      // XXX file but against startWith/endsWith for not allowing const
      auto pattern = cast(string) _pattern;

      final switch(_matching)
      {
         case VLogConfig.Matching.startsWith:
            match = startsWith(file, pattern) &&
                         level <= _level; 
            break;
         case VLogConfig.Matching.endsWith:
            match = (endsWith(file, pattern) ||
                     endsWith(file, pattern ~ ".d")) && 
                    level <= _level; 
            break;
         case VLogConfig.Matching.equals:
            match = (file == pattern ||
                     file == pattern ~ ".d") &&
                    level <= _level; 
            break;
      }

      return match;
   }

   private this(string pattern, Matching matching, uint level)
   {
      _pattern = pattern;
      _matching = matching;
      _level = level;
   }

   private string _pattern;
   private Matching _matching;
   private uint _level;
}

/++
Extension point for the module.
+/
shared interface Logger
{
/++
Logs a message.

The method is called by the logging module whenever it decides that a message should be logged. It is recommend that the implementation of this method doesn't perform any filtering based on level since at this point all configured filters were applied.

The method is allow to return immediately without persisting the message.
+/
   void log(Level level, string msg);

/++
Flushes pending log operations.

The method is called by the logging framework whenever it requires that the persistence of all previous log messages. For example the method is called when the client logs a fatal message.

The method must not return until all pending log operations complete.
+/
   void flush();
}

/++
Implements an actor based logging backend.

Log messages are sent to a logging thread which is responsible for persisting log messages. Messages of a given severity will be written in the log file of that severity and in the log files of lower severity. The file names of the log files created will follow the following pattern "$(B [name]).log.$(B [level]).$(B [time])". The string $(B [name]) is the parameter $(I name) passed to $(D getCreator). The string $(B [time]) is the time when the logger was created. The string $(B [level]) is the severity of the log file. A file for severity level 'x' will contain all log messages of greater or equal severity.
+/

// XXX Allow storing file in a diff dir
// XXX Allow the configuration of the log file name
class ActorLogger : Logger
{
   private struct Flush {}

   private this(string name)
   {
      _actor = spawn(&loggerMain, name);
   }

/++
Returns a delegate for creating an ActorLogger.

The method will always return a different delegate but a given delegate will always return the same $(D ActorLogger).

Params:
   name = Name to use when creating log files
+/
   static shared(Logger) delegate() getCreator(string name)
   {
      shared(Logger) creator()
      { 
         static Logger logger;
         logger = logger ? logger : new ActorLogger(name);
         return cast(shared(Logger)) logger;
      }

      return &creator;
   }

   shared void log(Level level, string msg)
   {
      send(cast(Tid) _actor, level, msg);
   }

   shared void flush()
   {
      send(cast(Tid) _actor, thisTid, Flush());
      receiveOnly!Flush();
   }

   private Tid _actor;
}

private void loggerMain(string name)
{
   auto logger = new MultiFileWriter(name);
   auto done = false;

   void log(Level level, string message)
   {
      logger.log(level, message);
   }

   void flush(Tid sender, ActorLogger.Flush flush)
   {
      logger.flush();
      send(sender, flush);
   }

   void terminate(OwnerTerminated e)
   {
      done = true;
   }

   while(!done)
   {
      receive(&log, &flush, &terminate);
   }
}

unittest
{
   void removeTestLogs(File[] writers)
   {
      foreach(ref writer; writers)
      {
         auto name = writer.name;
         writer.close();
         remove(name);
      }
   }

   auto msgs = ["fatal message",
                "error message",
                "warning message",
                "info message"];

   auto logger = new MultiFileWriter("logging_level_unittest");
   scope(exit) removeTestLogs(logger._writers);

   foreach(level; EnumMembers!Level)
   {
      logger.log(level, msgs[level]);
   }

   /+
    + Check the content of the files: for every file for severity level 'x'
    + there should be a message from a severity level <= 'x'. 
    +/
   foreach(fileLevel; EnumMembers!Level)
   {
      auto file = File(logger._writers[fileLevel].name, "r");
      for(auto level = Level.min; level <= fileLevel; ++level)
      {
         assert(file.readln() == (msgs[level] ~ "\n"));
      }
   }
}

private class MultiFileWriter
{
   this(string name)
   {
      auto time = cast(DateTime) Clock.currTime();

      // Create file for every level
      foreach(aLevel; EnumMembers!Level)
      {
         auto filename = text(name,
                              ".log.",
                              aLevel,
                              ".",
                              time.toISOString());
         _writers[aLevel] = File(filename, "w");
      }
   }

   void log(Level level, string msg)
   {
      for(Level aLevel = level; aLevel <= Level.max; ++aLevel)
      {
         _writers[aLevel].writeln(msg);
      }
   }

   void flush() {}

   private File[Level.max + 1] _writers;
}

/+unittest
{
   final class BufferMock
   {
      void log(Level level, string msg)
      {
         _called = true;
      }

      void flush()
      {
         _flushed = true;
      }
      
      void clear()
      {
         _called = false;
         _flushed = false;
      }

      bool _called;
      bool _flushed;
   }

   auto mock = new BufferMock();
   size_t size = 1024 * 1024;
   auto writer = new BufferedWriter(mock, size);

   // check that internal writer is not called
   mock.clear();
   writer.log(Level.warning, "1234567890");
   assert(!mock._called);
   assert(!mock._flushed);

   // check that internal writer is called but not flushed
   mock.clear();
   writer.log(Level.warning, new char[size]);
   assert(mock._called);
   assert(!mock._flushed);

   // if there is no data in the buffer then only flush should be called
   mock.clear();
   writer.flush();
   assert(!mock._called);
   assert(mock._flushed());

   // check that internal writer is not called
   mock.clear();
   writer.log(Level.warning, "1234567890");
   assert(!mock._called);
   assert(!mock._flushed);

   // data in the buffer both log and flush should get called when flushed
   mock.clear();
   writer.flush();
   assert(mock._called);
   assert(mock._flushed);
}

private final class BufferedWriter(LogWriter)
   if(isLogWriter(LogWriter))
{
   private struct Line
   {
      private Level _level;
      private string _message;
   }

   this(LogWriter writer, size_t bufferSize = 1024 * 1024)
   {
      _writer = writer;
      _bufferSize = bufferSize;
   }

   void log(Level level, string msg)
   {
      // if there is enough space then buffer the message
      // else write the buffer and the message
   }

   void flush()
   {
      // write the buffer
   }

   private LogWriter _writer;
   private size_t _bufferSize;
}+/

private shared InternalLogging _internal;