테스트 할 때 로그스태시 제외하기

dasd412·2022년 12월 25일
0

MSA 프로젝트

목록 보기
14/25

문제 상황

12:06:06.489 [main] DEBUG org.springframework.test.context.junit4.SpringJUnit4ClassRunner - SpringJUnit4ClassRunner constructor called with [class com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]
12:06:06.494 [main] DEBUG org.springframework.test.context.BootstrapUtils - Instantiating CacheAwareContextLoaderDelegate from class [org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate]
12:06:06.505 [main] DEBUG org.springframework.test.context.BootstrapUtils - Instantiating BootstrapContext using constructor [public org.springframework.test.context.support.DefaultBootstrapContext(java.lang.Class,org.springframework.test.context.CacheAwareContextLoaderDelegate)]
12:06:06.538 [main] DEBUG org.springframework.test.context.BootstrapUtils - Instantiating TestContextBootstrapper for test class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest] from class [org.springframework.boot.test.context.SpringBootTestContextBootstrapper]
12:06:06.560 [main] INFO org.springframework.boot.test.context.SpringBootTestContextBootstrapper - Neither @ContextConfiguration nor @ContextHierarchy found for test class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest], using SpringBootContextLoader
12:06:06.565 [main] DEBUG org.springframework.test.context.support.AbstractContextLoader - Did not detect default resource location for test class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]: class path resource [com/dasd412/api/diaryservice/adapter/in/web/DiaryPostRestControllerTest-context.xml] does not exist
12:06:06.565 [main] DEBUG org.springframework.test.context.support.AbstractContextLoader - Did not detect default resource location for test class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]: class path resource [com/dasd412/api/diaryservice/adapter/in/web/DiaryPostRestControllerTestContext.groovy] does not exist
12:06:06.566 [main] INFO org.springframework.test.context.support.AbstractContextLoader - Could not detect default resource locations for test class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]: no resource found for suffixes {-context.xml, Context.groovy}.
12:06:06.655 [main] DEBUG org.springframework.test.context.support.ActiveProfilesUtils - Could not find an 'annotation declaring class' for annotation type [org.springframework.test.context.ActiveProfiles] and class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]
12:06:06.865 [main] DEBUG org.springframework.boot.test.context.SpringBootTestContextBootstrapper - @TestExecutionListeners is not present for class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]: using defaults.
12:06:06.866 [main] INFO org.springframework.boot.test.context.SpringBootTestContextBootstrapper - Loaded default TestExecutionListener class names from location [META-INF/spring.factories]: [org.springframework.boot.test.mock.mockito.MockitoTestExecutionListener, org.springframework.boot.test.mock.mockito.ResetMocksTestExecutionListener, org.springframework.boot.test.autoconfigure.restdocs.RestDocsTestExecutionListener, org.springframework.boot.test.autoconfigure.web.client.MockRestServiceServerResetTestExecutionListener, org.springframework.boot.test.autoconfigure.web.servlet.MockMvcPrintOnlyOnFailureTestExecutionListener, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverTestExecutionListener, org.springframework.test.context.web.ServletTestExecutionListener, org.springframework.test.context.support.DirtiesContextBeforeModesTestExecutionListener, org.springframework.test.context.support.DependencyInjectionTestExecutionListener, org.springframework.test.context.support.DirtiesContextTestExecutionListener, org.springframework.test.context.transaction.TransactionalTestExecutionListener, org.springframework.test.context.jdbc.SqlScriptsTestExecutionListener, org.springframework.test.context.event.EventPublishingTestExecutionListener]
12:06:06.884 [main] INFO org.springframework.boot.test.context.SpringBootTestContextBootstrapper - Using TestExecutionListeners: [org.springframework.test.context.web.ServletTestExecutionListener@764faa6, org.springframework.test.context.support.DirtiesContextBeforeModesTestExecutionListener@4c1f22f3, org.springframework.boot.test.mock.mockito.MockitoTestExecutionListener@598bd2ba, org.springframework.boot.test.autoconfigure.SpringBootDependencyInjectionTestExecutionListener@5a755cc1, org.springframework.test.context.support.DirtiesContextTestExecutionListener@7ae42ce3, org.springframework.test.context.transaction.TransactionalTestExecutionListener@4f5991f6, org.springframework.test.context.jdbc.SqlScriptsTestExecutionListener@484094a5, org.springframework.test.context.event.EventPublishingTestExecutionListener@38234a38, org.springframework.boot.test.mock.mockito.ResetMocksTestExecutionListener@63fbfaeb, org.springframework.boot.test.autoconfigure.restdocs.RestDocsTestExecutionListener@602e0143, org.springframework.boot.test.autoconfigure.web.client.MockRestServiceServerResetTestExecutionListener@2c07545f, org.springframework.boot.test.autoconfigure.web.servlet.MockMvcPrintOnlyOnFailureTestExecutionListener@e57b96d, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverTestExecutionListener@32c726ee]
12:06:06.889 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved @ProfileValueSourceConfiguration [null] for test class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]
12:06:06.890 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved ProfileValueSource type [class org.springframework.test.annotation.SystemProfileValueSource] for class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]
12:06:06.903 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved @ProfileValueSourceConfiguration [null] for test class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]
12:06:06.903 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved ProfileValueSource type [class org.springframework.test.annotation.SystemProfileValueSource] for class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]
12:06:06.905 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved @ProfileValueSourceConfiguration [null] for test class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]
12:06:06.905 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved ProfileValueSource type [class org.springframework.test.annotation.SystemProfileValueSource] for class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]
12:06:06.905 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved @ProfileValueSourceConfiguration [null] for test class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]
12:06:06.906 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved ProfileValueSource type [class org.springframework.test.annotation.SystemProfileValueSource] for class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]
12:06:06.911 [main] DEBUG org.springframework.test.context.support.AbstractDirtiesContextTestExecutionListener - Before test class: context [DefaultTestContext@bcef303 testClass = DiaryPostRestControllerTest, testInstance = [null], testMethod = [null], testException = [null], mergedContextConfiguration = [WebMergedContextConfiguration@41709512 testClass = DiaryPostRestControllerTest, locations = '{}', classes = '{class com.dasd412.api.diaryservice.DiaryServiceApplication, class com.dasd412.api.diaryservice.DiaryServiceApplication}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{classpath:/application-test.properties}', propertySourceProperties = '{org.springframework.boot.test.context.SpringBootTestContextBootstrapper=true}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@27462a88, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@51e69659, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@451cd3fc, org.springframework.boot.test.web.client.TestRestTemplateContextCustomizer@3012646b, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@2ddc9a9f], resourceBasePath = 'src/main/webapp', contextLoader = 'org.springframework.boot.test.context.SpringBootContextLoader', parent = [null]], attributes = map['org.springframework.test.context.web.ServletTestExecutionListener.activateListener' -> true]], class annotated with @DirtiesContext [false] with mode [null].
12:06:06.913 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved @ProfileValueSourceConfiguration [null] for test class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]
12:06:06.914 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved ProfileValueSource type [class org.springframework.test.annotation.SystemProfileValueSource] for class [com.dasd412.api.diaryservice.adapter.in.web.DiaryPostRestControllerTest]
12:06:06.947 [main] DEBUG org.springframework.test.context.support.TestPropertySourceUtils - Adding inlined properties to environment: {spring.jmx.enabled=false, org.springframework.boot.test.context.SpringBootTestContextBootstrapper=true, server.port=-1}
12:06:09,867 |-WARN in net.logstash.logback.appender.LogstashTcpSocketAppender[logstash] - Log destination logstash:5000: connection failed. java.net.UnknownHostException: logstash
	at java.net.UnknownHostException: logstash
	at 	at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:229)
	at 	at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
	at 	at java.base/java.net.Socket.connect(Socket.java:615)
	at 	at net.logstash.logback.appender.AbstractLogstashTcpSocketAppender$TcpSendingEventHandler.openSocket(AbstractLogstashTcpSocketAppender.java:717)
	at 	at net.logstash.logback.appender.AbstractLogstashTcpSocketAppender$TcpSendingEventHandler.onStart(AbstractLogstashTcpSocketAppender.java:637)
	at 	at net.logstash.logback.appender.AsyncDisruptorAppender$EventClearingEventHandler.onStart(AsyncDisruptorAppender.java:351)
	at 	at net.logstash.logback.encoder.com.lmax.disruptor.BatchEventProcessor.notifyStart(BatchEventProcessor.java:224)
	at 	at net.logstash.logback.encoder.com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:120)
	at 	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at 	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at 	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at 	at java.base/java.lang.Thread.run(Thread.java:829)
