oinume journal

Scratchpad of what I learned

2020の抱負

新年あけましておめでとうございます。年末年始はインフルエンザになって寝込んでいて、そういえば今年は厄年だったことを思い出しました。もう1/15になってだけど2020年の抱負をあらためて書いておこうと思います。

1日6時間15分以上寝る

昨年は1日6時間以上寝る、ということが目標だったので今年は15分長くしてみる。理想は1日7時間睡眠なので最終的にはこれを目指したい。

アルゴリズムとデータ構造をもっと勉強する

昨年途中で投げ出してしまったヤツ。なお、ちゃんと解説をブログにアウトプットする。

  • Graph
  • オートマトン

アウトプット

1ヶ月に1つはちゃんとした記事を書く。昨年に引き続き継続は力なり、ということで。

英語

IELTS Overall 6.0を目指す。

2019年の振り返り

2019年も早いものであっという間に終わってしまった。以下が2019年初頭に考えていた抱負だったので、これをベースに振り返りをしてみよう。

journal.lampetty.net

アウトプット

ちゃんとした記事を月に一つは書く!というの目標に対しては以下のように未達だったけど、合計25個の記事を書いたし、未達だったのは3月と10月だけだったのでほぼ達成と言って良いのではないかと。

  • 1月: ◯
  • 2月: ◯
  • 3月: ✕
  • 4月: ◯
  • 5月: ◯
  • 6月: ◎
  • 8月: ◯
  • 9月: ◯
  • 10月: ✕
  • 11月: ◯
  • 12月: ◎

また、会社のAdvent Calendarでも以下の記事を書いた。3年半も勤めているのにこれが初めての記事だった...! はてブTwitterでもいろいろフィードバックされているのを見てとても勉強になったし、来年はもっとアウトプットしていこうという気持ちが強くなった。

tech.mercari.com

1日6時間以上寝る

iPhoneのヘルスケアアプリによると各月の平均睡眠時間は以下のような結果だった。2,4,5,9月以外は達成できているし、実感として昨年より良く寝れていて毎日のパフォーマンスも上がっている気がする。

  • 1月: データなし
  • 2月: 5h11min
  • 3月: 6h2min
  • 4月: 5h56min
  • 5月: 5h56min
  • 6月: 6h20min
  • 7月: 6h25min
  • 8月: 6h10min
  • 9月: 5h59min
  • 10月: 6h27min
  • 11月: 6h19min
  • 12月: 6h13min

アルゴリズムもっと勉強する

以下のような結果だった。Graphは中途半端なところで終わっているので再開したい。

暗号技術を勉強する

これはまったくやる暇がなかったのと、特に何かで必要なものではないので、目標設定をミスったかなという気がしている。

業務で必要なものを身につける

  • gRPC: ☓
  • Cloud Spanner: △
  • Cloud PubSub: ◯
  • SQLを復習する: ☓

これはそれぞれの項目でどこまでやるというゴールをちゃんと決めたほうが良かった。

英語を再開する

いつかは海外で働きたいと思っていて、自分の英語力をどう伸ばすかはずっと課題だったのでまずはIELTSを受けてみた。結果としては Overall: 5.0 であり「6.0ぐらいはあるかなー」という予想を大きく下回っていた。でも自分の実力がわかったし、これまでやってきたDMM英会話ベースでデイリーニュースを読むみたいな学習法だと英語力は伸びないということがわかったので、来年からは違う方法(カランメソッド)でやっていこうと思う。

  • Overall: 5.0
  • Listening: 5.5
  • Reading: 5.0
  • Writing: 5.0
  • Speaking: 5.0

あと、2年前から伸び悩んでいたTOEICも受けてみたのだけど、2年前より30点だけスコアが上がっていて自己ベストを更新したのが嬉しかった。DMM英会話をやめて単語ぐらいしか真面目に勉強していなかったけど、それでもまだスコアが伸びる余地があるということが実感できた。何よりも40歳を過ぎても何かの能力・スコアが上がるという実感が得られたのが嬉しい。

読んだ本

今年はほとんど本を読まなかった。真面目に読んだのは以下のみ。

Googleを支える技術

Googleの初期の検索システムの内部構造などについて詳しく書かれている本。とてもわかりやすく説明してあって楽しく読めた。

Googleを支える技術 ‾巨大システムの内側の世界 (WEB+DB PRESSプラスシリーズ)

