simgear/simgear/debug/logstream.cxx

// Stream based logging mechanism.
//
// Written by Bernie Bright, 1998
//
// Copyright (C) 1998  Bernie Bright - bbright@c031.aone.net.au
//
// This library is free software; you can redistribute it and/or
// modify it under the terms of the GNU Library General Public
// License as published by the Free Software Foundation; either
// version 2 of the License, or (at your option) any later version.
//
// This library is distributed in the hope that it will be useful,
// but WITHOUT ANY WARRANTY; without even the implied warranty of
// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
// Library General Public License for more details.
//
// You should have received a copy of the GNU General Public License
// along with this program; if not, write to the Free Software
// Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
//
// $Id$

#include <simgear_config.h>

#include "logstream.hxx"

#include <iostream>
#include <fstream>
#include <sstream>
#include <algorithm>

#include <boost/foreach.hpp>

#include <simgear/sg_inlines.h>
#include <simgear/threads/SGThread.hxx>
#include <simgear/threads/SGQueue.hxx>
#include <simgear/threads/SGGuard.hxx>

#include <simgear/misc/sgstream.hxx>
#include <simgear/misc/sg_path.hxx>

#if defined (SG_WINDOWS)
// for AllocConsole, OutputDebugString
    #include <windows.h>
    #include <fcntl.h>
    #include <io.h>
#endif

const char* debugClassToString(sgDebugClass c)
{
    switch (c) {
    case SG_NONE:       return "none";
    case SG_TERRAIN:    return "terrain";
    case SG_ASTRO:      return "astro";
    case SG_FLIGHT:     return "flight";
    case SG_INPUT:      return "input";
    case SG_GL:         return "opengl";
    case SG_VIEW:       return "view";
    case SG_COCKPIT:    return "cockpit";
    case SG_GENERAL:    return "general";
    case SG_MATH:       return "math";
    case SG_EVENT:      return "event";
    case SG_AIRCRAFT:   return "aircraft";
    case SG_AUTOPILOT:  return "autopilot";
    case SG_IO:         return "io";
    case SG_CLIPPER:    return "clipper";
    case SG_NETWORK:    return "network";
    case SG_ATC:        return "atc";
    case SG_NASAL:      return "nasal";
    case SG_INSTR:      return "instruments";
    case SG_SYSTEMS:    return "systems";
    case SG_AI:         return "ai";
    case SG_ENVIRONMENT:return "environment";
    case SG_SOUND:      return "sound";
    case SG_NAVAID:     return "navaid";
    case SG_GUI:        return "gui";
    case SG_TERRASYNC:  return "terrasync";
    case SG_PARTICLES:  return "particles";
    default:            return "unknown";
    }
}

//////////////////////////////////////////////////////////////////////////////

namespace simgear
{

LogCallback::LogCallback(sgDebugClass c, sgDebugPriority p) :
	m_class(c),
	m_priority(p)
{
}

bool LogCallback::shouldLog(sgDebugClass c, sgDebugPriority p) const
{
	 return ((c & m_class) != 0 && p >= m_priority);
}

void LogCallback::setLogLevels( sgDebugClass c, sgDebugPriority p )
{
	m_priority = p;
	m_class = c;
}

} // of namespace simgear

//////////////////////////////////////////////////////////////////////////////

class FileLogCallback : public simgear::LogCallback
{
public:
    FileLogCallback(const SGPath& aPath, sgDebugClass c, sgDebugPriority p) :
	    simgear::LogCallback(c, p)
    {
        m_file.open(aPath, std::ios_base::out | std::ios_base::trunc);
    }

    virtual void operator()(sgDebugClass c, sgDebugPriority p,
        const char* file, int line, const std::string& message)
    {
        if (!shouldLog(c, p)) return;
        m_file << debugClassToString(c) << ":" << (int) p
            << ":" << file << ":" << line << ":" << message << std::endl;
    }
private:
    sg_ofstream m_file;
};

