src/Log.cpp

   1 /*
   2  * Copyright (C) 2007 Mark Pustjens <pustjens@dds.nl>
   3  * Copyright (C) 2010-2015 Petr Pavlu <setup@dagobah.cz>
   4  *
   5  * This file is part of CenterIM.
   6  *
   7  * CenterIM is free software; you can redistribute it and/or modify
   8  * it under the terms of the GNU General Public License as published by
   9  * the Free Software Foundation; either version 2 of the License, or
  10  * (at your option) any later version.
  11  *
  12  * CenterIM is distributed in the hope that it will be useful,
  13  * but WITHOUT ANY WARRANTY; without even the implied warranty of
  14  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  15  * GNU General Public License for more details.
  16  *
  17  * You should have received a copy of the GNU General Public License
  18  * along with this program.  If not, see <http://www.gnu.org/licenses/>.
  19  *
  20  */
  21
  22 #include "Log.h"
  23
  24 #include <cppconsui/HorizontalListBox.h>
  25 #include <cppconsui/Spacer.h>
  26 #include <cstdio>
  27 #include "gettext.h"
  28
  29 Log *Log::my_instance = NULL;
  30
  31 Log *Log::instance()
  32 {
  33   return my_instance;
  34 }
  35
  36 #define WRITE_METHOD(name, level)                                              \
  37   void Log::name(const char *fmt, ...)                                         \
  38   {                                                                            \
  39     va_list args;                                                              \
  40     char *text;                                                                \
  41                                                                                \
  42     if (log_level_cim < level)                                                 \
  43       return; /* we don't want to see this log message */                      \
  44                                                                                \
  45     va_start(args, fmt);                                                       \
  46     text = g_strdup_vprintf(fmt, args);                                        \
  47     va_end(args);                                                              \
  48                                                                                \
  49     write(TYPE_CIM, level, text);                                              \
  50     g_free(text);                                                              \
  51   }
  52
  53 WRITE_METHOD(error, LEVEL_ERROR)
  54 WRITE_METHOD(critical, LEVEL_CRITICAL)
  55 WRITE_METHOD(warning, LEVEL_WARNING)
  56 WRITE_METHOD(message, LEVEL_MESSAGE)
  57 WRITE_METHOD(info, LEVEL_INFO)
  58 WRITE_METHOD(debug, LEVEL_DEBUG)
  59
  60 #undef WRITE_METHOD
  61
  62 Log::LogWindow::LogWindow() : Window(0, 0, 80, 24, NULL, TYPE_NON_FOCUSABLE)
  63 {
  64   setColorScheme("log");
  65
  66   CppConsUI::HorizontalListBox *lbox =
  67     new CppConsUI::HorizontalListBox(AUTOSIZE, AUTOSIZE);
  68   addWidget(*lbox, 1, 1);
  69
  70   lbox->appendWidget(*(new CppConsUI::Spacer(1, AUTOSIZE)));
  71   textview = new CppConsUI::TextView(AUTOSIZE, AUTOSIZE, true);
  72   lbox->appendWidget(*textview);
  73   lbox->appendWidget(*(new CppConsUI::Spacer(1, AUTOSIZE)));
  74
  75   onScreenResized();
  76 }
  77
  78 void Log::LogWindow::onScreenResized()
  79 {
  80   moveResizeRect(CENTERIM->getScreenArea(CenterIM::LOG_AREA));
  81 }
  82
  83 void Log::LogWindow::append(const char *text)
  84 {
  85   textview->append(text);
  86
  87   // shorten the window text
  88   size_t lines_num = textview->getLinesNumber();
  89
  90   if (lines_num > 200) {
  91     // remove 40 extra lines
  92     textview->erase(0, lines_num - 200 + 40);
  93   }
  94 }
  95
  96 Log::LogBufferItem::LogBufferItem(Type type_, Level level_, const char *text_)
  97   : type(type_), level(level_)
  98 {
  99   text = g_strdup(text_);
 100 }
 101
 102 Log::LogBufferItem::~LogBufferItem()
 103 {
 104   g_free(text);
 105 }
 106
 107 Log::Log()
 108   : log_window(NULL), phase2_active(false), logfile(NULL),
 109     log_level_cim(LEVEL_DEBUG), log_level_glib(LEVEL_DEBUG),
 110     log_level_purple(LEVEL_DEBUG)
 111 {
 112 #define REGISTER_G_LOG_HANDLER(name, handler)                                  \
 113   g_log_set_handler((name), (GLogLevelFlags)G_LOG_LEVEL_MASK, (handler), this)
 114
 115   // register the glib log handlers
 116   default_handler = REGISTER_G_LOG_HANDLER(NULL, default_log_handler_);
 117   glib_handler = REGISTER_G_LOG_HANDLER("GLib", glib_log_handler_);
 118   gmodule_handler = REGISTER_G_LOG_HANDLER("GModule", glib_log_handler_);
 119   glib_gobject_handler =
 120     REGISTER_G_LOG_HANDLER("GLib-GObject", glib_log_handler_);
 121   gthread_handler = REGISTER_G_LOG_HANDLER("GThread", glib_log_handler_);
 122 }
 123
 124 Log::~Log()
 125 {
 126   g_log_remove_handler(NULL, default_handler);
 127   g_log_remove_handler("GLib", glib_handler);
 128   g_log_remove_handler("GModule", gmodule_handler);
 129   g_log_remove_handler("GLib-GObject", glib_gobject_handler);
 130   g_log_remove_handler("GThread", gthread_handler);
 131
 132   outputBufferMessages();
 133 }
 134
 135 void Log::init()
 136 {
 137   g_assert(!my_instance);
 138
 139   my_instance = new Log;
 140 }
 141
 142 void Log::finalize()
 143 {
 144   g_assert(my_instance);
 145
 146   delete my_instance;
 147   my_instance = NULL;
 148 }
 149
 150 void Log::initPhase2()
 151 {
 152   /* Phase 2 is called after CppConsUI and libpurple has been initialized.
 153    * Logging to file is part of the phase 2. */
 154   g_assert(!phase2_active);
 155
 156   // init prefs
 157   purple_prefs_add_none(CONF_PREFIX "/log");
 158   purple_prefs_add_bool(CONF_PREFIX "/log/debug", false);
 159   purple_prefs_add_string(CONF_PREFIX "/log/filename", "debug.log");
 160   purple_prefs_add_string(CONF_PREFIX "/log/log_level_cim", "info");
 161   purple_prefs_add_string(CONF_PREFIX "/log/log_level_purple", "critical");
 162   purple_prefs_add_string(CONF_PREFIX "/log/log_level_glib", "warning");
 163
 164   updateCachedPreference(CONF_PREFIX "/log/debug");
 165   updateCachedPreference(CONF_PREFIX "/log/log_level_cim");
 166   updateCachedPreference(CONF_PREFIX "/log/log_level_purple");
 167   updateCachedPreference(CONF_PREFIX "/log/log_level_glib");
 168
 169   // connect callbacks
 170   purple_prefs_connect_callback(
 171     this, CONF_PREFIX "/log", log_pref_change_, this);
 172
 173   // create the log window
 174   g_assert(!log_window);
 175   log_window = new LogWindow;
 176   log_window->show();
 177
 178   // phase 2 is now active
 179   phase2_active = true;
 180
 181   // output buffered messages
 182   for (LogBufferItems::iterator i = log_items.begin(); i != log_items.end();
 183        i++) {
 184     LogBufferItem *item = *i;
 185
 186     // determine if this message should be displayed
 187     Level loglevel = getLogLevel(item->getType());
 188
 189     if (loglevel >= item->getLevel())
 190       write(item->getType(), item->getLevel(), item->getText());
 191
 192     delete item;
 193   }
 194   log_items.clear();
 195 }
 196
 197 void Log::finalizePhase2()
 198 {
 199   /* Phase 2 finalization is done before CppConsUI and libpurple is finalized.
 200    * Note that log levels are unchanged after phase 2 finishes. */
 201   g_assert(phase2_active);
 202
 203   // delete the log window
 204   g_assert(log_window);
 205   delete log_window;
 206   log_window = NULL;
 207
 208   purple_prefs_disconnect_by_handle(this);
 209
 210   // close the log file (if it is opened)
 211   if (logfile)
 212     g_io_channel_unref(logfile);
 213
 214   // done with phase 2
 215   phase2_active = false;
 216 }
 217
 218 void Log::purple_print(
 219   PurpleDebugLevel purplelevel, const char *category, const char *arg_s)
 220 {
 221   Level level = convertPurpleDebugLevel(purplelevel);
 222   if (log_level_purple < level)
 223     return; // we don't want to see this log message
 224
 225   if (!category) {
 226     category = "misc";
 227     warning(_("centerim/log: purple_print() parameter category was "
 228               "not defined."));
 229   }
 230
 231   char *text = g_strdup_printf("libpurple/%s: %s", category, arg_s);
 232   write(TYPE_PURPLE, level, text);
 233   g_free(text);
 234 }
 235
 236 gboolean Log::purple_is_enabled(
 237   PurpleDebugLevel purplelevel, const char * /*category*/)
 238 {
 239   Level level = convertPurpleDebugLevel(purplelevel);
 240
 241   if (log_level_purple < level)
 242     return FALSE;
 243
 244   return TRUE;
 245 }
 246
 247 void Log::default_log_handler(
 248   const char *domain, GLogLevelFlags flags, const char *msg)
 249 {
 250   if (!msg)
 251     return;
 252
 253   Level level = convertGLibDebugLevel(flags);
 254   if (log_level_glib < level)
 255     return; // we don't want to see this log message
 256
 257   char *text = g_strdup_printf("%s: %s", domain ? domain : "g_log", msg);
 258   write(TYPE_GLIB, level, text);
 259   g_free(text);
 260 }
 261
 262 void Log::glib_log_handler(
 263   const char *domain, GLogLevelFlags flags, const char *msg)
 264 {
 265   if (!msg)
 266     return;
 267
 268   Level level = convertGLibDebugLevel(flags);
 269   if (log_level_glib < level)
 270     return; // we don't want to see this log message
 271
 272   char *text = g_strdup_printf("%s: %s", domain ? domain : "g_log", msg);
 273   write(TYPE_GLIB, level, text);
 274   g_free(text);
 275 }
 276
 277 void Log::log_pref_change(
 278   const char *name, PurplePrefType /*type*/, gconstpointer /*val*/)
 279 {
 280   // log/* preference changed
 281   updateCachedPreference(name);
 282 }
 283
 284 void Log::updateCachedPreference(const char *name)
 285 {
 286   if (!strcmp(name, CONF_PREFIX "/log/debug")) {
 287     bool logfile_enabled = purple_prefs_get_bool(name);
 288
 289     if (logfile_enabled && !logfile) {
 290       char *filename = g_build_filename(purple_user_dir(),
 291         purple_prefs_get_string(CONF_PREFIX "/log/filename"), NULL);
 292       GError *err = NULL;
 293
 294       if (!(logfile = g_io_channel_new_file(filename, "a", &err))) {
 295         error(_("centerim/log: Error opening logfile '%s' (%s)."), filename,
 296           err->message);
 297         g_clear_error(&err);
 298       }
 299       g_free(filename);
 300     }
 301     else if (!logfile_enabled && logfile) {
 302       // debug was disabled so close logfile if it's opened
 303       g_io_channel_unref(logfile);
 304       logfile = NULL;
 305     }
 306   }
 307   else if (!strcmp(name, CONF_PREFIX "/log/log_level_cim"))
 308     log_level_cim = stringToLevel(purple_prefs_get_string(name));
 309   else if (!strcmp(name, CONF_PREFIX "/log/log_level_purple"))
 310     log_level_purple = stringToLevel(purple_prefs_get_string(name));
 311   else if (!strcmp(name, CONF_PREFIX "/log/log_level_glib"))
 312     log_level_glib = stringToLevel(purple_prefs_get_string(name));
 313 }
 314
 315 void Log::write(Type type, Level level, const char *text)
 316 {
 317   // if phase 2 is not active buffer the message
 318   if (!phase2_active) {
 319     LogBufferItem *item = new LogBufferItem(type, level, text);
 320     log_items.push_back(item);
 321     return;
 322   }
 323
 324   g_assert(log_window);
 325   log_window->append(text);
 326   writeToFile(text);
 327 }
 328
 329 void Log::writeErrorToWindow(const char *fmt, ...)
 330 {
 331   // can be called only if phase 2 is active
 332   g_assert(phase2_active);
 333   g_assert(log_window);
 334
 335   va_list args;
 336
 337   if (log_level_cim < LEVEL_ERROR)
 338     return; // we don't want to see this log message
 339
 340   va_start(args, fmt);
 341   char *text = g_strdup_vprintf(fmt, args);
 342   va_end(args);
 343
 344   log_window->append(text);
 345   g_free(text);
 346 }
 347
 348 void Log::writeToFile(const char *text)
 349 {
 350   // writing to file is enabled only in phase 2
 351   if (!phase2_active)
 352     return;
 353
 354   if (!text)
 355     return;
 356
 357   GError *err = NULL;
 358
 359   // write text into logfile
 360   if (logfile) {
 361     if (g_io_channel_write_chars(logfile, text, -1, NULL, &err) !=
 362       G_IO_STATUS_NORMAL) {
 363       writeErrorToWindow(
 364         _("centerim/log: Error writing to logfile (%s)."), err->message);
 365       g_clear_error(&err);
 366     }
 367     else {
 368       // if necessary write missing EOL character
 369       size_t len = strlen(text);
 370       if (len && text[len - 1] != '\n') {
 371         // ignore all errors
 372         g_io_channel_write_chars(logfile, "\n", -1, NULL, NULL);
 373       }
 374     }
 375
 376     if (g_io_channel_flush(logfile, &err) != G_IO_STATUS_NORMAL) {
 377       writeErrorToWindow(
 378         _("centerim/log: Error flushing logfile (%s)."), err->message);
 379       g_clear_error(&err);
 380     }
 381   }
 382 }
 383
 384 void Log::outputBufferMessages()
 385 {
 386   // output all buffered messages to stderr
 387   for (LogBufferItems::iterator i = log_items.begin(); i != log_items.end();
 388        i++) {
 389     LogBufferItem *item = *i;
 390
 391     // determine if this message should be displayed
 392     Level loglevel = getLogLevel(item->getType());
 393
 394     if (loglevel >= item->getLevel()) {
 395       const char *text = item->getText();
 396       g_assert(text);
 397
 398       std::fprintf(stderr, text);
 399
 400       // if necessary write missing EOL character
 401       if (text[strlen(text) - 1] != '\n')
 402         std::fprintf(stderr, "\n");
 403     }
 404
 405     delete item;
 406   }
 407   log_items.clear();
 408   std::fflush(stderr);
 409 }
 410
 411 Log::Level Log::convertPurpleDebugLevel(PurpleDebugLevel purplelevel)
 412 {
 413   switch (purplelevel) {
 414   case PURPLE_DEBUG_MISC:
 415     return LEVEL_DEBUG;
 416   case PURPLE_DEBUG_INFO:
 417     return LEVEL_INFO;
 418   case PURPLE_DEBUG_WARNING:
 419     return LEVEL_WARNING;
 420   case PURPLE_DEBUG_ERROR:
 421     return LEVEL_CRITICAL;
 422   case PURPLE_DEBUG_FATAL:
 423     return LEVEL_ERROR;
 424   case PURPLE_DEBUG_ALL:
 425     return LEVEL_ERROR; // use error level so this message is always printed
 426   }
 427
 428   warning(
 429     _("centerim/log: Unknown libpurple logging level '%d'."), purplelevel);
 430   return LEVEL_DEBUG;
 431 }
 432
 433 Log::Level Log::convertGLibDebugLevel(GLogLevelFlags gliblevel)
 434 {
 435   if (gliblevel & G_LOG_LEVEL_DEBUG)
 436     return LEVEL_DEBUG;
 437   if (gliblevel & G_LOG_LEVEL_INFO)
 438     return LEVEL_INFO;
 439   if (gliblevel & G_LOG_LEVEL_MESSAGE)
 440     return LEVEL_MESSAGE;
 441   if (gliblevel & G_LOG_LEVEL_WARNING)
 442     return LEVEL_WARNING;
 443   if (gliblevel & G_LOG_LEVEL_CRITICAL)
 444     return LEVEL_CRITICAL;
 445   if (gliblevel & G_LOG_LEVEL_ERROR)
 446     return LEVEL_ERROR;
 447
 448   warning(_("centerim/log: Unknown GLib logging level '%d'."), gliblevel);
 449   return LEVEL_DEBUG;
 450 }
 451
 452 Log::Level Log::stringToLevel(const char *slevel)
 453 {
 454   if (!g_ascii_strcasecmp(slevel, "none"))
 455     return LEVEL_NONE;
 456   else if (!g_ascii_strcasecmp(slevel, "debug"))
 457     return LEVEL_DEBUG;
 458   else if (!g_ascii_strcasecmp(slevel, "info"))
 459     return LEVEL_INFO;
 460   else if (!g_ascii_strcasecmp(slevel, "message"))
 461     return LEVEL_MESSAGE;
 462   else if (!g_ascii_strcasecmp(slevel, "warning"))
 463     return LEVEL_WARNING;
 464   else if (!g_ascii_strcasecmp(slevel, "critical"))
 465     return LEVEL_CRITICAL;
 466   else if (!g_ascii_strcasecmp(slevel, "error"))
 467     return LEVEL_ERROR;
 468   return LEVEL_NONE;
 469 }
 470
 471 Log::Level Log::getLogLevel(Type type)
 472 {
 473   switch (type) {
 474   case TYPE_CIM:
 475     return log_level_cim;
 476   case TYPE_GLIB:
 477     return log_level_glib;
 478   case TYPE_PURPLE:
 479     return log_level_purple;
 480   default:
 481     g_assert_not_reached();
 482   }
 483 }
 484
 485 /* vim: set tabstop=2 shiftwidth=2 textwidth=80 expandtab : */