shill: reduce logspam due to autoconnect
It's quite normal, and frequent, for an autoconnect request
(from the Manager, to a Service), to be supressed because
a) we're already connected to that Service, or
b) the Device needed by this Service is busy.
Reduce log-spam by logging those cases with SLOG at level 1,
rather than at LOG_INFO.
Checking a couple of the log files on one of my Chromebooks,
this would reduce the number of shill log lines by 7-8%.
While there: consolidate the kAutoConnConnected string into
Service. (It was previously defined independently in WiFiService
and WiMaxService.)
BUG=chromium-os:31143
TEST=unit tests
Change-Id: Ifc94e1357674999e65eb7b3ec98f6381ea59fc0d
Reviewed-on: https://gerrit.chromium.org/gerrit/38974
Reviewed-by: Paul Stewart <pstew@chromium.org>
Reviewed-by: Darin Petkov <petkov@chromium.org>
Commit-Ready: mukesh agrawal <quiche@chromium.org>
Tested-by: mukesh agrawal <quiche@chromium.org>
diff --git a/service.cc b/service.cc
index 1bde35f..0dc322d 100644
--- a/service.cc
+++ b/service.cc
@@ -37,6 +37,7 @@
namespace shill {
+const char Service::kAutoConnBusy[] = "busy";
const char Service::kAutoConnConnected[] = "connected";
const char Service::kAutoConnConnecting[] = "connecting";
const char Service::kAutoConnExplicitDisconnect[] = "explicitly disconnected";
@@ -252,8 +253,14 @@
Error error;
Connect(&error);
} else {
- LOG(INFO) << "Suppressed autoconnect to " << friendly_name_ << " "
- << "(" << reason << ")";
+ if (reason == kAutoConnConnected || reason == kAutoConnBusy) {
+ SLOG(Service, 1)
+ << "Suppressed autoconnect to " << friendly_name_ << " "
+ << "(" << reason << ")";
+ } else {
+ LOG(INFO) << "Suppressed autoconnect to " << friendly_name_ << " "
+ << "(" << reason << ")";
+ }
}
}
diff --git a/service.h b/service.h
index 2f91b39..c301da3 100644
--- a/service.h
+++ b/service.h
@@ -417,6 +417,8 @@
protected:
friend class base::RefCounted<Service>;
+ static const char kAutoConnBusy[];
+
virtual ~Service();
// Returns true if a character is allowed to be in a service storage id.
@@ -520,6 +522,7 @@
FRIEND_TEST(AllMockServiceTest, AutoConnectWithFailures);
FRIEND_TEST(CellularServiceTest, IsAutoConnectable);
FRIEND_TEST(DeviceTest, IPConfigUpdatedFailureWithStatic);
+ FRIEND_TEST(ServiceTest, AutoConnectLogging);
FRIEND_TEST(ServiceTest, CalculateState);
FRIEND_TEST(ServiceTest, CalculateTechnology);
FRIEND_TEST(ServiceTest, Certification);
diff --git a/service_unittest.cc b/service_unittest.cc
index f21e8ee..76c7316 100644
--- a/service_unittest.cc
+++ b/service_unittest.cc
@@ -480,6 +480,26 @@
EXPECT_STREQ(Service::kAutoConnConnecting, reason);
}
+TEST_F(ServiceTest, AutoConnectLogging) {
+ ScopedMockLog log;
+ EXPECT_CALL(log, Log(_, _, _));
+ service_->set_connectable(true);
+
+ ScopeLogger::GetInstance()->EnableScopesByName("+service");
+ ScopeLogger::GetInstance()->set_verbose_level(1);
+ service_->SetState(Service::kStateConnected);
+ EXPECT_CALL(log, Log(-1, _, HasSubstr(Service::kAutoConnConnected)));
+ service_->AutoConnect();
+
+ ScopeLogger::GetInstance()->EnableScopesByName("-service");
+ ScopeLogger::GetInstance()->set_verbose_level(0);
+ EXPECT_CALL(log, Log(logging::LOG_INFO, _,
+ HasSubstr(Service::kAutoConnNotConnectable)));
+ service_->set_connectable(false);
+ service_->AutoConnect();
+}
+
+
TEST_F(AllMockServiceTest, AutoConnectWithFailures) {
const char *reason;
service_->set_connectable(true);
diff --git a/wifi_service.cc b/wifi_service.cc
index 904fa9b..80c2561 100644
--- a/wifi_service.cc
+++ b/wifi_service.cc
@@ -36,7 +36,6 @@
namespace shill {
-const char WiFiService::kAutoConnBusy[] = "busy";
const char WiFiService::kAutoConnNoEndpoint[] = "no endpoints";
const char WiFiService::kStorageHiddenSSID[] = "WiFi.HiddenSSID";
diff --git a/wifi_service.h b/wifi_service.h
index 732f279..bda946f 100644
--- a/wifi_service.h
+++ b/wifi_service.h
@@ -122,7 +122,6 @@
FRIEND_TEST(WiFiServiceTest, Populate8021xNSS);
FRIEND_TEST(WiFiServiceTest, SignalToStrength); // SignalToStrength
- static const char kAutoConnBusy[];
static const char kAutoConnNoEndpoint[];
// Override the base clase implementation, because we need to allow
diff --git a/wimax_service.cc b/wimax_service.cc
index b5f76af..aa71d6d 100644
--- a/wimax_service.cc
+++ b/wimax_service.cc
@@ -25,7 +25,6 @@
const char WiMaxService::kStorageNetworkId[] = "NetworkId";
const char WiMaxService::kNetworkIdProperty[] = "NetworkId";
-const char WiMaxService::kAutoConnBusy[] = "busy";
WiMaxService::WiMaxService(ControlInterface *control,
diff --git a/wimax_service.h b/wimax_service.h
index 6eded37..f97689a 100644
--- a/wimax_service.h
+++ b/wimax_service.h
@@ -84,8 +84,6 @@
FRIEND_TEST(WiMaxServiceTest, SetState);
FRIEND_TEST(WiMaxServiceTest, StartStop);
- static const char kAutoConnBusy[];
-
// Inherited from Service.
virtual std::string GetDeviceRpcId(Error *error);
virtual bool IsAutoConnectable(const char **reason) const;