OpenCensus 및 Google Cloud Tracing으로 Gorm 쿼리 추적

incident.io에서 Postgres 데이터베이스용 ORM 라이브러리로 gorm.io을 사용합니다. 이 도구는 정말 강력한 도구이며 Go 및 Postgres 앱에서 수동으로 SQL을 사용하여 수년간 작업한 결과 매우 기쁩니다. other blog posts 라이브러리를 통해 특히 Google Cloud Tracing과 함께 추적에 막대한 투자를 하고 있음을 OpenCensus 에서 보셨을 것입니다. 애플리케이션 시간의 상당 부분이 gorm을 통해 Postgres와 대화하는 데 사용되므로 추적 스택에서 더 잘 볼 수 있기를 원했습니다.

운 좋게도 Gorm은 Callbacks API을 통해 추적을 제거할 수 있는 완벽한 후크를 가지고 있습니다. 이를 통해 Gorm에 쿼리 수명 주기의 특정 부분에서 호출되는 함수를 제공할 수 있습니다. 또는 우리의 경우 관찰 가능성을 위해 데이터를 꺼냅니다.

func beforeQuery(scope *gorm.DB) {
    // do stuff!
}

db.Callback().
    Create().
    Before("gorm:query").
    Register("instrumentation:before_query", beforeQuery)

이 게시물의 목표는 Gorm 쿼리에 추적 범위를 도입하여 시작 및 종료 이벤트를 모두 포착하고 그에 따라 범위를 처리해야 하는 것입니다. 이 예에서는 Google Cloud Tracing에 제공되는 go.opencensus.io/trace에서 제공하는 추적 도구를 사용하지만 다른 추적 라이브러리도 유사하게 작동해야 합니다.

이제 쿼리가 시작될 때 호출되는 함수가 있으므로 범위를 시작해야 합니다.

func beforeQuery(scope *gorm.DB) {
    db.Statement.Context = startTrace(
    db.Statement.Context,
    db,
    operation,
  )
}

func startTrace(
  ctx context.Context,
  db *gorm.DB,
) context.Context {
    // Don't trace queries if they don't have a parent span.
    if span := trace.FromContext(ctx); span == nil {
        return ctx
    }

    ctx, span := trace.StartSpan(ctx, "gorm.query")
    return ctx
}

그런 다음 범위도 종료해야 합니다.

func afterQuery(scope *gorm.DB) { endTrace(scope) }

func endTrace(db *gorm.DB) {
    span := trace.FromContext(db.Statement.Context)
    if span == nil || !span.IsRecordingEvents() {
        return
    }

    var status trace.Status

    if db.Error != nil {
        err := db.Error
        if err == gorm.ErrRecordNotFound {
            status.Code = trace.StatusCodeNotFound
        } else {
            status.Code = trace.StatusCodeUnknown
        }

        status.Message = err.Error()
    }
    span.SetStatus(status)
    span.End()
}

db.Callback().
    Query().
    After("gorm:query").
    Register("instrumentation:after_query", afterQuery)

이제 추적에서 모든 곰 쿼리를 볼 수 있습니다. 좋습니다!



그러나 그들은 우리가 실제로 무엇을 하고 있는지에 대해 매우 명확하지 않습니다. 다음을 추가하여 이러한 범위를 좀 더 유익하게 만들 수 있는지 봅시다.

스팬 이름에 대한 테이블 이름 및 쿼리 지문¹.

우리를 호출한 코드 줄

선택 쿼리의 WHERE 매개변수

영향을 받는 행 수

¹ 쿼리 지문은 형식 및 변수에 관계없이 쿼리에 대한 고유 식별자이므로 데이터베이스에서 동일하게 작동하는 쿼리를 고유하게 식별할 수 있습니다.

이전 코드를 확장해 보겠습니다.

