Skip to content
isdnetworks
Go back

버튼이 다시 활성화됐는데 서버는 계속 돌고 있었다

일괄 등록 화면에서 중복 자료가 생긴다는 얘기가 나왔다. 같은 상품이 두 번씩 들어간 건이 며칠 사이 수십 건이었다.

로그를 보니 같은 사용자가 같은 파일을 2분 간격으로 두 번 올렸다.

Table of contents

Open Table of contents

사용자는 실패한 줄 알았다

재현해 봤다. 1,200행짜리 파일을 올린다.

버튼이 "처리 중..." 으로 바뀐다
2분쯤 지나면 버튼이 원래대로 돌아온다
화면에는 아무 메시지도 없다

사용자 입장에서는 실패로 보이므로 같은 파일을 다시 올리게 된다.

그런데 서버는 그때도 계속 처리하고 있었고 화면이 끝났다고 표시하는 것과 서버가 끝난 것은 다른 일이었다.

같은 사람이 두 번 올렸다면 첫 번째가 실패로 보였을 가능성이 크고 그 화면을 먼저 확인한 것이 출발점이었다.

자료가 두 번 INSERT 된 것은 결과이고 왜 두 번 올렸는지가 원인 쪽이었다. 사용자를 탓할 자리가 아니라 화면이 무엇을 말했는지를 볼 자리였다.

accepted 도 실패도 아닌 화면을 보면 누구나 다시 누른다. 그 행동이 이상한 것이 아니라 그렇게 만든 화면이 문제였다.

원인 — 두 층의 시간 제한

브라우저 쪽 코드를 봤다.

$.ajax({
    url: '/product/bulk-upload',
    type: 'POST',
    data: formData,
    timeout: 120000,   // 2분
    ...
});

서버 쪽 설정도 봤다.

; php.ini
max_execution_time = 600
# nginx
fastcgi_read_timeout 600;

클라이언트는 timeout 이 2분이고 서버는 max_execution_time 이 10분이라 짧은 쪽이 먼저 포기한다.

클라이언트가 연결을 끊어도 php-fpm 프로세스는 계속 돈다. 끊김은 출력할 때만 감지되므로 아무것도 안 내보내는 처리는 감지할 자리가 없다.

0:00  요청 시작, 서버 처리 시작
2:00  클라이언트 타임아웃 → 화면은 원래대로
2:30  사용자가 다시 누름 → 두 번째 처리 시작
4:10  첫 번째 처리 완료 (1,200건 등록)
6:40  두 번째 처리 완료 (1,200건 또 등록)

두 처리가 겹쳐 도는 구간이 생기는데 사용자는 한 번 실패하고 한 번 성공했다고 믿는다.

general_log 만 보면 두 요청이 모두 정상으로 끝났다. 어느 줄에도 실패가 없으니 로그만으로는 이상을 못 찾는다.

브라우저 쪽 timeout 과 서버 쪽 처리를 붙여 놓고서야 그림이 맞았다. 한쪽만 보면 이 종류는 안 보인다.

조치 — 접수와 처리의 분리

가장 큰 변경은 요청을 받으면 파일만 저장하고 바로 응답하는 것이었다.

public function bulkUpload()
{
    $file = $this->upload_file();

    $jobId = $this->job_model->create([
        'type'       => 'product_bulk',
        'file_path'  => $file,
        'status'     => 'pending',
        'total'      => 0,
        'processed'  => 0,
        'user_id'    => $this->session->userdata('user_id'),
    ]);

    // 처리는 하지 않고 접수 번호만 돌려준다
    $this->output->set_output(json_encode([
        'job_id' => $jobId,
        'status' => 'accepted',
    ]));
}

create 로 접수 행 하나만 만들고 job_id 를 돌려주며 실제 처리는 별도 프로세스가 pending 을 꺼내서 한다.

화면은 그 번호로 상태를 조회한다.

function pollStatus(jobId) {
    $.get('/job/status/' + jobId, function (res) {
        updateProgress(res.processed, res.total);

        if (res.status === 'done' || res.status === 'failed') {
            showResult(res);
            return;
        }
        setTimeout(function () { pollStatus(jobId); }, 2000);
    });
}

응답이 즉시 오므로 timeout 이 걸릴 일이 없고 processedtotal 로 진행률도 보인다.

기다리는 구조 자체를 없앤 것인데 값만 맞추면 오래 걸리는 작업은 그대로 남는다.

timeoutmax_execution_time 을 맞추는 것도 해야 할 일이다. 다만 그것은 사용자가 10분을 기다리게 만드는 방향이다.

접수와 처리를 나누면 accepted 가 돌아오는 데 2초면 된다. 같은 문제를 두 방향으로 풀 수 있을 때 어느 쪽으로 가느냐가 여기서 갈렸다.

같은 파일은 한 번만 처리하게 했다

접수 단계에서 파일 내용의 해시를 키로 썼다.

$hash = md5_file($file);

$exists = $this->job_model->find_recent([
    'type'      => 'product_bulk',
    'file_hash' => $hash,
    'user_id'   => $userId,
    'since'     => date('Y-m-d H:i:s', time() - 3600),
]);

if ($exists) {
    // 이미 접수된 같은 파일이다
    return $this->respond([
        'job_id' => $exists['id'],
        'status' => 'duplicate',
    ]);
}

같은 사람이 한 시간 안에 같은 파일을 올리면 md5_file 이 같아서 원래 작업의 번호를 돌려준다.

키를 요청마다 새로 만들면 이 방어가 성립하지 않는다. 파일 내용에서 결정적으로 나오는 값이어야 한다.

요청 시각이나 난수로 file_hash 를 만들면 두 요청이 언제나 다른 값을 낸다. 그러면 중복 검사가 늘 통과하고 방어가 아무것도 안 한다.

같은 파일에서 같은 md5_file 이 나오는 것이 이 장치의 조건이었다. 그 조건을 안 지키면 코드는 있는데 효과가 없다.

화면이 침묵하지 않게 했다

타임아웃이 나더라도 사용자에게 알리게 했다.

error: function (xhr, status) {
    if (status === 'timeout') {
        alert('처리가 오래 걸리고 있습니다. 목록 화면에서 결과를 확인해 주세요. 다시 올리지 마세요.');
        return;
    }
    alert('오류가 발생했습니다: ' + status);
}

statustimeout 이면 무엇이 일어났고 무엇을 하면 되는지를 적어 보여 주는데 임시 조치가 먼저 나갔다.

그것만으로도 중복 신고가 줄었는데 화면이 침묵하는 것과 오래 걸린다고 말하는 것의 차이가 컸다.

판단 기준 — 짧은 쪽이 실제 상한

이 일 뒤로 새 기능을 만들 때 시간 제한을 목록으로 적어 둔다.

브라우저 ajax timeout   120초
nginx  fastcgi_read     600초
PHP    max_execution    600초
DB     wait_timeout     28800초

가장 짧은 것이 실제로 기다릴 수 있는 시간이고 그보다 오래 걸릴 것 같으면 동기 요청으로 안 만든다.

반대 방향의 실수도 있는데 클라이언트 timeout 을 10분으로 늘리는 것이다.

그러면 브라우저 탭 하나가 10분을 붙잡고 중간에 망이 한 번 끊기면 처음부터 다시다.

기다리게 만드는 것이 아니라 기다리지 않아도 되게 만드는 쪽이 맞고 값을 늘리는 것은 해법이 아니다.

정리


Share this post on:

Previous Post
요청 밖으로 뺀 무거운 계산
Next Post
나가는 길과 돌아오는 길