Multi-container app의 Bad Gateway(502) 문제 디버깅

Intel Training and Learning Suite(TLS)는 처음으로 경험해보는 multi-container application이다. 중간에 native개발을 위한 환경 설정을 끼워 넣어 보려고 이것 저것 시도하는 중에 web interface를 담당하는 tls_proxy라는 docker가 Bad Gateway를 띄우면서 문제가 생겼다. 디버깅 하는 과정에서 사용해 본 docker-compose명령어 들의 쓰임새가 유용할 것 같아서 기록으로 남겨 둔다.

Port number와 docker찾기: docker-compose ps

Web browser로 서비스에 접근하면(https://localhost) Bad Gateway(502) error가 발생하는데 처음으로 web-browser의 접속 요청을 받아서 처리하는 docker container는 docker-compose ps 명령어로 docker image별로 listening하는 port number들을 찾을 수 있다.

TLS의 경우는 tls_proxy가 http요청 처리를 위한 80번과 https를 위한 443번 port를 listening하고 있다.

$ docker-compose ps
    Name                  Command               State     Ports                     
------------------------------------------------------------------
tls_apiui      ./webservices/start.sh           Exit 0                                                                                                                                                     
tls_core       ./start.sh                       Up                                                                                                                                                         
tls_mongo      docker-entrypoint.sh --tls ...   Up       127.0.0.1:27017->27017/tcp                                                                                                                        
tls_openvino   /bin/bash                        Exit 0                                                                                                                                                     
tls_proxy      /docker-entrypoint.sh /bin ...   Up       0.0.0.0:443->443/tcp,:::443->443/tcp, 80/tcp                                                                                                      
tls_rabbitmq   docker-entrypoint.sh /init ...   Up       0.0.0.0:15672->15672/tcp,:::15672->15672/tcp, 15691/tcp, 15692/tcp, 0.0.0.0:1883->1883/tcp,:::1883->1883/tcp, 25672/tcp, 4369/tcp, 5671/tcp, 5672/tcp, 0.0.0.0:8883->8883/tcp,:::8883->8883/tcp
tls_redis      docker-entrypoint.sh sh st ...   Up       127.0.0.1:6379->6379/tcp

Docker의 log 보기: docker logs tls_proxy

tls_proxy가 요청을 처리하지 못한 이유는 docker logs <서버 이름>으로 확인할 수 있다.

$ docker logs tls_proxy
2023/05/31 01:31:06 [error] 12#12: *5 connect() failed (113: Host is unreachable) while connecting to upstream, client: 172.31.0.1, server: , request: "GET / HTTP/1.1", upstream: "http://172.31.0.8:3000/", host: "localhost"
...

사설 네트워크인 172.31.0.x로 docker service들을 구성했는데, 그중 인터페이스를 담당하는 172.31.0.1 docker가 172.31.0.8에 요청을 연결해 주어야 하는데 이 부분에서 오류가 나고 있는 모양이다.

Docker network 확인: docker network ls

현재 docker용으로 구성되어 있는 network을 확인해 보면 다음과 같다.

$ docker network ls
NETWORK ID     NAME                DRIVER    SCOPE
d15b28e7a1d5   bridge              bridge    local
acc99b5947d1   cvat_cvat           bridge    local
4485972f8274   host                host      local
6f21c18ba66f   none                null      local
20d132ccfc2a   tls_default         bridge    local

각 네트워크의 구성을 검사(inspect)해 볼 수 있는데 docker network inspect cvat_cvat명령어로 해당 네트워크를 검사해 보면 다음과 같이 위에서 오류가 발생했던 ip인 172.21.0.8번(tls_openvino)이 등록되지 않은 것을 볼 수 있다.

$ docker network inspect cvat_cvat|grep "Name\|IPv4Address"
        "Name": "cvat_cvat",
                "Name": "cvat_redis",
                "IPv4Address": "172.31.0.4/16",
                "Name": "cvat_opa",
                "IPv4Address": "172.31.0.3/16",
                "Name": "cvat_db",
                "IPv4Address": "172.31.0.5/16",
                "Name": "traefik",
                "IPv4Address": "172.31.0.2/16",
                "Name": "cvat",
                "IPv4Address": "172.31.0.6/16",
                "Name": "cvat_ui",
                "IPv4Address": "172.31.0.7/16",
                "Name": "tls_proxy",
                "IPv4Address": "172.31.0.9/16",

Docker의 log 보기: docker logs tls_openvino

문제가 되고 있는 docker container를 특정했으니 docker logs tls_openvino명령어로 다시 한번 해당 container의 로그를 확인해 본다.

error: A hook (`userconfig`) failed to load!
error: Failed to lift app: Error: Attempted to `require('/home/tls/webservices/apiserver/config/env/production.js')`, but an error occurred:
--
Error: ENOENT: no such file or directory, open '../../thirdparty/security/ca/ca_certificate.pem'
    at Object.openSync (fs.js:498:3)
    at Object.readFileSync (fs.js:394:35)
    at Object.<anonymous> (/home/tls/webservices/apiserver/config/env/production.js:70:15)

../../third party/security/ca/ca_certificate.pem파일을 읽지 못해서 오류가 발생했다고 나오는데, 실제로 container에서는 해당 파일의 위치를 상대 경로로 접근하지 않는다. Call stack에 나와 있는 production.js line 70근처의 내용을 보면 먼저 절대경로인 /run/secrets/*에 접근을 시도할 때 예외가 발생해서 상대 경로로 접근을 시도하고(개발용 코드로 추정) 이 마저도 실패한 것이 로그에 나온 것이다.

apiserver/config/env/production.js

try {
  tls_ca = fs.readFileSync("/run/secrets/ca_tls")
  tls_server_cert = fs.readFileSync("/run/secrets/tlsserver_cert")
  tls_server_key = fs.readFileSync("/run/secrets/tlsserver_key")
} catch (err) {
  tls_ca = fs.readFileSync("../../thirdparty/security/ca/ca_certificate.pem");
  tls_server_cert = fs.readFileSync("../../thirdparty/security/TLS_server_cert.crt");
  tls_server_key = fs.readFileSync("../../thirdparty/security/TLS_server_key.pem");
}

정리하자면, 문제는 server secret을 생성하는 과정에서 발생한 것이 docker image상의 key file path read에서 오류를 발생시키고 tls_openvino container가 제대로 뜨지 못한 문제이다.

해결(?)

문제의 원인은 생각보다 싱거웠는데, docker-compose 명령어를 실행시키는 native용 script에서 다음 줄을 연결하기 위한 \를 빼먹는 사소한(!) Bash 문법 오류가 발생 했었고, 이 오류가 무시된 채로 docker-compose build 명령어가 계속 수행되어 service가 up되는 상황까지 된 것이었다.

-       && pip install -U pip wheel setuptools
+       && pip install -U pip wheel setuptools \
        && pip install \

위의 수정과 함께 오류가 생기면 build를 멈추도록 set -e를 bash script에 추가 하는 것으로 이 문제는 일단락 되었다.