Spock 与 DbUnit 测试用例缓慢

Spock with DbUnit test cases slowness

我们已经实施 Spock + Db 单元 框架作为自动化单元测试的一部分。

我们现在有 2000 个测试用例(特性),用于 150 个带有 DbUnit 的规范

在这里,我们在数据库中添加所需的条目,然后测试每个方法的行为。

我们观察到执行这些测试用例大约需要 2 小时 30 分钟。

我已经为 setup 夹具添加了时间戳,并在特征方法中添加了时间戳。以下是我的观察:

allergy.dao.AllergyFormDAOSpec > Get Allergy Form STANDARD_OUT
    setup method execution started at : Fri Jan 12 19:00:42 IST 2018

allergy.dao.AllergyFormDAOSpec > API to get Allergy Form STANDARD_OUT
Feature method execution started at : Fri Jan 12 19:00:44 IST 2018
Feature method execution ended at: Fri Jan 12 19:00:45 IST 2018
Total time taken to run the one test case: 242

cleanup method execution started at : Fri Jan 12 19:00:45 IST 2018
Total time taken to run a feature method : 2531

在这里,我观察到在设置后加载特征方法平均需要 2-4 秒。但是,原始测试用例的执行时间不到一秒。

我想知道我是否可以获得关于此处可能延迟的内容的指示?因为,2000 个测试用例的 3 秒意味着 Spock 花费了将近 1 小时 30 分钟的时间,而不是真正的功能执行。

总而言之,我们希望减少每天 运行 Spock 测试用例所花费的总时间。

规格

package allergy.dao

import java.util.Date

import org.dbunit.IDatabaseTester;
import org.dbunit.ext.mssql.InsertIdentityOperation;

import allergy.AllergyForm;
import be.janbols.spock.extension.dbunit.DbUnit;
import spock.lang.Shared
import util.MasterSpec

class AllergyFormDAOSpec extends MasterSpec {
    def dao = new AllergyFormDAO();
    @Shared Date timeStart1
    @Shared Date timeEnd1

@DbUnit(configure={ IDatabaseTester it ->
    it.setUpOperation = InsertIdentityOperation.REFRESH
    it.tearDownOperation = InsertIdentityOperation.DELETE
})
def content =  {
    allergy_form(formId:99999,formName:'DummySpockForm',displayIndex:1,deleteFlag:0,is_biological:1)
    allergy_form_facilities(id:99999,formId:99999,facilityid:2)
    form_concentration(id:99999,formId:99999,name:'1:100',deleteflag:0,displayindex:1)
}

def setup(){
    timeStart1 = new Date()
    println "setup method execution started at : " +  timeStart1
}

def "API to test delete Form facility"(){
    def startTime = new Date()
    println "Feature method execution started at : " +  startTime
    given:"form Id is given"
        def formId = 99999
    when:"delete form facilities"
        def result =dao.deleteFormFacilities(null, formId)
    then:"validate result"
        (result>0)==true
        def endTime = new Date()
        println "Feature method execution ended at: " +  endTime
        println 'Total time taken to run the one test case: '+ (endTime.getTime() - startTime.getTime())
}

def cleanup() {
    timeEnd1 = new Date()
    println "cleanup method execution started at : " +  timeEnd1

    def difference = timeEnd1.time - timeStart1.time
    println "Total time taken to run a fixture method : " + difference
}
}

MasterSpec

package util

import com.ecw.dao.SqlTranslator
import catalog.Root
import spock.lang.Shared
import spock.lang.Specification

import javax.sql.DataSource

/**

 */
