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
IcuFormattedString(const base::Time & time,const std::string & format)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
DateAndTimeWithMicroseconds(const base::Time & time)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
TimeWithSeconds(const base::Time & time)56 std::string TimeWithSeconds(const base::Time& time) {
57 return IcuFormattedString(time, "HHmmss");
58 }
59
TimeWithMillieconds(const base::Time & time)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
LogEntry(const std::string & file,int file_line,LogLevel log_level,const std::string & event,const std::string & description)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
ToString(bool show_time,bool show_file,bool show_level,bool show_desc,bool format_html) const116 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
ToDictionary(base::DictionaryValue * output) const143 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
GetAsJSON() const153 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
GetNormalText(bool show_desc) const164 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
GetHtmlText(bool show_desc) const171 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
SendToVLogOrErrorLog() const193 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
ContentEquals(const LogEntry & other) const207 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
GetFormat(const std::string & format_string,bool * show_time,bool * show_file,bool * show_level,bool * show_desc,bool * format_html,bool * format_json)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:
NetworkEventLog()249 NetworkEventLog() {}
~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
entries()259 LogEntryList& entries() { return entries_; }
260
261 private:
262 LogEntryList entries_;
263
264 DISALLOW_COPY_AND_ASSIGN(NetworkEventLog);
265 };
266
AddLogEntry(const LogEntry & entry)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
GetAsString(StringOrder order,const std::string & format,LogLevel max_level,size_t max_events)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
Initialize()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
Shutdown()390 void Shutdown() {
391 delete g_network_event_log;
392 g_network_event_log = NULL;
393 }
394
IsInitialized()395 bool IsInitialized() { return g_network_event_log != NULL; }
396
397 namespace internal {
398
GetMaxLogEntries()399 size_t GetMaxLogEntries() { return g_max_network_event_log_entries; }
400
SetMaxLogEntries(size_t max_entries)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
AddEntry(const char * file,int file_line,LogLevel log_level,const std::string & event,const std::string & description)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
GetAsString(StringOrder order,const std::string & format,LogLevel max_level,size_t max_events)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
ValueAsString(const base::Value & value)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