SINGA-117 add a switch for enabling/disabling INFO-level logging

examples/cifar10/create_data.cc

@@ -46,6 +46,8 @@ const int kCIFARImageNBytes = 3072;
 const int kCIFARBatchSize = 10000;
 const int kCIFARTrainBatches = 5;
 
+static bool singa_verbose = false;
+
 void read_image(std::ifstream* file, int* label, char* buffer) {
   char label_char;
   file->read(&label_char, 1);
@@ -71,10 +73,10 @@ void create_data(const string& input_folder, const string& output_folder) {
 
   auto store = singa::io::CreateStore("kvfile");
   CHECK(store->Open(output_folder + "/train_data.bin", singa::io::kCreate));
-  LOG(INFO) << "Preparing training data";
+  LOG_IF(INFO, singa_verbose) << "Preparing training data";
   int count = 0;
   for (int fileid = 0; fileid < kCIFARTrainBatches; ++fileid) {
-    LOG(INFO) << "Training Batch " << fileid + 1;
+    LOG_IF(INFO, singa_verbose) << "Training Batch " << fileid + 1;
     snprintf(str_buffer, kCIFARImageNBytes, "/data_batch_%d.bin", fileid + 1);
     std::ifstream data_file((input_folder + str_buffer).c_str(),
         std::ios::in | std::ios::binary);
@@ -96,7 +98,7 @@ void create_data(const string& input_folder, const string& output_folder) {
   store->Flush();
   store->Close();
 
-  LOG(INFO) << "Create image mean";
+  LOG_IF(INFO, singa_verbose) << "Create image mean";
   store->Open(output_folder + "/image_mean.bin", singa::io::kCreate);
   for (int i = 0; i < kCIFARImageNBytes; i++)
     mean.set_data(i, mean.data(i) / count);
@@ -105,7 +107,7 @@ void create_data(const string& input_folder, const string& output_folder) {
   store->Flush();
   store->Close();
 
-  LOG(INFO) << "Create test data";
+  LOG_IF(INFO, singa_verbose) << "Create test data";
   store->Open(output_folder + "/test_data.bin", singa::io::kCreate);
   std::ifstream data_file((input_folder + "/test_batch.bin").c_str(),
       std::ios::in | std::ios::binary);

examples/mnist/create_data.cc

@@ -41,6 +41,8 @@
 
 using std::string;
 
+static bool singa_verbose = false;
+
 uint32_t swap_endian(uint32_t val) {
     val = ((val << 8) & 0xFF00FF00) | ((val >> 8) & 0xFF00FF);
     return (val << 16) | (val >> 16);
@@ -87,8 +89,8 @@ void create_data(const char* image_filename, const char* label_filename,
   singa::RecordProto image;
   image.add_shape(rows);
   image.add_shape(cols);
-  LOG(INFO) << "A total of " << num_items << " items.";
-  LOG(INFO) << "Rows: " << rows << " Cols: " << cols;
+  LOG_IF(INFO, singa_verbose) << "A total of " << num_items << " items.";
+  LOG_IF(INFO, singa_verbose) << "Rows: " << rows << " Cols: " << cols;
   for (int item_id = 0; item_id < num_items; ++item_id) {
     image_file.read(pixels, rows * cols);
     label_file.read(&label, 1);

src/comm/socket.cc

@@ -24,6 +24,8 @@
 
 namespace singa {
 
+extern bool singa_verbose;
+
 #ifdef USE_ZMQ
 Poller::Poller() {
   poller_ = zpoller_new(nullptr);
@@ -120,7 +122,7 @@ int Router::Bind(const std::string& endpoint) {
     port = zsock_bind(router_, "%s", endpoint.c_str());
   }
   CHECK_NE(port, -1) << endpoint;
-  LOG(INFO) << "bind successfully to " << zsock_endpoint(router_);
+  LOG_IF(INFO, singa_verbose) << "Bind successfully to " << zsock_endpoint(router_);
   return port;
 }
 
@@ -148,7 +150,7 @@ int Router::Send(Msg **msg) {
 Msg* Router::Receive() {
   zmsg_t* zmsg = zmsg_recv(router_);
   if (zmsg == nullptr) {
-    LOG(ERROR) << "Connection broken!";
+    LOG(FATAL) << "Connection broken!";
     exit(0);
   }
   zframe_t* dealer = zmsg_pop(zmsg);

src/driver.cc

@@ -45,6 +45,8 @@ extern "C" void openblas_set_num_threads(int num);
 
 namespace singa {
 
+extern bool singa_verbose;
+
 void Driver::Init(int argc, char **argv) {
   // unique job ID generated from singa-run.sh, passed in as "-singa_job <id>"
   int arg_pos = ArgPos(argc, argv, "-singa_job");
@@ -162,9 +164,9 @@ void Driver::Train(bool resume, const JobProto& job_conf) {
         std::to_string(job_id_) + "-" + job_conf.name());
   tinydir_dir workspace;
   if (tinydir_open(&workspace, job_conf.cluster().workspace().c_str()) == -1)
-    LOG(FATAL) << "workspace not exist: " << job_conf.cluster().workspace();
+    LOG(FATAL) << "Workspace not exist: " << job_conf.cluster().workspace();
   if (job_conf.num_openblas_threads() != 1)
-    LOG(WARNING) << "openblas luanches "
+    LOG(WARNING) << "Openblas luanches "
                  << job_conf.num_openblas_threads() << " threads";
   openblas_set_num_threads(job_conf.num_openblas_threads());
 
@@ -268,10 +270,10 @@ void Driver::SetupForResume(JobProto* job_conf) {
     char* ch = strstr(file.name, "step");
     if (ch == nullptr) {
       if (file.name[0] != '.')
-        LOG(INFO) << "Irregular file in checkpoint folder: " << file.name;
+        LOG(WARNING) << "Irregular file in checkpoint folder: " << file.name;
       continue;
     }
-    LOG(INFO) << "Add checkpoint file for resume: " << ch;
+    LOG_IF(INFO, singa_verbose) << "Add checkpoint file for resume: " << ch;
     int step = atoi(ch+4);
     if (step == latest_step) {
       ck_files.push_back(file.name);

src/io/kvfile.cc

@@ -60,7 +60,7 @@ path_(path), mode_(mode), capacity_(capacity) {
       }
       break;
     default:
-      LOG(FATAL) << "unknown model to open KVFile " << mode;
+      LOG(FATAL) << "Unknown model to open KVFile " << mode;
       break;
   }
 }

src/io/textfile_store.cc

@@ -56,7 +56,7 @@ bool TextFileStore::Read(std::string* key, std::string* value) {
     if (fs_->eof())
       return false;
     else
-      LOG(FATAL) << "error in reading csv file";
+      LOG(FATAL) << "Error in reading csv file";
   }
   *key = std::to_string(lineNo_++);
   return true;

src/main.cc

@@ -23,6 +23,10 @@
 #include <iostream>
 #include "singa/singa.h"
 
+namespace singa{
+extern bool singa_verbose;
+}
+
 /**
  * \file main.cc provides an example main function.
  *
@@ -48,12 +52,17 @@
 int main(int argc, char **argv) {
   if (argc < 4) {
     std::cout << "Args: -conf JOB_CONF -singa SINGA_CONF -job_id JOB_ID "
+              << " [-verbose]\t print info-level logs\n"
               << " [-resume|-test]\n"
               << "-resume\t resume training from latest checkpoint files\n"
               << "-test\t test performance or extract features\n";
     return 0;
   }
 
+  if (singa::ArgPos(argc, argv, "-verbose") != -1) {
+      singa::singa_verbose = true;
+  }
+
   // initialize glog before creating the driver
   google::InitGoogleLogging(argv[0]);
 

src/neuralnet/input_layer/deprecated.cc

@@ -34,6 +34,8 @@ using mshadow::Tensor;
 using std::string;
 using std::vector;
 
+extern bool singa_verbose;
+
 ShardDataLayer::~ShardDataLayer() {
   if (shard_ != nullptr)
     delete shard_;
@@ -63,7 +65,7 @@ void ShardDataLayer::ComputeFeature(int flag, const vector<Layer*>& srclayers) {
     std::uniform_int_distribution<int> distribution(0, random_skip_);
     auto generator = Singleton<Context>::Instance()->rand_generator();
     int nskip = distribution(*generator);
-    LOG(INFO) << "Random Skip " << nskip << " records, there are "
+    LOG_IF(INFO, singa_verbose) << "Random Skip " << nskip << " records, there are "
       << shard_->Count() << " records in total";
     string key;
     for (int i = 0; i < nskip; i++) {
@@ -119,7 +121,7 @@ void LMDBDataLayer::OpenLMDB(const std::string& path) {
       << "mdb_open failed";
   CHECK_EQ(mdb_cursor_open(mdb_txn_, mdb_dbi_, &mdb_cursor_), MDB_SUCCESS)
       << "mdb_cursor_open failed";
-  LOG(INFO) << "Opening lmdb " << path;
+  LOG_IF(INFO, singa_verbose) << "Opening lmdb " << path;
   CHECK_EQ(mdb_cursor_get(mdb_cursor_, &mdb_key_, &mdb_value_, MDB_FIRST),
            MDB_SUCCESS) << "mdb_cursor_get failed";
 }
@@ -139,7 +141,7 @@ void LMDBDataLayer::ComputeFeature(int flag, const vector<Layer*>& srclayers) {
     while (mdb_cursor_get(mdb_cursor_, &mdb_key_,
           &mdb_value_, MDB_NEXT) == MDB_SUCCESS)
       n++;
-    LOG(INFO) << "Random Skip " << nskip << " records of total "
+    LOG_IF(INFO, singa_verbose) << "Random Skip " << nskip << " records of total "
       << n << "records";
     // We have reached the end. Restart from the first.
     CHECK_EQ(mdb_cursor_get(mdb_cursor_, &mdb_key_,
@@ -148,7 +150,7 @@ void LMDBDataLayer::ComputeFeature(int flag, const vector<Layer*>& srclayers) {
       if (mdb_cursor_get(mdb_cursor_, &mdb_key_,
             &mdb_value_, MDB_NEXT) != MDB_SUCCESS) {
         // We have reached the end. Restart from the first.
-        DLOG(INFO) << "Restarting data prefetching from start.";
+        LOG_IF(INFO, singa_verbose) << "Restarting data prefetching from start.";
         CHECK_EQ(mdb_cursor_get(mdb_cursor_, &mdb_key_,
               &mdb_value_, MDB_FIRST), MDB_SUCCESS);
       }
@@ -165,7 +167,7 @@ void LMDBDataLayer::ComputeFeature(int flag, const vector<Layer*>& srclayers) {
     if (mdb_cursor_get(mdb_cursor_, &mdb_key_,
         &mdb_value_, MDB_NEXT) != MDB_SUCCESS) {
       // We have reached the end. Restart from the first.
-      DLOG(INFO) << "Restarting data prefetching from start.";
+      LOG_IF(INFO, singa_verbose) << "Restarting data prefetching from start.";
       CHECK_EQ(mdb_cursor_get(mdb_cursor_, &mdb_key_,
                &mdb_value_, MDB_FIRST), MDB_SUCCESS);
     }

src/neuralnet/input_layer/record.cc

@@ -62,7 +62,7 @@ bool RecordInputLayer::Parse(int k, int flag, const string& key,
     for (int i = 0; i < size; i++)
       ptr[i] =  static_cast<float>(static_cast<uint8_t>(pixel[i]));
   } else {
-    LOG(ERROR) << "not pixel nor pixel";
+    LOG(ERROR) << "Not pixel nor pixel";
   }
   if ((flag & kDeploy) == 0) {  // deploy mode does not have label
     aux_data_.at(k) = image.label();

src/neuralnet/neuralnet.cc

@@ -31,6 +31,8 @@ using std::map;
 using std::string;
 using std::vector;
 
+extern bool singa_verbose;
+
 NeuralNet* NeuralNet::Create(const NetProto& net_conf, Phase phase,
                                         int npartitions) {
   NetProto conf;
@@ -99,20 +101,20 @@ NeuralNet* NeuralNet::Create(const NetProto& net_conf, Phase phase,
     param->set_name(name);
     param->set_share_from(from);
   }
-  LOG(INFO) << "Initial NeuralNet Config is\n" << conf.DebugString();
+  LOG_IF(INFO, singa_verbose) << "Initial NeuralNet Config is\n" << conf.DebugString();
   // TODO(wangwei) create net based on net type, e.g., directed, undirected, etc
   return new NeuralNet(conf, npartitions);
 }
 
 NeuralNet::NeuralNet(NetProto netproto, int npartitions) {
-  LOG(INFO) << "Constructing NeuralNet...";
+  LOG_IF(INFO, singa_verbose) << "Constructing NeuralNet...";
   auto graph = CreateGraph(netproto, npartitions);
   CreateNetFromGraph(graph);
   PrepareDataStructures();
   for (Node* node : graph->nodes())
     delete static_cast<LayerProto*>(node->proto);
   delete graph;
-  LOG(INFO) << "NeuralNet Constructed";
+  LOG_IF(INFO, singa_verbose) << "NeuralNet constructed";
 }
 
 NeuralNet::~NeuralNet() {
@@ -129,7 +131,7 @@ void NeuralNet::Load(const vector<string>& paths) {
 void NeuralNet::Load(const vector<string>& paths,
     const unordered_map<string, Param*>& params) {
   for (const auto path : paths) {
-    LOG(ERROR) << "Load from checkpoint file " << path;
+    LOG_IF(INFO, singa_verbose) << "Load from checkpoint file " << path;
     BlobProtos bps;
     // TODO(wangwei) extend to read checkpoint from HDFS
     ReadProtoFromBinaryFile(path.c_str(), &bps);
@@ -219,7 +221,7 @@ NetProto NeuralNet::AddModelSplitLayers(const NetProto& netproto) {
                  ->set_num_splits(-dst_count[layer.name()]);
     }
   }
-  // LOG(INFO) << "NeuralNet Config After Model Split is\n"
+  // LOG_IF(INFO, singa_verbose) << "NeuralNet Config After Model Split is\n"
   //           << net_w_split.DebugString();
   return net_w_split;
 }
@@ -321,7 +323,7 @@ NetProto NeuralNet::AddPartitionConnectionLayers(const NetProto& netproto,
       }
     }
   }
-  LOG(INFO) << "NeuralNet Config After Adding Connection Layers is\n"
+  LOG_IF(INFO, singa_verbose) << "NeuralNet Config After Adding Connection Layers is\n"
             << net_w_connection.DebugString();
   return net_w_connection;
 }
@@ -404,7 +406,7 @@ Graph* NeuralNet::CreateGraph(const NetProto& netproto, int npartitions) {
     }
   }
   graph->Sort();
-  // DLOG(INFO) << "Pure graph structure\n" << graph->ToJson();
+  //LOG_IF(INFO, singa_verbose) << "Pure graph structure\n" << graph->ToJson();
   return graph;
 }
 
@@ -428,10 +430,10 @@ void NeuralNet::CreateNetFromGraph(Graph* graph) {
   map<string, string> layerinfo;
   map<string, vector<Layer*>> share_param_layers;
   for (Node* node : graph->nodes()) {
-    LOG(INFO) << "constructing graph: " << node->name;
+    LOG_IF(INFO, singa_verbose) << "constructing graph: " << node->name;
     auto layer = name2layer(node->name);
     layer->Setup(*(static_cast<LayerProto*>(node->proto)), srclayers(layer));
-    DLOG(INFO) << "constructing graph: " << layer->name();
+    LOG_IF(INFO, singa_verbose) << "Constructing graph: " << layer->name();
     layerinfo[layer->name()] = IntVecToString(layer->data(nullptr).shape());
     string param_name = "$";
     for (auto param : layer->GetParams()) {

src/neuralnet/neuron_layer/activation.cc

@@ -48,7 +48,7 @@ ActivationLayer::ComputeFeature(int flag, const vector<Layer*>& srclayers) {
       break;
       */
     default:
-      LOG(ERROR) << "Unknow activation type " <<
+      LOG(ERROR) << "Unknown activation type " <<
         layer_conf_.activation_conf().type();
   }
 }
@@ -75,7 +75,7 @@ ActivationLayer::ComputeGradient(int flag, const vector<Layer*>& srclayers) {
       break;
       */
     default:
-      LOG(ERROR) << "Unknow activation type " <<
+      LOG(ERROR) << "Unknown activation type " <<
         layer_conf_.activation_conf().type();
   }
 }

src/neuralnet/neuron_layer/pooling.cc

@@ -125,7 +125,7 @@ void CPoolingLayer::ComputeFeature(int flag, const vector<Layer*>& srclayers) {
         batchsize_, channels_, height_, width_, kernel_y_, kernel_x_,
         pad_y_, pad_x_, stride_y_, stride_y_, data_.mutable_cpu_data());
   else
-    LOG(FATAL) << "unknow pooling method";
+    LOG(FATAL) << "Unknown pooling method";
 }
 
 void CPoolingLayer::ComputeGradient(int flag, const vector<Layer*>& srclayers) {
@@ -140,7 +140,7 @@ void CPoolingLayer::ComputeGradient(int flag, const vector<Layer*>& srclayers) {
         stride_y_, stride_x_,
         srclayers[0]->mutable_grad(this)->mutable_cpu_data());
   else
-    LOG(FATAL) << "unknow pooling method";
+    LOG(FATAL) << "Unknown pooling method";
 }
 
 }  //  namespace singa

src/neuralnet/neuron_layer/softmax.cc

@@ -60,7 +60,7 @@ void SoftmaxLayer::ComputeFeature(int flag,
 void SoftmaxLayer::ComputeGradient(int flag,
     const vector<Layer*>& srclayers) {
   int batchsize = data_.shape()[0];
-  LOG(FATAL) << "not implemented";
+  LOG(FATAL) << "Not implemented";
   for (int n = 0; n < batchsize; n++) {
     // TODO(wangwei) finish the code using new math API
     // gxi=[(gyi+gyi*yi)-\sum_k(gyk*yk)]*yi

src/server.cc

@@ -35,6 +35,8 @@ namespace singa {
 using namespace mshadow;
 using std::vector;
 
+extern bool singa_verbose;
+
 Server::Server(int group_id, int server_id,
     const JobProto& job_conf,
     const vector<int>& slice2group,
@@ -59,7 +61,7 @@ void Stop(void* running) {
 }
 
 void Server::Run() {
-  LOG(ERROR) << "Server (group = " << grp_id_ <<", id = " << id_ << ") start";
+  LOG_IF(INFO, singa_verbose) << "Server (group = " << grp_id_ <<", id = " << id_ << ") start";
   auto cluster = Cluster::Get();
   if (cluster->nserver_groups()) {
     CHECK_GT(slice2group_.size(), 0);
@@ -132,7 +134,7 @@ void Server::Run() {
   msg->set_type(kStop);
   dealer->Send(&msg);
   std::this_thread::sleep_for(std::chrono::milliseconds(1000));
-  LOG(ERROR) << "Server (group = " << grp_id_ << ", id = " << id_ << ") stops";
+  LOG_IF(INFO, singa_verbose) << "Server (group = " << grp_id_ << ", id = " << id_ << ") stops";
   delete dealer;
 }
 
@@ -160,7 +162,7 @@ Msg* Server::HandlePut(Msg **msg) {
     last_sync_[slice_id].ReshapeLike(param->data());
     last_sync_[slice_id].CopyFrom(param->data());
   }
-  LOG(INFO) << "server (group = " << grp_id_ << ", id = " << id_
+  LOG_IF(INFO, singa_verbose) << "Server (group = " << grp_id_ << ", id = " << id_
             <<") put slice=" << slice_id << " size=" << param->size();
   return response;
 }