Zenn
Closed9

フィボナッチと並行処理

Go
concurrency
SpiegelSpiegel

今回使ったコードは以下の通り

sample1.go
//go:build run
// +build run

package main

import (
    "fmt"
    "log"
    "os"
)

var logger = log.New(os.Stdout, "", log.LstdFlags|log.Lmicroseconds)

func fibonacci(done <-chan bool, c chan<- int) {
    x, y := 0, 1

    for {
        select {
        case c <- x:
            x, y = y, x+y
            logger.Println("フィボナッチの方")
        case <-done:
            fmt.Println("quit")
            return
        }
    }
}

func main() {
    c := make(chan int)
    done := make(chan bool)
    go func() {
        for i := 0; i < 10; i++ {
            logger.Println("Goルーチンの方:", <-c)
        }
        close(done)
    }()
    fibonacci(done, c)
}

これを複数回実行してみる。ちなみに Windows 環境。

SpiegelSpiegel

パターン1：

$ go run sample1.go
2021/09/28 10:11:09.505296 Goルーチンの方: 0
2021/09/28 10:11:09.505296 フィボナッチの方
2021/09/28 10:11:09.546633 フィボナッチの方
2021/09/28 10:11:09.546633 Goルーチンの方: 1
2021/09/28 10:11:09.546633 Goルーチンの方: 1
2021/09/28 10:11:09.546633 フィボナッチの方
2021/09/28 10:11:09.546633 フィボナッチの方
2021/09/28 10:11:09.546633 Goルーチンの方: 2
2021/09/28 10:11:09.547166 Goルーチンの方: 3
2021/09/28 10:11:09.547166 フィボナッチの方
2021/09/28 10:11:09.547166 フィボナッチの方
2021/09/28 10:11:09.547166 Goルーチンの方: 5
2021/09/28 10:11:09.547166 Goルーチンの方: 8
2021/09/28 10:11:09.547166 フィボナッチの方
2021/09/28 10:11:09.547706 フィボナッチの方
2021/09/28 10:11:09.547706 Goルーチンの方: 13
2021/09/28 10:11:09.547706 Goルーチンの方: 21
2021/09/28 10:11:09.547706 フィボナッチの方
2021/09/28 10:11:09.548226 フィボナッチの方
2021/09/28 10:11:09.548226 Goルーチンの方: 34
quit

パターン2：

$ go run sample1.go
2021/09/28 10:11:50.443755 Goルーチンの方: 0
2021/09/28 10:11:50.443755 フィボナッチの方
2021/09/28 10:11:50.499196 フィボナッチの方
2021/09/28 10:11:50.499196 Goルーチンの方: 1
2021/09/28 10:11:50.499739 フィボナッチの方
2021/09/28 10:11:50.499739 Goルーチンの方: 1
2021/09/28 10:11:50.499739 Goルーチンの方: 2
2021/09/28 10:11:50.499739 フィボナッチの方
2021/09/28 10:11:50.499739 フィボナッチの方
2021/09/28 10:11:50.499739 Goルーチンの方: 3
2021/09/28 10:11:50.499739 Goルーチンの方: 5
2021/09/28 10:11:50.500255 フィボナッチの方
2021/09/28 10:11:50.500340 フィボナッチの方
2021/09/28 10:11:50.500340 Goルーチンの方: 8
2021/09/28 10:11:50.500340 Goルーチンの方: 13
2021/09/28 10:11:50.500340 フィボナッチの方
2021/09/28 10:11:50.500340 フィボナッチの方
2021/09/28 10:11:50.500340 Goルーチンの方: 21
2021/09/28 10:11:50.500888 Goルーチンの方: 34
2021/09/28 10:11:50.500888 フィボナッチの方
quit

パターン3：

$ go run sample1.go
2021/09/28 10:12:48.602996 フィボナッチの方
2021/09/28 10:12:48.602996 Goルーチンの方: 0
2021/09/28 10:12:48.643081 Goルーチンの方: 1
2021/09/28 10:12:48.643081 フィボナッチの方
2021/09/28 10:12:48.643081 フィボナッチの方
2021/09/28 10:12:48.643081 Goルーチンの方: 1
2021/09/28 10:12:48.643081 Goルーチンの方: 2
2021/09/28 10:12:48.643081 フィボナッチの方
2021/09/28 10:12:48.643081 フィボナッチの方
2021/09/28 10:12:48.643081 Goルーチンの方: 3
2021/09/28 10:12:48.644083 Goルーチンの方: 5
2021/09/28 10:12:48.644083 フィボナッチの方
2021/09/28 10:12:48.644083 フィボナッチの方
2021/09/28 10:12:48.644083 Goルーチンの方: 8
2021/09/28 10:12:48.644083 Goルーチンの方: 13
2021/09/28 10:12:48.644083 フィボナッチの方
2021/09/28 10:12:48.644083 フィボナッチの方
2021/09/28 10:12:48.644083 Goルーチンの方: 21
2021/09/28 10:12:48.644083 Goルーチンの方: 34
2021/09/28 10:12:48.644083 フィボナッチの方
quit
SpiegelSpiegel