12:06:09,868 |-WARN in net.logstash.logback.appender.LogstashTcpSocketAppender[logstash] - Log destination logstash:5000: Waiting 29998ms before attempting reconnection.
12:06:10,350 |-WARN in net.logstash.logback.appender.LogstashTcpSocketAppender[logstash] - Log destination logstash:5000: connection failed. java.net.UnknownHostException: logstash
	at java.net.UnknownHostException: logstash
	at 	at java.base/java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:229)
	at 	at java.base/java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
	at 	at java.base/java.net.Socket.connect(Socket.java:615)
	at 	at net.logstash.logback.appender.AbstractLogstashTcpSocketAppender$TcpSendingEventHandler.openSocket(AbstractLogstashTcpSocketAppender.java:717)
	at 	at net.logstash.logback.appender.AbstractLogstashTcpSocketAppender$TcpSendingEventHandler.onStart(AbstractLogstashTcpSocketAppender.java:637)
	at 	at net.logstash.logback.appender.AsyncDisruptorAppender$EventClearingEventHandler.onStart(AsyncDisruptorAppender.java:351)
	at 	at net.logstash.logback.encoder.com.lmax.disruptor.BatchEventProcessor.notifyStart(BatchEventProcessor.java:224)
	at 	at net.logstash.logback.encoder.com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:120)
	at 	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at 	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at 	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at 	at java.base/java.lang.Thread.run(Thread.java:829)
