[query] use log4j-api-scala for string interpolation

Author: ehigham

hail/build.mill

@@ -52,13 +52,15 @@ object Deps {
     def core: Task[Dep] = Task.Anon(mvn"org.apache.spark::spark-core:${Env.sparkVersion()}")
     def mllib: Task[Dep] = Task.Anon(mvn"org.apache.spark::spark-mllib:${Env.sparkVersion()}")
   }
-  
+
   object Log4j {
     // have to forceVersion for reasons unknown?
     val bom = mvn"org.apache.logging.log4j:log4j-bom:2.25.2".forceVersion()
     val api = mvn"org.apache.logging.log4j:log4j-api"
     val core = mvn"org.apache.logging.log4j:log4j-core"
     val slf4j = mvn"org.apache.logging.log4j:log4j-slf4j2-impl"
+
+    val scala = mvn"org.apache.logging.log4j::log4j-api-scala:13.1.0"
   }
 
   val samtools = mvn"com.github.samtools:htsjdk:3.0.5"
@@ -289,6 +291,7 @@ trait RootHailModule extends CrossScalaModule with HailModule { outer =>
     Deps.Asm.core,
     Deps.Asm.analysis,
     Deps.Asm.util,
+    Deps.Log4j.scala,
     Deps.samtools.excludeOrg("*"),
     Deps.jdistlib.excludeOrg("*"),
     Deps.freemarker,
@@ -326,7 +329,7 @@ trait RootHailModule extends CrossScalaModule with HailModule { outer =>
 
   override def assemblyRules: Seq[Rule] = super.assemblyRules ++ Seq(
     Rule.Exclude("META-INF/INDEX.LIST"),
-    Rule.ExcludePattern("scala/(?!collection/compat).*"),
+    Rule.ExcludePattern("^scala/(?!collection/compat).*"),
     Rule.AppendPattern("META-INF/services/.*", "\n"),
 //    Rule.Relocate("scala.collection.compat.**", "is.hail.relocated.@0"),
     Rule.Relocate("breeze.**", "is.hail.relocated.@0"),

hail/hail/src/is/hail/annotations/BroadcastValue.scala

@@ -6,11 +6,12 @@ import is.hail.expr.ir.defs.EncodedLiteral
 import is.hail.io.{BufferSpec, Decoder, TypedCodecSpec}
 import is.hail.types.physical.{PArray, PStruct, PType}
 import is.hail.types.virtual.{TBaseStruct, TStruct}
-import is.hail.utils.{formatSpace, log, ArrayOfByteArrayOutputStream}
+import is.hail.utils.{formatSpace, ArrayOfByteArrayOutputStream}
 import is.hail.utils.prettyPrint.ArrayOfByteArrayInputStream
 
 import java.io.InputStream
 
+import org.apache.logging.log4j.scala.Logging
 import org.apache.spark.sql.Row
 
 case class SerializableRegionValue(
@@ -36,7 +37,7 @@ object BroadcastRow {
   }
 }
 
-trait BroadcastRegionValue {
+trait BroadcastRegionValue extends Logging {
   def ctx: ExecuteContext
 
   def value: RegionValue
@@ -72,7 +73,7 @@ trait BroadcastRegionValue {
         if (broadcasted == null) {
           val arrays = encodeToByteArrays(theHailClassLoader)
           val totalSize = arrays.map(_.length).sum
-          log.info(
+          logger.info(
             s"BroadcastRegionValue.broadcast: broadcasting ${arrays.length} byte arrays of total size $totalSize (${formatSpace(totalSize.toLong)}"
           )
           val srv = SerializableRegionValue(arrays, decodedPType, makeDec)

hail/hail/src/is/hail/annotations/Region.scala

@@ -3,7 +3,8 @@ package is.hail.annotations
 import is.hail.asm4s
 import is.hail.asm4s.Code
 import is.hail.types.physical._
-import is.hail.utils._
+
+import org.apache.logging.log4j.scala.Logging
 
 object Region {
   type Size = Int
@@ -475,7 +476,7 @@ final class Region protected[annotations] (
   def totalManagedBytes(): Long = memory.totalManagedBytes()
 }
 
-object RegionUtils {
+object RegionUtils extends Logging {
   def printAddr(off: Long, name: String): String = s"$name: ${"%016x".format(off)}"
 
   def printAddr(off: Code[Long], name: String): Code[String] =
@@ -512,7 +513,7 @@ object RegionUtils {
 
     val nReferenced = region.nReferencedRegions()
 
-    info(
+    logger.info(
       s"""
          |$header:
          |  block size: $size

hail/hail/src/is/hail/annotations/RegionPool.scala

@@ -3,6 +3,8 @@ package is.hail.annotations
 import is.hail.expr.ir.LongArrayBuilder
 import is.hail.utils._
 
+import org.apache.logging.log4j.scala.Logging
+
 object RegionPool {
 
   def apply(strictMemoryCheck: Boolean = false): RegionPool = {
@@ -22,8 +24,8 @@ object RegionPool {
 }
 
 final class RegionPool private (strictMemoryCheck: Boolean, threadName: String, threadID: Long)
-    extends AutoCloseable {
-  log.info(s"RegionPool: initialized for thread $threadID: $threadName")
+    extends AutoCloseable with Logging {
+  logger.info(s"initialized for thread $threadID: $threadName")
 
   protected[annotations] val freeBlocks: Array[LongArrayBuilder] =
     Array.fill[LongArrayBuilder](4)(new LongArrayBuilder(8))
@@ -140,7 +142,7 @@ final class RegionPool private (strictMemoryCheck: Boolean, threadName: String,
 
     val freeBlockCounts = freeBlocks.map(_.size)
     val usedBlockCounts = blocks.zip(freeBlockCounts).map { case (tot, free) => tot - free }
-    info(
+    logger.info(
       s"""Region count for $context
          |    regions: $nRegions active, $nFree free
          |     blocks: $nBlocks
@@ -152,15 +154,15 @@ final class RegionPool private (strictMemoryCheck: Boolean, threadName: String,
   def report(context: String): Unit = {
     val inBlocks = bytesInBlocks()
 
-    log.info(
+    logger.info(
       s"RegionPool: $context: ${readableBytes(totalAllocatedBytes)} allocated (${readableBytes(inBlocks)} blocks / " +
         s"${readableBytes(totalAllocatedBytes - inBlocks)} chunks), regions.size = ${regions.size}, " +
         s"$numJavaObjects current java objects, thread $threadID: $threadName"
     )
-//    log.info("-----------STACK_TRACES---------")
+//    logger.info("-----------STACK_TRACES---------")
 //    val stacks: String = regions.result().toIndexedSeq.flatMap(r => r.stackTrace.map((r.getTotalChunkMemory(), _))).foldLeft("")((a: String, b) => a + "\n" + b.toString())
-//    log.info(stacks)
-//    log.info("---------------END--------------")
+//    logger.info(stacks)
+//    logger.info("---------------END--------------")
   }
 
   def scopedRegion[T](f: Region => T): T = using(Region(pool = this))(f)
@@ -202,7 +204,7 @@ final class RegionPool private (strictMemoryCheck: Boolean, threadName: String,
       if (strictMemoryCheck)
         fatal(msg)
       else
-        warn(msg)
+        logger.warn(msg)
     }
   }
 }

hail/hail/src/is/hail/asm4s/ClassBuilder.scala

@@ -10,6 +10,7 @@ import java.io._
 import java.nio.charset.StandardCharsets
 
 import javassist.bytecode.DuplicateMemberException
+import org.apache.logging.log4j.scala.Logging
 import org.apache.spark.TaskContext
 import org.objectweb.asm.ClassReader
 import org.objectweb.asm.util.{Textifier, TraceClassVisitor}
@@ -66,7 +67,7 @@ case class StaticField[T] private (lf: lir.StaticField) extends AnyVal {
   }
 }
 
-class ClassesBytes(classesBytes: Array[(String, Array[Byte])]) extends Serializable {
+class ClassesBytes(classesBytes: Array[(String, Array[Byte])]) extends Serializable with Logging {
   @transient @volatile var loaded: Boolean = false
 
   def load(hcl: HailClassLoader): Unit = {
@@ -81,7 +82,7 @@ class ClassesBytes(classesBytes: Array[(String, Array[Byte])]) extends Serializa
                 val buffer = new ByteArrayOutputStream()
                 FunctionBuilder.bytesToBytecodeString(bytes, buffer)
                 val classJVMByteCodeAsEscapedStr = buffer.toString(StandardCharsets.UTF_8.name())
-                log.error(s"Failed to load bytecode $e:\n" + classJVMByteCodeAsEscapedStr)
+                logger.error(s"Failed to load bytecode $e:\n" + classJVMByteCodeAsEscapedStr)
                 throw e
             }
           }

hail/hail/src/is/hail/backend/BackendUtils.scala

@@ -7,13 +7,15 @@ import is.hail.expr.ir.lowering.TableStageDependency
 import is.hail.io.fs._
 import is.hail.utils._
 
+import org.apache.logging.log4j.scala.Logging
+
 object BackendUtils {
   type F = AsmFunction3[Region, Array[Byte], Array[Byte], Array[Byte]]
 }
 
 class BackendUtils(
   mods: Array[(String, (HailClassLoader, FS, HailTaskContext, Region) => BackendUtils.F)]
-) {
+) extends Logging {
 
   import BackendUtils.F
 
@@ -46,7 +48,7 @@ class BackendUtils(
   ): Array[Array[Byte]] = {
 
     val cachedResults = ctx.executionCache.lookup(semhash)
-    log.info(s"$stageName: found ${cachedResults.length} entries for $semhash.")
+    logger.info(s"$stageName: found ${cachedResults.length} entries for $semhash.")
 
     val todo =
       contexts
@@ -65,7 +67,7 @@ class BackendUtils(
     val results = merge[(Array[Byte], Int)](cachedResults, successes, _._2 < _._2)
 
     ctx.executionCache.put(semhash, results)
-    log.info(s"$stageName: cached ${results.length} entries for $semhash.")
+    logger.info(s"$stageName: cached ${results.length} entries for $semhash.")
 
     failureOpt.foreach(throw _)
     Array.tabulate[Array[Byte]](results.length)(results(_)._1)
@@ -98,7 +100,7 @@ class BackendUtils(
 
     val elapsed = System.nanoTime() - start
     val nTasks = partitions.map(_.length).getOrElse(contexts.length)
-    log.info(s"$stageName: executed $nTasks tasks in ${formatTime(elapsed)}")
+    logger.info(s"$stageName: executed $nTasks tasks in ${formatTime(elapsed)}")
 
     r
   }

hail/hail/src/is/hail/backend/ExecutionCache.scala

@@ -3,7 +3,7 @@ package is.hail.backend
 import is.hail.HailFeatureFlags
 import is.hail.expr.ir.analyses.SemanticHash
 import is.hail.io.fs.FS
-import is.hail.utils.{using, Logging}
+import is.hail.utils.using
 
 import scala.io.Source
 import scala.util.control.NonFatal
@@ -12,6 +12,8 @@ import java.io.{FileNotFoundException, OutputStream}
 import java.util.Base64
 import java.util.concurrent.ConcurrentHashMap
 
+import org.apache.logging.log4j.scala.Logging
+
 trait ExecutionCache extends Serializable {
   def lookup(s: SemanticHash.Type): IndexedSeq[(Array[Byte], Int)]
   def put(s: SemanticHash.Type, r: IndexedSeq[(Array[Byte], Int)]): Unit
@@ -75,7 +77,7 @@ private case class FSExecutionCache(fs: FS, cacheDir: String) extends ExecutionC
         IndexedSeq.empty
 
       case NonFatal(t) =>
-        log.warn(s"Failed to read cache entry for $s", t)
+        logger.warn(s"Failed to read cache entry for $s", t)
         IndexedSeq.empty
     }
 

hail/hail/src/is/hail/backend/HailTaskContext.scala

@@ -5,6 +5,8 @@ import is.hail.utils._
 
 import java.io.Closeable
 
+import org.apache.logging.log4j.scala.Logging
+
 class TaskFinalizer {
   val closeables = new BoxedArrayBuilder[Closeable]()
 
@@ -18,7 +20,7 @@ class TaskFinalizer {
     (0 until closeables.size).foreach(i => closeables(i).close())
 }
 
-abstract class HailTaskContext extends AutoCloseable {
+abstract class HailTaskContext extends AutoCloseable with Logging {
   def stageId(): Int
 
   def partitionId(): Int
@@ -44,7 +46,7 @@ abstract class HailTaskContext extends AutoCloseable {
   }
 
   def close(): Unit = {
-    log.info(
+    logger.info(
       s"TaskReport: stage=${stageId()}, partition=${partitionId()}, attempt=${attemptNumber()}, " +
         s"peakBytes=${thePool.getHighestTotalUsage}, peakBytesReadable=${formatSpace(thePool.getHighestTotalUsage)}, " +
         s"chunks requested=${thePool.getUsage._1}, cache hits=${thePool.getUsage._2}"

hail/hail/src/is/hail/backend/driver/BatchQueryDriver.scala

@@ -21,6 +21,7 @@ import java.io.OutputStream
 import java.nio.charset.StandardCharsets
 import java.nio.file.Path
 
+import org.apache.logging.log4j.scala.Logging
 import org.json4s.JsonAST.JValue
 import org.json4s.jackson.JsonMethods
 
@@ -71,13 +72,13 @@ object BatchQueryDriver extends HttpLikeRpc with Logging {
         val (shortMessage, expandedMessage, errorId) =
           t match {
             case t: HailWorkerException =>
-              log.error(
+              logger.error(
                 "A worker failed. The exception was written for Python but we will also throw an exception to fail this driver job.",
                 t,
               )
               (t.shortMessage, t.expandedMessage, t.errorId)
             case _ =>
-              log.error(
+              logger.error(
                 "An exception occurred in the driver. The exception was written for Python but we will re-throw to fail this driver job.",
                 t,
               )
@@ -134,7 +135,7 @@ object BatchQueryDriver extends HttpLikeRpc with Logging {
     val inputURL = argv(5)
     val outputURL = argv(6)
 
-    log.info(f"${getClass.getName} $HAIL_PRETTY_VERSION")
+    logger.info(f"${getClass.getName} $HAIL_PRETTY_VERSION")
 
     sys.env.get("HAIL_SSL_CONFIG_DIR").foreach(tls.setSSLConfigFromDir)
 

hail/hail/src/is/hail/backend/driver/Py4JQueryDriver.scala

@@ -31,12 +31,13 @@ import java.util
 import com.google.api.client.http.HttpStatusCodes
 import com.sun.net.httpserver.{HttpExchange, HttpServer}
 import org.apache.hadoop.conf.Configuration
+import org.apache.logging.log4j.scala.Logging
 import org.apache.spark.sql.DataFrame
 import org.json4s._
 import org.json4s.jackson.{JsonMethods, Serialization}
 import sourcecode.Enclosing
 
-final class Py4JQueryDriver(backend: Backend) extends Closeable {
+final class Py4JQueryDriver(backend: Backend) extends Closeable with Logging {
 
   private[this] val flags: HailFeatureFlags = HailFeatureFlags.fromEnv()
   private[this] val hcl = new HailClassLoader(getClass.getClassLoader)
@@ -77,7 +78,7 @@ final class Py4JQueryDriver(backend: Backend) extends Closeable {
       localTmpdir = tmp
       backend match {
         case s: SparkBackend if tmp != "file://" + s.sc.getConf.get("spark.local.dir", "") =>
-          log.warn(
+          logger.warn(
             "Cannot modify Spark's local directory at runtime. " +
               "Please stop and re-initialize hail with 'spark.local.dir' " +
               "in your Spark configuration."
@@ -234,7 +235,7 @@ final class Py4JQueryDriver(backend: Backend) extends Closeable {
   def pyReadMultipleMatrixTables(jsonQuery: String): util.List[MatrixIR] =
     withExecuteContext(selfContainedExecution = false) { ctx =>
       implicit val fmts: Formats = DefaultFormats
-      log.info("pyReadMultipleMatrixTables: got query")
+      logger.info("pyReadMultipleMatrixTables: got query")
 
       val kvs = JsonMethods.parse(jsonQuery).extract[Map[String, JValue]]
       val paths = kvs("paths").extract[IndexedSeq[String]]
@@ -246,12 +247,12 @@ final class Py4JQueryDriver(backend: Backend) extends Closeable {
       val opts = NativeReaderOptions(intervalObjects, intervalPointType)
       val matrixReaders: util.List[MatrixIR] =
         paths.map { p =>
-          log.info(s"creating MatrixRead node for $p")
+          logger.info(s"creating MatrixRead node for $p")
           val mnr = MatrixNativeReader(ctx.fs, p, Some(opts))
           MatrixRead(mnr.fullMatrixTypeWithoutUIDs, false, false, mnr): MatrixIR
         }.asJava
 
-      log.info("pyReadMultipleMatrixTables: returning N matrix tables")
+      logger.info("pyReadMultipleMatrixTables: returning N matrix tables")
       matrixReaders
     }._1
 
@@ -293,10 +294,10 @@ final class Py4JQueryDriver(backend: Backend) extends Closeable {
 
   def pyGrepPrint(regex: String, files: Seq[String], maxLines: Int): Unit =
     fileAndLineCounts(regex, files, maxLines).foreach { case (file, lines) =>
-      info(s"$file: ${lines.length} ${plural(lines.length, "match", "matches")}:")
+      logger.info(s"$file: ${lines.length} ${plural(lines.length, "match", "matches")}:")
       lines.map(_.value).foreach { line =>
         val (screen, logged) = line.truncatable().strings
-        log.info("\t" + logged)
+        logger.info("\t" + logged)
         println(s"\t$screen")
       }
     }