[Spring log4j] EFS에 error 로그 기록 시 AppenderLoggingException 처리

ㅁ 개요

 ㅇ 시스템 로그 점검 시 로그 저장 시 파일 시스템에 문제가 발생하였다.

 

 

ㅁ 에러 내용

2022-12-07 10:16:20,753 I/O dispatcher 435 ERROR An exception occurred processing Appender error_file org.apache.logging.log4j.core.appender.AppenderLoggingException: Error writing to stream efs/logs/ts/error/gw-ts.log
    at org.apache.logging.log4j.core.Logger.log(Logger.java:161)
    at org.springframework.util.concurrent.ListenableFutureAdapter$1.onSuccess(ListenableFutureAdapter.java:64)
    at org.apache.http.concurrent.BasicFuture.completed(BasicFuture.java:122)
    at org.apache.http.impl.nio.client.DefaultClientExchangeHandlerImpl.responseCompleted(DefaultClientExchangeHandlerImpl.java:181)
    at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.processResponse(HttpAsyncRequestExecutor.java:448)
    at org.apache.http.nio.protocol.HttpAsyncRequestExecutor.inputReady(HttpAsyncRequestExecutor.java:338)
    at org.apache.http.impl.nio.DefaultNHttpClientConnection.consumeInput(DefaultNHttpClientConnection.java:265)
    at org.apache.http.impl.nio.client.InternalIODispatch.onInputReady(InternalIODispatch.java:39)
    at org.apache.http.impl.nio.reactor.BaseIOReactor.readable(BaseIOReactor.java:162)
    at org.apache.http.impl.nio.reactor.AbstractIOReactor.processEvent(AbstractIOReactor.java:337)
    at org.apache.http.impl.nio.reactor.BaseIOReactor.execute(BaseIOReactor.java:104)
Caused by: java.io.IOException: Stale file handle
    at java.io.FileOutputStream.writeBytes(Native Method)
    at java.io.FileOutputStream.write(FileOutputStream.java:326)
    ... 48 more

 ㅇ 쿠버네티스 환경에서 100개 이상의 POD의 로그정보를 efs 파일 시스템에 저장하고 있다.

 ㅇ 시스템 에러가 발생할 경우 efs/logs/ts/error 폴더에 에러 로그를 쌓고 있었다.

 

 

ㅁ 원인 분석

  실제로 에러로그 파일을 분석한 결과, 현재 GW와 연동된 시스템에서 협의되지 않은 결과코드로 인해 Exception이 다중 발생하였다. 트래픽에 대한 분산처리로 동시에 여러 컨테이너에서 error가 발생하였고, 동시에 하나의 efs error파일에 접근하면서 접근실패 exception이 발생하였다.

 

 

ㅁ log4j 수정

<RollingFile name="error_file" fileName="${log-path-efs}/error/gw-ts.log" filePattern="${log-path-efs}/error/$${date:yyyyMMdd}/gw-ts.log">
    <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [${hostName}] [%20.20t] [%-40.40logger{39}] (%-4L) : %m%n%wEx" />
    <Policies>
        <SizeBasedTriggeringPolicy size="500MB" /> <!-- 이 용량이 초과되면 아래 DefaultRolloverStrategy 정책만큼 넘버링  -->
        <TimeBasedTriggeringPolicy /><!-- Rotated everyday -->
    </Policies>
    <DefaultRolloverStrategy max="500" fileIndex="min" />
</RollingFile>

<root level="debug" >
    <appender-ref ref="service_file" />
    <appender-ref ref="error_file" level="error" />
</root>

  ㅇ 기존의 log4j 내용이다.

  ㅇ 날짜에 따른 Rolling은 되어 있었지만, 동시다발적으로 에러가 발생할 경우 동일한 파일에 접근하도록 되어 있었다.

 

<RollingFile name="error_file" fileName="${log-path-efs}/error/${hostName}-ts-error.log" filePattern="${log-path-efs}/error/$${date:yyyyMMdd}/${hostName}-ts-error.log">
    <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS} [${hostName}] [%20.20t] [%-40.40logger{39}] (%-4L) : %m%n%wEx" />
    <Policies>
        <SizeBasedTriggeringPolicy size="500MB" /> <!-- 이 용량이 초과되면 아래 DefaultRolloverStrategy 정책만큼 넘버링  -->
        <TimeBasedTriggeringPolicy /><!-- Rotated everyday -->
    </Policies>
    <DefaultRolloverStrategy max="500" fileIndex="min" />
</RollingFile>

 ㅇ 파일명에 ${hostName}을 주어 컨테이너별로 매칭되게 하여 다중 프로세스의 접속을 개선하였다.

 

 ㅇ 실제로 efs error 경로에 로그가 컨데이터별로 생성되는지 확인하였다.