class MasterSpec extends Specification {

@Shared
Properties properties = new Properties()
@Shared
public DataSource dataSource
@Shared
protected xmlDataSource = [:]

static int timeCntr = 0;

//setup is to read xml file's content in xmlDataSource Hashmap
def setup(){

    //Get Running Class name without its package
    def className = this.class.name.substring(this.class.name.lastIndexOf('.') + 1)
    def resourceAnno = specificationContext.currentFeature.featureMethod.getAnnotation(FileResource)

    if(resourceAnno != null){
        def files = resourceAnno.xmlFiles()
        def packageName = (this.class.package.name).replaceAll('\.','/')

        for(int i=0;i< files.length;i++){
            def f = new File("src/test/resources/"+packageName+"/"+className+"/"+files[i])
            def engine = new groovy.text.GStringTemplateEngine()
            def template = engine.createTemplate(f).make(null)
            def xmlString = template.toString()

            //load the hashmap with file name as Key and its content in form of string as Value
            xmlDataSource.put(files[i].split("\.")[0],xmlString)
        }
    }
}

def setupSpec() {
    Date timeStart = new Date()

    File propertiesFile = new File('src/test/webapps/myApp/conf/connection.properties').withInputStream {
        properties.load it
    }

    String strDBName = getPropertyValue("myApp.DBName")
    if(strDBName.indexOf('?') > -1){
        strDBName = strDBName.substring(0, strDBName.indexOf('?'))
    }
    String strServerName = getPropertyValue("myApp.DBHost");
    if(strServerName.indexOf(':') > -1){
        strServerName = strServerName.substring(0, strServerName.indexOf(':'))
    }
    String strUrl = getPropertyValue("myApp.DBUrl")
    String strPort = strUrl.substring(strUrl.lastIndexOf(':') + 1)

    //FOR MSSQL
    System.setProperty("myApp.SkipJndi", "yes")
    //dataSource = new JtdsDataSource()
    Object newObject = null;
    if(SqlTranslator.isDbSqlServer()){
        newObject = Class.forName("net.sourceforge.jtds.jdbcx.JtdsDataSource").newInstance()
    } else if(SqlTranslator.isDbMySql()){
        newObject = Class.forName("com.mysql.jdbc.jdbc2.optional.MysqlDataSource").newInstance()
    }

    dataSource = (DataSource)newObject
    dataSource.setDatabaseName(strDBName)
    dataSource.setUser(getPropertyValue("myApp.DBUser"))
    dataSource.setPassword(getPropertyValue("myApp.DBPassword"))
    dataSource.setServerName(strServerName)
    dataSource.setPortNumber(Integer.parseInt(strPort))

}
}

这个问题确实太宽泛了,没有提供足够的信息来给出一个合格的答案。但是,我可以说 Spock 本身应该非常快(不如 'raw' JUnit 快,毕竟它仍然是 groovy,但对于测试来说已经足够快了)。

从你的问题来看,你似乎怀疑 Spock 是一个瓶颈,所以, 例如,您可以在启用 DbUnit 的测试旁边放置一个空的 Spock 测试并测量其执行情况,我可以向您保证,您获得的时间可以忽略不计。

所以我认为原因是在 setup/cleanup 期间,DbUnit 调用了一些与数据库相关的代码(可能是架构 generation/tables 人口 and/or 删除)并且需要花费很多时间.因此,我的第二次尝试只是在测试期间打印 运行 的 SQL 查询,您可能会在设置方法期间显示其中许多 运行。

另一个可能的原因是为了进行测试,在测试之前插入了太多数据。

另一个可能的原因是您运行测试的数据库太慢(网络慢,数据库本身太忙)。

现在有什么解决方案? :) 您可能想看看 Spring 测试数据访问层的方法 + 如何进行初始设置。由于远远超出了问题的范围,spring这里就不多说了,仅供参考:

  • 生成一次数据
  • 在所有测试之前插入它 运行
  • 随着测试的开始开始交易
  • 测试完成后回滚事务(即使测试成功),这样数据就不会被保留。如果您使用 Isolation 并且数据库服务器支持它,您甚至可以 运行 并行测试,没问题。

如果缓慢的原因是数据库服务器,那么(除了 "change your RDBMS" 等明显的建议之外)您可以尝试 运行 docker 中的数据库 [=40] =] 甚至在你的测试在本地开始之前启动一个数据库 TestContainers.

答案实际上很简单:您忘记测量主规格的设置时间。也许您假设子规范中的 setup() 方法覆盖了其父规范的 setup() 方法。但在 Spock 中却没有!全部

  • setupSpec()
  • setup()
  • cleanup()
  • cleanupSpec()

class 层次结构中的所有规范将按以下顺序执行:首先是基础 class,然后是子 class。