12:06:10,350 |-WARN in net.logstash.logback.appender.LogstashTcpSocketAppender[logstash] - Log destination logstash:5000: Waiting 29999ms before attempting reconnection.
2022-12-25 12:06:10.384  INFO [diary-service,,,] 8952 --- [           main] c.c.c.ConfigServicePropertySourceLocator : Fetching config from server at : http://configserver:8071
2022-12-25 12:06:12.764  INFO [diary-service,,,] 8952 --- [           main] c.c.c.ConfigServicePropertySourceLocator : Connect Timeout Exception on Url - http://configserver:8071. Will be trying the next url if available
2022-12-25 12:06:12.765  WARN [diary-service,,,] 8952 --- [           main] c.c.c.ConfigServicePropertySourceLocator : Could not locate PropertySource: I/O error on GET request for "http://configserver:8071/diary-service/dev": configserver; nested exception is java.net.UnknownHostException: configserver
2022-12-25 12:06:12.773  INFO [diary-service,,,] 8952 --- [           main] .d.a.d.a.i.w.DiaryPostRestControllerTest : The following profiles are active: dev
2022-12-25 12:06:13.439  INFO [diary-service,,,] 8952 --- [           main] i.g.r.utils.RxJava2OnClasspathCondition  : RxJava2 related Aspect extensions are not activated, because RxJava2 is not on the classpath.
2022-12-25 12:06:13.440  INFO [diary-service,,,] 8952 --- [           main] i.g.r.utils.ReactorOnClasspathCondition  : Reactor related Aspect extensions are not activated because Resilience4j Reactor module is not on the classpath.
2022-12-25 12:06:13.454  INFO [diary-service,,,] 8952 --- [           main] i.g.r.utils.RxJava2OnClasspathCondition  : RxJava2 related Aspect extensions are not activated, because RxJava2 is not on the classpath.
2022-12-25 12:06:13.454  INFO [diary-service,,,] 8952 --- [           main] i.g.r.utils.ReactorOnClasspathCondition  : Reactor related Aspect extensions are not activated because Resilience4j Reactor module is not on the classpath.
2022-12-25 12:06:13.480  INFO [diary-service,,,] 8952 --- [           main] i.g.r.utils.RxJava2OnClasspathCondition  : RxJava2 related Aspect extensions are not activated, because RxJava2 is not on the classpath.
2022-12-25 12:06:13.481  INFO [diary-service,,,] 8952 --- [           main] i.g.r.utils.ReactorOnClasspathCondition  : Reactor related Aspect extensions are not activated because Resilience4j Reactor module is not on the classpath.
2022-12-25 12:06:13.495  INFO [diary-service,,,] 8952 --- [           main] i.g.r.utils.RxJava2OnClasspathCondition  : RxJava2 related Aspect extensions are not activated, because RxJava2 is not on the classpath.
2022-12-25 12:06:13.496  INFO [diary-service,,,] 8952 --- [           main] i.g.r.utils.ReactorOnClasspathCondition  : Reactor related Aspect extensions are not activated because Resilience4j Reactor module is not on the classpath.
2022-12-25 12:06:13.509  INFO [diary-service,,,] 8952 --- [           main] i.g.r.utils.RxJava2OnClasspathCondition  : RxJava2 related Aspect extensions are not activated, because RxJava2 is not on the classpath.
2022-12-25 12:06:13.510  INFO [diary-service,,,] 8952 --- [           main] i.g.r.utils.ReactorOnClasspathCondition  : Reactor related Aspect extensions are not activated because Resilience4j Reactor module is not on the classpath.
2022-12-25 12:06:13.522  INFO [diary-service,,,] 8952 --- [           main] i.g.r.utils.RxJava2OnClasspathCondition  : RxJava2 related Aspect extensions are not activated, because RxJava2 is not on the classpath.
2022-12-25 12:06:13.523  INFO [diary-service,,,] 8952 --- [           main] i.g.r.utils.ReactorOnClasspathCondition  : Reactor related Aspect extensions are not activated because Resilience4j Reactor module is not on the classpath.
2022-12-25 12:06:13.790  INFO [diary-service,,,] 8952 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Bootstrapping Spring Data JPA repositories in DEFAULT mode.
2022-12-25 12:06:14.046  INFO [diary-service,,,] 8952 --- [           main] .s.d.r.c.RepositoryConfigurationDelegate : Finished Spring Data repository scanning in 246ms. Found 3 JPA repository interfaces.
2022-12-25 12:06:14.176  WARN [diary-service,,,] 8952 --- [           main] o.s.boot.actuate.endpoint.EndpointId     : Endpoint ID 'service-registry' contains invalid characters, please migrate to a valid format.
2022-12-25 12:06:14.678  INFO [diary-service,,,] 8952 --- [           main] o.s.cloud.context.scope.GenericScope     : BeanFactory id=b442dc8d-9c6b-39c4-9dd6-f81cbdb39f94
2022-12-25 12:06:15.269  INFO [diary-service,,,] 8952 --- [           main] faultConfiguringBeanFactoryPostProcessor : No bean named 'errorChannel' has been explicitly defined. Therefore, a default PublishSubscribeChannel will be created.
2022-12-25 12:06:15.274  INFO [diary-service,,,] 8952 --- [           main] faultConfiguringBeanFactoryPostProcessor : No bean named 'taskScheduler' has been explicitly defined. Therefore, a default ThreadPoolTaskScheduler will be created.
2022-12-25 12:06:15.280  INFO [diary-service,,,] 8952 --- [           main] faultConfiguringBeanFactoryPostProcessor : No bean named 'integrationHeaderChannelRegistry' has been explicitly defined. Therefore, a default DefaultHeaderChannelRegistry will be created.
2022-12-25 12:06:15.574  INFO [diary-service,,,] 8952 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration' of type [org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2022-12-25 12:06:15.672  INFO [diary-service,,,] 8952 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.integration.config.IntegrationManagementConfiguration' of type [org.springframework.integration.config.IntegrationManagementConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2022-12-25 12:06:15.708  INFO [diary-service,,,] 8952 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'integrationChannelResolver' of type [org.springframework.integration.support.channel.BeanFactoryChannelResolver] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2022-12-25 12:06:15.716  INFO [diary-service,,,] 8952 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'integrationDisposableAutoCreatedBeans' of type [org.springframework.integration.config.annotation.Disposables] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
2022-12-25 12:06:15.794  INFO [diary-service,,,] 8952 --- [           main] trationDelegate$BeanPostProcessorChecker : Bean 'org.springframework.cloud.sleuth.instrument.messaging.TraceMessagingAutoConfiguration$SleuthKafkaConfiguration' of type [org.springframework.cloud.sleuth.instrument.messaging.TraceMessagingAutoConfiguration$SleuthKafkaConfiguration] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)

