loggingserver.cpp

Go to the documentation of this file.

#include <QtGlobal>
#include <QAtomicInt>
#include <QMutex>
#include <QMutexLocker>
#include <QWaitCondition>
#include <QList>
#include <QQueue>
#include <QHash>
#include <QCoreApplication>
#include <QFileInfo>
#include <QStringList>
#include <QMap>
#include <QSocketNotifier>
#include <iostream>
 
#include "mythlogging.h"
#include "logging.h"
#include "loggingserver.h"
#include "mythdb.h"
#include "mythcorecontext.h"
#include "dbutil.h"
#include "exitcodes.h"
#include "compat.h"
 
#include <cstdlib>
#ifndef _WIN32
#include "mythsyslog.h"
#if CONFIG_SYSTEMD_JOURNAL
#define SD_JOURNAL_SUPPRESS_LOCATION 1 // NOLINT(cppcoreguidelines-macro-usage)
#include <systemd/sd-journal.h>
#endif
#endif
#include <cstdarg>
#include <cstring>
#include <sys/stat.h>
#include <sys/types.h>
#include <fcntl.h>
#include <cstdio>
#include <unistd.h>
#if HAVE_GETTIMEOFDAY
#include <sys/time.h>
#endif
#include <csignal>
 
// Various ways to get to thread's tid
#if defined(__linux__)
#include <sys/syscall.h>
#elif defined(__FreeBSD__)
extern "C" {
#include <sys/ucontext.h>
#include <sys/thr.h>
}
#elif defined(Q_OS_DARWIN)
#include <mach/mach.h>
#endif
 
static QMutex                      loggerMapMutex;
static QMap<QString, LoggerBase *> loggerMap;
 
LogForwardThread                   *logForwardThread = nullptr;
 
using LoggerList = QList<LoggerBase *>;
 
struct LoggerListItem {
    LoggerList *m_itemList;
    std::chrono::seconds m_itemEpoch;
};
 
// A list of logging objects that process messages.
static QMutex                       gLoggerListMutex;
static LoggerListItem               *gLoggerList {nullptr};
 
// This is a FIFO queue containing the incoming messages "sent" from a
// client to this server. As each message arrives, it is queued here
// for later retrieval by a different thread.  This used to be
// populated by a thread that received messages from the network, and
// drained by a different thread that logged the messages.  It is now
// populated by the thread that generated the message, and drained by
// a different thread that logs the messages.
static QMutex                       gLogItemListMutex;
static LoggingItemList              gLogItemList;
static QWaitCondition               gLogItemListNotEmpty;
 
LoggerBase::LoggerBase(const char *string) :
    m_handle(string)
{
    QMutexLocker locker(&loggerMapMutex);
    loggerMap.insert(m_handle, this);
}
 
 
LoggerBase::~LoggerBase()
{
    QMutexLocker locker(&loggerMapMutex);
    loggerMap.remove(m_handle);
}
 
 
FileLogger::FileLogger(const char *filename) :
        LoggerBase(filename)
{
    m_fd = open(filename, O_WRONLY|O_CREAT|O_APPEND, 0664);
    m_opened = (m_fd != -1);
    LOG(VB_GENERAL, LOG_INFO, QString("Added logging to %1")
             .arg(filename));
}
 
 
FileLogger::~FileLogger()
{
    if( m_opened )
    {
        LOG(VB_GENERAL, LOG_INFO, QString("Removed logging to %1")
            .arg(m_handle));
        close(m_fd);
        m_fd = -1;
        m_opened = false;
    }
}
 
FileLogger *FileLogger::create(const QString& filename, QMutex *mutex)
{
    QByteArray ba = filename.toLocal8Bit();
    const char *file = ba.constData();
    auto *logger =
        qobject_cast<FileLogger *>(loggerMap.value(filename, nullptr));
 
    if (logger)
        return logger;
 
    // Need to add a new FileLogger
    mutex->unlock();
    // inserts into loggerMap
    logger = new FileLogger(file);
    mutex->lock();
 
    return logger;
}
 
void FileLogger::reopen(void)
{
    close(m_fd);
 
    m_fd = open(qPrintable(m_handle), O_WRONLY|O_CREAT|O_APPEND, 0664);
    m_opened = (m_fd != -1);
    LOG(VB_GENERAL, LOG_INFO, QString("Rolled logging on %1") .arg(m_handle));
}
 
