Play2のPromiseと非同期処理について調査した
PlayFrameWorkはイベント駆動型を基本としているため、全ての処理は非同期で実行される事が前提となっています。 これによって単一スレッドで複数のリクエストを捌く事ができます。
非同期のHTTP呼び出しを実現するPlay WS APIを使って外部のWebサイトにアクセスするコードを例にして、非同期処理でクライアントからのリクエストがどう扱われるか見てみます。
非同期処理でのリクエスト挙動
非同期で外部Webサイトにアクセスするコントローラ
public class TestController extends Controller { public static F.Promise<Result> nonBlockingUrlAccess() { final String uniqueId = UUID.randomUUID().toString(); Logger.debug("request start : " + uniqueId); F.Promise<WS.Response> resultPromise = WS.url("http://yahoo.co.jp").get(); return resultPromise.map(new F.Function<WS.Response, Result>() { @Override public Result apply(WS.Response response) throws Throwable { Logger.debug("return result : " + uniqueId); return Results.ok(); } }); } }
このコントローラに対して5箇所から同時にアクセスした場合、以下のようなログが吐かれます。
request start : 61f6a075-7b23-4547-a8f8-e108e0aa9b82 request start : 249b3fd0-80fa-4e02-9702-fc46580ff3a5 request start : c98bc9cb-9f5a-43ac-8bb4-190dab9431fe request start : d0d79bd4-ecdd-4b31-9fc5-aa13ceb41c29 request start : 512300bc-1757-4543-9004-39362ec1fbea return result : 249b3fd0-80fa-4e02-9702-fc46580ff3a5 return result : 512300bc-1757-4543-9004-39362ec1fbea return result : 61f6a075-7b23-4547-a8f8-e108e0aa9b82 return result : d0d79bd4-ecdd-4b31-9fc5-aa13ceb41c29 return result : c98bc9cb-9f5a-43ac-8bb4-190dab9431fe
また、処理時間は以下のようになります。
Concurrency Level: 5 Time taken for tests: 1.033 seconds Complete requests: 5 Failed requests: 0 Requests per second: 4.84 [#/sec] (mean) Time per request: 1033.332 [ms] (mean) Time per request: 206.666 [ms] (mean, across all concurrent requests)
Promiseを使って非同期に外部Webサイトにアクセスする事で、1スレッドで複数のリクエストを同時に受け付け、結果が返ってきたものから順番にレスポンスを返せている事が分かります。
このように、基本的に非同期処理を行っている限り問題は無いのですが、実際にコードを書いているとDBアクセスなどでどうしても同期処理を行わなければいけない場合があります。
という訳で同期処理を普通に行った際にクライアントからのリクエストがどう扱われるか見てみます。
同期処理でのリクエスト挙動
重い同期処理を模擬したコントローラ
public class TestController extends Controller { public static Result blockingHeavy() throws InterruptedException { final String uniqueId = UUID.randomUUID().toString(); Logger.debug("request start : " + uniqueId); Thread.sleep(1000); Logger.debug("return result : " + uniqueId); return ok(); } }
このコントローラに対して5箇所から同時にアクセスした場合、以下のようなログが吐かれます。
request start : 5c0fb9e8-875e-4192-957a-20bc102554df return result : 5c0fb9e8-875e-4192-957a-20bc102554df request start : e28064e5-231b-43f5-9c44-99551e278491 return result : e28064e5-231b-43f5-9c44-99551e278491 request start : 0cf300fb-be2c-4ff0-8809-38e9ed13e725 return result : 0cf300fb-be2c-4ff0-8809-38e9ed13e725 request start : 80f5e280-6d51-438c-91da-edf94173d021 return result : 80f5e280-6d51-438c-91da-edf94173d021 request start : 167c95a5-bcd2-4501-9411-f9adf46f9874 return result : 167c95a5-bcd2-4501-9411-f9adf46f9874
また、処理時間は以下のようになります。
Concurrency Level: 5 Time taken for tests: 5.029 seconds Complete requests: 5 Failed requests: 0 Requests per second: 0.99 [#/sec] (mean) Time per request: 5029.434 [ms] (mean) Time per request: 1005.887 [ms] (mean, across all concurrent requests)
先ほどとは違いリクエストは順列に1件ずつ処理されており、先に届いたリクエストが処理されるまで後のリクエストは処理されていません。同期処理を普通に書くとリクエストを同時に捌けなくなってしまう事が分かります。
※本来Playは「マルチスレッド + イベント駆動型」なので同期処理を普通に書いてもスレッド数ぶんは同時に捌けますが、今回は説明のためスレッド数を1に設定しています。
同期処理をPromiseでラップする
では同期処理をPromiseでラップしてみるとどうでしょうか?Promiseでラップされた処理は非同期に実行されるので、これで同期処理でも同時に捌けるようになるはずです。
重い同期処理をPromiseでラップしたコントローラ
public class TestController extends Controller { public static F.Promise<Result> blockingHeavyWithPromise() { final String uniqueId = UUID.randomUUID().toString(); Logger.debug("request start : " + uniqueId); F.Promise<Result> resultPromise = F.Promise.promise(new F.Function0<Result>() { @Override public Result apply() throws Throwable { Logger.debug("promise start : " + uniqueId); Thread.sleep(1000); Logger.debug("process end : " + uniqueId); return ok(); } }); return resultPromise.map(new F.Function<Result, Result>() { @Override public Result apply(Result result) throws Throwable { Logger.debug("return result : " + uniqueId); return result; } }); } }
このコントローラに対して5箇所から同時にアクセスした場合、以下のようなログが吐かれます。
request start : 676db307-d8a9-4639-853c-e52026cca17c request start : 28dcc477-4d96-483c-b6ed-50771b48bad6 request start : 7ff15ce5-ce17-4db7-98a9-71b9f068fb76 request start : e15ddb60-4efb-47da-b008-4bfc8f69a4bc promise start : ae1432ba-bbe4-4f22-b724-26fd919334c9 process end : ae1432ba-bbe4-4f22-b724-26fd919334c9 promise start : 676db307-d8a9-4639-853c-e52026cca17c process end : 676db307-d8a9-4639-853c-e52026cca17c promise start : 28dcc477-4d96-483c-b6ed-50771b48bad6 process end : 28dcc477-4d96-483c-b6ed-50771b48bad6 promise start : 7ff15ce5-ce17-4db7-98a9-71b9f068fb76 process end : 7ff15ce5-ce17-4db7-98a9-71b9f068fb76 promise start : e15ddb60-4efb-47da-b008-4bfc8f69a4bc process end : e15ddb60-4efb-47da-b008-4bfc8f69a4bc return result : ae1432ba-bbe4-4f22-b724-26fd919334c9 return result : 676db307-d8a9-4639-853c-e52026cca17c return result : 28dcc477-4d96-483c-b6ed-50771b48bad6 return result : 7ff15ce5-ce17-4db7-98a9-71b9f068fb76 return result : e15ddb60-4efb-47da-b008-4bfc8f69a4bc
また、処理時間は以下のようになります。
Concurrency Level: 5 Time taken for tests: 5.102 seconds Complete requests: 5 Failed requests: 0 Requests per second: 0.98 [#/sec] (mean) Time per request: 5101.675 [ms] (mean) Time per request: 1020.335 [ms] (mean, across all concurrent requests)
リクエストの受け付け自体は同時に行えていますが、今度はPromiseの実行部分が詰まっているように見えます。処理時間はPromiseでラップする前と変わりませんし、これでは意味がありません。
Promiseでラップ=新規スレッド立ち上げではない
PlayでPromiseを作成する際には暗黙的にGlobalのExecutionContextが渡されており、Promiseの処理はそのExecutionContextによって実行されます。
詳しくは下記のサイトにまとまっていますのでそちらをご覧ください。非常に参考になります。
要するに、ただPromiseを使って同期処理をラップしただけでは非同期処理にはならないという事らしいです。よく見たらPlayの公式documentationにも似たような事が書いてありますね。
このため、Future でブロッキングコードをラップするという誘惑に駆られるかもしれないことに注意してください。こうすることではノンブロッキングになりませんし、ブロッキングが他のスレッド内で起こるかもしれません。使用しているスレッドプールがブロッキングを扱うための十分なスレッドを持っていることを確かめる必要があります。
別ExecutionContextを明示してPromiseでラップする
長くなりましたが、同期処理をPromiseでラップしたい際にはメインで使っているものとは別のExecutionContextを明示して渡す、というのが正しそうです。Playでは複数のExecutionContextをapplication.confで定義できます。
Promiseに渡す用のExecutionContextを定義し、それを使ってPromiseを作成してみます。
play { akka { event-handlers = ["akka.event.slf4j.Slf4jEventHandler"] loglevel = WARNING actor { default-dispatcher = { fork-join-executor { parallelism-min = 1 parallelism-max = 1 } } promises-dispatcher = { fork-join-executor { parallelism-min = 10 parallelism-max = 10 } } } } }
重い同期処理を別ExecutionContextを明示してPromiseでラップしたコントローラ
public class TestController extends Controller { public static F.Promise<Result> blockingHeavyWithPromise() { ExecutionContext executionContext = Akka.system().dispatchers().lookup("play.akka.actor.promises-dispatcher"); final String uniqueId = UUID.randomUUID().toString(); Logger.debug("request start : " + uniqueId); F.Promise<Result> resultPromise = F.Promise.promise(new F.Function0<Result>() { @Override public Result apply() throws Throwable { Logger.debug("promise start : " + uniqueId); Thread.sleep(1000); Logger.debug("process end : " + uniqueId); return ok(); } },executionContext); return resultPromise.map(new F.Function<Result, Result>() { @Override public Result apply(Result result) throws Throwable { Logger.debug("return result : " + uniqueId); return result; } }); } }
このコントローラに対して5箇所から同時にアクセスした場合、以下のようなログが吐かれます。
request start : 8b458e3e-a60b-467b-ae03-868115e71942 promise start : 8b458e3e-a60b-467b-ae03-868115e71942 request start : b0d248e2-5bd4-43d4-9bb5-0e3cd575dfd6 request start : 7de18236-a6f7-44b9-b427-8e1126ace14e promise start : b0d248e2-5bd4-43d4-9bb5-0e3cd575dfd6 request start : d2f7df3a-fddb-4aaa-af3f-3888f15c0979 promise start : 7de18236-a6f7-44b9-b427-8e1126ace14e promise start : d2f7df3a-fddb-4aaa-af3f-3888f15c0979 request start : b448a9f2-cb15-4547-b79d-e5b2627e6a9e promise start : b448a9f2-cb15-4547-b79d-e5b2627e6a9e process end : b0d248e2-5bd4-43d4-9bb5-0e3cd575dfd6 process end : d2f7df3a-fddb-4aaa-af3f-3888f15c0979 process end : 8b458e3e-a60b-467b-ae03-868115e71942 process end : 7de18236-a6f7-44b9-b427-8e1126ace14e return result : 8b458e3e-a60b-467b-ae03-868115e71942 return result : b0d248e2-5bd4-43d4-9bb5-0e3cd575dfd6 process end : b448a9f2-cb15-4547-b79d-e5b2627e6a9e return result : d2f7df3a-fddb-4aaa-af3f-3888f15c0979 return result : b448a9f2-cb15-4547-b79d-e5b2627e6a9e return result : 7de18236-a6f7-44b9-b427-8e1126ace14e
また、処理時間は以下のようになります。
Concurrency Level: 5 Time taken for tests: 1.083 seconds Complete requests: 5 Failed requests: 0 Requests per second: 4.62 [#/sec] (mean) Time per request: 1082.881 [ms] (mean) Time per request: 216.576 [ms] (mean, across all concurrent requests)
リクエストも同時に捌けていますし、Promiseも詰まっていません。処理時間も問題ありませんし、やっと求めていた動きになりました。
結論
Playで同期処理をPromiseでラップする時は、明示的に別のExecutionContextを渡すべき
色々理解不足の点もありますので、何かおかしなところありましたら教えてください!