元々 Go は OS や MPU のスレッド詳細が完全に隠蔽されている。 CPU コアのキャッシュ動作も含めて考えると昔懐かしいタイムシェアリング的なイメージで goroutine を捉えるのは相当危険である。さらに Go 1.14 では goroutine のスケジューリングは preemptive になった。あるリソースに対する処理が特定のイベントでスイッチするとは限らないのだ。

今回の場合

logger.Println("フィボナッチの方")

と

logger.Println("Goルーチンの方:", <-c)

は異なる goroutine 下で動作し，しかもほぼ同時に発生する。どちらが先に標準出力を占有できるかは運しだい，と言うしかない。それでも同じ goroutine の出力が連続で出やすいというのは何か理由があるのだろうが，私には分からなかった。 tweet 主の @nobonobo さんも説明に困っておられるようだ。

でも，これって Linux 環境だと挙動が違うよね，多分。あとで試してみよう。

SpiegelSpiegel

フィボナッチ数列生成側がメイン goroutine で，受け取る側がサブ goroutine という構成は気持ち悪いので，フィボナッチ数列生成側をサブ goroutine として generater pattern に持ち込んでみた。

sample2.go
//go:build run
// +build run

package main

import (
    "fmt"
    "log"
    "os"
)

var logger = log.New(os.Stdout, "", log.LstdFlags|log.Lmicroseconds)

func fibonacci(done <-chan bool) <-chan int {
    x, y := 0, 1
    c := make(chan int)
    go func() {
        defer close(c)
        for {
            select {
            case c <- x: // no blocking (through if buffer full)
                x, y = y, x+y
                logger.Println("next fibonacci number:", x)
            case <-done: // close event
                fmt.Println("quit")
                return
            default:
            }
        }
    }()
    return c
}

func main() {
    done := make(chan bool)
    c := fibonacci(done)
    for i := 0; i < 10; i++ {
        logger.Println("get fibonacci number:", <-c)
    }
    close(done) // trigger close event
    for {       // waiting for closing channel
        if _, ok := <-c; !ok {
            break
        }
    }
}

これを実行すると

$ go run sample2.go
2021/09/28 11:51:17.977164 next fibonacci number: 1
2021/09/28 11:51:17.977164 get fibonacci number: 0
2021/09/28 11:51:18.018674 next fibonacci number: 1
2021/09/28 11:51:18.018674 get fibonacci number: 1
2021/09/28 11:51:18.019238 next fibonacci number: 2
2021/09/28 11:51:18.019238 get fibonacci number: 1
2021/09/28 11:51:18.019238 next fibonacci number: 3
2021/09/28 11:51:18.019238 get fibonacci number: 2
2021/09/28 11:51:18.019824 next fibonacci number: 5
2021/09/28 11:51:18.019824 get fibonacci number: 3
2021/09/28 11:51:18.019824 next fibonacci number: 8
2021/09/28 11:51:18.019824 get fibonacci number: 5
2021/09/28 11:51:18.020384 next fibonacci number: 13
2021/09/28 11:51:18.020384 get fibonacci number: 8
2021/09/28 11:51:18.020384 next fibonacci number: 21
2021/09/28 11:51:18.020384 get fibonacci number: 13
2021/09/28 11:51:18.021006 get fibonacci number: 21
2021/09/28 11:51:18.021006 next fibonacci number: 34
2021/09/28 11:51:18.021006 next fibonacci number: 55
2021/09/28 11:51:18.021006 get fibonacci number: 34
2021/09/28 11:51:18.021006 next fibonacci number: 89
quit

傾向が変わってきたねぇ。この辺がポイントかも知れん。

SpiegelSpiegel

更に，上のコードでチャネル c を

sample3.go
c := make(chan int, 1)

とすると

