kudu-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From aw...@apache.org
Subject [kudu] 05/07: Reduce startup log spam
Date Wed, 27 Feb 2019 02:15:02 GMT
This is an automated email from the ASF dual-hosted git repository.

awong pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/kudu.git

commit 2711b5c02b4d46c055cbf734ade99e8837f361a1
Author: Will Berkeley <wdberkeley@gmail.org>
AuthorDate: Wed Feb 20 15:21:21 2019 -0800

    Reduce startup log spam
    
    This eliminates a lot of the messages at startup that really aren't
    useful:
    
    1. No more of this:
    
    I0220 13:18:51.160027 372970944 ts_tablet_manager.cc:1007] T 2f7ecbdb5c564106a2646ffe5f21f347
P 0a909baebce949a6aa4cdc0f196ecd00: Loading tablet metadata
    I0220 13:18:51.161830 372970944 ts_tablet_manager.cc:1007] T 27705b0198da406d8301830cd942c7ee
P 0a909baebce949a6aa4cdc0f196ecd00: Loading tablet metadata
    I0220 13:18:51.162523 372970944 ts_tablet_manager.cc:1007] T 58f1243dad6346549370fbe50a739563
P 0a909baebce949a6aa4cdc0f196ecd00: Loading tablet metadata
    I0220 13:18:51.163156 372970944 ts_tablet_manager.cc:1007] T c4fc7d7a16e34f4aa87e1af2e1defa2e
P 0a909baebce949a6aa4cdc0f196ecd00: Loading tablet metadata
    I0220 13:18:51.163739 372970944 ts_tablet_manager.cc:1007] T 28d12a741054442d988646178daad91f
P 0a909baebce949a6aa4cdc0f196ecd00: Loading tablet metadata
    I0220 13:18:51.164413 372970944 ts_tablet_manager.cc:1007] T 0048470f677242dda0277aed2fef7b05
P 0a909baebce949a6aa4cdc0f196ecd00: Loading tablet metadata
    I0220 13:18:51.165114 372970944 ts_tablet_manager.cc:1007] T 2b9dc70391f54e3fbf116b46d86c2c50
P 0a909baebce949a6aa4cdc0f196ecd00: Loading tablet metadata
    ...
    
    Instead, just a periodic progress message and a summary message:
    
    I0220 15:15:29.755679 323278272 ts_tablet_manager.cc:344] Loading tablet metadata (0/60
complete)
    I0220 15:15:29.803109 323278272 ts_tablet_manager.cc:356] Loaded tablet metadata (60 total
tablets, 60 live tablets)
    
    2. No more of this:
    
    I0220 13:18:51.200745 372970944 ts_tablet_manager.cc:1175] T 27705b0198da406d8301830cd942c7ee
P 0a909baebce949a6aa4cdc0f196ecd00: Registered tablet (data state: TABLET_DATA_READY)
    I0220 13:18:51.201200 372970944 ts_tablet_manager.cc:1175] T 58f1243dad6346549370fbe50a739563
P 0a909baebce949a6aa4cdc0f196ecd00: Registered tablet (data state: TABLET_DATA_READY)
    I0220 13:18:51.201637 372970944 ts_tablet_manager.cc:1175] T c4fc7d7a16e34f4aa87e1af2e1defa2e
P 0a909baebce949a6aa4cdc0f196ecd00: Registered tablet (data state: TABLET_DATA_READY)
    I0220 13:18:51.202126 372970944 ts_tablet_manager.cc:1175] T 28d12a741054442d988646178daad91f
P 0a909baebce949a6aa4cdc0f196ecd00: Registered tablet (data state: TABLET_DATA_READY)
    I0220 13:18:51.202700 372970944 ts_tablet_manager.cc:1175] T 0048470f677242dda0277aed2fef7b05
P 0a909baebce949a6aa4cdc0f196ecd00: Registered tablet (data state: TABLET_DATA_READY)
    I0220 13:18:51.203141 372970944 ts_tablet_manager.cc:1175] T 2b9dc70391f54e3fbf116b46d86c2c50
