서버마다 다르던 런타임 버전

같은 코드인데 한 대에서만 오류가 났다. 다른 세 대는 멀쩡했다.

Open Table of contents

증상 — 한 대에서만 나던 오류
버전을 전부 찍어 봤다
무엇이 다른지 모아 놓고 봤다
조치 — 런타임을 코드와 같이
대응 — 넘어가는 동안의 혼재
검증 — 밖에서 확인하고 일부러 어긋내기
정리

증상 — 한 대에서만 나던 오류

오류는 이랬다.

PHP Fatal error: Uncaught TypeError: Argument 1 passed to ... must be of the type int, string given

TypeError 가 코드 탓이면 네 대가 다 났을 테니 코드 밖을 봐야 했다.

같은 배포가 나간 네 대 중 하나만 다르게 동작한다면 그 한 대의 환경이 다르다는 뜻이다. 무엇이 다른지부터 찍어 보기로 했다.

버전을 전부 찍어 봤다

네 대의 런타임 판을 한 번에 봤다.

$ for h in web01 web02 web03 web04; do
    echo -n "$h "; ssh $h 'php -v | head -1'
  done
web01 PHP 7.1.20
web02 PHP 7.1.20
web03 PHP 7.2.7
web04 PHP 7.1.20

web03 만 7.2.7 이고 나머지는 7.1.20 인데 언제 올라갔는지는 아무도 몰랐다.

확장 모듈도 봤다.

$ for h in web01 web02 web03 web04; do
    echo -n "$h "; ssh $h 'php -m | md5sum'
  done
web01 3f9a...
web02 3f9a...
web03 c412...
web04 8e77...

web04 는 php -v 는 같은데 php -m 의 해시가 달라서 결국 셋 다 다른 상태였다.

무엇이 다른지 모아 놓고 봤다

한 대씩 붙어서 보면 무엇이 다른지 눈에 안 들어온다.

$ for h in web01 web02 web03 web04; do
    ssh $h 'php -i' > /tmp/phpinfo.$h
  done
$ diff /tmp/phpinfo.web01 /tmp/phpinfo.web03 | head -40

판 말고도 memory_limit 과 date.timezone 과 opcache.validate_timestamps 가 달랐다.

date.timezone 이 다른 대에서 나온 로그는 시각이 아홉 시간 어긋나 있었다. 오류를 찾느라 그 로그를 같이 보고 있었으면 시각 때문에 한참을 더 헤맸을 것이다.

php -i 를 넷 다 받아 diff 를 뜬 것이 이번에 가장 값이 컸다. 무엇이 다른지 모르는 상태에서는 비교가 유일한 방법이다.

조치 — 런타임을 코드와 같이

web03 의 php 를 7.1.20 으로 내려도 다음에 또 어긋난다.

각 서버에 사람이 손으로 설치하고 있었고 설치 시점에 따라 판이 갈렸으므로 손으로 맞추면 언젠가 손으로 다시 어긋난다.

런타임을 코드와 같이 배포되게 바꿨다.

FROM php:7.1-fpm-alpine
RUN docker-php-ext-install pdo_mysql opcache bcmath
COPY php.ini /usr/local/etc/php/conf.d/app.ini
COPY . /app

php:7.1-fpm-alpine 이미지에 모듈과 php.ini 가 다 들어 있으니 어느 대에 올려도 같다.

고칠 것은 타입 오류 한 줄이었지만 그것만 고치면 같은 일이 다른 모양으로 다시 온다. 무엇을 고칠지보다 왜 어긋났는지가 이번 작업의 대상이었다.

대응 — 넘어가는 동안의 혼재

한 번에 다 바꿀 수 없어 두 대는 Docker 로 두 대는 그대로 두는 기간이 생겼다.

header('X-Node: ' . gethostname() . ' php' . PHP_VERSION);

X-Node 헤더에 어느 서버의 어느 판인지를 실어 보냈다.

오류가 나면 X-Node 만 보고 어느 쪽인지 바로 갈린다. 섞여 있는 것 자체는 피할 수 없으니 구분할 수 있게 만드는 것이 현실적인 대응이었다.

검증 — 밖에서 확인하고 일부러 어긋내기

Dockerfile 을 썼다고 네 대가 같아진 것은 아니다.

$ for h in web01 web02 web03 web04; do
    echo -n "$h "; curl -sI http://$h/health | grep -i '^x-node'
  done
web01 X-Node: web01 php7.1.20
web02 X-Node: web02 php7.1.20
web03 X-Node: web03 php7.1.20
web04 X-Node: web04 php7.1.20

curl -sI 로 넷이 같다는 것을 밖에서 물어 확인했다.

docker images 로 태그를 보는 것과는 다르다. 이미지를 갱신하고 컨테이너를 다시 안 띄웠으면 올라간 것과 도는 것이 어긋난다.

다시 어긋나면 걸리는 검사도 붙였다.

#!/bin/sh
ref=""
for h in $HOSTS; do
    v=$(curl -sI "http://$h/health" | awk '/^X-Node/ {print $3}')
    [ -z "$ref" ] && ref="$v"
    if [ "$v" != "$ref" ]; then
        echo "MISMATCH $h=$v ref=$ref"; exit 1
    fi
done
echo "OK $ref"

일부러 한 대를 다른 이미지로 올려서 MISMATCH 가 뜨는지 봤다.

통과만 보고 검사가 작동한다고 판단하면 아무것도 안 보는 검사를 그대로 두게 된다. 걸리는 것을 확인하고 나서야 그 검사를 믿을 수 있었다.

deploy.log 에 배포 기록도 남겼다.

$ cat /srv/deploy.log
2018-04-29T13:02  web01..web04  api:2018.04.29-1  by deploy
2018-04-25T10:41  web03         api:2018.04.25-2  by manual

web03 만 따로 나간 줄이 보여서 언제부터 어긋났는지가 그 한 줄에 남는다.

정리

같은 코드가 한 대에서만 실패하면 런타임 판과 모듈을 먼저 본다
한 대씩 보지 말고 한자리에 모아 비교한다
판 말고 설정도 서버마다 다르다
타임존이 다르면 로그 시각까지 어긋난다
손으로 맞추면 언젠가 손으로 어긋난다
런타임을 코드와 같이 배포되게 바꾼다
무엇을 고칠지보다 왜 어긋났는지가 작업의 대상이다
넘어가는 동안 섞이면 어느 쪽인지 응답에 표시한다
태그가 같은지가 아니라 실제로 도는 것을 밖에서 확인한다
검사를 넣고 일부러 어긋나게 해서 잡는지 본다
손으로 한 배포도 기록에 남기면 언제부터인지 찾을 수 있다