TL; DR
Вызов println в первом статическом блоке инициализирует около 30k + объектов, связанных с Groovy Development Kit.Для завершения может потребоваться как минимум 50 мс, в зависимости от мощности ноутбука, на котором мы проводим этот тест.
Подробности
Я не смог воспроизвести задержку на уровне сотен миллисекунд, но мне удалось получить задержку от 30 до 80 миллисекунд.Давайте начнем с класса, который я использовал в своих локальных тестах, который воспроизводит ваш вариант использования.
import spock.lang.Shared
import spock.lang.Specification
class EntryFacadeSpec extends Specification {
static {
println("${System.currentTimeMillis()} - start")
}
@Shared
def o = new Object()
static {
println("${System.currentTimeMillis()} - object")
}
@Shared
private salesEntries = new InMemorySalesEntryRepository()
static {
println("${System.currentTimeMillis()} - sales")
}
@Shared
private purchaseEntries = new InMemoryPurchaseEntryRepository()
static {
println("${System.currentTimeMillis()} - purchase")
}
def "test 1"() {
setup:
System.out.println(String.format('%d - test 1', System.currentTimeMillis()))
when:
def a = 1
then:
a == 1
}
def "test 2"() {
setup:
System.out.println(String.format('%d - test 2', System.currentTimeMillis()))
when:
def a = 2
then:
a == 2
}
static class InMemorySalesEntryRepository {}
static class InMemoryPurchaseEntryRepository {}
}
Теперь, когда я запускаю его, я вижу что-то подобное в консоли.
1542819186960 - start
1542819187019 - object
1542819187019 - sales
1542819187019 - purchase
1542819187035 - test 1
1542819187058 - test 2
Мы видим отставание в 59 миллисекунд между двумя первыми статическими блоками.Не имеет значения, что находится между этими двумя блоками, потому что Groovy-компилятор объединяет все эти 4 статических блока в один статический блок, который выглядит следующим образом в простой Java:
static {
$getCallSiteArray()[0].callStatic(EntryFacadeSpec.class, new GStringImpl(new Object[]{$getCallSiteArray()[1].call(System.class)}, new String[]{"", " - start"}));
$getCallSiteArray()[2].callStatic(EntryFacadeSpec.class, new GStringImpl(new Object[]{$getCallSiteArray()[3].call(System.class)}, new String[]{"", " - object"}));
$getCallSiteArray()[4].callStatic(EntryFacadeSpec.class, new GStringImpl(new Object[]{$getCallSiteArray()[5].call(System.class)}, new String[]{"", " - sales"}));
$getCallSiteArray()[6].callStatic(EntryFacadeSpec.class, new GStringImpl(new Object[]{$getCallSiteArray()[7].call(System.class)}, new String[]{"", " - purchase"}));
}
Таким образом, задержка в 59 миллисекунд происходит междудве первые строчкиДавайте поместим точку останова в первую строку и запустим отладчик.
Давайте перешагнем эту строку к следующей строке и посмотрим, что произойдет:
Мы видим, что при вызове Groovy println("${System.currentTimeMillis()} - start") было создано более 30 тыс. Объектов в JVM.Теперь давайте перейдем от второй строки к третьей, чтобы увидеть, что происходит:
Было создано только несколько объектов.
В этом примере показано, что добавление
static {
println(System.currentTimeMillis())
}
добавляет случайную сложность в настройку теста и не показывает, что существует задержка между инициализацией двух методов класса, но создает эту задержку.Однако, стоимость инициализации всех связанных с Groovy объектов - это то, чего мы не можем полностью избежать, и это нужно где-то оплатить.Например, если мы упростим тест до чего-то вроде этого:
import spock.lang.Specification
class EntryFacadeSpec extends Specification {
def "test 1"() {
setup:
println "asd ${System.currentTimeMillis()}"
println "asd ${System.currentTimeMillis()}"
when:
def a = 1
then:
a == 1
}
def "test 2"() {
setup:
System.out.println(String.format('%d - test 2', System.currentTimeMillis()))
when:
def a = 2
then:
a == 2
}
}
и мы установим точку останова в первом операторе println и перейдем к следующему, мы увидим что-то вроде этого:
Это все еще создает несколько тысяч объектов, но это намного меньше, чем в первом примере, потому что большинство объектов мы видели в первом примеребыли созданы еще до того, как Спок выполнил первый метод.
Разгон Производительность теста Спока
Первое, что мы можем сделать, - это использовать статическую компиляцию.В случае моего простого теста это сократило время выполнения с 300 мс (нестатическая компиляция) примерно до 227 мс.Также значительно уменьшено количество объектов, которые нужно инициализировать.Если я запускаю тот же сценарий отладчика, что и последний, показанный выше, с добавлением @CompileStatic, я получу что-то вроде этого:
Это все ещедовольно важно, но мы видим, что количество объектов, инициализированных для вызова метода println, было отброшено.
И последнее, что стоит упомянуть.Когда мы используем статическую компиляцию и хотим избежать вызова методов Groovy в статическом блоке класса для печати некоторого вывода, мы можем использовать комбинацию:
System.out.println(String.format("...", args))
, потому что Groovy выполняет именно это.С другой стороны, следующий код в Groovy:
System.out.printf("...", args)
может выглядеть аналогично предыдущему, но он скомпилируется примерно так (с включенной статической компиляцией):
DefaultGroovyMethods.printf(System.out, "...", args)
Второй случай будет намного медленнее при использовании в статическом блоке класса, потому что в этот момент Groovy jar еще не загружен и загрузчик классов должен разрешить DefaultGroovyMethods класс из файла JAR.Когда Спок выполняет метод теста, это не имеет большого значения, если вы используете System.out.println или DefaultGroovyMethods.printf, потому что классы Groovy уже загружены.
Вот почему, если мы переписаем ваш первоначальный пример примерно так:
import groovy.transform.CompileStatic
import spock.lang.Shared
import spock.lang.Specification
@CompileStatic
class EntryFacadeSpec extends Specification {
static {
System.out.println(String.format('%d - start', System.currentTimeMillis()))
}
@Shared
def o = new Object()
static {
System.out.println(String.format('%d - object', System.currentTimeMillis()))
}
@Shared
private salesEntries = new InMemorySalesEntryRepository()
static {
System.out.println(String.format('%d - sales', System.currentTimeMillis()))
}
@Shared
private purchaseEntries = new InMemoryPurchaseEntryRepository()
static {
System.out.println(String.format('%d - purchase', System.currentTimeMillis()))
}
def "test 1"() {
setup:
System.out.println(String.format('%d - test 1', System.currentTimeMillis()))
when:
def a = 1
then:
a == 1
}
def "test 2"() {
setup:
System.out.println(String.format('%d - test 2', System.currentTimeMillis()))
when:
def a = 2
then:
a == 2
}
static class InMemorySalesEntryRepository {}
static class InMemoryPurchaseEntryRepository {}
}
мы получим следующий вывод консоли:
1542821438552 - start
1542821438552 - object
1542821438552 - sales
1542821438552 - purchase
1542821438774 - test 1
1542821438786 - test 2
Но что более важно, он не регистрирует время инициализации поля, потому что Groovy компилирует эти 4 блока в одинкак это:
static {
System.out.println(String.format("%d - start", System.currentTimeMillis()));
Object var10000 = null;
System.out.println(String.format("%d - object", System.currentTimeMillis()));
var10000 = null;
System.out.println(String.format("%d - sales", System.currentTimeMillis()));
var10000 = null;
System.out.println(String.format("%d - purchase", System.currentTimeMillis()));
var10000 = null;
}
Между 1-м и 2-м вызовом нет лага, потому что в этот момент нет необходимости загружать классы Groovy.