Go のアプリケーションで DataDog APM に sql/database に関するメトリクスを送るにあたって解決した問題について

祭り

Nature Engineering Blog祭 の 9日目、ソフトウェアエンジニアの北原です。Nature では先日書いた blog のように DataDog APM を用いて Go のアプリケーションのメトリクス収集を行っています。

engineering.nature.global

その後も様々な対応を行いました。今回は database/sql の対応を行なった際に再び github.com/DataDog/dd-trace-go にプルリクエストを送ったので、それにまつわる話です。

標準パッケージである database/sql にも dd-trace-go は対応していまして

import (
    sqltrace "gopkg.in/DataDog/dd-trace-go.v1/contrib/database/sql"
    "github.com/go-sql-driver/mysql"
)

func Example() {
    // The first step is to register the driver that we will be using.
    sqltrace.Register("mysql", &mysql.MySQLDriver{})

    // Followed by a call to Open.
    db, err := sqltrace.Open("mysql", "xxx@...")
    if err != nil {
        log.Fatal(err)
    }

    // Then, we continue using the database/sql package as we normally would, with tracing.
    rows, err := db.Query("SELECT name FROM users WHERE age=?", 27)
    if err != nil {
        log.Fatal(err)
    }
    defer rows.Close()
}

このように書くだけでSQLの実行にかかった時間などをスパン*1として記録することができます。 ところが、検証途中に処理としては問題が起きていないのにエラーとして記録されるスパンがあることがわかりました。

確認したところ上の図にあるように Duplicate entry が発生しており これはアプリケーション側で楽観的にインサートを行い Duplicate entry の エラーだった場合、とそうではない場合で処理を分けていました。よってメトリクスとしては正常処理であると扱いたいとチーム内で話し合いをしました。

ところで database/sql はドライバという形でどのようなデータベースにも対応できるように実装されており dd-trace-go も APM にメトリクスをおくりつつ、更に別のドライバを実行するドライバとして実装されています。 上の例では sqltrace は mysql ドライバを呼んでいます。

以下のように我々が普段呼んでいる QueryContext などを実装しその結果を tryTrace メソッドに送ります。ここで span とエラーを紐付けて送っていたので、アプリケーション側でエラーとしたくない場合も mysql からエラーが返ると DataDog 側に送ってしまいます。

func (tc *tracedConn) QueryContext(ctx context.Context, query string, args []driver.NamedValue) (rows driver.Rows, err error) {
    start := time.Now()
    if queryerContext, ok := tc.Conn.(driver.QueryerContext); ok {
        rows, err := queryerContext.QueryContext(ctx, query, args)
        tc.tryTrace(ctx, queryTypeQuery, query, start, err)
        return rows, err
    }
func (tp *traceParams) tryTrace(ctx context.Context, qtype queryType, query string, startTime time.Time, err error) {
    if err == driver.ErrSkip {
        // Not a user error: driver is telling sql package that an
        // optional interface method is not implemented. There is
        // nothing to trace here.
        // See: https://github.com/DataDog/dd-trace-go/issues/270
        return
    }
    ....
    span, _ := tracer.StartSpanFromContext(ctx, name, opts...)
    ...
    span.Finish(tracer.WithError(err))
}

github.com

そこで送ったプルリクエストがこちらです。

github.com

つまり sqltrace.Open を呼ぶ際にエラーをチェックするオプションを渡すようにし、任意のエラーを APM には送らないということが可能になりました。

   // Followed by a call to Open.
    db, err := sqltrace.Open("mysql", "xxx@...", sqltrace.WithErrorCheck(func(err error) bool {
        if err == nil {
            return false
        }
        serr := err.Error()
        if serr == "something wrong" {
            return false
        }
        return true
    }))

得てしてこのようなオプション設定は既に前例があることが多いと思います。そこで dd-trace-go の他のパッケージや issue を調べたところ、gorm で同じようなエラー処理を追加したり, net/http.Server としてリクエスト単位で記録する、しないをできるようにしていることがわかりました。なのでそのような方向で追加するのはどうかと issue でまず相談し、確認をとりおわり次第(裏では既に fork して実装していましたが)すぐプルリクエストを送り、細かい修正をしあいました。

向こうのエンジニアチームとはタイムゾーンが違うことやそのほかにも様々なプルリクエストが来ているのがわかっていましたので、埋もれないようにこちらも温度感高く反応するのが大事かなとと思っています。

(20日前にプルリクエストが承認されたので、blog 祭り当日までにはリリースされているかなな〜と思ったら dd-trace-go が立て込んでいるのかマージがされておらず、さらに昨日名前ちょっと変えたいかもという相談もあったので、この機能が容易に使えるようになるにはもう少し時間がかかりそうです!)

来週はNatureエンジニアリングブログ祭最終週です。お楽しみに。

エンジニア積極採用中です

Natureでは一緒に開発してくれる仲間を募集しています。

herp.careers

カジュアル面談も歓迎なので、ぜひお申し込みください。

herp.careers

Natureのミッション、サービス、組織や文化、福利厚生についてご興味のある方は、ぜひCulture Deckをご覧ください。

speakerdeck.com