func startTrace(ctx context.Context, db *gorm.DB) context.Context {
    // Don't trace queries if they don't have a parent span.
    if span := trace.FromContext(ctx); span == nil {
        return ctx
    }

    // start the span
    ctx, span := trace.StartSpan(ctx, fmt.Sprintf("gorm.query.%s", db.Statement.Table))

    // set the caller of the gorm query, so we know where in the codebase the
    // query originated.
    //
    // walk up the call stack looking for the line of code that called us. but
    // give up if it's more than 20 steps, and skip the first 5 as they're all
    // gorm anyway
    var (
        file string
        line int
    )
    for n := 5; n < 20; n++ {
        _, file, line, _ = runtime.Caller(n)
        if strings.Contains(file, "/gorm.io/") {
            // skip any helper code and go further up the call stack
            continue
        }
        break
    }
    span.AddAttributes(trace.StringAttribute("caller", fmt.Sprintf("%s:%v", file, line)))

    // add the primary table to the span metadata
    span.AddAttributes(trace.StringAttribute("gorm.table", db.Statement.Table))
    return ctx
}

func endTrace(db *gorm.DB) {
    // get the span from the context
    span := trace.FromContext(db.Statement.Context)
    if span == nil || !span.IsRecordingEvents() {
        return
    }

    // set the span status, so we know if the query was successful
    var status trace.Status
    if db.Error != nil {
        err := db.Error
        if err == gorm.ErrRecordNotFound {
            status.Code = trace.StatusCodeNotFound
        } else {
            status.Code = trace.StatusCodeUnknown
        }

        status.Message = err.Error()
    }
    span.SetStatus(status)

    // add the number of affected rows & query string to the span metadata
    span.AddAttributes(
        trace.Int64Attribute("gorm.rows_affected", db.Statement.RowsAffected),
        trace.StringAttribute("gorm.query", db.Statement.SQL.String()),
    )
    // Query fingerprint provided by github.com/pganalyze/pg_query_go
    fingerprint, err := pg_query.Fingerprint(db.Statement.SQL.String())
    if err != nil {
        fingerprint = "unknown"
    }

    // Rename the span with the fingerprint, as the DB handle
    // doesn't have SQL to fingerprint before being executed
    span.SetName(fmt.Sprintf("gorm.query.%s.%s", db.Statement.Table, fingerprint))

    // finally end the span
    span.End()
}

func afterQuery(scope *gorm.DB) {
    // now in afterQuery we can add query vars to the span metadata
    // we do this in afterQuery rather than the trace functions so we
    // can re-use the traces for non-select cases where we wouldn't want
    // to record the vars as they may contain sensitive data

    // first we extract the vars from the query & map them into a
  // human readable format
    fieldStrings := []string{}
    if scope.Statement != nil {
        fieldStrings = lo.Map(scope.Statement.Vars, func(v any i int) string {
            return fmt.Sprintf("($%v = %v)", i+1, v)
        })
    }
    // then add the vars to the span metadata
    span := trace.FromContext(scope.Statement.Context)
    if span != nil && span.IsRecordingEvents() {
        span.AddAttributes(
            trace.StringAttribute("gorm.query.vars", strings.Join(fieldStrings, ", ")),
        )
    }
    endTrace(scope)
}

그리고 이제 우리는 매우 풍부하고 스캔하기 쉬운 스팬을 갖게 되어 우리 앱이 무엇을 하는 데 시간을 소비하는지 훨씬 더 쉽게 이해할 수 있습니다.



Gorm은 쿼리 수명 주기의 다양한 비트에 대한 콜백을 제공하며 모든 항목에 대한 특정 동작을 추가할 수 있습니다. 현재 생성, 삭제, 업데이트 및 쿼리를 개별적으로 추적하지만 더 나아가고 싶다면 다음을 확인할 수 있습니다. gorm docs ! . 이 게시물here에서 모든 코드를 찾을 수 있습니다.

주의하지 않으면 일부 민감한 데이터를 추적하게 될 수 있음을 기억하십시오. 따라서 해당되는 경우 쿼리 변수를 삭제해야 합니다. 한 가지 좋은 방법은 SELECT 쿼리만 추적하는 것입니다. 이는 일반적으로 민감한 정보가 아닌 ID를 통해 수행되기 때문입니다.