저장할 때마다 무거운 계산이 돌았다

상품을 저장하면 응답이 4초쯤 걸렸다. INSERT 자체는 빠른데 그 뒤가 오래 걸린다.

Table of contents

저장 뒤에 붙은 것들

저장 처리를 봤다.

public function save($data)
{
    $this->db->insert('product', $data);
    $no = $this->db->insert_id();

    $this->makeThumbnails($no);        // 이미지 4종 생성
    $this->updateSearchIndex($no);     // 검색용 자료 갱신
    $this->notifySubscribers($no);     // 관심 등록자에게 알림
    $this->recalcCategoryCount();      // 분류별 개수 재계산

    return $no;
}

저장은 한 줄이고 그 뒤에 네 가지가 붙어 있다. microtime 으로 각각을 재 봤다.

insert               0.02초
makeThumbnails       2.10초
updateSearchIndex    0.35초
notifySubscribers    1.40초
recalcCategoryCount  0.20초

makeThumbnails 와 notifySubscribers 가 대부분이다. 어디가 오래 걸리는지는 재 보기 전에는 짐작일 뿐이었다.

응답에 필요한지 갈랐다

네 가지 중 화면이 돌아가려면 무엇이 끝나야 하는지 봤다.

makeThumbnails 는 애매했는데 저장하고 목록으로 가면 그림이 있어야 하기 때문이다.

화면을 쓰는 쪽에 물어보니 잠깐 기본 이미지가 보여도 된다고 해서 makeThumbnails 도 큐로 뺐다.

큐로 뺐다

응답에 필요 없는 것을 queue->push 로 큐에 넣었다.

public function save($data)
{
    $this->db->insert('product', $data);
    $no = $this->db->insert_id();

    $this->queue->push('product.thumb',  ['product_no' => $no]);
    $this->queue->push('product.index',  ['product_no' => $no]);
    $this->queue->push('product.notify', ['product_no' => $no]);
    $this->queue->push('category.count', []);

    return $no;
}

insert 와 네 번의 push 만 남으니 응답이 0.05초가 됐다.

같은 작업이 여러 번 쌓였다

recalcCategoryCount 가 문제였다. 상품 열 개를 연달아 저장하면 큐에 열 개가 쌓이는데 결과는 다 같다. LLEN 으로 보니 같은 작업이 줄줄이 들어 있었다.

if (!$this->redis->exists('queue:pending:category.count')) {
    $this->queue->push('category.count', []);
    $this->redis->setex('queue:pending:category.count', 300, 1);
}

exists 로 봐서 이미 대기 중이면 안 넣는다. SET ... NX 로 걸면 이미 있을 때 실패가 돌아오므로 exists 와 setex 를 한 번에 할 수도 있다.

처리기가 꺼낼 때 DEL 로 이 표시를 지운다. 그 사이에 들어온 요청은 하나로 묶인다.

검증 — 순서와 실패와 지연

makeThumbnails 가 끝나기 전에 updateSearchIndex 가 돌면 이미지 경로가 빈다. 큐가 하나여도 처리기가 여럿이면 뒤엣것이 먼저 끝날 수 있어서 순서가 보장되지 않는다.

$this->queue->push('product.postprocess', ['product_no' => $no]);

// 처리기
$this->makeThumbnails($no);
$this->updateSearchIndex($no);
$this->notifySubscribers($no);

순서가 있는 것은 product.postprocess 하나에 두고 무관한 것만 따로 뺐다. 나누는 것 자체가 목적이 아니다.

응답이 이미 나간 뒤에 실패하면 사용자는 모르므로 작업별로 실패 처리도 정했다.

실패해도 다음에 회복되는 것과 회복 안 되는 것을 갈랐다. 회복되는 것은 재시도를 덜 해도 된다.

큐로 빼면 응답은 빨라지지만 실제 처리는 미뤄지므로 얼마나 밀리는지도 재야 했다.

$delay = time() - $job['at'];
log_message('info', "[{$job['type']}] 지연 {$delay}초");

넣은 시각을 페이로드에 담고 처리 시작 시각과의 차이를 남긴다. delay 가 평소 1~3초이고 피크에 20초까지 갔는데 썸네일이 목록에 나오기까지 20초면 사용자가 알아챈다. 처리기를 두 개로 늘려서 5초 아래로 줄였다.

정리

• microtime 으로 각각 재 보면 어디가 오래 걸리는지 나온다
• 응답에 필요한 것과 아닌 것을 가르고 애매하면 화면을 쓰는 쪽에 물어본다
• 필요 없는 것을 큐로 빼면 응답이 0.05초가 된다
• 같은 작업이 쌓이면 대기 표시로 중복을 막는다
• 처리가 시작되면 DEL 로 그 표시를 지운다
• 처리기가 여럿이면 순서가 안 지켜지니 순서 있는 것은 한 작업에 둔다
• 나누는 것 자체가 목적이 아니다
• 실패했을 때 다음에 회복되는지로 재시도 정책을 가른다
• 넣은 시각을 담아 처리까지의 지연을 재고 알아챌 수준인지 본다