( ꒪⌓꒪) ゆるよろ日記

( ゚∀゚)o彡°オパーイ!オパーイ! ( ;゚皿゚)ノシΣ フィンギィィーーッ!!!

go tool traceでgoroutineの実行状況を可視化する

こんにちわ。しいたけです。今日はgoroutineの実行状況をいいかんじに可視化するツールの話です。

goのプロファイリングツールと言えば、 runtime/pprofnet/http/pprof ですよね。これらの使い方はググればすぐに出てくるのですが、 詳細なtraceを取得して可視化できる runtime/trace については、日本語の情報が殆ど無いので書いてみましいたけ。

runtime/trace はgoroutineの実行状況やsystem callのイベント、Heapやnetworkの状況をこんな感じに可視化してくれるので便利です。

f:id:yuroyoro:20171211191843p:plain

これは自作のクローラーを動かしている際のtraceを可視化したもので、横軸がタイムラインになっており、上段に Heapの使用状況やgoroutineとos threadの数が, 下段はnetworkやProccesor(GOMAXPROCSで指定するgoroutineの実行環境)毎にどのコードが実行されているか、が表示されます。

Heapやgoroutines数の増減と処理の関連を時系列で追えるので、大まかなボトルネックの特定に便利です。また、各goroutine毎の開始/終了とsystem callやunblockイベント(goroutineの切り替え)を細かく追えるので、goroutineが刺さっている箇所の特定にも役立ちます

右側のboxの↓アイコンをクリックした上で、グラフ上でドラッグするとzoomin/outできます。また、View Options で Flow Eventsをチェックすると矢印が描画されます

ここに、実際に動かせるサンプルを置いておきます。

f:id:yuroyoro:20171211191957p:plain

これはとある自作Proxyのtraceの一部で、Proc3で実行されている皆さんおなじみの net/http.(*conn).serve がリクエストを受けて、 go 構文で新たなgoroutineを起動してProc2で実行される様子です。このように、どのタイミングでどのgoroutineが動いたのかが一目瞭然です。

f:id:yuroyoro:20171211192018p:plain

これはGCが実行されている様子です。ほとんどのProcでGC関連の処理が動いた後に、上段のHeapのallocatedが減っている様子が見てとれます。

で、このtraceの可視化の方法ですが、 手っ取り早いのは runtime/trace パッケージをimportして、 trace.Start(w io.Writer)trace.Stop() を呼び出す方法です

https://golang.org/pkg/runtime/trace/

package main

import (
    "log"
    "os"
    "runtime"
    "runtime/trace"
)

func main() {

    f, err := os.Create("trace.out")
    if err != nil {
        log.Fatal(err)
    }
    defer f.Close()

    trace.Start(f)
    defer trace.Stop()

  // do something ...
}

このように、traceを取得したい処理の前後で trace.Start を呼び出すと、結果がファイルに出力されます。 そのファイルを go tool trace コマンドの引数に渡すと、ブラウザで取得したtraceを分析できるようになります。

net/http/pprof パッケージを使っているウェブアプリケーションでも、簡単にtraceを取得することができます。

pprofがlistenしているなら、 /debug/pprof/trace?seconds=5 にリクエストを送ると、5秒間のtraceを取得して結果をダウンロードできます。得られたファイルを go tool trace に渡せば、同様にブラウザ上で分析できます。

詳細なボトルネックの分析は、 pprofやgo-torchでのflamegraphの分析が有向ですが、 go tool trace では時系列に対応しての分析が可能なので、それぞれ状況に合わせて使い分けると良いのではないかと思いましいたけ。

F.Y.I.

ディスク使用量をFlameGraphで可視化する

こんにちわ。しいたけです。今日はディスク使用量をFlameGraphにするツールの話です。

FlameGraphについては、 Flame GraphsGolangでFlame Graphを描く | SOTA を読んでもらうのが手っ取り早いのですが、ようはプロファイル結果を可視化する方法です。縦軸が呼び出しの階層に、横軸がサンプル数や実行時間などに対応しており、どの関数が支配的かを直感的に見ることができる優れたグラフですよ。