class StderrLogCallback : public simgear::LogCallback
{
public:
    StderrLogCallback(sgDebugClass c, sgDebugPriority p) :
		simgear::LogCallback(c, p)
    {
    }

#if defined (SG_WINDOWS)
    ~StderrLogCallback()
    {
        FreeConsole();
    }
#endif

    virtual void operator()(sgDebugClass c, sgDebugPriority p,
        const char* file, int line, const std::string& aMessage)
    {
        if (!shouldLog(c, p)) return;

        fprintf(stderr, "%s\n", aMessage.c_str());
        //fprintf(stderr, "%s:%d:%s:%d:%s\n", debugClassToString(c), p,
        //    file, line, aMessage.c_str());
        fflush(stderr);
    }
};


#ifdef SG_WINDOWS

class WinDebugLogCallback : public simgear::LogCallback
{
public:
    WinDebugLogCallback(sgDebugClass c, sgDebugPriority p) :
		simgear::LogCallback(c, p)
    {
    }

    virtual void operator()(sgDebugClass c, sgDebugPriority p,
        const char* file, int line, const std::string& aMessage)
    {
        if (!shouldLog(c, p)) return;

        std::ostringstream os;
		os << debugClassToString(c) << ":" << aMessage << std::endl;
		OutputDebugStringA(os.str().c_str());
    }
};

#endif

class LogStreamPrivate : public SGThread
{
private:
    /**
     * storage of a single log entry. This is used to pass log entries from
     * the various threads to the logging thread, and also to store the startup
     * entries
     */
    class LogEntry
    {
    public:
        LogEntry(sgDebugClass c, sgDebugPriority p,
            const char* f, int l, const std::string& msg) :
            debugClass(c), debugPriority(p), file(f), line(l),
                message(msg)
        {
        }

        const sgDebugClass debugClass;
        const sgDebugPriority debugPriority;
        const char* file;
        const int line;
        const std::string message;
    };

    /**
     * RAII object to pause the logging thread if it's running, and restart it.
     * used to safely make configuration changes.
     */
    class PauseThread
    {
    public:
        PauseThread(LogStreamPrivate* parent)
            : m_parent(parent)
            , m_wasRunning(m_parent->stop())
        {
        }

