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
60std::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
67class NetworkEventLog;
68NetworkEventLog* g_network_event_log = NULL;
69size_t g_max_network_event_log_entries = 4000;
70const char* kLogLevelName[] = {"Error", "User", "Event", "Debug"};
71
72struct 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
103LogEntry::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
116std::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
143void 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
153std::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
164std::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
171std::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
193void 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
207bool 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
214void 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
245typedef std::list<LogEntry> LogEntryList;
246
247class 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
267void 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
300std::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
382const LogLevel kDefaultLogLevel = LOG_LEVEL_EVENT;
383
384void Initialize() {
385  if (g_network_event_log)
386    delete g_network_event_log;  // reset log
387  g_network_event_log = new NetworkEventLog();
388}
389
390void Shutdown() {
391  delete g_network_event_log;
392  g_network_event_log = NULL;
393}
394
395bool IsInitialized() { return g_network_event_log != NULL; }
396
397namespace internal {
398
399size_t GetMaxLogEntries() { return g_max_network_event_log_entries; }
400
401void 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
409void 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
427std::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
436std::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