You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@mahout.apache.org by ak...@apache.org on 2017/02/27 23:15:51 UTC

mahout git commit: MAHOUT-1913: Clean Up of VCL bindings closes apache/mahout#290

Repository: mahout
Updated Branches:
  refs/heads/master 7883ebc26 -> 9ed9b4af4


MAHOUT-1913: Clean Up of VCL bindings closes apache/mahout#290


Project: http://git-wip-us.apache.org/repos/asf/mahout/repo
Commit: http://git-wip-us.apache.org/repos/asf/mahout/commit/9ed9b4af
Tree: http://git-wip-us.apache.org/repos/asf/mahout/tree/9ed9b4af
Diff: http://git-wip-us.apache.org/repos/asf/mahout/diff/9ed9b4af

Branch: refs/heads/master
Commit: 9ed9b4af4153fd3fed42d928c505d05335b29b92
Parents: 7883ebc
Author: Andrew Musselman <ak...@apache.org>
Authored: Mon Feb 27 15:15:43 2017 -0800
Committer: Andrew Musselman <ak...@apache.org>
Committed: Mon Feb 27 15:15:43 2017 -0800

----------------------------------------------------------------------
 .../mahout/math/backend/RootSolverFactory.scala | 37 ++++----
 .../mahout/cf/SimilarityAnalysisSuite.scala     |  2 +-
 .../apache/mahout/viennacl/openmp/OMPMMul.scala | 56 ++++++------
 .../mahout/viennacl/omp/ViennaCLSuiteOMP.scala  |  4 +-
 .../apache/mahout/viennacl/opencl/GPUMMul.scala | 93 +++++++++-----------
 5 files changed, 89 insertions(+), 103 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/mahout/blob/9ed9b4af/math-scala/src/main/scala/org/apache/mahout/math/backend/RootSolverFactory.scala
----------------------------------------------------------------------
diff --git a/math-scala/src/main/scala/org/apache/mahout/math/backend/RootSolverFactory.scala b/math-scala/src/main/scala/org/apache/mahout/math/backend/RootSolverFactory.scala
index 253a435..382537f 100644
--- a/math-scala/src/main/scala/org/apache/mahout/math/backend/RootSolverFactory.scala
+++ b/math-scala/src/main/scala/org/apache/mahout/math/backend/RootSolverFactory.scala
@@ -18,7 +18,7 @@ package org.apache.mahout.math.backend
 
 import org.apache.mahout.logging._
 import org.apache.mahout.math.backend.jvm.JvmBackend
-import org.apache.mahout.math.scalabindings.{MMul, _}
+import org.apache.mahout.math.scalabindings.{MMBinaryFunc, MMul, _}
 
 import scala.collection._
 import scala.reflect.{ClassTag, classTag}
