components/device_event_log/device_event_log_impl.cc

   1 // Copyright 2014 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 "components/device_event_log/device_event_log_impl.h"
   6
   7 #include <cmath>
   8 #include <list>
   9 #include <set>
  10
  11 #include "base/bind.h"
  12 #include "base/containers/adapters.h"
  13 #include "base/json/json_string_value_serializer.h"
  14 #include "base/json/json_writer.h"
  15 #include "base/location.h"
  16 #include "base/logging.h"
  17 #include "base/memory/scoped_ptr.h"
  18 #include "base/strings/string_tokenizer.h"
  19 #include "base/strings/string_util.h"
  20 #include "base/strings/stringprintf.h"
  21 #include "base/strings/utf_string_conversions.h"
  22 #include "base/values.h"
  23 #include "net/base/escape.h"
  24
  25 namespace device_event_log {
  26
  27 namespace {
  28
  29 const char* kLogLevelName[] = {"Error", "User", "Event", "Debug"};
  30
  31 const char* kLogTypeNetworkDesc = "Network";
  32 const char* kLogTypePowerDesc = "Power";
  33 const char* kLogTypeLoginDesc = "Login";
  34 const char* kLogTypeUsbDesc = "USB";
  35 const char* kLogTypeHidDesc = "HID";
  36
  37 std::string GetLogTypeString(LogType type) {
  38   switch (type) {
  39     case LOG_TYPE_NETWORK:
  40       return kLogTypeNetworkDesc;
  41     case LOG_TYPE_POWER:
  42       return kLogTypePowerDesc;
  43     case LOG_TYPE_LOGIN:
  44       return kLogTypeLoginDesc;
  45     case LOG_TYPE_USB:
  46       return kLogTypeUsbDesc;
  47     case LOG_TYPE_HID:
  48       return kLogTypeHidDesc;
  49     default:
  50       NOTREACHED();
  51       return "Unknown";
  52   }
  53 }
  54
  55 std::string DateAndTimeWithMicroseconds(const base::Time& time) {
  56   base::Time::Exploded exploded;
  57   time.LocalExplode(&exploded);
  58   // base::Time::Exploded does not include microseconds, but sometimes we need
  59   // microseconds, so append '.' + usecs to the end of the formatted string.
  60   int usecs = static_cast<int>(fmod(time.ToDoubleT() * 1000000, 1000000));
  61   return base::StringPrintf("%04d/%02d/%02d %02d:%02d:%02d.%06d", exploded.year,
  62                             exploded.month, exploded.day_of_month,
  63                             exploded.hour, exploded.minute, exploded.second,
  64                             usecs);
  65 }
  66
  67 std::string TimeWithSeconds(const base::Time& time) {
  68   base::Time::Exploded exploded;
  69   time.LocalExplode(&exploded);
  70   return base::StringPrintf("%02d:%02d:%02d", exploded.hour, exploded.minute,
  71                             exploded.second);
  72 }
  73
  74 std::string TimeWithMillieconds(const base::Time& time) {
  75   base::Time::Exploded exploded;
  76   time.LocalExplode(&exploded);
  77   return base::StringPrintf("%02d:%02d:%02d.%03d", exploded.hour,
  78                             exploded.minute, exploded.second,
  79                             exploded.millisecond);
  80 }
  81
  82 // Defined below for easier review. TODO(stevenjb): Move implementation here.
  83 std::string GetHtmlText(LogLevel log_level, const std::string& event);
  84
  85 std::string LogEntryToString(const DeviceEventLogImpl::LogEntry& log_entry,
  86                              bool show_time,
  87                              bool show_file,
  88                              bool show_type,
  89                              bool show_level,
  90                              bool format_html) {
  91   std::string line;
  92   if (show_time)
  93     line += "[" + TimeWithMillieconds(log_entry.time) + "] ";
  94   if (show_type)
  95     line += GetLogTypeString(log_entry.log_type) + ": ";
  96   if (show_level) {
  97     const char* kLevelDesc[] = {"ERROR", "USER", "EVENT", "DEBUG"};
  98     line += base::StringPrintf("%s: ", kLevelDesc[log_entry.log_level]);
  99   }
 100   if (show_file) {
 101     std::string filestr =
 102         format_html ? net::EscapeForHTML(log_entry.file) : log_entry.file;
 103     line += base::StringPrintf("%s:%d ", log_entry.file.c_str(),
 104                                log_entry.file_line);
 105   }
 106   line += format_html ? GetHtmlText(log_entry.log_level, log_entry.event)
 107                       : log_entry.event;
 108   if (log_entry.count > 1)
 109     line += base::StringPrintf(" (%d)", log_entry.count);
 110   return line;
 111 }
 112
 113 void LogEntryToDictionary(const DeviceEventLogImpl::LogEntry& log_entry,
 114                           base::DictionaryValue* output) {
 115   output->SetString("timestamp", DateAndTimeWithMicroseconds(log_entry.time));
 116   output->SetString("timestampshort", TimeWithSeconds(log_entry.time));
 117   output->SetString("level", kLogLevelName[log_entry.log_level]);
 118   output->SetString("type", GetLogTypeString(log_entry.log_type));
 119   output->SetString("file", base::StringPrintf("%s:%d ", log_entry.file.c_str(),
 120                                                log_entry.file_line));
 121   output->SetString("event", log_entry.event);
 122 }
 123
 124 std::string LogEntryAsJSON(const DeviceEventLogImpl::LogEntry& log_entry) {
 125   base::DictionaryValue entry_dict;
 126   LogEntryToDictionary(log_entry, &entry_dict);
 127   std::string json;
 128   JSONStringValueSerializer serializer(&json);
 129   if (!serializer.Serialize(entry_dict)) {
 130     LOG(ERROR) << "Failed to serialize to JSON";
 131   }
 132   return json;
 133 }
 134
 135 std::string GetHtmlText(LogLevel log_level, const std::string& event) {
 136   std::string text;
 137   if (log_level == LOG_LEVEL_DEBUG)
 138     text += "<i>";
 139   else if (log_level == LOG_LEVEL_USER)
 140     text += "<b>";
 141   else if (log_level == LOG_LEVEL_ERROR)
 142     text += "<b><i>";
 143
 144   text += net::EscapeForHTML(event);
 145
 146   if (log_level == LOG_LEVEL_DEBUG)
 147     text += "</i>";
 148   else if (log_level == LOG_LEVEL_USER)
 149     text += "</b>";
 150   else if (log_level == LOG_LEVEL_ERROR)
 151     text += "</i></b>";
 152   return text;
 153 }
 154
 155 void SendLogEntryToVLogOrErrorLog(
 156     const DeviceEventLogImpl::LogEntry& log_entry) {
 157   if (log_entry.log_level != LOG_LEVEL_ERROR && !VLOG_IS_ON(1))
 158     return;
 159   const bool show_time = true;
 160   const bool show_file = true;
 161   const bool show_type = true;
 162   const bool show_level = log_entry.log_level != LOG_LEVEL_ERROR;
 163   const bool format_html = false;
 164   std::string output = LogEntryToString(log_entry, show_time, show_file,
 165                                         show_type, show_level, format_html);
 166   if (log_entry.log_level == LOG_LEVEL_ERROR)
 167     LOG(ERROR) << output;
 168   else
 169     VLOG(1) << output;
 170 }
 171
 172 bool LogEntryMatches(const DeviceEventLogImpl::LogEntry& first,
 173                      const DeviceEventLogImpl::LogEntry& second) {
 174   return first.file == second.file && first.file_line == second.file_line &&
 175          first.log_level == second.log_level &&
 176          first.log_type == second.log_type && first.event == second.event;
 177 }
 178
 179 bool LogEntryMatchesTypes(const DeviceEventLogImpl::LogEntry& entry,
 180                           const std::set<LogType>& include_types,
 181                           const std::set<LogType>& exclude_types) {
 182   if (include_types.empty() && exclude_types.empty())
 183     return true;
 184   if (!include_types.empty() && include_types.count(entry.log_type))
 185     return true;
 186   if (!exclude_types.empty() && !exclude_types.count(entry.log_type))
 187     return true;
 188   return false;
 189 }
 190
 191 void GetFormat(const std::string& format_string,
 192                bool* show_time,
 193                bool* show_file,
 194                bool* show_type,
 195                bool* show_level,
 196                bool* format_html,
 197                bool* format_json) {
 198   base::StringTokenizer tokens(format_string, ",");
 199   *show_time = false;
 200   *show_file = false;
 201   *show_type = false;
 202   *show_level = false;
 203   *format_html = false;
 204   *format_json = false;
 205   while (tokens.GetNext()) {
 206     std::string tok(tokens.token());
 207     if (tok == "time")
 208       *show_time = true;
 209     if (tok == "file")
 210       *show_file = true;
 211     if (tok == "type")
 212       *show_type = true;
 213     if (tok == "level")
 214       *show_level = true;
 215     if (tok == "html")
 216       *format_html = true;
 217     if (tok == "json")
 218       *format_json = true;
 219   }
 220 }
 221
 222 LogType LogTypeFromString(const std::string& desc) {
 223   std::string desc_lc = base::ToLowerASCII(desc);
 224   if (desc_lc == "network")
 225     return LOG_TYPE_NETWORK;
 226   if (desc_lc == "power")
 227     return LOG_TYPE_POWER;
 228   if (desc_lc == "login")
 229     return LOG_TYPE_LOGIN;
 230   NOTREACHED() << "Unrecogized LogType: " << desc;
 231   return LOG_TYPE_UNKNOWN;
 232 }
 233
 234 void GetLogTypes(const std::string& types,
 235                  std::set<LogType>* include_types,
 236                  std::set<LogType>* exclude_types) {
 237   base::StringTokenizer tokens(types, ",");
 238   while (tokens.GetNext()) {
 239     std::string tok(tokens.token());
 240     if (tok.substr(0, 4) == "non-") {
 241       LogType type = LogTypeFromString(tok.substr(4));
 242       if (type != LOG_TYPE_UNKNOWN)
 243         exclude_types->insert(type);
 244     } else {
 245       LogType type = LogTypeFromString(tok);
 246       if (type != LOG_TYPE_UNKNOWN)
 247         include_types->insert(type);
 248     }
 249   }
 250 }
 251
 252 // Update count and time for identical events to avoid log spam.
 253 void IncreaseLogEntryCount(const DeviceEventLogImpl::LogEntry& new_entry,
 254                            DeviceEventLogImpl::LogEntry* cur_entry) {
 255   ++cur_entry->count;
 256   cur_entry->log_level = std::min(cur_entry->log_level, new_entry.log_level);
 257   cur_entry->time = base::Time::Now();
 258 }
 259
 260 }  // namespace
 261
 262 // static
 263 void DeviceEventLogImpl::SendToVLogOrErrorLog(const char* file,
 264                                               int file_line,
 265                                               LogType log_type,
 266                                               LogLevel log_level,
 267                                               const std::string& event) {
 268   LogEntry entry(file, file_line, log_type, log_level, event);
 269   SendLogEntryToVLogOrErrorLog(entry);
 270 }
 271
 272 DeviceEventLogImpl::DeviceEventLogImpl(
 273     scoped_refptr<base::SingleThreadTaskRunner> task_runner,
 274     size_t max_entries)
 275     : task_runner_(task_runner),
 276       max_entries_(max_entries),
 277       weak_ptr_factory_(this) {
 278   DCHECK(task_runner_);
 279 }
 280
 281 DeviceEventLogImpl::~DeviceEventLogImpl() {
 282 }
 283
 284 void DeviceEventLogImpl::AddEntry(const char* file,
 285                                   int file_line,
 286                                   LogType log_type,
 287                                   LogLevel log_level,
 288                                   const std::string& event) {
 289   LogEntry entry(file, file_line, log_type, log_level, event);
 290   if (!task_runner_->RunsTasksOnCurrentThread()) {
 291     task_runner_->PostTask(FROM_HERE,
 292                            base::Bind(&DeviceEventLogImpl::AddLogEntry,
 293                                       weak_ptr_factory_.GetWeakPtr(), entry));
 294     return;
 295   }
 296   AddLogEntry(entry);
 297 }
 298
 299 void DeviceEventLogImpl::AddLogEntry(const LogEntry& entry) {
 300   DCHECK(task_runner_->RunsTasksOnCurrentThread());
 301   if (!entries_.empty()) {
 302     LogEntry& last = entries_.back();
 303     if (LogEntryMatches(last, entry)) {
 304       IncreaseLogEntryCount(entry, &last);
 305       return;
 306     }
 307   }
 308   if (entries_.size() >= max_entries_)
 309     RemoveEntry();
 310   entries_.push_back(entry);
 311   SendLogEntryToVLogOrErrorLog(entry);
 312 }
 313
 314 void DeviceEventLogImpl::RemoveEntry() {
 315   const size_t max_error_entries = max_entries_ / 2;
 316   DCHECK(max_error_entries < entries_.size());
 317   // Remove the first (oldest) non-error entry, or the oldest entry if more
 318   // than half the entries are errors.
 319   size_t error_count = 0;
 320   for (LogEntryList::iterator iter = entries_.begin(); iter != entries_.end();
 321        ++iter) {
 322     if (iter->log_level != LOG_LEVEL_ERROR) {
 323       entries_.erase(iter);
 324       return;
 325     }
 326     if (++error_count > max_error_entries)
 327       break;
 328   }
 329   // Too many error entries, remove the oldest entry.
 330   entries_.pop_front();
 331 }
 332
 333 std::string DeviceEventLogImpl::GetAsString(StringOrder order,
 334                                             const std::string& format,
 335                                             const std::string& types,
 336                                             LogLevel max_level,
 337                                             size_t max_events) {
 338   DCHECK(task_runner_->RunsTasksOnCurrentThread());
 339   if (entries_.empty())
 340     return "No Log Entries.";
 341
 342   bool show_time, show_file, show_type, show_level, format_html, format_json;
 343   GetFormat(format, &show_time, &show_file, &show_type, &show_level,
 344             &format_html, &format_json);
 345
 346   std::set<LogType> include_types, exclude_types;
 347   GetLogTypes(types, &include_types, &exclude_types);
 348
 349   std::string result;
 350   base::ListValue log_entries;
 351   if (order == OLDEST_FIRST) {
 352     size_t offset = 0;
 353     if (max_events > 0 && max_events < entries_.size()) {
 354       // Iterate backwards through the list skipping uninteresting entries to
 355       // determine the first entry to include.
 356       size_t shown_events = 0;
 357       size_t num_entries = 0;
 358       for (const LogEntry& entry : base::Reversed(entries_)) {
 359         ++num_entries;
 360         if (!LogEntryMatchesTypes(entry, include_types, exclude_types))
 361           continue;
 362         if (entry.log_level > max_level)
 363           continue;
 364         if (++shown_events >= max_events)
 365           break;
 366       }
 367       offset = entries_.size() - num_entries;
 368     }
 369     for (const LogEntry& entry : entries_) {
 370       if (offset > 0) {
 371         --offset;
 372         continue;
 373       }
 374       if (!LogEntryMatchesTypes(entry, include_types, exclude_types))
 375         continue;
 376       if (entry.log_level > max_level)
 377         continue;
 378       if (format_json) {
 379         log_entries.AppendString(LogEntryAsJSON(entry));
 380       } else {
 381         result += LogEntryToString(entry, show_time, show_file, show_type,
 382                                    show_level, format_html);
 383         result += "\n";
 384       }
 385     }
 386   } else {
 387     size_t nlines = 0;
 388     // Iterate backwards through the list to show the most recent entries first.
 389     for (const LogEntry& entry : base::Reversed(entries_)) {
 390       if (!LogEntryMatchesTypes(entry, include_types, exclude_types))
 391         continue;
 392       if (entry.log_level > max_level)
 393         continue;
 394       if (format_json) {
 395         log_entries.AppendString(LogEntryAsJSON(entry));
 396       } else {
 397         result += LogEntryToString(entry, show_time, show_file, show_type,
 398                                    show_level, format_html);
 399         result += "\n";
 400       }
 401       if (max_events > 0 && ++nlines >= max_events)
 402         break;
 403     }
 404   }
 405   if (format_json) {
 406     JSONStringValueSerializer serializer(&result);
 407     serializer.Serialize(log_entries);
 408   }
 409
 410   return result;
 411 }
 412
 413 DeviceEventLogImpl::LogEntry::LogEntry(const char* filedesc,
 414                                        int file_line,
 415                                        LogType log_type,
 416                                        LogLevel log_level,
 417                                        const std::string& event)
 418     : file_line(file_line),
 419       log_type(log_type),
 420       log_level(log_level),
 421       event(event),
 422       time(base::Time::Now()),
 423       count(1) {
 424   if (filedesc) {
 425     file = filedesc;
 426     size_t last_slash_pos = file.find_last_of("\\/");
 427     if (last_slash_pos != std::string::npos) {
 428       file.erase(0, last_slash_pos + 1);
 429     }
 430   }
 431 }
 432
 433 }  // namespace device_event_log