Elastic APM Go 에이전트를 사용하여 Go 어플리케이션을 어떻게 계측합니까
Elastic APM(어플리케이션 성능 모니터링)은 분산 작업 부하에 대해 어플리케이션 성능과 가시성을 잘 파악할 수 있도록 도와줍니다. 이는 Go, Java, Ruby, Python, JavaScript(Node.js 및 브라우저를 위한 Real User Monitoring(RUM)) 등 수많은 언어를 공식적으로 지원하여 수행됩니다.
이러한 성능을 파악하려면 어플리케이션을 반드시 계측해야 합니다. 계측은 동작을 측정하기 위해 어플리케이션 코드를 변경하는 작업입니다. 일부 지원하는 언어의 경우 에이전트만 설치하면 됩니다. 예를 들어, Java 애플리케이션은 간단한 ‑javaagent 플래그를 사용하여 자동으로 계측합니다. 이는, 바이트코드 계측을 사용합니다. 이것은 컴파일된 Java 바이트 코드를 조작하는 프로세스로서, 일반적으로 Java 클래스는 프로그램이 시작할 때 로드됩니다. 이에 더하여, 상관 관계 연산에 스레드 로컬 스토리지를 사용하도록 싱글 스레드로 시작부터 끝까지 제어하는 것이 일반적입니다.
대체적으로, Go 프로그램은 네이티브 머신 코드로 컴파일되므로, 자동화 계측에 아주 적합하지는 않습니다. 또한, Go 프로그램의 스레딩 모델은 대부분의 다른 언어와 다릅니다. Go 프로그램의 경우, 코드를 실행하는 “goroutine”은 운영 체제 스레드 사이에서 이동할 수 있으며, 논리 연산은 종종 여러 개의 goroutine을 발생시킵니다. 그러면 Go 어플리케이션은 어떻게 계측합니까?
이 글에서는 Elastic APM을 사용하여 Go 어플리케이션 측정 방법을 살펴 보고, 계측 가능성의 3대 요소인 응답 시간 성능 정밀 데이터(추적) 분석, 인프라와 어플리케이션 지표 분석 및 로깅과의 통합을 이루고자 합니다. 본문 전반에서 어플리케이션과 계측을 전개하며 다음 주제를 차례로 다루겠습니다.
웹 요청 추적
Elastic APM Go 에이전트는 “추적” 연산용 API를 제공합니다. 예를 들어, 서버에 대한 인커밍 요청입니다. 연산 추적에는 연산을 설명하는 이벤트 기록이 포함됩니다. 예를 들어, 연산 이름, 타입/범주 그리고 소스 IP, 인증된 사용자 등과 같은 일부 속성입니다. 이 작업에서는 연산이 시작된 시간과 소요 시간, 연산 계보를 설명하는 식별자도 기록합니다.
Elastic APM Go 에이전트는 다양한 웹 프레임워크, RPC 프레임워크, 데이터베이스 드라이버를 계측하고 몇 개의 로깅 프레임워크를 통합하는 수많은 모듈을 공급합니다. 지원하는 기술의 전체 목록을 확인합니다.
gorilla/mux 라우터를 사용하여 간단한 웹 서비스에 Elastic APM 계측을 추가합니다. 그리고, Elastic APM을 통해 성능을 획득하려면 어떻게 할 것인지 확인합니다.
다음은 원본이며, 계측하지 않은 코드입니다.
package main
import (
"fmt"
"log"
"net/http"
"github.com/gorilla/mux"
)
func helloHandler(w http.ResponseWriter, req *http.Request) {
fmt.Fprintf(w, "Hello, %s!\n", mux.Vars(req)["name"])
}
func main() {
r := mux.NewRouter()
r.HandleFunc("/hello/{name}", helloHandler)
log.Fatal(http.ListenAndServe(":8000", r))
}
gorilla/mux 라우터가 제공하는 요청을 계측하려면, 미들웨어 지원을 통해 최신 버전의 gorilla/mux(v1.6.1 이후)를 사용해야 합니다. 그 후, go.elastic.co/apm/module/apmgorilla 임포트를 수행하고, 다음의 코드 라인만 추가하면 됩니다.
r.Use(apmgorilla.Middleware())
apmgorilla 미들웨어는 각 요청을 APM Server에 트랜잭션으로 보고합니다. 잠시 계측을 중지하는 시간을 갖고, APM UI에서 어떤 모습인지 살펴 봅니다.
성능 시각화
웹 서비스 계측을 수행했습니다. 그러나, 데이터를 전송할 곳이 없습니다. APM 에이전트는 기본값으로 APM Server에 데이터 전송을 시도합니다(http://localhost:8200). 최근 릴리스된 Elastic Stack 7.0.0을 사용하여 새로운 스택을 설정합니다. 스택의 기본값 배포를 무료로 다운로드 할 수 있습니다. 또는, Elastic Cloud에서 14일의 Elasticsearch Service 무료 평가판을 시작할 수 있습니다. 독자적으로 실행하는 것을 선호하는 경우, https://github.com/elastic/stack-docker에서 사례가 되는 Docker Compose 구성을 찾을 수 있습니다.
일단 스택 설정이 완료되면, 어플리케이션을 구성하여 APM Server로 데이터를 전송할 수 있습니다. APM Server의 URL 및 비밀 토큰을 알고 있어야 합니다. 이는, Elastic Cloud를 사용하는 경우, 배포 도중 “Activity” 페이지에서 그리고 배포 완료 후에는 “APM” 페이지에서 확인할 수 있습니다. 배포 도중, Elasticsearch 및 Kibana를 위한 암호를 기록해 놓아야 합니다. 그 이후에는 이를 다시 볼 수 없기 때문입니다(필요한 경우 재설정은 가능합니다).
환경 변수를 사용하여 APM Go 에이전트를 구성합니다. APM Server URL 및 비밀 토큰을 구성하려면, 다음의 환경 변수를 익스포트하여 사용자 어플리케이션에서 볼 수 있도록 합니다
export ELASTIC_APM_SERVER_URL=https://bdf8658ddda74d47af1875242c3ef203.apm.europe-west1.gcp.cloud.es.io:443 export ELASTIC_APM_SECRET_TOKEN=H9U312SRGzbG7M0Yp6
이제, 계측한 프로그램을 실행하면, 곧 APM UI에서 일부 데이터를 볼 수 있습니다. 에이전트는 지표를 주기적으로 전송합니다. 이는 CPU 및 메모리 사용, Go 런타임 통계 등입니다. 언제라도 요청이 제공되면, 에이전트는 트랜잭션 기록도 합니다. 이는 버퍼링되어 기본값 10초에 따라 배치 단위로 전송됩니다. 따라서, 서비스를 실행하고, 일부 요청을 전송하여 결과를 확인합니다.
해당 이벤트가 APM Server에 성공적으로 전송되는지 확인하려면, 추가 환경 변수를 몇 개 설정하면 됩니다.
export ELASTIC_APM_LOG_FILE=stderr export ELASTIC_APM_LOG_LEVEL=debug
이제, 어플리케이션을 시작합니다(hello.go에는 이전에 계측한 프로그램이 들어 있습니다).
go run hello.go
다음에는 github.com/rakyll/hey를 사용하여 서버에 일부 요청을 전송합니다.
go get -u github.com/rakyll/hey hey http://localhost:8000/hello/world
어플리케이션의 출력에서 다음과 같은 내용을 볼 수 있습니다.
{"level":"debug","time":"2019-03-28T20:33:56+08:00","message":"sent request with 200 transactions, 0 spans, 0 errors, 0 metricsets"}
hey의 출력에서, 응답 시간 지연 히스토그램을 포함하는 다양한 통계를 볼 수 있습니다. 이제 Kibana를 열고 APM UI로 이동하면, “/hello/{name}”라는 이름의 트랜잭션 그룹이 있는 “hello”라는 이름의 서비스를 보게 됩니다. 다음을 확인합니다.
몇 가지 사항이 궁금할 것입니다. 서비스에 어떤 이름을 만들 것인지 에이전트는 어떻게 아는가 그리고, 요청 URI가 아닌 경로 패턴을 사용하는 이유는 무엇인가? 등입니다. 첫 번째 질문은 쉽습니다. (환경 변수에서) 서비스 이름을 지정하지 않는다면, 프로그램 바이너리 이름을 사용하게 됩니다. 이 경우, 프로그램은 “hello”라는 바이너리 이름으로 컴파일됩니다.
경로 패턴을 사용하는 이유는 집계를 수행하기 위한 것입니다. 이제 트랜잭션을 클릭하면, 응답 시간 지연의 히스토그램을 볼 수 있습니다.
경로 패턴을 사용하여 집계하는 경우에도, 트랜잭션 특성에서 전체 요청된 URL을 사용할 수 있는 점에 유의합니다.
SQL 쿼리 추적
일반적인 어플리케이션의 경우, 데이터베이스, 캐시 등의 외부 서비스가 포함된 보다 복잡한 논리와 마주치게 됩니다. 어플리케이션에서 성능 문제에 대한 진단을 시도하는 경우, 이 서비스와 인터랙션이 중요하다는 점을 확인할 수 있습니다.
Go 어플리케이션에서 작성한 SQL 쿼리를 어떻게 관찰하는지 살펴 보겠습니다.
본 시연의 목적을 고려하여 임베디드 SQLite 데이터베이스를 사용합니다. 다만, database/sql을 사용하는 한, 어떤 드라이버를 사용해도 아무런 문제는 되지 않습니다.
database/sql 연산을 추적하기 위해 go.elastic.co/apm/module/apmsql을 사용합니다. apmsql 모듈은 데이터베이스 연산을 트랜잭션 내에서 span으로 보고하기 위해 database/sql 드라이버를 계측합니다. 이 모듈을 사용하려면, 데이터베이스 드라이버를 등록 및 여는 방법을 변경해야 합니다.
일반적인 어플리케이션의 경우 database/sql 드라이버 패키지를 임포트하여 드라이버를 등록합니다. 예를 들어 다음과 같습니다.
import _ “github.com/mattn/go-sqlite3” // registers the “sqlite3” driver
동일한 목적을 위해 몇 개의 편리한 패키지를 사용합니다. 그러나, 동일한 드라이버의 등록 계측 버전에 따라 다음과 같이 임포트하게 됩니다(예를 들어, SQLite3의 경우).
import _ "go.elastic.co/apm/module/apmsql/sqlite3"
이때 내부적으로는 apmsql.Register 메서드를 사용합니다. 이는 sql.Register를 호출하는 것과 같지만, 등록된 드라이버를 계측합니다. 언제라도 apmsql.Register를 사용하는 경우, sql.Open이 아닌 pmsql.Open을 사용하여 연결을 열어야 합니다.
import (
“go.elastic.co/apm/module/apmsql”
_ "go.elastic.co/apm/module/apmsql/sqlite3"
)
var db *sql.DB
func main() {
var err error
db, err = apmsql.Open("sqlite3", ":memory:")
if err != nil {
log.Fatal(err)
}
if _, err := db.Exec("CREATE TABLE stats (name TEXT PRIMARY KEY, count INTEGER);"); err != nil {
log.Fatal(err)
}
...
}
이미 기술한 것과 같이, 수많은 다른 언어와 달리, Go 언어에는 관련 연산을 하나로 연결하는 스레드 로컬 스토리지 기능이 없습니다. 그 대신, 컨텍스트를 명시적으로 전달해야 합니다. 웹 요청의 트랜잭션 기록을 시작하면, 요청 컨텍스트에서 진행 중인 트랜잭션에 대한 참조가 저장됩니다. 이는, net/http.Request.Context 메서드를 통하여 사용 가능합니다. Elastic APM으로 데이터베이스 쿼리를 보고하여 이것이 어떤 모습인지 각 이름이 얼마나 많이 나오는지 기록을 통해 확인해 봅니다.
var db *sql.DB
func helloHandler(w http.ResponseWriter, req *http.Request) {
vars := mux.Vars(req)
name := vars[“name”]
requestCount, err := updateRequestCount(req.Context(), name)
if err != nil {
panic(err)
}
fmt.Fprintf(w, "Hello, %s! (#%d)\n", name, requestCount)
}
// updateRequestCount가 db 내의 이름 카운트에 따라 증가하고, 새로운 카운트를 반환합니다.
func updateRequestCount(ctx context.Context, name string) (int, error) {
tx, err := db.BeginTx(ctx, nil)
if err != nil {
return -1, err
}
row := tx.QueryRowContext(ctx, "SELECT count FROM stats WHERE name=?", name)
var count int
switch err := row.Scan(&count); err {
case nil:
count++
if _, err := tx.ExecContext(ctx, "UPDATE stats SET count=? WHERE name=?", count, name); err != nil {
return -1, err
}
case sql.ErrNoRows:
count = 1
if _, err := tx.ExecContext(ctx, "INSERT INTO stats (name, count) VALUES (?, ?)", name, count); err != nil {
return -1, err
}
default:
return -1, err
}
return count, tx.Commit()
}
이 코드에서 확인해야 하는 중요한 비트가 2개 있습니다.
- 현재 database/sql *Context 메서드를 사용하고 있습니다(ExecContext, QueryRowContext)
- 바깥쪽 요청에서 메서드 호출 안으로 컨텍스트를 전달합니다.
apmsql-instrumented 데이터베이스 드라이버는 제공된 컨텍스트에서 진행 중인 트랜잭션의 참조를 찾으려고 시도합니다. 바로 이것이 보고된 데이터베이스 연산이 호출하는 요청 핸들러와 관련되는 부분입니다. 이 수정한 서비스에 일부 요청을 전송하고, 어떻게 되는지 보겠습니다.
데이터베이스 스팬 이름에는 전체 SQL 구문이 들어있지 않고 그 중 일부만 있는 점에 주목합니다. 이로 인하여 특정한 테이블 이름에서 연산을 나타내는 스팬을 보다 손쉽게 통합할 수 있습니다. 예를 들어 다음과 같습니다. 스팬을 클릭하면, 스팬 세부 사항에서 전체 SQL 구문을 확인할 수 있습니다.
커스텀 스팬 추적
이전 섹션에서 추적 작업에 데이터베이스 쿼리 스팬을 소개했습니다. 서비스에 익숙한 사용자인 경우, 이 2개의 쿼리는 동일한 연산(쿼리 및 그 후 카운터 업데이트 )의 일부라는 것을 즉시 알게 됩니다. 익숙하지 않으면 그렇지 않습니다. 또한, 이 쿼리 중간에 또는 그 전후에 처리가 상당히 진행된 경우, “updateRequestCount” 메서드를 사용하는 것이 좋습니다. 관련 함수의 커스텀 스팬 보고를 통해 이 작업을 할 수 있습니다.
다양한 방법으로 커스텀 스팬을 보고할 수 있습니다. 이때 가장 손쉬운 방법은 apm.StartSpan을 사용하는 것입니다. 이 함수에 트랜잭션이 들어있는 컨텍스트, 스팬 이름과 타입을 반드시 넘겨야 합니다. “updateRequestCount”라는 이름의 스팬을 만들겠습니다.
func updateRequestCount(ctx context.Context, name string) (int, error) {
span, ctx := apm.StartSpan(ctx, “updateRequestCount”, “custom”)
defer span.End()
...
}
위의 코드에서 볼 수 있는 것과 같이 apm.StartSpan은 스팬과 새로운 컨텍스트를 반환합니다. 넘겨준 컨택스트가 아닌 이 새로운 컨텍스트를 반드시 사용해야 합니다. 여기에 새로운 스팬이 들어 있습니다. 이제 UI에서 어떤 모습인지 알 수 있습니다.
아웃고잉 HTTP 요청 추적
지금까지 설명한 내용은 실제로 싱글 프로세스 추적입니다. 여러 개의 서비스가 관련되기는 하지만, 단지 프로세스 1개의 내부에서 추적할 뿐입니다. 클라이언트 관점에서 인커밍 요청, 데이터베이스 쿼리입니다.
최근 몇 년 사이 마이크로서비스가 점차 대세가 되어 갑니다. 마이크로서비스가 등장하기 전에는 SOA(Service-Oriented Architecture)가 모놀리식 애플리케이션을 모듈형 구성 요소로 분석하는 유명한 접근법이었습니다. 실제로, 어느 쪽을 사용하더라도, 계측 가능성을 어렵게 만드는 복잡성은 증가하게 됩니다. 이제, 상이한 데이터 센터 또는 타사 서비스인 경우라고 해도 연산은 프로세스 내부에 연결될 뿐만 아니라, 프로세스 사이 그리고 잠재적(분명히)으로는 다른 장치와도 연결됩니다.
Elastic APM Go 에이전트가 프로세스의 내부와 그 사이에서 추적을 처리하는 방법은 크게 다르지 않습니다. 예를 들어, 아웃고잉 HTTP 요청을 추적하는 경우, HTTP 클라이언트를 계측해야 하며, 바깥쪽 요청 컨텍스트가 아웃고잉 요청으로 전파되는 것을 확인해야 합니다. 계측한 클라이언트는 이것을 사용하여 스팬을 만들고, 아웃고잉 HTTP 요청에 헤더를 주입합니다. 실제로 어떤 형태인지 확인해 봅니다.
// apmhttp.WrapClient는 지정된 http.Client를 계측합니다 client := apmhttp.WrapClient(http.DefaultClient) // “ctx”에는 진행 중인 트랜잭션에 대한 참조가 포함되어 있으면, 이후 아래의 호출이 새로운 스팬을 시작합니다. resp, err := client.Do(req.WithContext(ctx)) … resp.Body.Close() // 요청 바디가 소모되거나 종료되면 스팬은 종료됩니다
만일 이 아웃고잉 요청이 Elastic APM으로 계측한 다른 어플리케이션으로 처리되면, 추적(관련 트랜잭션과 스팬의 컬렉션)이 서비스를 교차했다는 “추적이 분산되었습니다”라는 메시지가 나타나게 됩니다. 계측한 클라이언트는 아웃고잉 HTTP 요청을 위해 스팬을 식별하는 헤더를 주입하고, 수신하는 서비스는 이 헤더를 추출하여 클라이언트 스팬과 기록하는 트랜잭션의 상관 관계를 위해 사용합니다. 이는 go.elastic.co/apm/module에서 제공하는 다양한 웹 프레임워크 계측 모듈을 사용하여 모두 처리합니다.
이것을 시연하기 위해, 서비스를 확장하여 응답에 일부 사소한 내용을 추가해 보겠습니다. 이는 2018년 사우스 오스트레일리아에서 지정된 이름으로 생겨나는 아기의 수치입니다. “hello” 서비스에는 HTTP-based API를 거치는 두 번째 서비스로부터 이 정보가 들어 있게 됩니다. 이 두 번째 서비스 코드는 간단하게 설명하기 위해 생략했으나, “hello” 서비스와 거의 동일한 방식으로 구현 및 계측되는 것으로 생각할 수 있습니다.
func helloHandler(w http.ResponseWriter, req *http.Request) {
...
stats, err := getNameStats(req.Context(), name)
if err != nil {
panic(err)
}
fmt.Fprintf(w, "Hello, %s! (#%d)\n", name, requestCount)
fmt.Fprintf(w, "In %s, %d: ", stats.Region, stats.Year)
switch n := stats.Male.N + stats.Female.N; n {
case 1:
fmt.Fprintf(w, "there was 1 baby born with the name %s!\n", name)
default:
fmt.Fprintf(w, "there were %d babies born with the name %s!\n", n, name)
}
}
type nameStatsResults struct {
Region string
Year int
Male nameStats
Female nameStats
}
type nameStats struct {
N int
Rank int
}
func getNameStats(ctx context.Context, name string) (nameStatsResults, error) {
span, ctx := apm.StartSpan(ctx, "getNameStats", "custom")
defer span.End()
req, _ := http.NewRequest("GET", "http://localhost:8001/stats/"+url.PathEscape(name),
nil)
// HTTP 클라이언트를 계측하고, 요청에 주변 컨텍스트를 추가합니다.
// 이로 인해 다음이 포함되는 아웃고잉 HTTP 요청을 위한 스팬이 발생됩니다.
// 분산된 추적 헤더가 대상 서비스에서 추적을 계속합니다.
client := apmhttp.WrapClient(http.DefaultClient)
resp, err := client.Do(req.WithContext(ctx))
if err != nil {
return nameStatsResults{}, err
}
defer resp.Body.Close()
var res nameStatsResults
if err := json.NewDecoder(resp.Body).Decode(&res); err != nil {
return nameStatsResults{}, err
}
return res, nil
}
양측의 서비스 계측을 통해, 이제 “hello” 서비스에 대한 각 요청의 분산된 추적을 알게 되었습니다.
Adam Quan의 블로그 게시물에서 분산된 추적이라는 주제에 대해 보다 상세한 내용을 볼 수 있습니다(Distributed Tracing, OpenTracing and Elastic APM).
예외 패닉 추적
지금까지 살펴 본 것과 같이, 웹 프레임워크 계측 모듈은 트랜잭션을 기록하는 미들웨어를 제공합니다. 이에 더해, 이 모듈은 패닉을 획득하고 Elastic APM에 보고도 하여, 실패한 요청 조사를 지원합니다. 비-ASCII 문자가 나타날 때 updateRequestCount를 패닉으로 수정하여 이를 시도해 봅니다.
func updateRequestCount(ctx context.Context, name string) (int, error) {
span, ctx := apm.StartSpan(ctx, “updateRequestCount”, “custom”)
defer span.End()
if strings.IndexFunc(name, func(r rune) bool {return r >= unicode.MaxASCII}) >= 0 {
panic(“non-ASCII name!”)
}
...
}
이제 일부 비-ASCII 문자가 든 요청을 전송합니다.
curl -f http://localhost:8000/hello/世界 curl: (22) The requested URL returned error: 500 Internal Server Error
흠! 무엇이 문제일까요? APM UI를 살펴 보겠습니다. Errors 페이지의 “hello” 서비스로 이동합니다.
이제 “비-ASCII 이름!”이라는 오류(패닉) 메시지와 함께 오류가 발생한 것을 알 수 있습니다. 그리고, 패닉이 생성된 함수의 이름도 알 수 있습니다(updateRequestCount). 오류 이름을 클릭하면, 해당 오류의 가장 최근의 인스턴스에 대한 세부 사항으로 연결됩니다. 오류 세부 사항 페이지에서 전체 스택 추적, 오류 시점에서 오류가 발생한 트랜잭션 세부 사항의 스냅샷을 볼 수 있으며 완료된 트랜잭션에 대한 링크가 제공됩니다.
이 같은 패닉 획득과 함께, apm.CaptureError 함수를 사용하여 Elastic APM에 오류를 명시적으로 보고할 수 있습니다. 이 함수에 트랜잭션이 들어있는 컨텍스트와 오류 값을 반드시 넘겨야 합니다. CaptureError는 “apm.Error” 객체를 반환합니다. 이는, 옵션 사항으로 사용자 지정이 가능하며, 그 후 Send 메서드를 사용하여 최종화할 수 있습니다.
if err != nil {
apm.CaptureError(req.Context(), err).Send()
return err
}
마지막으로, 로깅 프레임워크와 통합하여 Elastic APM에 오류 로그를 전송할 수 있습니다. 다음 섹션에서 이에 대해 상세하게 설명하겠습니다.
로깅 통합
최근 수 년 간 “계측 가능성의 3개의 기둥”에 대해 수많은 논의가 있었습니다. 이는, 추적, 로그, 지표입니다. 지금까지 살펴 본 것은 추적이지만, Elastic Stack은 이 3가지 기둥 그리고 그 이상을 제공합니다. 조금 후 지표에 대해 약간 설명하겠습니다. Elastic APM이 어플리케이션 로깅을 통합하는 방법을 확인해 봅니다.
어떤 형식의 중앙집중식 로깅을 수행한 경우, 이미 Elastic Stack에 상당히 익숙할 것입니다. 이전의 이름은 ELK(Elasticsearch, Logstash, Kibana) Stack이었습니다. Elasticsearch에서 로그와 추적을 이미 수행한 경우, 이들의 교차 참조는 간단한 작업입니다.
Go 에이전트는 몇 가지 유명한 로깅 프레임워크를 위해 통합 모듈을 제공합니다. 즉, Logrus(apmlogrus), Zap(apmzap), Zerolog(apmzerolog) 등입니다. Logrus를 사용하여 웹 서비스에 일부 로깅을 추가한 후, 추적 데이터와 어떻게 통합할 수 있는지 살펴 봅니다.
import "github.com/sirupsen/logrus"
var log = &logrus.Logger{
Out: os.Stderr,
Hooks: make(logrus.LevelHooks),
Level: logrus.DebugLevel,
Formatter: &logrus.JSONFormatter{
FieldMap: logrus.FieldMap{
logrus.FieldKeyTime: "@timestamp",
logrus.FieldKeyLevel: "log.level",
logrus.FieldKeyMsg: "message",
logrus.FieldKeyFunc: "function.name", // non-ECS
},
},
}
func init() {
apm.DefaultTracer.SetLogger(log)
}
JSON 형태로 로그를 만들어 stderr에 기록하는 logrus.Logger를 구성했습니다. Elastic Stack에 보다 적합하게 하기 위해, 표준 로그 필드의 일부를 Elastic Common Schema(ECS)와 동등하게 매핑합니다. 다른 방법으로는 기본값을 그대로 둔 상태에서 Filebeat processor를 사용하여 이동시킬 수 있습니다. 이 방법이 조금 더 간단합니다. APM 에이전트는 에이전트 레벨 디버그 메시지 로깅을 위해 이 Logrus logger를 사용한다고 이미 설명했습니다.
이제 어플리케이션 로그와 APM 추적 데이터를 어떻게 통합하는지 살펴 보겠습니다. helloHandler 경로 핸들러에 일부 로깅을 추가한 후, 로그 메시지에 추적 ID를 어떻게 추가하는지 살펴 봅니다. 그 후, “Errors” 페이지에서 표시되도록 Elastic APM에 오류 로그 기록을 어떻게 전송하는지 살펴 봅니다.
func helloHandler(w http.ResponseWriter, req *http.Request) {
vars := mux.Vars(req)
log := log.WithFields(apmlogrus.TraceContext(req.Context()))
log.WithField("vars", vars).Info("handling hello request")
name := vars["name"]
requestCount, err := updateRequestCount(req.Context(), name, log)
if err != nil {
log.WithError(err).Error(“failed to update request count”)
http.Error(w, "failed to update request count", 500)
return
}
stats, err := getNameStats(req.Context(), name)
if err != nil {
log.WithError(err).Error(“failed to update request count”)
http.Error(w, "failed to get name stats", 500)
return
}
fmt.Fprintf(w, "Hello, %s! (#%d)\n", name, requestCount)
fmt.Fprintf(w, "In %s, %d: ", stats.Region, stats.Year)
switch n := stats.Male.N + stats.Female.N; n {
case 1:
fmt.Fprintf(w, "there was 1 baby born with the name %s!\n", name)
default:
fmt.Fprintf(w, "there were %d babies born with the name %s!\n", n, name)
}
}
func updateRequestCount(ctx context.Context, name string, log *logrus.Entry) (int, error) {
span, ctx := apm.StartSpan(ctx, "updateRequestCount", "custom")
defer span.End()
if strings.IndexFunc(name, func(r rune) bool { return r >= unicode.MaxASCII }) >= 0 {
panic("non-ASCII name!")
}
tx, err := db.BeginTx(ctx, nil)
if err != nil {
return -1, err
}
row := tx.QueryRowContext(ctx, "SELECT count FROM stats WHERE name=?", name)
var count int
switch err := row.Scan(&count); err {
case nil:
if count == 4 {
return -1, errors.Errorf("no more")
}
count++
if _, err := tx.ExecContext(ctx, "UPDATE stats SET count=? WHERE name=?", count, name); err != nil {
return -1, err
}
log.WithField("name", name).Infof("updated count to %d", count)
case sql.ErrNoRows:
count = 1
if _, err := tx.ExecContext(ctx, "INSERT INTO stats (name, count) VALUES (?, 1)", name); err != nil {
return -1, err
}
log.WithField("name", name).Info("initialised count to 1")
default:
return -1, err
}
return count, tx.Commit()
}
이제 파일(/tmp/hello.log, Linux 또는 macOS 사용자로 가정)로 출력을 리디렉션하여 프로그램을 실행하는 경우, Filebeat를 설치 및 실행하여 APM 데이터를 받는 동일한 Elastic Stack에 로그를 전송할 수 있습니다. Filebeat 설치 후, filebeat.yml 구성을 다음과 같이 수정합니다.
- “filebeat.inputs”에서 로그 입력에 “enabled: true”를 설정하고, “/tmp/hello.log”로 경로를 변경합니다.
- Elastic Cloud를 사용하고 있다면, “cloud.id” 및 “cloud.auth”를 설정하고, 그렇지 않은 경우에는 “output.elasticsearch.hosts”를 설정합니다.
- “decode_json_fields” 프로세서를 추가합니다. 이제 “processors”는 다음과 같이 됩니다.
processors:
- add_host_metadata: ~
- decode_json_fields:
fields: ["message"]
target: ""
overwrite_keys: true
이제 Filebeat를 실행하면, 로그가 기록을 시작합니다. 이제 서비스에 일부 요청을 전송합니다. “Show host logs” 기능을 사용하여 동일한 시점 상에서 추적으로부터 로그로 점프할 수 있습니다.
이 기능을 사용하면 호스트로 필터링하는 Logs UI로 이동합니다. Docker 컨테이너 내부 또는 Kubernetes 안에서 어플리케이션이 실행 중인 경우, Docker 컨테이너 또는 Kubernetes 포드에서 로그에 대한 링크 작업이 가능합니다.
로그 기록 세부 사항을 확장하면 로그 메시지에 추적 ID가 포함된 것을 볼 수 있습니다. 향후, 특정한 추적으로 로그 필터링에 다른 기능이 추가되어 관련된 로그 메시지만 볼 수 있게 됩니다.
이제 추적에서 로그로 점프하는 방법을 살펴 보았습니다. Elastic APM으로 오류 로그 전송, “Errors” 페이지에서 표시 방법 등의 다른 통합 지점에 대해 알아 보겠습니다. 이와 같이 하려면 logger에 apmlogrus.Hook를 추가해야 합니다.
func init() {
// apmlogrus.Hook가 Elastic APM에 "error", "panic", "fatal" 로그 메시지를 전송합니다.
log.AddHook(&apmlogrus.Hook{})
}
이미 4번째 호출에서 오류 반환을 위해 updateRequestCount를 변경 해 보았으며, helloHandler를 변경하여 오류라고 로그했습니다. 동일한 이름으로 5개 요청을 전송한 후, “Errors” 페이지에 무엇이 나타나는지 보겠습니다.
이제 오류 2개를 확인할 수 있습니다. 이 중 1개는 인메모리 데이터베이스 사용으로 인해 발생한 예상하지 못한 오류입니다. 상세한 설명은 다음과 같습니다. https://github.com/mattn/go-sqlite3/issues/204. 수고 하셨습니다! “요청 카운트 업데이트에 실패했습니다”라는 오류가 발생했습니다.
이들 오류 2개의 원인은 updateRequestCount인 점에 주목합니다. Elastic APM은 이것을 어떻게 압니까? 이것은 github.com/pkg/errors를 사용했기 때문입니다. 여기에서는 발생하거나 감싸는 각 오류에 대해 스택 추적을 추가하며, Go 에이전트는 이 스택 추적을 사용할 수 있다는 것을 압니다.
인프라 및 어플리케이션 지표
마지막으로, 지표를 설명합니다. Filebeat를 사용하여 호스트 및 컨테이너 로그로 점프하는 방법과 유사하게, Metricbeat를 사용하여 호스트와 컨테이너 인프라 지표로 점프할 수 있습니다. 또한, Elastic APM 에이전트는 시스템에 주기적으로 보고하며 CPU와 메모리 사용량을 처리합니다.
에이전트는 언어와 어플리케이션 전용 지표를 전송할 수도 있습니다. 예를 들어, Java 에이전트는 JVM-특정 지표를 전송하며, Go 에이전트는 Go 런타임용 지표를 전송합니다. 예를 들어, goroutines의 현재 개수, 힙 할당의 누적 개수 그리고 가비지 컬렉션의 소비 시간 퍼센트 등입니다.
UI를 확장하여 추가 어플리케이션 지표를 지원하는 작업이 진행 중입니다. 한편, 대시보드를 작성하여 Go-특정 지표를 시각화할 수 있습니다.
잠깐만요...아직 더 있습니다!
아직 살펴보지 않은 사항으로는 RUM(Real User Monitoring) 에이전트와 통합이 있습니다. 이것을 사용하여 브라우저에서 시작된 분산된 추적을 확인할 수 있으며, 백엔드 서비스를 통하여 계속 따라 갈 수 있습니다. 이 주제는 향후 블로그 게시물에서 상세하게 살펴 봅니다. 그때까지는 Elastic RUM에 대한 간단한 소개를 살펴 봅니다.
이 기사에서 많은 부분을 설명했습니다. 질문이 있으신 경우 토론 포럼에 참여하시면 최선을 다하여 답변하겠습니다.