        ~PauseThread()
        {
            if (m_wasRunning) {
                m_parent->startLog();
            }
        }
    private:
        LogStreamPrivate* m_parent;
        const bool m_wasRunning;
    };

public:
    LogStreamPrivate() :
        m_logClass(SG_ALL),
        m_logPriority(SG_ALERT)
    {
#if defined (SG_WINDOWS)
        /*
         * 2016-09-20(RJH) - Reworked console handling
         * 1) When started from the console use the console (when no --console)
         * 2) When started from the GUI (with --console) open a new console window
         * 3) When started from the GUI (without --console) don't open a new console
         *    window; stdout/stderr will not appear (except in logfiles as they do now)
         * 4) When started from the Console (with --console) open a new console window
         * 5) Ensure that IO redirection still works when started from the console
         * 
         * Notes:
         * 1) fgfs needs to be a GUI subsystem app - which it already is
         * 2) What can't be done is to make the cmd prompt run fgfs synchronously; 
         * this is only something that can be done via "start /wait fgfs".
         */

        int stderr_handle_type = GetFileType(GetStdHandle(STD_ERROR_HANDLE));
        int stdout_handle_type = GetFileType(GetStdHandle(STD_OUTPUT_HANDLE));
        int stdout_isNull = 0;
        int stderr_isNull = 0;

        m_stderr_isRedirectedAlready = stderr_handle_type == FILE_TYPE_DISK || stderr_handle_type == FILE_TYPE_PIPE || stderr_handle_type == FILE_TYPE_CHAR;
        m_stdout_isRedirectedAlready = stdout_handle_type == FILE_TYPE_DISK || stdout_handle_type == FILE_TYPE_PIPE || stdout_handle_type == FILE_TYPE_CHAR;

        /*
         * We don't want to attach to the console if either stream has been redirected - so in this case ensure that both streams
         * are redirected as otherwise something will be lost (as Alloc or Attach Console will cause the handles that were bound
         * to disappear)
         */
        if (m_stdout_isRedirectedAlready){
			if (!m_stderr_isRedirectedAlready) {
				MessageBox(0, "Redirection only works when you use 2>&1 before using > or |\r\n(e.g. fgfs 2>&1 | more)", "Simgear Error", MB_OK | MB_ICONERROR);
				exit(3);
			}
        } else {
            /*
            * Attempt to attach to the console process of the parent process; when launched from cmd.exe this should be the console, 
            * when launched via the RUN menu explorer, or another GUI app that wasn't started from the console this will fail.
            * When it fails we will redirect to the NUL device. This is to ensure that we have valid streams.
            * Later on in the initialisation sequence the --console option will be processed and this will cause the requestConsole() to
            * always open a new console, except for streams that are redirected. The same rules apply there, if both streams are redirected
            * the console will be opened, and it will contain a message to indicate that no output will be present because the streams are redirected
            */
            if (AttachConsole(ATTACH_PARENT_PROCESS) == 0) {
                /*
                * attach failed - so ensure that the streams are bound to the null device - but only when not already redirected
                */
                if (!m_stdout_isRedirectedAlready)
                {
                    stdout_isNull = true;
                    freopen("NUL", "w", stdout);
                }

                if (!m_stderr_isRedirectedAlready)
                {
                    stderr_isNull = true;
                    freopen("NUL", "w", stderr);
                }
            }
            /*
            * providing that AttachConsole succeeded - we can then either reopen the stream onto the console, or use
            * _fdopen to attached to the currently redirected (and open stream)
            */
            if (!stdout_isNull){
                if (!m_stdout_isRedirectedAlready)
                    freopen("conout$", "w", stdout);
                else 
                    /*
                    * for already redirected streams we need to attach the stream to the OS handle that is open.
                    * - this comes from part of the answer http://stackoverflow.com/a/13841522
                    *   _open_osfhandle returns an FD for the Win32 Handle, which is then opened using fdopen and
                    *   hopefully safely assigned to the stream (although it does look wrong to me it works)
                    * Removing this bit will stop pipes and command line redirection (> 2> and 2>&1 from working)
                    */
                    *stdout = *_fdopen(_open_osfhandle((intptr_t) GetStdHandle(STD_OUTPUT_HANDLE), _O_WRONLY), "a");
            }

            if (!stderr_isNull){
                if (!m_stderr_isRedirectedAlready)
                    freopen("conout$", "w", stderr);
                else
                    *stderr = *_fdopen(_open_osfhandle((intptr_t) GetStdHandle(STD_ERROR_HANDLE), _O_WRONLY), "a");
            }
        }
        //http://stackoverflow.com/a/25927081
        //Clear the error state for each of the C++ standard stream objects. 
        std::wcout.clear();
        std::cout.clear();
        std::wcerr.clear();
        std::cerr.clear();
#endif

        m_callbacks.push_back(new StderrLogCallback(m_logClass, m_logPriority));
        m_consoleCallbacks.push_back(m_callbacks.back());
#if defined (SG_WINDOWS) && !defined(NDEBUG)
		m_callbacks.push_back(new WinDebugLogCallback(m_logClass, m_logPriority));
		m_consoleCallbacks.push_back(m_callbacks.back());
#endif
    }

    ~LogStreamPrivate()
    {
        for (simgear::LogCallback* cb : m_callbacks) {
            delete cb;
        }
    }

    SGMutex m_lock;
    SGBlockingQueue<LogEntry> m_entries;

    // log entries posted during startup
    std::vector<LogEntry> m_startupEntries;
    bool m_startupLogging = false;

    typedef std::vector<simgear::LogCallback*> CallbackVec;
    CallbackVec m_callbacks;
    /// subset of callbacks which correspond to stdout / console,
	/// and hence should dynamically reflect console logging settings
	CallbackVec m_consoleCallbacks;