Googleを支える技術 ‾巨大システムの内側の世界 (WEB+DB PRESSプラスシリーズ)

  • 作者:西田 圭介
  • 出版社/メーカー: 技術評論社
  • 発売日: 2008/03/28
  • メディア: 単行本(ソフトカバー)

脳を鍛えるには運動しかない!

運動後に何かを勉強すると学習効率が上がるなど、実験結果の事例から運動と脳の関係性について説明する本。運動することはメンタルヘルスにも良い影響があるということで、これを読んだあとから必ず週に2回はジムで有酸素運動をするようにしている。

脳を鍛えるには運動しかない!  最新科学でわかった脳細胞の増やし方

脳を鍛えるには運動しかない! 最新科学でわかった脳細胞の増やし方

Go言語による並行処理

Goの並行処理についてとにかく丁寧にわかりやすく解説している良い本。Goは一通り書けるけど、channelやgoroutineを使いこなせていないと感じている人にはぜひオススメしたい。

Go言語による並行処理

Go言語による並行処理

  • 作者:Katherine Cox-Buday
  • 出版社/メーカー: オライリージャパン
  • 発売日: 2018/10/26
  • メディア: 単行本(ソフトカバー)

IntelliJ IDEAハンズオン

IntelliJについて詳しく解説してある本。ほぼ独学で使っているIntelliJについて、体系的に学び直せたのは良かった。

IntelliJ IDEAハンズオン――基本操作からプロジェクト管理までマスター

IntelliJ IDEAハンズオン――基本操作からプロジェクト管理までマスター

エンジニアの知的生産術

これが2019年の中でベストな本だった。まだ読み終わっていないけど、どうすれば効率的に本を読めるかなどが体系的に書かれているし、すぐに実践できる内容でもある。

エンジニアの知的生産術 ──効率的に学び、整理し、アウトプットする (WEB+DB PRESS plusシリーズ)

エンジニアの知的生産術 ──効率的に学び、整理し、アウトプットする (WEB+DB PRESS plusシリーズ)

  • 作者:西尾 泰和
  • 出版社/メーカー: 技術評論社
  • 発売日: 2018/08/10
  • メディア: 単行本(ソフトカバー)

育児

息子も5歳になって、0歳〜2歳の時に比べると本当に手がかからなくなってきたように思う。元気に育っていてそれが一番ありがたいし(元気すぎて困る)、今年だけで以下のアビリティを習得している(すごい!)。

  • 自転車に乗れるようになった!
  • ひらがなを全部読めるようになった
  • 自分の名前をひらがなで書けるようになった
  • (体操の)前転と後転がすごく上手になった
  • レゴをほぼ自分だけで組み立てられるようになった
  • 英単語を少しだけ覚え始めた
  • 箸を持てるようになった(練習中)

また、奥さんの海外出張が今年も2回あったけど、去年よりはうまく乗り切れた気がする。去年は出張中は寂しくて泣いてしまう時が多かったけど、今年は1,2回しか泣かなかったし、なるべく休みの日は鉄道博物館とか、今までに行ったことがないところに連れて行って楽しくやれたんじゃないかと思う。

まとめ

2019年は2018年に比べると仕事も忙しかったけど、学びやアウトプットは昨年よりこなせたかなと思う。2020年も引き続き目標を明確にして頑張っていきたいなと思う。

OpenCensusとhttptrace.ClientTraceを使ってHTTPリクエストのlatencyを可視化する

はじめに

みなさんこんにちは。これはGo5 Advent Calendar 2019の19日目の記事です。この記事はOpenCensusとhttptrace.ClientTraceを使ってHTTPリクエストの内部的なlatencyを可視化する話です。「内部的なlatency」というのは、HTTPリクエストの中で名前解決にどのぐらいかかったとか、コネクションを張るのにどのぐらいかかったなどです。

なお、この記事に記載しているコードは全てGitHubに上げてあります。

やりたいこと

とあるアプリケーションでHTTP Clientを使ってHTTPリクエストを大量に送る処理がありました。そのサーバーはUS Regionで動いていて、そこからHTTPリクエストを日本にあるサーバーに送るというもので、この処理のlatencyが非常に気になっていました。そのため、HTTPリクエストのどの部分が遅いのかを可視化したいと思って調べたところ、OpenCensusとhttptrace.ClientTraceに行き着いたのでその紹介をしたいと思います。

OpenCensusと分散トレーシング

今回使うのはOpenCensusのTracingという機能です。いわゆる分散トレーシングと呼ばれるものですが、詳しく説明していると長くなるので、詳細は以下の記事を読んでみて下さい。OpenCensusや分散トレーシングについてとてもよくまとまっています。

