Sencha Touch 2 で Ext Direct を使う (4)

この連載の最後は、リクエストのコンバインについてです。

リクエストのコンバイン

Ext Direct では、短時間での複数のRemote Procedure Call をまとめて処理する機能が組み込まれています。 デフォルトでは10ミリ秒以内に発生したリクエストは、まとめられてサーバーに送信されます。

コンバインされては困る場合には、 Ext.direct.RemotingProvider の enableBuffer コンフィグをfalseにします。 また、サーバーサイドの処理に時間がかかることが予想される場合は timeout コンフィグに適切な値を設定します。

この記事のソースコードは、 Assembla に置いてあります。 例によって、xFrameworkPX で作っています。

コンバインに関するコンフィグ

  • enableBuffer
  • timeout

どちらも、Providerがインスタンス化されたあとも、

enabelBuffer = false
timeout= 60

のように設定変更できる。

この動作について検証をしてみます。

Ext.Directコントローラー

[php] class extdirect extends xFrameworkPX_Controller_ExtDirect { public $modules = array( ‘directm’ => array() ); public $direct = array( ‘namespace’ => ‘MyApp’, ‘descriptor’ => ‘Ext.REMOTING_API’ ); public function execute() { $this->log->trace(‘Direct Called.’); parent::execute(); } } [/php]

通常はしないのですが、Directコントローラーのexecuteメソッドをオーバーラードして、 ログを残すようにしています。 これで、クライアント側からリクエストがあったときにログが記録されます。

Module (directm.php)

[php] class directm extends xFrameworkPX_Model { public $usetable = false; public function test($param, $wait) { $log = xFrameworkPX_Log::getInstance(); $log->trace(‘Function Called. param = ‘ . $param); sleep($wait); return ‘param is ‘ . $param . ‘ — Server Time:’ . date(‘H:i:s’); } } [/php]

モジュールのメソッドの方でも、呼び出しがあったことをログに記録するようにしています。 サーバーへのリクエスト毎にコントローラーでログが取られ メソッドの呼び出し毎にモジュールでログが取られるというわけです。

Module のtestメソッドは、指定した秒数だけwaitして返ってくるというものです。

普通にコンバイン

クライアント側のJSコードです。単純にRPCを10回、繰り返します。

rpc.js

[js] Ext.ns(‘MyApp’); Ext.onReady(function () { var i; Ext.direct.Manager.addProvider(Ext.REMOTING_API); for(i=0; i<10; i++) { MyApp.directm.test(i, 0, function (ret) { var now = new Date(); console.log(ret + ‘ client time:’ + Ext.Date.format(now, ‘H:i:s’)); }); } }); [/js]

コンソールには次のように表示されます。待ち時間を0にしていますので一瞬で処理は終わっています。

rpc.js:13param is 0 --- Server Time:14:04:19 client time:14:04:19
rpc.js:13param is 1 --- Server Time:14:04:19 client time:14:04:19
rpc.js:13param is 2 --- Server Time:14:04:19 client time:14:04:19
rpc.js:13param is 3 --- Server Time:14:04:19 client time:14:04:19
rpc.js:13param is 4 --- Server Time:14:04:19 client time:14:04:19
rpc.js:13param is 5 --- Server Time:14:04:19 client time:14:04:19
rpc.js:13param is 6 --- Server Time:14:04:19 client time:14:04:19
rpc.js:13param is 7 --- Server Time:14:04:19 client time:14:04:19
rpc.js:13param is 8 --- Server Time:14:04:19 client time:14:04:19
rpc.js:13param is 9 --- Server Time:14:04:19 client time:14:04:19

サーバーのログは次のようになっています。

