はじめに
アプリケーションのデバッグに利用できるツールは、デバッガやトレーサ、printfデバッグなどがあります。ただ、WebSocketやMySQLのトランザクション処理内などでは、迂闊にアプリケーションの実行を止めることができません。もし止めてしまうと、実行再開後にセッションがタイムアウトしていた・・・なんてことが起こります。
こういった場面で、気軽に使えることを目指している関数トレーサ goapptrace を作っています。
インストールの仕方
go installでインストールできます。
$ go install -u github.com/yuuki0xff/goapptrace
使い方
1. サーバ起動
goapptraceを使うためには、はじめにサーバをAPIサーバを起動しておく必要があります。
ログサイズは大きくなるかもしれないので、ストレージの空き容量に注意してください。
$ goapptrace server run
2. アプリケーションを起動
go runの代わりにgoapptrace runを使ってアプリケーションを起動してみてください。
トレース対象のアプリケーションがgo runで実行したり、go buildでコンパイルすることができる必要があります。独自のビルドシステムを使用している場合は、利用できません。
# ↓ これで起動できるアプリケーションなら、
$ go run foo.go args
# ↓ このようなコマンドを実行すると、アプリケーション内にトレーサが埋め込まれた状態で起動します。
$ goapptrace run foo.go args
3. トレース対象絞り込み
初期状態だと、トレース可能な関数はすべてトレースする設定になっています。このままでは多量のログが出力されると思うので、トレース対象の関数を絞り込む必要があるでしょう。
トレースしたい関数がすでに決まっているなら、このようなコマンドを実行してみてください。これ以降は指定した関数以外のログが出力されなくなります。
# 全ての関数のトレースを止める。
$ goapptrace trace stop
# トレースしたい関数の名前を確認して・・・
$ goapptrace trace ls
# トレースしたい関数を指定する。
# --regexp引数を指定すると、関数名を正規表現で指定できます。
$ goapptrace trace start LOG_ID 'example.com/user/app.foo'
$ goapptrace trace start --regexp LOG_ID '^example\.com/user/app\.'
頻繁に呼び出されている関数が、ログの量を増やしているということもあります。goapptrace log catをざっと眺めて、トレースする必要がなさそうな関数を見つけ、無効化してみましょう。
$ goapptrace trace stop $LOG_ID function-name
4. ログ確認
$ goapptrace log cat --tail=1000
仕組み
現状では、関数のエントリーポイントに下記のようなコードを挿入することでトレースしています。
func foo() {
// 省略
}
var flag bool
func foo() {
if flag {
id := tracer.FuncStart()
defer tracer.FuncEnd(id)
}
// 省略
}
上記のようなコードが挿入されると、関数が呼び出されたときにFuncStart()を、関数から抜けるときにFuncEnd()が呼び出されます。FuncStart()/FuncEnd()で、時刻やコールスタックなどをロギングしています。
また、GoroutineIDなどの必要な情報を取得できるようにするため、Go言語ランタイムにパッチを当てています。
goapptraceでは、上記のようなコード書き換えやパッチ当て処理をビルドプロセスの一部として扱っており、goapptrace buildやgoapptrace runを実行したときに自動でやってくれます。
今後
正式版のリリースに向けて、log viewerの改善をします。
このトレーサは、後からトレーサに機能追加をしても、利用者がコードに手を加える必要はありません。必要があれば分岐のロギング、channelとローカル変数をdumpする機能などを追加しようと思ってます。