    sgDebugClass m_logClass;
    sgDebugPriority m_logPriority;
    bool m_isRunning = false;
#if defined (SG_WINDOWS)
    // track whether the console was redirected on launch (in the constructor, which is called early on)
    bool m_stderr_isRedirectedAlready = false;
    bool m_stdout_isRedirectedAlready = false;
#endif

    void startLog()
    {
        SGGuard<SGMutex> g(m_lock);
        if (m_isRunning) return;
        m_isRunning = true;
        start();
    }

    void setStartupLoggingEnabled(bool on)
    {
        if (m_startupLogging == on) {
            return;
        }

        m_startupLogging = on;
        m_startupEntries.clear();
    }

    virtual void run()
    {
        while (1) {
            LogEntry entry(m_entries.pop());
            // special marker entry detected, terminate the thread since we are
            // making a configuration change or quitting the app
            if ((entry.debugClass == SG_NONE) && !strcmp(entry.file, "done")) {
                return;
            }

            if (m_startupLogging) {
                // save to the startup list for not-yet-added callbacks to
                // pull down on startup
                m_startupEntries.push_back(entry);
            }

            // submit to each installed callback in turn
            for (simgear::LogCallback* cb : m_callbacks) {
                (*cb)(entry.debugClass, entry.debugPriority,
                    entry.file, entry.line, entry.message);
            }
        } // of main thread loop
    }

    bool stop()
    {
        SGGuard<SGMutex> g(m_lock);
        if (!m_isRunning) {
            return false;
        }

        // log a special marker value, which will cause the thread to wakeup,
        // and then exit
        log(SG_NONE, SG_ALERT, "done", -1, "");
        join();

        m_isRunning = false;
        return true;
    }

    void addCallback(simgear::LogCallback* cb)
    {
        PauseThread pause(this);
        m_callbacks.push_back(cb);

        // we clear startup entries not using this, so always safe to run
        // this code, container will simply be empty
        for (auto entry : m_startupEntries) {
            (*cb)(entry.debugClass, entry.debugPriority,
               entry.file, entry.line, entry.message);
        }
    }

    void removeCallback(simgear::LogCallback* cb)
    {
        PauseThread pause(this);
        CallbackVec::iterator it = std::find(m_callbacks.begin(), m_callbacks.end(), cb);
        if (it != m_callbacks.end()) {
            m_callbacks.erase(it);
        }
    }

    void setLogLevels( sgDebugClass c, sgDebugPriority p )
    {
        PauseThread pause(this);
        m_logPriority = p;
        m_logClass = c;
		BOOST_FOREACH(simgear::LogCallback* cb, m_consoleCallbacks) {
	        cb->setLogLevels(c, p);
		}
    }

    bool would_log( sgDebugClass c, sgDebugPriority p ) const
    {
        if (p >= SG_INFO) return true;
        return ((c & m_logClass) != 0 && p >= m_logPriority);
    }

    void log( sgDebugClass c, sgDebugPriority p,
            const char* fileName, int line, const std::string& msg)
    {
        LogEntry entry(c, p, fileName, line, msg);
        m_entries.push(entry);
    }
};

/////////////////////////////////////////////////////////////////////////////

static logstream* global_logstream = NULL;
static LogStreamPrivate* global_privateLogstream = NULL;
static SGMutex global_logStreamLock;

logstream::logstream()
{
    global_privateLogstream = new LogStreamPrivate;
    global_privateLogstream->startLog();
}

logstream::~logstream()
{
    popup_msgs.clear();
    global_privateLogstream->stop();
    delete global_privateLogstream;
}

void
logstream::setLogLevels( sgDebugClass c, sgDebugPriority p )
{
    global_privateLogstream->setLogLevels(c, p);
}

void
logstream::addCallback(simgear::LogCallback* cb)
{
    global_privateLogstream->addCallback(cb);
}

void
logstream::removeCallback(simgear::LogCallback* cb)
{
    global_privateLogstream->removeCallback(cb);
}

