Spring AOP(Aspect-Oriented Programming)와 Redis 캐싱을 활용하여 OpenAI API 호출 성능을 측정하고 최적화한 경험을 공유하고자 합니다. 와인 추천 서비스에서 OpenAI API를 사용하여 유사 음식을 찾거나 와인 설명을 생성하는 과정에서 성능을 개선하기 위한 여정을 소개합니다.
1. 문제 정의: OpenAI API 호출 시 성능 이슈
우리 서비스에서는 사용자에게 맞춤형 와인을 추천하기 위해 다음과 같은 OpenAI API 호출을 사용합니다:
- 유사 음식 검색: 사용자가 입력한 음식과 유사한 음식을 데이터베이스에서 찾기 위해 OpenAI의 텍스트 유사성 분석 사용
- 와인 설명 생성: 추천된 와인에 대한 매력적인 설명문 생성
이 과정에서 몇 가지 이슈가 발생했습니다:
- 응답 시간 지연: OpenAI API 호출로 인한 전체 요청 처리 시간 증가
- 동일 요청 중복 발생: 같은 음식이나 같은 와인에 대해 반복적인 API 호출 발생
- 병목 지점 파악 어려움: 정확히 어느 부분에서 성능 지연이 발생하는지 파악 어려움
이러한 문제를 해결하기 위해 AOP를 활용한 성능 측정 시스템을 구축하였습니다.
2. OpenAI API 호출 코드 분석
먼저 OpenAI API를 호출하는 코드를 자세히 살펴보겠습니다. 우리 서비스에서는 두 가지 주요 사용 사례가 있습니다:
2-1. 유사 음식 검색 (FoodSimilarityService)
@Service
@RequiredArgsConstructor
public class FoodSimilarityService {
private final FoodRepository foodRepository;
private final WebClient.Builder webClientBuilder;
@Value("${openai.api.key}")
private String openaiApiKey;
@Value("${openai.api.url:https://api.openai.com/v1/chat/completions}")
private String openaiApiUrl;
@Value("${openai.api.model:gpt-3.5-turbo}")
private String openaiModel;
/**
* 사용자가 입력한 음식과 가장 유사한 Food 항목의 ID를 찾아 반환
*/
public List findSimilarFoods(List userFoods) {
List similarFoodIds = new ArrayList<>();
// 모든 음식 목록 가져오기
List allFoods = foodRepository.findAll();
if (allFoods.isEmpty()) {
return Collections.emptyList();
}
// 각 입력 음식에 대해 유사한 음식 찾기
for (String userFood : userFoods) {
// 정확히 일치하는 음식 확인
Optional exactMatchOpt = foodRepository.findByFoodNameContaining(userFood);
if (exactMatchOpt.isPresent()) {
similarFoodIds.add(exactMatchOpt.get().getId());
continue;
}
// OpenAI API로 유사도 계산
String mostSimilarFood = findMostSimilarFoodUsingOpenAI(userFood, allFoods);
if (mostSimilarFood != null && !mostSimilarFood.equals("no_similar_food")) {
Optional similarFoodOpt = foodRepository.findByFoodName(mostSimilarFood);
similarFoodOpt.ifPresent(food -> similarFoodIds.add(food.getId()));
}
}
return similarFoodIds;
}
/**
* OpenAI API를 사용하여 가장 유사한 음식 찾기
*/
private String findMostSimilarFoodUsingOpenAI(String userFood, List allFoods) {
// 음식 이름 목록
List foodNames = allFoods.stream()
.map(Food::getFoodName)
.collect(Collectors.toList());
try {
// OpenAI API 요청 구성
Map<string, object=""> requestBody = new HashMap<>();
requestBody.put("model", openaiModel);
requestBody.put("temperature", 0);
requestBody.put("max_tokens", 50);
List<map<string, object="">> messages = new ArrayList<>();
// 시스템 메시지
Map<string, object=""> systemMessage = new HashMap<>();
systemMessage.put("role", "system");
systemMessage.put("content", "당신은 음식 유사도를 판단하는 전문가입니다. 입력된 음식과 가장 유사한 음식을 찾아주세요.");
messages.add(systemMessage);
// 사용자 메시지
Map<string, object=""> userMessage = new HashMap<>();
userMessage.put("role", "user");
userMessage.put("content", buildPrompt(userFood, foodNames));
messages.add(userMessage);
requestBody.put("messages", messages);
// API 호출
String responseString = webClientBuilder.build()
.post()
.uri(openaiApiUrl)
.header(HttpHeaders.CONTENT_TYPE, MediaType.APPLICATION_JSON_VALUE)
.header(HttpHeaders.AUTHORIZATION, "Bearer " + openaiApiKey)
.body(BodyInserters.fromValue(requestBody))
.retrieve()
.bodyToMono(String.class)
.block();
// 응답 파싱 및 결과 반환
ObjectMapper objectMapper = new ObjectMapper();
JsonNode responseJson = objectMapper.readTree(responseString);
String content = responseJson.path("choices").path(0).path("message").path("content").asText();
for (String foodName : foodNames) {
if (content.contains(foodName)) {
return foodName;
}
}
if (content.contains("유사한 음식 없음") || content.contains("없습니다")) {
return "no_similar_food";
}
return null;
} catch (Exception e) {
e.printStackTrace();
return null;
}
}
}
</string,></string,></map<string,></string,>2-2. 와인 설명 생성 (OpenAIService)
@Service
@RequiredArgsConstructor
public class OpenAIService {
private final WebClient.Builder webClientBuilder;
private final ObjectMapper objectMapper;
// 간단한 인메모리 캐싱
private final Map<long, string=""> wineDescriptionCache = new ConcurrentHashMap<>();
@Value("${openai.api.key}")
private String openaiApiKey;
@Value("${openai.api.url:https://api.openai.com/v1/chat/completions}")
private String openaiApiUrl;
@Value("${openai.api.model:gpt-3.5-turbo}")
private String openaiModel;
/**
* 와인 정보를 기반으로 OpenAI를 통해 맞춤형 설명을 생성
*/
public Mono generateWineDescription(WineResponseDTO wine) {
// 캐시에서 확인
if (wineDescriptionCache.containsKey(wine.getWineId())) {
return Mono.just(wineDescriptionCache.get(wine.getWineId()));
}
String prompt = createPromptForWine(wine);
try {
ObjectNode requestBody = objectMapper.createObjectNode();
requestBody.put("model", openaiModel);
requestBody.put("temperature", 0.7);
ObjectNode systemMessage = objectMapper.createObjectNode();
systemMessage.put("role", "system");
systemMessage.put("content", "당신은 와인 전문가입니다. 주어진 와인의 특성을 바탕으로 간결하고 매력적인 설명을 생성해주세요.");
ObjectNode userMessage = objectMapper.createObjectNode();
userMessage.put("role", "user");
userMessage.put("content", prompt);
requestBody.putArray("messages")
.add(systemMessage)
.add(userMessage);
return webClientBuilder.build()
.post()
.uri(openaiApiUrl)
.header(HttpHeaders.AUTHORIZATION, "Bearer " + openaiApiKey)
.contentType(MediaType.APPLICATION_JSON)
.body(BodyInserters.fromValue(requestBody.toString()))
.retrieve()
.bodyToMono(String.class)
.map(response -> {
try {
JsonNode jsonResponse = objectMapper.readTree(response);
String generatedDescription = jsonResponse
.path("choices")
.path(0)
.path("message")
.path("content")
.asText();
// 캐시에 저장
wineDescriptionCache.put(wine.getWineId(), generatedDescription);
return generatedDescription;
} catch (Exception e) {
return "이 와인은 " + wine.getType() + " 타입의 와인으로 " + wine.getCountry() + "에서 생산되었습니다.";
}
})
.onErrorResume(e -> {
String fallbackDescription = "이 와인은 " + wine.getType() + " 타입의 와인으로 " + wine.getCountry() + "에서 생산되었습니다.";
return Mono.just(fallbackDescription);
});
} catch (Exception e) {
return Mono.just("이 와인은 " + wine.getType() + " 타입의 와인으로 " + wine.getCountry() + "에서 생산되었습니다.");
}
}
/**
* 여러 와인에 대한 설명을 일괄 생성
*/
public Mono<list> enrichWinesWithDescriptions(List wines) {
List<mono> enrichedWineMono = wines.stream()
.map(wine -> generateWineDescription(wine)
.map(description -> {
wine.setDescription(description);
return wine;
}))
.collect(Collectors.toList());
return Mono.zip(enrichedWineMono, wineList -> {
List result = new java.util.ArrayList<>(wineList.length);
for (Object obj : wineList) {
result.add((WineResponseDTO) obj);
}
return result;
});
}
}
</mono</list</long,>3. AOP를 활용한 성능 측정 시스템 구축
이제 위 코드의 성능을 측정하기 위해 AOP를 적용해 보겠습니다.
3-1. 필요한 의존성 추가
// Spring AOP 의존성
implementation 'org.springframework.boot:spring-boot-starter-aop'
3-2. 성능 측정용 AOP Aspect 클래스 구현
API 호출 부분의 성능을 측정하기 위한 Aspect 클래스를 다음과 같이 구현했습니다:
package com.ssafy.winedining.global.aspect;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.reflect.MethodSignature;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.springframework.util.StopWatch;
import java.util.Arrays;
@Aspect
@Component
public class PerformanceAspect {
private static final Logger logger = LoggerFactory.getLogger(PerformanceAspect.class);
// OpenAI 서비스 메소드에 대한 성능 측정
@Around("execution(* com.ssafy.winedining.domain.recommend.service.OpenAIService.*(..))")
public Object measureOpenAiServiceTime(ProceedingJoinPoint joinPoint) throws Throwable {
StopWatch stopWatch = new StopWatch();
// 메소드 시그니처 및 파라미터 정보 로깅
String methodName = joinPoint.getSignature().getName();
String className = joinPoint.getTarget().getClass().getSimpleName();
Object[] args = joinPoint.getArgs();
String params = "";
if (args != null && args.length > 0) {
params = Arrays.toString(args);
// 너무 긴 파라미터는 축약
if (params.length() > 100) {
params = params.substring(0, 100) + "...";
}
}
logger.info("[Performance] Starting {} ({}) with params: {}", methodName, className, params);
try {
stopWatch.start();
return joinPoint.proceed();
} finally {
stopWatch.stop();
logger.info("[Performance] {}.{} execution time: {} ms",
className, methodName, stopWatch.getTotalTimeMillis());
}
}
// 추천 서비스 메소드에 대한 성능 측정
@Around("execution(* com.ssafy.winedining.domain.recommend.service.RecommendService.*(..))")
public Object measureRecommendServiceTime(ProceedingJoinPoint joinPoint) throws Throwable {
StopWatch stopWatch = new StopWatch();
String methodName = joinPoint.getSignature().getName();
String className = joinPoint.getTarget().getClass().getSimpleName();
logger.info("[Performance] Starting recommendation process: {}.{}", className, methodName);
try {
stopWatch.start();
return joinPoint.proceed();
} finally {
stopWatch.stop();
logger.info("[Performance] {}.{} total execution time: {} ms",
className, methodName, stopWatch.getTotalTimeMillis());
}
}
// 음식 유사성 검색 메소드에 대한 성능 측정
@Around("execution(* com.ssafy.winedining.domain.recommend.service.moduleService.FoodSimilarityService.*(..))")
public Object measureFoodSimilarityTime(ProceedingJoinPoint joinPoint) throws Throwable {
StopWatch stopWatch = new StopWatch();
String methodName = joinPoint.getSignature().getName();
String className = joinPoint.getTarget().getClass().getSimpleName();
Object[] args = joinPoint.getArgs();
logger.info("[Performance] Starting food similarity search for: {}", Arrays.toString(args));
try {
stopWatch.start();
return joinPoint.proceed();
} finally {
stopWatch.stop();
logger.info("[Performance] {}.{} execution time: {} ms",
className, methodName, stopWatch.getTotalTimeMillis());
}
}
}3-3. AOP 설정 활성화
package com.ssafy.winedining.global.config;
import org.springframework.context.annotation.Configuration;
import org.springframework.context.annotation.EnableAspectJAutoProxy;
@Configuration
@EnableAspectJAutoProxy
public class AopConfig {
// 필요한 경우 추가 설정
}
4. 성능 측정 결과 분석
AOP를 적용한 후, 다양한 시나리오에서 성능 테스트를 진행했습니다. 그 결과는 다음과 같습니다:
단계시작 시간종료 시간소요 시간 (ms)비율 (%)
| 전체 추천 프로세스 | 15:13:33.282 | 15:13:34.210 | 928 | 100% |
| 유사 음식 검색 (FoodSimilarityService) | 15:13:33.283 | 15:13:34.200 | 916 | 98.7% |
| FastAPI 호출 | 15:13:34.209 | 15:13:34.210 | 0 | 0% |
| 와인 정보 조회 (총 3개) | 15:13:34.290 | 15:13:34.324 | 28 | 3.0% |
| - 첫 번째 와인 | 15:13:34.290 | 15:13:34.305 | 15 | 1.6% |
| - 두 번째 와인 | 15:13:34.307 | 15:13:34.315 | 7 | 0.8% |
| - 세 번째 와인 | 15:13:34.317 | 15:13:34.324 | 6 | 0.6% |
| OpenAI 와인 설명 생성 | 15:13:34.325 | 15:13:34.329 | 2 | 0.2% |
유사 음식 검색은 시간 계산이 잘 된거 같았지만 fastapi 호출과 openai 와인 설명 생성이 비정상적으로 시간초가 짧게 나오는것을 확인하였습니다.
그 이유로 FastAPI 와 OpenAI 와인 설명 생성은 비동기처리를 해주기 때문에 AOP 에서 메서드를 직접 감지하여 시간초를 계산하기 어려웠습니다.
비동기 코드에서 각 서비스 메서드의 성능을 측정하는 것은 일반적인 동기 코드보다 복잡할 수 있습니다. 하지만 Reactor의 Mono와 Flux에서 제공하는 기능을 활용하면 각 단계의 소요 시간을 측정할 수 있었습니다.
추천메서드에 적용한 방식
public Mono<List<WineResponseDTO>> getRecommendedWineDetails(Long userId, String paring) {
log.info("시작: getRecommendedWineDetails - userId: {}, paring: {}", userId, paring);
Instant startTotal = Instant.now();
// 1. 음식 유사성 찾기 시작
Instant startFoodSimilarity = Instant.now();
List<Long> similarFoodIds = new ArrayList<>();
if (paring != null && !paring.trim().isEmpty()) {
List<String> foodNames = Arrays.stream(paring.split(","))
.map(String::trim)
.filter(food -> !food.isEmpty())
.collect(Collectors.toList());
similarFoodIds = foodSimilarityService.findSimilarFoods(foodNames);
}
Instant endFoodSimilarity = Instant.now();
log.info("음식 유사성 찾기 소요 시간: {} ms",
Duration.between(startFoodSimilarity, endFoodSimilarity).toMillis());
// 1. 음식 유사성 찾기 끝
// 2. FastAPI 추천 시작
Instant startFastApiRecommend = Instant.now();
return recommendByPreference(userId, similarFoodIds)
.doOnSubscribe(s -> log.info("추천 API 호출 시작"))
.doOnSuccess(result -> {
Instant endFastApiRecommend = Instant.now();
log.info("추천 API 호출 완료 - 소요 시간: {} ms",
Duration.between(startFastApiRecommend, endFastApiRecommend).toMillis());
})
// 2. FastAPI 추천 끝
// 3. 와인 상세 정보 가져오기 시작
.flatMap(resultString -> {
Instant startWineDetailsProcess = Instant.now();
ObjectMapper mapper = new ObjectMapper();
try {
JsonNode root = mapper.readTree(resultString);
JsonNode idsNode = root.path("recommended_wine_ids");
List<Long> recommendedIds = new ArrayList<>();
if (idsNode.isArray()) {
for (JsonNode idNode : idsNode) {
recommendedIds.add(idNode.asLong());
}
}
log.info("추천된 와인 ID 목록: {}", recommendedIds);
// 와인 상세 정보 가져오기
Instant startWineDetails = Instant.now();
List<WineResponseDTO> wineDetails = new ArrayList<>();
for (Long wineId : recommendedIds) {
WineResponseDTO detail = wineService.getWineDetail(wineId);
wineDetails.add(detail);
}
Instant endWineDetails = Instant.now();
log.info("와인 상세 정보 조회 소요 시간: {} ms",
Duration.between(startWineDetails, endWineDetails).toMillis());
// 3. 와인 상세 정보 가져오기 끝
// 4. OpenAI 설명 생성 시작
Instant startOpenAI = Instant.now();
return openAIService.enrichWinesWithDescriptions(wineDetails)
.doOnSuccess(wines -> {
Instant endOpenAI = Instant.now();
log.info("OpenAI 설명 생성 소요 시간: {} ms",
Duration.between(startOpenAI, endOpenAI).toMillis());
Instant endTotal = Instant.now();
log.info("전체 getRecommendedWineDetails 소요 시간: {} ms",
Duration.between(startTotal, endTotal).toMillis());
});
// 4. OpenAI 설명 생성 끝
} catch (Exception e) {
log.error("와인 추천 처리 중 오류 발생: {}", e.getMessage(), e);
return Mono.error(e);
}
});
}
public Mono<String> recommendByPreference(Long userId, List<Long> similarFoodIds) {
Instant start = Instant.now();
// 1. 사용자 취향 데이터 조회
RecommendByPreferenceDto preferenceData = recommendDomainService.recommendByPreferene(userId);
Instant afterPreferenceData = Instant.now();
log.info("취향 데이터 조회 소요 시간: {} ms",
Duration.between(start, afterPreferenceData).toMillis());
// 2. DTO에 음식 ID 목록 설정
preferenceData.setFoodIds(similarFoodIds);
// 3. FastAPI에 DTO 전송
return recommendFastApiService.sendData(preferenceData, "preference")
.doOnSuccess(result -> {
Instant end = Instant.now();
log.info("FastAPI 통신 소요 시간: {} ms",
Duration.between(afterPreferenceData, end).toMillis());
log.info("전체 recommendByPreference 소요 시간: {} ms",
Duration.between(start, end).toMillis());
});
}
| 단계 | 소요 시간 (ms) | 비율 |
| 음식 유사성 찾기 (FoodSimilarityService.findSimilarFoods) | 2,224 | 55.2% |
| 취향 데이터 조회 | 5 | 0.1% |
| FastAPI 통신 (추천 API 호출) | 81 | 2.0% |
| 와인 상세 정보 조회 | 27 | 0.7% |
| OpenAI 설명 생성 | 1,695 | 42.0% |
| 전체 getRecommendedWineDetails | 4,029 | 100% |
음식 유사성 찾기가 와인 설명 생성보다 시간이 오래걸린것을 확인하고 이 또한 비동기로 처리해주기로 하였습니다.
그 이후 시간 계산
| 단계 | 소요 시간 (ms) | 비율 |
| 음식 유사성 찾기 (FoodSimilarityService.findSimilarFoodsAsync) | 1,831 | 52.4% |
| 취향 데이터 조회 | 7 | 0.2% |
| FastAPI 통신 (추천 API 호출) | 68 | 1.9% |
| 추천 결과 파싱 | 0 | 0.0% |
| 와인 상세 정보 조회 (병렬) | 29 | 0.8% |
| OpenAI 설명 생성 | 1,562 | 44.7% |
| 전체 getRecommendedWineDetails | 3,491 | 100% |
세부 분석:
- FoodSimilarityService (1,831ms):
- 여전히 가장 오래 걸린 작업이지만, 이전(2,224ms)보다 약 17.7% 개선됨
- OpenAI API 호출이 1,666ms로 대부분의 시간을 차지함
- SQL 쿼리는 전체 목록 조회, 유사 검색, 정확한 이름 검색 순으로 실행됨
- OpenAI 설명 생성 (1,562ms):
- 두 번째로 오래 걸린 작업으로, 이전(1,695ms)보다 약 7.8% 개선됨
- 3개 와인에 대한 설명을 모두 생성하는 시간
- 와인 상세 정보 조회 (29ms):
- 이전(27ms)과 비슷한 시간이 소요되었지만, 중요한 차이점은 병렬 처리됨
- 3개 와인이 동시에 조회되어 처리됨 (3개 스레드에서 각각 13ms, 13ms, 14ms 소요)
- FastAPI 통신 (68ms):
- 이전(81ms)보다 약 16.0% 개선됨
- 추천 알고리즘 API 호출 및 응답 수신 시간
- 취향 데이터 조회 (7ms):
- 이전(5ms)보다 약간 증가했지만 미미한 차이
- DB에서 사용자 취향 정보를 가져오는 시간
- 추천 결과 파싱 (0ms):
- 추천 API 응답을 파싱하는 데 소요된 시간이 매우 짧아 0ms로 기록됨
개선 효과:
- 전체 처리 시간: 4,029ms → 3,491ms (약 13.4% 개선)
- 병렬 처리 효과: 와인 상세 정보가 순차적 처리에서 병렬 처리로 변경됨
- 비동기 처리: 각 단계가 비동기적으로 처리되어 전체 흐름이 더 효율적으로 변경
5. Redis 캐싱 도입을 통한 성능 개선
성능 측정 결과 분석에서 OpenAI API 호출이 전체 처리 시간의 대부분을 차지하는 것으로 확인되었습니다. 이를 해결하기 위해 Redis 캐싱을 도입하여 반복적인 API 호출을 줄이기로 결정했습니다.
5-1. Redis 의존성 및 설정 추가
먼저 Redis를 사용하기 위한 의존성과 설정을 추가했습니다.
// Redis 의존성
implementation 'org.springframework.boot:spring-boot-starter-data-redis'
implementation 'org.springframework.boot:spring-boot-starter-cache'
@Configuration
public class RedisConfig {
@Value("${spring.redis.host:localhost}")
private String redisHost;
@Value("${spring.redis.port:6379}")
private int redisPort;
@Value("${spring.redis.password:}")
private String redisPassword;
@Bean
public RedisConnectionFactory redisConnectionFactory() {
RedisStandaloneConfiguration redisConfiguration = new RedisStandaloneConfiguration();
redisConfiguration.setHostName(redisHost);
redisConfiguration.setPort(redisPort);
// 비밀번호가 설정되어 있는 경우에만 적용
if (redisPassword != null && !redisPassword.isEmpty()) {
redisConfiguration.setPassword(redisPassword);
}
return new LettuceConnectionFactory(redisConfiguration);
}
@Bean
public RedisTemplate<String, Object> redisTemplate() {
RedisTemplate<String, Object> redisTemplate = new RedisTemplate<>();
redisTemplate.setConnectionFactory(redisConnectionFactory());
redisTemplate.setKeySerializer(new StringRedisSerializer());
redisTemplate.setValueSerializer(new GenericJackson2JsonRedisSerializer());
redisTemplate.setHashKeySerializer(new StringRedisSerializer());
redisTemplate.setHashValueSerializer(new GenericJackson2JsonRedisSerializer());
redisTemplate.afterPropertiesSet();
return redisTemplate;
}
}5-2. 유사 음식 검색에 캐싱 적용
@Service
@RequiredArgsConstructor
public class FoodSimilarityService {
private final FoodRepository foodRepository;
private final WebClient.Builder webClientBuilder;
// 기존 코드...
private Mono<Long> findSimilarFoodForSingleInput(String userFood, List<Food> allFoods) {
Instant start = Instant.now();
log.debug("'{}' 음식의 유사 음식 찾기 시작", userFood);
// 캐시 키 생성
String cacheKey = FOOD_SIMILARITY_CACHE_PREFIX + userFood;
// 1. Redis 캐시에서 먼저 조회
return Mono.fromCallable(() -> redisCacheService.get(cacheKey))
.subscribeOn(Schedulers.boundedElastic())
.flatMap(cachedResult -> {
if (cachedResult.isPresent()) {
// 타입 변환 안전하게 처리
Object cachedValue = cachedResult.get();
Long foodId = null;
if (cachedValue instanceof Integer) {
// Integer를 Long으로 변환
foodId = ((Integer) cachedValue).longValue();
log.debug("Integer에서 Long으로 변환: {} -> {}", cachedValue, foodId);
} else if (cachedValue instanceof Long) {
foodId = (Long) cachedValue;
} else {
// 다른 타입인 경우 (예: String)
try {
foodId = Long.parseLong(cachedValue.toString());
log.debug("String에서 Long으로 변환: {} -> {}", cachedValue, foodId);
} catch (NumberFormatException e) {
log.error("캐시 값을 Long으로 변환할 수 없음: {}", cachedValue);
return Mono.empty();
}
}
Instant end = Instant.now();
log.info("Redis 캐시에서 '{}' 음식의 유사 음식 ID {} 조회됨: 소요 시간 {}ms",
userFood, foodId, Duration.between(start, end).toMillis());
return Mono.just(foodId);
}
// 2. 정확히 일치하는 음식 찾기 (대소문자 무시, 부분 일치)
return Mono.fromCallable(() -> foodRepository.findByFoodNameContaining(userFood))
.subscribeOn(Schedulers.boundedElastic())
.flatMap(exactMatchOpt -> {
if (exactMatchOpt.isPresent()) {
Food exactMatch = exactMatchOpt.get();
Long foodId = exactMatch.getId();
// 캐시에 저장 - String으로 저장하여 타입 변환 문제 방지
redisCacheService.set(cacheKey, String.valueOf(foodId), CACHE_EXPIRATION_SECONDS);
Instant end = Instant.now();
log.debug("'{}' 음식에 대해 정확히 일치하는 음식 '{}' 찾음 (ID: {}): 소요 시간 {}ms",
userFood, exactMatch.getFoodName(), foodId,
Duration.between(start, end).toMillis());
return Mono.just(foodId);
}
// 3. 정확히 일치하는 음식이 없으면 OpenAI로 유사도 계산
return findMostSimilarFoodUsingOpenAIAsync(userFood, allFoods)
.flatMap(mostSimilarFood -> {
if (mostSimilarFood == null || "no_similar_food".equals(mostSimilarFood)) {
log.debug("'{}' 음식에 대해 유사한 음식을 찾지 못함", userFood);
return Mono.empty();
}
return Mono.fromCallable(() -> foodRepository.findByFoodName(mostSimilarFood))
.subscribeOn(Schedulers.boundedElastic())
.flatMap(similarFoodOpt -> {
if (similarFoodOpt.isPresent()) {
Long foodId = similarFoodOpt.get().getId();
// 캐시에 저장 - String으로 저장하여 타입 변환 문제 방지
redisCacheService.set(cacheKey, String.valueOf(foodId), CACHE_EXPIRATION_SECONDS);
Instant end = Instant.now();
log.debug("'{}' 음식에 대해 유사한 음식 '{}' 찾음 (ID: {}): 소요 시간 {}ms",
userFood, similarFoodOpt.get().getFoodName(), foodId,
Duration.between(start, end).toMillis());
return Mono.just(foodId);
}
return Mono.empty();
});
});
});
})
.doOnError(e -> log.error("'{}' 음식의 유사 음식 찾기 중 오류 발생: {}", userFood, e.getMessage(), e));
}
// 기존 API 호출 메소드는 그대로 유지
}5-3. 와인 설명 생성에 캐싱 적용
@Service
@RequiredArgsConstructor
public class OpenAIService {
private final WebClient.Builder webClientBuilder;
private final ObjectMapper objectMapper;
// 기존 코드...
/**
* 와인 정보를 기반으로 OpenAI를 통해 맞춤형 설명을 생성
* Redis 캐싱을 적용
*/
@Cacheable(value = "wineDescriptions", key = "#wine.wineId")
public Mono<String> generateWineDescription(WineResponseDTO wine) {
// 로깅 추가
log.info("[Cache] Cache miss for wine: {}", wine.getKrName());
String prompt = createPromptForWine(wine);
try {
// 기존 API 호출 코드 (ConcurrentHashMap 캐시 코드 제거)
ObjectNode requestBody = objectMapper.createObjectNode();
requestBody.put("model", openaiModel);
requestBody.put("temperature", 0.7);
ObjectNode systemMessage = objectMapper.createObjectNode();
systemMessage.put("role", "system");
systemMessage.put("content", "당신은 와인 전문가입니다. 주어진 와인의 특성을 바탕으로 간결하고 매력적인 설명을 생성해주세요.");
ObjectNode userMessage = objectMapper.createObjectNode();
userMessage.put("role", "user");
userMessage.put("content", prompt);
requestBody.putArray("messages")
.add(systemMessage)
.add(userMessage);
return webClientBuilder.build()
.post()
.uri(openaiApiUrl)
.header(HttpHeaders.AUTHORIZATION, "Bearer " + openaiApiKey)
.contentType(MediaType.APPLICATION_JSON)
.body(BodyInserters.fromValue(requestBody.toString()))
.retrieve()
.bodyToMono(String.class)
.map(response -> {
try {
JsonNode jsonResponse = objectMapper.readTree(response);
String generatedDescription = jsonResponse
.path("choices")
.path(0)
.path("message")
.path("content")
.asText();
return generatedDescription;
} catch (Exception e) {
return "이 와인은 " + wine.getType() + " 타입의 와인으로 " + wine.getCountry() + "에서 생산되었습니다.";
}
})
.onErrorResume(e -> {
String fallbackDescription = "이 와인은 " + wine.getType() + " 타입의 와인으로 " + wine.getCountry() + "에서 생산되었습니다.";
return Mono.just(fallbackDescription);
});
} catch (Exception e) {
return Mono.just("이 와인은 " + wine.getType() + " 타입의 와인으로 " + wine.getCountry() + "에서 생산되었습니다.");
}
}
// 기존 코드 유지...
}5-4. 추가 성능 최적화 방안
캐싱 외에도 다음과 같은 추가 최적화 방안을 적용했습니다:
1. 병렬 처리 개선
여러 와인에 대한 설명을 병렬로 생성하되, 효율적인 리소스 관리를 위해 제한된 동시 실행을 적용했습니다.
public Mono<List<WineResponseDTO>> enrichWinesWithDescriptions(List<WineResponseDTO> wines) {
// Parallel 스케줄러 사용 (제한된 병렬 처리)
Scheduler scheduler = Schedulers.newParallel("wine-description", 4);
List<Mono<WineResponseDTO>> enrichedWineMono = wines.stream()
.map(wine -> generateWineDescription(wine)
.publishOn(scheduler) // 병렬 처리를 위한 스케줄러 지정
.map(description -> {
wine.setDescription(description);
return wine;
}))
.collect(Collectors.toList());
return Mono.zip(enrichedWineMono, wineList -> {
List<WineResponseDTO> result = new ArrayList<>(wineList.length);
for (Object obj : wineList) {
result.add((WineResponseDTO) obj);
}
return result;
});
}
2. 요청 최적화
OpenAI API 요청 시 토큰 수를 최적화하여 응답 시간과 비용을 줄였습니다.
private String createPromptForWine(WineResponseDTO wine) {
StringBuilder promptBuilder = new StringBuilder();
promptBuilder.append("다음 와인에 대한 매력적인 설명을 50단어 이내로 작성해주세요.\n\n");
promptBuilder.append("와인 이름: ").append(wine.getKrName()).append("\n");
promptBuilder.append("와인 타입: ").append(wine.getType()).append("\n");
promptBuilder.append("국가: ").append(wine.getCountry()).append("\n");
promptBuilder.append("포도 품종: ").append(wine.getGrape()).append("\n");
// 필수 속성만 포함하여 토큰 수 절약
if (wine.getSweetness() != null && wine.getSweetness() > 0) {
promptBuilder.append("당도(0-5): ").append(wine.getSweetness()).append("\n");
}
if (wine.getAcidity() != null && wine.getAcidity() > 0) {
promptBuilder.append("산도(0-5): ").append(wine.getAcidity()).append("\n");
}
if (wine.getTannin() != null && wine.getTannin() > 0) {
promptBuilder.append("탄닌(0-5): ").append(wine.getTannin()).append("\n");
}
if (wine.getBody() != null && wine.getBody() > 0) {
promptBuilder.append("바디감(0-5): ").append(wine.getBody()).append("\n");
}
promptBuilder.append("\n초보자도 이해하기 쉬운 간결한 설명을 작성해주세요.");
return promptBuilder.toString();
}
| 18,872 | 1,529 | 91.9% |
분석 결과:
- 유사 음식 검색과 와인 설명 생성에서 99% 이상의 극적인 성능 개선
- 전체 추천 프로세스에서도 **91.9%**의 성능 개선 효과
- 캐싱을 통해 API 호출 비용도 크게 절감 (약 90% 이상)
6. 성능 측정 코드 최적화 팁
AOP를 활용한 성능 측정을 더욱 효과적으로 하기 위한 팁을 공유합니다:
6-1. 계층별 측정 포인트 설정
@Around("execution(* com.ssafy.*.*.controller.*.*(..))")
@Around("execution(* com.ssafy.*.*.service.*.*(..))")
@Around("execution(* com.ssafy.*.*.repository.*.*(..))")
6-2. 조건부 성능 측정 (예: 임계값 이상일 때만)
@Around("execution(* com.ssafy.winedining.domain.recommend.service.OpenAIService.*(..))")
public Object measureOpenAiServiceTime(ProceedingJoinPoint joinPoint) throws Throwable {
StopWatch stopWatch = new StopWatch();
stopWatch.start();
try {
return joinPoint.proceed();
} finally {
stopWatch.stop();
long executionTime = stopWatch.getTotalTimeMillis();
if (executionTime > 1000) { // 1초 이상 걸린 경우만 로깅
logger.warn("[Performance Alert] {}.{} took too long: {} ms",
joinPoint.getTarget().getClass().getSimpleName(),
joinPoint.getSignature().getName(),
executionTime);
}
}
}
6-3. 메소드 파라미터와 반환값 로깅
@Around("execution(* com.ssafy.winedining.domain.recommend.service.OpenAIService.*(..))")
public Object logMethodDetails(ProceedingJoinPoint joinPoint) throws Throwable {
MethodSignature signature = (MethodSignature) joinPoint.getSignature();
String[] parameterNames = signature.getParameterNames();
Object[] args = joinPoint.getArgs();
StringBuilder logMessage = new StringBuilder();
logMessage.append("Method: ").append(signature.getName()).append(" called with: ");
for (int i = 0; i < parameterNames.length; i++) {
logMessage.append(parameterNames[i]).append("=").append(args[i]);
if (i < parameterNames.length - 1) {
logMessage.append(", ");
}
}
logger.info(logMessage.toString());
Object result = joinPoint.proceed();
logger.info("Method: {} returned: {}", signature.getName(), result);
return result;
}
7. 결론
AOP를 활용한 성능 측정을 통해 우리는 다음과 같은 이점을 얻었습니다:
- 병목 지점의 명확한 식별: OpenAI API 호출, 특히 와인 설명 생성이 주요 병목 지점임을 확인
- 데이터 기반 의사결정: 측정된 성능 데이터를 바탕으로 캐싱이라는 최적의 개선 방안 선택
- 비침투적인 측정: 비즈니스 로직을 수정하지 않고 성능을 측정하여 코드 복잡도 증가 방지
- 지속적인 모니터링 기반 마련: 향후 성능 변화를 지속적으로 모니터링할 수 있는 기반 구축
이번 경험을 통해 AOP가 단순히 횡단 관심사 분리 도구를 넘어서, 성능 분석과 개선에도 매우 유용한 도구임을 깨달았습니다. 특히 OpenAI API와 같은 외부 API 호출이 많은 서비스에서는 이러한 성능 측정과 최적화가 서비스의 품질과 비용에 직접적인 영향을 미칩니다.
다음 포스팅에서는 Redis 캐싱을 더 세밀하게 구현하는 방법과 캐시 적중률 최적화 전략에 대해 다루도록 하겠습니다. 감사합니다!
현재 로그를 분석하여 Redis 캐싱이 적용된 후의 각 단계별 처리 시간을 표로 정리했습니다:
단계소요 시간 (ms)비율
| 음식 유사성 찾기 (FoodSimilarityService) | 5 | 16.1% |
| 취향 데이터 조회 | 2 | 6.5% |
| FastAPI 통신 (추천 API 호출) | 22 | 71.0% |
| 추천 결과 파싱 | 0 | 0.0% |
| 와인 상세 정보 조회 (병렬) | 3 | 9.7% |
| OpenAI 설명 생성 | 0 | 0.0% |
| 전체 getRecommendedWineDetails | 31 | 100% |
이전 성능과의 비교:
단계이전 시간 (ms)현재 시간 (ms)개선율
| 음식 유사성 찾기 | 1,831 | 5 | 99.7% |
| 취향 데이터 조회 | 7 | 2 | 71.4% |
| FastAPI 통신 | 68 | 22 | 67.6% |
| 추천 결과 파싱 | 0 | 0 | - |
| 와인 상세 정보 조회 | 29 | 3 | 89.7% |
| OpenAI 설명 생성 | 1,562 | 0 | 100.0% |
| 전체 처리 시간 | 3,491 | 31 | 99.1% |
분석 및 개선 결과:
- 전체 처리 시간: 3,491ms → 31ms (99.1% 개선)
- 전체 응답 시간이 약 112배 빨라졌습니다!
- 음식 유사성 찾기: 1,831ms → 5ms (99.7% 개선)
- Redis 캐시에서 즉시 결과를 가져와 OpenAI API 호출이 완전히 제거되었습니다.
- 로그에서 Redis 캐시에서 '삼겹살' 음식의 유사 음식 ID 2 조회됨 메시지 확인
- OpenAI 설명 생성: 1,562ms → 0ms (100% 개선)
- 세 개의 와인 모두 Redis 캐시에서 즉시 설명을 가져왔습니다.
- 로그에서 Redis 캐시에서 와인 ID xxx 설명 조회됨: 소요 시간 0ms 메시지 확인
- 병목 지점 변화:
- 이전: 음식 유사성 찾기(52.4%)와 OpenAI 설명 생성(44.7%)이 전체 시간의 97.1% 차지
- 현재: FastAPI 통신(71.0%)이 주요 병목 지점이 됨
결론:
- Redis 캐싱의 효과:
- 캐싱을 적용한 두 부분(음식 유사성, 와인 설명)이 거의 즉시 응답하게 되어 전체 처리 시간이 극적으로 개선되었습니다.
- 애플리케이션을 재시작해도 캐시가 유지되어 지속적인 성능 향상이 가능합니다.
- 새로운 최적화 대상:
- 이제 FastAPI 통신이 새로운 병목 지점(전체 시간의 71%)이 되었습니다.
- 이 부분도 캐싱을 적용하거나 추천 서비스를 더 효율적으로 개선할 수 있습니다.
- 타입 변환 문제 해결:
- 로그에서 Integer에서 Long으로 변환: 2 -> 2 메시지를 통해 타입 변환 문제가 정상적으로 해결된 것을 확인할 수 있습니다.
Redis 캐싱을 적용한 결과 전체 처리 시간이 3.5초에서 0.03초로 극적으로 감소했으며, 이는 사용자 경험을 크게 향상시킬 수 있는 매우 의미 있는 개선입니다.
'개발 > SpringBoot' 카테고리의 다른 글
| N+1 문제 해결을 통한 와인 목록 조회 성능 개선 (0) | 2025.04.07 |
|---|---|
| [JPA] Entity 설계 시 ID 값을 Integer 대신 Long 타입으로 지정하는 이유 (1) | 2025.02.07 |
| 깃허브로 그룹 프로젝트 하는 법 3: 브랜치와 이슈 만들기 (0) | 2024.11.14 |
| 깃허브로 그룹 프로젝트 하는 법 2 : 프로젝트 환경 세팅 (0) | 2024.11.12 |
| 깃허브로 그룹 프로젝트 하는 법 1 : 리파지토리 생성 및 팀원 초대 (0) | 2024.11.11 |
