AWS X-Ray 적용기

21 min readMar 22, 2018

제로웹에서는 서비스를 개발하고 운용하는데에 아마존 웹 서비스를 적극적으로 사용하고 있습니다. 제로웹 기술 블로그의 첫번째 글로 제로웹에서 운영 중인 API의 성능 개선을 위한 추적 도구로서 AWS X-Ray 를 적용한 경험을 공유합니다.

AWS X-Ray

AWS X-Ray 는 2016년 AWS re:Invent 행사에서 공개된 분산 어플리케이션 추적 도구이고, 2017년 4월부터 AWS 서울 리전(ap-northeast-2)에서도 사용할 수 있습니다. 분산 어플리케이션 추적 도구가 하는 일을 간단히 요약하면 다음과 같습니다:

수집: 개별 요청의 시작과 끝에 걸친 수행 흐름에 따라 / 내부 혹은 외부로의 연계된 요청이 얼마나 발생하는지 / 내/외부로의 각 요청 구간의 수행 시간은 얼마나 걸렸는지 수집
조회: 수집된 기록을 개별 요청 건별로 / 요청간 관계에 따라 / 조회 결과 반환 및 시각화

OpenTracing 과 Zipkin 에 대해 아시는 분이라면 그것의 아마존 웹 서비스 버전이라고 생각하시면 됩니다. 분산 어플리케이션 추적에 대한 복잡한 설명은 Google Dapper 논문 링크로 대체합니다.

마이크로 서비스 아키텍쳐가 트렌드인 요즘, 대부분의 서비스의 구성은 여러 컴포넌트의 유기적 결합으로 작은 규모에서도 서비스의 호출 경로를 명확하게 추적하고 문제를 진단하기 어려워졌습니다. 마이크로 서비스 아키텍쳐로 서비스를 운영하지 않고 있더라도, 어플리케이션 서버에서 하나의 요청을 처리하는데에 데이터베이스, 캐시 스토리지, 데이터 파이프라인 등으로의 호출이 잦아져 점점 더 어플리케이션 서버의 로그와 Slow SQL 쿼리 로그만으로는 성능 상의 문제가 생겼을 때 병목을 찾아 개선하기가 어려운 경험을 해보신 분들이 많으리라 생각합니다. AWS X-Ray 를 비롯한 분산 어플리케이션 추적 도구는 매 호출에 대해 상세한 수행 시간 정보 및 메타 정보를 기록할 수 있고, 위와 같이 명료한 시각화 도구를 제공하기 때문에 성능 문제에 대한 빠른 진단을 가능하게 합니다.

AWS X-Ray SDK 적용하기

어플리케이션을 AWS X-Ray 에서 추적하려면 AWS X-Ray 로 트레이스를 전송해야 합니다. 다행히 아마존 웹 서비스에서 여러 프로그래밍 언어의 서비스에 쉽게 적용할 수 있는 SDK 구현체를 제공하고 있습니다.

Python — https://github.com/aws/aws-xray-sdk-python
Ruby — https://github.com/aws/aws-xray-sdk-ruby
.NET — https://github.com/aws/aws-xray-sdk-dotnet
Java — https://github.com/aws/aws-xray-sdk-java
Node.js — https://github.com/aws/aws-xray-sdk-node
Go — https://github.com/aws/aws-xray-sdk-go

이 글에서는 Python SDK와 Flask를 기준으로 작성합니다. 우선 aws-xray-sdk-python 라이브러리를 설치합니다.

(venv) $ pip install aws-xray-sdk

이제 SDK를 Flask 어플리케이션과 연동하는 것은 꽤 간단합니다. service 와 dynamic_naming 인자로는 각자 적당한 값을 입력해주면 됩니다. 차후 이 이름으로 AWS X-Ray 에서 개별 서비스 컴포넌트를 식별하게 됩니다.

from aws_xray_sdk.core import xray_recorder
from aws_xray_sdk.ext.flask.middleware import XRayMiddlewareapp = Flask(__name__)
xray_recorder.configure(
    daemon_address='127.0.0.1:3000',
    service='zeroweb-sample',
    dynamic_naming='*zeroweb.kr')
XRayMiddleWare(app, xray_recorder)

