shill: fix Network.Shill.Wifi.TimeToJoin metric
The Network.Shill.Wifi.TimeToJoin metric was not being collected, due
to subtleties of how it was supposed to be hooked in to Metrics. So
fix it.
More specifically, What's supposed to happen is this:
Metrics::RegisterService
-> WiFiService::InitializeCustomMetrics // overrides base class impl
-> Metrics::AddServiceStateTransitionTimer(...)
The problem was that Metrics::RegisterService is called from
Service::Service. Thus, at the time that Metrics::RegisterService is called,
we only have a Service object, not a WiFiService object. Consequently, the
virtual method call from Manager::RegisterService resolves to the base class
implementation of InitializeCustomMetrics, which has an empty body.
To fix this, we make InitializeCustomMetrics a non-virtual method (it
only had a meaningful implementation in WiFiService, anyway), and call
it explicitly from the WiFiService ctor, rather than implicitly via
Metrics::RegisterService.
While there:
- Remove RegisterService calls in MetricsTests. These are both
unnecessary, and actively harmful. The harm comes from the fact
that the explicit call to RegisterService in the unit tests overrides
the effect of the RegisterService in the Service.
In the case of WiFiService, this meant calling the derived-class
implementation of InitializeCustomMetrics. That meant the test passed,
but only because it did not reflect actual program behavior.
- Log a WARNING if a Service is re-registered with Metrics (without an
intervening call to DeregisterService).
- Remove unused |service| field of ServiceMetrics.
- Add parenthesis to ctor invocation in Metrics::RegisterService. I
believe the fields are non-POD, and initialized either way (with or
without parentheses). But it seems clearer to use the parentheses,
since we want the fields initialized.
- Fix whitespace issue in WiFiService::InitializeCustomMetrics.
- Tweak log message in service.cc.
BUG=chromium:268058
TEST=new unit test, manual
Manual testing
--------------
1. boot system
2. connect to wifi
3. open chrome://histograms
4. find that Network.Shill.Wifi.TimeToJoin exists, and has at least one sample
Change-Id: Icd925148415ea30fb63709bf034e63b8930c179c
Reviewed-on: https://gerrit.chromium.org/gerrit/65739
Tested-by: mukesh agrawal <quiche@chromium.org>
Reviewed-by: Paul Stewart <pstew@chromium.org>
Commit-Queue: mukesh agrawal <quiche@chromium.org>
diff --git a/metrics.cc b/metrics.cc
index d3bd927..ba3b5f3 100644
--- a/metrics.cc
+++ b/metrics.cc
@@ -488,11 +488,11 @@
void Metrics::RegisterService(const Service *service) {
SLOG(Metrics, 2) << __func__;
- shared_ptr<ServiceMetrics> service_metrics(new ServiceMetrics);
+ LOG_IF(WARNING, service && ContainsKey(services_metrics_, service))
+ << "Repeatedly registering " << service->unique_name();
+ shared_ptr<ServiceMetrics> service_metrics(new ServiceMetrics());
services_metrics_[service] = service_metrics;
- service_metrics->service = service;
InitializeCommonServiceMetrics(service);
- service->InitializeCustomMetrics();
}
void Metrics::DeregisterService(const Service *service) {
diff --git a/metrics.h b/metrics.h
index 91db769..18471a4 100644
--- a/metrics.h
+++ b/metrics.h
@@ -454,10 +454,9 @@
// Tracks the time it takes |service| to go from |start_state| to
// |stop_state|. When |stop_state| is reached, the time is sent to UMA.
- void AddServiceStateTransitionTimer(const Service *service,
- const std::string &histogram_name,
- Service::ConnectState start_state,
- Service::ConnectState stop_state);
+ virtual void AddServiceStateTransitionTimer(
+ const Service *service, const std::string &histogram_name,
+ Service::ConnectState start_state, Service::ConnectState stop_state);
// Specializes |metric_name| for the specified |technology_id|.
std::string GetFullMetricName(const char *metric_name,
@@ -599,10 +598,6 @@
typedef std::map<Service::ConnectState, TimerReportersList>
TimerReportersByState;
struct ServiceMetrics {
- ServiceMetrics() : service(NULL) {}
- // The service is registered/deregistered in the Service
- // constructor/destructor, therefore there is no need to keep a ref count.
- const Service *service;
// All TimerReporter objects are stored in |timers| which owns the objects.
// |start_on_state| and |stop_on_state| contain pointers to the
// TimerReporter objects and control when to start and stop the timers.
diff --git a/metrics_unittest.cc b/metrics_unittest.cc
index 4f05864..63f0635 100644
--- a/metrics_unittest.cc
+++ b/metrics_unittest.cc
@@ -126,7 +126,6 @@
Metrics::kTimerHistogramMillisecondsMin,
Metrics::kTimerHistogramMillisecondsMax,
Metrics::kTimerHistogramNumBuckets));
- metrics_.RegisterService(service_);
metrics_.NotifyServiceStateChanged(service_, Service::kStateConfiguring);
metrics_.NotifyServiceStateChanged(service_, Service::kStateConnected);
}
@@ -137,7 +136,6 @@
Metrics::kTimerHistogramMillisecondsMin,
Metrics::kTimerHistogramMillisecondsMax,
Metrics::kTimerHistogramNumBuckets));
- metrics_.RegisterService(service_);
metrics_.NotifyServiceStateChanged(service_, Service::kStateConnected);
metrics_.NotifyServiceStateChanged(service_, Service::kStatePortal);
}
@@ -148,7 +146,6 @@
Metrics::kTimerHistogramMillisecondsMin,
Metrics::kTimerHistogramMillisecondsMax,
Metrics::kTimerHistogramNumBuckets));
- metrics_.RegisterService(service_);
metrics_.NotifyServiceStateChanged(service_, Service::kStateConnected);
metrics_.NotifyServiceStateChanged(service_, Service::kStateOnline);
}
@@ -159,7 +156,6 @@
EXPECT_CALL(library_, SendEnumToUMA(Metrics::kMetricNetworkServiceErrors,
Service::kFailureBadPassphrase,
Metrics::kMetricNetworkServiceErrorsMax));
- metrics_.RegisterService(service_);
metrics_.NotifyServiceStateChanged(service_, Service::kStateFailure);
}
@@ -169,7 +165,6 @@
Metrics::kTimerHistogramMillisecondsMin,
Metrics::kTimerHistogramMillisecondsMax,
Metrics::kTimerHistogramNumBuckets));
- metrics_.RegisterService(open_wifi_service_);
metrics_.NotifyServiceStateChanged(open_wifi_service_,
Service::kStateAssociating);
metrics_.NotifyServiceStateChanged(open_wifi_service_,
@@ -197,7 +192,6 @@
wep_wifi_service_->frequency_ = 2412;
wep_wifi_service_->physical_mode_ = Metrics::kWiFiNetworkPhyMode11a;
wep_wifi_service_->raw_signal_strength_ = kStrength;
- metrics_.RegisterService(wep_wifi_service_);
metrics_.NotifyServiceStateChanged(wep_wifi_service_,
Service::kStateConnected);
Mock::VerifyAndClearExpectations(&library_);
@@ -245,7 +239,6 @@
eap_wifi_service_->physical_mode_ = Metrics::kWiFiNetworkPhyMode11a;
eap_wifi_service_->raw_signal_strength_ = kStrength;
EXPECT_CALL(*eap_, OutputConnectionMetrics(&metrics_, Technology::kWifi));
- metrics_.RegisterService(eap_wifi_service_);
metrics_.NotifyServiceStateChanged(eap_wifi_service_,
Service::kStateConnected);
}
@@ -270,7 +263,6 @@
adhoc_wifi_service->frequency_ = 2412;
adhoc_wifi_service->physical_mode_ = Metrics::kWiFiNetworkPhyMode11b;
adhoc_wifi_service->raw_signal_strength_ = kStrength;
- metrics_.RegisterService(adhoc_wifi_service);
metrics_.NotifyServiceStateChanged(adhoc_wifi_service,
Service::kStateConnected);
}
diff --git a/mock_metrics.h b/mock_metrics.h
index 19af650..370ad35 100644
--- a/mock_metrics.h
+++ b/mock_metrics.h
@@ -18,6 +18,10 @@
MOCK_METHOD0(Start, void());
MOCK_METHOD0(Stop, void());
+ MOCK_METHOD4(AddServiceStateTransitionTimer,
+ void(const Service *service, const std::string &histogram_name,
+ Service::ConnectState start_state,
+ Service::ConnectState stop_state));
MOCK_METHOD1(NotifyDeviceScanStarted, void (int interface_index));
MOCK_METHOD1(NotifyDeviceScanFinished, void(int interface_index));
MOCK_METHOD1(ResetScanTimer, void(int interface_index));
diff --git a/service.cc b/service.cc
index 815a01b..f943346 100644
--- a/service.cc
+++ b/service.cc
@@ -219,8 +219,8 @@
}
Service::~Service() {
- LOG(INFO) << "Service " << unique_name_ << " destroyed.";
metrics_->DeregisterService(this);
+ LOG(INFO) << "Service " << unique_name_ << " destroyed.";
}
void Service::AutoConnect() {
diff --git a/service.h b/service.h
index 1ced60a..9f7dba9 100644
--- a/service.h
+++ b/service.h
@@ -289,9 +289,6 @@
// Clear all EAP certification elements.
virtual void ClearEAPCertification();
- // The inherited class should register any custom metrics in this method.
- virtual void InitializeCustomMetrics() const {}
-
// The inherited class that needs to send metrics after the service has
// transitioned to the ready state should override this method.
// |time_resume_to_ready_milliseconds| holds the elapsed time from when
diff --git a/wifi_service.cc b/wifi_service.cc
index 338d6dc..66c38ef 100644
--- a/wifi_service.cc
+++ b/wifi_service.cc
@@ -141,6 +141,8 @@
IgnoreParameterForConfigure(flimflam::kSSIDProperty);
IgnoreParameterForConfigure(flimflam::kSecurityProperty);
+ InitializeCustomMetrics();
+
// Log the |unique_name| to |friendly_name| mapping for debugging purposes.
// The latter will be tagged for scrubbing.
LOG(INFO) << "Constructed WiFi service " << unique_name()
@@ -363,9 +365,10 @@
}
void WiFiService::InitializeCustomMetrics() const {
+ SLOG(Metrics, 2) << __func__ << " for " << unique_name();
string histogram = metrics()->GetFullMetricName(
- Metrics::kMetricTimeToJoinMilliseconds,
- technology());
+ Metrics::kMetricTimeToJoinMilliseconds,
+ technology());
metrics()->AddServiceStateTransitionTimer(this,
histogram,
Service::kStateAssociating,
diff --git a/wifi_service.h b/wifi_service.h
index 850af84..5f50e3f 100644
--- a/wifi_service.h
+++ b/wifi_service.h
@@ -122,7 +122,7 @@
bool hidden_ssid() const { return hidden_ssid_; }
bool ieee80211w_required() const { return ieee80211w_required_; }
- virtual void InitializeCustomMetrics() const;
+ void InitializeCustomMetrics() const;
virtual void SendPostReadyStateMetrics(
int64 time_resume_to_ready_milliseconds) const;
diff --git a/wifi_service_unittest.cc b/wifi_service_unittest.cc
index d48feab..fd1300f 100644
--- a/wifi_service_unittest.cc
+++ b/wifi_service_unittest.cc
@@ -34,6 +34,7 @@
#include "shill/property_store_unittest.h"
#include "shill/refptr_types.h"
#include "shill/service_property_change_test.h"
+#include "shill/technology.h"
#include "shill/wifi_endpoint.h"
#include "shill/wpa_supplicant.h"
@@ -363,6 +364,16 @@
set<string> groups_;
};
+TEST_F(WiFiServiceTest, Constructor) {
+ string histogram = metrics()->GetFullMetricName(
+ Metrics::kMetricTimeToJoinMilliseconds, Technology::kWifi);
+ EXPECT_CALL(*metrics(), AddServiceStateTransitionTimer(_, _, _, _))
+ .Times(AnyNumber());
+ EXPECT_CALL(*metrics(), AddServiceStateTransitionTimer(
+ _, histogram, Service::kStateAssociating, Service::kStateConfiguring));
+ MakeSimpleService(flimflam::kSecurityNone);
+}
+
TEST_F(WiFiServiceTest, StorageId) {
WiFiServiceRefPtr wifi_service = MakeSimpleService(flimflam::kSecurityNone);
string id = wifi_service->GetStorageIdentifier();