future-architect.github.io

Span

分散トレーシングではSpanというものを一つの処理の単位として登録します。例えば以下のようなGoのコードでは、main関数でSpanを1つ作り、main関数からfunc1, func2を呼び出して、それぞれの関数でも新しくSpanを作っています。

これをJaegerという分散トレーシングを可視化するソフトウェアで表示したものが以下になります。

  • trace: main
    • trace: func1
    • trace: func2

というようにSpanがツリー構造になっていて、それぞれのSpanでどのぐらい時間がかかっているかがわかると思います。この論理的にまとまったSpanたちがTraceと呼ばれています。

httptrace.ClientTrace

httprace.ClientTraceはHTTPリクエストの中で行われる以下の処理について、処理が開始したタイミングと終了したタイミングでコールバックを設定してイベントを受け取ることができるライブラリで、以下のようなコールバックが定義されています。詳しくはClientTraceのgodocを読むと良いでしょう。参考までに、以下に定義されているコールバックのコメントとその日本語訳を記載しておきます。

  • GetConn
    • GetConn is called before a connection is created or retrieved from an idle pool
    • コネクションが生成されたもしくはアイドルプールから取得された時に呼ばれる
  • GotConn
    • GotConn is called after a successful connection is obtained
    • コネクションの確立が成功した時に呼ばれる
  • DNSStart
    • DNSStart is called when a DNS lookup begins.
    • 名前解決が始まった時に呼ばれる
  • DNSDone
    • DNSDone is called when a DNS lookup ends.
    • 名前解決が終了した時に呼ばれる
  • ConnectStart:
    • ConnectStart is called when a new connection's Dial begins
    • 新しいコネクションのDialが始まった時に呼ばれる
  • ConnectDone
    • ConnectDone is called when a new connection's Dial completes.
    • 新しいコネクションのDialが完了した時に呼ばれる
  • TLSHandshakeStart
    • TLSHandshakeStart is called when the TLS handshake is started
    • TLSハンドシェイクが始まった時に呼ばれる
  • TLSHandshakeDone
    • TLSHandshakeDone is called after the TLS handshake with either the successful handshake's connection state, or a non-nil error on handshake failure.
    • TLSHandshakeDoneは、TLSハンドシェイクの接続に成功している場合か、ハンドシェイクがerrorで失敗している場合のどちらでも、TLSハンドシェイクが完了した後に呼ばれる。
  • WroteHeaderField
    • WroteHeaderField is called after the Transport has written each request header
    • それぞれのリクエストヘッダーのが書き込まれた後に呼ばれる。ヘッダーが複数ある場合は何回も呼ばれることになる。
  • WroteHeaders: WroteHeaders is called after the Transport has written all request headers.
    • 全てのリクエストヘッダーが書き込まれた後に呼ばれる。
  • WroteRequest: WroteRequest is called with the result of writing the request and any body.
    • リクエストのBodyも含めてリクエストが書き込まれた後に呼ばれる。
  • GotFirstResponseByte
    • GotFirstResponseByte is called when the first byte of the response headers is available.
    • レスポンスヘッダーの最初の1バイトが読み込める状態になった時に呼ばれる

試しにそれぞれのコールバック関数でfmt.Printするだけの簡単な実装を書いて実行してみると、以下のように出力されました。どうやらこの順番でコールバックが呼ばれていることがわかります。

$ go run examples/client_trace/main.go
GetConn
DNSStart
DNSDone
ConnectStart
ConnectDone
TLSHandshakeStart
TLSHandshakeDone
GotConn
WroteHeaderField: Host
WroteHeaderField: User-Agent
WroteHeaderField: Accept-Encoding
WroteHeaders
WroteRequest
GotFirstResponseByte

ということで、httptrace.ClientTraceを使うとHTTPのコネクションの接続のタイミングやリクエストを送信したタイミングのイベントが受け取れるということがわかりました。

OpenCensus Tracing + httptrace.ClientTrace

それではOpenCensusの分散トレーシングとhttptrace.ClientTraceの2つを組み合わせてみましょう。以下のようにochttp.NewSpanAnnotatingClientTraceを使うことで、簡単にhttptrace.ClientTraceの情報をTraceのSpanに入れることができます。

上記のプログラムを実行して、Jaegerに送られたSpanを可視化したものが以下のスクリーンショットになります。先ほど紹介したGetConnやDNSStartなどがどのぐらい時間がかかったかが相対的にわかるようになっています。例えば、DNSStartは0.25msでDNSDoneは59.84msなので、59.84 - 0.25 = 59.59ms かかっていることになります。