이것만으로도 AWS X-Ray를 사용하기 위해 해야 할 코드 작업은 모두 끝났습니다! 이제 AWS X-Ray로 데이터를 송신하고 확인해볼 차례입니다.

AWS X-Ray Daemon 설치하기

앞서 Flask 어플리케이션에 X-Ray SDK 를 연동할 때, xray_recorder.configure() 함수의 호출 인자 daemon_address 값으로 127.0.0.1:3000 이 적혀있는 것을 보셨을 겁니다. 어플리케이션 서버에서 X-Ray로 보낼 트레이스 세그먼트 데이터의 양이 많을 수 있고, X-Ray로의 데이터 전송 API 프로토콜은 HTTPS 이기 때문에 매 어플리케이션 요청마다 X-Ray로 데이터를 보낸다면 외부로의 연결이 잦아져 성능상의 단점이 생길 수 있습니다. 이를 보완하기 위해 AWS X-Ray 에서는 UDP 로 데이터를 받고, 일정 주기로 모여진 데이터를 X-Ray로 전송해주는 X-Ray 데몬 프로세스를 제공하고 있습니다. xray_recorder.configure() 함수의 호출 인자 daemon_address 는 X-Ray 데몬의 주소가 됩니다. 그럼 이제 X-Ray 데몬을 설치하고 실행해보겠습니다. 먼저 X-Ray 데몬 다운로드 페이지에서 설치 파일을 내려받습니다. Ubuntu 에서 작업 중인 저는 Linux (DEB) 파일을 내려받고 설치합니다.

$ wget https://s3.dualstack.ap-northeast-2.amazonaws.com/aws-xray-assets.ap-northeast-2/xray-daemon/aws-xray-daemon-2.x.deb
...
$ sudo dpkg -i aws-xray-daemon-2.x.deb

이제 xray 를 실행합니다. 시스템 서비스로 등록이 되어 자동으로 설치가 되어있을 수도 있습니다. 이 경우 잘 켜졌는지 확인하기 위해 service xray status 등의 명령 수행 결과와 /var/log/xray/xray.log 로그를 확인해봅시다. 이 때, 아래와 같이 Unabled to retrieve the region from the EC2 instance 라는 에러 메시지가 나오면서 데몬이 실행이 되지 않을 수 있습니다. AWS EC2 인스턴스에서 데몬이 실행 중이라면 EC2 Metadata API 를 통해 구동 중인 AWS 리전 정보를 판단할 수 있지만, 지금은 제 컴퓨터에서 실행 중이니 오류가 발생합니다. --local-mode 옵션을 지정하고, 리전은 --region 옵션 혹은 AWS_REGION 환경 변수를 통해 수동으로 지정해 실행합니다. 리전 정보와 인증 크리덴셜 정보가 ~/.aws/ 디렉토리 하위 설정 또는 환경 변수를 통해 설정되어 있다면, 이제 Flask 어플리케이션을 켜고 브라우저에서 접속해보세요. X-Ray 데몬에서도 세그먼트를 전송했다는 로그를 볼 수 있습니다.

$ xray
2018-03-21T17:38:45+09:00 [Info] Initializing AWS X-Ray daemon 2.1.0
2018-03-21T17:38:45+09:00 [Info] Using buffer memory limit of 157 MB
2018-03-21T17:38:45+09:00 [Info] 2512 segment buffers allocated
2018-03-21T17:38:45+09:00 [Error] Cannot fetch region variable from config file, environment variables and ec2 metadata.$ AWS_REGION=ap-northeast-2 xray --local-mode
2018-03-21T17:40:20+09:00 [Info] Initializing AWS X-Ray daemon 2.1.0
2018-03-21T17:40:20+09:00 [Info] Using buffer memory limit of 157 MB
2018-03-21T17:40:20+09:00 [Info] 2512 segment buffers allocated
2018-03-21T17:40:20+09:00 [Info] Using region: ap-northeast-2
2018-03-21T17:41:37+09:00 [Info] Successfully sent batch of 1 segments (0.306 seconds)
2018-03-21T17:41:38+09:00 [Info] Successfully sent batch of 1 segments (0.025 seconds)
2018-03-21T17:41:42+09:00 [Info] Successfully sent batch of 1 segments (0.013 seconds)