@@ -28,7 +28,7 @@ final object RootSolverFactory extends SolverFactory {
 
   import org.apache.mahout.math.backend.incore._
 
-  implicit val logger = getLog(RootSolverFactory.getClass)
+  private implicit val logger = getLog(RootSolverFactory.getClass)
 
   private val solverTagsToScan =
     classTag[MMulSolver] ::
@@ -43,42 +43,39 @@ final object RootSolverFactory extends SolverFactory {
 
   }
 
-  ////////////////////////////////////////////////////////////
-
-  // TODO: MAHOUT-1909: lazy initialze the map. Query backends. Build resolution rules.
+  // TODO: MAHOUT-1909: Cache Modular Backend solvers after probing
+  // That is, lazily initialize the map, query backends, and build resolution rules.
   override protected[backend] val solverMap = new mutable.HashMap[ClassTag[_], Any]()
-  validateMap()
 
+  validateMap()
 
-  // default is JVM
+  // Default solver is JVM
   var clazz: MMBinaryFunc = MMul
 
-  // eventually match on implicit Classtag . for now.  just take as is.
-  // this is a bit hacky, Shoud not be doing onlytry/catch here..
+  // TODO: Match on implicit Classtag
+
   def getOperator[C: ClassTag]: MMBinaryFunc = {
 
     try {
-      // TODO: fix logging properties so that we're not mimicing as we are here.
-      println("[INFO] Creating org.apache.mahout.viennacl.opencl.GPUMMul solver")
+      logger.info("Creating org.apache.mahout.viennacl.opencl.GPUMMul solver")
       clazz = Class.forName("org.apache.mahout.viennacl.opencl.GPUMMul$").getField("MODULE$").get(null).asInstanceOf[MMBinaryFunc]
-      println("[INFO] Successfully created org.apache.mahout.viennacl.opencl.GPUMMul solver")
+      logger.info("Successfully created org.apache.mahout.viennacl.opencl.GPUMMul solver")
 
     } catch {
       case x: Exception =>
-        println("[WARN] Unable to create class GPUMMul: attempting OpenMP version")
-        // println(x.getMessage)
+        logger.warn("Unable to create class GPUMMul: attempting OpenMP version")
         try {
-          // attempt to instantiate the OpenMP version, assuming we\u2019ve
+          // Attempt to instantiate the OpenMP version, assuming we\u2019ve
           // created a separate OpenMP-only module (none exist yet)
-          println("[INFO] Creating org.apache.mahout.viennacl.openmp.OMPMMul solver")
+          logger.info("Creating org.apache.mahout.viennacl.openmp.OMPMMul solver")
           clazz = Class.forName("org.apache.mahout.viennacl.openmp.OMPMMul$").getField("MODULE$").get(null).asInstanceOf[MMBinaryFunc]
-          println("[INFO] Successfully created org.apache.mahout.viennacl.openmp.OMPMMul solver")
+          logger.info("Successfully created org.apache.mahout.viennacl.openmp.OMPMMul solver")
 
         } catch {
           case xx: Exception =>
-            println(xx.getMessage)
-            // fall back to JVM Dont need to Dynamicly assign MMul is in the same package.
-            println("[INFO] Unable to create class OMPMMul: falling back to java version")
+            logger.error(xx.getMessage)
+            // Fall back to JVM; don't need to dynamically assign since MMul is in the same package.
+            logger.info("Unable to create class OMPMMul: falling back to java version")
             clazz = MMul
         }
     }

http://git-wip-us.apache.org/repos/asf/mahout/blob/9ed9b4af/spark/src/test/scala/org/apache/mahout/cf/SimilarityAnalysisSuite.scala
----------------------------------------------------------------------
diff --git a/spark/src/test/scala/org/apache/mahout/cf/SimilarityAnalysisSuite.scala b/spark/src/test/scala/org/apache/mahout/cf/SimilarityAnalysisSuite.scala
index 2d74f7d..242ad74 100644
--- a/spark/src/test/scala/org/apache/mahout/cf/SimilarityAnalysisSuite.scala
+++ b/spark/src/test/scala/org/apache/mahout/cf/SimilarityAnalysisSuite.scala
@@ -72,7 +72,7 @@ class SimilarityAnalysisSuite extends FunSuite with MahoutSuite with Distributed
       (0.0,                0.0,                0.6795961471815897, 0.0,                4.498681156950466))
 
 
-  test("Cross-occurrence [A'A], [B'A] boolbean data using LLR") {
+  test("Cross-occurrence [A'A], [B'A] boolean data using LLR") {
     val a = dense(
         (1, 1, 0, 0, 0),
         (0, 0, 1, 1, 0),

http://git-wip-us.apache.org/repos/asf/mahout/blob/9ed9b4af/viennacl-omp/src/main/scala/org/apache/mahout/viennacl/openmp/OMPMMul.scala
----------------------------------------------------------------------
diff --git a/viennacl-omp/src/main/scala/org/apache/mahout/viennacl/openmp/OMPMMul.scala b/viennacl-omp/src/main/scala/org/apache/mahout/viennacl/openmp/OMPMMul.scala
index 58a06dd..9a59999 100644
--- a/viennacl-omp/src/main/scala/org/apache/mahout/viennacl/openmp/OMPMMul.scala
+++ b/viennacl-omp/src/main/scala/org/apache/mahout/viennacl/openmp/OMPMMul.scala
@@ -33,7 +33,7 @@ import scala.collection.JavaConversions._
 
 object OMPMMul extends MMBinaryFunc {
 
-  private final implicit val log = getLog(OMPMMul.getClass)
+  private implicit val log = getLog(OMPMMul.getClass)
 
   override def apply(a: Matrix, b: Matrix, r: Option[Matrix]): Matrix = {
 
@@ -209,7 +209,7 @@ object OMPMMul extends MMBinaryFunc {
 
   @inline
   private def jvmRWRW(a: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("jvmRWRW")
+    log.info("Using jvmRWRW method")
     // A bit hackish: currently, this relies a bit on the fact that like produces RW(?)
     val bclone = b.like(b.ncol, b.nrow).t
     for (brow \u2190 b) bclone(brow.index(), ::) := brow
@@ -221,12 +221,12 @@ object OMPMMul extends MMBinaryFunc {
   }
 
   private def jvmCWCW(a: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("jvmCWCW")
+    log.info("Using jvmCWCW method")
     jvmRWRW(b.t, a.t, r.map(_.t)).t
   }
 
   private def jvmCWRW(a: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("jvmCWRW")
+    log.info("Using jvmCWRW method")
     // This is a primary contender with Outer Prod sum algo.
     // Here, we force-reorient both matrices and run RWCW.
     // A bit hackish: currently, this relies a bit on the fact that clone always produces RW(?)
@@ -240,14 +240,16 @@ object OMPMMul extends MMBinaryFunc {
 
   // left is Sparse right is any
   private def ompSparseRWRW(a: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("ompSparseRWRW")
+    log.info("Using ompSparseRWRW method")
     val mxR = r.getOrElse(b.like(a.nrow, b.ncol))
 
-    // make sure that the matrix is not empty.  VCL {{compressed_matrix}}s must
-    // hav nnz > 0
-    // this method is horribly inefficent.  however there is a difference between
-    // getNumNonDefaultElements() and getNumNonZeroElements() which we do not always
-    // have access to  created MAHOUT-1882 for this
+    /* Make sure that the matrix is not empty.  VCL {{compressed_matrix}}s must
+       have nnz > 0
+       N.B. This method is horribly inefficent. However there is a difference between
+       getNumNonDefaultElements() and getNumNonZeroElements() which we do not always
+       have access to. We created MAHOUT-1882 for this.
+    */
+
     val hasElementsA = a.zSum() >  0.0
     val hasElementsB = b.zSum() >  0.0
 
@@ -255,7 +257,7 @@ object OMPMMul extends MMBinaryFunc {
     // simply convert it to a Dense Matrix which may result in an OOM error.
     // If it is empty use JVM MMul, since we can not convert it to a VCL CSR Matrix.
     if (!hasElementsA)  {
-      println("Matrix a has zero elements can not convert to CSR")
+      log.warn("Matrix a has zero elements can not convert to CSR")
       return MMul(a, b, r)
     }
 
@@ -268,7 +270,7 @@ object OMPMMul extends MMBinaryFunc {
       val oclC = new DenseRowMatrix(prod(oclA, oclB))
       val mxC = fromVclDenseRM(oclC)
       ms = System.currentTimeMillis() - ms
-      debug(s"ViennaCL/OpenMP multiplication time: $ms ms.")
+      log.debug(s"ViennaCL/OpenMP multiplication time: $ms ms.")
 
       oclA.close()
       oclB.close()
@@ -278,7 +280,7 @@ object OMPMMul extends MMBinaryFunc {
     } else {
       // Fall back to JVM based MMul if either matrix is sparse and empty
       if (!hasElementsA || !hasElementsB)  {
-        println("Matrix a or b has zero elements can not convert to CSR")
+        log.warn("Matrix a or b has zero elements can not convert to CSR")
         return MMul(a, b, r)
       }
 
@@ -289,7 +291,7 @@ object OMPMMul extends MMBinaryFunc {
       val oclC = new CompressedMatrix(prod(oclA, oclB))
       val mxC = fromVclCompressedMatrix(oclC)
       ms = System.currentTimeMillis() - ms
-      debug(s"ViennaCL/OpenMP multiplication time: $ms ms.")
+      log.debug(s"ViennaCL/OpenMP multiplication time: $ms ms.")
 
       oclA.close()
       oclB.close()
@@ -302,7 +304,7 @@ object OMPMMul extends MMBinaryFunc {
 
   //sparse %*% dense
   private def ompSparseRowRWRW(a: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("ompSparseRowRWRW")
+    log.info("Using ompSparseRowRWRW method")
     val hasElementsA = a.zSum() >  0
 
     // A has a sparse matrix structure of unknown size.  We do not want to
@@ -310,7 +312,7 @@ object OMPMMul extends MMBinaryFunc {
     // If it is empty fall back to  JVM MMul, since we can not convert it
     // to a VCL CSR Matrix.
     if (!hasElementsA)  {
-      println("Matrix a has zero elements can not convert to CSR")
+      log.warn("Matrix a has zero elements can not convert to CSR")
       return MMul(a, b, r)
     }
 
@@ -321,7 +323,7 @@ object OMPMMul extends MMBinaryFunc {
     val oclC = new DenseRowMatrix(prod(oclA, oclB))
     val mxC = fromVclDenseRM(oclC)
     ms = System.currentTimeMillis() - ms
-    debug(s"ViennaCL/OpenMP multiplication time: $ms ms.")
+    log.debug(s"ViennaCL/OpenMP multiplication time: $ms ms.")
 
     oclA.close()
     oclB.close()
@@ -339,7 +341,6 @@ object OMPMMul extends MMBinaryFunc {
   private def jvmSparseRowRWCW(a: Matrix, b: Matrix, r: Option[Matrix]) =
     ompSparseRowRWRW(a, b cloned, r)
 
-
   private def jvmSparseRowCWRW(a: Matrix, b: Matrix, r: Option[Matrix]) =
     ompSparseRowRWRW(a cloned, b, r)
 
@@ -356,7 +357,7 @@ object OMPMMul extends MMBinaryFunc {
     ompSparseRWRW(a cloned, b cloned, r)
 
   private def jvmDiagRW(diagm:Matrix, b:Matrix, r:Option[Matrix] = None):Matrix = {
-    println("jvmDiagRW")
+    log.info("Using jvmDiagRW method")
     val mxR = r.getOrElse(b.like(diagm.nrow, b.ncol))
 
     for (del \u2190 diagm.diagv.nonZeroes())
@@ -366,7 +367,7 @@ object OMPMMul extends MMBinaryFunc {
   }
 
   private def jvmDiagCW(diagm: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("jvmDiagCW")
+    log.info("Using jvmDiagCW method")
     val mxR = r.getOrElse(b.like(diagm.nrow, b.ncol))
     for (bcol \u2190 b.t) mxR(::, bcol.index()) := bcol * diagm.diagv
     mxR
@@ -378,7 +379,6 @@ object OMPMMul extends MMBinaryFunc {
   private def jvmRWDiag(a: Matrix, diagm: Matrix, r: Option[Matrix] = None) =
     jvmDiagCW(diagm, a.t, r.map {_.t}).t
 
-
   /** Dense column-wise AA' */
   private def jvmDCWAAt(a:Matrix, b:Matrix, r:Option[Matrix] = None) = {
     // a.t must be equiv. to b. Cloning must rewrite to row-wise.
@@ -386,12 +386,12 @@ object OMPMMul extends MMBinaryFunc {
   }
 
   /** Dense Row-wise AA' */
-  // we probably will not want to use this for the actual release unless A is cached already
+  // We probably will not want to use this for the actual release unless A is cached already
   // but adding for testing purposes.
   private def ompDRWAAt(a:Matrix, b:Matrix, r:Option[Matrix] = None) = {
     // a.t must be equiv to b.
-    println("executing on OMP")
-    debug("AAt computation detected; passing off to OMP")
+    log.info("Executing on OMP")
+    log.debug("AAt computation detected; passing off to OMP")
 
     // Check dimensions if result is supplied.
     require(r.forall(mxR \u21d2 mxR.nrow == a.nrow && mxR.ncol == a.nrow))
@@ -406,7 +406,7 @@ object OMPMMul extends MMBinaryFunc {
 
     val mxC = fromVclDenseRM(oclC)
     ms = System.currentTimeMillis() - ms
-    debug(s"ViennaCL/OpenMP multiplication time: $ms ms.")
+    log.debug(s"ViennaCL/OpenMP multiplication time: $ms ms.")
 
     oclA.close()
     //oclApr.close()
@@ -418,9 +418,9 @@ object OMPMMul extends MMBinaryFunc {
   }
 
   private def jvmOuterProdSum(a: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("jvmOuterProdSum")
-    // This may be already laid out for outer product computation, which may be faster than reorienting
-    // both matrices? need to check.
+    log.info("Using jvmOuterProdSum method")
+    // Need to check whether this is already laid out for outer product computation, which may be faster than
+    // reorienting both matrices.
     val (m, n) = (a.nrow, b.ncol)
 
     // Prefer col-wise result iff a is dense and b is sparse. In all other cases default to row-wise.

http://git-wip-us.apache.org/repos/asf/mahout/blob/9ed9b4af/viennacl-omp/src/test/scala/org/apache/mahout/viennacl/omp/ViennaCLSuiteOMP.scala
----------------------------------------------------------------------
diff --git a/viennacl-omp/src/test/scala/org/apache/mahout/viennacl/omp/ViennaCLSuiteOMP.scala b/viennacl-omp/src/test/scala/org/apache/mahout/viennacl/omp/ViennaCLSuiteOMP.scala
index 8eb3ff9..af29e3c 100644
--- a/viennacl-omp/src/test/scala/org/apache/mahout/viennacl/omp/ViennaCLSuiteOMP.scala
+++ b/viennacl-omp/src/test/scala/org/apache/mahout/viennacl/omp/ViennaCLSuiteOMP.scala
@@ -145,7 +145,7 @@ class ViennaCLSuiteOMP extends FunSuite with Matchers {
       info(s"ViennaCL/cpu/OpenMP Sparse multiplication time: $ms ms.")
 
       val ompMxC = fromVclCompressedMatrix(ompC)
-      (mxC - ompMxC).norm / mxC.nrow / mxC.ncol should be < 1e-16
+      (mxC - ompMxC).norm / mxC.nrow / mxC.ncol should be < 1e-10
 
       ompA.close()
       ompB.close()
@@ -192,7 +192,7 @@ class ViennaCLSuiteOMP extends FunSuite with Matchers {
 
         ms = System.currentTimeMillis() - ms
         info(s"ViennaCL/cpu/OpenMP dense matrix %*% dense vector multiplication time: $ms ms.")
-        (ompDvecC.toColMatrix - mDvecC.toColMatrix).norm / s  should be < 1e-16
+        (ompDvecC.toColMatrix - mDvecC.toColMatrix).norm / s  should be < 1e-10
 
         ompMxA.close()
         ompVecB.close()

http://git-wip-us.apache.org/repos/asf/mahout/blob/9ed9b4af/viennacl/src/main/scala/org/apache/mahout/viennacl/opencl/GPUMMul.scala
----------------------------------------------------------------------
diff --git a/viennacl/src/main/scala/org/apache/mahout/viennacl/opencl/GPUMMul.scala b/viennacl/src/main/scala/org/apache/mahout/viennacl/opencl/GPUMMul.scala
index 936448d..a0b317d 100644
--- a/viennacl/src/main/scala/org/apache/mahout/viennacl/opencl/GPUMMul.scala
+++ b/viennacl/src/main/scala/org/apache/mahout/viennacl/opencl/GPUMMul.scala
@@ -32,7 +32,7 @@ import org.apache.mahout.viennacl.opencl.javacpp.{CompressedMatrix, Context, Den
 import scala.collection.JavaConversions._
 object GPUMMul extends MMBinaryFunc {
 
-  private final implicit val log = getLog(GPUMMul.getClass)
+  private implicit val log = getLog(GPUMMul.getClass)
 
   override def apply(a: Matrix, b: Matrix, r: Option[Matrix]): Matrix = {
 
@@ -126,12 +126,12 @@ object GPUMMul extends MMBinaryFunc {
 
       alg(a, b, r)
     } catch {
-      // TODO FASTHACK:  just revert to JVM if there is an exception..
-      //  eg. java.lang.nullPointerException if more openCL contexts
+      // TODO FASTHACK: Revert to JVM if there is an exception.
+      //  E.g., java.lang.nullPointerException if more openCL contexts
       //  have been created than number of GPU cards.
-      //  better option wuold be to fall back to OpenCl First.
+      //  Better option wuold be to fall back to OpenCL first.
       case ex: Exception =>
-        println(ex.getMessage + "falling back to JVM MMUL")
+        log.warn(ex.getMessage + "falling back to JVM MMUL")
         return MMul(a, b, r)
     }
   }
@@ -140,18 +140,7 @@ object GPUMMul extends MMBinaryFunc {
 
   @inline
   private def gpuRWCW(a: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("gpuRWCW")
-//
-//    require(r.forall(mxR \u21d2 mxR.nrow == a.nrow && mxR.ncol == b.ncol))
-//    val (m, n) = (a.nrow, b.ncol)
-//
-//    val mxR = r.getOrElse(if (densityAnalysis(a)) a.like(m, n) else b.like(m, n))
-//
-//    for (row \u2190 0 until mxR.nrow; col \u2190 0 until mxR.ncol) {
-//      // this vector-vector should be sort of optimized, right?
-//      mxR(row, col) = a(row, ::) dot b(::, col)
-//    }
-//    mxR
+    log.info("Using gpuRWCW method")
 
     val hasElementsA = a.zSum() >  0.0
     val hasElementsB = b.zSum() >  0.0
@@ -161,7 +150,7 @@ object GPUMMul extends MMBinaryFunc {
 
     // If it is empty use JVM MMul, since we can not convert it to a VCL CSR Matrix.
     if (!hasElementsA)  {
-      println("Matrix a has zero elements can not convert to CSR")
+      log.warn("Matrix a has zero elements can not convert to CSR")
       return MMul(a, b, r)
     }
 
@@ -174,7 +163,7 @@ object GPUMMul extends MMBinaryFunc {
       val oclC = new DenseRowMatrix(prod(oclA, oclB))
       val mxC = fromVclDenseRM(oclC)
       ms = System.currentTimeMillis() - ms
-      debug(s"ViennaCL/OpenCL multiplication time: $ms ms.")
+      log.debug(s"ViennaCL/OpenCL multiplication time: $ms ms.")
 
       oclA.close()
       oclB.close()
@@ -184,7 +173,7 @@ object GPUMMul extends MMBinaryFunc {
     } else {
       // Fall back to JVM based MMul if either matrix is sparse and empty
       if (!hasElementsA || !hasElementsB)  {
-        println("Matrix a or b has zero elements can not convert to CSR")
+        log.warn("Matrix a or b has zero elements can not convert to CSR")
         return MMul(a, b, r)
       }
 
@@ -195,7 +184,7 @@ object GPUMMul extends MMBinaryFunc {
       val oclC = new CompressedMatrix(prod(oclA, oclB))
       val mxC = fromVclCompressedMatrix(oclC)
       ms = System.currentTimeMillis() - ms
-      debug(s"ViennaCL/OpenCL multiplication time: $ms ms.")
+      log.debug(s"ViennaCL/OpenCL multiplication time: $ms ms.")
 
       oclA.close()
       oclB.close()
@@ -208,7 +197,7 @@ object GPUMMul extends MMBinaryFunc {
 
   @inline
   private def jvmRWRW(a: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("jvmRWRW")
+    log.info("Using jvmRWRW method")
     // A bit hackish: currently, this relies a bit on the fact that like produces RW(?)
     val bclone = b.like(b.ncol, b.nrow).t
     for (brow \u2190 b) bclone(brow.index(), ::) := brow
@@ -220,12 +209,12 @@ object GPUMMul extends MMBinaryFunc {
   }
 
   private def jvmCWCW(a: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("jvmCWCW")
+    log.info("Using jvmCWCW method")
     jvmRWRW(b.t, a.t, r.map(_.t)).t
   }
 
   private def jvmCWRW(a: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("jvmCWRW")
+    log.info("Using jvmCWRW method")
     // This is a primary contender with Outer Prod sum algo.
     // Here, we force-reorient both matrices and run RWCW.
     // A bit hackish: currently, this relies a bit on the fact that clone always produces RW(?)
@@ -239,21 +228,22 @@ object GPUMMul extends MMBinaryFunc {
 
   // left is Sparse right is any
   private def gpuSparseRWRW(a: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("gpuSparseRWRW")
+    log.info("Using gpuSparseRWRW method")
     val mxR = r.getOrElse(b.like(a.nrow, b.ncol))
 
 
-//    // This is basically almost the algorithm from SparseMatrix.times
-//    for (arow \u2190 a; ael \u2190 arow.nonZeroes)
-//      mxR(arow.index(), ::).assign(b(ael.index, ::), Functions.plusMult(ael))
-//
-//    mxR
+    /* This is very close to the algorithm from SparseMatrix.times
+         for (arow \u2190 a; ael \u2190 arow.nonZeroes)
+           mxR(arow.index(), ::).assign(b(ael.index, ::), Functions.plusMult(ael))
+           mxR
+
+       Make sure that the matrix is not empty. VCL {{compressed_matrix}}s must
+       have nnz > 0
+       N.B. This method is horribly inefficent. However there is a difference between
+       getNumNonDefaultElements() and getNumNonZeroElements() which we do not always
+       have access to. We created MAHOUT-1882 for this.
+    */
 
-    // make sure that the matrix is not empty.  VCL {{compressed_matrix}}s must
-    // hav nnz > 0
-    // this method is horribly inefficent.  however there is a difference between
-    // getNumNonDefaultElements() and getNumNonZeroElements() which we do not always
-    // have access to  created MAHOUT-1882 for this
     val hasElementsA = a.zSum() >  0.0
     val hasElementsB = b.zSum() >  0.0
 
@@ -261,7 +251,7 @@ object GPUMMul extends MMBinaryFunc {
     // simply convert it to a Dense Matrix which may result in an OOM error.
     // If it is empty use JVM MMul, since we can not convert it to a VCL CSR Matrix.
     if (!hasElementsA)  {
-     println("Matrix a has zero elements can not convert to CSR")
+     log.warn("Matrix a has zero elements can not convert to CSR")
      return MMul(a, b, r)
     }
 
@@ -274,7 +264,7 @@ object GPUMMul extends MMBinaryFunc {
       val oclC = new DenseRowMatrix(prod(oclA, oclB))
       val mxC = fromVclDenseRM(oclC)
       ms = System.currentTimeMillis() - ms
-      debug(s"ViennaCL/OpenCL multiplication time: $ms ms.")
+      log.debug(s"ViennaCL/OpenCL multiplication time: $ms ms.")
 
       oclA.close()
       oclB.close()
@@ -284,7 +274,7 @@ object GPUMMul extends MMBinaryFunc {
     } else {
       // Fall back to JVM based MMul if either matrix is sparse and empty
       if (!hasElementsA || !hasElementsB)  {
-        println("Matrix a or b has zero elements can not convert to CSR")
+        log.warn("Matrix a or b has zero elements can not convert to CSR")
         return MMul(a, b, r)
       }
 
@@ -295,7 +285,7 @@ object GPUMMul extends MMBinaryFunc {
       val oclC = new CompressedMatrix(prod(oclA, oclB))
       val mxC = fromVclCompressedMatrix(oclC)
       ms = System.currentTimeMillis() - ms
-      debug(s"ViennaCL/OpenCL multiplication time: $ms ms.")
+      log.debug(s"ViennaCL/OpenCL multiplication time: $ms ms.")
 
       oclA.close()
       oclB.close()
@@ -306,9 +296,9 @@ object GPUMMul extends MMBinaryFunc {
 
   }
 
-  //sparse %*% dense
+  // Sparse %*% dense
   private def gpuSparseRowRWRW(a: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("gpuSparseRowRWRW")
+    log.info("Using gpuSparseRowRWRW method")
     val hasElementsA = a.zSum() >  0
 
     // A has a sparse matrix structure of unknown size.  We do not want to
@@ -316,7 +306,7 @@ object GPUMMul extends MMBinaryFunc {
     // If it is empty fall back to  JVM MMul, since we can not convert it
     // to a VCL CSR Matrix.
     if (!hasElementsA)  {
-      println("Matrix a has zero elements can not convert to CSR")
+      log.warn("Matrix a has zero elements can not convert to CSR")
       return MMul(a, b, r)
     }
 
@@ -327,7 +317,7 @@ object GPUMMul extends MMBinaryFunc {
     val oclC = new DenseRowMatrix(prod(oclA, oclB))
     val mxC = fromVclDenseRM(oclC)
     ms = System.currentTimeMillis() - ms
-    debug(s"ViennaCL/OpenCL multiplication time: $ms ms.")
+    log.debug(s"ViennaCL/OpenCL multiplication time: $ms ms.")
 
     oclA.close()
     oclB.close()
@@ -362,7 +352,7 @@ object GPUMMul extends MMBinaryFunc {
     gpuSparseRWRW(a cloned, b cloned, r)
 
   private def jvmDiagRW(diagm:Matrix, b:Matrix, r:Option[Matrix] = None):Matrix = {
-    println("jvmDiagRW")
+    log.info("Using jvmDiagRW method")
     val mxR = r.getOrElse(b.like(diagm.nrow, b.ncol))
 
     for (del \u2190 diagm.diagv.nonZeroes())
@@ -372,7 +362,7 @@ object GPUMMul extends MMBinaryFunc {
   }
 
   private def jvmDiagCW(diagm: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("jvmDiagCW")
+    log.info("Using jvmDiagCW method")
     val mxR = r.getOrElse(b.like(diagm.nrow, b.ncol))
     for (bcol \u2190 b.t) mxR(::, bcol.index()) := bcol * diagm.diagv
     mxR
@@ -396,8 +386,8 @@ object GPUMMul extends MMBinaryFunc {
   // but adding for testing purposes.
   private def gpuDRWAAt(a:Matrix, b:Matrix, r:Option[Matrix] = None) = {
     // a.t must be equiv to b.
-    println("executing on gpu")
-    debug("AAt computation detected; passing off to GPU")
+    log.info("Executing on gpu")
+    log.debug("AAt computation detected; passing off to GPU")
 
     // Check dimensions if result is supplied.
     require(r.forall(mxR \u21d2 mxR.nrow == a.nrow && mxR.ncol == a.nrow))
@@ -415,7 +405,6 @@ object GPUMMul extends MMBinaryFunc {
     debug(s"ViennaCL/OpenCL multiplication time: $ms ms.")
 
     oclA.close()
-    //oclApr.close()
     oclAt.close()
     oclC.close()
 
@@ -424,9 +413,9 @@ object GPUMMul extends MMBinaryFunc {
   }
 
   private def jvmOuterProdSum(a: Matrix, b: Matrix, r: Option[Matrix] = None): Matrix = {
-    println("jvmOuterProdSum")
-    // This may be already laid out for outer product computation, which may be faster than reorienting
-    // both matrices? need to check.
+    log.info("Using jvmOuterProdSum method")
+    // Need to check whether this is already laid out for outer product computation, which may be faster than
+    // reorienting both matrices.
     val (m, n) = (a.nrow, b.ncol)
 
     // Prefer col-wise result iff a is dense and b is sparse. In all other cases default to row-wise.
@@ -443,7 +432,7 @@ object GPUMMul extends MMBinaryFunc {
 
     // Loop outer products
     if (preferColWiseR) {
-      // this means B is sparse and A is not, so we need to iterate over b values and update R columns with +=
+      // B is sparse and A is not, so we need to iterate over b values and update R columns with +=
       // one at a time.
       for ((acol, brow) \u2190 a.t.zip(b); bel \u2190 brow.nonZeroes) mxR(::, bel.index()) += bel * acol
     } else {