목록 화면이 느려서 쿼리를 다 봤는데 쿼리는 빠른데 화면이 느렸다.
Table of contents
Open Table of contents
쿼리가 아니었다
목록을 가져오는 쿼리부터 쟀다.
$rows = $this->order->getList($cond); // 40msgetList 는 40밀리초로 빨랐는데 화면 전체가 4초였다. 그래서 구간별로 시간을 나눠 쟀다.
쿼리 40ms
가공 3,820ms ←
그리기 180ms가공 구간에서 시간을 쓰고 있었다. 조회가 빠른데 화면이 느리면 그 시간은 자료를 받은 뒤에 쓰이고 있다.
느리다는 제보를 받으면 쿼리부터 의심하는 것이 습관이라 40밀리초짜리를 한참 들여다봤다.
전체를 세 토막으로 나눠 재는 데는 몇 분이면 됐고 어느 토막인지 정하니 볼 곳이 좁아졌다.
원인 — 가벼운 이름 뒤의 무거운 일
시간을 쓰는 가공 구간을 열어 봤다.
foreach ($rows as &$r) {
$r['grade'] = get_member_grade($r['member_no']);
$r['region'] = get_region_name($r['zipcode']);
}get_member_grade 라는 이름만 보면 값을 꺼내 오는 함수처럼 보인다. 그래서 반복문 안에 들어가 있어도 아무도 이상하게 여기지 않았다.
function get_member_grade($memberNo) {
$client = new GuzzleHttp\Client();
$res = $client->get(MEMBER_API . '/member/' . $memberNo . '/grade');
return json_decode($res->getBody(), true)['grade'];
}열어 보니 GuzzleHttp\Client 로 다른 서비스를 부르고 있었고 행마다 한 번씩이라 50건이면 50번 나간다.
이름이 무거움을 안 드러내고 있었는데 반복문에 넣는 판단이 이름으로 이뤄지는 자리였다.
이 함수를 쓴 사람이 잘못한 것도 아니었다. 이름이 주는 정보대로 판단했을 뿐이고 그 정보가 틀렸다.
가벼워 보이는 이름을 붙인 쪽에 책임이 있었다. 쓰는 쪽은 안을 매번 열어 볼 수 없다.
함수를 쓸 때마다 안을 열어 보지 않고 이름과 인자와 돌려주는 값만 보고 쓰는 것이 보통이다.
그래서 이름이 곧 그 함수의 규격 노릇을 하고 규격이 틀리면 쓰는 쪽의 판단이 어긋난다.
이름을 바꿨다
먼저 get_member_grade 라는 이름부터 고쳤다.
function fetch_member_grade_from_api($memberNo) { ... }이름에 fetch 와 api 가 들어가니 부르는 쪽에서 무거운 것을 안다. 이름만 바꿔도 다음 사람이 반복문 안에 안 넣는다.
같은 모양을 더 찾아봤다.
$ grep -rn "new GuzzleHttp\\\\Client\|curl_init\|file_get_contents('http" --include=*.php src/ | wc -l
4141곳에서 외부를 부르고 있었고 그중 아홉이 이름만 봐서는 모르는 것이었다. 함수 이름으로는 못 찾으니 부르는 쪽 코드를 검색해야 나온다.
이름이 이미 틀려 있으니 이름으로 찾는 방법은 안 통하고 무엇을 부르는지로 찾아야 목록이 나온다.
아홉 개를 하나씩 열어 이름을 고치면서 그 아홉이 지금 어디에서 불리는지도 확인했다.
그중 둘이 이번처럼 반복문 안에 들어가 있었다. 화면이 느리다는 제보가 아직 안 온 자리였다.
제보를 기다렸으면 두 번 더 같은 조사를 했을 것이다. 한 번 찾을 때 같은 모양을 전부 세는 쪽이 쌌다.
조치 — 한 번에 가져오기
GuzzleHttp 호출 자체를 줄이는 것이 근본이었다.
$memberNos = array_unique(array_column($rows, 'member_no'));
$grades = $memberClient->getGrades($memberNos); // 한 번에
foreach ($rows as &$r) {
$r['grade'] = $grades[$r['member_no']] ?? null;
}array_column 으로 식별자를 모아 한 번에 요청하니 50번이 1번이 됐고 3,820밀리초가 210밀리초가 됐다.
상대 API에 여러 개를 한 번에 받는 것이 있는지 물어봤는데 없었다. 만들어 달라고 요청하고 그동안은 병렬로 불렀다.
$promises = [];
foreach ($memberNos as $no) {
$promises[$no] = $client->getAsync("/member/{$no}/grade");
}
$results = GuzzleHttp\Promise\settle($promises)->wait();getAsync 로 던져 놓고 settle 로 한 번에 기다린다. 50번이어도 시간이 줄지만 상대에게 한꺼번에 가므로 동시 개수를 제한했다.
묶어서 한 번에 받는 쪽이 병렬보다 낫다. 병렬은 우리 시간만 줄이고 상대의 부하는 그대로 둔다.
그래서 병렬은 임시 방편으로 두고 묶는 요청을 계속 기다렸다. 상대가 만들어 준 뒤에 그쪽으로 옮겼다.
실패했을 때를 다뤘다
외부를 부르는 것이니 실패할 수 있다.
foreach ($results as $no => $r) {
if ($r['state'] !== 'fulfilled') {
log_message('error', "등급 조회 실패 member={$no}");
$grades[$no] = null;
continue;
}
$grades[$no] = json_decode($r['value']->getBody(), true)['grade'];
}fulfilled 가 아니면 기록만 남기고 null 로 두고 넘어간다. 하나가 실패해도 목록은 나오고 등급 칸만 빈다.
전에는 하나가 실패하면 화면 전체가 오류였는데 grade 가 필수는 아니었으므로 그 판단이 틀렸다.
무엇이 필수인지를 정해 두면 실패의 크기가 달라지고 화면이 죽는 것과 칸이 비는 것은 다르다.
제약 — 시간 제한
Client 에 시간 제한이 없다는 것도 그때 알았다.
$client = new Client(['timeout' => 2.0, 'connect_timeout' => 1.0]);제한이 없으면 상대가 느릴 때 계속 기다린다. 실제로 화면 하나가 30초를 넘은 적이 있었다.
timeout 을 주니 느려도 2초에 끊고 나머지를 보여 주는데 상한을 우리가 정하는 것이 요점이었다.
2초라는 값은 그 화면이 허용할 수 있는 지연에서 거꾸로 잡았다. 상대의 평소 응답 시간에서 잡은 것이 아니다.
상대가 빨라지면 우리가 이득을 보고 느려지면 우리가 끊는다. 그 경계를 우리 화면의 사정으로 정했다.
상한이 없으면 우리 화면의 응답 시간을 상대가 정하게 되고 그쪽이 30초 걸리면 우리도 30초다.
상한을 두면 그 값이 우리 약속이 되고 상대가 느려도 우리는 2초 안에 무언가를 돌려준다.
검증 — 외부 호출을 보이게
같은 일이 다시 생기는 것을 알아채게 ExternalCallCounter 를 넣었다.
class ExternalCallCounter {
public static function record(string $service, float $ms): void {
self::$calls[] = [$service, $ms];
}
}record 로 모아 두고 요청이 끝날 때 한 줄로 남긴다.
/order/list external: member(1, 180ms) region(1, 42ms) total 222ms한 요청에서 외부를 몇 번 불렀는지가 보이고 숫자가 갑자기 늘면 누군가 반복문 안에 다시 넣은 것이다.
임계를 넘으면 경고를 남기게 해서 고친 것이 원래대로 가는 것을 사람이 안 지켜봐도 알게 했다.
정리
- 쿼리가 빠른데 화면이 느리면 가공 구간을 따로 잰다
- 이름이 가벼운 함수가 외부를 부르고 있을 수 있다
- 반복문에 넣는 판단은 이름을 보고 이뤄지므로 이름에 무거움을 드러낸다
- 함수 이름으로는 못 찾으니
GuzzleHttp\Client나curl_init을 검색한다 - 행마다 부르지 말고 식별자를 모아 한 번에 가져온다
- 상대에 그런 것이 없으면 만들어 달라고 하고 그동안은 병렬로 부른다
- 병렬로 부를 때 동시 개수를 제한해 상대를 밀지 않는다
- 필수가 아닌 값은 실패해도 나머지가 나오게 한다
timeout이 없으면 상대가 느릴 때 계속 기다린다- 한 요청의 외부 호출 수를 남겨 다시 늘어나는 것을 알아챈다