/// \brief Format and send a log message into the queue. This is called from
/// the LOG() macro. The intention is minimal blocking of the caller.
/// \param mask Verbosity mask of the message (VB_*)
/// \param level Log level of this message (LOG_* - matching syslog levels)
/// \param file Filename of source code logging the message
/// \param line Line number within the source of log message source
/// \param function Function name of the log message source
/// \param fromQString true if this message originated from QString
/// \param format printf format string (when not from QString), log message
/// (when from QString)
/// \param ... printf arguments (when not from QString)
void LogPrintLine( uint64_t mask, LogLevel_t level, const char *file, int line,
const char *function, int fromQString,
const char *format, ... )
{
va_list arguments;
int type = kMessage;
type |= (mask & VB_FLUSH) ? kFlush : 0;
type |= (mask & VB_STDIO) ? kStandardIO : 0;
LoggingItem *item = LoggingItem::create(file, function, line, level,
(LoggingType)type);
if (!item)
return;
char *formatcopy = NULL;
if( fromQString && strchr(format, '%') )
{
QString string(format);
format = strdup(string.replace(logRegExp, "%%").toLocal8Bit()
.constData());
formatcopy = (char *)format;
}
va_start(arguments, format);
vsnprintf(item->m_message, LOGLINE_MAX, format, arguments);
va_end(arguments);
if (formatcopy)
free(formatcopy);
QMutexLocker qLock(&logQueueMutex);
#if defined( _MSC_VER ) && defined( _DEBUG )
OutputDebugStringA( item->m_message );
OutputDebugStringA( "\n" );
#endif
logQueue.enqueue(item);
if (logThread && logThreadFinished && !logThread->isRunning())
{
while (!logQueue.isEmpty())
{
item = logQueue.dequeue();
qLock.unlock();
logThread->handleItem(item);
logThread->logConsole(item);
item->DecrRef();
qLock.relock();
}
}
else if (logThread && !logThreadFinished && (type & kFlush))
{
logThread->flush();
}
}
void DatabaseLogger::receivedMessage(const QList<QByteArray> &msg)
{
// Filter on the clientId
QByteArray clientBa = msg.first();
QString clientId = QString(clientBa.toHex());
{
QMutexLocker locker(&logRevClientMapMutex);
ClientList *clients = logRevClientMap.value(this, NULL);
if (!clients || !clients->contains(clientId))
return;
}
QByteArray json = msg.at(1);
LoggingItem *item = LoggingItem::create(json);
if (!logmsg(item))
item->DecrRef();
}
/// \brief Run the logging thread. This thread reads from the logging queue,
/// and handles distributing the LoggingItems to each logger instance.
/// The thread will not exit until the logging queue is emptied
/// completely, ensuring that all logging is flushed.
void LoggerThread::run(void)
{
RunProlog();
logThreadFinished = false;
LOG(VB_GENERAL, LOG_INFO, "Added logging to the console");
bool dieNow = false;
if (!m_noserver)
{
#ifndef NOLOGSERVER
try
{
if (m_locallogs)
{
logServerWait();
m_zmqContext = logServerThread->getZMQContext();
}
else
{
m_zmqContext = nzmqt::createDefaultContext(NULL);
m_zmqContext->start();
}
if (!m_zmqContext)
{
m_aborted = true;
dieNow = true;
}
else
{
qRegisterMetaType<QList<QByteArray> >("QList<QByteArray>");
m_zmqSocket =
m_zmqContext->createSocket(nzmqt::ZMQSocket::TYP_DEALER, this);
connect(m_zmqSocket,
SIGNAL(messageReceived(const QList<QByteArray>&)),
SLOT(messageReceived(const QList<QByteArray>&)),
Qt::QueuedConnection);
if (m_locallogs)
m_zmqSocket->connectTo("inproc://mylogs");
else
m_zmqSocket->connectTo("tcp://127.0.0.1:35327");
}
}
catch (nzmqt::ZMQException &e)
{
cerr << "Exception during logging socket setup: " << e.what() << endl;
m_aborted = true;
dieNow = true;
}
if (!m_aborted)
{
if (!m_locallogs)
{
m_initialWaiting = true;
pingLogServer();
// wait up to 150ms for mythlogserver to respond
m_initialTimer = new MythSignalingTimer(this,
SLOT(initialTimeout()));
m_initialTimer->start(150);
}
else
LOG(VB_GENERAL, LOG_INFO, "Added logging to mythlogserver locally");
loggingGetTimeStamp(&m_epoch, NULL);
m_heartbeatTimer = new MythSignalingTimer(this, SLOT(checkHeartBeat()));
m_heartbeatTimer->start(1000);
}
#else
logServerWait();
#endif
}
QMutexLocker qLock(&logQueueMutex);
while (!m_aborted || !logQueue.isEmpty())
{
qLock.unlock();
qApp->processEvents(QEventLoop::AllEvents, 10);
qApp->sendPostedEvents(NULL, QEvent::DeferredDelete);
qLock.relock();
if (logQueue.isEmpty())
{
m_waitEmpty->wakeAll();
m_waitNotEmpty->wait(qLock.mutex(), 100);
continue;
}
LoggingItem *item = logQueue.dequeue();
qLock.unlock();
fillItem(item);
handleItem(item);
logConsole(item);
item->DecrRef();
qLock.relock();
}
qLock.unlock();
// This must be before the timer stop below or we deadlock when the timer
// thread tries to deregister, and we wait for it.
logThreadFinished = true;
#ifndef NOLOGSERVER
if (m_initialTimer)
{
m_initialTimer->stop();
delete m_initialTimer;
m_initialTimer = NULL;
}
if (m_heartbeatTimer)
{
m_heartbeatTimer->stop();
delete m_heartbeatTimer;
m_heartbeatTimer = NULL;
}
if (m_zmqSocket)
{
m_zmqSocket->setLinger(0);
m_zmqSocket->close();
}
if (!m_locallogs)
delete m_zmqContext;
#endif
RunEpilog();
if (dieNow)
{
qApp->processEvents();
}
}
/// \brief Start the thread.
void DBLoggerThread::run(void)
{
RunProlog();
// Wait a bit before we start logging to the DB.. If we wait too long,
// then short-running tasks (like mythpreviewgen) will not log to the db
// at all, and that's undesirable.
while (true)
{
if ((m_aborted || (gCoreContext && m_logger->isDatabaseReady())))
break;
QMutexLocker locker(&m_queueMutex);
m_wait->wait(locker.mutex(), 100);
}
if (!m_aborted)
{
// We want the query to be out of scope before the RunEpilog() so
// shutdown occurs correctly as otherwise the connection appears still
// in use, and we get a qWarning on shutdown.
MSqlQuery *query = new MSqlQuery(MSqlQuery::InitCon());
m_logger->prepare(*query);
QMutexLocker qLock(&m_queueMutex);
while (!m_aborted || !m_queue->isEmpty())
{
if (m_queue->isEmpty())
{
m_wait->wait(qLock.mutex(), 100);
continue;
}
LoggingItem *item = m_queue->dequeue();
if (!item)
continue;
if (item->message()[0] != '\0')
{
qLock.unlock();
bool logged = m_logger->logqmsg(*query, item);
qLock.relock();
if (!logged)
{
m_queue->prepend(item);
m_wait->wait(qLock.mutex(), 100);
delete query;
query = new MSqlQuery(MSqlQuery::InitCon());
m_logger->prepare(*query);
continue;
}
}
item->DecrRef();
}
delete query;
}
RunEpilog();
}
void LogForwardThread::forwardMessage(LogMessage *msg)
{
#ifdef DUMP_PACKET
QList<QByteArray>::const_iterator it = msg->begin();
int i = 0;
for (; it != msg->end(); ++it, i++)
{
QByteArray buf = *it;
cout << i << ":\t" << buf.size() << endl << "\t"
<< buf.toHex().constData() << endl << "\t"
<< buf.constData() << endl;
}
#endif
msgsSinceHeartbeat.ref();
// First section is the client id
QByteArray clientBa = msg->first();
QString clientId = QString(clientBa.toHex());
QByteArray json = msg->at(1);
if (json.size() == 0)
{
// This is either a ping response or a first gasp
logClientMapMutex.lock();
LoggerListItem *logItem = logClientMap.value(clientId, NULL);
logClientMapMutex.unlock();
if (!logItem)
{
// Send an initial ping so the client knows we are in the house
emit pingClient(clientId);
}
else
{
// cout << "pong " << clientId.toLocal8Bit().constData() << endl;
loggingGetTimeStamp(&logItem->epoch, NULL);
}
return;
}
QMutexLocker lock(&logClientMapMutex);
LoggerListItem *logItem = logClientMap.value(clientId, NULL);
// cout << "msg " << clientId.toLocal8Bit().constData() << endl;
if (logItem)
{
loggingGetTimeStamp(&logItem->epoch, NULL);
}
else
{
LoggingItem *item = LoggingItem::create(json);
logClientCount.ref();
LOG(VB_FILE, LOG_DEBUG, QString("New Logging Client: ID: %1 (#%2)")
.arg(clientId).arg(logClientCount.fetchAndAddOrdered(0)));
#ifndef NOLOGSERVER
// TODO FIXME This is not thread-safe!
if (logClientCount.fetchAndAddOrdered(0) > 1 && m_shutdownTimer &&
m_shutdownTimer->isActive())
{
LOG(VB_GENERAL, LOG_INFO, "Aborting shutdown timer");
m_shutdownTimer->stop();
}
#endif
QMutexLocker lock2(&loggerMapMutex);
QMutexLocker lock3(&logRevClientMapMutex);
// Need to find or create the loggers
LoggerList *loggers = new LoggerList;
LoggerBase *logger;
// FileLogger from logFile
QString logfile = item->logFile();
logfile.detach();
if (!logfile.isEmpty())
{
logger = FileLogger::create(logfile, lock2.mutex());
ClientList *clients = logRevClientMap.value(logger);
if (clients)
clients->insert(0, clientId);
if (logger && loggers)
loggers->insert(0, logger);
}
#ifndef _WIN32
// SyslogLogger from facility
int facility = item->facility();
#if CONFIG_SYSTEMD_JOURNAL
if ((facility > 0) || (facility == SYSTEMD_JOURNAL_FACILITY))
{
logger = SyslogLogger::create(lock2.mutex(), facility > 0);
#else
if (facility > 0)
{
logger = SyslogLogger::create(lock2.mutex());
#endif
ClientList *clients = logRevClientMap.value(logger);
if (clients)
clients->insert(0, clientId);
if (logger && loggers)
loggers->insert(0, logger);
}
#endif
// DatabaseLogger from table
QString table = item->table();
if (!table.isEmpty())
{
logger = DatabaseLogger::create(table, lock2.mutex());
ClientList *clients = logRevClientMap.value(logger);
if (clients)
clients->insert(0, clientId);
if (logger && loggers)
loggers->insert(0, logger);
}
logItem = new LoggerListItem;
loggingGetTimeStamp(&logItem->epoch, NULL);
logItem->list = loggers;
logClientMap.insert(clientId, logItem);
item->DecrRef();
}
#ifndef NOLOGSERVER
m_zmqPubSock->sendMessage(*msg);
#else
if (logItem && logItem->list && !logItem->list->isEmpty())
{
LoggerList::iterator it = logItem->list->begin();
LoggingItem *item = LoggingItem::create(json);
if (!item)
return;
for (; it != logItem->list->end(); ++it)
{
(*it)->logmsg(item);
}
item->DecrRef();
}
#endif
}
/// \brief Stop the thread by setting the abort flag
void LogForwardThread::stop(void)
{
m_aborted = true;
}