이제 AWS 웹 콘솔의 X-Ray 화면으로 가봅니다. Traces 메뉴에 진입하면 조금 전 로컬에서 보낸 트레이스 세그먼트 데이터를 확인할 수 있습니다.

하단의 Trace list 중 하나의 ID 를 클릭해 들어가면, 개별 요청에 대해서 조회할 수도 있습니다.

Custom Segment Annotation 입력하기

@app.route('/user/<user_id>')
def get_user(user_id):
    user = db.find_user(user_id)
    return jsonify(
        user_id=user.id,
        user_name=user.name,
)

위와 같이 URL 로부터 사용자의 ID 를 입력받아 응답을 반환하는 API 가 있다고 해봅시다. 가능한 URL 의 경우의 수는 (유효한 URL만 세더라도) 사용자의 수만큼이 됩니다. URL 쿼리스트링 인자로 ?extra_informations=written_post 따위의 것을 입력하면 추가적인 데이터를 응답에 포함하게 만들었을 수도 있습니다. 가능한 URL의 경우의 수는 더욱 늘어날테고, 이제 AWS X-Ray 에서 URL 을 가지고 특정한 기능에 대한 통계를 유의미하게 보기 어려워집니다.

우선 한가지 방법은 CONTAINS 연산자를 이용해 질의를 하는 것입니다. 적어도 사용자를 조회하는 GET /user/<user_id> API에 대한 요청은 묶어낼 수가 있습니다. 하지만 ?extra_informations=FLAG_A,FLAG_B,FLAG_C&option_2=OPTION_X 와 같이 추가적인 가변 인자가 복잡한 경우의 수를 지니고 있는 경우라면 어떻게 할까요? 기존 구현이 에러 상황에 대해 응답 본문에만 에러 정보를 추가하고, HTTP 응답 코드는 200 을 그대로 사용하고 있다면 오류가 발생한 트레이스 목록을 어떻게 구별해낼 수 있을까요? 서비스를 운영하다보면 관리자를 위한 기능들이 생기는 경우도 많습니다 — 로직과 성능에도 차이를 보일 수 있기 때문에, 관리자 사용자의 요청과 일반 사용자의 요청을 구분해 추적해보려면 어떤 방법이 있을까요? 어쩌면, API의 종류에 무관하게 특정 사용자의 성능 기록만 추려 보고 싶을 수도 있겠군요.

AWS X-Ray 의 어노테이션(Annotation) 기능은 이 때에 사용할 수 있습니다. 어플리케이션 특화된 임의의 정보를 개발자가 트레이스마다 기입해둘 수가 있고, 어노테이션 키와 값들은 차후 X-Ray 콘솔에서 트레이스 필터링에 활용할 수가 있습니다. Flask의 Blueprint 이름과 View Function 이름에 해당하는 Endpoint 이름을 어노테이션으로 지정해보도록 하겠습니다.

@app.before_request
def set_xray_annotations():
    segment = xray_recorder.current_segment()
    segment.put_annotation('blueprint', request.blueprint or '')
    segment.put_annotation('endpoint', request.endpoint or '')

주의할 점은 XRayMiddleware(app, xray_recorder) 가 호출되어 X-Ray SDK 가 Flask 어플리케이션 객체에 설치된 이후에 app.before_request 가 호출되어야 하는 것입니다. 순서가 뒤바뀌면 set_xray_annotations() 함수 안의 xray_recorder.current_segment() 가 현재 트레이스 세그먼트를 찾지 못하게 됩니다.

이제 Group by 필터링 드롭 박스의 선택지에 Annotation.endpoint 가 생겼습니다. 이제 서비스 기능별로 트레이스를 추적할 수 있습니다. Annotation.endpoint = “get_user” 와 같이 질의문을 작성하는 것도 가능합니다. 서버를 실행 중인 장비의 hostname 이나, 사용자의 ID 를 어노테이션으로 추가하는 것도 같은 방법으로 수행할 수 있습니다.

AWS Lambda 호출 추적하기