$ go run sample3.go
2021/09/28 11:53:39.591597 next fibonacci number: 1
2021/09/28 11:53:39.641526 next fibonacci number: 1
2021/09/28 11:53:39.591597 get fibonacci number: 0
2021/09/28 11:53:39.641526 get fibonacci number: 1
2021/09/28 11:53:39.641526 get fibonacci number: 1
2021/09/28 11:53:39.641526 next fibonacci number: 2
2021/09/28 11:53:39.642096 next fibonacci number: 3
2021/09/28 11:53:39.642096 next fibonacci number: 5
2021/09/28 11:53:39.642096 get fibonacci number: 2
2021/09/28 11:53:39.642096 get fibonacci number: 3
2021/09/28 11:53:39.642652 get fibonacci number: 5
2021/09/28 11:53:39.642096 next fibonacci number: 8
2021/09/28 11:53:39.642652 get fibonacci number: 8
2021/09/28 11:53:39.642652 next fibonacci number: 13
2021/09/28 11:53:39.642652 next fibonacci number: 21
2021/09/28 11:53:39.643170 next fibonacci number: 34
2021/09/28 11:53:39.642652 get fibonacci number: 13
2021/09/28 11:53:39.643203 get fibonacci number: 21
2021/09/28 11:53:39.643203 get fibonacci number: 34
2021/09/28 11:53:39.643203 next fibonacci number: 55
quit

てな感じになる。ログの時刻が逆転しとるがな。さらに最初の sample1.go のほうも

sample1-1.go
c := make(chan int, 1)

として実行すると

$ go run sample1-1.go
2021/09/28 12:10:02.357825 フィボナッチの方
2021/09/28 12:10:02.400769 フィボナッチの方
2021/09/28 12:10:02.357825 Goルーチンの方: 0
2021/09/28 12:10:02.400769 Goルーチンの方: 1
2021/09/28 12:10:02.401299 Goルーチンの方: 1
2021/09/28 12:10:02.400769 フィボナッチの方
2021/09/28 12:10:02.401299 フィボナッチの方
2021/09/28 12:10:02.401299 フィボナッチの方
2021/09/28 12:10:02.401299 Goルーチンの方: 2
2021/09/28 12:10:02.401299 Goルーチンの方: 3
2021/09/28 12:10:02.401833 Goルーチンの方: 5
2021/09/28 12:10:02.401299 フィボナッチの方
2021/09/28 12:10:02.401833 フィボナッチの方
2021/09/28 12:10:02.401833 フィボナッチの方
2021/09/28 12:10:02.401833 Goルーチンの方: 8
2021/09/28 12:10:02.401833 Goルーチンの方: 13
2021/09/28 12:10:02.401833 Goルーチンの方: 21
2021/09/28 12:10:02.401833 フィボナッチの方
2021/09/28 12:10:02.402356 フィボナッチの方
2021/09/28 12:10:02.402356 フィボナッチの方
2021/09/28 12:10:02.402356 Goルーチンの方: 34
quit

と，こっちもログの時刻が逆転してる。ええもん見してもろた（笑）

SpiegelSpiegel

コピペですまん

https://twitter.com/nobonobo/status/1442462752602132484

  • 受信待機ブロックならgoroutineスイッチする
  • 受信完了したらgoroutine再開対象になる
  • 相手が送信待機済みで受信の場合は直ちに受信
  • 送信待機ブロックならgoroutineスイッチする
  • 送信完了したらgoroutine再開対象になる
  • 相手が受信待機済みで送信の場合は直ちに送信
SpiegelSpiegel

手元の Ubuntu 機で sample1.go を実行した結果

$ go run sample1.go 
2021/09/28 20:37:22.249353 Goルーチンの方: 0
2021/09/28 20:37:22.249477 フィボナッチの方
2021/09/28 20:37:22.249507 フィボナッチの方
2021/09/28 20:37:22.249547 Goルーチンの方: 1
2021/09/28 20:37:22.249566 Goルーチンの方: 1
2021/09/28 20:37:22.249579 フィボナッチの方
2021/09/28 20:37:22.249588 フィボナッチの方
2021/09/28 20:37:22.249595 Goルーチンの方: 2
2021/09/28 20:37:22.249603 Goルーチンの方: 3
2021/09/28 20:37:22.249609 フィボナッチの方
2021/09/28 20:37:22.249621 フィボナッチの方
2021/09/28 20:37:22.249629 Goルーチンの方: 5
2021/09/28 20:37:22.249637 Goルーチンの方: 8
2021/09/28 20:37:22.249643 フィボナッチの方
2021/09/28 20:37:22.249649 フィボナッチの方
2021/09/28 20:37:22.249653 Goルーチンの方: 13
2021/09/28 20:37:22.249658 Goルーチンの方: 21
2021/09/28 20:37:22.249662 フィボナッチの方
2021/09/28 20:37:22.249667 フィボナッチの方
2021/09/28 20:37:22.249671 Goルーチンの方: 34
quit

あっマイクロ秒単位でちゃんと表示されてる（笑） 何回かやったけど，このパターンのみしか出てこなかった。

次に sample2.go のほう。

