coll/tuned: Refactor logging, and add coll_tuned_verbose mca parameter

Previously the coll_tuned output stream didn't use
opal_output_set_verbosity at all.  This made it difficult to
distinguish problems from noisy logging.

Signed-off-by: Luke Robison <[email protected]>

Author: Luke Robison

ompi/mca/coll/tuned/coll_tuned.h

@@ -30,6 +30,8 @@
 
 BEGIN_C_DECLS
 
+#define COLL_TUNED_TRACING_VERBOSE 50
+
 /* these are the same across all modules and are loaded at component query time */
 extern int   ompi_coll_tuned_stream;
 extern int   ompi_coll_tuned_priority;

ompi/mca/coll/tuned/coll_tuned_allgather_decision.c

@@ -133,7 +133,7 @@ int ompi_coll_tuned_allgather_intra_do_this(const void *sbuf, size_t scount,
                                             mca_coll_base_module_t *module,
                                             int algorithm, int faninout, int segsize)
 {
-    OPAL_OUTPUT((ompi_coll_tuned_stream,
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
                  "coll:tuned:allgather_intra_do_this selected algorithm %d topo faninout %d segsize %d",
                  algorithm, faninout, segsize));
     switch (algorithm) {
@@ -174,7 +174,7 @@ int ompi_coll_tuned_allgather_intra_do_this(const void *sbuf, size_t scount,
                                                          rbuf, rcount, rdtype,
                                                          comm, module);
     } /* switch */
-    OPAL_OUTPUT((ompi_coll_tuned_stream,
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
                  "coll:tuned:allgather_intra_do_this attempt to select algorithm %d when only 0-%d is valid?",
                  algorithm, ompi_coll_tuned_forced_max_algorithms[ALLGATHER]));
     return (MPI_ERR_ARG);

ompi/mca/coll/tuned/coll_tuned_allgatherv_decision.c

@@ -133,7 +133,7 @@ int ompi_coll_tuned_allgatherv_intra_do_this(const void *sbuf, size_t scount,
                                              int algorithm, int faninout,
                                              int segsize)
 {
-    OPAL_OUTPUT((ompi_coll_tuned_stream,
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
                  "coll:tuned:allgatherv_intra_do_this selected algorithm %d topo faninout %d segsize %d",
                  algorithm, faninout, segsize));
 
@@ -167,7 +167,7 @@ int ompi_coll_tuned_allgatherv_intra_do_this(const void *sbuf, size_t scount,
                                                          rbuf, rcounts, rdispls, rdtype,
                                                          comm, module);
     } /* switch */
-    OPAL_OUTPUT((ompi_coll_tuned_stream,
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
                  "coll:tuned:allgatherv_intra_do_this attempt to select algorithm %d when only 0-%d is valid?",
                  algorithm, ompi_coll_tuned_forced_max_algorithms[ALLGATHERV]));
     return (MPI_ERR_ARG);

ompi/mca/coll/tuned/coll_tuned_allreduce_decision.c

@@ -130,8 +130,9 @@ int ompi_coll_tuned_allreduce_intra_do_this(const void *sbuf, void *rbuf, size_t
                                             mca_coll_base_module_t *module,
                                             int algorithm, int faninout, int segsize)
 {
-    OPAL_OUTPUT((ompi_coll_tuned_stream,"coll:tuned:allreduce_intra_do_this algorithm %d topo fan in/out %d segsize %d",
-                 algorithm, faninout, segsize));
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
+        "coll:tuned:allreduce_intra_do_this algorithm %d topo fan in/out %d segsize %d",
+        algorithm, faninout, segsize));
 
     switch (algorithm) {
     case (0):
@@ -151,7 +152,8 @@ int ompi_coll_tuned_allreduce_intra_do_this(const void *sbuf, void *rbuf, size_t
     case (7):
         return ompi_coll_base_allreduce_intra_allgather_reduce(sbuf, rbuf, count, dtype, op, comm, module);
     } /* switch */
-    OPAL_OUTPUT((ompi_coll_tuned_stream,"coll:tuned:allreduce_intra_do_this attempt to select algorithm %d when only 0-%d is valid?",
-                 algorithm, ompi_coll_tuned_forced_max_algorithms[ALLREDUCE]));
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
+        "coll:tuned:allreduce_intra_do_this attempt to select algorithm %d when only 0-%d is valid?",
+        algorithm, ompi_coll_tuned_forced_max_algorithms[ALLREDUCE]));
     return (MPI_ERR_ARG);
 }

ompi/mca/coll/tuned/coll_tuned_alltoall_decision.c