で、このFlameGraph、別にプロファイル結果だけではなく、ツリー構造で各ノードが量を持つ場合に、枝毎の累積量を可視化するのに利用できます。プロファイル以外に、ツリー構造でノードが量を持つ例として、ディレクトリ階層毎のディスク使用量が考えられます。

というわけで、指定ディレクトリ以下のディスク使用量をFlameGraph化するツールを書きました。

GitHub - yuroyoro/du-flamegraph: visualize disk usage as flamegraph

こんな感じのグラフが出力されます

http://yuroyoro.net/du-flamegraph.svg


goで書かれており、使い方は、 `go get -u yuroyoro/du-flamegraph` でインストールできます。

このツールは、 FlameGraphの描画に `flamegraph.pl` というスクリプトが必要であり、これは GitHub - brendangregg/FlameGraph: Stack trace visualizer にあります。
これを git cloneなどで手元に入れて、 $PATHに追加するか、 `--flamegraph-script` で位置を指定するかしてやれば、FlameGraph がsvgとして出力されます。

NAME:
   du-flamegraph - visualize disk usage as flamegraph

USAGE:
   du-flamegraph [global options] [FILE]

VERSION:
   0.0.0

GLOBAL OPTIONS:
   --width value, -w value    width of image (default 1200) (default: 1200)
   --height value, -h value   height of each frame (default 16) (default: 16)
   --flamegraph-script value  path of flamegraph.pl. if not given, find the script from $PATH
   --out value                distination path of grenerated flamegraph. default is ./du-flamegraph.svg (default: "./du-flamegraph.svg")
   --verbose                  show verbose log
   --version, -v              print the version

FlameGraph、色々と応用がききそうですね。

「関数型Ruby」という病(7) - Elixir's Pipe operator |> in Ruby

最近Elixirが人気ですよね。Erlang VM上でOTPの恩恵を受けながら簡潔な記法で並行処理を書ける言語ということで話題になっていますな? Elixirは関数型プログラミングのエッセンスを取り入れていると言われており、そのひとつにPipe演算子(|>) がある。

Pipe演算子(|>)とは何かというと、左辺の値を右辺の関数の第1引数に適用する演算子

iex> [1, [2], 3] |> List.flatten()
  [1,  2,  3]


上記のコードは、左辺の[1, [2], 3] を 右辺の List.fatten(list) の引数として渡す。 このPipe演算子は、Stream モジュールなどと合わせて利用するとデータが左から右へ流れている模様をコードとし視覚化することができるという利点があるっぽい(感じろ)。

iex(16)> f = fn a -> IO.puts "f(#{a}) : #{a+1}"; a ; end
#Function<6.90072148/1 in :erl_eval.expr/5>

iex(17)> g = fn a -> IO.puts "g(#{a}) : #{a*2}"; a * 2 ; end
#Function<6.90072148/1 in :erl_eval.expr/5>

iex(18)> 1..10 |> Stream.map(f) |> Stream.map(g) |> Enum.take(3)
f(1) : 2
g(1) : 2
f(2) : 3
g(2) : 4
f(3) : 4
g(3) : 6
[2, 4, 6]


1..10 |> Stream.map(f) |> Stream.map(g) |> Enum.take(3) というコードで、1から10のStreamに対してlazyに関数fとgを順番に適用しながら3つの要素を取り出すという様を素直に表現できていますね?(思え)

さて、そんな便利なパイプ演算子ですが、実は2年ほど前に作ったlambda_driver.gemに既に実装されていたりする。

Rubyでは中置演算子を独自に定義することはできないので、 Object クラスに |> というメソッドを生やすことで実現しよう(全角ェ)。 素朴な実装はこうだ

class Object
  def |>(f = nil)
  puts f
    if block_given?
      yield self
    else 
      f.call(self)
    end
  end

  alias_method "|>", :>=
