Home | History | Annotate | Download | only in network
      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
    445