@@ -165,8 +165,9 @@ int ompi_coll_tuned_alltoall_intra_do_this(const void *sbuf, size_t scount,
                                            int algorithm, int faninout, int segsize,
                                            int max_requests)
 {
-    OPAL_OUTPUT((ompi_coll_tuned_stream,"coll:tuned:alltoall_intra_do_this selected algorithm %d topo faninout %d segsize %d",
-                 algorithm, faninout, segsize));
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
+        "coll:tuned:alltoall_intra_do_this selected algorithm %d topo faninout %d segsize %d",
+        algorithm, faninout, segsize));
 
     switch (algorithm) {
     case (0):
@@ -182,7 +183,8 @@ int ompi_coll_tuned_alltoall_intra_do_this(const void *sbuf, size_t scount,
     case (5):
         return ompi_coll_base_alltoall_intra_two_procs(sbuf, scount, sdtype, rbuf, rcount, rdtype, comm, module);
     } /* switch */
-    OPAL_OUTPUT((ompi_coll_tuned_stream,"coll:tuned:alltoall_intra_do_this attempt to select algorithm %d when only 0-%d is valid?",
-                 algorithm, ompi_coll_tuned_forced_max_algorithms[ALLTOALL]));
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
+        "coll:tuned:alltoall_intra_do_this attempt to select algorithm %d when only 0-%d is valid?",
+        algorithm, ompi_coll_tuned_forced_max_algorithms[ALLTOALL]));
     return (MPI_ERR_ARG);
 }

ompi/mca/coll/tuned/coll_tuned_alltoallv_decision.c

@@ -96,7 +96,7 @@ int ompi_coll_tuned_alltoallv_intra_do_this(const void *sbuf, ompi_count_array_t
                                             mca_coll_base_module_t *module,
                                             int algorithm)
 {
-    OPAL_OUTPUT((ompi_coll_tuned_stream,
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
                  "coll:tuned:alltoallv_intra_do_this selected algorithm %d ",
                  algorithm));
 
@@ -114,7 +114,7 @@ int ompi_coll_tuned_alltoallv_intra_do_this(const void *sbuf, ompi_count_array_t
                                                        rbuf, rcounts, rdisps, rdtype,
                                                        comm, module);
     }  /* switch */
-    OPAL_OUTPUT((ompi_coll_tuned_stream,
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
                  "coll:tuned:alltoall_intra_do_this attempt to select "
                  "algorithm %d when only 0-%d is valid.",
                  algorithm, ompi_coll_tuned_forced_max_algorithms[ALLTOALLV]));

ompi/mca/coll/tuned/coll_tuned_barrier_decision.c

@@ -91,7 +91,7 @@ int ompi_coll_tuned_barrier_intra_do_this (struct ompi_communicator_t *comm,
                                            mca_coll_base_module_t *module,
                                            int algorithm, int faninout, int segsize)
 {
-    OPAL_OUTPUT((ompi_coll_tuned_stream,
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
                  "coll:tuned:barrier_intra_do_this selected algorithm %d topo fanin/out%d",
                  algorithm, faninout));
 
@@ -104,7 +104,8 @@ int ompi_coll_tuned_barrier_intra_do_this (struct ompi_communicator_t *comm,
     case (5):   return ompi_coll_base_barrier_intra_two_procs(comm, module);
     case (6):   return ompi_coll_base_barrier_intra_tree(comm, module);
     } /* switch */
-    OPAL_OUTPUT((ompi_coll_tuned_stream,"coll:tuned:barrier_intra_do_this attempt to select algorithm %d when only 0-%d is valid?",
-                 algorithm, ompi_coll_tuned_forced_max_algorithms[BARRIER]));
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
+        "coll:tuned:barrier_intra_do_this attempt to select algorithm %d when only 0-%d is valid?",
+        algorithm, ompi_coll_tuned_forced_max_algorithms[BARRIER]));
     return (MPI_ERR_ARG);
 }

ompi/mca/coll/tuned/coll_tuned_bcast_decision.c

@@ -140,8 +140,9 @@ int ompi_coll_tuned_bcast_intra_do_this(void *buf, size_t count,
                                         mca_coll_base_module_t *module,
                                         int algorithm, int faninout, int segsize)
 {
-    OPAL_OUTPUT((ompi_coll_tuned_stream,"coll:tuned:bcast_intra_do_this algorithm %d topo faninout %d segsize %d",
-                 algorithm, faninout, segsize));
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
+        "coll:tuned:bcast_intra_do_this algorithm %d topo faninout %d segsize %d",
+        algorithm, faninout, segsize));
 
     switch (algorithm) {
     case (0):
@@ -166,7 +167,8 @@ int ompi_coll_tuned_bcast_intra_do_this(void *buf, size_t count,
     case (9):
         return ompi_coll_base_bcast_intra_scatter_allgather_ring(buf, count, dtype, root, comm, module, segsize);
     } /* switch */
-    OPAL_OUTPUT((ompi_coll_tuned_stream,"coll:tuned:bcast_intra_do_this attempt to select algorithm %d when only 0-%d is valid?",
-                 algorithm, ompi_coll_tuned_forced_max_algorithms[BCAST]));
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
+        "coll:tuned:bcast_intra_do_this attempt to select algorithm %d when only 0-%d is valid?",
+        algorithm, ompi_coll_tuned_forced_max_algorithms[BCAST]));
     return (MPI_ERR_ARG);
 }

