Модульное тестирование spock утверждает вызовы журнала и видит результат

Я использую spock для тестирования кода загрузки Java Spring. Он получает регистратор логбека поверх аннотации lombok @ Slf4j.

Манекен класс с вызовом журнала

import lombok.extern.slf4j.Slf4j;
import org.springframework.stereotype.Component;

@Slf4j
@Component
public class Clazz {

  public void method() {
    // ... code
    log.warn("message", new RuntimeException());
  }
}

Спок Спек

import groovy.util.logging.Slf4j
import org.junit.Rule
import org.slf4j.Logger
import spock.lang.Specification

@Slf4j
class LogSpec extends Specification {

  Clazz clazz = new Clazz()

  private Logger logger = Mock(Logger.class)

  @Rule
  ReplaceSlf4jLogger replaceSlf4jLogger = new ReplaceSlf4jLogger(Clazz, logger)

  def "warning ia logged"() {

    given: "expected message"

    when: "when calling the method"
    clazz.method()

    then: "a warning is logged"
    1 * logger.warn(_, _) >> {
      msg, ex -> log.warn(msg, ex)
    }
  }
}

Помощник для переключения реального с фиктивным регистратором, взятым из этот ответ.

import org.junit.rules.ExternalResource
import org.slf4j.Logger

import java.lang.reflect.Field
import java.lang.reflect.Modifier

/**
 *  Helper to exchange loggers set by lombok with mock logger
 *
 * allows to assert log action.
 *
 * Undos change after test to keep normal logging in other tests.
 *
 * code from this  <a href="https://stackoverflow.com/a/25031713/3573038">answer</a> answer
 */
class ReplaceSlf4jLogger extends ExternalResource {
  Field logField
  Logger logger
  Logger originalLogger

  ReplaceSlf4jLogger(Class logClass, Logger logger) {
    logField = logClass.getDeclaredField("log")
    this.logger = logger
  }

  @Override
  protected void before() throws Throwable {
    logField.accessible = true

    Field modifiersField = Field.getDeclaredField("modifiers")
    modifiersField.accessible = true
    modifiersField.setInt(logField, logField.getModifiers() & ~Modifier.FINAL)

    originalLogger = (Logger) logField.get(null)
    logField.set(null, logger)
  }

  @Override
  protected void after() {
    logField.set(null, originalLogger)
  }
}

Я хотел бы протестировать вызовы журнала, но по-прежнему вижу сообщение журнала.

Я использую решение от этот ответ, оно работает для утверждения, но я не вижу журнала, потому что это фиктивный вызов.

Я придумал это решение, которое выполняет вызов с регистратором groovy spec.

 1 * logger.warn(_ , _) >> {
   msg, ex -> log.warn(msg, ex)
 }

Но я нахожу это многословным, любая идея, как я могу создать для него вспомогательную функцию. Я не очень хорошо знаком с функциональным Groovy, и перенос этого кода в функцию не работает.

Я также пробовал Spy вместо Mock, но это вызывает у меня ошибку, потому что класс регистратора является окончательным.

  import ch.qos.logback.classic.Logger  

  private Logger logger = Spy(Logger.class)

>> org.spockframework.mock.CannotCreateMockException: Cannot create mock 
for class ch.qos.logback.classic.Logger because Java mocks cannot mock final classes. 
If the code under test is written in Groovy, use a Groovy mock.

Класс регистратора во время выполнения

package ch.qos.logback.classic;

