network_event_log.cc revision a1401311d1ab56c4ed0a474bd38c108f75cb0cd9 
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
25namespace chromeos {
26namespace network_event_log {
27
28namespace {
29
30std::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
48std::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
56std::string TimeWithSeconds(const base::Time& time) {
57  return IcuFormattedString(time, "HHmmss");
58}
59
60class NetworkEventLog;
61NetworkEventLog* g_network_event_log = NULL;
62size_t g_max_network_event_log_entries = 4000;
63const char* kLogLevelName[] = {"Error", "User", "Event", "Debug"};
64
65struct LogEntry {
66  LogEntry(const std::string& file,
67           int file_line,
68           LogLevel log_level,
69           const std::string& event,
70           const std::string& description);
71
72  std::string ToString(bool show_time,
73                       bool show_file,
74                       bool show_desc,
75                       bool format_html) const;
76  void ToDictionary(base::DictionaryValue*) const;
77
78  std::string GetNormalText(bool show_desc) const;
79  std::string GetHtmlText(bool show_desc) const;
80  std::string GetAsJSON() const;
81
82  void SendToVLogOrErrorLog() const;
83
84  bool ContentEquals(const LogEntry& other) const;
85
86  std::string file;
87  int file_line;
88  LogLevel log_level;
89  std::string event;
90  std::string description;
91  base::Time time;
92  int count;
93};
94
95LogEntry::LogEntry(const std::string& file,
96                   int file_line,
97                   LogLevel log_level,
98                   const std::string& event,
99                   const std::string& description)
100    : file(file),
101      file_line(file_line),
102      log_level(log_level),
103      event(event),
104      description(description),
105      time(base::Time::Now()),
106      count(1) {}
107
108std::string LogEntry::ToString(bool show_time,
109                               bool show_file,
110                               bool show_desc,
111                               bool format_html) const {
112  std::string line;
113  if (show_time)
114    line += "[" + base::UTF16ToUTF8(base::TimeFormatTimeOfDay(time)) + "] ";
115  if (show_file) {
116    std::string filestr = format_html ? net::EscapeForHTML(file) : file;
117    line += base::StringPrintf("%s:%d ", file.c_str(), file_line);
118  }
119  line += format_html ? GetHtmlText(show_desc) : GetNormalText(show_desc);
120  if (count > 1)
121    line += base::StringPrintf(" (%d)", count);
122  return line;
123}
124
125void LogEntry::ToDictionary(base::DictionaryValue* output) const {
126  output->SetString("timestamp", DateAndTimeWithMicroseconds(time));
127  output->SetString("timestampshort", TimeWithSeconds(time));
128  output->SetString("level", kLogLevelName[log_level]);
129  output->SetString("file",
130                    base::StringPrintf("%s:%d ", file.c_str(), file_line));
131  output->SetString("event", event);
132  output->SetString("description", description);
133}
134
135std::string LogEntry::GetAsJSON() const {
136  base::DictionaryValue entry;
137  ToDictionary(&entry);
138  std::string json;
139  JSONStringValueSerializer serializer(&json);
140  if (!serializer.Serialize(entry)) {
141    LOG(ERROR) << "Failed to serialize to JSON";
142  }
143  return json;
144}
145
146std::string LogEntry::GetNormalText(bool show_desc) const {
147  std::string text = event;
148  if (show_desc && !description.empty())
149    text += ": " + description;
150  return text;
151}
152
153std::string LogEntry::GetHtmlText(bool show_desc) const {
154  std::string text;
155  if (log_level == LOG_LEVEL_DEBUG)
156    text += "<i>";
157  else if (log_level == LOG_LEVEL_USER)
158    text += "<b>";
159  else if (log_level == LOG_LEVEL_ERROR)
160    text += "<b><i>";
161
162  text += event;
163  if (show_desc && !description.empty())
164    text += ": " + net::EscapeForHTML(description);
165
166  if (log_level == LOG_LEVEL_DEBUG)
167    text += "</i>";
168  else if (log_level == LOG_LEVEL_USER)
169    text += "</b>";
170  else if (log_level == LOG_LEVEL_ERROR)
171    text += "</i></b>";
172  return text;
173}
174
175void LogEntry::SendToVLogOrErrorLog() const {
176  const bool show_time = true;
177  const bool show_file = true;
178  const bool show_desc = true;
179  const bool format_html = false;
180  std::string output = ToString(show_time, show_file, show_desc, format_html);
181  if (log_level == LOG_LEVEL_ERROR)
182    LOG(ERROR) << output;
183  else
184    VLOG(1) << output;
185}
186
187bool LogEntry::ContentEquals(const LogEntry& other) const {
188  return file == other.file &&
189         file_line == other.file_line &&
190         event == other.event &&
191         description == other.description;
192}
193
194void GetFormat(const std::string& format_string,
195               bool* show_time,
196               bool* show_file,
197               bool* show_desc,
198               bool* format_html,
199               bool* format_json) {
200  base::StringTokenizer tokens(format_string, ",");
201  *show_time = false;
202  *show_file = false;
203  *show_desc = false;
204  *format_html = false;
205  *format_json = false;
206  while (tokens.GetNext()) {
207    std::string tok(tokens.token());
208    if (tok == "time")
209      *show_time = true;
210    if (tok == "file")
211      *show_file = true;
212    if (tok == "desc")
213      *show_desc = true;
214    if (tok == "html")
215      *format_html = true;
216    if (tok == "json")
217      *format_json = true;
218  }
219}
220
221typedef std::list<LogEntry> LogEntryList;
222
223class NetworkEventLog {
224 public:
225  NetworkEventLog() {}
226  ~NetworkEventLog() {}
227
228  void AddLogEntry(const LogEntry& entry);
229
230  std::string GetAsString(StringOrder order,
231                          const std::string& format,
232                          LogLevel max_level,
233                          size_t max_events);
234
235  LogEntryList& entries() { return entries_; }
236
237 private:
238  LogEntryList entries_;
239
240  DISALLOW_COPY_AND_ASSIGN(NetworkEventLog);
241};
242
243void NetworkEventLog::AddLogEntry(const LogEntry& entry) {
244  if (!entries_.empty()) {
245    LogEntry& last = entries_.back();
246    if (last.ContentEquals(entry)) {
247      // Update count and time for identical events to avoid log spam.
248      ++last.count;
249      last.log_level = std::min(last.log_level, entry.log_level);
250      last.time = base::Time::Now();
251      return;
252    }
253  }
254  if (entries_.size() >= g_max_network_event_log_entries) {
255    const size_t max_error_entries = g_max_network_event_log_entries / 2;
256    // Remove the first (oldest) non-error entry, or the oldest entry if more
257    // than half the entries are errors.
258    size_t error_count = 0;
259    for (LogEntryList::iterator iter = entries_.begin(); iter != entries_.end();
260         ++iter) {
261      if (iter->log_level != LOG_LEVEL_ERROR) {
262        entries_.erase(iter);
263        break;
264      }
265      if (++error_count > max_error_entries) {
266        // Too many error entries, remove the oldest entry.
267        entries_.pop_front();
268        break;
269      }
270    }
271  }
272  entries_.push_back(entry);
273  entry.SendToVLogOrErrorLog();
274}
275
276std::string NetworkEventLog::GetAsString(StringOrder order,
277                                         const std::string& format,
278                                         LogLevel max_level,
279                                         size_t max_events) {
280  if (entries_.empty())
281    return "No Log Entries.";
282
283  bool show_time, show_file, show_desc, format_html, format_json;
284  GetFormat(
285      format, &show_time, &show_file, &show_desc, &format_html, &format_json);
286
287  std::string result;
288  base::ListValue log_entries;
289  if (order == OLDEST_FIRST) {
290    size_t offset = 0;
291    if (max_events > 0 && max_events < entries_.size()) {
292      // Iterate backwards through the list skipping uninteresting entries to
293      // determine the first entry to include.
294      size_t shown_events = 0;
295      size_t num_entries = 0;
296      for (LogEntryList::const_reverse_iterator riter = entries_.rbegin();
297           riter != entries_.rend();
298           ++riter) {
299        ++num_entries;
300        if (riter->log_level > max_level)
301          continue;
302        if (++shown_events >= max_events)
303          break;
304      }
305      offset = entries_.size() - num_entries;
306    }
307    for (LogEntryList::const_iterator iter = entries_.begin();
308         iter != entries_.end();
309         ++iter) {
310      if (offset > 0) {
311        --offset;
312        continue;
313      }
314      if (iter->log_level > max_level)
315        continue;
316      if (format_json) {
317        log_entries.AppendString((*iter).GetAsJSON());
318      } else {
319        result +=
320            (*iter).ToString(show_time, show_file, show_desc, format_html);
321        result += "\n";
322      }
323    }
324  } else {
325    size_t nlines = 0;
326    // Iterate backwards through the list to show the most recent entries first.
327    for (LogEntryList::const_reverse_iterator riter = entries_.rbegin();
328         riter != entries_.rend();
329         ++riter) {
330      if (riter->log_level > max_level)
331        continue;
332      if (format_json) {
333        log_entries.AppendString((*riter).GetAsJSON());
334      } else {
335        result +=
336            (*riter).ToString(show_time, show_file, show_desc, format_html);
337        result += "\n";
338      }
339      if (max_events > 0 && ++nlines >= max_events)
340        break;
341    }
342  }
343  if (format_json) {
344    JSONStringValueSerializer serializer(&result);
345    serializer.Serialize(log_entries);
346  }
347
348  return result;
349}
350
351}  // namespace
352
353const LogLevel kDefaultLogLevel = LOG_LEVEL_EVENT;
354
355void Initialize() {
356  if (g_network_event_log)
357    delete g_network_event_log;  // reset log
358  g_network_event_log = new NetworkEventLog();
359}
360
361void Shutdown() {
362  delete g_network_event_log;
363  g_network_event_log = NULL;
364}
365
366bool IsInitialized() { return g_network_event_log != NULL; }
367
368namespace internal {
369
370size_t GetMaxLogEntries() { return g_max_network_event_log_entries; }
371
372void SetMaxLogEntries(size_t max_entries) {
373  g_max_network_event_log_entries = max_entries;
374  if (!g_network_event_log)
375    return;
376  while (g_network_event_log->entries().size() > max_entries)
377    g_network_event_log->entries().pop_front();
378}
379
380void AddEntry(const char* file,
381              int file_line,
382              LogLevel log_level,
383              const std::string& event,
384              const std::string& description) {
385  std::string filestr;
386  if (file)
387    filestr = base::FilePath(std::string(file)).BaseName().value();
388  LogEntry entry(filestr, file_line, log_level, event, description);
389  if (!g_network_event_log) {
390    entry.SendToVLogOrErrorLog();
391    return;
392  }
393  g_network_event_log->AddLogEntry(entry);
394}
395
396}  // namespace internal
397
398std::string GetAsString(StringOrder order,
399                        const std::string& format,
400                        LogLevel max_level,
401                        size_t max_events) {
402  if (!g_network_event_log)
403    return "NetworkEventLog not initialized.";
404  return g_network_event_log->GetAsString(order, format, max_level, max_events);
405}
406
407std::string ValueAsString(const base::Value& value) {
408  std::string vstr;
409  base::JSONWriter::WriteWithOptions(
410      &value, base::JSONWriter::OPTIONS_OMIT_BINARY_VALUES, &vstr);
411  return vstr.empty() ? "''" : vstr;
412}
413
414}  // namespace network_event_log
415}  // namespace chromeos
416