Add logging for slow device events, limit network UI update rate

chromeos/device_event_log.h

 // 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 "base/timer/elapsed_timer.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)
 #define LOGIN_LOG(level)                                   \
   DEVICE_LOG(::chromeos::device_event_log::LOG_TYPE_LOGIN, \
              ::chromeos::device_event_log::LOG_LEVEL_##level)
 
-// Generally prefer the above macros unless |level| is not constant.
+// Generally prefer the above macros unless |type| or  |level| is not constant.
 
 #define DEVICE_LOG(type, level)                                   \
   ::chromeos::device_event_log::internal::DeviceEventLogInstance( \
       __FILE__, __LINE__, type, level).stream()
 
+// Declare {Type_LOG_IF_SLOW() at the top of a method to log slow methods
+// where "slow" is defined by kSlowMethodThresholdMs in the .cc file.
+#define SCOPED_NET_LOG_IF_SLOW() \
+  SCOPED_DEVICE_LOG_IF_SLOW(::chromeos::device_event_log::LOG_TYPE_NETWORK)
+
+// Generally prefer the above macros unless |type| is not constant.
+
+#define SCOPED_DEVICE_LOG_IF_SLOW(type)                   \
+  ::chromeos::device_event_log::internal::DeviceLogIfSlow \
+      scoped_device_log_if_slow(type, __FILE__, __func__)
+
 namespace device_event_log {
 
 // Used to specify the type of event. NOTE: Be sure to update LogTypeFromString
 // and GetLogTypeString when adding entries to this enum. Also consider
 // updating chrome://device-log (see device_log_ui.cc).
 enum LogType {
   // Shill / network configuration related events.
   LOG_TYPE_NETWORK,
   // Power manager related events.
   LOG_TYPE_POWER,
@@ skipping 58 matching lines @@
 CHROMEOS_EXPORT std::string GetAsString(StringOrder order,
                                         const std::string& format,
                                         const std::string& types,
                                         LogLevel max_level,
                                         size_t max_events);
 
 CHROMEOS_EXPORT extern const LogLevel kDefaultLogLevel;
 
 namespace internal {
 
+// Implementation class for DEVICE_LOG macros. Provides a stream for creating
+// a log string and adds the event using device_event_log::AddEntry on
+// destruction.
 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);
 };
 
+// Implementation class for SCOPED_LOG_IF_SLOW macros. Tests the elapsed time on
+// destruction and adds a Debug or Error log entry if it exceeds the
+// corresponding expected maximum elapsed time.
+class CHROMEOS_EXPORT DeviceLogIfSlow {

[satorux1, 2014/12/18 05:18:52]

Because macros are now prefixed SCOPED_, this class might want to have the same
prefix.

[stevenjb, 2014/12/18 18:16:17]

Done.

+ public:
+  DeviceLogIfSlow(LogType type, const char* file, const std::string& name);
+  ~DeviceLogIfSlow();
+
+ private:
+  const char* file_;
+  LogType type_;
+  std::string name_;
+  base::ElapsedTimer timer_;
+};
+
 }  // namespace internal
 
 }  // namespace device_event_log
 
 }  // namespace chromeos
 
 #endif  // CHROMEOS_DEVICE_EVENT_LOG_H_