让我用一个简单的例子来告诉你我在说什么:

主要规格:

为什么是线程局部静态变量?好吧,也许您正在 运行 同时进行测试。对于这个简单的例子,没有必要。

package de.scrum_master.Whosebug

import spock.lang.Specification
import static System.currentTimeMillis

class MasterSpec extends Specification {
  static ThreadLocal<Long> startMillis = new ThreadLocal<>()

  def setupSpec() {
    startMillis.set(currentTimeMillis())
    sleep 50
    println "BaseSpec.setupSpec: " + (currentTimeMillis() - startMillis.get())
  }

  def cleanupSpec() {
    sleep 50
    println "BaseSpec.cleanupSpec: " + (currentTimeMillis() - startMillis.get())
  }

  def setup() {
    sleep 50
    println "BaseSpec.setup: " + (currentTimeMillis() - startMillis.get())
  }

  def cleanup() {
    sleep 50
    println "BaseSpec.cleanup: " + (currentTimeMillis() - startMillis.get())
  }
}

派生规范:

为什么叫 DerivedTest?只是因为我的 Maven 构建配置为根据默认名称 *Test(Surefire 单元测试)或 *IT(故障安全集成测试)查找测试。

package de.scrum_master.Whosebug

import spock.lang.Unroll

import static java.lang.System.currentTimeMillis

class DerivedTest extends MasterSpec {
  def setupSpec() {
    sleep 50
    println "DerivedTest.setupSpec: " + (currentTimeMillis() - startMillis.get())
  }

  def cleanupSpec() {
    sleep 50
    println "DerivedTest.cleanupSpec: " + (currentTimeMillis() - startMillis.get())
  }

  def setup() {
    sleep 50
    println "DerivedTest.setup: " + (currentTimeMillis() - startMillis.get())
  }

  def cleanup() {
    sleep 50
    println "DerivedTest.cleanup: " + (currentTimeMillis() - startMillis.get())
  }

  @Unroll
  def "feature #id"() {
    given:
    long featureStartMillis = currentTimeMillis()
    sleep 50
    println "DerivedTest.feature $id: " + (currentTimeMillis() - startMillis.get())

    expect:
    true

    cleanup:
    println "DerivedTest.feature $id ONLY: " + (currentTimeMillis() - featureStartMillis)

    where:
    id << ["A", "B"]
  }
}

控制台日志:

BaseSpec.setupSpec: 105
DerivedTest.setupSpec: 193
BaseSpec.setup: 286
DerivedTest.setup: 336
DerivedTest.feature A: 396
DerivedTest.feature A ONLY: 55
DerivedTest.cleanup: 453
BaseSpec.cleanup: 504
BaseSpec.setup: 556
DerivedTest.setup: 606
DerivedTest.feature B: 656
DerivedTest.feature B ONLY: 50
DerivedTest.cleanup: 706
BaseSpec.cleanup: 757
DerivedTest.cleanupSpec: 808
BaseSpec.cleanupSpec: 858

你能看出执行顺序和每一步消耗的时间吗?

我会说,您在 master spec 中的复杂操作(读取配置文件、初始化和填充数据库等)

为了分析这个问题的根本原因,我们已经 运行 执行了以下场景的任务:

1) 1000 个没有任何 Db 或模拟依赖项的 Spock 测试用例 (PowerMock)

解释场景的示例代码:

package mathOperations;

import groovy.lang.Closure
import mathOperations.Math
import spock.lang.Specification

class MathSpec extends Specification {
    def objMath =new Math()

    def "API to test addition of two numbers"() {
        given :"a and b"
            def a=10
            def b=5
        when: "Math.AddNumber is called with given values"
            def result =objMath.addNumber(a,b)
        then: "Result should be 15"
            result==15
    }

    def "API to test subrtaction of two numbers"() {
        given :"a and b"
            def a=10
            def b=5
        when: "Math.subtractNumber is called with given values"
            def result =objMath.subtractNumber(a, b)
        then: "Result should be 5"
            result==5
    }

