Merge branch 'feature/logging' into develop

src/SConscript

@@ -20,6 +20,7 @@ files = [
     'basics.cc',
     'camera.cc',
     'light.cc',
+    'log.cc',
     'material.cc',
     'object.cc',
     'objectBox.cc',

src/charles.cc

@@ -9,6 +9,7 @@
 #include <unistd.h>
 
 #include "basics.h"
+#include "log.hh"
 #include "light.h"
 #include "material.h"
 #include "object_sphere.h"
@@ -17,6 +18,9 @@
 #include "scene.h"
 #include "writer_png.h"
 
+#define LOG_NAME "ROOT"
+#include "logModule.hh"
+
 
 int verbosity = 0;
 
@@ -24,7 +28,8 @@ int verbosity = 0;
 static void
 usage(const char *progname)
 {
-    fprintf(stderr, "Usage: %s [-hv] [-o <outfile>] <infile ...>\n", progname);
+    fprintf(stderr, "Usage: %s [-hv] [-l <logfile>] [-L <log level>] [-o <outfile>] <infile ...>\n",
+            progname);
 }
 
 
@@ -32,6 +37,8 @@ int
 main(int argc,
      const char *argv[])
 {
+    using namespace charles::log;
+
     Scene scene;
 
     scene.get_ambient().set_intensity(1.0);
@@ -66,24 +73,42 @@ main(int argc,
     PointLight *l1 = new PointLight(Vector3(6.0, -4.0, 2), Color::White, 1.0);
     scene.add_light(l1);
 
+    std::string logFilename;
+    unsigned int logLevel = 0;
+
     std::string outfile, infile;
 
     int opt;
-    while ((opt = getopt(argc, (char *const *)argv, "ho:v")) != -1) {
+    while ((opt = getopt(argc, (char *const *)argv, "hl:L:o:v:")) != -1) {
         switch (opt) {
             case 'h':
                 usage(argv[0]);
+                exit(0);
+                break;
+            case 'l':
+                logFilename = optarg;
+                break;
+            case 'L':
+                logLevel = std::stoul(optarg);
                 break;
             case 'o':
                 outfile = optarg;
                 break;
             case 'v':
-                ++verbosity;
                 break;
         }
     }
 
+    /* Set up logging */
+    if (logLevel > 0) {
+        if (logFilename.empty()) {
+            logFilename = "charles.log";
+        }
+        Log::Init(logFilename, logLevel);
+    }
+
     if (optind >= argc) {
+        LOG_ERROR << "Input file required.";
         fprintf(stderr, "Input file required.\n");
         usage(argv[0]);
         return -1;
@@ -102,11 +127,16 @@ main(int argc,
     }
 
     /* Call tracer. */
+    LOG_INFO << "Beginning render";
     scene.render();
 
     /* Write rendered scene to PNG file. */
     PNGWriter writer;
     scene.write(writer, outfile);
 
+    if (logLevel > 0) {
+        Log::Close();
+    }
+
     return 0;
 }

src/log.cc

@@ -0,0 +1,119 @@
+/* log.cc
+ * vim: set tw=80:
+ * Eryn Wells <eryn@erynwells.me>
+ */
+
+#include "log.hh"
+
+
+namespace charles {
+namespace log {
+
+/** Useful predefined levels. */
+namespace level {
+    const unsigned int Error = 10;
+    const unsigned int Warning = 20;
+    const unsigned int Info = 30;
+    const unsigned int Debug = 40;
+    const unsigned int Trace = 50;
+};
+
+
+unsigned int Log::sLevel = 0;
+std::ostream* Log::sOutput = nullptr;
+Log::LoggerMap Log::sLoggers;
+
+
+/* static */ void
+Log::Init(const std::string& filename,
+          unsigned int level)
+{
+    assert(sOutput == nullptr);
+    sOutput = new std::ofstream(filename);
+    sLevel = level;
+
+    Log("ROOT", 1) << "Opening log file " << filename;
+    Log("ROOT", 1) << "Log level set to " << sLevel;
+}
+
+
+/* static */ void
+Log::Close()
+{
+    assert(sOutput != nullptr);
+    delete sOutput;
+    sOutput = nullptr;
+}
+
+
+/**
+ * Construct a Log object.
+ *
+ * @param [in] name     The name of the log stream. If this name hasn't been
+ *                      seen before, a new one will be created for you.
+ * @param [in] level    The level. If this is higher than the level of the log
+ *                      stream, nothing will be output.
+ */
+Log::Log(const std::string& name,
+         unsigned int level)
+    : mName(name),
+      mLevel(level),
+      mOutput(Log::GetLogger(name))
+{
+    using namespace std::chrono;
+
+    /* Write a log message leader: "<time with millis> - <name>:<level> - ". */
+    auto now = system_clock::now();
+    auto nowMillis =
+        duration_cast<milliseconds>(now.time_since_epoch() % seconds(1));
+    auto cNow = system_clock::to_time_t(now);
+    *this << std::put_time(std::localtime(&cNow), "%F %T")
+          << "." << std::left << std::setw(3) << nowMillis.count()
+          << " - " << mName
+          << ":" << std::left << std::setw(2) << mLevel << " - ";
+}
+
+
+Log::~Log()
+{
+    /* Add a newline at the end of this log message. */
+    *this << "\n";
+}
+
+
+/* static */ Log::Logger&
+Log::GetLogger(const std::string& name)
+{
+    /*
+     * TODO: For now, output is always the same: sOutput. In the future, figure
+     * out a way to set different outputs for different streams.
+     */
+    auto pair = sLoggers.emplace(name, sLevel);
+    return pair.first->second;
+}
+
+#pragma mark Log::Logger
+
+Log::Logger::Logger(unsigned int l)
+    : level(l)
+{ }
+
+
+#pragma mark Tracer
+
+Tracer::Tracer(const std::string& name,
+               const std::string& function)
+    : mName(name),
+      mFunction(function)
+{
+    Log(mName, level::Trace) << "--> " << mFunction;
+}
+
+
+Tracer::~Tracer()
+{
+    Log(mName, level::Trace) << "<-- " << mFunction;
+}
+
+} /* namespace log */
+} /* namespace charles */

src/log.hh

@@ -0,0 +1,103 @@
+/* log.hh
+ * vim: set tw=80:
+ * Eryn Wells <eryn@erynwells.me>
+ */
+
+#ifndef __LOG_HH__
+#define __LOG_HH__
+
+#include <cassert>
+#include <cstddef>
+
+#include <chrono>
+#include <iomanip>
+#include <map>
+#include <fstream>
+#include <string>
+
+
+namespace charles {
+namespace log {
+
+/** Useful predefined levels. */
+namespace level {
+    extern const unsigned int Error;
+    extern const unsigned int Warning;
+    extern const unsigned int Info;
+    extern const unsigned int Debug;
+    extern const unsigned int Trace;
+};
+
+
+struct Log
+{
+    static void Init(const std::string& filename,
+                     unsigned int level = level::Info);
+    static void Close();
+
+    Log(const std::string& name = "root", unsigned int level = level::Info);
+    ~Log();
+
+    template<typename T> Log& operator<<(const T& item);
+
+private:
+    struct Logger
+    {
+        Logger(unsigned int level = level::Info);
+
+        unsigned int level;
+    };
+
+    typedef std::map<std::string, Logger> LoggerMap;
+
+    static unsigned int sLevel;
+    static std::ostream* sOutput;
+    static LoggerMap sLoggers;
+
+    static Logger& GetLogger(const std::string& name);
+
+    const std::string& mName;
+    unsigned int mLevel;
+    Logger& mOutput;
+};
+
+
+struct Tracer
+{
+    Tracer(const std::string& name,
+           const std::string& function);
+    ~Tracer();
+
+private:
+    const std::string& mName;
+    const std::string& mFunction;
+};
+
+
+template<typename T>
+Log&
+Log::operator<<(const T& item)
+{
+    if (mLevel <= mOutput.level) {
+        assert(sOutput != nullptr);
+        *sOutput << item;
+    }
+    return *this;
+}
+
+
+} /* namespace log */
+} /* namespace charles */
+
+
+#define LOG_NAME_LEVEL(name, level) charles::log::Log((name), (level))
+#define LOG_ERROR_NAME(name) LOG_NAME_LEVEL(name, charles::log::level::Error)
+#define LOG_WARN_NAME(name) LOG_NAME_LEVEL(name, charles::log::level::Warning)
+#define LOG_INFO_NAME(name) LOG_NAME_LEVEL(name, charles::log::level::Info)
+#define LOG_DEBUG_NAME(name) LOG_NAME_LEVEL(name, charles::log::level::Debug)
+#define LOG_TRACE_NAME(name) LOG_NAME_LEVEL(name, charles::log::level::Trace)
+
+#define TRACE_FUNC_NAME(name) \
+    auto __tracer = charles::log::Tracer((name), __PRETTY_FUNCTION__)
+
+#endif /* __LOG_HH__ */

src/logModule.hh

@@ -0,0 +1,27 @@
+/* logModule.hh
+ * vim: set tw=80:
+ * Eryn Wells <eryn@erynwells.me>
+ */
+/**
+ * Defines some helper macros for logging that simplify the ones defined in
+ * log.hh.
+ */
+
+#ifndef __LOGMODULE_HH__
+#define __LOGMODULE_HH__
+
+#if !defined(LOG_NAME)
+#warning "Log stream name undefined. Using ROOT log stream."
+#define LOG_NAME "ROOT"
+#endif
+
+#define LOG_LEVEL(level) LOG_NAME_LEVEL(LOG_NAME, level)
+#define LOG_ERROR LOG_ERROR_NAME(LOG_NAME)
+#define LOG_WARN LOG_WARN_NAME(LOG_NAME)
+#define LOG_INFO LOG_INFO_NAME(LOG_NAME)
+#define LOG_DEBUG LOG_DEBUG_NAME(LOG_NAME)
+#define LOG_TRACE LOG_TRACE_NAME(LOG_NAME)
+
+#define TRACE_FUNC TRACE_FUNC_NAME(LOG_NAME)
+
+#endif /* __LOGMODULE_HH__ */

src/scene.cc

@@ -11,10 +11,14 @@
 
 #include "basics.h"
 #include "light.h"
+#include "log.hh"
 #include "object.h"
 #include "scene.h"
 #include "writer.h"
 
+#define LOG_NAME "scene"
+#include "logModule.hh"
+
 using namespace charles;
 
 
@@ -144,6 +148,7 @@ Scene::write(Writer &writer, const std::string &filename)
 void
 Scene::render()
 {
+    LOG_INFO << "Rendering scene with " << shapes.size() << " objects.";
     printf("Rendering scene with %lu objects.\n", shapes.size());
     std::chrono::time_point<std::chrono::system_clock> start, end;
     start = std::chrono::system_clock::now();
@@ -167,6 +172,7 @@ Scene::render()
     _is_rendered = true;
 
     printf("Rendering completed in %f seconds.\n\n", seconds.count());
+    LOG_INFO << "Rendering completed in " << seconds.count() << " seconds.";
     mStats.PrintRayTable();
 }