Log time between network drops -- from online to offline.

Rewrite most of metrics_daemon. Convert to low-level D-Bus API -- this
simplifies the code a little and also allows us to catch the power
state signal. I still suspect we may be abusing D-Bus a little but it
seems to work.

snanda@ -- please review the power state code specifically.

BUG=none
TEST=tested on target platform and arm-generic builds

Review URL: http://codereview.chromium.org/1799001
diff --git a/metrics/Makefile b/metrics/Makefile
index 0b04736..54b9f53 100644
--- a/metrics/Makefile
+++ b/metrics/Makefile
@@ -8,7 +8,7 @@
 CCONFIG = $(shell $(PKG_CONFIG) --cflags dbus-1 glib-2.0 dbus-glib-1)
 LDCONFIG = $(shell $(PKG_CONFIG) --libs dbus-1 glib-2.0 gthread-2.0 dbus-glib-1)
 
-CFLAGS = -Wall -Werror -I/usr/include -fpic -O2 $(CCONFIG)
+CFLAGS = -Wall -Werror -I/usr/include -fPIC -O2 $(CCONFIG)
 CXXFLAGS = $(CFLAGS) -fno-exceptions
 
 CLIENT = metrics_client
@@ -22,11 +22,9 @@
 LIB_OBJS = \
 	metrics_library.o
 DAEMON_OBJS = \
-	marshal_void__string_boxed.o \
 	metrics_daemon.o \
 	metrics_daemon_main.o
 TESTDAEMON_OBJS = \
-	marshal_void__string_boxed.o \
 	metrics_daemon.o \
 	metrics_daemon_unittest.o
 
@@ -56,26 +54,16 @@
 %.o: %.c
 	$(CC) $(CFLAGS) -c $< -o $@
 
-%.c: %.list
-	glib-genmarshal --body --prefix=marshal $< > $@
-
-%.h: %.list
-	glib-genmarshal --header --prefix=marshal $< > $@
-
 # dependencies in addition to those defined by the rules
 
 metrics_daemon.o: \
-	marshal_void__string_boxed.h \
 	metrics_daemon.h \
-	network_states.h
+	network_states.h \
+	power_states.h
 metrics_daemon_unittest.o: \
-	marshal_void__string_boxed.h \
 	metrics_daemon.h \
-	network_states.h
-marshal_void__string_boxed.o: \
-	marshal_void__string_boxed.h
-
-.PRECIOUS: marshal_void__string_boxed.c  # keep around for debugging
+	network_states.h \
+	power_states.h
 
 install:
 	install $(CLIENT) $(DESTDIR)/usr/bin
@@ -87,5 +75,4 @@
 	install omaha_tracker.sh $(DESTDIR)/usr/sbin
 
 clean:
-	rm -f $(CLIENT) $(DAEMON) $(LIB) $(SHAREDLIB) $(TESTDAEMON)
-	rm -f *.o marshal_void__string_boxed.[ch]
+	rm -f $(CLIENT) $(DAEMON) $(LIB) $(SHAREDLIB) $(TESTDAEMON) *.o
diff --git a/metrics/marshal_void__string_boxed.list b/metrics/marshal_void__string_boxed.list
deleted file mode 100644
index e72aa4b..0000000
--- a/metrics/marshal_void__string_boxed.list
+++ /dev/null
@@ -1 +0,0 @@
-VOID:STRING,BOXED
diff --git a/metrics/metrics_daemon.cc b/metrics/metrics_daemon.cc
index 9400851..32581c1 100644
--- a/metrics/metrics_daemon.cc
+++ b/metrics/metrics_daemon.cc
@@ -5,22 +5,43 @@
 #include "metrics_daemon.h"
 #include "metrics_library.h"
 
-#include <glib-object.h>
-
-extern "C" {
-#include "marshal_void__string_boxed.h"
-}
+#include <dbus/dbus-glib-lowlevel.h>
 
 #include <base/logging.h>
 
-#define SAFE_MESSAGE(e) ((e && e->message) ? e->message : "unknown error")
+#define SAFE_MESSAGE(e) (e.message ? e.message : "unknown error")
+#define DBUS_IFACE_CONNMAN_MANAGER "org.moblin.connman.Manager"
+#define DBUS_IFACE_POWER_MANAGER "org.chromium.Power.Manager"
 