    def "API to test multiplication of two numbers"() {
        given :"a and b"
            def a=10
            def b=5
        when: "Math.multiplyNumber is called with given values"
            def result =objMath.multiplyNumber(a,b)
        then: "Result should be 50"
            result==50
    }
    def "API to test division two numbers"() {
        given :"a and b"
            def a=10
            def b=5
        when: "Math.divisionNumber is called with given values"
            def result =objMath.divisionNumber(a,b)
        then: "Result should be 2"
            result==2
    }

    def "API to test whether given both numbers are equal - Affirmative"() {
        given :"a and b"
            def a=10
            def b=10
        when: "Math.equalNumber is called with given values"
            def result =objMath.equalNumber(a,b)
        then: "It should return true"
            result==true
    }

    def "API to test whether given both numbers are equal - Negative"() {
        given :"a and b"
            def a=10
            def b=11
        when: "Math.equalNumber is called with given values"
            def result =objMath.equalNumber(a,b)
        then: "It should return false"
            result==false
    }
}

--> 花费了 25.153 秒,包括构建时间,下面是下面的报告

2) 1000 个带模拟的 Spock 测试用例 (PowerMock)

解释场景的示例代码:

package mathOperations;

import groovy.lang.Closure
import mathOperations.Math
import spock.lang.Specification
import org.powermock.core.classloader.annotations.PrepareForTest
import org.powermock.modules.junit4.rule.PowerMockRule
import org.junit.Rule
import utils.QRCodeUtils
import org.powermock.api.mockito.PowerMockito
import static org.powermock.api.mockito.PowerMockito.mockStatic
import static org.mockito.BDDMockito.*

@PrepareForTest([QRCodeUtils.class])
class MathSpec extends Specification {
    def objMath =new Math()

    @Rule PowerMockRule powerMockRule = new PowerMockRule()

    def "API to test add two numbers"() {
        given :"a and b"
        def a=10
        def b=5
        when: "Math.AddNumber is call with given values"
        mockGetOTPAttemptStatus(5)
        def result =objMath.addNumber(a,b)
        then: "result should be 15"
        result==15
    }

    def "API to test subract two numbers"() {
        given :"a and b"
        def a=10
        def b=5
        when: "Math.subtractNumber is call with given values"
        mockGetOTPAttemptStatus(5)
        def result =objMath.subtractNumber(a, b)
        then: "result should be 5"
        result==5
    }
    def "API to test multiple two numbers"() {
        given :"a and b"
        def a=10
        def b=5
        when: "Math.multiplyNumber is call with given values"
        mockGetOTPAttemptStatus(5)
        def result =objMath.multiplyNumber(a,b)
        then: "result should be 50"
        result==50
    }
    def "API to test divide two numbers"() {
        given :"a and b"
        def a=10
        def b=5
        when: "Math.divisionNumber is call with given values"
        mockGetOTPAttemptStatus(5)
        def result =objMath.divisionNumber(a,b)
        then: "result should be 2"
        result==2
    }
    def "API to test modulo of a number"() {
        given :"a and b"
        def a=10
        def b=5
        when: "Math.moduloNumber is call with given values"
        mockGetOTPAttemptStatus(5)
        def result =objMath.moduloNumber(a,b)
        then: "result should be 0"
        result==0
    }

    def "API to test power of a number"() {
        given :"a and b"
        def a=10
        def b=2
        when: "Math.powerofNumber is call with given values"
        mockGetOTPAttemptStatus(5)
        def result =objMath.powerofNumber(a,b)
        then: "result should be 0"
        result==8
    }

    def "API to test numbers are equal -affirmative"() {
        given :"a and b"
        def a=10
        def b=10
        when: "Math.equalNumber is call with given values"
        mockGetOTPAttemptStatus(5)
        def result =objMath.equalNumber(a,b)
        then: "It should return true"
        result==true
    }

    def "API to test numbers are equal -negative"() {
        given :"a and b"
        def a=10
        def b=11
        when: "Math.equalNumber is call with given values"
        mockGetOTPAttemptStatus(5)
        def result =objMath.equalNumber(a,b)
        then: "It should return false"
        result==false
    }

    void mockGetOTPAttemptStatus(int status) {
        mockStatic(QRCodeUtils.class)
        when(QRCodeUtils.getOTPAttemptStatus(anyInt())).thenReturn(status)
    }
}