bool FileLogger::logmsg(LoggingItem *item)
{
    if (!m_opened)
        return false;
 
    QString timestamp = item->getTimestampUs();
    QChar shortname = item->getLevelChar();
 
    std::string line;
    if( item->tid() )
    {
        line = qPrintable(QString("%1 %2 [%3/%4] %5 %6:%7 (%8) - %9\n")
                          .arg(timestamp, shortname,
                               QString::number(item->pid()),
                               QString::number(item->tid()),
                               item->threadName(), item->file(),
                               QString::number(item->line()),
                               item->function(),
                               item->message()));
    }
    else
    {
        line = qPrintable(QString("%1 %2 [%3] %5 %6:%7 (%8) - %9\n")
                          .arg(timestamp, shortname,
                               QString::number(item->pid()),
                               item->threadName(), item->file(),
                               QString::number(item->line()),
                               item->function(),
                               item->message()));
    }
 
    int result = write(m_fd, line.data(), line.size());
 
    if( result == -1 )
    {
        LOG(VB_GENERAL, LOG_ERR,
                 QString("Closed Log output on fd %1 due to errors").arg(m_fd));
        m_opened = false;
        close( m_fd );
        return false;
    }
    return true;
}
 
#ifndef _WIN32
SyslogLogger::SyslogLogger(bool open) :
    LoggerBase(nullptr)
{
    if (open)
    {
        openlog(nullptr, LOG_NDELAY, 0 );
        m_opened = true;
    }
 
    LOG(VB_GENERAL, LOG_INFO, "Added syslogging");
}
 
SyslogLogger::~SyslogLogger()
{
    LOG(VB_GENERAL, LOG_INFO, "Removing syslogging");
    if (m_opened)
        closelog();
}
 
SyslogLogger *SyslogLogger::create(QMutex *mutex, bool open)
{
    auto *logger = qobject_cast<SyslogLogger *>(loggerMap.value("", nullptr));
    if (logger)
        return logger;
 
    // Need to add a new FileLogger
    mutex->unlock();
    // inserts into loggerMap
    logger = new SyslogLogger(open);
    mutex->lock();
 
    return logger;
}
 
 
bool SyslogLogger::logmsg(LoggingItem *item)
{
    if (!m_opened || item->facility() <= 0)
        return false;
 
    char shortname = item->getLevelChar();
    syslog(item->level() | item->facility(), "%s[%d]: %c %s %s:%d (%s) %s",
           qPrintable(item->appName()), item->pid(), shortname,
           qPrintable(item->threadName()), qPrintable(item->file()), item->line(),
           qPrintable(item->function()), qPrintable(item->message()));
 
    return true;
}
 
#if CONFIG_SYSTEMD_JOURNAL
JournalLogger::JournalLogger() :
    LoggerBase(nullptr)
{
    LOG(VB_GENERAL, LOG_INFO, "Added journal logging");
}
 
JournalLogger::~JournalLogger()
{
    LOG(VB_GENERAL, LOG_INFO, "Removing journal logging");
}
 
JournalLogger *JournalLogger::create(QMutex *mutex)
{
    auto *logger = qobject_cast<JournalLogger *>(loggerMap.value("", nullptr));
    if (logger)
        return logger;
 
    // Need to add a new FileLogger
    mutex->unlock();
    // inserts into loggerMap
    logger = new JournalLogger();
    mutex->lock();
 
    return logger;
}
 
 
bool JournalLogger::logmsg(LoggingItem *item)
{
    sd_journal_send(
        "MESSAGE=%s", qUtf8Printable(item->message()),
        "PRIORITY=%d", item->level(),
        "CODE_FILE=%s", qUtf8Printable(item->file()),
        "CODE_LINE=%d", item->line(),
        "CODE_FUNC=%s", qUtf8Printable(item->function()),
        "SYSLOG_IDENTIFIER=%s", qUtf8Printable(item->appName()),
        "SYSLOG_PID=%d", item->pid(),
        "MYTH_THREAD=%s", qUtf8Printable(item->threadName()),
        NULL
        );
    return true;
}
#endif
#endif
 
#ifndef _WIN32
 
void logSigHup(void)
{
    if (!logForwardThread)
        return;
 
    // This will be running in the thread that's used by SignalHandler
    // Emit the signal which is connected to a slot that runs in the actual
    // handling thread.
    emit logForwardThread->incomingSigHup();
}
#endif
 
 
LogForwardThread::LogForwardThread() :
    MThread("LogForward")
{
    moveToThread(qthread());
}
 
LogForwardThread::~LogForwardThread()
{
    stop();
    wait();
}
 