2011-12-27 14:16:56,23     [00684] TRACE webapp/.extdirect.php - Direct Called.
2011-12-27 14:16:56,16     [00684] TRACE modules/directm.php - Function Called. param = 0
2011-12-27 14:16:56,16     [00684] TRACE modules/directm.php - Function Called. param = 1
2011-12-27 14:16:56,16     [00684] TRACE modules/directm.php - Function Called. param = 2
2011-12-27 14:16:56,16     [00684] TRACE modules/directm.php - Function Called. param = 3
2011-12-27 14:16:56,16     [00684] TRACE modules/directm.php - Function Called. param = 4
2011-12-27 14:16:56,16     [00684] TRACE modules/directm.php - Function Called. param = 5
2011-12-27 14:16:56,16     [00684] TRACE modules/directm.php - Function Called. param = 6
2011-12-27 14:16:56,16     [00684] TRACE modules/directm.php - Function Called. param = 7
2011-12-27 14:16:56,16     [00684] TRACE modules/directm.php - Function Called. param = 8
2011-12-27 14:16:56,16     [00684] TRACE modules/directm.php - Function Called. param = 9

コントローラーは1度だけ呼び出されていて、Moduleのメソッドは10回呼び出されています。 リクエストがまとめられていることがわかります。 では、メソッドに遅延を入れた場合はどうなるのでしょうか。

rpc.js の10行目でのRPC呼び出しで第2引数に1を渡してみます。

rpc.js:13param is 1 --- Server Time:14:21:13 client time:14:21:21
rpc.js:13param is 2 --- Server Time:14:21:14 client time:14:21:21
rpc.js:13param is 3 --- Server Time:14:21:15 client time:14:21:21
rpc.js:13param is 4 --- Server Time:14:21:16 client time:14:21:21
rpc.js:13param is 5 --- Server Time:14:21:17 client time:14:21:21
rpc.js:13param is 6 --- Server Time:14:21:18 client time:14:21:21
rpc.js:13param is 7 --- Server Time:14:21:19 client time:14:21:21
rpc.js:13param is 8 --- Server Time:14:21:20 client time:14:21:21
rpc.js:13param is 9 --- Server Time:14:21:21 client time:14:21:21

Server Time と client time を比べてみてください。10個のリクエストはサーバー上では1秒ごとに処理され、 それらがまとめてクライアントに返ってきているのがわかります。

リクエストのレスポンスは1秒ごとに返ってくるのではなく、10秒後に全部のレスポンスが返ります。 ここでは10秒ですが、このリクエストが30とかまとまると確実にタイムアウトを引き起こします。 一つひとつのリクエストは1秒で返ってくるはずですが、まとめられたため30秒(デフォルトのタイムアウト)を越えてタイムアウトになる訳です。

リクエストの分割

enableBufferコンフィグをfalseにすると、このリクエストのコンバインは行われなくなります。 そうすれば、一つひとつの処理を分割してリクエストすることが出来ます。 ただ、リクエストの数が多い場合は、XHRのオーバーヘッドは大きくなりますし、サーバー側に負担を掛けることにもなります。 2番目の例をebanleBufferコンフィグをfalseにして実行してみます。

rpc2.js

rpc2.js:14param is 4 --- Server Time:14:33:40 client time:14:33:40
rpc2.js:14param is 3 --- Server Time:14:33:40 client time:14:33:40
rpc2.js:14param is 2 --- Server Time:14:33:40 client time:14:33:40
rpc2.js:14param is 0 --- Server Time:14:33:40 client time:14:33:40
rpc2.js:14param is 5 --- Server Time:14:33:40 client time:14:33:40
rpc2.js:14param is 1 --- Server Time:14:33:40 client time:14:33:40
rpc2.js:14param is 7 --- Server Time:14:33:41 client time:14:33:41
rpc2.js:14param is 6 --- Server Time:14:33:41 client time:14:33:41
rpc2.js:14param is 8 --- Server Time:14:33:41 client time:14:33:41
rpc2.js:14param is 9 --- Server Time:14:33:41 client time:14:33:41

もどってくる順番が面白いことになっています。 応答時間を見ていると、サーバー側では6つのリクエストが一度に処理をされているような感じに見えます。 これはapacheの設定で変わるのだろうとおもいます。 それにしてももどってくる順番がでたらめですね。