P 0a909baebce949a6aa4cdc0f196ecd00: Registered tablet (data state: TABLET_DATA_READY)
    ...
    
    Instead, just a periodic progress message and a summary message:
    
    I0220 15:15:29.803143 323278272 ts_tablet_manager.cc:362] Registering tablets (0/60 complete)
    I0220 15:15:29.822479 323278272 ts_tablet_manager.cc:376] Registered 60 tablets
    
    3. Condense webserver startup messages. Instead of
    
    I0220 13:18:51.234637 372970944 webserver.cc:175] Starting webserver on 127.0.0.1:8050
    I0220 13:18:51.234654 372970944 webserver.cc:180] Document root: /Users/wdberkeley/src/kudu/www
    I0220 13:18:51.235159 372970944 webserver.cc:313] Webserver started. Bound to: http://127.0.0.1:8050/
    
    just
    
    I0220 15:15:29.834751 323278272 webserver.cc:307] Webserver started at http://127.0.0.1:8050/
using document root /Users/wdberkeley/src/kudu/www and password file <none>
    
    Note that the protocol 'http://' will now correctly show as 'https://'
    if the webserver is configured for SSL.
    
    4. I got rid of some of the highest level, lowest info content messages
       about the "tablet server starting", because that just means we
       finished executed code in tablet_server_main.cc, not that the tablet
       server is ready to do anything in particular.
    
    Change-Id: I3793a2385612cf920a94e5f62a559c350b8bf461
    Reviewed-on: http://gerrit.cloudera.org:8080/12540
    Tested-by: Will Berkeley <wdberkeley@gmail.com>
    Reviewed-by: Andrew Wong <awong@cloudera.com>
---
 src/kudu/master/master_main.cc         |  3 ---
 src/kudu/server/webserver.cc           | 37 +++++++++++++++++-----------------
 src/kudu/tablet/tablet_bootstrap.cc    |  5 +----
 src/kudu/tserver/tablet_server_main.cc |  3 ---
 src/kudu/tserver/ts_tablet_manager.cc  | 22 ++++++++++++--------
 5 files changed, 33 insertions(+), 37 deletions(-)

