Surpress subgraph log in CI

.travis.yml

@@ -34,6 +34,7 @@ script:
 # Temporarily disable travis build due to travis constantly time out, tracked in
 # https://github.com/apache/incubator-mxnet/issues/16535:
   - export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+  - export MXNET_SUBGRAPH_VERBOSE=0
   - mv make/osx.mk config.mk
 #  - make -j 2
 

ci/docker/runtime_functions.sh

@@ -1006,6 +1006,7 @@ cd_unittest_ubuntu() {
     export PYTHONPATH=./python/
     export MXNET_MKLDNN_DEBUG=1  # Ignored if not present
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export MXNET_ENABLE_CYTHON=0
     export CD_JOB=1 # signal this is a CD run so any unecessary tests can be skipped
 
@@ -1048,6 +1049,7 @@ unittest_ubuntu_python2_cpu_cython() {
     export PYTHONPATH=./python/
     export MXNET_MKLDNN_DEBUG=1
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export MXNET_ENABLE_CYTHON=1
     export MXNET_ENFORCE_CYTHON=1
     check_cython 2
@@ -1061,6 +1063,7 @@ unittest_ubuntu_python2_cpu() {
     export PYTHONPATH=./python/
     export MXNET_MKLDNN_DEBUG=0
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export MXNET_ENABLE_CYTHON=0
     nosetests-2.7 $NOSE_COVERAGE_ARGUMENTS $NOSE_TIMER_ARGUMENTS --with-xunit --xunit-file nosetests_unittest.xml --verbose tests/python/unittest
     nosetests-2.7 $NOSE_COVERAGE_ARGUMENTS $NOSE_TIMER_ARGUMENTS --with-xunit --xunit-file nosetests_train.xml --verbose tests/python/train
@@ -1072,6 +1075,7 @@ unittest_ubuntu_python3_cpu() {
     export PYTHONPATH=./python/
     export MXNET_MKLDNN_DEBUG=0  # Ignored if not present
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export MXNET_ENABLE_CYTHON=0
     nosetests-3.4 $NOSE_COVERAGE_ARGUMENTS $NOSE_TIMER_ARGUMENTS --with-xunit --xunit-file nosetests_unittest.xml --verbose tests/python/unittest
     nosetests-3.4 $NOSE_COVERAGE_ARGUMENTS $NOSE_TIMER_ARGUMENTS --with-xunit --xunit-file nosetests_quantization.xml --verbose tests/python/quantization
@@ -1082,6 +1086,7 @@ unittest_ubuntu_python3_cpu_mkldnn() {
     export PYTHONPATH=./python/
     export MXNET_MKLDNN_DEBUG=0  # Ignored if not present
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export MXNET_ENABLE_CYTHON=0
     nosetests-3.4 $NOSE_COVERAGE_ARGUMENTS $NOSE_TIMER_ARGUMENTS --with-xunit --xunit-file nosetests_unittest.xml --verbose tests/python/unittest
     nosetests-3.4 $NOSE_COVERAGE_ARGUMENTS $NOSE_TIMER_ARGUMENTS --with-xunit --xunit-file nosetests_mkl.xml --verbose tests/python/mkl
@@ -1092,6 +1097,7 @@ unittest_ubuntu_python2_gpu() {
     export PYTHONPATH=./python/
     export MXNET_MKLDNN_DEBUG=0  # Ignored if not present
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export CUDNN_VERSION=${CUDNN_VERSION:-7.0.3}
     nosetests-2.7 $NOSE_COVERAGE_ARGUMENTS $NOSE_TIMER_ARGUMENTS --with-xunit --xunit-file nosetests_gpu.xml --verbose tests/python/gpu
 }
@@ -1101,6 +1107,7 @@ unittest_ubuntu_python3_gpu() {
     export PYTHONPATH=./python/
     export MXNET_MKLDNN_DEBUG=0 # Ignored if not present
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export CUDNN_VERSION=${CUDNN_VERSION:-7.0.3}
     export MXNET_ENABLE_CYTHON=0
     nosetests-3.4 $NOSE_COVERAGE_ARGUMENTS $NOSE_TIMER_ARGUMENTS --with-xunit --xunit-file nosetests_gpu.xml --verbose tests/python/gpu
@@ -1111,6 +1118,7 @@ unittest_ubuntu_python3_gpu_cython() {
     export PYTHONPATH=./python/
     export MXNET_MKLDNN_DEBUG=1 # Ignored if not present
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export CUDNN_VERSION=${CUDNN_VERSION:-7.0.3}
     export MXNET_ENABLE_CYTHON=1
     export MXNET_ENFORCE_CYTHON=1
@@ -1122,6 +1130,7 @@ unittest_ubuntu_python3_gpu_nocudnn() {
     set -ex
     export PYTHONPATH=./python/
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export CUDNN_OFF_TEST_ONLY=true
     export MXNET_ENABLE_CYTHON=0
     nosetests-3.4 $NOSE_COVERAGE_ARGUMENTS $NOSE_TIMER_ARGUMENTS --with-xunit --xunit-file nosetests_gpu.xml --verbose tests/python/gpu
@@ -1131,6 +1140,7 @@ unittest_ubuntu_tensorrt_gpu() {
     set -ex
     export PYTHONPATH=./python/
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export LD_LIBRARY_PATH=/work/mxnet/lib:$LD_LIBRARY_PATH
     export CUDNN_VERSION=${CUDNN_VERSION:-7.0.3}
     export MXNET_ENABLE_CYTHON=0
@@ -1145,6 +1155,7 @@ unittest_ubuntu_python2_quantization_gpu() {
     export PYTHONPATH=./python/
     export MXNET_MKLDNN_DEBUG=0  # Ignored if not present
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export CUDNN_VERSION=${CUDNN_VERSION:-7.0.3}
     export MXNET_ENABLE_CYTHON=0
     nosetests-2.7 $NOSE_COVERAGE_ARGUMENTS $NOSE_TIMER_ARGUMENTS --with-xunit --xunit-file nosetests_quantization_gpu.xml --verbose tests/python/quantization_gpu
@@ -1157,6 +1168,7 @@ unittest_ubuntu_python3_quantization_gpu() {
     export PYTHONPATH=./python/
     export MXNET_MKLDNN_DEBUG=0 # Ignored if not present
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export CUDNN_VERSION=${CUDNN_VERSION:-7.0.3}
     export MXNET_ENABLE_CYTHON=0
     nosetests-3.4 $NOSE_COVERAGE_ARGUMENTS $NOSE_TIMER_ARGUMENTS --with-xunit --xunit-file nosetests_quantization_gpu.xml --verbose tests/python/quantization_gpu
@@ -1319,6 +1331,7 @@ integrationtest_ubuntu_gpu_python() {
     set -ex
     export PYTHONPATH=./python/
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     python example/image-classification/test_score.py
 }
 
@@ -1347,6 +1360,7 @@ integrationtest_ubuntu_cpu_dist_kvstore() {
     pushd .
     export PYTHONPATH=./python/
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export MXNET_USE_OPERATOR_TUNING=0
     cd tests/nightly/
     ../../tools/launch.py -n 7 --launcher local python dist_sync_kvstore.py --type=gluon_step_cpu
@@ -1381,6 +1395,7 @@ integrationtest_ubuntu_gpu_dist_kvstore() {
     pushd .
     export PYTHONPATH=./python/
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     cd tests/nightly/
     ../../tools/launch.py -n 4 --launcher local python dist_device_sync_kvstore.py
     ../../tools/launch.py -n 4 --launcher local python dist_sync_kvstore.py --type=init_gpu
@@ -1560,6 +1575,7 @@ nightly_tutorial_test_ubuntu_python3_gpu() {
     export MXNET_DOCS_BUILD_MXNET=0
     make html
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export PYTHONPATH=/work/mxnet/python/
     export MXNET_TUTORIAL_TEST_KERNEL=python3
     cd /work/mxnet/tests/tutorials
@@ -1573,6 +1589,7 @@ nightly_tutorial_test_ubuntu_python2_gpu() {
     export MXNET_DOCS_BUILD_MXNET=0
     make html
     export MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+    export MXNET_SUBGRAPH_VERBOSE=0
     export PYTHONPATH=/work/mxnet/python/
     export MXNET_TUTORIAL_TEST_KERNEL=python2
     cd /work/mxnet/tests/tutorials
@@ -1966,7 +1983,7 @@ cd_package_pypi() {
     popd
 }
 
-# Sanity checks wheel file 
+# Sanity checks wheel file
 cd_integration_test_pypi() {
     set -ex
     local python_cmd=${1:?"This function requires a python command as the first argument"}

ci/windows/test_py2_cpu.ps1

@@ -20,6 +20,7 @@
 $env:MXNET_LIBRARY_PATH=join-path $pwd.Path windows_package\lib\libmxnet.dll
 $env:PYTHONPATH=join-path $pwd.Path windows_package\python
 $env:MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+$env:MXNET_SUBGRAPH_VERBOSE=0
 $env:MXNET_HOME=[io.path]::combine($PSScriptRoot, 'mxnet_home')
 
 C:\Python27\Scripts\pip install -r tests\requirements.txt

ci/windows/test_py2_gpu.ps1

@@ -20,6 +20,7 @@
 $env:MXNET_LIBRARY_PATH=join-path $pwd.Path windows_package\lib\libmxnet.dll
 $env:PYTHONPATH=join-path $pwd.Path windows_package\python
 $env:MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+$env:MXNET_SUBGRAPH_VERBOSE=0
 $env:MXNET_HOME=[io.path]::combine($PSScriptRoot, 'mxnet_home')
 
 C:\Python27\Scripts\pip install -r tests\requirements.txt

ci/windows/test_py3_cpu.ps1

@@ -20,6 +20,7 @@
 $env:MXNET_LIBRARY_PATH=join-path $pwd.Path windows_package\lib\libmxnet.dll
 $env:PYTHONPATH=join-path $pwd.Path windows_package\python
 $env:MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+$env:MXNET_SUBGRAPH_VERBOSE=0
 $env:MXNET_HOME=[io.path]::combine($PSScriptRoot, 'mxnet_home')
 
 C:\Python37\Scripts\pip install -r tests\requirements.txt

ci/windows/test_py3_gpu.ps1

@@ -20,6 +20,7 @@
 $env:MXNET_LIBRARY_PATH=join-path $pwd.Path windows_package\lib\libmxnet.dll
 $env:PYTHONPATH=join-path $pwd.Path windows_package\python
 $env:MXNET_STORAGE_FALLBACK_LOG_VERBOSE=0
+$env:MXNET_SUBGRAPH_VERBOSE=0
 $env:MXNET_HOME=[io.path]::combine($PSScriptRoot, 'mxnet_home')
 
 C:\Python37\Scripts\pip install -r tests\requirements.txt

perl-package/AI-MXNet/t/test_autograd.t

@@ -23,6 +23,7 @@ use AI::MXNet::TestUtils qw(same almost_equal rand_ndarray);
 use AI::MXNet::Base qw(:DEFAULT pones);
 use Test::More tests => 246;
 $ENV{MXNET_STORAGE_FALLBACK_LOG_VERBOSE} = 0;
+$ENV{MXNET_SUBGRAPH_VERBOSE} = 0;
 
 sub autograd_assert
 {

perl-package/AI-MXNet/t/test_gluon_trainer.t

@@ -25,6 +25,7 @@ use AI::MXNet::TestUtils qw(almost_equal dies_ok);
 use Scalar::Util qw(refaddr);
 use AI::MXNet::Base;
 $ENV{MXNET_STORAGE_FALLBACK_LOG_VERBOSE} = 0;
+$ENV{MXNET_SUBGRAPH_VERBOSE} = 0;
 
 sub test_multi_trainer
 {
@@ -252,4 +253,3 @@ sub test_trainer_reset_kv
 }
 
 test_trainer_reset_kv();
-

perl-package/AI-MXNet/t/test_module.t

@@ -22,6 +22,7 @@ use AI::MXNet qw(mx);
 use AI::MXNet::Base;
 use AI::MXNet::TestUtils qw(almost_equal enumerate same_array dies_like rand_ndarray);
 $ENV{MXNET_STORAGE_FALLBACK_LOG_VERBOSE} = 0;
+$ENV{MXNET_SUBGRAPH_VERBOSE} = 0;
 
 sub test_module_layout
 {

perl-package/AI-MXNet/t/test_sparse_ndarray.t

@@ -24,6 +24,7 @@ use AI::MXNet::TestUtils qw(zip assert enumerate same rand_shape_2d rand_shape_3
     rand_sparse_ndarray random_arrays almost_equal rand_ndarray randint allclose dies_ok);
 use AI::MXNet::Base qw(pones pzeros pdl product rand_sparse);
 $ENV{MXNET_STORAGE_FALLBACK_LOG_VERBOSE} = 0;
+$ENV{MXNET_SUBGRAPH_VERBOSE} = 0;
 
 
 sub sparse_nd_ones

src/executor/graph_executor.cc

@@ -1627,16 +1627,16 @@ static nnvm::Graph InferForwardAttrs(nnvm::Graph g,
 
 static bool SubgraphBackendCheck(const op::SubgraphBackendPtr& backend,
                                  const Context& default_ctx,
-                                 bool verbose = false) {
+                                 int verbose = 1) {
   if (backend->HasAttr("enable") && (backend->GetAttr<bool>("enable") != true)) {
-    if (verbose) {
+    if (verbose > 1) {
       LOG(INFO) << "Subgraph backend " << backend->GetName()
                 << " isn't activated.";
     }
     return false;
   }
   if (backend->HasAttr("context") && backend->GetAttr<Context>("context") != default_ctx) {
-    if (verbose) {
+    if (verbose > 1) {
       LOG(INFO) << "Subgraph backend " << backend->GetName()
                 << " isn't activated as context mismatch.";
     }
@@ -1647,7 +1647,7 @@ static bool SubgraphBackendCheck(const op::SubgraphBackendPtr& backend,
 
 static bool SubgraphPropertyCheck(const std::string& backend_name,
                                   const op::SubgraphPropertyPtr& prop, bool need_grad,
-                                  bool verbose = false) {
+                                  int verbose = 1) {
   auto full_name =
       prop->HasAttr("property_name") ? prop->GetAttr<std::string>("property_name") : std::string();
   if (prop->HasAttr("disable") && prop->GetAttr<bool>("disable") == true) {
@@ -1657,7 +1657,7 @@ static bool SubgraphPropertyCheck(const std::string& backend_name,
   }
   if (prop->HasAttr("inference_only") && prop->GetAttr<bool>("inference_only") == true) {
     if (need_grad) {
-      if (verbose) {
+      if (verbose > 1) {
         LOG(INFO) << "skip partitioning graph with subgraph property " << full_name
                   << " from backend " << backend_name << " as it requires `grad_req=null`.";
       }
@@ -1699,7 +1699,7 @@ static nnvm::Symbol BuildSubgraph(
     const std::unordered_map<std::string, int>& arg_stype_map, const Context& default_ctx,
     const std::map<std::string, Context>& ctx_map, std::vector<Context>* in_arg_ctxes,
     std::vector<Context>* arg_grad_ctxes, std::vector<OpReqType>* grad_req_types,
-    std::vector<Context>* aux_state_ctxes, bool verbose = false) {
+    std::vector<Context>* aux_state_ctxes, int verbose = 1) {
   // setup map for in_arg_ctxes, arg_grad_ctxes, aux_state_ctxes and grad_req_types
   std::unordered_map<std::string, Context> in_arg_ctx_map;
   std::unordered_map<std::string, Context> arg_grad_ctx_map;
@@ -1794,7 +1794,7 @@ static nnvm::Symbol BuildSubgraph(const nnvm::Symbol& src, const op::SubgraphBac
                                   std::vector<NDArray>* in_args,
                                   std::vector<NDArray>* arg_grad_store,
                                   std::vector<OpReqType>* grad_req_type,
-                                  std::vector<NDArray>* aux_states, bool verbose = false) {
+                                  std::vector<NDArray>* aux_states, int verbose = 1) {
   // setup map for in_args, arg_grad_store, grad_req_type and aux_states
   std::unordered_map<std::string, NDArray> in_args_map;
   std::unordered_map<std::string, NDArray> arg_grad_store_map;
@@ -1929,11 +1929,11 @@ Executor *Executor::SimpleBind(nnvm::Symbol symbol,
   auto exec = new exec::GraphExecutor();
   bool init = false;
   if (!exec->subgraph_property().empty()) {
-    static bool verbose = dmlc::GetEnv("MXNET_SUBGRAPH_VERBOSE", false);
+    static int verbose = dmlc::GetEnv("MXNET_SUBGRAPH_VERBOSE", 1);
     const auto& backend_name = exec->subgraph_property();
     const auto& backend = op::SubgraphBackendRegistry::Get()->GetSubgraphBackend(backend_name);
     if (exec::SubgraphBackendCheck(backend, default_ctx, verbose)) {
-      LOG(INFO) << "Subgraph backend " << backend_name << " is activated.";
+      if (verbose) LOG(INFO) << "Subgraph backend " << backend_name << " is activated.";
       std::vector<Context> tmp_in_arg_ctxes = in_arg_ctxes;
       std::vector<Context> tmp_arg_grad_ctxes = arg_grad_ctxes;
       std::vector<Context> tmp_aux_state_ctxes = aux_state_ctxes;
@@ -2001,7 +2001,7 @@ Executor *Executor::Bind(nnvm::Symbol symbol,
                          const std::vector<NDArray> &aux_states,
                          Executor* shared_exec) {
   auto exec = new exec::GraphExecutor();
-  static bool verbose = dmlc::GetEnv("MXNET_SUBGRAPH_VERBOSE", false);
+  static int verbose = dmlc::GetEnv("MXNET_SUBGRAPH_VERBOSE", 1);
   std::vector<NDArray> tmp_in_args = in_args;
   std::vector<NDArray> tmp_arg_grad_store = arg_grad_store;
   std::vector<OpReqType> tmp_grad_req_type = grad_req_type;
@@ -2011,7 +2011,7 @@ Executor *Executor::Bind(nnvm::Symbol symbol,
     const auto& backend_name = exec->subgraph_property();
     const auto& backend = op::SubgraphBackendRegistry::Get()->GetSubgraphBackend(backend_name);
     if (exec::SubgraphBackendCheck(backend, default_ctx, verbose)) {
-      LOG(INFO) << "Subgraph backend " << backend_name << " is activated.";
+      if (verbose) LOG(INFO) << "Subgraph backend " << backend_name << " is activated.";
       symbol = exec::BuildSubgraph(symbol, backend, default_ctx, group2ctx, &tmp_in_args,
                                    &tmp_arg_grad_store, &tmp_grad_req_type, &tmp_aux_states,
                                    verbose);

src/operator/subgraph/build_subgraph.cc

@@ -318,8 +318,8 @@ void PreSelectSubgraphNodes(const nnvm::Graph& g, SubgraphSelectorV2Ptr subgraph
       for (auto node : excluded_nodes) {
         excluded_node_names += node->node->attrs.name + ", ";
       }
-      static bool verbose = dmlc::GetEnv("MXNET_SUBGRAPH_VERBOSE", false);
-      if (verbose) {
+      static int verbose = dmlc::GetEnv("MXNET_SUBGRAPH_VERBOSE", 1);
+      if (verbose > 1) {
         LOG(INFO) << "Found a cycle when BFS from node " << simple_nodes[snid]->node->attrs.name
                   << ". Excluding nodes " << excluded_node_names << "and retrying";
       }
@@ -706,9 +706,9 @@ void TopSortEntries(const nnvm::Graph& g,
 }
 
 nnvm::Graph BuildSubgraph(nnvm::Graph&& g) {
-    static bool verbose = dmlc::GetEnv("MXNET_SUBGRAPH_VERBOSE", false);
+    static int verbose = dmlc::GetEnv("MXNET_SUBGRAPH_VERBOSE", 1);
   if (!g.HasAttr("subgraph_property")) {  // treat the whole graph as a subgraph
-    if (verbose) {
+    if (verbose > 1) {
       LOG(INFO) << "The graph has no attribute of subgraph_property attached. "
                    "The original graph is returned.";
     }