AWS Lambda는 컴퓨팅 자원에 대한 운영과 관리 부담 없이, 소스 코드를 AWS Lambda 함수로 업로드하는 것만으로 여러 워크로드에서 기능을 수행할 수 있게 해주는 아마존 웹 서비스의 제품입니다. 저희 어플리케이션 서버에서는 AWS SDK for Python 인 boto3 라이브러리를 통해 원격 AWS Lambda 함수를 실행하는 부분이 있습니다. 사용자의 요청을 처리하는 과정에 AWS Lambda 실행 구간이 포함된다면, 당연히 X-Ray 의 트레이스에도 해당 내용이 보여져야겠죠. 이를 위해서는 다음의 내용이 충족되어야 합니다:

AWS Lambda 함수를 실행할 때, 현재의 요청과 Lambda 로의 요청이 연계될 수 있도록 Trace ID 등의 정보가 전파되어야 함
AWS Lambda 함수 실행 구간 및 내부의 구간이 X-Ray 로 집계될 수 있어야 함

AWS X-Ray SDK 는 1. 에 대한 기능을 제공하고 있습니다. xray_patch([‘boto3’]) 를 실행해주는 것만으로 boto3 를 사용한 외부 AWS 컴포넌트로의 요청에는 모두 X-Ray 추적용 헤더가 첨부됩니다.

AWS Lambda 가 X-Ray 로 집계되도록 하는 것에는 별다른 작업이 필요하지 않습니다. AWS Lambda 관리 콘솔에 들어가, 추적을 원하는 함수 설정 페이지에서 Active tracing 을 체크하기만 하면 됩니다.

이제 X-Ray 에서 Lambda 로의 호출이 있는 트레이스를 확인해보면, Flask 어플리케이션 구간의 세그먼트와 Lambda 함수 실행 구간의 세그먼트가 하나의 트레이스로서 연결되어 있는 것을 볼 수 있습니다.

Lambda-Function-1에 대한 구간 그룹이 2개로 보여지는 이유는, Lambda 로의 호출이 비동기 방식일 수 있기 때문입니다. 위 예시는 비동기 호출을 한 경우인데, 이 경우 Lambda 함수의 실행 결과는 호출자에게 전달되지 않고, 가능한 빨리 HTTP 202 Accepted 응답 코드만 전달이 됩니다. 이러한 이유로 Lambda 함수의 호출을 맞이하는 API 프론트 구간과 Lambda 함수가 실행되는 구간이 서로 다른 세그먼트로 집계됩니다.

트레이스 뿐만 아니라, X-Ray 콘솔의 Service map 메뉴로 가면 이제 개별 컴포넌트간의 시각화된 호출 통계도 확인할 수가 있습니다. Flask 어플리케이션과 AWS Lambda 뿐만 아니라 새로운 세그먼트 구간이 추가될 때마다 모두 여기에서 확인할 수가 있습니다.

SQLAlchemy 데이터베이스 쿼리 추적하기

RDBMS 를 사용하는 서비스에서 주로 성능 발목을 잡는 부분은 잦은 데이터베이스 연결과 비효율적인 데이터베이스 쿼리 수행 속도입니다. 일반적으로 성능 개선 프로젝트의 시작점이라고 할 수 있습니다.

Python에서 RDBMS 를 다룰 때 주로 사용하는 ORM 프레임워크는 SQLAlchemy 입니다. SQLAlchemy 를 거치는 데이터베이스 호출을 추적해보도록 하겠습니다. 우선 추적을 위해 데이터베이스 호출의 ‘시작’과 ‘끝’에 무언가 우리가 원하는 실행 구문을 주입(Inject)해야 합니다. 앞서 Flask 어플리케이션의 before_request 핸들러를 통해 어노테이션을 추가한 것과 같이 말입니다. SQLAlchemy 에도 여러 이벤트에 대해 즉각 전파를 받을 수 있도록 하는 기능을 가지고 있습니다. SQLAlchemy 엔진의 실행 전(before_execute)과 실행 후(after_execute) 이벤트를 구독하면 우리가 원하는 구간을 추려낼 수 있어 보입니다.

import tracebackengine = create_engine(uri, **engine_options)@event.listens_for(engine, 'before_execute')
def before_execute(
        conn, clauseelement, multiparams, params):
    segment_name = 'db::engine.execute()'
    if not isinstance(clauseelement, str):
        segment_name = \
            'db::' + type(clauseelement).__name__.upper()
    subsegment = xray_recorder.begin_subsegment(
        segment_name, namespace='remote')@event.listens_for(engine, 'after_execute')