2011-12-26 16:19:23,22     [32174] TRACE webapp/.extdirect.php - Direct Called.
2011-12-26 16:19:23,16     [32174] TRACE modules/directm.php - Function Called. param = 0
2011-12-26 16:19:24,22     [32174] TRACE webapp/.extdirect.php - Direct Called.
2011-12-26 16:19:24,16     [32174] TRACE modules/directm.php - Function Called. param = 1
2011-12-26 16:19:25,22     [32174] TRACE webapp/.extdirect.php - Direct Called.
2011-12-26 16:19:25,16     [32174] TRACE modules/directm.php - Function Called. param = 2
2011-12-26 16:19:27,22     [32174] TRACE webapp/.extdirect.php - Direct Called.
2011-12-26 16:19:27,16     [32174] TRACE modules/directm.php - Function Called. param = 3
2011-12-26 16:19:28,22     [32174] TRACE webapp/.extdirect.php - Direct Called.
2011-12-26 16:19:28,16     [32174] TRACE modules/directm.php - Function Called. param = 4
2011-12-26 16:19:29,22     [32174] TRACE webapp/.extdirect.php - Direct Called.
2011-12-26 16:19:29,16     [32174] TRACE modules/directm.php - Function Called. param = 5
2011-12-26 16:19:30,22     [32174] TRACE webapp/.extdirect.php - Direct Called.
2011-12-26 16:19:30,16     [32174] TRACE modules/directm.php - Function Called. param = 6
2011-12-26 16:19:31,22     [32174] TRACE webapp/.extdirect.php - Direct Called.
2011-12-26 16:19:31,16     [32174] TRACE modules/directm.php - Function Called. param = 7
2011-12-26 16:19:32,22     [32174] TRACE webapp/.extdirect.php - Direct Called.
2011-12-26 16:19:32,16     [32174] TRACE modules/directm.php - Function Called. param = 8
2011-12-26 16:19:33,22     [32174] TRACE webapp/.extdirect.php - Direct Called.
2011-12-26 16:19:33,16     [32174] TRACE modules/directm.php - Function Called. param = 9

サーバーのログを見ると、一つひとつが別のリクエストして送られてきていることがわかります。

enableBufferコンフィグをfalseにせずにリクエストを分割する方法としては、 リクエストを送り、そのレスポンスでのコールバックで次のリクエストを送るという方法があります。 そうすれば、送って受けてまた送って、という風に同期的な処理ができます。

rpc3.js

[js] Ext.onReady(function () { var i; Ext.direct.Manager.addProvider(Ext.REMOTING_API); i = 0; MyApp.f = function() { MyApp.directm.test(i, 1, function (ret) { var now = new Date(); console.log(ret + ‘ client time:’ + Ext.Date.format(now, ‘H:i:s’)); i++; if( i &lt; 10 ){ MyApp.f(); } }); }; MyApp.f(); }); [/js]

こんな感じです。この方法では最初のレスポンスが返ってきてから次のレスポンスを送るので、 同期的に処理をする必要があるときには便利です。

rpc3.js:14param is 0 --- Server Time:14:41:48 client time:14:41:48
rpc3.js:14param is 1 --- Server Time:14:41:50 client time:14:41:50
rpc3.js:14param is 2 --- Server Time:14:41:51 client time:14:41:51
rpc3.js:14param is 3 --- Server Time:14:41:52 client time:14:41:52
rpc3.js:14param is 4 --- Server Time:14:41:53 client time:14:41:53
rpc3.js:14param is 5 --- Server Time:14:41:54 client time:14:41:54
rpc3.js:14param is 6 --- Server Time:14:41:55 client time:14:41:55
rpc3.js:14param is 7 --- Server Time:14:41:56 client time:14:41:56
rpc3.js:14param is 8 --- Server Time:14:41:57 client time:14:41:57
rpc3.js:14param is 9 --- Server Time:14:41:58 client time:14:41:58

コンソールへの表示も、1秒ごとに更新され、順番に着実に処理されてゆく様子が見て取れます。