diff options
23 files changed, 1157 insertions, 916 deletions
diff --git a/chrome/browser/chromeos/system/syslogs_provider.cc b/chrome/browser/chromeos/system/syslogs_provider.cc index 3cfaab6..ecc3267 100644 --- a/chrome/browser/chromeos/system/syslogs_provider.cc +++ b/chrome/browser/chromeos/system/syslogs_provider.cc @@ -331,12 +331,17 @@ void SyslogsProviderImpl::ReadSyslogs( dbus::statistics::FORMAT_ALL); // Include recent network log events - (*logs)["network_event_log"] = network_event_log::GetAsString( - network_event_log::OLDEST_FIRST, - "time,file,desc", - network_event_log::kDefaultLogLevel, + (*logs)["network_event_log"] = device_event_log::GetAsString( + device_event_log::OLDEST_FIRST, "time,file", + device_event_log::LOG_TYPE_NETWORK, device_event_log::kDefaultLogLevel, system::kFeedbackMaxLineCount); + // Include recent non-network device events + (*logs)["device_event_log"] = device_event_log::GetAsString( + device_event_log::OLDEST_FIRST, "time,file", + device_event_log::LOG_TYPE_NON_NETWORK, + device_event_log::kDefaultLogLevel, system::kFeedbackMaxLineCount); + // SyslogsMemoryHandler will clean itself up. // SyslogsMemoryHandler::OnDetailsAvailable() will modify |logs| and call // request->ForwardResult(logs, zip_content). diff --git a/chrome/browser/chromeos/system_logs/device_event_log_source.cc b/chrome/browser/chromeos/system_logs/device_event_log_source.cc new file mode 100644 index 0000000..2462c4b --- /dev/null +++ b/chrome/browser/chromeos/system_logs/device_event_log_source.cc @@ -0,0 +1,41 @@ +// 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 "chrome/browser/chromeos/system_logs/device_event_log_source.h" + +#include "base/message_loop/message_loop.h" +#include "chromeos/device_event_log.h" +#include "content/public/browser/browser_thread.h" + +namespace system_logs { + +const char kNetworkEventLogEntry[] = "network_event_log"; +const char kDeviceEventLogEntry[] = "device_event_log"; + +DeviceEventLogSource::DeviceEventLogSource() : SystemLogsSource("DeviceEvent") { +} + +DeviceEventLogSource::~DeviceEventLogSource() { +} + +void DeviceEventLogSource::Fetch(const SysLogsSourceCallback& callback) { + DCHECK(content::BrowserThread::CurrentlyOn(content::BrowserThread::UI)); + DCHECK(!callback.is_null()); + + scoped_ptr<SystemLogsResponse> response(new SystemLogsResponse); + const int kMaxDeviceEventsForAboutSystem = 400; + (*response)[kNetworkEventLogEntry] = chromeos::device_event_log::GetAsString( + chromeos::device_event_log::OLDEST_FIRST, "time,file,level", + chromeos::device_event_log::LOG_TYPE_NETWORK, + chromeos::device_event_log::kDefaultLogLevel, + kMaxDeviceEventsForAboutSystem); + (*response)[kDeviceEventLogEntry] = chromeos::device_event_log::GetAsString( + chromeos::device_event_log::OLDEST_FIRST, "time,file,type,level", + chromeos::device_event_log::LOG_TYPE_NON_NETWORK, + chromeos::device_event_log::LOG_LEVEL_DEBUG, + kMaxDeviceEventsForAboutSystem); + callback.Run(response.get()); +} + +} // namespace system_logs diff --git a/chrome/browser/chromeos/system_logs/device_event_log_source.h b/chrome/browser/chromeos/system_logs/device_event_log_source.h new file mode 100644 index 0000000..1d62367 --- /dev/null +++ b/chrome/browser/chromeos/system_logs/device_event_log_source.h @@ -0,0 +1,27 @@ +// 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. + +#ifndef CHROME_BROWSER_CHROMEOS_SYSTEM_LOGS_DEVICE_EVENT_LOG_SOURCE_H_ +#define CHROME_BROWSER_CHROMEOS_SYSTEM_LOGS_DEVICE_EVENT_LOG_SOURCE_H_ + +#include "chrome/browser/feedback/system_logs/system_logs_fetcher_base.h" + +namespace system_logs { + +// Fetches entries for 'network_event_log' and 'device_event_log'. +class DeviceEventLogSource : public SystemLogsSource { + public: + DeviceEventLogSource(); + ~DeviceEventLogSource() override; + + // SystemLogsSource override. + void Fetch(const SysLogsSourceCallback& request) override; + + private: + DISALLOW_COPY_AND_ASSIGN(DeviceEventLogSource); +}; + +} // namespace system_logs + +#endif // CHROME_BROWSER_CHROMEOS_SYSTEM_LOGS_DEVICE_EVENT_LOG_SOURCE_H_ diff --git a/chrome/browser/chromeos/system_logs/network_event_log_source.cc b/chrome/browser/chromeos/system_logs/network_event_log_source.cc deleted file mode 100644 index f8fab9d..0000000 --- a/chrome/browser/chromeos/system_logs/network_event_log_source.cc +++ /dev/null @@ -1,37 +0,0 @@ -// Copyright (c) 2012 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 "chrome/browser/chromeos/system_logs/network_event_log_source.h" - -#include "base/message_loop/message_loop.h" -#include "chromeos/network/network_event_log.h" -#include "content/public/browser/browser_thread.h" - -namespace system_logs { - -const char kNetworkEventLogEntry[] = "network_event_log"; - -NetworkEventLogSource::NetworkEventLogSource() - : SystemLogsSource("NetworkEvent") { -} - -NetworkEventLogSource::~NetworkEventLogSource() { -} - -void NetworkEventLogSource::Fetch(const SysLogsSourceCallback& callback) { - DCHECK(content::BrowserThread::CurrentlyOn(content::BrowserThread::UI)); - DCHECK(!callback.is_null()); - - scoped_ptr<SystemLogsResponse> response(new SystemLogsResponse); - const int kMaxNetworkEventsForAboutSystem = 400; - (*response)[kNetworkEventLogEntry] = - chromeos::network_event_log::GetAsString( - chromeos::network_event_log::OLDEST_FIRST, - "time,file,level,desc", - chromeos::network_event_log::kDefaultLogLevel, - kMaxNetworkEventsForAboutSystem); - callback.Run(response.get()); -} - -} // namespace system_logs diff --git a/chrome/browser/chromeos/system_logs/network_event_log_source.h b/chrome/browser/chromeos/system_logs/network_event_log_source.h deleted file mode 100644 index beff802..0000000 --- a/chrome/browser/chromeos/system_logs/network_event_log_source.h +++ /dev/null @@ -1,27 +0,0 @@ -// Copyright (c) 2012 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. - -#ifndef CHROME_BROWSER_CHROMEOS_SYSTEM_LOGS_NETWORK_EVENT_LOG_SOURCE_H_ -#define CHROME_BROWSER_CHROMEOS_SYSTEM_LOGS_NETWORK_EVENT_LOG_SOURCE_H_ - -#include "chrome/browser/feedback/system_logs/system_logs_fetcher_base.h" - -namespace system_logs { - -// Fetches memory usage details. -class NetworkEventLogSource : public SystemLogsSource { - public: - NetworkEventLogSource(); - virtual ~NetworkEventLogSource(); - - // SystemLogsSource override. - virtual void Fetch(const SysLogsSourceCallback& request) override; - - private: - DISALLOW_COPY_AND_ASSIGN(NetworkEventLogSource); -}; - -} // namespace system_logs - -#endif // CHROME_BROWSER_CHROMEOS_SYSTEM_LOGS_NETWORK_EVENT_LOG_SOURCE_H_ diff --git a/chrome/browser/feedback/system_logs/about_system_logs_fetcher.cc b/chrome/browser/feedback/system_logs/about_system_logs_fetcher.cc index b7c7fee..c92fec5 100644 --- a/chrome/browser/feedback/system_logs/about_system_logs_fetcher.cc +++ b/chrome/browser/feedback/system_logs/about_system_logs_fetcher.cc @@ -14,8 +14,8 @@ #include "chrome/browser/chromeos/system_logs/command_line_log_source.h" #include "chrome/browser/chromeos/system_logs/dbus_log_source.h" #include "chrome/browser/chromeos/system_logs/debug_daemon_log_source.h" +#include "chrome/browser/chromeos/system_logs/device_event_log_source.h" #include "chrome/browser/chromeos/system_logs/lsb_release_log_source.h" -#include "chrome/browser/chromeos/system_logs/network_event_log_source.h" #include "chrome/browser/chromeos/system_logs/touch_log_source.h" #endif @@ -30,8 +30,8 @@ AboutSystemLogsFetcher::AboutSystemLogsFetcher() { #if defined(OS_CHROMEOS) data_sources_.push_back(new CommandLineLogSource()); data_sources_.push_back(new DBusLogSource()); + data_sources_.push_back(new DeviceEventLogSource()); data_sources_.push_back(new LsbReleaseLogSource()); - data_sources_.push_back(new NetworkEventLogSource()); data_sources_.push_back(new TouchLogSource()); // Debug Daemon data source - currently only this data source supports diff --git a/chrome/browser/feedback/system_logs/scrubbed_system_logs_fetcher.cc b/chrome/browser/feedback/system_logs/scrubbed_system_logs_fetcher.cc index 6d09779..7b3f442 100644 --- a/chrome/browser/feedback/system_logs/scrubbed_system_logs_fetcher.cc +++ b/chrome/browser/feedback/system_logs/scrubbed_system_logs_fetcher.cc @@ -14,8 +14,8 @@ #include "chrome/browser/chromeos/system_logs/command_line_log_source.h" #include "chrome/browser/chromeos/system_logs/dbus_log_source.h" #include "chrome/browser/chromeos/system_logs/debug_daemon_log_source.h" +#include "chrome/browser/chromeos/system_logs/device_event_log_source.h" #include "chrome/browser/chromeos/system_logs/lsb_release_log_source.h" -#include "chrome/browser/chromeos/system_logs/network_event_log_source.h" #include "chrome/browser/chromeos/system_logs/touch_log_source.h" #endif @@ -30,8 +30,8 @@ ScrubbedSystemLogsFetcher::ScrubbedSystemLogsFetcher() { #if defined(OS_CHROMEOS) data_sources_.push_back(new CommandLineLogSource()); data_sources_.push_back(new DBusLogSource()); + data_sources_.push_back(new DeviceEventLogSource()); data_sources_.push_back(new LsbReleaseLogSource()); - data_sources_.push_back(new NetworkEventLogSource()); data_sources_.push_back(new TouchLogSource()); // Debug Daemon data source - currently only this data source supports diff --git a/chrome/browser/ui/webui/chromeos/network_ui.cc b/chrome/browser/ui/webui/chromeos/network_ui.cc index d009a65..1f06b3a 100644 --- a/chrome/browser/ui/webui/chromeos/network_ui.cc +++ b/chrome/browser/ui/webui/chromeos/network_ui.cc @@ -40,11 +40,10 @@ class NetworkUIMessageHandler : public content::WebUIMessageHandler { private: void GetNetworkLog(const base::ListValue* value) const { - base::StringValue data(chromeos::network_event_log::GetAsString( - chromeos::network_event_log::NEWEST_FIRST, - "json", - chromeos::network_event_log::LOG_LEVEL_DEBUG, - kMaxLogEvents)); + base::StringValue data(chromeos::device_event_log::GetAsString( + chromeos::device_event_log::NEWEST_FIRST, "json", + device_event_log::LOG_TYPE_NETWORK, + chromeos::device_event_log::LOG_LEVEL_DEBUG, kMaxLogEvents)); web_ui()->CallJavascriptFunction("NetworkUI.getNetworkLogCallback", data); } diff --git a/chrome/chrome_browser_chromeos.gypi b/chrome/chrome_browser_chromeos.gypi index c7bce65..e4fa377 100644 --- a/chrome/chrome_browser_chromeos.gypi +++ b/chrome/chrome_browser_chromeos.gypi @@ -910,10 +910,10 @@ 'browser/chromeos/system_logs/dbus_log_source.h', 'browser/chromeos/system_logs/debug_daemon_log_source.cc', 'browser/chromeos/system_logs/debug_daemon_log_source.h', + 'browser/chromeos/system_logs/device_event_log_source.cc', + 'browser/chromeos/system_logs/device_event_log_source.h', 'browser/chromeos/system_logs/lsb_release_log_source.cc', 'browser/chromeos/system_logs/lsb_release_log_source.h', - 'browser/chromeos/system_logs/network_event_log_source.cc', - 'browser/chromeos/system_logs/network_event_log_source.h', 'browser/chromeos/system_logs/touch_log_source.cc', 'browser/chromeos/system_logs/touch_log_source.h', 'browser/chromeos/timezone/timezone_provider.h', diff --git a/chromeos/chromeos.gyp b/chromeos/chromeos.gyp index 01f2c02..aa10172 100644 --- a/chromeos/chromeos.gyp +++ b/chromeos/chromeos.gyp @@ -250,6 +250,10 @@ 'dbus/update_engine_client.h', 'dbus/volume_state.cc', 'dbus/volume_state.h', + 'device_event_log.cc', + 'device_event_log.h', + 'device_event_log_impl.cc', + 'device_event_log_impl.h', 'disks/disk_mount_manager.cc', 'disks/disk_mount_manager.h', 'login/auth/auth_attempt_state.cc', @@ -323,7 +327,6 @@ 'network/network_device_handler.h', 'network/network_device_handler_impl.cc', 'network/network_device_handler_impl.h', - 'network/network_event_log.cc', 'network/network_event_log.h', 'network/network_handler.cc', 'network/network_handler.h', @@ -431,6 +434,7 @@ 'dbus/shill_profile_client_unittest.cc', 'dbus/shill_service_client_unittest.cc', 'dbus/shill_third_party_vpn_driver_client_unittest.cc', + 'device_event_log_impl_unittest.cc', 'disks/disk_mount_manager_unittest.cc', 'login/auth/key_unittest.cc', 'login/login_state_unittest.cc', @@ -444,7 +448,6 @@ 'network/network_configuration_handler_unittest.cc', 'network/network_connection_handler_unittest.cc', 'network/network_device_handler_unittest.cc', - 'network/network_event_log_unittest.cc', 'network/network_profile_handler_stub.h', 'network/network_sms_handler_unittest.cc', 'network/network_state_handler_unittest.cc', diff --git a/chromeos/dbus/dbus_thread_manager.cc b/chromeos/dbus/dbus_thread_manager.cc index d5a188a..ecb01771 100644 --- a/chromeos/dbus/dbus_thread_manager.cc +++ b/chromeos/dbus/dbus_thread_manager.cc @@ -49,6 +49,7 @@ #include "chromeos/dbus/sms_client.h" #include "chromeos/dbus/system_clock_client.h" #include "chromeos/dbus/update_engine_client.h" +#include "chromeos/device_event_log.h" #include "dbus/bus.h" #include "dbus/dbus_statistics.h" @@ -59,6 +60,7 @@ static bool g_using_dbus_thread_manager_for_testing = false; DBusThreadManager::DBusThreadManager(scoped_ptr<DBusClientBundle> client_bundle) : client_bundle_(client_bundle.Pass()) { + device_event_log::Initialize(0 /* default max entries */); dbus::statistics::Initialize(); if (client_bundle_->IsUsingAnyRealClient()) { @@ -92,6 +94,7 @@ DBusThreadManager::~DBusThreadManager() { dbus_thread_->Stop(); dbus::statistics::Shutdown(); + device_event_log::Shutdown(); if (!g_dbus_thread_manager) return; // Called form Shutdown() or local test instance. diff --git a/chromeos/dbus/power_manager_client.cc b/chromeos/dbus/power_manager_client.cc index 52b6909..d1c9f2c 100644 --- a/chromeos/dbus/power_manager_client.cc +++ b/chromeos/dbus/power_manager_client.cc @@ -27,6 +27,7 @@ #include "chromeos/dbus/power_manager/policy.pb.h" #include "chromeos/dbus/power_manager/power_supply_properties.pb.h" #include "chromeos/dbus/power_manager/suspend.pb.h" +#include "chromeos/device_event_log.h" #include "dbus/bus.h" #include "dbus/message.h" #include "dbus/object_path.h" @@ -146,6 +147,7 @@ class PowerManagerClientImpl : public PowerManagerClient { } virtual void RequestStatusUpdate() override { + POWER_LOG(USER) << "RequestStatusUpdate"; dbus::MethodCall method_call( power_manager::kPowerManagerInterface, power_manager::kGetPowerSupplyPropertiesMethod); @@ -157,14 +159,17 @@ class PowerManagerClientImpl : public PowerManagerClient { } virtual void RequestSuspend() override { + POWER_LOG(USER) << "RequestSuspend"; SimpleMethodCallToPowerManager(power_manager::kRequestSuspendMethod); } virtual void RequestRestart() override { + POWER_LOG(USER) << "RequestRestart"; SimpleMethodCallToPowerManager(power_manager::kRequestRestartMethod); } virtual void RequestShutdown() override { + POWER_LOG(USER) << "RequestShutdown"; SimpleMethodCallToPowerManager(power_manager::kRequestShutdownMethod); } @@ -197,12 +202,13 @@ class PowerManagerClientImpl : public PowerManagerClient { virtual void SetPolicy( const power_manager::PowerManagementPolicy& policy) override { + POWER_LOG(USER) << "SetPolicy"; dbus::MethodCall method_call( power_manager::kPowerManagerInterface, power_manager::kSetPolicyMethod); dbus::MessageWriter writer(&method_call); if (!writer.AppendProtoAsArrayOfBytes(policy)) { - LOG(ERROR) << "Error calling " << power_manager::kSetPolicyMethod; + POWER_LOG(ERROR) << "Error calling " << power_manager::kSetPolicyMethod; return; } power_manager_proxy_->CallMethod( @@ -212,6 +218,7 @@ class PowerManagerClientImpl : public PowerManagerClient { } virtual void SetIsProjecting(bool is_projecting) override { + POWER_LOG(USER) << "SetIsProjecting"; dbus::MethodCall method_call( power_manager::kPowerManagerInterface, power_manager::kSetIsProjectingMethod); @@ -339,8 +346,8 @@ class PowerManagerClientImpl : public PowerManagerClient { void SignalConnected(const std::string& interface_name, const std::string& signal_name, bool success) { - LOG_IF(WARNING, !success) << "Failed to connect to signal " - << signal_name << "."; + if (!success) + POWER_LOG(ERROR) << "Failed to connect to signal " << signal_name << "."; } // Makes a method call to power manager with no arguments and no response. @@ -355,15 +362,15 @@ class PowerManagerClientImpl : public PowerManagerClient { void NameOwnerChangedReceived(const std::string& old_owner, const std::string& new_owner) { - VLOG(1) << "Power manager restarted (old owner was " - << (old_owner.empty() ? "[none]" : old_owner.c_str()) - << ", new owner is " - << (new_owner.empty() ? "[none]" : new_owner.c_str()) << ")"; + POWER_LOG(EVENT) << "Power manager restarted. Old owner: " + << (old_owner.empty() ? "[none]" : old_owner.c_str()) + << " New owner: " + << (new_owner.empty() ? "[none]" : new_owner.c_str()); suspend_is_pending_ = false; pending_suspend_id_ = -1; suspending_from_dark_resume_ = false; if (!new_owner.empty()) { - VLOG(1) << "Sending initial state to power manager"; + POWER_LOG(EVENT) << "Sending initial state to power manager"; RegisterSuspendDelays(); SetIsProjecting(last_is_projecting_); FOR_EACH_OBSERVER(Observer, observers_, PowerManagerRestarted()); @@ -376,12 +383,12 @@ class PowerManagerClientImpl : public PowerManagerClient { bool user_initiated = 0; if (!(reader.PopInt32(&brightness_level) && reader.PopBool(&user_initiated))) { - LOG(ERROR) << "Brightness changed signal had incorrect parameters: " - << signal->ToString(); + POWER_LOG(ERROR) << "Brightness changed signal had incorrect parameters: " + << signal->ToString(); return; } - VLOG(1) << "Brightness changed to " << brightness_level - << ": user initiated " << user_initiated; + POWER_LOG(DEBUG) << "Brightness changed to " << brightness_level + << ": user initiated " << user_initiated; FOR_EACH_OBSERVER(Observer, observers_, BrightnessChanged(brightness_level, user_initiated)); } @@ -390,8 +397,9 @@ class PowerManagerClientImpl : public PowerManagerClient { dbus::MessageReader reader(signal); power_manager::PeripheralBatteryStatus protobuf_status; if (!reader.PopArrayOfBytesAsProto(&protobuf_status)) { - LOG(ERROR) << "Unable to decode protocol buffer from " - << power_manager::kPeripheralBatteryStatusSignal << " signal"; + POWER_LOG(ERROR) << "Unable to decode protocol buffer from " + << power_manager::kPeripheralBatteryStatusSignal + << " signal"; return; } @@ -399,29 +407,29 @@ class PowerManagerClientImpl : public PowerManagerClient { std::string name = protobuf_status.name(); int level = protobuf_status.has_level() ? protobuf_status.level() : -1; - VLOG(1) << "Device battery status received " << level - << " for " << name << " at " << path; + POWER_LOG(DEBUG) << "Device battery status received " << level << " for " + << name << " at " << path; FOR_EACH_OBSERVER(Observer, observers_, PeripheralBatteryStatusReceived(path, name, level)); } void PowerSupplyPollReceived(dbus::Signal* signal) { - VLOG(1) << "Received power supply poll signal."; + POWER_LOG(DEBUG) << "Received power supply poll signal."; dbus::MessageReader reader(signal); power_manager::PowerSupplyProperties protobuf; if (reader.PopArrayOfBytesAsProto(&protobuf)) { HandlePowerSupplyProperties(protobuf); } else { - LOG(ERROR) << "Unable to decode " - << power_manager::kPowerSupplyPollSignal << "signal"; + POWER_LOG(ERROR) << "Unable to decode " + << power_manager::kPowerSupplyPollSignal << " signal"; } } void OnGetPowerSupplyPropertiesMethod(dbus::Response* response) { if (!response) { - LOG(ERROR) << "Error calling " - << power_manager::kGetPowerSupplyPropertiesMethod; + POWER_LOG(ERROR) << "Error calling " + << power_manager::kGetPowerSupplyPropertiesMethod; return; } @@ -430,9 +438,9 @@ class PowerManagerClientImpl : public PowerManagerClient { if (reader.PopArrayOfBytesAsProto(&protobuf)) { HandlePowerSupplyProperties(protobuf); } else { - LOG(ERROR) << "Unable to decode " - << power_manager::kGetPowerSupplyPropertiesMethod - << " response"; + POWER_LOG(ERROR) << "Unable to decode " + << power_manager::kGetPowerSupplyPropertiesMethod + << " response"; } } @@ -440,15 +448,15 @@ class PowerManagerClientImpl : public PowerManagerClient { const GetScreenBrightnessPercentCallback& callback, dbus::Response* response) { if (!response) { - LOG(ERROR) << "Error calling " - << power_manager::kGetScreenBrightnessPercentMethod; + POWER_LOG(ERROR) << "Error calling " + << power_manager::kGetScreenBrightnessPercentMethod; return; } dbus::MessageReader reader(response); double percent = 0.0; if (!reader.PopDouble(&percent)) - LOG(ERROR) << "Error reading response from powerd: " - << response->ToString(); + POWER_LOG(ERROR) << "Error reading response from powerd: " + << response->ToString(); callback.Run(percent); } @@ -464,25 +472,26 @@ class PowerManagerClientImpl : public PowerManagerClient { const std::string& method_name, dbus::Response* response) { if (!response) { - LOG(ERROR) << "Error calling " << method_name; + POWER_LOG(ERROR) << "Error calling " << method_name; return; } dbus::MessageReader reader(response); power_manager::RegisterSuspendDelayReply protobuf; if (!reader.PopArrayOfBytesAsProto(&protobuf)) { - LOG(ERROR) << "Unable to parse reply from " << method_name; + POWER_LOG(ERROR) << "Unable to parse reply from " << method_name; return; } if (dark_suspend) { dark_suspend_delay_id_ = protobuf.delay_id(); has_dark_suspend_delay_id_ = true; - VLOG(1) << "Registered dark suspend delay " << dark_suspend_delay_id_; + POWER_LOG(EVENT) << "Registered dark suspend delay " + << dark_suspend_delay_id_; } else { suspend_delay_id_ = protobuf.delay_id(); has_suspend_delay_id_ = true; - VLOG(1) << "Registered suspend delay " << suspend_delay_id_; + POWER_LOG(EVENT) << "Registered suspend delay " << suspend_delay_id_; } } @@ -490,29 +499,31 @@ class PowerManagerClientImpl : public PowerManagerClient { std::string signal_name = signal->GetMember(); if ((in_dark_resume && !has_dark_suspend_delay_id_) || (!in_dark_resume && !has_suspend_delay_id_)) { - LOG(ERROR) << "Received unrequested " << signal_name << " signal"; + POWER_LOG(ERROR) << "Received unrequested " << signal_name << " signal"; return; } dbus::MessageReader reader(signal); power_manager::SuspendImminent proto; if (!reader.PopArrayOfBytesAsProto(&proto)) { - LOG(ERROR) << "Unable to decode protocol buffer from " << signal_name - << " signal"; + POWER_LOG(ERROR) << "Unable to decode protocol buffer from " + << signal_name << " signal"; return; } - VLOG(1) << "Got " << signal_name << " signal announcing suspend attempt " - << proto.suspend_id(); + POWER_LOG(EVENT) << "Got " << signal_name + << " signal announcing suspend attempt " + << proto.suspend_id(); // If a previous suspend is pending from the same state we are currently in // (fully powered on or in dark resume), then something's gone a little // wonky. - if (suspend_is_pending_ && - suspending_from_dark_resume_ == in_dark_resume) { - LOG(WARNING) << "Got " << signal_name << " signal about pending suspend " - << "attempt " << proto.suspend_id() << " while still " - << "waiting on attempt " << pending_suspend_id_; + if (suspend_is_pending_ && suspending_from_dark_resume_ == in_dark_resume) { + POWER_LOG(ERROR) << "Got " << signal_name + << " signal about pending suspend attempt " + << proto.suspend_id() + << " while still waiting on attempt " + << pending_suspend_id_; } pending_suspend_id_ = proto.suspend_id(); @@ -531,16 +542,17 @@ class PowerManagerClientImpl : public PowerManagerClient { dbus::MessageReader reader(signal); power_manager::SuspendDone proto; if (!reader.PopArrayOfBytesAsProto(&proto)) { - LOG(ERROR) << "Unable to decode protocol buffer from " - << power_manager::kSuspendDoneSignal << " signal"; + POWER_LOG(ERROR) << "Unable to decode protocol buffer from " + << power_manager::kSuspendDoneSignal << " signal"; return; } const base::TimeDelta duration = base::TimeDelta::FromInternalValue(proto.suspend_duration()); - VLOG(1) << "Got " << power_manager::kSuspendDoneSignal << " signal:" - << " suspend_id=" << proto.suspend_id() - << " duration=" << duration.InSeconds() << " sec"; + POWER_LOG(EVENT) << "Got " << power_manager::kSuspendDoneSignal + << " signal:" + << " suspend_id=" << proto.suspend_id() + << " duration=" << duration.InSeconds() << " sec"; if (render_process_manager_delegate_) render_process_manager_delegate_->SuspendDone(); @@ -554,8 +566,8 @@ class PowerManagerClientImpl : public PowerManagerClient { dbus::MessageReader reader(signal); power_manager::IdleActionImminent proto; if (!reader.PopArrayOfBytesAsProto(&proto)) { - LOG(ERROR) << "Unable to decode protocol buffer from " - << power_manager::kIdleActionImminentSignal << " signal"; + POWER_LOG(ERROR) << "Unable to decode protocol buffer from " + << power_manager::kIdleActionImminentSignal << " signal"; return; } FOR_EACH_OBSERVER(Observer, observers_, @@ -571,15 +583,16 @@ class PowerManagerClientImpl : public PowerManagerClient { dbus::MessageReader reader(signal); power_manager::InputEvent proto; if (!reader.PopArrayOfBytesAsProto(&proto)) { - LOG(ERROR) << "Unable to decode protocol buffer from " - << power_manager::kInputEventSignal << " signal"; + POWER_LOG(ERROR) << "Unable to decode protocol buffer from " + << power_manager::kInputEventSignal << " signal"; return; } base::TimeTicks timestamp = base::TimeTicks::FromInternalValue(proto.timestamp()); - VLOG(1) << "Got " << power_manager::kInputEventSignal << " signal:" - << " type=" << proto.type() << " timestamp=" << proto.timestamp(); + POWER_LOG(USER) << "Got " << power_manager::kInputEventSignal << " signal:" + << " type=" << proto.type() + << " timestamp=" << proto.timestamp(); switch (proto.type()) { case power_manager::InputEvent_Type_POWER_BUTTON_DOWN: case power_manager::InputEvent_Type_POWER_BUTTON_UP: { @@ -622,7 +635,7 @@ class PowerManagerClientImpl : public PowerManagerClient { dbus::MessageWriter writer(&method_call); if (!writer.AppendProtoAsArrayOfBytes(protobuf_request)) { - LOG(ERROR) << "Error constructing message for " << method_name; + POWER_LOG(ERROR) << "Error constructing message for " << method_name; return; } @@ -697,8 +710,8 @@ class PowerManagerClientImpl : public PowerManagerClient { power_manager::kPowerManagerInterface, method_name); dbus::MessageWriter writer(&method_call); - VLOG(1) << "Announcing readiness of suspend delay " << delay_id - << " for suspend attempt " << pending_suspend_id_; + POWER_LOG(EVENT) << "Announcing readiness of suspend delay " << delay_id + << " for suspend attempt " << pending_suspend_id_; power_manager::SuspendReadinessInfo protobuf_request; protobuf_request.set_delay_id(delay_id); protobuf_request.set_suspend_id(pending_suspend_id_); @@ -707,7 +720,7 @@ class PowerManagerClientImpl : public PowerManagerClient { suspend_is_pending_ = false; if (!writer.AppendProtoAsArrayOfBytes(protobuf_request)) { - LOG(ERROR) << "Error constructing message for " << method_name; + POWER_LOG(ERROR) << "Error constructing message for " << method_name; return; } power_manager_proxy_->CallMethod( @@ -807,39 +820,41 @@ class PowerManagerClientStubImpl : public PowerManagerClient { } virtual void DecreaseScreenBrightness(bool allow_off) override { - VLOG(1) << "Requested to descrease screen brightness"; + POWER_LOG(USER) << "Requested to descrease screen brightness"; SetBrightness(brightness_ - 5.0, true); } virtual void IncreaseScreenBrightness() override { - VLOG(1) << "Requested to increase screen brightness"; + POWER_LOG(USER) << "Requested to increase screen brightness"; SetBrightness(brightness_ + 5.0, true); } virtual void SetScreenBrightnessPercent(double percent, bool gradual) override { - VLOG(1) << "Requested to set screen brightness to " << percent << "% " - << (gradual ? "gradually" : "instantaneously"); + POWER_LOG(USER) << "Requested to set screen brightness to " << percent + << "% " << (gradual ? "gradually" : "instantaneously"); SetBrightness(percent, false); } virtual void GetScreenBrightnessPercent( const GetScreenBrightnessPercentCallback& callback) override { + POWER_LOG(USER) << "Requested to get screen brightness"; callback.Run(brightness_); } virtual void DecreaseKeyboardBrightness() override { - VLOG(1) << "Requested to descrease keyboard brightness"; + POWER_LOG(USER) << "Requested to descrease keyboard brightness"; } virtual void IncreaseKeyboardBrightness() override { - VLOG(1) << "Requested to increase keyboard brightness"; + POWER_LOG(USER) << "Requested to increase keyboard brightness"; } virtual void RequestStatusUpdate() override { - base::MessageLoop::current()->PostTask(FROM_HERE, - base::Bind(&PowerManagerClientStubImpl::UpdateStatus, - weak_ptr_factory_.GetWeakPtr())); + POWER_LOG(USER) << "Requested status update"; + base::MessageLoop::current()->PostTask( + FROM_HERE, base::Bind(&PowerManagerClientStubImpl::UpdateStatus, + weak_ptr_factory_.GetWeakPtr())); } virtual void RequestSuspend() override {} diff --git a/chromeos/device_event_log.cc b/chromeos/device_event_log.cc new file mode 100644 index 0000000..a548647 --- /dev/null +++ b/chromeos/device_event_log.cc @@ -0,0 +1,90 @@ +// 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 "chromeos/device_event_log.h" + +#include <string> + +#include "base/logging.h" +#include "chromeos/device_event_log_impl.h" + +namespace chromeos { + +namespace device_event_log { + +namespace { + +const size_t kDefaultMaxEntries = 4000; + +DeviceEventLogImpl* g_device_event_log = NULL; + +} // namespace + +const LogLevel kDefaultLogLevel = LOG_LEVEL_EVENT; + +void Initialize(size_t max_entries) { + CHECK(!g_device_event_log); + if (max_entries == 0) + max_entries = kDefaultMaxEntries; + g_device_event_log = new DeviceEventLogImpl(max_entries); +} + +void Shutdown() { + delete g_device_event_log; + g_device_event_log = NULL; +} + +void AddEntry(const char* file, + int line, + LogType type, + LogLevel level, + const std::string& event) { + if (g_device_event_log) { + g_device_event_log->AddEntry(file, line, type, level, event); + } else { + DeviceEventLogImpl::SendToVLogOrErrorLog(file, line, type, level, event); + } +} + +void AddEntryWithDescription(const char* file, + int line, + LogType type, + LogLevel level, + const std::string& event, + const std::string& desc) { + std::string event_with_desc = event; + if (!desc.empty()) + event_with_desc += ": " + desc; + AddEntry(file, line, type, level, event_with_desc); +} + +std::string GetAsString(StringOrder order, + const std::string& format, + LogType log_type, + LogLevel max_level, + size_t max_events) { + if (!g_device_event_log) + return "DeviceEventLog not initialized."; + return g_device_event_log->GetAsString(order, format, log_type, max_level, + max_events); +} + +namespace internal { + +DeviceEventLogInstance::DeviceEventLogInstance(const char* file, + int line, + device_event_log::LogType type, + device_event_log::LogLevel level) + : file_(file), line_(line), type_(type), level_(level) { +} + +DeviceEventLogInstance::~DeviceEventLogInstance() { + device_event_log::AddEntry(file_, line_, type_, level_, stream_.str()); +} + +} // namespace internal + +} // namespace device_event_log + +} // namespace chromeos diff --git a/chromeos/device_event_log.h b/chromeos/device_event_log.h new file mode 100644 index 0000000..ae7e80e --- /dev/null +++ b/chromeos/device_event_log.h @@ -0,0 +1,140 @@ +// 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. + +#ifndef CHROMEOS_DEVICE_EVENT_LOG_H_ +#define CHROMEOS_DEVICE_EVENT_LOG_H_ + +#include <cstring> +#include <sstream> + +#include "base/basictypes.h" +#include "chromeos/chromeos_export.h" + +namespace chromeos { + +// These macros can be used to log chromeos device related events. +// The following values should be used for |level| in these macros: +// ERROR Unexpected events, or device level failures. Use sparingly. +// USER Events initiated directly by a user (or Chrome) action. +// EVENT Default event type. +// DEBUG Debugging details that are usually not interesting. +// Examples: +// NET_LOG(EVENT) << "NetworkState Changed " << name << ": " << state; +// POWER_LOG(USER) << "Suspend requested"; + +#define NET_LOG(level) \ + DEVICE_LOG(::chromeos::device_event_log::LOG_TYPE_NETWORK, \ + ::chromeos::device_event_log::LOG_LEVEL_##level) +#define POWER_LOG(level) \ + DEVICE_LOG(::chromeos::device_event_log::LOG_TYPE_POWER, \ + ::chromeos::device_event_log::LOG_LEVEL_##level) + +// Generally prefer the above macros unless |level| is not constant. + +#define DEVICE_LOG(type, level) \ + ::chromeos::device_event_log::internal::DeviceEventLogInstance( \ + __FILE__, __LINE__, type, level).stream() + +namespace device_event_log { + +// Used to specify the type of event. +enum LogType { + // Shill / network configuration related events. + LOG_TYPE_NETWORK, + // Power manager related events. + LOG_TYPE_POWER, + // Use this in GetAsString for non NETWORK events (which are more frequent). + LOG_TYPE_NON_NETWORK, + // Use this in GetAsString for all events. + LOG_TYPE_ALL, +}; + +// Used to specify the detail level for logging. In GetAsString, used to +// specify the maximum detail level (i.e. EVENT will include USER and ERROR). +// See top-level comment for guidelines for each type. +enum LogLevel { + LOG_LEVEL_ERROR = 0, + LOG_LEVEL_USER = 1, + LOG_LEVEL_EVENT = 2, + LOG_LEVEL_DEBUG = 3 +}; + +// Used to specify which order to output event entries in GetAsString. +enum StringOrder { OLDEST_FIRST, NEWEST_FIRST }; + +// Initializes / shuts down device event logging. If |max_entries| = 0 the +// default value will be used. +CHROMEOS_EXPORT void Initialize(size_t max_entries); +CHROMEOS_EXPORT void Shutdown(); + +// If the global instance is initialized, adds an entry to it. Regardless of +// whether the global instance was intitialzed, this logs the event to +// LOG(ERROR) if |type| = ERROR or VLOG(1) otherwise. +CHROMEOS_EXPORT void AddEntry(const char* file, + int line, + LogType type, + LogLevel level, + const std::string& event); + +// For backwards compatibility with network_event_log. Combines |event| and +// |description| and calls AddEntry(). +CHROMEOS_EXPORT void AddEntryWithDescription(const char* file, + int line, + LogType type, + LogLevel level, + const std::string& event, + const std::string& description); + +// Outputs the log to a formatted string. +// |order| determines which order to output the events. +// |format| is a string that determines which elements to show. Elements +// must be comma-separated, e.g. "time,desc". +// Note: order of the format strings does not affect the output. +// "time" - Include a timestamp. +// "file" - Include file and line number. +// "type" - Include the event type. +// "html" - Include html tags. +// "json" - Return as JSON format +// Only events matching |log_type| are included in the output. +// Only events with |log_level| <= |max_level| are included in the output. +// If |max_events| > 0, limits how many events are output. +// If |json| is specified, returns a JSON list of dictionaries containing time, +// level, file, event, and description. +CHROMEOS_EXPORT std::string GetAsString(StringOrder order, + const std::string& format, + LogType log_type, + LogLevel max_level, + size_t max_events); + +CHROMEOS_EXPORT extern const LogLevel kDefaultLogLevel; + +namespace internal { + +class CHROMEOS_EXPORT DeviceEventLogInstance { + public: + DeviceEventLogInstance(const char* file, + int line, + device_event_log::LogType type, + device_event_log::LogLevel level); + ~DeviceEventLogInstance(); + + std::ostream& stream() { return stream_; } + + private: + const char* file_; + const int line_; + device_event_log::LogType type_; + device_event_log::LogLevel level_; + std::ostringstream stream_; + + DISALLOW_COPY_AND_ASSIGN(DeviceEventLogInstance); +}; + +} // namespace internal + +} // namespace device_event_log + +} // namespace chromeos + +#endif // CHROMEOS_DEVICE_EVENT_LOG_H_ diff --git a/chromeos/device_event_log_impl.cc b/chromeos/device_event_log_impl.cc new file mode 100644 index 0000000..06ee48e --- /dev/null +++ b/chromeos/device_event_log_impl.cc @@ -0,0 +1,362 @@ +// 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 "chromeos/device_event_log_impl.h" + +#include <cmath> +#include <list> + +#include "base/files/file_path.h" +#include "base/json/json_string_value_serializer.h" +#include "base/json/json_writer.h" +#include "base/logging.h" +#include "base/memory/scoped_ptr.h" +#include "base/strings/string_tokenizer.h" +#include "base/strings/stringprintf.h" +#include "base/strings/utf_string_conversions.h" +#include "base/values.h" +#include "net/base/escape.h" + +namespace chromeos { + +namespace device_event_log { + +namespace { + +const char* kLogLevelName[] = {"Error", "User", "Event", "Debug"}; + +const char* kLogTypeNetworkDesc = "Network"; +const char* kLogTypePowerDesc = "Power"; + +std::string GetLogTypeString(LogType type) { + if (type == LOG_TYPE_NETWORK) + return kLogTypeNetworkDesc; + if (type == LOG_TYPE_POWER) + return kLogTypePowerDesc; + NOTREACHED(); + return "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); +} + +// Defined below for easier review. TODO(stevenjb): Move implementation here. +std::string GetHtmlText(LogLevel log_level, const std::string& event); + +std::string LogEntryToString(const DeviceEventLogImpl::LogEntry& log_entry, + bool show_time, + bool show_file, + bool show_type, + bool show_level, + bool format_html) { + std::string line; + if (show_time) + line += "[" + TimeWithMillieconds(log_entry.time) + "] "; + if (show_type) + line += GetLogTypeString(log_entry.log_type) + ": "; + if (show_level) { + const char* kLevelDesc[] = {"ERROR", "USER", "EVENT", "DEBUG"}; + line += base::StringPrintf("%s: ", kLevelDesc[log_entry.log_level]); + } + if (show_file) { + std::string filestr = + format_html ? net::EscapeForHTML(log_entry.file) : log_entry.file; + line += base::StringPrintf("%s:%d ", log_entry.file.c_str(), + log_entry.file_line); + } + line += format_html ? GetHtmlText(log_entry.log_level, log_entry.event) + : 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; +} + +std::string GetHtmlText(LogLevel log_level, const std::string& event) { + std::string text; + if (log_level == LOG_LEVEL_DEBUG) + text += "<i>"; + else if (log_level == LOG_LEVEL_USER) + text += "<b>"; + else if (log_level == LOG_LEVEL_ERROR) + text += "<b><i>"; + + text += net::EscapeForHTML(event); + + if (log_level == LOG_LEVEL_DEBUG) + text += "</i>"; + else if (log_level == LOG_LEVEL_USER) + text += "</b>"; + else if (log_level == LOG_LEVEL_ERROR) + text += "</i></b>"; + return text; +} + +void SendLogEntryToVLogOrErrorLog( + const DeviceEventLogImpl::LogEntry& log_entry) { + if (log_entry.log_level != LOG_LEVEL_ERROR && !VLOG_IS_ON(1)) + return; + const bool show_time = true; + const bool show_file = true; + const bool show_type = true; + const bool show_level = false; + const bool format_html = false; + std::string output = LogEntryToString(log_entry, show_time, show_file, + show_type, show_level, format_html); + 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 LogEntryMatchesType(const DeviceEventLogImpl::LogEntry& entry, + LogType type) { + if (type == LOG_TYPE_ALL) + return true; + if (type == LOG_TYPE_NON_NETWORK && entry.log_type != LOG_TYPE_NETWORK) + return true; + return type == entry.log_type; +} + +void GetFormat(const std::string& format_string, + bool* show_time, + bool* show_file, + bool* show_type, + bool* show_level, + bool* format_html, + bool* format_json) { + base::StringTokenizer tokens(format_string, ","); + *show_time = false; + *show_file = false; + *show_type = false; + *show_level = false; + *format_html = false; + *format_json = false; + while (tokens.GetNext()) { + std::string tok(tokens.token()); + if (tok == "time") + *show_time = true; + if (tok == "file") + *show_file = true; + if (tok == "type") + *show_type = true; + if (tok == "level") + *show_level = true; + if (tok == "html") + *format_html = true; + if (tok == "json") + *format_json = true; + } +} + +} // 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(size_t max_entries) + : max_entries_(max_entries) { +} + +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); + AddLogEntry(entry); +} + +void DeviceEventLogImpl::AddLogEntry(const LogEntry& entry) { + if (!entries_.empty()) { + LogEntry& last = entries_.back(); + if (LogEntryMatches(last, entry)) { + // Update count and time for identical events to avoid log spam. + ++last.count; + last.log_level = std::min(last.log_level, entry.log_level); + last.time = base::Time::Now(); + return; + } + } + if (entries_.size() >= max_entries_) { + const size_t max_error_entries = max_entries_ / 2; + // 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 (LogEntryList::iterator iter = entries_.begin(); iter != entries_.end(); + ++iter) { + if (iter->log_level != LOG_LEVEL_ERROR) { + entries_.erase(iter); + break; + } + if (++error_count > max_error_entries) { + // Too many error entries, remove the oldest entry. + entries_.pop_front(); + break; + } + } + } + entries_.push_back(entry); + SendLogEntryToVLogOrErrorLog(entry); +} + +std::string DeviceEventLogImpl::GetAsString(StringOrder order, + const std::string& format, + LogType log_type, + LogLevel max_level, + size_t max_events) { + if (entries_.empty()) + return "No Log Entries."; + + bool show_time, show_file, show_type, show_level, format_html, format_json; + GetFormat(format, &show_time, &show_file, &show_type, &show_level, + &format_html, &format_json); + + std::string result; + base::ListValue log_entries; + 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 (LogEntryList::const_reverse_iterator riter = entries_.rbegin(); + riter != entries_.rend(); ++riter) { + ++num_entries; + if (!LogEntryMatchesType(*riter, log_type)) + continue; + if (riter->log_level > max_level) + continue; + if (++shown_events >= max_events) + break; + } + offset = entries_.size() - num_entries; + } + for (LogEntryList::const_iterator iter = entries_.begin(); + iter != entries_.end(); ++iter) { + if (offset > 0) { + --offset; + continue; + } + if (!LogEntryMatchesType(*iter, log_type)) + continue; + if (iter->log_level > max_level) + continue; + if (format_json) { + log_entries.AppendString(LogEntryAsJSON(*iter)); + } else { + result += LogEntryToString(*iter, show_time, show_file, show_type, + show_level, format_html); + result += "\n"; + } + } + } else { + size_t nlines = 0; + // Iterate backwards through the list to show the most recent entries first. + for (LogEntryList::const_reverse_iterator riter = entries_.rbegin(); + riter != entries_.rend(); ++riter) { + if (!LogEntryMatchesType(*riter, log_type)) + continue; + if (riter->log_level > max_level) + continue; + if (format_json) { + log_entries.AppendString(LogEntryAsJSON(*riter)); + } else { + result += LogEntryToString(*riter, show_time, show_file, show_type, + show_level, format_html); + result += "\n"; + } + if (max_events > 0 && ++nlines >= max_events) + break; + } + } + if (format_json) { + JSONStringValueSerializer serializer(&result); + serializer.Serialize(log_entries); + } + + return result; +} + +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), + event(event), + time(base::Time::Now()), + count(1) { + if (filedesc) + file = base::FilePath(std::string(filedesc)).BaseName().value(); +} + +} // namespace device_event_log + +} // namespace chromeos diff --git a/chromeos/device_event_log_impl.h b/chromeos/device_event_log_impl.h new file mode 100644 index 0000000..f053571 --- /dev/null +++ b/chromeos/device_event_log_impl.h @@ -0,0 +1,83 @@ +// 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. + +#ifndef CHROMEOS_DEVICE_EVENT_LOG_IMPL_H_ +#define CHROMEOS_DEVICE_EVENT_LOG_IMPL_H_ + +#include <list> +#include <string> + +#include "base/time/time.h" +#include "chromeos/chromeos_export.h" +#include "chromeos/device_event_log.h" + +namespace chromeos { + +namespace device_event_log { + +class CHROMEOS_EXPORT DeviceEventLogImpl { + public: + struct LogEntry { + LogEntry(const char* filedesc, + int file_line, + LogType log_type, + LogLevel log_level, + const std::string& event); + + std::string file; + int file_line; + LogType log_type; + LogLevel log_level; + std::string event; + base::Time time; + int count; + }; + + explicit DeviceEventLogImpl(size_t max_entries); + ~DeviceEventLogImpl(); + + // Implements device_event_log::AddEntry. + void AddEntry(const char* file, + int file_line, + LogType type, + LogLevel level, + const std::string& event); + + // Implements device_event_log::GetAsString. + std::string GetAsString(StringOrder order, + const std::string& format, + LogType log_type, + LogLevel max_level, + size_t max_events); + + // Called from device_event_log::AddEntry if the global instance has not been + // created (or has already been destroyed). Logs to LOG(ERROR) or VLOG(1). + static void SendToVLogOrErrorLog(const char* file, + int file_line, + LogType type, + LogLevel log_level, + const std::string& event); + + private: + friend class DeviceEventLogTest; + + typedef std::list<LogEntry> LogEntryList; + + void AddLogEntry(const LogEntry& entry); + + // For testing + size_t max_entries() const { return max_entries_; } + void set_max_entries_for_test(size_t entries) { max_entries_ = entries; } + + size_t max_entries_; + LogEntryList entries_; + + DISALLOW_COPY_AND_ASSIGN(DeviceEventLogImpl); +}; + +} // namespace device_event_log + +} // namespace chromeos + +#endif // CHROMEOS_DEVICE_EVENT_LOG_IMPL_H_ diff --git a/chromeos/device_event_log_impl_unittest.cc b/chromeos/device_event_log_impl_unittest.cc new file mode 100644 index 0000000..f3676a6 --- /dev/null +++ b/chromeos/device_event_log_impl_unittest.cc @@ -0,0 +1,267 @@ +// 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 "chromeos/device_event_log_impl.h" + +#include <algorithm> + +#include "base/basictypes.h" +#include "base/compiler_specific.h" +#include "base/format_macros.h" +#include "base/memory/scoped_ptr.h" +#include "base/strings/string_split.h" +#include "base/strings/stringprintf.h" +#include "testing/gtest/include/gtest/gtest.h" + +namespace chromeos { + +namespace device_event_log { + +namespace { + +const size_t kDefaultMaxEvents = 100; +LogLevel kDefaultLevel = LOG_LEVEL_EVENT; +LogType kDefaultType = LOG_TYPE_NETWORK; + +} // namespace + +class DeviceEventLogTest : public testing::Test { + public: + DeviceEventLogTest() {} + + void SetUp() override { + impl_.reset(new DeviceEventLogImpl(kDefaultMaxEvents)); + } + + void TearDown() override { impl_.reset(); } + + protected: + std::string SkipTime(const std::string& input) { + std::string output; + std::vector<std::string> lines; + base::SplitString(input, '\n', &lines); + for (size_t i = 0; i < lines.size(); ++i) { + size_t n = lines[i].find(']'); + if (n != std::string::npos) + output += "[time] " + lines[i].substr(n + 2) + '\n'; + else + output += lines[i]; + } + return output; + } + + size_t CountLines(const std::string& input) { + return std::count(input.begin(), input.end(), '\n'); + } + + std::string GetLogString(StringOrder order, + const std::string& format, + LogLevel max_level, + size_t max_events) { + return impl_->GetAsString(order, format, kDefaultType, max_level, + max_events); + } + + std::string GetOrderedString(StringOrder order, size_t max_events) { + return impl_->GetAsString(order, "file", kDefaultType, kDefaultLevel, + max_events); + } + + std::string GetLogStringForType(LogType type) { + return impl_->GetAsString(OLDEST_FIRST, "type", type, kDefaultLevel, 0); + } + + void AddNetworkEntry(const char* file, + int line, + LogLevel level, + const std::string& event) { + impl_->AddEntry(file, line, kDefaultType, level, event); + } + + void AddTestEvent(LogLevel level, const std::string& event) { + AddNetworkEntry("file", 0, level, event); + } + + void AddEventType(LogType type, const std::string& event) { + impl_->AddEntry("file", 0, type, kDefaultLevel, event); + } + + size_t GetMaxEntries() const { return impl_->max_entries(); } + + scoped_ptr<DeviceEventLogImpl> impl_; + + private: + DISALLOW_COPY_AND_ASSIGN(DeviceEventLogTest); +}; + +TEST_F(DeviceEventLogTest, TestNetworkEvents) { + std::string output_none = GetOrderedString(OLDEST_FIRST, 0); + EXPECT_EQ("No Log Entries.", output_none); + + LogLevel level = kDefaultLevel; + AddNetworkEntry("file1", 1, level, "event1"); + AddNetworkEntry("file2", 2, level, "event2"); + AddNetworkEntry("file3", 3, level, "event3"); + AddNetworkEntry("file3", 3, level, "event3"); + + const std::string expected_output_oldest_first( + "file1:1 event1\n" + "file2:2 event2\n" + "file3:3 event3 (2)\n"); + std::string output_oldest_first = GetOrderedString(OLDEST_FIRST, 0); + EXPECT_EQ(expected_output_oldest_first, output_oldest_first); + + const std::string expected_output_oldest_first_short( + "file2:2 event2\n" + "file3:3 event3 (2)\n"); + std::string output_oldest_first_short = GetOrderedString(OLDEST_FIRST, 2); + EXPECT_EQ(expected_output_oldest_first_short, output_oldest_first_short); + + const std::string expected_output_newest_first( + "file3:3 event3 (2)\n" + "file2:2 event2\n" + "file1:1 event1\n"); + std::string output_newest_first = GetOrderedString(NEWEST_FIRST, 0); + EXPECT_EQ(expected_output_newest_first, output_newest_first); + + const std::string expected_output_newest_first_short( + "file3:3 event3 (2)\n" + "file2:2 event2\n"); + std::string output_newest_first_short = GetOrderedString(NEWEST_FIRST, 2); + EXPECT_EQ(expected_output_newest_first_short, output_newest_first_short); +} + +TEST_F(DeviceEventLogTest, TestMaxEntries) { + const size_t max_entries = GetMaxEntries(); + const size_t entries_to_add = max_entries + 3; + for (size_t i = 0; i < entries_to_add; ++i) { + AddTestEvent(LOG_LEVEL_EVENT, base::StringPrintf("event_%" PRIuS, i)); + } + std::string output = GetOrderedString(OLDEST_FIRST, 0); + size_t output_lines = CountLines(output); + EXPECT_EQ(max_entries, output_lines); +} + +TEST_F(DeviceEventLogTest, TestStringFormat) { + AddTestEvent(LOG_LEVEL_ERROR, "event0"); + EXPECT_EQ("file:0 event0\n", + GetLogString(OLDEST_FIRST, "file", kDefaultLevel, 1)); + EXPECT_EQ("[time] event0\n", + SkipTime(GetLogString(OLDEST_FIRST, "time", kDefaultLevel, 1))); + EXPECT_EQ("event0\n", GetLogString(OLDEST_FIRST, "", kDefaultLevel, 1)); + EXPECT_EQ("<b><i>event0</i></b>\n", + GetLogString(OLDEST_FIRST, "html", kDefaultLevel, 1)); + EXPECT_EQ( + "[time] file:0 event0\n", + SkipTime(GetLogString(OLDEST_FIRST, "file,time", kDefaultLevel, 1))); + + AddTestEvent(LOG_LEVEL_DEBUG, "event1"); + EXPECT_EQ("[time] file:0 <i>event1</i>\n", + SkipTime(GetLogString(OLDEST_FIRST, "file,time,html", + LOG_LEVEL_DEBUG, 1))); + + AddTestEvent(kDefaultLevel, "event2"); + EXPECT_EQ("Network: file:0 event2\n", + GetLogString(OLDEST_FIRST, "file,type", kDefaultLevel, 1)); +} + +TEST_F(DeviceEventLogTest, TestLogLevel) { + AddTestEvent(LOG_LEVEL_ERROR, "error1"); + AddTestEvent(LOG_LEVEL_ERROR, "error2"); + AddTestEvent(LOG_LEVEL_EVENT, "event3"); + AddTestEvent(LOG_LEVEL_ERROR, "error4"); + AddTestEvent(LOG_LEVEL_EVENT, "event5"); + AddTestEvent(LOG_LEVEL_DEBUG, "debug6"); + + std::string out; + out = GetLogString(OLDEST_FIRST, "", LOG_LEVEL_ERROR, 0); + EXPECT_EQ(3u, CountLines(out)); + out = GetLogString(OLDEST_FIRST, "", LOG_LEVEL_EVENT, 0); + EXPECT_EQ(5u, CountLines(out)); + out = GetLogString(OLDEST_FIRST, "", LOG_LEVEL_DEBUG, 0); + EXPECT_EQ(6u, CountLines(out)); + + // Test max_level. Get only the ERROR entries. + out = GetLogString(OLDEST_FIRST, "", LOG_LEVEL_ERROR, 0); + EXPECT_EQ("error1\nerror2\nerror4\n", out); +} + +TEST_F(DeviceEventLogTest, TestMaxEvents) { + AddTestEvent(LOG_LEVEL_EVENT, "event1"); + AddTestEvent(LOG_LEVEL_ERROR, "error2"); + AddTestEvent(LOG_LEVEL_EVENT, "event3"); + AddTestEvent(LOG_LEVEL_ERROR, "error4"); + AddTestEvent(LOG_LEVEL_EVENT, "event5"); + + // Oldest first + EXPECT_EQ("error4\n", GetLogString(OLDEST_FIRST, "", LOG_LEVEL_ERROR, 1)); + + EXPECT_EQ("error2\nerror4\n", + GetLogString(OLDEST_FIRST, "", LOG_LEVEL_ERROR, 2)); + + EXPECT_EQ("event3\nerror4\nevent5\n", + GetLogString(OLDEST_FIRST, "", LOG_LEVEL_EVENT, 3)); + + EXPECT_EQ("error2\nevent3\nerror4\nevent5\n", + GetLogString(OLDEST_FIRST, "", LOG_LEVEL_EVENT, 4)); + + EXPECT_EQ("event1\nerror2\nevent3\nerror4\nevent5\n", + GetLogString(OLDEST_FIRST, "", LOG_LEVEL_EVENT, 5)); + + // Newest first + EXPECT_EQ("error4\n", GetLogString(NEWEST_FIRST, "", LOG_LEVEL_ERROR, 1)); + + EXPECT_EQ("error4\nerror2\n", + GetLogString(NEWEST_FIRST, "", LOG_LEVEL_ERROR, 2)); + + EXPECT_EQ("event5\nerror4\nevent3\n", + GetLogString(NEWEST_FIRST, "", LOG_LEVEL_EVENT, 3)); + + EXPECT_EQ("event5\nerror4\nevent3\nerror2\n", + GetLogString(NEWEST_FIRST, "", LOG_LEVEL_EVENT, 4)); + + EXPECT_EQ("event5\nerror4\nevent3\nerror2\nevent1\n", + GetLogString(NEWEST_FIRST, "", LOG_LEVEL_EVENT, 5)); +} + +TEST_F(DeviceEventLogTest, TestMaxErrors) { + const int kMaxTestEntries = 4; + impl_.reset(new DeviceEventLogImpl(kMaxTestEntries)); + AddTestEvent(LOG_LEVEL_EVENT, "event1"); + AddTestEvent(LOG_LEVEL_ERROR, "error2"); + AddTestEvent(LOG_LEVEL_EVENT, "event3"); + AddTestEvent(LOG_LEVEL_ERROR, "error4"); + AddTestEvent(LOG_LEVEL_EVENT, "event5"); + AddTestEvent(LOG_LEVEL_EVENT, "event6"); + EXPECT_EQ("error2\nerror4\nevent5\nevent6\n", + GetLogString(OLDEST_FIRST, "", LOG_LEVEL_DEBUG, 0)); +} + +TEST_F(DeviceEventLogTest, TestType) { + AddEventType(LOG_TYPE_NETWORK, "event1"); + AddEventType(LOG_TYPE_POWER, "event2"); + AddEventType(LOG_TYPE_NETWORK, "event3"); + AddEventType(LOG_TYPE_POWER, "event4"); + AddEventType(LOG_TYPE_NETWORK, "event5"); + AddEventType(LOG_TYPE_NETWORK, "event6"); + EXPECT_EQ( + "Network: event1\nNetwork: event3\nNetwork: event5\nNetwork: event6\n", + GetLogStringForType(LOG_TYPE_NETWORK)); + EXPECT_EQ("Power: event2\nPower: event4\n", + GetLogStringForType(LOG_TYPE_POWER)); + EXPECT_EQ("Power: event2\nPower: event4\n", + GetLogStringForType(LOG_TYPE_NON_NETWORK)); + EXPECT_EQ( + "Network: event1\n" + "Power: event2\n" + "Network: event3\n" + "Power: event4\n" + "Network: event5\n" + "Network: event6\n", + GetLogStringForType(LOG_TYPE_ALL)); +} + +} // namespace device_event_log + +} // namespace chromeos diff --git a/chromeos/network/managed_network_configuration_handler_impl.cc b/chromeos/network/managed_network_configuration_handler_impl.cc index 11d33f4..e750dda 100644 --- a/chromeos/network/managed_network_configuration_handler_impl.cc +++ b/chromeos/network/managed_network_configuration_handler_impl.cc @@ -73,10 +73,9 @@ void InvokeErrorCallback(const std::string& service_path, void LogErrorWithDict(const tracked_objects::Location& from_where, const std::string& error_name, scoped_ptr<base::DictionaryValue> error_data) { - network_event_log::internal::AddEntry( - from_where.file_name(), from_where.line_number(), - network_event_log::LOG_LEVEL_ERROR, - error_name, ""); + device_event_log::AddEntry(from_where.file_name(), from_where.line_number(), + device_event_log::LOG_TYPE_NETWORK, + device_event_log::LOG_LEVEL_ERROR, error_name); } const base::DictionaryValue* GetByGUID(const GuidToPolicyMap& policies, diff --git a/chromeos/network/network_event_log.cc b/chromeos/network/network_event_log.cc deleted file mode 100644 index 3f6d123..0000000 --- a/chromeos/network/network_event_log.cc +++ /dev/null @@ -1,440 +0,0 @@ -// Copyright (c) 2012 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 "chromeos/network/network_event_log.h" - -#include <cmath> -#include <list> - -#include "base/files/file_path.h" -#include "base/json/json_string_value_serializer.h" -#include "base/json/json_writer.h" -#include "base/logging.h" -#include "base/memory/scoped_ptr.h" -#include "base/strings/string_tokenizer.h" -#include "base/strings/stringprintf.h" -#include "base/strings/utf_string_conversions.h" -#include "base/values.h" -#include "net/base/escape.h" - -namespace chromeos { -namespace network_event_log { - -namespace { - -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); -} - -class NetworkEventLog; -NetworkEventLog* g_network_event_log = NULL; -size_t g_max_network_event_log_entries = 4000; -const char* kLogLevelName[] = {"Error", "User", "Event", "Debug"}; - -struct LogEntry { - LogEntry(const std::string& file, - int file_line, - LogLevel log_level, - const std::string& event, - const std::string& description); - - std::string ToString(bool show_time, - bool show_file, - bool show_level, - bool show_desc, - bool format_html) const; - void ToDictionary(base::DictionaryValue*) const; - - std::string GetNormalText(bool show_desc) const; - std::string GetHtmlText(bool show_desc) const; - std::string GetAsJSON() const; - - void SendToVLogOrErrorLog() const; - - bool ContentEquals(const LogEntry& other) const; - - std::string file; - int file_line; - LogLevel log_level; - std::string event; - std::string description; - base::Time time; - int count; -}; - -LogEntry::LogEntry(const std::string& file, - int file_line, - LogLevel log_level, - const std::string& event, - const std::string& description) - : file(file), - file_line(file_line), - log_level(log_level), - event(event), - description(description), - time(base::Time::Now()), - count(1) {} - -std::string LogEntry::ToString(bool show_time, - bool show_file, - bool show_level, - bool show_desc, - bool format_html) const { - std::string line; - if (show_time) - line += "[" + TimeWithMillieconds(time) + "] "; - if (show_level) { - const char* kLevelDesc[] = { - "ERROR", - "USER", - "EVENT", - "DEBUG" - }; - line += base::StringPrintf("%s: ", kLevelDesc[log_level]); - } - if (show_file) { - std::string filestr = format_html ? net::EscapeForHTML(file) : file; - line += base::StringPrintf("%s:%d ", file.c_str(), file_line); - } - line += format_html ? GetHtmlText(show_desc) : GetNormalText(show_desc); - if (count > 1) - line += base::StringPrintf(" (%d)", count); - return line; -} - -void LogEntry::ToDictionary(base::DictionaryValue* output) const { - output->SetString("timestamp", DateAndTimeWithMicroseconds(time)); - output->SetString("timestampshort", TimeWithSeconds(time)); - output->SetString("level", kLogLevelName[log_level]); - output->SetString("file", - base::StringPrintf("%s:%d ", file.c_str(), file_line)); - output->SetString("event", event); - output->SetString("description", description); -} - -std::string LogEntry::GetAsJSON() const { - base::DictionaryValue entry; - ToDictionary(&entry); - std::string json; - JSONStringValueSerializer serializer(&json); - if (!serializer.Serialize(entry)) { - LOG(ERROR) << "Failed to serialize to JSON"; - } - return json; -} - -std::string LogEntry::GetNormalText(bool show_desc) const { - std::string text = event; - if (show_desc && !description.empty()) - text += ": " + description; - return text; -} - -std::string LogEntry::GetHtmlText(bool show_desc) const { - std::string text; - if (log_level == LOG_LEVEL_DEBUG) - text += "<i>"; - else if (log_level == LOG_LEVEL_USER) - text += "<b>"; - else if (log_level == LOG_LEVEL_ERROR) - text += "<b><i>"; - - text += event; - if (show_desc && !description.empty()) - text += ": " + net::EscapeForHTML(description); - - if (log_level == LOG_LEVEL_DEBUG) - text += "</i>"; - else if (log_level == LOG_LEVEL_USER) - text += "</b>"; - else if (log_level == LOG_LEVEL_ERROR) - text += "</i></b>"; - return text; -} - -void LogEntry::SendToVLogOrErrorLog() const { - if (log_level != LOG_LEVEL_ERROR && !VLOG_IS_ON(1)) - return; - const bool show_time = true; - const bool show_file = true; - const bool show_level = false; - const bool show_desc = true; - const bool format_html = false; - std::string output = - ToString(show_time, show_file, show_level, show_desc, format_html); - if (log_level == LOG_LEVEL_ERROR) - LOG(ERROR) << output; - else - VLOG(1) << output; -} - -bool LogEntry::ContentEquals(const LogEntry& other) const { - return file == other.file && - file_line == other.file_line && - event == other.event && - description == other.description; -} - -void GetFormat(const std::string& format_string, - bool* show_time, - bool* show_file, - bool* show_level, - bool* show_desc, - bool* format_html, - bool* format_json) { - base::StringTokenizer tokens(format_string, ","); - *show_time = false; - *show_file = false; - *show_level = false; - *show_desc = false; - *format_html = false; - *format_json = false; - while (tokens.GetNext()) { - std::string tok(tokens.token()); - if (tok == "time") - *show_time = true; - if (tok == "file") - *show_file = true; - if (tok == "level") - *show_level = true; - if (tok == "desc") - *show_desc = true; - if (tok == "html") - *format_html = true; - if (tok == "json") - *format_json = true; - } -} - -typedef std::list<LogEntry> LogEntryList; - -class NetworkEventLog { - public: - NetworkEventLog() {} - ~NetworkEventLog() {} - - void AddLogEntry(const LogEntry& entry); - - std::string GetAsString(StringOrder order, - const std::string& format, - LogLevel max_level, - size_t max_events); - - LogEntryList& entries() { return entries_; } - - private: - LogEntryList entries_; - - DISALLOW_COPY_AND_ASSIGN(NetworkEventLog); -}; - -void NetworkEventLog::AddLogEntry(const LogEntry& entry) { - if (!entries_.empty()) { - LogEntry& last = entries_.back(); - if (last.ContentEquals(entry)) { - // Update count and time for identical events to avoid log spam. - ++last.count; - last.log_level = std::min(last.log_level, entry.log_level); - last.time = base::Time::Now(); - return; - } - } - if (entries_.size() >= g_max_network_event_log_entries) { - const size_t max_error_entries = g_max_network_event_log_entries / 2; - // 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 (LogEntryList::iterator iter = entries_.begin(); iter != entries_.end(); - ++iter) { - if (iter->log_level != LOG_LEVEL_ERROR) { - entries_.erase(iter); - break; - } - if (++error_count > max_error_entries) { - // Too many error entries, remove the oldest entry. - entries_.pop_front(); - break; - } - } - } - entries_.push_back(entry); - entry.SendToVLogOrErrorLog(); -} - -std::string NetworkEventLog::GetAsString(StringOrder order, - const std::string& format, - LogLevel max_level, - size_t max_events) { - if (entries_.empty()) - return "No Log Entries."; - - bool show_time, show_file, show_level, show_desc, format_html, format_json; - GetFormat(format, - &show_time, - &show_file, - &show_level, - &show_desc, - &format_html, - &format_json); - - std::string result; - base::ListValue log_entries; - 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 (LogEntryList::const_reverse_iterator riter = entries_.rbegin(); - riter != entries_.rend(); - ++riter) { - ++num_entries; - if (riter->log_level > max_level) - continue; - if (++shown_events >= max_events) - break; - } - offset = entries_.size() - num_entries; - } - for (LogEntryList::const_iterator iter = entries_.begin(); - iter != entries_.end(); - ++iter) { - if (offset > 0) { - --offset; - continue; - } - if (iter->log_level > max_level) - continue; - if (format_json) { - log_entries.AppendString((*iter).GetAsJSON()); - } else { - result += (*iter).ToString( - show_time, show_file, show_level, show_desc, format_html); - result += "\n"; - } - } - } else { - size_t nlines = 0; - // Iterate backwards through the list to show the most recent entries first. - for (LogEntryList::const_reverse_iterator riter = entries_.rbegin(); - riter != entries_.rend(); - ++riter) { - if (riter->log_level > max_level) - continue; - if (format_json) { - log_entries.AppendString((*riter).GetAsJSON()); - } else { - result += (*riter).ToString( - show_time, show_file, show_level, show_desc, format_html); - result += "\n"; - } - if (max_events > 0 && ++nlines >= max_events) - break; - } - } - if (format_json) { - JSONStringValueSerializer serializer(&result); - serializer.Serialize(log_entries); - } - - return result; -} - -} // namespace - -const LogLevel kDefaultLogLevel = LOG_LEVEL_EVENT; - -void Initialize() { - if (g_network_event_log) - delete g_network_event_log; // reset log - g_network_event_log = new NetworkEventLog(); -} - -void Shutdown() { - delete g_network_event_log; - g_network_event_log = NULL; -} - -bool IsInitialized() { return g_network_event_log != NULL; } - -namespace internal { - -size_t GetMaxLogEntries() { return g_max_network_event_log_entries; } - -void SetMaxLogEntries(size_t max_entries) { - g_max_network_event_log_entries = max_entries; - if (!g_network_event_log) - return; - while (g_network_event_log->entries().size() > max_entries) - g_network_event_log->entries().pop_front(); -} - -void AddEntry(const char* file, - int file_line, - LogLevel log_level, - const std::string& event, - const std::string& description) { - std::string filestr; - if (file) - filestr = base::FilePath(std::string(file)).BaseName().value(); - LogEntry entry(filestr, file_line, log_level, event, description); - if (!g_network_event_log) { - entry.SendToVLogOrErrorLog(); - return; - } - g_network_event_log->AddLogEntry(entry); -} - -} // namespace internal - -std::string GetAsString(StringOrder order, - const std::string& format, - LogLevel max_level, - size_t max_events) { - if (!g_network_event_log) - return "NetworkEventLog not initialized."; - return g_network_event_log->GetAsString(order, format, max_level, max_events); -} - -std::string ValueAsString(const base::Value& value) { - std::string vstr; - base::JSONWriter::WriteWithOptions( - &value, base::JSONWriter::OPTIONS_OMIT_BINARY_VALUES, &vstr); - return vstr.empty() ? "''" : vstr; -} - -} // namespace network_event_log -} // namespace chromeos diff --git a/chromeos/network/network_event_log.h b/chromeos/network/network_event_log.h index 2bdb451..104da00 100644 --- a/chromeos/network/network_event_log.h +++ b/chromeos/network/network_event_log.h @@ -12,6 +12,7 @@ #include "base/strings/stringprintf.h" #include "base/time/time.h" #include "chromeos/chromeos_export.h" +#include "chromeos/device_event_log.h" namespace base { class Value; @@ -22,41 +23,8 @@ namespace chromeos { // Namespace for functions for logging network events. namespace network_event_log { -// Used to determine which order to output event entries in GetAsString. -enum StringOrder { - OLDEST_FIRST, - NEWEST_FIRST -}; - -// Used to set the detail level for logging. -enum LogLevel { - LOG_LEVEL_ERROR = 0, - LOG_LEVEL_USER = 1, - LOG_LEVEL_EVENT = 2, - LOG_LEVEL_DEBUG = 3 -}; - -// Default log level. -CHROMEOS_EXPORT extern const LogLevel kDefaultLogLevel; - -// Initializes / shuts down network event logging. Calling Initialize more than -// once will reset the log. -CHROMEOS_EXPORT void Initialize(); -CHROMEOS_EXPORT void Shutdown(); - -// Returns true if network event logging has been initialized. -CHROMEOS_EXPORT bool IsInitialized(); - namespace internal { -// Gets the maximum number of log entries. -CHROMEOS_EXPORT size_t GetMaxLogEntries(); - -// Sets the maximum number of entries to something other than the default. If -// |max_entries| is less than the current maximum number of entries, this will -// delete any existing entries in excess of |max_entries|. -CHROMEOS_EXPORT void SetMaxLogEntries(size_t max_entries); - // Adds an entry to the event log at level specified by |log_level|. // A maximum number of events are recorded after which new events replace // old ones. Error events are prioritized such that error events will only be @@ -65,55 +33,37 @@ CHROMEOS_EXPORT void SetMaxLogEntries(size_t max_entries); // has been called. NOTE: Generally use NET_LOG instead. CHROMEOS_EXPORT void AddEntry(const char* file, int file_line, - LogLevel log_level, + device_event_log::LogLevel log_level, const std::string& event, const std::string& description); } // namespace internal -// Outputs the log to a formatted string. -// |order| determines which order to output the events. -// |format| is a string that determines which elements to show. Elements -// must be comma-separated, e.g. "time,desc". -// Note: order of the format strings does not affect the output. -// "time" - Include a timestamp. -// "file" - Include file and line number. -// "desc" - Include the description. -// "html" - Include html tags. -// "json" - Return as JSON format -// Only events with |log_level| <= |max_level| are included in the output. -// If |max_events| > 0, limits how many events are output. -// If |json| is specified, returns a JSON list of dictionaries containing time, -// level, file, event, and description. -CHROMEOS_EXPORT std::string GetAsString(StringOrder order, - const std::string& format, - LogLevel max_level, - size_t max_events); - // Helper function for displaying a value as a string. CHROMEOS_EXPORT std::string ValueAsString(const base::Value& value); // Errors -#define NET_LOG_ERROR(event, desc) NET_LOG_LEVEL( \ - ::chromeos::network_event_log::LOG_LEVEL_ERROR, event, desc) +#define NET_LOG_ERROR(event, desc) \ + NET_LOG_LEVEL(::chromeos::device_event_log::LOG_LEVEL_ERROR, event, desc) // Chrome initiated events, e.g. connection requests, scan requests, // configuration removal (either from the UI or from ONC policy application). -#define NET_LOG_USER(event, desc) NET_LOG_LEVEL( \ - ::chromeos::network_event_log::LOG_LEVEL_USER, event, desc) +#define NET_LOG_USER(event, desc) \ + NET_LOG_LEVEL(::chromeos::device_event_log::LOG_LEVEL_USER, event, desc) // Important events, e.g. state updates -#define NET_LOG_EVENT(event, desc) NET_LOG_LEVEL( \ - ::chromeos::network_event_log::LOG_LEVEL_EVENT, event, desc) +#define NET_LOG_EVENT(event, desc) \ + NET_LOG_LEVEL(::chromeos::device_event_log::LOG_LEVEL_EVENT, event, desc) // Non-essential debugging events -#define NET_LOG_DEBUG(event, desc) NET_LOG_LEVEL( \ - ::chromeos::network_event_log::LOG_LEVEL_DEBUG, event, desc) +#define NET_LOG_DEBUG(event, desc) \ + NET_LOG_LEVEL(::chromeos::device_event_log::LOG_LEVEL_DEBUG, event, desc) // Macro to include file and line number info in the event log. -#define NET_LOG_LEVEL(log_level, event, description) \ - ::chromeos::network_event_log::internal::AddEntry( \ - __FILE__, __LINE__, log_level, event, description) +#define NET_LOG_LEVEL(log_level, event, description) \ + ::chromeos::device_event_log::AddEntryWithDescription( \ + __FILE__, __LINE__, ::chromeos::device_event_log::LOG_TYPE_NETWORK, \ + log_level, event, description) } // namespace network_event_log diff --git a/chromeos/network/network_event_log_unittest.cc b/chromeos/network/network_event_log_unittest.cc deleted file mode 100644 index 8a06488..0000000 --- a/chromeos/network/network_event_log_unittest.cc +++ /dev/null @@ -1,244 +0,0 @@ -// Copyright (c) 2012 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 "chromeos/network/network_event_log.h" - -#include <algorithm> - -#include "base/basictypes.h" -#include "base/compiler_specific.h" -#include "base/format_macros.h" -#include "base/strings/string_split.h" -#include "base/strings/stringprintf.h" -#include "testing/gtest/include/gtest/gtest.h" - -namespace chromeos { -namespace network_event_log { - -namespace { - -network_event_log::LogLevel kDefaultLevel = network_event_log::LOG_LEVEL_EVENT; - -} // namespace - -class NetworkEventLogTest : public testing::Test { - public: - NetworkEventLogTest() { - } - - virtual void SetUp() override { - network_event_log::Initialize(); - } - - virtual void TearDown() override { - network_event_log::Shutdown(); - } - - protected: - std::string SkipTime(const std::string& input) { - std::string output; - std::vector<std::string> lines; - base::SplitString(input, '\n', &lines); - for (size_t i = 0; i < lines.size(); ++i) { - size_t n = lines[i].find(']'); - if (n != std::string::npos) - output += "[time] " + lines[i].substr(n+2) + '\n'; - else - output += lines[i]; - } - return output; - } - - size_t CountLines(const std::string& input) { - return std::count(input.begin(), input.end(), '\n'); - } - - std::string GetLogString(StringOrder order, size_t max_events) { - return network_event_log::GetAsString( - order, "file,desc", kDefaultLevel, max_events); - } - - private: - DISALLOW_COPY_AND_ASSIGN(NetworkEventLogTest); -}; - -TEST_F(NetworkEventLogTest, TestNetworkEvents) { - std::string output_none = GetLogString(OLDEST_FIRST, 0); - EXPECT_EQ("No Log Entries.", output_none); - - LogLevel level = kDefaultLevel; - network_event_log::internal::AddEntry( - "file1", 1, level, "event1", "description1"); - network_event_log::internal::AddEntry( - "file2", 2, level, "event2", "description2"); - network_event_log::internal::AddEntry( - "file3", 3, level, "event3", "description3"); - network_event_log::internal::AddEntry( - "file3", 3, level, "event3", "description3"); - - const std::string expected_output_oldest_first( - "file1:1 event1: description1\n" - "file2:2 event2: description2\n" - "file3:3 event3: description3 (2)\n"); - std::string output_oldest_first = GetLogString(OLDEST_FIRST, 0); - EXPECT_EQ(expected_output_oldest_first, output_oldest_first); - - const std::string expected_output_oldest_first_short( - "file2:2 event2: description2\n" - "file3:3 event3: description3 (2)\n"); - std::string output_oldest_first_short = GetLogString(OLDEST_FIRST, 2); - EXPECT_EQ(expected_output_oldest_first_short, output_oldest_first_short); - - const std::string expected_output_newest_first( - "file3:3 event3: description3 (2)\n" - "file2:2 event2: description2\n" - "file1:1 event1: description1\n"); - std::string output_newest_first = GetLogString(NEWEST_FIRST, 0); - EXPECT_EQ(expected_output_newest_first, output_newest_first); - - const std::string expected_output_newest_first_short( - "file3:3 event3: description3 (2)\n" - "file2:2 event2: description2\n"); - std::string output_newest_first_short = GetLogString(NEWEST_FIRST, 2); - EXPECT_EQ(expected_output_newest_first_short, output_newest_first_short); -} - -TEST_F(NetworkEventLogTest, TestMaxNetworkEvents) { - const size_t max_entries = network_event_log::internal::GetMaxLogEntries(); - const size_t entries_to_add = max_entries + 3; - for (size_t i = 0; i < entries_to_add; ++i) { - network_event_log::internal::AddEntry( - "test", 1, LOG_LEVEL_EVENT, - base::StringPrintf("event_%" PRIuS, i), ""); - } - std::string output = GetLogString(OLDEST_FIRST, 0); - size_t output_lines = CountLines(output); - EXPECT_EQ(max_entries, output_lines); -} - -TEST_F(NetworkEventLogTest, TestStringFormat) { - network_event_log::internal::AddEntry( - "file", 0, LOG_LEVEL_ERROR, "event0", "description"); - EXPECT_EQ("file:0 event0\n", network_event_log::GetAsString( - OLDEST_FIRST, "file", kDefaultLevel, 1)); - EXPECT_EQ("[time] event0\n", SkipTime(network_event_log::GetAsString( - OLDEST_FIRST, "time", kDefaultLevel, 1))); - EXPECT_EQ("event0: description\n", network_event_log::GetAsString( - OLDEST_FIRST, "desc", kDefaultLevel, 1)); - EXPECT_EQ("event0\n", network_event_log::GetAsString( - OLDEST_FIRST, "", kDefaultLevel, 1)); - EXPECT_EQ("<b><i>event0</i></b>\n", network_event_log::GetAsString( - OLDEST_FIRST, "html", kDefaultLevel, 1)); - EXPECT_EQ("[time] file:0 event0: description\n", - SkipTime(network_event_log::GetAsString( - OLDEST_FIRST, "file,time,desc", kDefaultLevel, 1))); - - network_event_log::internal::AddEntry( - "file", 0, LOG_LEVEL_DEBUG, "event1", "description"); - EXPECT_EQ("[time] file:0 <i>event1: description</i>\n", - SkipTime(network_event_log::GetAsString( - OLDEST_FIRST, "file,time,desc,html", LOG_LEVEL_DEBUG, 1))); -} - -namespace { - -void AddTestEvent(LogLevel level, const std::string& event) { - network_event_log::internal::AddEntry("file", 0, level, event, "description"); -} - -} // namespace - -TEST_F(NetworkEventLogTest, TestLogLevel) { - AddTestEvent(LOG_LEVEL_ERROR, "error1"); - AddTestEvent(LOG_LEVEL_ERROR, "error2"); - AddTestEvent(LOG_LEVEL_EVENT, "event3"); - AddTestEvent(LOG_LEVEL_ERROR, "error4"); - AddTestEvent(LOG_LEVEL_EVENT, "event5"); - AddTestEvent(LOG_LEVEL_DEBUG, "debug6"); - - std::string output; - output = network_event_log::GetAsString( - OLDEST_FIRST, "", LOG_LEVEL_ERROR, 0); - EXPECT_EQ(3u, CountLines(output)); - output = network_event_log::GetAsString( - OLDEST_FIRST, "", LOG_LEVEL_EVENT, 0); - EXPECT_EQ(5u, CountLines(output)); - output = network_event_log::GetAsString( - OLDEST_FIRST, "", LOG_LEVEL_DEBUG, 0); - EXPECT_EQ(6u, CountLines(output)); - - // Test max_level. Get only the ERROR entries. - output = network_event_log::GetAsString( - OLDEST_FIRST, "", LOG_LEVEL_ERROR, 0); - EXPECT_EQ("error1\nerror2\nerror4\n", output); -} - -TEST_F(NetworkEventLogTest, TestMaxEvents) { - AddTestEvent(LOG_LEVEL_EVENT, "event1"); - AddTestEvent(LOG_LEVEL_ERROR, "error2"); - AddTestEvent(LOG_LEVEL_EVENT, "event3"); - AddTestEvent(LOG_LEVEL_ERROR, "error4"); - AddTestEvent(LOG_LEVEL_EVENT, "event5"); - - // Oldest first - EXPECT_EQ("error4\n", network_event_log::GetAsString( - OLDEST_FIRST, "", LOG_LEVEL_ERROR, 1)); - - EXPECT_EQ("error2\nerror4\n", network_event_log::GetAsString( - OLDEST_FIRST, "", LOG_LEVEL_ERROR, 2)); - - EXPECT_EQ("event3\nerror4\nevent5\n", network_event_log::GetAsString( - OLDEST_FIRST, "", LOG_LEVEL_EVENT, 3)); - - EXPECT_EQ("error2\nevent3\nerror4\nevent5\n", network_event_log::GetAsString( - OLDEST_FIRST, "", LOG_LEVEL_EVENT, 4)); - - EXPECT_EQ("event1\nerror2\nevent3\nerror4\nevent5\n", - network_event_log::GetAsString( - OLDEST_FIRST, "", LOG_LEVEL_EVENT, 5)); - - // Newest first - EXPECT_EQ("error4\n", network_event_log::GetAsString( - NEWEST_FIRST, "", LOG_LEVEL_ERROR, 1)); - - EXPECT_EQ("error4\nerror2\n", network_event_log::GetAsString( - NEWEST_FIRST, "", LOG_LEVEL_ERROR, 2)); - - EXPECT_EQ("event5\nerror4\nevent3\n", network_event_log::GetAsString( - NEWEST_FIRST, "", LOG_LEVEL_EVENT, 3)); - - EXPECT_EQ("event5\nerror4\nevent3\nerror2\n", network_event_log::GetAsString( - NEWEST_FIRST, "", LOG_LEVEL_EVENT, 4)); - - EXPECT_EQ("event5\nerror4\nevent3\nerror2\nevent1\n", - network_event_log::GetAsString( - NEWEST_FIRST, "", LOG_LEVEL_EVENT, 5)); -} - -TEST_F(NetworkEventLogTest, TestMaxErrors) { - network_event_log::internal::SetMaxLogEntries(4); - AddTestEvent(LOG_LEVEL_EVENT, "event1"); - AddTestEvent(LOG_LEVEL_ERROR, "error2"); - AddTestEvent(LOG_LEVEL_EVENT, "event3"); - AddTestEvent(LOG_LEVEL_ERROR, "error4"); - AddTestEvent(LOG_LEVEL_EVENT, "event5"); - AddTestEvent(LOG_LEVEL_EVENT, "event6"); - EXPECT_EQ("error2\nerror4\nevent5\nevent6\n", network_event_log::GetAsString( - OLDEST_FIRST, "", LOG_LEVEL_DEBUG, 0)); - network_event_log::internal::SetMaxLogEntries(0); - EXPECT_EQ("No Log Entries.", network_event_log::GetAsString( - OLDEST_FIRST, "", LOG_LEVEL_DEBUG, 0)); - network_event_log::internal::SetMaxLogEntries(4); - AddTestEvent(LOG_LEVEL_ERROR, "error1"); - AddTestEvent(LOG_LEVEL_ERROR, "error2"); - AddTestEvent(LOG_LEVEL_ERROR, "error3"); - AddTestEvent(LOG_LEVEL_ERROR, "error4"); - AddTestEvent(LOG_LEVEL_EVENT, "event5"); - AddTestEvent(LOG_LEVEL_EVENT, "event6"); - EXPECT_EQ("error3\nerror4\nevent5\nevent6\n", network_event_log::GetAsString( - OLDEST_FIRST, "", LOG_LEVEL_DEBUG, 0)); -} - -} // namespace network_event_log -} // namespace chromeos diff --git a/chromeos/network/network_handler.cc b/chromeos/network/network_handler.cc index e54c935..05280cf 100644 --- a/chromeos/network/network_handler.cc +++ b/chromeos/network/network_handler.cc @@ -15,7 +15,6 @@ #include "chromeos/network/network_configuration_handler.h" #include "chromeos/network/network_connection_handler.h" #include "chromeos/network/network_device_handler_impl.h" -#include "chromeos/network/network_event_log.h" #include "chromeos/network/network_profile_handler.h" #include "chromeos/network/network_profile_observer.h" #include "chromeos/network/network_sms_handler.h" @@ -30,8 +29,6 @@ NetworkHandler::NetworkHandler() : message_loop_(base::MessageLoopProxy::current()) { CHECK(DBusThreadManager::IsInitialized()); - network_event_log::Initialize(); - network_state_handler_.reset(new NetworkStateHandler()); network_device_handler_.reset(new NetworkDeviceHandlerImpl()); network_profile_handler_.reset(new NetworkProfileHandler()); @@ -50,7 +47,6 @@ NetworkHandler::NetworkHandler() } NetworkHandler::~NetworkHandler() { - network_event_log::Shutdown(); } void NetworkHandler::Init() { diff --git a/chromeos/network/network_state_handler.cc b/chromeos/network/network_state_handler.cc index bbfa6ce7..a4562b0 100644 --- a/chromeos/network/network_state_handler.cc +++ b/chromeos/network/network_state_handler.cc @@ -7,6 +7,8 @@ #include "base/bind.h" #include "base/format_macros.h" #include "base/guid.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/metrics/histogram.h" @@ -51,6 +53,13 @@ std::string GetLogName(const ManagedState* state) { state->path().c_str()); } +std::string ValueAsString(const base::Value& value) { + std::string vstr; + base::JSONWriter::WriteWithOptions( + &value, base::JSONWriter::OPTIONS_OMIT_BINARY_VALUES, &vstr); + return vstr.empty() ? "''" : vstr; +} + } // namespace const char NetworkStateHandler::kDefaultCheckPortalList[] = @@ -82,20 +91,20 @@ void NetworkStateHandler::AddObserver( NetworkStateHandlerObserver* observer, const tracked_objects::Location& from_here) { observers_.AddObserver(observer); - network_event_log::internal::AddEntry( - from_here.file_name(), from_here.line_number(), - network_event_log::LOG_LEVEL_DEBUG, - "NetworkStateHandler::AddObserver", ""); + device_event_log::AddEntry(from_here.file_name(), from_here.line_number(), + device_event_log::LOG_TYPE_NETWORK, + device_event_log::LOG_LEVEL_DEBUG, + "NetworkStateHandler::AddObserver"); } void NetworkStateHandler::RemoveObserver( NetworkStateHandlerObserver* observer, const tracked_objects::Location& from_here) { observers_.RemoveObserver(observer); - network_event_log::internal::AddEntry( - from_here.file_name(), from_here.line_number(), - network_event_log::LOG_LEVEL_DEBUG, - "NetworkStateHandler::RemoveObserver", ""); + device_event_log::AddEntry(from_here.file_name(), from_here.line_number(), + device_event_log::LOG_TYPE_NETWORK, + device_event_log::LOG_LEVEL_DEBUG, + "NetworkStateHandler::RemoveObserver"); } NetworkStateHandler::TechnologyState NetworkStateHandler::GetTechnologyState( @@ -569,12 +578,12 @@ void NetworkStateHandler::UpdateNetworkServiceProperty( } // Log event. std::string detail = network->name() + "." + key; - detail += " = " + network_event_log::ValueAsString(value); - network_event_log::LogLevel log_level; + detail += " = " + ValueAsString(value); + device_event_log::LogLevel log_level; if (key == shill::kErrorProperty || key == shill::kErrorDetailsProperty) { - log_level = network_event_log::LOG_LEVEL_ERROR; + log_level = device_event_log::LOG_LEVEL_ERROR; } else { - log_level = network_event_log::LOG_LEVEL_EVENT; + log_level = device_event_log::LOG_LEVEL_EVENT; } NET_LOG_LEVEL(log_level, log_event, detail); } @@ -599,7 +608,7 @@ void NetworkStateHandler::UpdateDeviceProperty(const std::string& device_path, return; std::string detail = device->name() + "." + key; - detail += " = " + network_event_log::ValueAsString(value); + detail += " = " + ValueAsString(value); NET_LOG_EVENT("DevicePropertyUpdated", detail); NotifyDeviceListChanged(); |