단위 테스트할 때는 로그스태시 연결할 필요가 없다. 그런데 LogstashTcpSocketAppender가 5000번 포트에 접속을 시도하고 있었다.

원인

logback.xml이 다음과 같았다.
그리고 logback-test.xml은 없었다.

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/base.xml"/>
    <springProperty scope="context" name="application_name" source="spring.application.name"/>

    <appender name="logstash" class="net.logstash.logback.appender.LogstashTcpSocketAppender">
        <destination>logstash:5000</destination>
        <encoder class="net.logstash.logback.encoder.LogstashEncoder"/>
    </appender>

    <root level="INFO">
        <appender-ref ref="logstash"/>
        <appender-ref ref="CONSOLE"/>
    </root>

    <logger name="org.springframework" level="INFO"/>
    <logger name="com.dasd412" level="DEBUG"/>
</configuration>

이유는 프로파일과 관련있다. test 프로파일 시에 logback-test.xml이 있다면 해당 xml을 읽겠지만, 없으므로 위 logback.xml을 읽어들인다.

해결 방법

logback-test.xml을 만든 후, 다음과 같이 작성한다.

<configuration />

아무런 설정이 없으므로 연결 시도도 하지 않을 것이다.

결과

테스트를 실행하니 로그 스태시와의 연결을 시도하는 로그가 사라졌다.

참고

https://mkyong.com/logging/logback-disable-logging-in-unit-test/

profile
아키텍쳐 설계와 테스트 코드에 관심이 많음.

0개의 댓글