void LogForwardThread::run(void)
{
    RunProlog();
 
    connect(this, &LogForwardThread::incomingSigHup,
            this, &LogForwardThread::handleSigHup,
            Qt::QueuedConnection);
 
    qRegisterMetaType<QList<QByteArray> >("QList<QByteArray>");
 
    while (!m_aborted)
    {
        qApp->processEvents(QEventLoop::AllEvents, 10);
        qApp->sendPostedEvents(nullptr, QEvent::DeferredDelete);
 
        {
            QMutexLocker lock(&gLogItemListMutex);
            if (gLogItemList.isEmpty() &&
                !gLogItemListNotEmpty.wait(lock.mutex(), 90))
            {
                continue;
            }
 
            int processed = 0;
            while (!gLogItemList.isEmpty())
            {
                processed++;
                LoggingItem *item = gLogItemList.takeFirst();
                lock.unlock();
                forwardMessage(item);
                item->DecrRef();
 
                // Force a processEvents every 128 messages so a busy queue
                // doesn't preclude timer notifications, etc.
                if ((processed & 127) == 0)
                {
                    qApp->processEvents(QEventLoop::AllEvents, 10);
                    qApp->sendPostedEvents(nullptr, QEvent::DeferredDelete);
                }
 
                lock.relock();
            }
        }
    }
 
    LoggerList loggers;
 
    {
        QMutexLocker lock(&loggerMapMutex);
        loggers = loggerMap.values();
    }
 
    while (!loggers.isEmpty())
    {
        LoggerBase *logger = loggers.takeFirst();
        delete logger;
    }
 
    RunEpilog();
}
 
 
void LogForwardThread::handleSigHup(void)
{
#ifndef _WIN32
    LOG(VB_GENERAL, LOG_INFO, "SIGHUP received, rolling log files.");
 
    /* SIGHUP was sent.  Close and reopen debug logfiles */
    QMutexLocker locker(&loggerMapMutex);
    QMap<QString, LoggerBase *>::iterator it;
    for (it = loggerMap.begin(); it != loggerMap.end(); ++it)
    {
        it.value()->reopen();
    }
#endif
}
 
void LogForwardThread::forwardMessage(LoggingItem *item)
{
    QMutexLocker lock(&gLoggerListMutex);
    LoggerListItem *logItem = gLoggerList;
 
    if (logItem)
    {
        logItem->m_itemEpoch = nowAsDuration<std::chrono::seconds>();
    }
    else
    {
        QMutexLocker lock2(&loggerMapMutex);
 
        // Need to find or create the loggers
        auto *loggers = new LoggerList;
 
        // FileLogger from logFile
        QString logfile = item->logFile();
        if (!logfile.isEmpty())
        {
            LoggerBase *logger = FileLogger::create(logfile, lock2.mutex());
 
            if (logger && loggers)
                loggers->insert(0, logger);
        }
 
#ifndef _WIN32
        // SyslogLogger from facility
        int facility = item->facility();
        if (facility > 0)
        {
            LoggerBase *logger = SyslogLogger::create(lock2.mutex());
 
            if (logger && loggers)
                loggers->insert(0, logger);
        }
 
#if CONFIG_SYSTEMD_JOURNAL
        // Journal Logger
        if (facility == SYSTEMD_JOURNAL_FACILITY)
        {
            LoggerBase *logger = JournalLogger::create(lock2.mutex());
 
            if (logger && loggers)
                loggers->insert(0, logger);
        }
#endif
#endif
 
        // Add the list of loggers for this client into the map.
        logItem = new LoggerListItem;
        logItem->m_itemEpoch = nowAsDuration<std::chrono::seconds>();
        logItem->m_itemList = loggers;
        gLoggerList = logItem;
    }
 
    // Does this client have an entry in the loggers map, does that
    // entry have a list of loggers, and does that list have anything
    // in it.  I.E. is there anywhere to log this item.
    if (logItem->m_itemList && !logItem->m_itemList->isEmpty())
    {
        // Log this item on each of the loggers.
        for (auto *it : qAsConst(*logItem->m_itemList))
            it->logmsg(item);
    }
}
 
void LogForwardThread::stop(void)
{
    m_aborted = true;
}
 
bool logForwardStart(void)
{
    logForwardThread = new LogForwardThread();
    logForwardThread->start();
 
    usleep(10000);
    return (logForwardThread && logForwardThread->isRunning());
}
 
void logForwardStop(void)
{
    if (!logForwardThread)
        return;
 
    logForwardThread->stop();
    delete logForwardThread;
    logForwardThread = nullptr;
}
 
// Take a logging item and queue it for the logging server thread to
// process.
void logForwardMessage(LoggingItem *item)
{
    QMutexLocker lock(&gLogItemListMutex);
 
    bool wasEmpty = gLogItemList.isEmpty();
    item->IncrRef();
    gLogItemList.append(item);
 
    if (wasEmpty)
        gLogItemListNotEmpty.wakeAll();
}
 
/*
 * vim:ts=4:sw=4:ai:et:si:sts=4
 */