ompi/mca/coll/tuned/coll_tuned_component.c

@@ -56,6 +56,7 @@ char* ompi_coll_tuned_dynamic_rules_filename = (char*) NULL;
 int   ompi_coll_tuned_init_tree_fanout = 4;
 int   ompi_coll_tuned_init_chain_fanout = 4;
 int   ompi_coll_tuned_init_max_requests = 128;
+int   ompi_coll_tuned_verbose = 0;
 
 /* Set it to the same value as intermediate msg by default, so it does not affect
  * default algorithm selection. Changing this value will force using linear with
@@ -191,6 +192,15 @@ static int tuned_register(void)
                                            MCA_BASE_VAR_SCOPE_ALL,
                                            &ompi_coll_tuned_dynamic_rules_filename);
 
+    ompi_coll_tuned_verbose = 0;
+    (void) mca_base_component_var_register(&mca_coll_tuned_component.super.collm_version,
+                                           "verbose",
+                                           "Verbosity of the tuned coll component",
+                                           MCA_BASE_VAR_TYPE_INT, NULL, 0, MCA_BASE_VAR_FLAG_SETTABLE,
+                                           OPAL_INFO_LVL_9,
+                                           MCA_BASE_VAR_SCOPE_ALL,
+                                           &ompi_coll_tuned_verbose);
+
     /* register forced params */
     ompi_coll_tuned_allreduce_intra_check_forced_init(&ompi_coll_tuned_forced_params[ALLREDUCE]);
     ompi_coll_tuned_alltoall_intra_check_forced_init(&ompi_coll_tuned_forced_params[ALLTOALL]);
@@ -214,11 +224,10 @@ static int tuned_open(void)
 {
     int rc;
 
-#if OPAL_ENABLE_DEBUG
-    if (ompi_coll_base_framework.framework_verbose) {
+    if (ompi_coll_tuned_verbose) {
         ompi_coll_tuned_stream = opal_output_open(NULL);
+        opal_output_set_verbosity(ompi_coll_tuned_stream, ompi_coll_tuned_verbose);
     }
-#endif  /* OPAL_ENABLE_DEBUG */
 
     /* now check that the user hasn't overrode any of the decision functions if dynamic rules are enabled */
     /* the user can redo this before every comm dup/create if they like */
@@ -231,20 +240,24 @@ static int tuned_open(void)
     /* by default DISABLE dynamic rules and instead use fixed [if based] rules */
     if (ompi_coll_tuned_use_dynamic_rules) {
         if( ompi_coll_tuned_dynamic_rules_filename ) {
-            OPAL_OUTPUT((ompi_coll_tuned_stream,"coll:tuned:component_open Reading collective rules file [%s]",
-                         ompi_coll_tuned_dynamic_rules_filename));
+            OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
+                "coll:tuned:component_open Reading collective rules file [%s]",
+                ompi_coll_tuned_dynamic_rules_filename));
             rc = ompi_coll_tuned_read_rules_config_file( ompi_coll_tuned_dynamic_rules_filename,
                                                          &(mca_coll_tuned_component.all_base_rules));
             if( rc == OPAL_SUCCESS ) {
-                OPAL_OUTPUT((ompi_coll_tuned_stream,"coll:tuned:module_open Read a valid rules file"));
+                OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
+                    "coll:tuned:module_open Read a valid rules file"));
             } else {
-                OPAL_OUTPUT((ompi_coll_tuned_stream,"coll:tuned:module_open Reading collective rules file failed\n"));
+                OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
+                    "coll:tuned:module_open Reading collective rules file failed\n"));
                 mca_coll_tuned_component.all_base_rules = NULL;
             }
         }
     }
 
-    OPAL_OUTPUT((ompi_coll_tuned_stream, "coll:tuned:component_open: done!"));
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
+        "coll:tuned:component_open: done!"));
 
     return OMPI_SUCCESS;
 }
@@ -253,12 +266,14 @@ static int tuned_open(void)
 /* i.e. alg table and dynamic changeable rules if allocated etc */
 static int tuned_close(void)
 {
-    OPAL_OUTPUT((ompi_coll_tuned_stream, "coll:tuned:component_close: called"));
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
+        "coll:tuned:component_close: called"));
 
     /* dealloc alg table if allocated */
     /* dealloc dynamic changeable rules if allocated */
 
-    OPAL_OUTPUT((ompi_coll_tuned_stream, "coll:tuned:component_close: done!"));
+    OPAL_OUTPUT_VERBOSE((COLL_TUNED_TRACING_VERBOSE, ompi_coll_tuned_stream,
+        "coll:tuned:component_close: done!"));
 
     if( NULL != mca_coll_tuned_component.all_base_rules ) {
         ompi_coll_tuned_free_all_rules(mca_coll_tuned_component.all_base_rules);