--> 花了 9 分 14.222 秒,包括构建时间,下面是报告

3) 1000 个仅使用 Dbunit 的 Spock 测试用例。 (通常,我们在测试用例中平均插入 15-20 table 个条目。在这里,我们添加了相同的条目)

解释场景的示例代码:

package mathOperations;

import groovy.lang.Closure
import java.sql.Statement
import mathOperations.Math
import spock.lang.Shared
import util.BaseSpec
import catalog.Root
import spock.lang.Ignore
import org.dbunit.ext.mssql.InsertIdentityOperation
import be.janbols.spock.extension.dbunit.DbUnit
import org.dbunit.IDatabaseTester

class MathSpec extends BaseSpec {

    @Shared root
    def objMath =new Math()

    @DbUnit(configure={
        IDatabaseTester it ->
        it.setUpOperation = InsertIdentityOperation.REFRESH
        it.tearDownOperation = InsertIdentityOperation.DELETE
    })
    def content =  {
        table1(id:99,MasterFile:'UnitTestFile',DataElementName:'test',DataElementDBColName:'TestDbCol',DataElementTableName:'TestTable')
        table2(id:99,MasterFile:'UnitTestFile',DataElementName:'test',DataElementDBColName:'TestDbCol',DataElementTableName:'TestTable')
        table3(id:99,Code:'T00.0',Status:'A',LongDesc:'Unit Testing')
        table4(id:99,Code:'T00.0',Status:'A',LongDesc:'Unit Testing')
        table5(id:99,Code:'T00.0',Status:'A',LongDesc:'Unit Testing')
        table6(id:99,Code:'T00.0',Status:'A',LongDesc:'Unit Testing')
        table7(id:99,Code:'T00.0',Status:'A',LongDesc:'Unit Testing')
        table8(id:99,Code:'T00.0',Status:'A',LongDesc:'Unit Testing')
        table9(id:99,Code:'T00.0',Status:'A',LongDesc:'Unit Testing')
        table10(id:99,Code:'T00.0',Status:'A',LongDesc:'Unit Testing')
    }

    def "API to test addition of two numbers"() {
        given :"a and b"
            def a=10
            def b=5
        when: "Math.AddNumber is called with given values"
            def result =objMath.addNumber(a,b)
        then: "Result should be 15"
            result==15
    }

    def "API to test subrtaction of two numbers"() {
        given :"a and b"
            def a=10
            def b=5
        when: "Math.subtractNumber is called with given values"
            def result =objMath.subtractNumber(a, b)
        then: "Result should be 5"
            result==5
    }

    def "API to test multiplication of two numbers"() {
        given :"a and b"
            def a=10
            def b=5
        when: "Math.multiplyNumber is called with given values"
            def result =objMath.multiplyNumber(a,b)
        then: "Result should be 50"
            result==50
    }
    def "API to test division two numbers"() {
        given :"a and b"
            def a=10
            def b=5
        when: "Math.divisionNumber is called with given values"
            def result =objMath.divisionNumber(a,b)
        then: "Result should be 2"
            result==2
    }

    def "API to test whether given both numbers are equal - Affirmative"() {
        given :"a and b"
            def a=10
            def b=10
        when: "Math.equalNumber is called with given values"
            def result =objMath.equalNumber(a,b)
        then: "It should return true"
            result==true
    }

    def "API to test whether given both numbers are equal - Negative"() {
        given :"a and b"
            def a=10
            def b=11
        when: "Math.equalNumber is called with given values"
            def result =objMath.equalNumber(a,b)
        then: "It should return false"
            result==false
    }
}

--> 花了 57 分钟 18.136 秒,包括构建时间,下面是报告

我们得出的结论是,Spock 没有花时间来 运行 测试用例,但执行检测的 Power Mock SO Link 和 DbUnit(使用反射加载所有内容)是瓶颈。

解法: 我们将使用内部框架 insert/delete 数据库数据而不是 DbUnit。此外,我们已将 Power Mock 替换为 JMockit

最终结果: 正如我在问题中所做的那样 post 从 2 小时和 30 分钟 开始,一直这些 1000 个测试用例现在减少到 6 分钟。 :)