end


さて、この全角の |> を使って、上記のElixirのコードをRubyで書いてみるとどうなるか?

irb(main):059:0> f = ->(a){ puts "f(#{a}) : #{a + 1}" ; a + 1}
=> #<Proc:0x007ffb8d8b2348@(irb):59 (lambda)>

irb(main):060:0> g = ->(a){ puts "g(#{a}) : #{a *2}" ; a * 2}
=> #<Proc:0x007ffb8d860a98@(irb):60 (lambda)>

irb(main):061:0>  (1..10).|>(&:lazy).|>{|x| x.map(&f) }.|>{|x| x.map(&g) }.|>{|x| x.take(3)}.|>(&:force)
f(1) : 2
g(2) : 4
f(2) : 3
g(3) : 6
f(3) : 4
g(4) : 8
=> [4, 6, 8]


なんというか、すごく……ダサいですね……。

というか、Rubyだったら素直にこう書いた方がいい

irb(main):143:0> (1..10).lazy.map(&f).map(&g).take(3).force
f(1) : 2
g(2) : 4
f(2) : 3
g(3) : 6
f(3) : 4
g(4) : 8
=> [4, 6, 8]


ごくごくまれに、左辺値がObjectとかでrevapplyを使いたくなることもなきにしもあらずだが、そういう場合でも大抵は Object#try で事足りる。

結論 : Rubyには必要ないのでは?

「commit-m: GitHubコミットメッセージの文例が検索できるサービス」がとても便利だったのでcliから使えるコマンド書いた

http://commit-m.minamijoyo.com/:titele という有名OSSのコミットメッセージを検索できるサービスがあって、英語のコミットメッセージを書くときに「あれ? これどういう風に書けばいいんダー」ってときに例文を検索できて捗る。

commit-m.minamijoyo.com

が、自分の場合はコミットメッセージ書くときはvim とか git commit -m とかからなのでCLIで検索できたらより捗るかと思ってGolangで書いた。 APIとかは無いようなのでクロールしてる。 GoQuery 使えばこの手のクローラーが一瞬でかけるのでよさがある。

github.com

go get github.com/yuroyoro/gommit-m で入れた後に gommit-m keyword [page] で検索できる。

f:id:yuroyoro:20151110131804p:plain

表参道.rb #4で「本当は怖い オープンクラスと Duck Typing」というLTをやった話

スライドです

f:id:yuroyoro:20150904130822p:plain
本当は怖いオープンクラスとDuckTyping - 表参道.rb #4

まぁたいした話じゃないんですが、マッドマックスの画像をスクリーンに大写しできたのでその点だけで個人的には満足しています

「型を讃えよ」

Rspecでfailするとデスメタルが流れるようにした

このような事があったので自動化した。
Mac限定。


こんな感じ。successだとレベルがアガる。

事前にbash-itunes というコマンドラインツールを入れておく。
iTunesを日本語で使ってる場合、patchを当てる必要がある。
こちらを山椒

コードはこれな。

class PlayItunesReporter
  attr_accessor :success_track, :failure_track
  def initialize(options = {})
    @success_track = options[:success]
    @failure_track = options[:failure]
  end

  def dump_summary(notification)
    return unless notification.examples.length > 0

    if notification.failed_examples.length == 0
      play!(success_track)
    else
      play!(failure_track)
    end
  end

  def play!(track)
    `itunes play "#{track}"`
  end
end


RSpec.configure do |config|

  itunes = PlayItunesReporter.new(success: "レベル・アップ", failure: 'Nemesis')
  config.reporter.register_listener itunes, :dump_summary
end

正直、曲は好きなの使えばいい。なんならこれでもいい

inspired by : コンパイル中に音楽を流せる sbt プラグインを作りました。 - tototoshi の日記

GolangでSIMDプログラミング

以前から気になっていたSIMDプログラミングをGoでやってみた。

