MythTV  master
loggingserver.cpp
Go to the documentation of this file.
1 #include <QtGlobal>
2 #include <QAtomicInt>
3 #include <QMutex>
4 #include <QMutexLocker>
5 #include <QWaitCondition>
6 #include <QList>
7 #include <QQueue>
8 #include <QHash>
9 #include <QCoreApplication>
10 #include <QFileInfo>
11 #include <QStringList>
12 #include <QMap>
13 #include <QSocketNotifier>
14 #include <iostream>
15 
16 #include "mythlogging.h"
17 #include "logging.h"
18 #include "loggingserver.h"
19 #include "mythdb.h"
20 #include "mythcorecontext.h"
21 #include "dbutil.h"
22 #include "exitcodes.h"
23 #include "compat.h"
24 
25 #include <cstdlib>
26 #ifndef _WIN32
27 #include "mythsyslog.h"
28 #if CONFIG_SYSTEMD_JOURNAL
29 #define SD_JOURNAL_SUPPRESS_LOCATION 1 // NOLINT(cppcoreguidelines-macro-usage)
30 #include <systemd/sd-journal.h>
31 #endif
32 #endif
33 #include <cstdarg>
34 #include <cstring>
35 #include <sys/stat.h>
36 #include <sys/types.h>
37 #include <fcntl.h>
38 #include <cstdio>
39 #include <unistd.h>
40 #if HAVE_GETTIMEOFDAY
41 #include <sys/time.h>
42 #endif
43 #include <csignal>
44 
45 // Various ways to get to thread's tid
46 #if defined(__linux__)
47 #include <sys/syscall.h>
48 #elif defined(__FreeBSD__)
49 extern "C" {
50 #include <sys/ucontext.h>
51 #include <sys/thr.h>
52 }
53 #elif defined(Q_OS_DARWIN)
54 #include <mach/mach.h>
55 #endif
56 
57 static QMutex loggerMapMutex;
58 static QMap<QString, LoggerBase *> loggerMap;
59 
61 
62 using LoggerList = QList<LoggerBase *>;
63 
66  std::chrono::seconds m_itemEpoch;
67 };
68 
69 // A list of logging objects that process messages.
70 static QMutex gLoggerListMutex;
71 static LoggerListItem *gLoggerList {nullptr};
72 
73 // This is a FIFO queue containing the incoming messages "sent" from a
74 // client to this server. As each message arrives, it is queued here
75 // for later retrieval by a different thread. This used to be
76 // populated by a thread that received messages from the network, and
77 // drained by a different thread that logged the messages. It is now
78 // populated by the thread that generated the message, and drained by
79 // a different thread that logs the messages.
80 static QMutex gLogItemListMutex;
82 static QWaitCondition gLogItemListNotEmpty;
83 
87 LoggerBase::LoggerBase(const char *string) :
88  m_handle(string)
89 {
90  QMutexLocker locker(&loggerMapMutex);
91  loggerMap.insert(m_handle, this);
92 }
93 
94 
98 {
99  QMutexLocker locker(&loggerMapMutex);
100  loggerMap.remove(m_handle);
101 }
102 
103 
108 {
109  m_fd = open(filename, O_WRONLY|O_CREAT|O_APPEND, 0664);
110  m_opened = (m_fd != -1);
111  LOG(VB_GENERAL, LOG_INFO, QString("Added logging to %1")
112  .arg(filename));
113 }
114 
115 
118 {
119  if( m_opened )
120  {
121  LOG(VB_GENERAL, LOG_INFO, QString("Removed logging to %1")
122  .arg(m_handle));
123  close(m_fd);
124  m_fd = -1;
125  m_opened = false;
126  }
127 }
128 
129 FileLogger *FileLogger::create(const QString& filename, QMutex *mutex)
130 {
131  QByteArray ba = filename.toLocal8Bit();
132  const char *file = ba.constData();
133  auto *logger =
134  qobject_cast<FileLogger *>(loggerMap.value(filename, nullptr));
135 
136  if (logger)
137  return logger;
138 
139  // Need to add a new FileLogger
140  mutex->unlock();
141  // inserts into loggerMap
142  logger = new FileLogger(file);
143  mutex->lock();
144 
145  return logger;
146 }
147 
151 {
152  close(m_fd);
153 
154  m_fd = open(qPrintable(m_handle), O_WRONLY|O_CREAT|O_APPEND, 0664);
155  m_opened = (m_fd != -1);
156  LOG(VB_GENERAL, LOG_INFO, QString("Rolled logging on %1") .arg(m_handle));
157 }
158 
162 {
163  if (!m_opened)
164  return false;
165 
166  QString timestamp = item->getTimestampUs();
167  QChar shortname = item->getLevelChar();
168 
169  std::string line;
170  if( item->tid() )
171  {
172  line = qPrintable(QString("%1 %2 [%3/%4] %5 %6:%7 (%8) - %9\n")
173  .arg(timestamp, shortname,
174  QString::number(item->pid()),
175  QString::number(item->tid()),
176  item->threadName(), item->file(),
177  QString::number(item->line()),
178  item->function(),
179  item->message()));
180  }
181  else
182  {
183  line = qPrintable(QString("%1 %2 [%3] %5 %6:%7 (%8) - %9\n")
184  .arg(timestamp, shortname,
185  QString::number(item->pid()),
186  item->threadName(), item->file(),
187  QString::number(item->line()),
188  item->function(),
189  item->message()));
190  }
191 
192  int result = write(m_fd, line.data(), line.size());
193 
194  if( result == -1 )
195  {
196  LOG(VB_GENERAL, LOG_ERR,
197  QString("Closed Log output on fd %1 due to errors").arg(m_fd));
198  m_opened = false;
199  close( m_fd );
200  return false;
201  }
202  return true;
203 }
204 
205 #ifndef _WIN32
206 SyslogLogger::SyslogLogger(bool open) :
209  LoggerBase(nullptr)
210 {
211  if (open)
212  {
213  openlog(nullptr, LOG_NDELAY, 0 );
214  m_opened = true;
215  }
216 
217  LOG(VB_GENERAL, LOG_INFO, "Added syslogging");
218 }
219 
221 SyslogLogger::~SyslogLogger()
222 {
223  LOG(VB_GENERAL, LOG_INFO, "Removing syslogging");
224  if (m_opened)
225  closelog();
226 }
227 
228 SyslogLogger *SyslogLogger::create(QMutex *mutex, bool open)
229 {
230  auto *logger = qobject_cast<SyslogLogger *>(loggerMap.value("", nullptr));
231  if (logger)
232  return logger;
233 
234  // Need to add a new FileLogger
235  mutex->unlock();
236  // inserts into loggerMap
237  logger = new SyslogLogger(open);
238  mutex->lock();
239 
240  return logger;
241 }
242 
243 
246 bool SyslogLogger::logmsg(LoggingItem *item)
247 {
248  if (!m_opened || item->facility() <= 0)
249  return false;
250 
251  char shortname = item->getLevelChar();
252  syslog(item->level() | item->facility(), "%s[%d]: %c %s %s:%d (%s) %s",
253  qPrintable(item->appName()), item->pid(), shortname,
254  qPrintable(item->threadName()), qPrintable(item->file()), item->line(),
255  qPrintable(item->function()), qPrintable(item->message()));
256 
257  return true;
258 }
259 
260 #if CONFIG_SYSTEMD_JOURNAL
261 JournalLogger::JournalLogger() :
263  LoggerBase(nullptr)
264 {
265  LOG(VB_GENERAL, LOG_INFO, "Added journal logging");
266 }
267 
269 JournalLogger::~JournalLogger()
270 {
271  LOG(VB_GENERAL, LOG_INFO, "Removing journal logging");
272 }
273 
274 JournalLogger *JournalLogger::create(QMutex *mutex)
275 {
276  auto *logger = qobject_cast<JournalLogger *>(loggerMap.value("", nullptr));
277  if (logger)
278  return logger;
279 
280  // Need to add a new FileLogger
281  mutex->unlock();
282  // inserts into loggerMap
283  logger = new JournalLogger();
284  mutex->lock();
285 
286  return logger;
287 }
288 
289 
292 bool JournalLogger::logmsg(LoggingItem *item)
293 {
294  sd_journal_send(
295  "MESSAGE=%s", qUtf8Printable(item->message()),
296  "PRIORITY=%d", item->level(),
297  "CODE_FILE=%s", qUtf8Printable(item->file()),
298  "CODE_LINE=%d", item->line(),
299  "CODE_FUNC=%s", qUtf8Printable(item->function()),
300  "SYSLOG_IDENTIFIER=%s", qUtf8Printable(item->appName()),
301  "SYSLOG_PID=%d", item->pid(),
302  "MYTH_THREAD=%s", qUtf8Printable(item->threadName()),
303  NULL
304  );
305  return true;
306 }
307 #endif
308 #endif
309 
310 #ifndef _WIN32
311 
314 void logSigHup(void)
315 {
316  if (!logForwardThread)
317  return;
318 
319  // This will be running in the thread that's used by SignalHandler
320  // Emit the signal which is connected to a slot that runs in the actual
321  // handling thread.
323 }
324 #endif
325 
326 
329  MThread("LogForward")
330 {
331  moveToThread(qthread());
332 }
333 
336 {
337  stop();
338  wait();
339 }
340 
345 {
346  RunProlog();
347 
348  connect(this, &LogForwardThread::incomingSigHup,
350  Qt::QueuedConnection);
351 
352  qRegisterMetaType<QList<QByteArray> >("QList<QByteArray>");
353 
354  while (!m_aborted)
355  {
356  qApp->processEvents(QEventLoop::AllEvents, 10);
357  qApp->sendPostedEvents(nullptr, QEvent::DeferredDelete);
358 
359  {
360  QMutexLocker lock(&gLogItemListMutex);
361  if (gLogItemList.isEmpty() &&
362  !gLogItemListNotEmpty.wait(lock.mutex(), 90))
363  {
364  continue;
365  }
366 
367  int processed = 0;
368  while (!gLogItemList.isEmpty())
369  {
370  processed++;
371  LoggingItem *item = gLogItemList.takeFirst();
372  lock.unlock();
373  forwardMessage(item);
374  item->DecrRef();
375 
376  // Force a processEvents every 128 messages so a busy queue
377  // doesn't preclude timer notifications, etc.
378  if ((processed & 127) == 0)
379  {
380  qApp->processEvents(QEventLoop::AllEvents, 10);
381  qApp->sendPostedEvents(nullptr, QEvent::DeferredDelete);
382  }
383 
384  lock.relock();
385  }
386  }
387  }
388 
389  LoggerList loggers;
390 
391  {
392  QMutexLocker lock(&loggerMapMutex);
393  loggers = loggerMap.values();
394  }
395 
396  while (!loggers.isEmpty())
397  {
398  LoggerBase *logger = loggers.takeFirst();
399  delete logger;
400  }
401 
402  RunEpilog();
403 }
404 
405 
408 {
409 #ifndef _WIN32
410  LOG(VB_GENERAL, LOG_INFO, "SIGHUP received, rolling log files.");
411 
412  /* SIGHUP was sent. Close and reopen debug logfiles */
413  QMutexLocker locker(&loggerMapMutex);
414  QMap<QString, LoggerBase *>::iterator it;
415  for (it = loggerMap.begin(); it != loggerMap.end(); ++it)
416  {
417  it.value()->reopen();
418  }
419 #endif
420 }
421 
423 {
424  QMutexLocker lock(&gLoggerListMutex);
425  LoggerListItem *logItem = gLoggerList;
426 
427  if (logItem)
428  {
429  logItem->m_itemEpoch = nowAsDuration<std::chrono::seconds>();
430  }
431  else
432  {
433  QMutexLocker lock2(&loggerMapMutex);
434 
435  // Need to find or create the loggers
436  auto *loggers = new LoggerList;
437 
438  // FileLogger from logFile
439  QString logfile = item->logFile();
440  if (!logfile.isEmpty())
441  {
442  LoggerBase *logger = FileLogger::create(logfile, lock2.mutex());
443 
444  if (logger && loggers)
445  loggers->insert(0, logger);
446  }
447 
448 #ifndef _WIN32
449  // SyslogLogger from facility
450  int facility = item->facility();
451  if (facility > 0)
452  {
453  LoggerBase *logger = SyslogLogger::create(lock2.mutex());
454 
455  if (logger && loggers)
456  loggers->insert(0, logger);
457  }
458 
459 #if CONFIG_SYSTEMD_JOURNAL
460  // Journal Logger
461  if (facility == SYSTEMD_JOURNAL_FACILITY)
462  {
463  LoggerBase *logger = JournalLogger::create(lock2.mutex());
464 
465  if (logger && loggers)
466  loggers->insert(0, logger);
467  }
468 #endif
469 #endif
470 
471  // Add the list of loggers for this client into the map.
472  logItem = new LoggerListItem;
473  logItem->m_itemEpoch = nowAsDuration<std::chrono::seconds>();
474  logItem->m_itemList = loggers;
475  gLoggerList = logItem;
476  }
477 
478  // Does this client have an entry in the loggers map, does that
479  // entry have a list of loggers, and does that list have anything
480  // in it. I.E. is there anywhere to log this item.
481  if (logItem->m_itemList && !logItem->m_itemList->isEmpty())
482  {
483  // Log this item on each of the loggers.
484  for (auto *it : qAsConst(*logItem->m_itemList))
485  it->logmsg(item);
486  }
487 }
488 
491 {
492  m_aborted = true;
493 }
494 
495 bool logForwardStart(void)
496 {
499 
500  usleep(10000);
502 }
503 
504 void logForwardStop(void)
505 {
506  if (!logForwardThread)
507  return;
508 
510  delete logForwardThread;
511  logForwardThread = nullptr;
512 }
513 
514 // Take a logging item and queue it for the logging server thread to
515 // process.
517 {
518  QMutexLocker lock(&gLogItemListMutex);
519 
520  bool wasEmpty = gLogItemList.isEmpty();
521  item->IncrRef();
522  gLogItemList.append(item);
523 
524  if (wasEmpty)
525  gLogItemListNotEmpty.wakeAll();
526 }
527 
528 /*
529  * vim:ts=4:sw=4:ai:et:si:sts=4
530  */
gLoggerList
static LoggerListItem * gLoggerList
Definition: loggingserver.cpp:71
FileLogger::m_opened
bool m_opened
true when the logfile is opened
Definition: loggingserver.h:54
logForwardStop
void logForwardStop(void)
Definition: loggingserver.cpp:504
MThread::start
void start(QThread::Priority p=QThread::InheritPriority)
Tell MThread to start running the thread in the near future.
Definition: mthread.cpp:283
LoggingItem::threadName
QString threadName
Definition: logging.h:67
dbutil.h
ReferenceCounter::DecrRef
virtual int DecrRef(void)
Decrements reference count and deletes on 0.
Definition: referencecounter.cpp:125
loggerMap
static QMap< QString, LoggerBase * > loggerMap
Definition: loggingserver.cpp:58
mythdb.h
gLoggerListMutex
static QMutex gLoggerListMutex
Definition: loggingserver.cpp:70
LoggerBase
Base class for the various logging mechanisms.
Definition: loggingserver.h:24
LoggingItem::logFile
QString logFile
Definition: logging.h:69
MThread::wait
bool wait(std::chrono::milliseconds time=std::chrono::milliseconds::max())
Wait for the MThread to exit, with a maximum timeout.
Definition: mthread.cpp:300
FileLogger::logmsg
bool logmsg(LoggingItem *item) override
Process a log message, writing to the logfile.
Definition: loggingserver.cpp:161
logForwardThread
LogForwardThread * logForwardThread
Definition: loggingserver.cpp:60
mythburn.write
def write(text, progress=True)
Definition: mythburn.py:308
LOG
#define LOG(_MASK_, _LEVEL_, _QSTRING_)
Definition: mythlogging.h:39
MThread::RunProlog
void RunProlog(void)
Sets up a thread, call this if you reimplement run().
Definition: mthread.cpp:196
logForwardStart
bool logForwardStart(void)
Definition: loggingserver.cpp:495
logfile
QString logfile
Definition: mythjobqueue.cpp:45
build_compdb.file
file
Definition: build_compdb.py:55
LoggingItem::tid
qlonglong tid
Definition: logging.h:58
LoggerBase::~LoggerBase
~LoggerBase() override
LoggerBase Deconstructor.
Definition: loggingserver.cpp:97
LogForwardThread::m_aborted
bool m_aborted
Flag to abort the thread.
Definition: loggingserver.h:106
LoggingItem::level
int level
Definition: logging.h:62
close
#define close
Definition: compat.h:43
logForwardMessage
void logForwardMessage(LoggingItem *item)
Definition: loggingserver.cpp:516
LoggingItem
The logging items that are generated by LOG() and are sent to the console.
Definition: logging.h:53
LoggingItem::getLevelChar
char getLevelChar(void)
Get the message log level as a single character.
Definition: logging.cpp:206
mythlogging.h
LogForwardThread
The logging thread that forwards received messages to the consuming loggers via ZeroMQ.
Definition: loggingserver.h:95
LoggingItem::pid
int pid
Definition: logging.h:57
gLogItemListNotEmpty
static QWaitCondition gLogItemListNotEmpty
Definition: loggingserver.cpp:82
LogForwardThread::~LogForwardThread
~LogForwardThread() override
LogForwardThread destructor.
Definition: loggingserver.cpp:335
compat.h
LogForwardThread::handleSigHup
static void handleSigHup(void)
SIGHUP handler - reopen all open logfiles for logrollers.
Definition: loggingserver.cpp:407
LogForwardThread::run
void run(void) override
Run the log forwarding thread.
Definition: loggingserver.cpp:344
LoggerBase::m_handle
QString m_handle
semi-opaque handle for identifying instance
Definition: loggingserver.h:39
MThread::qthread
QThread * qthread(void)
Returns the thread, this will always return the same pointer no matter how often you restart the thre...
Definition: mthread.cpp:233
MThread::RunEpilog
void RunEpilog(void)
Cleans up a thread's resources, call this if you reimplement run().
Definition: mthread.cpp:209
LoggerBase::LoggerBase
LoggerBase(const char *string)
LoggerBase Constructor.
Definition: loggingserver.cpp:87
LoggingItem::message
QString message
Definition: logging.h:70
LoggingItem::appName
QString appName
Definition: logging.h:68
FileLogger::m_fd
int m_fd
contains the file descriptor for the logfile
Definition: loggingserver.h:55
LoggingItem::file
QString file
Definition: logging.h:65
LogForwardThread::LogForwardThread
LogForwardThread()
LogForwardThread constructor.
Definition: loggingserver.cpp:328
gLogItemListMutex
static QMutex gLogItemListMutex
Definition: loggingserver.cpp:80
LoggingItem::line
int line
Definition: logging.h:60
LoggerListItem::m_itemList
LoggerList * m_itemList
Definition: loggingserver.cpp:65
LogForwardThread::forwardMessage
static void forwardMessage(LoggingItem *item)
Definition: loggingserver.cpp:422
mythcorecontext.h
FileLogger
File-based logger - used for logfiles and console.
Definition: loggingserver.h:43
gLogItemList
static LoggingItemList gLogItemList
Definition: loggingserver.cpp:81
LogForwardThread::stop
void stop(void)
Stop the thread by setting the abort flag.
Definition: loggingserver.cpp:490
mythsyslog.h
logging.h
FileLogger::~FileLogger
~FileLogger() override
FileLogger deconstructor - close the logfile.
Definition: loggingserver.cpp:117
LoggingItem::getTimestampUs
QString getTimestampUs(const char *format="yyyy-MM-dd HH:mm:ss") const
Definition: logging.cpp:198
logger
static void logger(cdio_log_level_t level, const char *message)
Definition: cddecoder.cpp:35
MThread
This is a wrapper around QThread that does several additional things.
Definition: mthread.h:48
MThread::isRunning
bool isRunning(void) const
Definition: mthread.cpp:263
LoggingItemList
QList< LoggingItem * > LoggingItemList
Definition: loggingserver.h:91
LoggingItem::function
QString function
Definition: logging.h:66
FileLogger::FileLogger
FileLogger(const char *filename)
FileLogger constructor.
Definition: loggingserver.cpp:106
LogForwardThread::incomingSigHup
void incomingSigHup(void)
FileLogger::reopen
void reopen(void) override
Reopen the logfile after a SIGHUP.
Definition: loggingserver.cpp:150
FileLogger::create
static FileLogger * create(const QString &filename, QMutex *mutex)
Definition: loggingserver.cpp:129
LoggingItem::facility
int facility
Definition: logging.h:63
exitcodes.h
loggerMapMutex
static QMutex loggerMapMutex
Definition: loggingserver.cpp:57
LoggerListItem
Definition: loggingserver.cpp:64
ReferenceCounter::IncrRef
virtual int IncrRef(void)
Increments reference count.
Definition: referencecounter.cpp:101
build_compdb.filename
filename
Definition: build_compdb.py:21
loggingserver.h
LoggerListItem::m_itemEpoch
std::chrono::seconds m_itemEpoch
Definition: loggingserver.cpp:66
LoggerList
QList< LoggerBase * > LoggerList
Definition: loggingserver.cpp:62