[230826] 입찰 API 병목 현상 로직 점검

입찰 API 로직 점검

💬 입찰 API에서 생기는 병목 현상을 해결하기 위해 로직을 확인했습니다. 로직의 중요 부분의 수행 시간을 측정하고 로그를 찍어서 확인했습니다. 

 

✔ 로직 수행 시간 측정 로그

💬 Slf4j를 사용해서 로그를 출력했습니다. 하지만 화면에 출력된 로그는 DEBUG, ERROR, INFO 등 모두 찍혔습니다. 수행 시간만 별도로 확인을 하기 위해 INFO로 설정해 출력했으며, logback을 사용해 별도의 파일에 저장을 했습니다.

 

1. Dependency 추가

 

implementation (
        'ch.qos.logback:logback-classic:1.4.11',
        'ch.qos.logback:logback-core:1.4.11',
)

 

2. logback.xml 작성

<configuration scan="true" scanPeriod="5 seconds">

    <appender name="TIME_INFO" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>INFO</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>./logback-info-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>100MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>%d{HH:mm:ss.SSS} [%-5level] - %msg%n</Pattern>
        </layout>
    </appender>

    <root level="INFO">
        <appender-ref ref="TIME_INFO"/>
        <appender-ref ref="STDOUT" />
    </root>
</configuration>​

 

✔ 측정 결과

💬 단위 ms로 시간을 찍어본 결과 가장 많은 시간을 사용하는 부분은 SSE를 통해 이벤트를 보내는 것이었습니다. 전체 로직의 95% 정도 차지를 하고 있었습니다. 이 작업을 현재 로직에서 분리를 해낸다면 성능 향상을 크게 이룰 수 있을 것으로 보입니다. 

 

✔ 개선

💬 병목 현상에서 가장 문제가 되는 로직을 찾았으니 개선을 해볼 수 있을 것 같습니다. 시간 관계상 오늘 알아보고 처리하는 것은 힘들어 보였습니다. 내일 알아보고 처리해보려고 합니다.