Single Instruction Multiple Data (SIMD) 演算とは1回の命令で複数のデータを同時に処理する演算です.近年の CPU には SIMD 演算を行うことができる SIMD 演算器が搭載されており,Intel 社の CPU ならば Streaming SIMD Extensions (SSE) を用いることで SIMD 演算を行うことが可能です.SSE は CPU に搭載されている 128bit レジスタを用いて演算を行うため単精度データならば4つ,倍精度データならば2つずつ演算を行うことができます.また,近年 SSE 後継の SIMD 拡張命令として Intel Advanced Vector eXtentions (AVX) が登場しました.AVX は第2世代 Intel Core i シリーズのプロセッサ (Sandy Bridge) から使用することが可能であり,演算幅が SSE の2倍の 256bit となっています.つまり,単精度データならば8つ,倍精度データならば4つずつ演算を行うことが可能です.

http://kawa0810.hateblo.jp/entry/20120303/1330797281

といっても、GoのコンパイラSIMDを使ったバイナリを吐くかというとそうではないので、アセンブラなりCなりでSIMDを使うように書いてcgoから使う、という形になる。今後も、GoがSIMD対応することは無さそう(Google グループ)

アセンブラを書くのはつらい(というか書けない)ので、gcc組み込みのSIMD intrinsicsをcgoから使う。intrinsics関数を利用するとcからSSE/AVXを利用できる。今回はSandy Bridgeから利用できるAVXを使って、32bitのfloatの加算をやってみた。

コード

cgoのCFLAGSに -mavxを指定して、gccにAVXを使用するように指定し、immintrin.hをincludeするだけで、cgoからAVXを使える。簡単。


注意点

cgoからintrinsicsを使う際には、注意しなければならないことがある。intrinsicsでSIMD演算を行う場合、

という流れになる。
AVXだと32bit * 8 = 256bitを一度にレジスタにロードして、結果を取り出すことになる。
ここで、メモリとレジスタのやりとりにおいては、対象アドレスが32byteにAlignされている必要がある。
32byte Alignとは、ポインタのアドレスが32で割り切れるようになっている、という意味。

intrinsicsでは、floatの配列を__m256という型にキャストすれば、レジスタとのやりとりをよしなにやってくれるようだが、このときのfloat配列のアドレスは、上述のように32byte alignedである必要がある。

さて、Goからintrinsics関数を利用するときに、このfloat配列のアドレスをどうするのか、という問題が発生する。
対策は2つ。

  • C側でfloat配列を確保する
  • GoでSliceを確保し、Sliceの先頭アドレスを渡す

C側で確保する場合は、話は簡単で、_mm_malloc関数を使うと指定bitでalignして確保できる。他にもgcc4.7からalignを指定する機能もある。ただし、Cで確保した配列をGoのSliceとして扱うには、ちょっとした変換が必要である。また、C側で確保したメモリなのでGoのGC管理下にない。解放のタイミングはプログラマが責任を持つ必要がある。ちょっと、つらい。

GoのSliceを利用する場合、確保されたアドレスが32byte alignedである保証はない。したがって、intrinsicsで非alignedでも利用できる命令(_mm256_loadu_ps)を用いる。この場合は、それなりのオーバーヘッドが発生する。

ベンチマーク結果

Cでメモリ確保する版(BenchmarkAvxAdd)、GoのSliceを渡す版(BenchmarkNonAlignedAvxAdd)、Goのforループで加算する版(BenchmarkGoAdd)でベンチマークを取ってみた。

BenchmarkAvxAdd 3000000 415 ns/op
BenchmarkNonAlignedAvxAdd 1000000 1143 ns/op
BenchmarkGoAdd 1000000 2059 ns/op

32byteにalignした場合が最も速くて、Goのループに比べて約5倍高速。32byte alignedで無い場合は、alignedに比べて2倍強遅くなっている。

ベンチマーク結果をみると、かなりの高速化が期待できる。
Goでwaifu2xのような画像処理を高速に書く場合は、一部の演算をSIMD化する、という最適化はありなのかも知れない。