$ go run sample2.go 
2021/09/28 20:38:22.379395 next fibonacci number: 1
2021/09/28 20:38:22.379452 get fibonacci number: 0
2021/09/28 20:38:22.379612 next fibonacci number: 1
2021/09/28 20:38:22.379679 get fibonacci number: 1
2021/09/28 20:38:22.379685 next fibonacci number: 2
2021/09/28 20:38:22.379750 get fibonacci number: 1
2021/09/28 20:38:22.379756 next fibonacci number: 3
2021/09/28 20:38:22.379820 get fibonacci number: 2
2021/09/28 20:38:22.379827 next fibonacci number: 5
2021/09/28 20:38:22.379831 get fibonacci number: 3
2021/09/28 20:38:22.379837 next fibonacci number: 8
2021/09/28 20:38:22.379895 get fibonacci number: 5
2021/09/28 20:38:22.379901 next fibonacci number: 13
2021/09/28 20:38:22.379965 get fibonacci number: 8
2021/09/28 20:38:22.379972 next fibonacci number: 21
2021/09/28 20:38:22.380048 get fibonacci number: 13
2021/09/28 20:38:22.380053 next fibonacci number: 34
2021/09/28 20:38:22.380112 get fibonacci number: 21
2021/09/28 20:38:22.380118 next fibonacci number: 55
2021/09/28 20:38:22.380182 get fibonacci number: 34
quit

これもまともにマイクロ秒単位で出力されている以外は同じかな。

次は sample1-1.go のほう。バッファ付きチャネルを使ったやつやね。

$ go run sample1-1.go 
2021/09/28 20:41:44.524961 フィボナッチの方
2021/09/28 20:41:44.525063 フィボナッチの方
2021/09/28 20:41:44.525048 Goルーチンの方: 0
2021/09/28 20:41:44.525095 Goルーチンの方: 1
2021/09/28 20:41:44.525101 Goルーチンの方: 1
2021/09/28 20:41:44.525122 フィボナッチの方
2021/09/28 20:41:44.525130 フィボナッチの方
2021/09/28 20:41:44.525136 フィボナッチの方
2021/09/28 20:41:44.525143 Goルーチンの方: 2
2021/09/28 20:41:44.525150 Goルーチンの方: 3
2021/09/28 20:41:44.525155 Goルーチンの方: 5
2021/09/28 20:41:44.525163 フィボナッチの方
2021/09/28 20:41:44.525172 フィボナッチの方
2021/09/28 20:41:44.525178 フィボナッチの方
2021/09/28 20:41:44.525185 Goルーチンの方: 8
2021/09/28 20:41:44.525191 Goルーチンの方: 13
2021/09/28 20:41:44.525197 Goルーチンの方: 21
2021/09/28 20:41:44.525203 フィボナッチの方
2021/09/28 20:41:44.525209 フィボナッチの方
2021/09/28 20:41:44.525213 フィボナッチの方
2021/09/28 20:41:44.525219 Goルーチンの方: 34
quit

おっ，こっちでもログ時刻が逆転してる。ついでなので sample3.go もやっておく。

$ go run sample3.go 
2021/09/28 20:44:29.348319 next fibonacci number: 1
2021/09/28 20:44:29.348414 next fibonacci number: 1
2021/09/28 20:44:29.348377 get fibonacci number: 0
2021/09/28 20:44:29.348457 get fibonacci number: 1
2021/09/28 20:44:29.348458 next fibonacci number: 2
2021/09/28 20:44:29.348464 get fibonacci number: 1
2021/09/28 20:44:29.348484 get fibonacci number: 2
2021/09/28 20:44:29.348473 next fibonacci number: 3
2021/09/28 20:44:29.348518 next fibonacci number: 5
2021/09/28 20:44:29.348524 next fibonacci number: 8
2021/09/28 20:44:29.348609 get fibonacci number: 3
2021/09/28 20:44:29.348617 get fibonacci number: 5
2021/09/28 20:44:29.348618 next fibonacci number: 13
2021/09/28 20:44:29.348641 next fibonacci number: 21
2021/09/28 20:44:29.348626 get fibonacci number: 8
2021/09/28 20:44:29.348658 get fibonacci number: 13
2021/09/28 20:44:29.348662 get fibonacci number: 21
2021/09/28 20:44:29.348659 next fibonacci number: 34
2021/09/28 20:44:29.348678 next fibonacci number: 55
2021/09/28 20:44:29.348683 next fibonacci number: 89
2021/09/28 20:44:29.348697 get fibonacci number: 34
quit

こっちも同様かな。

結局，標準出力への出力が重たくて，実際に何がどういうタイミングで起こってるのか分かりにくいよね。これ以上は無理かなぁ...

このスクラップは2021/10/06にクローズされました