-MetricsDaemon::NetworkState
+// static
+const char*
+MetricsDaemon::dbus_matches_[] = {
+  "type='signal',"
+  "sender='org.moblin.connman',"
+  "interface='" DBUS_IFACE_CONNMAN_MANAGER "',"
+  "path='/',"
+  "member='StateChanged'",
+
+  "type='signal',"
+  "interface='" DBUS_IFACE_POWER_MANAGER "',"
+  "path='/',"
+  "member='PowerStateChanged'",
+};
+
+// static
+const char *
 MetricsDaemon::network_states_[MetricsDaemon::kNumberNetworkStates] = {
-#define STATE(name, capname) { #name, "Network.Connman" # capname },
+#define STATE(name, capname) #name,
 #include "network_states.h"
 };
 
+// static
+const char *
+MetricsDaemon::power_states_[MetricsDaemon::kNumberPowerStates] = {
+#define STATE(name, capname) #name,
+#include "power_states.h"
+};
+
 void MetricsDaemon::Run(bool run_as_daemon, bool testing) {
   Init(testing);
   if (!run_as_daemon || daemon(0, 0) == 0) {
@@ -30,115 +51,139 @@
 
 void MetricsDaemon::Init(bool testing) {
   testing_ = testing;
-  network_state_id_ = kUnknownNetworkStateId;
+  network_state_ = kUnknownNetworkState;
+  network_state_changed_ = 0;
+  power_state_ = kUnknownPowerState;
 
-  ::g_thread_init(NULL);
-  ::g_type_init();
-  ::dbus_g_thread_init();
+  g_thread_init(NULL);
+  g_type_init();
+  dbus_g_thread_init();
 
-  ::GError* error = NULL;
-  ::DBusGConnection* dbc = ::dbus_g_bus_get(DBUS_BUS_SYSTEM, &error);
-  // Note that LOG(FATAL) terminates the process; otherwise we'd have to worry
-  // about leaking |error|.
-  LOG_IF(FATAL, dbc == NULL) <<
-    "cannot connect to dbus: " << SAFE_MESSAGE(error);
+  DBusError error;
+  dbus_error_init(&error);
 
-  ::DBusGProxy* net_proxy = ::dbus_g_proxy_new_for_name(
-      dbc, "org.moblin.connman", "/", "org.moblin.connman.Metrics");
-  LOG_IF(FATAL, net_proxy == NULL) << "no dbus proxy for network";
+  DBusConnection *connection = dbus_bus_get(DBUS_BUS_SYSTEM, &error);
+  LOG_IF(FATAL, dbus_error_is_set(&error)) <<
+      "No D-Bus connection: " << SAFE_MESSAGE(error);
 
-#if 0
-  // Unclear how soon one can call dbus_g_type_get_map().  Doing it before the
-  // call to dbus_g_bus_get() results in a (non-fatal) assertion failure.
-  // GetProperties returns a hash table.
-  hashtable_gtype = ::dbus_g_type_get_map("GHashTable", G_TYPE_STRING,
-                                          G_TYPE_VALUE);
-#endif
+  dbus_connection_setup_with_g_main(connection, NULL);
 
-  dbus_g_object_register_marshaller(marshal_VOID__STRING_BOXED,
-                                    G_TYPE_NONE,
-                                    G_TYPE_STRING,
-                                    G_TYPE_VALUE,
-                                    G_TYPE_INVALID);
-  ::dbus_g_proxy_add_signal(net_proxy, "ConnectionStateChanged",
-                            G_TYPE_STRING, G_TYPE_VALUE, G_TYPE_INVALID);
-  ::dbus_g_proxy_connect_signal(net_proxy, "ConnectionStateChanged",
-                                G_CALLBACK(&StaticNetSignalHandler),
-                                this, NULL);
+  // Registers D-Bus matches for the signals we would like to catch.
+  for (unsigned int m = 0; m < sizeof(dbus_matches_) / sizeof(char *); m++) {
+    const char* match = dbus_matches_[m];
+    LOG(INFO) << "adding dbus match: " << match;
+    dbus_bus_add_match(connection, match, &error);
+    LOG_IF(FATAL, dbus_error_is_set(&error)) <<
+        "unable to add a match: " << SAFE_MESSAGE(error);
+  }
+
+  // Adds the D-Bus filter routine to be called back whenever one of
+  // the registered D-Bus matches is successful. The daemon is not
+  // activated for D-Bus messages that don't match.
+  CHECK(dbus_connection_add_filter(connection, MessageFilter, this, NULL));
 }
 
 void MetricsDaemon::Loop() {
-  ::GMainLoop* loop = ::g_main_loop_new(NULL, false);
-  ::g_main_loop_run(loop);
+  GMainLoop* loop = g_main_loop_new(NULL, false);
+  g_main_loop_run(loop);
 }
 
-void MetricsDaemon::StaticNetSignalHandler(::DBusGProxy* proxy,
-                                           const char* property,
-                                           const ::GValue* value,
-                                           void *data) {
-  (static_cast<MetricsDaemon*>(data))->NetSignalHandler(proxy, property, value);
+// static
+DBusHandlerResult MetricsDaemon::MessageFilter(DBusConnection* connection,
+                                               DBusMessage* message,
+                                               void* user_data) {
+  LOG(INFO) << "message filter";
+
+  int message_type = dbus_message_get_type(message);
+  if (message_type != DBUS_MESSAGE_TYPE_SIGNAL) {
+    LOG(WARNING) << "unexpected message type " << message_type;
+    return DBUS_HANDLER_RESULT_NOT_YET_HANDLED;
+  }
+
+  // Signal messages always have interfaces.
+  const char* interface = dbus_message_get_interface(message);
+  CHECK(interface != NULL);
+
+  MetricsDaemon* daemon = static_cast<MetricsDaemon*>(user_data);
+
+  DBusMessageIter iter;
+  dbus_message_iter_init(message, &iter);
+  if (strcmp(interface, DBUS_IFACE_CONNMAN_MANAGER) == 0) {
+    CHECK(strcmp(dbus_message_get_member(message), "StateChanged") == 0);
+
+    char *state_name;
+    dbus_message_iter_get_basic(&iter, &state_name);
+    daemon->NetStateChanged(state_name);
+  } else if (strcmp(interface, DBUS_IFACE_POWER_MANAGER) == 0) {
+    CHECK(strcmp(dbus_message_get_member(message), "PowerStateChanged") == 0);
+
+    char *state_name;
+    dbus_message_iter_get_basic(&iter, &state_name);
+    daemon->PowerStateChanged(state_name);
+  } else {
+    LOG(WARNING) << "unexpected interface: " << interface;
+    return DBUS_HANDLER_RESULT_NOT_YET_HANDLED;
+  }
+
+  return DBUS_HANDLER_RESULT_HANDLED;
 }
 
-void MetricsDaemon::NetSignalHandler(::DBusGProxy* proxy,
-                                     const char* property,
-                                     const ::GValue* value) {
-  if (strcmp("ConnectionState", property) != 0) {
-    return;
+void MetricsDaemon::NetStateChanged(const char* state_name) {
+  LOG(INFO) << "network state: " << state_name;
+
+  time_t now = time(NULL);
+  NetworkState state = LookupNetworkState(state_name);
+
+  // Logs the time in seconds between the network going online to
+  // going offline in order to measure the mean time to network
+  // dropping. Going offline as part of suspend-to-RAM is not logged
+  // as network drop -- the assumption is that the message for
+  // suspend-to-RAM comes before the network offline message which
+  // seems to and should be the case.
+  if (state == kNetworkStateOffline &&
+      network_state_ == kNetworkStateOnline &&
+      power_state_ != kPowerStateMem) {
+    int online_time = static_cast<int>(now - network_state_changed_);
+    PublishMetric("Network.TimeToDrop", online_time,
+                  1, 8 /* hours */ * 60 * 60, 50);
   }
 
-  const char* newstate = static_cast<const char*>(g_value_get_string(value));
-  LogNetworkStateChange(newstate);
+  network_state_ = state;
+  network_state_changed_ = now;
 }
 
-void MetricsDaemon::LogNetworkStateChange(const char* newstate) {
-  NetworkStateId new_id = GetNetworkStateId(newstate);
-  if (new_id == kUnknownNetworkStateId) {
-    LOG(WARNING) << "unknown network connection state " << newstate;
-    return;
-  }
-  NetworkStateId old_id = network_state_id_;
-  if (new_id == old_id) {  // valid new state and no change
-    return;
-  }
-  struct timeval now;
-  if (gettimeofday(&now, NULL) != 0) {
-    PLOG(WARNING) << "gettimeofday";
-  }
-  if (old_id != kUnknownNetworkStateId) {
-    struct timeval diff;
-    timersub(&now, &network_state_start_, &diff);
-    int diff_ms = diff.tv_usec / 1000 + diff.tv_sec * 1000;
-    // Saturates rather than overflowing.  We expect this to be statistically
-    // insignificant, since INT_MAX milliseconds is 24.8 days.
-    if (diff.tv_sec >= INT_MAX / 1000) {
-      diff_ms = INT_MAX;
-    }
-    PublishMetric(network_states_[old_id].stat_name,
-                  diff_ms,
-                  1,
-                  8 * 60 * 60 * 1000,  // 8 hours in milliseconds
-                  100);
-  }
-  network_state_id_ = new_id;
-  network_state_start_ = now;
-}
-
-MetricsDaemon::NetworkStateId
-MetricsDaemon::GetNetworkStateId(const char* state_name) {
+MetricsDaemon::NetworkState
+MetricsDaemon::LookupNetworkState(const char* state_name) {
   for (int i = 0; i < kNumberNetworkStates; i++) {
-    if (strcmp(state_name, network_states_[i].name) == 0) {
-      return static_cast<NetworkStateId>(i);
+    if (strcmp(state_name, network_states_[i]) == 0) {
+      return static_cast<NetworkState>(i);
     }
   }
-  return static_cast<NetworkStateId>(-1);
+  LOG(WARNING) << "unknown network connection state: " << state_name;
+  return kUnknownNetworkState;
+}
+
+void MetricsDaemon::PowerStateChanged(const char* state_name) {
+  LOG(INFO) << "power state: " << state_name;
+  power_state_ = LookupPowerState(state_name);
+}
+
+MetricsDaemon::PowerState
+MetricsDaemon::LookupPowerState(const char* state_name) {
+  for (int i = 0; i < kNumberPowerStates; i++) {
+    if (strcmp(state_name, power_states_[i]) == 0) {
+      return static_cast<PowerState>(i);
+    }
+  }
+  LOG(WARNING) << "unknown power state: " << state_name;
+  return kUnknownPowerState;
 }
 
 void MetricsDaemon::PublishMetric(const char* name, int sample,
                                   int min, int max, int nbuckets) {
-  if (testing_) {
-    LOG(INFO) << "received metric: " << name << " " << sample <<
-        " " << min << " " << max << " " << nbuckets;
-  } else {
+  LOG(INFO) << "received metric: " << name << " " << sample <<
+      " " << min << " " << max << " " << nbuckets;
+  if (!testing_) {
     MetricsLibrary::SendToChrome(name, sample, min, max, nbuckets);
   }
 }
diff --git a/metrics/metrics_daemon.h b/metrics/metrics_daemon.h
index b18e366..23f0eb2 100644
--- a/metrics/metrics_daemon.h
+++ b/metrics/metrics_daemon.h
@@ -5,40 +5,40 @@
 #ifndef METRICS_DAEMON_H_
 #define METRICS_DAEMON_H_
 
-#include <dbus/dbus-glib.h>
-#include <sys/time.h>
+#include <dbus/dbus.h>
 #include <time.h>
 
 class MetricsDaemon {
 
  public:
   MetricsDaemon()
-      : network_state_id_(kUnknownNetworkStateId) {
-  }
+      : testing_(false),
+        network_state_(kUnknownNetworkState),
+        network_state_changed_(0),
+        power_state_(kUnknownPowerState) {}
   ~MetricsDaemon() {}
 
-  // Does all the work.  If |run_as_daemon| is true, daemonize by forking.  If
-  // |testing| is true, log the stats instead of sending them to Chrome.
+  // Does all the work. If |run_as_daemon| is true, daemonizes by
+  // forking. If |testing| is true, logs the stats instead of sending
+  // them to Chrome.
   void Run(bool run_as_daemon, bool testing);
 
  private:
-  // Shared with Chrome for transport.
-  static const char* kMetricsFilePath;
-  static const int kMetricsMessageMaxLength = 4096;
-
-  // The network states.  See network_states.h.
-  typedef enum {
-    // Initial/unknown network state id.
-    kUnknownNetworkStateId = -1,
+  // The network states (see network_states.h).
+  enum NetworkState {
+    kUnknownNetworkState = -1, // Initial/unknown network state.
 #define STATE(name, capname) kNetworkState ## capname,
 #include "network_states.h"
     kNumberNetworkStates
-  } NetworkStateId;
+  };
 
-  typedef struct {
-    const char* name;
-    const char* stat_name;
-  } NetworkState;
+  // The power states (see power_states.h).
+  enum PowerState {
+    kUnknownPowerState = -1, // Initial/unknown power state.
+#define STATE(name, capname) kPowerState ## capname,
+#include "power_states.h"
+    kNumberPowerStates
+  };
 
   // Initializes.
   void Init(bool testing);
@@ -46,22 +46,22 @@
   // Creates the event loop and enters it.
   void Loop();
 
-  // Static callback for network events on DBus.
-  static void StaticNetSignalHandler(::DBusGProxy* proxy, const char* property,
-                                     const ::GValue* value, void* data);
+  // D-Bus filter callback.
+  static DBusHandlerResult MessageFilter(DBusConnection* connection,
+                                         DBusMessage* message,
+                                         void* user_data);
 
-  // Callback for network events on DBus.
-  void NetSignalHandler(::DBusGProxy* proxy, const char* property,
-                        const ::GValue* value);
+  // Processes network state change.
+  void NetStateChanged(const char* state_name);
 
-  // This is called at each network state change.  The new state is identified
-  // by the string @newstate.  As a side effect, this method ships to Chrome
-  // (or prints to stdout when testing) the name and duration of the state
-  // that has ended.
-  void LogNetworkStateChange(const char* newstate);
+  // Given the state name, returns the state id.
+  NetworkState LookupNetworkState(const char* state_name);
 
-  // Given a string with the name of a state, returns the id for the state.
-  NetworkStateId GetNetworkStateId(const char* state_name);
+  // Processes power state change.
+  void PowerStateChanged(const char* state_name);
+
+  // Given the state name, returns the state id.
+  PowerState LookupPowerState(const char* state_name);
 
   // Sends a stat to Chrome for transport to UMA (or prints it for
   // testing). See MetricsLibrary::SendToChrome in metrics_library.h
@@ -69,20 +69,19 @@
   void PublishMetric(const char* name, int sample,
                      int min, int max, int nbuckets);
 
-#if 0
-  // Fetches a name-value hash table from DBus.
-  bool GetProperties(::DBusGProxy* proxy, ::GHashTable** table);
+  // D-Bus message match strings.
+  static const char* dbus_matches_[];
 
-  // The type descriptor for a glib hash table.
-  GType hashtable_gtype;
-#endif
+  // Array of network states.
+  static const char* network_states_[kNumberNetworkStates];
 
-  // Array of network states of interest.
-  static NetworkState network_states_[kNumberNetworkStates];
+  // Array of power states.
+  static const char* power_states_[kNumberPowerStates];
 
-  bool testing_;                           // just testing
-  NetworkStateId network_state_id_;        // id of current state
-  struct timeval network_state_start_;     // when current state was entered
+  bool testing_;                  // just testing
+  NetworkState network_state_;    // current network state
+  time_t network_state_changed_;  // timestamp last net state change
+  PowerState power_state_;        // current power state
 };
 
 #endif  // METRICS_DAEMON_H_
diff --git a/metrics/network_states.h b/metrics/network_states.h
index 69205ed..b02f64a 100644
--- a/metrics/network_states.h
+++ b/metrics/network_states.h
@@ -1,4 +1,4 @@
-// Copyright (c) 2009 The Chromium OS Authors. All rights reserved.
+// Copyright (c) 2010 The Chromium OS Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
@@ -22,13 +22,7 @@
 #define STATE(name, capname)
 #endif
 
-STATE(association, Association)
-STATE(configuration, Configuration)
-STATE(disconnect, Disconnect)
-STATE(failure, Failure)
-STATE(idle, Idle)
 STATE(offline, Offline)
 STATE(online, Online)
-STATE(ready, Ready)
 
 #undef STATE
diff --git a/metrics/power_states.h b/metrics/power_states.h
new file mode 100644
index 0000000..413085e
--- /dev/null
+++ b/metrics/power_states.h
@@ -0,0 +1,28 @@
+// Copyright (c) 2010 The Chromium OS Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style license that can be
+// found in the LICENSE file.
+
+// A table of power states, to be included when building tabular things.
+//
+// This file is used to construct two things: an enumerated type in
+// metrics_daemon.h, and a table of structures with state names in
+// metrics_daemon.cc.  Including this file ensures that the two tables are
+// always in sync (and saves typing).  I don't know of other ways of achieving
+// the same result in C/C++, but it doesn't mean there isn't one.
+
+// Before you include this file, define STATE to do something useful, or else
+// if will be a no-op.  STATE will be undefined on exit.  Don't worry about
+// collisions for the STATE macro (as long as it's a macro) because the
+// compiler will flag them---in that case, just change the name.  If someone is
+// misguided enough to use STATE for something other than a macro, the error
+// messages will be slightly more complicated.
+
+
+#ifndef STATE
+#define STATE(name, capname)
+#endif
+
+STATE(on, On)
+STATE(mem, Mem)
+
+#undef STATE