これは以下の手順で見ることができます。

$ docker-compose up #jaegerを起動
$ go run examples/ochttp_client_trace/main.go #プログラムを実行
$ open http://localhost:16686/search # ブラウザでjaegerを開く

NewSpanAnnotatingClientTraceとspanAnnotator

先ほどのNewSpanAnnotatingClientTraceでは、内部的にコールバックを定義したspanAnnotatorを用意して、これをhttptrace.ClientTraceのそれぞれのコールバックとして登録しています。spanAnnotatorはSpanを持っていて、それぞれのコールバック関数の中でSpanに対してAnnotationを登録しています。

Annotationを登録する時にはtimestampも記録されているため、上のJaegerのスクリーンショットのように各コールバック関数のタイミングで相対的にどのぐらい時間がかかったのかがわかるようになっています。

参考までに、以下はspanAnnotatorのDNSStartとDNSDoneのコードです。

func (s spanAnnotator) dnsStart(info httptrace.DNSStartInfo) {
    attrs := []trace.Attribute{
        trace.StringAttribute("httptrace.dns_start.host", info.Host),
    }
    s.sp.Annotate(attrs, "DNSStart")
}

func (s spanAnnotator) dnsDone(info httptrace.DNSDoneInfo) {
    var addrs []string
    for _, addr := range info.Addrs {
        addrs = append(addrs, addr.String())
    }
    attrs := []trace.Attribute{
        trace.StringAttribute("httptrace.dns_done.addrs", strings.Join(addrs, " , ")),
    }
    if info.Err != nil {
        attrs = append(attrs,
            trace.StringAttribute("httptrace.dns_done.error", info.Err.Error()))
    }
    s.sp.Annotate(attrs, "DNSDone")
}

まとめ

OpenCensusとhttptrace.ClientTraceを組み合わせることで、HTTPリクエストの詳細なlatencyを可視化する方法を紹介しました。

私の場合は、この情報を元にして「コネクションの確立に時間がかかっているから、KeepAliveを長い時間有効にしてなるべくコネクションを使いまわそう」という感じでパフォーマンスチューニングの役に立てています。この記事が何かしらのパフォーマンスチューニングの役に立てば嬉しいです。

改訂2版 みんなのGo言語

改訂2版 みんなのGo言語

Go言語における並行処理 - ユースケース編

はじめに

これは以下の記事の続きの記事。以下の2つではgoroutineとchannelについて説明したので、これらを使って具体的な並行処理のユースケースを書いてみる。

goroutineによる並行処理がすべて終わるまで待つ

処理を複数のgoroutineで並行で実行したい、というのはよくある例。起動したgoroutineがすべて終わるまで待ちたいときには、以下のようにsync.WaitGroupを使う。

package main

import (
    "fmt"
    "sync"
)

func main() {
    var wg sync.WaitGroup
    for i := 1; i <= 20; i++ {
        wg.Add(1) // カウンターをインクリメントする
        go func(i int) {
            fmt.Printf("i = %02d, fibonacci = %04d\n", i, fibonacci(i))
            defer wg.Done() // 処理が終わったのでカウンターをデクリメントする
        }(i)
    }
    wg.Wait() // カウンターが0になるまで待つ
    fmt.Println("Done")
}

func fibonacci(n int) int {
    if n <= 1 {
        return n
    }
    return fibonacci(n-1) + fibonacci(n-2)
}

goroutineで並行処理する数に上限を設けたい

よくある要件として「同時に実行する数を制限したい」があるが、この場合はセマフォというパターンで実装する。具体的には、Goであればchannelにバッファが付けられるので、このバッファの数で同時実行数を制限できる。

package main

import (
    "flag"
    "fmt"
    "io/ioutil"
    "net/http"
    "regexp"
    "sync"
    "time"
)

var (
    concurrency = flag.Int("c", 1, "num of concurrency")
)

