123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521 |
- // Copyright 2014 The Chromium Authors. All rights reserved.
- // Use of this source code is governed by a BSD-style license that can be
- // found in the LICENSE file.
- #include "components/device_event_log/device_event_log_impl.h"
- #include <cmath>
- #include <list>
- #include <set>
- #include "base/bind.h"
- #include "base/containers/adapters.h"
- #include "base/json/json_string_value_serializer.h"
- #include "base/json/json_writer.h"
- #include "base/location.h"
- #include "base/logging.h"
- #include "base/process/process_handle.h"
- #include "base/strings/string_tokenizer.h"
- #include "base/strings/string_util.h"
- #include "base/strings/stringprintf.h"
- #include "base/strings/utf_string_conversions.h"
- #include "base/values.h"
- #include "build/build_config.h"
- namespace device_event_log {
- namespace {
- const char* const kLogLevelName[] = {"Error", "User", "Event", "Debug"};
- const char kLogTypeNetworkDesc[] = "Network";
- const char kLogTypePowerDesc[] = "Power";
- const char kLogTypeLoginDesc[] = "Login";
- const char kLogTypeBluetoothDesc[] = "Bluetooth";
- const char kLogTypeUsbDesc[] = "USB";
- const char kLogTypeHidDesc[] = "HID";
- const char kLogTypeMemoryDesc[] = "Memory";
- const char kLogTypePrinterDesc[] = "Printer";
- const char kLogTypeFidoDesc[] = "FIDO";
- const char kLogTypeSerialDesc[] = "Serial";
- const char kLogTypeCameraDesc[] = "Camera";
- enum class ShowTime {
- kNone,
- kTimeWithMs,
- kUnix,
- };
- std::string GetLogTypeString(LogType type) {
- switch (type) {
- case LOG_TYPE_NETWORK:
- return kLogTypeNetworkDesc;
- case LOG_TYPE_POWER:
- return kLogTypePowerDesc;
- case LOG_TYPE_LOGIN:
- return kLogTypeLoginDesc;
- case LOG_TYPE_BLUETOOTH:
- return kLogTypeBluetoothDesc;
- case LOG_TYPE_USB:
- return kLogTypeUsbDesc;
- case LOG_TYPE_HID:
- return kLogTypeHidDesc;
- case LOG_TYPE_MEMORY:
- return kLogTypeMemoryDesc;
- case LOG_TYPE_PRINTER:
- return kLogTypePrinterDesc;
- case LOG_TYPE_FIDO:
- return kLogTypeFidoDesc;
- case LOG_TYPE_SERIAL:
- return kLogTypeSerialDesc;
- case LOG_TYPE_CAMERA:
- return kLogTypeCameraDesc;
- case LOG_TYPE_UNKNOWN:
- break;
- }
- NOTREACHED();
- return "Unknown";
- }
- LogType GetLogTypeFromString(base::StringPiece desc) {
- std::string desc_lc = base::ToLowerASCII(desc);
- for (int i = 0; i < LOG_TYPE_UNKNOWN; ++i) {
- auto type = static_cast<LogType>(i);
- std::string log_desc_lc = base::ToLowerASCII(GetLogTypeString(type));
- if (desc_lc == log_desc_lc)
- return type;
- }
- NOTREACHED() << "Unrecogized LogType: " << desc;
- return LOG_TYPE_UNKNOWN;
- }
- std::string DateAndTimeWithMicroseconds(const base::Time& time) {
- base::Time::Exploded exploded;
- time.LocalExplode(&exploded);
- // base::Time::Exploded does not include microseconds, but sometimes we need
- // microseconds, so append '.' + usecs to the end of the formatted string.
- int usecs = static_cast<int>(fmod(time.ToDoubleT() * 1000000, 1000000));
- return base::StringPrintf("%04d/%02d/%02d %02d:%02d:%02d.%06d", exploded.year,
- exploded.month, exploded.day_of_month,
- exploded.hour, exploded.minute, exploded.second,
- usecs);
- }
- std::string TimeWithSeconds(const base::Time& time) {
- base::Time::Exploded exploded;
- time.LocalExplode(&exploded);
- return base::StringPrintf("%02d:%02d:%02d", exploded.hour, exploded.minute,
- exploded.second);
- }
- std::string TimeWithMillieconds(const base::Time& time) {
- base::Time::Exploded exploded;
- time.LocalExplode(&exploded);
- return base::StringPrintf("%02d:%02d:%02d.%03d", exploded.hour,
- exploded.minute, exploded.second,
- exploded.millisecond);
- }
- #if BUILDFLAG(IS_POSIX)
- std::string UnixTime(const base::Time& time) {
- base::Time::Exploded utc_exploded, exploded;
- time.UTCExplode(&utc_exploded);
- time.LocalExplode(&exploded);
- // Note: |timezone_hours| is only used to display the correct timezone UTC
- // offset (which alas is not conveniently provided in Time::Exploded).
- // Thus, we don't have to account for any date shift, it is already considered
- // in |exploded| (i.e. exploded.day may not match utc_exploded.day).
- int timezone_hours = exploded.hour - utc_exploded.hour;
- if (timezone_hours >= 12)
- timezone_hours = 24 - timezone_hours;
- else if (timezone_hours <= -12)
- timezone_hours = 24 + timezone_hours;
- char sign = timezone_hours > 0 ? '+' : '-';
- // See note in DateAndTimeWithMicroseconds.
- int usecs = static_cast<int>(fmod(time.ToDoubleT() * 1000000, 1000000));
- // This format is consistent with the date/time format in /var/log/messages
- // and /var/log/net.log, e.g: 2020-01-23T01:23:45.678901-07:00.
- // Note: %+02d does not respect the '0', resulting in e.g. +7:00.
- return base::StringPrintf(
- "%04d-%02d-%02dT%02d:%02d:%02d.%06d%c%02d:00", exploded.year,
- exploded.month, exploded.day_of_month, exploded.hour, exploded.minute,
- exploded.second, usecs, sign, std::abs(timezone_hours));
- }
- #endif
- std::string LogEntryToString(const DeviceEventLogImpl::LogEntry& log_entry,
- ShowTime show_time,
- bool show_file,
- bool show_type,
- bool show_level) {
- std::string line;
- if (show_time == ShowTime::kTimeWithMs)
- line += "[" + TimeWithMillieconds(log_entry.time) + "] ";
- #if BUILDFLAG(IS_POSIX)
- if (show_time == ShowTime::kUnix)
- line += UnixTime(log_entry.time) + " ";
- #endif
- if (show_type)
- line += GetLogTypeString(log_entry.log_type) + ": ";
- if (show_level) {
- const char* kLevelDesc[] = {"ERROR", "USER", "EVENT", "DEBUG"};
- line += std::string(kLevelDesc[log_entry.log_level]);
- #if BUILDFLAG(IS_POSIX)
- if (show_time == ShowTime::kUnix) {
- // Format the level consistently with /var/log/messages.
- line += base::StringPrintf(" chrome[%d]", base::GetCurrentProcId());
- }
- #endif
- line += ": ";
- }
- if (show_file) {
- line += base::StringPrintf("%s:%d ", log_entry.file.c_str(),
- log_entry.file_line);
- }
- line += log_entry.event;
- if (log_entry.count > 1)
- line += base::StringPrintf(" (%d)", log_entry.count);
- return line;
- }
- void LogEntryToDictionary(const DeviceEventLogImpl::LogEntry& log_entry,
- base::DictionaryValue* output) {
- output->SetString("timestamp", DateAndTimeWithMicroseconds(log_entry.time));
- output->SetString("timestampshort", TimeWithSeconds(log_entry.time));
- output->SetString("level", kLogLevelName[log_entry.log_level]);
- output->SetString("type", GetLogTypeString(log_entry.log_type));
- output->SetString("file", base::StringPrintf("%s:%d ", log_entry.file.c_str(),
- log_entry.file_line));
- output->SetString("event", log_entry.event);
- }
- std::string LogEntryAsJSON(const DeviceEventLogImpl::LogEntry& log_entry) {
- base::DictionaryValue entry_dict;
- LogEntryToDictionary(log_entry, &entry_dict);
- std::string json;
- JSONStringValueSerializer serializer(&json);
- if (!serializer.Serialize(entry_dict)) {
- LOG(ERROR) << "Failed to serialize to JSON";
- }
- return json;
- }
- void SendLogEntryToVLogOrErrorLog(
- const DeviceEventLogImpl::LogEntry& log_entry) {
- if (log_entry.log_level != LOG_LEVEL_ERROR && !VLOG_IS_ON(1))
- return;
- const ShowTime show_time = ShowTime::kTimeWithMs;
- const bool show_file = true;
- const bool show_type = true;
- const bool show_level = log_entry.log_level != LOG_LEVEL_ERROR;
- std::string output =
- LogEntryToString(log_entry, show_time, show_file, show_type, show_level);
- if (log_entry.log_level == LOG_LEVEL_ERROR)
- LOG(ERROR) << output;
- else
- VLOG(1) << output;
- }
- bool LogEntryMatches(const DeviceEventLogImpl::LogEntry& first,
- const DeviceEventLogImpl::LogEntry& second) {
- return first.file == second.file && first.file_line == second.file_line &&
- first.log_level == second.log_level &&
- first.log_type == second.log_type && first.event == second.event;
- }
- bool LogEntryMatchesTypes(const DeviceEventLogImpl::LogEntry& entry,
- const std::set<LogType>& include_types,
- const std::set<LogType>& exclude_types) {
- if (include_types.empty() && exclude_types.empty())
- return true;
- if (!include_types.empty() && include_types.count(entry.log_type))
- return true;
- if (!exclude_types.empty() && !exclude_types.count(entry.log_type))
- return true;
- return false;
- }
- void GetFormat(const std::string& format_string,
- ShowTime* show_time,
- bool* show_file,
- bool* show_type,
- bool* show_level,
- bool* format_json) {
- base::StringTokenizer tokens(format_string, ",");
- *show_time = ShowTime::kNone;
- *show_file = false;
- *show_type = false;
- *show_level = false;
- *format_json = false;
- while (tokens.GetNext()) {
- base::StringPiece tok = tokens.token_piece();
- if (tok == "time") {
- *show_time = ShowTime::kTimeWithMs;
- } else if (tok == "unixtime") {
- #if BUILDFLAG(IS_POSIX)
- *show_time = ShowTime::kUnix;
- #else
- *show_time = ShowTime::kTimeWithMs;
- #endif
- } else if (tok == "file") {
- *show_file = true;
- } else if (tok == "type") {
- *show_type = true;
- } else if (tok == "level") {
- *show_level = true;
- } else if (tok == "json") {
- *format_json = true;
- }
- }
- }
- void GetLogTypes(const std::string& types,
- std::set<LogType>* include_types,
- std::set<LogType>* exclude_types) {
- base::StringTokenizer tokens(types, ",");
- while (tokens.GetNext()) {
- base::StringPiece tok = tokens.token_piece();
- if (base::StartsWith(tok, "non-")) {
- LogType type = GetLogTypeFromString(tok.substr(4));
- if (type != LOG_TYPE_UNKNOWN)
- exclude_types->insert(type);
- } else {
- LogType type = GetLogTypeFromString(tok);
- if (type != LOG_TYPE_UNKNOWN)
- include_types->insert(type);
- }
- }
- }
- // Update count and time for identical events to avoid log spam.
- void IncreaseLogEntryCount(const DeviceEventLogImpl::LogEntry& new_entry,
- DeviceEventLogImpl::LogEntry* cur_entry) {
- ++cur_entry->count;
- cur_entry->log_level = std::min(cur_entry->log_level, new_entry.log_level);
- cur_entry->time = base::Time::Now();
- }
- } // namespace
- // static
- void DeviceEventLogImpl::SendToVLogOrErrorLog(const char* file,
- int file_line,
- LogType log_type,
- LogLevel log_level,
- const std::string& event) {
- LogEntry entry(file, file_line, log_type, log_level, event);
- SendLogEntryToVLogOrErrorLog(entry);
- }
- DeviceEventLogImpl::DeviceEventLogImpl(
- scoped_refptr<base::SingleThreadTaskRunner> task_runner,
- size_t max_entries)
- : task_runner_(task_runner), max_entries_(max_entries) {
- DCHECK(task_runner_);
- }
- DeviceEventLogImpl::~DeviceEventLogImpl() {}
- void DeviceEventLogImpl::AddEntry(const char* file,
- int file_line,
- LogType log_type,
- LogLevel log_level,
- const std::string& event) {
- LogEntry entry(file, file_line, log_type, log_level, event);
- if (!task_runner_->RunsTasksInCurrentSequence()) {
- task_runner_->PostTask(
- FROM_HERE, base::BindOnce(&DeviceEventLogImpl::AddLogEntry,
- weak_ptr_factory_.GetWeakPtr(), entry));
- return;
- }
- AddLogEntry(entry);
- }
- void DeviceEventLogImpl::AddEntryWithTimestampForTesting(
- const char* file,
- int file_line,
- LogType log_type,
- LogLevel log_level,
- const std::string& event,
- base::Time time) {
- LogEntry entry(file, file_line, log_type, log_level, event, time);
- if (!task_runner_->RunsTasksInCurrentSequence()) {
- task_runner_->PostTask(
- FROM_HERE, base::BindOnce(&DeviceEventLogImpl::AddLogEntry,
- weak_ptr_factory_.GetWeakPtr(), entry));
- return;
- }
- AddLogEntry(entry);
- }
- void DeviceEventLogImpl::AddLogEntry(const LogEntry& entry) {
- DCHECK(task_runner_->RunsTasksInCurrentSequence());
- if (!entries_.empty()) {
- LogEntry& last = entries_.back();
- if (LogEntryMatches(last, entry)) {
- IncreaseLogEntryCount(entry, &last);
- return;
- }
- }
- if (entries_.size() >= max_entries_)
- RemoveEntry();
- entries_.push_back(entry);
- SendLogEntryToVLogOrErrorLog(entry);
- }
- void DeviceEventLogImpl::RemoveEntry() {
- const size_t max_error_entries = max_entries_ / 2;
- DCHECK(max_error_entries < entries_.size());
- // Remove the first (oldest) non-error entry, or the oldest entry if more
- // than half the entries are errors.
- size_t error_count = 0;
- for (auto iter = entries_.begin(); iter != entries_.end(); ++iter) {
- if (iter->log_level != LOG_LEVEL_ERROR) {
- entries_.erase(iter);
- return;
- }
- if (++error_count > max_error_entries)
- break;
- }
- // Too many error entries, remove the oldest entry.
- entries_.pop_front();
- }
- std::string DeviceEventLogImpl::GetAsString(StringOrder order,
- const std::string& format,
- const std::string& types,
- LogLevel max_level,
- size_t max_events) {
- DCHECK(task_runner_->RunsTasksInCurrentSequence());
- if (entries_.empty())
- return "No Log Entries.";
- ShowTime show_time;
- bool show_file, show_type, show_level, format_json;
- GetFormat(format, &show_time, &show_file, &show_type, &show_level,
- &format_json);
- std::set<LogType> include_types, exclude_types;
- GetLogTypes(types, &include_types, &exclude_types);
- std::string result;
- base::Value log_entries(base::Value::Type::LIST);
- if (order == OLDEST_FIRST) {
- size_t offset = 0;
- if (max_events > 0 && max_events < entries_.size()) {
- // Iterate backwards through the list skipping uninteresting entries to
- // determine the first entry to include.
- size_t shown_events = 0;
- size_t num_entries = 0;
- for (const LogEntry& entry : base::Reversed(entries_)) {
- ++num_entries;
- if (!LogEntryMatchesTypes(entry, include_types, exclude_types))
- continue;
- if (entry.log_level > max_level)
- continue;
- if (++shown_events >= max_events)
- break;
- }
- offset = entries_.size() - num_entries;
- }
- for (const LogEntry& entry : entries_) {
- if (offset > 0) {
- --offset;
- continue;
- }
- if (!LogEntryMatchesTypes(entry, include_types, exclude_types))
- continue;
- if (entry.log_level > max_level)
- continue;
- if (format_json) {
- log_entries.Append(LogEntryAsJSON(entry));
- } else {
- result += LogEntryToString(entry, show_time, show_file, show_type,
- show_level);
- result += "\n";
- }
- }
- } else {
- size_t nlines = 0;
- // Iterate backwards through the list to show the most recent entries first.
- for (const LogEntry& entry : base::Reversed(entries_)) {
- if (!LogEntryMatchesTypes(entry, include_types, exclude_types))
- continue;
- if (entry.log_level > max_level)
- continue;
- if (format_json) {
- log_entries.Append(LogEntryAsJSON(entry));
- } else {
- result += LogEntryToString(entry, show_time, show_file, show_type,
- show_level);
- result += "\n";
- }
- if (max_events > 0 && ++nlines >= max_events)
- break;
- }
- }
- if (format_json) {
- JSONStringValueSerializer serializer(&result);
- serializer.Serialize(log_entries);
- }
- return result;
- }
- void DeviceEventLogImpl::ClearAll() {
- entries_.clear();
- }
- void DeviceEventLogImpl::Clear(const base::Time& begin, const base::Time& end) {
- auto begin_it = std::find_if(
- entries_.begin(), entries_.end(),
- [begin](const LogEntry& entry) { return entry.time >= begin; });
- auto end_rev_it =
- std::find_if(entries_.rbegin(), entries_.rend(),
- [end](const LogEntry& entry) { return entry.time <= end; });
- entries_.erase(begin_it, end_rev_it.base());
- }
- int DeviceEventLogImpl::GetCountByLevelForTesting(LogLevel level) {
- int count = 0;
- for (const auto& entry : entries_) {
- if (entry.log_level == level)
- ++count;
- }
- return count;
- }
- DeviceEventLogImpl::LogEntry::LogEntry(const char* filedesc,
- int file_line,
- LogType log_type,
- LogLevel log_level,
- const std::string& event)
- : file_line(file_line),
- log_type(log_type),
- log_level(log_level),
- time(base::Time::Now()),
- count(1) {
- base::TrimWhitespaceASCII(event, base::TRIM_ALL, &this->event);
- if (filedesc) {
- file = filedesc;
- size_t last_slash_pos = file.find_last_of("\\/");
- if (last_slash_pos != std::string::npos) {
- file.erase(0, last_slash_pos + 1);
- }
- }
- }
- DeviceEventLogImpl::LogEntry::LogEntry(const char* filedesc,
- int file_line,
- LogType log_type,
- LogLevel log_level,
- const std::string& event,
- base::Time time_for_testing)
- : LogEntry(filedesc, file_line, log_type, log_level, event) {
- time = time_for_testing;
- }
- DeviceEventLogImpl::LogEntry::LogEntry(const LogEntry& other) = default;
- } // namespace device_event_log
|