chromeos/network/network_event_log.cc

   1 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 #include "chromeos/network/network_event_log.h"
   6
   7 #include <cmath>
   8 #include <list>
   9
  10 #include "base/files/file_path.h"
  11 #include "base/i18n/time_formatting.h"
  12 #include "base/json/json_string_value_serializer.h"
  13 #include "base/json/json_writer.h"
  14 #include "base/logging.h"
  15 #include "base/memory/scoped_ptr.h"
  16 #include "base/strings/string_tokenizer.h"
  17 #include "base/strings/stringprintf.h"
  18 #include "base/strings/utf_string_conversions.h"
  19 #include "base/values.h"
  20 #include "net/base/escape.h"
  21 #include "third_party/icu/source/i18n/unicode/datefmt.h"
  22 #include "third_party/icu/source/i18n/unicode/dtptngen.h"
  23 #include "third_party/icu/source/i18n/unicode/smpdtfmt.h"
  24
  25 namespace chromeos {
  26 namespace network_event_log {
  27
  28 namespace {
  29
  30 std::string IcuFormattedString(const base::Time& time,
  31                                const std::string& format) {
  32   UErrorCode status = U_ZERO_ERROR;
  33   scoped_ptr<icu::DateTimePatternGenerator> generator(
  34       icu::DateTimePatternGenerator::createInstance(status));
  35   DCHECK(U_SUCCESS(status));
  36   icu::UnicodeString generated_pattern =
  37       generator->getBestPattern(icu::UnicodeString(format.c_str()), status);
  38   DCHECK(U_SUCCESS(status));
  39   icu::SimpleDateFormat formatter(generated_pattern, status);
  40   DCHECK(U_SUCCESS(status));
  41   icu::UnicodeString formatted;
  42   formatter.format(static_cast<UDate>(time.ToDoubleT() * 1000), formatted);
  43   base::string16 formatted16(formatted.getBuffer(),
  44                              static_cast<size_t>(formatted.length()));
  45   return base::UTF16ToUTF8(formatted16);
  46 }
  47
  48 std::string DateAndTimeWithMicroseconds(const base::Time& time) {
  49   std::string formatted = IcuFormattedString(time, "yyMMddHHmmss");
  50   // icu only supports milliseconds, but sometimes we need microseconds, so
  51   // append '.' + usecs to the end of the formatted string.
  52   int usecs = static_cast<int>(fmod(time.ToDoubleT() * 1000000, 1000000));
  53   return base::StringPrintf("%s.%06d", formatted.c_str(), usecs);
  54 }
  55
  56 std::string TimeWithSeconds(const base::Time& time) {
  57   return IcuFormattedString(time, "HHmmss");
  58 }
  59
  60 std::string TimeWithMillieconds(const base::Time& time) {
  61   std::string formatted = IcuFormattedString(time, "HHmmss");
  62   // icu doesn't support milliseconds combined with other formatting.
  63   int msecs = static_cast<int>(fmod(time.ToDoubleT() * 1000, 1000));
  64   return base::StringPrintf("%s.%03d", formatted.c_str(), msecs);
  65 }
  66
  67 class NetworkEventLog;
  68 NetworkEventLog* g_network_event_log = NULL;
  69 size_t g_max_network_event_log_entries = 4000;
  70 const char* kLogLevelName[] = {"Error", "User", "Event", "Debug"};
  71
  72 struct LogEntry {
  73   LogEntry(const std::string& file,
  74            int file_line,
  75            LogLevel log_level,
  76            const std::string& event,
  77            const std::string& description);
  78
  79   std::string ToString(bool show_time,
  80                        bool show_file,
  81                        bool show_level,
  82                        bool show_desc,
  83                        bool format_html) const;
  84   void ToDictionary(base::DictionaryValue*) const;
  85
  86   std::string GetNormalText(bool show_desc) const;
  87   std::string GetHtmlText(bool show_desc) const;
  88   std::string GetAsJSON() const;
  89
  90   void SendToVLogOrErrorLog() const;
  91
  92   bool ContentEquals(const LogEntry& other) const;
  93
  94   std::string file;
  95   int file_line;
  96   LogLevel log_level;
  97   std::string event;
  98   std::string description;
  99   base::Time time;
 100   int count;
 101 };
 102
 103 LogEntry::LogEntry(const std::string& file,
 104                    int file_line,
 105                    LogLevel log_level,
 106                    const std::string& event,
 107                    const std::string& description)
 108     : file(file),
 109       file_line(file_line),
 110       log_level(log_level),
 111       event(event),
 112       description(description),
 113       time(base::Time::Now()),
 114       count(1) {}
 115
 116 std::string LogEntry::ToString(bool show_time,
 117                                bool show_file,
 118                                bool show_level,
 119                                bool show_desc,
 120                                bool format_html) const {
 121   std::string line;
 122   if (show_time)
 123     line += "[" + TimeWithMillieconds(time) + "] ";
 124   if (show_level) {
 125     const char* kLevelDesc[] = {
 126       "ERROR",
 127       "USER",
 128       "EVENT",
 129       "DEBUG"
 130     };
 131     line += base::StringPrintf("%s: ", kLevelDesc[log_level]);
 132   }
 133   if (show_file) {
 134     std::string filestr = format_html ? net::EscapeForHTML(file) : file;
 135     line += base::StringPrintf("%s:%d ", file.c_str(), file_line);
 136   }
 137   line += format_html ? GetHtmlText(show_desc) : GetNormalText(show_desc);
 138   if (count > 1)
 139     line += base::StringPrintf(" (%d)", count);
 140   return line;
 141 }
 142
 143 void LogEntry::ToDictionary(base::DictionaryValue* output) const {
 144   output->SetString("timestamp", DateAndTimeWithMicroseconds(time));
 145   output->SetString("timestampshort", TimeWithSeconds(time));
 146   output->SetString("level", kLogLevelName[log_level]);
 147   output->SetString("file",
 148                     base::StringPrintf("%s:%d ", file.c_str(), file_line));
 149   output->SetString("event", event);
 150   output->SetString("description", description);
 151 }
 152
 153 std::string LogEntry::GetAsJSON() const {
 154   base::DictionaryValue entry;
 155   ToDictionary(&entry);
 156   std::string json;
 157   JSONStringValueSerializer serializer(&json);
 158   if (!serializer.Serialize(entry)) {
 159     LOG(ERROR) << "Failed to serialize to JSON";
 160   }
 161   return json;
 162 }
 163
 164 std::string LogEntry::GetNormalText(bool show_desc) const {
 165   std::string text = event;
 166   if (show_desc && !description.empty())
 167     text += ": " + description;
 168   return text;
 169 }
 170
 171 std::string LogEntry::GetHtmlText(bool show_desc) const {
 172   std::string text;
 173   if (log_level == LOG_LEVEL_DEBUG)
 174     text += "<i>";
 175   else if (log_level == LOG_LEVEL_USER)
 176     text += "<b>";
 177   else if (log_level == LOG_LEVEL_ERROR)
 178     text += "<b><i>";
 179
 180   text += event;
 181   if (show_desc && !description.empty())
 182     text += ": " + net::EscapeForHTML(description);
 183
 184   if (log_level == LOG_LEVEL_DEBUG)
 185     text += "</i>";
 186   else if (log_level == LOG_LEVEL_USER)
 187     text += "</b>";
 188   else if (log_level == LOG_LEVEL_ERROR)
 189     text += "</i></b>";
 190   return text;
 191 }
 192
 193 void LogEntry::SendToVLogOrErrorLog() const {
 194   const bool show_time = true;
 195   const bool show_file = true;
 196   const bool show_level = false;
 197   const bool show_desc = true;
 198   const bool format_html = false;
 199   std::string output =
 200       ToString(show_time, show_file, show_level, show_desc, format_html);
 201   if (log_level == LOG_LEVEL_ERROR)
 202     LOG(ERROR) << output;
 203   else
 204     VLOG(1) << output;
 205 }
 206
 207 bool LogEntry::ContentEquals(const LogEntry& other) const {
 208   return file == other.file &&
 209          file_line == other.file_line &&
 210          event == other.event &&
 211          description == other.description;
 212 }
 213
 214 void GetFormat(const std::string& format_string,
 215                bool* show_time,
 216                bool* show_file,
 217                bool* show_level,
 218                bool* show_desc,
 219                bool* format_html,
 220                bool* format_json) {
 221   base::StringTokenizer tokens(format_string, ",");
 222   *show_time = false;
 223   *show_file = false;
 224   *show_level = false;
 225   *show_desc = false;
 226   *format_html = false;
 227   *format_json = false;
 228   while (tokens.GetNext()) {
 229     std::string tok(tokens.token());
 230     if (tok == "time")
 231       *show_time = true;
 232     if (tok == "file")
 233       *show_file = true;
 234     if (tok == "level")
 235       *show_level = true;
 236     if (tok == "desc")
 237       *show_desc = true;
 238     if (tok == "html")
 239       *format_html = true;
 240     if (tok == "json")
 241       *format_json = true;
 242   }
 243 }
 244
 245 typedef std::list<LogEntry> LogEntryList;
 246
 247 class NetworkEventLog {
 248  public:
 249   NetworkEventLog() {}
 250   ~NetworkEventLog() {}
 251
 252   void AddLogEntry(const LogEntry& entry);
 253
 254   std::string GetAsString(StringOrder order,
 255                           const std::string& format,
 256                           LogLevel max_level,
 257                           size_t max_events);
 258
 259   LogEntryList& entries() { return entries_; }
 260
 261  private:
 262   LogEntryList entries_;
 263
 264   DISALLOW_COPY_AND_ASSIGN(NetworkEventLog);
 265 };
 266
 267 void NetworkEventLog::AddLogEntry(const LogEntry& entry) {
 268   if (!entries_.empty()) {
 269     LogEntry& last = entries_.back();
 270     if (last.ContentEquals(entry)) {
 271       // Update count and time for identical events to avoid log spam.
 272       ++last.count;
 273       last.log_level = std::min(last.log_level, entry.log_level);
 274       last.time = base::Time::Now();
 275       return;
 276     }
 277   }
 278   if (entries_.size() >= g_max_network_event_log_entries) {
 279     const size_t max_error_entries = g_max_network_event_log_entries / 2;
 280     // Remove the first (oldest) non-error entry, or the oldest entry if more
 281     // than half the entries are errors.
 282     size_t error_count = 0;
 283     for (LogEntryList::iterator iter = entries_.begin(); iter != entries_.end();
 284          ++iter) {
 285       if (iter->log_level != LOG_LEVEL_ERROR) {
 286         entries_.erase(iter);
 287         break;
 288       }
 289       if (++error_count > max_error_entries) {
 290         // Too many error entries, remove the oldest entry.
 291         entries_.pop_front();
 292         break;
 293       }
 294     }
 295   }
 296   entries_.push_back(entry);
 297   entry.SendToVLogOrErrorLog();
 298 }
 299
 300 std::string NetworkEventLog::GetAsString(StringOrder order,
 301                                          const std::string& format,
 302                                          LogLevel max_level,
 303                                          size_t max_events) {
 304   if (entries_.empty())
 305     return "No Log Entries.";
 306
 307   bool show_time, show_file, show_level, show_desc, format_html, format_json;
 308   GetFormat(format,
 309             &show_time,
 310             &show_file,
 311             &show_level,
 312             &show_desc,
 313             &format_html,
 314             &format_json);
 315
 316   std::string result;
 317   base::ListValue log_entries;
 318   if (order == OLDEST_FIRST) {
 319     size_t offset = 0;
 320     if (max_events > 0 && max_events < entries_.size()) {
 321       // Iterate backwards through the list skipping uninteresting entries to
 322       // determine the first entry to include.
 323       size_t shown_events = 0;
 324       size_t num_entries = 0;
 325       for (LogEntryList::const_reverse_iterator riter = entries_.rbegin();
 326            riter != entries_.rend();
 327            ++riter) {
 328         ++num_entries;
 329         if (riter->log_level > max_level)
 330           continue;
 331         if (++shown_events >= max_events)
 332           break;
 333       }
 334       offset = entries_.size() - num_entries;
 335     }
 336     for (LogEntryList::const_iterator iter = entries_.begin();
 337          iter != entries_.end();
 338          ++iter) {
 339       if (offset > 0) {
 340         --offset;
 341         continue;
 342       }
 343       if (iter->log_level > max_level)
 344         continue;
 345       if (format_json) {
 346         log_entries.AppendString((*iter).GetAsJSON());
 347       } else {
 348         result += (*iter).ToString(
 349             show_time, show_file, show_level, show_desc, format_html);
 350         result += "\n";
 351       }
 352     }
 353   } else {
 354     size_t nlines = 0;
 355     // Iterate backwards through the list to show the most recent entries first.
 356     for (LogEntryList::const_reverse_iterator riter = entries_.rbegin();
 357          riter != entries_.rend();
 358          ++riter) {
 359       if (riter->log_level > max_level)
 360         continue;
 361       if (format_json) {
 362         log_entries.AppendString((*riter).GetAsJSON());
 363       } else {
 364         result += (*riter).ToString(
 365             show_time, show_file, show_level, show_desc, format_html);
 366         result += "\n";
 367       }
 368       if (max_events > 0 && ++nlines >= max_events)
 369         break;
 370     }
 371   }
 372   if (format_json) {
 373     JSONStringValueSerializer serializer(&result);
 374     serializer.Serialize(log_entries);
 375   }
 376
 377   return result;
 378 }
 379
 380 }  // namespace
 381
 382 const LogLevel kDefaultLogLevel = LOG_LEVEL_EVENT;
 383
 384 void Initialize() {
 385   if (g_network_event_log)
 386     delete g_network_event_log;  // reset log
 387   g_network_event_log = new NetworkEventLog();
 388 }
 389
 390 void Shutdown() {
 391   delete g_network_event_log;
 392   g_network_event_log = NULL;
 393 }
 394
 395 bool IsInitialized() { return g_network_event_log != NULL; }
 396
 397 namespace internal {
 398
 399 size_t GetMaxLogEntries() { return g_max_network_event_log_entries; }
 400
 401 void SetMaxLogEntries(size_t max_entries) {
 402   g_max_network_event_log_entries = max_entries;
 403   if (!g_network_event_log)
 404     return;
 405   while (g_network_event_log->entries().size() > max_entries)
 406     g_network_event_log->entries().pop_front();
 407 }
 408
 409 void AddEntry(const char* file,
 410               int file_line,
 411               LogLevel log_level,
 412               const std::string& event,
 413               const std::string& description) {
 414   std::string filestr;
 415   if (file)
 416     filestr = base::FilePath(std::string(file)).BaseName().value();
 417   LogEntry entry(filestr, file_line, log_level, event, description);
 418   if (!g_network_event_log) {
 419     entry.SendToVLogOrErrorLog();
 420     return;
 421   }
 422   g_network_event_log->AddLogEntry(entry);
 423 }
 424
 425 }  // namespace internal
 426
 427 std::string GetAsString(StringOrder order,
 428                         const std::string& format,
 429                         LogLevel max_level,
 430                         size_t max_events) {
 431   if (!g_network_event_log)
 432     return "NetworkEventLog not initialized.";
 433   return g_network_event_log->GetAsString(order, format, max_level, max_events);
 434 }
 435
 436 std::string ValueAsString(const base::Value& value) {
 437   std::string vstr;
 438   base::JSONWriter::WriteWithOptions(
 439       &value, base::JSONWriter::OPTIONS_OMIT_BINARY_VALUES, &vstr);
 440   return vstr.empty() ? "''" : vstr;
 441 }
 442
 443 }  // namespace network_event_log
 444 }  // namespace chromeos