func main() {
    flag.Parse()
    semaphore := make(chan struct{}, *concurrency) // 同時実行数
    var wg sync.WaitGroup
    urls := []string{
        "https://journal.lampetty.net/entry/what-i-like-about-heroku",
        "https://journal.lampetty.net/entry/e2e-test-with-agouti-in-go",
        "https://journal.lampetty.net/entry/heroku-custom-clock-processes",
        "https://journal.lampetty.net/entry/mac-settings-on-sierra",
        "https://journal.lampetty.net/entry/mysqldump-option-where",
        "https://journal.lampetty.net/entry/introducing-lekcije",
        "https://journal.lampetty.net/entry/intellij-shortcuts-for-reading-source-code",
        "https://journal.lampetty.net/entry/introducing-dead-mans-snitch",
        "https://journal.lampetty.net/entry/concurrency-in-go-channels",
        "https://journal.lampetty.net/entry/concurrency-in-go-goroutines",
        "https://journal.lampetty.net/entry/cancel-and-timeout-with-context-in-go",
        "https://journal.lampetty.net/entry/gcp-cloud-pubsub-memo",
        "https://journal.lampetty.net/entry/oauth2-client-handson-in-go-authorization-code-grant",
        "https://journal.lampetty.net/entry/satisfying-a-large-interface-quickly-in-go",
    }
    for _, u := range urls {
        wg.Add(1)
        u := u
        go func() {
            defer wg.Done()
            fetch(semaphore, u)
        }()
    }
    wg.Wait()
}

var r = regexp.MustCompile(`<title>(.*)</title>`)

func fetch(semaphore chan struct{}, url string) {
    semaphore <- struct{}{}
    defer func() {
        <-semaphore
    }()
    time.Sleep(3 * time.Second)
    resp, err := http.Get(url)
    if err != nil {
        fmt.Printf("err = %v\n", err)
        return
    }
    defer func() { _ = resp.Body.Close() }()

    bytes, err := ioutil.ReadAll(resp.Body)
    if err != nil {
        fmt.Printf("err = %v\n", err)
        return
    }
    body := string(bytes)
    if group := r.FindStringSubmatch(body); len(group) > 0 {
        fmt.Printf("%v\n", group[1])
    }
}

上記のプログラムはURLのリストからhttp.Getしてtitleだけを表示するプログラムである。ここではsemaphoreというバッファ付きのchannelを使って、以下のように同時実行数を制限できるようにしている。

  • mainの中でsemaphoreを生成
  • fetch関数にsemaphoreを渡す
  • fetchの内部で、処理を実行する前にsemaphoreにデータを入れて、処理が終わったらdeferでsemaphoreからデータを取り出している。これによりchannelのバッファを超える場合は処理がブロックされるようになる

以下のように実行時に-c 3と指定することで、同時にhttp.Getする数が3つに制限されてコンソールに出力される数が3行ずつになるはず。

$ go run semaphore.go -c 3

Herokuの好きなところ - oinume journal
Better Heroku Schedulerを探したらCustom clock processesにたどり着いた - oinume journal
WebアプリケーションのE2EテストをGoで書く - oinume journal
...

バックグラウンドで一定の間隔で処理を行いたい

これはtime.Tickerとselectを使うことで簡単に実装できる。以下は1秒ごとにdoSomethingを呼び出すプログラム。

package main

import (
    "fmt"
    "time"
)

func main() {
    ticker := time.NewTicker(time.Second)
    defer ticker.Stop()
    for i := 0; i < 10; i++ {
        select {
        case <-ticker.C:
            doSomething(i)
        }
    }
}

func doSomething(v int) {
    fmt.Printf("%d\n", v)
}

まとめ

ユースケースについては探せばもっとありそうだけど、よくありそうな並行処理の実装パターン3つを紹介した。何かのためになれば幸いです。

Go言語による並行処理

Go言語による並行処理

  • 作者:Katherine Cox-Buday
  • 出版社/メーカー: オライリージャパン
  • 発売日: 2018/10/26
  • メディア: 単行本(ソフトカバー)

2019年9月の振り返り

8月の振り返りをサボってしまったのでまとめて。

アウトプット

Goの並行処理の記事とMySQL 8.0へアップデートする記事を書いた。

睡眠

1日6時間以上寝る、ということを今年の目標にしている。ヘルスケアアプリによると

  • 8月: 6h10min
  • 9月: 5h59min

という感じで9月はギリギリで未達成。しかもこれ平均で平日は大体5時間ぐらいなのでかなりやばめ。

英語

9月にIELTSのテストを受けてきた。詳細については以下にまとめたけど、感触としては悪くない気がする。ちなみに11月にTOEICも受ける予定。あと来年前半にTOEFLもおそらく受ける。

https://journal.lampetty.net/entry/taking-ielts-test-first-time:ttile

アルゴリズム

特に進捗なし

Go, gRPC, SQLの復習

引き続き Go言語による並行処理 を読んでいる。あと一つ記事を書きたい。

まとめ

まぁボチボチ頑張る。