Extend test durations on CI for Ledger API Test Tool driven test. (#944)

* Extend test durations on CI for Ledger API Test Tool driven test.

This introduces a command-line argument to scale timeouts used in the test.

* ledger-api-its: Make FutureTimeouts.timeout duration scaled inside.

Also include more information in the error message.

ledger/ledger-api-integration-tests/src/test/lib/scala/com/digitalasset/platform/semantictest/SemanticTestAdapter.scala

@@ -31,11 +31,13 @@ import scala.concurrent.{ExecutionContext, Future}
 class SemanticTestAdapter(
     lc: LedgerContext,
     packages: Map[Ref.PackageId, Ast.Package],
-    parties: Iterable[String])(
+    parties: Iterable[String],
+    timeoutScaleFactor: Double = 1.0
+)(
     implicit ec: ExecutionContext,
     am: ActorMaterializer,
-    esf: ExecutionSequencerFactory)
+    esf: ExecutionSequencerFactory
-    extends SemanticTester.GenericLedger {
+) extends SemanticTester.GenericLedger {
   override type EventNodeId = String
 
   private def ledgerId = lc.ledgerId
@@ -61,7 +63,10 @@ class SemanticTestAdapter(
     : Future[Event.Events[String, Value.AbsoluteContractId, TxValue[Value.AbsoluteContractId]]] = {
     for {
       tx <- LedgerTestingHelpers
-        .sync(lc.commandService.submitAndWaitForTransactionId, lc)
+        .sync(
+          lc.commandService.submitAndWaitForTransactionId,
+          lc,
+          timeoutScaleFactor = timeoutScaleFactor)
         .submitAndListenForSingleTreeResultOfCommand(
           SubmitRequest(Some(apiCommand(submitterName, cmds))),
           TransactionFilter(parties.map(_ -> Filters.defaultInstance)(breakOut)),

ledger/ledger-api-integration-tests/src/test/lib/scala/com/digitalasset/platform/tests/integration/ledger/api/FutureTimeouts.scala

@@ -4,22 +4,29 @@
 package com.digitalasset.platform.tests.integration.ledger.api
 import akka.actor.ActorSystem
 import com.digitalasset.platform.common.util.DirectExecutionContext
+import org.scalatest.concurrent.Waiters
 
 import scala.concurrent.duration._
 import scala.concurrent.{Future, Promise, TimeoutException}
 import scala.util.control.NoStackTrace
 
-trait FutureTimeouts {
+trait FutureTimeouts extends Waiters {
 
   // TODO get rid of the default timeout, see issue: #464 and #548
   protected def timeout[T](f: Future[T], opName: String, duration: FiniteDuration = 500.seconds)(
       implicit system: ActorSystem): Future[T] = {
+    val scaledDuration = scaled(duration)
     val promise: Promise[T] = Promise[T]()
 
-    val cancellable = system.scheduler.scheduleOnce(duration, { () =>
+    val cancellable = system.scheduler.scheduleOnce(
-      promise.failure(new TimeoutException(s"$opName timed out after $duration.") with NoStackTrace)
+      scaledDuration, { () =>
-      ()
+        promise.failure(
-    })(system.dispatcher)
+          new TimeoutException(
+            s"$opName timed out after $scaledDuration${if (duration != scaledDuration)
+              s" (scaled from $duration)"}.") with NoStackTrace)
+        ()
+      }
+    )(system.dispatcher)
 
     f.onComplete(_ => cancellable.cancel())(DirectExecutionContext)
 

ledger/ledger-api-integration-tests/src/test/lib/scala/com/digitalasset/platform/tests/integration/ledger/api/LedgerTestingHelpers.scala

@@ -29,6 +29,7 @@ import com.digitalasset.platform.participant.util.ValueConversions._
 import com.google.rpc.code.Code
 import com.google.rpc.status.Status
 import io.grpc.StatusRuntimeException
+import org.scalatest.concurrent.Waiters
 import org.scalatest.{Assertion, Inside, Matchers, OptionValues}
 
 import scala.collection.{breakOut, immutable}
@@ -39,8 +40,10 @@ import scala.language.implicitConversions
 @SuppressWarnings(Array("org.wartremover.warts.Any"))
 class LedgerTestingHelpers(
     submitCommand: SubmitRequest => Future[Completion],
-    context: LedgerContext)(implicit mat: ActorMaterializer)
+    context: LedgerContext,
+    timeoutScaleFactor: Double = 1.0)(implicit mat: ActorMaterializer)
     extends Matchers
+    with Waiters
     with FutureTimeouts
     with Inside
     with OptionValues {
@@ -123,7 +126,7 @@ class LedgerTestingHelpers(
         )
         .filter(_.transactionId == transactionId)
         .take(1)
-        .takeWithin(3.seconds)
+        .takeWithin(scaled(3.seconds))
         .runWith(Sink.headOption)
     } yield {
       tx shouldBe empty
@@ -234,7 +237,7 @@ class LedgerTestingHelpers(
       )
       .filter(x => commandId.fold(true)(cid => x.commandId == cid))
       .take(1)
-      .takeWithin(15.seconds)
+      .takeWithin(scaled(15.seconds))
       .runWith(Sink.seq)
   }
 
@@ -252,7 +255,7 @@ class LedgerTestingHelpers(
       )
       .filter(x => commandId.fold(true)(cid => x.commandId == cid))
       .take(1)
-      .takeWithin(3.seconds)
+      .takeWithin(scaled(3.seconds))
       .runWith(Sink.seq)
   }
 
@@ -475,7 +478,7 @@ class LedgerTestingHelpers(
       )
       .filter(x => commandId.fold(true)(cid => x.commandId == cid))
       .take(1)
-      .takeWithin(3.seconds)
+      .takeWithin(scaled(3.seconds))
       .runWith(Sink.seq)
   }
 
@@ -589,25 +592,31 @@ class LedgerTestingHelpers(
             completion
         }
         .take(1)
-        .takeWithin(3.seconds)
+        .takeWithin(scaled(3.seconds))
         .runWith(Sink.seq)
         .map(_.headOption)
     }
   }
+
+  override def spanScaleFactor: Double = timeoutScaleFactor
 }
 
 object LedgerTestingHelpers extends OptionValues {
+
   def sync(
       submitCommand: SubmitAndWaitRequest => Future[SubmitAndWaitForTransactionIdResponse],
-      context: LedgerContext)(
+      context: LedgerContext,
+      timeoutScaleFactor: Double = 1.0)(
       implicit ec: ExecutionContext,
       mat: ActorMaterializer): LedgerTestingHelpers =
-    async(helper(submitCommand), context)
+    async(helper(submitCommand), context, timeoutScaleFactor = timeoutScaleFactor)
 
   def asyncFromTimeService(
       timeService: TimeService,
       submit: TimeProvider => SubmitRequest => Future[Completion],
-      context: LedgerContext)(
+      context: LedgerContext,
+      timeoutScaleFactor: Double = 1.0
+  )(
       implicit ec: ExecutionContext,
       mat: ActorMaterializer,
       esf: ExecutionSequencerFactory): LedgerTestingHelpers = {
@@ -617,13 +626,16 @@ object LedgerTestingHelpers extends OptionValues {
         res <- submit(st)(submitRequest)
       } yield res
     }
-    async(submitCommand, context)
+    async(submitCommand, context, timeoutScaleFactor = timeoutScaleFactor)
   }
 
-  def async(submitCommand: SubmitRequest => Future[Completion], context: LedgerContext)(
+  def async(
+      submitCommand: SubmitRequest => Future[Completion],
+      context: LedgerContext,
+      timeoutScaleFactor: Double = 1.0)(
       implicit ec: ExecutionContext,
       mat: ActorMaterializer): LedgerTestingHelpers =
-    new LedgerTestingHelpers(submitCommand, context)
+    new LedgerTestingHelpers(submitCommand, context, timeoutScaleFactor)
 
   def responseToCompletion(commandId: String, respF: Future[SubmitAndWaitForTransactionIdResponse])(
       implicit ec: ExecutionContext): Future[Completion] =

ledger/ledger-api-test-tool/BUILD.bazel

@@ -81,6 +81,9 @@ client_server_test(
     timeout = "short",
     client = ":ledger-api-test-tool",
     client_args = [
+        # NOTE(GP): our CI has a tendency to be more unpredictable than local
+        # machine with timeouts, we value lack of flakes on CI.
+        "--timeout-scale-factor=10",
     ],
 
     # Data files available to both client and server.
@@ -103,9 +106,11 @@ client_server_test(
     timeout = "short",
     client = ":ledger-api-test-tool",
     client_args = [
-        "--crt $(rootpath testdata/client.crt) " +
+        "--crt $(rootpath testdata/client.crt)",
-        "--cacrt $(rootpath testdata/ca.crt) " +
+        "--cacrt $(rootpath testdata/ca.crt)",
         "--pem $(rootpath testdata/client.pem)",
+        # See note above.
+        "--timeout-scale-factor=10",
     ],
 
     # Data files available to both client and server.

ledger/ledger-api-test-tool/src/main/scala/com/daml/ledger/api/testtool/Cli.scala

@@ -29,7 +29,7 @@ object Cli {
 
   private val argParser = new scopt.OptionParser[Config]("ledger-api-test-tool") {
     head("""The Ledger API Test Tool is a command line tool for testing the correctness of
-           |ledger implementations based on DAML and Ledger API.""".stripMargin)
+        |ledger implementations based on DAML and Ledger API.""".stripMargin)
 
     help("help").text("prints this usage text")
 
@@ -56,17 +56,25 @@ object Cli {
       .text("TLS: The crt file to be used as the the trusted root CA.")
       .action(cacrtConfig)
 
+    opt[Double](name = "timeout-scale-factor")
+      .optional()
+      .action((v, c) => c.copy(timeoutScaleFactor = v))
+      .text("""Scale factor for timeouts used in testing. Useful to tune timeouts
+          |depending on the environment and the Ledger implementation under test.
+          |Defaults to 1.0. Use numbers higher than 1.0 to make test timeouts more lax,
+          |use numbers lower than 1.0 to make test timeouts more strict.""".stripMargin)
+
     opt[Unit]("must-fail")
       .action((_, c) => c.copy(mustFail = true))
       .text("""Reverse success status logic of the tool. Use this flag if you expect one or
-              |more or the scenario tests to fail. If enabled, the tool will succeed when at
+          |more or the scenario tests to fail. If enabled, the tool will succeed when at
-              |least one test fails, and it will fail when all tests succeed. Defaults to
+          |least one test fails, and it will fail when all tests succeed. Defaults to
-              |false.""".stripMargin)
+          |false.""".stripMargin)
 
     opt[Unit]('r', "reset")
       .action((_, c) => c.copy(performReset = true))
       .text("""Perform a ledger reset before running the tests. If enabled, the tool will wipe
-              |all of the contents of the target ledger. Defaults to false.""".stripMargin)
+          |all of the contents of the target ledger. Defaults to false.""".stripMargin)
 
     opt[Unit]('x', "extract")
       .action((_, c) => c.copy(extract = true))

ledger/ledger-api-test-tool/src/main/scala/com/daml/ledger/api/testtool/Config.scala

@@ -12,6 +12,7 @@ final case class Config(
     packageContainer: DamlPackageContainer,
     performReset: Boolean,
     mustFail: Boolean,
+    timeoutScaleFactor: Double,
     extract: Boolean,
     tlsConfig: Option[TlsConfiguration]
 )
@@ -23,6 +24,7 @@ object Config {
     packageContainer = DamlPackageContainer(),
     performReset = false,
     mustFail = false,
+    timeoutScaleFactor = 1.0,
     extract = false,
     tlsConfig = None
   )

ledger/ledger-api-test-tool/src/main/scala/com/daml/ledger/api/testtool/LedgerApiTestTool.scala

@@ -72,7 +72,12 @@ object LedgerApiTestTool {
       scenarios.foreach {
         case (pkgId, names) =>
           val tester = new SemanticTester(
-            parties => new SemanticTestAdapter(ledger, packages, parties),
+            parties =>
+              new SemanticTestAdapter(
+                ledger,
+                packages,
+                parties,
+                timeoutScaleFactor = config.timeoutScaleFactor),
             pkgId,
             packages,
             partyNameMangler,
@@ -84,7 +89,7 @@ object LedgerApiTestTool {
               val _ = try {
                 Await.result(
                   tester.testScenario(name),
-                  10.seconds
+                  (60 * config.timeoutScaleFactor).seconds
                 )
               } catch {
                 case (t: Throwable) =>