gitlabspock

How to tell if Spock is actually executing tests in parallel


We have some API integration tests that take ~30 minutes to run a test class with 19 rows in the where: table. We're trying to speed this up using Spock's (experimental) Parellel Execution feature. We are using a simple SpockConfig.groovy file:

runner {
    parallel {
        enabled true
        fixed(4)
    }
}

This still took ~30 minutes on a GitLab runner. Is there any way to log something out so we can verify that the test is running in parallel? Or am I misunderstanding the nature of Spock's parallelization?


Solution

  • You can parallelise Spock testing on several levels, i.e. per specification (test class) or per feature (test method). The per-method setting also means that in iterated (unrolled) tests, iterations can run in parallel. Here is some proof:

    import static org.spockframework.runtime.model.parallel.ExecutionMode.CONCURRENT
    
    runner {
      parallel {
        enabled true
        // These values are the default already, specifying them is redundant
        // defaultSpecificationExecutionMode = CONCURRENT
        // defaultExecutionMode = CONCURRENT
        fixed 4
      }
    }
    
    package de.scrum_master.testing
    
    import spock.lang.Specification
    
    import static java.lang.System.currentTimeMillis
    import static java.lang.Thread.currentThread
    
    class ParallelExecutionTest extends Specification {
      static long startTime = currentTimeMillis()
      static volatile int execCount = 0
    
      def "feature-A-#count"() {
        given:
        def i = ++execCount
        printf "%5d %2d [%s] >> %s%n", currentTimeMillis() - startTime, i, currentThread().name, specificationContext.currentIteration.displayName
        sleep 1000
        printf "%5d %2d [%s] << %s%n", currentTimeMillis() - startTime, i, currentThread().name, specificationContext.currentIteration.displayName
    
        where:
        count << (1..8)
      }
    
      def "feature-B-#count"() {
        given:
        def i = ++execCount
        printf "%5d %2d [%s] >> %s%n", currentTimeMillis() - startTime, i, currentThread().name, specificationContext.currentIteration.displayName
        sleep 1000
        printf "%5d %2d [%s] << %s%n", currentTimeMillis() - startTime, i, currentThread().name, specificationContext.currentIteration.displayName
    
        where:
        count << (1..8)
      }
    }
    

    The output would look something like this (I used the volatile variable in order to more easily sort the log output in my editor into groups of threads running simultaneously in groups of 4:

       68  1 [ForkJoinPool-1-worker-3] >> feature-B-1
       68  2 [ForkJoinPool-1-worker-2] >> feature-A-5
       68  3 [ForkJoinPool-1-worker-1] >> feature-B-6
       68  4 [ForkJoinPool-1-worker-4] >> feature-B-2
     1177  1 [ForkJoinPool-1-worker-3] << feature-B-1
     1177  3 [ForkJoinPool-1-worker-1] << feature-B-6
     1179  4 [ForkJoinPool-1-worker-4] << feature-B-2
     1180  2 [ForkJoinPool-1-worker-2] << feature-A-5
    
     1191  5 [ForkJoinPool-1-worker-3] >> feature-B-3
     1199  6 [ForkJoinPool-1-worker-4] >> feature-B-4
     1200  7 [ForkJoinPool-1-worker-1] >> feature-B-5
     1204  8 [ForkJoinPool-1-worker-2] >> feature-A-6
     2199  5 [ForkJoinPool-1-worker-3] << feature-B-3
     2205  7 [ForkJoinPool-1-worker-1] << feature-B-5
     2213  6 [ForkJoinPool-1-worker-4] << feature-B-4
     2213  8 [ForkJoinPool-1-worker-2] << feature-A-6
    
     2203  9 [ForkJoinPool-1-worker-3] >> feature-B-7
     2207 10 [ForkJoinPool-1-worker-1] >> feature-A-1
     2217 11 [ForkJoinPool-1-worker-4] >> feature-B-8
     2222 12 [ForkJoinPool-1-worker-2] >> feature-A-8
     3205  9 [ForkJoinPool-1-worker-3] << feature-B-7
     3213 10 [ForkJoinPool-1-worker-1] << feature-A-1
     3229 12 [ForkJoinPool-1-worker-2] << feature-A-8
     3230 11 [ForkJoinPool-1-worker-4] << feature-B-8
    
     3208 13 [ForkJoinPool-1-worker-3] >> feature-A-2
     3216 14 [ForkJoinPool-1-worker-1] >> feature-A-3
     3234 15 [ForkJoinPool-1-worker-4] >> feature-A-4
     3237 16 [ForkJoinPool-1-worker-2] >> feature-A-7
     4214 13 [ForkJoinPool-1-worker-3] << feature-A-2
     4230 14 [ForkJoinPool-1-worker-1] << feature-A-3
     4245 15 [ForkJoinPool-1-worker-4] << feature-A-4
     4245 16 [ForkJoinPool-1-worker-2] << feature-A-7
    

    As you can clearly see, with your own settings you can expect that multiple features and even multiple iterations in your spec run concurrently. If in your case the concurrent iterations take as long to finish as running the test sequentially, it could mean that those tests spend a lot of time using a shared resource which is synchronised or in some other way can only be used by one caller at the same time. So probably not Spock is the problem here, but the shared resource or the way you synchronise on it.