Tracing on Erlang/OTP 19

# Tracing on Erlang/OTP 19

OTP19-rc1が来ましたね.
いくつかの大きな変更の中に, traceに関する変更があります. Erlang Factory 2016で[それに関する発表](http://www.erlang-factory.com/sfbay2016/lukas-larsson)がされているので, 発表 + ドキュメント + 他から纏めてみました.
誤りがあればご指摘ください m(_ _)m

## traceとは...?

C/C++だとgdbでbreak pointを仕込んだり、ポインタの中身を見たりすることがあるかと思います.
こういった実行中のプログラムの状態を知る為の仕組みをErlangはVM上で提供しています.

そもそも使ったことないという人は, 以下のうち**一つは抑えておくと世界が変わるのでオススメ**です.

- Erlang/OTP
 - [erlang:trace/3](http://erlang.org/doc/man/erlang.html#trace-3)
 - [dbg](http://erlang.org/doc/man/dbg.html)
- その他のライブラリ
 - [recon](https://github.com/ferd/recon)
 - [eper](https://github.com/massemanet/eper) (redbug)

## traceの種類/概要

- trraced processes
 - receive / send (message)
 - in / out (schedule)
- traced modules
 - call / return

上記のような2種類に分類されるイベント([erlang:trace/3](http://erlang.org/doc/man/erlang.html#trace-3)参照) を指定することができ, 指定されたイベントが発生した時, tracerプロセスに対してメッセージが送信されます.

また, meta traceを使うことで他のプロセスに対してそのメッセージを送ることもできます.  ([erlang:trace_pattern/3](http://erlang.org/doc/man/erlang.html#trace_pattern-3) のmetaを参照)

### Match specification
関数呼び出しに関するイベントは, 特定のパターンにマッチする関数の呼び出しを指定することができます.
なので, `Mod:Function(a, _)`の場合のみトレースするといったこともできます.

http://erlang.org/doc/apps/erts/match_spec.html

### Sequence Trace
http://erlang.org/doc/man/seq_trace.html

メッセージのやりとりを追うことができるtrace. 

```
(<0.227.0>) call dbg:get_tracer()
SeqTrace [0]: (<0.227.0>) <0.217.0> ! {<0.227.0>,{get_tracer,nonode@nohost}} [Serial: {0,1}]
SeqTrace [0]: (<0.217.0>) <0.227.0> ! {dbg,{ok,<0.218.0>}} [Serial: {1,3}]
SeqTrace [0]: (<0.227.0>) <0.167.0> ! {io_request,<0.227.0>,#Ref<0.0.0.3303>,getopts} [Serial: {3,
                                                                                  4}]
SeqTrace [0]: (<0.167.0>) <0.165.0> ! {<0.167.0>,get_unicode_state} [Serial: {4,63}]
SeqTrace [0]: (<0.165.0>) <0.167.0> ! {<0.165.0>,get_unicode_state,true} [Serial: {63,64}]
```

### DTrace / SystemTap
gdbでattachするとErlangVMがとまってしまいます. ErlangVMを止めずに低オーバーヘッドで調査する為のツールとしてDTrace (Mac / BSD), SystemTap (Linux) をサポートしています.

例えば, NIF/Port driverがスケジューラーをロックしてしまった場合 (よくありますね！) なんかに活躍できるっぽいです.

- http://erlang.org/doc/apps/runtime_tools/DTRACE.html
- http://erlang.org/doc/apps/runtime_tools/SYSTEMTAP.html
- http://voluntas.hatenablog.com/entry/20120330/1333110554
- http://www.erlang-factory.com/static/upload/media/1399288388410589dtrace.pdf

## trace on OTP19
### scalabirity
OTP19以前は一度globalなsystem message dispatcher threadを経由していた為, **trace messageはシーケンシャルに処理**されていた.
これは, traceの一部はproc msg / proc statusをtrace messageの順にlockする必要があった為であり, 拡張性を阻害する原因となっていた.

OTP19では, **traceeからtracerに直接メッセージが送信される**ようになりました.
より具体的には,

- proc statusのlockをなくした
- proc msgのlockをtry lock (timeout可能なlock) にした.
- process毎に存在するtrace message queueのlockを取るようになった.

### performance
詳しくは, スライドのグラフ / 動画を参照して欲しい.

- call trace to process
 - traceなしと比べると100倍程度遅いものの, 従来よりも2～3倍速い.
- call trace to port
 - 従来見られたscheduler数が増えると悪化する問題が改善された
- Max mem usage during trace to process
 - 従来の半分程度まで削減
- Max mem usage during trace to port
 - 従来よりも**悪化**するが, 従来は遅すぎて使い物にならなかったようです.
 - to processの場合と比べると同程度もしくは, 少ない程度.

### new behaviour
OTP19から[erl_tracer behvaiour](http://erlang.org/documentation/doc-8.0-rc1/erts-8.0/doc/html/erl_tracer.html) が追加された.

#### 特徴
- Erlang codeで全てのtrace eventに対するフィルタを記述することができる
 - 但し, ドキュメントには(将来的にはこの制限はなくなるが) NIFで全部実装しろという記述がある為, 真偽のほどは不明
 - 従来の方法では, receiveしてからのハンドリングか[match specifications](http://erlang.org/doc/apps/erts/match_spec.html)によるマッチしかできなかった (はず)
- backendをplugginの形で選ぶことができる
 - erl_tracer behaviourで実装されていれば何でもOK
- NIFで実装されているので, trace termのcopyは発生しない

#### callback function
callback functionは以下の大きく以下の二種類に分類される

- enabled ...... traceするか/しないか
 - enabled_procs
 - enabled_ports
 - eabled_running_ports
 - (以下略)
- trace ...... trace時の挙動
 - trace_procs
 - trace_ports
 - trace_running_ports
 - (以下略)

どちらとも`(enabled/trace)_XXXX`が定義されていればそちらを, 定義されていない場合は`enabled/trace`をtrace event毎に実行する. 
(`trace`系の関数は`enabled`系の関数で`trace`を返した場合のみ実行される)

#### Usage
```erlang
1> erlang:trace(new, true, [send, {tracer, ErlTracerModule, Tracer}]).
```

- [Example tracer module nif](http://erlang.org/documentation/doc-8.0-rc1/erts-8.0/doc/html/erl_tracer.html#example)