commit 1835e776e977a8b9aa8e6ada86b9493016c61828
author mukesh agrawal <quiche@chromium.org> Tue Jan 15 18:35:03 2013 -0800
committer ChromeBot <chrome-bot@google.com> Wed Jan 16 11:22:37 2013 -0800
tree 4a7037adf15a4e8c9f05247ef976b8e8ac991702
parent 5086b9744e8330e7f3bd8ab91fe20b53dda28a1c

shill: increase logging for DHCPConfig

Log more detail about when and why we try to kill the dhcpcd process.
The messages are logged at INFO (for first kill attempt), and WARNING
(for subsequent attempts).

This should not spam the log file, as stopping DHCPConfig should be an
infrequent occurence.

BUG=chromium-os:37730
TEST=unit tests

Change-Id: I0310a03d6ba8ef9c648a16590f003a851eb37122
Reviewed-on: https://gerrit.chromium.org/gerrit/41337
Reviewed-by: Paul Stewart <pstew@chromium.org>
Reviewed-by: Darin Petkov <petkov@chromium.org>
Commit-Queue: mukesh agrawal <quiche@chromium.org>
Tested-by: mukesh agrawal <quiche@chromium.org>

dhcp_config.cc

diff --git a/dhcp_config.cc b/dhcp_config.cc
index fa0af7c..710775e 100644
--- a/dhcp_config.cc
+++ b/dhcp_config.cc
@@ -90,7 +90,7 @@
   SLOG(DHCP, 2) << __func__ << ": " << device_name();
 
   // Don't leave behind dhcpcd running.
-  Stop();
+  Stop(__func__);
 
   // Make sure we don't get any callbacks to the destroyed instance.
   CleanupClientState();
@@ -132,7 +132,7 @@
   if (!arp_gateway_ && proxy_.get()) {
     proxy_->Release(device_name());
   }
-  Stop();
+  Stop(__func__);
   return true;
 }
 
@@ -222,9 +222,9 @@
   return true;
 }
 
-void DHCPConfig::Stop() {
+void DHCPConfig::Stop(const char *reason) {
   if (pid_) {
-    SLOG(DHCP, 2) << "Terminating " << pid_;
+    LOG(INFO) << "Terminating " << pid_ << " (" << reason << ")";
     if (kill(pid_, SIGTERM) < 0) {
       PLOG(ERROR);
       return;
@@ -237,8 +237,12 @@
       if (ret == pid_ || ret == -1)
         break;
       usleep(kDHCPCDExitPollMilliseconds * 1000);
-      if (count == num_iterations / 2)  // Make one last attempt to kill dhcpcd.
+      if (count == num_iterations / 2) {
+        // Make one last attempt to kill dhcpcd.
+        LOG(WARNING) << "Terminating " << pid_ << " with SIGKILL "
+                     << "(" << reason << ")";
         kill(pid_, SIGKILL);
+      }
     }
     if (ret != pid_)
       PLOG(ERROR);
@@ -253,7 +257,7 @@
   // the Provider. Since the Provider doesn't invoke Restart, this would mean
   // that Restart was erroneously executed through a bare reference.
   CHECK(!pid_ || !HasOneRef());
-  Stop();
+  Stop(__func__);
   if (pid_) {
     provider_->UnbindPID(pid_);
   }

dhcp_config.h

diff --git a/dhcp_config.h b/dhcp_config.h
index 1df1728..2c3d907 100644
--- a/dhcp_config.h
+++ b/dhcp_config.h
@@ -125,7 +125,7 @@
   bool Start();
 
   // Stops dhcpcd if running.
-  void Stop();
+  void Stop(const char *reason);
 
   // Stops dhcpcd if already running and then starts it. Returns true on success
   // and false otherwise.

dhcp_config_unittest.cc

diff --git a/dhcp_config_unittest.cc b/dhcp_config_unittest.cc
index 2654a70..559eb1a 100644
--- a/dhcp_config_unittest.cc
+++ b/dhcp_config_unittest.cc
@@ -27,6 +27,8 @@
 using std::string;
 using std::vector;
 using testing::_;
+using testing::AnyNumber;
+using testing::ContainsRegex;
 using testing::Return;
 using testing::SetArgumentPointee;
 using testing::Test;
@@ -553,8 +555,12 @@
 TEST_F(DHCPConfigTest, Stop) {
   // Ensure no crashes.
   const int kPID = 1 << 17;  // Ensure unknown positive PID.
+  ScopedMockLog log;
+  EXPECT_CALL(log, Log(_, _, _)).Times(AnyNumber());
+  EXPECT_CALL(log, Log(_, _, ContainsRegex(
+      base::StringPrintf("Terminating.+%s", __func__))));
   config_->pid_ = kPID;
-  config_->Stop();
+  config_->Stop(__func__);
   EXPECT_TRUE(config_->lease_acquisition_timeout_callback_.IsCancelled());
 }
 
@@ -565,7 +571,7 @@
   EXPECT_TRUE(config_->RenewIP());
   EXPECT_FALSE(config_->lease_acquisition_timeout_callback_.IsCancelled());
   config_->pid_ = 0;  // Keep Stop from killing a real process.
-  config_->Stop();
+  config_->Stop(__func__);
   EXPECT_TRUE(config_->lease_acquisition_timeout_callback_.IsCancelled());
 }