public final class Logger implements org.slf4j.Logger, LocationAwareLogger, AppenderAttachable<ILoggingEvent>, Serializable {

Спасибо

Поделитесь MCVE, пожалуйста. «Я делаю что-то похожее на другого парня, но он не делает того, что я ожидал» вряд ли можно назвать вопросом, на который можно дать ответ. Мне нравится видеть вашу спецификацию Spock, а также тестируемый код, чтобы иметь возможность воспроизвести и понять вашу проблему. Если вы просите слишком многого, решите проблему в одиночку.

kriegaex 15.04.2018 05:19

Я добавил MCVE.

mhuelfen 16.04.2018 09:40

Нет, это не так.

kriegaex 16.04.2018 11:52

Извините, я пропустил часть о спецификации. Я добавил теперь рабочую спецификацию, фиктивный класс и помощник.

mhuelfen 16.04.2018 20:31
3
4
3 959
2
Перейти к ответу Данный вопрос помечен как решенный

Ответы 2

Ответ принят как подходящий

На самом деле в вашем MCVE вы ожидаете, что метод warn(_, _) будет вызываться с двумя параметрами, но вы не ведете такой журнал в Clazz, поэтому вам нужно либо изменить Clazz, чтобы также регистрировать исключение, либо изменить тест, чтобы ожидать вызова метода с одним параметром . Я делаю здесь последнее.

Что касается вашей проблемы, решение состоит в том, чтобы использовать не макет, а шпиона. Однако вам нужно сказать Споку, за каким именно классом вы хотите шпионить. Это потому, что вы, конечно, не можете следить за типом интерфейса. Я выбрал SimpleLogger (замените все, что вы используете в своем приложении).

package de.scrum_master.stackoverflow

import groovy.util.logging.Slf4j
import org.junit.Rule
import org.slf4j.impl.SimpleLogger
import spock.lang.Specification

@Slf4j
class LombokSlf4jLogTest extends Specification {
  SimpleLogger logger = Spy(constructorArgs: ["LombokSlf4jLogTest"])

  @Rule
  ReplaceSlf4jLogger replaceSlf4jLogger = new ReplaceSlf4jLogger(Clazz, logger)

  def "warning is logged"() {
    when: "when calling the method"
    new Clazz().method()

    then: "a warning is logged"
    1 * logger.warn(_)
  }
}

Обновлять: Как бы то ни было, вот версия, которая также работает с LogBack-Classic вместо Log4J-Simple в пути к классам. Вместо того, чтобы напрямую шпионить за последним классом, давайте просто шпионим за Groovy @Delegate:

Также обратите внимание, что я перешел на *_ в тесте, чтобы приспособиться к вызовам warn с произвольным количеством аргументов.

package de.scrum_master.stackoverflow

import groovy.util.logging.Slf4j
import org.junit.Rule
import org.slf4j.Logger
import spock.lang.Specification

@Slf4j
class LombokSlf4jLogTest extends Specification {
  def logger = Spy(new LoggerDelegate(originalLogger: log))

  @Rule
  ReplaceSlf4jLogger replaceSlf4jLogger = new ReplaceSlf4jLogger(Clazz, logger)

  def "warning is logged"() {
    when: "when calling the method"
    new Clazz().method()

    then: "a warning is logged"
    1 * logger.warn(*_)
    true
  }

