Implement TorAppConfig.start(), use tor logs to detect when the tor is fully started (#3549)

* Implement TorAppConfig.start(), use tor logs to detect when the tor binary is fully started

* Clean up comments

* take ben's suggestion and only start the binary when tor is enabled

* Add cases for when binary is alreayd started

* Actually set the stop flag correctly

* Scalafmt

app/server/src/main/scala/org/bitcoins/server/BitcoinSServerMain.scala

@@ -56,13 +56,6 @@ class BitcoinSServerMain(override val serverArgParser: ServerArgParser)(implicit
 
     for {
       _ <- startedConfigF
-
-      _ <-
-        if (torConf.enabled) {
-          val tor = torConf.createClient
-          tor.startBinary()
-        } else Future.unit
-
       start <- {
         nodeConf.nodeType match {
           case _: InternalImplementationNodeType =>
@@ -81,13 +74,7 @@ class BitcoinSServerMain(override val serverArgParser: ServerArgParser)(implicit
       _ <- walletConf.stop()
       _ <- nodeConf.stop()
       _ <- chainConf.stop()
-      _ <- {
-        if (torConf.enabled) {
-          torConf.createClient.stopBinary()
-        } else {
-          Future.unit
-        }
-      }
+      _ <- torConf.stop()
       _ = logger.info(s"Stopped ${nodeConf.nodeType.shortName} node")
       _ <- system.terminate()
     } yield {

build.sbt

@@ -139,7 +139,7 @@ lazy val lndRpc = project
 lazy val tor = project
   .in(file("tor"))
   .settings(CommonSettings.prodSettings: _*)
-  .dependsOn(coreJVM, appCommons)
+  .dependsOn(coreJVM, appCommons, asyncUtilsJVM)
 
 lazy val torTest = project
   .in(file("tor-test"))

dlc-node/src/main/scala/org/bitcoins/dlc/node/config/DLCNodeAppConfig.scala

@@ -20,7 +20,7 @@ import scala.concurrent._
   */
 case class DLCNodeAppConfig(
     private val directory: Path,
-    private val conf: Config*)
+    private val conf: Config*)(implicit ec: ExecutionContext)
     extends AppConfig {
   override protected[bitcoins] def configOverrides: List[Config] = conf.toList
 

tor/src/main/scala/org/bitcoins/tor/config/TorAppConfig.scala

@@ -1,6 +1,7 @@
 package org.bitcoins.tor.config
 
 import com.typesafe.config.Config
+import org.bitcoins.asyncutil.AsyncUtil
 import org.bitcoins.commons.config.{AppConfig, AppConfigFactory, ConfigOps}
 import org.bitcoins.core.util.NetworkUtil
 import org.bitcoins.tor.TorProtocolHandler.{Password, SafeCookie}
@@ -8,14 +9,17 @@ import org.bitcoins.tor.client.TorClient
 import org.bitcoins.tor.{Socks5ProxyParams, TorParams}
 
 import java.io.File
-import java.nio.file.Path
+import java.nio.file.{Files, Path}
+import java.util.concurrent.atomic.AtomicBoolean
 import scala.concurrent.{ExecutionContext, Future}
 
 /** Configuration for the Bitcoin-S node
   * @param directory The data directory of the node
   * @param confs Optional sequence of configuration overrides
   */
-case class TorAppConfig(private val directory: Path, private val confs: Config*)
+case class TorAppConfig(
+    private val directory: Path,
+    private val confs: Config*)(implicit ec: ExecutionContext)
     extends AppConfig {
   override protected[bitcoins] def configOverrides: List[Config] = confs.toList
   override protected[bitcoins] def moduleName: String = TorAppConfig.moduleName
@@ -27,12 +31,69 @@ case class TorAppConfig(private val directory: Path, private val confs: Config*)
 
   protected[bitcoins] def baseDatadir: Path = directory
 
+  private val isStarted: AtomicBoolean = new AtomicBoolean(false)
+
   /** Ensures correct tables and other required information is in
     * place for our node.
     */
-  override def start(): Future[Unit] = Future.unit
+  override def start(): Future[Unit] = {
+    if (torParams.isDefined && !isStarted.get) {
+      isStarted.set(true)
+      val start = System.currentTimeMillis()
+      //remove old tor log file so we accurately tell when
+      //the binary is started, if we don't remove this
+      //we could have that log line appear from previous runs
+      if (torLogFile.toFile.exists()) {
+        torLogFile.toFile.delete()
+      }
+      val startedBinary: Future[Unit] = createClient.startBinary()
+      for {
+        _ <- startedBinary
+        _ <- isBinaryFullyStarted()
+      } yield {
+        logger.info(
+          s"Tor binary is fully started, it took=${System.currentTimeMillis() - start}ms")
+      }
+    } else if (isStarted.get) {
+      logger.debug(s"Tor binary already started")
+      Future.unit
+    } else {
+      logger.warn(
+        s"Tor was requested to start, but it is diabled in the configuration file. Not starting tor")
+      Future.unit
+    }
+  }
 
-  override def stop(): Future[Unit] = Future.unit
+  private val isBootstrappedLogLine = "Bootstrapped 100% (done): Done"
+
+  /** Checks if the tor binary is started by looking for a log in the [[torLogFile]]
+    * The log line we are looking or is
+    * {{{
+    *     Bootstrapped 100% (done): Done
+    *  }}}
+    */
+  private def isBinaryFullyStarted(): Future[Unit] = {
+    AsyncUtil.retryUntilSatisfied(checkIfLogExists)
+  }
+
+  /** Checks it the [[isBootstrappedLogLine]] exists in the tor log file */
+  private def checkIfLogExists: Boolean = {
+    val stream = Files.lines(torLogFile)
+    try {
+      stream
+        .filter((line: String) => line.contains(isBootstrappedLogLine))
+        .count() > 0
+    } finally if (stream != null) stream.close()
+  }
+
+  override def stop(): Future[Unit] = {
+    createClient
+      .stopBinary()
+      .map { _ =>
+        isStarted.set(false)
+        ()
+      }
+  }
 
   lazy val socks5ProxyParams: Option[Socks5ProxyParams] = {
     if (config.getBoolean("bitcoin-s.proxy.enabled")) {