void
logstream::log( sgDebugClass c, sgDebugPriority p,
        const char* fileName, int line, const std::string& msg)
{
    global_privateLogstream->log(c, p, fileName, line, msg);
}

void
logstream::popup( const std::string& msg)
{
    popup_msgs.push_back(msg);
}

std::string
logstream::get_popup()
{
    std::string rv = "";
    if (!popup_msgs.empty())
    {
        rv = popup_msgs.front();
        popup_msgs.erase(popup_msgs.begin());
    }
    return rv;
}

bool
logstream::has_popup()
{
    return (popup_msgs.size() > 0) ? true : false;
}

bool
logstream::would_log( sgDebugClass c, sgDebugPriority p ) const
{
    return global_privateLogstream->would_log(c,p);
}

sgDebugClass
logstream::get_log_classes() const
{
    return global_privateLogstream->m_logClass;
}

sgDebugPriority
logstream::get_log_priority() const
{
    return global_privateLogstream->m_logPriority;
}

void
logstream::set_log_priority( sgDebugPriority p)
{
    global_privateLogstream->setLogLevels(global_privateLogstream->m_logClass, p);
}

void
logstream::set_log_classes( sgDebugClass c)
{
    global_privateLogstream->setLogLevels(c, global_privateLogstream->m_logPriority);
}


logstream&
sglog()
{
    // Force initialization of cerr.
    static std::ios_base::Init initializer;

    // http://www.aristeia.com/Papers/DDJ_Jul_Aug_2004_revised.pdf
    // in the absence of portable memory barrier ops in Simgear,
    // let's keep this correct & safe
    SGGuard<SGMutex> g(global_logStreamLock);

    if( !global_logstream )
        global_logstream = new logstream();
    return *global_logstream;
}

void
logstream::logToFile( const SGPath& aPath, sgDebugClass c, sgDebugPriority p )
{
    global_privateLogstream->addCallback(new FileLogCallback(aPath, c, p));
}

void logstream::setStartupLoggingEnabled(bool enabled)
{
    global_privateLogstream->setStartupLoggingEnabled(enabled);
}

namespace simgear
{

void requestConsole()
{ 
#if defined (SG_WINDOWS)
   /*
    * 2016-09-20(RJH) - Reworked console handling
    * This is part of the reworked console handling for Win32. This is for building as a Win32 GUI Subsystem where no
    * console is allocated on launch. If building as a console app then the startup will ensure that a console is created - but
    * we don't need to handle that.
    * The new handling is quite simple:
    *              1. The constructor will ensure that these streams exists. It will attach to the
    *                 parent command prompt if started from the command prompt, otherwise the
    *                 stdout/stderr will be bound to the NUL device.
    *              2. with --console a window will always appear regardless of where the process was
    *                 started from. Any non redirected streams will be redirected 
    *              3. You cannot use --console and either redirected stream.
    *
    * This is called after the Private Log Stream constructor so we need to undo any console that it has attached to.
    */

    if (!global_privateLogstream->m_stderr_isRedirectedAlready && !global_privateLogstream->m_stdout_isRedirectedAlready) {
        FreeConsole();
        if (AllocConsole()) {
            if (!global_privateLogstream->m_stdout_isRedirectedAlready)
                freopen("conout$", "w", stdout);

            if (!global_privateLogstream->m_stderr_isRedirectedAlready)
                freopen("conout$", "w", stderr);

            //http://stackoverflow.com/a/25927081
            //Clear the error state for each of the C++ standard stream objects. 
            std::wcout.clear();
            std::cout.clear();
            std::wcerr.clear();
            std::cerr.clear();
        }
    } else {
        MessageBox(0, "--console ignored because stdout or stderr redirected with > or 2>", "Simgear Error", MB_OK | MB_ICONERROR);
    }
#endif
}


void shutdownLogging()
{
    SGGuard<SGMutex> g(global_logStreamLock);
    delete global_logstream;
    global_logstream = 0;
}

} // of namespace simgear