def after_execute(
        conn, clauseelement, multiparams, params, result):
    xray_recorder.end_subsegment()@event.listens_for(engine, 'handle_error')
def handle_error(exception_context):
    subsegment = xray_recorder.current_subsegment()
    stack = traceback.extract_stack(
        limit=xray_recorder._max_trace_back)
    subsegment.add_exception(
        exception_context.original_exception, stack)

before_execute 이벤트에서는 xray_recorder.begin_subsegment() 로 현재 요청 세그먼트로부터 하위 세그먼트를 만들었습니다. 약간의 트릭을 더해 데이터베이스로의 호출이 SELECT 구문인지, INSERT 구문인지 등을 세그먼트 이름에 추가했습니다. after_execute 이벤트에서는 열려있는 현재 하위 세그먼트를 닫습니다. 간혹 오류가 발생해서 정상적으로 after_execute 이벤트로 진입하지 못하여 하위 세그먼트가 닫히지 않는 문제가 생길 수 있으므로, handle_error 이벤트에 대한 핸들러를 추가로 작성했습니다. 이 때는 subsegment.add_exception() 함수를 통해 발생한 오류의 구체적인 내용을 기록해둘 수도 있습니다.

데이터베이스 쿼리가 두번 발생했습니다. SQLAlchemy 혹은 ORM 을 잘 모르고 사용하는 경우 — relationship property 에 lazy access 가 빈번한 경우 등 — 어떤 페이지에서는 데이터베이스 쿼리가 수십번 발생하는 경우를 발견하실 수도 있습니다. 이제 현재의 상황이 명쾌하게 보이고, 개선의 결과도 눈으로 확인할 수 있으니 편리해졌죠? 개별 트레이스 조회와 서비스 맵의 확인을 함께 활용해 여러모로 서비스 전체 토폴로지 중 병목이 되는 지점을 쉽게 진단할 수 있게 되었습니다.

Custom X-Ray Subsegment 추적하기

외부 서버/API로의 호출만 추적할 수 있는 것은 아닙니다. 데이터베이스 호출을 추적한 방법 그대로, 코드 내 어디서든 하위 세그먼트를 생성하면 모든 코드 내 구간을 구체적으로 추적할 수 있게 됩니다. 조금 전의 예시를 다시 확인해보겠습니다.

마지막 데이터베이스 호출이 끝나는 시간 상의 위치는 5.5ms 지점입니다. 한편 전체 요청 세그먼트가 종료되는 위치는 6.0ms 입니다. 0.5ms 동안 응답 데이터를 JSON 형태로 시리얼라이징한 뒤, 클라이언트로 응답 패킷을 내려보내고, 데이터베이스 세션을 종료하고, 요청 처리에 대한 서버 로그를 파일 혹은 표준 출력으로 출력하기도 했을텐데요. 환경에 따라 0.5ms 가 5ms 가 될 수도 있고, 잦은 0.5ms 가 5ms 보다 성능 상의 약점이 될 수도 있기 때문에, 이번에는 JSON 시리얼라이징을 포함한 응답 데이터의 구성에 얼마나 시간이 소비되는지 추적해보기로 합니다.

import json
from flask import Response@xray_recorder.capture('json_response')
def json_response(**data):
    xray_recorder.begin_subsegment('json_dumps')
    serialized_data = json.dumps(data)
    xray_recorder.end_subsegment()
    xray_recorder.begin_subsegment('construct_Response')
    response = Response(serialized_data)
    response.headers['Content-Type'] = 'application/json'
    xray_recorder.end_subsegment()
    return response@app.route('/api')
def api():
    result = process()
    return json_response({'result': result})

flask.jsonify() 는 충분히 유용하지만 하위 세그먼트를 추적해보기 위해 새로운 함수 json_response() 를 만들었습니다. 함수 내의 구간은 xray_recorder.begin_subsegment() 와 xray_recorder.end_subsegment() 로 추적할 수 있고, 함수 전체 구간은 xray_recorder.capture() 데코레이터 함수를 이용하면 됩니다. 이제 JSON 시리얼라이징 및 HTTP Response 객체를 생성하는 부분이 각각의 하위 세그먼트로서 트레이스에서 보여집니다.