  static class LoggerDelegate {
    @Delegate Logger originalLogger
  }
}

Обновление 2020-01-23: Я только что нашел это снова и заметил, что забыл объяснить, почему решение @Delegate работает: потому что делегат Groovy автоматически реализует все интерфейсы, которые класс экземпляра делегата также реализует по умолчанию. В этом случае поле регистратора объявлено как Logger, которое является типом интерфейса. Вот почему, например, Экземпляры Log4J или Logback могут использоваться в зависимости от конфигурации. Уловка издевательства или слежки за типом окончательного класса, не реализующим интерфейс или используемым явно с его именем класса, не сработает в этом случае, потому что делегирующий класс не будет (и не может) быть подклассом последнего типа класса и, следовательно, может не вводиться вместо делегата.


Обновление 2020-04-14: Я не упоминал ранее, что если вы не хотите шпионить за реальным регистратором, а просто используете манекен, на котором вы можете проверять взаимодействия, просто используйте обычный макет Spock на интерфейсе org.slf4j.Logger: def logger = Mock(Logger) Это на самом деле самое простое решение, и вы не загромождайте свой тестовый журнал трассировками стека исключений и другими выводами журнала. Я был настолько сосредоточен на том, чтобы помочь ОП с его шпионским решением, что не упомянул об этом раньше.

Я пробовал шпионский подход, но я использую последний класс Logger во время выполнения, см. Конец моего вопроса. Поэтому, если я использую другой класс Logger в качестве шпиона в тесте, результат может отличаться. Вот почему у меня возникла идея создать вспомогательную функцию, которая утверждает вызов журнала и снова регистрирует его.

mhuelfen 17.04.2018 09:42

Я использовал ваш код, нигде нет окончательного регистратора Logback, только регистратора Log4J. Вы упоминаете об этом только в небольшом отрывке, не имеющем отношения к MCVE. Кажется, MCVE на самом деле не один. Итак, если вы не сделаете проблему воспроизводимой для меня, как я могу вам помочь? Я не люблю тратить время зря. Мое решение работает с вашим кодом! Так что, если ваш код отличается, проблема в вашем вопросе, а не в моем ответе. P.S .: Вы редактировали свой код после Я ответил.

kriegaex 17.04.2018 11:01

Еще один момент: если результат будет отличаться, это не имеет значения для вашего теста. Важно то, что метод регистратора вызывается с ожидаемым параметром (параметрами), и это вы можете протестировать с помощью моего подхода. Кроме того, и LogBack Classic, и Slf5J-Simple реализуют один и тот же интерфейс, поэтому они заменяют друг друга. И ваше собственное решение также напрямую издевается над интерфейсом, оно также не вводит экземпляр LogBack-Classic в Clazz.

kriegaex 17.04.2018 11:42
Обновлять: См. Мой второй пример теста, если вы хотите знать, как использовать Spock Spy на Groovy @Delegate вместо прямого слежения за последним классом. Надеюсь, теперь ты счастлив.
kriegaex 17.04.2018 12:00

Спасибо за ваши усилия. У меня это работает, и я действительно счастлив!

mhuelfen 17.04.2018 12:57
Обновление 2: Обратите внимание на мое (очень запоздалое) объяснение того, почему решение @Delegate работает и при каких обстоятельствах оно не будет работать. Я хочу, чтобы этот ответ был максимально полезным для будущих читателей.
kriegaex 23.01.2020 12:16

Отличный ответ, спасибо. Особенно интересует часть @Delegate, милая

davidfrancis 31.03.2020 19:06
Обновление 3: Я также упомянул, как просто использовать макет интерфейса регистратора вместо шпиона, если вам не нужен тест для ведения реального журнала, а просто нужно проверить, что регистратор был вызван должным образом.
kriegaex 14.04.2020 05:41

Это еще один «творческий» подход к такого рода вопросам, которым я хотел бы поделиться.

Вместо того, чтобы издеваться над регистратором, вы можете создать «искусственный» аппендер, программно добавить его к регистратору в тестируемом классе.

Приложение будет отслеживать зарегистрированные сообщения, и на этапе проверки вы получите это зарегистрированное сообщение и подтвердите

В итоге вы получите что-то вроде этого (псевдокод, чтобы показать идею):


class MsgTrackingAppender implements Appender { // Appender of your logging system
   private List<LogEvent> events = new ArrayList<>();

   public void doAppend(LogEvent evt) {
       events.add(evt);
   }

   public List<LogEvent> getEvents() {
       return events;
   }
}

// now in test you can do:
class LogSpec extends Specification {

   def "test me"() {
     given:
       Clazz underTest = Clazz()
       MsgTrackingAppender appender = new MsgTrackingAppender()
       LogFactory.getLogger(Clazz.class).addAppender(appender)
     when:
       underTest.method()
     then:
       appender.events.size == 1
       appender.events[0].level == Level.WARN
       appender.events[0].message == ... // verify whatever you want on the messages       
   }
}

ИМО, этот подход проще в использовании, чем обширное издевательство, но это, конечно, дело вкуса.

Я просто заметил этот ответ, потому что у меня была активность. Мне нравятся творческие подходы, особенно если они чистые. Вы в основном создаете свой собственный тестовый двойник (технически то, что в Spock будет называться заглушкой) и вводите его как зависимость (или как соавтор, выберите термин) в регистратор. Хотя я по-прежнему предпочитаю "имитировать" зависимости как можно более "ровно", ваша зависимость идет на один уровень глубже, используя реальный регистратор (который также требует остальной инфраструктуры регистрации), внедряя свой "диагностический аппендер". Действительно, очень мило.

kriegaex 01.04.2020 05:46

Другие вопросы по теме