diff --git a/src/kudu/master/master_main.cc b/src/kudu/master/master_main.cc
index 1abb837..583a185 100644
--- a/src/kudu/master/master_main.cc
+++ b/src/kudu/master/master_main.cc
@@ -77,13 +77,10 @@ static int MasterMain(int argc, char** argv) {
 
   MasterOptions opts;
   Master server(opts);
-  LOG(INFO) << "Initializing master server...";
   CHECK_OK(server.Init());
 
-  LOG(INFO) << "Starting Master server...";
   CHECK_OK(server.Start());
 
-  LOG(INFO) << "Master server successfully started.";
   while (true) {
     SleepFor(MonoDelta::FromSeconds(60));
   }
diff --git a/src/kudu/server/webserver.cc b/src/kudu/server/webserver.cc
index d0fde6b..304d3e8 100644
--- a/src/kudu/server/webserver.cc
+++ b/src/kudu/server/webserver.cc
@@ -162,9 +162,10 @@ Status Webserver::BuildListenSpec(string* spec) const {
   RETURN_NOT_OK(ParseAddressList(http_address_, 80, &addrs));
 
   vector<string> parts;
+  parts.reserve(addrs.size());
   for (const Sockaddr& addr : addrs) {
-    // Mongoose makes sockets with 's' suffixes accept SSL traffic only
-    parts.push_back(addr.ToString() + (IsSecure() ? "s" : ""));
+    // Mongoose makes sockets with 's' suffixes accept SSL traffic only.
+    parts.emplace_back(addr.ToString() + (IsSecure() ? "s" : ""));
   }
 
   JoinStrings(parts, ",", spec);
@@ -172,25 +173,17 @@ Status Webserver::BuildListenSpec(string* spec) const {
 }
 
 Status Webserver::Start() {
-  LOG(INFO) << "Starting webserver on " << http_address_;
-
   vector<string> options;
-
   if (static_pages_available()) {
-    LOG(INFO) << "Document root: " << opts_.doc_root;
     options.emplace_back("document_root");
     options.push_back(opts_.doc_root);
     options.emplace_back("enable_directory_listing");
     options.emplace_back("no");
-  } else {
-    LOG(INFO)<< "Document root disabled";
   }
 
   if (IsSecure()) {
-    LOG(INFO) << "Webserver: Enabling HTTPS support";
-
-    // Initialize OpenSSL, and prevent Squeasel from also performing global OpenSSL
-    // initialization.
+    // Initialize OpenSSL, and prevent Squeasel from also performing global
+    // OpenSSL initialization.
     security::InitializeOpenSSL();
     options.emplace_back("ssl_global_init");
     options.emplace_back("false");
@@ -208,7 +201,7 @@ Status Webserver::Start() {
                                                             &key_password));
       }
       options.emplace_back("ssl_private_key_password");
-      options.push_back(key_password); // maybe empty if not configured.
+      options.push_back(key_password); // May be empty if not configured.
     }
 
     options.emplace_back("ssl_ciphers");
@@ -223,14 +216,13 @@ Status Webserver::Start() {
   }
 
   if (!opts_.password_file.empty()) {
-    // Mongoose doesn't log anything if it can't stat the password file (but will if it
-    // can't open it, which it tries to do during a request)
+    // Mongoose doesn't log anything if it can't stat the password file (but
+    // will if it can't open it, which it tries to do during a request).
     if (!Env::Default()->FileExists(opts_.password_file)) {
       ostringstream ss;
       ss << "Webserver: Password file does not exist: " << opts_.password_file;
       return Status::InvalidArgument(ss.str());
     }
-    LOG(INFO) << "Webserver: Password file is " << opts_.password_file;
     options.emplace_back("global_auth_file");
     options.push_back(opts_.password_file);
   }
@@ -298,7 +290,8 @@ Status Webserver::Start() {
       std::bind<void>(std::mem_fn(&Webserver::RootHandler),
                       this, std::placeholders::_1, std::placeholders::_2);
 
-  RegisterPathHandler("/", "Home", default_callback, true /* styled */, true /* on_nav_bar
*/);
+  RegisterPathHandler("/", "Home", default_callback,
+                      /*is_styled=*/true, /*is_on_nav_bar=*/true);
 
   vector<Sockaddr> addrs;
   RETURN_NOT_OK(GetBoundAddresses(&addrs));
@@ -307,10 +300,16 @@ Status Webserver::Start() {
     if (!bound_addresses_str.empty()) {
       bound_addresses_str += ", ";
     }
-    bound_addresses_str += "http://" + addr.ToString() + "/";
+    bound_addresses_str += Substitute("$0$1/",
+                                      IsSecure() ? "https://" : "http://",
+                                      addr.ToString());
   }
 
-  LOG(INFO) << "Webserver started. Bound to: " << bound_addresses_str;
+  LOG(INFO) << Substitute(
+      "Webserver started at $0 using document root $1 and password file $2",
+      bound_addresses_str,
+      static_pages_available() ? opts_.doc_root : "<none>",
+      opts_.password_file.empty() ? "<none>" : opts_.password_file);
   return Status::OK();
 }
 
diff --git a/src/kudu/tablet/tablet_bootstrap.cc b/src/kudu/tablet/tablet_bootstrap.cc
index 2b03540..d37157e 100644
--- a/src/kudu/tablet/tablet_bootstrap.cc
+++ b/src/kudu/tablet/tablet_bootstrap.cc
@@ -436,9 +436,7 @@ class TabletBootstrap {
 };
 
 void TabletBootstrap::SetStatusMessage(const string& status) {
-  LOG(INFO) << "T " << tablet_meta_->tablet_id()
-            << " P " << tablet_meta_->fs_manager()->uuid() << ":
"
-            << status;
+  LOG_WITH_PREFIX(INFO) << status;
   if (tablet_replica_) tablet_replica_->SetStatusMessage(status);
 }
 
@@ -567,7 +565,6 @@ Status TabletBootstrap::RunBootstrap(shared_ptr<Tablet>* rebuilt_tablet,
     VLOG_WITH_PREFIX(1) << "Tablet Metadata: " << SecureDebugString(super_block);
   }
 
-
   // Ensure the tablet's data dirs are present and healthy before it is opened.
   DataDirGroupPB data_dir_group;
   RETURN_NOT_OK_PREPEND(
diff --git a/src/kudu/tserver/tablet_server_main.cc b/src/kudu/tserver/tablet_server_main.cc
index 17989be..7c7ca60 100644
--- a/src/kudu/tserver/tablet_server_main.cc
+++ b/src/kudu/tserver/tablet_server_main.cc
@@ -82,15 +82,12 @@ static int TabletServerMain(int argc, char** argv) {
 
   TabletServerOptions opts;
   TabletServer server(opts);
-  LOG(INFO) << "Initializing tablet server...";
   CHECK_OK(server.Init());
 
   MAYBE_FAULT(FLAGS_fault_before_start);
 
-  LOG(INFO) << "Starting tablet server...";
   CHECK_OK(server.Start());
 
-  LOG(INFO) << "Tablet server successfully started.";
   while (true) {
     SleepFor(MonoDelta::FromSeconds(60));
   }
diff --git a/src/kudu/tserver/ts_tablet_manager.cc b/src/kudu/tserver/ts_tablet_manager.cc
index b365ba4..2dc868e 100644
--- a/src/kudu/tserver/ts_tablet_manager.cc
+++ b/src/kudu/tserver/ts_tablet_manager.cc
@@ -334,7 +334,7 @@ Status TSTabletManager::Init() {
 
   InitLocalRaftPeerPB();
 
-  vector<scoped_refptr<TabletMetadata> > metas;
+  vector<scoped_refptr<TabletMetadata>> metas;
 
   // First, load all of the tablet metadata. We do this before we start
   // submitting the actual OpenTablet() tasks so that we don't have to compete
@@ -347,16 +347,20 @@ Status TSTabletManager::Init() {
     RETURN_NOT_OK_PREPEND(OpenTabletMeta(tablet_id, &meta),
                           "Failed to open tablet metadata for tablet: " + tablet_id);
     loaded_count++;
-    if (PREDICT_FALSE(meta->tablet_data_state() != TABLET_DATA_READY)) {
+    if (meta->tablet_data_state() != TABLET_DATA_READY) {
       RETURN_NOT_OK(HandleNonReadyTabletOnStartup(meta));
       continue;
     }
     metas.push_back(meta);
   }
-  LOG(INFO) << Substitute("Loaded tablet metadata ($0 live tablets)", metas.size());
+  LOG(INFO) << Substitute("Loaded tablet metadata ($0 total tablets, $1 live tablets)",
+                          loaded_count, metas.size());
 
   // Now submit the "Open" task for each.
-  for (const scoped_refptr<TabletMetadata>& meta : metas) {
+  int registered_count = 0;
+  for (const auto& meta : metas) {
+    KLOG_EVERY_N_SECS(INFO, 1) << Substitute("Registering tablets ($0/$1 complete)",
+                                             registered_count, metas.size());
     scoped_refptr<TransitionInProgressDeleter> deleter;
     {
       std::lock_guard<RWMutex> lock(lock_);
@@ -367,7 +371,9 @@ Status TSTabletManager::Init() {
     RETURN_NOT_OK(CreateAndRegisterTabletReplica(meta, NEW_REPLICA, &replica));
     RETURN_NOT_OK(open_tablet_pool_->SubmitFunc(boost::bind(&TSTabletManager::OpenTablet,
                                                             this, replica, deleter)));
+    registered_count++;
   }
+  LOG(INFO) << Substitute("Registered $0 tablets", registered_count);
 
   {
     std::lock_guard<RWMutex> lock(lock_);
@@ -1004,7 +1010,7 @@ Status TSTabletManager::StartTabletStateTransitionUnlocked(
 
 Status TSTabletManager::OpenTabletMeta(const string& tablet_id,
                                        scoped_refptr<TabletMetadata>* metadata) {
-  LOG(INFO) << LogPrefix(tablet_id) << "Loading tablet metadata";
+  VLOG(1) << LogPrefix(tablet_id) << "Loading tablet metadata";
   TRACE("Loading metadata...");
   scoped_refptr<TabletMetadata> meta;
   RETURN_NOT_OK_PREPEND(TabletMetadata::Load(fs_manager_, tablet_id, &meta),
@@ -1027,7 +1033,7 @@ void TSTabletManager::OpenTablet(const scoped_refptr<TabletReplica>&
replica,
   shared_ptr<Tablet> tablet;
   scoped_refptr<Log> log;
 
-  LOG(INFO) << LogPrefix(tablet_id) << "Bootstrapping tablet";
+  VLOG(1) << LogPrefix(tablet_id) << "Bootstrapping tablet";
   TRACE("Bootstrapping tablet");
 
   scoped_refptr<ConsensusMetadata> cmeta;
@@ -1172,8 +1178,8 @@ void TSTabletManager::RegisterTablet(const std::string& tablet_id,
   }
 
   TabletDataState data_state = replica->tablet_metadata()->tablet_data_state();
-  LOG(INFO) << LogPrefix(tablet_id) << Substitute("Registered tablet (data state:
$0)",
-                                                  TabletDataState_Name(data_state));
+  VLOG(1) << LogPrefix(tablet_id) << Substitute("Registered tablet (data state:
$0)",
+                                                TabletDataState_Name(data_state));
 }
 
 bool TSTabletManager::LookupTablet(const string& tablet_id,


Mime
View raw message