これは2025のScalaアドベントカレンダーの14日目の記事です。
昨日は xuweiさんの
でした
FS2 Stream の並列化処理の落とし穴
この記事で扱うこと
FS2 の Stream を chunk 単位で処理して、進捗がわかるログも出して さらにパフォーマンス改善のために並列化もされていてる実装があり、そこにさらに修正を行うときに見つけた不具合について共有します。
並列化されているはずなのに想定より明らかに処理に時間がかかるという問題に遭遇しました。
この問題が発生した原因と解決案、またその時の注意点について共有します。
環境
- scala "3.7.1"
- lib "co.fs2::fs2-io:2.5.12"
前提
- 入力:Stream[IO, A](今回は 1 to 100 が流れる)
- chunkN(chunkSize) で chunk 化し、chunk 毎に処理する
- 各アイテムの処理に 1 秒かかる想定
- StreamProgressLogger という基盤コードを利用する
次のような stream 利用して検証を行います
val stream1 = Stream.emits((1 to 100).toList).covary[IO]
StreamProgressLogger
Stream の処理の進捗を確認するために chunk ごとに分割して index を付与し処理の前後でログを出力する基盤コードがあります。
object StreamProgressLogger { def progress[A, B]( chunkSize: Int, stream: => Stream[IO, A] )( execute: Pipe[IO, Chunk[A], B] ): Stream[IO, B] = stream .chunkN(chunkSize) .zipWithIndex .flatMap { case (chunk, index) => for { _ <- Stream.eval(IO.delay(println(s"index: $index start polling stream"))) result <- execute(Stream.emit(chunk)) _ <- Stream.eval(IO.delay(println(s"index: $index end polling stream"))) } yield result } }
※今回の問題が発現する最低限の実装にしています
普段の実装
弊社で Stream を利用した処理を利用する場合は次のような StreamProgressLogger を利用した実装をしています。
val chunkSize = 10 StreamProgressLogger.progress(chunkSize, stream1)( _.evalMap(_.toList.pure[IO]) .evalMap( _.traverse{ value => // 1件の処理時間が1sかかるとする IO.sleep(1.second) *> IO.delay{ val th = Thread.currentThread.getName println(s"[${Instant.now}] [$th] processed value: ${value}") } } ) )
実行結果
index: 0 start polling stream [2025-12-14T00:47:56.632678Z] [scala-execution-context-global-15] processed value: 1 [2025-12-14T00:47:57.639903Z] [scala-execution-context-global-15] processed value: 2 [2025-12-14T00:47:58.643818Z] [scala-execution-context-global-15] processed value: 3 [2025-12-14T00:47:59.648911Z] [scala-execution-context-global-15] processed value: 4 [2025-12-14T00:48:00.654425Z] [scala-execution-context-global-15] processed value: 5 [2025-12-14T00:48:01.658471Z] [scala-execution-context-global-15] processed value: 6 [2025-12-14T00:48:02.664106Z] [scala-execution-context-global-15] processed value: 7 [2025-12-14T00:48:03.668296Z] [scala-execution-context-global-15] processed value: 8 [2025-12-14T00:48:04.672399Z] [scala-execution-context-global-15] processed value: 9 [2025-12-14T00:48:05.677061Z] [scala-execution-context-global-15] processed value: 10 index: 0 end polling stream index: 1 start polling stream [2025-12-14T00:48:06.684323Z] [scala-execution-context-global-15] processed value: 11 [2025-12-14T00:48:07.686396Z] [scala-execution-context-global-15] processed value: 12 [2025-12-14T00:48:08.690626Z] [scala-execution-context-global-15] processed value: 13 [2025-12-14T00:48:09.692465Z] [scala-execution-context-global-15] processed value: 14 [2025-12-14T00:48:10.696527Z] [scala-execution-context-global-15] processed value: 15 [2025-12-14T00:48:11.702045Z] [scala-execution-context-global-15] processed value: 16 [2025-12-14T00:48:12.707277Z] [scala-execution-context-global-15] processed value: 17 [2025-12-14T00:48:13.712269Z] [scala-execution-context-global-15] processed value: 18 [2025-12-14T00:48:14.717250Z] [scala-execution-context-global-15] processed value: 19 [2025-12-14T00:48:15.719001Z] [scala-execution-context-global-15] processed value: 20 index: 1 end polling stream index: 2 start polling stream [2025-12-14T00:48:16.720437Z] [scala-execution-context-global-15] processed value: 21 [2025-12-14T00:48:17.725311Z] [scala-execution-context-global-15] processed value: 22 [2025-12-14T00:48:18.729721Z] [scala-execution-context-global-15] processed value: 23 [2025-12-14T00:48:19.735382Z] [scala-execution-context-global-15] processed value: 24 [2025-12-14T00:48:20.740723Z] [scala-execution-context-global-15] processed value: 25 [2025-12-14T00:48:21.746114Z] [scala-execution-context-global-15] processed value: 26 [2025-12-14T00:48:22.749048Z] [scala-execution-context-global-15] processed value: 27 [2025-12-14T00:48:23.751993Z] [scala-execution-context-global-15] processed value: 28 [2025-12-14T00:48:24.754909Z] [scala-execution-context-global-15] processed value: 29 [2025-12-14T00:48:25.760454Z] [scala-execution-context-global-15] processed value: 30 index: 2 end polling stream index: 3 start polling stream [2025-12-14T00:48:26.767155Z] [scala-execution-context-global-15] processed value: 31 [2025-12-14T00:48:27.770670Z] [scala-execution-context-global-15] processed value: 32 [2025-12-14T00:48:28.771865Z] [scala-execution-context-global-15] processed value: 33 [2025-12-14T00:48:29.777610Z] [scala-execution-context-global-15] processed value: 34 [2025-12-14T00:48:30.781722Z] [scala-execution-context-global-15] processed value: 35 [2025-12-14T00:48:31.783052Z] [scala-execution-context-global-15] processed value: 36 [2025-12-14T00:48:32.786116Z] [scala-execution-context-global-15] processed value: 37 [2025-12-14T00:48:33.789667Z] [scala-execution-context-global-15] processed value: 38 [2025-12-14T00:48:34.795086Z] [scala-execution-context-global-15] processed value: 39 [2025-12-14T00:48:35.798654Z] [scala-execution-context-global-15] processed value: 40 index: 3 end polling stream index: 4 start polling stream [2025-12-14T00:48:36.806019Z] [scala-execution-context-global-15] processed value: 41 [2025-12-14T00:48:37.810381Z] [scala-execution-context-global-15] processed value: 42 [2025-12-14T00:48:38.811492Z] [scala-execution-context-global-15] processed value: 43 [2025-12-14T00:48:39.816896Z] [scala-execution-context-global-15] processed value: 44 [2025-12-14T00:48:40.818793Z] [scala-execution-context-global-15] processed value: 45 [2025-12-14T00:48:41.822896Z] [scala-execution-context-global-15] processed value: 46 [2025-12-14T00:48:42.828527Z] [scala-execution-context-global-15] processed value: 47 [2025-12-14T00:48:43.833709Z] [scala-execution-context-global-15] processed value: 48 [2025-12-14T00:48:44.837558Z] [scala-execution-context-global-15] processed value: 49 [2025-12-14T00:48:45.843282Z] [scala-execution-context-global-15] processed value: 50 index: 4 end polling stream index: 5 start polling stream [2025-12-14T00:48:46.845557Z] [scala-execution-context-global-15] processed value: 51 [2025-12-14T00:48:47.851207Z] [scala-execution-context-global-15] processed value: 52 [2025-12-14T00:48:48.853295Z] [scala-execution-context-global-15] processed value: 53 [2025-12-14T00:48:49.859490Z] [scala-execution-context-global-15] processed value: 54 [2025-12-14T00:48:50.863081Z] [scala-execution-context-global-15] processed value: 55 [2025-12-14T00:48:51.866392Z] [scala-execution-context-global-15] processed value: 56 [2025-12-14T00:48:52.869021Z] [scala-execution-context-global-15] processed value: 57 [2025-12-14T00:48:53.874905Z] [scala-execution-context-global-15] processed value: 58 [2025-12-14T00:48:54.877553Z] [scala-execution-context-global-15] processed value: 59 [2025-12-14T00:48:55.880214Z] [scala-execution-context-global-15] processed value: 60 index: 5 end polling stream index: 6 start polling stream [2025-12-14T00:48:56.884569Z] [scala-execution-context-global-15] processed value: 61 [2025-12-14T00:48:57.886311Z] [scala-execution-context-global-15] processed value: 62 [2025-12-14T00:48:58.891856Z] [scala-execution-context-global-15] processed value: 63 [2025-12-14T00:48:59.893330Z] [scala-execution-context-global-15] processed value: 64 [2025-12-14T00:49:00.898849Z] [scala-execution-context-global-15] processed value: 65 [2025-12-14T00:49:01.902743Z] [scala-execution-context-global-15] processed value: 66 [2025-12-14T00:49:02.908172Z] [scala-execution-context-global-15] processed value: 67 [2025-12-14T00:49:03.909374Z] [scala-execution-context-global-15] processed value: 68 [2025-12-14T00:49:04.909938Z] [scala-execution-context-global-15] processed value: 69 [2025-12-14T00:49:05.913690Z] [scala-execution-context-global-15] processed value: 70 index: 6 end polling stream index: 7 start polling stream [2025-12-14T00:49:06.918547Z] [scala-execution-context-global-15] processed value: 71 [2025-12-14T00:49:07.924102Z] [scala-execution-context-global-15] processed value: 72 [2025-12-14T00:49:08.924991Z] [scala-execution-context-global-15] processed value: 73 [2025-12-14T00:49:09.930485Z] [scala-execution-context-global-15] processed value: 74 [2025-12-14T00:49:10.932433Z] [scala-execution-context-global-15] processed value: 75 [2025-12-14T00:49:11.934621Z] [scala-execution-context-global-15] processed value: 76 [2025-12-14T00:49:12.939041Z] [scala-execution-context-global-15] processed value: 77 [2025-12-14T00:49:13.941173Z] [scala-execution-context-global-15] processed value: 78 [2025-12-14T00:49:14.946023Z] [scala-execution-context-global-15] processed value: 79 [2025-12-14T00:49:15.951248Z] [scala-execution-context-global-15] processed value: 80 index: 7 end polling stream index: 8 start polling stream [2025-12-14T00:49:16.957514Z] [scala-execution-context-global-15] processed value: 81 [2025-12-14T00:49:17.962589Z] [scala-execution-context-global-15] processed value: 82 [2025-12-14T00:49:18.964295Z] [scala-execution-context-global-15] processed value: 83 [2025-12-14T00:49:19.968126Z] [scala-execution-context-global-15] processed value: 84 [2025-12-14T00:49:20.973614Z] [scala-execution-context-global-15] processed value: 85 [2025-12-14T00:49:21.996175Z] [scala-execution-context-global-15] processed value: 86 [2025-12-14T00:49:23.001488Z] [scala-execution-context-global-15] processed value: 87 [2025-12-14T00:49:24.003584Z] [scala-execution-context-global-15] processed value: 88 [2025-12-14T00:49:25.007103Z] [scala-execution-context-global-15] processed value: 89 [2025-12-14T00:49:26.012730Z] [scala-execution-context-global-15] processed value: 90 index: 8 end polling stream index: 9 start polling stream [2025-12-14T00:49:27.017581Z] [scala-execution-context-global-15] processed value: 91 [2025-12-14T00:49:28.020723Z] [scala-execution-context-global-15] processed value: 92 [2025-12-14T00:49:29.025231Z] [scala-execution-context-global-15] processed value: 93 [2025-12-14T00:49:30.026422Z] [scala-execution-context-global-15] processed value: 94 [2025-12-14T00:49:31.028912Z] [scala-execution-context-global-15] processed value: 95 [2025-12-14T00:49:32.029908Z] [scala-execution-context-global-15] processed value: 96 [2025-12-14T00:49:33.033808Z] [scala-execution-context-global-15] processed value: 97 [2025-12-14T00:49:34.037280Z] [scala-execution-context-global-15] processed value: 98 [2025-12-14T00:49:35.038440Z] [scala-execution-context-global-15] processed value: 99 [2025-12-14T00:49:36.041779Z] [scala-execution-context-global-15] processed value: 100 index: 9 end polling stream
47:56 ~ 49:36 => 処理に 100s かかっている (ログの出し方とか sleep の位置の問題などで正確には 101s のはずだが便宜上 100s とする)
今回問題になった実装
パフォーマンス改善として、次のように execute(Pipe)の中で parEvalMapUnordered を利用して非同期化する実装になっていました。
val chunkSize = 10 val parallelSize = 2 StreamProgressLogger.progress(chunkSize, stream1)( _.evalMap(_.toList.pure[IO]) .parEvalMapUnordered(parallelSize)( _.traverse { value => IO.sleep(1.second) *> IO.delay(println(s"processed: $value")) } ) )
ところが、今回更なるパフォーマンス改善のために調査を行なった際、ここの処理が実態として並列化されていないことがわかりました。
実行結果
index: 0 start polling stream [2025-12-14T00:51:55.801422Z] [scala-execution-context-global-15] processed value: 1 [2025-12-14T00:51:56.810910Z] [scala-execution-context-global-15] processed value: 2 [2025-12-14T00:51:57.814442Z] [scala-execution-context-global-15] processed value: 3 [2025-12-14T00:51:58.819894Z] [scala-execution-context-global-15] processed value: 4 [2025-12-14T00:51:59.824292Z] [scala-execution-context-global-15] processed value: 5 [2025-12-14T00:52:00.828281Z] [scala-execution-context-global-15] processed value: 6 [2025-12-14T00:52:01.834113Z] [scala-execution-context-global-15] processed value: 7 [2025-12-14T00:52:02.839476Z] [scala-execution-context-global-15] processed value: 8 [2025-12-14T00:52:03.844230Z] [scala-execution-context-global-15] processed value: 9 [2025-12-14T00:52:04.849574Z] [scala-execution-context-global-15] processed value: 10 index: 0 end polling stream index: 1 start polling stream [2025-12-14T00:52:05.877181Z] [scala-execution-context-global-20] processed value: 11 [2025-12-14T00:52:06.879170Z] [scala-execution-context-global-20] processed value: 12 [2025-12-14T00:52:07.880962Z] [scala-execution-context-global-20] processed value: 13 [2025-12-14T00:52:08.886544Z] [scala-execution-context-global-20] processed value: 14 [2025-12-14T00:52:09.890149Z] [scala-execution-context-global-20] processed value: 15 [2025-12-14T00:52:10.895794Z] [scala-execution-context-global-20] processed value: 16 [2025-12-14T00:52:11.901045Z] [scala-execution-context-global-20] processed value: 17 [2025-12-14T00:52:12.906595Z] [scala-execution-context-global-20] processed value: 18 [2025-12-14T00:52:13.909442Z] [scala-execution-context-global-20] processed value: 19 [2025-12-14T00:52:14.915007Z] [scala-execution-context-global-20] processed value: 20 index: 1 end polling stream index: 2 start polling stream [2025-12-14T00:52:15.938972Z] [scala-execution-context-global-21] processed value: 21 [2025-12-14T00:52:16.944180Z] [scala-execution-context-global-21] processed value: 22 [2025-12-14T00:52:17.950109Z] [scala-execution-context-global-21] processed value: 23 [2025-12-14T00:52:18.955897Z] [scala-execution-context-global-21] processed value: 24 [2025-12-14T00:52:19.958521Z] [scala-execution-context-global-21] processed value: 25 [2025-12-14T00:52:20.961081Z] [scala-execution-context-global-21] processed value: 26 [2025-12-14T00:52:21.962554Z] [scala-execution-context-global-21] processed value: 27 [2025-12-14T00:52:22.972440Z] [scala-execution-context-global-21] processed value: 28 [2025-12-14T00:52:23.978286Z] [scala-execution-context-global-21] processed value: 29 [2025-12-14T00:52:24.979712Z] [scala-execution-context-global-21] processed value: 30 index: 2 end polling stream index: 3 start polling stream [2025-12-14T00:52:25.999360Z] [scala-execution-context-global-20] processed value: 31 [2025-12-14T00:52:27.003159Z] [scala-execution-context-global-20] processed value: 32 [2025-12-14T00:52:28.005511Z] [scala-execution-context-global-20] processed value: 33 [2025-12-14T00:52:29.011158Z] [scala-execution-context-global-20] processed value: 34 [2025-12-14T00:52:30.015882Z] [scala-execution-context-global-20] processed value: 35 [2025-12-14T00:52:31.021436Z] [scala-execution-context-global-20] processed value: 36 [2025-12-14T00:52:32.025126Z] [scala-execution-context-global-20] processed value: 37 [2025-12-14T00:52:33.026332Z] [scala-execution-context-global-20] processed value: 38 [2025-12-14T00:52:34.028756Z] [scala-execution-context-global-20] processed value: 39 [2025-12-14T00:52:35.034212Z] [scala-execution-context-global-20] processed value: 40 index: 3 end polling stream index: 4 start polling stream [2025-12-14T00:52:36.053724Z] [scala-execution-context-global-20] processed value: 41 [2025-12-14T00:52:37.058206Z] [scala-execution-context-global-20] processed value: 42 [2025-12-14T00:52:38.063105Z] [scala-execution-context-global-20] processed value: 43 [2025-12-14T00:52:39.068519Z] [scala-execution-context-global-20] processed value: 44 [2025-12-14T00:52:40.074621Z] [scala-execution-context-global-20] processed value: 45 [2025-12-14T00:52:41.079046Z] [scala-execution-context-global-20] processed value: 46 [2025-12-14T00:52:42.081744Z] [scala-execution-context-global-20] processed value: 47 [2025-12-14T00:52:43.087293Z] [scala-execution-context-global-20] processed value: 48 [2025-12-14T00:52:44.088005Z] [scala-execution-context-global-20] processed value: 49 [2025-12-14T00:52:45.093640Z] [scala-execution-context-global-20] processed value: 50 index: 4 end polling stream index: 5 start polling stream [2025-12-14T00:52:46.111686Z] [scala-execution-context-global-16] processed value: 51 [2025-12-14T00:52:47.116672Z] [scala-execution-context-global-16] processed value: 52 [2025-12-14T00:52:48.119541Z] [scala-execution-context-global-16] processed value: 53 [2025-12-14T00:52:49.123085Z] [scala-execution-context-global-16] processed value: 54 [2025-12-14T00:52:50.127176Z] [scala-execution-context-global-16] processed value: 55 [2025-12-14T00:52:51.130441Z] [scala-execution-context-global-16] processed value: 56 [2025-12-14T00:52:52.135865Z] [scala-execution-context-global-16] processed value: 57 [2025-12-14T00:52:53.141538Z] [scala-execution-context-global-16] processed value: 58 [2025-12-14T00:52:54.147132Z] [scala-execution-context-global-16] processed value: 59 [2025-12-14T00:52:55.152529Z] [scala-execution-context-global-16] processed value: 60 index: 5 end polling stream index: 6 start polling stream [2025-12-14T00:52:56.163081Z] [scala-execution-context-global-14] processed value: 61 [2025-12-14T00:52:57.168704Z] [scala-execution-context-global-14] processed value: 62 [2025-12-14T00:52:58.171894Z] [scala-execution-context-global-14] processed value: 63 [2025-12-14T00:52:59.177378Z] [scala-execution-context-global-14] processed value: 64 [2025-12-14T00:53:00.182079Z] [scala-execution-context-global-14] processed value: 65 [2025-12-14T00:53:01.185572Z] [scala-execution-context-global-14] processed value: 66 [2025-12-14T00:53:02.191089Z] [scala-execution-context-global-14] processed value: 67 [2025-12-14T00:53:03.191960Z] [scala-execution-context-global-14] processed value: 68 [2025-12-14T00:53:04.195922Z] [scala-execution-context-global-14] processed value: 69 [2025-12-14T00:53:05.200906Z] [scala-execution-context-global-14] processed value: 70 index: 6 end polling stream index: 7 start polling stream [2025-12-14T00:53:06.216053Z] [scala-execution-context-global-21] processed value: 71 [2025-12-14T00:53:07.221029Z] [scala-execution-context-global-21] processed value: 72 [2025-12-14T00:53:08.225747Z] [scala-execution-context-global-21] processed value: 73 [2025-12-14T00:53:09.231110Z] [scala-execution-context-global-21] processed value: 74 [2025-12-14T00:53:10.235844Z] [scala-execution-context-global-21] processed value: 75 [2025-12-14T00:53:11.240934Z] [scala-execution-context-global-21] processed value: 76 [2025-12-14T00:53:12.245597Z] [scala-execution-context-global-21] processed value: 77 [2025-12-14T00:53:13.246839Z] [scala-execution-context-global-21] processed value: 78 [2025-12-14T00:53:14.251959Z] [scala-execution-context-global-21] processed value: 79 [2025-12-14T00:53:15.254538Z] [scala-execution-context-global-21] processed value: 80 index: 7 end polling stream index: 8 start polling stream [2025-12-14T00:53:16.268225Z] [scala-execution-context-global-14] processed value: 81 [2025-12-14T00:53:17.269104Z] [scala-execution-context-global-14] processed value: 82 [2025-12-14T00:53:18.274049Z] [scala-execution-context-global-14] processed value: 83 [2025-12-14T00:53:19.276544Z] [scala-execution-context-global-14] processed value: 84 [2025-12-14T00:53:20.282046Z] [scala-execution-context-global-14] processed value: 85 [2025-12-14T00:53:21.286924Z] [scala-execution-context-global-14] processed value: 86 [2025-12-14T00:53:22.291442Z] [scala-execution-context-global-14] processed value: 87 [2025-12-14T00:53:23.294064Z] [scala-execution-context-global-14] processed value: 88 [2025-12-14T00:53:24.297071Z] [scala-execution-context-global-14] processed value: 89 [2025-12-14T00:53:25.300914Z] [scala-execution-context-global-14] processed value: 90 index: 8 end polling stream index: 9 start polling stream [2025-12-14T00:53:26.312594Z] [scala-execution-context-global-17] processed value: 91 [2025-12-14T00:53:27.318190Z] [scala-execution-context-global-17] processed value: 92 [2025-12-14T00:53:28.323902Z] [scala-execution-context-global-17] processed value: 93 [2025-12-14T00:53:29.329175Z] [scala-execution-context-global-17] processed value: 94 [2025-12-14T00:53:30.331477Z] [scala-execution-context-global-17] processed value: 95 [2025-12-14T00:53:31.332847Z] [scala-execution-context-global-17] processed value: 96 [2025-12-14T00:53:32.338876Z] [scala-execution-context-global-17] processed value: 97 [2025-12-14T00:53:33.344368Z] [scala-execution-context-global-17] processed value: 98 [2025-12-14T00:53:34.349795Z] [scala-execution-context-global-17] processed value: 99 [2025-12-14T00:53:35.351482Z] [scala-execution-context-global-17] processed value: 100 index: 9 end polling stream
51:55 ~ 53:35 => 処理に 100s かかっている → 並列化していないものと処理時間が変わっていない
原因
この実装は execute に流れている要素数が「常に 1」になっていて、 progress は execute(Stream.emit(chunk)) を呼んでいます。つまり execute が受け取る入力は次のとおりです。
Stream[IO, Chunk[A]]
その Stream は chunk を 1 要素だけ emit して終わる
その結果、Pipe 内の parEvalMapUnordered(parallelSize) は次のような状態になります。
“並列化したい Stream 要素”が 1 個しか無い
よって並列度を上げても同時実行される単位が増えない
つまり「並列化の演算子を入れた場所は正しそうに見えるが、並列化する対象(Stream 要素)が 1 個しかない」ため、実態として並列数=1 となり速度に効きません。
対応案1:chunk 単位で並列化する
chunk 化の直後に parEvalMapUnordered を適用します。
def parallelProgress[A, B]( chunkSize: Int, parallelSize: Int, stream: => Stream[IO, A] )( execute: Chunk[A] => IO[B] ): Stream[IO, B] = stream .chunkN(chunkSize) .zipWithIndex .parEvalMapUnordered(parallelSize) { case (chunk, index) => for { _ <- IO.delay(println(s"index: $index start polling stream")) result <- execute(chunk) _ <- IO.delay(println(s"index: $index end polling stream")) } yield result }
実行結果
index: 0 start polling stream index: 1 start polling stream [2025-12-14T00:54:37.561205Z] [scala-execution-context-global-17] processed value: 1 [2025-12-14T00:54:37.561204Z] [scala-execution-context-global-16] processed value: 11 [2025-12-14T00:54:38.563054Z] [scala-execution-context-global-17] processed value: 2 [2025-12-14T00:54:38.563054Z] [scala-execution-context-global-16] processed value: 12 [2025-12-14T00:54:39.564030Z] [scala-execution-context-global-16] processed value: 13 [2025-12-14T00:54:39.564036Z] [scala-execution-context-global-17] processed value: 3 [2025-12-14T00:54:40.569457Z] [scala-execution-context-global-17] processed value: 4 [2025-12-14T00:54:40.569460Z] [scala-execution-context-global-16] processed value: 14 [2025-12-14T00:54:41.572006Z] [scala-execution-context-global-16] processed value: 5 [2025-12-14T00:54:41.571998Z] [scala-execution-context-global-17] processed value: 15 [2025-12-14T00:54:42.577257Z] [scala-execution-context-global-17] processed value: 6 [2025-12-14T00:54:42.577272Z] [scala-execution-context-global-16] processed value: 16 [2025-12-14T00:54:43.581273Z] [scala-execution-context-global-16] processed value: 7 [2025-12-14T00:54:43.581273Z] [scala-execution-context-global-17] processed value: 17 [2025-12-14T00:54:44.586609Z] [scala-execution-context-global-16] processed value: 18 [2025-12-14T00:54:44.586604Z] [scala-execution-context-global-17] processed value: 8 [2025-12-14T00:54:45.592229Z] [scala-execution-context-global-17] processed value: 19 [2025-12-14T00:54:45.592269Z] [scala-execution-context-global-16] processed value: 9 [2025-12-14T00:54:46.597164Z] [scala-execution-context-global-17] processed value: 20 [2025-12-14T00:54:46.597164Z] [scala-execution-context-global-16] processed value: 10 index: 0 end polling stream index: 1 end polling stream index: 2 start polling stream index: 3 start polling stream [2025-12-14T00:54:47.624894Z] [scala-execution-context-global-17] processed value: 21 [2025-12-14T00:54:47.624941Z] [scala-execution-context-global-18] processed value: 31 [2025-12-14T00:54:48.630583Z] [scala-execution-context-global-18] processed value: 32 [2025-12-14T00:54:48.630583Z] [scala-execution-context-global-17] processed value: 22 [2025-12-14T00:54:49.631715Z] [scala-execution-context-global-17] processed value: 23 [2025-12-14T00:54:49.631715Z] [scala-execution-context-global-18] processed value: 33 [2025-12-14T00:54:50.633388Z] [scala-execution-context-global-18] processed value: 34 [2025-12-14T00:54:50.633446Z] [scala-execution-context-global-17] processed value: 24 [2025-12-14T00:54:51.637520Z] [scala-execution-context-global-17] processed value: 35 [2025-12-14T00:54:51.637520Z] [scala-execution-context-global-18] processed value: 25 [2025-12-14T00:54:52.638957Z] [scala-execution-context-global-18] processed value: 36 [2025-12-14T00:54:52.638962Z] [scala-execution-context-global-17] processed value: 26 [2025-12-14T00:54:53.640003Z] [scala-execution-context-global-18] processed value: 27 [2025-12-14T00:54:53.640115Z] [scala-execution-context-global-17] processed value: 37 [2025-12-14T00:54:54.645701Z] [scala-execution-context-global-17] processed value: 38 [2025-12-14T00:54:54.645701Z] [scala-execution-context-global-18] processed value: 28 [2025-12-14T00:54:55.649485Z] [scala-execution-context-global-18] processed value: 39 [2025-12-14T00:54:55.649480Z] [scala-execution-context-global-17] processed value: 29 [2025-12-14T00:54:56.653413Z] [scala-execution-context-global-17] processed value: 40 [2025-12-14T00:54:56.653852Z] [scala-execution-context-global-18] processed value: 30 index: 3 end polling stream index: 2 end polling stream index: 4 start polling stream index: 5 start polling stream [2025-12-14T00:54:57.668565Z] [scala-execution-context-global-15] processed value: 51 [2025-12-14T00:54:57.668598Z] [scala-execution-context-global-19] processed value: 41 [2025-12-14T00:54:58.671105Z] [scala-execution-context-global-19] processed value: 52 [2025-12-14T00:54:58.671105Z] [scala-execution-context-global-15] processed value: 42 [2025-12-14T00:54:59.673673Z] [scala-execution-context-global-19] processed value: 43 [2025-12-14T00:54:59.673672Z] [scala-execution-context-global-15] processed value: 53 [2025-12-14T00:55:00.677369Z] [scala-execution-context-global-19] processed value: 54 [2025-12-14T00:55:00.677369Z] [scala-execution-context-global-15] processed value: 44 [2025-12-14T00:55:01.682723Z] [scala-execution-context-global-19] processed value: 55 [2025-12-14T00:55:01.683075Z] [scala-execution-context-global-19] processed value: 45 [2025-12-14T00:55:02.688268Z] [scala-execution-context-global-19] processed value: 56 [2025-12-14T00:55:02.688385Z] [scala-execution-context-global-15] processed value: 46 [2025-12-14T00:55:03.692659Z] [scala-execution-context-global-19] processed value: 47 [2025-12-14T00:55:03.692659Z] [scala-execution-context-global-15] processed value: 57 [2025-12-14T00:55:04.698204Z] [scala-execution-context-global-15] processed value: 58 [2025-12-14T00:55:04.698204Z] [scala-execution-context-global-19] processed value: 48 [2025-12-14T00:55:05.704070Z] [scala-execution-context-global-19] processed value: 59 [2025-12-14T00:55:05.704087Z] [scala-execution-context-global-15] processed value: 49 [2025-12-14T00:55:06.709624Z] [scala-execution-context-global-15] processed value: 60 [2025-12-14T00:55:06.709624Z] [scala-execution-context-global-19] processed value: 50 index: 5 end polling stream index: 4 end polling stream index: 6 start polling stream index: 7 start polling stream [2025-12-14T00:55:07.720479Z] [scala-execution-context-global-19] processed value: 71 [2025-12-14T00:55:07.720440Z] [scala-execution-context-global-18] processed value: 61 [2025-12-14T00:55:08.723131Z] [scala-execution-context-global-19] processed value: 62 [2025-12-14T00:55:08.723131Z] [scala-execution-context-global-18] processed value: 72 [2025-12-14T00:55:09.728250Z] [scala-execution-context-global-18] processed value: 73 [2025-12-14T00:55:09.728250Z] [scala-execution-context-global-19] processed value: 63 [2025-12-14T00:55:10.731018Z] [scala-execution-context-global-18] processed value: 74 [2025-12-14T00:55:10.731018Z] [scala-execution-context-global-19] processed value: 64 [2025-12-14T00:55:11.736225Z] [scala-execution-context-global-19] processed value: 75 [2025-12-14T00:55:11.736229Z] [scala-execution-context-global-18] processed value: 65 [2025-12-14T00:55:12.740471Z] [scala-execution-context-global-19] processed value: 66 [2025-12-14T00:55:12.740971Z] [scala-execution-context-global-18] processed value: 76 [2025-12-14T00:55:13.746137Z] [scala-execution-context-global-18] processed value: 67 [2025-12-14T00:55:13.746160Z] [scala-execution-context-global-19] processed value: 77 [2025-12-14T00:55:14.749593Z] [scala-execution-context-global-18] processed value: 68 [2025-12-14T00:55:14.749564Z] [scala-execution-context-global-19] processed value: 78 [2025-12-14T00:55:15.753434Z] [scala-execution-context-global-19] processed value: 69 [2025-12-14T00:55:15.753434Z] [scala-execution-context-global-18] processed value: 79 [2025-12-14T00:55:16.756966Z] [scala-execution-context-global-18] processed value: 80 [2025-12-14T00:55:16.756931Z] [scala-execution-context-global-19] processed value: 70 index: 7 end polling stream index: 6 end polling stream index: 8 start polling stream index: 9 start polling stream [2025-12-14T00:55:17.768614Z] [scala-execution-context-global-16] processed value: 91 [2025-12-14T00:55:17.768614Z] [scala-execution-context-global-23] processed value: 81 [2025-12-14T00:55:18.773515Z] [scala-execution-context-global-23] processed value: 92 [2025-12-14T00:55:18.773515Z] [scala-execution-context-global-16] processed value: 82 [2025-12-14T00:55:19.778257Z] [scala-execution-context-global-16] processed value: 93 [2025-12-14T00:55:19.778257Z] [scala-execution-context-global-23] processed value: 83 [2025-12-14T00:55:20.779737Z] [scala-execution-context-global-23] processed value: 94 [2025-12-14T00:55:20.779655Z] [scala-execution-context-global-16] processed value: 84 [2025-12-14T00:55:21.785096Z] [scala-execution-context-global-16] processed value: 85 [2025-12-14T00:55:21.785078Z] [scala-execution-context-global-23] processed value: 95 [2025-12-14T00:55:22.790370Z] [scala-execution-context-global-16] processed value: 96 [2025-12-14T00:55:22.790370Z] [scala-execution-context-global-23] processed value: 86 [2025-12-14T00:55:23.794793Z] [scala-execution-context-global-16] processed value: 87 [2025-12-14T00:55:23.794786Z] [scala-execution-context-global-23] processed value: 97 [2025-12-14T00:55:24.798454Z] [scala-execution-context-global-23] processed value: 88 [2025-12-14T00:55:24.798454Z] [scala-execution-context-global-16] processed value: 98 [2025-12-14T00:55:25.803290Z] [scala-execution-context-global-16] processed value: 89 [2025-12-14T00:55:25.803291Z] [scala-execution-context-global-23] processed value: 99 [2025-12-14T00:55:26.809916Z] [scala-execution-context-global-23] processed value: 90 index: 8 end polling stream [2025-12-14T00:55:26.810701Z] [scala-execution-context-global-16] processed value: 100 index: 9 end polling stream
54:37~55:26 49s ≒ 50s → 2 並列で chunk ごとに処理しているので並列数 2 で動作しているので並列数 1 の時の 2 倍で処理されていて正しい。
Pros
並列度 = parallelSize がそのまま意味を持つ(理解しやすい)
chunk を「ジョブ単位」にして並列実行できる(運用上のスループット改善が読みやすい)
Cons
execute の型が Pipe から Chunk[A]=> IO[B]へ変わる→ 既存の Pipe の実装の修正が必要
ログが unordered になる(並列なので index 順に終わらない)ので少し見にくい
2025/12/19 追記 関数のシグネチャを同じにしたまま並列化対応させる方法
def progressPar[G[x] >: F[x]: Concurrent, A, B](stream: => Stream[G, A], chunkSize: Int, paralleSize: Int)( execute: Pipe[G, Chunk[A], B] )(using monoid: Monoid[B]): Stream[G, B] = { stream .chunkN(chunkSize) .zipWithIndex .parEvalMap(paralleSize) { case (chunk, index) => Concurrent[G].flatMap( Concurrent[G].flatMap(logger.info(s"$prefix[$index] start polling stream"))(_ => execute(Stream.emit(chunk)).compile.fold(monoid.empty)(monoid.combine) ) )(result => Concurrent[G].map(logger.info(s"$prefix[$index] end polling stream"))(_ => result)) } }
対応案2:chunk 内側で並列化する(chunk 内の要素を並列)
progress は維持して execute の中で List 化した後に parTraverse します。
StreamProgressLogger.progress(chunkSize, stream1)(
_.evalMap(_.toList.pure[IO])
.evalMap(
_.parTraverse { value =>
IO.sleep(1.second) *> IO.delay(println(s"processed: $value"))
}
)
)
実行結果
index: 0 start polling stream [2025-12-14T00:55:55.252780Z] [scala-execution-context-global-23] processed value: 7 [2025-12-14T00:55:55.252727Z] [scala-execution-context-global-21] processed value: 6 [2025-12-14T00:55:55.252207Z] [scala-execution-context-global-17] processed value: 1 [2025-12-14T00:55:55.255154Z] [scala-execution-context-global-17] processed value: 10 [2025-12-14T00:55:55.252435Z] [scala-execution-context-global-18] processed value: 4 [2025-12-14T00:55:55.252634Z] [scala-execution-context-global-20] processed value: 3 [2025-12-14T00:55:55.251469Z] [scala-execution-context-global-15] processed value: 2 [2025-12-14T00:55:55.252536Z] [scala-execution-context-global-19] processed value: 5 [2025-12-14T00:55:55.252701Z] [scala-execution-context-global-22] processed value: 8 [2025-12-14T00:55:55.255301Z] [scala-execution-context-global-23] processed value: 9 index: 0 end polling stream index: 1 start polling stream [2025-12-14T00:55:56.263448Z] [scala-execution-context-global-22] processed value: 11 [2025-12-14T00:55:56.263868Z] [scala-execution-context-global-19] processed value: 14 [2025-12-14T00:55:56.264018Z] [scala-execution-context-global-20] processed value: 16 [2025-12-14T00:55:56.264178Z] [scala-execution-context-global-17] processed value: 19 [2025-12-14T00:55:56.263622Z] [scala-execution-context-global-23] processed value: 12 [2025-12-14T00:55:56.264197Z] [scala-execution-context-global-20] processed value: 20 [2025-12-14T00:55:56.264054Z] [scala-execution-context-global-18] processed value: 17 [2025-12-14T00:55:56.264030Z] [scala-execution-context-global-19] processed value: 18 [2025-12-14T00:55:56.263915Z] [scala-execution-context-global-15] processed value: 15 [2025-12-14T00:55:56.263893Z] [scala-execution-context-global-22] processed value: 13 index: 1 end polling stream index: 2 start polling stream [2025-12-14T00:55:57.270632Z] [scala-execution-context-global-22] processed value: 21 [2025-12-14T00:55:57.270780Z] [scala-execution-context-global-18] processed value: 24 [2025-12-14T00:55:57.270926Z] [scala-execution-context-global-18] processed value: 28 [2025-12-14T00:55:57.270746Z] [scala-execution-context-global-19] processed value: 23 [2025-12-14T00:55:57.270737Z] [scala-execution-context-global-15] processed value: 22 [2025-12-14T00:55:57.270912Z] [scala-execution-context-global-21] processed value: 29 [2025-12-14T00:55:57.270933Z] [scala-execution-context-global-17] processed value: 30 [2025-12-14T00:55:57.270832Z] [scala-execution-context-global-22] processed value: 27 [2025-12-14T00:55:57.270830Z] [scala-execution-context-global-23] processed value: 25 [2025-12-14T00:55:57.270831Z] [scala-execution-context-global-20] processed value: 26 index: 2 end polling stream index: 3 start polling stream [2025-12-14T00:55:58.277849Z] [scala-execution-context-global-20] processed value: 31 [2025-12-14T00:55:58.278199Z] [scala-execution-context-global-22] processed value: 33 [2025-12-14T00:55:58.278039Z] [scala-execution-context-global-23] processed value: 32 [2025-12-14T00:55:58.278439Z] [scala-execution-context-global-23] processed value: 34 [2025-12-14T00:55:58.278462Z] [scala-execution-context-global-15] processed value: 36 [2025-12-14T00:55:58.278737Z] [scala-execution-context-global-23] processed value: 39 [2025-12-14T00:55:58.278340Z] [scala-execution-context-global-22] processed value: 40 [2025-12-14T00:55:58.278314Z] [scala-execution-context-global-17] processed value: 35 [2025-12-14T00:55:58.278223Z] [scala-execution-context-global-20] processed value: 37 [2025-12-14T00:55:58.278476Z] [scala-execution-context-global-21] processed value: 38 index: 3 end polling stream index: 4 start polling stream [2025-12-14T00:55:59.285761Z] [scala-execution-context-global-21] processed value: 42 [2025-12-14T00:55:59.285800Z] [scala-execution-context-global-23] processed value: 45 [2025-12-14T00:55:59.285788Z] [scala-execution-context-global-17] processed value: 44 [2025-12-14T00:55:59.285761Z] [scala-execution-context-global-20] processed value: 41 [2025-12-14T00:55:59.285890Z] [scala-execution-context-global-23] processed value: 49 [2025-12-14T00:55:59.285809Z] [scala-execution-context-global-15] processed value: 47 [2025-12-14T00:55:59.285844Z] [scala-execution-context-global-21] processed value: 50 [2025-12-14T00:55:59.285800Z] [scala-execution-context-global-18] processed value: 46 [2025-12-14T00:55:59.285788Z] [scala-execution-context-global-22] processed value: 43 [2025-12-14T00:55:59.285810Z] [scala-execution-context-global-19] processed value: 48 index: 4 end polling stream index: 5 start polling stream [2025-12-14T00:56:00.288362Z] [scala-execution-context-global-22] processed value: 54 [2025-12-14T00:56:00.288494Z] [scala-execution-context-global-23] processed value: 53 [2025-12-14T00:56:00.288490Z] [scala-execution-context-global-15] processed value: 58 [2025-12-14T00:56:00.288481Z] [scala-execution-context-global-21] processed value: 56 [2025-12-14T00:56:00.288414Z] [scala-execution-context-global-18] processed value: 51 [2025-12-14T00:56:00.288348Z] [scala-execution-context-global-19] processed value: 52 [2025-12-14T00:56:00.288605Z] [scala-execution-context-global-23] processed value: 59 [2025-12-14T00:56:00.288553Z] [scala-execution-context-global-22] processed value: 57 [2025-12-14T00:56:00.288532Z] [scala-execution-context-global-20] processed value: 60 [2025-12-14T00:56:00.288535Z] [scala-execution-context-global-17] processed value: 55 index: 5 end polling stream index: 6 start polling stream [2025-12-14T00:56:01.293653Z] [scala-execution-context-global-22] processed value: 64 [2025-12-14T00:56:01.293777Z] [scala-execution-context-global-20] processed value: 61 [2025-12-14T00:56:01.293866Z] [scala-execution-context-global-19] processed value: 66 [2025-12-14T00:56:01.293946Z] [scala-execution-context-global-22] processed value: 65 [2025-12-14T00:56:01.294009Z] [scala-execution-context-global-19] processed value: 69 [2025-12-14T00:56:01.294072Z] [scala-execution-context-global-21] processed value: 70 [2025-12-14T00:56:01.293630Z] [scala-execution-context-global-17] processed value: 62 [2025-12-14T00:56:01.293679Z] [scala-execution-context-global-23] processed value: 63 [2025-12-14T00:56:01.293959Z] [scala-execution-context-global-20] processed value: 68 [2025-12-14T00:56:01.293899Z] [scala-execution-context-global-18] processed value: 67 index: 6 end polling stream index: 7 start polling stream [2025-12-14T00:56:02.300519Z] [scala-execution-context-global-18] processed value: 72 [2025-12-14T00:56:02.300737Z] [scala-execution-context-global-17] processed value: 75 [2025-12-14T00:56:02.300866Z] [scala-execution-context-global-19] processed value: 78 [2025-12-14T00:56:02.300967Z] [scala-execution-context-global-22] processed value: 79 [2025-12-14T00:56:02.300604Z] [scala-execution-context-global-23] processed value: 73 [2025-12-14T00:56:02.300594Z] [scala-execution-context-global-20] processed value: 71 [2025-12-14T00:56:02.300876Z] [scala-execution-context-global-17] processed value: 80 [2025-12-14T00:56:02.300873Z] [scala-execution-context-global-15] processed value: 76 [2025-12-14T00:56:02.300781Z] [scala-execution-context-global-18] processed value: 77 [2025-12-14T00:56:02.300743Z] [scala-execution-context-global-21] processed value: 74 index: 7 end polling stream index: 8 start polling stream [2025-12-14T00:56:03.304572Z] [scala-execution-context-global-15] processed value: 81 [2025-12-14T00:56:03.305256Z] [scala-execution-context-global-15] processed value: 84 [2025-12-14T00:56:03.305392Z] [scala-execution-context-global-20] processed value: 86 [2025-12-14T00:56:03.305477Z] [scala-execution-context-global-15] processed value: 87 [2025-12-14T00:56:03.305594Z] [scala-execution-context-global-23] processed value: 88 [2025-12-14T00:56:03.304662Z] [scala-execution-context-global-21] processed value: 83 [2025-12-14T00:56:03.304609Z] [scala-execution-context-global-18] processed value: 82 [2025-12-14T00:56:03.305615Z] [scala-execution-context-global-22] processed value: 89 [2025-12-14T00:56:03.305542Z] [scala-execution-context-global-20] processed value: 90 [2025-12-14T00:56:03.305367Z] [scala-execution-context-global-17] processed value: 85 index: 8 end polling stream index: 9 start polling stream [2025-12-14T00:56:04.308024Z] [scala-execution-context-global-17] processed value: 91 [2025-12-14T00:56:04.308024Z] [scala-execution-context-global-20] processed value: 92 [2025-12-14T00:56:04.308123Z] [scala-execution-context-global-17] processed value: 93 [2025-12-14T00:56:04.308180Z] [scala-execution-context-global-20] processed value: 94 [2025-12-14T00:56:04.308285Z] [scala-execution-context-global-20] processed value: 95 [2025-12-14T00:56:04.308389Z] [scala-execution-context-global-20] processed value: 97 [2025-12-14T00:56:04.308397Z] [scala-execution-context-global-17] processed value: 96 [2025-12-14T00:56:04.308492Z] [scala-execution-context-global-17] processed value: 98 [2025-12-14T00:56:04.308519Z] [scala-execution-context-global-17] processed value: 99 [2025-12-14T00:56:04.308560Z] [scala-execution-context-global-17] processed value: 100 index: 9 end polling stream
55:54 ~ 56:04 → 10s で動作している。chunk 内の要素は 10 個でその要素を並列で処理、つまり 10 並列で動作しているので 1 並列で動作しているものと比べて 10 倍で処理していて正しい 。
Pros
progress の設計(chunk 単位で開始/終了ログ)が活きる → 進捗ログが読みやすい
chunkSize が 10 なら最大 10 並列(chunk 内)で処理できる
progress の API を変えずに済む
Cons(重要)
parTraverse は基本的に fail-fast なので「失敗時にどこまで処理したいか」の方針を決めないと事故りやすい
途中キャンセルにより、副作用(ログ出力・外部 I/O)が途中まで出たり出なかったりする
具体的に parTraverse の動作で困った例を共有します。
問題なく動作する例
val io1 = IO.pure(println("a")) *> IO.delay(println("b")) val io2 = IO.raiseError(new RuntimeException("exception!")) val listIO = List(io1, io2) val ioList = listIO.parTraverse(identity).void ioList.unsafeRunSync()
result
a b Exception in thread "main" java.lang.RuntimeException: exception! at fs2$minusparallel$minustest$_.<init>(fs2-parallel-test.sc:145) at fs2$minusparallel$minustest_sc$.script$lzyINIT1(fs2-parallel-test.sc:164) at fs2$minusparallel$minustest_sc$.script(fs2-parallel-test.sc:164) at fs2$minusparallel$minustest_sc$.main(fs2-parallel-test.sc:168) at fs2$minusparallel$minustest_sc.main(fs2-parallel-test.sc) at parTraverse$extension @ fs2$minusparallel$minustest$_.<init>(fs2-parallel-test.sc:148) at unsafeRunSync @ fs2$minusparallel$minustest$_.<init>(fs2-parallel-test.sc:150)
a と b が出力され、exception が発生します。
想定外の動作をする例
val io2 = IO.raiseError(new RuntimeException("exception!")) val io3 = IO.sleep(1.second) *> IO.pure(println("c")) *> IO.delay(println("d")) //最初に時間のかかる処理を行う想定
result
c Exception in thread "main" java.lang.RuntimeException: exception! at fs2$minusparallel$minustest$_.<init>(fs2-parallel-test.sc:145) at fs2$minusparallel$minustest_sc$.script$lzyINIT1(fs2-parallel-test.sc:181) at fs2$minusparallel$minustest_sc$.script(fs2-parallel-test.sc:181) at fs2$minusparallel$minustest_sc$.main(fs2-parallel-test.sc:185) at fs2$minusparallel$minustest_sc.main(fs2-parallel-test.sc) at parTraverse$extension @ fs2$minusparallel$minustest$_.<init>(fs2-parallel-test.sc:165) at unsafeRunSync @ fs2$minusparallel$minustest$_.<init>(fs2-parallel-test.sc:167)
c は出力されるが、 d は出力されません。
このような現象が起きるのは IO.pure のため、定義時に評価され c は即時に出力されるのに対し、 d は IO の評価で sleep している間にエラーが発生し、IO がキャンセルされるため d はタイミングによっては処理されず出力されません。
対応方法は要件によって異なりますが、次の 3 つの方針があります。
- どこかでエラーが発生したら処理を止める。出力が中途半端でも問題なければ、サンプルコードのままでよい。
- エラーが発生しても並列に動作している箇所の処理を継続してよいなら、
.attemptで最後まで実行する。List の要素が Either[Throw, A]で、1 つでも Left があれば、最後は RailsError へ再度落とすなどを行う。 - どこかでエラーが発生したら、すべての処理内容をロールバックしたい(処理で S3 に PUT したものも消したい)場合など、条件がさまざまであれば対応も多様に検討する必要がある。
今回の結論
今回はログの見やすさなどから対応案 2 での対応を行いました。(対応案1でも並列数の設定を変えればパフォーマンス上は対応案2と同等の処理速度が出せます)
あとがき
この問題はいままでは該当の処理の速度が問題になったときに並列数の設定をあげるのと同時に CPU 割り当ても一定量増やすという対応を行なっていました。その結果 CPU 割り当てが増えたことによる影響で CPU スロットリングが解消されて処理能力が向上しておりそれを「並列数を増やしたから性能が向上した」と誤認していたようです。
私がこの担当になったとき CPU 割り当てを増やして、パフォーマンスが向上することを確認した後、処理速度が遅いなぁと感じていたので更なるチューニングのために色々設定を変えて動作確認をしていました。 その中で並列数によって処理時間は変わらないことに気がついて(色々遠回りしましたが)この問題を見つけました。協調性のない行動(?)がたまたま実装の不具合を見つけることもあるんですね。



















